Hi, can’t seem to get the zimbra connector working on my testlab.
Have installed zimbra. And have run the zimbra connector wizard against a mail domain. And indeed an initial user account in the directory with an email specifed was initially created.
However any subsequent attempt to modify the user (password/zimbra account status) results in the below exception regarding ZimbraNotInitialized()
Not sure how to troubleshoot, as you can see from the zimbra4ucs log the initial setup and connection to zimbra is working. Seems only subsequent changes fail, there are files located in the /var/lib/zimbra4ucs-user-listener/ location.
Have tried uninstalling and reinstalling and removing domains and users from zimbra with no improvement.
Zimbra4ucs connector log shows wizard initialisation and subsequent failure to modify:
2018-07-07 14:40:34,777 - INFO - processing file: /var/lib/zimbra4ucs-user-listener/1530937964.531754
2018-07-07 14:40:34,778 - INFO - create uid=fblogs,cn=users,dc=homelab,dc=intranet
2018-07-07 14:40:34,778 - INFO - Request 'CreateAccountRequest' with {'a': [{'_content': 'fred', 'n': 'gn'}, {'_content': 'blogs', 'n': 'sn'}, {'_content': 'fred blogs', 'n': 'displayName'}, {'_content': 'FALSE', 'n': 'zimbraHideInGal'}, {'_content': 'active', 'n': 'zimbraAccountStatus'}, {'_content': 'FALSE', 'n': 'zimbraIsSystemAccount'}, {'_content': 'FALSE', 'n': 'zimbraIsAdminAccount'}, {'_content': 'FALSE', 'n': 'zimbraIsSystemResource'}], 'name': 'fred@homelab.intranet'}
2018-07-07 14:40:34,798 - INFO - processing file: /var/lib/zimbra4ucs-user-listener/1530937964.623981
2018-07-07 14:40:34,799 - INFO - modify uid=fblogs,cn=users,dc=homelab,dc=intranet
2018-07-07 14:40:34,799 - INFO - changes {'entryCSN': (['20180707043244.603316Z#000000#000#000000'], ['20180707043244.504695Z#000000#000#000000']), 'sambaPrimaryGroupSID': (['S-1-5-21-514488223-688142699-2505213924-513'], None)}
2018-07-07 14:40:34,800 - INFO - Request 'GetAccountRequest' with {'account': {'by': 'name', '_content': 'fred@homelab.intranet'}, 'attrs': 'zimbraId'}
2018-07-07 14:40:34,815 - INFO - Request 'ModifyAccountRequest' with {'a': [], 'id': u'abe45140-9cca-4c75-8eef-93db80e2f089'}
2018-07-07 14:40:34,836 - INFO - processing file: /var/lib/zimbra4ucs-user-listener/1530937968.721671
2018-07-07 14:40:34,837 - INFO - modify uid=fblogs,cn=users,dc=homelab,dc=intranet
2018-07-07 14:40:34,837 - INFO - changes {'sambaSID': (['S-1-5-21-514488223-688142699-2505213924-1128'], ['S-1-4-2020']), 'memberOf': (['cn=Domain Users,cn=groups,dc=homelab,dc=intranet'], None), 'modifiersName': (['cn=admin,dc=homelab,dc=intranet'], ['uid=Administrator,cn=users,dc=homelab,dc=intranet']), 'entryCSN': (['20180707043248.706396Z#000000#000#000000'], ['20180707043244.603316Z#000000#000#000000']), 'modifyTimestamp': (['20180707043248Z'], ['20180707043244Z'])}
2018-07-07 14:40:34,838 - INFO - Request 'GetAccountRequest' with {'account': {'by': 'name', '_content': 'fred@homelab.intranet'}, 'attrs': 'zimbraId'}
2018-07-07 14:40:34,855 - INFO - Request 'ModifyAccountRequest' with {'a': [], 'id': u'abe45140-9cca-4c75-8eef-93db80e2f089'}
2018-07-07 14:40:40,065 - INFO - started with args: ['start'], opts: {'data_dir_maildomain': '/var/lib/zimbra4ucs-maildomain-listener', 'log_file': '/var/log/univention/zimbra4ucs.log', 'log_level': '3', 'dry_run': False, 'data_dir_user': '/var/lib/zimbra4ucs-user-listener'}
2018-07-07 14:40:40,082 - INFO - checking changes for maildomains
2018-07-07 14:40:40,082 - INFO - checking changes for user
2018-07-07 14:40:45,086 - INFO - checking changes for maildomains
2018-07-07 14:40:45,086 - INFO - checking changes for user
2018-07-07 14:40:50,092 - INFO - checking changes for maildomains
2018-07-07 14:40:50,092 - INFO - checking changes for user
2018-07-07 14:40:55,099 - INFO - checking changes for maildomains
2018-07-07 14:40:55,099 - INFO - checking changes for user
2018-07-07 14:41:00,104 - INFO - checking changes for maildomains
2018-07-07 14:41:00,104 - INFO - checking changes for user
2018-07-07 14:41:05,108 - INFO - checking changes for maildomains
2018-07-07 14:41:05,108 - INFO - checking changes for user
2018-07-07 14:41:10,114 - INFO - checking changes for maildomains
2018-07-07 14:41:10,114 - INFO - checking changes for user
2018-07-07 14:41:15,120 - INFO - checking changes for maildomains
2018-07-07 14:41:15,120 - INFO - checking changes for user
2018-07-07 14:41:20,126 - INFO - checking changes for maildomains
2018-07-07 14:41:20,126 - INFO - checking changes for user
2018-07-07 14:41:25,133 - INFO - checking changes for maildomains
2018-07-07 14:41:25,133 - INFO - checking changes for user
2018-07-07 14:41:25,133 - INFO - processing file: /var/lib/zimbra4ucs-user-listener/1530938481.521915
2018-07-07 14:41:25,134 - INFO - modify uid=fblogs,cn=users,dc=homelab,dc=intranet
2018-07-07 14:41:25,134 - INFO - changes {'modifiersName': (['uid=Administrator,cn=users,dc=homelab,dc=intranet'], ['cn=admin,dc=homelab,dc=intranet']), 'entryCSN': (['20180707044121.516358Z#000000#000#000000'], ['20180707043248.706396Z#000000#000#000000']), 'modifyTimestamp': (['20180707044121Z'], ['20180707043248Z']), 'zimbraAccountStatus': (['locked'], ['active'])}
2018-07-07 14:41:25,134 - ERROR - <traceback object at 0x7fb1dba2b9e0>
Traceback (most recent call last):
File "/usr/sbin/zimbra4ucs-connector", line 72, in run
opts.dry_run)
File "/usr/lib/pymodules/python2.7/zimbra4ucs/tools.py", line 96, in process_files
cls.modify(dn, new, old)
File "/usr/lib/pymodules/python2.7/zimbra4ucs/models.py", line 158, in ldap_modify
return cls(cls.get_connection(), **cls.map_ldap_attributes(old)).modify(cls.map_ldap_attributes(new))
File "/usr/lib/pymodules/python2.7/zimbra4ucs/models.py", line 173, in get_connection
cls.connection = ZimbraConfiguration.get_connection()
File "/usr/lib/pymodules/python2.7/zimbra4ucs/__init__.py", line 150, in get_connection
raise ZimbraNotInitialized()
ZimbraNotInitialized
2018-07-07 14:41:30,140 - INFO - checking changes for maildomains
2018-07-07 14:41:30,141 - INFO - checking changes for user
2018-07-07 14:41:30,141 - INFO - processing file: /var/lib/zimbra4ucs-user-listener/1530938481.521915
2018-07-07 14:41:30,141 - INFO - modify uid=fblogs,cn=users,dc=homelab,dc=intranet
2018-07-07 14:41:30,141 - INFO - changes {'modifiersName': (['uid=Administrator,cn=users,dc=homelab,dc=intranet'], ['cn=admin,dc=homelab,dc=intranet']), 'entryCSN': (['20180707044121.516358Z#000000#000#000000'], ['20180707043248.706396Z#000000#000#000000']), 'modifyTimestamp': (['20180707044121Z'], ['20180707043248Z']), 'zimbraAccountStatus': (['locked'], ['active'])}
2018-07-07 14:41:30,141 - ERROR - <traceback object at 0x7fb1dba43a28>
Traceback (most recent call last):
File "/usr/sbin/zimbra4ucs-connector", line 72, in run
opts.dry_run)
File "/usr/lib/pymodules/python2.7/zimbra4ucs/tools.py", line 96, in process_files
cls.modify(dn, new, old)
File "/usr/lib/pymodules/python2.7/zimbra4ucs/models.py", line 158, in ldap_modify
return cls(cls.get_connection(), **cls.map_ldap_attributes(old)).modify(cls.map_ldap_attributes(new))
File "/usr/lib/pymodules/python2.7/zimbra4ucs/models.py", line 173, in get_connection
cls.connection = ZimbraConfiguration.get_connection()
File "/usr/lib/pymodules/python2.7/zimbra4ucs/__init__.py", line 150, in get_connection
raise ZimbraNotInitialized()
ZimbraNotInitialized
2018-07-07 14:41:35,147 - INFO - checking changes for maildomains
2018-07-07 14:41:35,147 - INFO - checking changes for user
2018-07-07 14:41:35,148 - INFO - processing file: /var/lib/zimbra4ucs-user-listener/1530938481.521915
2018-07-07 14:41:35,148 - INFO - modify uid=fblogs,cn=users,dc=homelab,dc=intranet
2018-07-07 14:41:35,148 - INFO - changes {'modifiersName': (['uid=Administrator,cn=users,dc=homelab,dc=intranet'], ['cn=admin,dc=homelab,dc=intranet']), 'entryCSN': (['20180707044121.516358Z#000000#000#000000'], ['20180707043248.706396Z#000000#000#000000']), 'modifyTimestamp': (['20180707044121Z'], ['20180707043248Z']), 'zimbraAccountStatus': (['locked'], ['active'])}
2018-07-07 14:41:35,148 - ERROR - <traceback object at 0x7fb1dba2b488>
Traceback (most recent call last):
File "/usr/sbin/zimbra4ucs-connector", line 72, in run
opts.dry_run)
File "/usr/lib/pymodules/python2.7/zimbra4ucs/tools.py", line 96, in process_files
cls.modify(dn, new, old)
File "/usr/lib/pymodules/python2.7/zimbra4ucs/models.py", line 158, in ldap_modify
return cls(cls.get_connection(), **cls.map_ldap_attributes(old)).modify(cls.map_ldap_attributes(new))
File "/usr/lib/pymodules/python2.7/zimbra4ucs/models.py", line 173, in get_connection
cls.connection = ZimbraConfiguration.get_connection()
File "/usr/lib/pymodules/python2.7/zimbra4ucs/__init__.py", line 150, in get_connection
raise ZimbraNotInitialized()
ZimbraNotInitialized
Zimbra /opt/zimbra/log/audit.log extract shows initialisation from module wizard:
2018-07-07 14:40:39,466 INFO [qtp335471116-599:https:https://mail.homelab.intranet:7071/service/admin/soap] [name=admin@mail.homelab.intranet;mid=2;ip=192.168.1.10;port=48896;soapId=e48adca;] security - cmd=CreateAccount; name=zimbra4ucs@homelab.intranet; zimbraHideInGal=FALSE; zimbraAccountStatus=active; zimbraAuthLdapExternalDn=uid=zimbra4ucs,cn=users,dc=homelab,dc=intranet; displayName=Zimbra4UCS Service LDAP Account; zimbraIsAdminAccount=TRUE; gn=Zimbra4UCS Service; zimbraIsSystemResource=TRUE; description=Account used by Zimbra4UCS to authenticate against LDAP directory; zimbraIsSystemAccount=TRUE; sn=LDAP Account; zimbraMailStatus=enabled;
2018-07-07 14:40:39,495 INFO [qtp335471116-625:https:https://mail.homelab.intranet:7071/service/admin/soap] [name=admin@mail.homelab.intranet;mid=2;ip=192.168.1.10;port=48900;soapId=e48adcc;] security - cmd=ModifyDomain; name=homelab.intranet; zimbraAuthLdapSearchFilter=(&(mailPrimaryAddress=%n)(objectClass=person)); zimbraAuthLdapSearchBindDn=uid=zimbra4ucs,cn=users,dc=homelab,dc=intranet; zimbraAuthLdapURL=ldap://ucs-4406.homelab.intranet:7389; zimbraAuthLdapStartTlsEnabled=TRUE; zimbraAuthLdapSearchBase=dc=homelab,dc=intranet; zimbraAuthLdapSearchBindPassword=2r4wb8EHhzftLgRXtz; zimbraAuthMech=ldap;
Nothing else comes through after this.