4100 Unknown disk operation error

[cayenne]

First post here after reading tons of useful information. I have a 4100 that I just upgraded with 4 WD1600JB's. Install and format went well, the problem happened after configuring for Raid5. When viewing the disk status I get the error of unknown disk operation error. Scrolling to the bottom of the log, I find "File System : Failed to resynchronize logical set 60000, error -1". I saw back in October a couple of other users had this problem, but never saw any resolution. Has anyone found the answer? Here is the drive revision information as well, so I don't think it is going to be related to different drives since they are all the same.

Intf: 0, dev: 0: Model: WDC WD1600JB-00REA0
Firmware Rev: 20.00K20 Serial #: WD-WCANM8953438
Intf: 1, dev: 0: Model: WDC WD1600JB-00REA0
Firmware Rev: 20.00K20 Serial #: WD-WCANM8955155
Intf: 2, dev: 0: Model: WDC WD1600JB-00REA0
Firmware Rev: 20.00K20 Serial #: WD-WCANM7079341
Intf: 3, dev: 0: Model: WDC WD1600JB-00REA0
Firmware Rev: 20.00K20 Serial #: WD-WCANM7039244

[blue68f100]

Need a little more info.

Have you checked your unit against the sticky for 4100 users. Reference to MB.

Also post "co de info" from debug and the Model # of your unit including the -00x and original size.

[cayenne]

I checked against the 4100 Motherboard sticky and mine has had the revisions completed already. Here is the print out of "co de info"

Logical Device: 10006 Position: 0 JBOD Size (KB): 32296 Free (KB): 32096 Private Mounted
Label:Private Contains system files only
Unique Id: 0x39D7F81B0A037E1F Mount: /priv Index: 12 Order: 0
Partition: 10006 Physical: 10007 FS Size (KB): 32768 Starting Blk: 515 Private
Physical: 10007 Drive Slot: 0 IDE Size (KB): 134217216 Fixed

Logical Device: 1000E Position: 0 JBOD Size (KB): 32296 Free (KB): 31584 Private Mounted
Label:Private Contains system files only
Unique Id: 0x13FB35613EEFA96D Mount: /pri2 Index: 13 Order: 1
Partition: 1000E Physical: 1000F FS Size (KB): 32768 Starting Blk: 515 Private
Physical: 1000F Drive Slot: 1 IDE Size (KB): 134217216 Fixed

Logical Device: 60000 Position: 1 RAID Size (KB): 400133952 Free (KB): 0 Public Unmounted
Label:RAID5 Large data protection disk
Unique Id: 0x4D3A81815169B601 Mount: /0 Index: 0 Order: 255
Partition: 10000 Physical: 10007 R 60000 Size (KB): 133377984 Starting Blk: 104776 Public
Physical: 10007 Drive Slot: 0 IDE Size (KB): 134217216 Fixed
Partition: 10008 Physical: 1000F R 60000 Size (KB): 133377984 Starting Blk: 104776 Public
Physical: 1000F Drive Slot: 1 IDE Size (KB): 134217216 Fixed
Partition: 10010 Physical: 10017 R 60000 Size (KB): 133377984 Starting Blk: 104776 Public
Physical: 10017 Drive Slot: 2 IDE Size (KB): 134217216 Fixed
Partition: 10018 Physical: 1001F R 60000 Size (KB): 133377984 Starting Blk: 104776 Public
Physical: 1001F Drive Slot: 3 IDE Size (KB): 134217216 Fixed

I am in the middle of doing a disk check right now. As soon as it is complete I will post back with the server information.
Thanks!

[cayenne]

Disk check just completed and the controller is now Rebuilding Backup Disk. This is where it usually fails somewhere around 30% complete. Here is the server specifics:


Software Version: 3.4.772
Hardware Version: 2.2.1
Bios Version: 2.4.437

[frankb3910]

There are two other logs you can access from the debug window. They may offer a little more information. One is: info log t -- The second one is: i l p -1 (make sure you have spaces in there).

When i was having trouble with mine, i could see the following in the logs:

01/12/2007 15:11:29 106 D SYS | RAID5Resync on array 0: 47% done
01/12/2007 15:15:48 106 D SYS | RAID5Resync on array 0: 48% done
01/12/2007 15:18:30 106 D SYS | DISK: req=0x692EDC8 dev=0xC0002 fn=1blk=0x7D6A360 sts=18
01/12/2007 15:20:09 106 D SYS | RAID5Resync on array 0: 49% done


You can see it is reporting progress then, there is some kind of disc error. In this case dev=0xC002 is telling you which drive is throwing off errors.

I had another user tell me that the hard drives generate a lot of heat when rebuilding a raid, he suggested removing the cover to allow for better cooling.

I also tried switching cables to be sure the problem didn't move around when cables were moved. It did turn out to be a bad hard drive in my case. After replacing that drive (and taking off the cover) I was able to get a successful raid 5 rebuild.

[frankb3910]

I also meant to mention that I upgraded the ram to 256MB which (I believe) is the max that these can handle. If you search the threads, there is more information on what kind of ram to buy specifically. I think that really was a big help in working with the larger hard drives.

