Rebuild error FSCK fatal error = 8

radio · 09-17-2006, 03:07 AM

I put the Snap 4000 (Server v4.0.860) with 4 320Gb in a RAID 5 configuration into production and started copying files to it tonight. There was a thunderstorm tonight, and I gather the power went out because when I went in the Snap was powered off. I guess the UPS is shot.

Disk status included "Error: Unable to allocate memory"

Here is the recent log:

I System Initialization : Initialization Complete! Memory to be released: 30450768 bytes. System 9/17/2006 2:03:23 AM
E File System Check : FSCK fatal error = 8 Disk 60000
RAID 5 9/17/2006 2:03:23 AM
E File System Check : Failed to allocate 10930276 bytes for update bitmap!!! Disk 60000
RAID 5 9/17/2006 2:03:23 AM
W File System Check : partition is NOT clean. Disk 60000
RAID 5 9/17/2006 2:03:22 AM
I File System Check : Executing fsck /dev/rraid0 /force /fix /fixfatal Disk 60000
RAID 5 9/17/2006 2:03:22 AM
I File System : Opened FDB for device 0x1000E Disk (Priv) 9/17/2006 2:03:22 AM
I File System Check : partition is clean. Disk (Priv) 9/17/2006 2:03:22 AM
I File System Check : Executing fsck /dev/ride1g /fix /fixfatal Disk (Priv) 9/17/2006 2:03:22 AM
I File System : Opened FDB for device 0x10006 Disk (Priv) 9/17/2006 2:03:22 AM
I File System Check : partition is clean. Disk (Priv) 9/17/2006 2:03:22 AM
I File System Check : Executing fsck /dev/ride0g /fix /fixfatal Disk (Priv) 9/17/2006 2:03:22 AM
S System Initialization : Server v4.0.860
Build Date: Mar 2 2005 17:50:35
Boot Count: 29 System 9/17/2006 2:03:17 AM
I System Shutdown : In Progress... System 9/17/2006 2:02:38 AM
I System Shutdown : in 3 seconds System 9/17/2006 2:02:35 AM
I System Initialization : Initialization Complete! Memory to be released: 30450768 bytes. System 9/17/2006 2:00:45 AM
E File System Check : FSCK fatal error = 8 Disk 60000
RAID 5 9/17/2006 2:00:45 AM
E File System Check : Failed to allocate 10930276 bytes for update bitmap!!! Disk 60000
RAID 5 9/17/2006 2:00:45 AM
W File System Check : partition is NOT clean. Disk 60000
RAID 5 9/17/2006 2:00:44 AM
I File System Check : Executing fsck /dev/rraid0 /force /fix /fixfatal Disk 60000
RAID 5 9/17/2006 2:00:44 AM

My first guess is not enought memory, so -

Command: debug memory

Total System Physical Memory: 67108864
File System Memory Allocated: 37160400
Memory To be Written: 0
Memory On Loan: 0
Loan Count: 0
Heap Memory: 32117904
Memory In Use: 31111168
Objects Allocated: 23
Communication Memory Allocated: 1524152
Memory In Use: 465908
SDB Non-Volatile Memory Allocated: 65536
Memory In Use: 16044
Handles Allocated:4679
Handles In Use: 358
SDB Volatile Memory Allocated: 98304
Memory In Use: 192
Handles Allocated: 11705
Handles In Use: 7

Looks like 64M is not enough to rebuild large disks.

Questions:

Does the wisdom here on Procooling agree with me? Is this clearly a ram problem?
Yes-> Where can I get the specs on the ram I need?
No -> Anything else I can try?

Why could I build the array in the first place, but not allocate the memory for the bitmap now?

I tried to find the FAQ section on procooling, but couldn't. Either it's really late, and I'm braindead or it was replaced by the WIKI. I was sure there was info in the FAQ that's not in the WIKI.

Phoenix32 · 09-17-2006, 03:27 AM

Take a look at the last page of the "Snap OS 3.4.805, anyone?" message thread. You might want to follow along and contribute based on what you posted here....

radio · 09-18-2006, 01:49 AM

Well, I just couldn't wait, so I canabalized another computer and foud a 256M DIMM.

Funny thing was, the high profile, single sided stick that was in the snap was a 128! (only saw 64 though). Someone must have tried to upgrade it and failed... but I digress

FSCK went ok, and it fixed a few things. It took a little over an hour. It's rebuilding the backup disk now (3%).

So add this to the knowledge base:

4000 series
OS: 4.0.860
HW 2.0.1
BIOS 2.0.282

Needs more than 64M to rebuild. 256M works. The error was:

File System Check : FSCK fatal error = 8
File System Check : Failed to allocate 10930276 bytes for update bitmap!!!

I don't know if I should be doing this, but while it's rebuilding, I started copying the rest of the 200Gb to it.

oidar

radio · 09-25-2006, 11:07 PM

Quote:

For starters, we are back to the time to build or rebuild a RAID 5 array. With 250 GB drives, it takes 5 or so hours. With the 320 GB drives, it takes 24 hours (without doing any copying or use). This is an indicator something "strange" is going on. It just doesn't add up. Does this mean the the SNAP is having a difficult time with the build/rebuild? If so, what kind of difficulty? Is it actually working, or does it just "look like" it is working properly? Nothing for sure here, just an indicator.

Ok, I think I have a clue.

I broke down and "broke" the raid, because I got so much help here, that I feel I owe something. Hopefully this will answer some questions.

The raid is rebuilding. It's just over half used - something like 450GB. Get this, it's taking exactly as long to rebuild as it did on an empty disk - almost exactly 24 hours. I think I found the reason it's longer with larger drives. It's highlighted in red below. The short answer is that it is using swap space because it can not allocate enough memory for an rcd_lncnt. - that's my semi-educated guess.

secondly the TB limit might be caused by the size of the i-node table. hummmm, i-node tables should be related to the number of files on the disk.... or is it just a static cache based on disk size... hummm... Damn, I'm going to have to fill the disk and break it again. I was going to say.... never mind. I'll get back to you.

Lets here your thoughts.

oidar

09/25/2006 22:57:15 Command: info log Temporary

Requested: Log=Temporary, Boot=N/A Direction=Fwd Types=All Source=All

