[OpenAFS-devel] Assertion failed! file vol-salvage.c, line 2719.

Michael Niksch nik@zurich.ibm.com
Mon, 17 Feb 2003 15:10:06 +0100


--
--PART-BOUNDARY=.110302171510.ZM47032.ibm.com
Content-Type: text/plain; charset=us-ascii

Today, one of my fileservers (OpenAFS 1.2.8 rs_aix43 namei) dumped core
(without any preceding messages in FileLog or VolserLog) and ran
salvager. Trying to follow up on some problems salvager reported, I
found that a couple of my volumes have problems that salvager cannot
fix. The problems are of the type

  dir vnode 787: invalid entry: ??/.. has no inode
   (vnode 399, unique 1) -- deleted

and despite of the "deleted" remark, the same problems keep showing up
in every subsequent run of salvager against those volumes.

I tried everything I could think of to get rid of the problem without
success. I ran salvager with the -oktozap and -salvagedirs flags, I
moved the volumes to a different fileserver, I compiled and ran OpenAFS
1.2.9-rc2 salvager, and I restored one of the volumes from backup, but
the problem persists with the same vnode number. Interestingly enough,
the output from salvager differs slightly, sometimes reporting

  "Salvage volume group" core dumped!

and

  Assertion failed! file vol-salvage.c, line 2719.

and sometimes not. I am attaching the output of a few subsequent runs
of salvager.

I am not sure whether my fileserver crash may have been related to
those problems. Anyway, I would rather know what is wrong with those
volumes, and how it could be fixed. Note that I can read data from the
volumes, and that one of them hasn't been changed for 7 years.

-- 
Michael Niksch                     /Zurich/IBM @ IBMCH
IBM Zurich Research Laboratory     nik@zurich.ibm.com
Saeumerstrasse 4                   http://www.zurich.ibm.com/~nik/
CH-8803 Rueschlikon / Switzerland  P: +41-1-724-8913 F: +41-1-724-8080

--PART-BOUNDARY=.110302171510.ZM47032.ibm.com
X-Zm-Content-Name: SalvageLog.030217.14
Content-Description: Plain Text
Content-Type: text/plain ; name="SalvageLog.030217.14" ; charset=us-ascii

