Project

General

Profile

Bug #23223

bad sectors on VM

Added by Terence Agius over 3 years ago. Updated over 2 years ago.

Status:
Closed
Priority:
No priority
Assignee:
Alexander Motin
Category:
OS
Target version:
Seen in:
Severity:
New
Reason for Closing:
Reason for Blocked:
Need additional information
Needs QA:
Yes
Needs Doc:
Yes
Needs Merging:
Yes
Needs Automation:
No
Support Suite Ticket:
n/a
Hardware Configuration:
ChangeLog Required:
No

Description

I am having an issue on a ZVOL assigned on a zfs mirror on 2 x 960GB SSD drives

When formatting disk in a windows 2008 server virtual machine which has an iSCSI drive attached (which is the ZVOL mentioned above) it find 50% of the disk as bad sectors!

How is this possible?


Related issues

Related to FreeNAS - Bug #24772: corrupt disk only ssdClosed: Cannot reproduce2017-06-22

History

#1 Updated by Terence Agius over 3 years ago

  • File debug-adi-nas2-20170409104935.txz added

#2 Avatar?id=14398&size=24x24 Updated by Kris Moore over 3 years ago

  • Assignee set to Alexander Motin

Over for investigation

#3 Updated by Alexander Motin over 3 years ago

  • Status changed from Unscreened to Screened

That is odd. Could you describe your setup a little better? Does Windows itself connects to iSCSI target, or it goes through virtual machine disk emulation?

I see some of your iSCSI extents have 2048 byte blocks. That is unusual, so I suppose you know what you are doing and why, and you are sure that all software you are using support that. Are you accessing one of them in this problematic setup?

#4 Updated by Terence Agius over 3 years ago

In general I always use the same setup and this is the first time I have this issue

Virtual Machine connects directly to the NAS via the Windows iScsi driver. I also made a mistake in descritpion
it is a RAID-Z2 setup using 6 x 960GB SSD and to my knowledge I used the allocated amount approx 2.6TB (I did not over provision)

If it is any help, the performance has not been up to par

There is another update. last night I changed parameters on the iscsi options for the particular connection (Extents). I changed the logical blocksize from 2048 to 512 and since then I lost all data on a secondary connection (nas02data)

#5 Updated by Alexander Motin over 3 years ago

  • Status changed from Screened to Closed: User Config Issue

I see your tank/NAS02MAILDATA ZVOL uses 2KB blocks. This is extremely space-inefficient to store 2KB blocks on your RAIDZ2 of 6 disks, since the last by design reaches planned space efficiency only for blocks of 16KB (4KB*(6-2)), but respecting compression, 32KB and higher is recommended. As result of this, your ZVOL could take 5-6 times more space then you expected, and as result overflowing pool, and possibly causing errors you are talking about. The fact that compression is disabled there, does not help with space efficiency either.

Changing block size probably confused the initiator. While data may still be intact, initiator may be unable to address them properly due to different block size. The proper way would be to create different extent and move the data.

#6 Updated by Terence Agius over 3 years ago

I use blocks the same size as the sector format on the disk for performance purposes; what is the relationship between raid/blocksize and space? I must plead my ignorance in this regard

#7 Updated by Alexander Motin over 3 years ago

Terence Agius wrote:

I use blocks the same size as the sector format on the disk for performance purposes;

Using the same size indeed may help with short random write performance. But going that low as you did heavily hurt linear operation performance due to huge CPU overhead and data fragmentation. FreeNAS by default sets ZVOL block size to value we believe optimal for specific pool configuration. There is a reason why it is hidden on Advanced options page.

what is the relationship between raid/blocksize and space? I must plead my ignorance in this regard

FreeNAS by default never writes less then 4KB of data to single disk to allow you later replace disks with newer models which mostly have 4KB sectors. RAIDZ, unlike RAID5, never overwrites data to avoid RAID5 write hole. It writes every user block separately. It means that for your 6-disk RAIDZ2 minimal space efficient write will be to write 4KB to each of 4 data disks, plus additional 8KB of parity to parity disks. If you set ZVOL block size to 2KB, then ZFS had to first round those 2KB up to 4KB and then add 8KB of parity. As result space efficiency of your pool will be 17% instead of expected 67%, plus you loose any benefits from enabling compression.

