Project

General

Profile

Bug #14399

kernel panic on export

Added by Richard Kojedzinszky over 4 years ago. Updated almost 3 years ago.

Status:
Closed: Not To Be Fixed
Priority:
Nice to have
Assignee:
Alexander Motin
Category:
OS
Target version:
Severity:
New
Reason for Closing:
Reason for Blocked:
Needs QA:
Yes
Needs Doc:
Yes
Needs Merging:
Yes
Needs Automation:
No
Support Suite Ticket:
n/a
Hardware Configuration:
ChangeLog Required:
No

Description

I was just playing with ZFS pools to reproduce bug in #14337, and probably have hit another. I've done the testing with md devices, so there could be no hardware failures. I've created a pool with version 28, attached devices, detached, upgraded, exported, imported, wrote files on it, and such in random order. It took only 5 minutes when the system did a panic. But unfortunately, I cannot reproduce. The generated textdump is attached.

History

#1 Updated by Richard Kojedzinszky over 4 years ago

  • File panic.tar added

The attached script can reproduce the panic. Just run zpool-export.sh on a freenas. I've tested on a box with 8G ram.

#2 Updated by Jordan Hubbard over 4 years ago

  • Assignee changed from Alexander Motin to Chris Torek

#3 Updated by Chris Torek over 4 years ago

Copying my notes-so-far into the bug...

kdb_enter() at kdb_enter+0x3e/frame 0xfffffe023b640610
vpanic() at vpanic+0x146/frame 0xfffffe023b640650
panic() at panic+0x43/frame 0xfffffe023b6406b0
assfail3() at assfail3+0x2f/frame 0xfffffe023b6406d0
range_tree_destroy() at range_tree_destroy+0x34/frame 0xfffffe023b6406f0
metaslab_fini() at metaslab_fini+0x1d8/frame 0xfffffe023b640720
vdev_free() at vdev_free+0x91/frame 0xfffffe023b640760
vdev_free() at vdev_free+0x40/frame 0xfffffe023b6407a0
spa_unload() at spa_unload+0xc8/frame 0xfffffe023b6407e0
spa_export_common() at spa_export_common+0x431/frame 0xfffffe023b640840
zfs_ioc_pool_export() at zfs_ioc_pool_export+0x30/frame 0xfffffe023b640870
zfsdev_ioctl() at zfsdev_ioctl+0x667/frame 0xfffffe023b640920
devfs_ioctl_f() at devfs_ioctl_f+0x139/frame 0xfffffe023b640980
kern_ioctl() at kern_ioctl+0x255/frame 0xfffffe023b6409f0
sys_ioctl() at sys_ioctl+0x140/frame 0xfffffe023b640ad0
amd64_syscall() at amd64_syscall+0x40f/frame 0xfffffe023b640bf0

zfsdev_ioctl is at:

6396            } else {
6397                    error = vec->zvec_legacy_func(zc);
6398            }

zfs_ioc_pool_export is short, here's the whole function,
and we're at the spa_export() call:

static int
zfs_ioc_pool_export(zfs_cmd_t *zc)
{
        int error;
        boolean_t force = (boolean_t)zc->zc_cookie;
        boolean_t hardforce = (boolean_t)zc->zc_guid;

        zfs_log_history(zc);
        error = spa_export(zc->zc_name, NULL, force, hardforce);
        if (error == 0)
                zvol_remove_minors(zc->zc_name);
        return (error);
}

spa_export is just a call to spa_export_common and has been
expanded/tail-called:

spa_export(char *pool, nvlist_t **oldconfig, boolean_t force,
    boolean_t hardforce)
{
        return (spa_export_common(pool, POOL_STATE_EXPORTED, oldconfig,
            force, hardforce));
}

now we're in spa_export_common at 4592, calling spa_unload:

4591            if (spa->spa_state != POOL_STATE_UNINITIALIZED) {
4592                    spa_unload(spa);
4593                    spa_deactivate(spa);
4594            }

now we're in spa_unload at a vdev_free call, line 1322 (we plan to
return to the dsl_pool_close step just below this, and the ASSERT
has been compiled out):

1321            if (spa->spa_root_vdev)
1322                    vdev_free(spa->spa_root_vdev);
1323            ASSERT(spa->spa_root_vdev == NULL);

