Stderr output

<core_client_version>8.0.2</core_client_version>
<![CDATA[
<stderr_txt>
 = 'paused', new = 'running')
2025-03-13 17:19:16 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:19:36 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:19:46 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:20:06 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:20:16 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:20:36 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:20:46 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:21:06 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:21:16 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:21:36 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:21:46 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:22:06 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:22:16 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:22:36 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:22:46 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:23:06 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:23:16 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:23:36 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:23:46 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:24:06 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:24:16 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:24:36 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:24:46 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:25:06 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:25:16 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:25:36 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:25:47 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:26:07 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:26:17 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:26:37 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:26:47 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:27:07 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:27:17 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:27:37 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:27:47 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:28:07 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:28:17 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:28:37 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:28:47 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:29:07 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:29:16 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:29:36 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:29:46 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:30:07 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:30:16 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:30:36 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:30:46 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:31:07 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:31:16 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:31:36 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:31:47 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:32:08 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:32:17 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:32:37 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:32:47 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:33:08 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:33:17 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:33:37 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:33:47 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:34:08 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 17:42:37 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 17:42:44 (16804): Error in resume VM for VM: -182
Command:
VBoxManage -q controlvm "boinc_ee2e428a927b5094" resume
Output:
VBoxManage.exe: error: VM is paused due to host power management
VBoxManage.exe: error: Details: code VBOX_E_INVALID_VM_STATE (0x80bb0002), component ConsoleWrap, interface IConsole, callee IUnknown
VBoxManage.exe: error: Context: "Resume()" at line 395 of file VBoxManageControlVM.cpp

2025-03-13 19:09:03 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 19:09:07 (16804): Guest Log: 01:21:45.278242 timesync vgsvcTimeSyncWorker: Radical host time change: 5 195 076 000 000ns (HostNow=1 741 864 146 245 000 000 ns HostLast=1 741 858 951 169 000 000 ns)
2025-03-13 19:09:14 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 19:09:34 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 19:09:37 (16804): Guest Log: 01:21:55.279758 timesync vgsvcTimeSyncWorker: Radical guest time change: 6 367 286 082 000ns (GuestNow=1 741 864 156 255 947 000 ns GuestLast=1 741 857 788 969 865 000 ns fSetTimeLastLoop=true )
2025-03-13 19:15:14 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 19:15:34 (16804): VM state change detected. (old = 'paused', new = 'running')
2025-03-13 19:15:41 (16804): VM state change detected. (old = 'running', new = 'paused')
2025-03-13 22:36:01 (16804): Stopping VM.
2025-03-13 22:36:01 (16804): Error in stop VM for VM: -108
Command:
VBoxManage -q controlvm "boinc_ee2e428a927b5094" savestate
Output:

2025-03-13 22:36:01 (16804): VM did not stop when requested.
2025-03-13 22:36:01 (16804): VM was NOT successfully terminated.
2025-03-14 12:49:15 (7160): vboxwrapper version 26208
2025-03-14 12:49:15 (7160): BOINC client version: 8.0.2
2025-03-14 12:49:15 (7160): Detected: VirtualBox VboxManage Interface (Version: 7.0.6)
2025-03-14 12:49:15 (7160): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2025-03-14 12:49:16 (7160): Guest Log: BIOS: VirtualBox 7.0.6
2025-03-14 12:49:16 (7160): Guest Log: CPUID EDX: 0x178bfbff
2025-03-14 12:49:16 (7160): Guest Log: BIOS: No PCI IDE controller, not probing IDE
2025-03-14 12:49:16 (7160): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors
2025-03-14 12:49:16 (7160): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032
2025-03-14 12:49:16 (7160): Guest Log: BIOS: Booting from Hard Disk...
2025-03-14 12:49:16 (7160): Guest Log: BIOS: KBD: unsupported int 16h function 03
2025-03-14 12:49:16 (7160): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 
2025-03-14 12:49:16 (7160): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds
2025-03-14 12:49:16 (7160): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)
2025-03-14 12:49:16 (7160): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log
2025-03-14 12:49:16 (7160): Guest Log: 00:00:00.000065 main     Log opened 2025-03-13T07:20:51.907812000Z
2025-03-14 12:49:16 (7160): Guest Log: 00:00:00.000119 main     OS Product: Linux
2025-03-14 12:49:16 (7160): Guest Log: 00:00:00.000139 main     OS Release: 4.14.232-19.cernvm.x86_64
2025-03-14 12:49:16 (7160): Guest Log: 00:00:00.000156 main     OS Version: #1 SMP Fri Apr 30 17:12:25 CEST 2021
2025-03-14 12:49:16 (7160): Guest Log: 00:00:00.000193 main     Executable: /usr/sbin/VBoxService
2025-03-14 12:49:16 (7160): Guest Log: 00:00:00.000193 main     Process ID: 2286
2025-03-14 12:49:16 (7160): Guest Log: 00:00:00.000194 main     Package type: LINUX_64BITS_GENERIC
2025-03-14 12:49:16 (7160): Guest Log: 00:00:00.001964 main     5.2.6 r120293 started. Verbose level = 0
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Mounting the shared directory
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Shared directory mounted, enabling vboxmonitor
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Sourcing essential functions from /cvmfs/grid.cern.ch
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Testing connection to cern.ch
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Testing connection to VCCS
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Testing connection to HTCondor
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Testing connection to WMAgent
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Testing connection to EOSCMS
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Testing connection to CMS-Factory
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Testing connection to CMS-Frontier
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Testing connection to Frontier
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Could not find a local HTTP proxy
2025-03-14 12:49:16 (7160): Guest Log: [INFO] CVMFS and Frontier will have to use DIRECT connections
2025-03-14 12:49:16 (7160): Guest Log: [INFO] This makes the application less efficient
2025-03-14 12:49:16 (7160): Guest Log: [INFO] It also puts higher load on the project servers
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Setting up a local HTTP proxy is highly recommended
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Advice can be found in the project forum
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Reloading and probing the CVMFS configuration
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Probing /cvmfs/grid.cern.ch... OK
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Probing /cvmfs/cms.cern.ch... OK
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Probing /cvmfs/cms-ib.cern.ch... OK
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Probing /cvmfs/singularity.opensciencegrid.org... OK
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Probing /cvmfs/oasis.opensciencegrid.org... OK
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Excerpt from "cvmfs_config stat": VERSION HOST PROXY
2025-03-14 12:49:16 (7160): Guest Log: [INFO] 2.7.2.0 http://s1sampa-cvmfs.openhtc.io:8080 DIRECT
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Environment HTTP proxy: not set
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Reading volunteer information
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Requesting an X509 credential from LHC@home
2025-03-14 12:49:16 (7160): Guest Log: [INFO] Requesting an idtoken from LHC@home
2025-03-14 12:49:16 (7160): Guest Log: [INFO] CMS application starting. Check log files.
2025-03-14 12:49:16 (7160): Guest Log: 01:21:45.278242 timesync vgsvcTimeSyncWorker: Radical host time change: 5 195 076 000 000ns (HostNow=1 741 864 146 245 000 000 ns HostLast=1 741 858 951 169 000 000 ns)
2025-03-14 12:49:16 (7160): Guest Log: 01:21:55.279758 timesync vgsvcTimeSyncWorker: Radical guest time change: 6 367 286 082 000ns (GuestNow=1 741 864 156 255 947 000 ns GuestLast=1 741 857 788 969 865 000 ns fSetTimeLastLoop=true )
2025-03-14 12:49:16 (7160): Starting VM using VBoxManage interface. (boinc_ee2e428a927b5094, slot#0)
2025-03-14 12:49:22 (7160): Successfully started VM. (PID = '18668')
2025-03-14 12:49:22 (7160): Reporting VM Process ID to BOINC.
2025-03-14 12:49:22 (7160): Guest Log: BIOS: VirtualBox 7.0.6
2025-03-14 12:49:22 (7160): Guest Log: CPUID EDX: 0x178bfbff
2025-03-14 12:49:22 (7160): Guest Log: BIOS: No PCI IDE controller, not probing IDE
2025-03-14 12:49:22 (7160): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors
2025-03-14 12:49:22 (7160): VM state change detected. (old = 'poweredoff', new = 'running')
2025-03-14 12:49:22 (7160): Detected: Web Application Enabled (http://localhost:64970)
2025-03-14 12:49:22 (7160): Preference change detected
2025-03-14 12:49:22 (7160): Setting CPU throttle for VM. (98%)
2025-03-14 12:49:22 (7160): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 180 seconds) or (Vbox_job.xml: 600 seconds))
2025-03-14 12:49:24 (7160): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032
2025-03-14 12:49:24 (7160): Guest Log: BIOS: Booting from Hard Disk...
2025-03-14 12:49:25 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 12:49:45 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 12:49:46 (7160): Guest Log: BIOS: KBD: unsupported int 16h function 03
2025-03-14 12:49:46 (7160): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 
2025-03-14 12:50:05 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 12:50:25 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 12:50:40 (7160): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds
2025-03-14 12:50:40 (7160): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)
2025-03-14 12:50:41 (7160): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log
2025-03-14 12:50:41 (7160): Guest Log: 00:00:00.000063 main     Log opened 2025-03-14T04:50:40.211433000Z
2025-03-14 12:50:41 (7160): Guest Log: 00:00:00.000127 main     OS Product: Linux
2025-03-14 12:50:41 (7160): Guest Log: 00:00:00.000151 main     OS Release: 4.14.232-19.cernvm.x86_64
2025-03-14 12:50:41 (7160): Guest Log: 00:00:00.000169 main     OS Version: #1 SMP Fri Apr 30 17:12:25 CEST 2021
2025-03-14 12:50:41 (7160): Guest Log: 00:00:00.000191 main     Executable: /usr/sbin/VBoxService
2025-03-14 12:50:41 (7160): Guest Log: 00:00:00.000191 main     Process ID: 2288
2025-03-14 12:50:41 (7160): Guest Log: 00:00:00.000192 main     Package type: LINUX_64BITS_GENERIC
2025-03-14 12:50:41 (7160): Guest Log: 00:00:00.000615 main     5.2.6 r120293 started. Verbose level = 0
2025-03-14 12:51:07 (7160): Guest Log: [INFO] Mounting the shared directory
2025-03-14 12:51:07 (7160): Guest Log: [INFO] Shared directory mounted, enabling vboxmonitor
2025-03-14 12:51:07 (7160): Guest Log: [INFO] Sourcing essential functions from /cvmfs/grid.cern.ch
2025-03-14 12:51:07 (7160): Guest Log: [INFO] Testing connection to cern.ch
2025-03-14 12:51:07 (7160): Guest Log: [INFO] Testing connection to VCCS
2025-03-14 12:51:08 (7160): Guest Log: [INFO] Testing connection to HTCondor
2025-03-14 12:51:09 (7160): Guest Log: [INFO] Testing connection to WMAgent
2025-03-14 12:51:09 (7160): Guest Log: [INFO] Testing connection to EOSCMS
2025-03-14 12:51:10 (7160): Guest Log: [INFO] Testing connection to CMS-Factory
2025-03-14 12:51:10 (7160): Guest Log: [INFO] Testing connection to CMS-Frontier
2025-03-14 12:51:11 (7160): Guest Log: [INFO] Testing connection to Frontier
2025-03-14 12:51:13 (7160): Guest Log: [INFO] Could not find a local HTTP proxy
2025-03-14 12:51:13 (7160): Guest Log: [INFO] CVMFS and Frontier will have to use DIRECT connections
2025-03-14 12:51:13 (7160): Guest Log: [INFO] This makes the application less efficient
2025-03-14 12:51:13 (7160): Guest Log: [INFO] It also puts higher load on the project servers
2025-03-14 12:51:13 (7160): Guest Log: [INFO] Setting up a local HTTP proxy is highly recommended
2025-03-14 12:51:13 (7160): Guest Log: [INFO] Advice can be found in the project forum
2025-03-14 12:51:13 (7160): Guest Log: [INFO] Reloading and probing the CVMFS configuration
2025-03-14 12:51:20 (7160): Guest Log: [INFO] Probing /cvmfs/grid.cern.ch... OK
2025-03-14 12:51:23 (7160): Guest Log: [INFO] Probing /cvmfs/cms.cern.ch... OK
2025-03-14 12:51:24 (7160): Guest Log: [INFO] Probing /cvmfs/oasis.opensciencegrid.org... OK
2025-03-14 12:51:25 (7160): Guest Log: [INFO] Probing /cvmfs/cms-ib.cern.ch... OK
2025-03-14 12:51:25 (7160): Guest Log: [INFO] Probing /cvmfs/singularity.opensciencegrid.org... OK
2025-03-14 12:51:26 (7160): Guest Log: [INFO] Excerpt from "cvmfs_config stat": VERSION HOST PROXY
2025-03-14 12:51:26 (7160): Guest Log: [INFO] 2.7.2.0 http://s1ral-cvmfs.openhtc.io DIRECT
2025-03-14 12:51:26 (7160): Guest Log: [INFO] Environment HTTP proxy: not set
2025-03-14 12:51:26 (7160): Guest Log: [INFO] Reading volunteer information
2025-03-14 12:51:41 (7160): Guest Log: [INFO] Requesting an X509 credential from LHC@home
2025-03-14 12:51:43 (7160): Guest Log: [INFO] Requesting an idtoken from LHC@home
2025-03-14 12:51:44 (7160): Guest Log: [INFO] CMS application starting. Check log files.
2025-03-14 12:52:46 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 12:53:06 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 12:54:36 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 12:54:56 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 13:06:08 (7160): Status Report: Job Duration: '64800.000000'
2025-03-14 13:06:08 (7160): Status Report: Elapsed Time: '6000.000000'
2025-03-14 13:06:08 (7160): Status Report: CPU Time: '7447.265625'
2025-03-14 13:08:58 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 13:09:18 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 13:09:28 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 14:09:37 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 14:09:40 (7160): Guest Log: 00:17:52.312005 timesync vgsvcTimeSyncWorker: Radical host time change: 3 617 730 000 000ns (HostNow=1 741 932 579 928 000 000 ns HostLast=1 741 928 962 198 000 000 ns)
2025-03-14 14:09:50 (7160): Guest Log: 00:18:02.331139 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 677 423 993 000ns (GuestNow=1 741 932 589 947 239 000 ns GuestLast=1 741 928 912 523 246 000 ns fSetTimeLastLoop=true )
2025-03-14 14:09:51 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 14:10:11 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 14:10:51 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 14:11:11 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 14:11:41 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 14:12:01 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 14:17:42 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 14:18:02 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 14:20:13 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 14:20:33 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:10:25 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:10:26 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:13:46 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:14:06 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:27:19 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:27:39 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:27:59 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:28:19 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:30:00 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:30:20 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:31:10 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:31:30 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:32:20 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:32:40 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:35:21 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:35:41 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:36:11 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:36:31 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:37:02 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:37:22 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:45:54 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:46:14 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:46:34 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:46:54 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:47:44 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:48:04 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:48:34 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:48:54 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:53:06 (7160): Status Report: Job Duration: '64800.000000'
2025-03-14 15:53:06 (7160): Status Report: Elapsed Time: '12000.000000'
2025-03-14 15:53:06 (7160): Status Report: CPU Time: '17835.203125'
2025-03-14 15:54:16 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:54:37 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:54:56 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:55:16 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:55:36 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:55:56 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:56:06 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:56:26 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:56:36 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:56:56 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:57:06 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:57:26 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:57:46 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:58:06 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:58:16 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:58:36 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:58:46 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:59:06 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:59:15 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 15:59:35 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 15:59:46 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 16:00:07 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 16:00:16 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 16:00:36 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 16:00:46 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 16:01:07 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 16:01:16 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 16:01:36 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 16:01:46 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 16:02:07 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 16:02:16 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 16:02:36 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 16:02:46 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 16:03:07 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 16:03:26 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 16:03:46 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 16:03:56 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 16:04:17 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 16:04:36 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 16:04:56 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 16:05:06 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 16:05:27 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 16:05:36 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 16:05:56 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 16:06:06 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 16:06:26 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 16:06:36 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 16:06:56 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 16:07:06 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 16:07:27 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 16:07:37 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 16:07:57 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 16:08:07 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 16:08:08 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 17:04:52 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 17:05:12 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 17:09:23 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 17:09:43 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 17:10:03 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 17:10:23 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 17:13:09 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:13:56 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:14:02 (7160): Guest Log: 03:05:49.597901 timesync vgsvcTimeSyncWorker: Radical host time change: 3 657 261 000 000ns (HostNow=1 741 947 242 065 000 000 ns HostLast=1 741 943 584 804 000 000 ns)
2025-03-14 18:14:06 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:14:26 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:14:32 (7160): Guest Log: 03:05:59.599719 timesync vgsvcTimeSyncWorker: Radical guest time change: 4 594 852 953 000ns (GuestNow=1 741 947 252 066 879 000 ns GuestLast=1 741 942 657 213 926 000 ns fSetTimeLastLoop=true )
2025-03-14 18:15:25 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:15:45 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:15:55 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:16:15 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:16:25 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:16:45 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:16:55 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:17:15 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:17:25 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:17:46 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:17:56 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:18:16 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:18:26 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:19:06 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:19:16 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:19:36 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:19:46 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:20:06 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:20:16 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:20:36 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:20:46 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:21:06 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:21:16 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:21:36 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:21:46 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:22:06 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:22:16 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:22:36 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:22:46 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:23:06 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:23:16 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:23:36 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:23:46 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:24:06 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:24:16 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:24:36 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:24:46 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:25:06 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:25:16 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:25:36 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:25:46 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:26:06 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:26:16 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:26:36 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:26:46 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:27:06 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:27:16 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:27:37 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:27:47 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:28:07 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:28:17 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:28:37 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:28:47 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:29:07 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:29:17 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:29:37 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:29:47 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:30:07 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:30:17 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:30:37 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:30:47 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:31:07 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:31:17 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:31:37 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:31:47 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:32:07 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:32:18 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:32:38 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:32:48 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:33:08 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:33:18 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:33:38 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:33:48 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:34:08 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:34:18 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:34:38 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:34:48 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:35:08 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:35:18 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:35:38 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:35:48 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:36:08 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:36:18 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:36:38 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:36:58 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:37:18 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:37:28 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:37:48 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:37:58 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:38:18 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:38:28 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:38:48 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:38:58 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:39:18 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:39:28 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:39:48 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:39:58 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:40:19 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:40:29 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:40:49 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:40:59 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:41:19 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:41:29 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:41:49 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:41:59 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:42:19 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:42:29 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:42:49 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:42:59 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:43:19 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:43:29 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:43:49 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:43:59 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:44:19 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:44:29 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:44:49 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:44:59 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:45:19 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:45:29 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 18:45:49 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 18:45:59 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:46:06 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:46:14 (7160): Guest Log: 03:17:20.052148 timesync vgsvcTimeSyncWorker: Radical host time change: 3 616 102 000 000ns (HostNow=1 741 952 773 879 000 000 ns HostLast=1 741 949 157 777 000 000 ns)
2025-03-14 19:46:22 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:46:42 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:46:44 (7160): Guest Log: 03:17:30.055774 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 636 101 683 000ns (GuestNow=1 741 952 783 882 699 000 ns GuestLast=1 741 949 147 781 016 000 ns fSetTimeLastLoop=true )
2025-03-14 19:46:52 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:47:12 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:47:22 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:47:42 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:47:52 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:48:12 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:48:22 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:48:42 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:48:52 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:49:12 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:49:22 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:49:42 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:49:52 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:50:12 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:50:22 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:50:42 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:50:52 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:51:12 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:51:22 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:51:42 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:51:53 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:52:13 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:52:23 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:52:43 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:52:53 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:53:13 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:53:23 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:53:43 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:53:53 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:54:12 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:54:22 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:54:42 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:54:53 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:55:12 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:55:22 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:55:42 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:55:52 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:56:12 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:56:22 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:56:42 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:56:52 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:57:12 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:57:22 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:57:42 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:57:52 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:58:12 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:58:22 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:58:42 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:58:52 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:59:12 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:59:22 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 19:59:42 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 19:59:52 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:00:12 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:00:22 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:00:42 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:00:52 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:01:12 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:01:22 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:01:42 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:01:53 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:02:13 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:02:24 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:02:43 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:02:53 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:03:13 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:03:23 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:03:43 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:03:53 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:04:13 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:04:23 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:04:43 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:04:53 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:05:13 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:05:23 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:05:43 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:05:53 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:06:13 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:06:23 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:06:43 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:06:53 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:07:13 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:07:23 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:07:43 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:07:53 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:08:13 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:08:23 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:08:43 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:08:53 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:09:13 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:09:23 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:09:43 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:09:53 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:10:13 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:10:23 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:10:43 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:10:53 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:11:13 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:11:23 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:11:43 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:11:53 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:12:13 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:12:23 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:12:43 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:12:53 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:13:14 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:13:24 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:13:44 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:13:54 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:14:14 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:14:24 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:14:44 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:14:54 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 20:15:14 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 20:15:24 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:15:29 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:15:34 (7160): Guest Log: 03:27:20.443815 timesync vgsvcTimeSyncWorker: Radical host time change: 3 615 350 000 000ns (HostNow=1 741 958 134 523 000 000 ns HostLast=1 741 954 519 173 000 000 ns)
2025-03-14 21:15:37 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:15:57 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:16:04 (7160): Guest Log: 03:27:30.444914 timesync vgsvcTimeSyncWorker: Radical guest time change: 4 770 253 477 000ns (GuestNow=1 741 958 144 524 155 000 ns GuestLast=1 741 953 374 270 678 000 ns fSetTimeLastLoop=true )
2025-03-14 21:16:07 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:16:27 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:16:37 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:16:57 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:17:08 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:17:28 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:17:38 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:17:58 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:18:08 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:18:28 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:18:38 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:18:58 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:19:08 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:19:28 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:19:38 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:19:58 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:20:08 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:20:28 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:20:38 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:20:58 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:21:08 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:21:28 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:21:38 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:21:58 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:22:08 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:22:28 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:22:38 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:22:58 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:23:08 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:23:28 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:23:38 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:23:58 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:24:08 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:24:28 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:24:38 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:24:58 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:25:08 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:25:28 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:25:38 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:25:58 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:26:08 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:26:28 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:26:38 (7160): VM state change detected. (old = 'running', new = 'paused')
2025-03-14 21:26:58 (7160): VM state change detected. (old = 'paused', new = 'running')
2025-03-14 21:27:01 (7160): Stopping VM.
2025-03-14 21:27:16 (7160): Successfully stopped VM.
2025-03-15 10:42:46 (13324): vboxwrapper version 26208
2025-03-15 10:42:46 (13324): BOINC client version: 8.0.2
2025-03-15 10:42:49 (13324): Detected: VirtualBox VboxManage Interface (Version: 7.0.6)
2025-03-15 10:42:49 (13324): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2025-03-15 10:42:50 (13324): Guest Log: BIOS: VirtualBox 7.0.6
2025-03-15 10:42:50 (13324): Guest Log: CPUID EDX: 0x178bfbff
2025-03-15 10:42:50 (13324): Guest Log: BIOS: No PCI IDE controller, not probing IDE
2025-03-15 10:42:50 (13324): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors
2025-03-15 10:42:50 (13324): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032
2025-03-15 10:42:50 (13324): Guest Log: BIOS: Booting from Hard Disk...
2025-03-15 10:42:50 (13324): Guest Log: BIOS: KBD: unsupported int 16h function 03
2025-03-15 10:42:50 (13324): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 
2025-03-15 10:42:50 (13324): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds
2025-03-15 10:42:50 (13324): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)
2025-03-15 10:42:50 (13324): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log
2025-03-15 10:42:50 (13324): Guest Log: 00:00:00.000063 main     Log opened 2025-03-14T04:50:40.211433000Z
2025-03-15 10:42:50 (13324): Guest Log: 00:00:00.000127 main     OS Product: Linux
2025-03-15 10:42:50 (13324): Guest Log: 00:00:00.000151 main     OS Release: 4.14.232-19.cernvm.x86_64
2025-03-15 10:42:50 (13324): Guest Log: 00:00:00.000169 main     OS Version: #1 SMP Fri Apr 30 17:12:25 CEST 2021
2025-03-15 10:42:50 (13324): Guest Log: 00:00:00.000191 main     Executable: /usr/sbin/VBoxService
2025-03-15 10:42:50 (13324): Guest Log: 00:00:00.000191 main     Process ID: 2288
2025-03-15 10:42:50 (13324): Guest Log: 00:00:00.000192 main     Package type: LINUX_64BITS_GENERIC
2025-03-15 10:42:50 (13324): Guest Log: 00:00:00.000615 main     5.2.6 r120293 started. Verbose level = 0
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Mounting the shared directory
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Shared directory mounted, enabling vboxmonitor
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Sourcing essential functions from /cvmfs/grid.cern.ch
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Testing connection to cern.ch
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Testing connection to VCCS
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Testing connection to HTCondor
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Testing connection to WMAgent
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Testing connection to EOSCMS
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Testing connection to CMS-Factory
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Testing connection to CMS-Frontier
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Testing connection to Frontier
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Could not find a local HTTP proxy
2025-03-15 10:42:50 (13324): Guest Log: [INFO] CVMFS and Frontier will have to use DIRECT connections
2025-03-15 10:42:50 (13324): Guest Log: [INFO] This makes the application less efficient
2025-03-15 10:42:50 (13324): Guest Log: [INFO] It also puts higher load on the project servers
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Setting up a local HTTP proxy is highly recommended
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Advice can be found in the project forum
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Reloading and probing the CVMFS configuration
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Probing /cvmfs/grid.cern.ch... OK
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Probing /cvmfs/cms.cern.ch... OK
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Probing /cvmfs/oasis.opensciencegrid.org... OK
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Probing /cvmfs/cms-ib.cern.ch... OK
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Probing /cvmfs/singularity.opensciencegrid.org... OK
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Excerpt from "cvmfs_config stat": VERSION HOST PROXY
2025-03-15 10:42:50 (13324): Guest Log: [INFO] 2.7.2.0 http://s1ral-cvmfs.openhtc.io DIRECT
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Environment HTTP proxy: not set
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Reading volunteer information
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Requesting an X509 credential from LHC@home
2025-03-15 10:42:50 (13324): Guest Log: [INFO] Requesting an idtoken from LHC@home
2025-03-15 10:42:50 (13324): Guest Log: [INFO] CMS application starting. Check log files.
2025-03-15 10:42:50 (13324): Guest Log: 00:17:52.312005 timesync vgsvcTimeSyncWorker: Radical host time change: 3 617 730 000 000ns (HostNow=1 741 932 579 928 000 000 ns HostLast=1 741 928 962 198 000 000 ns)
2025-03-15 10:42:50 (13324): Guest Log: 00:18:02.331139 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 677 423 993 000ns (GuestNow=1 741 932 589 947 239 000 ns GuestLast=1 741 928 912 523 246 000 ns fSetTimeLastLoop=true )
2025-03-15 10:42:50 (13324): Guest Log: 03:05:49.597901 timesync vgsvcTimeSyncWorker: Radical host time change: 3 657 261 000 000ns (HostNow=1 741 947 242 065 000 000 ns HostLast=1 741 943 584 804 000 000 ns)
2025-03-15 10:42:50 (13324): Guest Log: 03:05:59.599719 timesync vgsvcTimeSyncWorker: Radical guest time change: 4 594 852 953 000ns (GuestNow=1 741 947 252 066 879 000 ns GuestLast=1 741 942 657 213 926 000 ns fSetTimeLastLoop=true )
2025-03-15 10:42:50 (13324): Guest Log: 03:17:20.052148 timesync vgsvcTimeSyncWorker: Radical host time change: 3 616 102 000 000ns (HostNow=1 741 952 773 879 000 000 ns HostLast=1 741 949 157 777 000 000 ns)
2025-03-15 10:42:50 (13324): Guest Log: 03:17:30.055774 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 636 101 683 000ns (GuestNow=1 741 952 783 882 699 000 ns GuestLast=1 741 949 147 781 016 000 ns fSetTimeLastLoop=true )
2025-03-15 10:42:50 (13324): Guest Log: 03:27:20.443815 timesync vgsvcTimeSyncWorker: Radical host time change: 3 615 350 000 000ns (HostNow=1 741 958 134 523 000 000 ns HostLast=1 741 954 519 173 000 000 ns)
2025-03-15 10:42:50 (13324): Guest Log: 03:27:30.444914 timesync vgsvcTimeSyncWorker: Radical guest time change: 4 770 253 477 000ns (GuestNow=1 741 958 144 524 155 000 ns GuestLast=1 741 953 374 270 678 000 ns fSetTimeLastLoop=true )
2025-03-15 10:42:50 (13324): Starting VM using VBoxManage interface. (boinc_ee2e428a927b5094, slot#0)
2025-03-15 10:43:01 (13324): Successfully started VM. (PID = '15316')
2025-03-15 10:43:01 (13324): Reporting VM Process ID to BOINC.
2025-03-15 10:43:01 (13324): VM state change detected. (old = 'poweredoff', new = 'running')
2025-03-15 10:43:01 (13324): Detected: Web Application Enabled (http://localhost:64970)
2025-03-15 10:43:02 (13324): Guest Log: 03:31:10.569827 timesync vgsvcTimeSyncWorker: Radical host time change: 47 787 919 000 000ns (HostNow=1 742 006 581 598 000 000 ns HostLast=1 741 958 793 679 000 000 ns)
2025-03-15 10:43:02 (13324): VM state change detected. (old = 'running', new = 'paused')
2025-03-15 10:43:57 (13324): Status Report: Job Duration: '64800.000000'
2025-03-15 10:43:57 (13324): Status Report: Elapsed Time: '17530.000000'
2025-03-15 10:43:57 (13324): Status Report: CPU Time: '33132.046875'
2025-03-15 10:43:57 (13324): Preference change detected
2025-03-15 10:43:57 (13324): Setting CPU throttle for VM. (98%)
2025-03-15 10:43:58 (13324): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 180 seconds) or (Vbox_job.xml: 600 seconds))
2025-03-15 10:43:58 (13324): VM state change detected. (old = 'paused', new = 'running')
2025-03-15 10:44:07 (13324): Guest Log: 03:31:20.570481 timesync vgsvcTimeSyncWorker: Radical guest time change: 48 226 949 698 000ns (GuestNow=1 742 006 591 598 703 000 ns GuestLast=1 741 958 364 649 005 000 ns fSetTimeLastLoop=true )
2025-03-15 10:44:08 (13324): VM state change detected. (old = 'runn

©2025 CERN