Project

General

Profile

Bug #5515

dataset user hold doesn't reject empty tags

Added by Josef Sipek almost 5 years ago. Updated over 4 years ago.

Status:
Closed
Priority:
Normal
Assignee:
Category:
zfs - Zettabyte File System
Start date:
2015-01-08
Due date:
% Done:

100%

Estimated time:
Difficulty:
Medium
Tags:
needs-triage

Description

Dataset user holds can't handle empty tag names, but they don't actually reject them.

> ::stack
vpanic()
0xfffffffffbe0bab8()
mzap_addent+0x9c(ffffff0226a8d280, 548163dc)
zap_add+0x1e3(ffffff020bfd3bc0, 4e, ffffff023573def0, 8, 1, ffffff00092be7b8)
dsl_dataset_user_hold_sync_one_impl+0xb9(0, ffffff020c3c2c40, ffffff023573def0, 0, 548163dc,
ffffff0217286a00)
dsl_dataset_user_hold_sync+0x91(ffffff00089dfb00, ffffff0217286a00)                                       
dsl_sync_task_sync+0x13a(ffffff00089dfa10, ffffff0217286a00)
dsl_pool_sync+0x39b(ffffff020d097380, 29)
spa_sync+0x30f(ffffff6a795af000, 29)
txg_sync_thread+0x260(ffffff020d097380)
thread_start+8()

It's a txg sync thread that ran into the assert.

Let's print the zap_name_t passed into mzap_addent:

