Bug 177536 - [zfs] zfs livelock (deadlock) with high write-to-disk load
Summary: [zfs] zfs livelock (deadlock) with high write-to-disk load
Status: Closed FIXED
Alias: None
Product: Base System
Classification: Unclassified
Component: kern (show other bugs)
Version: Unspecified
Hardware: Any Any
: Normal Affects Only Me
Assignee: freebsd-fs (Nobody)
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2013-04-01 08:50 UTC by Martin Birgmeier
Modified: 2014-08-15 10:34 UTC (History)
2 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Martin Birgmeier 2013-04-01 08:50:00 UTC
I am using a program whose purpose is to efficiently copy disk partitions to image files stored on zfs. Multiple backups in time are kept using snapshots of the file system on which these image files reside.

The program uses mmap(2) to map an image file into memory, then reads the disk partition to be backup up in fixed-size blocks (default 128k). For each block, it first compares the already stored data with the new one using memcmp(3), and does a write using memcpy(3) only if there is a mismatch. In this way, only the blocks which have changed are really written, keeping the zfs snapshots small.

The files mapped in this way are typically several 100GB in size.

Problem: Every now and then, the above operation results in a live lock (deadlock) of the zfs server. Specifically today, the following could be observed:
- the program described above did not proceed any further after having read/written several dozen GB of data
- an 'ls -l' in the directory holding the image file was stuck
- there was constant low-level disk activity, but obviously no progress regarding writing data

Some environmental information:
- The pool consists of 6 partitions on 6 SATA disks in raidz2 configuration
- The pool has been created on 2010-10-22 and still has version 14
- / is an UFS partition on one of the SATA disks
- The server has 16 GB RAM
- There are no indications at all of any hardware disk failures
- other zfs file systems on the same pool could still be read/written to
- the machines responded quite normally to many requests including remote login etc.
- a VBoxHeadless session whose host user data was exclusively on the UFS root, with the vbox disk pointing to another raw partition on one of the disks was stuck
- From previous experience I knew that I had to hard reset the machine, since a shutdown would result in zfs sync (?) continuing forever after the UFS sync had already finished (by the way, it was a bad idea not to do a shutdown today, as I destroyed my .zhistory residing on the root UFS partition that way)
- Even if the problem does not occur, when the program described above has finished comparing/copying all blocks, several more minutes pass before the program finally finishes. During that time there is high disk activity.
- Under FreeBSD 8.2, the problem did not occur, and neither the symptoms described in the previous point (long time to program finish).

How-To-Repeat: The problem cannot be easily reproduced; however, from past experience it seems that the following increases the chances of it happening:
- a high write load
- after that write load has already lasted for a while, another rather high read load (possibly on another zfs file system of the same zpool)
- maybe activity on an unrelated partition (non-ZFS) on the disks which also carry the partitions used for the zpool

Unfortunately, most of this is just guesses and hopefully not too misleading.
Comment 1 Andriy Gapon freebsd_committer freebsd_triage 2013-04-01 21:51:14 UTC
Two points:
- the problem may be (partially) fixed in stable/9
- https://wiki.freebsd.org/AvgZfsDeadlockDebug

-- 
Andriy Gapon
Comment 2 Martin Birgmeier 2013-04-02 19:07:05 UTC
Thanks for the pointer - which I knew about, but unfortunately found out
too late that the kernel needs to be compiled with options STACK and/or
options DDB/KDB for this to work.

Could this information be added to that page?

I already recompiled the kernel, but are ambivalent about whether I
should now hope to see the deadlock again... ;-)

One more thing: Could you point me to the SVN revision in head and/or
stable/9 which presumably contains the (partial) fix?

Regards,

Martin

On 04/01/13 22:51, Andriy Gapon wrote:
> Two points:
> - the problem may be (partially) fixed in stable/9
> - https://wiki.freebsd.org/AvgZfsDeadlockDebug
>
Comment 3 Mark Linimon freebsd_committer freebsd_triage 2013-04-03 21:14:16 UTC
Responsible Changed
From-To: freebsd-bugs->freebsd-fs

Over to maintainer(s).
Comment 4 Andriy Gapon freebsd_committer freebsd_triage 2013-04-04 16:31:39 UTC
on 02/04/2013 21:07 Martin Birgmeier said the following:
> Thanks for the pointer - which I knew about, but unfortunately found out
> too late that the kernel needs to be compiled with options STACK and/or
> options DDB/KDB for this to work.
> 
> Could this information be added to that page?

Well, I do not see any reason for people to not include at least STACK in their
kernel.  It's in GENERIC too.  you are the first one to run into this kind of an
issue :-)

> I already recompiled the kernel, but are ambivalent about whether I
> should now hope to see the deadlock again... ;-)
> 
> One more thing: Could you point me to the SVN revision in head and/or
> stable/9 which presumably contains the (partial) fix?

I believe that with r244626 from 2012-12-23 you should not experience hang on
shutdown.

> On 04/01/13 22:51, Andriy Gapon wrote:
>> Two points:
>> - the problem may be (partially) fixed in stable/9
>> - https://wiki.freebsd.org/AvgZfsDeadlockDebug
>>
> 


-- 
Andriy Gapon
Comment 5 Martin Birgmeier 2013-04-27 10:40:16 UTC
So it happened again... same system (9.1.0 release), except that the
kernel has been recompiled with options DDB, KDB, and STACK.

I ran procstat -kk -a (twice). Output can be found in
http://members.aon.at/xyzzy/procstat.-kk.-a.1.gz and
http://members.aon.at/xyzzy/procstat.-kk.-a.2.gz, respectively. I also
started kgdb in script(1), executing "thread apply all bt" in it. Output
can be found in http://members.aon.at/xyzzy/kgdb.thread.apply.all.bt.gz.

