Personal tools
You are here: Home → Issue tracker → zpool export only works on the second try
 

#47 — zpool export only works on the second try

State Confirmed
Version: 0.6.9
Area Functionality
Issue type Bug
Severity Medium
Submitted by (anonymous)
Submitted on May 27, 2010
Responsible Seth Heeren
Target release: 0.6.9
Return to tracker
Last modified on Oct 11, 2010 by Seth Heeren
Every time I tree to export a pool, it only works on the second try:

The first invocation gives: "cannot export 'green': pool is busy" (green = pool name).

This happens both with 0.6.9 beta 3 and with this snapshot: http://zfs-fuse.sehe.nl/?p=zfs-fuse;a=commit;h=f3cdd7b7
Added by Seth Heeren on May 27, 2010 05:32 PM
Issue state: unconfirmed → open
Target release: None → 0.6.9
Responsible manager: (UNASSIGNED) → sgheeren
Known. It appears that Emmanuel _had_ fixed this for zfs umount

commit ca52e45704e23fff11247f567daa13d97c3fa50a
Author: Emmanuel Anne <emmanuel.anne@gmail.com>
Date: Fri Apr 23 09:50:55 2010 +0200

    add sync() calls for zfs destroy
    
    apparently there was a collision with fuse work on umount and zfs operations.
    Without the sync() calls we had very often a "dataset is busy" message when
    trying to destroy a dataset.
    Even zfs create test/1 && zfs destroy test/1 produced the message here, even
    worse with recursive filesystems. There are 3 more calls to sync() finally !

I propose I post him a message on the list to point at this issue. I'm not sure Emmanuel watches this tracker
Added by (anonymous) on May 27, 2010 05:42 PM
Sounds great. I will test it as soon as either of you posts a link to an updated version.
Added by (anonymous) on May 27, 2010 06:19 PM
I'm also observing the same phenomenon when destroying file systems: the first try reports
"cannot destroy 'green/backup2': dataset is busy", the second try works.
Added by Seth Heeren on May 27, 2010 06:39 PM
Mmmm thinking of that...

(a) I just saw that Emmanuels patch replaced nanosleeps by sync calls...
(b) I recall seeing that sync on special vdevs (like regular files) is causing warnings in the log:

May 28 01:31:26 karmic zfs-fuse: WARNING: Failed to flush write cache on device '/tmp/pool_blk/za1'. Data on pool 'pool' may be lost if power fails. No further warnings will be given.

Can you tell me whether you are seeing such messages in your syslog (I can imagine there is something special going on with the dm-crypt layer. Is there a loopmount involved?)
Added by (anonymous) on May 28, 2010 05:10 AM
I do not see any error messages in /var/log/messages or in dmesg when doing zpool export.

There is no loop device involved. The dm-crypt device was created by "cryptsetup -y create green /dev/sdb1" and is available through /dev/mapper/green.
Added by (anonymous) on May 28, 2010 08:50 AM
Mmm I wasn't actually looking for messages 'at export'. More like warning messages in general during operation (or, more likely just after importing)
Added by (anonymous) on May 28, 2010 08:58 AM
I'm not seeing any error messages ealier either. Here are the distinct lines from /var/log/messages with zfs-fuse over the past few days. Nothing suspicious AFAICT:

zfs-fuse: ARC caching: maximum ARC size: compiled-in default
zfs-fuse: ARC setup: max ARC size set to 134217728 bytes
zfs-fuse: ARC setup: min ARC size set to 16777216 bytes
zfs-fuse: initial max_map_count 65530
zfs-fuse: spa_async_autoexpand: would have used /devices/pci@0,0/pci8086,2829@d/disk@0,0:wd
zfs-fuse: spa_async_autoexpand: would have used /devices/pci@0,0/pci8086,2829@d/disk@1,0:wd
Added by Seth Heeren on May 28, 2010 03:17 PM
Thanks for the added infos