09/24/2006 22:41:53 35 S SYS | System Initialization : Server v4.0.860
Build Date: Mar 2 2005 17:50:35
Boot Count: 35
09/24/2006 22:41:53 35 D SYS | Executable built by KEVIN
09/24/2006 22:41:53 35 D SYS | Hardware platform:2.0.1 Model:2 (256 MBytes) S/N:30xxxx
09/24/2006 22:41:53 35 D SYS | ETH: Reset- Eaddr set to 00 xx B6 04 xx xx
09/24/2006 22:41:53 35 D SYS | Update IP...
09/24/2006 22:41:54 35 D SYS | Initial file system BIO cache size is 26838528 bytes, 3232 buffers
09/24/2006 22:41:54 35 D SYS | DISK: Initial ARBs: 3232 Memory: 530048
09/24/2006 22:41:54 35 D SYS | Code Page set to 437
09/24/2006 22:41:54 35 D SYS | QDL System is DISABLED
09/24/2006 22:41:54 35 D SYS | Disk cache flush enabled
09/24/2006 22:41:54 35 D SYS | SNMP agent disabled.
09/24/2006 22:41:54 35 D SYS | SNTP disabled.
09/24/2006 22:41:54 35 D SYS | AFP: not started
09/24/2006 22:41:54 35 D SYS | FTPD: 'FTPD' not started.
09/24/2006 22:41:54 35 D SYS | Update WorkGroup...
09/24/2006 22:41:59 35 D SYS | Intf: 0, dev: 0: Model: ST3320620A
09/24/2006 22:41:59 35 D SYS | Firmware Rev: 3.AAD Serial #: 5QF0H0GS
09/24/2006 22:41:59 35 D SYS | Intf: 0, dev: 1: Model: ST3320620A
09/24/2006 22:41:59 35 D SYS | Firmware Rev: 3.AAD Serial #: 5QF0GZ5P
09/24/2006 22:41:59 35 D SYS | Intf: 1, dev: 0: Model: ST3320620A
09/24/2006 22:41:59 35 D SYS | Firmware Rev: 3.AAD Serial #: 5QF0GSDJ
09/24/2006 22:41:59 35 D SYS | Intf: 1, dev: 1: Model: ST3320620A
09/24/2006 22:41:59 35 D SYS | Firmware Rev: 3.AAD Serial #: 5QF0FHMP
09/24/2006 22:41:59 35 E L01 | File System : Logical set member 1 not found. Original device ID: 60000
09/24/2006 22:41:59 35 W L01 | File System : 1 member(s) missing in logical device (original ID: 60000)
09/24/2006 22:41:59 35 D SYS | RAID5Initialize: creating 64 worker threads
09/24/2006 22:41:59 35 D SYS | RAID5InitSet: device 1 unavailable to initialize set
09/24/2006 22:41:59 35 D SYS | RAID5InitializeCache: allocated cache of 65526KB
09/24/2006 22:41:59 35 I L00 | File System Check : Executing fsck /dev/ride0g /fix /fixfatal
09/24/2006 22:41:59 35 I L00 | File System Check : partition is clean.
09/24/2006 22:41:59 35 D SYS | Update FDB 0x10006...
09/24/2006 22:41:59 35 I L00 | File System : Opened FDB for device 0x10006
09/24/2006 22:41:59 35 D SYS | Scheduled ACL Set and Propagate at /priv/os_private for FDB_ID_12
09/24/2006 22:41:59 35 I L00 | File System Check : Executing fsck /dev/ride1g /fix /fixfatal
09/24/2006 22:41:59 35 D SYS | Propagate on /priv/os_private: Success - 8 files, 0 dirs; Errors - 0 files, 0 dirs
09/24/2006 22:41:59 35 I L00 | File System Check : partition is clean.
09/24/2006 22:41:59 35 D SYS | Update FDB 0x1000E...
09/24/2006 22:41:59 35 I L00 | File System : Opened FDB for device 0x1000E
09/24/2006 22:41:59 35 D SYS | Scheduled ACL Set and Propagate at /pri2/os_private for FDB_ID_13
09/24/2006 22:41:59 35 I L01 | File System Check : Executing fsck /dev/rraid0 /force /fix /fixfatal
09/24/2006 22:41:59 35 D SYS | Propagate on /pri2/os_private: Success - 8 files, 0 dirs; Errors - 0 files, 0 dirs
09/24/2006 22:41:59 35 I L01 | File System Check : partition is clean.
09/24/2006 22:41:59 35 D SYS | Fsck - Using primary superblock
09/24/2006 22:42:00 35 D SYS | 150674960 bytes pre-allocated
09/24/2006 22:42:01 35 D SYS | Memory allocation for i-node cache: 90% of free RAM
09/24/2006 22:42:02 35 D L01 | File System Check : Failed to allocate 174884354 bytes for rcd_lncntp!!!
09/24/2006 22:42:03 35 D SYS | -- Swap-based Fsck --09/24/2006 22:42:03 35 D SYS | 26414 i-node cache blocks, cache hash table: 12281 entries
09/24/2006 22:42:03 35 D SYS | 256 i-nodes per generic cache block
09/24/2006 22:42:03 35 D SYS | 170 i-nodes per directory cache block
09/24/2006 22:42:03 35 I L01 | File System Check : ** Phase 1 - Check blocks and sizes
09/24/2006 22:42:04 35 I NET | DHCP: T1 length was 0 is now 302400
09/24/2006 22:42:04 35 I NET | DHCP: T2 length was 0 is now 453600
09/24/2006 22:42:04 35 I NET | DHCP/BOOTP: Setting IP address to xx.xx.xx.xx
09/24/2006 22:42:04 35 D SYS | Update IP...
09/24/2006 22:42:04 35 D SYS | BOOTP: DNS = 200A3C03
09/24/2006 22:43:57 35 D SMB | SMB : Becoming master browser for xxx
09/24/2006 23:31:35 35 D SYS | Created shadow FDB files
09/24/2006 23:31:35 35 I L00 | File System : Closed FDB for device 0x1000E
09/24/2006 23:31:36 35 D SYS | Failed to copy (2), skipping tag.dat
09/24/2006 23:31:36 35 D SYS | Compared times file1Secs (451750DE) file2Secs (45174FD9)
09/24/2006 23:31:36 35 D SYS | Copy private FS /priv/tag.dat to /pri2/tag.dat = pass
09/24/2006 23:31:36 35 D SYS | Cloned private FS from 10006 to 1000E
09/24/2006 23:31:36 35 I D01 | File System : Spare Device 10008 has been converted from Individual Drive.
09/24/2006 23:31:36 35 D SYS | Spare Device 10008 has been created and will be used momentarily.
09/25/2006 0:01:31 35 I L01 | File System Check : ** Phase 1b - Rescan for more duplicate blocks
09/25/2006 0:01:31 35 I L01 | File System Check : ** Phase 2 - Check pathnames
09/25/2006 0:02:34 35 I L01 | File System Check : ** Phase 3 - Check connectivity
09/25/2006 0:02:34 35 I L01 | File System Check : ** Phase 4 - Check reference counts
09/25/2006 0:03:00 35 I L01 | File System Check : ** Phase 4b - Check backlinks
09/25/2006 0:03:54 35 I L01 | File System Check : ** Phase 5 - Check cylinder groups
09/25/2006 0:35:56 35 D SYS | 150676124 bytes used during fsck()
09/25/2006 0:35:56 35 I L01 | File System Check : 66886 files, 58210492 used, 56784693 free (0 frags, 56784693 blocks, 0.0%% fragmentation)
09/25/2006 0:35:56 35 D SYS | Elapsed time: 6837 s.
09/25/2006 0:35:56 35 D SYS | Fsck cache statistics:
09/25/2006 0:35:56 35 D SYS | total memory used for cache: 119910736 bytes
09/25/2006 0:35:56 35 D SYS | total number of directories: 7793
09/25/2006 0:35:56 35 D SYS | maximum depth of recursion in sorting: 1
09/25/2006 0:35:56 35 D SYS | number of swaps in sorting phase: 13976
09/25/2006 0:35:56 35 D SYS | ----- generic i-node cache -----
09/25/2006 0:35:56 35 D SYS | cache entries: 35218
09/25/2006 0:35:56 35 D SYS | cache hits: 203744218 (99%)
09/25/2006 0:35:56 35 D SYS | cache misses: 740182 (0%)
09/25/2006 0:35:56 35 D SYS | reused cache entries: 713768
09/25/2006 0:35:56 35 D SYS | total reads from swap device: 398611
09/25/2006 0:35:56 35 D SYS | total writes to swap device: 349364
09/25/2006 0:35:56 35 D SYS | total writes skipped (clean blocks): 364404
09/25/2006 0:35:56 35 D SYS | average successful cache lookup: 1.00 iterations
09/25/2006 0:35:56 35 D SYS | maximum successful cache lookup: 1 iterations
09/25/2006 0:35:56 35 D SYS | average unsuccessful cache lookup: 1.00 iterations
09/25/2006 0:35:56 35 D SYS | maximum unsuccessful cache lookup: 1 iterations
09/25/2006 0:35:56 35 D SYS | ----- directory i-node cache -----
09/25/2006 0:35:56 35 D SYS | cache entries: 17610
09/25/2006 0:35:56 35 D SYS | cache hits: 138928 (99%)
09/25/2006 0:35:56 35 D SYS | cache misses: 45 (0%)
09/25/2006 0:35:56 35 D SYS | reused cache entries: 91
09/25/2006 0:35:56 35 D SYS | total reads from swap device: 45
09/25/2006 0:35:56 35 D SYS | total writes to swap device: 91
09/25/2006 0:35:56 35 D SYS | total writes skipped (clean blocks): 0
09/25/2006 0:35:56 35 D SYS | average successful cache lookup: 1.00 iterations
09/25/2006 0:35:56 35 D SYS | maximum successful cache lookup: 1 iterations
09/25/2006 0:35:56 35 D SYS | average unsuccessful cache lookup: 1.00 iterations
09/25/2006 0:35:56 35 D SYS | maximum unsuccessful cache lookup: 1 iterations
09/25/2006 0:35:56 35 I L01 | File System Check : Cleanup completed...
09/25/2006 0:35:56 35 D SYS | Update FDB 0x60000...
09/25/2006 0:35:56 35 I L01 | File System : Opened FDB for device 0x60000
09/25/2006 0:35:56 35 D SYS | Scheduled ACL Set and Propagate at /0/os_private for FDB_ID_0
09/25/2006 0:35:56 35 I L00 | File System Check : Executing fsck /dev/ride1g /fix /fixfatal
09/25/2006 0:35:56 35 D SYS | Propagate on /0/os_private: Success - 13 files, 0 dirs; Errors - 0 files, 0 dirs
09/25/2006 0:35:56 35 I L00 | File System Check : partition is clean.
09/25/2006 0:35:57 35 D SYS | Failed to copy (2), skipping tag.dat
09/25/2006 0:35:57 35 D SYS | Compared times file1Secs (45175BB8) file2Secs (451750DE)
09/25/2006 0:35:57 35 D SYS | Copy private FS /priv/tag.dat to /pri2/tag.dat = pass
09/25/2006 0:35:57 35 D SYS | Cloned private FS from 10006 to 1000E
09/25/2006 0:35:57 35 D SYS | Update FDB 0x1000E...
09/25/2006 0:35:57 35 I L00 | File System : Opened FDB for device 0x1000E
09/25/2006 0:35:57 35 D SYS | Scheduled ACL Set and Propagate at /pri2/os_private for FDB_ID_13
09/25/2006 0:35:57 35 D SYS | Propagate on /pri2/os_private: Success - 8 files, 0 dirs; Errors - 0 files, 0 dirs
09/25/2006 0:35:57 35 D SYS | NFS: The hash table has been initialized.
09/25/2006 0:35:57 35 D SYS | NFS: the NFSID <--->FDBID cache has been initialised.
09/25/2006 0:35:57 35 D SYS | NFS Server started.
09/25/2006 0:35:57 35 D SYS | suspend_factor = E3A0E
09/25/2006 0:35:57 35 D SYS | DISK: Additional ARBs: 18441 (Mem: 3024324) Total Arbs: 21673 (Mem: 3554372)
09/25/2006 0:35:57 35 I SYS | System Initialization : Initialization Complete! Memory to be released: 153134064 bytes.
09/25/2006 0:35:57 35 D SYS | Restarted process timing
09/25/2006 0:35:57 35 W D[80060000] | File System : Logical device 80060000: no spares found to perform hot replacement
09/25/2006 0:36:06 35 D SYS | RAID5ReplaceMember on array 0: started (device = 0x80010008, buffer size = 64KB)
09/25/2006 0:50:24 35 D SYS | RAID5ReplaceMember on array 0: 1% done
09/25/2006 1:04:36 35 D SYS | RAID5ReplaceMember on array 0: 2% done
09/25/2006 1:18:48 35 D SYS | RAID5ReplaceMember on array 0: 3% done
09/25/2006 1:33:00 35 D SYS | RAID5ReplaceMember on array 0: 4% done
09/25/2006 1:47:13 35 D SYS | RAID5ReplaceMember on array 0: 5% done
09/25/2006 2:01:25 35 D SYS | RAID5ReplaceMember on array 0: 6% done
09/25/2006 2:15:37 35 D SYS | RAID5ReplaceMember on array 0: 7% done
09/25/2006 2:29:49 35 D SYS | RAID5ReplaceMember on array 0: 8% done
09/25/2006 2:44:01 35 D SYS | RAID5ReplaceMember on array 0: 9% done
09/25/2006 2:58:13 35 D SYS | RAID5ReplaceMember on array 0: 10% done
09/25/2006 3:12:26 35 D SYS | RAID5ReplaceMember on array 0: 11% done
09/25/2006 3:26:38 35 D SYS | RAID5ReplaceMember on array 0: 12% done
09/25/2006 3:40:50 35 D SYS | RAID5ReplaceMember on array 0: 13% done
09/25/2006 3:55:04 35 D SYS | RAID5ReplaceMember on array 0: 14% done
09/25/2006 4:09:17 35 D SYS | RAID5ReplaceMember on array 0: 15% done
09/25/2006 4:23:30 35 D SYS | RAID5ReplaceMember on array 0: 16% done
09/25/2006 4:37:42 35 D SYS | RAID5ReplaceMember on array 0: 17% done
09/25/2006 4:51:56 35 D SYS | RAID5ReplaceMember on array 0: 18% done
09/25/2006 5:06:09 35 D SYS | RAID5ReplaceMember on array 0: 19% done
09/25/2006 5:20:22 35 D SYS | RAID5ReplaceMember on array 0: 20% done
09/25/2006 5:34:34 35 D SYS | RAID5ReplaceMember on array 0: 21% done
09/25/2006 5:48:48 35 D SYS | RAID5ReplaceMember on array 0: 22% done
09/25/2006 6:03:02 35 D SYS | RAID5ReplaceMember on array 0: 23% done
09/25/2006 6:17:15 35 D SYS | RAID5ReplaceMember on array 0: 24% done
09/25/2006 6:31:28 35 D SYS | RAID5ReplaceMember on array 0: 25% done
09/25/2006 6:45:43 35 D SYS | RAID5ReplaceMember on array 0: 26% done
09/25/2006 6:59:57 35 D SYS | RAID5ReplaceMember on array 0: 27% done
09/25/2006 7:14:10 35 D SYS | RAID5ReplaceMember on array 0: 28% done
09/25/2006 7:28:24 35 D SYS | RAID5ReplaceMember on array 0: 29% done
09/25/2006 7:42:39 35 D SYS | RAID5ReplaceMember on array 0: 30% done
09/25/2006 7:56:54 35 D SYS | RAID5ReplaceMember on array 0: 31% done
09/25/2006 8:11:08 35 D SYS | RAID5ReplaceMember on array 0: 32% done
09/25/2006 8:25:23 35 D SYS | RAID5ReplaceMember on array 0: 33% done
09/25/2006 8:39:37 35 D SYS | RAID5ReplaceMember on array 0: 34% done
09/25/2006 8:53:53 35 D SYS | RAID5ReplaceMember on array 0: 35% done
09/25/2006 9:08:07 35 D SYS | RAID5ReplaceMember on array 0: 36% done
09/25/2006 9:22:22 35 D SYS | RAID5ReplaceMember on array 0: 37% done
09/25/2006 9:36:37 35 D SYS | RAID5ReplaceMember on array 0: 38% done
09/25/2006 9:50:53 35 D SYS | RAID5ReplaceMember on array 0: 39% done
09/25/2006 10:05:08 35 D SYS | RAID5ReplaceMember on array 0: 40% done
09/25/2006 10:19:23 35 D SYS | RAID5ReplaceMember on array 0: 41% done
09/25/2006 10:33:39 35 D SYS | RAID5ReplaceMember on array 0: 42% done
09/25/2006 10:47:56 35 D SYS | RAID5ReplaceMember on array 0: 43% done
09/25/2006 11:02:12 35 D SYS | RAID5ReplaceMember on array 0: 44% done
09/25/2006 11:16:28 35 D SYS | RAID5ReplaceMember on array 0: 45% done
09/25/2006 11:30:44 35 D SYS | RAID5ReplaceMember on array 0: 46% done
09/25/2006 11:45:02 35 D SYS | RAID5ReplaceMember on array 0: 47% done
09/25/2006 11:59:19 35 D SYS | RAID5ReplaceMember on array 0: 48% done
09/25/2006 12:13:36 35 D SYS | RAID5ReplaceMember on array 0: 49% done
09/25/2006 12:28:01 35 D SYS | RAID5ReplaceMember on array 0: 50% done
09/25/2006 12:42:20 35 D SYS | RAID5ReplaceMember on array 0: 51% done
09/25/2006 12:56:37 35 D SYS | RAID5ReplaceMember on array 0: 52% done
09/25/2006 13:10:55 35 D SYS | RAID5ReplaceMember on array 0: 53% done
09/25/2006 13:25:13 35 D SYS | RAID5ReplaceMember on array 0: 54% done
09/25/2006 13:39:31 35 D SYS | RAID5ReplaceMember on array 0: 55% done
09/25/2006 13:53:50 35 D SYS | RAID5ReplaceMember on array 0: 56% done
09/25/2006 14:08:09 35 D SYS | RAID5ReplaceMember on array 0: 57% done
09/25/2006 14:22:28 35 D SYS | RAID5ReplaceMember on array 0: 58% done
09/25/2006 14:36:48 35 D SYS | RAID5ReplaceMember on array 0: 59% done
09/25/2006 14:51:09 35 D SYS | RAID5ReplaceMember on array 0: 60% done
09/25/2006 15:05:29 35 D SYS | RAID5ReplaceMember on array 0: 61% done
09/25/2006 15:19:49 35 D SYS | RAID5ReplaceMember on array 0: 62% done
09/25/2006 15:34:10 35 D SYS | RAID5ReplaceMember on array 0: 63% done
09/25/2006 15:48:32 35 D SYS | RAID5ReplaceMember on array 0: 64% done
09/25/2006 16:02:53 35 D SYS | RAID5ReplaceMember on array 0: 65% done
09/25/2006 16:17:14 35 D SYS | RAID5ReplaceMember on array 0: 66% done
09/25/2006 16:31:36 35 D SYS | RAID5ReplaceMember on array 0: 67% done
09/25/2006 16:46:00 35 D SYS | RAID5ReplaceMember on array 0: 68% done
09/25/2006 17:00:23 35 D SYS | RAID5ReplaceMember on array 0: 69% done
09/25/2006 17:14:46 35 D SYS | RAID5ReplaceMember on array 0: 70% done
09/25/2006 17:29:09 35 D SYS | RAID5ReplaceMember on array 0: 71% done
09/25/2006 17:43:33 35 D SYS | RAID5ReplaceMember on array 0: 72% done
09/25/2006 17:57:59 35 D SYS | RAID5ReplaceMember on array 0: 73% done
09/25/2006 18:12:24 35 D SYS | RAID5ReplaceMember on array 0: 74% done
09/25/2006 18:26:50 35 D SYS | RAID5ReplaceMember on array 0: 75% done
09/25/2006 18:41:16 35 D SYS | RAID5ReplaceMember on array 0: 76% done
09/25/2006 18:55:42 35 D SYS | RAID5ReplaceMember on array 0: 77% done
09/25/2006 19:10:08 35 D SYS | RAID5ReplaceMember on array 0: 78% done
09/25/2006 19:24:36 35 D SYS | RAID5ReplaceMember on array 0: 79% done
09/25/2006 19:39:05 35 D SYS | RAID5ReplaceMember on array 0: 80% done
09/25/2006 19:53:35 35 D SYS | RAID5ReplaceMember on array 0: 81% done
09/25/2006 20:08:04 35 D SYS | RAID5ReplaceMember on array 0: 82% done
09/25/2006 20:22:34 35 D SYS | RAID5ReplaceMember on array 0: 83% done
09/25/2006 20:37:04 35 D SYS | RAID5ReplaceMember on array 0: 84% done
09/25/2006 20:51:37 35 D SYS | RAID5ReplaceMember on array 0: 85% done
09/25/2006 21:06:11 35 D SYS | RAID5ReplaceMember on array 0: 86% done
09/25/2006 21:20:44 35 D SYS | RAID5ReplaceMember on array 0: 87% done
09/25/2006 21:35:18 35 D SYS | RAID5ReplaceMember on array 0: 88% done
09/25/2006 21:49:52 35 D SYS | RAID5ReplaceMember on array 0: 89% done
09/25/2006 22:04:28 35 D SYS | RAID5ReplaceMember on array 0: 90% done
09/25/2006 22:19:06 35 D SYS | RAID5ReplaceMember on array 0: 91% done
09/25/2006 22:33:44 35 D SYS | RAID5ReplaceMember on array 0: 92% done
09/25/2006 22:48:23 35 D SYS | RAID5ReplaceMember on array 0: 93% done

