Bug 49746 - INSUFFICIENT_ACCESS: {'desc': 'Insufficient access'} - univention-portal-server
INSUFFICIENT_ACCESS: {'desc': 'Insufficient access'} - univention-portal-server
Status: CLOSED FIXED
Product: UCS
Classification: Unclassified
Component: Portal
UCS 4.4
Other Linux
: P5 normal (vote)
: UCS 4.4-0-errata
Assigned To: Philipp Hahn
Dirk Wiesenthal
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2019-06-28 11:02 CEST by Felix Botner
Modified: 2019-07-10 13:20 CEST (History)
1 user (show)

See Also:
What kind of report is it?: Bug Report
What type of bug is this?: 4: Minor Usability: Impairs usability in secondary scenarios
Who will be affected by this bug?: 5: Will affect all installed domains
How will those affected feel about the bug?: 2: A Pain – users won’t like this once they notice it
User Pain: 0.229
Enterprise Customer affected?: Yes
School Customer affected?: Yes
ISV affected?: Yes
Waiting Support:
Ticket number:
Bug group (optional):
Max CVSS v3 score:


Attachments
syslog-no-samba-master.gz (127.36 KB, application/gzip)
2019-06-28 11:02 CEST, Felix Botner
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Felix Botner univentionstaff 2019-06-28 11:02:17 CEST
Multiple times In the syslog of master/backup/... of the errata jenkins tests.