More info on the "test case":
- As described in the initial report, / is a UFS GPT partition on one of
6 SATA disks. There exists a zpool "hal.1" on one (other) GPT partition
on each of these disks.
- VirtualBox is run by a user whose home dir is on one of the zfs file
systems.
- First, a big write load to another zfs file system of the same zpool
was started (160 GB copy from a remote machine).
- Then, 3 VBoxHeadless instances were started.
==> livelock on zfs
- procstat run twice, then script + kgdb
- copied output to another machine
- shutdown the hung machine (via "shutdown -p")
==> "some processes would not die"
==> "syncing disks" executes until all zeros, then the system just sits
there with continuous disk activity (obviously from zfs), shutdown does
not proceed further
- hard reset
- on reboot: UFS file system check (no errors), ZFS starts fine and
seems mostly unaffected (except of course that the 160 GB copy is truncated)

An analysis would be appreciated, and also a hint whether I should
switch to stable/9 instead.

Regards,

Martin
Comment 6 Christopher Harrison 2013-07-31 17:36:26 UTC
I have also been hitting this bug with 9.1-RELEASE.    My debugging has 
got me to the point where I am almost certain the problem is in the MPS 
driver in 9.1-RELEASE.   9.0-RELEASE would not deadlock under high I/O 
but 9.1-RELEASE running the mps driver seems too.
Martin:
What device are your drives connected too?   Is it an LSI HBA?

My device is:
mps0@pci0:5:0:0:    class=0x010700 card=0x30c01000 chip=0x00641000 
rev=0x02 hdr=0x00
     vendor     = 'LSI Logic / Symbios Logic'
     device     = 'SAS2116 PCI-Express Fusion-MPT SAS-2 [Meteor]'
     class      = mass storage
     subclass   = SAS
igb2@pci0:4:0:0:    class=0x020000 card=0x10c915d9 chip=0x10c98086 
rev=0x01 hdr=0x00

I have 6 systems in production which experience this deadlock issue.   
The deadlock appears most frequently under high load but I have 
experienced it on systems which are idle too.

     -C
Comment 7 Martin Birgmeier 2013-07-31 20:56:20 UTC
No, this is not an LSI HBA, but rather

atapci0: <JMicron JMB361 UDMA133 controller> port
0xcc00-0xcc07,0xc880-0xc883,0xc800-0xc807,0xc480-0xc483,0xc400-0xc40f
mem 0xfe8fe000-0xfe8fffff irq 18 at device 0.0 on pci3
atapci1: <AHCI SATA controller> at channel -1 on atapci0
atapci1: AHCI v1.00 controller with 2 3Gbps ports, PM supported
ata2: <ATA channel> on atapci1
ata3: <ATA channel> on atapci1
ata4: <ATA channel> at channel 0 on atapci0
atapci2: <ATI IXP700/800 SATA300 controller> port
0xa000-0xa007,0x9000-0x9003,0x8000-0x8007,0x7000-0x7003,0x6000-0x600f
mem 0xfe4ffc00-0xfe4fffff irq 19 at device 17.0 on pci0
atapci2: AHCI v1.20 controller with 6 3Gbps ports, PM supported
ata5: <ATA channel> at channel 0 on atapci2
ata6: <ATA channel> at channel 1 on atapci2
ata7: <ATA channel> at channel 2 on atapci2
ata8: <ATA channel> at channel 3 on atapci2
ata9: <ATA channel> at channel 4 on atapci2
ata10: <ATA channel> at channel 5 on atapci2
ada0 at ata5 bus 0 scbus3 target 0 lun 0
ada1 at ata6 bus 0 scbus4 target 0 lun 0
ada2 at ata7 bus 0 scbus5 target 0 lun 0
ada3 at ata8 bus 0 scbus6 target 0 lun 0
ada4 at ata9 bus 0 scbus7 target 0 lun 0
ada5 at ata10 bus 0 scbus8 target 0 lun 0

(This is just a simple PC motherboard - ASUS M4A89GTD PRO USB3.)

Regards,

Martin
Comment 8 Christopher Harrison 2013-07-31 21:32:02 UTC
what raidz level are you using: raidz2, raid0, raid1
also what are the pool config (see below, my pool is called z):

