ReadyNas Pro 6 Freezes x3 as of 26/4 in the one month
Hi,
I have a couple of ReadyNas pro's in production serving a couple of NFS VMware environments with Terminal servers and SMB shares for 2 businesses with approx 8-10 staff at one site and approx 20 staff at the other site. They have been performing pretty much faultless and awesome since 2011 when first installed.
Recently i've had the RNPRO6 lock up at BOTH sites and have had to be manually restarted..(Scary moments). Over Anzac day the RNPRO6 at the bigger site locked up and i've managed to pull the logs - excerpt below
looking at the logs here the last entry was with device /dev/sdi , this looks like the USB drive attached to the NAS.. there is 1 x 500gb drive attached to each nas which hold the daily VMware backups (Off Nas disk) driven by Veeam.
Can someone from Readynas support take a look please, as I need to have the USB drives connected for off-source backups.. FYI the backups kick off at 19:15 every night to the USB drive.. prior to the last few weeks, the backups have been fine.
Both ReadyNas units are at firmware version: 4.2.19 (realise there is 4.22 out now but havent been able to get to the upgrade or see the major urgency to take an outage due to units being solid until now).
Heres the excerpt of the system log just prior to when it went unresponsive on Wednesday evening..
Apr 24 19:17:30 NAS vnstatd[4122]: Traffic rate for "eth0" higher than set maximum 100 Mbit (30->413, r73 t729), syncing. Apr 24 19:22:30 NAS vnstatd[4122]: Traffic rate for "eth0" higher than set maximum 100 Mbit (30->413, r74 t661), syncing. Apr 24 19:23:59 NAS kernel: usb 1-2: USB disconnect, address 3 Apr 24 19:23:59 NAS udevd-event[4245]: unlink_secure: chown(/dev/sdg1, 0, 0) failed: No such file or directory Apr 24 19:23:59 NAS udevd-event[4245]: unlink_secure: chmod(/dev/sdg1, 0000) failed: No such file or directory Apr 24 19:24:01 NAS kernel: JBD: I/O error detected when updating journal superblock for sdg1. Apr 24 19:24:01 NAS kernel: EXT3-fs (sdg1): I/O error while writing superblock Apr 24 19:24:02 NAS kernel: usb 1-2: new high speed USB device using ehci_hcd and address 4 Apr 24 19:24:02 NAS kernel: scsi12 : usb-storage 1-2:1.0 Apr 24 19:24:03 NAS kernel: scsi 12:0:0:0: Direct-Access Seagate Portable 0130 PQ: 0 ANSI: 4 Apr 24 19:24:03 NAS kernel: sd 12:0:0:0: Attached scsi generic sg6 type 0 Apr 24 19:24:03 NAS kernel: sd 12:0:0:0: [sdg] 976773168 512-byte logical blocks: (500 GB/465 GiB) Apr 24 19:24:03 NAS kernel: sd 12:0:0:0: [sdg] Write Protect is off Apr 24 19:24:03 NAS kernel: sd 12:0:0:0: [sdg] Mode Sense: 2f 08 00 00 Apr 24 19:24:03 NAS kernel: sd 12:0:0:0: [sdg] Assuming drive cache: write through Apr 24 19:24:03 NAS kernel: sd 12:0:0:0: [sdg] Assuming drive cache: write through Apr 24 19:24:03 NAS kernel: sdg: sdg1 Apr 24 19:24:03 NAS kernel: sd 12:0:0:0: [sdg] Assuming drive cache: write through Apr 24 19:24:03 NAS kernel: sd 12:0:0:0: [sdg] Attached SCSI disk Apr 24 19:24:12 NAS kernel: usb 2-2: USB disconnect, address 5 Apr 24 19:24:12 NAS kernel: Aborting journal on device sdi1. Apr 24 19:24:12 NAS kernel: JBD: I/O error detected when updating journal superblock for sdi1. Apr 24 19:24:12 NAS kernel: journal commit I/O error Apr 24 19:24:12 NAS udevd-event[4533]: unlink_secure: chown(/dev/sdi1, 0, 0) failed: No such file or directory Apr 24 19:24:13 NAS udevd-event[4533]: unlink_secure: chmod(/dev/sdi1, 0000) failed: No such file or directory Apr 24 19:24:13 NAS kernel: EXT3-fs error (device sdi1): ext3_get_inode_loc: unable to read inode block - inode=6443018, block=103088130 Apr 24 19:24:13 NAS kernel: EXT3-fs (sdi1): I/O error while writing superblock Apr 24 19:24:13 NAS kernel: EXT3-fs (sdi1): error: ext3_journal_start_sb: Detected aborted journal Apr 24 19:24:13 NAS kernel: EXT3-fs (sdi1): error: remounting filesystem read-only
Apr 26 08:09:09 NAS syslogd 1.4.1#18: restart.
Apr 26 08:09:09 NAS kernel: klogd 1.4.1#18, log source = /proc/kmsg started. Apr 26 08:09:09 NAS kernel: Initializing cgroup subsys cpu Apr 26 08:09:09 NAS kernel: Linux version 2.6.37.6.RNx86_64.2.1 (jmaggard@calzone) (gcc version 4.1.2 20061115 (prerelease) (Debian 4.1.1-21)) #1 SMP Mon Aug 15 16:19:41 PDT 2011 Apr 26 08:09:09 NAS kernel: Command line: initrd=initrd.gz console=ttyS0 reason=normal BOOT_IMAGE=kernel Apr 26 08:09:09 NAS kernel: BIOS-provided physical RAM map: Apr 26 08:09:09 NAS kernel: BIOS-e820: 0000000000000000 - 000000000009cc00 (usable) Apr 26 08:09:09 NAS kernel: BIOS-e820: 000000000009cc00 - 00000000000a0000 (reserved) Apr 26 08:09:09 NAS kernel: BIOS-e820: 00000000000e0000 - 0000000000100000 (reserved) Apr 26 08:09:09 NAS kernel: BIOS-e820: 0000000000100000 - 000000003feb0000 (usable) Apr 26 08:09:09 NAS kernel: BIOS-e820: 000000003feb0000 - 000000003febe000 (ACPI data) Apr 26 08:09:09 NAS kernel: BIOS-e820: 000000003febe000 - 000000003fef0000 (ACPI NVS) Apr 26 08:09:09 NAS kernel: BIOS-e820: 000000003fef0000 - 000000003ff00000 (reserved) Apr 26 08:09:09 NAS kernel: BIOS-e820: 00000000fee00000 - 00000000fee01000 (reserved) Apr 26 08:09:09 NAS kernel: BIOS-e820: 00000000ffb00000 - 0000000100000000 (reserved) Apr 26 08:09:09 NAS kernel: NX (Execute Disable) protection: active Apr 26 08:09:09 NAS kernel: DMI present. Apr 26 08:09:09 NAS kernel: DMI: To Be Filled By O.E.M. To Be Filled By O.E.M./To be filled by O.E.M., BIOS 080014 10/03/2008 Apr 26 08:09:09 NAS kernel: e820 update range: 0000000000000000 - 0000000000010000 (usable) ==> (reserved) Apr 26 08:09:09 NAS kernel: e820 remove range: 00000000000a0000 - 0000000000100000 (usable) Apr 26 08:09:09 NAS kernel: last_pfn = 0x3feb0 max_arch_pfn = 0x400000000 Apr 26 08:09:09 NAS kernel: initial memory mapped : 0 - 20000000 Apr 26 08:09:09 NAS kernel: init_memory_mapping: 0000000000000000-000000003feb0000 Apr 26 08:09:09 NAS kernel: 0000000000 - 003fe00000 page 2M Apr 26 08:09:09 NAS kernel: 003fe00000 - 003feb0000 page 4k Apr 26 08:09:09 NAS kernel: kernel direct mapping tables up to 3feb0000 @ 1fffd000-20000000 Apr 26 08:09:09 NAS kernel: RAMDISK: 3fd2d000 - 3feb0000 Apr 26 08:09:09 NAS kernel: ACPI: RSDP 00000000000f9850 00014 (v00 ACPIAM) Apr 26 08:09:09 NAS kernel: ACPI: RSDT 000000003feb0000 00038 (v01 A M I OEMRSDT 10000803 MSFT 00000097) Apr 26 08:09:09 NAS kernel: ACPI: FACP 000000003feb0200 00084 (v02 A M I OEMFACP 10000803 MSFT 00000097) Apr 26 08:09:09 NAS kernel: ACPI: DSDT 000000003feb0440 05696 (v01 1ADHK 1ADHK007 00000007 INTL 20051117) Apr 26 08:09:09 NAS kernel: ACPI: FACS 000000003febe000 00040 Apr 26 08:09:09 NAS kernel: ACPI: APIC 000000003feb0390 0006C (v01 A M I OEMAPIC 10000803 MSFT 00000097) Apr 26 08:09:09 NAS kernel: ACPI: MCFG 000000003feb0400 0003C (v01 A M I OEMMCFG 10000803 MSFT 00000097) Apr 26 08:09:09 NAS kernel: ACPI: OEMB 000000003febe040 00060 (v01 A M I AMI_OEM 10000803 MSFT 00000097) Apr 26 08:09:09 NAS kernel: ACPI: GSCI 000000003febe0a0 02024 (v01 A M I GMCHSCI 10000803 MSFT 00000097) Apr 26 08:09:09 NAS kernel: ACPI: Local APIC address 0xfee00000 Apr 26 08:09:09 NAS kernel: [ffffea0000000000-ffffea0000dfffff] PMD -> [ffff88003e400000-ffff88003f1fffff] on node 0 Apr 26 08:09:09 NAS kernel: Zone PFN ranges: Apr 26 08:09:09 NAS kernel: DMA 0x00000010 -> 0x00001000 Apr 26 08:09:09 NAS kernel: DMA32 0x00001000 -> 0x00100000 Apr 26 08:09:09 NAS kernel: Normal empty Apr 26 08:09:09 NAS kernel: Movable zone start PFN for each node Apr 26 08:09:09 NAS kernel: early_node_map[2] active PFN ranges Apr 26 08:09:09 NAS kernel: 0: 0x00000010 -> 0x0000009c Apr 26 08:09:09 NAS kernel: 0: 0x00000100 -> 0x0003feb0 Apr 26 08:09:09 NAS kernel: On node 0 totalpages: 261692 Apr 26 08:09:09 NAS kernel: DMA zone: 56 pages used for memmap Apr 26 08:09:09 NAS kernel: DMA zone: 2 pages reserved Apr 26 08:09:09 NAS kernel: DMA zone: 3922 pages, LIFO batch:0 Apr 26 08:09:09 NAS kernel: DMA32 zone: 3524 pages used for memmap Apr 26 08:09:09 NAS kernel: DMA32 zone: 254188 pages, LIFO batch:31 Apr 26 08:09:09 NAS kernel: ACPI: PM-Timer IO Port: 0x808 Apr 26 08:09:09 NAS kernel: ACPI: Local APIC address 0xfee00000 Apr 26 08:09:09 NAS kernel: ACPI: LAPIC (acpi_id[0x01] lapic_id[0x00] enabled) Apr 26 08:09:09 NAS kernel: ACPI: LAPIC (acpi_id[0x02] lapic_id[0x01] enabled) Apr 26 08:09:09 NAS kernel: ACPI: LAPIC (acpi_id[0x03] lapic_id[0x82] disabled) Apr 26 08:09:09 NAS kernel: ACPI: LAPIC (acpi_id[0x04] lapic_id[0x83] disabled) Apr 26 08:09:09 NAS kernel: ACPI: IOAPIC (id[0x02] address[0xfec00000] gsi_base[0]) Apr 26 08:09:09 NAS kernel: IOAPIC[0]: apic_id 2, version 32, address 0xfec00000, GSI 0-23 Apr 26 08:09:09 NAS kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) Apr 26 08:09:09 NAS kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) Apr 26 08:09:09 NAS kernel: ACPI: IRQ0 used by override. Apr 26 08:09:09 NAS kernel: ACPI: IRQ2 used by override. Apr 26 08:09:09 NAS kernel: ACPI: IRQ9 used by override. Apr 26 08:09:09 NAS kernel: Using ACPI (MADT) for SMP configuration information Apr 26 08:09:09 NAS kernel: SMP: Allowing 4 CPUs, 2 hotplug CPUs Apr 26 08:09:09 NAS kernel: nr_irqs_gsi: 40 Apr 26 08:09:09 NAS kernel: Allocating PCI resources starting at 3ff00000 (gap: 3ff00000:bef00000) Apr 26 08:09:09 NAS kernel: setup_percpu: NR_CPUS:8 nr_cpumask_bits:8 nr_cpu_ids:4 nr_node_ids:1 Apr 26 08:09:09 NAS kernel: PERCPU: Embedded 26 pages/cpu @ffff88003fa00000 s73856 r8192 d24448 u524288 Apr 26 08:09:09 NAS kernel: pcpu-alloc: s73856 r8192 d24448 u524288 alloc=1*2097152 Apr 26 08:09:09 NAS kernel: pcpu-alloc: [0] 0 1 2 3 Apr 26 08:09:09 NAS kernel: Built 1 zonelists in Zone order, mobility grouping on. Total pages: 258110 Apr 26 08:09:09 NAS kernel: Kernel command line: initrd=initrd.gz console=ttyS0 reason=normal BOOT_IMAGE=kernel Apr 26 08:09:09 NAS kernel: PID hash table entries: 4096 (order: 3, 32768 bytes) Apr 26 08:09:09 NAS kernel: Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes) Apr 26 08:09:09 NAS kernel: Inode-cache hash table entries: 65536 (order: 7, 524288 bytes) Apr 26 08:09:09 NAS kernel: Memory: 1019900k/1047232k available (5304k kernel code, 464k absent, 26868k reserved, 2648k data, 396k init) Apr 26 08:09:09 NAS kernel: SLUB: Genslabs=15, HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 Apr 26 08:09:09 NAS kernel: Hierarchical RCU implementation. Apr 26 08:09:09 NAS kernel: ^IRCU-based detection of stalled CPUs is disabled. Apr 26 08:09:09 NAS kernel: NR_IRQS:512 Apr 26 08:09:09 NAS kernel: Console: colour VGA+ 80x25 Apr 26 08:09:09 NAS kernel: console [ttyS0] enabled Apr 26 08:09:09 NAS kernel: Fast TSC calibration using PIT Apr 26 08:09:09 NAS kernel: Detected 1795.784 MHz processor. Apr 26 08:09:09 NAS kernel: Calibrating delay loop (skipped), value calculated using timer frequency.. 3591.56 BogoMIPS (lpj=1795784) Apr 26 08:09:09 NAS kernel: pid_max: default: 32768 minimum: 301 Apr 26 08:09:09 NAS kernel: Mount-cache hash table entries: 256 Apr 26 08:09:09 NAS kernel: Initializing cgroup subsys blkio Apr 26 08:09:09 NAS kernel: CPU: Physical Processor ID: 0 Apr 26 08:09:09 NAS kernel: CPU: Processor Core ID: 0 Apr 26 08:09:09 NAS kernel: mce: CPU supports 6 MCE banks Apr 26 08:09:09 NAS kernel: [Hardware Error]: No human readable MCE decoding support on this CPU type. Apr 26 08:09:09 NAS kernel: [Hardware Error]: Run the message through 'mcelog --ascii' to decode. Apr 26 08:09:09 NAS kernel: Disabling lock debugging due to kernel taint Apr 26 08:09:09 NAS kernel: CPU0: Thermal monitoring enabled (TM2) Apr 26 08:09:09 NAS kernel: using mwait in idle threads. Apr 26 08:09:09 NAS kernel: Performance Events: PEBS fmt0+, Core2 events, Intel PMU driver. Apr 26 08:09:09 NAS kernel: PEBS disabled due to CPU errata. Apr 26 08:09:09 NAS kernel: ... version: 2 Apr 26 08:09:09 NAS kernel: ... bit width: 40 Apr 26 08:09:09 NAS kernel: ... generic registers: 2 Apr 26 08:09:09 NAS kernel: ... value mask: 000000ffffffffff Apr 26 08:09:09 NAS kernel: ... max period: 000000007fffffff Apr 26 08:09:09 NAS kernel: ... fixed-purpose events: 3 Apr 26 08:09:09 NAS kernel: ... event mask: 0000000700000003 Apr 26 08:09:09 NAS kernel: ACPI: Core revision 20101013 Apr 26 08:09:09 NAS kernel: Setting APIC routing to flat Apr 26 08:09:09 NAS kernel: ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 Apr 26 08:09:09 NAS kernel: CPU0: Intel(R) Pentium(R) Dual CPU E2160 @ 1.80GHz stepping 0d Apr 26 08:09:09 NAS kernel: Booting Node 0, Processors #1 Apr 26 08:09:09 NAS kernel: Brought up 2 CPUs Apr 26 08:09:09 NAS kernel: Total of 2 processors activated (7181.82 BogoMIPS). Apr 26 08:09:09 NAS kernel: xor: automatically using best checksumming function: generic_sse Apr 26 08:09:09 NAS kernel: generic_sse: 6576.000 MB/sec Apr 26 08:09:09 NAS kernel: xor: using function: generic_sse (6576.000 MB/sec) Apr 26 08:09:09 NAS kernel: NET: Registered protocol family 16 Apr 26 08:09:09 NAS kernel: ACPI: bus type pci registered Apr 26 08:09:09 NAS kernel: PCI: Using configuration type 1 for base access Apr 26 08:09:09 NAS kernel: bio: create slab <bio-0> at 0 Apr 26 08:09:09 NAS kernel: raid6: int64x1 1519 MB/s Apr 26 08:09:09 NAS kernel: raid6: int64x2 2207 MB/s Apr 26 08:09:09 NAS kernel: raid6: int64x4 2050 MB/s Apr 26 08:09:09 NAS kernel: raid6: int64x8 1359 MB/s Apr 26 08:09:09 NAS kernel: raid6: sse2x1 3171 MB/s Apr 26 08:09:09 NAS kernel: raid6: sse2x2 3375 MB/s Apr 26 08:09:09 NAS kernel: raid6: sse2x4 5316 MB/s Apr 26 08:09:09 NAS kernel: raid6: using algorithm sse2x4 (5316 MB/s) Apr 26 08:09:09 NAS kernel: ACPI: EC: Look up EC in DSDT Apr 26 08:09:09 NAS kernel: ACPI: Executed 1 blocks of module-level executable AML code
/Messages cut from remainder of log. Apr 26 08:13:34 NAS kernel: [Hardware Error]: Machine check events logged
Re: ReadyNas Pro 6 Freezes x3 as of 26/4 in the one month
Support does not show up here much. If these are Pro's you have 5 year email support. You can go online and submit a ticket. They seem to respond within a business day, but that doesn't mean they will figure it out. By the looks of things the USB drive disconnected during the backup and journeling got corrupted. You should probably also pursue whether something happened in the drive causing it to disconnect. Check drive stats etc. I know it seems coincidental, but maybe both of your drives started having issues and those are causing the USB device to disconnect. Have a look at more of the log to see if there are other disconnects happening (not during the backup). Maybe this is going on benignly all the time. Also check to make sure the disk isn't filling up. That may not be well tested.
Re: ReadyNas Pro 6 Freezes x3 as of 26/4 in the one month
Hi, Thanks for the response, just for future ref is there a way via cli to list all the devices and their device id's just so I can confirm 100% what device sdi is... i've used dmesg although it gives quite a verbose output..
Re: ReadyNas Pro 6 Freezes x3 as of 26/4 in the one month
Hi,
Thanks all for the tips..
Today had another crash, I disconnected the usb drives last night via front view, this morning the operator on site removed them from the readynas and boom.. Same issue, hung..
Something weird is going on with this box and USB I/o it shouldn't have even had them mounted as of last night..
I Will log a ticket, i am having the drives sent across to me to scan and check for errors in any case.. For backups to these drives, is there any merit in upgrading the firmware to 4.22 and going ext-4 or perhaps reformatting the USB drives as NTFS? Whilst I am still on 4.2.19 as I Need to save large single files so fat32 no good obviously..
Re: ReadyNas Pro 6 Freezes x3 as of 26/4 in the one month
Most likely the frontview dismount was undone by the drive disconnecting and reconnecting so it got re-hotplugged which is sort of consistent with the problem.
If you have ssh access you can reformat them with mkfs.ext4 without having to do an upgrade. If you are backing up /c to your USB this will at least reduce the backup activity because it will get around a problem where some files backup every night due to timestamp granularity on ext3. If there is something corrupt in that filesystem I suppose it might help but that is probably a longshot. Need to understand why the device disconnects or it will keep happening.
Is it possible you've recently enabled a feature to idle the USB drives when they are not used? Maybe this is a wakeup issue with the enclosure or disk.
Re: ReadyNas Pro 6 Freezes x3 as of 26/4 in the one month
Hi,
that sounds viable, in frontview the drives were listed as disconnected..after testing the drives and running some drive scans on them there are 21 bad sectors on one, the other drive seems to be all clear.
I'll replace the drive with the bad sectors and will probably reformat the good drive as ext4, upgrade the readynas in any case and change the cables!!
Thanks for all your help, i'll post back once i've replaced the disk, and updated the firmware..