Hallis · 09-26-2006, 05:33 AM

Good info here. Keep it coming. Was the rebuild a success?

Shane

blue68f100 · 09-26-2006, 08:01 AM

This is good info. Maybe we can get to the root of the problem and find a fix.

One thing I have read is that you DO NOT want to fail a drive in the middle of a rebuild. You can proably get away with it, if its the same drive. Copying files during a rebuild will really slow in down.

09/24/2006 22:42:01 35 D SYS | Memory allocation for i-node cache: 90% of free RAM This is good having that much free.
09/24/2006 22:42:02 35 D L01 | File System Check : Failed to allocate 174884354 bytes for rcd_lncntp!!!

This is proably the source for all the problem. Does not have enough ram (or some space) to alocate 175mb.
But you only have 128meg due to high density, Yes???
If 256m you should have 192 meg after the 64 meg for OS.

Looking at the log in detail. The def block size based on disk size is to large. The snap re-sizes the block size on the fly.

RAID5InitializeCache: allocated cache of 65526KB This is only 64M were is the other OS? I think there is a debug setting for this.

I see several places where it compairs files. The concludes the files are not there or not the correct size.

Now i'm wondering if we can reset the inode size to correct the problem. Or this was due to copying files during the rebuild????

Hallis · 09-26-2006, 09:45 AM

Since there are file check errors might it be a good idea to either totally wipe the drives or to also reinstall the OS?

blue68f100 · 09-26-2006, 12:09 PM

Failed to allocate bytes.....

This may be due to several things.
1. He is short on Ram with only 128.
2. The def is not possiable with 320gig drives
3. OS Coruption
4. Hardware problem

Theirs no turning back now.

We will need the value from several 4000 with different capacitys to know how to adjust them.

In debug we have 2 cmd that may help.

debug cmds:
raid cache size (set raid cache size in MB)
threads count (set raid thread count)

We need these to know how thing are allociated.

debug cache
debug memory

We need current values to get some idea on how to adjust it.

Hallis · 09-26-2006, 12:13 PM

Well here's a possable way. Does it work in JBOD mode?

blue68f100 · 09-26-2006, 01:06 PM

On that thought.

Run 2 RAID 1's better data retention than Raid 5 but not as fast.

Phoenix32 · 09-26-2006, 07:21 PM

Quote:

Originally Posted by radio

