Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

gc-wip: Sync daemon fails to start after creating/deleting particular users #60

Open
wladich opened this issue Oct 26, 2020 · 3 comments
Open

gc-wip: Sync daemon fails to start after creating/deleting particular users #60

wladich opened this issue Oct 26, 2020 · 3 comments

Comments

@wladich
Copy link
Collaborator

wladich commented Oct 26, 2020 •
edited
Loading

After a test session I can not start sync daemon anymore. I am not sure which action triggered the error so I am attaching output of ldapsearch for main and GC instances

Another issue I see is that the traceback is written only to journal but not to globalcatalog.log.

Oct 26 19:20:47 master1.testrelm.test systemd[1]: Started IPA Global Catalog Sync daemon.
Oct 26 19:20:47 master1.testrelm.test ipa-gcsyncd[49294]: ipa: DEBUG: importing all plugin modules in ipaserver.plugins...
...
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: ipa: DEBUG: importing plugin module ipaserver.plugins.whoami
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: ipa: DEBUG: importing plugin module ipaserver.plugins.xmlserver
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: ipa: DEBUG: LDAP URL: ldapi://%2Frun%2Fslapd-TESTRELM-TEST.socket/cn%3Daccounts%2Cdc%3Dtestrelm%2Cdc%3Dtest?objectclass,cn,displayname,gidnumber,givenname,homedirectory,ipaextern>
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: ipa: DEBUG: retrieving schema for SchemaCache url=ldapi://%2fvar%2frun%2fslapd-GLOBAL-CATALOG.socket conn=<ldap.ldapobject.ReconnectLDAPObject object at 0x7f5721f73d60>
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: ipa: DEBUG: get_saved_cookie
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: ipa: DEBUG: Read cookie master1.testrelm.test:389#cn=Directory Manager:cn=accounts,dc=testrelm,dc=test:(|(objectClass=groupofnames)(objectClass=person))#643
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: ipa: DEBUG: New cookie is: master1.testrelm.test:389#cn=Directory Manager:cn=accounts,dc=testrelm,dc=test:(|(objectClass=groupofnames)(objectClass=person))#643
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: ipa: INFO: LDAP bind...
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: ipa: INFO: Commencing sync process
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: ipa: DEBUG: Current cookie is: master1.testrelm.test:389#cn=Directory Manager:cn=accounts,dc=testrelm,dc=test:(|(objectClass=groupofnames)(objectClass=person))#643
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: Traceback (most recent call last):
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib/python3.8/site-packages/pyasn1/type/constraint.py", line 32, in __call__
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     self._testValue(value, idx)
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib/python3.8/site-packages/pyasn1/type/constraint.py", line 320, in _testValue
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     raise error.ValueConstraintError(value)
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: pyasn1.type.error.ValueConstraintError: b'\x1f\x86'
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: During handling of the above exception, another exception occurred:
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: Traceback (most recent call last):
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib/python3.8/site-packages/pyasn1/type/base.py", line 269, in __init__
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     self.subtypeSpec(value)
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib/python3.8/site-packages/pyasn1/type/constraint.py", line 35, in __call__
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     raise error.ValueConstraintError(
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: pyasn1.type.error.ValueConstraintError: <ValueSizeConstraint object, consts 16, 16> failed at: ValueConstraintError(b'\x1f\x86')
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: During handling of the above exception, another exception occurred:
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: Traceback (most recent call last):
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/libexec/ipa/gc/ipa-gcsyncd", line 111, in <module>
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     while sync_conn.syncrepl_poll(all=1, msgid=ldap_search):
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib64/python3.8/site-packages/ldap/syncrepl.py", line 449, in syncrepl_poll
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     sim = SyncInfoMessage(resp)
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib64/python3.8/site-packages/ldap/syncrepl.py", line 311, in __init__
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     d = decoder.decode(encodedMessage, asn1Spec=SyncInfoValue())
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib/python3.8/site-packages/pyasn1/codec/ber/decoder.py", line 1581, in __call__
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     value, substrate = concreteDecoder.valueDecoder(
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib/python3.8/site-packages/pyasn1/codec/ber/decoder.py", line 1006, in valueDecoder
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     component, head = decodeFun(
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib/python3.8/site-packages/pyasn1/codec/ber/decoder.py", line 1581, in __call__
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     value, substrate = concreteDecoder.valueDecoder(
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib/python3.8/site-packages/pyasn1/codec/ber/decoder.py", line 609, in valueDecoder
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     component, head = decodeFun(head, componentType, **options)
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib/python3.8/site-packages/pyasn1/codec/ber/decoder.py", line 1581, in __call__
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     value, substrate = concreteDecoder.valueDecoder(
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib/python3.8/site-packages/pyasn1/codec/ber/decoder.py", line 728, in valueDecoder
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     component, head = decodeFun(head, componentType, **options)
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib/python3.8/site-packages/pyasn1/codec/ber/decoder.py", line 1581, in __call__
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     value, substrate = concreteDecoder.valueDecoder(
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib/python3.8/site-packages/pyasn1/codec/ber/decoder.py", line 244, in valueDecoder
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     return self._createComponent(asn1Spec, tagSet, head, **options), tail
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib/python3.8/site-packages/pyasn1/codec/ber/decoder.py", line 55, in _createComponent
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     return asn1Spec.clone(value)
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib/python3.8/site-packages/pyasn1/type/base.py", line 376, in clone
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     return self.__class__(value, **initializers)
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib/python3.8/site-packages/pyasn1/type/univ.py", line 837, in __init__
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     base.SimpleAsn1Type.__init__(self, value, **kwargs)
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:   File "/usr/lib/python3.8/site-packages/pyasn1/type/base.py", line 273, in __init__
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]:     raise exType('%s at %s' % (exValue, self.__class__.__name__))
Oct 26 19:20:48 master1.testrelm.test ipa-gcsyncd[49294]: pyasn1.type.error.ValueConstraintError: <ValueSizeConstraint object, consts 16, 16> failed at: ValueConstraintError(b'\x1f\x86') at SyncUUID
Oct 26 19:20:48 master1.testrelm.test systemd[1]: ipa-gcsyncd.service: Main process exited, code=exited, status=1/FAILURE
Oct 26 19:20:48 master1.testrelm.test systemd[1]: ipa-gcsyncd.service: Failed with result 'exit-code'.
Oct 26 19:20:48 master1.testrelm.test systemd[1]: ipa-gcsyncd.service: Consumed 1.657s CPU time.
@wladich
Copy link
Collaborator Author

wladich commented Oct 26, 2020

gc_dump.txt
main_dump.txt

@wladich
Copy link
Collaborator Author

wladich commented Oct 27, 2020

@tbordaz
Could you please look at the backtrace? Do you need any additional data to investigate the issue?
I can reproduce the issue by running the test on local vagrant environment, but it PR-CI the it is passing succesfuly.

The test which triggers the issue: https://github.com/wladich/freeipa/blob/d3e6734c3f731df53764a14c3dee009fb23478f1/ipatests/test_integration/test_global_catalog.py#L565
http://freeipa-org-pr-ci.s3-website.eu-central-1.amazonaws.com/jobs/dbd7866a-17cf-11eb-be89-fa163e4ad552/report.html

@wladich wladich changed the title Sync daemon fails to start gc-wip: Sync daemon fails to start Oct 27, 2020
@wladich wladich changed the title gc-wip: Sync daemon fails to start gc-wip: Sync daemon fails to start after creating particular users Nov 23, 2020
@wladich
Copy link
Collaborator Author

wladich commented Nov 23, 2020

Just hit the issue again, here is what the test is doing:

systemctl stop ipa-gcsyncd.service
ipa user-add StartupsyncComplex1 --first Startupsync --last Complex1
ipa user-add StartupsyncComplex2 --first Startupsync --last Complex2
ipa user-del StartupsyncComplex1
ipa group-add startupsynccomplex
ipa group-add-member startupsynccomplex --users StartupsyncComplex2
systemctl start ipa-gcsyncd.service

And ipa-gcsyncd fails to start, the traceback can be seen in the first comment

@wladich wladich changed the title gc-wip: Sync daemon fails to start after creating particular users gc-wip: Sync daemon fails to start after creating/deleting particular users Nov 24, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@wladich