Andrej Vrabčo Vrabec Posted October 5, 2017 Posted October 5, 2017 Hello, i have this strange problem after upgrade to kernel 3.4.113-sun8i (orange pi plus 2e, debian server version armbian, Seagate BarraCuda 2TB sata hdd, connect with axagon usb3 to sata adapter and set standby after 30min, power by power adapter). Before update, all working fine. Now, after kernel update, drive never stop spinning. I stopped rpimonitor and smartd services and still dont work. If I use hdparm -Y /dev/disk/by-uuid/... then drive spindown but after som second start spinning again. How can i solve this? this is my syslog Oct 5 11:36:21 localhost kernel: [ 1450.160126] usb 4-1: reset high-speed USB device number 3 using sunxi-ehci Oct 5 11:36:21 localhost kernel: [ 1450.323990] program smartctl is using a deprecated SCSI ioctl, please convert it to SG_IO Oct 5 11:36:22 localhost kernel: [ 1451.054567] ehci_irq: highspeed device disconnect Oct 5 11:36:22 localhost kernel: [ 1451.054780] usb 4-1: USB disconnect, device number 3 Oct 5 11:36:22 localhost systemd[1]: Unmounting /everest... Oct 5 11:36:22 localhost kernel: [ 1451.083041] scsi 1:0:0:0: rejecting I/O to offline device Oct 5 11:36:22 localhost kernel: [ 1451.090039] scsi 1:0:0:0: [sdb] killing request Oct 5 11:36:22 localhost umount[4025]: umount: /everest: target is busy Oct 5 11:36:22 localhost umount[4025]: (In some cases useful info about processes that Oct 5 11:36:22 localhost umount[4025]: use the device is found by lsof(8) or fuser(1).) Oct 5 11:36:22 localhost systemd[1]: everest.mount mount process exited, code=exited status=32 Oct 5 11:36:22 localhost systemd[1]: Failed unmounting /everest. Oct 5 11:36:26 localhost kernel: [ 1454.983885] ehci_irq: highspeed device connect Oct 5 11:36:26 localhost kernel: [ 1455.250109] usb 4-1: new high-speed USB device number 4 using sunxi-ehci Oct 5 11:36:26 localhost kernel: [ 1455.434318] scsi2 : usb-storage 4-1:1.0 Oct 5 11:36:27 localhost kernel: [ 1456.441540] scsi 2:0:0:0: Direct-Access ST2000LM 015-2E8174 8105 PQ: 0 ANSI: 6 Oct 5 11:36:27 localhost kernel: [ 1456.461235] sd 2:0:0:0: [sdb] 3907029168 512-byte logical blocks: (2.00 TB/1.81 TiB) Oct 5 11:36:27 localhost kernel: [ 1456.480576] sd 2:0:0:0: [sdb] Write Protect is off Oct 5 11:36:27 localhost kernel: [ 1456.494221] sd 2:0:0:0: [sdb] Mode Sense: 33 00 00 08 Oct 5 11:36:27 localhost kernel: [ 1456.495191] sd 2:0:0:0: [sdb] No Caching mode page found Oct 5 11:36:27 localhost kernel: [ 1456.509243] sd 2:0:0:0: [sdb] Assuming drive cache: write through Oct 5 11:36:27 localhost kernel: [ 1456.528186] sd 2:0:0:0: [sdb] No Caching mode page found Oct 5 11:36:27 localhost kernel: [ 1456.550171] sd 2:0:0:0: [sdb] Assuming drive cache: write through Oct 5 11:36:29 localhost kernel: [ 1458.605604] sdb: sdb1 < sdb5 > Oct 5 11:36:29 localhost rsyslogd-2007: action 'action 18' suspended, next retry is Thu Oct 5 11:37:29 2017 [try http://www.rsyslog.com/e/2007 ] Oct 5 11:36:29 localhost kernel: [ 1458.616989] sd 2:0:0:0: [sdb] No Caching mode page found Oct 5 11:36:29 localhost kernel: [ 1458.626399] sd 2:0:0:0: [sdb] Assuming drive cache: write through Oct 5 11:36:29 localhost kernel: [ 1458.636553] sd 2:0:0:0: [sdb] Attached SCSI disk There is strange reset high-speed USB device. device number is not always the same. smartctl: Device Model: ST2000LM015-2E8174 Serial Number: WCC2LKE4 LU WWN Device Id: 5 000c50 09d5bf744 Firmware Version: SDM1 User Capacity: 2,000,398,934,016 bytes [2.00 TB] Sector Sizes: 512 bytes logical, 4096 bytes physical Rotation Rate: 5400 rpm Form Factor: 2.5 inches Device is: Not in smartctl database [for details use: -P showall] ATA Version is: ACS-3 T13/2161-D revision 3b SATA Version is: SATA 3.1, 6.0 Gb/s (current: 3.0 Gb/s) Local Time is: Thu Oct 5 12:15:26 2017 CEST SMART support is: Available - device has SMART capability. SMART support is: Enabled === START OF READ SMART DATA SECTION === SMART Status not supported: Incomplete response, ATA output registers missing SMART overall-health self-assessment test result: PASSED Warning: This result is based on an Attribute check. General SMART Values: Offline data collection status: (0x82) Offline data collection activity was completed without error. Auto Offline Data Collection: Enabled. Self-test execution status: ( 249) Self-test routine in progress... 90% of test remaining. Total time to complete Offline data collection: ( 0) seconds. Offline data collection capabilities: (0x79) SMART execute Offline immediate. No Auto Offline data collection support. Suspend Offline collection upon new command. Offline surface scan supported. Self-test supported. Conveyance Self-test supported. Selective Self-test supported. SMART capabilities: (0x0003) Saves SMART data before entering power-saving mode. Supports SMART auto save timer. Error logging capability: (0x01) Error logging supported. General Purpose Logging supported. Short self-test routine recommended polling time: ( 1) minutes. Extended self-test routine recommended polling time: ( 328) minutes. Conveyance self-test routine recommended polling time: ( 2) minutes. SCT capabilities: (0x3035) SCT Status supported. SCT Feature Control supported. SCT Data Table supported. SMART Attributes Data Structure revision number: 10 Vendor Specific SMART Attributes with Thresholds: ID# ATTRIBUTE_NAME FLAG VALUE WORST THRESH TYPE UPDATED WHEN_FAILED RAW_VALUE 1 Raw_Read_Error_Rate 0x000f 067 064 006 Pre-fail Always - 4829255 3 Spin_Up_Time 0x0003 099 099 000 Pre-fail Always - 0 4 Start_Stop_Count 0x0032 100 100 020 Old_age Always - 820 5 Reallocated_Sector_Ct 0x0033 100 100 036 Pre-fail Always - 0 7 Seek_Error_Rate 0x000f 071 060 045 Pre-fail Always - 12169512 9 Power_On_Hours 0x0032 096 096 000 Old_age Always - 4241 (227 219 0) 10 Spin_Retry_Count 0x0013 100 100 097 Pre-fail Always - 0 12 Power_Cycle_Count 0x0032 100 100 020 Old_age Always - 619 184 End-to-End_Error 0x0032 100 100 099 Old_age Always - 0 187 Reported_Uncorrect 0x0032 100 100 000 Old_age Always - 0 188 Command_Timeout 0x0032 099 099 000 Old_age Always - 678615187824 189 High_Fly_Writes 0x003a 100 100 000 Old_age Always - 0 190 Airflow_Temperature_Cel 0x0022 057 041 040 Old_age Always - 43 (Min/Max 32/43) 191 G-Sense_Error_Rate 0x0032 100 100 000 Old_age Always - 0 192 Power-Off_Retract_Count 0x0032 100 100 000 Old_age Always - 44 193 Load_Cycle_Count 0x0032 059 059 000 Old_age Always - 83820 194 Temperature_Celsius 0x0022 043 059 000 Old_age Always - 43 (0 17 0 0 0) 197 Current_Pending_Sector 0x0012 100 100 000 Old_age Always - 0 198 Offline_Uncorrectable 0x0010 100 100 000 Old_age Offline - 0 199 UDMA_CRC_Error_Count 0x003e 200 200 000 Old_age Always - 1 240 Head_Flying_Hours 0x0000 100 253 000 Old_age Offline - 4180 (83 22 0) 241 Total_LBAs_Written 0x0000 100 253 000 Old_age Offline - 1624240994 242 Total_LBAs_Read 0x0000 100 253 000 Old_age Offline - 578023611 254 Free_Fall_Sensor 0x0032 100 100 000 Old_age Always - 0 SMART Error Log Version: 1 No Errors Logged SMART Self-test log structure revision number 1 Num Test_Description Status Remaining LifeTime(hours) LBA_of_first_error # 1 Extended offline Self-test routine in progress 90% 4241 - SMART Selective self-test log data structure revision number 1 SPAN MIN_LBA MAX_LBA CURRENT_TEST_STATUS 1 0 0 Not_testing 2 0 0 Not_testing 3 0 0 Not_testing 4 0 0 Not_testing 5 0 0 Not_testing Selective self-test flags (0x0): After scanning selected spans, do NOT read-scan remainder of disk. If Selective self-test is pending on power-up, resume after 0 minute delay. lsusb Bus 008 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub Bus 007 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub Bus 006 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub Bus 005 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub Bus 004 Device 004: ID 4971:8017 SimpleTech Bus 004 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub thanks
tkaiser Posted October 5, 2017 Posted October 5, 2017 armbianmonitor -u Edit: And please also output from 'lsusb -t' just in case (armbianmonitor version on current OS images is rather outdated)
Andrej Vrabčo Vrabec Posted October 5, 2017 Author Posted October 5, 2017 http://sprunge.us/jcTE lsusb -t /: Bus 08.Port 1: Dev 1, Class=root_hub, Driver=sunxi-ohci/1p, 12M /: Bus 07.Port 1: Dev 1, Class=root_hub, Driver=sunxi-ohci/1p, 12M /: Bus 06.Port 1: Dev 1, Class=root_hub, Driver=sunxi-ohci/1p, 12M /: Bus 05.Port 1: Dev 1, Class=root_hub, Driver=sunxi-ohci/1p, 12M /: Bus 04.Port 1: Dev 1, Class=root_hub, Driver=sunxi-ehci/1p, 480M |__ Port 1: Dev 4, If 0, Class=Mass Storage, Driver=usb-storage, 480M /: Bus 03.Port 1: Dev 1, Class=root_hub, Driver=sunxi-ehci/1p, 480M /: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=sunxi-ehci/1p, 480M /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=sunxi-ehci/1p, 480M
tkaiser Posted October 5, 2017 Posted October 5, 2017 Thank you. Just in case please also output from zgrep reset /var/log/syslog* | curl -F 'sprunge=<-' http://sprunge.us I don't think anything is related to the kernel update (since wrt USB support nothing has changed there since ages), this looks more like a hardware problem to me and the first thing I would do is reseating/replacing cables. Also an fsck might be a good idea due to the 'Buffer I/O error on device sda5' occurences. I remember an issue with smartctl and USB resets but that was with an ODROID-XU4 and a JMS561: https://forum.odroid.com/viewtopic.php?f=147&t=27246 -- but IIRC you said you get USB resets also without smartd being active, true?
Andrej Vrabčo Vrabec Posted October 5, 2017 Author Posted October 5, 2017 http://sprunge.us/jZWD -> only for today syslog from cca 6:00 And yes, if I stop smartd service then there is still this problem. Orange is running in parents house without internet access (bad provider without public ip) and i am hear after long time and updating. Thats why all is old. Ok i try some other things, mayby now is running something what dont run before update.
tkaiser Posted October 5, 2017 Posted October 5, 2017 3 minutes ago, Andrej Vrabčo Vrabec said: http://sprunge.us/jZWD -> only for today syslog from cca 6:00 No, hardware issue and existing since ages: /var/log/syslog.1:Oct 3 09:00:26 localhost kernel: [6266594.040198] usb 4-1: reset high-speed USB device number 38 using sunxi-ehci /var/log/syslog.2.gz:Oct 2 09:00:27 localhost kernel: [6180195.100167] usb 4-1: reset high-speed USB device number 38 using sunxi-ehci /var/log/syslog.6.gz:Sep 28 09:00:27 localhost kernel: [5834595.040136] usb 4-1: reset high-speed USB device number 35 using sunxi-ehci The kernel enumerates the devices and increases the number after a total device loss (since 'new device'). That's why it today went from 'usb 4-1: reset high-speed USB device number 2' to 'usb 4-1: reset high-speed USB device number 3' (2 --> 3) but as can be seen above prior to the kernel update this also happened all the time since it even incremented the counter up to 38 (so 36 times lost the disk completely since last reboot before). Check cable/contacts, the issue lives there most probably if the disk is externally powered.
tkaiser Posted October 5, 2017 Posted October 5, 2017 BTW: 6180195 / 3600 / 24 = 71.5 days until last reboot and 36 times disk disappeared from the bus. It happened every 2nd day on average
Recommended Posts