Description
http://build.wiredtiger.com:8080/job/wiredtiger-test-format-stress/6045
On tinderbox, I unpacked the tarball in ~jenkins/stress.6045.
50: file, variable-length column-store
|
[1420229849:916566][30371:0x7f6d8ffff700], t, file:wt, session.checkpoint: ../src/reconcile/rec_write.c, 3202: state == WT_CHILD_MODIFIED
|
The stack and other useful structures:
WT-3 0x0000000000465684 in __wt_assert (session=0x101d600, error=0, file_name=0x678833 "../src/reconcile/rec_write.c", line_number=3202, fmt=0x67868a "%s")
|
at ../src/support/err.c:447
|
WT-4 0x000000000044f50b in __rec_col_int (session=0x101d600, r=0x7f6cf438c6e0, page=0x105b710) at ../src/reconcile/rec_write.c:3202
|
WT-5 0x0000000000449fa1 in __wt_reconcile (session=0x101d600, ref=0x105b6d0, salvage=0x0, flags=0) at ../src/reconcile/rec_write.c:400
|
WT-6 0x000000000048f57d in __sync_file (session=0x101d600, syncop=1) at ../src/btree/bt_sync.c:135
|
WT-7 0x000000000048f79d in __wt_cache_op (session=0x101d600, ckptbase=0x7f6cf43035f0, op=1) at ../src/btree/bt_sync.c:222
|
WT-8 0x000000000046ed3a in __checkpoint_worker (session=0x101d600, cfg=0x7f6d8fffed80, is_checkpoint=1) at ../src/txn/txn_ckpt.c:886
|
WT-9 0x000000000046efb2 in __wt_checkpoint (session=0x101d600, cfg=0x7f6d8fffed80) at ../src/txn/txn_ckpt.c:951
|
WT-10 0x000000000046cfd2 in __checkpoint_apply (session=0x101d600, cfg=0x7f6d8fffed80, op=0x46ef0b <__wt_checkpoint>) at ../src/txn/txn_ckpt.c:183
|
WT-11 0x000000000046db47 in __wt_txn_checkpoint (session=0x101d600, cfg=0x7f6d8fffed80) at ../src/txn/txn_ckpt.c:403
|
WT-12 0x0000000000462346 in __session_checkpoint (wt_session=0x101d600, config=0x7f6d8fffede0 "name=thread-3") at ../src/session/session_api.c:895
|
WT-13 0x000000000040ff96 in ops (arg=0x1085d90) at ../../../test/format/ops.c:341
|
WT-14 0x0000003f17e07ee5 in start_thread (arg=0x7f6d8ffff700) at pthread_create.c:309
|
WT-3 0x0000000000465684 in __wt_assert (session=0x101d600, error=0, file_name=0x678833 "../src/reconcile/rec_write.c", line_number=3202, fmt=0x67868a "%s")
|
at ../src/support/err.c:447
|
WT-4 0x000000000044f50b in __rec_col_int (session=0x101d600, r=0x7f6cf438c6e0, page=0x105b710) at ../src/reconcile/rec_write.c:3202
|
WT-5 0x0000000000449fa1 in __wt_reconcile (session=0x101d600, ref=0x105b6d0, salvage=0x0, flags=0) at ../src/reconcile/rec_write.c:400
|
WT-6 0x000000000048f57d in __sync_file (session=0x101d600, syncop=1) at ../src/btree/bt_sync.c:135
|
WT-7 0x000000000048f79d in __wt_cache_op (session=0x101d600, ckptbase=0x7f6cf43035f0, op=1) at ../src/btree/bt_sync.c:222
|
WT-8 0x000000000046ed3a in __checkpoint_worker (session=0x101d600, cfg=0x7f6d8fffed80, is_checkpoint=1) at ../src/txn/txn_ckpt.c:886
|
WT-9 0x000000000046efb2 in __wt_checkpoint (session=0x101d600, cfg=0x7f6d8fffed80) at ../src/txn/txn_ckpt.c:951
|
WT-10 0x000000000046cfd2 in __checkpoint_apply (session=0x101d600, cfg=0x7f6d8fffed80, op=0x46ef0b <__wt_checkpoint>) at ../src/txn/txn_ckpt.c:183
|
WT-11 0x000000000046db47 in __wt_txn_checkpoint (session=0x101d600, cfg=0x7f6d8fffed80) at ../src/txn/txn_ckpt.c:403
|
WT-12 0x0000000000462346 in __session_checkpoint (wt_session=0x101d600, config=0x7f6d8fffede0 "name=thread-3") at ../src/session/session_api.c:895
|
WT-13 0x000000000040ff96 in ops (arg=0x1085d90) at ../../../test/format/ops.c:341
|
WT-14 0x0000003f17e07ee5 in start_thread (arg=0x7f6d8ffff700) at pthread_create.c:309
|
|
(gdb) p state
|
$2 = 1
|
[WT_CHILD_IGNORE]
|
(gdb) p *ref
|
$3 = {page = 0x7f6d2c14e4d0, home = 0x105b710, ref_hint = 2235, state = WT_REF_MEM, addr = 0x0, key = {recno = 120921, ikey = 0x1d859}, page_del = 0x0}
|
(gdb) p *page
|
$4 = {u = {intl = {recno = 91014, parent_ref = 0x105b6d0, __index = 0x7f6d2c3b0810}, row = {d = 0x16386, ins = 0x105b6d0, upd = 0x7f6d2c3b0810, entries = 0},
|
col_fix = {recno = 91014, bitf = 0x105b6d0 "\020\267\005\001", entries = 742066192}, col_var = {recno = 91014, d = 0x105b6d0, repeats = 0x7f6d2c3b0810,
|
nrepeats = 0, entries = 0}}, dsk = 0x105b800, modify = 0x7f6d0c368d90, read_gen = 202, memory_footprint = 237213, type = 3 '\003', flags_atomic = 18 '\022'}
|
(gdb) p *child
|
$5 = {u = {intl = {recno = 120921, parent_ref = 0x7f6d2c14e518, __index = 0x7f6d2c14e590}, row = {d = 0x1d859, ins = 0x7f6d2c14e518, upd = 0x7f6d2c14e590,
|
entries = 4}, col_fix = {recno = 120921, bitf = 0x7f6d2c14e518 "(", entries = 739566992}, col_var = {recno = 120921, d = 0x7f6d2c14e518,
|
repeats = 0x7f6d2c14e590, nrepeats = 4, entries = 25}}, dsk = 0x7f6d2c39ffe0, modify = 0x7f6d2c14e660, read_gen = 291, memory_footprint = 1589,
|
type = 4 '\004', flags_atomic = 2 '\002'}
|
(gdb) p *r
|
$7 = {ref = 0x105b6d0, page = 0x105b710, flags = 0, dsk = {data = 0x7f6cf40d8c00, size = 0, flags = 1, mem = 0x7f6cf40d8c00, memsize = 33280}, max_txn = 177851,
|
skipped_txn = 177859, orig_write_gen = 350, leave_dirty = 0, raw_compression = 0, raw_max_slots = 0, raw_entries = 0x0, raw_offsets = 0x0, raw_recnos = 0x0,
|
raw_destination = {data = 0x0, size = 0, flags = 1, mem = 0x0, memsize = 0}, ovfl_items = 0, all_empty_value = 1, any_empty_value = 0, page_size = 32768,
|
page_size_orig = 32768, split_size = 15360, bnd = 0x7f6cf4050170, bnd_next = 3, bnd_next_max = 541, bnd_entries = 640, bnd_allocated = 81920,
|
total_entries = 2096, bnd_state = SPLIT_TRACKING_OFF, recno = 120921, entries = 277, first_free = 0x7f6cf40d9c70 "\343\001U", space_avail = 11152, skip = 0x0,
|
skip_next = 0, skip_allocated = 0, cell_zero = 0, dictionary = 0x0, dictionary_next = 0, dictionary_slots = 0, dictionary_head = {0x0, 0x0, 0x0, 0x0, 0x0, 0x0,
|
0x0, 0x0, 0x0, 0x0}, k = {buf = {data = 0x0, size = 0, flags = 0, mem = 0x0, memsize = 0}, cell = {__chunk = '\000' <repeats 15 times>}, cell_len = 0,
|
len = 0}, v = {buf = {data = 0x7f6d2c14e470, size = 9, flags = 0, mem = 0x7f6cf41043a0, memsize = 11}, cell = {
|
__chunk = "$\343\001\270\003\211\000\000\000\000\000\000\000\000\000"}, cell_len = 6, len = 15}, cur = 0x7f6cf438c8f8, _cur = {data = 0x0, size = 0,
|
flags = 0, mem = 0x0, memsize = 0}, last = 0x7f6cf438c928, _last = {data = 0x7f6d181789ef, size = 17, flags = 0, mem = 0x0, memsize = 0},
|
key_pfx_compress = 0, key_pfx_compress_conf = 0, key_sfx_compress = 0, key_sfx_compress_conf = 0, is_bulk_load = 0, salvage = 0x0, tested_ref_state = 3}
|
(gdb) p/x r->flags
|
$8 = 0x0
|
(gdb) p *ref->page->modify
|
$9 = {disk_snap_min = 0, rec_max_txn = 0, first_dirty_txn = 177812, update_txn = 0, inmem_split_txn = 0, bytes_dirty = 1589, u1 = {replace = {addr = 0x0,
|
size = 0 '\000', type = 0 '\000', reuse = 0 '\000'}, m = {multi = 0x0, multi_entries = 0}}, u2 = {intl = {root_split = 0x0, split_txn = 140106867730128},
|
leaf = {append = 0x0, update = 0x7f6d2c14e6d0}}, ovfl_track = 0x0, write_gen = 1, page_lock = 3 '\003', flags = 0 '\000'}
|
I'm not sure if the comment above the assertion (frame 4) about all other non-zero states are row-only is still correct because it is the exact state we're in. We appear to have a child page set up as described in the comment in __rec_child_modify:1156:
* but, if we're forced to instantiate
|
* a deleted child page and it's never modified, we end up here with
|
* a page that has a modify structure, no modifications, and no disk
|
* address. Ignore those pages, they're not modified and there is no
|
* reason to write the cell.
|
The CONFIG:
############################################
|
# RUN PARAMETERS
|
############################################
|
abort=0
|
auto_throttle=1
|
firstfit=0
|
bitcnt=1
|
bloom=1
|
bloom_bit_count=57
|
bloom_hash_count=12
|
bloom_oldest=0
|
cache=73
|
checkpoints=1
|
checksum=uncompressed
|
chunk_size=7
|
compaction=0
|
compression=none
|
data_extend=0
|
data_source=file
|
delete_pct=45
|
dictionary=0
|
evict_max=5
|
file_type=variable-length column-store
|
backups=0
|
huffman_key=0
|
huffman_value=0
|
insert_pct=10
|
internal_key_truncation=1
|
internal_page_max=15
|
isolation=read-uncommitted
|
key_gap=18
|
key_max=49
|
key_min=13
|
leak_memory=0
|
leaf_page_max=9
|
logging=0
|
logging_archive=0
|
logging_prealloc=0
|
logging=0
|
lsm_worker_threads=4
|
merge_max=9
|
mmap=1
|
ops=100000
|
prefix_compression=1
|
prefix_compression_min=2
|
repeat_data_pct=20
|
reverse=0
|
rows=100000
|
runs=100
|
split_pct=46
|
statistics=0
|
threads=7
|
timer=0
|
value_max=2694
|
value_min=14
|
wiredtiger_config=
|
write_pct=42
|
############################################
|
Attachments
Issue Links
- is related to
-
WT-1546 Checkpoint bug
- Closed
- related to
-
WT-1 placeholder WT-1
- Closed
-
WT-2 What does metadata look like?
- Closed
-
WT-3 What file formats are required?
- Closed
-
WT-4 Flexible cursor traversals
- Closed
-
WT-5 How does pget work: is it necessary?
- Closed
-
WT-6 Complex schema example
- Closed
-
WT-7 Do we need the handle->err/errx methods?
- Closed
-
WT-8 Do we need table load, bulk-load and/or dump methods?
- Closed
-
WT-9 Does adding schema need to be transactional?
- Closed
-
WT-10 Basic "getting started" tutorial
- Closed
-
WT-11 placeholder #11
- Closed
-
WT-12 Write more examples
- Closed
-
WT-13 Define supported platforms
- Closed
-
WT-14 Windows build
- Closed
-
WT-15 Automated build/test infrastructure
- Closed
-
WT-1521 test/checkpoint failure
- Closed
-
WT-1547 Fix test/checkpoint skipping dirty pages
- Closed