I think I found the reason it's longer with larger drives. It's highlighted in red below. The short answer is that it is using swap space because it can not allocate enough memory for an rcd_lncnt. - that's my semi-educated guess.

This makes sense and may very well be the case.

If so, I wonder if the 4.0.860 OS is hurting the situation then because of it's much larger memory usage? Would it be much different with 3.4.807? Is there a way to get 512MB memory to work? Would that even help?

Thank you for the info. You may very well be right on this educated guess. It even puts more weight on the fact that when you had 64MB it didn't work at all, and it is a "Software" RAID.

Phoenix32 · 09-26-2006, 07:27 PM

Quote:

Originally Posted by blue68f100

This is good info. Maybe we can get to the root of the problem and find a fix.

One thing I have read is that you DO NOT want to fail a drive in the middle of a rebuild. You can proably get away with it, if its the same drive. Copying files during a rebuild will really slow in down.

09/24/2006 22:42:01 35 D SYS | Memory allocation for i-node cache: 90% of free RAM This is good having that much free.
09/24/2006 22:42:02 35 D L01 | File System Check : Failed to allocate 174884354 bytes for rcd_lncntp!!!

This is proably the source for all the problem. Does not have enough ram (or some space) to alocate 175mb.
But you only have 128meg due to high density, Yes???
If 256m you should have 192 meg after the 64 meg for OS.

Looking at the log in detail. The def block size based on disk size is to large. The snap re-sizes the block size on the fly.

RAID5InitializeCache: allocated cache of 65526KB This is only 64M were is the other OS? I think there is a debug setting for this.

I see several places where it compairs files. The concludes the files are not there or not the correct size.

Now i'm wondering if we can reset the inode size to correct the problem. Or this was due to copying files during the rebuild????

You are thinking along the same lines as me here. Its either that or finding a way to get the unit to take more memory (this chipset should support 512MB, but only has one slot, which is the problem). I agree that changing a few of the default settings may help/correct. If so, then we would have a much faster and more reliable RAID array. If not correctable, we (meaning you software types) should be able to determine the exact cuttoff for the 4000 and drive size to prevent this. Maybe 300GB drives instead of 320's for example. But the real answer I think is on the track you are on here Dave.

Hallis · 09-26-2006, 07:45 PM

If so then perhapse this unit might not be so good for 900gb-1.2tb raids.

blue68f100 · 09-26-2006, 08:07 PM

Quote:

Its either that or finding a way to get the unit to take more memory (this chipset should support 512MB, but only has one slot, which is the problem).

They make ram expanders. I have seen some with 2 and 3 slots. Most are just like a low profile card that allow the ram chips to plug in at 90 deg. The problem is I do not know if there is space to the side of the ram slot for it to work, not having one.

Quote:

good for 900gb-1.2tb raids.

4 x 250 (1T) have not been any problem.

Hallis · 09-26-2006, 08:11 PM

Quote:

Originally Posted by blue68f100

They make ram expanders. I have seen some with 2 and 3 slots. Most are just like a low profile card that allow the ram chips to plug in at 90 deg. The problem is I do not know if there is space to the side of the ram slot for it to work, not having one.

4 x 250 (1T) have not been any problem.

right, i keep thinking 3x300+ with a spare

cianwill · 09-26-2006, 08:25 PM

Hmm, now that I have upgraded mine to having 256MB of RAM I wonder....maybe try to get all 4 400's to do Raid 5 again....hmmm

Hallis · 09-26-2006, 08:26 PM

Im of the mind, when critical data is in the balence, dont fix it if it isn't broken, Back the data up elsewhere, THEN do it

Shane

blue68f100 · 09-26-2006, 09:11 PM

Quote:

Originally Posted by cianwill

Hmm, now that I have upgraded mine to having 256MB of RAM I wonder....maybe try to get all 4 400's to do Raid 5 again....hmmm

Resetting the raid cache to 2/3 -3/4 of memory may do the trick as you previous found on dells site. It should at the least make it faster. If not the problem still exist. If it can build the raid 5 in the 8hr mark, you may have a winner.

Phoenix32 · 09-27-2006, 12:43 AM

Quote:

Originally Posted by Hallis

If so then perhapse this unit might not be so good for 900gb-1.2tb raids.

Well, I think it is good for somewhere between 4 x 250 and 4 x 320, just not sure where that limit is going to be (250, 300, or 320). Who knows, maybe if this memory thing or memory/cache settings works out, might be able to go above 1.2 TB and use 400 or 500 GB drives? I doubt it, but maybe...

Phoenix32 · 09-27-2006, 12:46 AM

Quote:

Originally Posted by Hallis

right, i keep thinking 3x300+ with a spare

If (I said if) 4 x 300 is okay (not sure), then 3 x 400 with a spare should be good too. It all comes down to this "where the limit is" question...

Phoenix32 · 09-27-2006, 12:47 AM

Quote:

Originally Posted by cianwill

Hmm, now that I have upgraded mine to having 256MB of RAM I wonder....maybe try to get all 4 400's to do Raid 5 again....hmmm

Please do... Might help answer a few things... If it won't go, try 3 x 400 and see how that acts (back on the 3 x 400 + spare idea).

Hallis · 09-27-2006, 05:45 AM

I've got 3x400's ready to go into something, 2 brand new in the box still. Fry's had a butt kicking sale and i couldnt resist. i MIGHT, be able to get an image for that 4500, so we'll see what happens there.

Shane

Phoenix32 · 09-27-2006, 09:16 AM

Sniff sniff

This old boy cannot even think about affording a 4500 from what I can tell (I did try though)...

Hallis · 09-27-2006, 10:13 AM

Just have to find the right deal. Mine didnt cost a lot at all. Only $225

radio · 09-27-2006, 11:29 AM

Yes, the build was successful. It took almost exactly 24hours down to the minute.

I copyed another mass of data to it, so it was 2/3 full and broke it again. It looks like its rebuilding fine and will again take 24 hours.

I missread the logs - the swap was only for hte FSCK, not rebuilding the disks, so it might not be virtual memory slowing it down. Then again, it could still use swap space without reporting it. I'll reply to someother comments here in the next post, but I just wanted to let you know I am using 256M memory, not 128.

oidar

Here's the data:

After unplugging one drive:

09/26/2006 23:54:33 Command: info log temporary

Requested: Log=Temporary, Boot=N/A Direction=Fwd Types=All Source=All

09/26/2006 23:52:31 37 S SYS | System Initialization : Server v4.0.860

Build Date: Mar 2 2005 17:50:35

Boot Count: 37

09/26/2006 23:52:31 37 D SYS | Executable built by KEVIN

09/26/2006 23:52:31 37 D SYS | Hardware platform:2.0.1 Model:2 (256 MBytes) S/N:308308

09/26/2006 23:52:31 37 D SYS | ETH: Reset- Eaddr set to 00 C0 B6 04 B4 54

09/26/2006 23:52:31 37 D SYS | Update IP...

09/26/2006 23:52:32 37 D SYS | Initial file system BIO cache size is 26838528 bytes, 3232 buffers

09/26/2006 23:52:32 37 D SYS | DISK: Initial ARBs: 3232 Memory: 530048

09/26/2006 23:52:32 37 D SYS | Code Page set to 437

09/26/2006 23:52:32 37 D SYS | QDL System is DISABLED

09/26/2006 23:52:32 37 D SYS | Disk cache flush enabled

09/26/2006 23:53:27 37 D SYS | ide_BaseDriverEntry: Ready Error at start.

09/26/2006 23:53:27 37 D SYS | ide_BaseDriverEntry: Ready Failed

09/26/2006 23:53:27 37 D SYS | SNMP agent disabled.

09/26/2006 23:53:27 37 D SYS | SNTP disabled.

09/26/2006 23:53:27 37 D SYS | AFP: not started

09/26/2006 23:53:27 37 D SYS | FTPD: 'FTPD' not started.

09/26/2006 23:53:27 37 D SYS | Update WorkGroup...

09/26/2006 23:53:27 37 I NET | DHCP: T1 length was 0 is now 302400

09/26/2006 23:53:27 37 I NET | DHCP: T2 length was 0 is now 453600

09/26/2006 23:53:27 37 I NET | DHCP/BOOTP: Setting IP address to 192.168.0.103

09/26/2006 23:53:27 37 D SYS | Update IP...

09/26/2006 23:53:27 37 D SYS | BOOTP: DNS = 200A8C0

09/26/2006 23:53:27 37 D SYS | Intf: 0, dev: 0: Model: ST3320620A

09/26/2006 23:53:27 37 D SYS | Firmware Rev: 3.AAD Serial #: 5QF0H0GS

09/26/2006 23:53:27 37 D SYS | Intf: 0, dev: 1: Failed to find drive.

09/26/2006 23:53:27 37 D SYS | Intf: 1, dev: 0: Model: ST3320620A

09/26/2006 23:53:27 37 D SYS | Firmware Rev: 3.AAD Serial #: 5QF0GSDJ

09/26/2006 23:53:27 37 D SYS | Intf: 1, dev: 1: Model: ST3320620A

09/26/2006 23:53:27 37 D SYS | Firmware Rev: 3.AAD Serial #: 5QF0FHMP

09/26/2006 23:53:27 37 E L01 | File System : Logical set member 1 not found. Original device ID: 60000

09/26/2006 23:53:27 37 W L01 | File System : 1 member(s) missing in logical device (original ID: 60000)

09/26/2006 23:53:27 37 D SYS | RAID5Initialize: creating 64 worker threads

09/26/2006 23:53:27 37 D SYS | RAID5InitSet: device 1 unavailable to initialize set

09/26/2006 23:53:27 37 D SYS | RAID5InitializeCache: allocated cache of 65526KB

09/26/2006 23:53:28 37 I L00 | File System Check : Executing fsck /dev/ride0g /fix /fixfatal

09/26/2006 23:53:28 37 I L00 | File System Check : partition is clean.

09/26/2006 23:53:28 37 D SYS | Update FDB 0x10006...

09/26/2006 23:53:28 37 I L00 | File System : Opened FDB for device 0x10006

09/26/2006 23:53:28 37 D SYS | Scheduled ACL Set and Propagate at /priv/os_private for FDB_ID_12

