ReadyNAS 1100 randomly crashes

[clewis]

I've posted before and gotten no response, but this is an annoying issue that concerns me. The ReadyNAS 1100 has been up for 2 months, working flawlessly, and this morning, it randomly became inaccessible via the network. RAIDar couldn't see it, I couldn't ping it, etc. Turning it off via the power switch on the back and then back on brought it right back up and everything is fine. My question is, why is this happening? It was happening every couple of weeks for a while, and now it's been at least 8 weeks since it happened. I haven't changed anything. I'd like some feedback on what is going on with it. Below is a paste from the system log...it looks to me like everything hit the fan at 06:47:01 today, and then at 12:30 was when I brought it back up. I'm pasting in the entire log from July 17 (so far) which probably contains more info than you need. Please give me some help figuring out what is going on. Thank you!

Jul 16 23:56:20 winshapenas noflushd[1107]: Spinning down disks.
Jul 16 23:56:28 winshapenas noflushd[1107]: Disks spinning up after 0 minutes.
Jul 17 00:19:43 winshapenas noflushd[1107]: Spinning down disks.
Jul 17 00:21:15 winshapenas noflushd[1107]: Disks spinning up after 1 minutes.
Jul 17 00:25:47 winshapenas nss_wins[1173]: Connection from UDP: [10.28.232.235]:62464
Jul 17 00:25:47 winshapenas last message repeated 3 times
Jul 17 00:36:31 winshapenas noflushd[1107]: Spinning down disks.
Jul 17 00:38:13 winshapenas noflushd[1107]: Disks spinning up after 1 minutes.
Jul 17 00:45:20 winshapenas kernel: BUG: scheduling while atomic: nmbd/0x00000100/2373
Jul 17 00:45:20 winshapenas kernel: [80288efc : mutex_lock+0x20/0x34 ] [802546c0 : is_local_netif+0x1c/0x58 ] [80255b8c : arp_process+0x630/0x780 ] [80255dcc : arp_rcv+0xe0/0x168 ] [8021692c : netif_receive_skb+0x1c8/0x290 ] [80216a7c : process_backlog+0x88/0x14c ] [80216bc0 : net_rx_action+0x80/0x13c ] [80032148 : __do_softirq+0xa0/0xc4 ] [800321ac : do_softirq+0x40/0x54 ] [80014948 : real_irq_entry+0x34/0x58 ] [80216e04 : dev_ifconf+0x90/0x140 ] [80217d74 : dev_ioctl+0x2ec/0x300 ] [8020b71c : sock_ioctl+0xf0/0x288 ] [80084390 : do_ioctl+0x58/0x78 ] [80084590 : vfs_ioctl+0x70/0x280 ] [800847cc : sys_ioctl+0x2c/0x58 ]
Jul 17 00:56:37 winshapenas smbd[6033]: PAM pam_putenv: delete non-existent entry; KRB5CCNAME
Jul 17 01:11:00 winshapenas smbd[25942]: PAM pam_putenv: delete non-existent entry; KRB5CCNAME
Jul 17 01:26:51 winshapenas noflushd[1107]: Spinning down disks.
Jul 17 02:05:12 winshapenas noflushd[1107]: Disks spinning up after 38 minutes.
Jul 17 02:20:28 winshapenas noflushd[1107]: Spinning down disks.
Jul 17 04:00:12 winshapenas noflushd[1107]: Disks spinning up after 99 minutes.
Jul 17 04:25:09 winshapenas noflushd[1107]: Spinning down disks.
Jul 17 06:25:05 winshapenas noflushd[1107]: Disks spinning up after 119 minutes.
Jul 17 06:47:01 winshapenas kernel: X_RAID_DUMP
Jul 17 06:47:01 winshapenas kernel:
Jul 17 06:47:01 winshapenas kernel: VERSION/ID : SB=(V:0.1.0) ID=<a2100db9.00000000.00000000.00000000> CT:4790ff15
Jul 17 06:47:01 winshapenas kernel: RAID_INFO : DISKS(TOTAL:4 RAID:4 PARITY:3 ONL:4 WRK:4 FAILED:0 SPARE:0 BASE:0)
Jul 17 06:47:01 winshapenas kernel: SZ:0976752688 UT:00000000 STATE:0 LUNS:2 EXTCMD:1 LSZ:0976752686
Jul 17 06:47:01 winshapenas kernel: LOGICAL_DRIVE : 0: B:0000000002 E:0004096000 R:1 O:1 I:1:000000000 DM:f
Jul 17 06:47:01 winshapenas kernel: LOGICAL_DRIVE : 1: B:0004096002 E:0972656686 R:4 O:1 I:1:000000000 DM:f
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 0: DISK<N:0/1,hdc(22,0),ID:0,PT:1,SZ:0976752688,ST: B:online>
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 1: DISK<N:1/2,hde(33,0),ID:1,PT:1,SZ:0976752688,ST: :online>
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 2: DISK<N:2/3,hdg(34,0),ID:2,PT:1,SZ:0976752688,ST: :online>
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 3: DISK<N:3/4,hdi(56,0),ID:3,PT:1,SZ:0976752688,ST:P :online>
Jul 17 06:47:01 winshapenas kernel: CURRENT_DRIVE : DISK<N:0/1,XXX(22,0),ID:0,PT:1,SZ:0976752688,ST: B:online>
Jul 17 06:47:01 winshapenas kernel:
Jul 17 06:47:01 winshapenas kernel: VERSION/ID : SB=(V:0.1.0) ID=<a2100db9.00000000.00000000.00000000> CT:4790ff15
Jul 17 06:47:01 winshapenas kernel: RAID_INFO : DISKS(TOTAL:4 RAID:4 PARITY:3 ONL:4 WRK:4 FAILED:0 SPARE:0 BASE:0)
Jul 17 06:47:01 winshapenas kernel: SZ:0976752688 UT:00000000 STATE:0 LUNS:2 EXTCMD:1 LSZ:0976752686
Jul 17 06:47:01 winshapenas kernel: LOGICAL_DRIVE : 0: B:0000000002 E:0004096000 R:1 O:1 I:1:000000000 DM:f
Jul 17 06:47:01 winshapenas kernel: LOGICAL_DRIVE : 1: B:0004096002 E:0972656686 R:4 O:1 I:1:000000000 DM:f
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 0: DISK<N:0/1,hdc(22,0),ID:0,PT:1,SZ:0976752688,ST: B:online>
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 1: DISK<N:1/2,hde(33,0),ID:1,PT:1,SZ:0976752688,ST: :online>
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 2: DISK<N:2/3,hdg(34,0),ID:2,PT:1,SZ:0976752688,ST: :online>
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 3: DISK<N:3/4,hdi(56,0),ID:3,PT:1,SZ:0976752688,ST:P :online>
Jul 17 06:47:01 winshapenas kernel: CURRENT_DRIVE : DISK<N:1/2,XXX(33,0),ID:1,PT:1,SZ:0976752688,ST: :online>
Jul 17 06:47:01 winshapenas kernel:
Jul 17 06:47:01 winshapenas kernel: VERSION/ID : SB=(V:0.1.0) ID=<a2100db9.00000000.00000000.00000000> CT:4790ff15
Jul 17 06:47:01 winshapenas kernel: RAID_INFO : DISKS(TOTAL:4 RAID:4 PARITY:3 ONL:4 WRK:4 FAILED:0 SPARE:0 BASE:0)
Jul 17 06:47:01 winshapenas kernel: SZ:0976752688 UT:00000000 STATE:0 LUNS:2 EXTCMD:1 LSZ:0976752686
Jul 17 06:47:01 winshapenas kernel: LOGICAL_DRIVE : 0: B:0000000002 E:0004096000 R:1 O:1 I:1:000000000 DM:f
Jul 17 06:47:01 winshapenas kernel: LOGICAL_DRIVE : 1: B:0004096002 E:0972656686 R:4 O:1 I:1:000000000 DM:f
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 0: DISK<N:0/1,hdc(22,0),ID:0,PT:1,SZ:0976752688,ST: B:online>
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 1: DISK<N:1/2,hde(33,0),ID:1,PT:1,SZ:0976752688,ST: :online>
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 2: DISK<N:2/3,hdg(34,0),ID:2,PT:1,SZ:0976752688,ST: :online>
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 3: DISK<N:3/4,hdi(56,0),ID:3,PT:1,SZ:0976752688,ST:P :online>
Jul 17 06:47:01 winshapenas kernel: CURRENT_DRIVE : DISK<N:2/3,XXX(34,0),ID:2,PT:1,SZ:0976752688,ST: :online>
Jul 17 06:47:01 winshapenas kernel:
Jul 17 06:47:01 winshapenas kernel: VERSION/ID : SB=(V:0.1.0) ID=<a2100db9.00000000.00000000.00000000> CT:4790ff15
Jul 17 06:47:01 winshapenas kernel: RAID_INFO : DISKS(TOTAL:4 RAID:4 PARITY:3 ONL:4 WRK:4 FAILED:0 SPARE:0 BASE:0)
Jul 17 06:47:01 winshapenas kernel: SZ:0976752688 UT:00000000 STATE:0 LUNS:2 EXTCMD:1 LSZ:0976752686
Jul 17 06:47:01 winshapenas kernel: LOGICAL_DRIVE : 0: B:0000000002 E:0004096000 R:1 O:1 I:1:000000000 DM:f
Jul 17 06:47:01 winshapenas kernel: LOGICAL_DRIVE : 1: B:0004096002 E:0972656686 R:4 O:1 I:1:000000000 DM:f
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 0: DISK<N:0/1,hdc(22,0),ID:0,PT:1,SZ:0976752688,ST: B:online>
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 1: DISK<N:1/2,hde(33,0),ID:1,PT:1,SZ:0976752688,ST: :online>
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 2: DISK<N:2/3,hdg(34,0),ID:2,PT:1,SZ:0976752688,ST: :online>
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 3: DISK<N:3/4,hdi(56,0),ID:3,PT:1,SZ:0976752688,ST:P :online>
Jul 17 06:47:01 winshapenas kernel: CURRENT_DRIVE : DISK<N:3/4,XXX(56,0),ID:3,PT:1,SZ:0976752688,ST:P :online>
Jul 17 06:47:01 winshapenas kernel:
Jul 17 06:47:01 winshapenas kernel: VERSION/ID : SB=(V:0.1.0) ID=<a2100db9.00000000.00000000.00000000> CT:4790ff15
Jul 17 06:47:01 winshapenas kernel: RAID_INFO : DISKS(TOTAL:4 RAID:4 PARITY:3 ONL:4 WRK:4 FAILED:0 SPARE:0 BASE:0)
Jul 17 06:47:01 winshapenas kernel: SZ:0976752688 UT:00000000 STATE:0 LUNS:2 EXTCMD:1 LSZ:0976752686
Jul 17 06:47:01 winshapenas kernel: LOGICAL_DRIVE : 0: B:0000000002 E:0004096000 R:1 O:1 I:1:000000000 DM:f
Jul 17 06:47:01 winshapenas kernel: LOGICAL_DRIVE : 1: B:0004096002 E:0972656686 R:4 O:1 I:1:000000000 DM:f
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 0: DISK<N:0/1,hdc(22,0),ID:0,PT:1,SZ:0976752688,ST: B:online>
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 1: DISK<N:1/2,hde(33,0),ID:1,PT:1,SZ:0976752688,ST: :online>
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 2: DISK<N:2/3,hdg(34,0),ID:2,PT:1,SZ:0976752688,ST: :online>
Jul 17 06:47:01 winshapenas kernel: PHYSICAL_DRIVE: 3: DISK<N:3/4,hdi(56,0),ID:3,PT:1,SZ:0976752688,ST:P :online>
Jul 17 06:47:01 winshapenas kernel: CURRENT_DRIVE : DISK<N:0/1,XXX(22,0),ID:0,PT:1,SZ:0976752688,ST: B:online>
Jul 17 06:47:01 winshapenas kernel:
Jul 17 06:47:01 winshapenas kernel: RUN_PARAMETERS: raid_running=1,last_word=ok,interface_start_at=1,fake=0
Jul 17 06:47:01 winshapenas kernel: RAID_REBUILD : sync=0,logical=0,parity=3,sectors/TOTAL=0/4294967295
Jul 17 06:47:01 winshapenas kernel: : source=f, total_drives=4, auto_sync=1
Jul 17 06:47:01 winshapenas kernel: RAID_P_CHECK : chck=0,logical/total=0/2,raid_level=0
Jul 17 06:47:01 winshapenas kernel: : err/sectors/TOTAL=0/0/0,report_err=1
Jul 17 06:47:01 winshapenas kernel: : initialized=0xf,initialize_error=0x0,initializing=0x0
Jul 17 06:47:01 winshapenas kernel: : where=0,total=0
Jul 17 06:47:01 winshapenas kernel: SIZE_INFOR : sb_size=9440,sections_size=32/256,disk_t_size=128
Jul 17 06:47:01 winshapenas kernel: : sb=f8134294,disks=512/1536,luns=2048/3168,thisdisk=5216/128,diskid=5344/4096
Jul 17 06:47:01 winshapenas kernel: DJO_RECORD : dj_raid=NO_RAID,chns=0,source=0,disks=0 parity=0,chn_image=f,
Jul 17 06:47:01 winshapenas kernel: : sectors=2760266/0x2a1e4a,need_IO=0
Jul 17 06:47:01 winshapenas kernel: IO__RECORD : 0=2378863264,1=3399262594,2=573645619,3=1040, busy=0/0/0/0/0,t_d=f
Jul 17 06:47:01 winshapenas kernel: sd 4:0:0:0: SCSI error: return code = 0x8000002
Jul 17 06:47:01 winshapenas kernel: sda: Current: sense key=0xb
Jul 17 06:47:01 winshapenas kernel: ASC=0x0 ASCQ=0x0
Jul 17 06:47:01 winshapenas kernel: Buffer I/O error on device sda, logical block 1953546336 (at)
Jul 17 06:47:01 winshapenas kernel: sd 4:0:0:0: SCSI error: return code = 0x8000002
Jul 17 06:47:01 winshapenas kernel: sda: Current: sense key=0xb
Jul 17 06:47:01 winshapenas kernel: ASC=0x0 ASCQ=0x0
Jul 17 06:47:01 winshapenas kernel: Buffer I/O error on device sda, logical block 1953546336 (ksoftirqd/0)
Jul 17 12:30:04 winshapenas syslogd 1.4.1#10: restart.
Jul 17 12:30:04 winshapenas kernel: klogd 1.4.1#10, log source = /proc/kmsg started.
Jul 17 12:30:04 winshapenas kernel: Linux version 2.6.17.14ReadyNAS (root@calzone) (gcc version 3.3.5 (Infrant 3.3.5-1)) #1 Wed Sep 22 04:42:09 PDT 2010
Jul 17 12:30:04 winshapenas kernel: You system is PADRE.
Jul 17 12:30:04 winshapenas kernel: ASIC=IT1004
Jul 17 12:30:04 winshapenas kernel: On node 0 totalpages: 32768
Jul 17 12:30:04 winshapenas kernel: Normal zone: 31744 pages, LIFO batch:7
Jul 17 12:30:04 winshapenas kernel: DMA zone: 1024 pages, LIFO batch:0
Jul 17 12:30:04 winshapenas kernel: zlist 0 802ef15c
Jul 17 12:30:04 winshapenas kernel: zone 802eef14, name Normal
Jul 17 12:30:04 winshapenas kernel: zlist 1 802ef170
Jul 17 12:30:04 winshapenas kernel: zone 802eeccc, name DMA
Jul 17 12:30:04 winshapenas kernel: zlist 2 802ef184
Jul 17 12:30:04 winshapenas kernel: zone 802eef14, name Normal
Jul 17 12:30:04 winshapenas kernel: Built 1 zonelists
Jul 17 12:30:04 winshapenas kernel: Kernel command line: root=/dev/ram0 init=/linuxrc rw raid=noautodetect profile=2
Jul 17 12:30:04 winshapenas kernel: kernel profiling enabled (shift: 2)
Jul 17 12:30:04 winshapenas kernel: PID hash table entries: 4096 (order: 12, 16384 bytes)
Jul 17 12:30:04 winshapenas kernel: Dentry cache hash table entries: 65536 (order: 4, 262144 bytes)
Jul 17 12:30:04 winshapenas kernel: Inode-cache hash table entries: 32768 (order: 3, 131072 bytes)
Jul 17 12:30:04 winshapenas kernel: Memory: 487296k/524288k available (2592k kernel code, 36592k reserved, 656k data, 96k init, 0k highmem)
Jul 17 12:30:04 winshapenas kernel: init_mm.pgd 9f0ff000
Jul 17 12:30:04 winshapenas kernel: Calibrating delay loop... 177.35 BogoMIPS (lpj=886784)
Jul 17 12:30:04 winshapenas kernel: Mount-cache hash table entries: 2048
Jul 17 12:30:04 winshapenas kernel: checking if image is initramfs...it isn't (no cpio magic); looks like an initrd
Jul 17 12:30:04 winshapenas kernel: Freeing initrd memory: 16384k freed
Jul 17 12:30:04 winshapenas kernel: NET: Registered protocol family 16
Jul 17 12:30:04 winshapenas kernel: usbcore: registered new driver usbfs
Jul 17 12:30:04 winshapenas kernel: usbcore: registered new driver hub
Jul 17 12:30:04 winshapenas kernel: NET: Registered protocol family 2
Jul 17 12:30:04 winshapenas kernel: IP route cache hash table entries: 4096 (order: 0, 16384 bytes)
Jul 17 12:30:04 winshapenas kernel: TCP established hash table entries: 16384 (order: 2, 65536 bytes)
Jul 17 12:30:04 winshapenas kernel: TCP bind hash table entries: 8192 (order: 1, 32768 bytes)
Jul 17 12:30:04 winshapenas kernel: TCP: Hash tables configured (established 16384 bind 8192)
Jul 17 12:30:04 winshapenas kernel: TCP reno registered
Jul 17 12:30:04 winshapenas kernel: audit: initializing netlink socket (disabled)
Jul 17 12:30:04 winshapenas kernel: audit(1070280003.230:1): initialized
Jul 17 12:30:04 winshapenas kernel: VFS: Disk quotas dquot_6.5.1
Jul 17 12:30:04 winshapenas kernel: Dquot-cache hash table entries: 4096 (order 0, 16384 bytes)
Jul 17 12:30:04 winshapenas kernel: Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
Jul 17 12:30:04 winshapenas kernel: Initializing Cryptographic API
Jul 17 12:30:04 winshapenas kernel: io scheduler noop registered
Jul 17 12:30:04 winshapenas kernel: io scheduler anticipatory registered
Jul 17 12:30:04 winshapenas kernel: io scheduler deadline registered
Jul 17 12:30:04 winshapenas kernel: io scheduler cfq registered (default)
Jul 17 12:30:04 winshapenas kernel: RAMDISK driver initialized: 16 RAM disks of 16384K size 1024 blocksize
Jul 17 12:30:04 winshapenas kernel: loop: loaded (max 8 devices)
Jul 17 12:30:04 winshapenas kernel: nbd: registered device at major 43
Jul 17 12:30:04 winshapenas kernel: tun: Universal TUN/TAP device driver, 1.6
Jul 17 12:30:04 winshapenas kernel: tun: (C) 1999-2004 Max Krasnyansky <maxk@qualcomm.com>
Jul 17 12:30:04 winshapenas kernel: md: raid0 personality registered for level 0
Jul 17 12:30:04 winshapenas kernel: md: raid1 personality registered for level 1
Jul 17 12:30:04 winshapenas kernel: md: raid5 personality registered for level 5
Jul 17 12:30:04 winshapenas kernel: md: raid4 personality registered for level 4
Jul 17 12:30:04 winshapenas kernel: xor engine => SPARC.
Jul 17 12:30:04 winshapenas kernel: device-mapper: 4.6.0-ioctl (2006-02-17) initialised: dm-devel@redhat.com
Jul 17 12:30:04 winshapenas kernel: Serial: Padre driver $Revision: 1.1.1.1 $ 2 ports
Jul 17 12:30:04 winshapenas kernel: ttyS0 at I/O 0x0 (irq = 7) is a padre uart
Jul 17 12:30:04 winshapenas kernel: ttyS1 at I/O 0x0 (irq = 😎 is a padre uart
Jul 17 12:30:04 winshapenas kernel: oprofile: using timer interrupt.
Jul 17 12:30:04 winshapenas kernel: TCP bic registered
Jul 17 12:30:04 winshapenas kernel: NET: Registered protocol family 1
Jul 17 12:30:04 winshapenas kernel: NET: Registered protocol family 17
Jul 17 12:30:04 winshapenas kernel: NET: Registered protocol family 5
Jul 17 12:30:04 winshapenas kernel: 802.1Q VLAN Support v1.8 Ben Greear <greearb@candelatech.com>
Jul 17 12:30:04 winshapenas kernel: All bugs added by David S. Miller <davem@redhat.com>
Jul 17 12:30:04 winshapenas kernel: md: Skipping autodetection of RAID arrays. (raid=noautodetect)
Jul 17 12:30:04 winshapenas kernel: RAMDISK: Compressed image found at block 0
Jul 17 12:30:04 winshapenas kernel: VFS: Mounted root (ext2 filesystem).
Jul 17 12:30:04 winshapenas kernel: Freeing unused kernel memory: 96k freed
Jul 17 12:30:04 winshapenas kernel: padre_i2c: module license 'Infrant Technologies, Inc.' taints kernel.
Jul 17 12:30:04 winshapenas kernel: padre_i2c: no version for "udiv" found: kernel tainted.
Jul 17 12:30:04 winshapenas kernel: TWSI Initialize
Jul 17 12:30:04 winshapenas kernel: Loading PASEO LED/BUTTON driver
Jul 17 12:30:04 winshapenas kernel: Padre NSPIO setup: 80353394... No argv, go to default.
Jul 17 12:30:04 winshapenas kernel: raid5: xor select to PADRE_RXA.
Jul 17 12:30:04 winshapenas kernel: Uniform Multi-Platform E-IDE driver Revision: 7.00alpha2
Jul 17 12:30:04 winshapenas kernel: ide: Assuming 33MHz system bus speed for PIO modes; override with idebus=xx
Jul 17 12:30:04 winshapenas kernel: padre chip scan,token=1
Jul 17 12:30:04 winshapenas kernel: Scan the padre NSP IO hardware.
Jul 17 12:30:04 winshapenas kernel: Need memory for RTEngine 63680
Jul 17 12:30:04 winshapenas kernel: PIO mode on chan 7
Jul 17 12:30:04 winshapenas kernel: DMA mode on chan 0
Jul 17 12:30:04 winshapenas kernel: DMA mode on chan 1
Jul 17 12:30:04 winshapenas kernel: DMA mode on chan 2
Jul 17 12:30:04 winshapenas kernel: DMA mode on chan 3
Jul 17 12:30:04 winshapenas kernel: Padre IDE controller, sata start:1
Jul 17 12:30:04 winshapenas kernel: No TLER on ST3500630NS ^P\200
Jul 17 12:30:04 winshapenas kernel: hdc: ST3500630NS (s/n:9QG4QHHJ), ATA DISK drive (ATAEXT)
Jul 17 12:30:04 winshapenas kernel: No TLER on ST3500630NS ^P\200
Jul 17 12:30:04 winshapenas kernel: hde: ST3500630NS (s/n:9QG4TLN5), ATA DISK drive (ATAEXT)
Jul 17 12:30:04 winshapenas kernel: No TLER on ST3500630NS ^P\200
Jul 17 12:30:04 winshapenas kernel: hdg: ST3500630NS (s/n:9QG4TLSB), ATA DISK drive (ATAEXT)
Jul 17 12:30:04 winshapenas kernel: No TLER on ST3500630NS ^P\200
Jul 17 12:30:04 winshapenas kernel: hdi: ST3500630NS (s/n:9QG1VK3Q), ATA DISK drive (ATAEXT)
Jul 17 12:30:04 winshapenas kernel: ide1 at 0x200-0x207,0x208 on irq 32
Jul 17 12:30:04 winshapenas kernel: ide2 at 0x280-0x287,0x288 on irq 33
Jul 17 12:30:04 winshapenas kernel: ide3 at 0x300-0x307,0x308 on irq 34
Jul 17 12:30:04 winshapenas kernel: ide4 at 0x380-0x387,0x388 on irq 35
Jul 17 12:30:04 winshapenas kernel: Update NSPIO settings 80353394.
Jul 17 12:30:04 winshapenas kernel: hdc: max request size: 512KiB
Jul 17 12:30:04 winshapenas kernel: hdc: use capacity 976773168 sectors (500107 MB)
Jul 17 12:30:04 winshapenas kernel: Drive support hpa, still should not change max addr.
Jul 17 12:30:04 winshapenas kernel: hdc: 976752688 sectors (500097 MB) w/16384KiB Cache, CHS=60800/255/63
Jul 17 12:30:04 winshapenas kernel: hdc: cache flushes supported
Jul 17 12:30:04 winshapenas kernel: hdc: hdc1 hdc2 hdc3 < hdc5 >
Jul 17 12:30:04 winshapenas kernel: hde: max request size: 512KiB
Jul 17 12:30:04 winshapenas kernel: hde: use capacity 976773168 sectors (500107 MB)
Jul 17 12:30:04 winshapenas kernel: Drive support hpa, still should not change max addr.
Jul 17 12:30:04 winshapenas kernel: hde: 976752688 sectors (500097 MB) w/16384KiB Cache, CHS=60800/255/63
Jul 17 12:30:04 winshapenas kernel: hde: cache flushes supported
Jul 17 12:30:04 winshapenas kernel: hde: hde1 hde2 hde3 < hde5 >
Jul 17 12:30:04 winshapenas kernel: hdg: max request size: 512KiB
Jul 17 12:30:04 winshapenas kernel: hdg: use capacity 976773168 sectors (500107 MB)
Jul 17 12:30:04 winshapenas kernel: Drive support hpa, still should not change max addr.
Jul 17 12:30:04 winshapenas kernel: hdg: 976752688 sectors (500097 MB) w/16384KiB Cache, CHS=60800/255/63
Jul 17 12:30:04 winshapenas kernel: hdg: cache flushes supported
Jul 17 12:30:04 winshapenas kernel: hdg: hdg1 hdg2 hdg3 < hdg5 >
Jul 17 12:30:04 winshapenas kernel: hdi: max request size: 512KiB
Jul 17 12:30:04 winshapenas kernel: hdi: use capacity 976773168 sectors (500107 MB)
Jul 17 12:30:04 winshapenas kernel: Drive support hpa, still should not change max addr.
Jul 17 12:30:04 winshapenas kernel: hdi: 976752688 sectors (500097 MB) w/16384KiB Cache, CHS=60800/255/63
Jul 17 12:30:04 winshapenas kernel: hdi: cache flushes supported
Jul 17 12:30:04 winshapenas kernel: hdi: unknown partition table
Jul 17 12:30:04 winshapenas kernel: Link to padre IO.
Jul 17 12:30:04 winshapenas kernel:
Jul 17 12:30:04 winshapenas kernel: RAID disks check:
Jul 17 12:30:04 winshapenas kernel: ALL = 22/33/34/56/0/0/0/0, 4
Jul 17 12:30:04 winshapenas kernel: IDE = 22/33/34/0/0/0/0/0, 3
Jul 17 12:30:04 winshapenas kernel: MD = 0/0/0/0/0/0/0/0, 0
Jul 17 12:30:04 winshapenas kernel: RAID rule check result: 0
Jul 17 12:30:04 winshapenas kernel: md: md driver 0.90.3 MAX_MD_DEVS=256, MD_SB_DISKS=27
Jul 17 12:30:04 winshapenas kernel: md: bitmap version 4.39
Jul 17 12:30:04 winshapenas kernel: Disk protected mark = 1
Jul 17 12:30:04 winshapenas kernel: x_raid_start: 1,current:0
Jul 17 12:30:04 winshapenas kernel: BDL_count= 0, fw=SN04, model=
Jul 17 12:30:04 winshapenas kernel: BDL_count= 1, fw=SN04, model=
Jul 17 12:30:04 winshapenas kernel: GOT MEMORY FOR DJ: 128*4k
Jul 17 12:30:04 winshapenas kernel: Drive hdc SB at 976759632(-sbs) CURRENT
Jul 17 12:30:04 winshapenas kernel: Drive hde SB at 976759632(-sbs) CURRENT
Jul 17 12:30:04 winshapenas kernel: Drive hdg SB at 976759632(-sbs) CURRENT
Jul 17 12:30:04 winshapenas kernel: Drive hdi SB at 976759632(-sbs) CURRENT
Jul 17 12:30:04 winshapenas kernel: x_raid_start: 1,result:0
Jul 17 12:30:04 winshapenas kernel: Find PHY: 0
Jul 17 12:30:04 winshapenas kernel: Lookup PHY ID: 0x000f, 0x01
Jul 17 12:30:04 winshapenas kernel: Boot type/reason: skip_fsck/0/000da2100db9
Jul 17 12:30:04 winshapenas kernel: This is not P0, no NAND support, bail out.
Jul 17 12:30:04 winshapenas kernel: NEON flash: probing 8-bit flash bus
Jul 17 12:30:04 winshapenas kernel: CFI: Found no NEON flash device at location zero
Jul 17 12:30:04 winshapenas kernel: NEON flash: no partition info available, registering whole flash at once
Jul 17 12:30:04 winshapenas kernel: Found boot device at func=0 port=1
Jul 17 12:30:04 winshapenas kernel: miniuhci: idVendor=0c09 idProduct=0010, bcdDevice=0011
Jul 17 12:30:04 winshapenas kernel: miniuhci: ENDPOINT IN=81 OUT=02
Jul 17 12:30:04 winshapenas kernel: miniuhci: vendor=UNIGEN CORP
Jul 17 12:30:04 winshapenas kernel: miniuhci: model=UFD
Jul 17 12:30:04 winshapenas kernel: miniuhci: serial=AA04012700007545
Jul 17 12:30:04 winshapenas kernel: miniuhci: driver loaded
Jul 17 12:30:04 winshapenas kernel: I2C device 1f doesn't exist
Jul 17 12:30:04 winshapenas kernel: I2C device 1b doesn't exist
Jul 17 12:30:04 winshapenas kernel: LCD device not found
Jul 17 12:30:04 winshapenas kernel: X_RAID_START
Jul 17 12:30:04 winshapenas kernel: startstop XRAID command = start, flash_cache=0
Jul 17 12:30:04 winshapenas kernel: X_RAID clean shutdown indicator: 0xf.
Jul 17 12:30:04 winshapenas kernel: 0 4 4 4 4 0 0 0
Jul 17 12:30:04 winshapenas kernel: 0 1 1 1
Jul 17 12:30:04 winshapenas kernel: 1 0 1 1
Jul 17 12:30:04 winshapenas kernel: 1 1 0 1
Jul 17 12:30:04 winshapenas kernel: 1 1 1 0
Jul 17 12:30:04 winshapenas kernel: Update time for sb 1 = 4790ff15.
Jul 17 12:30:04 winshapenas kernel: Update time for sb 2 = 4790ff15.
Jul 17 12:30:04 winshapenas kernel: Update time for sb 3 = 4790ff15.
Jul 17 12:30:04 winshapenas kernel: Update time for sb 4 = 4790ff15.
Jul 17 12:30:04 winshapenas kernel: recent_ID = 1, select_ID=1, most_ID=4 right_mac=4
Jul 17 12:30:04 winshapenas kernel: Selected sb 1, ctime=4790ff15, id=a2100db9.
Jul 17 12:30:04 winshapenas kernel: Use this image: 1
Jul 17 12:30:04 winshapenas kernel:
Jul 17 12:30:04 winshapenas kernel: VERSION/ID : SB=(V:0.1.0) ID=<a2100db9.00000000.00000000.00000000> CT:4790ff15
Jul 17 12:30:04 winshapenas kernel: RAID_INFO : DISKS(TOTAL:4 RAID:4 PARITY:3 ONL:4 WRK:4 FAILED:0 SPARE:0 BASE:0)
Jul 17 12:30:04 winshapenas kernel: SZ:0976752688 UT:00000000 STATE:0 LUNS:2 EXTCMD:1 LSZ:0976752686
Jul 17 12:30:04 winshapenas kernel: LOGICAL_DRIVE : 0: B:0000000002 E:0004096000 R:1 O:1 I:1:000000000 DM:f
Jul 17 12:30:04 winshapenas kernel: LOGICAL_DRIVE : 1: B:0004096002 E:0972656686 R:4 O:1 I:1:000000000 DM:f
Jul 17 12:30:04 winshapenas kernel: PHYSICAL_DRIVE: 0: DISK<N:0/1,hdc(22,0),ID:0,PT:1,SZ:0976752688,ST: B:online>
Jul 17 12:30:04 winshapenas kernel: PHYSICAL_DRIVE: 1: DISK<N:1/2,hde(33,0),ID:1,PT:1,SZ:0976752688,ST: :online>
Jul 17 12:30:04 winshapenas kernel: PHYSICAL_DRIVE: 2: DISK<N:2/3,hdg(34,0),ID:2,PT:1,SZ:0976752688,ST: :online>
Jul 17 12:30:04 winshapenas kernel: PHYSICAL_DRIVE: 3: DISK<N:3/4,hdi(56,0),ID:3,PT:1,SZ:0976752688,ST:P :online>
Jul 17 12:30:04 winshapenas kernel: CURRENT_DRIVE : DISK<N:0/1,XXX(22,0),ID:0,PT:1,SZ:0976752688,ST: B:online>
Jul 17 12:30:04 winshapenas kernel: Need to do drives searching.
Jul 17 12:30:04 winshapenas kernel: Find p d at 3, chn 3
Jul 17 12:30:04 winshapenas kernel: Total=4; raid=4; ready=0; work=4; failed=0
Jul 17 12:30:04 winshapenas kernel: Check degraded mode, start_pos=1
Jul 17 12:30:04 winshapenas kernel: No drive missing, X_RAID run in opt mode.
Jul 17 12:30:04 winshapenas kernel: Change X_RAID running mode from 0 to 1
Jul 17 12:30:04 winshapenas kernel: Update backup SB.
Jul 17 12:30:04 winshapenas kernel: X_RAID: recovery thread got woken up ...
Jul 17 12:30:04 winshapenas kernel: New = 3, source drives = f, current/active=4/4
Jul 17 12:30:04 winshapenas kernel: hdc: hdc1 hdc2 hdc3 < hdc5 >
Jul 17 12:30:04 winshapenas kernel: hde: hde1 hde2 hde3 < hde5 >
Jul 17 12:30:04 winshapenas kernel: hdg: hdg1 hdg2 hdg3 < hdg5 >
Jul 17 12:30:04 winshapenas kernel: hdi: unknown partition table
Jul 17 12:30:04 winshapenas kernel: kjournald starting. Commit interval 5 seconds
Jul 17 12:30:04 winshapenas kernel: EXT3-fs warning: mounting unchecked fs, running e2fsck is recommended
Jul 17 12:30:04 winshapenas kernel: EXT3 FS on hdc1, internal journal
Jul 17 12:30:04 winshapenas kernel: EXT3-fs: mounted filesystem with ordered data mode.
Jul 17 12:30:04 winshapenas kernel: linked, 1000mbps mode
Jul 17 12:30:04 winshapenas kernel: EXT2-fs warning (device hdc1): ext2_fill_super: mounting ext3 filesystem as ext2
Jul 17 12:30:04 winshapenas kernel: miniuhci: driver removed
Jul 17 12:30:04 winshapenas kernel: Adding 255968k swap on /dev/hdc2. Priority:0 extents:1 across:255968k
Jul 17 12:30:04 winshapenas kernel: Adding 255968k swap on /dev/hde2. Priority:0 extents:1 across:255968k
Jul 17 12:30:04 winshapenas kernel: Adding 255968k swap on /dev/hdg2. Priority:0 extents:1 across:255968k
Jul 17 12:30:04 winshapenas kernel: enable_irq(20) unbalanced from f80285c0
Jul 17 12:30:04 winshapenas kernel: hdc: cache flushes supported
Jul 17 12:30:04 winshapenas kernel: hde: cache flushes supported
Jul 17 12:30:04 winshapenas kernel: hdg: cache flushes supported
Jul 17 12:30:04 winshapenas kernel: hdi: cache flushes supported
Jul 17 12:30:04 winshapenas kernel: hdi: unknown partition table
Jul 17 12:30:04 winshapenas kernel: EXT2-fs warning (device dm-0): ext2_fill_super: mounting ext3 filesystem as ext2
Jul 17 12:30:04 winshapenas kernel: EXT2-fs warning: mounting unchecked fs, running e2fsck is recommended
Jul 17 12:30:04 winshapenas kernel: X_RAID_SYNC_FORCE
Jul 17 12:30:04 winshapenas kernel: X_RAID: recovery thread got woken up ...
Jul 17 12:30:04 winshapenas kernel: New = 3, source drives = f, current/active=4/4
Jul 17 12:30:04 winshapenas kernel: Prepare sync raid 1, source_image=f, sync=4, ready=3
Jul 17 12:30:04 winshapenas kernel: Start sync:0, source_image=1/3, between 2 to 4096002
Jul 17 12:30:04 winshapenas kernel: sata_hotplug: /sbin/hotplug xraid_sync_started hdiUser mode helper start.
Jul 17 12:30:04 winshapenas kernel: done do_sata_hotplug
Jul 17 12:30:04 winshapenas kernel: hdc: cache flushes supported
Jul 17 12:30:04 winshapenas kernel: hde: cache flushes supported
Jul 17 12:30:04 winshapenas kernel: hdg: cache flushes supported
Jul 17 12:30:04 winshapenas kernel: hdi: cache flushes supported
Jul 17 12:30:05 winshapenas avahi-daemon[1293]: Found user 'admin' (UID 98) and group 'admin' (GID 98).
Jul 17 12:30:05 winshapenas avahi-daemon[1293]: Successfully dropped root privileges.
Jul 17 12:30:05 winshapenas avahi-daemon[1293]: avahi-daemon 0.6.15 starting up.
Jul 17 12:30:05 winshapenas avahi-daemon[1293]: Loading service file /etc/avahi/services/readynas.service.
Jul 17 12:30:06 winshapenas avahi-daemon[1293]: Loading service file /etc/avahi/services/timemachine.service.
Jul 17 12:30:06 winshapenas avahi-daemon[1293]: New relevant interface eth0.IPv4 for mDNS.
Jul 17 12:30:06 winshapenas avahi-daemon[1293]: Joining mDNS multicast group on interface eth0.IPv4 with address 10.28.1.13.
Jul 17 12:30:06 winshapenas avahi-daemon[1293]: Network interface enumeration completed.
Jul 17 12:30:06 winshapenas avahi-daemon[1293]: Registering new address record for 10.28.1.13 on eth0.
Jul 17 12:30:06 winshapenas avahi-daemon[1293]: Registering HINFO record with values 'PADRE'/'LINUX'.
Jul 17 12:30:07 winshapenas avahi-daemon[1293]: Server startup complete. Host name is winshapenas.local. Local service cookie is 1004816628.
Jul 17 12:30:07 winshapenas avahi-daemon[1293]: Service "winshapenas" (/etc/avahi/services/timemachine.service) successfully established.
Jul 17 12:30:07 winshapenas avahi-daemon[1293]: Service "ReadyNAS Discovery [winshapenas]" (/etc/avahi/services/readynas.service) successfully established.
Jul 17 12:30:11 winshapenas snmpd[1331]: cache has existing timer id.
Jul 17 12:30:14 winshapenas snmpd[1331]: Turning on AgentX master support.
Jul 17 12:30:22 winshapenas nss_wins[1331]: NET-SNMP version 5.2.3
Jul 17 12:30:23 winshapenas RAIDiator: RAID sync started on volume C.\n\n[Sun Jul 17 12:30:02 EDT 2011]
Jul 17 12:30:54 winshapenas avahi-daemon[1293]: Interface eth0.IPv4 no longer relevant for mDNS.
Jul 17 12:30:54 winshapenas avahi-daemon[1293]: Leaving mDNS multicast group on interface eth0.IPv4 with address 10.28.1.13.
Jul 17 12:30:54 winshapenas avahi-daemon[1293]: Withdrawing address record for 10.28.1.13 on eth0.
Jul 17 12:30:54 winshapenas kernel: GMAC: 37640300; GMT: 00000002; DMA RX: 0000c009; DMA TX: 00008009
Jul 17 12:30:59 winshapenas avahi-daemon[1293]: New relevant interface eth0.IPv4 for mDNS.
Jul 17 12:30:59 winshapenas avahi-daemon[1293]: Joining mDNS multicast group on interface eth0.IPv4 with address 10.28.1.13.
Jul 17 12:30:59 winshapenas avahi-daemon[1293]: Registering new address record for 10.28.1.13 on eth0.
Jul 17 12:30:59 winshapenas kernel: linked, 1000mbps mode
Jul 17 12:31:00 winshapenas avahi-daemon[1293]: Withdrawing address record for 10.28.1.13 on eth0.
Jul 17 12:31:00 winshapenas avahi-daemon[1293]: Leaving mDNS multicast group on interface eth0.IPv4 with address 10.28.1.13.
Jul 17 12:31:00 winshapenas avahi-daemon[1293]: iface.c: interface_mdns_mcast_join() called but no local address available.
Jul 17 12:31:00 winshapenas avahi-daemon[1293]: Interface eth0.IPv4 no longer relevant for mDNS.
Jul 17 12:31:00 winshapenas avahi-daemon[1293]: New relevant interface eth0.IPv4 for mDNS.
Jul 17 12:31:00 winshapenas avahi-daemon[1293]: Joining mDNS multicast group on interface eth0.IPv4 with address 10.28.1.13.
Jul 17 12:31:00 winshapenas avahi-daemon[1293]: Registering new address record for 10.28.1.13 on eth0.
Jul 17 12:31:00 winshapenas avahi-daemon[1293]: Withdrawing address record for 10.28.1.13 on eth0.
Jul 17 12:31:00 winshapenas avahi-daemon[1293]: Leaving mDNS multicast group on interface eth0.IPv4 with address 10.28.1.13.
Jul 17 12:31:00 winshapenas avahi-daemon[1293]: iface.c: interface_mdns_mcast_join() called but no local address available.
Jul 17 12:31:00 winshapenas avahi-daemon[1293]: Interface eth0.IPv4 no longer relevant for mDNS.
Jul 17 12:31:00 winshapenas avahi-daemon[1293]: New relevant interface eth0.IPv4 for mDNS.
Jul 17 12:31:00 winshapenas avahi-daemon[1293]: Joining mDNS multicast group on interface eth0.IPv4 with address 10.28.1.13.
Jul 17 12:31:00 winshapenas avahi-daemon[1293]: Registering new address record for 10.28.1.13 on eth0.
Jul 17 12:31:05 winshapenas kernel: linked, 1000mbps mode
Jul 17 12:31:05 winshapenas avahi-daemon[1293]: New relevant interface eth1.IPv4 for mDNS.
Jul 17 12:31:05 winshapenas avahi-daemon[1293]: Joining mDNS multicast group on interface eth1.IPv4 with address 10.28.1.14.
Jul 17 12:31:05 winshapenas avahi-daemon[1293]: Registering new address record for 10.28.1.14 on eth1.
Jul 17 12:31:05 winshapenas avahi-daemon[1293]: Withdrawing address record for 10.28.1.14 on eth1.
Jul 17 12:31:05 winshapenas avahi-daemon[1293]: Leaving mDNS multicast group on interface eth1.IPv4 with address 10.28.1.14.
Jul 17 12:31:05 winshapenas avahi-daemon[1293]: iface.c: interface_mdns_mcast_join() called but no local address available.
Jul 17 12:31:05 winshapenas avahi-daemon[1293]: Interface eth1.IPv4 no longer relevant for mDNS.
Jul 17 12:31:05 winshapenas avahi-daemon[1293]: New relevant interface eth1.IPv4 for mDNS.
Jul 17 12:31:05 winshapenas avahi-daemon[1293]: Joining mDNS multicast group on interface eth1.IPv4 with address 10.28.1.14.
Jul 17 12:31:05 winshapenas avahi-daemon[1293]: Registering new address record for 10.28.1.14 on eth1.
Jul 17 12:31:05 winshapenas RAIDiator: gmac.agent: Waiting for gmac.agent services lock to clear.
Jul 17 12:31:12 winshapenas kernel: Sync:1, source_image=1/1, between 2 to 4096002,all_tgt=f
Jul 17 12:31:34 winshapenas ntpdate[2235]: step time server 173.201.38.85 offset -0.943715 sec
Jul 17 12:31:35 winshapenas kernel: ehci_hcd 0000:00:17.2: EHCI Host Controller
Jul 17 12:31:36 winshapenas kernel: ehci_hcd 0000:00:17.2: new USB bus registered, assigned bus number 1
Jul 17 12:31:36 winshapenas kernel: ehci_hcd 0000:00:17.2: irq 27, io mem 0x5c010000
Jul 17 12:31:36 winshapenas kernel: ehci_hcd 0000:00:17.2: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004
Jul 17 12:31:36 winshapenas cnid_metad[2251]: Set syslog logging to level: LOG_NOTE
Jul 17 12:31:36 winshapenas kernel: usb usb1: configuration #1 chosen from 1 choice
Jul 17 12:31:36 winshapenas kernel: hub 1-0:1.0: USB hub found
Jul 17 12:31:36 winshapenas kernel: hub 1-0:1.0: 4 ports detected
Jul 17 12:31:37 winshapenas kernel: ehci_hcd 0000:00:17.2: hide boot device at port 2
Jul 17 12:31:37 winshapenas kernel: USB Universal Host Controller Interface driver v3.0
Jul 17 12:31:37 winshapenas kernel: PCI: VIA IRQ fixup for 0000:00:17.0, from 0 to 11
Jul 17 12:31:37 winshapenas kernel: uhci_hcd 0000:00:17.0: UHCI Host Controller
Jul 17 12:31:37 winshapenas kernel: uhci_hcd 0000:00:17.0: new USB bus registered, assigned bus number 2
Jul 17 12:31:37 winshapenas kernel: uhci_hcd 0000:00:17.0: irq 27, io base 0x5c001000
Jul 17 12:31:37 winshapenas kernel: usb usb2: configuration #1 chosen from 1 choice
Jul 17 12:31:38 winshapenas kernel: hub 2-0:1.0: USB hub found
Jul 17 12:31:38 winshapenas kernel: hub 2-0:1.0: 2 ports detected
Jul 17 12:31:38 winshapenas kernel: PCI: VIA IRQ fixup for 0000:00:17.1, from 0 to 10
Jul 17 12:31:38 winshapenas kernel: uhci_hcd 0000:00:17.1: UHCI Host Controller
Jul 17 12:31:38 winshapenas kernel: uhci_hcd 0000:00:17.1: new USB bus registered, assigned bus number 3
Jul 17 12:31:38 winshapenas kernel: uhci_hcd 0000:00:17.1: irq 26, io base 0x5c001020
Jul 17 12:31:38 winshapenas kernel: usb usb3: configuration #1 chosen from 1 choice
Jul 17 12:31:38 winshapenas kernel: hub 3-0:1.0: USB hub found
Jul 17 12:31:38 winshapenas kernel: hub 3-0:1.0: 2 ports detected
Jul 17 12:31:48 winshapenas usb.agent: ... no modules for USB product 0/0/206
Jul 17 12:31:49 winshapenas avahi-daemon[1293]: New relevant interface LeafNets.IPv4 for mDNS.
Jul 17 12:31:49 winshapenas avahi-daemon[1293]: Joining mDNS multicast group on interface LeafNets.IPv4 with address 5.168.38.56.
Jul 17 12:31:49 winshapenas avahi-daemon[1293]: Registering new address record for 5.168.38.56 on LeafNets.
Jul 17 12:31:58 winshapenas usb.agent: ... no modules for USB product 0/0/206
Jul 17 12:32:00 winshapenas usb.agent: ... no modules for USB product 0/0/206
Jul 17 12:32:04 winshapenas RAIDiator: gmac.agent: "nice -n 5 /usr/sbin/apache-ssl -f /etc/frontview/apache/httpd.conf" failed to start.
Jul 17 12:32:09 winshapenas kernel: Sync:2, source_image=1/2, between 2 to 4096002,all_tgt=f
Jul 17 12:32:10 winshapenas ntpdate[2534]: step time server 173.201.38.85 offset 0.016527 sec
Jul 17 12:32:12 winshapenas avahi-daemon[1293]: Interface LeafNets.IPv4 no longer relevant for mDNS.
Jul 17 12:32:12 winshapenas avahi-daemon[1293]: Leaving mDNS multicast group on interface LeafNets.IPv4 with address 5.168.38.56.
Jul 17 12:32:12 winshapenas avahi-daemon[1293]: IP_DROP_MEMBERSHIP failed: No such device
Jul 17 12:32:12 winshapenas avahi-daemon[1293]: Withdrawing address record for 5.168.38.56 on LeafNets.
Jul 17 12:32:18 winshapenas avahi-daemon[1293]: New relevant interface LeafNets.IPv4 for mDNS.
Jul 17 12:32:18 winshapenas avahi-daemon[1293]: Joining mDNS multicast group on interface LeafNets.IPv4 with address 5.168.38.56.
Jul 17 12:32:18 winshapenas avahi-daemon[1293]: Registering new address record for 5.168.38.56 on LeafNets.
Jul 17 12:33:00 winshapenas smbd[2643]: PAM pam_putenv: delete non-existent entry; KRB5CCNAME
Jul 17 12:33:04 winshapenas kernel: Sync:3, source_image=1/3, between 2 to 4096002,all_tgt=f
Jul 17 12:33:53 winshapenas kernel: Start sync raid 4 from 4096002 to 976752688
Jul 17 12:35:12 winshapenas smbd[2646]: PAM pam_putenv: delete non-existent entry; KRB5CCNAME
Jul 17 12:35:30 winshapenas kernel: usb 1-1: new high speed USB device using ehci_hcd and address 3
Jul 17 12:35:31 winshapenas kernel: usb 1-1: configuration #1 chosen from 1 choice
Jul 17 12:35:33 winshapenas kernel: usb 1-1: USB disconnect, address 3
Jul 17 12:35:33 winshapenas kernel: usb 1-1: new high speed USB device using ehci_hcd and address 4
Jul 17 12:35:33 winshapenas kernel: SCSI subsystem initialized
Jul 17 12:35:34 winshapenas kernel: usb 1-1: configuration #1 chosen from 1 choice
Jul 17 12:35:34 winshapenas kernel: Initializing USB Mass Storage driver...
Jul 17 12:35:34 winshapenas kernel: scsi0 : SCSI emulation for USB Mass Storage devices
Jul 17 12:35:34 winshapenas kernel: usbcore: registered new driver usb-storage
Jul 17 12:35:34 winshapenas kernel: USB Mass Storage support registered.
Jul 17 12:35:34 winshapenas kernel: usb-storage: device found at 4
Jul 17 12:35:34 winshapenas kernel: usb-storage: waiting for device to settle before scanning
Jul 17 12:35:44 winshapenas kernel: Vendor: External Model: AL25744_12345678 Rev:
Jul 17 12:35:44 winshapenas kernel: Type: Direct-Access ANSI SCSI revision: 02
Jul 17 12:35:44 winshapenas kernel: SCSI device sda: 1953546337 512-byte hdwr sectors (1000216 MB)
Jul 17 12:35:44 winshapenas kernel: sda: Write Protect is off
Jul 17 12:35:44 winshapenas kernel: sda: Mode Sense: 1a 0c 00 00
Jul 17 12:35:44 winshapenas kernel: sda: assuming drive cache: write through
Jul 17 12:35:44 winshapenas kernel: SCSI device sda: 1953546337 512-byte hdwr sectors (1000216 MB)
Jul 17 12:35:44 winshapenas kernel: sda: Write Protect is off
Jul 17 12:35:44 winshapenas kernel: sda: Mode Sense: 1a 0c 00 00
Jul 17 12:35:44 winshapenas kernel: sda: assuming drive cache: write through
Jul 17 12:35:44 winshapenas kernel: sda: sda1
Jul 17 12:35:44 winshapenas kernel: sd 0:0:0:0: Attached scsi disk sda
Jul 17 12:35:44 winshapenas kernel: usb-storage: device scan complete
Jul 17 12:35:45 winshapenas scsi.agent: disk at /devices/pci0000:00/0000:00:17.2/usb1/1-1/1-1:1.0/host0/target0:0:0/0:0:0:0
Jul 17 12:36:03 winshapenas kernel: kjournald starting. Commit interval 5 seconds
Jul 17 12:36:03 winshapenas kernel: EXT3 FS on sda1, internal journal
Jul 17 12:36:03 winshapenas kernel: EXT3-fs: recovery complete.
Jul 17 12:36:03 winshapenas kernel: EXT3-fs: mounted filesystem with ordered data mode.
Jul 17 12:43:03 winshapenas smbd[3182]: PAM pam_putenv: delete non-existent entry; KRB5CCNAME
Jul 17 12:49:26 winshapenas smbd[3322]: PAM pam_putenv: delete non-existent entry; KRB5CCNAME
Jul 17 12:50:21 winshapenas smbd[3129]: PAM pam_putenv: delete non-existent entry; KRB5CCNAME
Jul 17 12:51:38 winshapenas smbd[3170]: PAM pam_putenv: delete non-existent entry; KRB5CCNAME
Jul 17 12:51:38 winshapenas smbd[3325]: PAM pam_putenv: delete non-existent entry; KRB5CCNAME
Jul 17 12:53:36 winshapenas smbd[3407]: PAM pam_putenv: delete non-existent entry; KRB5CCNAME
Jul 17 12:53:38 winshapenas smbd[3409]: PAM pam_putenv: delete non-existent entry; KRB5CCNAME
Jul 17 12:53:40 winshapenas smbd[3411]: PAM pam_putenv: delete non-existent entry; KRB5CCNAME
Jul 17 12:55:46 winshapenas nss_wins[1331]: Connection from UDP: [10.28.232.235]:61271
Jul 17 12:55:46 winshapenas last message repeated 3 times
Jul 17 12:57:51 winshapenas kernel: sd 0:0:0:0: SCSI error: return code = 0x8000002
Jul 17 12:57:51 winshapenas kernel: sda: Current: sense key=0xb
Jul 17 12:57:51 winshapenas kernel: ASC=0x0 ASCQ=0x0
Jul 17 12:57:51 winshapenas kernel: Buffer I/O error on device sda, logical block 1953546336 (ksoftirqd/0)
Jul 17 12:57:51 winshapenas kernel: sd 0:0:0:0: SCSI error: return code = 0x8000002
Jul 17 12:57:51 winshapenas kernel: sda: Current: sense key=0xb
Jul 17 12:57:51 winshapenas kernel: ASC=0x0 ASCQ=0x0
Jul 17 12:57:51 winshapenas kernel: Buffer I/O error on device sda, logical block 1953546336 (ksoftirqd/0)

[arjoseph1]

Try to disable disk spin down.

[clewis]

Thanks, will do.

Our hardware monitor actually alerted us about the crash at 12:56AM Sunday morning...here are the logs from that time period...not sure if that tells us anything more.

Jul 17 00:36:31 winshapenas noflushd[1107]: Spinning down disks.
Jul 17 00:38:13 winshapenas noflushd[1107]: Disks spinning up after 1 minutes.
Jul 17 00:45:20 winshapenas kernel: BUG: scheduling while atomic: nmbd/0x00000100/2373
Jul 17 00:45:20 winshapenas kernel: [80288efc : mutex_lock+0x20/0x34 ] [802546c0 : is_local_netif+0x1c/0x58 ] [80255b8c : arp_process+0x630/0x780 ] [80255dcc : arp_rcv+0xe0/0x168 ] [8021692c : netif_receive_skb+0x1c8/0x290 ] [80216a7c : process_backlog+0x88/0x14c ] [80216bc0 : net_rx_action+0x80/0x13c ] [80032148 : __do_softirq+0xa0/0xc4 ] [800321ac : do_softirq+0x40/0x54 ] [80014948 : real_irq_entry+0x34/0x58 ] [80216e04 : dev_ifconf+0x90/0x140 ] [80217d74 : dev_ioctl+0x2ec/0x300 ] [8020b71c : sock_ioctl+0xf0/0x288 ] [80084390 : do_ioctl+0x58/0x78 ] [80084590 : vfs_ioctl+0x70/0x280 ] [800847cc : sys_ioctl+0x2c/0x58 ]
Jul 17 00:56:37 winshapenas smbd[6033]: PAM pam_putenv: delete non-existent entry; KRB5CCNAME
Jul 17 01:11:00 winshapenas smbd[25942]: PAM pam_putenv: delete non-existent entry; KRB5CCNAME
Jul 17 01:26:51 winshapenas noflushd[1107]: Spinning down disks.
Jul 17 02:05:12 winshapenas noflushd[1107]: Disks spinning up after 38 minutes.
Jul 17 02:20:28 winshapenas noflushd[1107]: Spinning down disks.
Jul 17 04:00:12 winshapenas noflushd[1107]: Disks spinning up after 99 minutes.
Jul 17 04:25:09 winshapenas noflushd[1107]: Spinning down disks.
Jul 17 06:25:05 winshapenas noflushd[1107]: Disks spinning up after 119 minutes.

[arjoseph1]

Observe the nas behavior after you have disabled disk spin down. Verify if the NAS will still crash.

[clewis]

So far, so good....

[arjoseph1]

Sounds good. Just keep me posted. 😄