> ffffff0226a8d280::print zap_name_t
{
    zn_zap = 0xffffff01edfef088
    zn_key_intlen = 0x1
    zn_key_orig = 0xffffff023573def0
    zn_key_orig_numints = 0x1
    zn_key_norm = 0xffffff023573def0
    zn_key_norm_numints = 0x1
    zn_hash = 0
    zn_matchtype = 0 (0)
    zn_normbuf = [ '\\376', '\\312', '\\335', '\\272', '\\376', '\\312', '\\335', '\\272', '\\376', '\\312', '\\335',
 '\\272', '\\376', '\\312', '\\335', '\\272', '\\376', '\\312', '\\335', '\\272', '\\376', '\\312', '\\335', '\\272', '
\\376', '\\312', '\\335', '\\272', '\\376', '\\312', '\\335', '\\272', ... ]
}
> ffffff0226a8d280::print zap_name_t zn_key_orig | ::dump
                   \\/ 1 2 3  4 5 6 7  8 9 a b  c d e f  v123456789abcdef
ffffff023573def0:  00000000 00000000 bbcaddba fecaddba  ................

So, the original key is the empty string. Now, let's figure out what it is that we're comparing it against:

> ffffff0226a8d280::print zap_name_t zn_zap | ::print zap_t
{
    zap_objset = 0xffffff020bfd3bc0
    zap_object = 0x4e
    zap_dbuf = 0xffffff01f77bdc40
    zap_rwlock = {
        _opaque = [ 0xffffff00092bec44 ]
    }
    zap_ismicro = 0x1 (B_TRUE)
    zap_normflags = 0
    zap_salt = 0x3e053b6dd
    zap_u = {
        zap_fat = {
            zap_phys = 0xffffff0374c55400
            zap_num_entries_mtx = {
                _opaque = [ 0x70000 ]
            }
            zap_block_shift = 0
        }
        zap_micro = {
            zap_phys = 0xffffff0374c55400
            zap_num_entries = 0
            zap_num_chunks = 0x7
            zap_alloc_next = 0
            zap_avl = {
                avl_root = 0
                avl_compar = mze_compare
                avl_offset = 0
                avl_numnodes = 0
                avl_size = 0x30
            }
        }
    }
}

> ffffff0226a8d280::print zap_name_t zn_zap->zap_dbuf->db_data
zn_zap->zap_dbuf->db_data = 0xffffff0374c55400
> 0xffffff0374c55400,200::dump
                   \\/ 1 2 3  4 5 6 7  8 9 a b  c d e f  v123456789abcdef
ffffff0374c55400:  03000000 00000080 ddb653e0 03000000  ..........S.....
<remained of the buffer is all zeros>

So, just about any index into this buffer will cause us to get an empty string. This is of course bad, and it explains why the assertion failed.

Let's look at the first arg passed to dsl_dataset_user_hold_sync:

> ffffff00089dfb00::print dsl_dataset_user_hold_arg_t
{
    dduha_holds = 0xffffff1fa8262528
    dduha_chkholds = 0xffffff020033a340
    dduha_errlist = 0xffffff020033a730
    dduha_minor = 0
}
> ffffff00089dfb00::print dsl_dataset_user_hold_arg_t dduha_chkholds | ::nvlist
tpool0@2014-12-05T07:50:52.856Z__by__6FD6B7B1-7C53-11E4-B8E6-8BE4B232A11D=''

So, it looks like someone has handed us the empty string (instead of zfs itself screwing something up and ending up with an empty string). Let's look at the thread dealing with the ioctl that triggered the sync task:

> ::stacks -m zfs
THREAD           STATE    SOBJ                COUNT
ffffff0007ba8c40 SLEEP    CV                      3
                 swtch+0x18a
                 cv_wait+0x89
                 spa_thread+0x223
                 thread_start+8

ffffff00085e6c40 SLEEP    CV                      3
                 swtch+0x18a
                 cv_wait+0x89
                 txg_thread_wait+0xcf
                 txg_quiesce_thread+0x112
                 thread_start+8

ffffff00085efc40 SLEEP    CV                      2
                 swtch+0x18a
                 cv_timedwait_hires+0xf8
                 cv_timedwait+0x5c
                 txg_thread_wait+0x73
                 txg_sync_thread+0xdd
                 thread_start+8

ffffff0007b49c40 SLEEP    CV                      1
                 swtch+0x18a
                 cv_timedwait_hires+0xf8
                 cv_timedwait+0x5c
                 arc_reclaim_thread+0x12d
                 thread_start+8

ffffff0007b4fc40 SLEEP    CV                      1
                 swtch+0x18a
                 cv_timedwait_hires+0xf8
                 cv_timedwait+0x5c
                 l2arc_feed_thread+0xc6
                 thread_start+8

ffffff020c04a040 SLEEP    CV                      1
                 swtch+0x18a
                 cv_wait+0x89
                 txg_wait_synced+0xc3
                 dsl_sync_task+0x1a5
                 dsl_dataset_user_hold+0x89
                 zfs_ioc_hold+0x96
                 zfsdev_ioctl+0x21e
                 cdev_ioctl+0x39
                 spec_ioctl+0x60
                 fop_ioctl+0x55
                 ioctl+0x9b
                 _sys_sysenter_post_swapgs+0x237

ffffff00092bec40 PANIC    <NONE>                  1
                 param_preset
                 0xfffffffffbe0bab8
                 mzap_addent+0x9c
                 zap_add+0x1e3
                 dsl_dataset_user_hold_sync_one_impl+0xb9
                 dsl_dataset_user_hold_sync+0x91
                 dsl_sync_task_sync+0x13a
                 dsl_pool_sync+0x39b
                 spa_sync+0x30f
                 txg_sync_thread+0x260
                 thread_start+8
> ffffff020c04a040::findstack
stack pointer for thread ffffff020c04a040: ffffff00089df910
[ ffffff00089df910 _resume_from_idle+0xf4() ]
  ffffff00089df940 swtch+0x18a()
  ffffff00089df970 cv_wait+0x89()
  ffffff00089df9d0 txg_wait_synced+0xc3()
  ffffff00089dfae0 dsl_sync_task+0x1a5()
  ffffff00089dfb60 dsl_dataset_user_hold+0x89()
  ffffff00089dfbc0 zfs_ioc_hold+0x96()
  ffffff00089dfc70 zfsdev_ioctl+0x21e()
  ffffff00089dfcb0 cdev_ioctl+0x39()
  ffffff00089dfd00 spec_ioctl+0x60()
  ffffff00089dfd90 fop_ioctl+0x55()
  ffffff00089dfeb0 ioctl+0x9b()
  ffffff00089dff00 _sys_sysenter_post_swapgs+0x237()
> ffffff00089df910::stack
swtch+0x18a()
cv_wait+0x89(ffffff020d09757a, ffffff020d097538)
txg_wait_synced+0xc3(ffffff020d097380, 29)
dsl_sync_task+0x1a5(ffffff0235740020, fffffffff786e0a0, fffffffff786e700, ffffff00089dfb00, 1, 1)
dsl_dataset_user_hold+0x89(ffffff1fa8262528, 0, ffffff020033a730)
zfs_ioc_hold+0x96(ffffff6a8a352000, ffffff020033afa0, ffffff020033a730)
zfsdev_ioctl+0x21e(10600000000, 5a30, fdb39f74, 100003, ffffff01e9d4fba0, ffffff00089dfe58)
cdev_ioctl+0x39(10600000000, 5a30, fdb39f74, 100003, ffffff01e9d4fba0, ffffff00089dfe58)
spec_ioctl+0x60(ffffff01e525f700, 5a30, fdb39f74, 100003, ffffff01e9d4fba0, ffffff00089dfe58)
fop_ioctl+0x55(ffffff01e525f700, 5a30, fdb39f74, 100003, ffffff01e9d4fba0, ffffff00089dfe58)
ioctl+0x9b(4a, 5a30, fdb39f74)
_sys_sysenter_post_swapgs+0x237()

Specifically, let's look at the arguments it got from userspace:

> ffffff6a8a352000::dump
                   \\/ 1 2 3  4 5 6 7  8 9 a b  c d e f  v123456789abcdef
ffffff6a8a352000:  74706f6f 6c300000 00000000 00000000  tpool0..........                                  
> ffffff020033afa0::nvlist
holds
    tpool0@2014-12-05T07:50:52.856Z__by__6FD6B7B1-7C53-11E4-B8E6-8BE4B232A11D=''

So, we have been asked to add a hold with name
'tpool0@2014-12-05T07:50:52.856Z_by_6FD6B7B1-7C53-11E4-B8E6-8BE4B232A11D"
with the value of an empty string. Is this valid?

Aha! It turns out that the tag must not be empty. This happens to work fine
as a no-op on non-debug builds, but debug builds rely on the fact that the
string is not empty.

Easy to reproduce on debug builds:

# zfs snapshot rpool1/test/16k@foo
# zfs list -rt all rpool1/test/16k@foo
NAME                  USED  AVAIL  REFER  MOUNTPOINT
rpool1/test/16k@foo      0      -  48.9G  -
# zfs hold test rpool1/test/16k@foo
# zfs hold '' rpool1/test/16k@foo
<panic>

Related issues

Precedes illumos gate - Bug #5521: zfs hold with empty tag prints the wrong error messageNew2015-01-10

Actions

History

#1

Updated by Electric Monk over 4 years ago

  • % Done changed from 80 to 100
  • Status changed from New to Closed

git commit 752fd8dabccac68d6d09f82f3bf3561e055e400b

commit  752fd8dabccac68d6d09f82f3bf3561e055e400b
Author: Josef 'Jeff' Sipek <josef.sipek@nexenta.com>
Date:   2015-05-21T03:34:52.000Z

    5515 dataset user hold doesn't reject empty tags
    Reviewed by: Matthew Ahrens <mahrens@delphix.com>
    Reviewed by: Yuri Pankov <yuri.pankov@nexenta.com>
    Reviewed by: Saso Kiselkov <saso.kiselkov@nexenta.com>
    Approved by: Matthew Ahrens <mahrens@delphix.com>

Also available in: Atom PDF