I'm working on updating the OpenBSD port of OpenLDAP to 2.6.2 (it's currently stuck at 2.4.59).
In 2.5 kqueue support was added to slapd for BSDs, but it's not working correctly on OpenBSD. If slapd runs as a daemon, errors like these are seen:
slap_client_connect: URI=ldaps://XXX Warning, ldap_start_tls failed (1) mdb_opinfo_get: err Invalid argument(22)
However if slapd is run in the foreground with -d, things are ok.
They are also OK if kqueue is disabled (by neutering the autoconf check) so this isn't blocking me updating the port but I thought I'd write up what I have in case someone has any ideas what might be up or anything they'd like me to try and report back on.
Here are some log excerpts:
17:23:44.692: slapd starting 17:23:44.692: daemon: added 3r listener=0x0 17:23:44.692: daemon: added 6r listener=0x100263797200 17:23:44.692: daemon: added 7r listener=0x100263785400 17:23:44.692: daemon: kqueue: listen=6 active_threads=0 tvp=zero 17:23:44.692: daemon: kqueue: listen=7 active_threads=0 tvp=zero 17:23:44.692: daemon: activity on 1 descriptor 17:23:44.692: daemon: activity on: 17:23:44.692: 17:23:44.692: daemon: kqueue: listen=6 active_threads=0 tvp=zero 17:23:44.692: daemon: kqueue: listen=7 active_threads=0 tvp=zero 17:23:44.692: >>> dnNormalize: <cn=Consumer 101> 17:23:44.692: <<< dnNormalize: <cn=consumer 101> 17:23:44.692: =>do_syncrepl rid=101 17:23:44.763: slap_client_connect: URI=ldaps://XXXXXXXXXXXXXXX Warning, ldap_start_tls failed (1) 17:23:44.781: => mdb_entry_get: ndn: "dc=XXXXXXX,dc=XXX" 17:23:44.782: => mdb_entry_get: oc: "(null)", at: "contextCSN" 17:23:44.782: mdb_opinfo_get: err Invalid argument(22) 17:23:44.782: =>do_syncrep2 rid=101 17:23:44.782: daemon: added 9r listener=0x0 17:23:44.783: daemon: activity on 1 descriptor 17:23:44.783: daemon: activity on: 17:23:44.783: 17:23:44.783: daemon: kqueue: listen=6 active_threads=0 tvp=NULL 17:23:44.783: daemon: kqueue: listen=7 active_threads=0 tvp=NULL 17:23:44.800: daemon: activity on 1 descriptor 17:23:44.800: daemon: activity on: 17:23:44.800: 9r 17:23:44.800: 17:23:44.800: daemon: read active on 9 17:23:44.800: daemon: kqueue: listen=6 active_threads=0 tvp=NULL 17:23:44.800: daemon: kqueue: listen=7 active_threads=0 tvp=NULL 17:23:44.800: connection_get(9) 17:23:44.800: connection_get(9): got connid=0 17:23:44.801: =>do_syncrepl rid=101 17:23:44.801: =>do_syncrep2 rid=101
Not sure if it's any help but looking at kdump(1) output after a run under ktrace(1) I didn't spot the immediate problem resulting in "ldap_start_tls failed (1)" however the "mdb_opinfo_get: err Invalid argument(22)" occurs after attempting to call fcntl with F_SETLK on the fd 5 which is the kqueue fd:
65304 slapd RET write 97/0x61 65304 slapd CALL poll(0x89d39cb9004,1,INFTIM) 65304 slapd STRU struct kevent [2] { ident=9, filter=EVFILT_READ, flags=0x1005<EV_ADD|EV_ENABLE>, fflags=0<>, data=0, udata=0x231a1bea } { ident=9, filter=EVFILT_EXCEPT, flags=0x1005<EV_ADD|EV_ENABLE>, fflags=0x4<>, data=0, udata=0x231a1bea } 65304 slapd STRU struct kevent { ident=9, filter=EVFILT_READ, flags=0x1005<EV_ADD|EV_ENABLE>, fflags=0<>, data=36, udata=0x231a1bea } 65304 slapd STRU struct pollfd { fd=9, events=0x3<POLLIN|POLLPRI>, revents=0x1<POLLIN> } 65304 slapd RET poll 1 65304 slapd CALL read(9,0x89ccfb103e0,0x5) 65304 slapd GIO fd 9 read 5 bytes "^W^C^C\0^_" 65304 slapd RET read 5 65304 slapd CALL read(9,0x89ccfb349c5,0x1f) 65304 slapd GIO fd 9 read 31 bytes "\M^W\M-r\M-f\M^C\M-2\M^V\M-E^O\M-hdgq\M-"\M-o\M-&\M^[*\M-9\M^E\M-Sd\M^A2\M-QE\M-cb |\M^VI" 65304 slapd RET read 31/0x1f 65304 slapd CALL mmap(0,0x2000,0x3<PROT_READ|PROT_WRITE>,0x1002<MAP_PRIVATE|MAP_ANON>,-1,0) 65304 slapd RET mmap 9468564512768/0x89c926ca000 65304 slapd CALL fcntl(5,F_SETLK,0x8ef465d0) 65304 slapd RET fcntl -1 errno 22 Invalid argument 65304 slapd CALL getpid() 65304 slapd RET getpid 65304/0xff18 65304 slapd CALL sendsyslog(0x89c8ef44040,59,0<>) 65304 slapd GIO fd -1 wrote 59 bytes "<167>slapd[65304]: mdb_opinfo_get: err Invalid argument(22)"
Any suggestions would be welcome. Thanks!
--On Thursday, May 12, 2022 7:57 PM +0100 Stuart Henderson stu@spacehopper.org wrote:
I'm working on updating the OpenBSD port of OpenLDAP to 2.6.2 (it's currently stuck at 2.4.59).
Any suggestions would be welcome. Thanks!
Please file a bug at https://bugs.openldap.org/ with the detailed information you gathered.
Regards, Quanah
On 2022-05-12, Quanah Gibson-Mount quanah@fast-mail.org wrote:
--On Thursday, May 12, 2022 7:57 PM +0100 Stuart Henderson stu@spacehopper.org wrote:
I'm working on updating the OpenBSD port of OpenLDAP to 2.6.2 (it's currently stuck at 2.4.59).
Any suggestions would be welcome. Thanks!
Please file a bug at https://bugs.openldap.org/ with the detailed information you gathered.
Following up for the list archives: if slapd forks (i.e. to daemonize when not running in the foreground), it closes the file descriptor associated with the kqueue socket. However the OS does not inherit the kqueue fd across a fork anyway, so it was actually closing an unrelated fd, in this case the fd for lock.mdb.
Thanks for your help Quanah and Howard which led me to track it down.
openldap-technical@openldap.org