(Aside: this ASSERT seems broken, how will vdev_free null out
spa->spa_root_vdev? aha, vdev_free checks whether the vdev has
a spa and is the spa's root vdev and if so NULL-s that out.)

In vdev_free we are doing:

704             for (int c = 0; c < vd->vdev_children; c++)
705                     vdev_free(vd->vdev_child[c]);

and apparently there is at least one child so we are in
vdev_free again for the child. Here vdev_metaslab_fini()
has been expanded inline, so we are at

713             if (vd->vdev_mg != NULL) {
714                     vdev_metaslab_fini(vd);
715                     metaslab_group_destroy(vd->vdev_mg);
716             }

which has reached:

1010            if (vd->vdev_ms != NULL) {
1011                    metaslab_group_passivate(vd->vdev_mg);
1012                    for (m = 0; m < count; m++) {
1013                            metaslab_t *msp = vd->vdev_ms[m];
1014
1015                            if (msp != NULL)
1016                                    metaslab_fini(msp);
1017                    }

which has called metaslab_fini:

1419            for (int t = 0; t < TXG_DEFER_SIZE; t++) {
1420                    range_tree_destroy(msp->ms_defertree[t]);
1421            }

which gets us to range_tree_destroy:

150     void
151     range_tree_destroy(range_tree_t *rt)
152     {
153             VERIFY0(rt->rt_space);
154
155             if (rt->rt_ops != NULL)
156                     rt->rt_ops->rtop_destroy(rt, rt->rt_arg);

Apparently we're in the VERIFY0:

#define VERIFY0(x)              VERIFY3_IMPL(x, ==, 0, uintmax_t)
#define VERIFY3_IMPL(LEFT, OP, RIGHT, TYPE) do { \
        const TYPE __left = (TYPE)(LEFT); \
        const TYPE __right = (TYPE)(RIGHT); \
        if (!(__left OP __right)) \
                assfail3(#LEFT " " #OP " " #RIGHT, \
                        (uintmax_t)__left, #OP, (uintmax_t)__right, \
                        __FILE__, __LINE__); \
_NOTE(CONSTCOND) } while (0)

so we're complaining that the rt_space value is 0x3a00, when it
should just be 0.

(Another aside to self, checking the code that maintains rt_space,
some of it calls the wrong rt_ops functions. Lucky for us the
range tree code is not used with actual non-NULL rt_ops, I suppose?)

Conclusion so far is that we're about to lose some metaslab space,
in whatever this msp->ms_defertree[] array is.

#4 Updated by Josh Paetzel over 4 years ago

I've always wanted to rename the assfail() and assfail3() functions to orfice_containment_failure()

#5 Updated by Richard Kojedzinszky over 4 years ago

May this relate to #14337?

#6 Updated by Chris Torek over 4 years ago

  • Status changed from Unscreened to Screened

It could be related, I'm still learning all kinds of stuff about ZFS myself. Maybe mav would have a better idea.

#7 Avatar?id=14398&size=24x24 Updated by Kris Moore almost 4 years ago

  • Priority changed from No priority to Nice to have
  • Target version set to 9.10.1-U3

Chris,

Ping! Is this something still on the radar for investigation?

#8 Avatar?id=14398&size=24x24 Updated by Kris Moore almost 4 years ago

  • Target version changed from 9.10.1-U3 to 9.10.2

#9 Avatar?id=14398&size=24x24 Updated by Kris Moore almost 4 years ago

  • Target version changed from 9.10.2 to 9.10.2-U1

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

  • Target version changed from 9.10.2-U1 to 9.10.2-U3

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

  • Target version changed from 9.10.2-U3 to 9.10.4

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

  • Target version changed from 9.10.4 to 11.1

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

  • Assignee changed from Chris Torek to Alexander Motin

#14 Updated by Alexander Motin almost 3 years ago

  • Status changed from Screened to Closed: Not To Be Fixed
  • Target version changed from 11.1 to N/A

I am closing this on timeout. It may already be fixed with many ZFS update in past 1.5 years.

#15 Updated by Dru Lavigne almost 3 years ago

  • File deleted (textdump.tar.0.gz)

#16 Updated by Dru Lavigne almost 3 years ago

  • File deleted (panic.tar)

Also available in: Atom PDF