SRAM monitoring scripts are failing regularly

[baszoetekouw]

A few times per day, the sram-monitor scritp failes like this:

Aug 07 06:10:01 bhr13 systemd[1]: Starting SRAM Monitor (chrome)...
Aug 07 06:10:01 bhr13 run_sram_monitoring.sh[1834227]: Stopping container
Aug 07 06:10:01 bhr13 run_sram_monitoring.sh[1834228]: Error: No such container: browser
Aug 07 06:10:01 bhr13 run_sram_monitoring.sh[1834227]: Starting chrome container
Aug 07 06:10:02 bhr13 run_sram_monitoring.sh[1834233]: e97d596cb6a18b9b16c283d144e810502ac86dfa149cdbb99ee062b98064254f
Aug 07 06:10:10 bhr13 run_sram_monitoring.sh[1834227]: ....... Up!
Aug 07 06:10:10 bhr13 run_sram_monitoring.sh[1834467]: = READING ['prd.yml', 'chrome'] ====
Aug 07 06:10:10 bhr13 run_sram_monitoring.sh[1834467]: = Starting Browser chrome ===
Aug 07 06:10:13 bhr13 run_sram_monitoring.sh[1834467]: ============
Aug 07 06:10:13 bhr13 run_sram_monitoring.sh[1834467]: user: {'name': 'student', 'password': 'xxx'}
Aug 07 06:10:13 bhr13 run_sram_monitoring.sh[1834467]: userinfo: {'sub': '[email protected]', 'name': 'Student One', 'given_name': 'Student', 'family_name': 'One', 'email': '[email protected]', 'uid': ['sone8'], 'eduperson_entitlement': ['urn:mace:surf.nl:sram:group:sramadmin', 'urn:mace:surf.nl:sram:group:sramadmin:samloidc_monitor', 'urn:mace:surf.nl:sram:group:surf-ram#sram.surf.nl'], 'eduperson_principal_name': ['[email protected]'], 'eduperson_scoped_affiliation': ['[email protected]'], 'voperson_external_affiliation': ['[email protected]', '[email protected]'], 'voperson_external_id': ['[email protected]'], 'voperson_id': ['[email protected]']}
Aug 07 06:10:29 bhr13 run_sram_monitoring.sh[1834467]: = OK =======
Aug 07 06:10:30 bhr13 run_sram_monitoring.sh[1834467]: ============
Aug 07 06:10:30 bhr13 run_sram_monitoring.sh[1834467]: user: {'name': 'employee', 'password': 'xxx'}
Aug 07 06:10:30 bhr13 run_sram_monitoring.sh[1834467]: userinfo: {'sub': '[email protected]', 'name': 'Employee One', 'given_name': 'Employee', 'family_name': 'One', 'email': '[email protected]', 'uid': ['eone'], 'eduperson_entitlement': ['urn:mace:surf.nl:sram:group:sramadmin:samloidc_monitor', 'urn:mace:surf.nl:sram:group:sramadmin', 'urn:mace:surf.nl:sram:group:surf-ram#sram.surf.nl'], 'eduperson_principal_name': ['[email protected]'], 'eduperson_scoped_affiliation': ['[email protected]'], 'voperson_external_affiliation': ['[email protected]', '[email protected]'], 'voperson_external_id': ['[email protected]'], 'voperson_id': ['[email protected]']}
Aug 07 06:10:43 bhr13 run_sram_monitoring.sh[1834467]: = OK =======
Aug 07 06:10:43 bhr13 run_sram_monitoring.sh[1834467]: ============
Aug 07 06:10:43 bhr13 run_sram_monitoring.sh[1834467]: user: {'name': 'student', 'password': 'xxx'}
Aug 07 06:10:43 bhr13 run_sram_monitoring.sh[1834467]: userinfo: {'uid': ['sone8'], 'schacHomeOrganization': ['test-idp.sram.surf.nl'], 'voPersonExternalID': ['[email protected]'], 'displayName': ['Student One'], 'cn': ['Student One'], 'sn': ['One'], 'givenName': ['Student'], 'mail': ['[email protected]'], 'eduPersonUniqueId': ['[email protected]'], 'subject-id': ['[email protected]'], 'voPersonID': ['[email protected]'], 'voPersonExternalAffiliation': ['[email protected]', '[email protected]'], 'eduPersonEntitlement': ['urn:mace:surf.nl:sram:group:sramadmin', 'urn:mace:surf.nl:sram:group:sramadmin:samloidc_monitor', 'urn:mace:surf.nl:sram:group:surf-ram#sram.surf.nl'], 'eduPersonPrincipalName': ['[email protected]'], 'eduPersonScopedAffiliation': ['[email protected]']}
Aug 07 06:10:56 bhr13 run_sram_monitoring.sh[1834467]: = OK =======
Aug 07 06:10:57 bhr13 run_sram_monitoring.sh[1834467]: ============
Aug 07 06:10:57 bhr13 run_sram_monitoring.sh[1834467]: user: {'name': 'employee', 'password': 'xxx'}
Aug 07 06:10:57 bhr13 run_sram_monitoring.sh[1834467]: userinfo: {'uid': ['eone'], 'schacHomeOrganization': ['test-idp.sram.surf.nl'], 'voPersonExternalID': ['[email protected]'], 'displayName': ['Employee One'], 'cn': ['Employee One'], 'sn': ['One'], 'givenName': ['Employee'], 'mail': ['[email protected]'], 'eduPersonUniqueId': ['[email protected]'], 'subject-id': ['[email protected]'], 'voPersonID': ['[email protected]'], 'voPersonExternalAffiliation': ['[email protected]', '[email protected]'], 'eduPersonEntitlement': ['urn:mace:surf.nl:sram:group:sramadmin:samloidc_monitor', 'urn:mace:surf.nl:sram:group:sramadmin', 'urn:mace:surf.nl:sram:group:surf-ram#sram.surf.nl'], 'eduPersonPrincipalName': ['[email protected]'], 'eduPersonScopedAffiliation': ['[email protected]']}
Aug 07 06:11:09 bhr13 run_sram_monitoring.sh[1834467]: = OK =======
Aug 07 06:11:10 bhr13 run_sram_monitoring.sh[1834848]: = READING ['prd.yml', 'chrome'] ====
Aug 07 06:11:10 bhr13 run_sram_monitoring.sh[1834848]: = Starting Browser chrome ===
Aug 07 06:11:10 bhr13 run_sram_monitoring.sh[1834848]: https://sram.surf.nl/
Aug 07 06:11:10 bhr13 run_sram_monitoring.sh[1834848]: ============
Aug 07 06:11:10 bhr13 run_sram_monitoring.sh[1834848]: student Student One
Aug 07 06:11:27 bhr13 run_sram_monitoring.sh[1834848]: = OK =======
Aug 07 06:11:27 bhr13 run_sram_monitoring.sh[1834848]: ============
Aug 07 06:11:27 bhr13 run_sram_monitoring.sh[1834848]: employee Employee One
Aug 07 06:11:50 bhr13 run_sram_monitoring.sh[1835023]: = READING ['prd.yml', 'chrome'] ====
Aug 07 06:11:50 bhr13 run_sram_monitoring.sh[1835023]: = Starting Browser chrome ===
Aug 07 06:11:51 bhr13 run_sram_monitoring.sh[1835023]: https://sram.surf.nl/weblogin/sram_demo_pam/386e4be1-d859-443c-92e5-949fec48ff27
Aug 07 06:12:07 bhr13 run_sram_monitoring.sh[1835023]: code: 3597
Aug 07 06:12:08 bhr13 run_sram_monitoring.sh[1835023]: result: SUCCESS
Aug 07 06:12:08 bhr13 run_sram_monitoring.sh[1835023]: = OK =======
Aug 07 06:12:08 bhr13 run_sram_monitoring.sh[1835114]: 1723011010
Aug 07 06:12:08 bhr13 run_sram_monitoring.sh[1835114]: login=OK
Aug 07 06:12:08 bhr13 run_sram_monitoring.sh[1835114]: sbs_login=error at url: https://ds.sram.surf.nl/ds/?entityID=https%3A%2F%2Fproxy.sram.surf.nl%2Fmetadata%2Fbackend.xml&return=https%3A%2F%2Fproxy.sram.surf.nl%2Fsaml2sp%2Fdisco error NoSuchElementException on line 84 of '/opt/sram-monitor/sbs-login.py'
Aug 07 06:12:08 bhr13 run_sram_monitoring.sh[1835114]: pam_weblogin=OK
Aug 07 06:12:08 bhr13 run_sram_monitoring.sh[1835114]: browser=chrome
Aug 07 06:12:13 bhr13 run_sram_monitoring.sh[1834227]: End of  chrome test
Aug 07 06:12:13 bhr13 run_sram_monitoring.sh[1835170]: Stopping container

