�[2mserver # [   12.167812] postgresql-post-start[1001]: ALTER DATABASE�[0m
�[2mserver # [   12.182647] systemd[1]: Started PostgreSQL Server.�[0m
�[2mserver # [   12.390118] audiobookshelf[836]: [2024-09-16 01:29:41.114] INFO: [Database] Db connection was successful�[0m
�[2mserver # [   12.878708] dhcpcd[688]: eth0: leased 10.0.2.15 for 86400 seconds�[0m
�[2mserver # [   12.883708] dhcpcd[688]: eth0: adding route to 10.0.2.0/24�[0m
�[2mserver # [   12.888404] dhcpcd[688]: eth0: adding default route via 10.0.2.2�[0m
�[2mserver # [   13.112926] systemd[1]: Stopped target Host and Network Name Lookups.�[0m
�[2mserver # [   13.119380] systemd[1]: Stopping Host and Network Name Lookups...�[0m
�[2mserver # [   13.124711] systemd[1]: Stopped target User and Group Name Lookups.�[0m
�[2mserver # [   13.131907] systemd[1]: Stopping User and Group Name Lookups...�[0m
�[2mserver # [   13.133421] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...�[0m
�[2mserver # [   13.137579] systemd[1]: nscd.service: Deactivated successfully.�[0m
�[2mserver # [   13.143101] systemd[1]: Stopped Name Service Cache Daemon (nsncd).�[0m
�[2mserver # [   13.156484] systemd[1]: Starting Name Service Cache Daemon (nsncd)...�[0m
�[2mserver # [   13.206776] systemd[1]: Started DHCP Client.�[0m
�[2mserver # [   13.212458] systemd[1]: Reached target Network is Online.�[0m
�[2mserver # [   13.226406] systemd[1]: Started Lightweight LDAP server (lldap).�[0m
�[2mserver # [   13.258398] authelia-auth.example.com-pre-start[1062]: nc: connect to 127.0.0.1 port 3890 (tcp) failed: Connection refused�[0m
�[2mserver # [   13.275577] authelia-auth.example.com-pre-start[866]: Waiting for port 127.0.0.1:3890 to open...�[0m
�[2mserver # [   13.291353] systemd[1]: Started Name Service Cache Daemon (nsncd).�[0m
�[2mserver # [   13.292677] systemd[1]: Reached target Host and Network Name Lookups.�[0m
�[2mserver # [   13.297656] nsncd[1051]: Sep 16 01:29:42.019 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 3s }, path: "/var/run/nscd/socket"�[0m
�[2mserver # [   13.303865] systemd[1]: Reached target User and Group Name Lookups.�[0m
�[2mserver # [   13.384359] lldap-start[1075]: Loading configuration from /nix/store/q38wsm073lq5yvxzxjmzpmcas94nr75y-lldap_config.toml�[0m
�[2mserver # [   13.522154] audiobookshelf[836]: [2024-09-16 01:29:42.246] INFO: [Database] Db initialized with models: user, library, libraryFolder, book, podcast, podcastEpisode, libraryItem, mediaProgress, series, bookSeries, author, bookAuthor, collection, collectionBook, playlist, playlistMediaItem, device, playbackSession, feed, feedEpisode, setting, customMetadataProvider, mediaItemShare�[0m
�[2mserver # [   13.606763] audiobookshelf[836]: [2024-09-16 01:29:42.330] INFO: [LogManager] Init current daily log filename: 2024-09-16.txt�[0m
�[2mclient # [   13.691660] dhcpcd[691]: eth0: leased 10.0.2.15 for 86400 seconds�[0m
�[2mclient # [   13.694124] dhcpcd[691]: eth0: adding route to 10.0.2.0/24�[0m
�[2mclient # [   13.695292] dhcpcd[691]: eth0: adding default route via 10.0.2.2�[0m
�[2mserver # [   13.717565] audiobookshelf[836]: [2024-09-16 01:29:42.441] INFO: [BackupManager] 0 Backups Found�[0m
�[2mserver # [   13.724352] audiobookshelf[836]: [2024-09-16 01:29:42.448] INFO: [BackupManager] Auto Backups are disabled�[0m
�[2mclient # [   13.851528] systemd[1]: Stopped target Host and Network Name Lookups.�[0m
�[2mclient # [   13.854503] systemd[1]: Stopping Host and Network Name Lookups...�[0m
�[2mclient # [   13.861486] systemd[1]: Stopped target User and Group Name Lookups.�[0m
�[2mclient # [   13.867352] systemd[1]: Stopping User and Group Name Lookups...�[0m
�[2mclient # [   13.869865] systemd[1]: Stopping Name Service Cache Daemon (nsncd)...�[0m
�[2mclient # [   13.872406] systemd[1]: nscd.service: Deactivated successfully.�[0m
�[2mclient # [   13.876609] systemd[1]: Stopped Name Service Cache Daemon (nsncd).�[0m
�[2mserver # [   13.865169] audiobookshelf[836]: [2024-09-16 01:29:42.588] INFO: Listening on http://127.0.0.1:8113�[0m
�[2mclient # [   13.898205] systemd[1]: Starting Name Service Cache Daemon (nsncd)...�[0m
�[2mclient # [   13.944245] systemd[1]: Started DHCP Client.�[0m
�[2mclient # [   13.953641] systemd[1]: Reached target Network is Online.�[0m
�[2mclient # [   13.984591] systemd[1]: Started Name Service Cache Daemon (nsncd).�[0m
�[2mserver # [   13.974865] lldap-start[1075]: 2024-09-16T01:29:42.138651279+00:00  INFO     set_up_server [ 325ms | 100.00% ]�[0m
�[2mclient # [   13.992310] nsncd[883]: Sep 16 01:29:42.585 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 3s }, path: "/var/run/nscd/socket"�[0m
�[2mserver # [   13.976390] lldap-start[1075]: 2024-09-16T01:29:42.139458086+00:00  INFO     ┝━ ｉ [info]: Starting LLDAP version 0.5.1-alpha�[0m
�[2mclient # [   13.995194] systemd[1]: Reached target Multi-User System.�[0m
�[2mserver # [   13.977910] lldap-start[1075]: 2024-09-16T01:29:42.221533880+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema from version 1�[0m
�[2mclient # [   13.996442] systemd[1]: Reached target Host and Network Name Lookups.�[0m
�[2mclient # [   13.997697] systemd[1]: Reached target User and Group Name Lookups.�[0m
�[2mserver # [   13.979752] lldap-start[1075]: 2024-09-16T01:29:42.221544217+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 2�[0m
�[2mclient # [   13.998943] systemd[1]: Startup finished in 2.891s (kernel) + 11.097s (userspace) = 13.988s.�[0m
�[2mserver # [   13.982302] lldap-start[1075]: 2024-09-16T01:29:42.235085323+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 3�[0m
�[2mserver # [   13.984536] lldap-start[1075]: 2024-09-16T01:29:42.259161009+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 4�[0m
�[2mserver # [   13.986359] lldap-start[1075]: 2024-09-16T01:29:42.269279334+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 5�[0m
�[2mserver # [   13.988626] lldap-start[1075]: 2024-09-16T01:29:42.286848047+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 6�[0m
�[2mserver # [   13.990539] lldap-start[1075]: 2024-09-16T01:29:42.296999337+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 7�[0m
�[2mserver # [   13.992345] lldap-start[1075]: 2024-09-16T01:29:42.305484494+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 8�[0m
�[2mserver # [   13.994225] lldap-start[1075]: 2024-09-16T01:29:42.314452394+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 9�[0m
�[2mserver # [   13.996762] lldap-start[1075]: 2024-09-16T01:29:42.323916446+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 10�[0m
�[2mserver # [   13.998588] lldap-start[1075]: 2024-09-16T01:29:42.379807627+00:00  WARN     ┝━ 🚧 [warn]: Could not find lldap_admin group, trying to create it�[0m
�[2mserver # [   14.000824] lldap-start[1075]: 2024-09-16T01:29:42.401887249+00:00  WARN     ┝━ 🚧 [warn]: Could not find lldap_password_manager group, trying to create it�[0m
�[2mserver # [   14.002728] lldap-start[1075]: 2024-09-16T01:29:42.417994883+00:00  WARN     ┝━ 🚧 [warn]: Could not find lldap_strict_readonly group, trying to create it�[0m
�[2mserver # [   14.004937] lldap-start[1075]: 2024-09-16T01:29:42.433558313+00:00  WARN     ┝━ 🚧 [warn]: Could not find an admin user, trying to create the user "admin" with the config-provided password�[0m
�[2mserver # [   14.007340] lldap-start[1075]: 2024-09-16T01:29:42.695781026+00:00  INFO     ┝━ ｉ [info]: Starting the LDAP server on port 3890�[0m
�[2mserver # [   14.009583] lldap-start[1075]: 2024-09-16T01:29:42.696946537+00:00  INFO     ┕━ ｉ [info]: Starting the API/web server on port 17170�[0m
�[2mserver # [   14.011967] lldap-start[1075]: 2024-09-16T01:29:42.705234742+00:00  INFO     ｉ [info]: starting 1 workers�[0m
�[2mserver # [   14.013524] lldap-start[1075]: 2024-09-16T01:29:42.707384177+00:00  INFO     ｉ [info]: Actix runtime found; starting in Actix runtime�[0m
�[2mserver # [   14.019806] lldap-start[1075]: 2024-09-16T01:29:42.745357718+00:00  INFO     ｉ [info]: DB Cleanup Cron started�[0m
�[2mserver # Connection to localhost (127.0.0.1) 8113 port [tcp/*] succeeded!�[0m
(finished: waiting for TCP port 8113 on localhost, in 5.60 seconds)
server: �[1m�[32mmust succeed: mkdir -p /tmp/shared/tmp0nlawouw�[0m
(finished: must succeed: mkdir -p /tmp/shared/tmp0nlawouw, in 0.02 seconds)
server: �[1m�[32mmust succeed: cp -r /etc/ssl/certs/ca-certificates.crt /tmp/shared/tmp0nlawouw/ca-certificates.crt�[0m
(finished: must succeed: cp -r /etc/ssl/certs/ca-certificates.crt /tmp/shared/tmp0nlawouw/ca-certificates.crt, in 0.03 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.03 seconds)
client: �[1m�[32mmust succeed: mkdir -p /tmp/shared/tmp1qvzymh5�[0m
(finished: must succeed: mkdir -p /tmp/shared/tmp1qvzymh5, in 0.02 seconds)
client: �[1m�[32mmust succeed: mkdir -p /etc/ssl/certs�[0m
(finished: must succeed: mkdir -p /etc/ssl/certs, in 0.02 seconds)
client: �[1m�[32mmust succeed: cp -r /tmp/shared/tmp1qvzymh5/ca-certificates.crt /etc/ssl/certs/ca-certificates.crt�[0m
(finished: must succeed: cp -r /tmp/shared/tmp1qvzymh5/ca-certificates.crt /etc/ssl/certs/ca-certificates.crt, in 0.03 seconds)
�[1m�[32msubtest: access�[0m
curl --show-error --location --cookie-jar cookie.txt --cookie cookie.txt --connect-to a.example.com:443:server:443 --connect-to a.example.com:80:server:80 --connect-to auth.example.com:443:server:443 --silent --output /dev/null --write-out '{"code":%{response_code}}' https://a.example.com
(finished: subtest: access, in 0.15 seconds)
(finished: run the VM test script, in 15.65 seconds)
test script finished in 15.70s
�[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 27)
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)