[Lethe]

It could be one of the disks (or maybe more) has factory lowlevel format set so that the full 60GB is not available.

At work I have had three disks failures out of 5 boxes - Snap always send a 80GB disk to replace the bust 60GB drive that came with the unit - but after rebuilding the RAID, only 60GB is used.

Nick

[cayenne]

Originally Posted by Lethe

It could be one of the disks (or maybe more) has factory lowlevel format set so that the full 60GB is not available.

At work I have had three disks failures out of 5 boxes - Snap always send a 80GB disk to replace the bust 60GB drive that came with the unit - but after rebuilding the RAID, only 60GB is used.

Nick

Nick,
These are brand new WD 160GB drives. I am assuming they are all fine, but I will be running Spinrite on them this evening to double check.

Frank,
I will also post the full info log which shows where it is failing at 37%.

[blue68f100]

You will be surprised what Spinrite will find. I did that on my 400gig's I installed in my 4500. MFG no longer check the media for bad sectors. They rely on the SMART tech to make the repair on the fly.

A closer detail of the logs may indicate which drive is having the problem.

As far as replacement drives. You can go larger in all positions execpt drive 1. The Snap OS uses drive 1 to base the capacity off of. Then there were several Quantiums that had the same model and size but were actually different.

[cayenne]

From what I have seen, all of the drives are pretty close in size down to the byte level. They are all the same revision so it will be as close as you can get with manufactured drives. They are all 160GB so they are being recongnized as the max allowed without LBA48. I will look into the logs in more detail this evening and see what the results are.

[Lethe]

A 60GB drive doesn't not have to be 100% - there is a tolerance level. It might be 58GB etc.

If you do find a bad drive (which could be bad, or undersize for what it wants), replace it with an 80GB.

*EDIT. Sorry. I didn't see the 160GB drives mentioned - I was looking at cayennes' drive info

Nick

[cayenne]

Here is a bit more detailed information from the log which may provide more insight. Thanks for the assistance, I removed bits of it to make it shorter to post.

01/29/2007 12:56:21 12 D SYS | No FDB, or FDB corrupt. Reverting to shadow FDB
01/29/2007 12:56:21 12 D SYS | Reverting to Default FDB: FDB missing or invalid
01/29/2007 12:56:21 12 D SYS | Reverting to Default FDB: Quotas have been turned Off
01/29/2007 12:56:21 12 I L01 | File System : Successfully initialized empty FDB for device 0x60000
01/29/2007 12:56:21 12 D SYS | Reverting to Default FDB: ACLs will be set to default
01/29/2007 12:56:21 12 I L01 | File System : All ACLs for device 0x60000, reset to defaults
01/29/2007 12:56:21 12 D SYS | Scheduled ACL Set and Propagate at /0 for FDB_ID_0
01/29/2007 12:56:21 12 I L01 | File System : Opened FDB for device 0x60000
01/29/2007 12:56:21 12 D SYS | Scheduled ACL Set and Propagate at /0/os_private for FDB_ID_0
01/29/2007 14:41:35 12 D SYS | RAID5Resync on array 0: 34% done
01/29/2007 14:44:40 12 D SYS | RAID5Resync on array 0: 35% done
01/29/2007 14:47:45 12 D SYS | RAID5Resync on array 0: 36% done
01/29/2007 14:50:49 12 D SYS | RAID5Resync on array 0: 37% done
01/29/2007 14:51:40 12 D SYS | DISK: req=0x3A89300 dev=0xC0002 fn=1 blk=0x6065180 sts=16
01/29/2007 14:51:42 12 D SYS | DISK: req=0x3A89300 dev=0xC0002 fn=1 blk=0x6065180 sts=16
01/29/2007 14:51:42 12 D SYS | DISK: req=0x3A89300 dev=0x80002 fn=1 blk=0x6065180 sts=16
01/29/2007 14:51:42 12 D SYS | RAID5Resync on array 0: read to cache failed (16)
01/29/2007 14:51:42 12 D SYS | RAID5Resync on array 0: failed
01/29/2007 14:51:43 12 E L01 | File System : Failed to resynchronize logical set 60000, error -1

[blue68f100]

Have you reset the 4100 back to factory settings?

I assume you are not getting any disk led on the front panel.

I have dropped a note to Snap-tech, he will know what it is.

Did you keep the previous attemp? Want to see if its the devices are same, dev=0xC0002 & dev=0x80002.

[cayenne]

Originally Posted by blue68f100

Have you reset the 4100 back to factory settings?

I assume you are not getting any disk led on the front panel.

I have dropped a note to Snap-tech, he will know what it is.

Did you keep the previous attemp? Want to see if its the devices are same, dev=0xC0002 & dev=0x80002.

After upgrading the OS, this is the new log. Still the same devices and at the same point in the rebuild.