09/26/2006 23:53:28 37 I L00 | File System Check : Executing fsck /dev/ride2g /fix /fixfatal

09/26/2006 23:53:28 37 D SYS | Propagate on /priv/os_private: Success - 8 files, 0 dirs; Errors - 0 files, 0 dirs

09/26/2006 23:53:28 37 I L00 | File System Check : partition is clean.

09/26/2006 23:53:28 37 D SYS | Failed to copy (2), skipping tag.dat

09/26/2006 23:53:28 37 D SYS | Compared times file1Secs (451A035D) file2Secs (45174CF7)

09/26/2006 23:53:28 37 D SYS | Copy private FS /priv/tag.dat to /pri2/tag.dat = pass

09/26/2006 23:53:28 37 D SYS | Cloned private FS from 10006 to 10016

09/26/2006 23:53:28 37 D SYS | Update FDB 0x10016...

09/26/2006 23:53:28 37 I L00 | File System : Opened FDB for device 0x10016

09/26/2006 23:53:28 37 D SYS | Scheduled ACL Set and Propagate at /pri2/os_private for FDB_ID_13

09/26/2006 23:53:28 37 I L01 | File System Check : Executing fsck /dev/rraid0 /fix

09/26/2006 23:53:28 37 D SYS | Propagate on /pri2/os_private: Success - 8 files, 0 dirs; Errors - 0 files, 0 dirs

09/26/2006 23:53:28 37 I L01 | File System Check : partition is clean.

09/26/2006 23:53:28 37 D SYS | Update FDB 0x60000...

09/26/2006 23:53:28 37 I L01 | File System : Opened FDB for device 0x60000

09/26/2006 23:53:28 37 D SYS | Scheduled ACL Set and Propagate at /0/os_private for FDB_ID_0

09/26/2006 23:53:28 37 D SYS | Propagate on /0/os_private: Success - 14 files, 0 dirs; Errors - 0 files, 0 dirs

09/26/2006 23:53:28 37 D SYS | NFS: The hash table has been initialized.

09/26/2006 23:53:28 37 D SYS | NFS: the NFSID <--->FDBID cache has been initialised.

09/26/2006 23:53:28 37 D SYS | NFS Server started.

09/26/2006 23:53:28 37 D SYS | suspend_factor = 1C720A

09/26/2006 23:53:28 37 D SYS | DISK: Additional ARBs: 18442 (Mem: 3024488) Total Arbs: 21674 (Mem: 3554536)

09/26/2006 23:53:29 37 I SYS | System Initialization : Initialization Complete! Memory to be released: 153142368 bytes.

09/26/2006 23:53:29 37 D SYS | Restarted process timing

09/26/2006 23:53:29 37 W D[80060000] | File System : Logical device 80060000: no spares found to perform hot replacement

eventLogGetRecord() printed 64 records at 09/26/2006 23:54:33

As it started to rebuild:

Requested: Log=Temporary, Boot=N/A Direction=Fwd Types=All Source=All

09/26/2006 23:57:42 38 S SYS | System Initialization : Server v4.0.860

Build Date: Mar 2 2005 17:50:35

Boot Count: 38

09/26/2006 23:57:42 38 D SYS | Executable built by KEVIN

09/26/2006 23:57:42 38 D SYS | Hardware platform:2.0.1 Model:2 (256 MBytes) S/N:308308

09/26/2006 23:57:42 38 D SYS | ETH: Reset- Eaddr set to 00 C0 B6 04 B4 54

09/26/2006 23:57:42 38 D SYS | Update IP...

09/26/2006 23:57:43 38 D SYS | Initial file system BIO cache size is 26838528 bytes, 3232 buffers

09/26/2006 23:57:43 38 D SYS | DISK: Initial ARBs: 3232 Memory: 530048

09/26/2006 23:57:43 38 D SYS | Code Page set to 437

09/26/2006 23:57:43 38 D SYS | QDL System is DISABLED

09/26/2006 23:57:43 38 D SYS | Disk cache flush enabled

09/26/2006 23:57:43 38 D SYS | SNMP agent disabled.

09/26/2006 23:57:43 38 D SYS | SNTP disabled.

09/26/2006 23:57:43 38 D SYS | AFP: not started

09/26/2006 23:57:43 38 D SYS | FTPD: 'FTPD' not started.

09/26/2006 23:57:43 38 D SYS | Update WorkGroup...

09/26/2006 23:57:48 38 D SYS | Intf: 0, dev: 0: Model: ST3320620A

09/26/2006 23:57:48 38 D SYS | Firmware Rev: 3.AAD Serial #: 5QF0H0GS

09/26/2006 23:57:48 38 D SYS | Intf: 0, dev: 1: Model: ST3320620A

09/26/2006 23:57:48 38 D SYS | Firmware Rev: 3.AAD Serial #: 5QF0GZ5P

09/26/2006 23:57:48 38 D SYS | Intf: 1, dev: 0: Model: ST3320620A

09/26/2006 23:57:48 38 D SYS | Firmware Rev: 3.AAD Serial #: 5QF0GSDJ

09/26/2006 23:57:48 38 D SYS | Intf: 1, dev: 1: Model: ST3320620A

09/26/2006 23:57:48 38 D SYS | Firmware Rev: 3.AAD Serial #: 5QF0FHMP

09/26/2006 23:57:48 38 D SYS | Bad time stamp: potential set member 10008 discarded

09/26/2006 23:57:48 38 E L01 | File System : Logical set member 1 not found. Original device ID: 60000

09/26/2006 23:57:48 38 W L01 | File System : 1 member(s) missing in logical device (original ID: 60000)

09/26/2006 23:57:48 38 D SYS | RAID5Initialize: creating 64 worker threads

09/26/2006 23:57:48 38 D SYS | RAID5InitSet: device 1 unavailable to initialize set

09/26/2006 23:57:48 38 D SYS | RAID5InitializeCache: allocated cache of 65526KB

09/26/2006 23:57:48 38 I L00 | File System Check : Executing fsck /dev/ride0g /fix /fixfatal

09/26/2006 23:57:48 38 I L00 | File System Check : partition is clean.

09/26/2006 23:57:48 38 D SYS | Update FDB 0x10006...

09/26/2006 23:57:48 38 I L00 | File System : Opened FDB for device 0x10006

09/26/2006 23:57:48 38 D SYS | Scheduled ACL Set and Propagate at /priv/os_private for FDB_ID_12

09/26/2006 23:57:48 38 I L00 | File System Check : Executing fsck /dev/ride1g /fix /fixfatal

09/26/2006 23:57:48 38 D SYS | Propagate on /priv/os_private: Success - 8 files, 0 dirs; Errors - 0 files, 0 dirs

09/26/2006 23:57:48 38 I L00 | File System Check : partition is clean.

09/26/2006 23:57:48 38 D SYS | Failed to copy (2), skipping tag.dat

09/26/2006 23:57:48 38 D SYS | Compared times file1Secs (451A046D) file2Secs (451A035D)

09/26/2006 23:57:48 38 D SYS | Copy private FS /priv/tag.dat to /pri2/tag.dat = pass

09/26/2006 23:57:48 38 D SYS | Cloned private FS from 10006 to 1000E

09/26/2006 23:57:48 38 D SYS | Update FDB 0x1000E...

09/26/2006 23:57:48 38 I L00 | File System : Opened FDB for device 0x1000E

09/26/2006 23:57:48 38 D SYS | Scheduled ACL Set and Propagate at /pri2/os_private for FDB_ID_13

09/26/2006 23:57:48 38 I L01 | File System Check : Executing fsck /dev/rraid0 /fix

09/26/2006 23:57:48 38 D SYS | Propagate on /pri2/os_private: Success - 8 files, 0 dirs; Errors - 0 files, 0 dirs

09/26/2006 23:57:49 38 I L01 | File System Check : partition is clean.

09/26/2006 23:57:49 38 D SYS | Update FDB 0x60000...

09/26/2006 23:57:49 38 I L01 | File System : Opened FDB for device 0x60000

09/26/2006 23:57:49 38 D SYS | Scheduled ACL Set and Propagate at /0/os_private for FDB_ID_0

09/26/2006 23:57:49 38 D SYS | Propagate on /0/os_private: Success - 14 files, 0 dirs; Errors - 0 files, 0 dirs

09/26/2006 23:57:49 38 D SYS | NFS: The hash table has been initialized.

09/26/2006 23:57:49 38 D SYS | NFS: the NFSID <--->FDBID cache has been initialised.

09/26/2006 23:57:49 38 D SYS | NFS Server started.

09/26/2006 23:57:49 38 D SYS | suspend_factor = 1C720A

09/26/2006 23:57:49 38 D SYS | DISK: Additional ARBs: 18442 (Mem: 3024488) Total Arbs: 21674 (Mem: 3554536)

09/26/2006 23:57:49 38 I SYS | System Initialization : Initialization Complete! Memory to be released: 153142368 bytes.

09/26/2006 23:57:49 38 D SYS | Restarted process timing

09/26/2006 23:57:49 38 W D[80060000] | File System : Logical device 80060000: no spares found to perform hot replacement

09/26/2006 23:59:46 38 D SMB | SMB : Becoming master browser for WHYS

09/27/2006 0:03:11 38 I D01 | File System : Process formatting device /dev/ride1a

09/27/2006 0:03:11 38 I D01 | File System : Formatting /dev/ride1a

09/27/2006 0:03:11 38 I D01 | File System : Warning: 496 sectors in last cylinder unallocated

09/27/2006 0:03:11 38 I D01 | File System : /dev/ride1a: 621810192 sectors in 607237 cylinders of 16 tracks, 64 sectors

09/27/2006 0:03:11 38 I D01 | File System : 303618MB in 37953 cyl groups (16 c/g, 8MB/g, 768 i/g)

09/27/2006 0:13:17 38 D SYS | No FDB, or FDB corrupt. Reverting to shadow FDB

09/27/2006 0:13:17 38 D SYS | Reverting to Default FDB: FDB missing or invalid

09/27/2006 0:13:17 38 D SYS | Reverting to Default FDB: Quotas have been turned Off

09/27/2006 0:13:17 38 I D01 | File System : Successfully initialized empty FDB for device 0x10008