I can absolutely _not_ reproduce it (rev 2faf547521); not even with nested fs-es, mounted arbitrarily:


$ /etc/zfs/mountall.sh
mounting 'desktop/home' on '/MUBI/home'...
Removing inactive mountpoint directory /MUBI/home/sehe (resides on fs mounted on /MUBI/home)
Removing inactive mountpoint directory /MUBI/home/marlies (resides on fs mounted on /MUBI/home)
mounting 'desktop/home/marlies' on '/MUBI/home/marlies'...
Removing inactive mountpoint directory /MUBI/home/marlies/Photos (resides on fs mounted on /MUBI/home/marlies)
Removing inactive mountpoint directory /MUBI/home/marlies/.wine (resides on fs mounted on /MUBI/home/marlies)
mounting 'desktop/home/marlies/.wine' on '/MUBI/home/marlies/.wine'...
mounting 'desktop/home/marlies/Photos' on '/MUBI/home/marlies/Photos'...
mounting 'desktop/home/sehe' on '/MUBI/home/sehe'...
mounting 'desktop' on '/MUBI/zfs'...
Removing inactive mountpoint directory /MUBI/zfs/PersoonlijkeBestanden (resides on fs mounted on /MUBI/zfs)
mounting 'desktop/PersoonlijkeBestanden' on '/MUBI/zfs/PersoonlijkeBestanden'...
Removing inactive mountpoint directory /MUBI/zfs/PersoonlijkeBestanden/boekhoudingen (resides on fs mounted on /MUBI/zfs/PersoonlijkeBestanden)
Removing inactive mountpoint directory /MUBI/zfs/PersoonlijkeBestanden/VTLBBerekeningen (resides on fs mounted on /MUBI/zfs/PersoonlijkeBestanden)
Removing inactive mountpoint directory /MUBI/zfs/PersoonlijkeBestanden/OutlookMail (resides on fs mounted on /MUBI/zfs/PersoonlijkeBestanden)
Removing inactive mountpoint directory /MUBI/zfs/PersoonlijkeBestanden/MyPictures (resides on fs mounted on /MUBI/zfs/PersoonlijkeBestanden)
Removing inactive mountpoint directory /MUBI/zfs/PersoonlijkeBestanden/Mubi (resides on fs mounted on /MUBI/zfs/PersoonlijkeBestanden)
Removing inactive mountpoint directory /MUBI/zfs/PersoonlijkeBestanden/KLANTBESTAND (resides on fs mounted on /MUBI/zfs/PersoonlijkeBestanden)
Removing inactive mountpoint directory /MUBI/zfs/PersoonlijkeBestanden/FORMULIEREN (resides on fs mounted on /MUBI/zfs/PersoonlijkeBestanden)
Removing inactive mountpoint directory /MUBI/zfs/PersoonlijkeBestanden/Email (resides on fs mounted on /MUBI/zfs/PersoonlijkeBestanden)
Removing inactive mountpoint directory /MUBI/zfs/PersoonlijkeBestanden/Belastingdienst (resides on fs mounted on /MUBI/zfs/PersoonlijkeBestanden)
Removing inactive mountpoint directory /MUBI/zfs/PersoonlijkeBestanden/BUDGETTEER (resides on fs mounted on /MUBI/zfs/PersoonlijkeBestanden)
mounting 'desktop/PersoonlijkeBestanden/BUDGETTEER' on '/MUBI/zfs/PersoonlijkeBestanden/BUDGETTEER'...
mounting 'desktop/PersoonlijkeBestanden/Belastingdienst' on '/MUBI/zfs/PersoonlijkeBestanden/Belastingdienst'...
mounting 'desktop/PersoonlijkeBestanden/Email' on '/MUBI/zfs/PersoonlijkeBestanden/Email'...
mounting 'desktop/PersoonlijkeBestanden/FORMULIEREN' on '/MUBI/zfs/PersoonlijkeBestanden/FORMULIEREN'...
mounting 'desktop/PersoonlijkeBestanden/KLANTBESTAND' on '/MUBI/zfs/PersoonlijkeBestanden/KLANTBESTAND'...
mounting 'desktop/PersoonlijkeBestanden/Mubi' on '/MUBI/zfs/PersoonlijkeBestanden/Mubi'...
mounting 'desktop/PersoonlijkeBestanden/MyPictures' on '/MUBI/zfs/PersoonlijkeBestanden/MyPictures'...
mounting 'desktop/PersoonlijkeBestanden/OutlookMail' on '/MUBI/zfs/PersoonlijkeBestanden/OutlookMail'...
mounting 'desktop/PersoonlijkeBestanden/VTLBBerekeningen' on '/MUBI/zfs/PersoonlijkeBestanden/VTLBBerekeningen'...
skipping 'desktop/PersoonlijkeBestanden/_oud_en_problematisch' on '/MUBI/zfs/PersoonlijkeBestanden/_oud_en_problematisch' (property canmount=off set)
mounting 'desktop/PersoonlijkeBestanden/boekhoudingen' on '/MUBI/zfs/PersoonlijkeBestanden/boekhoudingen'...
$ find /MUBI/ -type f -exec md5sum {} \; | wc -l& zpool export desktop