#8 Updated by Alexander Motin over 3 years ago

If you need high performance and efficiency in storing small blocks, you should possibly reconfigure your pool into set of mirrors instead RAIDZ. For 4KB block three double mirrors would give you 50% space efficiency with slightly lower reliablity, while two tripple mirrors would give you 33% space efficiency with much higher reliability then you have now, and any of them would give you much higher IOPS performance. While generally we recommend block size to start from 16KB to minimize CPU overhead and allow compression.

#9 Updated by Terence Agius over 3 years ago

I have destroyed the volume and recreated it still as a raid-z2
this time I have used lz4 compression and 128k blocks for both zvols
I am also using 512 LBS
I have also allocated less space than before
yet issue is worse than before; now both volumes can't be used at the same time
any ideas?

#10 Updated by Alexander Motin over 3 years ago

Sorry, but my crystal ball is not functional today. It would help if you describe with more details what exactly does not work.

#11 Updated by Terence Agius over 3 years ago

lol
ok

I created 2 zvols
I created 2 extents/targets one for each
I connected each target to a separate VM using windows 2008
I quick formatted each drive
I started copying files to both drives simultaneously to each iscsi target
drives disappears after about 20Gbytes of copying
Then I tried formatting one of the drives, and I got the bad sectors

#12 Updated by Alexander Motin over 3 years ago

  • Status changed from Closed: User Config Issue to Investigation

I expected to see there some errors reported by Windows or on FreeNAS console. You may also try to set kern.cam.ctl.debug sysctl to 1 to make SCSI target log to console all errors it sends to initiators.

#13 Updated by Terence Agius over 3 years ago

I put debug option in freenas
I started a format on one drive
and I started a copy on the other drive
after about 30 minutes copy stopped on windows with a scandisk warning (disk has some errors should I check drive or continue) while format gave error that bad sectors were found (all disk)
There are no errors displayed on freenas

There are errors and warning on both Windows 2008
MPIO errors -

man Connection to the target was lost. The initiator will attempt to retry the connection.
The initiator could not send an iSCSI PDU. Error status is given in the dump data.

\Device\MPIODisk7 is currently in a degraded state. One or more paths have failed, though the process is now complete.

The initiator could not send an iSCSI PDU. Error status is given in the dump data.

#14 Updated by Alexander Motin over 3 years ago

From this description it sounds like bad sectors were caused not by SCSI target error, but by iSCSI disconnect. If there is nothing in FreeNAS logs about this disconnect, you could possibly try to increase value of kern.cam.ctl.iscsi.debug sysctl to get more info about iSCSI operation.

#15 Updated by Terence Agius over 3 years ago

I will do the tests; but something is not right

there are 2 questions;
1) every time this issue happens I loose my browser session with the nas
2) I have no issue with other zvol disks which use standard ide drives and are in a mirror

#16 Updated by Alexander Motin over 3 years ago

Terence Agius wrote:

there are 2 questions;
1) every time this issue happens I loose my browser session with the nas

How does it look and how do you recover from that? Can you ping the system when it happens?

2) I have no issue with other zvol disks which use standard ide drives and are in a mirror

It may be result of very different speeds provided by SSD pool stress the system in very different way. Though it does not explain much, it is not a valid reason.

#17 Updated by Terence Agius over 3 years ago

Yes I thought about it myself
I tried again several times overnight, and had no issues
No errors or warnings

This would indicate some disconnection issue during day when network switches are busier
But why should this bring the whole NAS down?

The connection between ZVOLS and iScsi on VMs use 2 VLANS which nobody has access to

I have no idea what to do

#18 Updated by Alexander Motin over 3 years ago

If you can reproduce this scenario on demand, I would try to do it while being logged in to FreeNAS console and monitoring what is going on with the NAS itself (`top -SHIz`, `systat -vm 1`, `gstat -I 1s -p`, etc) and its network connectivity (pinged different hosts, etc).

#19 Updated by Terence Agius over 3 years ago