MOS Configuration:
         version: 28
         name: 'z'
         state: 0
         txg: 214028175
         pool_guid: 5334451366918939808
         hostid: 4266313884
         hostname: 'pisces.biostat.wisc.edu'
         hole_array[0]: 3
         vdev_children: 4
         vdev_tree:
             type: 'root'
             id: 0
             guid: 5334451366918939808
             children[0]:
                 type: 'raidz'
                 id: 0
                 guid: 10192098197416954465
                 nparity: 2
                 metaslab_array: 34
                 metaslab_shift: 37
                 ashift: 9
                 asize: 16003083796480
                 is_log: 0
                 create_txg: 4
                 children[0]:
                     type: 'disk'
                     id: 0
                     guid: 5442684633350386182
                     path: '/dev/da3p1'
                     phys_path: '/dev/da3p1'
                     whole_disk: 1
                     DTL: 2318341
                     create_txg: 4
                 children[1]:
                     type: 'disk'
                     id: 1
                     guid: 4184769488943604229
                     path: '/dev/da2p1'
                     phys_path: '/dev/da2p1'
                     whole_disk: 1
                     DTL: 2318340
                     create_txg: 4
                 children[2]:
                     type: 'disk'
                     id: 2
                     guid: 6673578809124996458
                     path: '/dev/da1p1'
                     phys_path: '/dev/da1p1'
                     whole_disk: 1
                     DTL: 2318358
                     create_txg: 4
                 children[3]:
                     type: 'disk'
                     id: 3
                     guid: 14565784372994613264
                     path: '/dev/da0p1'
                     phys_path: '/dev/da0p1'
                     whole_disk: 1
                     DTL: 2318357
                     create_txg: 4
                 children[4]:
                     type: 'disk'
                     id: 4
                     guid: 17127372890035360647
                     path: '/dev/da6p1'
                     phys_path: '/dev/da6p1'
                     whole_disk: 1
                     DTL: 2318356
                     create_txg: 4
                 children[5]:
                     type: 'disk'
                     id: 5
                     guid: 5667576937780231702
                     path: '/dev/label/disk05'
                     phys_path: '/dev/label/disk05'
                     whole_disk: 1
                     DTL: 26389621
                     create_txg: 4
                 children[6]:
                     type: 'disk'
                     id: 6
                     guid: 16545540667878636920
                     path: '/dev/da5p1'
                     phys_path: '/dev/da5p1'
                     whole_disk: 1
                     DTL: 2318354
                     create_txg: 4
                 children[7]:
                     type: 'disk'
                     id: 7
                     guid: 16180883375304336701
                     path: '/dev/da4p1'
                     phys_path: '/dev/da4p1'
                     whole_disk: 1
                     DTL: 2318353
                     create_txg: 4
             children[1]:
                 type: 'raidz'
                 id: 1
                 guid: 7000405778472969514
                 nparity: 2
                 metaslab_array: 32
                 metaslab_shift: 37
                 ashift: 9
                 asize: 16003083796480
                 is_log: 0
                 create_txg: 4
                 children[0]:
                     type: 'disk'
                     id: 0
                     guid: 11848332905648146086
                     path: '/dev/da10p1'
                     phys_path: '/dev/da10p1'
                     whole_disk: 1
                     DTL: 2318352
                     create_txg: 4
                 children[1]:
                     type: 'disk'
                     id: 1
                     guid: 17180048053682905420
                     path: '/dev/da9p1'
                     phys_path: '/dev/da9p1'
                     whole_disk: 1
                     DTL: 2318351
                     create_txg: 4
                 children[2]:
                     type: 'disk'
                     id: 2
                     guid: 14648362260613207535
                     path: '/dev/da8p1'
                     phys_path: '/dev/da8p1'
                     whole_disk: 1
                     DTL: 2318350
                     create_txg: 4
                 children[3]:
                     type: 'disk'
                     id: 3
                     guid: 2512073543886070959
                     path: '/dev/da7p1'
                     phys_path: '/dev/da7p1'
                     whole_disk: 1
                     DTL: 2318349
                     create_txg: 4
                 children[4]:
                     type: 'disk'
                     id: 4
                     guid: 9213113982598250625
                     path: '/dev/da14p1'
                     phys_path: '/dev/da14p1'
                     whole_disk: 1
                     DTL: 2318348
                     create_txg: 4
                 children[5]:
                     type: 'disk'
                     id: 5
                     guid: 14965308070554000358
                     path: '/dev/da13p1'
                     phys_path: '/dev/da13p1'
                     whole_disk: 1
                     DTL: 2318347
                     create_txg: 4
                 children[6]:
                     type: 'disk'
                     id: 6
                     guid: 8812761598924675500
                     path: '/dev/da12p1'
                     phys_path: '/dev/da12p1'
                     whole_disk: 1
                     DTL: 2318346
                     create_txg: 4
                 children[7]:
                     type: 'disk'
                     id: 7
                     guid: 15539718945154864246
                     path: '/dev/da11p1'
                     phys_path: '/dev/da11p1'
                     whole_disk: 1
                     DTL: 2318345
                     create_txg: 4
             children[2]:
                 type: 'raidz'
                 id: 2
                 guid: 12675549095184402399
                 nparity: 2
                 metaslab_array: 30
                 metaslab_shift: 37
                 ashift: 9
                 asize: 16003083796480
                 is_log: 0
                 create_txg: 4
                 children[0]:
                     type: 'disk'
                     id: 0
                     guid: 9157198169193782917
                     path: '/dev/da16p1'
                     phys_path: '/dev/da16p1'
                     whole_disk: 1
                     DTL: 35652327
                     create_txg: 4
                 children[1]:
                     type: 'disk'
                     id: 1
                     guid: 14494767130322696735
                     path: '/dev/da17p1'
                     phys_path: '/dev/da17p1'
                     whole_disk: 1
                     DTL: 2318365
                     create_txg: 4
                 children[2]:
                     type: 'disk'
                     id: 2
                     guid: 17589735305722725561
                     path: '/dev/da18p1'
                     phys_path: '/dev/da18p1'
                     whole_disk: 1
                     DTL: 2318364
                     create_txg: 4
                 children[3]:
                     type: 'disk'
                     id: 3
                     guid: 14307956723966398718
                     path: '/dev/da19p1'
                     phys_path: '/dev/da19p1'
                     whole_disk: 1
                     DTL: 2318363
                     create_txg: 4
                 children[4]:
                     type: 'disk'
                     id: 4
                     guid: 15965579855708087029
                     path: '/dev/da20p1'
                     phys_path: '/dev/da20p1'
                     whole_disk: 1
                     DTL: 2318362
                     create_txg: 4
                 children[5]:
                     type: 'disk'
                     id: 5
                     guid: 760237787742339099
                     path: '/dev/da21p1'
                     phys_path: '/dev/da21p1'
                     whole_disk: 1
                     DTL: 2318361
                     create_txg: 4
                 children[6]:
                     type: 'disk'
                     id: 6
                     guid: 2500372020986714069
                     path: '/dev/da22p1'
                     phys_path: '/dev/da22p1'
                     whole_disk: 1
                     DTL: 2318360
                     create_txg: 4
                 children[7]:
                     type: 'disk'
                     id: 7
                     guid: 4544065732274116075
                     path: '/dev/label/disk24'
                     phys_path: '/dev/label/disk24'
                     whole_disk: 1
                     DTL: 5572568
                     create_txg: 4
             children[3]:
                 type: 'hole'
                 id: 3
                 guid: 0
                 metaslab_array: 0
                 metaslab_shift: 17
                 ashift: 0
                 asize: 0
                 is_log: 0
                 is_hole: 1

