�[2mserver # [   12.178221] lldap-start[1061]: 2024-09-14T01:21:19.109852368+00:00  INFO     ｉ [info]: starting 1 workers�[0m
�[2mserver # [   12.179244] lldap-start[1061]: 2024-09-14T01:21:19.110018031+00:00  INFO     ｉ [info]: Actix runtime found; starting in Actix runtime�[0m
�[2mserver # [   12.182314] lldap-start[1061]: 2024-09-14T01:21:19.135696714+00:00  INFO     ｉ [info]: DB Cleanup Cron started�[0m
�[2mserver # [   12.420841] authelia-auth.example.com-pre-start[1074]: Connection to 127.0.0.1 3890 port [tcp/ndsconnect] succeeded!�[0m
�[2mserver # [   12.422368] lldap-start[1061]: 2024-09-14T01:21:19.373061519+00:00  INFO     LDAP session [ 1.55ms | 100.00% ]�[0m
�[2mserver # [   14.534754] authelia-auth.example.com-pre-start[1084]: Configuration parsed and loaded with warnings:�[0m
�[2mserver # [   14.536217] authelia-auth.example.com-pre-start[1084]: 	 - configuration key 'identity_providers.oidc.issuer_private_key' is deprecated in 4.38.0 and has been replaced by 'identity_providers.oidc.jwks': you are not required to make any changes as this has been automatically mapped for you, but to stop this warning being logged you will need to adjust your configuration, and this configuration key and auto-mapping is likely to be removed in 5.0.0 : see https://www.authelia.com/c/oidc for more information�[0m
�[2mserver # [   14.540085] authelia-auth.example.com-pre-start[1084]: 	 - identity_providers: oidc: clients: client 'dummy_client': option 'client_secret' is plaintext but for clients not using the 'token_endpoint_auth_method' of 'client_secret_jwt' it should be a hashed value as plaintext values are deprecated with the exception of 'client_secret_jwt' and will be removed in the near future�[0m
�[2mserver # [   14.545599] systemd[1]: Started Authelia authentication and authorization server.�[0m
�[2mserver # [   14.548181] systemd[1]: Reached target Multi-User System.�[0m
�[2mserver # [   14.549050] systemd[1]: Startup finished in 2.140s (kernel) + 12.407s (userspace) = 14.548s.�[0m
�[2mserver # [   14.621921] authelia[1090]: time="2024-09-14T01:21:21Z" level=debug msg="Loaded Configuration Sources" files="[/nix/store/b03ck5gyv4k4wyqv39snrslahhy5pvgi-config.yml /var/lib/authelia-auth.example.com/oidc_clients.yaml]" filters="[]"�[0m
�[2mserver # [   14.623808] authelia[1090]: time="2024-09-14T01:21:21Z" level=debug msg="Logging Initialized" fields.level=debug file= format=json keep_stdout=false�[0m
�[2mserver # [   14.627554] authelia[1090]: time="2024-09-14T01:21:21Z" level=debug msg="Process user information" gid=999 uid=999 username=authelia�[0m
�[2mserver # [   14.630174] authelia[1090]: time="2024-09-14T01:21:21Z" level=warning msg="Configuration: configuration key 'identity_providers.oidc.issuer_private_key' is deprecated in 4.38.0 and has been replaced by 'identity_providers.oidc.jwks': you are not required to make any changes as this has been automatically mapped for you, but to stop this warning being logged you will need to adjust your configuration, and this configuration key and auto-mapping is likely to be removed in 5.0.0 : see https://www.authelia.com/c/oidc for more information"�[0m
�[2mserver # [   14.638306] authelia[1090]: time="2024-09-14T01:21:21Z" level=warning msg="Configuration: identity_providers: oidc: clients: client 'dummy_client': option 'client_secret' is plaintext but for clients not using the 'token_endpoint_auth_method' of 'client_secret_jwt' it should be a hashed value as plaintext values are deprecated with the exception of 'client_secret_jwt' and will be removed in the near future"�[0m
�[2mserver # [   14.641198] authelia[1090]: time="2024-09-14T01:21:21Z" level=info msg="Authelia v4.38.10-nixpkgs is starting"�[0m
�[2mserver # [   14.642112] authelia[1090]: time="2024-09-14T01:21:21Z" level=info msg="Log severity set to debug"�[0m
�[2mserver # [   14.664359] authelia[1090]: {"level":"debug","msg":"Registering client dummy_client with policy one_factor (one_factor)","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   14.679653] authelia[1090]: {"level":"info","msg":"Storage schema is being checked for updates","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   14.701182] authelia[1090]: {"level":"info","msg":"Storage schema migration from 0 to 15 is being attempted","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   14.744496] authelia[1090]: {"level":"debug","msg":"Storage schema migrated from version 0 to 1","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   14.762285] authelia[1090]: {"level":"debug","msg":"Storage schema migrated from version 1 to 2","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   14.773060] authelia[1090]: {"level":"debug","msg":"Storage schema migrated from version 2 to 3","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   14.840648] authelia[1090]: {"level":"debug","msg":"Storage schema migrated from version 3 to 4","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   14.843421] authelia[1090]: {"level":"debug","msg":"Storage schema migrated from version 4 to 5","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   14.925487] authelia[1090]: {"level":"debug","msg":"Storage schema migrated from version 5 to 6","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   14.957081] authelia[1090]: {"level":"debug","msg":"Storage schema migrated from version 6 to 7","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   14.965149] authelia[1090]: {"level":"debug","msg":"Storage schema migrated from version 7 to 8","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   14.966781] authelia[1090]: {"level":"debug","msg":"Storage schema migrated from version 8 to 9","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   14.968716] authelia[1090]: {"level":"debug","msg":"Storage schema migrated from version 9 to 10","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   14.970530] authelia[1090]: {"level":"debug","msg":"Storage schema migrated from version 10 to 11","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   14.987187] authelia[1090]: {"level":"debug","msg":"Storage schema migrated from version 11 to 12","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   14.994024] authelia[1090]: {"level":"debug","msg":"Storage schema migrated from version 12 to 13","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   14.995879] authelia[1090]: {"level":"debug","msg":"Storage schema migrated from version 13 to 14","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   15.001328] authelia[1090]: {"level":"debug","msg":"Storage schema migrated from version 14 to 15","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   15.002381] authelia[1090]: {"level":"info","msg":"Storage schema migration from 0 to 15 is complete","time":"2024-09-14T01:21:21Z"}�[0m
�[2mserver # [   15.122502] authelia[1090]: {"level":"debug","msg":"LDAP Supported OIDs. Control Types: none. Extensions: 1.3.6.1.4.1.4203.1.11.1","time":"2024-09-14T01:21:22Z"}�[0m
�[2mserver # [   15.123972] lldap-start[1061]: 2024-09-14T01:21:21.968102229+00:00  INFO     LDAP session [ 63.7ms | 1.82% / 100.00% ]�[0m
�[2mserver # [   15.124907] lldap-start[1061]: 2024-09-14T01:21:21.970062254+00:00  INFO     ┝━ LDAP request [ 62.5ms | 98.12% ]�[0m
�[2mserver # [   15.125818] lldap-start[1061]: 2024-09-14T01:21:22.033789069+00:00  INFO     ┕━ LDAP request [ 38.6µs | 0.06% ]�[0m
�[2mserver # [   15.133095] authelia[1090]: {"error":"error occurred during dial: dial udp: lookup time.cloudflare.com: no such host","level":"warning","msg":"Could not determine the clock offset due to an error","time":"2024-09-14T01:21:22Z"}�[0m
(finished: waiting for unit authelia-auth.example.com.service, in 7.35 seconds)
server: �[1m�[32mwaiting for TCP port 9117 on localhost�[0m
�[2mserver # [   15.164628] authelia[1090]: {"level":"info","msg":"Startup complete","time":"2024-09-14T01:21:22Z"}�[0m
�[2mserver # [   15.166528] authelia[1090]: {"level":"info","msg":"Listening for non-TLS connections on '127.0.0.1:9959' path '/metrics'","server":"metrics","service":"server","time":"2024-09-14T01:21:22Z"}�[0m
�[2mserver # [   15.168334] authelia[1090]: {"level":"info","msg":"Listening for non-TLS connections on '127.0.0.1:9091' path '/'","server":"main","service":"server","time":"2024-09-14T01:21:22Z"}�[0m
�[2mserver # Connection to localhost (::1) 9117 port [tcp/*] succeeded!�[0m
(finished: waiting for TCP port 9117 on localhost, in 0.04 seconds)
server: �[1m�[32mwaiting for TCP port 9091 on localhost�[0m
�[2mserver # Connection to localhost (127.0.0.1) 9091 port [tcp/xmltec-xmlmail] succeeded!�[0m
(finished: waiting for TCP port 9091 on localhost, in 0.03 seconds)
server: �[1m�[32mmust succeed: mkdir -p /tmp/shared/tmp6fdxmag9�[0m
(finished: must succeed: mkdir -p /tmp/shared/tmp6fdxmag9, in 0.02 seconds)
server: �[1m�[32mmust succeed: cp -r /etc/ssl/certs/ca-certificates.crt /tmp/shared/tmp6fdxmag9/ca-certificates.crt�[0m
(finished: must succeed: cp -r /etc/ssl/certs/ca-certificates.crt /tmp/shared/tmp6fdxmag9/ca-certificates.crt, in 0.02 seconds)
client: �[1m�[32mmust succeed: rm -r /etc/ssl/certs�[0m
client: �[1m�[32mwaiting for the VM to finish booting�[0m
client: Guest shell says: b'Spawning backdoor root shell...\n'
client: connected to guest root shell
client: (connecting took 0.00 seconds)
(finished: waiting for the VM to finish booting, in 0.00 seconds)
(finished: must succeed: rm -r /etc/ssl/certs, in 0.02 seconds)
client: �[1m�[32mmust succeed: mkdir -p /tmp/shared/tmp7hi8ah81�[0m
(finished: must succeed: mkdir -p /tmp/shared/tmp7hi8ah81, in 0.01 seconds)
client: �[1m�[32mmust succeed: mkdir -p /etc/ssl/certs�[0m
(finished: must succeed: mkdir -p /etc/ssl/certs, in 0.01 seconds)
client: �[1m�[32mmust succeed: cp -r /tmp/shared/tmp7hi8ah81/ca-certificates.crt /etc/ssl/certs/ca-certificates.crt�[0m
(finished: must succeed: cp -r /tmp/shared/tmp7hi8ah81/ca-certificates.crt /etc/ssl/certs/ca-certificates.crt, in 0.02 seconds)
�[1m�[32msubtest: unauthenticated access is not granted�[0m
curl --show-error --location --cookie-jar cookie.txt --cookie cookie.txt --connect-to jackett.example.com:443:server:443 --connect-to jackett.example.com:80:server:80 --connect-to auth.example.com:443:server:443 --silent --output /dev/null --write-out '{"code":%{response_code},"auth_host":"%{urle.host}","auth_query":"%{urle.query}","all":%{json}}' https://jackett.example.com
�[2mserver # [   15.437989] authelia[1090]: {"level":"debug","msg":"Check authorization of subject username= groups= ip=2001:db8:1::1 and object https://jackett.example.com/ (method GET).","time":"2024-09-14T01:21:22Z"}�[0m
�[2mserver # [   15.439821] authelia[1090]: {"level":"info","method":"GET","msg":"Access to https://jackett.example.com/ (method GET) is not authorized to user \u003canonymous\u003e, responding with status code 401","path":"/api/verify","remote_ip":"2001:db8:1::1","time":"2024-09-14T01:21:22Z"}�[0m
(finished: subtest: unauthenticated access is not granted, in 0.13 seconds)
�[1m�[32msubtest: extraScript�[0m
�[1m�[32msubtest: health�[0m
curl --show-error --location --cookie-jar cookie.txt --cookie cookie.txt --connect-to jackett.example.com:443:server:443 --connect-to jackett.example.com:80:server:80 --connect-to auth.example.com:443:server:443 --silent --output /dev/null --write-out '{"code":%{response_code}}' jackett.example.com/health
�[2mserver # [   15.536418] authelia[1090]: {"level":"debug","msg":"Check authorization of subject username= groups= ip=2001:db8:1::1 and object https://jackett.example.com/health (method GET).","time":"2024-09-14T01:21:22Z"}�[0m
�[2mserver # [   15.538575] authelia[1090]: {"level":"info","method":"GET","msg":"Access to https://jackett.example.com/health (method GET) is not authorized to user \u003canonymous\u003e, responding with status code 401","path":"/api/verify","remote_ip":"2001:db8:1::1","time":"2024-09-14T01:21:22Z"}�[0m
response = {'code': 200}
(finished: subtest: health, in 0.10 seconds)
�[1m�[32msubtest: login�[0m
curl --show-error --location --cookie-jar cookie.txt --cookie cookie.txt --connect-to jackett.example.com:443:server:443 --connect-to jackett.example.com:80:server:80 --connect-to auth.example.com:443:server:443 --silent --output /dev/null --write-out '{"code":%{response_code}}' jackett.example.com/UI/Login
�[2mserver # [   15.630645] authelia[1090]: {"level":"debug","msg":"Check authorization of subject username= groups= ip=2001:db8:1::1 and object https://jackett.example.com/UI/Login (method GET).","time":"2024-09-14T01:21:22Z"}�[0m
�[2mserver # [   15.633539] authelia[1090]: {"level":"info","method":"GET","msg":"Access to https://jackett.example.com/UI/Login (method GET) is not authorized to user \u003canonymous\u003e, responding with status code 401","path":"/api/verify","remote_ip":"2001:db8:1::1","time":"2024-09-14T01:21:22Z"}�[0m
(finished: subtest: login, in 0.09 seconds)
�[1m�[32msubtest: apikey�[0m
server: �[1m�[32mmust succeed: cat /var/lib/jackett/ServerConfig.json�[0m
(finished: must succeed: cat /var/lib/jackett/ServerConfig.json, in 0.01 seconds)
(finished: subtest: apikey, in 0.02 seconds)
(finished: subtest: extraScript, in 0.21 seconds)
(finished: run the VM test script, in 16.36 seconds)
test script finished in 16.42s
�[1m�[32mcleanup�[0m
kill machine (pid 8)
qemu-kvm: terminating on signal 15 from pid 5 (/nix/store/h3i0acpmr8mrjx07519xxmidv8mpax4y-python3-3.12.5/bin/python3.12)
kill machine (pid 29)
qemu-kvm: terminating on signal 15 from pid 5 (/nix/store/h3i0acpmr8mrjx07519xxmidv8mpax4y-python3-3.12.5/bin/python3.12)
(finished: cleanup, in 0.01 seconds)
kill vlan (pid 6)