Bug 54032 - UMC UDM modules won't open with SAML login in large environment / with many group memberships
UMC UDM modules won't open with SAML login in large environment / with many g...
Status: CLOSED FIXED
Product: UCS
Classification: Unclassified
Component: UMC (Generic)
UCS 4.4
Other Windows NT
: P5 normal (vote)
: UCS 5.0-1-errata
Assigned To: Nikola Radovanovic
Dirk Wiesenthal
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2021-11-04 15:09 CET by Michael Grandjean
Modified: 2022-02-23 16:29 CET (History)
5 users (show)

See Also:
What kind of report is it?: Bug Report
What type of bug is this?: 5: Major Usability: Impairs usability in key scenarios
Who will be affected by this bug?: 2: Will only affect a few installed domains
How will those affected feel about the bug?: 4: A User would return the product
User Pain: 0.229
Enterprise Customer affected?:
School Customer affected?: Yes
ISV affected?:
Waiting Support:
Flags outvoted (downgraded) after PO Review:
Ticket number: 2021110921000214
Bug group (optional):
Max CVSS v3 score:


Attachments
timeout patch for tools.js (2.28 KB, patch)
2022-01-28 06:43 CET, Nikola Radovanovic
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Comment 2 Florian Best univentionstaff 2021-11-04 15:24:45 CET
Can you copy the javascript errors from the developer console?
Can you have a look in the network tab of the developer console, if there are requests which take very long or fail?

Is there a proxy / ha / gateway between UMC and your browser?
Comment 3 Michael Grandjean univentionstaff 2021-11-08 12:19:37 CET
Thx, Florian.

> Can you copy the javascript errors from the developer console?

The first and main error is:
"Could not load JSON data from /univention/get/meta?1636366412986: RequestTimeoutError: Timeout exceeded"

Everything else seems to be a consequential failure, afaics.

> Can you have a look in the network tab of the developer console, if there are requests which take very long or fail?

Yes, as the error above indicates, the GET for /univention/get/meta?1636366412986 takes very long.

Environment 1: 10,2 seconds, results in timeout, UDM UMC modules won't open
Environment 2:  9,1 seconds, long wait, but no timeout, UDM UMC modules open

Environments 1 and 2 are very similiar, Env2 has just a bit more power regarding CPUs, RAM, Disk-IO etc.

> Is there a proxy / ha / gateway between UMC and your browser?

Only a simple firewall/NAT with port translation, nothing too fancy.
Comment 4 Michael Grandjean univentionstaff 2021-11-08 12:26:34 CET
I discovered that there is a difference if I login via SAML or not:

1. Login via SAML (https://<my-idp-fqdn>/univention/simplesamlphp/): 
described behaviour as above, the GET for /univention/get/meta?1636366412986 takes >10 seconds and fails, resulting in UMC UDM modules that can't be opened.

2. Login via non-SAML/PAM-Stack (https://<my-fqdn>/univention/login/):
no problems, the GET for /univention/get/meta?1636366412986 takes around 100 ms(!) and all UMC modules can be opened.

This is the *same* environment. Unfortunately, the customer makes heavy use of SAML, so the non-SAML-version is not a valid workaround there.
Comment 7 Florian Best univentionstaff 2021-11-08 12:37:52 CET
Does restarting slapd solve the problem?
Comment 9 Florian Best univentionstaff 2021-11-08 12:57:50 CET
dojo.js.uncompressed.js:1310 Uncaught TypeError: Cannot read properties of undefined (reading 'split')
    at ActivationPage.js:66
    at pa (dojo.js.uncompressed.js:1164)
    at dojo.js.uncompressed.js:1330
    at X (dojo.js.uncompressed.js:1307)
    at na (dojo.js.uncompressed.js:1325)
    at q (dojo.js.uncompressed.js:1492)
    at HTMLScriptElement.<anonymous> (dojo.js.uncompressed.js:1745)
(anonymous) @ ActivationPage.js:66
Comment 14 Michael Grandjean univentionstaff 2021-11-24 13:41:59 CET
After some more digging, one problem seems to be "too many" group memberships (e.g >100). Getting all groups and their UMC-policies took long enough to yield the timeout.

I was able to reduce the number of group memberships in the customer environment, so the problem does not occur anymore.

However, I don't understand why this only happens with SAML-based logins and was no problem at all with non-SAML-based logins.
Comment 15 Dirk Schnick univentionstaff 2021-11-30 22:14:59 CET
I have set up a test environment and compared direct login and SAML login in management-(web)-server.log.
Why is SAML requesting three times?

Direct
30.11.21 13:11:50.295  MAIN        ( INFO    ) : Sending authentication request for user u'gundhart.sch'
30.11.21 13:11:50.315  AUTH        ( INFO    ) : Trying to authenticate user u'gundhart.sch'
30.11.21 13:11:50.418  MODULE      ( PROCESS ) : Setting auth type to None
30.11.21 13:11:54.315  MAIN        ( PROCESS ) : SessionClient(0x7f418068bc58): _authenticated: success=True  status=200  message=None result={u'username': u'gundhart.sch'}
30.11.21 13:11:54.316  MAIN        ( PROCESS ) : auth_type=None

SAML
30.11.21 13:00:15.108  MAIN        ( INFO    ) : Sending authentication request for user u'gundhart.sch'
30.11.21 13:00:15.133  AUTH        ( INFO    ) : Trying to authenticate user u'gundhart.sch'
30.11.21 13:00:15.237  MODULE      ( PROCESS ) : Setting auth type to u'SAML'
30.11.21 13:00:15.409  MAIN        ( INFO    ) : Sending authentication request for user u'gundhart.sch'
30.11.21 13:00:15.410  MAIN        ( INFO    ) : Sending authentication request for user u'gundhart.sch'
30.11.21 13:00:19.098  MAIN        ( PROCESS ) : SessionClient(0x7f418068b9f0): _authenticated: success=True  status=200  message=None result={u'username': u'gundhart.sch'}
30.11.21 13:00:19.106  AUTH        ( INFO    ) : Trying to authenticate user u'gundhart.sch'
30.11.21 13:00:19.120  MODULE      ( PROCESS ) : Setting auth type to u'SAML'
30.11.21 13:00:19.120  AUTH        ( INFO    ) : Trying to authenticate user u'gundhart.sch'
30.11.21 13:00:23.172  MAIN        ( PROCESS ) : SessionClient(0x7f418068b9f0): _authenticated: success=True  status=200  message=None result={u'username': u'gundhart.sch'}
30.11.21 13:00:23.173  MODULE      ( PROCESS ) : Setting auth type to u'SAML'
30.11.21 13:00:27.146  MAIN        ( PROCESS ) : SessionClient(0x7f418068b9f0): _authenticated: success=True  status=200  message=None result={u'username': u'gundhart.sch'}

It looks to me like the policy are also received three times. So SAML login takes three times more activity and time. Why?

If you want to use my test environment give me a hint. I can reproduce the behavior.
Comment 19 Florian Best univentionstaff 2021-12-13 16:27:40 CET
Comment via chat from Michael on 8th November:
"nach slapd restart bin ich runter auf ~4 Sekunden für das GET"
Comment 22 Michael Grandjean univentionstaff 2021-12-14 13:26:09 CET
(In reply to Florian Best from comment #19)
> Comment via chat from Michael on 8th November:
> "nach slapd restart bin ich runter auf ~4 Sekunden für das GET"

Unfortunately, that effect lastet only for the very first login after slapd restart, but was back to >10 seconds for every consecutive login.
Comment 27 Florian Best univentionstaff 2021-12-14 16:08:02 CET
Bug #52298 might help to speed up the login process in large environments a little bit.
Comment 29 Nikola Radovanovic univentionstaff 2022-01-26 13:27:26 CET
3ef9bf12da | UMC UDM modules won't open with SAML login in large environment
8156a4f7fb | Advisory update
Comment 30 Julia Bremer univentionstaff 2022-01-27 09:38:45 CET
All our selenium tests fail now.
No UMC modules are loaded anymore after updating univention-web
I see this in the logs:

{"level": "WARNING", "message": "https://master091.autotest091.local/univention/management/main.js 1248:13 \"Module could not be loaded: umc/modules/lib\"", "source": "console-api", "timestamp": 1643261997670}
{"level": "SEVERE", "message": "https://master091.autotest091.local/univention/js/dojo/dojo.js 20:35 Uncaught TypeError: Cannot read property 'split' of undefined", "source": "javascript", "timestamp": 1643261997670}

and
Uncaught TypeError: tools.status(...) is undefined


http://jenkins.knut.univention.de:8080/job/UCS-5.0/job/UCS-5.0-1/job/AutotestJoin/lastCompletedBuild/testReport/
Comment 31 Nikola Radovanovic univentionstaff 2022-01-27 15:18:00 CET
(In reply to Julia Bremer from comment #30)
There are some data missing in response with using xhr.get(), namely these:

"appliance_name": null,
"has_free_license": true,
"has_license_base": true,
"has_system_uuid": true,
"hasFreeLicense": true,
"ldap/master": "ucs-4739.fooad.local",
"license/base": "UCS Core Edition",
"server/role": "domaincontroller_master",
"ssl/validity/host": "20841",
"ssl/validity/root": "20841",
"ssl/validity/warning": "30",
"ucs_version": "5.0-1 errata199",
"ucsVersion": "5.0-1 errata199",
"umc/web/favorites/default": "welcome,udm:users/user,udm:groups/group,udm:computers/computer,appcenter:appcenter,updater",
"umc/web/piwik": null,
"update/available": "no",
"update/reboot/required": null,
"uuid/license": "f5f1be5d-a8b6-4223-8227-7f4136409c1d",
"uuid/system": "1d21cb20-1c12-40ad-9679-ac3f34fa9c11",
"version/erratalevel": "199",
"version/patchlevel": "1",
"version/version": "5.0"

I have to find out why - guess some headers in request is/are missing
Comment 32 Florian Best univentionstaff 2022-01-27 15:24:03 CET
(In reply to Nikola Radovanovic from comment #31)
> (In reply to Julia Bremer from comment #30)
> There are some data missing in response with using xhr.get(), namely these:
> …
> I have to find out why - guess some headers in request is/are missing

Yes, the cookie (and Accept, Accept-Language headers) are missing.
The UMC-server has a different response for logged in and unauthenticated clients.
Comment 33 Florian Best univentionstaff 2022-01-27 17:38:52 CET
it might work with the xhr flag `withCredentials=true`.
But we shouldn't use xhr directly as we are encapsulating xhr requests in our libraries to e.g. make a unified error handling and request handling.

My suggestion would be to use:
deferred = tools.umcpCommand('get/meta').then(lang.hitch(this, function(meta) { lang.mixin(this._status, meta.result); }));

If you really want a custom error message you can also do this via `umcpCommand` - but it would also hide the real error message then.
Comment 34 Nikola Radovanovic univentionstaff 2022-01-28 06:43:21 CET
Created attachment 10909 [details]
timeout patch for tools.js

(In reply to Florian Best from comment #33)
Do you mean something like this?
Comment 35 Florian Best univentionstaff 2022-01-28 10:55:59 CET
(In reply to Nikola Radovanovic from comment #34)
> Created attachment 10909 [details]
> timeout patch for tools.js
> 
> (In reply to Florian Best from comment #33)
> Do you mean something like this?

yes
Comment 36 Nikola Radovanovic univentionstaff 2022-01-31 10:15:29 CET
3ef9bf12da | UMC UDM modules won't open with SAML login in large environment
8156a4f7fb | Advisory update
5310d9619d | univention-web 4.0.1-44A~5.0.0.202201261311
778d5ec044 | Fix timeout handling
116465c0fa | UMC UDM modules won't open with SAML login in large environment
88360feaca | Advisory update

I pushed directly as per instruction. Actually, there is one event now waiting for 10 secs. If loading of data took longer - it will display the message as instructed; otherwise, this event is canceled and nothing is shown. I realized that if we do timeout on actual loading of MetaData, it will not internally populate status correctly and although call lasted long it will prevent normal functioning of the app.

Not sure shall we clone this bug now and tackle actual slowdown problems separately.
Comment 37 Florian Best univentionstaff 2022-01-31 23:34:48 CET
git:116465c0fa83fdf17dfff1d68ce91c34a9c1ed15 changed univention-web-js version from 4.0.1-43 to 4.0.2-44 - so a minor update which shouldn't be done during errata updates.

The changes in the translation files also causes this test to fail:
60_umc.101_test_umc_frontend_i18n.TestI18N.test_with_content[js/umc/i18n/en/app.json] (from pytest) 

https://jenkins.knut.univention.de:8181/job/UCS-5.0/job/UCS-5.0-1/job/AutotestJoin/lastCompletedBuild/SambaVersion=no-samba,Systemrolle=master/testReport/60_umc.101_test_umc_frontend_i18n/TestI18N/test_with_content_js_umc_i18n_en_app_json_/

→ because "/var/www/univention/js/umc/i18n/en/app.json" is now empty ({}) and has no entries anymore.
Comment 42 Nikola Radovanovic univentionstaff 2022-02-09 23:12:17 CET
3ef9bf12da | UMC UDM modules won't open with SAML login in large environment
8156a4f7fb | Advisory update
5310d9619d | univention-web 4.0.1-44A~5.0.0.202201261311
778d5ec044 | Fix timeout handling
116465c0fa | UMC UDM modules won't open with SAML login in large environment
88360feaca | Advisory update
a5c790d937 | Advisory update
6047990d2c | Advisory update
10178777d8 | UMC UDM modules won't open with SAML login in large environment
66b8ec35d3 | Advisory update

Empty English po JSON file should now be fixed
Comment 43 Dirk Wiesenthal univentionstaff 2022-02-22 10:50:46 CET
Non-SAML Tests: OK
SAML Tests: OK
0 groups, 1800 groups: OK
Code: OK
YAML: OK
Help article: Very brief, but okay