On 07/31/13 14:56, Martin Birgmeier wrote:
> No, this is not an LSI HBA, but rather
>
> atapci0:<JMicron JMB361 UDMA133 controller>  port
> 0xcc00-0xcc07,0xc880-0xc883,0xc800-0xc807,0xc480-0xc483,0xc400-0xc40f
> mem 0xfe8fe000-0xfe8fffff irq 18 at device 0.0 on pci3
> atapci1:<AHCI SATA controller>  at channel -1 on atapci0
> atapci1: AHCI v1.00 controller with 2 3Gbps ports, PM supported
> ata2:<ATA channel>  on atapci1
> ata3:<ATA channel>  on atapci1
> ata4:<ATA channel>  at channel 0 on atapci0
> atapci2:<ATI IXP700/800 SATA300 controller>  port
> 0xa000-0xa007,0x9000-0x9003,0x8000-0x8007,0x7000-0x7003,0x6000-0x600f
> mem 0xfe4ffc00-0xfe4fffff irq 19 at device 17.0 on pci0
> atapci2: AHCI v1.20 controller with 6 3Gbps ports, PM supported
> ata5:<ATA channel>  at channel 0 on atapci2
> ata6:<ATA channel>  at channel 1 on atapci2
> ata7:<ATA channel>  at channel 2 on atapci2
> ata8:<ATA channel>  at channel 3 on atapci2
> ata9:<ATA channel>  at channel 4 on atapci2
> ata10:<ATA channel>  at channel 5 on atapci2
> ada0 at ata5 bus 0 scbus3 target 0 lun 0
> ada1 at ata6 bus 0 scbus4 target 0 lun 0
> ada2 at ata7 bus 0 scbus5 target 0 lun 0
> ada3 at ata8 bus 0 scbus6 target 0 lun 0
> ada4 at ata9 bus 0 scbus7 target 0 lun 0
> ada5 at ata10 bus 0 scbus8 target 0 lun 0
>
> (This is just a simple PC motherboard - ASUS M4A89GTD PRO USB3.)
>
> Regards,
>
> Martin
>
Comment 9 Martin Birgmeier 2013-08-01 06:20:50 UTC
It is raidz2, using gpt partitions each covering half of six 2 TB disks.
The remainder of these disks are mostly unused, with one containing a
small UFS root for booting, and the others some small partitions which
are used for various VirtualBox instances.

Regards,

Martin

