container-test-run-authelia
checks.aarch64-linux.authelia
· build #214
· raw
1build01: building dv9v3fsv99wn3p2zkn1dpbc05wpbjqcv-container-test-run-authelia.drv2Machine state will be reset. To keep it, pass --keep-machine-state3start all VLans4(finished: start all VLans, in 0.00 seconds)56Test will time out and terminate in 3600.0 seconds7run the VM test script8additionally exposed symbols:9 server,10 vlan1,11 start_all, test_script, machines, machines_qemu, machines_nspawn, vlans, driver, log, os, create_machine, subtest, run_tests, join_all, retry, serial_stdout_off, serial_stdout_on, polling_condition, BaseMachine, QemuMachine, NspawnMachine, t, debug, dump_machine_ssh12start all VMs13server: systemd-nspawn running (pid 51)14server: Waiting for journal at /build/vm-state-server/var/log/journal...15(finished: start all VMs, in 0.00 seconds)16??? Warning (UserWarning): wait_for_unit(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.17 File "/nix/store/drwj5qfqx9axxgf0jvxlavglj43fr2kh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 3918server: waiting for unit authelia-authelia.service19nixos-nspawn(server): TAP vde-tap1 not found; container will be isolated from VDE20nixos-nspawn(server): A common reason for this is that /dev/net is not available in the Nix sandbox. Try adding /dev/net to extra-sandbox-paths.21Note: in a future version of systemd-nspawn the default set of permitted socket address families will be restricted to AF_INET, AF_INET6 and AF_UNIX. Use --restrict-address-families= to configure the set of permitted socket address families, or set RestrictAddressFamilies= in a .nspawn file.22░ Spawning container server on /build/vm-state-server.23server # No journal files were found.24server # No journal boot entry found for the specified boot (+0).25server # [2479108.594972] server systemd-journald[187]: Journal started26server # [2479108.595033] server systemd-journald[187]: Runtime Journal (/run/log/journal/80fe9d30b3a74d97a00626b0014e29b2) is 8M, max 2.5G, 2.4G free.27server # [2479108.604684] server systemd[1]: Finished Apply Kernel Variables.28server # [2479108.618197] server systemd[1]: Finished Create Static Device Nodes in /dev gracefully.29server # [2479108.633187] server systemd[1]: Starting Flush Journal to Persistent Storage...30server # [2479108.634103] server systemd[1]: Starting Network Name Resolution...31server # [2479108.634818] server systemd[1]: Starting Create Static Device Nodes in /dev...32server # [2479108.642407] server systemd-journald[187]: Time spent on flushing to /var/log/journal/80fe9d30b3a74d97a00626b0014e29b2 is 1.534ms for 7 entries.33server # [2479108.642407] server systemd-journald[187]: System Journal (/var/log/journal/80fe9d30b3a74d97a00626b0014e29b2) is 8M, max 4G, 3.9G free.34server # [2479108.655083] server systemd[1]: Finished Create Static Device Nodes in /dev.35server # [2479108.655652] server systemd[1]: Reached target Preparation for Local File Systems.36server # [2479108.655759] server systemd[1]: Reached target Local File Systems.37server # [2479108.656689] server systemd[1]: Listening on Boot Loader Control Service Socket.38server # [2479108.656740] server systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container39server # [2479108.657582] server systemd[1]: Starting Save Transient machine-id to Disk...40server # [2479108.657618] server systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys41server # [2479108.659686] server systemd[1]: Finished Flush Journal to Persistent Storage.42server # [2479108.660973] server systemd[1]: Starting Create System Files and Directories...43server # [2479108.678395] server systemd-tmpfiles[241]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted44server # [2479108.678609] server systemd-tmpfiles[241]: fchmod() of /var/log/journal failed: Operation not permitted45server # [2479108.678971] server systemd-tmpfiles[241]: fchmod() of /var/log/journal/80fe9d30b3a74d97a00626b0014e29b2 failed: Operation not permitted46server # [2479108.679196] server systemd-tmpfiles[241]: fchmod() of /run/log/journal failed: Operation not permitted47server # [2479108.680650] server systemd[1]: Finished Create System Files and Directories.48server # [2479108.681793] server systemd[1]: Starting Rebuild Journal Catalog...49server # [2479108.682557] server systemd[1]: Starting Record System Boot/Shutdown in UTMP...50server # [2479108.692100] server systemd[1]: Finished Save Transient machine-id to Disk.51server # [2479108.704253] server systemd[1]: Finished Record System Boot/Shutdown in UTMP.52server # [2479108.705610] server systemd[1]: Finished Rebuild Journal Catalog.53server # [2479108.707258] server systemd[1]: Starting Update is Completed...54server # [2479108.719539] server systemd[1]: Finished Update is Completed.55server # [2479108.773833] server systemd[1]: Finished Firewall.56server # [2479108.774012] server systemd[1]: Reached target Preparation for Network.57server # [2479108.774254] server systemd[1]: Listening on Network Management Resolve Hook Socket.58server # [2479108.775464] server systemd[1]: Starting Network Management...59server # [2479109.368572] server systemd-networkd[301]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted60server # [2479109.368664] server systemd-networkd[301]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted61server # [2479109.377465] server systemd-networkd[301]: /etc/systemd/network/99-ethernet-default-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.62server # [2479109.377627] server systemd-networkd[301]: /etc/systemd/network/99-wireless-client-dhcp.network: No valid settings found in the [Match] section, ignoring file. To match all interfaces, add Name=* in the [Match] section.63server # [2479109.377778] server systemd-networkd[301]: lo: Link UP64server # [2479109.377783] server systemd-networkd[301]: lo: Gained carrier65server # [2479109.377968] server systemd-networkd[301]: eth1: Configuring with /etc/systemd/network/40-eth1.network.66server # [2479109.378390] server systemd-networkd[301]: eth1: Link UP67server # [2479109.378739] server systemd[1]: Started Network Management.68server # [2479109.379603] server systemd-networkd[301]: eth1: Gained carrier69server # [2479109.380098] server systemd[1]: Starting Enable Persistent Storage in systemd-networkd...70server # [2479109.445585] server systemd[1]: Finished Enable Persistent Storage in systemd-networkd.71server # [2479109.602156] server systemd[1]: etc-machine\x2did.mount: Deactivated successfully.72server # [2479109.668036] server systemd-resolved[223]: Positive Trust Anchors:73server # [2479109.668047] server systemd-resolved[223]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d74server # [2479109.668050] server systemd-resolved[223]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b1675server # [2479109.668084] server systemd-resolved[223]: Negative trust anchors: home.arpa 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 170.0.0.192.in-addr.arpa 171.0.0.192.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa ipv4only.arpa resolver.arpa corp home internal intranet lan local private test76server # [2479109.688357] server systemd-resolved[223]: Using system hostname 'server'.77server # [2479109.689723] server systemd[1]: Started Network Name Resolution.78server # [2479109.689856] server systemd[1]: Reached target Network.79server # [2479109.689963] server systemd[1]: Reached target Network is Online.80server # [2479109.690049] server systemd[1]: Reached target System Initialization.81server # [2479109.690136] server systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container82server # [2479109.690182] server systemd[1]: Started Daily Cleanup of Temporary Directories.83server # [2479109.690223] server systemd[1]: Reached target Timer Units.84server # [2479109.690448] server systemd[1]: Listening on D-Bus System Message Bus Socket.85server # [2479109.690654] server systemd[1]: Listening on Nix Daemon Socket.86server # [2479109.690870] server systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.87server # [2479109.690916] server systemd[1]: Reached target Socket Units.88server # [2479109.690990] server systemd[1]: Reached target Basic System.89server # [2479109.693252] server systemd[1]: Starting Authelia authentication and authorization server...90server # [2479109.694713] server systemd[1]: Starting Caddy...91server # [2479109.696048] server systemd[1]: Starting Import lastlog data into lastlog2 database...92server # [2479109.697515] server systemd[1]: Starting Name Service Cache Daemon (nsncd)...93server # [2479109.745320] server systemd[1]: Starting D-Bus System Message Bus...94server # [2479109.797301] server systemd[1]: Finished Import lastlog data into lastlog2 database.95server # [2479109.919943] server systemd[1]: Started Name Service Cache Daemon (nsncd).96server # [2479109.920184] server nsncd[309]: Oct 03 00:05:29.905 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"97server # [2479109.920091] server systemd[1]: Reached target Host and Network Name Lookups.98server # [2479109.920202] server systemd[1]: Reached target User and Group Name Lookups.99server # [2479109.945786] server systemd[1]: Starting User Login Management...100server # [2479109.947121] server systemd[1]: Starting Permit User Sessions...101server # [2479109.959178] server systemd[1]: Finished Permit User Sessions.102server # [2479109.960879] server systemd[1]: Started Console Getty.103server # [2479109.960961] server systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0104server # [2479109.961004] server systemd[1]: Reached target Login Prompts.105server # [2479110.066236] server dbus-broker-launch[313]: Looking up NSS user entry for 'systemd-timesync'...106server # [2479110.067467] server dbus-broker-launch[313]: NSS returned no entry for 'systemd-timesync'107server # [2479110.067467] server dbus-broker-launch[313]: Invalid user-name in /nix/store/l9d5hc5401vxlqlgy5w71l94nm2yzh2i-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"108server # [2479110.067869] server systemd[1]: Started D-Bus System Message Bus.109server # [2479110.077095] server dbus-broker-launch[313]: Ready110server # [2479110.267183] server systemd[1]: Started Caddy.111server # [2479110.560126] server systemd-networkd[301]: eth1: Gained IPv6LL112server # [2479110.658272] server systemd-logind[329]: New seat seat0.113server # [2479110.658454] server systemd[1]: Started User Login Management.114server # [2479110.660884] server systemd[1]: Starting linger-users.service...115server # [2479110.730384] server systemd[1]: linger-users.service: Deactivated successfully.116server # [2479110.730601] server systemd[1]: Finished linger-users.service.117server # [2479111.573916] server authelia[373]: Configuration parsed and loaded successfully without errors.118server # [2479112.464896] server systemd[1]: Started Authelia authentication and authorization server.119server # [2479112.467096] server systemd[1]: Starting Punchcard time tracking (punchcard)...120server # [2479112.516687] server authelia[406]: time="2026-10-03T00:05:32Z" level=info msg="Authelia v4.39.27-nixpkgs is starting"121server # [2479112.516687] server authelia[406]: time="2026-10-03T00:05:32Z" level=info msg="Log severity set to info"122server # [2479112.547928] server authelia[406]: time="2026-10-03T00:05:32Z" level=info msg="Storage schema is being checked for updates"123server # [2479112.548807] server authelia[406]: time="2026-10-03T00:05:32Z" level=info msg="Storage schema migration from 0 to 29 is being attempted"124server # [2479112.640061] server authelia[406]: time="2026-10-03T00:05:32Z" level=info msg="Storage schema migration from 0 to 29 is complete"125server # [2479112.647497] server systemd-resolved[223]: Switching to fallback DNS server 1.1.1.1#one.one.one.one.126server # [2479112.649947] server authelia[406]: time="2026-10-03T00:05:32Z" level=warning msg="Could not determine the clock offset due to an error" error="error occurred during dial: dial udp: lookup time.cloudflare.com: no such host"127server # [2479112.661682] server systemd[1]: Started Punchcard time tracking (punchcard).128server # [2479112.662160] server systemd[1]: Reached target Multi-User System.129server # [2479112.662749] server systemd[1]: Startup finished in 4.521s.130server # [2479112.670659] server punchcard-punchcard-start[410]: 2026/10/03 00:05:32 Warning: .env file not found, using environment variables: open .env: no such file or directory131server # [2479112.678869] server punchcard-punchcard-start[410]: 2026/10/03 00:05:32 OIDC authentication enabled with issuer: https://auth.test.clan132server # [2479112.678869] server punchcard-punchcard-start[410]: 2026/10/03 00:05:32 Redirect URL: https://punchcard.test.clan/callback133server # [2479112.679408] server punchcard-punchcard-start[410]: 2026/10/03 00:05:32 Server starting on :8099134server: (finished: waiting for unit authelia-authelia.service, in 5.66 seconds)135??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.136 File "/nix/store/drwj5qfqx9axxgf0jvxlavglj43fr2kh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39137server: waiting for success: curl -sf http://127.0.0.1:9091/api/health138??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.139 File "/nix/store/drwj5qfqx9axxgf0jvxlavglj43fr2kh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39140server: (finished: waiting for success: curl -sf http://127.0.0.1:9091/api/health, in 0.02 seconds)141server: must succeed: test -f /run/authelia-authelia/users.json142server: (finished: must succeed: test -f /run/authelia-authelia/users.json, in 0.01 seconds)143server: must succeed: cat /run/authelia-authelia/users.json144server: (finished: must succeed: cat /run/authelia-authelia/users.json, in 0.01 seconds)145server: must succeed: test -f /run/authelia-authelia/oidc.json146server: (finished: must succeed: test -f /run/authelia-authelia/oidc.json, in 0.01 seconds)147server: must succeed: cat /run/authelia-authelia/oidc.json148server: (finished: must succeed: cat /run/authelia-authelia/oidc.json, in 0.01 seconds)149server: waiting for unit caddy.service150server: (finished: waiting for unit caddy.service, in 0.02 seconds)151server: waiting for success: curl -sf https://auth.test.clan/api/health152server: (finished: waiting for success: curl -sf https://auth.test.clan/api/health, in 0.10 seconds)153server: waiting for success: curl -sf https://auth.test.clan/.well-known/openid-configuration154server: (finished: waiting for success: curl -sf https://auth.test.clan/.well-known/openid-configuration, in 0.10 seconds)155??? Warning (UserWarning): wait_for_unit(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.156 File "/nix/store/drwj5qfqx9axxgf0jvxlavglj43fr2kh-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39157server: waiting for unit punchcard-punchcard.service158server: (finished: waiting for unit punchcard-punchcard.service, in 0.02 seconds)159server: waiting for success: curl -sf https://punchcard.test.clan/login160server # [2479112.982372] server authelia[406]: time="2026-10-03T00:05:32Z" level=info msg="Startup complete"161server # [2479112.982547] server authelia[406]: time="2026-10-03T00:05:32Z" level=info msg="Listening for non-TLS connections on '127.0.0.1:9091' path '/'" server=main service=server162server: (finished: waiting for success: curl -sf https://punchcard.test.clan/login, in 0.10 seconds)163server: must succeed: cat /run/secrets/per-machine/server/authelia-user-bob/password164server: (finished: must succeed: cat /run/secrets/per-machine/server/authelia-user-bob/password, in 0.01 seconds)165server: must succeed: curl -s -o /dev/null -w '%{redirect_url}' -c /tmp/pc-cookies https://punchcard.test.clan/login/start166server: (finished: must succeed: curl -s -o /dev/null -w '%{redirect_url}' -c /tmp/pc-cookies https://punchcard.test.clan/login/start, in 0.21 seconds)167server: must succeed: curl -sf -X POST https://auth.test.clan/api/firstfactor -H 'Content-Type: application/json' -c /tmp/auth-cookies -d '{"username": "bob", "password": "compare-grumbling-cartload-factual-sizing-countless-jumbo", "keepMeLoggedIn": false}'168server: (finished: must succeed: curl -sf -X POST https://auth.test.clan/api/firstfactor -H 'Content-Type: application/json' -c /tmp/auth-cookies -d '{"username": "bob", "password": "compare-grumbling-cartload-factual-sizing-countless-jumbo", "keepMeLoggedIn": false}', in 1.18 seconds)169server: must succeed: curl -s -o /dev/null -w '%{redirect_url}' -b /tmp/auth-cookies -c /tmp/auth-cookies 'https://auth.test.clan/api/oidc/authorization?client_id=punchcard-punchcard&code_challenge=6VIYGzu7MXptKeGQ5ChXzAl3f-U7Mx7_JNvOGk-OzVI&code_challenge_method=S256&redirect_uri=https%3A%2F%2Fpunchcard.test.clan%2Fcallback&response_type=code&scope=openid+profile+email&state=TqbqOXj3XxUsApxgeYDoiuvXVTTOWh4UrHffbu0cD6Q%3D'170server: (finished: must succeed: curl -s -o /dev/null -w '%{redirect_url}' -b /tmp/auth-cookies -c /tmp/auth-cookies 'https://auth.test.clan/api/oidc/authorization?client_id=punchcard-punchcard&code_challenge=6VIYGzu7MXptKeGQ5ChXzAl3f-U7Mx7_JNvOGk-OzVI&code_challenge_method=S256&redirect_uri=https%3A%2F%2Fpunchcard.test.clan%2Fcallback&response_type=code&scope=openid+profile+email&state=TqbqOXj3XxUsApxgeYDoiuvXVTTOWh4UrHffbu0cD6Q%3D', in 0.13 seconds)171server: must succeed: curl -s -o /dev/null -w '%{http_code}' -c /tmp/pc-cookies -b /tmp/pc-cookies 'https://punchcard.test.clan/callback?code=authelia_ac_sd3_9aPCgaypNFKMcXPR9cFu0axDsTDJHRZsdPSRgQo.cMF-HjKYQtPiyG32Jn7FLLbIwwUhFKdp8fPMC8_QzOg&iss=https%3A%2F%2Fauth.test.clan&scope=openid+profile+email&state=TqbqOXj3XxUsApxgeYDoiuvXVTTOWh4UrHffbu0cD6Q%3D'172server: (finished: must succeed: curl -s -o /dev/null -w '%{http_code}' -c /tmp/pc-cookies -b /tmp/pc-cookies 'https://punchcard.test.clan/callback?code=authelia_ac_sd3_9aPCgaypNFKMcXPR9cFu0axDsTDJHRZsdPSRgQo.cMF-HjKYQtPiyG32Jn7FLLbIwwUhFKdp8fPMC8_QzOg&iss=https%3A%2F%2Fauth.test.clan&scope=openid+profile+email&state=TqbqOXj3XxUsApxgeYDoiuvXVTTOWh4UrHffbu0cD6Q%3D', in 0.33 seconds)173server: must succeed: curl -s -L -o /dev/null -w '%{http_code}' -b /tmp/pc-cookies -c /tmp/pc-cookies https://punchcard.test.clan/174server: (finished: must succeed: curl -s -L -o /dev/null -w '%{http_code}' -b /tmp/pc-cookies -c /tmp/pc-cookies https://punchcard.test.clan/, in 0.06 seconds)175(finished: run the VM test script, in 7.97 seconds)176server # [2479115.039621] server authelia[406]: time="2026-10-03T00:05:35Z" level=error msg="Access Request failed with error: Client authentication failed (e.g., unknown client, no client authentication included, or unsupported authentication method). The required credentials were not found, used an unknown method, could not be parsed, were otherwise malformed, or were otherwise incorrect. The request was determined to be using 'token_endpoint_auth_method' method 'client_secret_basic', however the registered client with id 'punchcard-punchcard' is configured to only support 'token_endpoint_auth_method' method 'client_secret_post'. Either the Authorization Server client registration will need to have the 'token_endpoint_auth_method' updated to 'client_secret_basic' or the Relying Party will need to be configured to use 'client_secret_post'." method=POST path=/api/oidc/token remote_ip="::1"177server # [2479115.268276] server punchcard-punchcard-start[410]: 2026/10/03 00:05:35 User () logged in successfully178test script finished in 7.99s179cleanup180kill NspawnMachine (pid 51)181(finished: cleanup, in 0.16 seconds)182Container server terminated by signal KILL.