�[2mserver # [   12.852964] nsncd[1099]: Sep 16 01:29:35.768 INFO started, config: Config { ignored_request_types: {}, worker_count: 8, handoff_timeout: 3s }, path: "/var/run/nscd/socket"�[0m
�[2mserver # [   12.856394] systemd[1]: Reached target Host and Network Name Lookups.�[0m
�[2mserver # [   12.857316] systemd[1]: Reached target User and Group Name Lookups.�[0m
�[2mserver # [   12.901357] lldap-start[1119]: Loading configuration from /nix/store/q38wsm073lq5yvxzxjmzpmcas94nr75y-lldap_config.toml�[0m
�[2mserver # [   13.112185] forgejo-post-start[1128]: nc: /run/forgejo/forgejo.sock: No such file or directory�[0m
�[2mserver # [   13.115189] forgejo-post-start[1015]: Waiting for unix /run/forgejo/forgejo.sock to open...�[0m
�[2mserver # [   13.202325] gitea[1000]: 2024/09/16 01:29:36 cmd/web.go:194:serveInstalled() [W] Table oauth2_application Column confidential_client db default is true, struct default is TRUE�[0m
�[2mserver # [   13.230130] lldap-start[1119]: 2024-09-16T01:29:35.834973298+00:00  INFO     set_up_server [ 206ms | 100.00% ]�[0m
�[2mserver # [   13.231151] lldap-start[1119]: 2024-09-16T01:29:35.835383406+00:00  INFO     ┝━ ｉ [info]: Starting LLDAP version 0.5.1-alpha�[0m
�[2mserver # [   13.232303] lldap-start[1119]: 2024-09-16T01:29:35.874440604+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema from version 1�[0m
�[2mserver # [   13.233590] lldap-start[1119]: 2024-09-16T01:29:35.874447030+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 2�[0m
�[2mserver # [   13.234962] lldap-start[1119]: 2024-09-16T01:29:35.880303640+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 3�[0m
�[2mserver # [   13.236411] lldap-start[1119]: 2024-09-16T01:29:35.889641698+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 4�[0m
�[2mserver # [   13.237735] lldap-start[1119]: 2024-09-16T01:29:35.894906893+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 5�[0m
�[2mserver # [   13.239067] lldap-start[1119]: 2024-09-16T01:29:35.904174551+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 6�[0m
�[2mserver # [   13.240183] lldap-start[1119]: 2024-09-16T01:29:35.908597739+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 7�[0m
�[2mserver # [   13.241538] lldap-start[1119]: 2024-09-16T01:29:35.913427124+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 8�[0m
�[2mserver # [   13.243140] lldap-start[1119]: 2024-09-16T01:29:35.919054934+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 9�[0m
�[2mserver # [   13.244172] lldap-start[1119]: 2024-09-16T01:29:35.923187023+00:00  INFO     ┝━ ｉ [info]: Upgrading DB schema to version 10�[0m
�[2mserver # [   13.245315] lldap-start[1119]: 2024-09-16T01:29:35.946503953+00:00  WARN     ┝━ 🚧 [warn]: Could not find lldap_admin group, trying to create it�[0m
�[2mserver # [   13.246878] lldap-start[1119]: 2024-09-16T01:29:35.955130748+00:00  WARN     ┝━ 🚧 [warn]: Could not find lldap_password_manager group, trying to create it�[0m
�[2mserver # [   13.248415] lldap-start[1119]: 2024-09-16T01:29:35.961513123+00:00  WARN     ┝━ 🚧 [warn]: Could not find lldap_strict_readonly group, trying to create it�[0m
�[2mserver # [   13.250102] lldap-start[1119]: 2024-09-16T01:29:35.967701899+00:00  WARN     ┝━ 🚧 [warn]: Could not find an admin user, trying to create the user "admin" with the config-provided password�[0m
�[2mserver # [   13.252125] lldap-start[1119]: 2024-09-16T01:29:36.144767978+00:00  INFO     ┝━ ｉ [info]: Starting the LDAP server on port 3890�[0m
�[2mserver # [   13.253192] lldap-start[1119]: 2024-09-16T01:29:36.145277820+00:00  INFO     ┕━ ｉ [info]: Starting the API/web server on port 17170�[0m
�[2mserver # [   13.254324] lldap-start[1119]: 2024-09-16T01:29:36.149239217+00:00  INFO     ｉ [info]: starting 1 workers�[0m
�[2mserver # [   13.255266] lldap-start[1119]: 2024-09-16T01:29:36.149452373+00:00  INFO     ｉ [info]: Actix runtime found; starting in Actix runtime�[0m
�[2mserver # [   13.257141] lldap-start[1119]: 2024-09-16T01:29:36.172239626+00:00  INFO     ｉ [info]: DB Cleanup Cron started�[0m
�[2mserver # [   13.420563] gitea[1000]: 2024/09/16 01:29:36 cmd/web.go:194:serveInstalled() [W] Table system_setting Column version db default is , struct default is 1�[0m
�[2mserver # [   13.594145] gitea[1000]: 2024/09/16 01:29:36 cmd/web.go:194:serveInstalled() [W] Table user Column max_repo_creation db default is '-1', struct default is -1�[0m
�[2mserver # [   14.537194] gitea[1000]: 2024/09/16 01:29:37 cmd/web.go:194:serveInstalled() [W] Table label Column archived_unix db default is , struct default is NULL�[0m
�[2mserver # [   14.664192] gitea[1000]: 2024/09/16 01:29:37 routers/init.go:139:InitWebInstalled() [I] ORM engine initialization successful!�[0m
�[2mserver # [   15.126388] forgejo-post-start[1136]: nc: /run/forgejo/forgejo.sock: No such file or directory�[0m
�[2mserver # [   15.127893] forgejo-post-start[1015]: Waiting for unix /run/forgejo/forgejo.sock to open...�[0m
�[2mserver # [   17.136189] forgejo-post-start[1147]: nc: /run/forgejo/forgejo.sock: No such file or directory�[0m
�[2mserver # [   17.138421] forgejo-post-start[1015]: Waiting for unix /run/forgejo/forgejo.sock to open...�[0m
�[2mserver # [   17.363577] gitea[1000]: 2024/09/16 01:29:40 ...er/issues/indexer.go:76:func1() [I] PID 1000: Initializing Issue Indexer: bleve�[0m
�[2mserver # [   17.370073] gitea[1000]: 2024/09/16 01:29:40 ...xer/stats/indexer.go:41:populateRepoIndexer() [I] Populating the repo stats indexer with existing repositories�[0m
�[2mserver # [   17.378554] gitea[1000]: 2024/09/16 01:29:40 ...er/issues/indexer.go:153:func2() [I] Issue Indexer Initialization took 17.439926ms�[0m
�[2mserver # [   17.383266] gitea[1000]: 2024/09/16 01:29:40 routers/init.go:83:syncAppConfForGit() [I] AppPath changed from '' to '/nix/store/l7wlg2cw9s1bcknb0nqv1j75lr26wydf-forgejo-lts-7.0.9/bin/gitea'�[0m
�[2mserver # [   17.385498] gitea[1000]: 2024/09/16 01:29:40 routers/init.go:88:syncAppConfForGit() [I] CustomConf changed from '' to '/var/lib/forgejo/custom/conf/app.ini'�[0m
�[2mserver # [   17.388217] gitea[1000]: 2024/09/16 01:29:40 routers/init.go:94:syncAppConfForGit() [I] re-sync repository hooks ...�[0m
�[2mserver # [   17.397394] gitea[1000]: 2024/09/16 01:29:40 routers/init.go:97:syncAppConfForGit() [I] re-write ssh public keys ...�[0m
�[2mserver # [   17.773718] gitea[1000]: 2024/09/16 01:29:40 ...s/actions/cleanup.go:36:cleanExpiredArtifacts() [I] Found 0 expired artifacts�[0m
�[2mserver # [   17.816176] gitea[1000]: 2024/09/16 01:29:40 ...s/actions/cleanup.go:60:cleanNeedDeleteArtifacts() [I] Found 0 artifacts pending deletion�[0m
�[2mserver # [   17.996795] lldap-start[1119]: 2024-09-16T01:29:40.731250617+00:00  INFO     LDAP session [ 178ms | 1.70% / 100.00% ]�[0m
�[2mserver # [   17.997981] lldap-start[1119]: 2024-09-16T01:29:40.734522262+00:00  INFO     ┝━ LDAP request [ 174ms | 97.33% ]�[0m
�[2mserver # [   17.999204] lldap-start[1119]: 2024-09-16T01:29:40.909446170+00:00  INFO     ┕━ LDAP request [ 1.73ms | 0.97% ]�[0m
�[2mserver # [   18.000493] gitea[1000]: 2024/09/16 01:29:40 .../ldap/source_sync.go:60:Sync() [E] LDAP search found no entries but did not report an error. Refusing to deactivate all users�[0m
�[2mserver # [   18.249189] gitea[1000]: 2024/09/16 01:29:41 cmd/web.go:304:listen() [I] Listen: http+unix:///run/forgejo/forgejo.sock�[0m
�[2mserver # [   18.251192] gitea[1000]: 2024/09/16 01:29:41 cmd/web.go:308:listen() [I] AppURL(ROOT_URL): https://f.example.com/�[0m
�[2mserver # [   18.252194] gitea[1000]: 2024/09/16 01:29:41 ...s/graceful/server.go:50:NewServer() [I] Starting new Web server: unix:/run/forgejo/forgejo.sock on PID: 1000�[0m
�[2mserver # [   21.288418] gitea[1000]: 2024/09/16 01:29:44 ...eb/routing/logger.go:102:func1() [I] router: completed POST /api/internal/actions/generate_actions_runner_token for 127.0.0.1:0, 200 OK in 8.8ms @ private/actions.go:24(private.GenerateActionsRunnerToken)�[0m
�[2mserver # [   21.296992] systemd[1]: Started Forgejo (Beyond coding. We forge.).�[0m
�[2mserver # [   21.301943] systemd[1]: Starting Gitea Actions Runner...�[0m
�[2mserver # [   21.338365] z2hjid7csb31h52v09k7l293hin39aj0-gitea-register-runner-local[1191]: mkdir: created directory '/var/lib/gitea-runner/local'�[0m
�[2mserver # [   21.354555] z2hjid7csb31h52v09k7l293hin39aj0-gitea-register-runner-local[1197]: rm: cannot remove '/var/lib/gitea-runner/local/.runner': No such file or directory�[0m
(finished: waiting for unit forgejo.service, in 21.86 seconds)
server: �[1m�[32mwaiting for unit nginx.service�[0m
�[2mserver # [   21.413423] z2hjid7csb31h52v09k7l293hin39aj0-gitea-register-runner-local[1198]: level=info msg="Registering runner, arch=amd64, os=linux, version=v3.5.1."�[0m
�[2mserver # [   21.415134] z2hjid7csb31h52v09k7l293hin39aj0-gitea-register-runner-local[1198]: level=warning msg="Runner in user-mode."�[0m
�[2mserver # [   21.430689] gitea[1000]: 2024/09/16 01:29:44 ...eb/routing/logger.go:102:func1() [I] router: completed POST /api/actions/ping.v1.PingService/Ping for 127.0.0.1:0, 200 OK in 2.9ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)�[0m
�[2mserver # [   21.435144] z2hjid7csb31h52v09k7l293hin39aj0-gitea-register-runner-local[1198]: level=debug msg="Successfully pinged the Forgejo instance server"�[0m
(finished: waiting for unit nginx.service, in 0.05 seconds)
server: �[1m�[32mwaiting for UNIX-domain stream on '/run/forgejo/forgejo.sock'�[0m
�[2mserver # [   21.454340] gitea[1000]: 2024/09/16 01:29:44 ...eb/routing/logger.go:102:func1() [I] router: completed POST /api/actions/runner.v1.RunnerService/Register for 127.0.0.1:0, 200 OK in 16.4ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)�[0m
�[2mserver # [   21.458726] z2hjid7csb31h52v09k7l293hin39aj0-gitea-register-runner-local[1198]: level=info msg="Runner registered successfully."�[0m
�[2mserver # [   21.465218] systemd[1]: Started Gitea Actions Runner.�[0m
�[2mserver # [   21.467628] systemd[1]: Reached target Multi-User System.�[0m
�[2mserver # [   21.468536] systemd[1]: Startup finished in 2.185s (kernel) + 19.281s (userspace) = 21.466s.�[0m
(finished: waiting for UNIX-domain stream on '/run/forgejo/forgejo.sock', in 0.04 seconds)
�[1m�[32msubtest: access�[0m
curl --show-error --location --cookie-jar cookie.txt --cookie cookie.txt --connect-to f.example.com:443:server:443 --connect-to f.example.com:80:server:80 --connect-to auth.example.com:443:server:443 --silent --output /dev/null --write-out '{"code":%{response_code}}' http://f.example.com
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)
�[2mserver # [   21.500295] act_runner[1216]: time="2024-09-16T01:29:44Z" level=info msg="Starting runner daemon"�[0m
�[2mserver # [   21.520902] gitea[1000]: 2024/09/16 01:29:44 ...eb/routing/logger.go:102:func1() [I] router: completed POST /api/actions/runner.v1.RunnerService/Declare for 127.0.0.1:0, 200 OK in 10.2ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)�[0m
�[2mserver # [   21.523297] act_runner[1216]: time="2024-09-16T01:29:44Z" level=info msg="runner: local, with version: v3.5.1, with labels: [native], declared successfully"�[0m
�[2mserver # [   21.526051] act_runner[1216]: time="2024-09-16T01:29:44Z" level=info msg="[poller 0] launched"�[0m
�[2mserver # [   21.539196] gitea[1000]: 2024/09/16 01:29:44 ...eb/routing/logger.go:102:func1() [I] router: completed POST /api/actions/runner.v1.RunnerService/FetchTask for 127.0.0.1:0, 200 OK in 11.5ms @ <autogenerated>:1(http.Handler.ServeHTTP-fm)�[0m
�[2mserver # [   21.550540] gitea[1000]: 2024/09/16 01:29:44 ...eb/routing/logger.go:102:func1() [I] router: completed GET / for [2001:db8:1::1]:0, 200 OK in 7.5ms @ web/home.go:32(web.Home)�[0m
(finished: subtest: access, in 0.06 seconds)
�[1m�[32msubtest: extraScript�[0m
server: �[1m�[32mwaiting for unit gitea-runner-local.service�[0m
(finished: waiting for unit gitea-runner-local.service, in 0.04 seconds)
server: �[1m�[32mmust succeed: journalctl -o cat -u gitea-runner-local.service | grep -q 'Runner registered successfully'�[0m
(finished: must succeed: journalctl -o cat -u gitea-runner-local.service | grep -q 'Runner registered successfully', in 0.02 seconds)
(finished: subtest: extraScript, in 0.06 seconds)
(finished: run the VM test script, in 22.29 seconds)
test script finished in 22.37s
�[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.02 seconds)
kill vlan (pid 6)