container-test-run-authelia
checks.aarch64-linux.authelia
· build #230
· raw
1build01: building nbn13lga70x2snc2x2cr7pqqg15d3xsn-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/x4i03lhka9aiwxswmbhjfzzbl77nlxmj-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 # [2724624.106317] server systemd-journald[186]: Journal started26server # [2724624.106379] server systemd-journald[186]: Runtime Journal (/run/log/journal/d93d4ec893e94ae4bf30b1cd10b85b09) is 8M, max 2.5G, 2.4G free.27server # [2724624.116229] server systemd[1]: Finished Apply Kernel Variables.28server # [2724624.129067] server systemd[1]: Finished Create Static Device Nodes in /dev gracefully.29server # [2724624.144271] server systemd[1]: Starting Flush Journal to Persistent Storage...30server # [2724624.145177] server systemd[1]: Starting Network Name Resolution...31server # [2724624.145855] server systemd[1]: Starting Create Static Device Nodes in /dev...32server # [2724624.155708] server systemd-journald[186]: Time spent on flushing to /var/log/journal/d93d4ec893e94ae4bf30b1cd10b85b09 is 1.641ms for 7 entries.33server # [2724624.155708] server systemd-journald[186]: System Journal (/var/log/journal/d93d4ec893e94ae4bf30b1cd10b85b09) is 8M, max 4G, 3.9G free.34server # [2724624.162651] server systemd[1]: Finished Create Static Device Nodes in /dev.35server # [2724624.163212] server systemd[1]: Reached target Preparation for Local File Systems.36server # [2724624.163328] server systemd[1]: Reached target Local File Systems.37server # [2724624.164199] server systemd[1]: Listening on Boot Loader Control Service Socket.38server # [2724624.164242] server systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container39server # [2724624.165215] server systemd[1]: Starting Save Transient machine-id to Disk...40server # [2724624.165249] server systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys41server # [2724624.200126] server systemd[1]: Finished Flush Journal to Persistent Storage.42server # [2724624.201595] server systemd[1]: Starting Create System Files and Directories...43server # [2724624.219415] server systemd-tmpfiles[256]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted44server # [2724624.219631] server systemd-tmpfiles[256]: fchmod() of /var/log/journal failed: Operation not permitted45server # [2724624.219805] server systemd-tmpfiles[256]: fchmod() of /var/log/journal/d93d4ec893e94ae4bf30b1cd10b85b09 failed: Operation not permitted46server # [2724624.220093] server systemd-tmpfiles[256]: fchmod() of /run/log/journal failed: Operation not permitted47server # [2724624.221535] server systemd[1]: Finished Create System Files and Directories.48server # [2724624.222636] server systemd[1]: Starting Rebuild Journal Catalog...49server # [2724624.223454] server systemd[1]: Starting Record System Boot/Shutdown in UTMP...50server # [2724624.241054] server systemd[1]: Finished Record System Boot/Shutdown in UTMP.51server # [2724624.254062] server systemd[1]: Finished Rebuild Journal Catalog.52server # [2724624.255221] server systemd[1]: Starting Update is Completed...53server # [2724624.268384] server systemd[1]: Finished Update is Completed.54server # [2724624.280573] server systemd[1]: Finished Firewall.55server # [2724624.280753] server systemd[1]: Reached target Preparation for Network.56server # [2724624.281014] server systemd[1]: Listening on Network Management Resolve Hook Socket.57server # [2724624.282244] server systemd[1]: Starting Network Management...58server # [2724624.894521] server systemd-networkd[299]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted59server # [2724624.894610] server systemd-networkd[299]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted60server # [2724624.903534] server systemd-networkd[299]: /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.61server # [2724624.903700] server systemd-networkd[299]: /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.62server # [2724624.920467] server systemd-networkd[299]: lo: Link UP63server # [2724624.920472] server systemd-networkd[299]: lo: Gained carrier64server # [2724624.920660] server systemd-networkd[299]: eth1: Configuring with /etc/systemd/network/40-eth1.network.65server # [2724624.921098] server systemd[1]: Started Network Management.66server # [2724624.921135] server systemd-networkd[299]: eth1: Link UP67server # [2724624.921398] server systemd-networkd[299]: eth1: Gained carrier68server # [2724624.922966] server systemd[1]: Starting Enable Persistent Storage in systemd-networkd...69server # [2724624.962328] server systemd[1]: Finished Enable Persistent Storage in systemd-networkd.70server # [2724625.191387] server systemd-resolved[223]: Positive Trust Anchors:71server # [2724625.191398] server systemd-resolved[223]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d72server # [2724625.191402] server systemd-resolved[223]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b1673server # [2724625.191436] 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 test74server # [2724625.212190] server systemd-resolved[223]: Using system hostname 'server'.75server # [2724625.213604] server systemd[1]: Started Network Name Resolution.76server # [2724625.213748] server systemd[1]: Reached target Network.77server # [2724625.213859] server systemd[1]: Reached target Network is Online.78server # [2724625.213949] server systemd[1]: Reached target System Initialization.79server # [2724625.214041] server systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container80server # [2724625.214098] server systemd[1]: Started Daily Cleanup of Temporary Directories.81server # [2724625.214138] server systemd[1]: Reached target Timer Units.82server # [2724625.214360] server systemd[1]: Listening on D-Bus System Message Bus Socket.83server # [2724625.214572] server systemd[1]: Listening on Nix Daemon Socket.84server # [2724625.214792] server systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.85server # [2724625.214839] server systemd[1]: Reached target Socket Units.86server # [2724625.214915] server systemd[1]: Reached target Basic System.87server # [2724625.217126] server systemd[1]: Starting Authelia authentication and authorization server...88server # [2724625.218566] server systemd[1]: Starting Caddy...89server # [2724625.219918] server systemd[1]: Starting Import lastlog data into lastlog2 database...90server # [2724625.221419] server systemd[1]: Starting Name Service Cache Daemon (nsncd)...91server # [2724625.223524] server systemd[1]: Starting D-Bus System Message Bus...92server # [2724625.375479] server systemd[1]: Finished Import lastlog data into lastlog2 database.93server # [2724625.422641] server systemd[1]: etc-machine\x2did.mount: Deactivated successfully.94server # [2724625.424316] server systemd[1]: Finished Save Transient machine-id to Disk.95server # [2724625.468845] server systemd[1]: Started Name Service Cache Daemon (nsncd).96server # [2724625.468967] server systemd[1]: Reached target Host and Network Name Lookups.97server # [2724625.469073] server systemd[1]: Reached target User and Group Name Lookups.98server # [2724625.469513] server nsncd[307]: Oct 05 20:17:25.455 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"99server # [2724625.471328] server systemd[1]: Starting User Login Management...100server # [2724625.472836] server systemd[1]: Starting Permit User Sessions...101server # [2724625.520328] server systemd[1]: Finished Permit User Sessions.102server # [2724625.522086] server systemd[1]: Started Console Getty.103server # [2724625.522163] server systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0104server # [2724625.522202] server systemd[1]: Reached target Login Prompts.105server # [2724625.587481] server dbus-broker-launch[308]: Looking up NSS user entry for 'systemd-timesync'...106server # [2724625.589067] server dbus-broker-launch[308]: NSS returned no entry for 'systemd-timesync'107server # [2724625.589067] server dbus-broker-launch[308]: Invalid user-name in /nix/store/vsdka124nlmyn27bs73mc4q6jq4qyzkn-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"108server # [2724625.589506] server systemd[1]: Started D-Bus System Message Bus.109server # [2724625.597053] server dbus-broker-launch[308]: Ready110server # [2724625.812652] server systemd[1]: Started Caddy.111server # [2724626.221279] server systemd-logind[328]: New seat seat0.112server # [2724626.221528] server systemd[1]: Started User Login Management.113server # [2724626.223479] server systemd[1]: Starting linger-users.service...114server # [2724626.271200] server systemd[1]: linger-users.service: Deactivated successfully.115server # [2724626.271530] server systemd[1]: Finished linger-users.service.116server # [2724626.340130] server systemd-networkd[299]: eth1: Gained IPv6LL117server # [2724627.115119] server authelia[372]: Configuration parsed and loaded successfully without errors.118server # [2724627.969036] server systemd[1]: Started Authelia authentication and authorization server.119server # [2724627.970749] server systemd[1]: Starting Punchcard time tracking (punchcard)...120server # [2724628.044761] server authelia[405]: time="2026-10-05T20:17:28Z" level=info msg="Authelia v4.39.27-nixpkgs is starting"121server # [2724628.045302] server authelia[405]: time="2026-10-05T20:17:28Z" level=info msg="Log severity set to info"122server # [2724628.076572] server authelia[405]: time="2026-10-05T20:17:28Z" level=info msg="Storage schema is being checked for updates"123server # [2724628.080126] server authelia[405]: time="2026-10-05T20:17:28Z" level=info msg="Storage schema migration from 0 to 29 is being attempted"124server # [2724628.147126] server authelia[405]: time="2026-10-05T20:17:28Z" level=info msg="Storage schema migration from 0 to 29 is complete"125server # [2724628.184253] server systemd[1]: Started Punchcard time tracking (punchcard).126server # [2724628.184746] server systemd[1]: Reached target Multi-User System.127server # [2724628.185150] server systemd[1]: Startup finished in 4.560s.128server # [2724628.192929] server punchcard-punchcard-start[409]: 2026/10/05 20:17:28 Warning: .env file not found, using environment variables: open .env: no such file or directory129server # [2724628.247082] server systemd-resolved[223]: Switching to fallback DNS server 1.1.1.1#one.one.one.one.130server # [2724628.249063] server punchcard-punchcard-start[409]: 2026/10/05 20:17:28 OIDC authentication enabled with issuer: https://auth.test.clan131server # [2724628.249063] server punchcard-punchcard-start[409]: 2026/10/05 20:17:28 Redirect URL: https://punchcard.test.clan/callback132server # [2724628.249381] server authelia[405]: time="2026-10-05T20:17:28Z" 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"133server # [2724628.249622] server punchcard-punchcard-start[409]: 2026/10/05 20:17:28 Server starting on :8099134server # [2724628.527872] server authelia[405]: time="2026-10-05T20:17:28Z" level=info msg="Startup complete"135server # [2724628.527872] server authelia[405]: time="2026-10-05T20:17:28Z" level=info msg="Listening for non-TLS connections on '127.0.0.1:9091' path '/'" server=main service=server136server: (finished: waiting for unit authelia-authelia.service, in 5.66 seconds)137??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.138 File "/nix/store/x4i03lhka9aiwxswmbhjfzzbl77nlxmj-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39139server: waiting for success: curl -sf http://127.0.0.1:9091/api/health140??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.141 File "/nix/store/x4i03lhka9aiwxswmbhjfzzbl77nlxmj-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39142server: (finished: waiting for success: curl -sf http://127.0.0.1:9091/api/health, in 0.02 seconds)143server: must succeed: test -f /run/authelia-authelia/users.json144server: (finished: must succeed: test -f /run/authelia-authelia/users.json, in 0.01 seconds)145server: must succeed: cat /run/authelia-authelia/users.json146server: (finished: must succeed: cat /run/authelia-authelia/users.json, in 0.01 seconds)147server: must succeed: test -f /run/authelia-authelia/oidc.json148server: (finished: must succeed: test -f /run/authelia-authelia/oidc.json, in 0.01 seconds)149server: must succeed: cat /run/authelia-authelia/oidc.json150server: (finished: must succeed: cat /run/authelia-authelia/oidc.json, in 0.01 seconds)151server: waiting for unit caddy.service152server: (finished: waiting for unit caddy.service, in 0.02 seconds)153server: waiting for success: curl -sf https://auth.test.clan/api/health154server: (finished: waiting for success: curl -sf https://auth.test.clan/api/health, in 0.10 seconds)155server: waiting for success: curl -sf https://auth.test.clan/.well-known/openid-configuration156server: (finished: waiting for success: curl -sf https://auth.test.clan/.well-known/openid-configuration, in 0.10 seconds)157??? Warning (UserWarning): wait_for_unit(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.158 File "/nix/store/x4i03lhka9aiwxswmbhjfzzbl77nlxmj-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39159server: waiting for unit punchcard-punchcard.service160server: (finished: waiting for unit punchcard-punchcard.service, in 0.02 seconds)161server: waiting for success: curl -sf https://punchcard.test.clan/login162server: (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.22 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": "arrive-cardigan-freight-party-sliding-mangle-liqueur", "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": "arrive-cardigan-freight-party-sliding-mangle-liqueur", "keepMeLoggedIn": false}', in 1.14 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=NFHtEQS0MBqryrkqJgngButB-rEHZT51ZVK-7-TCxNw&code_challenge_method=S256&redirect_uri=https%3A%2F%2Fpunchcard.test.clan%2Fcallback&response_type=code&scope=openid+profile+email&state=4RyWvbUYX7GdPZXXwHRsCGP02HKYOpy7wVelaRqJXUk%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=NFHtEQS0MBqryrkqJgngButB-rEHZT51ZVK-7-TCxNw&code_challenge_method=S256&redirect_uri=https%3A%2F%2Fpunchcard.test.clan%2Fcallback&response_type=code&scope=openid+profile+email&state=4RyWvbUYX7GdPZXXwHRsCGP02HKYOpy7wVelaRqJXUk%3D', in 0.11 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_R3Q0crcYSrV50Nksukp0BL-b9bvzvrp65YFBk8UDUIk.Drvfv6duB6l0gyMLqy0Z5cwkXTXv8s_JXYKjRFGjD1A&iss=https%3A%2F%2Fauth.test.clan&scope=openid+profile+email&state=4RyWvbUYX7GdPZXXwHRsCGP02HKYOpy7wVelaRqJXUk%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_R3Q0crcYSrV50Nksukp0BL-b9bvzvrp65YFBk8UDUIk.Drvfv6duB6l0gyMLqy0Z5cwkXTXv8s_JXYKjRFGjD1A&iss=https%3A%2F%2Fauth.test.clan&scope=openid+profile+email&state=4RyWvbUYX7GdPZXXwHRsCGP02HKYOpy7wVelaRqJXUk%3D', in 0.34 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 # [2724630.531503] server authelia[405]: time="2026-10-05T20:17:30Z" 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"175server # [2724630.767412] server punchcard-punchcard-start[409]: 2026/10/05 20:17:30 User () logged in successfully176server: (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.11 seconds)177(finished: run the VM test script, in 8.00 seconds)178test script finished in 8.05s179cleanup180kill NspawnMachine (pid 51)181(finished: cleanup, in 0.21 seconds)182Container server terminated by signal KILL.