On 07/31/13 22:32, Christopher D. Harrison wrote:
> what raidz level are you using: raidz2, raid0, raid1
> also what are the pool config (see below, my pool is called z):
>
> MOS Configuration:
>         version: 28
>         name: 'z'
>         state: 0
>         txg: 214028175
>         pool_guid: 5334451366918939808
>         hostid: 4266313884
>         hostname: 'pisces.biostat.wisc.edu'
>         hole_array[0]: 3
>         vdev_children: 4
>         vdev_tree:
>             type: 'root'
>             id: 0
>             guid: 5334451366918939808
>             children[0]:
>                 type: 'raidz'
>                 id: 0
>                 guid: 10192098197416954465
>                 nparity: 2
>                 metaslab_array: 34
>                 metaslab_shift: 37
>                 ashift: 9
>                 asize: 16003083796480
>                 is_log: 0
>                 create_txg: 4
>                 children[0]:
>                     type: 'disk'
>                     id: 0
>                     guid: 5442684633350386182
>                     path: '/dev/da3p1'
>                     phys_path: '/dev/da3p1'
>                     whole_disk: 1
>                     DTL: 2318341
>                     create_txg: 4
>                 children[1]:
>                     type: 'disk'
>                     id: 1
>                     guid: 4184769488943604229
>                     path: '/dev/da2p1'
>                     phys_path: '/dev/da2p1'
>                     whole_disk: 1
>                     DTL: 2318340
>                     create_txg: 4
>                 children[2]:
>                     type: 'disk'
>                     id: 2
>                     guid: 6673578809124996458
>                     path: '/dev/da1p1'
>                     phys_path: '/dev/da1p1'
>                     whole_disk: 1
>                     DTL: 2318358
>                     create_txg: 4
>                 children[3]:
>                     type: 'disk'
>                     id: 3
>                     guid: 14565784372994613264
>                     path: '/dev/da0p1'
>                     phys_path: '/dev/da0p1'
>                     whole_disk: 1
>                     DTL: 2318357
>                     create_txg: 4
>                 children[4]:
>                     type: 'disk'
>                     id: 4
>                     guid: 17127372890035360647
>                     path: '/dev/da6p1'
>                     phys_path: '/dev/da6p1'
>                     whole_disk: 1
>                     DTL: 2318356
>                     create_txg: 4
>                 children[5]:
>                     type: 'disk'
>                     id: 5
>                     guid: 5667576937780231702
>                     path: '/dev/label/disk05'
>                     phys_path: '/dev/label/disk05'
>                     whole_disk: 1
>                     DTL: 26389621
>                     create_txg: 4
>                 children[6]:
>                     type: 'disk'
>                     id: 6
>                     guid: 16545540667878636920
>                     path: '/dev/da5p1'
>                     phys_path: '/dev/da5p1'
>                     whole_disk: 1
>                     DTL: 2318354
>                     create_txg: 4
>                 children[7]:
>                     type: 'disk'
>                     id: 7
>                     guid: 16180883375304336701
>                     path: '/dev/da4p1'
>                     phys_path: '/dev/da4p1'
>                     whole_disk: 1
>                     DTL: 2318353
>                     create_txg: 4
>             children[1]:
>                 type: 'raidz'
>                 id: 1
>                 guid: 7000405778472969514
>                 nparity: 2
>                 metaslab_array: 32
>                 metaslab_shift: 37
>                 ashift: 9
>                 asize: 16003083796480
>                 is_log: 0
>                 create_txg: 4
>                 children[0]:
>                     type: 'disk'
>                     id: 0
>                     guid: 11848332905648146086
>                     path: '/dev/da10p1'
>                     phys_path: '/dev/da10p1'
>                     whole_disk: 1
>                     DTL: 2318352
>                     create_txg: 4
>                 children[1]:
>                     type: 'disk'
>                     id: 1
>                     guid: 17180048053682905420
>                     path: '/dev/da9p1'
>                     phys_path: '/dev/da9p1'
>                     whole_disk: 1
>                     DTL: 2318351
>                     create_txg: 4
>                 children[2]:
>                     type: 'disk'
>                     id: 2
>                     guid: 14648362260613207535
>                     path: '/dev/da8p1'
>                     phys_path: '/dev/da8p1'
>                     whole_disk: 1
>                     DTL: 2318350
>                     create_txg: 4
>                 children[3]:
>                     type: 'disk'
>                     id: 3
>                     guid: 2512073543886070959
>                     path: '/dev/da7p1'
>                     phys_path: '/dev/da7p1'
>                     whole_disk: 1
>                     DTL: 2318349
>                     create_txg: 4
>                 children[4]:
>                     type: 'disk'
>                     id: 4
>                     guid: 9213113982598250625
>                     path: '/dev/da14p1'
>                     phys_path: '/dev/da14p1'
>                     whole_disk: 1
>                     DTL: 2318348
>                     create_txg: 4
>                 children[5]:
>                     type: 'disk'
>                     id: 5
>                     guid: 14965308070554000358
>                     path: '/dev/da13p1'
>                     phys_path: '/dev/da13p1'
>                     whole_disk: 1
>                     DTL: 2318347
>                     create_txg: 4
>                 children[6]:
>                     type: 'disk'
>                     id: 6
>                     guid: 8812761598924675500
>                     path: '/dev/da12p1'
>                     phys_path: '/dev/da12p1'
>                     whole_disk: 1
>                     DTL: 2318346
>                     create_txg: 4
>                 children[7]:
>                     type: 'disk'
>                     id: 7
>                     guid: 15539718945154864246
>                     path: '/dev/da11p1'
>                     phys_path: '/dev/da11p1'
>                     whole_disk: 1
>                     DTL: 2318345
>                     create_txg: 4
>             children[2]:
>                 type: 'raidz'
>                 id: 2
>                 guid: 12675549095184402399
>                 nparity: 2
>                 metaslab_array: 30
>                 metaslab_shift: 37
>                 ashift: 9
>                 asize: 16003083796480
>                 is_log: 0
>                 create_txg: 4
>                 children[0]:
>                     type: 'disk'
>                     id: 0
>                     guid: 9157198169193782917
>                     path: '/dev/da16p1'
>                     phys_path: '/dev/da16p1'
>                     whole_disk: 1
>                     DTL: 35652327
>                     create_txg: 4
>                 children[1]:
>                     type: 'disk'
>                     id: 1
>                     guid: 14494767130322696735
>                     path: '/dev/da17p1'
>                     phys_path: '/dev/da17p1'
>                     whole_disk: 1
>                     DTL: 2318365
>                     create_txg: 4
>                 children[2]:
>                     type: 'disk'
>                     id: 2
>                     guid: 17589735305722725561
>                     path: '/dev/da18p1'
>                     phys_path: '/dev/da18p1'
>                     whole_disk: 1
>                     DTL: 2318364
>                     create_txg: 4
>                 children[3]:
>                     type: 'disk'
>                     id: 3
>                     guid: 14307956723966398718
>                     path: '/dev/da19p1'
>                     phys_path: '/dev/da19p1'
>                     whole_disk: 1
>                     DTL: 2318363
>                     create_txg: 4
>                 children[4]:
>                     type: 'disk'
>                     id: 4
>                     guid: 15965579855708087029
>                     path: '/dev/da20p1'
>                     phys_path: '/dev/da20p1'
>                     whole_disk: 1
>                     DTL: 2318362
>                     create_txg: 4
>                 children[5]:
>                     type: 'disk'
>                     id: 5
>                     guid: 760237787742339099
>                     path: '/dev/da21p1'
>                     phys_path: '/dev/da21p1'
>                     whole_disk: 1
>                     DTL: 2318361
>                     create_txg: 4
>                 children[6]:
>                     type: 'disk'
>                     id: 6
>                     guid: 2500372020986714069
>                     path: '/dev/da22p1'
>                     phys_path: '/dev/da22p1'
>                     whole_disk: 1
>                     DTL: 2318360
>                     create_txg: 4
>                 children[7]:
>                     type: 'disk'
>                     id: 7
>                     guid: 4544065732274116075
>                     path: '/dev/label/disk24'
>                     phys_path: '/dev/label/disk24'
>                     whole_disk: 1
>                     DTL: 5572568
>                     create_txg: 4
>             children[3]:
>                 type: 'hole'
>                 id: 3
>                 guid: 0
>                 metaslab_array: 0
>                 metaslab_shift: 17
>                 ashift: 0
>                 asize: 0
>                 is_log: 0
>                 is_hole: 1
>
> On 07/31/13 14:56, Martin Birgmeier wrote:
>> No, this is not an LSI HBA, but rather
>>
>> atapci0:<JMicron JMB361 UDMA133 controller>  port
>> 0xcc00-0xcc07,0xc880-0xc883,0xc800-0xc807,0xc480-0xc483,0xc400-0xc40f
>> mem 0xfe8fe000-0xfe8fffff irq 18 at device 0.0 on pci3
>> atapci1:<AHCI SATA controller>  at channel -1 on atapci0
>> atapci1: AHCI v1.00 controller with 2 3Gbps ports, PM supported
>> ata2:<ATA channel>  on atapci1
>> ata3:<ATA channel>  on atapci1
>> ata4:<ATA channel>  at channel 0 on atapci0
>> atapci2:<ATI IXP700/800 SATA300 controller>  port
>> 0xa000-0xa007,0x9000-0x9003,0x8000-0x8007,0x7000-0x7003,0x6000-0x600f
>> mem 0xfe4ffc00-0xfe4fffff irq 19 at device 17.0 on pci0
>> atapci2: AHCI v1.20 controller with 6 3Gbps ports, PM supported
>> ata5:<ATA channel>  at channel 0 on atapci2
>> ata6:<ATA channel>  at channel 1 on atapci2
>> ata7:<ATA channel>  at channel 2 on atapci2
>> ata8:<ATA channel>  at channel 3 on atapci2
>> ata9:<ATA channel>  at channel 4 on atapci2
>> ata10:<ATA channel>  at channel 5 on atapci2
>> ada0 at ata5 bus 0 scbus3 target 0 lun 0
>> ada1 at ata6 bus 0 scbus4 target 0 lun 0
>> ada2 at ata7 bus 0 scbus5 target 0 lun 0
>> ada3 at ata8 bus 0 scbus6 target 0 lun 0
>> ada4 at ata9 bus 0 scbus7 target 0 lun 0
>> ada5 at ata10 bus 0 scbus8 target 0 lun 0
>>
>> (This is just a simple PC motherboard - ASUS M4A89GTD PRO USB3.)
>>
>> Regards,
>>
>> Martin
>>
>
>
>
Comment 10 Christopher Harrison 2013-08-01 15:11:30 UTC
Just last night I got the system to deadlock again.   I grabbed a kernel 
bt but I realized I do no have full debug enabled.   I think our 
problems are to different ones.   As my bt points directly to an LSI 
adapter or kernel driver issue.
     -C
