Hey,
alright… Please post the output of:
lsof -PniTCP:6669 -sTCP:LISTEN
lsof -aPniTCP -p 8647
iptables -t nat -L INPUT -nv
iptables -t nat -L DOCKER -nv
Edit: added two more commands.
root@pdc:~# lsof -PniTCP:6669 -sTCP:LISTEN
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
univentio 8647 root 4u IPv6 19742005 0t0 TCP *:6669 (LISTEN)
root@pdc:~# lsof -aPniTCP -p 8647
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
univentio 8647 root 4u IPv6 19742005 0t0 TCP *:6669 (LISTEN)
root@pdc:~# iptables -t nat -L INPUT -nv
Chain INPUT (policy ACCEPT 4921K packets, 415M bytes)
pkts bytes target prot opt in out source destination
root@pdc:~#
root@pdc:~# iptables -t nat -L DOCKER -nv
Chain DOCKER (2 references)
pkts bytes target prot opt in out source destination
0 0 RETURN all -- docker0 * 0.0.0.0/0 0.0.0.0/0
root@pdc:~#
those are the outputs m.
Eniola’
Alright, nothing unusual in that output.
Let’s crank up the log levels of both the notifier and the listener and restart both daemons afterwards:
ucr set listener/debug/level=4 set notifier/debug/level=4
systemctl restart univention-directory-notifier.service univention-directory-listener.service
Now wait a bit and observe the content of the two aforementioned files /var/lib/univention-ldap/last_id and /var/lib/univention-directory-listener/notifier_id. Does the latter start rising and approaching the former?
Also look at the log files for both daemons for messages from after the restart (/var/log/univention/notifier.log and /var/log/univention/listener.log). How do the connection attempts look in listener.log?
For example, here’s the output at log level 4 for listener.log from my test server where the listener is working normally:
23.10.17 16:21:38.259 DEBUG_INIT
23.10.17 16:21:38.260 LISTENER ( INFO ) : LDAP-Server is master.mbu-test.intranet:7389
23.10.17 16:21:38.260 LISTENER ( INFO ) : no server given, choosing one by myself (master.mbu-test.intranet)
23.10.17 16:21:38.260 LDAP ( INFO ) : connecting to ldap://master.mbu-test.intranet:7389
23.10.17 16:21:38.268 LDAP ( INFO ) : simple_bind as cn=admin,dc=mbu-test,dc=intranet
23.10.17 16:21:38.269 LISTENER ( INFO ) : connecting to notifier master.mbu-test.intranet:6669
23.10.17 16:21:38.270 LISTENER ( INFO ) : established connection to 10.191.1.1 port 6669
23.10.17 16:21:38.270 LISTENER ( ALL ) : >>>Version: 2
Capabilities:
23.10.17 16:21:38.270 LISTENER ( ALL ) : RESULT: [(null)]
23.10.17 16:21:38.270 LISTENER ( ALL ) : <<<Version: 2
Capabilities:
23.10.17 16:21:38.270 LISTENER ( INFO ) : connection okay to host master.mbu-test.intranet:7389
I see something… can’t find cache id for 6105 which happens to be the next after last notifier_id (6104).
root@pdc:~# tail -f /var/log/univention/notifier.log
23.10.17 15:39:01.252 TRANSFILE ( PROCESS ) : searching cache id = 6105
23.10.17 15:39:01.252 TRANSFILE ( ALL ) : 6105 not found in cache
23.10.17 15:39:01.252 TRANSFILE ( ALL ) : 6105 get one dn
23.10.17 15:39:01.252 TRANSFILE ( ALL ) : LOCK from notify_transcation_get_one_dn
23.10.17 15:39:01.252 TRANSFILE ( ALL ) : LOCK /var/lib/univention-ldap/notify/transaction
23.10.17 15:39:01.296 TRANSFILE ( ALL ) : FCLOSE start
23.10.17 15:39:01.296 TRANSFILE ( ALL ) : FCLOSE end
23.10.17 15:39:01.296 TRANSFILE ( ALL ) : UNLOCK /var/lib/univention-ldap/notify/transaction
23.10.17 15:39:01.296 TRANSFILE ( ALL ) : 6105 failed
23.10.17 15:39:01.296 TRANSFILE ( ERROR ) : 7 failed, close connection to listener
23.10.17 15:39:07.073 TRANSFILE ( ALL ) : new connection data = 27
23.10.17 15:39:07.073 TRANSFILE ( ALL ) : line = [Version: 2]
23.10.17 15:39:07.073 TRANSFILE ( ALL ) : RECV: VERSION
23.10.17 15:39:07.073 TRANSFILE ( ALL ) : VERSION=2
23.10.17 15:39:07.073 TRANSFILE ( ALL ) : Set version for fd 7 to 2
23.10.17 15:39:07.073 TRANSFILE ( ALL ) : line = [Capabilities: ]
23.10.17 15:39:07.073 TRANSFILE ( ALL ) : RECV: Capabilities
23.10.17 15:39:07.073 TRANSFILE ( ALL ) : SEND: Version: 2
Capabilities:
23.10.17 15:39:07.073 TRANSFILE ( ALL ) : END Package
23.10.17 15:39:07.073 TRANSFILE ( ALL ) : ------------------------------
23.10.17 15:39:07.073 TRANSFILE ( ALL ) : Listener fd = 4
23.10.17 15:39:07.073 TRANSFILE ( ALL ) : Listener fd = 7
23.10.17 15:39:07.073 TRANSFILE ( ALL ) : ------------------------------
23.10.17 15:39:08.841 TRANSFILE ( ALL ) : new connection data = 16
23.10.17 15:39:08.841 TRANSFILE ( ALL ) : line = [MSGID: 1]
23.10.17 15:39:08.841 TRANSFILE ( ALL ) : line = [GET_ID]
23.10.17 15:39:08.841 TRANSFILE ( ALL ) : RECV: GET_ID
23.10.17 15:39:08.842 TRANSFILE ( ALL ) : END Package
23.10.17 15:39:08.842 TRANSFILE ( ALL ) : ------------------------------
23.10.17 15:39:08.842 TRANSFILE ( ALL ) : Listener fd = 4
23.10.17 15:39:08.842 TRANSFILE ( ALL ) : Listener fd = 7
23.10.17 15:39:08.842 TRANSFILE ( ALL ) : ------------------------------
23.10.17 15:39:08.842 TRANSFILE ( ALL ) : new connection data = 21
23.10.17 15:39:08.842 TRANSFILE ( ALL ) : line = [MSGID: 2]
23.10.17 15:39:08.842 TRANSFILE ( ALL ) : line = [GET_DN 6105]
23.10.17 15:39:08.842 TRANSFILE ( ALL ) : RECV: GET_DN
23.10.17 15:39:08.842 TRANSFILE ( ALL ) : id: 6105
23.10.17 15:39:08.842 TRANSFILE ( ALL ) : try to read 6105 from cache
23.10.17 15:39:08.842 TRANSFILE ( PROCESS ) : searching cache id = 6105
23.10.17 15:39:08.842 TRANSFILE ( ALL ) : 6105 not found in cache
23.10.17 15:39:08.842 TRANSFILE ( ALL ) : 6105 get one dn
23.10.17 15:39:08.842 TRANSFILE ( ALL ) : LOCK from notify_transcation_get_one_dn
23.10.17 15:39:08.842 TRANSFILE ( ALL ) : LOCK /var/lib/univention-ldap/notify/transaction
23.10.17 15:39:08.885 TRANSFILE ( ALL ) : FCLOSE start
23.10.17 15:39:08.885 TRANSFILE ( ALL ) : FCLOSE end
23.10.17 15:39:08.886 TRANSFILE ( ALL ) : UNLOCK /var/lib/univention-ldap/notify/transaction
23.10.17 15:39:08.886 TRANSFILE ( ALL ) : 6105 failed
23.10.17 15:39:08.886 TRANSFILE ( ERROR ) : 7 failed, close connection to listener
23.10.17 15:39:14.606 TRANSFILE ( ALL ) : new connection data = 27
23.10.17 15:39:14.606 TRANSFILE ( ALL ) : line = [Version: 2]
23.10.17 15:39:14.606 TRANSFILE ( ALL ) : RECV: VERSION
23.10.17 15:39:14.606 TRANSFILE ( ALL ) : VERSION=2
23.10.17 15:39:14.606 TRANSFILE ( ALL ) : Set version for fd 7 to 2
23.10.17 15:39:14.606 TRANSFILE ( ALL ) : line = [Capabilities: ]
23.10.17 15:39:14.606 TRANSFILE ( ALL ) : RECV: Capabilities
23.10.17 15:39:14.606 TRANSFILE ( ALL ) : SEND: Version: 2
Capabilities:
23.10.17 15:39:14.606 TRANSFILE ( ALL ) : END Package
23.10.17 15:39:14.606 TRANSFILE ( ALL ) : ------------------------------
23.10.17 15:39:14.606 TRANSFILE ( ALL ) : Listener fd = 4
23.10.17 15:39:14.606 TRANSFILE ( ALL ) : Listener fd = 7
23.10.17 15:39:14.606 TRANSFILE ( ALL ) : ------------------------------
23.10.17 15:39:16.045 TRANSFILE ( ALL ) : new connection data = 16
23.10.17 15:39:16.045 TRANSFILE ( ALL ) : line = [MSGID: 1]
23.10.17 15:39:16.045 TRANSFILE ( ALL ) : line = [GET_ID]
23.10.17 15:39:16.045 TRANSFILE ( ALL ) : RECV: GET_ID
23.10.17 15:39:16.045 TRANSFILE ( ALL ) : END Package
23.10.17 15:39:16.045 TRANSFILE ( ALL ) : ------------------------------
23.10.17 15:39:16.045 TRANSFILE ( ALL ) : Listener fd = 4
23.10.17 15:39:16.045 TRANSFILE ( ALL ) : Listener fd = 7
23.10.17 15:39:16.045 TRANSFILE ( ALL ) : ------------------------------
23.10.17 15:39:16.046 TRANSFILE ( ALL ) : new connection data = 21
23.10.17 15:39:16.047 TRANSFILE ( ALL ) : line = [MSGID: 2]
23.10.17 15:39:16.047 TRANSFILE ( ALL ) : line = [GET_DN 6105]
23.10.17 15:39:16.047 TRANSFILE ( ALL ) : RECV: GET_DN
23.10.17 15:39:16.047 TRANSFILE ( ALL ) : id: 6105
23.10.17 15:39:16.047 TRANSFILE ( ALL ) : try to read 6105 from cache
23.10.17 15:39:16.047 TRANSFILE ( PROCESS ) : searching cache id = 6105
23.10.17 15:39:16.047 TRANSFILE ( ALL ) : 6105 not found in cache
23.10.17 15:39:16.047 TRANSFILE ( ALL ) : 6105 get one dn
23.10.17 15:39:16.047 TRANSFILE ( ALL ) : LOCK from notify_transcation_get_one_dn
23.10.17 15:39:16.047 TRANSFILE ( ALL ) : LOCK /var/lib/univention-ldap/notify/transaction
23.10.17 15:39:16.112 TRANSFILE ( ALL ) : FCLOSE start
23.10.17 15:39:16.115 TRANSFILE ( ALL ) : FCLOSE end
23.10.17 15:39:16.116 TRANSFILE ( ALL ) : UNLOCK /var/lib/univention-ldap/notify/transaction
23.10.17 15:39:16.116 TRANSFILE ( ALL ) : 6105 failed
23.10.17 15:39:16.116 TRANSFILE ( ERROR ) : 7 failed, close connection to listener
23.10.17 15:39:22.092 TRANSFILE ( ALL ) : new connection data = 27
23.10.17 15:39:22.092 TRANSFILE ( ALL ) : line = [Version: 2]
23.10.17 15:39:22.092 TRANSFILE ( ALL ) : RECV: VERSION
23.10.17 15:39:22.092 TRANSFILE ( ALL ) : VERSION=2
23.10.17 15:39:22.092 TRANSFILE ( ALL ) : Set version for fd 7 to 2
23.10.17 15:39:22.092 TRANSFILE ( ALL ) : line = [Capabilities: ]
23.10.17 15:39:22.092 TRANSFILE ( ALL ) : RECV: Capabilities
23.10.17 15:39:22.093 TRANSFILE ( ALL ) : SEND: Version: 2
Capabilities:
...
23.10.17 15:40:34.463 TRANSFILE ( ALL ) : line = [MSGID: 2]
23.10.17 15:40:34.463 TRANSFILE ( ALL ) : line = [GET_DN 6105]
23.10.17 15:40:34.463 TRANSFILE ( ALL ) : RECV: GET_DN
23.10.17 15:40:34.463 TRANSFILE ( ALL ) : id: 6105
23.10.17 15:40:34.463 TRANSFILE ( ALL ) : try to read 6105 from cache
23.10.17 15:40:34.463 TRANSFILE ( PROCESS ) : searching cache id = 6105
23.10.17 15:40:34.463 TRANSFILE ( ALL ) : 6105 not found in cache
23.10.17 15:40:34.463 TRANSFILE ( ALL ) : 6105 get one dn
23.10.17 15:40:34.463 TRANSFILE ( ALL ) : LOCK from notify_transcation_get_one_dn
23.10.17 15:40:34.463 TRANSFILE ( ALL ) : LOCK /var/lib/univention-ldap/notify/transaction
23.10.17 15:40:34.540 TRANSFILE ( ALL ) : FCLOSE start
23.10.17 15:40:34.540 TRANSFILE ( ALL ) : FCLOSE end
23.10.17 15:40:34.540 TRANSFILE ( ALL ) : UNLOCK /var/lib/univention-ldap/notify/transaction
23.10.17 15:40:34.540 TRANSFILE ( ALL ) : 6105 failed
23.10.17 15:40:34.540 TRANSFILE ( ERROR ) : 7 failed, close connection to listener
listener log.
root@pdc:~# tail -f /var/log/univention/listener.log
The listener looks to be back up now. but the last id & notifier id is still same.
root@pdc:~# cat /var/lib/univention-ldap/last_id
8167root@pdc:~# cat /var/lib/univention-directory-listener/notifier_id
6104root@pdc:~#
Eniola’
Those notifier messages don’t look good. Can you please have a look at the following file: /var/lib/univention-ldap/notify/transaction It’s a text file that contains one line per change in the LDAP directory. It should contain a line that starts with the transaction ID 6105. Is that the case? Does the file look damaged anywhere?
there’s no 6105-6107
Eniola’
That’s definitely bad. I honestly don’t know how to proceed from here. I’m certain you won’t get the listener process running without fixing those two missing entries somehow. Having the listener work correctly is a precondition for everything else working properly; so it cannot just be ignored either.
I highly suggest you open a support case with Univention. They should be able to salvage the system.
Thanks man.
You’ve been amazing.
Eniola’
FAAAAAAAAAMMMMMMMMMMM! I JUST FIXED IT…
AHAHAHAHAHAHAH I created dummy entries for 6105-7…
Ahahahahaha notifier id now = last id.
I couldn’t have done it without you man.
Thanks a lotttttttt!..
You’re quite welcome.
I had thought about advising you to do just that but decided against it. In general faking entries that way can lead to inconsistent behavior further down the road. For example, if one of those lines was the creation of a user, then that user would not have been created in the Samba LDAP, and further modifications to that user would have failed. That being said, the data you posted did suggest the missing lines were likely about the same DNS entries that the surrounding lines were about.
Hi M,
How have you been? I’m back again (LOL)…
Is there a way to upload multiple users from the CLI instead of having to use the GUI?.. I just want to know before I have to put man hours into writing a python script for the process.
Regards,
Eniola’
Can you please open a new topic for such an unrelated question? Makes life easier for everyone. Thanks!
Sorry my bad…
