Custom Query (1456 matches)

At some point in time (I'm not sure when), it looks like either smartmontools or FreeBSD (I'm not sure which) appears to have begun using the wrong time when doing self-tests.

More precisely: when a self-test is run (ex. smartctl -t short /dev/ada0), the completion time as shown in the SMART self-test log is extremely distant/far off compared to attribute 9 Power_On_Hours.

This problem is reproducible across multiple drive models (Samsung SSD 840 EVO, WD3003FZEX, WD1003FZEX).

I cannot reproduce this problem on Windows XP Pro SP3 (32-bit) using smartmontools 6.3.

I'll provide some hard data, including -r ataioctl,2 output, from multiple drives on a system, and show actual proof of this problem.

I keep going back and forth trying to figure out if this is a smartmontools bug or a FreeBSD CAM/kernel bug (and if it's the latter, it manifests itself in an extremely bizarre way).

Rolling back to smartmontools 6.2 does not fix the problem.

Function: os_freebsd.cpp/freebsd_smart_interface::autodetect_smart_device()

line 1800

Relevant part of the code:

1796	        // now check if we are working with USB device, see umass.c
1797	        if(strcmp(ccb.cpi.dev_name,"umass-sim") == 0) { // USB device found
1798	          usbdevlist(bus,vendor_id, product_id, version);
1799	          int bus=ccb.cpi.unit_number; // unit_number will match umass number
1800	          cam_close_device(cam_dev);
1801	          if(usbdevlist(bus,vendor_id, product_id, version)){
1802	            const char * usbtype = get_usb_dev_type_by_id(vendor_id, product_id, version);
1803	            if (!usbtype)
1804	              return false;
1805	            return get_sat_device(usbtype, new freebsd_scsi_device(this, name, ""));
1806	          }
1807	        }
1808	#if FREEBSDVER > 800100
1809	        // check if we have ATA device connected to CAM (ada)
1810	        if(ccb.cpi.protocol == PROTO_ATA){
1811	          cam_close_device(cam_dev);
1812	          return new freebsd_atacam_device(this, name, "");
1813	        }
1814	#endif
1815	        // close cam device, we don`t need it anymore
1816	        cam_close_device(cam_dev);

The first cam_close_device(cam_dev) is called within if(strcmp(ccb.cpi.dev_name,"umass-sim") == 0) block. But such block may not end with return

In such case the second cam_close_device(cam_dev) will be called on line 1811 or 1816.

Double-close may cause several problems including memory corruption.

It seems to be a simple typo. It's Alex's code (AFAIK), so I hope he can correct it easily. If he will not repair it then I will assign this ticket later to myself.

Credits to Axel Beckert and Petr Salinger for it's help with problem identification and partial analysis. See also ​http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=561113

This issue is similar to Ticket #137, but we are already running the latest Firmware Version: 4PC10362 for Intel 320 Series. And we just upgrade to smartctl 5.42, I cannot reproduce the issue with smartctl 5.40. This seems likely to be a FW issue, but I need the details of what change in smartctl is causing the issue now, so I can open a ticket with intel.

Also UDMA_CRC_Error_Count counts sometimes during the test.

This is the kernel error:

ata5.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x6 frozen ata5.00: cmd 61/40:00:2d:c1:03/00:00:00:00:00/40 tag 0 ncq 32768 out

res 40/00:00:00:00:00/00:00:00:00:00/a0 Emask 0x4 (timeout)

ata5.00: status: { DRDY } ata5: hard resetting link ata5: SATA link up 3.0 Gbps (SStatus 123 SControl 300) ata5.00: configured for UDMA/133 ata5: EH complete SCSI device sdb: 156301488 512-byte hdwr sectors (80026 MB) sdb: Write Protect is off sdb: Mode Sense: 00 3a 00 00 SCSI device sdb: drive cache: write back ata5.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen ata5.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0

res 40/00:04:de:e3:50/00:00:09:00:00/40 Emask 0x4 (timeout)

ata5.00: status: { DRDY } ata5: hard resetting link ata5: SATA link up 3.0 Gbps (SStatus 123 SControl 300) ata5.00: configured for UDMA/133 sd 4:0:0:0: timing out command, waited 60s ata5: EH complete sd 4:0:0:0: timing out command, waited 60s SCSI device sdb: 156301488 512-byte hdwr sectors (80026 MB) sdb: Write Protect is off sdb: Mode Sense: 00 3a 00 00 SCSI device sdb: drive cache: write back ata5.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x6 frozen ata5.00: cmd 61/30:00:0e:e4:af/00:00:01:00:00/40 tag 0 ncq 24576 out

res 40/00:0c:5e:70:ac/00:00:06:00:00/40 Emask 0x4 (timeout)

ata5.00: status: { DRDY } ata5: hard resetting link ata5: SATA link up 3.0 Gbps (SStatus 123 SControl 300) ata5.00: configured for UDMA/133 ata5: EH complete SCSI device sdb: 156301488 512-byte hdwr sectors (80026 MB) sdb: Write Protect is off sdb: Mode Sense: 00 3a 00 00 SCSI device sdb: drive cache: write back ata6.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen ata6.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0

res 40/00:00:00:4f:c2/00:00:00:00:00/00 Emask 0x4 (timeout)

ata6.00: status: { DRDY } ata6: hard resetting link ata6: SATA link up 3.0 Gbps (SStatus 123 SControl 300) ata6.00: configured for UDMA/133 sd 5:0:0:0: timing out command, waited 60s ata6: EH complete SCSI device sdc: 156301488 512-byte hdwr sectors (80026 MB) sdc: Write Protect is off sdc: Mode Sense: 00 3a 00 00 SCSI device sdc: drive cache: write back sd 5:0:0:0: timing out command, waited 60s ata6: EH complete SCSI device sdc: 156301488 512-byte hdwr sectors (80026 MB) sdc: Write Protect is off sdc: Mode Sense: 00 3a 00 00 SCSI device sdc: drive cache: write back sd 5:0:0:0: timing out command, waited 60s ata5.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x6 frozen ata5.00: cmd 61/08:00:f6:1d:b0/00:00:01:00:00/40 tag 0 ncq 4096 out

res 40/00:0c:9e:04:ae/00:00:06:00:00/40 Emask 0x4 (timeout)

ata5.00: status: { DRDY } ata5: hard resetting link ata5: SATA link up 3.0 Gbps (SStatus 123 SControl 300) ata5.00: configured for UDMA/133 ata5: EH complete SCSI device sdb: 156301488 512-byte hdwr sectors (80026 MB) sdb: Write Protect is off sdb: Mode Sense: 00 3a 00 00 SCSI device sdb: drive cache: write back

I can reproduce this much faster by running the following script:

#!/bin/bash

while [ 1 ]; do

echo date; time ./smartctl -a -d ata /dev/sdb > /dev/null time ./smartctl -a -d ata /dev/sdc > /dev/null echo date echo ""

done

./smartctl -a -d ata /dev/sdb smartctl 5.42 2011-10-20 r3458 [i686-linux-2.6.18.solos38] (local build) Copyright (C) 2002-11 by Bruce Allen, ​http://smartmontools.sourceforge.net

START OF INFORMATION SECTION

Model Family: Intel 320 Series SSDs Device Model: INTEL SSDSA2CW080G3 Serial Number: CVPR112401SR080BGN LU WWN Device Id: 5 001517 959516ee6 Firmware Version: 4PC10362 User Capacity: 80,026,361,856 bytes [80.0 GB] Sector Size: 512 bytes logical/physical Device is: In smartctl database [for details use: -P show] ATA Version is: 8 ATA Standard is: ATA-8-ACS revision 4 Local Time is: Thu Feb 16 11:23:03 2012 EST SMART support is: Available - device has SMART capability. SMART support is: Enabled

START OF READ SMART DATA SECTION

SMART overall-health self-assessment test result: PASSED

General SMART Values: Offline data collection status: (0x00) Offline data collection activity

was never started. Auto Offline Data Collection: Disabled.

Self-test execution status: ( 0) The previous self-test routine completed

without error or no self-test has ever been run.

Total time to complete Offline data collection: ( 1) seconds. Offline data collection capabilities: (0x75) SMART execute Offline immediate.

No Auto Offline data collection support. Abort Offline collection upon new command. No 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: ( 1) minutes. Conveyance self-test routine recommended polling time: ( 1) minutes. SCT capabilities: (0x003d) SCT Status supported.

SCT Error Recovery Control supported. SCT Feature Control supported. SCT Data Table supported.

SMART Attributes Data Structure revision number: 5 Vendor Specific SMART Attributes with Thresholds: ID# ATTRIBUTE_NAME FLAG VALUE WORST THRESH TYPE UPDATED WHEN_FAILED RAW_VALUE

3 Spin_Up_Time 0x0020 100 100 000 Old_age Offline - 0 4 Start_Stop_Count 0x0030 100 100 000 Old_age Offline - 0 5 Reallocated_Sector_Ct 0x0032 100 100 000 Old_age Always - 0 9 Power_On_Hours 0x0032 100 100 000 Old_age Always - 2662

12 Power_Cycle_Count 0x0032 100 100 000 Old_age Always - 504

170 Reserve_Block_Count 0x0033 100 100 010 Pre-fail Always - 0 171 Program_Fail_Count 0x0032 100 100 000 Old_age Always - 0 172 Erase_Fail_Count 0x0032 100 100 000 Old_age Always - 0 183 Runtime_Bad_Block 0x0030 100 100 000 Old_age Offline - 0 184 End-to-End_Error 0x0032 100 100 090 Old_age Always - 0 187 Reported_Uncorrect 0x0032 100 100 000 Old_age Always - 0 192 Unsafe_Shutdown_Count 0x0032 100 100 000 Old_age Always - 499 199 UDMA_CRC_Error_Count 0x0030 100 100 000 Old_age Offline - 0 225 Host_Writes_32MiB 0x0032 100 100 000 Old_age Always - 16940 226 Workld_Media_Wear_Indic 0x0032 100 100 000 Old_age Always - 257 227 Workld_Host_Reads_Perc 0x0032 100 100 000 Old_age Always - 59 228 Workload_Minutes 0x0032 100 100 000 Old_age Always - 159763 232 Available_Reservd_Space 0x0033 100 100 010 Pre-fail Always - 0 233 Media_Wearout_Indicator 0x0032 100 100 000 Old_age Always - 0 241 Host_Writes_32MiB 0x0032 100 100 000 Old_age Always - 16940 242 Host_Reads_32MiB 0x0032 100 100 000 Old_age Always - 24461

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 Vendor (0x45) Completed without error 00% 2662 -

Note: selective self-test log revision number (0) not 1 implies that no selective self-test has ever been run SMART Selective self-test log data structure revision number 0 Note: revision number not 1 implies that no selective self-test has ever been run

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.

/smartctl -a -d ata /dev/sdc smartctl 5.42 2011-10-20 r3458 [i686-linux-2.6.18.solos38] (local build) Copyright (C) 2002-11 by Bruce Allen, ​http://smartmontools.sourceforge.net

START OF INFORMATION SECTION

Model Family: Intel 320 Series SSDs Device Model: INTEL SSDSA2CW080G3 Serial Number: CVPR112407BG080BGN LU WWN Device Id: 5 001517 959518c16 Firmware Version: 4PC10362 User Capacity: 80,026,361,856 bytes [80.0 GB] Sector Size: 512 bytes logical/physical Device is: In smartctl database [for details use: -P show] ATA Version is: 8 ATA Standard is: ATA-8-ACS revision 4 Local Time is: Thu Feb 16 11:25:21 2012 EST SMART support is: Available - device has SMART capability. SMART support is: Enabled

START OF READ SMART DATA SECTION

SMART overall-health self-assessment test result: PASSED

General SMART Values: Offline data collection status: (0x00) Offline data collection activity

was never started. Auto Offline Data Collection: Disabled.

Self-test execution status: ( 0) The previous self-test routine completed

without error or no self-test has ever been run.

Total time to complete Offline data collection: ( 1) seconds. Offline data collection capabilities: (0x75) SMART execute Offline immediate.

No Auto Offline data collection support. Abort Offline collection upon new command. No 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: ( 1) minutes. Conveyance self-test routine recommended polling time: ( 1) minutes. SCT capabilities: (0x003d) SCT Status supported.

SCT Error Recovery Control supported. SCT Feature Control supported. SCT Data Table supported.

SMART Attributes Data Structure revision number: 5 Vendor Specific SMART Attributes with Thresholds: ID# ATTRIBUTE_NAME FLAG VALUE WORST THRESH TYPE UPDATED WHEN_FAILED RAW_VALUE

3 Spin_Up_Time 0x0020 100 100 000 Old_age Offline - 0 4 Start_Stop_Count 0x0030 100 100 000 Old_age Offline - 0 5 Reallocated_Sector_Ct 0x0032 100 100 000 Old_age Always - 0 9 Power_On_Hours 0x0032 100 100 000 Old_age Always - 2665

12 Power_Cycle_Count 0x0032 100 100 000 Old_age Always - 505

170 Reserve_Block_Count 0x0033 100 100 010 Pre-fail Always - 0 171 Program_Fail_Count 0x0032 100 100 000 Old_age Always - 0 172 Erase_Fail_Count 0x0032 100 100 000 Old_age Always - 0 183 Runtime_Bad_Block 0x0030 100 100 000 Old_age Offline - 0 184 End-to-End_Error 0x0032 100 100 090 Old_age Always - 0 187 Reported_Uncorrect 0x0032 100 100 000 Old_age Always - 0 192 Unsafe_Shutdown_Count 0x0032 100 100 000 Old_age Always - 500 199 UDMA_CRC_Error_Count 0x0030 100 100 000 Old_age Offline - 2 225 Host_Writes_32MiB 0x0032 100 100 000 Old_age Always - 36272 226 Workld_Media_Wear_Indic 0x0032 100 100 000 Old_age Always - 429 227 Workld_Host_Reads_Perc 0x0032 100 100 000 Old_age Always - 15 228 Workload_Minutes 0x0032 100 100 000 Old_age Always - 159917 232 Available_Reservd_Space 0x0033 100 100 010 Pre-fail Always - 0 233 Media_Wearout_Indicator 0x0032 100 100 000 Old_age Always - 0 241 Host_Writes_32MiB 0x0032 100 100 000 Old_age Always - 36272 242 Host_Reads_32MiB 0x0032 100 100 000 Old_age Always - 6808

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 Vendor (0x4d) Completed without error 00% 2665 -

Note: selective self-test log revision number (0) not 1 implies that no selective self-test has ever been run SMART Selective self-test log data structure revision number 0 Note: revision number not 1 implies that no selective self-test has ever been run

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.