Spa deadman

Dave Baukus daveb at spectralogic.com
Wed Oct 17 20:00:09 UTC 2018


While running something close to FreeBSD_stable11.0, I have several crashes
where the spa_deadman() timer is firing and panicking the system.

There are not any indications of IO errors. I have dug into one of the
crash dumps and have found the following:

 From the vdev_deadman() stack, I have the zio_t that is apparently stuck and
causing the panic (partial zio dump below and complete zio dump at bottom):

zio = {
   ...
   io_flags = 805571754 = 30040caa ==
         ZIO_FLAG_AGGREGATED | ZIO_FLAG_DELEGATED|ZIO_FLAG_DONT_QUEUE|
ZIO_FLAG_DONT_CACHE|ZIO_FLAG_DONT_RETRY|ZIO_FLAG_CANFAIL|
ZIO_FLAG_SCAN_THREAD|ZIO_FLAG_RESILVER|ZIO_FLAG_IO_REPAIR
   io_stage = ZIO_STAGE_VDEV_IO_START,
   io_pipeline = 3014656, == 002e0000 ==
ZIO_STAGE_DONE|ZIO_STAGE_VDEV_IO_ASSESS|ZIO_STAGE_VDEV_IO_DONE|
         ZIO_STAGE_VDEV_IO_START
   io_orig_flags = 805571754,
   io_orig_stage = ZIO_STAGE_READY,
   io_orig_pipeline = 3014656,
   io_error = 0,
   io_child_error = 0xfffff80b496d729c,
   io_children = 0xfffff80b496d72b0,
   io_child_count = 0,
   io_phys_children = 0,
   io_parent_count = 2,
   io_stall = 0x0,
   io_gang_leader = 0x0,
   io_gang_tree = 0x0,
   io_executor = 0xfffff802c1e6ea00,

Presumably, the above aggregated IO was issued and never completed, but
I can find the above zio in spa_zio_taskq[ZIO_TYPE_WRITE][ZIO_TASKQ_INTERRUPT] (details below).

My questions are:

1.) Am I wrong in wondering how a stuck zio in vq->vq_active_tree can also be
in the spa_zio_taskq[ZIO_TYPE_WRITE][ZIO_TASKQ_INTERRUPT] IO completion queue ?

2.) Is there any zio crumbs that would let me confirm or deny that the ZIO in
spa_zio_taskq[ZIO_TYPE_WRITE][ZIO_TASKQ_INTERRUPT] was or was not scheduled?

If it was scheduled then why would it not, given its current state,
execute vdev_queue_io_done() ?Which would have (?) removed it from
vq->vq_active_tree

One such crumb I noticed, but am not sure what to make of it, is the fact
that zio->io_executor == 0xfffff802c1e6ea00 is a thread in the
spa_zio_taskq[ZIO_TYPE_WRITE][ZIO_TASKQ_INTERRUPT] thread pool.

3.) Am I off in the weeds ?

4.) An suggestions on what to look at appreciated

Thanks - dave

-----------------------------------------
Dump of spa_zio_taskq[ZIO_TYPE_WRITE][ZIO_TASKQ_INTERRUPT]:

spa_zio_taskq[2][2]: 0xfffff802328a1210
$24 = {
   stqs_count = 1,
   stqs_taskq = 0xfffff800258a6030
}

TASK QUEUE 0 :: (struct taskqueue *)0xfffff802c84f4100
$25 = {
   tq_queue = {
     stqh_first = 0xfffff80b496d7370,
     stqh_last = 0xfffff80b496d7370
   },
   tq_enqueue = 0xffffffff80553fe0 <taskqueue_thread_enqueue>,
   tq_context = 0xfffff800258a6060,
   tq_name = 0xfffff800254b2880 "zio_write_intr",
   tq_active = {
     tqh_first = 0x0,
     tqh_last = 0xfffff802c84f4128
   },
   tq_mutex = {
     lock_object = {
       lo_name = 0xfffff800254b2880 "zio_write_intr",
       lo_flags = 16973824,
       lo_data = 0,
       lo_witness = 0x0
     },
     mtx_lock = 4
   },
   tq_threads = 0xfffff802c1ae0c00,
   tq_tcount = 8,
   tq_spin = 0,
   tq_flags = 5,
   tq_callouts = 0,
   tq_callbacks = 0xfffff802c84f4170,
   tq_cb_contexts = 0xfffff802c84f4180
}

Walking tq_queue{} from above:
(taskq_ent_t *)0xfffff80b496d7370
$27 = {
   tqent_task = {
     ta_link = {
       stqe_next = 0x0
     },
     ta_pending = 1,
     ta_priority = 0,
     ta_func = 0xffffffff810c9bd0 <taskq_run_ent>,
     ta_context = 0xfffff80b496d7370
   },
   tqent_func = 0xffffffff8116e1f0 <zio_execute>,
   tqent_arg = 0xfffff80b496d7000 <<<<<<<<<<<<<<<<<<< The "stuck" zio
}

tq->tq_threads:
(struct thread **)0xfffff802c1ae0c00, count 8
0 :: (struct thread *)0xfffff802c1e6ea00 <<<<<<<<<<<< zio->io_executor
1 :: (struct thread *)0xfffff802c1e70a00
2 :: (struct thread *)0xfffff802c191d500
3 :: (struct thread *)0xfffff8028a7f0a00
4 :: (struct thread *)0xfffff8028a878000
5 :: (struct thread *)0xfffff802c1e70000
6 :: (struct thread *)0xfffff8028a866500
7 :: (struct thread *)0xfffff802c1e6f000

-----------------------------------------
Dump of the "stuck zio":