On 8/1/13 12:20 AM, Martin Birgmeier wrote:
> It is raidz2, using gpt partitions each covering half of six 2 TB disks.
> The remainder of these disks are mostly unused, with one containing a
> small UFS root for booting, and the others some small partitions which
> are used for various VirtualBox instances.
>
> Regards,
>
> Martin
>
> On 07/31/13 22:32, Christopher D. Harrison wrote:
>> what raidz level are you using: raidz2, raid0, raid1
>> also what are the pool config (see below, my pool is called z):
>>
>> MOS Configuration:
>>          version: 28
>>          name: 'z'
>>          state: 0
>>          txg: 214028175
>>          pool_guid: 5334451366918939808
>>          hostid: 4266313884
>>          hostname: 'pisces.biostat.wisc.edu'
>>          hole_array[0]: 3
>>          vdev_children: 4
>>          vdev_tree:
>>              type: 'root'
>>              id: 0
>>              guid: 5334451366918939808
>>              children[0]:
>>                  type: 'raidz'
>>                  id: 0
>>                  guid: 10192098197416954465
>>                  nparity: 2
>>                  metaslab_array: 34
>>                  metaslab_shift: 37
>>                  ashift: 9
>>                  asize: 16003083796480
>>                  is_log: 0
>>                  create_txg: 4
>>                  children[0]:
>>                      type: 'disk'
>>                      id: 0
>>                      guid: 5442684633350386182
>>                      path: '/dev/da3p1'
>>                      phys_path: '/dev/da3p1'
>>                      whole_disk: 1
>>                      DTL: 2318341
>>                      create_txg: 4
>>                  children[1]:
>>                      type: 'disk'
>>                      id: 1
>>                      guid: 4184769488943604229
>>                      path: '/dev/da2p1'
>>                      phys_path: '/dev/da2p1'
>>                      whole_disk: 1
>>                      DTL: 2318340
>>                      create_txg: 4
>>                  children[2]:
>>                      type: 'disk'
>>                      id: 2
>>                      guid: 6673578809124996458
>>                      path: '/dev/da1p1'
>>                      phys_path: '/dev/da1p1'
>>                      whole_disk: 1
>>                      DTL: 2318358
>>                      create_txg: 4
>>                  children[3]:
>>                      type: 'disk'
>>                      id: 3
>>                      guid: 14565784372994613264
>>                      path: '/dev/da0p1'
>>                      phys_path: '/dev/da0p1'
>>                      whole_disk: 1
>>                      DTL: 2318357
>>                      create_txg: 4
>>                  children[4]:
>>                      type: 'disk'
>>                      id: 4
>>                      guid: 17127372890035360647
>>                      path: '/dev/da6p1'
>>                      phys_path: '/dev/da6p1'
>>                      whole_disk: 1
>>                      DTL: 2318356
>>                      create_txg: 4
>>                  children[5]:
>>                      type: 'disk'
>>                      id: 5
>>                      guid: 5667576937780231702
>>                      path: '/dev/label/disk05'
>>                      phys_path: '/dev/label/disk05'
>>                      whole_disk: 1
>>                      DTL: 26389621
>>                      create_txg: 4
>>                  children[6]:
>>                      type: 'disk'
>>                      id: 6
>>                      guid: 16545540667878636920
>>                      path: '/dev/da5p1'
>>                      phys_path: '/dev/da5p1'
>>                      whole_disk: 1
>>                      DTL: 2318354
>>                      create_txg: 4
>>                  children[7]:
>>                      type: 'disk'
>>                      id: 7
>>                      guid: 16180883375304336701
>>                      path: '/dev/da4p1'
>>                      phys_path: '/dev/da4p1'
>>                      whole_disk: 1
>>                      DTL: 2318353
>>                      create_txg: 4
>>              children[1]:
>>                  type: 'raidz'
>>                  id: 1
>>                  guid: 7000405778472969514
>>                  nparity: 2
>>                  metaslab_array: 32
>>                  metaslab_shift: 37
>>                  ashift: 9
>>                  asize: 16003083796480
>>                  is_log: 0
>>                  create_txg: 4
>>                  children[0]:
>>                      type: 'disk'
>>                      id: 0
>>                      guid: 11848332905648146086
>>                      path: '/dev/da10p1'
>>                      phys_path: '/dev/da10p1'
>>                      whole_disk: 1
>>                      DTL: 2318352
>>                      create_txg: 4
>>                  children[1]:
>>                      type: 'disk'
>>                      id: 1
>>                      guid: 17180048053682905420
>>                      path: '/dev/da9p1'
>>                      phys_path: '/dev/da9p1'
>>                      whole_disk: 1
>>                      DTL: 2318351
>>                      create_txg: 4
>>                  children[2]:
>>                      type: 'disk'
>>                      id: 2
>>                      guid: 14648362260613207535
>>                      path: '/dev/da8p1'
>>                      phys_path: '/dev/da8p1'
>>                      whole_disk: 1
>>                      DTL: 2318350
>>                      create_txg: 4
>>                  children[3]:
>>                      type: 'disk'
>>                      id: 3
>>                      guid: 2512073543886070959
>>                      path: '/dev/da7p1'
>>                      phys_path: '/dev/da7p1'
>>                      whole_disk: 1
>>                      DTL: 2318349
>>                      create_txg: 4
>>                  children[4]:
>>                      type: 'disk'
>>                      id: 4
>>                      guid: 9213113982598250625
>>                      path: '/dev/da14p1'
>>                      phys_path: '/dev/da14p1'
>>                      whole_disk: 1
>>                      DTL: 2318348
>>                      create_txg: 4
>>                  children[5]:
>>                      type: 'disk'
>>                      id: 5
>>                      guid: 14965308070554000358
>>                      path: '/dev/da13p1'
>>                      phys_path: '/dev/da13p1'
>>                      whole_disk: 1
>>                      DTL: 2318347
>>                      create_txg: 4
>>                  children[6]:
>>                      type: 'disk'
>>                      id: 6
>>                      guid: 8812761598924675500
>>                      path: '/dev/da12p1'
>>                      phys_path: '/dev/da12p1'
>>                      whole_disk: 1
>>                      DTL: 2318346
>>                      create_txg: 4
>>                  children[7]:
>>                      type: 'disk'
>>                      id: 7
>>                      guid: 15539718945154864246
>>                      path: '/dev/da11p1'
>>                      phys_path: '/dev/da11p1'
>>                      whole_disk: 1
>>                      DTL: 2318345
>>                      create_txg: 4
>>              children[2]:
>>                  type: 'raidz'
>>                  id: 2
>>                  guid: 12675549095184402399
>>                  nparity: 2
>>                  metaslab_array: 30
>>                  metaslab_shift: 37
>>                  ashift: 9
>>                  asize: 16003083796480
>>                  is_log: 0
>>                  create_txg: 4
>>                  children[0]:
>>                      type: 'disk'
>>                      id: 0
>>                      guid: 9157198169193782917
>>                      path: '/dev/da16p1'
>>                      phys_path: '/dev/da16p1'
>>                      whole_disk: 1
>>                      DTL: 35652327
>>                      create_txg: 4
>>                  children[1]:
>>                      type: 'disk'
>>                      id: 1
>>                      guid: 14494767130322696735
>>                      path: '/dev/da17p1'
>>                      phys_path: '/dev/da17p1'
>>                      whole_disk: 1
>>                      DTL: 2318365
>>                      create_txg: 4
>>                  children[2]:
>>                      type: 'disk'
>>                      id: 2
>>                      guid: 17589735305722725561
>>                      path: '/dev/da18p1'
>>                      phys_path: '/dev/da18p1'
>>                      whole_disk: 1
>>                      DTL: 2318364
>>                      create_txg: 4
>>                  children[3]:
>>                      type: 'disk'
>>                      id: 3
>>                      guid: 14307956723966398718
>>                      path: '/dev/da19p1'
>>                      phys_path: '/dev/da19p1'
>>                      whole_disk: 1
>>                      DTL: 2318363
>>                      create_txg: 4
>>                  children[4]:
>>                      type: 'disk'
>>                      id: 4
>>                      guid: 15965579855708087029
>>                      path: '/dev/da20p1'
>>                      phys_path: '/dev/da20p1'
>>                      whole_disk: 1
>>                      DTL: 2318362
>>                      create_txg: 4
>>                  children[5]:
>>                      type: 'disk'
>>                      id: 5
>>                      guid: 760237787742339099
>>                      path: '/dev/da21p1'
>>                      phys_path: '/dev/da21p1'
>>                      whole_disk: 1
>>                      DTL: 2318361
>>                      create_txg: 4
>>                  children[6]:
>>                      type: 'disk'
>>                      id: 6
>>                      guid: 2500372020986714069
>>                      path: '/dev/da22p1'
>>                      phys_path: '/dev/da22p1'
>>                      whole_disk: 1
>>                      DTL: 2318360
>>                      create_txg: 4
>>                  children[7]:
>>                      type: 'disk'
>>                      id: 7
>>                      guid: 4544065732274116075
>>                      path: '/dev/label/disk24'
>>                      phys_path: '/dev/label/disk24'
>>                      whole_disk: 1
>>                      DTL: 5572568
>>                      create_txg: 4
>>              children[3]:
>>                  type: 'hole'
>>                  id: 3
>>                  guid: 0
>>                  metaslab_array: 0
>>                  metaslab_shift: 17
>>                  ashift: 0
>>                  asize: 0
>>                  is_log: 0
>>                  is_hole: 1
>>
>> On 07/31/13 14:56, Martin Birgmeier wrote:
>>> No, this is not an LSI HBA, but rather
>>>
>>> atapci0:<JMicron JMB361 UDMA133 controller>  port
>>> 0xcc00-0xcc07,0xc880-0xc883,0xc800-0xc807,0xc480-0xc483,0xc400-0xc40f
>>> mem 0xfe8fe000-0xfe8fffff irq 18 at device 0.0 on pci3
>>> atapci1:<AHCI SATA controller>  at channel -1 on atapci0
>>> atapci1: AHCI v1.00 controller with 2 3Gbps ports, PM supported
>>> ata2:<ATA channel>  on atapci1
>>> ata3:<ATA channel>  on atapci1
>>> ata4:<ATA channel>  at channel 0 on atapci0
>>> atapci2:<ATI IXP700/800 SATA300 controller>  port
>>> 0xa000-0xa007,0x9000-0x9003,0x8000-0x8007,0x7000-0x7003,0x6000-0x600f
>>> mem 0xfe4ffc00-0xfe4fffff irq 19 at device 17.0 on pci0
>>> atapci2: AHCI v1.20 controller with 6 3Gbps ports, PM supported
>>> ata5:<ATA channel>  at channel 0 on atapci2
>>> ata6:<ATA channel>  at channel 1 on atapci2
>>> ata7:<ATA channel>  at channel 2 on atapci2
>>> ata8:<ATA channel>  at channel 3 on atapci2
>>> ata9:<ATA channel>  at channel 4 on atapci2
>>> ata10:<ATA channel>  at channel 5 on atapci2
>>> ada0 at ata5 bus 0 scbus3 target 0 lun 0
>>> ada1 at ata6 bus 0 scbus4 target 0 lun 0
>>> ada2 at ata7 bus 0 scbus5 target 0 lun 0
>>> ada3 at ata8 bus 0 scbus6 target 0 lun 0
>>> ada4 at ata9 bus 0 scbus7 target 0 lun 0
>>> ada5 at ata10 bus 0 scbus8 target 0 lun 0
>>>
>>> (This is just a simple PC motherboard - ASUS M4A89GTD PRO USB3.)
>>>
>>> Regards,
>>>
>>> Martin
>>>
>>
>>
Comment 11 Xin LI 2013-08-15 06:37:22 UTC
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

