Run Test: slices-bi-singlenode-login 2026-03-12 16:00:42.750680 CET - Run: /usr/local/bin/uv pip install --upgrade slices-cli --extra-index-url=https://doc.slices-ri.eu/pypi/ 2026-03-12 16:00:45.852143 CET - Run: slices --version 2026-03-12 16:00:46.029542 CET - version: Slices CLI v2025.1.5 Slices CLI core v1.1.2 Slices CLI bi v2.0.2 Slices clientlib core v5.3.8 Slices clientlib bi v5.1.2 2026-03-12 16:00:46.029803 CET - Run: slices pubkey list --format text 2026-03-12 16:00:46.723804 CET - Pubkey already registered 2026-03-12 16:00:46.724040 CET - Run: slices bi infrastructure list --format csv --all --refresh 2026-03-12 16:00:47.221932 CET - Refreshed infrastructure list. Total: 22 entries. 2026-03-12 16:00:47.222076 CET - Check List Flavors 2026-03-12 16:00:47.222261 CET - Run: slices bi --infra de-munich-bi-vm flavor list -f json 2026-03-12 16:01:49.745634 CET - Step 'List Flavors' took 62.52 seconds, which is longer than the warning threshold of 5 seconds 2026-03-12 16:01:49.745687 CET - Check List DiskImages 2026-03-12 16:01:49.745875 CET - Run: slices bi --infra de-munich-bi-vm diskimage list -f json 2026-03-12 16:02:50.365062 CET - Step 'List DiskImages' took 60.62 seconds, which is longer than the warning threshold of 5 seconds 2026-03-12 16:02:50.365114 CET - Requesting resources 2026-03-12 16:02:50.365542 CET - Cloudinit user data: #!/bin/sh echo "Hello World. The time is now $(date -R)!" | tee '/user_data_output.txt' 2026-03-12 16:02:50.365635 CET - Run: slices bi --infra de-munich-bi-vm create tst --image 'Ubuntu 24.04.3' --flavor tiny --duration 2h --experiment tst-d92799af --user-data /tmp/tmpwd8jwjn2 2026-03-12 16:05:57.635458 CET - Resource ID: r_de-munich-bi-vm_01kkh9aff5fc0t0fvzehxdx1qw 2026-03-12 16:05:57.635601 CET - Step 'Requesting resource' took 187.27 seconds, which is longer than the warning threshold of 30 seconds 2026-03-12 16:05:57.635624 CET - Waiting until resource ready 2026-03-12 16:05:59.636070 CET - Run: slices bi --infra de-munich-bi-vm list-resources --format json --experiment tst-d92799af tst 2026-03-12 16:07:00.386925 CET - Status: UP 2026-03-12 16:07:00.386979 CET - Experiment ID: exp_expauth.ilabt.imec.be_01kkh94spqe2mthsmss57779ne 2026-03-12 16:07:00.387018 CET - Validate resources 2026-03-12 16:08:01.181659 CET - Content of log file '/opt/slices-monitor-worker/slices_monitor_tests/a2b25509-4174-40cf-973d-5b16c9326e61/step_Validateresources_command_1.txt': /opt/slices-monitor-worker/slices-cli-venv/bin/slices bi --infra de-munich-bi-vm list-resources --format json --experiment tst-d92799af tst 2026-03-12 16:08:01.181743 CET - Content of log file '/opt/slices-monitor-worker/slices_monitor_tests/a2b25509-4174-40cf-973d-5b16c9326e61/list-resources_json.txt': [ { "cluster_id": "default", "created_at": "2026-03-12T15:05:57.467286Z", "disk_image_id": "image_de-munich-bi-vm_01kjceghcff5gbwgxyt40nkj7a", "experiment_id": "exp_expauth.ilabt.imec.be_01kkh94spqe2mthsmss57779ne", "expires_at": "2026-03-12T17:02:00Z", "flavor_id": "flavor_de-munich-bi-vm_01kjceghd0fh1vh08ygdp4hrn9", "friendly_name": "tst", "id": "r_de-munich-bi-vm_01kkh9aff5fc0t0fvzehxdx1qw", "network_interfaces": [], "private_ipv4": "131.159.14.123", "private_ipv6": null, "public_ipv4": null, "public_ipv6": null, "ssh_authorized_keys": [ "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAINNiZPtQkfCEsc1x2QSwNWekfhWwWZbOvpE8hE0dH253 Wim (ftester) Van de Meerssche" ], "ssh_logins": [ { "host": "131.159.14.123", "port": 22, "username": "ftester", "host_keys": [ "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBD7SdvvE7iSLXM65nqhZyubFVnSiHFZgXboVnloah+0JzdaKa7SenpJOLTRcYPRm9WKCt9LBfj0tgxaXlnYqyK4= root@tst", "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKnmsTZvL4jE8d5AH4LJwlDSZPa+J1/IIrCYnS84bfUe root@tst", "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDPnNS3Y7KVgF+jK3ecuKbDis62WeaoXscwOKncN1pOoVamHbhF0uoAuGdWK/V4RrhCPGsdHXBNV0vh8xD7HpIOMSnxjieajh2JOLdOeIxItiX8UOiaoK+nmgsO7KBLIqfuFpvuAkslcr+Iv4+W5kkRP/WZptyJ4u4EYLzaDBxC3HO3NMqGszpAH5mEg70FKEbsMfN8QD1t0BWfKA22kFL/WLRb1mssZ0npDFf0w8NZ6aCjChggnTVF7ovZVm57oRbDz66T37qDeg5U3G5fa5ETS2haiyrFjv7fGRTOTGK5U+Pmvqp5TZU1F1yB99WYPA9jpKlNDxErj+cU9h/VGNTfYNqGmY4pdpbnZNoos/h0vKI7djGteZ4otXaZ1sOCHz+IkAoUHTBNYTPu/7YoXHw8rCzW/4Ey+J9ZNpD5ZvMBvUhFRmSN1xXc8FoOBp4CLw5YPt4ikLtKB5FJqdDaTPT9UPeHzw8PnoseBCE3iz4gX5YCuhSSbUPXMM0LuKXgBl0= root@tst" ], "description": "login for the VM", "jump_proxy": { "host": "tripwire.net.in.tum.de", "port": 10022, "username": "proxy", "host_keys": [ "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDG0Lq9tQhNNac9cAakdBSPzZ4/jYgRWIJ+0liG9c+c59LJltwOwnPYdOWvLv5HsN391E/fUXojP61vipOrMyuIipiEhOLhjAzP5b5R1WW3xWXWn+BWoXfBocPqPk2V/86aruTACox5CN4etwHWtuxkREyHfteVUhbcFHzNm0qYBQnLXDQxkuZOFbVTnYqRXh3pX0PuncJmwBB4IGE15JKs+A3WBFp1vz1Q2UvtH34rY8rmfKW80fFlzqnJqQun8gAHDfIl0Qa3QTxnecaocLolds5NGwHY7QRzW3yA7FirauZEaMho9Mbm9TRNNlEIR043amlrlukbMRLf/KqoyHJH7NZDXSwkcLrjOn5QsuliCbGbhrYlWux/y61719QKyn2XnuDpuOx1eM/7Kk+oHZhgPK6WgdMWmCBU3LaGfzjaCLMvED4lfBgT1nALTsE3KE2cvzbntlb/fHydevrKMmNrc1Em7WXYtGBjXuVs1G/fYAX9IrE8q6jXrSwO9FSZaZU=", "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBCKHIhTPdwDCtXQPH2/CR3MUzZUl3W6WNCrEBxka53WgjdfFtLko21enKbGYxI+POwDdE5sE6eIvjKDsZtFeA2Q=", "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIA8fyPxzW+ozU5ooygHANHFMVUA2xwnFU1TA5eoF3Xef" ], "description": "login for the JumpHost", "jump_proxy": null } } ], "status": "up", "terminated_at": null, "userdata": "#!/bin/sh\necho \"Hello World. The time is now $(date -R)!\" | tee '/user_data_output.txt'", "console_url": null, "machine_id": null, "failure_reason": null, "infra_id": "de-munich-bi-vm", "machine_name": null } ] 2026-03-12 16:08:01.181759 CET - Error in test step 'Validate resources': The resource has a private IPv4 address, but it is NOT a private address: 131.159.14.123 2026-03-12 16:08:01.181776 CET - Step 'Validate resources' took 60.79 seconds, which is longer than the warning threshold of 5 seconds 2026-03-12 16:08:01.181793 CET - Check if resources are registered in experiment 2026-03-12 16:08:01.181916 CET - Run: slices experiment list-resources --format json tst-d92799af 2026-03-12 16:08:01.788136 CET - Status (on expauth): UP 2026-03-12 16:08:01.788266 CET - Testing extend expires_at (all resources in experiment) 2026-03-12 16:08:01.788403 CET - Run: slices bi --infra de-munich-bi-vm extend --duration 3h --experiment tst-d92799af 2026-03-12 16:13:03.841407 CET - Run: slices bi --infra de-munich-bi-vm list-resources --format json --experiment tst-d92799af tst 2026-03-12 16:14:04.735980 CET - Testing extend expires_at (single resource in experiment) 2026-03-12 16:14:04.736179 CET - Run: slices bi --infra de-munich-bi-vm extend tst --duration 4h --experiment tst-d92799af 2026-03-12 16:19:08.439632 CET - Run: slices bi --infra de-munich-bi-vm list-resources --format json --experiment tst-d92799af tst 2026-03-12 16:20:09.332119 CET - Step 'Check extend expire' took 727.54 seconds, which is longer than the warning threshold of 40 seconds 2026-03-12 16:20:09.332184 CET - Testing ssh login 2026-03-12 16:20:09.342504 CET - Run: slices bi --infra de-munich-bi-vm ssh --no-exec --proxy on --show ssh_config --experiment tst-d92799af tst 2026-03-12 16:21:10.225918 CET - Step 'Ssh info ssh_config' took 60.88 seconds, which is longer than the warning threshold of 5 seconds 2026-03-12 16:21:10.226231 CET - Run: slices bi --infra de-munich-bi-vm ssh --no-exec --proxy off --show server_pubkey_openssh --experiment tst-d92799af tst 2026-03-12 16:22:11.019176 CET - Step 'Check SSH pubkey (resource)' took 60.79 seconds, which is longer than the warning threshold of 5 seconds 2026-03-12 16:22:11.019419 CET - Run: slices bi --infra de-munich-bi-vm ssh --no-exec --proxy off --show proxy_pubkey_openssh --experiment tst-d92799af tst 2026-03-12 16:23:16.921659 CET - Step 'Check SSH pubkey (proxy)' took 65.90 seconds, which is longer than the warning threshold of 5 seconds 2026-03-12 16:23:16.921764 CET - Logging in using 'slices bi ssh' 2026-03-12 16:23:16.921789 CET - Forcing IPv4 only. 2026-03-12 16:23:16.921952 CET - Run: slices bi --infra de-munich-bi-vm ssh --show nothing --experiment tst-d92799af tst -- -4 uname -a 2026-03-12 16:24:19.892781 CET - Forcing IPv4 only. 2026-03-12 16:24:19.892936 CET - Run: slices bi --infra de-munich-bi-vm ssh --show nothing --experiment tst-d92799af tst -- -4 uptime 2026-03-12 16:25:22.492754 CET - CLI SSH Test passed. 2026-03-12 16:25:22.492801 CET - Uname: Linux tst 6.8.0-87-generic #88-Ubuntu SMP PREEMPT_DYNAMIC Sat Oct 11 09:28:41 UTC 2025 x86_64 x86_64 x86_64 GNU/Linux 2026-03-12 16:25:22.492811 CET - Uptime: 15:25:22 up 19 min, 1 user, load average: 0.08, 0.02, 0.01 2026-03-12 16:25:22.492831 CET - Step 'Ssh login (via slices-cli, IPv4 only)' took 125.57 seconds, which is longer than the warning threshold of 20 seconds 2026-03-12 16:25:22.492853 CET - Logging in using SSH over SSH proxy 2026-03-12 16:25:22.493004 CET - Run: slices bi --infra de-munich-bi-vm ssh --no-exec --proxy on --show proxy_pubkey_openssh --experiment tst-d92799af tst 2026-03-12 16:26:23.477918 CET - Step 'Ssh info proxy_pubkey_openssh' took 60.99 seconds, which is longer than the warning threshold of 5 seconds 2026-03-12 16:26:23.478507 CET - Added paramiko HostKeyEntry for 131.159.14.123 2026-03-12 16:26:23.478607 CET - Added paramiko HostKeyEntry for 131.159.14.123 2026-03-12 16:26:23.478761 CET - Added paramiko HostKeyEntry for 131.159.14.123 2026-03-12 16:26:23.479054 CET - Added paramiko HostKeyEntry for [tripwire.net.in.tum.de]:10022 2026-03-12 16:26:23.479134 CET - Added paramiko HostKeyEntry for [tripwire.net.in.tum.de]:10022 2026-03-12 16:26:23.479169 CET - Added paramiko HostKeyEntry for [tripwire.net.in.tum.de]:10022 2026-03-12 16:26:23.479178 CET - Connecting to proxy tripwire.net.in.tum.de:10022 2026-03-12 16:26:24.244165 CET - Connecting to 131.159.14.123:22 over proxy 2026-03-12 16:26:25.628104 CET - SSH Test output: 2026-03-12 16:26:25.628149 CET - Uname: Linux tst 6.8.0-87-generic #88-Ubuntu SMP PREEMPT_DYNAMIC Sat Oct 11 09:28:41 UTC 2025 x86_64 x86_64 x86_64 GNU/Linux 2026-03-12 16:26:25.628159 CET - Uptime: 15:26:25 up 20 min, 1 user, load average: 0.03, 0.01, 0.00 2026-03-12 16:26:25.794573 CET - lsb_release: Ubuntu 24.04.3 LTS 2026-03-12 16:26:25.794621 CET - lsb_release matches expected value 2026-03-12 16:26:25.794633 CET - SSH Test passed. 2026-03-12 16:26:25.961373 CET - Cloud-init user-data: Hello World. The time is now Thu, 12 Mar 2026 15:06:55 +0000! 2026-03-12 16:26:25.967532 CET - Destroying tst-d92799af tst 2026-03-12 16:26:25.967710 CET - Run: slices bi --infra de-munich-bi-vm destroy --experiment tst-d92799af tst 2026-03-12 16:29:27.179972 CET - Step 'Destroy' took 181.21 seconds, which is longer than the warning threshold of 15 seconds 2026-03-12 16:29:27.180034 CET - Wait 2s before retry 2026-03-12 16:32:30.437314 CET - Content of log file '/opt/slices-monitor-worker/slices_monitor_tests/a2b25509-4174-40cf-973d-5b16c9326e61/step_DestroyRetry1_retry1_command_1.txt': /opt/slices-monitor-worker/slices-cli-venv/bin/slices bi --infra de-munich-bi-vm destroy --experiment tst-d92799af tst 2026-03-12 16:32:30.437395 CET - Content of log file '/opt/slices-monitor-worker/slices_monitor_tests/a2b25509-4174-40cf-973d-5b16c9326e61/destroy_retry1.txt': Deleting tst: task starting # task_id='dc68d6223d7e4ba5a9df9cc66374b2fd' tas… 1… Destroy failure ❌ ❌ Failed to destroy tst with ID r_de-munich-bi-vm_01kkh9aff5fc0t0fvzehxdx1qw Failure: INTERNAL_ERROR task_id='dc68d6223d7e4ba5a9df9cc66374b2fd' task_name='slices_bi_refimpl_backend.tasks.compute_resource:delete_compute_resou rce' labels={} labels_types={} args=[UUID('019ce295-3de5-7b01-a03f-7f747ade86fc'), 'status_change:api_initiated:delete'] kwargs={'initiator': 'user_account.ilabt.imec.be_1c3x2sxhmv8dqtmkxh9392sa0g'} Details stored at: /root/.slices/cli_error_details/err_2026-03-12T15:32:30+00:00.txt 2026-03-12 16:32:30.437414 CET - Error in test step 'Destroy (Retry 1)': "slices bi destroy" failed (return value is 1) 2026-03-12 16:32:30.437430 CET - Step 'Destroy' took 181.26 seconds, which is longer than the warning threshold of 15 seconds 2026-03-12 16:32:30.437446 CET - Wait 2s before retry 2026-03-12 16:35:33.493735 CET - Content of log file '/opt/slices-monitor-worker/slices_monitor_tests/a2b25509-4174-40cf-973d-5b16c9326e61/step_DestroyRetry2_retry2_command_1.txt': /opt/slices-monitor-worker/slices-cli-venv/bin/slices bi --infra de-munich-bi-vm destroy --experiment tst-d92799af tst 2026-03-12 16:35:33.493816 CET - Content of log file '/opt/slices-monitor-worker/slices_monitor_tests/a2b25509-4174-40cf-973d-5b16c9326e61/destroy_retry2.txt': Deleting tst: task starting # task_id='019a87e8509c400bad6ecae583c0a060' tas… 1… Destroy failure ❌ ❌ Failed to destroy tst with ID r_de-munich-bi-vm_01kkh9aff5fc0t0fvzehxdx1qw Failure: INTERNAL_ERROR task_id='019a87e8509c400bad6ecae583c0a060' task_name='slices_bi_refimpl_backend.tasks.compute_resource:delete_compute_resou rce' labels={} labels_types={} args=[UUID('019ce295-3de5-7b01-a03f-7f747ade86fc'), 'status_change:api_initiated:delete'] kwargs={'initiator': 'user_account.ilabt.imec.be_1c3x2sxhmv8dqtmkxh9392sa0g'} Details stored at: /root/.slices/cli_error_details/err_2026-03-12T15:35:33+00:00.txt 2026-03-12 16:35:33.493835 CET - Error in test step 'Destroy (Retry 2)': "slices bi destroy" failed (return value is 1) 2026-03-12 16:35:33.493854 CET - Step 'Destroy' took 181.06 seconds, which is longer than the warning threshold of 15 seconds 2026-03-12 16:35:33.493870 CET - Wait 2s before retry 2026-03-12 16:38:39.908045 CET - Content of log file '/opt/slices-monitor-worker/slices_monitor_tests/a2b25509-4174-40cf-973d-5b16c9326e61/step_DestroyRetry3_retry3_command_1.txt': /opt/slices-monitor-worker/slices-cli-venv/bin/slices bi --infra de-munich-bi-vm destroy --experiment tst-d92799af tst 2026-03-12 16:38:39.908127 CET - Content of log file '/opt/slices-monitor-worker/slices_monitor_tests/a2b25509-4174-40cf-973d-5b16c9326e61/destroy_retry3.txt': Deleting tst: task starting # task_id='9fca41e62a79438ea7be4610590a4399' tas… 1… Destroy failure ❌ ❌ Failed to destroy tst with ID r_de-munich-bi-vm_01kkh9aff5fc0t0fvzehxdx1qw Failure: INTERNAL_ERROR task_id='9fca41e62a79438ea7be4610590a4399' task_name='slices_bi_refimpl_backend.tasks.compute_resource:delete_compute_resou rce' labels={} labels_types={} args=[UUID('019ce295-3de5-7b01-a03f-7f747ade86fc'), 'status_change:api_initiated:delete'] kwargs={'initiator': 'user_account.ilabt.imec.be_1c3x2sxhmv8dqtmkxh9392sa0g'} Details stored at: /root/.slices/cli_error_details/err_2026-03-12T15:38:39+00:00.txt 2026-03-12 16:38:39.908147 CET - Error in test step 'Destroy (Retry 3)': "slices bi destroy" failed (return value is 1) 2026-03-12 16:38:39.908163 CET - Step 'Destroy' took 184.41 seconds, which is longer than the warning threshold of 15 seconds