time out in samba4.ldap.dirsync.python(dc) test

[Alexander Bokovoy]

Hi,

I'm seeing a time out while running samba4.ldap.dirsync.python(dc)
test in master (even before our kerberos refactoring work landed). It
all seems started with
https://git.samba.org/?p=samba.git;a=commitdiff;h=438971e214e6f55f19148ed2afc03ec1c7066f65
which landed in master on March 25th. I'm not sure why autobuild
didn't catch the time out.

All I see in the output is neverending
ldap: no matching message id for 23
ldap: no matching message id for 23
ldap: no matching message id for 23
ldap: no matching message id for 23
ldap: no matching message id for 23
ldap: no matching message id for 23
ldap: no matching message id for 23
ldap: no matching message id for 23
ldap: no matching message id for 23
ldap: no matching message id for 23
ldap: no matching message id for 23

attaching strace shows that indeed there is a loop:

recvfrom(4, 0x24068a0, 5, 0, 0, 0)      = -1 EAGAIN (Resource
temporarily unavailable)
fstat(2, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0x7fdc6206d000
lseek(2, 0, SEEK_CUR)                   = -1 ESPIPE (Illegal seek)
write(2, "ldap: no matching message id for 23\n", 36) = 36
munmap(0x7fdc6206d000, 4096)            = 0
epoll_wait(3, {{EPOLLIN, {u32=37495360, u64=37495360}}}, 1, 168751) = 1
ioctl(4, FIONREAD, [213])               = 0
recvfrom(4, "\27\3\3\0\320", 5, 0, NULL, NULL) = 5
recvfrom(4, "\20\307\330\277\266\334\336q\300\335\201\302\275\270\3353]s\236w5`\31
=\315 cRfMM\236e\344\213\374\31\330\36\322\6\311n\0L)\352\366\271\373\250p\256\315\30\374f\330Jl>\260\256I\2jWt6\364=\243|\37\245\342\260\23,\370J$\260\307Eg\350\212KM\223\377\217\362\7\267{\204\346\310\260\23\1\221\5\317\30\327\210\317\223\17-\207\37\342\253\20\17d\241\210]\350na\343\376b\272\243\241h\371\4\231\7\310\233\1\242\347\1\25\344y\24\";,V(+\177\f\305~\24mp\2023\310\305F\366`\26\341\f\211}~\216\2706\204\2473sb4\254J\312Y\25b\303\315-\231Dz\241\36T\302\360c\372\211\207\6\323\311\347",
208, 0, NULL, NULL) = 208
getrusage(RUSAGE_SELF, {ru_utime={3, 36538}, ru_stime={1, 125828}, ...}) = 0
times({tms_utime=303, tms_stime=112, tms_cutime=0, tms_cstime=0}) = 439866604
getrusage(RUSAGE_SELF, {ru_utime={3, 36538}, ru_stime={1, 125828}, ...}) = 0
times({tms_utime=303, tms_stime=112, tms_cutime=0, tms_cstime=0}) = 439866604
ioctl(4, FIONREAD, [0])                 = 0
recvfrom(4, 0x2408170, 5, 0, 0, 0)      = -1 EAGAIN (Resource
temporarily unavailable)
fstat(2, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0x7fdc6206d000
lseek(2, 0, SEEK_CUR)                   = -1 ESPIPE (Illegal seek)
write(2, "ldap: no matching message id for 23\n", 36) = 36
munmap(0x7fdc6206d000, 4096)            = 0
epoll_wait(3, {{EPOLLOUT, {u32=37495360, u64=37495360}}}, 1, 168742) = 1
getrusage(RUSAGE_SELF, {ru_utime={3, 36538}, ru_stime={1, 125828}, ...}) = 0

in the end it freaks out with time out:
UNEXPECTED(error):
samba4.ldap.dirsync.python(dc).__main__.SimpleDirsyncTests.test_dirsync_errors
REASON: _StringException: _StringException: Content-Type:
text/x-traceback;charset=utf8,language=python
traceback
147
Traceback (most recent call last):
  File "/home/abokovoy/workspace/samba/source4/dsdb/tests/python/dirsync.py",
line 117, in setUp
    self.ldb_admin.newuser(self.dirsync_user, self.user_pass)
  File "bin/python/samba/samdb.py", line 401, in newuser
    self.add(ldbmessage)
LdbError: (3, 'ldb_wait: Time limit exceeded (3)')

-- 
/ Alexander Bokovoy