09/27/2006 0:13:17 38 D SYS | Reverting to Default FDB: ACLs will be set to default

09/27/2006 0:13:17 38 I D01 | File System : All ACLs for device 0x10008, reset to defaults

09/27/2006 0:13:17 38 D SYS | Scheduled ACL Set and Propagate at /1 for FDB_ID_1

09/27/2006 0:13:17 38 I D01 | File System : Opened FDB for device 0x10008

09/27/2006 0:13:17 38 D SYS | Scheduled ACL Set and Propagate at /1/os_private for FDB_ID_1

09/27/2006 0:13:17 38 I SYS | System Database : Added share SHARE2.

09/27/2006 0:13:17 38 I D01 | File System : Format complete

09/27/2006 0:13:17 38 D SYS | Propagate on /1: Success - 4 files, 2 dirs; Errors - 0 files, 0 dirs

09/27/2006 0:13:17 38 D SYS | Propagate on /1/os_private: Success - 4 files, 0 dirs; Errors - 0 files, 0 dirs

09/27/2006 0:19:01 38 D SYS | Created shadow FDB files

09/27/2006 0:19:01 38 I D01 | File System : Closed FDB for device 0x10008

09/27/2006 0:19:01 38 D SYS | Created shadow FDB files

09/27/2006 0:19:01 38 I L00 | File System : Closed FDB for device 0x1000E

09/27/2006 0:19:01 38 D SYS | Failed to copy (2), skipping tag.dat

09/27/2006 0:19:01 38 D SYS | Compared times file1Secs (451A086E) file2Secs (451A046D)

09/27/2006 0:19:01 38 D SYS | Copy private FS /priv/tag.dat to /pri2/tag.dat = pass

09/27/2006 0:19:01 38 D SYS | Cloned private FS from 10006 to 1000E

09/27/2006 0:19:01 38 I D01 | File System : Spare Device 10008 has been converted from Individual Drive.

09/27/2006 0:19:01 38 D SYS | Spare Device 10008 has been created and will be used momentarily.

09/27/2006 0:19:01 38 I L00 | File System Check : Executing fsck /dev/ride1g /fix /fixfatal

09/27/2006 0:19:01 38 I L00 | File System Check : partition is clean.

09/27/2006 0:19:02 38 D SYS | Update FDB 0x1000E...

09/27/2006 0:19:02 38 I L00 | File System : Opened FDB for device 0x1000E

09/27/2006 0:19:02 38 D SYS | Scheduled ACL Set and Propagate at /pri2/os_private for FDB_ID_13

09/27/2006 0:19:02 38 D SYS | Propagate on /pri2/os_private: Success - 8 files, 0 dirs; Errors - 0 files, 0 dirs

09/27/2006 0:19:11 38 D SYS | RAID5ReplaceMember on array 0: started (device = 0x80010008, buffer size = 64KB)

eventLogGetRecord() printed 95 records at 09/27/2006 0:19:24

------------

Command executed without error.

Here is the other debug info you requested:

09/27/2006 1:45:05 Command: debug cache

Block cache hits: 16092 Misses: 1086

Name cache stats:

Good hits: 684 Neg hits: 8

False hits: 0 Bad hits: 141

Misses: 226 Long (ignored): 0

2 Pass tries: 4 2 Pass hits: 4

------------

Command executed without error.

Total System Physical Memory: 268435456

File System Memory Allocated: 179980896

Memory To be Written: 0

Memory On Loan: 0

Loan Count: 0

Heap Memory: 159009040

Memory In Use: 156860112

Objects Allocated: 25

Communication Memory Allocated: 2059232

Memory In Use: 467604

SDB Non-Volatile Memory Allocated: 65536

Memory In Use: 16118

Handles Allocated:4679

Handles In Use: 362

SDB Volatile Memory Allocated: 98304

Memory In Use: 304

Handles Allocated: 11705

Handles In Use: 11

System has been configured!

09-17-2006, 03:27 AM	#2
Phoenix32 Thermophile Join Date: May 2006 Location: Yakima, WA Posts: 1,282	Re: Rebuild error FSCK fatal error = 8 Take a look at the last page of the "Snap OS 3.4.805, anyone?" message thread. You might want to follow along and contribute based on what you posted here....

09-18-2006, 01:49 AM	#3
radio Cooling Neophyte Join Date: Aug 2006 Location: central US Posts: 67	Re: Rebuild error FSCK fatal error = 8 Well, I just couldn't wait, so I canabalized another computer and foud a 256M DIMM. Funny thing was, the high profile, single sided stick that was in the snap was a 128! (only saw 64 though). Someone must have tried to upgrade it and failed... but I digress FSCK went ok, and it fixed a few things. It took a little over an hour. It's rebuilding the backup disk now (3%). So add this to the knowledge base: 4000 series OS: 4.0.860 HW 2.0.1 BIOS 2.0.282 Needs more than 64M to rebuild. 256M works. The error was: File System Check : FSCK fatal error = 8 File System Check : Failed to allocate 10930276 bytes for update bitmap!!! I don't know if I should be doing this, but while it's rebuilding, I started copying the rest of the 200Gb to it. oidar

09-26-2006, 05:33 AM	#5
Hallis Cooling Savant Join Date: Oct 2001 Location: Dallas, Tx Posts: 469	Re: Rebuild error FSCK fatal error = 8 Good info here. Keep it coming. Was the rebuild a success? Shane

09-26-2006, 08:01 AM	#6
blue68f100 Thermophile Join Date: Jul 2005 Location: Plano, TX Posts: 3,135	Re: Rebuild error FSCK fatal error = 8 This is good info. Maybe we can get to the root of the problem and find a fix. One thing I have read is that you DO NOT want to fail a drive in the middle of a rebuild. You can proably get away with it, if its the same drive. Copying files during a rebuild will really slow in down. 09/24/2006 22:42:01 35 D SYS \| Memory allocation for i-node cache: 90% of free RAM This is good having that much free. 09/24/2006 22:42:02 35 D L01 \| File System Check : Failed to allocate 174884354 bytes for rcd_lncntp!!! This is proably the source for all the problem. Does not have enough ram (or some space) to alocate 175mb. But you only have 128meg due to high density, Yes??? If 256m you should have 192 meg after the 64 meg for OS. Looking at the log in detail. The def block size based on disk size is to large. The snap re-sizes the block size on the fly. RAID5InitializeCache: allocated cache of 65526KB This is only 64M were is the other OS? I think there is a debug setting for this. I see several places where it compairs files. The concludes the files are not there or not the correct size. Now i'm wondering if we can reset the inode size to correct the problem. Or this was due to copying files during the rebuild???? __________________ 1 Snap 4500 - 1.0T (4 x 250gig WD2500SB RE), Raid5, 1 Snap 4500 - 1.6T (4 x 400gig Seagates), Raid5, 1 Snap 4200 - 4.0T (4 x 2gig Seagates), Raid5, Using SATA converts from Andy Link to SnapOS FAQ's http://forums.procooling.com/vbb/showthread.php?t=13820

09-26-2006, 09:45 AM	#7
Hallis Cooling Savant Join Date: Oct 2001 Location: Dallas, Tx Posts: 469	Re: Rebuild error FSCK fatal error = 8 Since there are file check errors might it be a good idea to either totally wipe the drives or to also reinstall the OS?

09-26-2006, 12:09 PM	#8
blue68f100 Thermophile Join Date: Jul 2005 Location: Plano, TX Posts: 3,135	Re: Rebuild error FSCK fatal error = 8 Failed to allocate bytes..... This may be due to several things. 1. He is short on Ram with only 128. 2. The def is not possiable with 320gig drives 3. OS Coruption 4. Hardware problem Theirs no turning back now. We will need the value from several 4000 with different capacitys to know how to adjust them. In debug we have 2 cmd that may help. debug cmds: raid cache size (set raid cache size in MB) threads count (set raid thread count) We need these to know how thing are allociated. debug cache debug memory We need current values to get some idea on how to adjust it. __________________ 1 Snap 4500 - 1.0T (4 x 250gig WD2500SB RE), Raid5, 1 Snap 4500 - 1.6T (4 x 400gig Seagates), Raid5, 1 Snap 4200 - 4.0T (4 x 2gig Seagates), Raid5, Using SATA converts from Andy Link to SnapOS FAQ's http://forums.procooling.com/vbb/showthread.php?t=13820 Last edited by blue68f100; 09-26-2006 at 12:57 PM.

09-26-2006, 12:13 PM	#9
Hallis Cooling Savant Join Date: Oct 2001 Location: Dallas, Tx Posts: 469	Re: Rebuild error FSCK fatal error = 8 Well here's a possable way. Does it work in JBOD mode?

09-26-2006, 01:06 PM	#10
blue68f100 Thermophile Join Date: Jul 2005 Location: Plano, TX Posts: 3,135	Re: Rebuild error FSCK fatal error = 8 On that thought. Run 2 RAID 1's better data retention than Raid 5 but not as fast. __________________ 1 Snap 4500 - 1.0T (4 x 250gig WD2500SB RE), Raid5, 1 Snap 4500 - 1.6T (4 x 400gig Seagates), Raid5, 1 Snap 4200 - 4.0T (4 x 2gig Seagates), Raid5, Using SATA converts from Andy Link to SnapOS FAQ's http://forums.procooling.com/vbb/showthread.php?t=13820

09-26-2006, 07:45 PM	#13
Hallis Cooling Savant Join Date: Oct 2001 Location: Dallas, Tx Posts: 469	Re: Rebuild error FSCK fatal error = 8 If so then perhapse this unit might not be so good for 900gb-1.2tb raids.

09-26-2006, 08:25 PM	#16
cianwill Cooling Neophyte Join Date: Jun 2006 Location: Manassas, VA Posts: 49	Re: Rebuild error FSCK fatal error = 8 Hmm, now that I have upgraded mine to having 256MB of RAM I wonder....maybe try to get all 4 400's to do Raid 5 again....hmmm __________________ 4200 x4 80 GB RAID 5 M4100 x4 160 GB RAID 5 4000 x4 320 GB RAID 5 1100 x1 80 GB 1100 x 1 40 GB

