search

abbra / freeipa

Mirror of FreeIPA, an integrated security information management solution
http://www.freeipa.org
GNU General Public License v3.0
2 stars 1 forks source link

ipa-gcsyncd backtrace #39

Closed abbra closed 4 years ago

abbra commented 4 years ago

Current tree state (rebased to FreeIPA git master):

Aug 31 09:04:50 master.ipa.test systemd[1]: Started IPA Global Catalog Sync daemon.
Aug 31 09:04:52 master.ipa.test ipa-gcsyncd[40513]: ipa: INFO: LDAP bind...
Aug 31 09:04:52 master.ipa.test ipa-gcsyncd[40513]: ipa: INFO: Commencing sync process
Aug 31 09:04:52 master.ipa.test ns-slapd[31992]: [31/Aug/2020:09:04:52.076592838 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 144
Aug 31 09:04:52 master.ipa.test ipa-gcsyncd[40513]: Traceback (most recent call last):
Aug 31 09:04:52 master.ipa.test ipa-gcsyncd[40513]:   File "/usr/libexec/ipa/gc/ipa-gcsyncd", line 111, in <module>
Aug 31 09:04:52 master.ipa.test ipa-gcsyncd[40513]:     while sync_conn.syncrepl_poll(all=1, msgid=ldap_search):
Aug 31 09:04:52 master.ipa.test ipa-gcsyncd[40513]:   File "/usr/lib64/python3.8/site-packages/ldap/syncrepl.py", line 402, in syncrepl_poll
Aug 31 09:04:52 master.ipa.test ipa-gcsyncd[40513]:     type, msg, mid, ctrls, n, v = self.result4(
Aug 31 09:04:52 master.ipa.test ipa-gcsyncd[40513]:   File "/usr/lib64/python3.8/site-packages/ldap/ldapobject.py", line 756, in result4
Aug 31 09:04:52 master.ipa.test ipa-gcsyncd[40513]:     ldap_result = self._ldap_call(self._l.result4,msgid,all,timeout,add_ctrls,add_intermediates,add_extop)
Aug 31 09:04:52 master.ipa.test ipa-gcsyncd[40513]:   File "/usr/lib64/python3.8/site-packages/ldap/ldapobject.py", line 329, in _ldap_call
Aug 31 09:04:52 master.ipa.test ipa-gcsyncd[40513]:     reraise(exc_type, exc_value, exc_traceback)
Aug 31 09:04:52 master.ipa.test ipa-gcsyncd[40513]:   File "/usr/lib64/python3.8/site-packages/ldap/compat.py", line 44, in reraise
Aug 31 09:04:52 master.ipa.test ipa-gcsyncd[40513]:     raise exc_value
Aug 31 09:04:52 master.ipa.test ipa-gcsyncd[40513]:   File "/usr/lib64/python3.8/site-packages/ldap/ldapobject.py", line 313, in _ldap_call
Aug 31 09:04:52 master.ipa.test ipa-gcsyncd[40513]:     result = func(*args,**kwargs)
Aug 31 09:04:52 master.ipa.test ipa-gcsyncd[40513]: ldap.LDAPError: {'desc': 'Content Sync Refresh Required', 'info': 'Invalid session cookie'}
Aug 31 09:04:52 master.ipa.test systemd[1]: ipa-gcsyncd.service: Main process exited, code=exited, status=1/FAILURE
Aug 31 09:04:52 master.ipa.test systemd[1]: ipa-gcsyncd.service: Failed with result 'exit-code'.
Aug 31 09:04:52 master.ipa.test systemd[1]: ipa-gcsyncd.service: Consumed 1.981s CPU time.
abbra commented 4 years ago

I did install with a previous version, then rebased to FreeIPA commit 49e643783d22ded7a44d84599020af4e8a3d4d5a and upgraded from COPR abbra/gc-wip repository.

abbra commented 4 years ago 
# rpm -q 389-ds-base
389-ds-base-1.4.4.2-1.fc32.x86_64
abbra commented 4 years ago

gc_cookie file content:

master.ipa.test:389#cn=Directory Manager:cn=accounts,dc=ipa,dc=test:(|(objectClass=groupofnames)(objectClass=person))#4294967295

There are no errors in the GC dirsrv instance log but in the primary one I see this:

31/Aug/2020:08:23:20.663415043 +0000] - ERR - slapi_connection_remove_operation - Can't find op 5 for conn 47
[31/Aug/2020:08:24:21.929660983 +0000] - ERR - connection_remove_operation - Can't find op 2 for conn 53
[31/Aug/2020:08:25:25.096477083 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 55
[31/Aug/2020:08:26:26.446025544 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 57
[31/Aug/2020:08:27:28.557057861 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 59
[31/Aug/2020:08:28:31.083538198 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 62
[31/Aug/2020:08:29:33.364090083 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 64
[31/Aug/2020:08:30:36.805653344 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 66
[31/Aug/2020:08:31:38.092879685 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 68
[31/Aug/2020:08:32:40.423789497 +0000] - ERR - connection_remove_operation - Can't find op 2 for conn 70
[31/Aug/2020:08:33:42.628345061 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 72
[31/Aug/2020:08:34:45.986856183 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 74
[31/Aug/2020:08:35:47.614972552 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 76
[31/Aug/2020:08:36:49.894447162 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 78
[31/Aug/2020:08:37:52.233734936 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 80
[31/Aug/2020:08:38:54.631830246 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 82
[31/Aug/2020:08:39:57.957239282 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 93
[31/Aug/2020:08:40:59.111936453 +0000] - ERR - connection_remove_operation - Can't find op 2 for conn 95
[31/Aug/2020:08:42:01.373576916 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 97
[31/Aug/2020:08:43:03.625181287 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 100
[31/Aug/2020:08:44:06.878737690 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 102
[31/Aug/2020:08:45:08.208163900 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 104
[31/Aug/2020:08:46:11.445388108 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 106
[31/Aug/2020:08:47:13.648515356 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 108
[31/Aug/2020:08:48:15.837436566 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 110
[31/Aug/2020:08:49:17.073731578 +0000] - ERR - connection_remove_operation - Can't find op 2 for conn 112
[31/Aug/2020:08:50:19.388568733 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 114
[31/Aug/2020:08:51:22.820151783 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 116
[31/Aug/2020:08:52:24.392121348 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 118
[31/Aug/2020:08:53:27.638250898 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 120
[31/Aug/2020:08:54:28.871458352 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 123
[31/Aug/2020:08:55:31.160944921 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 125
[31/Aug/2020:08:56:33.686777646 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 127
[31/Aug/2020:08:57:35.906532575 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 129
[31/Aug/2020:08:58:38.351865153 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 132
[31/Aug/2020:08:59:40.648943282 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 134
[31/Aug/2020:09:00:43.888817204 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 136
[31/Aug/2020:09:01:45.084862747 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 138
[31/Aug/2020:09:02:47.378922176 +0000] - ERR - connection_remove_operation - Can't find op 2 for conn 140
[31/Aug/2020:09:03:50.819297887 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 142
[31/Aug/2020:09:04:52.077207367 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 144
[31/Aug/2020:09:05:55.364290697 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 146
[31/Aug/2020:09:06:56.626864855 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 148
[31/Aug/2020:09:07:58.818986845 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 150
[31/Aug/2020:09:09:01.144154360 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 152
[31/Aug/2020:09:10:03.386332885 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 155
[31/Aug/2020:09:11:05.595846537 +0000] - ERR - slapi_connection_remove_operation - Can't find op 2 for conn 157
abbra commented 4 years ago

This is a bug https://pagure.io/389-ds-base/issue/51190

abbra commented 4 years ago

A workaround is to remove /var/lib/ipa/gc_cookie and to restart ipa-gcsyncd.service.

abbra commented 4 years ago

I'll keep this open until 389-ds with the fix from issue 51190 is integrated to Fedora.

flo-renaud commented 4 years ago

@abbra The wrong cookie issue has been fixed and the GC code now contains a workaround for invalid cookies: https://github.com/abbra/freeipa/pull/41. I think we can close this issue.