--hQiwHBbRI9kgIhsi
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
> One problem is that the debug output gives no indication of which thread
> is which so it seems pretty tricky to separate out the different calls.
> Do you have any hints or tricks for doing this?
Ok, so I altered the DPRINTF so that it gets the current thread id too:
fprintf(stderr, "%s:%d:%lu " fmt "\n", mdb_func_, __LINE__, syscall(__NR_gettid), __VA_ARGS__)
I also added some DPUTS to the start of every function in the API.
New log attached. Essentially, there are four threads of interest:
7036 - write txns for /tmp/data1
7039 - read txns (incl cursor) for /tmp/data1
7040 - write txns for /tmp/data2
7041 - read txns (incl cursor) for /tmp/data2
As there are no writes going on, the write threads do no work once the
envs and dbis are created and opened.
In this run, it's 7039 that finds the usual problem. If we just grep for
7039 from the log, we get (edited highlights):
mdb_txn_begin:2860:7039 begin txn 1862r 0x7f4034000a10 on mdbenv 0xd483c0, root page 417
...
mdb_get:5570:7039 mdb_get
mdb_get:5576:7039 ===> get db 4 key [00000000000000010000000000000001311e7dc5]
...
mdb_cursor_set:6002:7039 ==> cursor placed on key [00000000000000010000000000000001311e7dc5]
mdb_txn_reset:2990:7039 mdb_txn_reset
mdb_txn_end:2919:7039 mdb_txn_end
mdb_txn_end:2931:7039 reset txn 1862r 0x7f4034000a10 on mdbenv 0xd483c0, root page 417
... now we start up /tmp/data2 in the other threads.
When we next see 7039 return:
mdb_txn_renew:2749:7039 mdb_txn_renew
mdb_txn_renew:2759:7039 renew txn 1862r 0x7f4034000a10 on mdbenv 0xd483c0, root page 417
mdb_cursor_open:7408:7039 mdb_cursor_open
mdb_page_search:5445:7039 db 1 root page 417 has flags 0x2
mdb_page_search_root:5342:7039 found leaf page 417 for key [5472616e73616374696f6e73]
mdb_node_search:5091:7039 searching 5 keys in leaf page 417
mdb_node_search:5135:7039 found leaf index 2 [5472616e73616374696f6e52656673], rc = 8448
mdb_node_search:5135:7039 found leaf index 3 [5472616e73616374696f6e73], rc = 0
mdb_page_search:5445:7039 db 4 root page 276 has flags 0x1
mdb_cursor_get:6103:7039 mdb_cursor_get
mdb_cursor_first:6011:7039 mdb_cursor_first
mdb_page_search:5445:7039 db 4 root page 276 has flags 0x1
mdb_page_search_root:5290:7039 branch page 276 has 2 keys
mdb_page_search_root:5296:7039 found index 0 to page 710
mdb_cursor_push:5202:7039 pushing page 710 on db 4 cursor 0x7f4034000bd0
mdb_page_search_root:5290:7039 branch page 710 has 134 keys
mdb_page_search_root:5296:7039 found index 0 to page 43
mdb_cursor_push:5202:7039 pushing page 43 on db 4 cursor 0x7f4034000bd0
mdb_page_search_root:5342:7039 found leaf page 43 for key [null]
... at this point the error is detected and we start tidying up.
>From the tids that are being logged, it doesn't appear to me that
anything's up with the threading. It looks like there's some issue with
opening a cursor in a read only txn that has already been reset and
renewed.
The strange thing is that this only happens when this program is running
across more than one database. With a single database it never goes
wrong. So it seems like there's some interaction between opening a
second db and an existing db (with reset txns?).
Many thanks for your time.
Matthew
--hQiwHBbRI9kgIhsi
Content-Type: text/plain; charset=us-ascii
Content-Disposition: attachment; filename=log
GoshawkDBConsistencyChecker 2016/03/26 22:24:37.798236 [./consistencychecker /tmp/data1 /tmp/data2]
GoshawkDBConsistencyChecker 2016/03/26 22:24:37.798527 ...loading from /tmp/data1
GoshawkDBConsistencyChecker 2016/03/26 22:24:37.798558 Starting disk server on /tmp/data1
mdb_env_create:3862:7036 mdb_env_create
mdb_env_open:4702:7036 mdb_env_open
mdb_env_open2:4192:7036 opened database version 1, pagesize 4096
mdb_env_open2:4193:7036 using meta page 0
mdb_env_open2:4194:7036 depth: 1
mdb_env_open2:4195:7036 entries: 5
mdb_env_open2:4196:7036 branch pages: 0
mdb_env_open2:4197:7036 leaf pages: 1
mdb_env_open2:4198:7036 overflow pages: 0
mdb_env_open2:4199:7036 root: 417
mdb_env_open:4821:7036 opened dbenv 0xd483c0
mdb_txn_begin:2767:7036 mdb_txn_begin
mdb_txn_begin:2860:7036 begin txn 1863w 0xd49660 on mdbenv 0xd483c0, root page 417
mdb_cursor_set:5812:7036 mdb_cursor_set
mdb_page_search:5445:7036 db 1 root page 417 has flags 0x2
mdb_page_search_root:5342:7036 found leaf page 417 for key [5472616e73616374696f6e52656673]
mdb_node_search:5091:7036 searching 5 keys in leaf page 417
mdb_node_search:5135:7036 found leaf index 2 [5472616e73616374696f6e52656673], rc = 0
mdb_cursor_set:6002:7036 ==> cursor placed on key [5472616e73616374696f6e52656673]
mdb_cursor_set:5812:7036 mdb_cursor_set
mdb_page_search:5445:7036 db 1 root page 417 has flags 0x2
mdb_page_search_root:5342:7036 found leaf page 417 for key [56617273]
mdb_node_search:5091:7036 searching 5 keys in leaf page 417
mdb_node_search:5135:7036 found leaf index 2 [5472616e73616374696f6e52656673], rc = 2
mdb_node_search:5135:7036 found leaf index 3 [5472616e73616374696f6e73], rc = 2
mdb_node_search:5135:7036 found leaf index 4 [56617273], rc = 0
mdb_cursor_set:6002:7036 ==> cursor placed on key [56617273]
mdb_cursor_set:5812:7036 mdb_cursor_set
mdb_page_search:5445:7036 db 1 root page 417 has flags 0x2
mdb_page_search_root:5342:7036 found leaf page 417 for key [5472616e73616374696f6e73]
mdb_node_search:5091:7036 searching 5 keys in leaf page 417
mdb_node_search:5135:7036 found leaf index 2 [5472616e73616374696f6e52656673], rc = 8448
mdb_node_search:5135:7036 found leaf index 3 [5472616e73616374696f6e73], rc = 0
mdb_cursor_set:6002:7036 ==> cursor placed on key [5472616e73616374696f6e73]
mdb_txn_commit:3361:7036 mdb_txn_commit
mdb_txn_end:2919:7036 mdb_txn_end
mdb_txn_end:2931:7036 empty-commit txn 1863w 0xd49660 on mdbenv 0xd483c0, root page 417
mdb_txn_begin:2767:7039 mdb_txn_begin
mdb_txn_begin:2860:7039 begin txn 1862r 0x7f4034000a10 on mdbenv 0xd483c0, root page 417
mdb_txn_renew:2749:7039 mdb_txn_renew
mdb_txn_abort:3004:7039 mdb_txn_abort
mdb_txn_end:2919:7039 mdb_txn_end
mdb_txn_end:2931:7039 abort txn 1862r 0x7f4034000a10 on mdbenv 0xd483c0, root page 417
mdb_txn_begin:2767:7039 mdb_txn_begin
mdb_txn_begin:2860:7039 begin txn 1862r 0x7f4034000a10 on mdbenv 0xd483c0, root page 417
mdb_get:5570:7039 mdb_get
mdb_get:5576:7039 ===> get db 3 key [0000000000000000000000000000000000000000]
mdb_page_search:5445:7039 db 1 root page 417 has flags 0x2
mdb_page_search_root:5342:7039 found leaf page 417 for key [56617273]
mdb_node_search:5091:7039 searching 5 keys in leaf page 417
mdb_node_search:5135:7039 found leaf index 2 [5472616e73616374696f6e52656673], rc = 2
mdb_node_search:5135:7039 found leaf index 3 [5472616e73616374696f6e73], rc = 2
mdb_node_search:5135:7039 found leaf index 4 [56617273], rc = 0
mdb_page_search:5445:7039 db 3 root page 471 has flags 0x1
mdb_cursor_set:5812:7039 mdb_cursor_set
mdb_page_search:5445:7039 db 3 root page 471 has flags 0x1
mdb_page_search_root:5290:7039 branch page 471 has 3 keys
mdb_page_search_root:5296:7039 found index 0 to page 628
mdb_node_search:5091:7039 searching 3 keys in branch page 471
mdb_node_search:5138:7039 found branch index 1 [000000000000011c0000000600000001311e7dc5 -> 725], rc = -1
mdb_page_search_root:5314:7039 following index 0 for key [0000000000000000000000000000000000000000]
mdb_cursor_push:5202:7039 pushing page 628 on db 3 cursor 0x7f403c27b6b0
mdb_page_search_root:5290:7039 branch page 628 has 68 keys
mdb_page_search_root:5296:7039 found index 0 to page 137
mdb_node_search:5091:7039 searching 68 keys in branch page 628
mdb_node_search:5138:7039 found branch index 34 [00000000000000780000000600000001311e7dc5 -> 138], rc = -30720
mdb_node_search:5138:7039 found branch index 17 [00000000000000220000000600000001311e7dc5 -> 88], rc = -8704
mdb_node_search:5138:7039 found branch index 8 [000000000000000e0000000600000001311e7dc5 -> 50], rc = -3584
mdb_node_search:5138:7039 found branch index 4 [00000000000000030000000500000001311e7dc5 -> 52], rc = -768
mdb_node_search:5138:7039 found branch index 2 [00000000000000010000000300000001311e7dc5 -> 1401], rc = -256
mdb_node_search:5138:7039 found branch index 1 [00000000000000000000000600000001311e7dc5 -> 983], rc = -1536
mdb_page_search_root:5314:7039 following index 0 for key [0000000000000000000000000000000000000000]
mdb_cursor_push:5202:7039 pushing page 137 on db 3 cursor 0x7f403c27b6b0
mdb_page_search_root:5342:7039 found leaf page 137 for key [0000000000000000000000000000000000000000]
mdb_node_search:5091:7039 searching 6 keys in leaf page 137
mdb_node_search:5135:7039 found leaf index 2 [000000000000000000000000000000015b297cbd], rc = -256
mdb_node_search:5135:7039 found leaf index 0 [0000000000000000000000000000000000000000], rc = 0
mdb_cursor_set:6002:7039 ==> cursor placed on key [0000000000000000000000000000000000000000]
mdb_get:5570:7039 mdb_get
mdb_get:5576:7039 ===> get db 4 key [00000000000000010000000000000001311e7dc5]
mdb_page_search:5445:7039 db 1 root page 417 has flags 0x2
mdb_page_search_root:5342:7039 found leaf page 417 for key [5472616e73616374696f6e73]
mdb_node_search:5091:7039 searching 5 keys in leaf page 417
mdb_node_search:5135:7039 found leaf index 2 [5472616e73616374696f6e52656673], rc = 8448
mdb_node_search:5135:7039 found leaf index 3 [5472616e73616374696f6e73], rc = 0
mdb_page_search:5445:7039 db 4 root page 276 has flags 0x1
mdb_cursor_set:5812:7039 mdb_cursor_set
mdb_page_search:5445:7039 db 4 root page 276 has flags 0x1
mdb_page_search_root:5290:7039 branch page 276 has 2 keys
mdb_page_search_root:5296:7039 found index 0 to page 710
mdb_node_search:5091:7039 searching 2 keys in branch page 276
mdb_node_search:5138:7039 found branch index 1 [00000000000005df00000000000000015b297cbd -> 449], rc = -5
mdb_page_search_root:5314:7039 following index 0 for key [00000000000000010000000000000001311e7dc5]
mdb_cursor_push:5202:7039 pushing page 710 on db 4 cursor 0x7f403c27b6b0
mdb_page_search_root:5290:7039 branch page 710 has 134 keys
mdb_page_search_root:5296:7039 found index 0 to page 43
mdb_node_search:5091:7039 searching 134 keys in branch page 710
mdb_node_search:5138:7039 found branch index 67 [00000000000002e10000000000000001b1f3f9b0 -> 344], rc = -2
mdb_node_search:5138:7039 found branch index 33 [00000000000000bd0000000000000001311e7dc5 -> 336], rc = -48128
mdb_node_search:5138:7039 found branch index 16 [000000000000005700000000000000015b297cbd -> 123], rc = -22016
mdb_node_search:5138:7039 found branch index 8 [000000000000001d0000000000000001311e7dc5 -> 135], rc = -7168
mdb_node_search:5138:7039 found branch index 4 [00000000000000100000000600000001311e7dc5 -> 19], rc = -3840
mdb_node_search:5138:7039 found branch index 2 [000000000000000200000000000000015b297cbd -> 109], rc = -256
mdb_node_search:5138:7039 found branch index 1 [00000000000000010000000000000001311e7dc5 -> 5], rc = 0
mdb_page_search_root:5314:7039 following index 1 for key [00000000000000010000000000000001311e7dc5]
mdb_cursor_push:5202:7039 pushing page 5 on db 4 cursor 0x7f403c27b6b0
mdb_page_search_root:5342:7039 found leaf page 5 for key [00000000000000010000000000000001311e7dc5]
mdb_node_search:5091:7039 searching 3 keys in leaf page 5
mdb_node_search:5135:7039 found leaf index 1 [00000000000000010000000000000001b1f3f9b0], rc = -128
mdb_node_search:5135:7039 found leaf index 0 [00000000000000010000000000000001311e7dc5], rc = 0
mdb_cursor_set:6002:7039 ==> cursor placed on key [00000000000000010000000000000001311e7dc5]
mdb_txn_reset:2990:7039 mdb_txn_reset
mdb_txn_end:2919:7039 mdb_txn_end
mdb_txn_end:2931:7039 reset txn 1862r 0x7f4034000a10 on mdbenv 0xd483c0, root page 417
GoshawkDBConsistencyChecker 2016/03/26 22:24:37.799971 ...loading from /tmp/data2
GoshawkDBConsistencyChecker 2016/03/26 22:24:37.800025 Starting disk server on /tmp/data2
mdb_env_create:3862:7040 mdb_env_create
mdb_env_open:4702:7040 mdb_env_open
mdb_env_open2:4192:7040 opened database version 1, pagesize 4096
mdb_env_open2:4193:7040 using meta page 1
mdb_env_open2:4194:7040 depth: 1
mdb_env_open2:4195:7040 entries: 5
mdb_env_open2:4196:7040 branch pages: 0
mdb_env_open2:4197:7040 leaf pages: 1
mdb_env_open2:4198:7040 overflow pages: 0
mdb_env_open2:4199:7040 root: 1291
mdb_env_open:4821:7040 opened dbenv 0x7f402c0008c0
mdb_txn_begin:2767:7040 mdb_txn_begin
mdb_txn_begin:2860:7040 begin txn 1796w 0x7f402c001b80 on mdbenv 0x7f402c0008c0, root page 1291
mdb_cursor_set:5812:7040 mdb_cursor_set
mdb_page_search:5445:7040 db 1 root page 1291 has flags 0x2
mdb_page_search_root:5342:7040 found leaf page 1291 for key [5472616e73616374696f6e73]
mdb_node_search:5091:7040 searching 5 keys in leaf page 1291
mdb_node_search:5135:7040 found leaf index 2 [5472616e73616374696f6e52656673], rc = 8448
mdb_node_search:5135:7040 found leaf index 3 [5472616e73616374696f6e73], rc = 0
mdb_cursor_set:6002:7040 ==> cursor placed on key [5472616e73616374696f6e73]
mdb_cursor_set:5812:7040 mdb_cursor_set
mdb_page_search:5445:7040 db 1 root page 1291 has flags 0x2
mdb_page_search_root:5342:7040 found leaf page 1291 for key [5472616e73616374696f6e52656673]
mdb_node_search:5091:7040 searching 5 keys in leaf page 1291
mdb_node_search:5135:7040 found leaf index 2 [5472616e73616374696f6e52656673], rc = 0
mdb_cursor_set:6002:7040 ==> cursor placed on key [5472616e73616374696f6e52656673]
mdb_cursor_set:5812:7040 mdb_cursor_set
mdb_page_search:5445:7040 db 1 root page 1291 has flags 0x2
mdb_page_search_root:5342:7040 found leaf page 1291 for key [56617273]
mdb_node_search:5091:7040 searching 5 keys in leaf page 1291
mdb_node_search:5135:7040 found leaf index 2 [5472616e73616374696f6e52656673], rc = 2
mdb_node_search:5135:7040 found leaf index 3 [5472616e73616374696f6e73], rc = 2
mdb_node_search:5135:7040 found leaf index 4 [56617273], rc = 0
mdb_cursor_set:6002:7040 ==> cursor placed on key [56617273]
mdb_txn_commit:3361:7040 mdb_txn_commit
mdb_txn_end:2919:7040 mdb_txn_end
mdb_txn_end:2931:7040 empty-commit txn 1796w 0x7f402c001b80 on mdbenv 0x7f402c0008c0, root page 1291
mdb_txn_begin:2767:7041 mdb_txn_begin
mdb_txn_begin:2860:7041 begin txn 1795r 0x7f4030000a10 on mdbenv 0x7f402c0008c0, root page 1291
mdb_txn_renew:2749:7041 mdb_txn_renew
mdb_txn_abort:3004:7041 mdb_txn_abort
mdb_txn_end:2919:7041 mdb_txn_end
mdb_txn_end:2931:7041 abort txn 1795r 0x7f4030000a10 on mdbenv 0x7f402c0008c0, root page 1291
mdb_txn_begin:2767:7041 mdb_txn_begin
mdb_txn_begin:2860:7041 begin txn 1795r 0x7f4030000a10 on mdbenv 0x7f402c0008c0, root page 1291
mdb_get:5570:7041 mdb_get
mdb_get:5576:7041 ===> get db 4 key [0000000000000000000000000000000000000000]
mdb_page_search:5445:7041 db 1 root page 1291 has flags 0x2
mdb_page_search_root:5342:7041 found leaf page 1291 for key [56617273]
mdb_node_search:5091:7041 searching 5 keys in leaf page 1291
mdb_node_search:5135:7041 found leaf index 2 [5472616e73616374696f6e52656673], rc = 2
mdb_node_search:5135:7041 found leaf index 3 [5472616e73616374696f6e73], rc = 2
mdb_node_search:5135:7041 found leaf index 4 [56617273], rc = 0
mdb_page_search:5445:7041 db 4 root page 530 has flags 0x1
mdb_cursor_set:5812:7041 mdb_cursor_set
mdb_page_search:5445:7041 db 4 root page 530 has flags 0x1
mdb_page_search_root:5290:7041 branch page 530 has 3 keys
mdb_page_search_root:5296:7041 found index 0 to page 535
mdb_node_search:5091:7041 searching 3 keys in branch page 530
mdb_node_search:5138:7041 found branch index 1 [000000000000010b0000000600000001311e7dc5 -> 1361], rc = -1
mdb_page_search_root:5314:7041 following index 0 for key [0000000000000000000000000000000000000000]
mdb_cursor_push:5202:7041 pushing page 535 on db 4 cursor 0x7f403b2796b0
mdb_page_search_root:5290:7041 branch page 535 has 68 keys
mdb_page_search_root:5296:7041 found index 0 to page 35
mdb_node_search:5091:7041 searching 68 keys in branch page 535
mdb_node_search:5138:7041 found branch index 34 [00000000000000700000000600000001311e7dc5 -> 262], rc = -28672
mdb_node_search:5138:7041 found branch index 17 [00000000000000210000000600000001311e7dc5 -> 41], rc = -8448
mdb_node_search:5138:7041 found branch index 8 [000000000000000f0000000600000001311e7dc5 -> 383], rc = -3840
mdb_node_search:5138:7041 found branch index 4 [00000000000000040000000600000001311e7dc5 -> 97], rc = -1024
mdb_node_search:5138:7041 found branch index 2 [00000000000000010000000300000001311e7dc5 -> 568], rc = -256
mdb_node_search:5138:7041 found branch index 1 [00000000000000000000000600000001311e7dc5 -> 197], rc = -1536
mdb_page_search_root:5314:7041 following index 0 for key [0000000000000000000000000000000000000000]
mdb_cursor_push:5202:7041 pushing page 35 on db 4 cursor 0x7f403b2796b0
mdb_page_search_root:5342:7041 found leaf page 35 for key [0000000000000000000000000000000000000000]
mdb_node_search:5091:7041 searching 6 keys in leaf page 35
mdb_node_search:5135:7041 found leaf index 2 [000000000000000000000000000000015b297cbd], rc = -256
mdb_node_search:5135:7041 found leaf index 0 [0000000000000000000000000000000000000000], rc = 0
mdb_cursor_set:6002:7041 ==> cursor placed on key [0000000000000000000000000000000000000000]
mdb_get:5570:7041 mdb_get
mdb_get:5576:7041 ===> get db 2 key [00000000000000010000000000000001311e7dc5]
mdb_page_search:5445:7041 db 1 root page 1291 has flags 0x2
mdb_page_search_root:5342:7041 found leaf page 1291 for key [5472616e73616374696f6e73]
mdb_node_search:5091:7041 searching 5 keys in leaf page 1291
mdb_node_search:5135:7041 found leaf index 2 [5472616e73616374696f6e52656673], rc = 8448
mdb_node_search:5135:7041 found leaf index 3 [5472616e73616374696f6e73], rc = 0
mdb_page_search:5445:7041 db 2 root page 1304 has flags 0x1
mdb_cursor_set:5812:7041 mdb_cursor_set
mdb_page_search:5445:7041 db 2 root page 1304 has flags 0x1
mdb_page_search_root:5290:7041 branch page 1304 has 2 keys
mdb_page_search_root:5296:7041 found index 0 to page 238
mdb_node_search:5091:7041 searching 2 keys in branch page 1304
mdb_node_search:5138:7041 found branch index 1 [00000000000002cc0000000000000001311e7dc5 -> 1305], rc = -2
mdb_page_search_root:5314:7041 following index 0 for key [00000000000000010000000000000001311e7dc5]
mdb_cursor_push:5202:7041 pushing page 238 on db 2 cursor 0x7f403b2796b0
mdb_page_search_root:5290:7041 branch page 238 has 68 keys
mdb_page_search_root:5296:7041 found index 0 to page 2
mdb_node_search:5091:7041 searching 68 keys in branch page 238
mdb_node_search:5138:7041 found branch index 34 [00000000000000bd0000000000000001311e7dc5 -> 57], rc = -48128
mdb_node_search:5138:7041 found branch index 17 [000000000000005c0000000000000001311e7dc5 -> 18], rc = -23296
mdb_node_search:5138:7041 found branch index 8 [000000000000001d0000000000000001311e7dc5 -> 151], rc = -7168
mdb_node_search:5138:7041 found branch index 4 [000000000000000e0000000000000001311e7dc5 -> 28], rc = -3328
mdb_node_search:5138:7041 found branch index 2 [000000000000000200000000000000015b297cbd -> 133], rc = -256
mdb_node_search:5138:7041 found branch index 1 [00000000000000010000000000000001311e7dc5 -> 8], rc = 0
mdb_page_search_root:5314:7041 following index 1 for key [00000000000000010000000000000001311e7dc5]
mdb_cursor_push:5202:7041 pushing page 8 on db 2 cursor 0x7f403b2796b0
mdb_page_search_root:5342:7041 found leaf page 8 for key [00000000000000010000000000000001311e7dc5]
mdb_node_search:5091:7041 searching 3 keys in leaf page 8
mdb_node_search:5135:7041 found leaf index 1 [00000000000000010000000000000001b1f3f9b0], rc = -128
mdb_node_search:5135:7041 found leaf index 0 [00000000000000010000000000000001311e7dc5], rc = 0
mdb_cursor_set:6002:7041 ==> cursor placed on key [00000000000000010000000000000001311e7dc5]
mdb_txn_reset:2990:7041 mdb_txn_reset
mdb_txn_end:2919:7041 mdb_txn_end
mdb_txn_end:2931:7041 reset txn 1795r 0x7f4030000a10 on mdbenv 0x7f402c0008c0, root page 1291
mdb_txn_renew:2749:7041 mdb_txn_renew
mdb_txn_renew:2759:7041 renew txn 1795r 0x7f4030000a10 on mdbenv 0x7f402c0008c0, root page 1291
mdb_cursor_open:7408:7041 mdb_cursor_open
mdb_page_search:5445:7041 db 1 root page 1291 has flags 0x2
mdb_page_search_root:5342:7041 found leaf page 1291 for key [56617273]
mdb_node_search:5091:7041 searching 5 keys in leaf page 1291
mdb_node_search:5135:7041 found leaf index 2 [5472616e73616374696f6e52656673], rc = 2
mdb_node_search:5135:7041 found leaf index 3 [5472616e73616374696f6e73], rc = 2
mdb_node_search:5135:7041 found leaf index 4 [56617273], rc = 0
mdb_page_search:5445:7041 db 4 root page 530 has flags 0x1
mdb_cursor_get:6103:7041 mdb_cursor_get
mdb_cursor_first:6011:7041 mdb_cursor_first
mdb_page_search:5445:7041 db 4 root page 530 has flags 0x1
mdb_page_search_root:5290:7041 branch page 530 has 3 keys
mdb_page_search_root:5296:7041 found index 0 to page 535
mdb_cursor_push:5202:7041 pushing page 535 on db 4 cursor 0x7f4030000d00
mdb_page_search_root:5290:7041 branch page 535 has 68 keys
mdb_page_search_root:5296:7041 found index 0 to page 35
mdb_cursor_push:5202:7041 pushing page 35 on db 4 cursor 0x7f4030000d00
mdb_page_search_root:5342:7041 found leaf page 35 for key [null]
RM:b1f3f9b0(/tmp/data2) VarUUId:0000000000000000000000000000000000000000 [0 0 0 0 26 0 0 0 0 0 0 0 0 0 5 0 17 0 0 0 162 0 0 0 25 0 0 0 2 0 0 0 21 0 0 0 162 0 0 0 28 0 0 0 0 0 2 0 52 0 0 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 1 49 30 125 197 0 0 0 0 5 0 0 0 14 0 0 0 17 0 0 0 13 0 0 0 1 0 0 0 162 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2 0 0 0 0 0 0 0 5 0 0 0 14 0 0 0 5 0 0 0 13 0 0 0 5 0 0 0 162 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]
mdb_txn_renew:2749:7039 mdb_txn_renew
mdb_txn_renew:2759:7039 renew txn 1862r 0x7f4034000a10 on mdbenv 0xd483c0, root page 417
mdb_cursor_open:7408:7039 mdb_cursor_open
mdb_page_search:5445:7039 db 1 root page 417 has flags 0x2
mdb_page_search_root:5342:7039 found leaf page 417 for key [5472616e73616374696f6e73]
mdb_node_search:5091:7039 searching 5 keys in leaf page 417
mdb_node_search:5135:7039 found leaf index 2 [5472616e73616374696f6e52656673], rc = 8448
mdb_node_search:5135:7039 found leaf index 3 [5472616e73616374696f6e73], rc = 0
mdb_page_search:5445:7039 db 4 root page 276 has flags 0x1
mdb_cursor_get:6103:7039 mdb_cursor_get
mdb_cursor_first:6011:7039 mdb_cursor_first
mdb_page_search:5445:7039 db 4 root page 276 has flags 0x1
mdb_page_search_root:5290:7039 branch page 276 has 2 keys
mdb_page_search_root:5296:7039 found index 0 to page 710
mdb_cursor_push:5202:7039 pushing page 710 on db 4 cursor 0x7f4034000bd0
mdb_page_search_root:5290:7039 branch page 710 has 134 keys
mdb_page_search_root:5296:7039 found index 0 to page 43
mdb_cursor_push:5202:7039 pushing page 43 on db 4 cursor 0x7f4034000bd0
mdb_page_search_root:5342:7039 found leaf page 43 for key [null]
mdb_cursor_close:7493:7039 mdb_cursor_close
mdb_txn_reset:2990:7039 mdb_txn_reset
mdb_txn_end:2919:7039 mdb_txn_end
mdb_txn_end:2931:7039 reset txn 1862r 0x7f4034000a10 on mdbenv 0xd483c0, root page 417
GoshawkDBConsistencyChecker 2016/03/26 22:24:37.802540 Shutting down iterator
GoshawkDBConsistencyChecker 2016/03/26 22:24:37.802554 Err on finding first var in RM:311e7dc5(/tmp/data1): expected to find topology var, but found VarUUId:000000000000000000000000000000015b297cbd instead! ([0 0 0 0 30 0 0 0 0 0 0 0 2 0 3 0 189 124 41 91 1 0 0 0 0 2 0 0 2 0 0 0 9 0 0 0 162 0 0 0 17 0 0 0 47 0 0 0 57 0 0 0 55 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 91 41 124 189 0 0 0 0 4 0 0 0 1 0 4 0 3 0 0 0 0 0 0 0 13 0 0 0 162 0 0 0 21 0 0 0 42 0 0 0 21 0 0 0 2 0 0 0 17 0 0 0 7 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 91 41 124 189 0 0 0 0 0 1 2 3 4 0 0 0 0 0 0 0 0 0 2 0 12 0 0 0 1 0 1 0 197 125 30 49 1 0 0 0 17 0 0 0 11 0 0 0 176 249 243 177 1 0 0 0 13 0 0 0 11 0 0 0 189 124 41 91 0 0 0 0 9 0 0 0 11 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0])
--hQiwHBbRI9kgIhsi--