OK

Meanwhile I have tuned some parameters in sysctl which should help a little
I have also enabled jumbo frames on the switches
will let you know as soon as I can reproduce issue consistently

#20 Updated by Terence Agius over 3 years ago

I have done more tests
and managed to reproduce issue twice
now I am getting info in freenas log

Apr 12 14:17:16 adi-nas2 (0:6:2/3): MAINTENANCE (IN). CDB: a3 0a 00 00 00 00 00 00 00 04 00 00 Tag: 0x3cef1b00/0
Apr 12 14:17:16 adi-nas2 (0:6:2/3): CTL Status: SCSI Error
Apr 12 14:17:16 adi-nas2 (0:6:2/3): SCSI Status: Check Condition
Apr 12 14:17:16 adi-nas2 (0:6:2/3): SCSI sense: UNIT ATTENTION asc:29,1 (Power on occurred)
Apr 12 14:17:17 adi-nas2 (0:3:0/0): MAINTENANCE (IN). CDB: a3 0a 00 00 00 00 00 00 00 04 00 00 Tag: 0x8a5c0000/0
Apr 12 14:17:17 adi-nas2 (0:3:0/0): CTL Status: SCSI Error
Apr 12 14:17:17 adi-nas2 (0:3:0/0): SCSI Status: Check Condition
Apr 12 14:17:17 adi-nas2 (0:3:0/0): SCSI sense: UNIT ATTENTION asc:29,1 (Power on occurred)
Apr 12 14:17:17 adi-nas2 ntpd2219: ntpd 4.2.8p9-a (1): Starting
Apr 12 14:17:21 adi-nas2 WARNING: 192.168.50.11 (iqn.1991-05.com.microsoft:adi-ms2.adi.local): no ping reply (NOP-Out) after 5 seconds; dropping connection
Apr 12 14:17:21 adi-nas2 (0:6:0/4294967295): Task Action: I_T Nexus Reset
Apr 12 14:17:21 adi-nas2 (0:6:0/4294967295): CTL Status: Command Completed Successfully
Apr 12 14:17:22 adi-nas2 root: /etc/rc: WARNING: failed precmd routine for vmware_guestd
Apr 12 14:17:22 adi-nas2 WARNING: 192.168.32.10 (iqn.1991-05.com.microsoft:adi-fs1.adi.local): no ping reply (NOP-Out) after 5 seconds; dropping connection
Apr 12 14:17:22 adi-nas2 (0:3:0/0): Task Action: I_T Nexus Reset
Apr 12 14:17:22 adi-nas2 (0:3:0/0): CTL Status: Command Completed Successfully
Apr 12 14:17:34 adi-nas2 (0:6:2/3): READ. CDB: 28 00 00 60 d5 c8 00 00 08 00 Tag: 0xcbf11b00/1
Apr 12 14:17:34 adi-nas2 (0:6:2/3): CTL Status: SCSI Error
Apr 12 14:17:34 adi-nas2 (0:6:2/3): SCSI Status: Check Condition
Apr 12 14:17:34 adi-nas2 (0:6:2/3): SCSI sense: UNIT ATTENTION asc:29,7 (I_T nexus loss occurred)
Apr 12 14:17:37 adi-nas2 (0:4:0/1): MAINTENANCE (IN). CDB: a3 0a 00 00 00 00 00 00 00 04 00 00 Tag: 0xb8b70200/0
Apr 12 14:17:37 adi-nas2 (0:4:0/1): CTL Status: SCSI Error
Apr 12 14:17:37 adi-nas2 (0:4:0/1): SCSI Status: Check Condition
Apr 12 14:17:37 adi-nas2 (0:4:0/1): SCSI sense: UNIT ATTENTION asc:29,1 (Power on occurred)
Apr 12 14:17:40 adi-nas2 (1:4:0/1): MAINTENANCE (IN). CDB: a3 0a 00 00 00 00 00 00 00 04 00 00 Tag: 0xb7b70200/0
Apr 12 14:17:40 adi-nas2 (1:4:0/1): CTL Status: SCSI Error
Apr 12 14:17:40 adi-nas2 (1:4:0/1): SCSI Status: Check Condition
Apr 12 14:17:40 adi-nas2 (1:4:0/1): SCSI sense: UNIT ATTENTION asc:29,1 (Power on occurred)
Apr 12 14:17:40 adi-nas2 (1:6:2/3): MAINTENANCE (IN). CDB: a3 0a 00 00 00 00 00 00 00 04 00 00 Tag: 0xdcee1b00/0
Apr 12 14:17:40 adi-nas2 (1:6:2/3): CTL Status: SCSI Error
Apr 12 14:17:40 adi-nas2 (1:6:2/3): SCSI Status: Check Condition
Apr 12 14:17:40 adi-nas2 (1:6:2/3): SCSI sense: UNIT ATTENTION asc:29,1 (Power on occurred)
Apr 12 14:17:43 adi-nas2 alert.py: [common.pipesubr:66] Popen()ing: /usr/local/sbin/dmidecode -s system-product-name
Apr 12 14:17:43 adi-nas2 alert.py: [common.pipesubr:66] Popen()ing: /usr/local/sbin/dmidecode -s baseboard-product-name
Apr 12 14:18:00 adi-nas2 (0:3:0/0): TEST UNIT READY. CDB: 00 00 00 00 00 00 Tag: 0xac5c0000/0
Apr 12 14:18:00 adi-nas2 (0:3:0/0): CTL Status: SCSI Error
Apr 12 14:18:00 adi-nas2 (0:3:0/0): SCSI Status: Check Condition
Apr 12 14:18:00 adi-nas2 (0:3:0/0): SCSI sense: UNIT ATTENTION asc:29,7 (I_T nexus loss occurred)
Apr 12 14:18:03 adi-nas2 (2:3:0/0): MAINTENANCE (IN). CDB: a3 0a 00 00 00 00 00 00 00 04 00 00 Tag: 0x8a5c0000/0
Apr 12 14:18:03 adi-nas2 (2:3:0/0): CTL Status: SCSI Error
Apr 12 14:18:03 adi-nas2 (2:3:0/0): SCSI Status: Check Condition
Apr 12 14:18:03 adi-nas2 (2:3:0/0): SCSI sense: UNIT ATTENTION asc:29,1 (Power on occurred)
Apr 12 14:18:03 adi-nas2 (1:3:0/0): MAINTENANCE (IN). CDB: a3 0a 00 00 00 00 00 00 00 04 00 00 Tag: 0x885c0000/0
Apr 12 14:18:03 adi-nas2 (1:3:0/0): CTL Status: SCSI Error
Apr 12 14:18:03 adi-nas2 (1:3:0/0): SCSI Status: Check Condition
Apr 12 14:18:03 adi-nas2 (1:3:0/0): SCSI sense: UNIT ATTENTION asc:29,1 (Power on occurred)
Apr 12 14:18:03 adi-nas2 (0:5:1/2): MAINTENANCE (IN). CDB: a3 0a 00 00 00 00 00 00 00 04 00 00 Tag: 0x1b400000/0
Apr 12 14:18:03 adi-nas2 (0:5:1/2): CTL Status: SCSI Error
Apr 12 14:18:03 adi-nas2 (0:5:1/2): SCSI Status: Check Condition
Apr 12 14:18:03 adi-nas2 (0:5:1/2): SCSI sense: UNIT ATTENTION asc:29,1 (Power on occurred)
Apr 12 14:18:03 adi-nas2 (1:5:1/2): MAINTENANCE (IN). CDB: a3 0a 00 00 00 00 00 00 00 04 00 00 Tag: 0xde400000/0
Apr 12 14:18:03 adi-nas2 (1:5:1/2): CTL Status: SCSI Error
Apr 12 14:18:03 adi-nas2 (1:5:1/2): SCSI Status: Check Condition
Apr 12 14:18:03 adi-nas2 (1:5:1/2): SCSI sense: UNIT ATTENTION asc:29,1 (Power on occurred)
Apr 12 14:18:24 adi-nas2 WARNING: 192.168.50.10 (iqn.1991-05.com.microsoft:adi-fs1.adi.local): no ping reply (NOP-Out) after 5 seconds; dropping connection
Apr 12 14:18:24 adi-nas2 (1:3:0/0): Task Action: I_T Nexus Reset
Apr 12 14:18:24 adi-nas2 (1:3:0/0): CTL Status: Command Completed Successfully
Apr 12 14:18:27 adi-nas2 (1:3:0/0): READ. CDB: 28 00 26 0d a2 f0 00 00 80 00 Tag: 0xc95c0000/1
Apr 12 14:18:27 adi-nas2 (1:3:0/0): CTL Status: SCSI Error
Apr 12 14:18:27 adi-nas2 (1:3:0/0): SCSI Status: Check Condition
Apr 12 14:18:27 adi-nas2 (1:3:0/0): SCSI sense: UNIT ATTENTION asc:29,7 (I_T nexus loss occurred)
Apr 12 14:18:39 adi-nas2 WARNING: 192.168.50.10 (iqn.1991-05.com.microsoft:adi-fs1.adi.local): no ping reply (NOP-Out) after 5 seconds; dropping connection
Apr 12 14:18:39 adi-nas2 (1:3:0/0): Task Action: I_T Nexus Reset
Apr 12 14:18:39 adi-nas2 (1:3:0/0): CTL Status: Command Completed Successfully
Apr 12 14:18:42 adi-nas2 (1:3:0/0): READ. CDB: 28 00 26 0d 7c 88 00 00 80 00 Tag: 0xf05c0000/1
Apr 12 14:18:42 adi-nas2 (1:3:0/0): CTL Status: SCSI Error
Apr 12 14:18:42 adi-nas2 (1:3:0/0): SCSI Status: Check Condition
Apr 12 14:18:42 adi-nas2 (1:3:0/0): SCSI sense: UNIT ATTENTION asc:29,7 (I_T nexus loss occurred)