I can't say for sure based on the information you have provided, but
stable/9 have a lot of fixes that could be related.

One problem we found in field that is not easy to reproduce is that
there is a lost interrupt issue in FreeBSD core.  This was fixed in
r253184 (post-9.1-RELEASE and before 9.2, the fix will be part of the
upcoming FreeBSD 9.2-RELEASE):

http://svnweb.freebsd.org/base/stable/9/sys/kern/kern_intr.c?r1=249402&r2=253184&view=patch

The symptom of this issue is that you basically see a lot of processes
blocking on zio->zio_cv, while there is no disk activity.  However,
the information you have provided can neither prove or deny my guess.
 I post the information here so people are aware of this issue if they
search these terms.

Cheers,
-----BEGIN PGP SIGNATURE-----

iQEcBAEBCAAGBQJSDGkSAAoJEG80Jeu8UPuzrBwH/01K+aR4WVN6SfK8i9WpjxhW
nhv0dWP/Q6+XStmNJcthNfT3Ox2lR+yNYhPif3uUtOYGjlEZX/t9QpptXo86Xwji
kN7cPZwELqE+0FS10uWtlaOYexqD7eg2QK2oj75hTfcKr5XfJWEVgWxlj+Iv6eAI
6JkNd7mdvOJReAgHVyt6mMdR/p4xhDP+/3lJXg1YoINYVfWzpolLAZcxdPxAxF+O
4rYM+BA/pcpglbK7CFd59tIUOeUaeOPHPVBeqw1NvMHw2EfJANx8PSyiu2jWdSeQ
264XgS3ZuphVWFYuapt2nQdkLaBFCQyfCU/3hu1lNQjD+6iwWoKIwtae32kmN+0=
=cwdX
-----END PGP SIGNATURE-----
Comment 12 Martin Birgmeier 2014-08-15 07:42:52 UTC
I am running 9.2 now, and the problem does not occur any more.

Please close the PR.

-- Martin