Stderr output

<core_client_version>8.2.4</core_client_version>
<![CDATA[
<message>
(unknown error) (317) - exit code 4294967114 (0xffffff4a)</message>
<stderr_txt>
2025-11-15 13:31:22 (25848): vboxwrapper version 26210
2025-11-15 13:31:22 (25848): BOINC client version: 8.2.4
2025-11-15 13:31:23 (25848): Detected: VirtualBox VboxManage Interface (Version: 7.1.12)
2025-11-15 13:31:23 (25848): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2025-11-15 13:31:23 (25848): Successfully copied 'init_data.xml' to the shared directory.
2025-11-15 13:31:23 (25848): Create VM. (boinc_a698867267faa521, slot#4)
2025-11-15 13:31:24 (25848): Setting Memory Size for VM. (4584MB)
2025-11-15 13:31:24 (25848): Setting CPU Count for VM. (4)
2025-11-15 13:31:24 (25848): Setting Chipset Options for VM.
2025-11-15 13:31:25 (25848): Setting Graphics Controller Options for VM. (Driver: VBoxVGA, 16MB)
2025-11-15 13:31:25 (25848): Setting Boot Options for VM.
2025-11-15 13:31:25 (25848): Setting Network Configuration for NAT. (Driver: virtio)
2025-11-15 13:31:26 (25848): Enabling VM Network Access.
2025-11-15 13:31:26 (25848): Disabling USB Support for VM.
2025-11-15 13:31:26 (25848): Disabling COM Port Support for VM.
2025-11-15 13:31:26 (25848): Disabling LPT Port Support for VM.
2025-11-15 13:31:27 (25848): Disabling Audio Support for VM.
2025-11-15 13:31:27 (25848): Disabling Clipboard Support for VM.
2025-11-15 13:31:27 (25848): Disabling Drag and Drop Support for VM.
2025-11-15 13:31:27 (25848): Adding storage controller(s) to VM.
2025-11-15 13:31:28 (25848): Adding virtual disk drive to VM. (CMS_2025_04_08_prod.vdi)
2025-11-15 13:31:28 (25848): Adding VirtualBox Guest Additions to VM.
2025-11-15 13:31:29 (25848): Adding network bandwidth throttle group to VM. (Defaulting to 1024GB)
2025-11-15 13:31:29 (25848): forwarding host port 63907 to guest port 80
2025-11-15 13:31:29 (25848): Enabling remote desktop for VM.
2025-11-15 13:31:30 (25848): Enabling shared directory for VM.
2025-11-15 13:31:30 (25848): Starting VM using VBoxManage interface. (boinc_a698867267faa521, slot#4)
2025-11-15 13:31:36 (25848): Successfully started VM. (PID = '24712')
2025-11-15 13:31:36 (25848): Reporting VM Process ID to BOINC.
2025-11-15 13:31:36 (25848): Guest Log: BIOS: VirtualBox 7.1.12
2025-11-15 13:31:36 (25848): Guest Log: CPUID EDX: 0x178bfbff
2025-11-15 13:31:36 (25848): Guest Log: BIOS: No PCI IDE controller, not probing IDE
2025-11-15 13:31:36 (25848): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors
2025-11-15 13:31:36 (25848): VM state change detected. (old = 'poweredoff', new = 'running')
2025-11-15 13:31:36 (25848): Detected: Web Application Enabled (http://localhost:63907)
2025-11-15 13:31:36 (25848): Detected: Remote Desktop Enabled (localhost:63908)
2025-11-15 13:31:36 (25848): Preference change detected
2025-11-15 13:31:36 (25848): Setting CPU throttle for VM. (100%)
2025-11-15 13:31:36 (25848): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2025-11-15 13:31:38 (25848): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032
2025-11-15 13:31:38 (25848): Guest Log: BIOS: Booting from Hard Disk...
2025-11-15 13:31:40 (25848): Guest Log: BIOS: KBD: unsupported int 16h function 03
2025-11-15 13:31:40 (25848): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 
2025-11-15 13:32:00 (25848): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds
2025-11-15 13:32:00 (25848): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)
2025-11-15 13:32:01 (25848): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log
2025-11-15 13:32:01 (25848): Guest Log: 00:00:00.000096 main     Log opened 2025-11-15T13:32:00.957065000Z
2025-11-15 13:32:01 (25848): Guest Log: 00:00:00.000216 main     OS Product: Linux
2025-11-15 13:32:01 (25848): Guest Log: 00:00:00.000256 main     OS Release: 4.14.232-19.cernvm.x86_64
2025-11-15 13:32:01 (25848): Guest Log: 00:00:00.000282 main     OS Version: #1 SMP Fri Apr 30 17:12:25 CEST 2021
2025-11-15 13:32:01 (25848): Guest Log: 00:00:00.000308 main     Executable: /usr/sbin/VBoxService
2025-11-15 13:32:01 (25848): Guest Log: 00:00:00.000308 main     Process ID: 2285
2025-11-15 13:32:01 (25848): Guest Log: 00:00:00.000309 main     Package type: LINUX_64BITS_GENERIC
2025-11-15 13:32:01 (25848): Guest Log: 00:00:00.001421 main     5.2.6 r120293 started. Verbose level = 0
2025-11-15 13:32:17 (25848): Guest Log: [INFO] Mounting the shared directory
2025-11-15 13:32:17 (25848): Guest Log: [INFO] Shared directory mounted, enabling vboxmonitor
2025-11-15 13:32:17 (25848): Guest Log: [INFO] Sourcing essential functions from /cvmfs/grid.cern.ch
2025-11-15 13:32:17 (25848): Guest Log: [INFO] Testing connection to cern.ch
2025-11-15 13:32:17 (25848): Guest Log: [INFO] Testing connection to VCCS
2025-11-15 13:32:17 (25848): Guest Log: [INFO] Testing connection to HTCondor-Collector
2025-11-15 13:32:18 (25848): Guest Log: [INFO] Testing connection to HTCondor-CCB
2025-11-15 13:32:18 (25848): Guest Log: [INFO] Testing connection to WMAgent
2025-11-15 13:32:18 (25848): Guest Log: [INFO] Testing connection to EOSCMS
2025-11-15 13:32:18 (25848): Guest Log: [INFO] Testing connection to CMS-Factory
2025-11-15 13:32:19 (25848): Guest Log: [INFO] Testing connection to CMS-Frontier
2025-11-15 13:32:19 (25848): Guest Log: [INFO] Testing connection to Frontier
2025-11-15 13:32:19 (25848): Guest Log: [INFO] Testing connection to http://cms-frontier.openhtc.io:8080/FrontierProd/Frontier/
2025-11-15 13:32:19 (25848): Guest Log: [INFO] Got a proxy from the local BOINC client
2025-11-15 13:32:20 (25848): Guest Log: [INFO] Will use it for CVMFS and Frontier
2025-11-15 13:32:20 (25848): Guest Log: [INFO] Reloading and probing the CVMFS configuration
2025-11-15 13:32:26 (25848): Guest Log: [INFO] Probing /cvmfs/grid.cern.ch... OK
2025-11-15 13:32:29 (25848): Guest Log: [INFO] Probing /cvmfs/cms-ib.cern.ch... OK
2025-11-15 13:32:29 (25848): Guest Log: [INFO] Probing /cvmfs/singularity.opensciencegrid.org... OK
2025-11-15 13:32:29 (25848): Guest Log: [INFO] Probing /cvmfs/oasis.opensciencegrid.org... OK
2025-11-15 13:32:32 (25848): Guest Log: [INFO] Probing /cvmfs/cms.cern.ch... OK
2025-11-15 13:32:32 (25848): Guest Log: [INFO] Excerpt from "cvmfs_config stat": VERSION HOST PROXY
2025-11-15 13:32:32 (25848): Guest Log: [INFO] 2.7.2.0 http://s1ral-cvmfs.openhtc.io http://192.168.1.130:3128
2025-11-15 13:32:33 (25848): Guest Log: [INFO] Environment HTTP proxy: http://192.168.1.130:3128
2025-11-15 13:32:33 (25848): Guest Log: [INFO] Reading volunteer information
2025-11-15 13:32:37 (25848): Guest Log: [INFO] Requesting an X509 credential from LHC@home
2025-11-15 13:32:38 (25848): Guest Log: [INFO] Requesting an idtoken from LHC@home
2025-11-15 13:32:39 (25848): Guest Log: [INFO] CMS application starting. Check log files.
2025-11-15 14:18:19 (25848): VM Heartbeat file specified, but missing heartbeat.
2025-11-15 14:18:19 (25848): Powering off VM.
2025-11-15 14:19:05 (25848): Error in poweroff VM for VM: -182
Command:
VBoxManage -q controlvm "boinc_a698867267faa521" poweroff
Output:
0%...10%...20%...
2025-11-15 14:19:05 (25848): VM did not power off when requested.
2025-11-15 14:19:05 (25848): VM was NOT successfully terminated.
2025-11-15 14:19:05 (25848): Deregistering VM. (boinc_a698867267faa521, slot#4)
2025-11-15 14:19:05 (25848): Removing network bandwidth throttle group from VM.
2025-11-15 14:19:06 (25848): Removing VM from VirtualBox.

    Hypervisor System Log:

66:27:22.787459 USBPROXY usbLibGetDevices: Starting USB device enumeration
66:27:22.788019 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#VID_2109&PID_2812#5&2a753ff6&0&5#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 4
66:27:22.791319 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 13
66:27:22.791381 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 14
66:27:22.791814 USBPROXY usbLibGetDevices: Found 5 USB devices, 0 captured
66:27:24.623844 USBPROXY usbLibGetDevices: Starting USB device enumeration
66:27:24.624419 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#VID_2109&PID_2812#5&2a753ff6&0&5#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 4
66:27:24.628645 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 13
66:27:24.628735 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 14
66:27:24.629242 USBPROXY usbLibGetDevices: Found 5 USB devices, 0 captured
66:35:03.871321 USBPROXY usbLibGetDevices: Starting USB device enumeration
66:35:03.871956 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#VID_2109&PID_2812#5&2a753ff6&0&5#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 4
66:35:03.875998 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 13
66:35:03.876062 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 14
66:35:03.876498 USBPROXY usbLibGetDevices: Found 5 USB devices, 0 captured
66:35:05.478193 USBPROXY usbLibGetDevices: Starting USB device enumeration
66:35:05.478779 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#VID_2109&PID_2812#5&2a753ff6&0&5#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 4
66:35:05.482520 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 13
66:35:05.482582 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 14
66:35:05.482996 USBPROXY usbLibGetDevices: Found 5 USB devices, 0 captured
66:42:12.374136 USBPROXY usbLibGetDevices: Starting USB device enumeration
66:42:12.374696 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#VID_2109&PID_2812#5&2a753ff6&0&5#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 4
66:42:12.378027 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 13
66:42:12.378123 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 14
66:42:12.378600 USBPROXY usbLibGetDevices: Found 5 USB devices, 0 captured
66:42:12.954542 USBPROXY usbLibGetDevices: Starting USB device enumeration
66:42:12.955051 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#VID_2109&PID_2812#5&2a753ff6&0&5#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 4
66:42:12.959199 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 13
66:42:12.959259 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 14
66:42:12.959782 USBPROXY usbLibGetDevices: Found 5 USB devices, 0 captured
66:42:13.639410 USBPROXY usbLibGetDevices: Starting USB device enumeration
66:42:13.639930 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#VID_2109&PID_2812#5&2a753ff6&0&5#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 4
66:42:13.642995 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 13
66:42:13.643072 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 14
66:42:13.643622 USBPROXY usbLibGetDevices: Found 5 USB devices, 0 captured
66:49:54.486945 USBPROXY usbLibGetDevices: Starting USB device enumeration
66:49:54.487583 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#VID_2109&PID_2812#5&2a753ff6&0&5#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 4
66:49:54.490732 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 13
66:49:54.490834 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 14
66:49:54.491372 USBPROXY usbLibGetDevices: Found 5 USB devices, 0 captured
66:49:55.977819 USBPROXY usbLibGetDevices: Starting USB device enumeration
66:49:55.978324 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#VID_2109&PID_2812#5&2a753ff6&0&5#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 4
66:49:55.982389 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 13
66:49:55.982488 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 14
66:49:55.982906 USBPROXY usbLibGetDevices: Found 5 USB devices, 0 captured
66:49:57.418530 USBPROXY usbLibGetDevices: Starting USB device enumeration
66:49:57.419124 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#VID_2109&PID_2812#5&2a753ff6&0&5#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 4
66:49:57.422744 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 13
66:49:57.422808 USBPROXY Getting USB descriptor (id 0) failed (dwErr=31) on hub USB#ROOT_HUB30#4&143f169d&0&0#{f18a0e88-c30c-11d0-8815-00a0c906bed8} port 14
66:49:57.423217 USBPROXY usbLibGetDevices: Found 5 USB devices, 0 captured
66:50:49.992830          ERROR [COM]: aRC=E_FAIL (0x80004005) aIID={e36a5081-a82a-40bd-9e4e-42a44d6ce50f} aComponent={SessionMachine} aText={This machine does not have any snapshots}, preserve=false aResultDetail=0
66:50:50.295410          ERROR [COM]: aRC=VBOX_E_INVALID_OBJECT_STATE (0x80bb0007) aIID={e36a5081-a82a-40bd-9e4e-42a44d6ce50f} aComponent={MachineWrap} aText={Cannot unregister the machine 'boinc_a698867267faa521' while it is locked}, preserve=false aResultDetail=0
66:50:51.548926          ERROR [COM]: aRC=VBOX_E_INVALID_OBJECT_STATE (0x80bb0007) aIID={e36a5081-a82a-40bd-9e4e-42a44d6ce50f} aComponent={MachineWrap} aText={Cannot unregister the machine 'boinc_a698867267faa521' while it is locked}, preserve=false aResultDetail=0
66:50:53.802330          ERROR [COM]: aRC=VBOX_E_INVALID_OBJECT_STATE (0x80bb0007) aIID={e36a5081-a82a-40bd-9e4e-42a44d6ce50f} aComponent={MachineWrap} aText={Cannot unregister the machine 'boinc_a698867267faa521' while it is locked}, preserve=false aResultDetail=0
66:50:58.058241          ERROR [COM]: aRC=VBOX_E_INVALID_OBJECT_STATE (0x80bb0007) aIID={e36a5081-a82a-40bd-9e4e-42a44d6ce50f} aComponent={MachineWrap} aText={Cannot unregister the machine 'boinc_a698867267faa521' while it is locked}, preserve=false aResultDetail=0
66:51:06.314983          ERROR [COM]: aRC=VBOX_E_INVALID_OBJECT_STATE (0x80bb0007) aIID={e36a5081-a82a-40bd-9e4e-42a44d6ce50f} aComponent={MachineWrap} aText={Cannot unregister the machine 'boinc_a698867267faa521' while it is locked}, preserve=false aResultDetail=0
66:51:22.571424          ERROR [COM]: aRC=VBOX_E_INVALID_OBJECT_STATE (0x80bb0007) aIID={e36a5081-a82a-40bd-9e4e-42a44d6ce50f} aComponent={MachineWrap} aText={Cannot unregister the machine 'boinc_a698867267faa521' while it is locked}, preserve=false aResultDetail=0

    VM Execution Log:

00:00:02.189772 VMMDev: Guest Log: CPUID EDX: 0x178bfbff
00:00:02.190204 VMMDev: Guest Log: BIOS: No PCI IDE controller, not probing IDE
00:00:02.190405 AHCI#0: Reset the HBA
00:00:02.190410 VD#0: Cancelling all active requests
00:00:02.190443 AHCI#0: Port 0 reset
00:00:02.190472 VD#0: Cancelling all active requests
00:00:02.191013 VMMDev: Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors
00:00:02.191051 AHCI#0: Port 1 reset
00:00:02.191137 AHCI#0: Port 2 reset
00:00:02.259704 VBoxHeadless: starting event loop
00:00:02.332002 PIT: mode=2 count=0x48d3 (18643) - 64.00 Hz (ch=0)
00:00:02.386681 Display::i_handleDisplayResize: uScreenId=0 pvVRAM=000001b38c1d0000 w=640 h=480 bpp=32 cbLine=0xA00 flags=0x0 origin=0,0
00:00:04.845440 PIT: mode=2 count=0x10000 (65536) - 18.20 Hz (ch=0)
00:00:04.845725 VMMDev: Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032
00:00:04.846269 VMMDev: Guest Log: BIOS: Booting from Hard Disk...
00:00:04.900609 Display::i_handleDisplayResize: uScreenId=0 pvVRAM=0000000000000000 w=720 h=400 bpp=0 cbLine=0x0 flags=0x0 origin=0,0
00:00:04.955673 Display::i_handleDisplayResize: uScreenId=0 pvVRAM=000001b38c1d0000 w=640 h=480 bpp=24 cbLine=0x780 flags=0x0 origin=0,0
00:00:07.050906 VMMDev: Guest Log: BIOS: KBD: unsupported int 16h function 03
00:00:07.051214 VMMDev: Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 
00:00:07.152996 Display::i_handleDisplayResize: uScreenId=0 pvVRAM=0000000000000000 w=720 h=400 bpp=0 cbLine=0x0 flags=0x0 origin=0,0
00:00:07.771420 GIM: KVM: VCPU  0: Enabled system-time struct. at 0x000000013e3f7000 - u32TscScale=0x9a96d751 i8TscShift=-1 uVersion=2 fFlags=0x1 uTsc=0x4534852d9 uVirtNanoTS=0x14e52f8c2 TscKHz=3312002
00:00:07.771492 TM: Switching TSC mode from 'VirtTSCEmulated' to 'RealTSCOffset'
00:00:08.276645 GIM: KVM: Enabled wall-clock struct. at 0x0000000002b40348 - u32Sec=1763213501 u32Nano=793275124 uVersion=2
00:00:08.283364 PIT: mode=2 count=0x4a9 (1193) - 1000.15 Hz (ch=0)
00:00:08.286472 IEM: rdmsr(0x4e) -> #GP(0)
00:00:08.390973 PIT: mode=0 count=0x10000 (65536) - 18.20 Hz (ch=0)
00:00:08.391562 GIM: KVM: VCPU  1: Enabled system-time struct. at 0x000000013e3f7040 - u32TscScale=0x9a96d751 i8TscShift=-1 uVersion=2 fFlags=0x1 uTsc=0x4cdb6cb84 uVirtNanoTS=0x1734a44e8 TscKHz=3312002
00:00:08.391875 IEM: rdmsr(0x4e) -> #GP(0)
00:00:08.394340 GIM: KVM: VCPU  2: Enabled system-time struct. at 0x000000013e3f7080 - u32TscScale=0x9a96d751 i8TscShift=-1 uVersion=2 fFlags=0x1 uTsc=0x4ce436d23 uVirtNanoTS=0x17374baf3 TscKHz=3312002
00:00:08.394638 IEM: rdmsr(0x4e) -> #GP(0)
00:00:08.397075 GIM: KVM: VCPU  3: Enabled system-time struct. at 0x000000013e3f70c0 - u32TscScale=0x9a96d751 i8TscShift=-1 uVersion=2 fFlags=0x1 uTsc=0x4cecd3390 uVirtNanoTS=0x1739e5439 TscKHz=3312002
00:00:08.397368 IEM: rdmsr(0x4e) -> #GP(0)
00:00:09.628117 AHCI#0: Reset the HBA
00:00:09.628150 VD#0: Cancelling all active requests
00:00:09.629132 AHCI#0: Port 0 reset
00:00:09.630680 VD#0: Cancelling all active requests
00:00:09.635621 Display::i_handleDisplayResize: uScreenId=0 pvVRAM=000001b38c1d0000 w=800 h=600 bpp=32 cbLine=0xC80 flags=0x1 origin=0,0
00:00:09.941582 AHCI#0: Port 1 reset
00:00:24.616883 AIOMgr: Async flushes not supported
00:00:26.789869 VMMDev: Guest Additions information report: Version 5.2.6 r120293 '5.2.6'
00:00:26.789935 VMMDev: Guest Additions information report: Interface = 0x00010004 osType = 0x00053100 (Linux >= 2.6, 64-bit)
00:00:26.790121 VMMDev: Guest Additions capability report: (0x0 -> 0x0) seamless: no, hostWindowMapping: no, graphics: no
00:00:26.790290 VMMDev: vmmDevReqHandler_HeartbeatConfigure: No change (fHeartbeatActive=false)
00:00:26.790313 VMMDev: Heartbeat flatline timer set to trigger after 4 000 000 000 ns
00:00:26.790361 VMMDev: Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds
00:00:26.799572 VMMDev: Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)
00:00:27.429049 VMMDev: Guest Additions capability report: (0x0 -> 0x0) seamless: no, hostWindowMapping: no, graphics: no
00:00:27.521726 VMMDev: Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log
00:00:27.521756 VMMDev: Guest Log: 00:00:00.000096 main     Log opened 2025-11-15T13:32:00.957065000Z
00:00:27.521826 VMMDev: Guest Log: 00:00:00.000216 main     OS Product: Linux
00:00:27.521862 VMMDev: Guest Log: 00:00:00.000256 main     OS Release: 4.14.232-19.cernvm.x86_64
00:00:27.521888 VMMDev: Guest Log: 00:00:00.000282 main     OS Version: #1 SMP Fri Apr 30 17:12:25 CEST 2021
00:00:27.521915 VMMDev: Guest Log: 00:00:00.000308 main     Executable: /usr/sbin/VBoxService
00:00:27.521921 VMMDev: Guest Log: 00:00:00.000308 main     Process ID: 2285
00:00:27.521927 VMMDev: Guest Log: 00:00:00.000309 main     Package type: LINUX_64BITS_GENERIC
00:00:27.523031 VMMDev: Guest Log: 00:00:00.001421 main     5.2.6 r120293 started. Verbose level = 0
00:00:43.479475 VMMDev: Guest Log: [INFO] Mounting the shared directory
00:00:43.596320 VMMDev: Guest Log: [INFO] Shared directory mounted, enabling vboxmonitor
00:00:43.717335 VMMDev: Guest Log: [INFO] Sourcing essential functions from /cvmfs/grid.cern.ch
00:00:43.847995 VMMDev: Guest Log: [INFO] Testing connection to cern.ch
00:00:44.033838 VMMDev: Guest Log: [INFO] Testing connection to VCCS
00:00:44.193090 VMMDev: Guest Log: [INFO] Testing connection to HTCondor-Collector
00:00:44.357600 VMMDev: Guest Log: [INFO] Testing connection to HTCondor-CCB
00:00:44.530273 VMMDev: Guest Log: [INFO] Testing connection to WMAgent
00:00:44.688619 VMMDev: Guest Log: [INFO] Testing connection to EOSCMS
00:00:45.121339 VMMDev: Guest Log: [INFO] Testing connection to CMS-Factory
00:00:45.277445 VMMDev: Guest Log: [INFO] Testing connection to CMS-Frontier
00:00:45.484519 VMMDev: Guest Log: [INFO] Testing connection to Frontier
00:00:45.649495 VMMDev: Guest Log: [INFO] Testing connection to http://cms-frontier.openhtc.io:8080/FrontierProd/Frontier/
00:00:46.178815 VMMDev: Guest Log: [INFO] Got a proxy from the local BOINC client
00:00:46.259316 VMMDev: Guest Log: [INFO] Will use it for CVMFS and Frontier
00:00:46.945886 VMMDev: Guest Log: [INFO] Reloading and probing the CVMFS configuration
00:00:52.892886 VMMDev: Guest Log: [INFO] Probing /cvmfs/grid.cern.ch... OK
00:00:55.796568 VMMDev: Guest Log: [INFO] Probing /cvmfs/cms-ib.cern.ch... OK
00:00:55.858340 VMMDev: Guest Log: [INFO] Probing /cvmfs/singularity.opensciencegrid.org... OK
00:00:55.891405 VMMDev: Guest Log: [INFO] Probing /cvmfs/oasis.opensciencegrid.org... OK
00:00:58.510280 VMMDev: Guest Log: [INFO] Probing /cvmfs/cms.cern.ch... OK
00:00:59.148272 VMMDev: Guest Log: [INFO] Excerpt from "cvmfs_config stat": VERSION HOST PROXY
00:00:59.224105 VMMDev: Guest Log: [INFO] 2.7.2.0 http://s1ral-cvmfs.openhtc.io http://192.168.1.130:3128
00:00:59.293404 VMMDev: Guest Log: [INFO] Environment HTTP proxy: http://192.168.1.130:3128
00:00:59.440551 VMMDev: Guest Log: [INFO] Reading volunteer information
00:01:04.181384 VMMDev: Guest Log: [INFO] Requesting an X509 credential from LHC@home
00:01:05.032660 VMMDev: Guest Log: [INFO] Requesting an idtoken from LHC@home
00:01:05.553820 VMMDev: Guest Log: [INFO] CMS application starting. Check log files.
00:23:04.506243 I/O cache: Error while writing entry at offset 8796451328 (86016 bytes) to medium "ahci-0-0" (rc=VERR_NO_MEMORY)
00:23:04.506906 VM: Raising runtime error 'BLKCACHE_IOERR' (fFlags=0x6)
00:23:04.506960 Changing the VM state from 'RUNNING' to 'SUSPENDING'
00:23:04.507047 PDMR3Suspend: after     0 ms, 1 loops: 1 async tasks - ahci/0
00:46:45.934817 Console: Machine state changed to 'Stopping'
00:46:45.935688 Console::powerDown(): A request to power off the VM has been issued (mMachineState=Stopping, InUninit=0)
00:46:46.164364 VRDP: TCP server closed.
00:46:46.164774 PDMR3Suspend: after 1421657 ms, 2 loops: 1 async tasks - ahci/0

    VM Startup Log:


    VM Trace Log:

-q modifyvm "boinc_a698867267faa521" --cable-connected1 on 
Exit Code: 0
Output:

2025-11-15 13:31:26 (25848): 
Command: VBoxManage -q modifyvm "boinc_a698867267faa521" --usb off 
Exit Code: 0
Output:

2025-11-15 13:31:26 (25848): 
Command: VBoxManage -q modifyvm "boinc_a698867267faa521" --uart1 off --uart2 off 
Exit Code: 0
Output:

2025-11-15 13:31:27 (25848): 
Command: VBoxManage -q modifyvm "boinc_a698867267faa521" --lpt1 off --lpt2 off 
Exit Code: 0
Output:

2025-11-15 13:31:27 (25848): 
Command: VBoxManage -q modifyvm "boinc_a698867267faa521" --audio-enabled off 
Exit Code: 0
Output:

2025-11-15 13:31:27 (25848): 
Command: VBoxManage -q modifyvm "boinc_a698867267faa521" --clipboard disabled 
Exit Code: 0
Output:

2025-11-15 13:31:27 (25848): 
Command: VBoxManage -q modifyvm "boinc_a698867267faa521" --draganddrop disabled 
Exit Code: 0
Output:

2025-11-15 13:31:28 (25848): 
Command: VBoxManage -q storagectl "boinc_a698867267faa521" --name "Hard Disk Controller" --add "sata" --controller "IntelAHCI" --hostiocache off --portcount 3
Exit Code: 0
Output:

2025-11-15 13:31:28 (25848): 
Command: VBoxManage -q showhdinfo "D:\BOINC1/projects/lhcathome.cern.ch_lhcathome/CMS_2025_04_08_prod.vdi" 
Exit Code: 0
Output:
UUID:           fa49c4e2-ad29-47a5-b96a-3c89ce80d84c
Parent UUID:    base
State:          locked read
Type:           multiattach
Location:       D:\BOINC1\projects\lhcathome.cern.ch_lhcathome\CMS_2025_04_08_prod.vdi
Storage format: VDI
Format variant: dynamic default
Capacity:       20480 MBytes
Size on disk:   3853 MBytes
Encryption:     disabled
Property:       AllocationBlockSize=1048576
Child UUIDs:    cbe85910-f4a5-49f4-98c7-8dfa530b1991
                b4b6bc47-df42-4774-991d-bc39fac3c058
                05df7225-87d0-4e8b-a3a7-8bb204e30c82
                28e6e343-b7b8-4a37-976b-9ea994ad19ca

2025-11-15 13:31:28 (25848): 
Command: VBoxManage -q storageattach "boinc_a698867267faa521" --storagectl "Hard Disk Controller" --port 0 --device 0 --type hdd --mtype multiattach --medium "D:\BOINC1/projects/lhcathome.cern.ch_lhcathome/CMS_2025_04_08_prod.vdi" 
Exit Code: 0
Output:

2025-11-15 13:31:29 (25848): 
Command: VBoxManage -q storageattach "boinc_a698867267faa521" --storagectl "Hard Disk Controller" --port 1 --device 0 --type dvddrive --medium "C:\Program Files\Oracle\VirtualBox/VBoxGuestAdditions.iso" 
Exit Code: 0
Output:

2025-11-15 13:31:29 (25848): 
Command: VBoxManage -q bandwidthctl "boinc_a698867267faa521" add "boinc_a698867267faa521_net" --type network --limit 1024G 
Exit Code: 0
Output:

2025-11-15 13:31:29 (25848): 
Command: VBoxManage -q modifyvm "boinc_a698867267faa521" --natpf1 ",tcp,127.0.0.1,63907,,80" 
Exit Code: 0
Output:

2025-11-15 13:31:29 (25848): 
Command: VBoxManage -q list extpacks
Exit Code: 0
Output:
Extension Packs: 1
Pack no. 0:   Oracle VirtualBox Extension Pack
Version:        7.1.12
Revision:       169651
Edition:        
Description:    Oracle Cloud Infrastructure integration, Host Webcam, VirtualBox RDP, PXE ROM, Disk Encryption, NVMe, full VM encryption.
VRDE Module:    VBoxVRDP
Crypto Module:  VBoxPuelCrypto
Usable:         true
Why unusable:   

2025-11-15 13:31:30 (25848): 
Command: VBoxManage -q modifyvm "boinc_a698867267faa521" --vrde on --vrdeextpack default --vrdeauthlibrary default --vrdeauthtype null --vrdeport 63908 --vrde-property "Security/Method=RDP" 
Exit Code: 0
Output:

2025-11-15 13:31:30 (25848): 
Command: VBoxManage -q sharedfolder add "boinc_a698867267faa521" --name "shared" --hostpath "D:\BOINC1\slots\4/shared"
Exit Code: 0
Output:

2025-11-15 13:31:35 (25848): 
Command: VBoxManage -q startvm "boinc_a698867267faa521" --type headless
Exit Code: 0
Output:
Waiting for VM "boinc_a698867267faa521" to power on...
VM "boinc_a698867267faa521" has been successfully started.

2025-11-15 13:31:36 (25848): 
Command: VBoxManage -q controlvm "boinc_a698867267faa521" cpuexecutioncap 100 
Exit Code: 0
Output:

2025-11-15 14:19:05 (25848): 
Command: VBoxManage -q controlvm "boinc_a698867267faa521" poweroff
Exit Code: -182
Output:
0%...10%...20%...
2025-11-15 14:19:05 (25848): 
Command: VBoxManage -q snapshot "boinc_a698867267faa521" list 
Exit Code: -108
Output:
This machine does not have any snapshots

2025-11-15 14:19:06 (25848): 
Command: VBoxManage -q bandwidthctl "boinc_a698867267faa521" remove "boinc_a698867267faa521_net" 
Exit Code: 0
Output:
VBoxManage.exe: error: Bandwidth groups cannot be deleted while the VM is running

2025-11-15 14:19:06 (25848): 
Command: VBoxManage -q unregistervm "boinc_a698867267faa521" --delete 
Exit Code: -2135228409
Output:
VBoxManage.exe: error: Cannot unregister the machine 'boinc_a698867267faa521' while it is locked
VBoxManage.exe: error: Details: code VBOX_E_INVALID_OBJECT_STATE (0x80bb0007), component MachineWrap, interface IMachine, callee IUnknown
VBoxManage.exe: error: Context: "Unregister(fDeleteAll ? CleanupMode_DetachAllReturnHardDisksAndVMRemovable :CleanupMode_DetachAllReturnHardDisksOnly, ComSafeArrayAsOutParam(aMedia))" at line 235 of file VBoxManageMisc.cpp

2025-11-15 14:19:07 (25848): 
Command: VBoxManage -q unregistervm "boinc_a698867267faa521" --delete 
Exit Code: -2135228409
Output:
VBoxManage.exe: error: Cannot unregister the machine 'boinc_a698867267faa521' while it is locked
VBoxManage.exe: error: Details: code VBOX_E_INVALID_OBJECT_STATE (0x80bb0007), component MachineWrap, interface IMachine, callee IUnknown
VBoxManage.exe: error: Context: "Unregister(fDeleteAll ? CleanupMode_DetachAllReturnHardDisksAndVMRemovable :CleanupMode_DetachAllReturnHardDisksOnly, ComSafeArrayAsOutParam(aMedia))" at line 235 of file VBoxManageMisc.cpp

2025-11-15 14:19:09 (25848): 
Command: VBoxManage -q unregistervm "boinc_a698867267faa521" --delete 
Exit Code: -2135228409
Output:
VBoxManage.exe: error: Cannot unregister the machine 'boinc_a698867267faa521' while it is locked
VBoxManage.exe: error: Details: code VBOX_E_INVALID_OBJECT_STATE (0x80bb0007), component MachineWrap, interface IMachine, callee IUnknown
VBoxManage.exe: error: Context: "Unregister(fDeleteAll ? CleanupMode_DetachAllReturnHardDisksAndVMRemovable :CleanupMode_DetachAllReturnHardDisksOnly, ComSafeArrayAsOutParam(aMedia))" at line 235 of file VBoxManageMisc.cpp

2025-11-15 14:19:14 (25848): 
Command: VBoxManage -q unregistervm "boinc_a698867267faa521" --delete 
Exit Code: -2135228409
Output:
VBoxManage.exe: error: Cannot unregister the machine 'boinc_a698867267faa521' while it is locked
VBoxManage.exe: error: Details: code VBOX_E_INVALID_OBJECT_STATE (0x80bb0007), component MachineWrap, interface IMachine, callee IUnknown
VBoxManage.exe: error: Context: "Unregister(fDeleteAll ? CleanupMode_DetachAllReturnHardDisksAndVMRemovable :CleanupMode_DetachAllReturnHardDisksOnly, ComSafeArrayAsOutParam(aMedia))" at line 235 of file VBoxManageMisc.cpp

2025-11-15 14:19:22 (25848): 
Command: VBoxManage -q unregistervm "boinc_a698867267faa521" --delete 
Exit Code: -2135228409
Output:
VBoxManage.exe: error: Cannot unregister the machine 'boinc_a698867267faa521' while it is locked
VBoxManage.exe: error: Details: code VBOX_E_INVALID_OBJECT_STATE (0x80bb0007), component MachineWrap, interface IMachine, callee IUnknown
VBoxManage.exe: error: Context: "Unregister(fDeleteAll ? CleanupMode_DetachAllReturnHardDisksAndVMRemovable :CleanupMode_DetachAllReturnHardDisksOnly, ComSafeArrayAsOutParam(aMedia))" at line 235 of file VBoxManageMisc.cpp

2025-11-15 14:19:38 (25848): 
Command: VBoxManage -q unregistervm "boinc_a698867267faa521" --delete 
Exit Code: -2135228409
Output:
VBoxManage.exe: error: Cannot unregister the machine 'boinc_a698867267faa521' while it is locked
VBoxManage.exe: error: Details: code VBOX_E_INVALID_OBJECT_STATE (0x80bb0007), component MachineWrap, interface IMachine, callee IUnknown
VBoxManage.exe: error: Context: "Unregister(fDeleteAll ? CleanupMode_DetachAllReturnHardDisksAndVMRemovable :CleanupMode_DetachAllReturnHardDisksOnly, ComSafeArrayAsOutParam(aMedia))" at line 235 of file VBoxManageMisc.cpp

2025-11-15 14:19:53 (25848): called boinc_finish(-182)

</stderr_txt>
]]>

©2025 CERN