Hope this helps

#21 Updated by Alexander Motin over 3 years ago

This shows link disconnection, probably due to some networking issue, but does not give much clues about the cause. Hasving full tcpdump for the time of disconnection could possibly be more informative.

#22 Updated by Terence Agius over 3 years ago

I have been absent because I needed to verify if there were any network issues
And there are none

I have connected the nas directly to server which hosts the virtual machines. I have even used a new network card which is identical to the card used on the nas. Even the cables are brand new

I have also tested the ssd drives which result in no error

So this seems to be an issue on or in freenas.

#23 Updated by Alexander Motin over 3 years ago

I haven't told that networking can not be on FreeNAS, but so far I haven nothing to start from.

#24 Updated by Terence Agius over 3 years ago

OK what can I provide?
Do you have tests systems were you can reproduce the problem?
As things are this NAS is useless

#25 Updated by Alexander Motin over 3 years ago

If I could reproduce the problem, it would not exist. I haven't tested Windows for some time, but I'll do it again at some point.

#26 Updated by Alexander Motin about 3 years ago

  • Related to Bug #24772: corrupt disk only ssd added

#27 Updated by Alexander Motin about 3 years ago

  • Seen in changed from Unspecified to 9.10.2-U2

#28 Updated by Dru Lavigne about 3 years ago

  • Status changed from Investigation to 46

Sasha: is there anything we can fix here?

#29 Updated by Alexander Motin about 3 years ago

  • Status changed from 46 to Investigation
  • Target version set to 11.2-BETA1

There are plenty of report with alike symptoms but insufficient diagnostics to guess the causes. I keep this ticket to return to this problem one day when I have time.

#30 Avatar?id=14398&size=24x24 Updated by Kris Moore over 2 years ago

  • Target version changed from 11.2-BETA1 to 11.3

#31 Updated by Dru Lavigne over 2 years ago

  • Status changed from Investigation to Closed
  • Target version changed from 11.3 to N/A
  • Private changed from Yes to No
  • Reason for Blocked set to Need additional information

Sasha: closing this one out. We can open again if you find time and useful diagnostics.

#32 Updated by Dru Lavigne over 2 years ago

  • File deleted (debug-adi-nas2-20170409104935.txz)

Also available in: Atom PDF