RAID5Resync on array 0: 37% done
01/29/2007 19:37:53 20 D SYS | DISK: req=0x3A9B2F8 dev=0xC0002 fn=1 blk=0x6065180 sts=16
01/29/2007 19:37:54 20 D SYS | IDE: A 48 bit LBA capable Hard Drive was detected ...
01/29/2007 19:37:54 20 D SYS | IDE: 48 bit LBA is not supported on 4100 and 12000 platforms.
01/29/2007 19:37:54 20 D SYS | IDE: Setting the hard drive size to maximum addressable by 28 bits: 131071 MBytes.
01/29/2007 19:37:56 20 D SYS | DISK: req=0x3A9B2F8 dev=0xC0002 fn=1 blk=0x6065180 sts=16
01/29/2007 19:37:56 20 D SYS | IDE: A 48 bit LBA capable Hard Drive was detected ...
01/29/2007 19:37:56 20 D SYS | IDE: 48 bit LBA is not supported on 4100 and 12000 platforms.
01/29/2007 19:37:56 20 D SYS | IDE: Setting the hard drive size to maximum addressable by 28 bits: 131071 MBytes.
01/29/2007 19:37:56 20 D SYS | DISK: req=0x3A9B2F8 dev=0x80002 fn=1 blk=0x6065180 sts=16
01/29/2007 19:37:56 20 D SYS | RAID5Resync on array 0: read to cache failed (16)
01/29/2007 19:37:57 20 D SYS | RAID5Resync on array 0: failed
01/29/2007 19:37:57 20 E L01 | File System : Failed to resynchronize logical set 60000, error -1

[blue68f100]

Does the mfg have a utility to set the drives max size? If so trying setting to 135gig.

[Hallis]

Stupid question, what OS version is it running? Despite the hardware limitation for LBA 48bit i think an OS upgrade to 3.4.805 wouldnt hurt.

Shane

[cayenne]

Hallis,
I upgrade the OS to 4.0.860 last night. Unfortunately it made no difference. I am running Spinrite today to ensure the drives are okay. I am also going to take blue68f100's advice and use Western Digital's utility to scale the size back to 135 gig and see if it makes a difference

[frankb3910]

Cayenne - I used 160MB Maxtor drives in my upgraded 4100.

As I mentioned, did you consider upgrading the RAM? I believe you will have better luck with the server using these larger drives, if you upgrade the RAM.

I did not have any problem using the larger drives. They format automatically to around 128MB - this is due to limitations in the 4100, you will not be able to use the full 160MB but again, I have done this and it worked, that was not a problem.

I had error messages in my logs very similar to yours.

Snap-tech (one of the power users around here, and former snap technician) was very helpful to me. He was the one that suggested taking the cover off to allow for more cooling while building the RAID.

I would also switch the drives around - or switch the cables, format again, and try to rebuild the raid. Then you could see if the error message indicated a different drive.

I have NEVER seen these messages in my log files, it must be coming from the 4.0 OS, I am still on some version of 3.x

IDE: A 48 bit LBA capable Hard Drive was detected ...
IDE: 48 bit LBA is not supported on 4100 and 12000 platforms.

I still do not think that is of any concern or cause of your problem.

[cayenne]

First of all, I want to thank everyone for their help and the great information that was provided. I was able to get the server up and running last night. After running tests on all of the drives with Spinrite, I found erradic problems on drive 3 / IDE channel 2. It's hard to believe I would have had this trouble with a brand new drive, but things happen. I replaced the drive, rebuilt the array and waited.... So far all is good and no error messages this time. I was able to leave all of the drives at their full capacity and they were recognized as 137 gig drives. I now have somewhere around 385 gigs free as RAID5.

[cayenne]

First of all, I want to thank everyone for their help and the great information that was provided. I was able to get the server up and running last night. After running tests on all of the drives with Spinrite, I found erradic problems on drive 3 / IDE channel 2. It's hard to believe I would have had this trouble with a brand new drive, but things happen. I replaced the drive, rebuilt the array and waited.... So far all is good and no error messages this time. I was able to leave all of the drives at their full capacity and they were recognized as 137 gig drives. I now have somewhere around 385 gigs free as RAID5.

[blue68f100]

Timing on raid 5 drive are criticle.

Did you try re-instatalling the problem drive after SpinRite blocked out the bad sectors?

I did with mine, after Spinrite used up over 1/2 of the spare sectors. So far no more problems. What you were running in to was that the SMART tech was tring to repair /remap sectors on the fly. Which makes it timeout if it has several back to back. All of mine were in 2 different areas.

[cayenne]

Originally Posted by blue68f100

Timing on raid 5 drive are criticle.

Did you try re-instatalling the problem drive after SpinRite blocked out the bad sectors?

I did with mine, after Spinrite used up over 1/2 of the spare sectors. So far no more problems. What you were running in to was that the SMART tech was tring to repair /remap sectors on the fly. Which makes it timeout if it has several back to back. All of mine were in 2 different areas.

I didn't try reinstalling the drive because everytime I reran SpinRite it would find problems in other areas of the drive. It didn't seem to be centered around one area. In my opinion I had spent enough time fighting it, so I just replaced it.

[blue68f100]

You definately got a bad drive if that is going on. Send it back.