aka: no error messages, but the sbs login script fails to get through the discovery screen.

We should try to dump a screenshot and dump the DOM tree at the point so we can see what the fleep is happening here. Still not sure if this is a bug in the script, or whether there's some kind of glitch in the actual discovery screen.

[mrvanes]

Gebruiken we deze dan al in prd? Ik ben de draad een beetje kwijt?
SURFscz/SRAM-monitoring#4

[mrvanes]

Here's a screenshot of the last (Aug 8 08:20) failure

It seems the searching for the IdP results takes longer than 10 seconds in these cases?

[baszoetekouw]

AH nee die had ik idd neit gezien. Ga ik mergen!

[mrvanes]

Dat is goed, maar dat is ook al de huidige stand van zaken op bhr13 zag ik, dus daar lag het niet aan

[baszoetekouw]

Hmm, en gezien dat screenshot lijkt het misschien wel een echte bug. Ik ga het ook eens aan eduteams vragen. Weet jij of selecnium ook een netwerk log kan maken. (developer tools openen ofzo?).

Nu ik het bugreport naar eduteams aan he schrijven ben zie ik wel een patroon: het treedt steeds op om 0:00, 6:00, 12:00, 18:00 UTC, aka het moment dat eduteams hun metadata update...

[mrvanes]

Doesn't fix the problem, but helps aligning the logging and error reporting
SURFscz/SRAM-monitoring#5