openldap-bugs

openldap-bugs@openldap.org

1 participants
20965 discussions

(ITS#8395) DH Params code causes startTLS failure while slapd initializes the code
by quanah＠openldap.org 02 Apr '16

02 Apr '16

Full_Name: Quanah Gibson-Mount Version: RE24 OS: Linux 2.6 URL: ftp://ftp.openldap.org/incoming/ Submission from: (NULL) (75.111.52.177) While testing the new DH params code for slapd, we found that there is an interval in which slapd will break for startTLS connections while it loads in the DH key. Example: Slapd is up and running, accepts startTLS connections just fine: Apr 2 21:13:08 zre-ldap002 slapd[4844]: conn=1004 fd=13 TLS established tls_ssf=256 ssf=256 tls_proto=TLSv1.2 tls_cipher=AES256-SHA256 Then we update olcTLSDHParamFile to add a DH key: Apr 2 21:13:09 zre-ldap002 slapd[4844]: conn=1005 op=22 MOD dn="cn=config" Apr 2 21:13:09 zre-ldap002 slapd[4844]: conn=1005 op=22 MOD attr=olcTLSDHParamFile Immediately after this, all startTLS attempts fail for the next few minutes: Apr 2 21:13:15 zre-ldap002 slapd[4844]: conn=1008 fd=14 ACCEPT from IP=10.137.242.52:48327 (IP=10.137.242.52:389) Apr 2 21:13:15 zre-ldap002 slapd[4844]: conn=1008 op=0 EXT oid=1.3.6.1.4.1.1466.20037 Apr 2 21:13:15 zre-ldap002 slapd[4844]: conn=1008 op=0 STARTTLS Apr 2 21:13:15 zre-ldap002 slapd[4844]: conn=1008 op=0 RESULT oid= err=52 etime=0.000078 text=Could not initialize TLS Apr 2 21:13:16 zre-ldap002 slapd[4844]: conn=1008 op=1 UNBIND Apr 2 21:13:16 zre-ldap002 slapd[4844]: conn=1008 fd=14 closed Apr 2 21:13:16 zre-ldap002 slapd[4844]: conn=1009 fd=14 ACCEPT from IP=10.137.242.52:48328 (IP=10.137.242.52:389) Apr 2 21:13:16 zre-ldap002 slapd[4844]: conn=1009 op=0 EXT oid=1.3.6.1.4.1.1466.20037 Apr 2 21:13:16 zre-ldap002 slapd[4844]: conn=1009 op=0 STARTTLS Apr 2 21:13:16 zre-ldap002 slapd[4844]: conn=1009 op=0 RESULT oid= err=52 etime=0.000054 text=Could not initialize TLS Apr 2 21:13:16 zre-ldap002 slapd[4844]: conn=1009 op=1 UNBIND Apr 2 21:13:16 zre-ldap002 slapd[4844]: conn=1009 fd=14 closed Apr 2 21:13:17 zre-ldap002 slapd[4844]: connD1D1010 fd=14 ACCEPT from IP=10.137.242.52:48329 (IP=10.137.242.52:389) Apr 2 21:13:18 zre-ldap002 slapd[4844]: conn=1010 op=0 EXT oid=1.3.6.1.4.1.1466.20037 Apr 2 21:13:18 zre-ldap002 slapd[4844]: conn=1010 op=0 STARTTLS Apr 2 21:13:18 zre-ldap002 slapd[4844]: conn=1010 op=0 RESULT oid= err=52 etime=0.000124 text=Could not initialize TLS Apr 2 21:13:18 zre-ldap002 slapd[4844]: conn=1010 op=1 UNBIND Apr 2 21:13:18 zre-ldap002 slapd[4844]: conn=1010 fd=14 closed Apr 2 21:13:18 zre-ldap002 slapd[4844]: conn=1011 fd=14 ACCEPT from IP=10.137.242.52:48330 (IP=10.137.242.52:389) Apr 2 21:13:18 zre-ldap002 slapd[4844]: conn=1011 op=0 EXT oid=1.3.6.1.4.1.1466.20037 Apr 2 21:13:18 zre-ldap002 slapd[4844]: conn=1011 op=0 STARTTLS Apr 2 21:13:18 zre-lda0202 slapd[4844]: conn=1011 op=0 RESULT oid= err=52 etime=0.000075 text=Could not initialize TLS Apr 2 21:13:18 zre-ldap002 slapd[4844]: conn=1011 op=1 UNBIND Apr 2 21:13:18 zre-ldap002 slapd[4844]: conn=1011 fd=14 closed Apr 2 21:13:20 zre-ldap002 slapd[4844]: conn=1012 fd=14 ACCEPT from IP=10.137.242.52:48331 (IP=10.137.242.52:389) Apr 2 21:13:20 zre-ldap002 slapd[4844]: conn=1012 op=0 EXT oid=1.3.6.1.4.1.1466.20037 Apr 2 21:13:20 zre-ldap002 slapd[4844]: conn=1012 op=0 STARTTLS Apr 2 21:13:20 zre-ldap002 slapd[4844]: conn=1012 op=0 RESULT oid= err=52 etime=0.000098 text=Could not initialize TLS Apr 2 21:13:20 zre-ldap002 slapd[4844]: conn=1012 op=1 UNBIND Apr 2 21:13:20 zre-ldap002 slapd[4844]: conn=1012 fd=14 closed Apr 2 21:13:20 zre-ldap002 slapd[4844]: conn=1013 fd=14 ACCEPT from IP=10.137.242.52:48332 (IP=10.137.242.52:389) Apr 2 21:13:20 zre-ldap002 slapd[4844]: conn=1013 op=0 EXT oid=1.3.6.1.4.1.1466.20037 Apr 2 21:13:20 zre-ldap002 slapd[4844]: conn=1013 op=0 STARTTLS Apr 2 21:13:20 zre-ldap002 slapd[4844]: conn=1013 op=0 RESULT oid= err=52 etime=0.000062 text=Could not initialize TLS Apr 2 21:13:20 zre-ldap002 slapd[4844]: conn=1013 op=1 UNBIND Apr 2 21:13:20 zre-ldap002 slapd[4844]: conn=1013 fd=14 closed Apr 2 21:13"22 zre-ldap0 s slapd[4844]: conn=1014 fd=14 ACCEPT from IP=10.137.242.52:48333 (IP=10.137.242.52:389) Apr 2 21:13:22 zre-ldap002 slapd[4844]: conn=1014 op=0 EXT oid=1.3.6.1.4.1.1466.20037 Apr 2 21:13:22 zre-ldap002 slapd[4844]: conn=1014 op=0 STARTTLS Apr 2 21:13:22 zre-ldap002 slapd[4844]: conn=1014 op=0 RESULT oid= err=52 etime=0.000108 text=Could not initialize TLS Apr 2 21:13:22 zre-ldap002 slapd[4844]: conn=1014 op=1 UNBIND Apr 2 21:13:22 zre-ldap002 slapd[4844]: conn=1014 fd=14 closed Apr 2 21:13:22 zre-ldap002 slapd[4844]: conn=1015 fd=14 ACCEPT from IP=10.137.242.52:48334 (IP=10.137.242.52:389) Apr 2 21:13:22 zre-ldap002 slapd[4844]: conn=1015 op=0 EXT oid=1.3.6.1.4.1.1466.20037 Apr 2 21:13:22 zre-ldap002 slapd[4844]: conn=1015 op=0 STARTTLS Apr 2 21:13:22 zre-ldap002 slapd[4844]: conn=1015 op=0 RESULT oid= err=52 etime=0.000066 text=Could not initialize TLS Apr 2 21:13:22 zre-ldap002 slapd[4844]: conn=1015 op=1 UNBIND .... Apr 2 21:14:01 zre-ldap002 slapd[4844]: conn=1022d%d=14 ACCEPT from IP=10.137.242.52:48339 (IP=10.137.242.52:389) Apr 2 21:14:01 zre-ldap002 slapd[4844]: conn=1022 op=0 EXT oid=1.3.6.1.4.1.1466.20037 Apr 2 21:14:01 zre-ldap002 slapd[4844]: conn=1022 op=0 STARTTLS Apr 2 21:14:01 zre-ldap002 slapd[4844]: conn=1022 op=0 RESULT oid= err=52 etime=0.000143 text=Could not initialize TLS Apr 2 21:14:01 zre-ldap002 slapd[4844]: conn=1022 fd=14 closed (connection lost) Eventually it recovers: Apr 2 21:16:02 zre-ldap002 slapd[4844]: conn=1027 fd=14 ACCEPT from IP=10.137.242.52:48340 (IP=10.137.242.52:389) Apr 2 21:16:02 zre-ldap002 slapd[4844]: conn=1027 op=0 EXT oid=1.3.6.1.4.1.1466.20037 Apr 2 21:16:02 zre-ldap002 slapd[4844]: conn=1027 op=0 STARTTLS Apr 2 21:16:02 zre-ldap002 slapd[4844]: connD1D1027 op=0 RESULT oid= err=0 etime=0.000085 text= Apr 2 21:16:02 zre-ldap002 slapd[4844]: conn=1027 fd=14 TLS established tls_ssf=128 ssf=128 tls_proto=TLSv1.2 tls_cipher=AES128-SHA256 My guess is that startTLS is essentially broken while slapd spends time loading in the DH key. I would think that during this time, slapd should be deferring connections rather than accepting them immediately.

1 0

(ITS#8394) LMDB fails GCC5 without -fno-strict-aliasing
by bdallen＠nps.edu 01 Apr '16

01 Apr '16

Full_Name: Bruce Allen Version: 2.4.44 OS: Fedora 23 URL: ftp://ftp.openldap.org/incoming/ Submission from: (NULL) (205.155.65.226) LMDB v0.9.18 crashes with segmentation fault in mdb.c line 6590 when compiled using these compilers: * gcc (GCC) 5.3.1 20151207 (Red Hat 5.3.1-2) * x86_64-w64-mingw32-gcc (GCC) 5.2.0 20150716 (Fedora MinGW 5.2.0-1.fc23) The crash happens afterrititing the 12'th item (with the same key but different value using flags MDB_NODUPDATA and MDB_DUPSORT). The problem goes away when compiling mdb.c with the -fno-strict-aliasing flag.

1 0

(ITS#8393) LMDB - MDB_GET_BOTH broken on non-dup value
by hyc＠openldap.org 27 Mar '16

27 Mar '16

Full_Name: Howard Chu Version: 0.9.18 OS: Linux URL: ftp://ftp.openldap.org/incoming/ Submission from: (NULL) (78.155.228.110) Submitted by: hyc Using mdb_cursor_get(MDB_GET_BOTH) doesn't return the data item if the record is not a dup (i.e., there's only a single value under the key) even though it matches. This doesn't affect slapd because (1) when we use this command, the key always has more than 1 value and (2) when we use it, the data item we passed in is exactly the same as what we would get returned, on a match. This affects other apps where both (1) and (2) are not true, e.g. a compare function is used that only compares a subset of the data, in order to retrieve the full record.

1 0

Re: (ITS#8392) Opening multiple databases from the same process
by matthew＠wellquite.org 27 Mar '16

27 Mar '16

Fixed. The short version is it's definitely a problem of my own making, though it's not related to threading. It's an oversight in the design of my own bindings which only causes an issue when you open multiple databases at the same time. I shall be able to fix without a problem in my bindings. Thank you for your help, and sorry for wasting your time. Kind regards, Matthew

1 0

Re: (ITS#8392) Opening multiple databases from the same process
by hyc＠symas.com 26 Mar '16

26 Mar '16

Nothing immediately obvious jumps out. You might try adding some mdb_page_list() calls in here, maybe at each point where it pushes a new page onto the cursor. -- -- Howard Chu CTO, Symas Corp. http://www.symas.com Director, Highland Sun http://highlandsun.com/hyc/ Chief Architect, OpenLDAP http://www.openldap.org/project/

1 0

Re: (ITS#8392) Opening multiple databases from the same process
by matthew＠wellquite.org 26 Mar '16

26 Mar '16

--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--

1 0

Re: (ITS#8392) Opening multiple databases from the same process
by matthew＠wellquite.org 26 Mar '16

26 Mar '16

--rwEMma7ioTxnRzrJ Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Hi Howard, Thanks for the quick reply. On Sat, Mar 26, 2016 at 06:44:29PM +0000, Howard Chu wrote: > Is this entire task read-only, nobody is modifying any of the DBs while > these readers are iterating thru the DBs? This entire process is read only, and indeed the transactions that contain cursors are marked RDONLY. No other process is running that accesses any of these databases. > You might consider compiling LMDB with MDB_DEBUG defined, enabling debug > output, and then watching the cursor activity. Of course, the act of writing > debug messages will impact thread scheduling, so it may not reveal what's > going on. Ok, I've done all that and got debug output going. I can still provoke the same problem easily. A log is attached. Ultimately, both cursors should start on a key 0000000000000000000000000000000000000000, but the second cursor/db discovers it actually starts on 0000000000000000000000000000000141d8872b. 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? Matthew --rwEMma7ioTxnRzrJ Content-Type: text/plain; charset=us-ascii Content-Disposition: attachment; filename=log GoshawkDBConsistencyChecker 2016/03/26 20:58:25.362121 [./consistencychecker /tmp/data1 /tmp/data2] GoshawkDBConsistencyChecker 2016/03/26 20:58:25.362201 ...loading from /tmp/data1 GoshawkDBConsistencyChecker 2016/03/26 20:58:25.362223 Starting disk server on /tmp/data1 mdb_env_open2:4175 opened database version 1, pagesize 4096 mdb_env_open2:4176 using meta page 0 mdb_env_open2:4177 depth: 1 mdb_env_open2:4178 entries: 5 mdb_env_open2:4179 branch pages: 0 mdb_env_open2:4180 leaf pages: 1 mdb_env_open2:4181 overflow pages: 0 mdb_env_open2:4182 root: 1192 mdb_env_open:4803 opened dbenv 0xd363c0 mdb_txn_begin:2850 begin txn 1785w 0xd37660 on mdbenv 0xd363c0, root page 1192 mdb_page_search:5426 db 1 root page 1192 has flags 0x2 mdb_page_search_root:5323 found leaf page 1192 for key [5472616e73616374696f6e52656673] mdb_node_search:5072 searching 5 keys in leaf page 1192 mdb_node_search:5116 found leaf index 2 [5472616e73616374696f6e52656673], rc = 0 mdb_cursor_set:5980 ==> cursor placed on key [5472616e73616374696f6e52656673] mdb_page_search:5426 db 1 root page 1192 has flags 0x2 mdb_page_search_root:5323 found leaf page 1192 for key [56617273] mdb_node_search:5072 searching 5 keys in leaf page 1192 mdb_node_search:5116 found leaf index 2 [5472616e73616374696f6e52656673], rc = 2 mdb_node_search:5116 found leaf index 3 [5472616e73616374696f6e73], rc = 2 mdb_node_search:5116 found leaf index 4 [56617273], rc = 0 mdb_cursor_set:5980 ==> cursor placed on key [56617273] mdb_page_search:5426 db 1 root page 1192 has flags 0x2 mdb_page_search_root:5323 found leaf page 1192 for key [5472616e73616374696f6e73] mdb_node_search:5072 searching 5 keys in leaf page 1192 mdb_node_search:5116 found leaf index 2 [5472616e73616374696f6e52656673], rc = 8448 mdb_node_search:5116 found leaf index 3 [5472616e73616374696f6e73], rc = 0 mdb_cursor_set:5980 ==> cursor placed on key [5472616e73616374696f6e73] mdb_txn_end:2918 empty-commit txn 1785w 0xd37660 on mdbenv 0xd363c0, root page 1192 mdb_txn_begin:2850 begin txn 1784r 0x7f36e8000a10 on mdbenv 0xd363c0, root page 1192 mdb_txn_end:2918 abort txn 1784r 0x7f36e8000a10 on mdbenv 0xd363c0, root page 1192 mdb_txn_begin:2850 begin txn 1784r 0x7f36e8000a10 on mdbenv 0xd363c0, root page 1192 mdb_get:5556 ===> get db 3 key [0000000000000000000000000000000000000000] mdb_page_search:5426 db 1 root page 1192 has flags 0x2 mdb_page_search_root:5323 found leaf page 1192 for key [56617273] mdb_node_search:5072 searching 5 keys in leaf page 1192 mdb_node_search:5116 found leaf index 2 [5472616e73616374696f6e52656673], rc = 2 mdb_node_search:5116 found leaf index 3 [5472616e73616374696f6e73], rc = 2 mdb_node_search:5116 found leaf index 4 [56617273], rc = 0 mdb_page_search:5426 db 3 root page 854 has flags 0x1 mdb_page_search:5426 db 3 root page 854 has flags 0x1 mdb_page_search_root:5271 branch page 854 has 2 keys mdb_page_search_root:5277 found index 0 to page 868 mdb_node_search:5072 searching 2 keys in branch page 854 mdb_node_search:5119 found branch index 1 [00000000000001f500000006000000016634c9ee -> 734], rc = -1 mdb_page_search_root:5295 following index 0 for key [0000000000000000000000000000000000000000] mdb_cursor_push:5183 pushing page 868 on db 3 cursor 0x7f36f0d5e6c0 mdb_page_search_root:5271 branch page 868 has 135 keys mdb_page_search_root:5277 found index 0 to page 96 mdb_node_search:5072 searching 135 keys in branch page 868 mdb_node_search:5119 found branch index 67 [00000000000000c600000006000000016634c9ee -> 65], rc = -50688 mdb_node_search:5119 found branch index 33 [000000000000005a00000006000000016634c9ee -> 61], rc = -23040 mdb_node_search:5119 found branch index 16 [000000000000001900000006000000016634c9ee -> 964], rc = -6400 mdb_node_search:5119 found branch index 8 [000000000000000f00000006000000016634c9ee -> 72], rc = -3840 mdb_node_search:5119 found branch index 4 [000000000000000500000006000000016634c9ee -> 124], rc = -1280 mdb_node_search:5119 found branch index 2 [000000000000000100000004000000016634c9ee -> 1021], rc = -256 mdb_node_search:5119 found branch index 1 [000000000000000000000006000000016634c9ee -> 869], rc = -1536 mdb_page_search_root:5295 following index 0 for key [0000000000000000000000000000000000000000] mdb_cursor_push:5183 pushing page 96 on db 3 cursor 0x7f36f0d5e6c0 mdb_page_search_root:5323 found leaf page 96 for key [0000000000000000000000000000000000000000] mdb_node_search:5072 searching 7 keys in leaf page 96 mdb_node_search:5116 found leaf index 3 [000000000000000000000000000000019f23085d], rc = -256 mdb_node_search:5116 found leaf index 1 [0000000000000000000000000000000141d8872b], rc = -256 mdb_node_search:5116 found leaf index 0 [0000000000000000000000000000000000000000], rc = 0 mdb_cursor_set:5980 ==> cursor placed on key [0000000000000000000000000000000000000000] mdb_get:5556 ===> get db 4 key [000000000000000100000000000000019f23085d] mdb_page_search:5426 db 1 root page 1192 has flags 0x2 mdb_page_search_root:5323 found leaf page 1192 for key [5472616e73616374696f6e73] mdb_node_search:5072 searching 5 keys in leaf page 1192 mdb_node_search:5116 found leaf index 2 [5472616e73616374696f6e52656673], rc = 8448 mdb_node_search:5116 found leaf index 3 [5472616e73616374696f6e73], rc = 0 mdb_page_search:5426 db 4 root page 592 has flags 0x1 mdb_page_search:5426 db 4 root page 592 has flags 0x1 mdb_page_search_root:5271 branch page 592 has 128 keys mdb_page_search_root:5277 found index 0 to page 37 mdb_node_search:5072 searching 128 keys in branch page 592 mdb_node_search:5119 found branch index 64 [00000000000001fe000000000000000141d8872b -> 565], rc = -1 mdb_node_search:5119 found branch index 32 [00000000000000fe00000000000000019f23085d -> 461], rc = -64768 mdb_node_search:5119 found branch index 16 [000000000000007300000000000000016634c9ee -> 323], rc = -29184 mdb_node_search:5119 found branch index 8 [000000000000003f000000000000000141d8872b -> 20], rc = -15872 mdb_node_search:5119 found branch index 4 [000000000000001200000000000000019f23085d -> 448], rc = -4352 mdb_node_search:5119 found branch index 2 [000000000000000200000000000000019f23085d -> 141], rc = -256 mdb_node_search:5119 found branch index 1 [000000000000000100000000000000019f23085d -> 142], rc = 0 mdb_page_search_root:5295 following index 1 for key [000000000000000100000000000000019f23085d] mdb_cursor_push:5183 pushing page 142 on db 4 cursor 0x7f36f0d5e6c0 mdb_page_search_root:5323 found leaf page 142 for key [000000000000000100000000000000019f23085d] mdb_node_search:5072 searching 3 keys in leaf page 142 mdb_node_search:5116 found leaf index 1 [0000000000000002000000000000000141d8872b], rc = -256 mdb_node_search:5116 found leaf index 0 [000000000000000100000000000000019f23085d], rc = 0 mdb_cursor_set:5980 ==> cursor placed on key [000000000000000100000000000000019f23085d] mdb_txn_end:2918 reset txn 1784r 0x7f36e8000a10 on mdbenv 0xd363c0, root page 1192 GoshawkDBConsistencyChecker 2016/03/26 20:58:25.364770 ...loading from /tmp/data2 GoshawkDBConsistencyChecker 2016/03/26 20:58:25.364807 Starting disk server on /tmp/data2 mdb_env_open2:4175 opened database version 1, pagesize 4096 mdb_env_open2:4176 using meta page 1 mdb_env_open2:4177 depth: 1 mdb_env_open2:4178 entries: 5 mdb_env_open2:4179 branch pages: 0 mdb_env_open2:4180 leaf pages: 1 mdb_env_open2:4181 overflow pages: 0 mdb_env_open2:4182 root: 1239 mdb_env_open:4803 opened dbenv 0x7f36e00008c0 mdb_txn_begin:2850 begin txn 1858w 0x7f36e0001b80 on mdbenv 0x7f36e00008c0, root page 1239 mdb_page_search:5426 db 1 root page 1239 has flags 0x2 mdb_page_search_root:5323 found leaf page 1239 for key [5472616e73616374696f6e73] mdb_node_search:5072 searching 5 keys in leaf page 1239 mdb_node_search:5116 found leaf index 2 [5472616e73616374696f6e52656673], rc = 8448 mdb_node_search:5116 found leaf index 3 [5472616e73616374696f6e73], rc = 0 mdb_cursor_set:5980 ==> cursor placed on key [5472616e73616374696f6e73] mdb_page_search:5426 db 1 root page 1239 has flags 0x2 mdb_page_search_root:5323 found leaf page 1239 for key [5472616e73616374696f6e52656673] mdb_node_search:5072 searching 5 keys in leaf page 1239 mdb_node_search:5116 found leaf index 2 [5472616e73616374696f6e52656673], rc = 0 mdb_cursor_set:5980 ==> cursor placed on key [5472616e73616374696f6e52656673] mdb_page_search:5426 db 1 root page 1239 has flags 0x2 mdb_page_search_root:5323 found leaf page 1239 for key [56617273] mdb_node_search:5072 searching 5 keys in leaf page 1239 mdb_node_search:5116 found leaf index 2 [5472616e73616374696f6e52656673], rc = 2 mdb_node_search:5116 found leaf index 3 [5472616e73616374696f6e73], rc = 2 mdb_node_search:5116 found leaf index 4 [56617273], rc = 0 mdb_cursor_set:5980 ==> cursor placed on key [56617273] mdb_txn_end:2918 empty-commit txn 1858w 0x7f36e0001b80 on mdbenv 0x7f36e00008c0, root page 1239 mdb_txn_begin:2850 begin txn 1857r 0x7f36e4000a10 on mdbenv 0x7f36e00008c0, root page 1239 mdb_txn_end:2918 abort txn 1857r 0x7f36e4000a10 on mdbenv 0x7f36e00008c0, root page 1239 mdb_txn_begin:2850 begin txn 1857r 0x7f36e4000a10 on mdbenv 0x7f36e00008c0, root page 1239 mdb_get:5556 ===> get db 4 key [0000000000000000000000000000000000000000] mdb_page_search:5426 db 1 root page 1239 has flags 0x2 mdb_page_search_root:5323 found leaf page 1239 for key [56617273] mdb_node_search:5072 searching 5 keys in leaf page 1239 mdb_node_search:5116 found leaf index 2 [5472616e73616374696f6e52656673], rc = 2 mdb_node_search:5116 found leaf index 3 [5472616e73616374696f6e73], rc = 2 mdb_node_search:5116 found leaf index 4 [56617273], rc = 0 mdb_page_search:5426 db 4 root page 633 has flags 0x1 mdb_page_search:5426 db 4 root page 633 has flags 0x1 mdb_page_search_root:5271 branch page 633 has 2 keys mdb_page_search_root:5277 found index 0 to page 634 mdb_node_search:5072 searching 2 keys in branch page 633 mdb_node_search:5119 found branch index 1 [00000000000000f900000006000000016634c9ee -> 115], rc = -63744 mdb_page_search_root:5295 following index 0 for key [0000000000000000000000000000000000000000] mdb_cursor_push:5183 pushing page 634 on db 4 cursor 0x7f36f055d6c0 mdb_page_search_root:5271 branch page 634 has 68 keys mdb_page_search_root:5277 found index 0 to page 56 mdb_node_search:5072 searching 68 keys in branch page 634 mdb_node_search:5119 found branch index 34 [000000000000006100000006000000016634c9ee -> 562], rc = -24832 mdb_node_search:5119 found branch index 17 [000000000000001c00000006000000016634c9ee -> 18], rc = -7168 mdb_node_search:5119 found branch index 8 [000000000000000e00000006000000016634c9ee -> 160], rc = -3584 mdb_node_search:5119 found branch index 4 [000000000000000400000006000000016634c9ee -> 405], rc = -1024 mdb_node_search:5119 found branch index 2 [000000000000000100000004000000016634c9ee -> 489], rc = -256 mdb_node_search:5119 found branch index 1 [000000000000000000000006000000016634c9ee -> 636], rc = -1536 mdb_page_search_root:5295 following index 0 for key [0000000000000000000000000000000000000000] mdb_cursor_push:5183 pushing page 56 on db 4 cursor 0x7f36f055d6c0 mdb_page_search_root:5323 found leaf page 56 for key [0000000000000000000000000000000000000000] mdb_node_search:5072 searching 7 keys in leaf page 56 mdb_node_search:5116 found leaf index 3 [000000000000000000000000000000019f23085d], rc = -256 mdb_node_search:5116 found leaf index 1 [0000000000000000000000000000000141d8872b], rc = -256 mdb_node_search:5116 found leaf index 0 [0000000000000000000000000000000000000000], rc = 0 mdb_cursor_set:5980 ==> cursor placed on key [0000000000000000000000000000000000000000] mdb_get:5556 ===> get db 2 key [000000000000000100000000000000019f23085d] mdb_page_search:5426 db 1 root page 1239 has flags 0x2 mdb_page_search_root:5323 found leaf page 1239 for key [5472616e73616374696f6e73] mdb_node_search:5072 searching 5 keys in leaf page 1239 mdb_node_search:5116 found leaf index 2 [5472616e73616374696f6e52656673], rc = 8448 mdb_node_search:5116 found leaf index 3 [5472616e73616374696f6e73], rc = 0 mdb_page_search:5426 db 2 root page 606 has flags 0x1 mdb_page_search:5426 db 2 root page 606 has flags 0x1 mdb_page_search_root:5271 branch page 606 has 128 keys mdb_page_search_root:5277 found index 0 to page 8 mdb_node_search:5072 searching 128 keys in branch page 606 mdb_node_search:5119 found branch index 64 [0000000000000219000000000000000141d8872b -> 414], rc = -2 mdb_node_search:5119 found branch index 32 [00000000000000fe00000000000000019f23085d -> 832], rc = -64768 mdb_node_search:5119 found branch index 16 [000000000000007400000000000000016634c9ee -> 85], rc = -29440 mdb_node_search:5119 found branch index 8 [000000000000003f000000000000000141d8872b -> 108], rc = -15872 mdb_node_search:5119 found branch index 4 [000000000000001200000000000000019f23085d -> 10], rc = -4352 mdb_node_search:5119 found branch index 2 [000000000000000200000000000000019f23085d -> 19], rc = -256 mdb_node_search:5119 found branch index 1 [000000000000000100000000000000019f23085d -> 33], rc = 0 mdb_page_search_root:5295 following index 1 for key [000000000000000100000000000000019f23085d] mdb_cursor_push:5183 pushing page 33 on db 2 cursor 0x7f36f055d6c0 mdb_page_search_root:5323 found leaf page 33 for key [000000000000000100000000000000019f23085d] mdb_node_search:5072 searching 3 keys in leaf page 33 mdb_node_search:5116 found leaf index 1 [0000000000000002000000000000000141d8872b], rc = -256 mdb_node_search:5116 found leaf index 0 [000000000000000100000000000000019f23085d], rc = 0 mdb_cursor_set:5980 ==> cursor placed on key [000000000000000100000000000000019f23085d] mdb_txn_end:2918 reset txn 1857r 0x7f36e4000a10 on mdbenv 0x7f36e00008c0, root page 1239 mdb_txn_renew:2750 renew txn 1857r 0x7f36e4000a10 on mdbenv 0x7f36e00008c0, root page 1239 mdb_page_search:5426 db 1 root page 1239 has flags 0x2 mdb_page_search_root:5323 found leaf page 1239 for key [56617273] mdb_node_search:5072 searching 5 keys in leaf page 1239 mdb_node_search:5116 found leaf index 2 [5472616e73616374696f6e52656673], rc = 2 mdb_node_search:5116 found leaf index 3 [5472616e73616374696f6e73], rc = 2 mdb_node_search:5116 found leaf index 4 [56617273], rc = 0 mdb_page_search:5426 db 4 root page 633 has flags 0x1 mdb_page_search:5426 db 4 root page 633 has flags 0x1 mdb_page_search_root:5271 branch page 633 has 2 keys mdb_page_search_root:5277 found index 0 to page 634 mdb_cursor_push:5183 pushing page 634 on db 4 cursor 0x7f36e4000bd0 mdb_page_search_root:5271 branch page 634 has 68 keys mdb_page_search_root:5277 found index 0 to page 56 mdb_cursor_push:5183 pushing page 56 on db 4 cursor 0x7f36e4000bd0 mdb_page_search_root:5323 found leaf page 56 for key [null] RM:9f23085d(/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 159 35 8 93 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:2750 renew txn 1784r 0x7f36e8000a10 on mdbenv 0xd363c0, root page 1192 mdb_page_search:5426 db 1 root page 1192 has flags 0x2 mdb_page_search_root:5323 found leaf page 1192 for key [5472616e73616374696f6e73] mdb_node_search:5072 searching 5 keys in leaf page 1192 mdb_node_search:5116 found leaf index 2 [5472616e73616374696f6e52656673], rc = 8448 mdb_node_search:5116 found leaf index 3 [5472616e73616374696f6e73], rc = 0 mdb_page_search:5426 db 4 root page 592 has flags 0x1 mdb_page_search:5426 db 4 root page 592 has flags 0x1 mdb_page_search_root:5271 branch page 592 has 128 keys mdb_page_search_root:5277 found index 0 to page 37 mdb_cursor_push:5183 pushing page 37 on db 4 cursor 0x7f36e8000bd0 mdb_page_search_root:5323 found leaf page 37 for key [null] mdb_txn_end:2918 reset txn 1784r 0x7f36e8000a10 on mdbenv 0xd363c0, root page 1192 GoshawkDBConsistencyChecker 2016/03/26 20:58:25.367498 Shutting down iterator GoshawkDBConsistencyChecker 2016/03/26 20:58:25.367507 Err on finding first var in RM:6634c9ee(/tmp/data1): expected to find topology var, but found VarUUId:0000000000000000000000000000000141d8872b instead! ([0 0 0 0 30 0 0 0 0 0 0 0 2 0 3 0 43 135 216 65 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 65 216 135 43 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 65 216 135 43 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 238 201 52 102 1 0 0 0 17 0 0 0 11 0 0 0 93 8 35 159 1 0 0 0 13 0 0 0 11 0 0 0 43 135 216 65 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]) --rwEMma7ioTxnRzrJ--

1 0

Re: (ITS#8392) Opening multiple databases from the same process
by hyc＠symas.com 26 Mar '16

26 Mar '16

matthew(a)wellquite.org wrote: > Full_Name: Matthew Sackman > Version: LMDB 0.9.18 > OS: Linux > URL: ftp://ftp.openldap.org/incoming/ > Submission from: (NULL) (109.149.185.170) > > > Linux koba 4.4.0-1-amd64 #1 SMP Debian 4.4.6-1 (2016-03-17) x86_64 GNU/Linux > LMDB 0.9.18 (compiled locally) > > I'm currently writing a program that iterates through multiple LMDB databases in > order to check differences between them. On each database I have one > long-running read-only txn with a cursor, and I'm walking through all the > databases at the same time. > > I'm seeing some very odd behaviour. For example, cursor.Get with FIRST is not > always returning the first item in the table (which I happen to know exactly > what it should be). The behaviour is non-deterministic - different runs produce > different results. > > I've searched through the docs and I can't find any statements regarding opening > multiple dbs from the same process. Is this supported? > > I'm writing this in Go, using my own bindings. I'm pretty certain that I'm doing > all the threading correctly and I certainly get this same issue regardless of > whether I'm using NOTLS or not (with my bindings, it shouldn't be necessary > because I'm locking go-routines to os-threads), plus these are the same bindings > that I've used throughout GoshawkDB and I've not come across this problem until > now. > > I can guarantee that each DB that I open will be opened in a different OS thread > and that no single OS thread will ever access different DBs. Is this entire task read-only, nobody is modifying any of the DBs while these readers are iterating thru the DBs? I've only used Go very briefly. I would be quite suspicious of that goroutine behavior but don't have any insight there. You might consider compiling LMDB with MDB_DEBUG defined, enabling debug output, and then watching the cursor activity. Of course, the act of writing debug messages will impact thread scheduling, so it may not reveal what's going on. -- -- Howard Chu CTO, Symas Corp. http://www.symas.com Director, Highland Sun http://highlandsun.com/hyc/ Chief Architect, OpenLDAP http://www.openldap.org/project/

1 0

(ITS#8392) Opening multiple databases from the same process
by matthew＠wellquite.org 26 Mar '16

26 Mar '16

Full_Name: Matthew Sackman Version: LMDB 0.9.18 OS: Linux URL: ftp://ftp.openldap.org/incoming/ Submission from: (NULL) (109.149.185.170) Linux koba 4.4.0-1-amd64 #1 SMP Debian 4.4.6-1 (2016-03-17) x86_64 GNU/Linux LMDB 0.9.18 (compiled locally) I'm currently writing a program that iterates through multiple LMDB databases in order to check differences between them. On each database I have one long-running read-only txn with a cursor, and I'm walking through all the databases at the same time. I'm seeing some very odd behaviour. For example, cursor.Get with FIRST is not always returning the first item in the table (which I happen to know exactly what it should be). The behaviour is non-deterministic - different runs produce different results. I've searched through the docs and I can't find any statements regarding opening multiple dbs from the same process. Is this supported? I'm writing this in Go, using my own bindings. I'm pretty certain that I'm doing all the threading correctly and I certainly get this same issue regardless of whether I'm using NOTLS or not (with my bindings, it shouldn't be necessary because I'm locking go-routines to os-threads), plus these are the same bindings that I've used throughout GoshawkDB and I've not come across this problem until now. I can guarantee that each DB that I open will be opened in a different OS thread and that no single OS thread will ever access different DBs.

1 0

(ITS#8391) peername string starts with "IP=" not "IP:"
by subbarao＠computer.org 25 Mar '16

25 Mar '16

Full_Name: Kartik Subbarao Version: 2.4.41 OS: Ubuntu 14.04 URL: ftp://ftp.openldap.org/incoming/ Submission from: (NULL) (108.16.127.8) There is an error in the ACL section of the OpenLDAP Software 2.4 Administrator's guide: http://www.openldap.org/devel/admin/slapdconf2.html In the following line: by peername.regex=IP:10\..+ read Instead of "IP:", the correct syntax is "IP=". by peername.regex=IP=10\..+ read

1 0

Jump to page:

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

openldap-bugs