Name CMS_2980052_1753707295.656291_0
Workunit 233845889
Created 28 Jul 2025, 12:54:56 UTC
Sent 28 Jul 2025, 14:54:40 UTC
Report deadline 28 Aug 2025, 14:54:40 UTC
Received 28 Jul 2025, 20:26:08 UTC
Server state Over
Outcome Computation error
Client state Compute error
Exit status -182 (0xFFFFFF4A) ERR_TIMEOUT
Computer ID 10557113
Run time 4 hours 6 min 34 sec
CPU time 8 hours 44 min 45 sec
Validate state Invalid
Credit 0.00
Device peak FLOPS 27.01 GFLOPS
Application version CMS Simulation v70.91 (vbox64_mt_mcore_cms)
windows_x86_64
Peak working set size 92.23 MB
Peak swap size 91.49 MB
Peak disk usage 1.65 GB

Stderr output

<core_client_version>8.0.2</core_client_version>
<![CDATA[
<message>
(unknown error) (317) - exit code 4294967114 (0xffffff4a)</message>
<stderr_txt>
2025-07-29 00:04:41 (16052): vboxwrapper version 26210
2025-07-29 00:04:41 (16052): BOINC client version: 8.0.2
2025-07-29 00:04:42 (16052): Detected: VirtualBox VboxManage Interface (Version: 7.0.6)
2025-07-29 00:04:42 (16052): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2025-07-29 00:04:42 (16052): Successfully copied 'init_data.xml' to the shared directory.
2025-07-29 00:04:42 (16052): Create VM. (boinc_f34c2cb0ed8350b2, slot#5)
2025-07-29 00:04:43 (16052): Setting Memory Size for VM. (4584MB)
2025-07-29 00:04:43 (16052): Setting CPU Count for VM. (4)
2025-07-29 00:04:43 (16052): Setting Chipset Options for VM.
2025-07-29 00:04:44 (16052): Setting Graphics Controller Options for VM. (Driver: VBoxVGA, 16MB)
2025-07-29 00:04:44 (16052): Setting Boot Options for VM.
2025-07-29 00:04:44 (16052): Setting Network Configuration for NAT. (Driver: virtio)
2025-07-29 00:04:45 (16052): Enabling VM Network Access.
2025-07-29 00:04:45 (16052): Disabling USB Support for VM.
2025-07-29 00:04:45 (16052): Disabling COM Port Support for VM.
2025-07-29 00:04:45 (16052): Disabling LPT Port Support for VM.
2025-07-29 00:04:46 (16052): Disabling Audio Support for VM.
2025-07-29 00:04:46 (16052): Disabling Clipboard Support for VM.
2025-07-29 00:04:46 (16052): Disabling Drag and Drop Support for VM.
2025-07-29 00:04:47 (16052): Adding storage controller(s) to VM.
2025-07-29 00:04:47 (16052): Adding virtual disk drive to VM. (CMS_2025_04_08_prod.vdi)
2025-07-29 00:04:49 (16052): Adding VirtualBox Guest Additions to VM.
2025-07-29 00:04:49 (16052): Adding network bandwidth throttle group to VM. (Defaulting to 1024GB)
2025-07-29 00:04:49 (16052): forwarding host port 54225 to guest port 80
2025-07-29 00:04:50 (16052): Enabling remote desktop for VM.
2025-07-29 00:04:50 (16052): Required extension pack not installed, remote desktop not enabled.
2025-07-29 00:04:50 (16052): Enabling shared directory for VM.
2025-07-29 00:04:50 (16052): Starting VM using VBoxManage interface. (boinc_f34c2cb0ed8350b2, slot#5)
2025-07-29 00:04:55 (16052): Successfully started VM. (PID = '17172')
2025-07-29 00:04:55 (16052): Reporting VM Process ID to BOINC.
2025-07-29 00:04:55 (16052): Guest Log: BIOS: VirtualBox 7.0.6
2025-07-29 00:04:55 (16052): Guest Log: CPUID EDX: 0x178bfbff
2025-07-29 00:04:55 (16052): Guest Log: BIOS: No PCI IDE controller, not probing IDE
2025-07-29 00:04:55 (16052): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors
2025-07-29 00:04:55 (16052): VM state change detected. (old = 'poweredoff', new = 'running')
2025-07-29 00:04:55 (16052): Detected: Web Application Enabled (http://localhost:54225)
2025-07-29 00:04:55 (16052): Preference change detected
2025-07-29 00:04:55 (16052): Setting CPU throttle for VM. (90%)
2025-07-29 00:04:56 (16052): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 120 seconds) or (Vbox_job.xml: 600 seconds))
2025-07-29 00:04:57 (16052): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032
2025-07-29 00:04:57 (16052): Guest Log: BIOS: Booting from Hard Disk...
2025-07-29 00:04:59 (16052): Guest Log: BIOS: KBD: unsupported int 16h function 03
2025-07-29 00:04:59 (16052): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 
2025-07-29 00:05:21 (16052): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds
2025-07-29 00:05:21 (16052): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)
2025-07-29 00:05:21 (16052): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log
2025-07-29 00:05:21 (16052): Guest Log: 00:00:00.000046 main     Log opened 2025-07-28T15:05:23.222554000Z
2025-07-29 00:05:21 (16052): Guest Log: 00:00:00.000109 main     OS Product: Linux
2025-07-29 00:05:21 (16052): Guest Log: 00:00:00.000123 main     OS Release: 4.14.232-19.cernvm.x86_64
2025-07-29 00:05:21 (16052): Guest Log: 00:00:00.000134 main     OS Version: #1 SMP Fri Apr 30 17:12:25 CEST 2021
2025-07-29 00:05:21 (16052): Guest Log: 00:00:00.000144 main     Executable: /usr/sbin/VBoxService
2025-07-29 00:05:21 (16052): Guest Log: 00:00:00.000144 main     Process ID: 2293
2025-07-29 00:05:21 (16052): Guest Log: 00:00:00.000145 main     Package type: LINUX_64BITS_GENERIC
2025-07-29 00:05:21 (16052): Guest Log: 00:00:00.000560 main     5.2.6 r120293 started. Verbose level = 0
2025-07-29 00:05:38 (16052): Guest Log: [INFO] Mounting the shared directory
2025-07-29 00:05:38 (16052): Guest Log: [INFO] Shared directory mounted, enabling vboxmonitor
2025-07-29 00:05:38 (16052): Guest Log: [INFO] Sourcing essential functions from /cvmfs/grid.cern.ch
2025-07-29 00:05:39 (16052): Guest Log: [INFO] Testing connection to cern.ch
2025-07-29 00:05:40 (16052): Guest Log: [INFO] Testing connection to VCCS
2025-07-29 00:05:41 (16052): Guest Log: [INFO] Testing connection to HTCondor
2025-07-29 00:05:41 (16052): Guest Log: [INFO] Testing connection to WMAgent
2025-07-29 00:05:42 (16052): Guest Log: [INFO] Testing connection to EOSCMS
2025-07-29 00:05:43 (16052): Guest Log: [INFO] Testing connection to CMS-Factory
2025-07-29 00:05:43 (16052): Guest Log: [INFO] Testing connection to CMS-Frontier
2025-07-29 00:05:44 (16052): Guest Log: [INFO] Testing connection to Frontier
2025-07-29 00:05:44 (16052): Guest Log: [INFO] Testing connection to http://cms-frontier.openhtc.io:8080/FrontierProd/Frontier/
2025-07-29 00:05:46 (16052): Guest Log: [INFO] Could not find a local HTTP proxy
2025-07-29 00:05:46 (16052): Guest Log: [INFO] CVMFS and Frontier will have to use DIRECT connections
2025-07-29 00:05:46 (16052): Guest Log: [INFO] This makes the application less efficient
2025-07-29 00:05:46 (16052): Guest Log: [INFO] It also puts higher load on the project servers
2025-07-29 00:05:46 (16052): Guest Log: [INFO] Setting up a local HTTP proxy is highly recommended
2025-07-29 00:05:46 (16052): Guest Log: [INFO] Advice can be found in the project forum
2025-07-29 00:05:55 (16052): Guest Log: [INFO] Reloading and probing the CVMFS configuration
2025-07-29 00:05:59 (16052): Guest Log: [INFO] Probing /cvmfs/grid.cern.ch... OK
2025-07-29 00:06:01 (16052): Guest Log: [INFO] Probing /cvmfs/cms-ib.cern.ch... OK
2025-07-29 00:06:03 (16052): Guest Log: [INFO] Probing /cvmfs/singularity.opensciencegrid.org... OK
2025-07-29 00:06:04 (16052): Guest Log: [INFO] Probing /cvmfs/oasis.opensciencegrid.org... OK
2025-07-29 00:06:04 (16052): Guest Log: [INFO] Probing /cvmfs/cms.cern.ch... OK
2025-07-29 00:06:05 (16052): Guest Log: [INFO] Excerpt from "cvmfs_config stat": VERSION HOST PROXY
2025-07-29 00:06:05 (16052): Guest Log: [INFO] 2.7.2.0 http://s1swinburne-cvmfs.openhtc.io:8080 DIRECT
2025-07-29 00:06:05 (16052): Guest Log: [INFO] Environment HTTP proxy: not set
2025-07-29 00:06:05 (16052): Guest Log: [INFO] Reading volunteer information
2025-07-29 00:06:43 (16052): Guest Log: [INFO] Requesting an X509 credential from LHC@home
2025-07-29 00:06:45 (16052): Guest Log: [INFO] Requesting an idtoken from LHC@home
2025-07-29 00:06:46 (16052): Guest Log: [INFO] CMS application starting. Check log files.
2025-07-29 01:44:58 (16052): Status Report: Job Duration: '64800.000000'
2025-07-29 01:44:58 (16052): Status Report: Elapsed Time: '6000.000000'
2025-07-29 01:44:58 (16052): Status Report: CPU Time: '417.812500'
2025-07-29 02:20:59 (16052): VM state change detected. (old = 'running', new = 'paused')
2025-07-29 02:23:52 (16052): VM state change detected. (old = 'paused', new = 'running')
2025-07-29 03:27:55 (16052): Status Report: Job Duration: '64800.000000'
2025-07-29 03:27:55 (16052): Status Report: Elapsed Time: '12000.000000'
2025-07-29 03:27:55 (16052): Status Report: CPU Time: '12275.156250'
2025-07-29 04:52:48 (16052): VM state change detected. (old = 'running', new = 'paused')
2025-07-29 04:53:33 (16052): VM state change detected. (old = 'paused', new = 'running')
2025-07-29 05:08:46 (16052): Status Report: Job Duration: '64800.000000'
2025-07-29 05:08:46 (16052): Status Report: Elapsed Time: '18000.003571'
2025-07-29 05:08:46 (16052): Status Report: CPU Time: '31485.812500'
2025-07-29 05:22:06 (16052): VM Heartbeat file specified, but missing heartbeat.
2025-07-29 05:22:06 (16052): Powering off VM.
2025-07-29 05:22:53 (16052): Error in poweroff VM for VM: -182
Command:
VBoxManage -q controlvm "boinc_f34c2cb0ed8350b2" poweroff
Output:
0%...10%...20%...
2025-07-29 05:22:53 (16052): VM did not power off when requested.
2025-07-29 05:22:53 (16052): VM was NOT successfully terminated.
2025-07-29 05:22:53 (16052): Deregistering VM. (boinc_f34c2cb0ed8350b2, slot#5)
2025-07-29 05:22:53 (16052): Removing network bandwidth throttle group from VM.
2025-07-29 05:22:53 (16052): Removing VM from VirtualBox.

    Hypervisor System Log:

05:18:42.815064          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815105          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815110          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815115          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815119          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815123          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815127          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815132          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815136          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815140          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815144          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815148          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815153          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815157          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815161          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815165          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815169          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815174          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815178          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815185          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815190          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815194          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815198          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815203          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815207          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815211          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815215          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815219          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815223          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815227          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815232          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815236          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815240          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815244          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815248          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815253          ERROR [COM]: aRC=E_ACCESSDENIED (0x80070005) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={The object functionality is limited}, preserve=false aResultDetail=0
05:18:42.815390          ERROR [COM]: aRC=VBOX_E_INVALID_OBJECT_STATE (0x80bb0007) aIID={300763af-5d6b-46e6-aa96-273eac15538a} aComponent={MachineWrap} aText={Cannot unregister the machine 'boinc_f34c2cb0ed8350b2' while it is locked}, preserve=false aResultDetail=0

    VM Execution Log:

00:00:06.992897 GIM: KVM: VCPU  1: Enabled system-time struct. at 0x000000013e3f7040 - u32TscScale=0xee6b2803 i8TscShift=-2 uVersion=2 fFlags=0x1 uTsc=0x5a792af04 uVirtNanoTS=0x1510a12ce TscKHz=4294964
00:00:06.995177 GIM: KVM: VCPU  2: Enabled system-time struct. at 0x000000013e3f7080 - u32TscScale=0xee6b2803 i8TscShift=-2 uVersion=2 fFlags=0x1 uTsc=0x5a82f75a8 uVirtNanoTS=0x1512e9361 TscKHz=4294964
00:00:06.997457 GIM: KVM: VCPU  3: Enabled system-time struct. at 0x000000013e3f70c0 - u32TscScale=0xee6b2803 i8TscShift=-2 uVersion=2 fFlags=0x1 uTsc=0x5a8cc2b3e uVirtNanoTS=0x151530ffb TscKHz=4294964
00:00:07.747659 AHCI#0: Reset the HBA
00:00:07.747686 VD#0: Cancelling all active requests
00:00:07.749240 AHCI#0: Port 0 reset
00:00:07.750284 VD#0: Cancelling all active requests
00:00:07.752283 Display::i_handleDisplayResize: uScreenId=0 pvVRAM=000002602da30000 w=800 h=600 bpp=32 cbLine=0xC80 flags=0x1 origin=0,0
00:00:08.052992 AHCI#0: Port 1 reset
00:00:23.037652 NAT: IPv6 not supported
00:00:23.343299 NAT: DHCP offered IP address 10.0.2.15
00:00:23.371001 NAT: DHCP offered IP address 10.0.2.15
00:00:23.438319 AIOMgr: Async flushes not supported
00:00:27.425485 VMMDev: Guest Additions information report: Version 5.2.6 r120293 '5.2.6'
00:00:27.425520 VMMDev: Guest Additions information report: Interface = 0x00010004 osType = 0x00053100 (Linux >= 2.6, 64-bit)
00:00:27.425589 VMMDev: Guest Additions capability report: (0x0 -> 0x0) seamless: no, hostWindowMapping: no, graphics: no
00:00:27.425629 VMMDev: vmmDevReqHandler_HeartbeatConfigure: No change (fHeartbeatActive=false)
00:00:27.425637 VMMDev: Heartbeat flatline timer set to trigger after 4 000 000 000 ns
00:00:27.425659 VMMDev: Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds
00:00:27.425882 VMMDev: Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)
00:00:28.102758 VMMDev: Guest Additions capability report: (0x0 -> 0x0) seamless: no, hostWindowMapping: no, graphics: no
00:00:28.132954 VMMDev: Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log
00:00:28.132971 VMMDev: Guest Log: 00:00:00.000046 main     Log opened 2025-07-28T15:05:23.222554000Z
00:00:28.133002 VMMDev: Guest Log: 00:00:00.000109 main     OS Product: Linux
00:00:28.133014 VMMDev: Guest Log: 00:00:00.000123 main     OS Release: 4.14.232-19.cernvm.x86_64
00:00:28.133025 VMMDev: Guest Log: 00:00:00.000134 main     OS Version: #1 SMP Fri Apr 30 17:12:25 CEST 2021
00:00:28.133036 VMMDev: Guest Log: 00:00:00.000144 main     Executable: /usr/sbin/VBoxService
00:00:28.133039 VMMDev: Guest Log: 00:00:00.000144 main     Process ID: 2293
00:00:28.133042 VMMDev: Guest Log: 00:00:00.000145 main     Package type: LINUX_64BITS_GENERIC
00:00:28.133434 VMMDev: Guest Log: 00:00:00.000560 main     5.2.6 r120293 started. Verbose level = 0
00:00:28.626142 NAT: DHCP offered IP address 10.0.2.15
00:00:28.626265 NAT: DHCP offered IP address 10.0.2.15
00:00:45.155662 VMMDev: Guest Log: [INFO] Mounting the shared directory
00:00:45.197577 VMMDev: Guest Log: [INFO] Shared directory mounted, enabling vboxmonitor
00:00:45.246548 VMMDev: Guest Log: [INFO] Sourcing essential functions from /cvmfs/grid.cern.ch
00:00:46.195322 VMMDev: Guest Log: [INFO] Testing connection to cern.ch
00:00:46.827209 VMMDev: Guest Log: [INFO] Testing connection to VCCS
00:00:47.439752 VMMDev: Guest Log: [INFO] Testing connection to HTCondor
00:00:48.065663 VMMDev: Guest Log: [INFO] Testing connection to WMAgent
00:00:48.693255 VMMDev: Guest Log: [INFO] Testing connection to EOSCMS
00:00:49.564420 VMMDev: Guest Log: [INFO] Testing connection to CMS-Factory
00:00:50.182281 VMMDev: Guest Log: [INFO] Testing connection to CMS-Frontier
00:00:51.075134 VMMDev: Guest Log: [INFO] Testing connection to Frontier
00:00:51.148881 VMMDev: Guest Log: [INFO] Testing connection to http://cms-frontier.openhtc.io:8080/FrontierProd/Frontier/
00:00:52.569571 VMMDev: Guest Log: [INFO] Could not find a local HTTP proxy
00:00:52.602112 VMMDev: Guest Log: [INFO] CVMFS and Frontier will have to use DIRECT connections
00:00:52.633851 VMMDev: Guest Log: [INFO] This makes the application less efficient
00:00:52.667971 VMMDev: Guest Log: [INFO] It also puts higher load on the project servers
00:00:52.701566 VMMDev: Guest Log: [INFO] Setting up a local HTTP proxy is highly recommended
00:00:52.738078 VMMDev: Guest Log: [INFO] Advice can be found in the project forum
00:01:01.935971 VMMDev: Guest Log: [INFO] Reloading and probing the CVMFS configuration
00:01:06.151516 VMMDev: Guest Log: [INFO] Probing /cvmfs/grid.cern.ch... OK
00:01:08.059660 VMMDev: Guest Log: [INFO] Probing /cvmfs/cms-ib.cern.ch... OK
00:01:10.358032 VMMDev: Guest Log: [INFO] Probing /cvmfs/singularity.opensciencegrid.org... OK
00:01:10.509348 VMMDev: Guest Log: [INFO] Probing /cvmfs/oasis.opensciencegrid.org... OK
00:01:11.151833 VMMDev: Guest Log: [INFO] Probing /cvmfs/cms.cern.ch... OK
00:01:11.424735 VMMDev: Guest Log: [INFO] Excerpt from "cvmfs_config stat": VERSION HOST PROXY
00:01:11.457557 VMMDev: Guest Log: [INFO] 2.7.2.0 http://s1swinburne-cvmfs.openhtc.io:8080 DIRECT
00:01:11.494047 VMMDev: Guest Log: [INFO] Environment HTTP proxy: not set
00:01:11.566799 VMMDev: Guest Log: [INFO] Reading volunteer information
00:01:50.108779 VMMDev: Guest Log: [INFO] Requesting an X509 credential from LHC@home
00:01:51.681274 VMMDev: Guest Log: [INFO] Requesting an idtoken from LHC@home
00:01:53.059494 VMMDev: Guest Log: [INFO] CMS application starting. Check log files.
02:16:05.490414 Changing the VM state from 'RUNNING' to 'SUSPENDING'
02:16:05.492965 AIOMgr: Endpoint for file 'C:\ProgramData\BOINC\slots\5\boinc_f34c2cb0ed8350b2\Snapshots\{d98fe675-7fb8-4d2e-af1f-7ce893efbb32}.vdi' (flags 000c0781) created successfully
02:16:05.493774 PDMR3Suspend: 3 185 353 ns run time
02:16:05.493783 Changing the VM state from 'SUSPENDING' to 'SUSPENDED'
02:16:05.493789 Console: Machine state changed to 'Paused'
02:18:57.620350 Changing the VM state from 'SUSPENDED' to 'RESUMING'
02:18:57.620826 AIOMgr: Endpoint for file 'C:\ProgramData\BOINC\slots\5\boinc_f34c2cb0ed8350b2\Snapshots\{d98fe675-7fb8-4d2e-af1f-7ce893efbb32}.vdi' (flags 000c0723) created successfully
02:18:57.628808 Changing the VM state from 'RESUMING' to 'RUNNING'
02:18:57.628820 Console: Machine state changed to 'Running'
02:19:00.378443 AIOMgr: Async flushes not supported
04:47:54.467873 Changing the VM state from 'RUNNING' to 'SUSPENDING'
04:47:54.468701 AIOMgr: Endpoint for file 'C:\ProgramData\BOINC\slots\5\boinc_f34c2cb0ed8350b2\Snapshots\{d98fe675-7fb8-4d2e-af1f-7ce893efbb32}.vdi' (flags 000c0781) created successfully
04:47:54.469607 PDMR3Suspend: 1 663 605 ns run time
04:47:54.469617 Changing the VM state from 'SUSPENDING' to 'SUSPENDED'
04:47:54.469624 Console: Machine state changed to 'Paused'
04:48:39.477230 Changing the VM state from 'SUSPENDED' to 'RESUMING'
04:48:39.477683 AIOMgr: Endpoint for file 'C:\ProgramData\BOINC\slots\5\boinc_f34c2cb0ed8350b2\Snapshots\{d98fe675-7fb8-4d2e-af1f-7ce893efbb32}.vdi' (flags 000c0723) created successfully
04:48:39.485679 Changing the VM state from 'RESUMING' to 'RUNNING'
04:48:39.485696 Console: Machine state changed to 'Running'
04:48:43.357236 AIOMgr: Async flushes not supported
04:54:49.608260 I/O cache: Error while writing entry at offset 12682453504 (303104 bytes) to medium "ahci-0-0" (rc=VERR_NO_MEMORY)
04:54:49.608389 VM: Raising runtime error 'BLKCACHE_IOERR' (fFlags=0x6)
04:54:49.608412 Changing the VM state from 'RUNNING' to 'SUSPENDING'
04:54:49.608450 PDMR3Suspend: after     0 ms, 1 loops: 1 async tasks - ahci/0
04:54:50.609941 PDMR3Suspend: after  1001 ms, 10 loops: 1 async tasks - ahci/0
05:17:11.825771 Console: Machine state changed to 'Stopping'
05:17:11.828080 Console::powerDown(): A request to power off the VM has been issued (mMachineState=Stopping, InUninit=0)
05:17:11.829622 PDMR3Suspend: after 1342221 ms, 11 loops: 1 async tasks - ahci/0

    VM Startup Log:


    VM Trace Log:

ontext: "AttachDevice(Bstr(pszCtl).raw(), port, device, DeviceType_HardDisk, pMedium2Mount)" at line 785 of file VBoxManageStorageController.cpp

2025-07-29 00:04:48 (16052): 
Command: VBoxManage -q showhdinfo "C:\ProgramData\BOINC/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:          created
Type:           multiattach
Location:       C:\ProgramData\BOINC\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

2025-07-29 00:04:48 (16052): 
Command: VBoxManage -q closemedium disk "C:\ProgramData\BOINC\projects\lhcathome.cern.ch_lhcathome\CMS_2025_04_08_prod.vdi" 
Exit Code: 0
Output:

2025-07-29 00:04:48 (16052): 
Command: VBoxManage -q showhdinfo "C:\ProgramData\BOINC/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:          created
Type:           normal (base)
Location:       C:\ProgramData\BOINC\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

2025-07-29 00:04:48 (16052): 
Command: VBoxManage -q storageattach "boinc_f34c2cb0ed8350b2" --storagectl "Hard Disk Controller" --port 0 --device 0 --type hdd --medium "C:\ProgramData\BOINC/projects/lhcathome.cern.ch_lhcathome/CMS_2025_04_08_prod.vdi" 
Exit Code: 0
Output:

2025-07-29 00:04:49 (16052): 
Command: VBoxManage -q storageattach "boinc_f34c2cb0ed8350b2" --storagectl "Hard Disk Controller" --port 0 --device 0 --type hdd --medium none 
Exit Code: 0
Output:

2025-07-29 00:04:49 (16052): 
Command: VBoxManage -q storageattach "boinc_f34c2cb0ed8350b2" --storagectl "Hard Disk Controller" --port 0 --device 0 --type hdd --mtype multiattach --medium "C:\ProgramData\BOINC/projects/lhcathome.cern.ch_lhcathome/CMS_2025_04_08_prod.vdi" 
Exit Code: 0
Output:

2025-07-29 00:04:49 (16052): 
Command: VBoxManage -q storageattach "boinc_f34c2cb0ed8350b2" --storagectl "Hard Disk Controller" --port 1 --device 0 --type dvddrive --medium "C:\Program Files\Oracle\VirtualBox/VBoxGuestAdditions.iso" 
Exit Code: 0
Output:

2025-07-29 00:04:49 (16052): 
Command: VBoxManage -q bandwidthctl "boinc_f34c2cb0ed8350b2" add "boinc_f34c2cb0ed8350b2_net" --type network --limit 1024G 
Exit Code: 0
Output:

2025-07-29 00:04:50 (16052): 
Command: VBoxManage -q modifyvm "boinc_f34c2cb0ed8350b2" --natpf1 ",tcp,127.0.0.1,54225,,80" 
Exit Code: 0
Output:

2025-07-29 00:04:50 (16052): 
Command: VBoxManage -q list extpacks
Exit Code: 0
Output:
Extension Packs: 0

2025-07-29 00:04:50 (16052): 
Command: VBoxManage -q sharedfolder add "boinc_f34c2cb0ed8350b2" --name "shared" --hostpath "C:\ProgramData\BOINC\slots\5/shared"
Exit Code: 0
Output:

2025-07-29 00:04:54 (16052): 
Command: VBoxManage -q startvm "boinc_f34c2cb0ed8350b2" --type headless
Exit Code: 0
Output:
Waiting for VM "boinc_f34c2cb0ed8350b2" to power on...
VM "boinc_f34c2cb0ed8350b2" has been successfully started.

2025-07-29 00:04:56 (16052): 
Command: VBoxManage -q controlvm "boinc_f34c2cb0ed8350b2" cpuexecutioncap 90 
Exit Code: 0
Output:

2025-07-29 02:20:59 (16052): 
Command: VBoxManage -q controlvm "boinc_f34c2cb0ed8350b2" pause
Exit Code: 0
Output:

2025-07-29 02:23:51 (16052): 
Command: VBoxManage -q controlvm "boinc_f34c2cb0ed8350b2" resume
Exit Code: 0
Output:

2025-07-29 04:52:48 (16052): 
Command: VBoxManage -q controlvm "boinc_f34c2cb0ed8350b2" pause
Exit Code: 0
Output:

2025-07-29 04:53:33 (16052): 
Command: VBoxManage -q controlvm "boinc_f34c2cb0ed8350b2" resume
Exit Code: 0
Output:

2025-07-29 05:22:53 (16052): 
Command: VBoxManage -q controlvm "boinc_f34c2cb0ed8350b2" poweroff
Exit Code: -182
Output:
0%...10%...20%...
2025-07-29 05:22:53 (16052): 
Command: VBoxManage -q snapshot "boinc_f34c2cb0ed8350b2" list 
Exit Code: -108
Output:
This machine does not have any snapshots

2025-07-29 05:22:53 (16052): 
Command: VBoxManage -q bandwidthctl "boinc_f34c2cb0ed8350b2" remove "boinc_f34c2cb0ed8350b2_net" 
Exit Code: 0
Output:
VBoxManage.exe: error: Bandwidth groups cannot be deleted while the VM is running

2025-07-29 05:22:53 (16052): 
Command: VBoxManage -q unregistervm "boinc_f34c2cb0ed8350b2" --delete 
Exit Code: -2135228409
Output:
VBoxManage.exe: error: Cannot unregister the machine 'boinc_f34c2cb0ed8350b2' 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 236 of file VBoxManageMisc.cpp

2025-07-29 05:22:54 (16052): 
Command: VBoxManage -q unregistervm "boinc_f34c2cb0ed8350b2" --delete 
Exit Code: -2135228409
Output:
VBoxManage.exe: error: Cannot unregister the machine 'boinc_f34c2cb0ed8350b2' 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 236 of file VBoxManageMisc.cpp

2025-07-29 05:22:57 (16052): 
Command: VBoxManage -q unregistervm "boinc_f34c2cb0ed8350b2" --delete 
Exit Code: -2135228409
Output:
VBoxManage.exe: error: Cannot unregister the machine 'boinc_f34c2cb0ed8350b2' 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 236 of file VBoxManageMisc.cpp

2025-07-29 05:23:01 (16052): 
Command: VBoxManage -q unregistervm "boinc_f34c2cb0ed8350b2" --delete 
Exit Code: -2135228409
Output:
VBoxManage.exe: error: Cannot unregister the machine 'boinc_f34c2cb0ed8350b2' 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 236 of file VBoxManageMisc.cpp

2025-07-29 05:23:09 (16052): 
Command: VBoxManage -q unregistervm "boinc_f34c2cb0ed8350b2" --delete 
Exit Code: -2135228409
Output:
VBoxManage.exe: error: Cannot unregister the machine 'boinc_f34c2cb0ed8350b2' 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 236 of file VBoxManageMisc.cpp

2025-07-29 05:23:26 (16052): 
Command: VBoxManage -q unregistervm "boinc_f34c2cb0ed8350b2" --delete 
Exit Code: -2135228409
Output:
VBoxManage.exe: error: Cannot unregister the machine 'boinc_f34c2cb0ed8350b2' 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 236 of file VBoxManageMisc.cpp

2025-07-29 05:23:41 (16052): called boinc_finish(-182)

</stderr_txt>
]]>


©2025 CERN