set $zio = (zio_t *) 0xfffff80b496d7000

p *$zio
$21 = {
   io_bookmark = {
     zb_objset = 0,
     zb_object = 0,
     zb_level = 0,
     zb_blkid = 0
   },
   io_prop = {
     zp_checksum = ZIO_CHECKSUM_INHERIT,
     zp_compress = ZIO_COMPRESS_INHERIT,
     zp_type = DMU_OT_NONE,
     zp_level = 0 '\0',
     zp_copies = 0 '\0',
     zp_dedup = 0,
     zp_dedup_verify = 0,
     zp_nopwrite = 0
   },
   io_type = ZIO_TYPE_WRITE,
   io_child_type = ZIO_CHILD_VDEV,
   io_cmd = 0,
   io_priority = ZIO_PRIORITY_ASYNC_WRITE,
   io_reexecute = 0 '\0',
   io_state = 0xfffff80b496d704d "\001",
   io_txg = 0,
   io_spa = 0xfffff802328a1000,
   io_bp = 0x0,
   io_bp_override = 0x0,
   io_bp_copy = {
     blk_dva = 0xfffff80b496d7070,
     blk_prop = 0,
     blk_pad = 0xfffff80b496d70a8,
     blk_phys_birth = 0,
     blk_birth = 0,
     blk_fill = 0,
     blk_cksum = {
       zc_word = 0xfffff80b496d70d0
     }
   },
   io_parent_list = {
     list_size = 48,
     list_offset = 16,
     list_head = {
       list_next = 0xfffff808dd31ae80,
       list_prev = 0xfffff80805300f70
     }
   },
   io_child_list = {
     list_size = 48,
     list_offset = 32,
     list_head = {
       list_next = 0xfffff80b496d7120,
       list_prev = 0xfffff80b496d7120
     }
   },
   io_walk_link = 0x0,
   io_logical = 0x0,
   io_transform_stack = 0x0,
   io_ready = 0,
   io_children_ready = 0,
   io_physdone = 0,
   io_done = 0xffffffff811546d0 <vdev_queue_agg_io_done>,
   io_private = 0x4000,
   io_prev_space_delta = 0,
   io_bp_orig = {
     blk_dva = 0xfffff80b496d7178,
     blk_prop = 0,
     blk_pad = 0xfffff80b496d71b0,
     blk_phys_birth = 0,
     blk_birth = 0,
     blk_fill = 0,
     blk_cksum = {
       zc_word = 0xfffff80b496d71d8
     }
   },
   io_data = 0xfffffe0228133000,
   io_orig_data = 0xfffffe0228133000,
   io_size = 524288,
   io_orig_size = 524288,
   io_vcount = 2,
   io_vd = 0xfffff80c867d0000,
   io_vsd = 0x0,
   io_vsd_ops = 0x0,
   io_offset = 7712562135040,
   io_timestamp = 333322534657425,
   io_target_timestamp = 0,
   io_queue_node = {
     avl_child = 0xfffff80b496d7250,
     avl_pcb = 1
   },
   io_offset_node = {
     avl_child = 0xfffff80b496d7268,
     avl_pcb = 0
   },
   io_flags = 805571754 = 30040caa ==
         ZIO_FLAG_AGGREGATED | ZIO_FLAG_DELEGATED|ZIO_FLAG_DONT_QUEUE|
         ZIO_FLAG_DONT_CACHE|ZIO_FLAG_DONT_RETRY|ZIO_FLAG_CANFAIL|
         ZIO_FLAG_SCAN_THREAD|ZIO_FLAG_RESILVER|ZIO_FLAG_IO_REPAIR
   io_stage = ZIO_STAGE_VDEV_IO_START,
   io_pipeline = 3014656,
   io_orig_flags = 805571754,
   io_orig_stage = ZIO_STAGE_READY,
   io_orig_pipeline = 3014656, == 002e0000 ==
          ZIO_STAGE_DONE | ZIO_STAGE_VDEV_IO_ASSESS | ZIO_STAGE_VDEV_IO_DONE | \
         ZIO_STAGE_VDEV_IO_START

   io_error = 0,
   io_child_error = 0xfffff80b496d729c,
   io_children = 0xfffff80b496d72b0,
   io_child_count = 0,
   io_phys_children = 0,
   io_parent_count = 2,
   io_stall = 0x0,
   io_gang_leader = 0x0,
   io_gang_tree = 0x0,
   io_executor = 0xfffff802c1e6ea00,
   io_waiter = 0x0,
   io_lock = {
     lock_object = {
       lo_name = 0xffffffff8120a5c8 "zio->io_lock",
       lo_flags = 40960000,
       lo_data = 0,
       lo_witness = 0x0
     },
     sx_lock = 1
   },
   io_cv = {
     cv_description = 0xffffffff8120a5d6 "zio->io_cv",
     cv_waiters = 0
   },
   io_cksum_report = 0x0,
   io_ena = 0,
   io_tqent = {
     tqent_task = {
       ta_link = {
         stqe_next = 0x0
       },
       ta_pending = 1,
       ta_priority = 0,
       ta_func = 0xffffffff810c9bd0 <taskq_run_ent>,
       ta_context = 0xfffff80b496d7370
     },
     tqent_func = 0xffffffff8116e1f0 <zio_execute>,
     tqent_arg = 0xfffff80b496d7000
   },
   io_trim_node = {
     avl_child = 0xfffff80b496d73a0,
     avl_pcb = 0
   },
   io_trim_link = {
     list_next = 0x0,
     list_prev = 0x0
   }
}



-- 
Dave Baukus


More information about the freebsd-fs mailing list