09-26-2006, 08:26 PM	#17
Hallis Cooling Savant Join Date: Oct 2001 Location: Dallas, Tx Posts: 469	Re: Rebuild error FSCK fatal error = 8 Im of the mind, when critical data is in the balence, dont fix it if it isn't broken, Back the data up elsewhere, THEN do it Shane

09-27-2006, 05:45 AM	#22
Hallis Cooling Savant Join Date: Oct 2001 Location: Dallas, Tx Posts: 469	Re: Rebuild error FSCK fatal error = 8 I've got 3x400's ready to go into something, 2 brand new in the box still. Fry's had a butt kicking sale and i couldnt resist. i MIGHT, be able to get an image for that 4500, so we'll see what happens there. Shane

09-27-2006, 09:16 AM	#23
Phoenix32 Thermophile Join Date: May 2006 Location: Yakima, WA Posts: 1,282	Re: Rebuild error FSCK fatal error = 8 Sniff sniff This old boy cannot even think about affording a 4500 from what I can tell (I did try though)...

09-27-2006, 10:13 AM	#24
Hallis Cooling Savant Join Date: Oct 2001 Location: Dallas, Tx Posts: 469	Re: Rebuild error FSCK fatal error = 8 Just have to find the right deal. Mine didnt cost a lot at all. Only $225