@(#) OpenAFS 1.2.9-rc2 built  2003-02-17 
02/17/2003 14:29:30 STARTING AFS SALVAGER 2.4 (/usr/afs/bin/salvager -f /vicepaa)
02/17/2003 14:29:30 SALVAGING FILE SYSTEM PARTITION /vicepaa (device=vicepaa)
02/17/2003 14:29:30 ***Forced salvage of all volumes on this partition***
02/17/2003 14:29:32 SALVAGING VOLUME 536870963.
02/17/2003 14:29:32 u.rbl (536870963) updated 01/19/1996 17:56
02/17/2003 14:29:32 Vnode 787: length incorrect; changed from 2048 to 0
02/17/2003 14:29:32 The dir header alloc map for page 0 is bad.
02/17/2003 14:29:32 Directory bad, vnode 785; salvaging...
02/17/2003 14:29:32 Salvaging directory 785...
02/17/2003 14:29:32 Checking the results of the directory salvage...
02/17/2003 14:29:33 dir vnode 785: invalid entry: ??/.. has no inode (vnode 399, unique 1) -- deleted
02/17/2003 14:29:34 "Salvage volume group" core dumped!
02/17/2003 14:29:34 SALVAGING VOLUME 536871417.
02/17/2003 14:29:34 u.axs (536871417) updated 02/05/2003 15:46
02/17/2003 14:29:34 Vnode 329: length incorrect; changed from 2048 to 0
02/17/2003 14:29:34 First page in directory does not exist.
02/17/2003 14:29:34 Directory bad, vnode 329; salvaging...
02/17/2003 14:29:34 Salvaging directory 329...
02/17/2003 14:29:34 Failed to read first page of fromDir!
02/17/2003 14:29:34 Checking the results of the directory salvage...
02/17/2003 14:29:35 dir vnode 329: invalid entry: ??/.. has no inode (vnode 589, unique 1) -- deleted
02/17/2003 14:29:35 The dir header alloc map for page 0 is bad.
02/17/2003 14:29:35 Directory bad, vnode 593; salvaging...
02/17/2003 14:29:35 Salvaging directory 593...
02/17/2003 14:29:35 Checking the results of the directory salvage...
02/17/2003 14:29:35 dir vnode 593: invalid entry: ??/.. has no inode (vnode 589, unique 1) -- deleted
02/17/2003 14:29:36 "Salvage volume group" core dumped!
02/17/2003 14:29:36 SALVAGING VOLUME 536894014.
02/17/2003 14:29:36 tmp.u.rbl.rest (536894014) updated 01/19/1996 17:56
02/17/2003 14:29:36 The dir header alloc map for page 0 is bad.
02/17/2003 14:29:36 Directory bad, vnode 785; salvaging...
02/17/2003 14:29:36 Salvaging directory 785...
02/17/2003 14:29:36 Checking the results of the directory salvage...
02/17/2003 14:29:36 dir vnode 785: invalid entry: ??/.. has no inode (vnode 399, unique 1) -- deleted
02/17/2003 14:29:37 "Salvage volume group" core dumped!
02/17/2003 14:29:37 SALVAGING OF PARTITION /vicepaa COMPLETED

--PART-BOUNDARY=.110302171510.ZM47032.ibm.com
X-Zm-Content-Name: SalvageLog.030217.15
Content-Description: Plain Text
Content-Type: text/plain ; name="SalvageLog.030217.15" ; charset=us-ascii

@(#) OpenAFS 1.2.9-rc2 built  2003-02-17 
02/17/2003 14:37:23 STARTING AFS SALVAGER 2.4 (/usr/afs/bin/salvager -f /vicepaa)
02/17/2003 14:37:23 SALVAGING FILE SYSTEM PARTITION /vicepaa (device=vicepaa)
02/17/2003 14:37:23 ***Forced salvage of all volumes on this partition***
02/17/2003 14:37:23 SALVAGING VOLUME 536870963.
02/17/2003 14:37:23 u.rbl (536870963) updated 01/19/1996 17:56
02/17/2003 14:37:23 Vnode 785: length incorrect; changed from 2048 to 0
02/17/2003 14:37:23 First page in directory does not exist.
02/17/2003 14:37:23 Directory bad, vnode 785; salvaging...
02/17/2003 14:37:23 Salvaging directory 785...
02/17/2003 14:37:23 Failed to read first page of fromDir!
02/17/2003 14:37:23 Checking the results of the directory salvage...
02/17/2003 14:37:25 dir vnode 785: invalid entry: ??/.. has no inode (vnode 399, unique 1) -- deleted
02/17/2003 14:37:25 First page in directory does not exist.
02/17/2003 14:37:25 Directory bad, vnode 787; salvaging...
02/17/2003 14:37:25 Salvaging directory 787...
02/17/2003 14:37:25 Failed to read first page of fromDir!
02/17/2003 14:37:25 Checking the results of the directory salvage...
02/17/2003 14:37:25 dir vnode 787: invalid entry: ??/.. has no inode (vnode 399, unique 1) -- deleted
02/17/2003 14:37:25 Found 2 orphaned files and directories (approx. 2 KB)
02/17/2003 14:37:25 Salvaged u.rbl (536870963): 5190 files, 184844 blocks
02/17/2003 14:37:25 SALVAGING VOLUME 536871417.
02/17/2003 14:37:25 u.axs (536871417) updated 02/05/2003 15:46
02/17/2003 14:37:25 Vnode 593: length incorrect; changed from 2048 to 0
02/17/2003 14:37:25 The dir header alloc map for page 0 is bad.
02/17/2003 14:37:25 Directory bad, vnode 329; salvaging...
02/17/2003 14:37:25 Salvaging directory 329...
02/17/2003 14:37:25 Checking the results of the directory salvage...
02/17/2003 14:37:26 dir vnode 329: invalid entry: ??/.. has no inode (vnode 589, unique 1) -- deleted
02/17/2003 14:37:26 "Salvage volume group" core dumped!
02/17/2003 14:37:26 SALVAGING VOLUME 536894014.
02/17/2003 14:37:26 tmp.u.rbl.rest (536894014) updated 01/19/1996 17:56
02/17/2003 14:37:26 Vnode 785: length incorrect; changed from 2048 to 0
02/17/2003 14:37:26 First page in directory does not exist.
02/17/2003 14:37:26 Directory bad, vnode 785; salvaging...
02/17/2003 14:37:26 Salvaging directory 785...
02/17/2003 14:37:26 Failed to read first page of fromDir!
02/17/2003 14:37:26 Checking the results of the directory salvage...
02/17/2003 14:37:26 dir vnode 785: invalid entry: ??/.. has no inode (vnode 399, unique 1) -- deleted
02/17/2003 14:37:27 The dir header alloc map for page 0 is bad.
02/17/2003 14:37:27 Directory bad, vnode 787; salvaging...
02/17/2003 14:37:27 Salvaging directory 787...
02/17/2003 14:37:27 Checking the results of the directory salvage...
02/17/2003 14:37:27 dir vnode 787: invalid entry: ??/.. has no inode (vnode 399, unique 1) -- deleted
02/17/2003 14:37:27 "Salvage volume group" core dumped!
02/17/2003 14:37:27 SALVAGING OF PARTITION /vicepaa COMPLETED

--PART-BOUNDARY=.110302171510.ZM47032.ibm.com
X-Zm-Content-Name: SalvageLog.030217.16
Content-Description: Plain Text
Content-Type: text/plain ; name="SalvageLog.030217.16" ; charset=us-ascii

@(#) OpenAFS 1.2.9-rc2 built  2003-02-17 
02/17/2003 14:38:01 STARTING AFS SALVAGER 2.4 (/usr/afs/bin/salvager -f /vicepaa)
02/17/2003 14:38:01 SALVAGING FILE SYSTEM PARTITION /vicepaa (device=vicepaa)
02/17/2003 14:38:01 ***Forced salvage of all volumes on this partition***
02/17/2003 14:38:01 SALVAGING VOLUME 536870963.
02/17/2003 14:38:01 u.rbl (536870963) updated 01/19/1996 17:56
02/17/2003 14:38:01 The dir header alloc map for page 0 is bad.
02/17/2003 14:38:01 Directory bad, vnode 785; salvaging...
02/17/2003 14:38:01 Salvaging directory 785...
02/17/2003 14:38:01 Checking the results of the directory salvage...
02/17/2003 14:38:02 dir vnode 785: invalid entry: ??/.. has no inode (vnode 399, unique 1) -- deleted
02/17/2003 14:38:02 "Salvage volume group" core dumped!
02/17/2003 14:38:02 SALVAGING VOLUME 536871417.
02/17/2003 14:38:02 u.axs (536871417) updated 02/05/2003 15:46
02/17/2003 14:38:02 Vnode 329: length incorrect; changed from 2048 to 0
02/17/2003 14:38:02 First page in directory does not exist.
02/17/2003 14:38:02 Directory bad, vnode 329; salvaging...
02/17/2003 14:38:02 Salvaging directory 329...
02/17/2003 14:38:02 Failed to read first page of fromDir!
02/17/2003 14:38:02 Checking the results of the directory salvage...
02/17/2003 14:38:03 dir vnode 329: invalid entry: ??/.. has no inode (vnode 589, unique 1) -- deleted
02/17/2003 14:38:03 First page in directory does not exist.
02/17/2003 14:38:03 Directory bad, vnode 593; salvaging...
02/17/2003 14:38:03 Salvaging directory 593...
02/17/2003 14:38:03 Failed to read first page of fromDir!
02/17/2003 14:38:03 Checking the results of the directory salvage...
02/17/2003 14:38:03 dir vnode 593: invalid entry: ??/.. has no inode (vnode 589, unique 1) -- deleted
02/17/2003 14:38:03 The dir header alloc map for page 0 is bad.
02/17/2003 14:38:03 Directory bad, vnode 595; salvaging...
02/17/2003 14:38:03 Salvaging directory 595...
02/17/2003 14:38:03 Checking the results of the directory salvage...
02/17/2003 14:38:04 dir vnode 595: invalid entry: ??/.. has no inode (vnode 589, unique 1) -- deleted
02/17/2003 14:38:04 "Salvage volume group" core dumped!
02/17/2003 14:38:04 SALVAGING VOLUME 536894014.
02/17/2003 14:38:04 tmp.u.rbl.rest (536894014) updated 01/19/1996 17:56
02/17/2003 14:38:04 Vnode 787: length incorrect; changed from 2048 to 0
02/17/2003 14:38:04 The dir header alloc map for page 0 is bad.
02/17/2003 14:38:04 Directory bad, vnode 785; salvaging...
02/17/2003 14:38:04 Salvaging directory 785...
02/17/2003 14:38:04 Checking the results of the directory salvage...
02/17/2003 14:38:04 dir vnode 785: invalid entry: ??/.. has no inode (vnode 399, unique 1) -- deleted
02/17/2003 14:38:05 "Salvage volume group" core dumped!
02/17/2003 14:38:05 SALVAGING OF PARTITION /vicepaa COMPLETED

--PART-BOUNDARY=.110302171510.ZM47032.ibm.com
X-Zm-Content-Name: SalvageLog.030217.17
Content-Description: Plain Text
Content-Type: text/plain ; name="SalvageLog.030217.17" ; charset=us-ascii

@(#) OpenAFS 1.2.9-rc2 built  2003-02-17 
02/17/2003 14:40:58 STARTING AFS SALVAGER 2.4 (/usr/afs/bin/salvager -partition /vicepaa -force)
02/17/2003 14:40:58 SALVAGING FILE SYSTEM PARTITION /vicepaa (device=vicepaa)
02/17/2003 14:40:58 ***Forced salvage of all volumes on this partition***
02/17/2003 14:40:58 SALVAGING VOLUME 536870963.
02/17/2003 14:40:58 u.rbl (536870963) updated 01/19/1996 17:56
02/17/2003 14:40:58 Vnode 785: length incorrect; changed from 2048 to 0
02/17/2003 14:40:58 First page in directory does not exist.
02/17/2003 14:40:58 Directory bad, vnode 785; salvaging...
02/17/2003 14:40:58 Salvaging directory 785...
02/17/2003 14:40:58 Failed to read first page of fromDir!
02/17/2003 14:40:58 Checking the results of the directory salvage...
02/17/2003 14:40:59 dir vnode 785: invalid entry: ??/.. has no inode (vnode 399, unique 1) -- deleted
02/17/2003 14:40:59 The dir header alloc map for page 0 is bad.
02/17/2003 14:40:59 Directory bad, vnode 787; salvaging...
02/17/2003 14:40:59 Salvaging directory 787...
02/17/2003 14:40:59 Checking the results of the directory salvage...
02/17/2003 14:41:00 dir vnode 787: invalid entry: ??/.. has no inode (vnode 399, unique 1) -- deleted
02/17/2003 14:41:00 "Salvage volume group" core dumped!
02/17/2003 14:41:00 SALVAGING VOLUME 536871417.
02/17/2003 14:41:00 u.axs (536871417) updated 02/05/2003 15:46
02/17/2003 14:41:00 Vnode 595: length incorrect; changed from 2048 to 0
02/17/2003 14:41:00 The dir header alloc map for page 0 is bad.
02/17/2003 14:41:00 Directory bad, vnode 329; salvaging...
02/17/2003 14:41:00 Salvaging directory 329...
02/17/2003 14:41:00 Checking the results of the directory salvage...
02/17/2003 14:41:00 dir vnode 329: invalid entry: ??/.. has no inode (vnode 589, unique 1) -- deleted
02/17/2003 14:41:00 "Salvage volume group" core dumped!
02/17/2003 14:41:00 SALVAGING VOLUME 536894014.
02/17/2003 14:41:00 tmp.u.rbl.rest (536894014) updated 01/19/1996 17:56
02/17/2003 14:41:00 Vnode 785: length incorrect; changed from 2048 to 0
02/17/2003 14:41:01 First page in directory does not exist.
02/17/2003 14:41:01 Directory bad, vnode 785; salvaging...
02/17/2003 14:41:01 Salvaging directory 785...
02/17/2003 14:41:01 Failed to read first page of fromDir!
02/17/2003 14:41:01 Checking the results of the directory salvage...
02/17/2003 14:41:01 dir vnode 785: invalid entry: ??/.. has no inode (vnode 399, unique 1) -- deleted
02/17/2003 14:41:01 First page in directory does not exist.
02/17/2003 14:41:01 Directory bad, vnode 787; salvaging...
02/17/2003 14:41:01 Salvaging directory 787...
02/17/2003 14:41:01 Failed to read first page of fromDir!
02/17/2003 14:41:01 Checking the results of the directory salvage...
02/17/2003 14:41:02 dir vnode 787: invalid entry: ??/.. has no inode (vnode 399, unique 1) -- deleted
02/17/2003 14:41:02 Found 2 orphaned files and directories (approx. 2 KB)
02/17/2003 14:41:02 Salvaged tmp.u.rbl.rest (536894014): 5190 files, 184896 blocks
02/17/2003 14:41:02 SALVAGING OF PARTITION /vicepaa COMPLETED

--PART-BOUNDARY=.110302171510.ZM47032.ibm.com--