Jun 28 01:12:57 slave094 univention-portal-server[1857]: Error during refresh
Jun 28 01:12:57 slave094 univention-portal-server[1857]: Traceback (most recent call last):
Jun 28 01:12:57 slave094 univention-portal-server[1857]:   File "/usr/bin/univention-portal-server", line 180, in refresh
Jun 28 01:12:57 slave094 univention-portal-server[1857]:     localhost = self.udm.obj_by_dn(ldap_hostdn)
Jun 28 01:12:57 slave094 univention-portal-server[1857]:   File "/usr/lib/pymodules/python2.7/univention/udm/udm.py", line 241, in obj_by_dn
Jun 28 01:12:57 slave094 univention-portal-server[1857]:     ldap_obj = self.connection.get(dn, attr=[str('univentionObjectType')])
Jun 28 01:12:57 slave094 univention-portal-server[1857]:   File "/usr/lib/pymodules/python2.7/univention/admin/uldap.py", line 708, in get
Jun 28 01:12:57 slave094 univention-portal-server[1857]:     return self.lo.get(dn, attr, required)
Jun 28 01:12:57 slave094 univention-portal-server[1857]:   File "/usr/lib/python2.7/dist-packages/univention/uldap.py", line 383, in get
Jun 28 01:12:57 slave094 univention-portal-server[1857]:     result = self.lo.search_s(dn, ldap.SCOPE_BASE, '(objectClass=*)', attr)
Jun 28 01:12:57 slave094 univention-portal-server[1857]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 597, in search_s
Jun 28 01:12:57 slave094 univention-portal-server[1857]:     return self.search_ext_s(base,scope,filterstr,attrlist,attrsonly,None,None,timeout=self.timeout)
Jun 28 01:12:57 slave094 univention-portal-server[1857]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 993, in search_ext_s
Jun 28 01:12:57 slave094 univention-portal-server[1857]:     return self._apply_method_s(SimpleLDAPObject.search_ext_s,*args,**kwargs)
Jun 28 01:12:57 slave094 univention-portal-server[1857]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 931, in _apply_method_s
Jun 28 01:12:57 slave094 univention-portal-server[1857]:     return func(self,*args,**kwargs)
Jun 28 01:12:57 slave094 univention-portal-server[1857]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 591, in search_ext_s
Jun 28 01:12:57 slave094 univention-portal-server[1857]:     return self.result(msgid,all=1,timeout=timeout)[1]
Jun 28 01:12:57 slave094 univention-portal-server[1857]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 503, in result
Jun 28 01:12:57 slave094 univention-portal-server[1857]:     resp_type, resp_data, resp_msgid = self.result2(msgid,all,timeout)
Jun 28 01:12:57 slave094 univention-portal-server[1857]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 507, in result2
Jun 28 01:12:57 slave094 univention-portal-server[1857]:     resp_type, resp_data, resp_msgid, resp_ctrls = self.result3(msgid,all,timeout)
Jun 28 01:12:57 slave094 univention-portal-server[1857]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 514, in result3
Jun 28 01:12:57 slave094 univention-portal-server[1857]:     resp_ctrl_classes=resp_ctrl_classes
Jun 28 01:12:57 slave094 univention-portal-server[1857]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 521, in result4
Jun 28 01:12:57 slave094 univention-portal-server[1857]:     ldap_result = self._ldap_call(self._l.result4,msgid,all,timeout,add_ctrls,add_intermediates,add_extop)
Jun 28 01:12:57 slave094 univention-portal-server[1857]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 106, in _ldap_call
Jun 28 01:12:57 slave094 univention-portal-server[1857]:     result = func(*args,**kwargs)
Jun 28 01:12:57 slave094 univention-portal-server[1857]: INSUFFICIENT_ACCESS: {'desc': 'Insufficient access'}
Comment 1 Felix Botner univentionstaff 2019-06-28 11:02:46 CEST
Created attachment 10094 [details]
syslog-no-samba-master.gz
Comment 2 Felix Botner univentionstaff 2019-06-28 11:04:00 CEST
(In reply to Felix Botner from comment #0)
> Multiple times In the syslog of master/backup/... of the errata jenkins
-> zless  syslog-no-samba-master.gz| grep Insuff|wc -l
140
Comment 3 Florian Best univentionstaff 2019-06-28 11:04:37 CEST
This happened this night the first time?
Comment 4 Florian Best univentionstaff 2019-06-28 11:06:57 CEST
I could imagine that this happens during a machine.secret rotation. If any cached ldap connection wouldn't do a bind() again.
Comment 5 Felix Botner univentionstaff 2019-06-28 13:17:46 CEST
(In reply to Florian Best from comment #4)
> I could imagine that this happens during a machine.secret rotation. If any
> cached ldap connection wouldn't do a bind() again.

yes, seems that self.udm (i guess this thing holds the connection) does not "reload" the password

-> kill -HUP 12696 (portal server refresh)

Jun 28 13:14:15 master univention-portal-server[12696]: refreshing cache
Jun 28 13:14:15 master univention-portal-server[12696]: INFO:univention.portal.cache:refreshing cache
Jun 28 13:14:15 master slapd[12787]: <= mdb_equality_candidates: (univentionComputerPortal) not indexed
Jun 28 13:14:15 master univention-portal-server[12696]: No CSS code available
Jun 28 13:14:15 master univention-portal-server[12696]: INFO:univention.portal.css:No CSS code available
Jun 28 13:14:15 master univention-portal-server[12696]: Writing CSS file /var/www/univention/portal/portal.css
Jun 28 13:14:15 master univention-portal-server[12696]: INFO:univention.portal.css:Writing CSS file /var/www/univention/portal/portal.css
Jun 28 13:14:15 master slapd[12787]: <= mdb_equality_candidates: (univentionPortalEntryPortal) not indexed

-> /usr/lib/univention-server/server_password_change

and

-> service slapd restart

to simulate the connection timeout for the univention portal server connection

-> kill -HUP 12696 (portal server refresh)

Jun 28 13:16:01 master univention-portal-server[12696]: Traceback (most recent call last):
Jun 28 13:16:01 master univention-portal-server[12696]:   File "/usr/bin/univention-portal-server", line 180, in refresh
Jun 28 13:16:01 master univention-portal-server[12696]:     localhost = self.udm.obj_by_dn(ldap_hostdn)
Jun 28 13:16:01 master univention-portal-server[12696]:   File "/usr/lib/pymodules/python2.7/univention/udm/udm.py", line 241, in obj_by_dn
Jun 28 13:16:01 master univention-portal-server[12696]:     ldap_obj = self.connection.get(dn, attr=[str('univentionObjectType')])
Jun 28 13:16:01 master univention-portal-server[12696]:   File "/usr/lib/pymodules/python2.7/univention/admin/uldap.py", line 708, in get
Jun 28 13:16:01 master univention-portal-server[12696]:     return self.lo.get(dn, attr, required)
Jun 28 13:16:01 master univention-portal-server[12696]:   File "/usr/lib/python2.7/dist-packages/univention/uldap.py", line 383, in get
Jun 28 13:16:01 master univention-portal-server[12696]:     result = self.lo.search_s(dn, ldap.SCOPE_BASE, '(objectClass=*)', attr)
Jun 28 13:16:01 master univention-portal-server[12696]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 597, in search_s
Jun 28 13:16:01 master univention-portal-server[12696]:     return self.search_ext_s(base,scope,filterstr,attrlist,attrsonly,None,None,timeout=self.timeout)
Jun 28 13:16:01 master univention-portal-server[12696]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 993, in search_ext_s
Jun 28 13:16:01 master univention-portal-server[12696]:     return self._apply_method_s(SimpleLDAPObject.search_ext_s,*args,**kwargs)
Jun 28 13:16:01 master univention-portal-server[12696]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 935, in _apply_method_s
Jun 28 13:16:01 master univention-portal-server[12696]:     self.reconnect(self._uri,retry_max=self._retry_max,retry_delay=self._retry_delay)
Jun 28 13:16:01 master univention-portal-server[12696]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 903, in reconnect
Jun 28 13:16:01 master univention-portal-server[12696]:     self._apply_last_bind()
Jun 28 13:16:01 master univention-portal-server[12696]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 873, in _apply_last_bind
Jun 28 13:16:01 master univention-portal-server[12696]:     func(self,*args,**kwargs)
Jun 28 13:16:01 master univention-portal-server[12696]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 223, in simple_bind_s
Jun 28 13:16:01 master univention-portal-server[12696]:     resp_type, resp_data, resp_msgid, resp_ctrls = self.result3(msgid,all=1,timeout=self.timeout)
Jun 28 13:16:01 master univention-portal-server[12696]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 514, in result3
Jun 28 13:16:01 master univention-portal-server[12696]:     resp_ctrl_classes=resp_ctrl_classes
Jun 28 13:16:01 master univention-portal-server[12696]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 521, in result4
Jun 28 13:16:01 master univention-portal-server[12696]:     ldap_result = self._ldap_call(self._l.result4,msgid,all,timeout,add_ctrls,add_intermediates,add_extop)
Jun 28 13:16:01 master univention-portal-server[12696]:   File "/usr/lib/python2.7/dist-packages/ldap/ldapobject.py", line 106, in _ldap_call
Jun 28 13:16:01 master univention-portal-server[12696]:     result = func(*args,**kwargs)
Jun 28 13:16:01 master univention-portal-server[12696]: INVALID_CREDENTIALS: {'desc': 'Invalid credentials'}
Comment 6 Florian Best univentionstaff 2019-06-28 13:19:20 CEST
Yes, I am currently doing the same. We will fix that now.
Comment 7 Florian Best univentionstaff 2019-06-28 14:06:05 CEST
I added reconnection handling to the portal server and added a password rotation script which reloads-or-restarts the service.

univention-portal (3.0.1-27)
f96ab2d5f5e0 | Bug #49746: restart univention-portal-server on server password change

univention-portal.yaml
9db78f709d44 | YAML Bug #49746
Comment 8 Felix Botner univentionstaff 2019-07-03 09:14:39 CEST
seen in the jenkins tests 

Jul 02 23:47:37 master091 univention-portal-server[31779]: refreshing cache
Jul 02 23:47:37 master091 univention-portal-server[31779]: INFO:univention.portal.cache:refreshing cache
Jul 02 23:47:37 master091 systemd[1]: Reloaded Univention Portal server.
Jul 02 23:47:37 master091 univention-portal-server[31779]: Error during refresh
Jul 02 23:47:37 master091 univention-portal-server[31779]: Traceback (most recent call last):
Jul 02 23:47:37 master091 univention-portal-server[31779]:   File "/usr/bin/univention-portal-server", line 181, in refresh
Jul 02 23:47:37 master091 univention-portal-server[31779]:     fd = self._refresh()
Jul 02 23:47:37 master091 univention-portal-server[31779]:   File "/usr/bin/univention-portal-server", line 195, in _refresh
Jul 02 23:47:37 master091 univention-portal-server[31779]:     portal_dn = localhost.props.portal
Jul 02 23:47:37 master091 univention-portal-server[31779]: AttributeError: 'ComputersAllObjectProperties' object has no attribute 'portal'
Jul 02 23:47:37 master091 univention-portal-server[31779]: ERROR:univention.portal.cache:Error during refresh
Jul 02 23:47:37 master091 univention-portal-server[31779]: Traceback (most recent call last):
Jul 02 23:47:37 master091 univention-portal-server[31779]:   File "/usr/bin/univention-portal-server", line 181, in refresh
Jul 02 23:47:37 master091 univention-portal-server[31779]:     fd = self._refresh()
Jul 02 23:47:37 master091 univention-portal-server[31779]:   File "/usr/bin/univention-portal-server", line 195, in _refresh
Jul 02 23:47:37 master091 univention-portal-server[31779]:     portal_dn = localhost.props.portal
Jul 02 23:47:37 master091 univention-portal-server[31779]: AttributeError: 'ComputersAllObjectProperties' object has no attribute 'portal'
Jul 02 23:47:37 master091 nrpe[1755]: Caught SIGTERM - shutting down...

http://jenkins.knut.univention.de:8080/job/UCS-4.4/job/UCS-4.4-0/job/AutotestJoin/SambaVersion=no-samba,Systemrolle=master/ws/test/journalctl.log/*view*/
Comment 9 Florian Best univentionstaff 2019-07-03 10:04:26 CEST
> Traceback (most recent call last):
>  File "/usr/bin/univention-portal-server", line 181, in refresh
>      fd = self._refresh()
>  File "/usr/bin/univention-portal-server", line 195, in _refresh
>      portal_dn = localhost.props.portal
> AttributeError: 'ComputersAllObjectProperties' object has no attribute 'portal'

Hmm, I cannot trigger this. I tried:
Remove univentionPortalComputer attribute from the computer:
But obj.props.portal is None then.
I tried setting the DN to a not existing object and to an invalid value but it then contains that DN/value.
Comment 10 Florian Best univentionstaff 2019-07-03 10:16:56 CEST
(In reply to Florian Best from comment #9)
> > Traceback (most recent call last):
> >  File "/usr/bin/univention-portal-server", line 181, in refresh
> >      fd = self._refresh()
> >  File "/usr/bin/univention-portal-server", line 195, in _refresh
> >      portal_dn = localhost.props.portal
> > AttributeError: 'ComputersAllObjectProperties' object has no attribute 'portal'
> 
> Hmm, I cannot trigger this. I tried:
> Remove univentionPortalComputer attribute from the computer:
> But obj.props.portal is None then.
> I tried setting the DN to a not existing object and to an invalid value but
> it then contains that DN/value.

Okay got it. This happens if the extended attribute does not exists (yet): cn=portal,cn=custom attributes,cn=univention,l=school,l=dev.
Comment 11 Florian Best univentionstaff 2019-07-03 10:51:31 CEST
Okay, the simple UDM API doesn't provide any ways to reset caching but I could find a way to reload the extended attributes in case they don't exists.

univention-portal (3.0.1-28)
90a57cea93ec | Bug #49746: fix reloading of extended attributes
Comment 12 Dirk Wiesenthal univentionstaff 2019-07-04 16:47:39 CEST
Reconnection does not work yet. univention.udm.connections caches the machine connection, therefore recreating a UDM.machine() object does use the already initialized (and timed out) connection. => We could stop caching connections altogether?

Also, UDM caches the modules to which it passes its connection. One needs to create a new module object with a new connection. => To not hit the cache, one could use the connection id instead of the binddn.

This could free us from using private variables in the portal.
Comment 13 Philipp Hahn univentionstaff 2019-07-05 16:45:01 CEST
[4.4-0] a8d6b13324 Bug #49746 udm: Remove caching of machine connections
 management/univention-directory-manager-modules/debian/changelog  | 6 ++++++
 .../modules/univention/udm/connections.py                         | 8 +++-----
 .../modules/univention/udm/connections.pyi                        | 1 -
 .../modules/univention/udm/udm.py                                 | 2 +-
 .../modules/univention/udm/udm.pyi                                | 2 +-
 5 files changed, 11 insertions(+), 8 deletions(-)

Package: univention-directory-manager-modules
Version: 14.0.12-43A~4.4.0.201907051641
Branch: ucs_4.4-0
Scope: errata4.4-0

[4.4-0] ff581787f0 Bug #49526: univention-directory-manager-modules 14.0.12-42A~4.4.0.201906261823
 doc/errata/staging/univention-directory-manager-modules.yaml | 9 +++++----
 1 file changed, 5 insertions(+), 4 deletions(-)
[4.4-0] b9bb57cf87 Bug #49526: univention-directory-manager-modules 14.0.12-43A~4.4.0.201907051641
 doc/errata/staging/univention-directory-manager-modules.yaml | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

QA: See commit message for my test protocol
Comment 14 Dirk Wiesenthal univentionstaff 2019-07-09 20:18:52 CEST
OK, portal works now.