container-test-run-authelia
checks.aarch64-linux.authelia
· build #185
· raw
1Machine state will be reset. To keep it, pass --keep-machine-state2start all VLans3(finished: start all VLans, in 0.00 seconds)45Test will time out and terminate in 3600.0 seconds6run the VM test script7additionally exposed symbols:8 server,9 vlan1,10 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_ssh11start all VMs12server: systemd-nspawn running (pid 51)13server: Waiting for journal at /build/vm-state-server/var/log/journal...14(finished: start all VMs, in 0.00 seconds)15??? Warning (UserWarning): wait_for_unit(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.16 File "/nix/store/z312acj8n2ggn1w3agk97mbvdsm371iw-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 3917server: waiting for unit authelia-authelia.service18nixos-nspawn(server): TAP vde-tap1 not found; container will be isolated from VDE19nixos-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.20Note: 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.21░ Spawning container server on /build/vm-state-server.22server # No journal files were found.23server # No journal boot entry found for the specified boot (+0).24server # [1600533.238395] server systemd-journald[189]: Journal started25server # [1600533.238455] server systemd-journald[189]: Runtime Journal (/run/log/journal/d82b56ff3d064c3186548ad89030688b) is 8M, max 2.5G, 2.4G free.26server # [1600533.240620] server systemd[1]: Finished Apply Kernel Variables.27server # [1600533.251439] server systemd[1]: Finished Create Static Device Nodes in /dev gracefully.28server # [1600533.264099] server systemd[1]: Starting Flush Journal to Persistent Storage...29server # [1600533.264954] server systemd[1]: Starting Network Name Resolution...30server # [1600533.265593] server systemd[1]: Starting Create Static Device Nodes in /dev...31server # [1600533.275360] server systemd-journald[189]: Time spent on flushing to /var/log/journal/d82b56ff3d064c3186548ad89030688b is 1.449ms for 7 entries.32server # [1600533.275360] server systemd-journald[189]: System Journal (/var/log/journal/d82b56ff3d064c3186548ad89030688b) is 8M, max 4G, 3.9G free.33server # [1600533.282455] server systemd[1]: Finished Create Static Device Nodes in /dev.34server # [1600533.283052] server systemd[1]: Reached target Preparation for Local File Systems.35server # [1600533.283182] server systemd[1]: Reached target Local File Systems.36server # [1600533.284041] server systemd[1]: Listening on Boot Loader Control Service Socket.37server # [1600533.284092] server systemd[1]: Update Boot Loader Random Seed skipped, unmet condition check ConditionVirtualization=!container38server # [1600533.284921] server systemd[1]: Starting Save Transient machine-id to Disk...39server # [1600533.284957] server systemd[1]: Rule-based Manager for Device Events and Files skipped, unmet condition check ConditionPathIsReadWrite=/sys40server # [1600533.295981] server systemd[1]: Finished Flush Journal to Persistent Storage.41server # [1600533.297431] server systemd[1]: Starting Create System Files and Directories...42server # [1600533.314296] server systemd-tmpfiles[240]: Cannot set file attributes for '/var/empty', value=0x00000010, mask=0x00000010, ignoring: Operation not permitted43server # [1600533.314483] server systemd-tmpfiles[240]: fchmod() of /var/log/journal failed: Operation not permitted44server # [1600533.314618] server systemd-tmpfiles[240]: fchmod() of /var/log/journal/d82b56ff3d064c3186548ad89030688b failed: Operation not permitted45server # [1600533.314821] server systemd-tmpfiles[240]: fchmod() of /run/log/journal failed: Operation not permitted46server # [1600533.316235] server systemd[1]: Finished Create System Files and Directories.47server # [1600533.317296] server systemd[1]: Starting Rebuild Journal Catalog...48server # [1600533.318181] server systemd[1]: Starting Record System Boot/Shutdown in UTMP...49server # [1600533.330202] server systemd[1]: Finished Record System Boot/Shutdown in UTMP.50server # [1600533.332687] server systemd[1]: Finished Save Transient machine-id to Disk.51server # [1600533.341840] server systemd[1]: Finished Rebuild Journal Catalog.52server # [1600533.342811] server systemd[1]: Starting Update is Completed...53server # [1600533.354507] server systemd[1]: Finished Update is Completed.54server # [1600533.405084] server systemd[1]: Finished Firewall.55server # [1600533.405470] server systemd[1]: Reached target Preparation for Network.56server # [1600533.405714] server systemd[1]: Listening on Network Management Resolve Hook Socket.57server # [1600533.406876] server systemd[1]: Starting Network Management...58server # [1600534.086037] server systemd-networkd[303]: Failed to increase receive buffer size for general netlink socket, ignoring: Operation not permitted59server # [1600534.086127] server systemd-networkd[303]: Failed to increase receive buffer size for nftables netlink socket, ignoring: Operation not permitted60server # [1600534.095708] server systemd-networkd[303]: /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 # [1600534.095872] server systemd-networkd[303]: /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 # [1600534.096060] server systemd-networkd[303]: lo: Link UP63server # [1600534.096064] server systemd-networkd[303]: lo: Gained carrier64server # [1600534.096244] server systemd-networkd[303]: eth1: Configuring with /etc/systemd/network/40-eth1.network.65server # [1600534.096647] server systemd[1]: Started Network Management.66server # [1600534.096791] server systemd-networkd[303]: eth1: Link UP67server # [1600534.097149] server systemd-networkd[303]: eth1: Gained carrier68server # [1600534.097677] server systemd[1]: Starting Enable Persistent Storage in systemd-networkd...69server # [1600534.134243] server systemd[1]: Finished Enable Persistent Storage in systemd-networkd.70server # [1600534.233760] server systemd[1]: etc-machine\x2did.mount: Deactivated successfully.71server # [1600534.393658] server systemd-resolved[218]: Positive Trust Anchors:72server # [1600534.393671] server systemd-resolved[218]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d73server # [1600534.393674] server systemd-resolved[218]: . IN DS 38696 8 2 683d2d0acb8c9b712a1948b27f741219298d0a450d612c483af444a4c0fb2b1674server # [1600534.393707] server systemd-resolved[218]: 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 test75server # [1600534.415950] server systemd-resolved[218]: Using system hostname 'server'.76server # [1600534.417390] server systemd[1]: Started Network Name Resolution.77server # [1600534.417520] server systemd[1]: Reached target Network.78server # [1600534.417630] server systemd[1]: Reached target Network is Online.79server # [1600534.417715] server systemd[1]: Reached target System Initialization.80server # [1600534.417807] server systemd[1]: Discard unused filesystem blocks once a week skipped, unmet condition check ConditionVirtualization=!container81server # [1600534.417857] server systemd[1]: Started Daily Cleanup of Temporary Directories.82server # [1600534.417896] server systemd[1]: Reached target Timer Units.83server # [1600534.418132] server systemd[1]: Listening on D-Bus System Message Bus Socket.84server # [1600534.418358] server systemd[1]: Listening on Nix Daemon Socket.85server # [1600534.418577] server systemd[1]: Listening on Virtual Machine and Container Registration Service Socket.86server # [1600534.418624] server systemd[1]: Reached target Socket Units.87server # [1600534.418701] server systemd[1]: Reached target Basic System.88server # [1600534.421338] server systemd[1]: Starting Authelia authentication and authorization server...89server # [1600534.422807] server systemd[1]: Starting Caddy...90server # [1600534.424100] server systemd[1]: Starting Import lastlog data into lastlog2 database...91server # [1600534.425521] server systemd[1]: Starting Name Service Cache Daemon (nsncd)...92server # [1600534.427646] server systemd[1]: Starting D-Bus System Message Bus...93server # [1600534.542091] server systemd[1]: Finished Import lastlog data into lastlog2 database.94server # [1600534.666297] server nsncd[311]: Sep 22 20:02:34.652 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 10s }, path: "/var/run/nscd/socket"95server # [1600534.666381] server systemd[1]: Started Name Service Cache Daemon (nsncd).96server # [1600534.666455] server systemd[1]: Reached target Host and Network Name Lookups.97server # [1600534.666529] server systemd[1]: Reached target User and Group Name Lookups.98server # [1600534.677701] server systemd[1]: Starting User Login Management...99server # [1600534.678998] server systemd[1]: Starting Permit User Sessions...100server # [1600534.690188] server systemd[1]: Finished Permit User Sessions.101server # [1600534.691800] server systemd[1]: Started Console Getty.102server # [1600534.691877] server systemd[1]: Getty on tty1 skipped, unmet condition check ConditionPathExists=/dev/tty0103server # [1600534.691915] server systemd[1]: Reached target Login Prompts.104server # [1600534.854860] server dbus-broker-launch[312]: Looking up NSS user entry for 'systemd-timesync'...105server # [1600534.856624] server dbus-broker-launch[312]: NSS returned no entry for 'systemd-timesync'106server # [1600534.856624] server dbus-broker-launch[312]: Invalid user-name in /nix/store/0lhf3pxn1mzryf17kllghy3ybnjfh4x9-system-path/share/dbus-1/system.d/org.freedesktop.timesync1.conf +16: user="systemd-timesync"107server # [1600534.857333] server systemd[1]: Started D-Bus System Message Bus.108server # [1600534.864880] server dbus-broker-launch[312]: Ready109server # [1600535.066724] server systemd[1]: Started Caddy.110server # [1600535.462453] server systemd-logind[331]: New seat seat0.111server # [1600535.462668] server systemd[1]: Started User Login Management.112server # [1600535.464855] server systemd[1]: Starting linger-users.service...113server # [1600535.514556] server systemd[1]: linger-users.service: Deactivated successfully.114server # [1600535.514876] server systemd[1]: Finished linger-users.service.115server # [1600535.712273] server systemd-networkd[303]: eth1: Gained IPv6LL116server # [1600536.498291] server authelia[377]: Configuration parsed and loaded successfully without errors.117server: (finished: waiting for unit authelia-authelia.service, in 5.66 seconds)118??? Warning (UserWarning): wait_until_succeeds(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.119 File "/nix/store/z312acj8n2ggn1w3agk97mbvdsm371iw-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39120server: waiting for success: curl -sf http://127.0.0.1:9091/api/health121??? Warning (UserWarning): execute(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.122 File "/nix/store/z312acj8n2ggn1w3agk97mbvdsm371iw-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39123server # [1600537.449547] server systemd[1]: Started Authelia authentication and authorization server.124server # [1600537.451634] server systemd[1]: Starting Punchcard time tracking (punchcard)...125server # [1600537.499298] server authelia[408]: time="2026-09-22T20:02:37Z" level=info msg="Authelia v4.39.22-nixpkgs is starting"126server # [1600537.499864] server authelia[408]: time="2026-09-22T20:02:37Z" level=info msg="Log severity set to info"127server # [1600537.517548] server authelia[408]: time="2026-09-22T20:02:37Z" level=info msg="Storage schema is being checked for updates"128server # [1600537.518641] server authelia[408]: time="2026-09-22T20:02:37Z" level=info msg="Storage schema migration from 0 to 28 is being attempted"129server # [1600537.555351] server authelia[408]: time="2026-09-22T20:02:37Z" level=info msg="Storage schema migration from 0 to 28 is complete"130server # [1600537.613522] server systemd-resolved[218]: Switching to fallback DNS server 1.1.1.1#one.one.one.one.131server # [1600537.615967] server authelia[408]: time="2026-09-22T20:02:37Z" 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"132server # [1600537.620225] server systemd[1]: Started Punchcard time tracking (punchcard).133server # [1600537.620708] server systemd[1]: Reached target Multi-User System.134server # [1600537.621276] server systemd[1]: Startup finished in 4.817s.135server # [1600537.628582] server punchcard-punchcard-start[412]: 2026/09/22 20:02:37 Warning: .env file not found, using environment variables: open .env: no such file or directory136server # [1600537.637086] server punchcard-punchcard-start[412]: 2026/09/22 20:02:37 OIDC authentication enabled with issuer: https://auth.test.clan137server # [1600537.637086] server punchcard-punchcard-start[412]: 2026/09/22 20:02:37 Redirect URL: https://punchcard.test.clan/callback138server # [1600537.637589] server punchcard-punchcard-start[412]: 2026/09/22 20:02:37 Server starting on :8099139server # [1600537.933420] server authelia[408]: time="2026-09-22T20:02:37Z" level=info msg="Startup complete"140server # [1600537.933561] server authelia[408]: time="2026-09-22T20:02:37Z" level=info msg="Listening for non-TLS connections on '127.0.0.1:9091' path '/'" server=main service=server141server: (finished: waiting for success: curl -sf http://127.0.0.1:9091/api/health, in 1.03 seconds)142server: must succeed: test -f /run/authelia-authelia/users.json143server: (finished: must succeed: test -f /run/authelia-authelia/users.json, in 0.01 seconds)144server: must succeed: cat /run/authelia-authelia/users.json145server: (finished: must succeed: cat /run/authelia-authelia/users.json, in 0.01 seconds)146server: must succeed: test -f /run/authelia-authelia/oidc.json147server: (finished: must succeed: test -f /run/authelia-authelia/oidc.json, in 0.01 seconds)148server: must succeed: cat /run/authelia-authelia/oidc.json149server: (finished: must succeed: cat /run/authelia-authelia/oidc.json, in 0.01 seconds)150server: waiting for unit caddy.service151server: (finished: waiting for unit caddy.service, in 0.01 seconds)152server: waiting for success: curl -sf https://auth.test.clan/api/health153server: (finished: waiting for success: curl -sf https://auth.test.clan/api/health, in 0.07 seconds)154server: waiting for success: curl -sf https://auth.test.clan/.well-known/openid-configuration155server: (finished: waiting for success: curl -sf https://auth.test.clan/.well-known/openid-configuration, in 0.10 seconds)156??? Warning (UserWarning): wait_for_unit(): passing a bare int/float as a duration is deprecated. Use datetime.timedelta instead.157 File "/nix/store/z312acj8n2ggn1w3agk97mbvdsm371iw-nixos-test-driver-1.1/lib/python3.14/site-packages/test_driver/duration.py", line 39158server: waiting for unit punchcard-punchcard.service159server: (finished: waiting for unit punchcard-punchcard.service, in 0.02 seconds)160server: waiting for success: curl -sf https://punchcard.test.clan/login161server: (finished: waiting for success: curl -sf https://punchcard.test.clan/login, in 0.05 seconds)162server: must succeed: cat /run/secrets/per-machine/server/authelia-user-bob/password163server: (finished: must succeed: cat /run/secrets/per-machine/server/authelia-user-bob/password, in 0.01 seconds)164server: must succeed: curl -s -o /dev/null -w '%{redirect_url}' -c /tmp/pc-cookies https://punchcard.test.clan/login/start165server: (finished: must succeed: curl -s -o /dev/null -w '%{redirect_url}' -c /tmp/pc-cookies https://punchcard.test.clan/login/start, in 0.19 seconds)166server: 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": "avert-paltry-tucking-strudel-bunion-splashy-ripcord", "keepMeLoggedIn": false}'167server: (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": "avert-paltry-tucking-strudel-bunion-splashy-ripcord", "keepMeLoggedIn": false}', in 1.15 seconds)168server: 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=C0Bjozh8HJQERIu59GDwyXI17Q1WZ1Nn1b68ae6wB4k&code_challenge_method=S256&redirect_uri=https%3A%2F%2Fpunchcard.test.clan%2Fcallback&response_type=code&scope=openid+profile+email&state=lOxC-i9Mksmza-0T2HpaoyeUe_x69biqqap9v4BSb5U%3D'169server: (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=C0Bjozh8HJQERIu59GDwyXI17Q1WZ1Nn1b68ae6wB4k&code_challenge_method=S256&redirect_uri=https%3A%2F%2Fpunchcard.test.clan%2Fcallback&response_type=code&scope=openid+profile+email&state=lOxC-i9Mksmza-0T2HpaoyeUe_x69biqqap9v4BSb5U%3D', in 0.09 seconds)170server: 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_sTP1e_ordb8YPdJqak8kAEFagVQ4hPOPmHauOyFSmLQ.H_9c8eh6Li_nYPoGtrrEYv-bnc3o_A8EfJ3Rrk_3EHw&iss=https%3A%2F%2Fauth.test.clan&scope=openid+profile+email&state=lOxC-i9Mksmza-0T2HpaoyeUe_x69biqqap9v4BSb5U%3D'171server: (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_sTP1e_ordb8YPdJqak8kAEFagVQ4hPOPmHauOyFSmLQ.H_9c8eh6Li_nYPoGtrrEYv-bnc3o_A8EfJ3Rrk_3EHw&iss=https%3A%2F%2Fauth.test.clan&scope=openid+profile+email&state=lOxC-i9Mksmza-0T2HpaoyeUe_x69biqqap9v4BSb5U%3D', in 0.32 seconds)172server: must succeed: curl -s -L -o /dev/null -w '%{http_code}' -b /tmp/pc-cookies -c /tmp/pc-cookies https://punchcard.test.clan/173server # [1600540.631502] server authelia[408]: time="2026-09-22T20:02:40Z" 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"174server # [1600540.851902] server punchcard-punchcard-start[412]: 2026/09/22 20:02:40 User () logged in successfully175server: (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)176(finished: run the VM test script, in 8.84 seconds)177test script finished in 8.88s178cleanup179kill NspawnMachine (pid 51)180(finished: cleanup, in 0.21 seconds)181Container server terminated by signal KILL.