09-27-2006, 11:29 AM	#25
radio Cooling Neophyte Join Date: Aug 2006 Location: central US Posts: 67	Re: Rebuild error FSCK fatal error = 8 Yes, the build was successful. It took almost exactly 24hours down to the minute. I copyed another mass of data to it, so it was 2/3 full and broke it again. It looks like its rebuilding fine and will again take 24 hours. I missread the logs - the swap was only for hte FSCK, not rebuilding the disks, so it might not be virtual memory slowing it down. Then again, it could still use swap space without reporting it. I'll reply to someother comments here in the next post, but I just wanted to let you know I am using 256M memory, not 128. oidar Here's the data: After unplugging one drive: 09/26/2006 23:54:33 Command: info log temporary Requested: Log=Temporary, Boot=N/A Direction=Fwd Types=All Source=All 09/26/2006 23:52:31 37 S SYS \| System Initialization : Server v4.0.860 Build Date: Mar 2 2005 17:50:35 Boot Count: 37 09/26/2006 23:52:31 37 D SYS \| Executable built by KEVIN 09/26/2006 23:52:31 37 D SYS \| Hardware platform:2.0.1 Model:2 (256 MBytes) S/N:308308 09/26/2006 23:52:31 37 D SYS \| ETH: Reset- Eaddr set to 00 C0 B6 04 B4 54 09/26/2006 23:52:31 37 D SYS \| Update IP... 09/26/2006 23:52:32 37 D SYS \| Initial file system BIO cache size is 26838528 bytes, 3232 buffers 09/26/2006 23:52:32 37 D SYS \| DISK: Initial ARBs: 3232 Memory: 530048 09/26/2006 23:52:32 37 D SYS \| Code Page set to 437 09/26/2006 23:52:32 37 D SYS \| QDL System is DISABLED 09/26/2006 23:52:32 37 D SYS \| Disk cache flush enabled 09/26/2006 23:53:27 37 D SYS \| ide_BaseDriverEntry: Ready Error at start. 09/26/2006 23:53:27 37 D SYS \| ide_BaseDriverEntry: Ready Failed 09/26/2006 23:53:27 37 D SYS \| SNMP agent disabled. 09/26/2006 23:53:27 37 D SYS \| SNTP disabled. 09/26/2006 23:53:27 37 D SYS \| AFP: not started 09/26/2006 23:53:27 37 D SYS \| FTPD: 'FTPD' not started. 09/26/2006 23:53:27 37 D SYS \| Update WorkGroup... 09/26/2006 23:53:27 37 I NET \| DHCP: T1 length was 0 is now 302400 09/26/2006 23:53:27 37 I NET \| DHCP: T2 length was 0 is now 453600 09/26/2006 23:53:27 37 I NET \| DHCP/BOOTP: Setting IP address to 192.168.0.103 09/26/2006 23:53:27 37 D SYS \| Update IP... 09/26/2006 23:53:27 37 D SYS \| BOOTP: DNS = 200A8C0 09/26/2006 23:53:27 37 D SYS \| Intf: 0, dev: 0: Model: ST3320620A 09/26/2006 23:53:27 37 D SYS \| Firmware Rev: 3.AAD Serial #: 5QF0H0GS 09/26/2006 23:53:27 37 D SYS \| Intf: 0, dev: 1: Failed to find drive. 09/26/2006 23:53:27 37 D SYS \| Intf: 1, dev: 0: Model: ST3320620A 09/26/2006 23:53:27 37 D SYS \| Firmware Rev: 3.AAD Serial #: 5QF0GSDJ 09/26/2006 23:53:27 37 D SYS \| Intf: 1, dev: 1: Model: ST3320620A 09/26/2006 23:53:27 37 D SYS \| Firmware Rev: 3.AAD Serial #: 5QF0FHMP 09/26/2006 23:53:27 37 E L01 \| File System : Logical set member 1 not found. Original device ID: 60000 09/26/2006 23:53:27 37 W L01 \| File System : 1 member(s) missing in logical device (original ID: 60000) 09/26/2006 23:53:27 37 D SYS \| RAID5Initialize: creating 64 worker threads 09/26/2006 23:53:27 37 D SYS \| RAID5InitSet: device 1 unavailable to initialize set 09/26/2006 23:53:27 37 D SYS \| RAID5InitializeCache: allocated cache of 65526KB 09/26/2006 23:53:28 37 I L00 \| File System Check : Executing fsck /dev/ride0g /fix /fixfatal 09/26/2006 23:53:28 37 I L00 \| File System Check : partition is clean. 09/26/2006 23:53:28 37 D SYS \| Update FDB 0x10006... 09/26/2006 23:53:28 37 I L00 \| File System : Opened FDB for device 0x10006 09/26/2006 23:53:28 37 D SYS \| Scheduled ACL Set and Propagate at /priv/os_private for FDB_ID_12 09/26/2006 23:53:28 37 I L00 \| File System Check : Executing fsck /dev/ride2g /fix /fixfatal 09/26/2006 23:53:28 37 D SYS \| Propagate on /priv/os_private: Success - 8 files, 0 dirs; Errors - 0 files, 0 dirs 09/26/2006 23:53:28 37 I L00 \| File System Check : partition is clean. 09/26/2006 23:53:28 37 D SYS \| Failed to copy (2), skipping tag.dat 09/26/2006 23:53:28 37 D SYS \| Compared times file1Secs (451A035D) file2Secs (45174CF7) 09/26/2006 23:53:28 37 D SYS \| Copy private FS /priv/tag.dat to /pri2/tag.dat = pass 09/26/2006 23:53:28 37 D SYS \| Cloned private FS from 10006 to 10016 09/26/2006 23:53:28 37 D SYS \| Update FDB 0x10016... 09/26/2006 23:53:28 37 I L00 \| File System : Opened FDB for device 0x10016 09/26/2006 23:53:28 37 D SYS \| Scheduled ACL Set and Propagate at /pri2/os_private for FDB_ID_13 09/26/2006 23:53:28 37 I L01 \| File System Check : Executing fsck /dev/rraid0 /fix 09/26/2006 23:53:28 37 D SYS \| Propagate on /pri2/os_private: Success - 8 files, 0 dirs; Errors - 0 files, 0 dirs 09/26/2006 23:53:28 37 I L01 \| File System Check : partition is clean. 09/26/2006 23:53:28 37 D SYS \| Update FDB 0x60000... 09/26/2006 23:53:28 37 I L01 \| File System : Opened FDB for device 0x60000 09/26/2006 23:53:28 37 D SYS \| Scheduled ACL Set and Propagate at /0/os_private for FDB_ID_0 09/26/2006 23:53:28 37 D SYS \| Propagate on /0/os_private: Success - 14 files, 0 dirs; Errors - 0 files, 0 dirs 09/26/2006 23:53:28 37 D SYS \| NFS: The hash table has been initialized. 09/26/2006 23:53:28 37 D SYS \| NFS: the NFSID <--->FDBID cache has been initialised. 09/26/2006 23:53:28 37 D SYS \| NFS Server started. 09/26/2006 23:53:28 37 D SYS \| suspend_factor = 1C720A 09/26/2006 23:53:28 37 D SYS \| DISK: Additional ARBs: 18442 (Mem: 3024488) Total Arbs: 21674 (Mem: 3554536) 09/26/2006 23:53:29 37 I SYS \| System Initialization : Initialization Complete! Memory to be released: 153142368 bytes. 09/26/2006 23:53:29 37 D SYS \| Restarted process timing 09/26/2006 23:53:29 37 W D[80060000] \| File System : Logical device 80060000: no spares found to perform hot replacement eventLogGetRecord() printed 64 records at 09/26/2006 23:54:33 As it started to rebuild: Requested: Log=Temporary, Boot=N/A Direction=Fwd Types=All Source=All 09/26/2006 23:57:42 38 S SYS \| System Initialization : Server v4.0.860 Build Date: Mar 2 2005 17:50:35 Boot Count: 38 09/26/2006 23:57:42 38 D SYS \| Executable built by KEVIN 09/26/2006 23:57:42 38 D SYS \| Hardware platform:2.0.1 Model:2 (256 MBytes) S/N:308308 09/26/2006 23:57:42 38 D SYS \| ETH: Reset- Eaddr set to 00 C0 B6 04 B4 54 09/26/2006 23:57:42 38 D SYS \| Update IP... 09/26/2006 23:57:43 38 D SYS \| Initial file system BIO cache size is 26838528 bytes, 3232 buffers 09/26/2006 23:57:43 38 D SYS \| DISK: Initial ARBs: 3232 Memory: 530048 09/26/2006 23:57:43 38 D SYS \| Code Page set to 437 09/26/2006 23:57:43 38 D SYS \| QDL System is DISABLED 09/26/2006 23:57:43 38 D SYS \| Disk cache flush enabled 09/26/2006 23:57:43 38 D SYS \| SNMP agent disabled. 09/26/2006 23:57:43 38 D SYS \| SNTP disabled. 09/26/2006 23:57:43 38 D SYS \| AFP: not started 09/26/2006 23:57:43 38 D SYS \| FTPD: 'FTPD' not started. 09/26/2006 23:57:43 38 D SYS \| Update WorkGroup... 09/26/2006 23:57:48 38 D SYS \| Intf: 0, dev: 0: Model: ST3320620A 09/26/2006 23:57:48 38 D SYS \| Firmware Rev: 3.AAD Serial #: 5QF0H0GS 09/26/2006 23:57:48 38 D SYS \| Intf: 0, dev: 1: Model: ST3320620A 09/26/2006 23:57:48 38 D SYS \| Firmware Rev: 3.AAD Serial #: 5QF0GZ5P 09/26/2006 23:57:48 38 D SYS \| Intf: 1, dev: 0: Model: ST3320620A 09/26/2006 23:57:48 38 D SYS \| Firmware Rev: 3.AAD Serial #: 5QF0GSDJ 09/26/2006 23:57:48 38 D SYS \| Intf: 1, dev: 1: Model: ST3320620A 09/26/2006 23:57:48 38 D SYS \| Firmware Rev: 3.AAD Serial #: 5QF0FHMP 09/26/2006 23:57:48 38 D SYS \| Bad time stamp: potential set member 10008 discarded 09/26/2006 23:57:48 38 E L01 \| File System : Logical set member 1 not found. Original device ID: 60000 09/26/2006 23:57:48 38 W L01 \| File System : 1 member(s) missing in logical device (original ID: 60000) 09/26/2006 23:57:48 38 D SYS \| RAID5Initialize: creating 64 worker threads 09/26/2006 23:57:48 38 D SYS \| RAID5InitSet: device 1 unavailable to initialize set 09/26/2006 23:57:48 38 D SYS \| RAID5InitializeCache: allocated cache of 65526KB 09/26/2006 23:57:48 38 I L00 \| File System Check : Executing fsck /dev/ride0g /fix /fixfatal 09/26/2006 23:57:48 38 I L00 \| File System Check : partition is clean. 09/26/2006 23:57:48 38 D SYS \| Update FDB 0x10006... 09/26/2006 23:57:48 38 I L00 \| File System : Opened FDB for device 0x10006 09/26/2006 23:57:48 38 D SYS \| Scheduled ACL Set and Propagate at /priv/os_private for FDB_ID_12 09/26/2006 23:57:48 38 I L00 \| File System Check : Executing fsck /dev/ride1g /fix /fixfatal 09/26/2006 23:57:48 38 D SYS \| Propagate on /priv/os_private: Success - 8 files, 0 dirs; Errors - 0 files, 0 dirs 09/26/2006 23:57:48 38 I L00 \| File System Check : partition is clean. 09/26/2006 23:57:48 38 D SYS \| Failed to copy (2), skipping tag.dat 09/26/2006 23:57:48 38 D SYS \| Compared times file1Secs (451A046D) file2Secs (451A035D) 09/26/2006 23:57:48 38 D SYS \| Copy private FS /priv/tag.dat to /pri2/tag.dat = pass 09/26/2006 23:57:48 38 D SYS \| Cloned private FS from 10006 to 1000E 09/26/2006 23:57:48 38 D SYS \| Update FDB 0x1000E... 09/26/2006 23:57:48 38 I L00 \| File System : Opened FDB for device 0x1000E 09/26/2006 23:57:48 38 D SYS \| Scheduled ACL Set and Propagate at /pri2/os_private for FDB_ID_13 09/26/2006 23:57:48 38 I L01 \| File System Check : Executing fsck /dev/rraid0 /fix 09/26/2006 23:57:48 38 D SYS \| Propagate on /pri2/os_private: Success - 8 files, 0 dirs; Errors - 0 files, 0 dirs 09/26/2006 23:57:49 38 I L01 \| File System Check : partition is clean. 09/26/2006 23:57:49 38 D SYS \| Update FDB 0x60000... 09/26/2006 23:57:49 38 I L01 \| File System : Opened FDB for device 0x60000 09/26/2006 23:57:49 38 D SYS \| Scheduled ACL Set and Propagate at /0/os_private for FDB_ID_0 09/26/2006 23:57:49 38 D SYS \| Propagate on /0/os_private: Success - 14 files, 0 dirs; Errors - 0 files, 0 dirs 09/26/2006 23:57:49 38 D SYS \| NFS: The hash table has been initialized. 09/26/2006 23:57:49 38 D SYS \| NFS: the NFSID <--->FDBID cache has been initialised. 09/26/2006 23:57:49 38 D SYS \| NFS Server started. 09/26/2006 23:57:49 38 D SYS \| suspend_factor = 1C720A 09/26/2006 23:57:49 38 D SYS \| DISK: Additional ARBs: 18442 (Mem: 3024488) Total Arbs: 21674 (Mem: 3554536) 09/26/2006 23:57:49 38 I SYS \| System Initialization : Initialization Complete! Memory to be released: 153142368 bytes. 09/26/2006 23:57:49 38 D SYS \| Restarted process timing 09/26/2006 23:57:49 38 W D[80060000] \| File System : Logical device 80060000: no spares found to perform hot replacement 09/26/2006 23:59:46 38 D SMB \| SMB : Becoming master browser for WHYS 09/27/2006 0:03:11 38 I D01 \| File System : Process formatting device /dev/ride1a 09/27/2006 0:03:11 38 I D01 \| File System : Formatting /dev/ride1a 09/27/2006 0:03:11 38 I D01 \| File System : Warning: 496 sectors in last cylinder unallocated 09/27/2006 0:03:11 38 I D01 \| File System : /dev/ride1a: 621810192 sectors in 607237 cylinders of 16 tracks, 64 sectors 09/27/2006 0:03:11 38 I D01 \| File System : 303618MB in 37953 cyl groups (16 c/g, 8MB/g, 768 i/g) 09/27/2006 0:13:17 38 D SYS \| No FDB, or FDB corrupt. Reverting to shadow FDB 09/27/2006 0:13:17 38 D SYS \| Reverting to Default FDB: FDB missing or invalid 09/27/2006 0:13:17 38 D SYS \| Reverting to Default FDB: Quotas have been turned Off 09/27/2006 0:13:17 38 I D01 \| File System : Successfully initialized empty FDB for device 0x10008 09/27/2006 0:13:17 38 D SYS \| Reverting to Default FDB: ACLs will be set to default 09/27/2006 0:13:17 38 I D01 \| File System : All ACLs for device 0x10008, reset to defaults 09/27/2006 0:13:17 38 D SYS \| Scheduled ACL Set and Propagate at /1 for FDB_ID_1 09/27/2006 0:13:17 38 I D01 \| File System : Opened FDB for device 0x10008 09/27/2006 0:13:17 38 D SYS \| Scheduled ACL Set and Propagate at /1/os_private for FDB_ID_1 09/27/2006 0:13:17 38 I SYS \| System Database : Added share SHARE2. 09/27/2006 0:13:17 38 I D01 \| File System : Format complete 09/27/2006 0:13:17 38 D SYS \| Propagate on /1: Success - 4 files, 2 dirs; Errors - 0 files, 0 dirs 09/27/2006 0:13:17 38 D SYS \| Propagate on /1/os_private: Success - 4 files, 0 dirs; Errors - 0 files, 0 dirs 09/27/2006 0:19:01 38 D SYS \| Created shadow FDB files 09/27/2006 0:19:01 38 I D01 \| File System : Closed FDB for device 0x10008 09/27/2006 0:19:01 38 D SYS \| Created shadow FDB files 09/27/2006 0:19:01 38 I L00 \| File System : Closed FDB for device 0x1000E 09/27/2006 0:19:01 38 D SYS \| Failed to copy (2), skipping tag.dat 09/27/2006 0:19:01 38 D SYS \| Compared times file1Secs (451A086E) file2Secs (451A046D) 09/27/2006 0:19:01 38 D SYS \| Copy private FS /priv/tag.dat to /pri2/tag.dat = pass 09/27/2006 0:19:01 38 D SYS \| Cloned private FS from 10006 to 1000E 09/27/2006 0:19:01 38 I D01 \| File System : Spare Device 10008 has been converted from Individual Drive. 09/27/2006 0:19:01 38 D SYS \| Spare Device 10008 has been created and will be used momentarily. 09/27/2006 0:19:01 38 I L00 \| File System Check : Executing fsck /dev/ride1g /fix /fixfatal 09/27/2006 0:19:01 38 I L00 \| File System Check : partition is clean. 09/27/2006 0:19:02 38 D SYS \| Update FDB 0x1000E... 09/27/2006 0:19:02 38 I L00 \| File System : Opened FDB for device 0x1000E 09/27/2006 0:19:02 38 D SYS \| Scheduled ACL Set and Propagate at /pri2/os_private for FDB_ID_13 09/27/2006 0:19:02 38 D SYS \| Propagate on /pri2/os_private: Success - 8 files, 0 dirs; Errors - 0 files, 0 dirs 09/27/2006 0:19:11 38 D SYS \| RAID5ReplaceMember on array 0: started (device = 0x80010008, buffer size = 64KB) eventLogGetRecord() printed 95 records at 09/27/2006 0:19:24 ------------ Command executed without error. Here is the other debug info you requested: 09/27/2006 1:45:05 Command: debug cache Block cache hits: 16092 Misses: 1086 Name cache stats: Good hits: 684 Neg hits: 8 False hits: 0 Bad hits: 141 Misses: 226 Long (ignored): 0 2 Pass tries: 4 2 Pass hits: 4 ------------ Command executed without error. Total System Physical Memory: 268435456 File System Memory Allocated: 179980896 Memory To be Written: 0 Memory On Loan: 0 Loan Count: 0 Heap Memory: 159009040 Memory In Use: 156860112 Objects Allocated: 25 Communication Memory Allocated: 2059232 Memory In Use: 467604 SDB Non-Volatile Memory Allocated: 65536 Memory In Use: 16118 Handles Allocated:4679 Handles In Use: 362 SDB Volatile Memory Allocated: 98304 Memory In Use: 304 Handles Allocated: 11705 Handles In Use: 11 System has been configured!

Currently Active Users Viewing This Thread: 1 (0 members and 1 guests)