As you can probably tell, the last statement is quite a stress test in every sense. It never broke in about 12 times I tried to let it. In fact, export will simply await the umounts, and the umounts will await the find job, like good citizens.
Added by (anonymous) on May 28, 2010 03:37 PM
I can reproduce it every time, but I see that it is timing-dependent. If I break in gdb on libzfs_pool.c:1240, I get the error, however, I've just successfully stepped through the zfs_ioctl above WITHOUT the error being reported. Maybe I can insert some printfs and reproduce it then.
Added by (anonymous) on May 28, 2010 04:01 PM
I now have a "working" and "non-working" configuration, the former doesn't display the error message, the latter does. The only difference between the two is that I inserted a usleep(50000) in the for(;;) loop in zfsfuse_ioctl in the former.

I also added the following debug statement to case IOCTL_ANS in function zfsfuse_ioctl in both configurations:

fprintf(stderr, "zfsfuse_ioctl: errno = %d\n", cmd.cmd_u.ioctl_ans_ret);

When doing zpool export, I can see:
- in the non-working configuration: 9 outputs of errno = 0, followed by one output of errno = 16, then the error message
- in the working configuration: 10 outputs of errno = 0, then everything ok

Does this give any clue? Any way of finding out more without instrumenting fuse?
Added by Seth Heeren on Jun 02, 2010 05:50 PM
I adapted Emmanuels workaround (a sleep around the actual export/destroy operation). It will be in 0.6.9

The real analysis is still in progress, which is why I intend to keep this issue open.

Instrumenting will never teach anything about timing issues. Instead, we need to know _what_ references cause EBUSY to be returned. Once we know that, we can fix it by removing the cause.
Somehow on Solaris, this works differently.
Added by Emmanuel Anne on Oct 11, 2010 02:56 AM
Of course it works differently in solaris. This is caused by fuse, when you tell it to umount a fs it starts to check if it's going to work and if so then it umounts in the background. That's why we had the problem.
Actually it's been fixed for me a very long time ago, I can't reproduce this with any configuration right now, so if you intend to keep this open, please move it elsewhere like testing, reference or whatever, not "confirmed opened issue".
Added by Seth Heeren on Oct 11, 2010 11:23 AM
It's not in 0.6.9

It was in testing. However, you yourself found a major glitch in that code that was fixed 651597e9f9d71 (August 11th).

For this very reason I usually hope to close the bug once the fix is generally available and I can ask the OP to confirm. If the bug stays inactive after that, I'll close it saying "closing due to inactivity"