Stderr output

<core_client_version>7.16.20</core_client_version>
<![CDATA[
<stderr_txt>
2025-02-13 00:49:37 (24148): Detected: vboxwrapper 26206
2025-02-13 00:49:37 (24148): Detected: BOINC client v7.16.20
2025-02-13 00:49:38 (24148): Detected: VirtualBox VboxManage Interface (Version: 6.0.14)
2025-02-13 00:49:38 (24148): Successfully copied 'init_data.xml' to the shared directory.
2025-02-13 00:49:39 (24148): Create VM. (boinc_e64d5d2102081322, slot#0)
2025-02-13 00:49:42 (24148): Setting Memory Size for VM. (4400MB)
2025-02-13 00:49:43 (24148): Setting CPU Count for VM. (4)
2025-02-13 00:49:44 (24148): Setting Chipset Options for VM.
2025-02-13 00:49:45 (24148): Setting Graphics Controller Options for VM.
2025-02-13 00:49:45 (24148): Setting Boot Options for VM.
2025-02-13 00:49:46 (24148): Setting Network Configuration for NAT.
2025-02-13 00:49:47 (24148): Enabling VM Network Access.
2025-02-13 00:49:48 (24148): Disabling USB Support for VM.
2025-02-13 00:49:48 (24148): Disabling COM Port Support for VM.
2025-02-13 00:49:49 (24148): Disabling LPT Port Support for VM.
2025-02-13 00:49:49 (24148): Disabling Audio Support for VM.
2025-02-13 00:49:50 (24148): Disabling Clipboard Support for VM.
2025-02-13 00:49:51 (24148): Disabling Drag and Drop Support for VM.
2025-02-13 00:49:51 (24148): Adding storage controller(s) to VM.
2025-02-13 00:49:52 (24148): Adding virtual disk drive to VM. (ATLAS_vbox_3.01_image.vdi)
2025-02-13 00:49:55 (24148): Adding VirtualBox Guest Additions to VM.
2025-02-13 00:49:55 (24148): Adding network bandwidth throttle group to VM. (Defaulting to 1024GB)
2025-02-13 00:49:56 (24148): forwarding host port 60223 to guest port 80
2025-02-13 00:49:57 (24148): Enabling remote desktop for VM.
2025-02-13 00:49:57 (24148): Required extension pack not installed, remote desktop not enabled.
2025-02-13 00:49:57 (24148): Enabling shared directory for VM.
2025-02-13 00:49:58 (24148): Starting VM using VBoxManage interface. (boinc_e64d5d2102081322, slot#0)
2025-02-13 00:50:10 (24148): Successfully started VM. (PID = '23152')
2025-02-13 00:50:10 (24148): Reporting VM Process ID to BOINC.
2025-02-13 00:50:10 (24148): Guest Log: BIOS: VirtualBox 6.0.14
2025-02-13 00:50:10 (24148): Guest Log: CPUID EDX: 0x178bfbff
2025-02-13 00:50:10 (24148): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors
2025-02-13 00:50:10 (24148): VM state change detected. (old = 'poweredoff', new = 'running')
2025-02-13 00:50:10 (24148): Detected: Web Application Enabled (http://localhost:60223)
2025-02-13 00:50:11 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 01:01:08 (24148): Preference change detected
2025-02-13 01:01:08 (24148): Setting CPU throttle for VM. (100%)
2025-02-13 01:01:08 (24148): Setting checkpoint interval to 900 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 900 seconds))
2025-02-13 01:01:08 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 01:01:09 (24148): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032
2025-02-13 01:01:09 (24148): Guest Log: BIOS: Booting from Hard Disk...
2025-02-13 01:01:12 (24148): Guest Log: BIOS: KBD: unsupported int 16h function 03
2025-02-13 01:01:12 (24148): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=81
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=81
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=82
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=82
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=83
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=83
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=84
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=84
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=85
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=85
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=86
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=86
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=87
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=87
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=88
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=88
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=89
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=89
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8a
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8a
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8b
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8b
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8c
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8c
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8d
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8d
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8e
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8e
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8f
2025-02-13 01:01:12 (24148): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8f
2025-02-13 01:01:18 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 01:13:59 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 01:14:02 (24148): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds
2025-02-13 01:14:02 (24148): Guest Log: vboxguest: misc device minor 58, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)
2025-02-13 01:14:09 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 01:33:00 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 01:33:07 (24148): Guest Log: VBoxService 5.2.32 r132073 (verbosity: 0) linux.amd64 (Jul 12 2019 10:32:28) release log
2025-02-13 01:33:07 (24148): Guest Log: 00:00:00.000227 main     Log opened 2025-02-13T00:50:37.339182000Z
2025-02-13 01:33:07 (24148): Guest Log: 00:00:00.000354 main     OS Product: Linux
2025-02-13 01:33:07 (24148): Guest Log: 00:00:00.000395 main     OS Release: 3.10.0-957.27.2.el7.x86_64
2025-02-13 01:33:07 (24148): Guest Log: 00:00:00.000433 main     OS Version: #1 SMP Mon Jul 29 17:46:05 UTC 2019
2025-02-13 01:33:07 (24148): Guest Log: 00:00:00.000467 main     Executable: /opt/VBoxGuestAdditions-5.2.32/sbin/VBoxService
2025-02-13 01:33:07 (24148): Guest Log: 00:00:00.000467 main     Process ID: 1304
2025-02-13 01:33:07 (24148): Guest Log: 00:00:00.000468 main     Package type: LINUX_64BITS_GENERIC
2025-02-13 01:33:07 (24148): Guest Log: 00:00:00.001190 main     5.2.32 r132073 started. Verbose level = 0
2025-02-13 01:33:08 (24148): Guest Log: [INFO] Probing /cvmfs/atlas.cern.ch...
2025-02-13 01:33:08 (24148): Guest Log: [INFO] Mounting shared directory
2025-02-13 01:33:08 (24148): Guest Log: [INFO] Checking for init_data.xml
2025-02-13 01:33:10 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 02:01:11 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 02:01:18 (24148): Guest Log: 00:00:10.005795 timesync vgsvcTimeSyncWorker: Radical guest time change: 20 559 691 494 000ns (GuestNow=1 739 428 397 035 417 000 ns GuestLast=1 739 407 837 343 923 000 ns fSetTimeLastLoop=true )
2025-02-13 02:01:21 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 02:42:23 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 02:42:30 (24148): Guest Log: 00:00:20.006803 timesync vgsvcTimeSyncWorker: Radical host time change: 2 472 557 000 000ns (HostNow=1 739 432 550 656 000 000 ns HostLast=1 739 430 078 099 000 000 ns)
2025-02-13 02:42:33 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 03:01:14 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 03:01:21 (24148): Guest Log: 00:00:30.010247 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 472 559 441 000ns (GuestNow=1 739 432 560 659 487 000 ns GuestLast=1 739 430 088 100 046 000 ns fSetTimeLastLoop=true )
2025-02-13 03:01:24 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 03:14:05 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 03:14:15 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 03:18:15 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 03:18:22 (24148): Guest Log: 00:00:50.013737 timesync vgsvcTimeSyncWorker: Radical guest time change: 1 891 000 576 000ns (GuestNow=1 739 434 461 660 784 000 ns GuestLast=1 739 432 570 660 208 000 ns fSetTimeLastLoop=true )
2025-02-13 03:18:25 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 03:33:15 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 03:33:25 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 03:35:15 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 03:35:25 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 03:37:06 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 03:37:16 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 04:01:17 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 04:01:27 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 04:12:18 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 04:12:28 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 04:30:08 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 04:30:10 (24148): Guest Log: [INFO] Probing /cvmfs/atlas.cern.ch... OK
2025-02-13 04:30:10 (24148): Guest Log: [INFO] Detected branch: prod
2025-02-13 04:30:11 (24148): Guest Log: This is the prod version of the ATLAS job wrapper
2025-02-13 04:30:11 (24148): Guest Log: Copying input files
2025-02-13 04:30:16 (24148): Guest Log: Copied input files into RunAtlas.
2025-02-13 04:30:16 (24148): Guest Log: This VM did not configure a local http proxy via BOINC.
2025-02-13 04:30:16 (24148): Guest Log: Small home clusters do not require a local http proxy but it is suggested if
2025-02-13 04:30:16 (24148): Guest Log: more than 10 cores throughout the same LAN segment are regularly running ATLAS like tasks.
2025-02-13 04:30:16 (24148): Guest Log: Further information can be found at the LHC@home message board.
2025-02-13 04:30:18 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 04:34:08 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 04:34:18 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 04:42:19 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 04:42:29 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 05:01:09 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 05:01:20 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 05:14:01 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 05:14:06 (24148): Guest Log: 00:02:30.186719 timesync vgsvcTimeSyncWorker: Radical guest time change: 1 841 151 706 000ns (GuestNow=1 739 440 885 897 111 000 ns GuestLast=1 739 439 044 745 405 000 ns fSetTimeLastLoop=true )
2025-02-13 05:14:11 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 06:01:13 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 06:01:18 (24148): Guest Log: 00:02:40.187224 timesync vgsvcTimeSyncWorker: Radical host time change: 2 831 979 000 000ns (HostNow=1 739 444 478 250 000 000 ns HostLast=1 739 441 646 271 000 000 ns)
2025-02-13 06:01:23 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 06:04:13 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 06:04:18 (24148): Guest Log: 00:02:50.188343 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 592 353 387 000ns (GuestNow=1 739 444 488 251 227 000 ns GuestLast=1 739 440 895 897 840 000 ns fSetTimeLastLoop=true )
2025-02-13 06:04:23 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 06:35:05 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 06:35:10 (24148): Guest Log: 00:03:00.188764 timesync vgsvcTimeSyncWorker: Radical host time change: 1 851 798 000 000ns (HostNow=1 739 446 510 025 000 000 ns HostLast=1 739 444 658 227 000 000 ns)
2025-02-13 06:35:15 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 06:53:56 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 06:54:01 (24148): Guest Log: 00:03:10.190565 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 021 775 398 000ns (GuestNow=1 739 446 520 026 922 000 ns GuestLast=1 739 444 498 251 524 000 ns fSetTimeLastLoop=true )
2025-02-13 06:54:06 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 06:54:36 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 06:54:46 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 06:55:16 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 06:55:26 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 07:01:16 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 07:01:26 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 07:14:07 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 07:14:12 (24148): Guest Log: Running cvmfs_config stat atlas.cern.ch
2025-02-13 07:14:12 (24148): Guest Log: VERSION PID UPTIME(M) MEM(K) REVISION EXPIRES(M) NOCATALOGS CACHEUSE(K) CACHEMAX(K) NOFDUSE NOFDMAX NOIOERR NOOPEN HITRATE(%) RX(K) SPEED(K/S) HOST PROXY ONLINE
2025-02-13 07:14:12 (24148): Guest Log: 2.6.3.0 1658 227 30312 142598 4 1 3119916 4096000 0 65024 0 0 n/a 1169 27 http://s1fnal-cvmfs.openhtc.io:8080/cvmfs/atlas.cern.ch DIRECT 1
2025-02-13 07:14:16 (24148): Guest Log: copied the webapp to /var/www
2025-02-13 07:14:16 (24148): Guest Log: ATHENA_PROC_NUMBER=4
2025-02-13 07:14:16 (24148): Guest Log: ATHENA_CORE_NUMBER=4
2025-02-13 07:14:17 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 07:15:47 (24148): Guest Log: Apptainer command /cvmfs/atlas.cern.ch/repo/containers/sw/apptainer/x86_64-el7/current/bin/apptainer exec -B /cvmfs,/data,/home/atlas/RunAtlas /cvmfs/atlas.cern.ch/repo/containers/fs/singularity/x86_64-centos7 
2025-02-13 07:15:47 (24148): Guest Log:  *** Starting ATLAS job. (PandaID=6511676170 taskID=43205075) ***
2025-02-13 07:15:47 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 07:15:57 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 07:16:57 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 07:17:07 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 07:24:57 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 07:25:07 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 07:25:27 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 07:25:37 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 07:25:47 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 07:25:57 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 07:29:27 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 07:29:37 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 07:34:28 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 07:34:38 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 20:01:05 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 20:01:09 (24148): Guest Log: 00:05:10.234563 timesync vgsvcTimeSyncWorker: Radical host time change: 44 797 740 000 000ns (HostNow=1 739 494 869 214 000 000 ns HostLast=1 739 450 071 474 000 000 ns)
2025-02-13 20:01:15 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 20:15:17 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 20:15:21 (24148): Guest Log: 00:05:20.235330 timesync vgsvcTimeSyncWorker: Radical guest time change: 45 327 168 105 000ns (GuestNow=1 739 494 879 214 579 000 ns GuestLast=1 739 449 552 046 474 000 ns fSetTimeLastLoop=true )
2025-02-13 20:15:27 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 20:41:48 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 20:41:58 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 21:01:08 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 21:01:12 (24148): Guest Log: 00:05:40.243096 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 432 291 589 000ns (GuestNow=1 739 497 321 506 932 000 ns GuestLast=1 739 494 889 215 343 000 ns fSetTimeLastLoop=true )
2025-02-13 21:01:18 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 21:14:09 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 21:14:19 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 22:01:02 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 22:01:06 (24148): Guest Log: 00:06:00.245507 timesync vgsvcTimeSyncWorker: Radical host time change: 2 812 764 000 000ns (HostNow=1 739 502 065 329 000 000 ns HostLast=1 739 499 252 565 000 000 ns)
2025-02-13 22:01:06 (24148): Guest Log: 00:06:00.245580 timesync vgsvcTimeSyncWorker: Radical guest time change: 1 931 058 143 000ns (GuestNow=1 739 499 262 566 360 000 ns GuestLast=1 739 497 331 508 217 000 ns fSetTimeLastLoop=true )
2025-02-13 22:01:12 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 22:30:23 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 22:30:27 (24148): Guest Log: 00:06:10.255533 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 812 770 562 000ns (GuestNow=1 739 502 075 336 922 000 ns GuestLast=1 739 499 262 566 360 000 ns fSetTimeLastLoop=true )
2025-02-13 22:30:33 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 22:39:13 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 22:39:23 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 23:01:05 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 23:01:15 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-13 23:14:06 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-13 23:14:09 (24148): Guest Log: 00:06:40.262956 timesync vgsvcTimeSyncWorker: Radical guest time change: 1 832 076 406 000ns (GuestNow=1 739 505 678 474 004 000 ns GuestLast=1 739 503 846 397 598 000 ns fSetTimeLastLoop=true )
2025-02-13 23:14:16 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 00:01:08 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 00:01:11 (24148): Guest Log: 00:06:50.271723 timesync vgsvcTimeSyncWorker: Radical host time change: 2 822 097 000 000ns (HostNow=1 739 509 271 009 000 000 ns HostLast=1 739 506 448 912 000 000 ns)
2025-02-14 00:01:18 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 00:12:08 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 00:12:11 (24148): Guest Log: 00:07:00.286590 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 592 541 011 000ns (GuestNow=1 739 509 281 023 675 000 ns GuestLast=1 739 505 688 482 664 000 ns fSetTimeLastLoop=true )
2025-02-14 00:12:18 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 00:34:39 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 00:34:49 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 01:01:11 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 01:01:14 (24148): Guest Log: 00:07:20.296452 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 001 438 074 000ns (GuestNow=1 739 511 292 471 411 000 ns GuestLast=1 739 509 291 033 337 000 ns fSetTimeLastLoop=true )
2025-02-14 01:01:21 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 01:14:02 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 01:14:12 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 02:01:04 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 02:01:07 (24148): Guest Log: 00:07:40.298497 timesync vgsvcTimeSyncWorker: Radical host time change: 2 822 230 000 000ns (HostNow=1 739 516 467 453 000 000 ns HostLast=1 739 513 645 223 000 000 ns)
2025-02-14 02:01:14 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 03:01:07 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 03:01:10 (24148): Guest Log: 00:07:50.319867 timesync vgsvcTimeSyncWorker: Radical host time change: 3 602 534 000 000ns (HostNow=1 739 520 069 987 000 000 ns HostLast=1 739 516 467 453 000 000 ns)
2025-02-14 03:01:10 (24148): Guest Log: 00:07:50.319972 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 583 735 026 000ns (GuestNow=1 739 516 477 474 050 000 ns GuestLast=1 739 512 893 739 024 000 ns fSetTimeLastLoop=true )
2025-02-14 03:01:17 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 03:14:08 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 03:14:11 (24148): Guest Log: 00:08:00.320325 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 602 513 525 000ns (GuestNow=1 739 520 079 987 575 000 ns GuestLast=1 739 516 477 474 050 000 ns fSetTimeLastLoop=true )
2025-02-14 03:14:18 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 03:22:28 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 03:22:38 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 03:46:09 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 03:46:19 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 03:51:09 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 03:51:19 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 04:01:10 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 04:01:20 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 04:22:22 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 04:22:32 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 04:24:01 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 04:24:04 (24148): Guest Log: 00:09:00.382629 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 152 461 489 000ns (GuestNow=1 739 524 954 406 888 000 ns GuestLast=1 739 522 801 945 399 000 ns fSetTimeLastLoop=true )
2025-02-14 04:24:11 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 05:01:03 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 05:01:06 (24148): Guest Log: 00:09:10.772905 timesync vgsvcTimeSyncWorker: Radical host time change: 2 221 524 000 000ns (HostNow=1 739 527 265 580 000 000 ns HostLast=1 739 525 044 056 000 000 ns)
2025-02-14 05:01:13 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 05:14:04 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 05:14:07 (24148): Guest Log: 00:09:20.773425 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 311 493 236 000ns (GuestNow=1 739 527 275 935 459 000 ns GuestLast=1 739 524 964 442 223 000 ns fSetTimeLastLoop=true )
2025-02-14 05:14:14 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 05:30:04 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 05:30:14 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 05:30:44 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 05:30:54 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 05:31:24 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 05:31:34 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 06:01:06 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 06:01:16 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 06:39:18 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 06:39:21 (24148): Guest Log: 00:10:11.240963 timesync vgsvcTimeSyncWorker: Radical host time change: 2 293 103 000 000ns (HostNow=1 739 533 161 415 000 000 ns HostLast=1 739 530 868 312 000 000 ns)
2025-02-14 06:39:21 (24148): Guest Log: 00:10:11.241087 timesync vgsvcTimeSyncWorker: Radical guest time change: 1 841 603 600 000ns (GuestNow=1 739 530 878 756 022 000 ns GuestLast=1 739 529 037 152 422 000 ns fSetTimeLastLoop=true )
2025-02-14 06:39:28 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 07:00:59 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 07:01:02 (24148): Guest Log: 00:10:21.241956 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 292 660 014 000ns (GuestNow=1 739 533 171 416 036 000 ns GuestLast=1 739 530 878 756 022 000 ns fSetTimeLastLoop=true )
2025-02-14 07:01:09 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 07:14:00 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 07:14:10 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 07:32:21 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 07:32:31 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 07:46:41 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 07:46:44 (24148): Guest Log: 00:10:51.265273 timesync vgsvcTimeSyncWorker: Radical guest time change: 1 871 311 933 000ns (GuestNow=1 739 536 353 660 160 000 ns GuestLast=1 739 534 482 348 227 000 ns fSetTimeLastLoop=true )
2025-02-14 07:46:51 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 20:01:00 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 20:01:03 (24148): Guest Log: 00:11:01.266563 timesync vgsvcTimeSyncWorker: Radical host time change: 44 058 837 000 000ns (HostNow=1 739 581 263 115 000 000 ns HostLast=1 739 537 204 278 000 000 ns)
2025-02-14 20:01:10 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 20:07:50 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 20:07:53 (24148): Guest Log: 00:11:11.267533 timesync vgsvcTimeSyncWorker: Radical guest time change: 44 909 455 197 000ns (GuestNow=1 739 581 273 116 094 000 ns GuestLast=1 739 536 363 660 897 000 ns fSetTimeLastLoop=true )
2025-02-14 20:08:00 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 20:08:20 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 20:08:30 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 20:31:51 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 20:32:01 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 20:32:31 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 20:32:34 (24148): Guest Log: 00:11:41.570326 timesync vgsvcTimeSyncWorker: Radical guest time change: 1 830 545 404 000ns (GuestNow=1 739 583 123 663 144 000 ns GuestLast=1 739 581 293 117 740 000 ns fSetTimeLastLoop=true )
2025-02-14 20:32:41 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 20:33:21 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 20:33:31 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 20:37:51 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 20:38:01 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 20:38:21 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 20:38:31 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 20:47:23 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 20:47:33 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 21:01:03 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 21:01:13 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 21:13:24 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 21:13:34 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 21:14:04 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 21:14:14 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 21:20:44 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 21:20:54 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 21:21:24 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 21:21:34 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 21:24:14 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 21:24:24 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 21:35:45 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 21:35:55 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 21:36:25 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 21:36:35 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 21:37:25 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 21:37:35 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 21:43:45 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 21:43:55 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 21:44:25 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 21:44:35 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 21:52:45 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 21:52:55 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 22:00:56 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 22:01:06 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 22:11:06 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 22:11:16 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 22:29:47 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 22:29:57 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 22:30:27 (24148): Guest Log: 00:15:02.033784 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 200 502 303 000ns (GuestNow=1 739 590 197 150 393 000 ns GuestLast=1 739 587 996 648 090 000 ns fSetTimeLastLoop=true )
2025-02-14 22:30:27 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 22:30:37 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 22:41:48 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 22:41:58 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 22:42:28 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 22:42:38 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 22:43:18 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 22:43:38 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 22:49:48 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 22:49:58 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 22:50:28 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 22:50:38 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 23:00:18 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 23:00:28 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 23:00:58 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 23:01:08 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 23:07:19 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 23:07:30 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 23:14:10 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 23:14:20 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 23:32:11 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 23:32:21 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 23:44:51 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 23:44:59 (24148): Guest Log: 00:17:12.510341 timesync vgsvcTimeSyncWorker: Radical guest time change: 1 880 791 939 000ns (GuestNow=1 739 593 948 633 787 000 ns GuestLast=1 739 592 067 841 848 000 ns fSetTimeLastLoop=true )
2025-02-14 23:45:01 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-14 23:45:21 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-14 23:45:31 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 00:01:02 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 00:01:12 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 00:10:52 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 00:11:02 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 00:11:22 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 00:11:32 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 00:12:22 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 00:12:32 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 00:20:53 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 00:21:03 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 00:21:23 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 00:21:33 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 00:24:13 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 00:24:23 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 00:44:54 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 00:45:04 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 00:45:34 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 00:45:44 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 00:58:24 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 00:58:35 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 01:01:05 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 01:01:15 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 01:09:15 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 01:09:25 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 01:14:05 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 01:14:15 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 01:28:46 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 01:28:56 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 01:33:16 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 01:33:26 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 01:34:46 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 01:34:56 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 01:36:26 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 01:36:36 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 01:43:47 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 01:43:57 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 01:44:27 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 01:44:37 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 01:45:17 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 01:45:27 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 01:53:27 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 01:53:38 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 01:54:48 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 01:54:57 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 01:55:28 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 01:55:37 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 01:56:18 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 01:56:28 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 02:01:08 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 02:01:18 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 02:24:49 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 02:24:59 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 02:25:19 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 02:25:29 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 02:26:19 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 02:26:29 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 02:32:30 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 02:32:40 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 02:33:00 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 02:33:10 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 02:34:00 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 02:34:10 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 02:42:00 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 02:42:10 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 02:46:50 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 02:47:00 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 02:47:20 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 02:47:30 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 02:48:20 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 02:48:30 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 02:53:50 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 02:54:01 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 02:54:21 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 02:54:31 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 02:55:21 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 02:55:31 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 03:01:01 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 03:01:11 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 03:03:21 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 03:03:31 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 03:14:01 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 03:14:11 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 03:25:52 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 03:26:02 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 03:26:22 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 03:26:32 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 03:27:22 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 03:27:32 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 03:30:22 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 03:30:32 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 03:30:52 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 03:31:02 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 03:45:34 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 03:45:43 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 03:47:53 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 03:47:58 (24148): Guest Log: 00:25:22.702045 timesync vgsvcTimeSyncWorker: Radical guest time change: 1 841 916 907 000ns (GuestNow=1 739 609 148 299 481 000 ns GuestLast=1 739 607 306 382 574 000 ns fSetTimeLastLoop=true )
2025-02-15 03:48:04 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 03:48:24 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 03:48:33 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 04:01:05 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 04:01:15 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 04:03:55 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 04:04:06 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 04:05:14 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 04:05:24 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 04:05:34 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 04:05:44 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 04:07:44 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 04:07:54 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 04:08:24 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 04:08:34 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 04:13:54 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 04:14:04 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 04:15:25 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 04:15:35 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 04:24:25 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 04:24:35 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 04:39:47 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 04:39:56 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 04:40:26 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 04:40:32 (24148): Guest Log: 00:27:22.730492 timesync vgsvcTimeSyncWorker: Radical guest time change: 1 882 212 722 000ns (GuestNow=1 739 612 401 169 185 000 ns GuestLast=1 739 610 518 956 463 000 ns fSetTimeLastLoop=true )
2025-02-15 04:40:37 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 05:01:08 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 05:01:18 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 05:14:08 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 05:14:18 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 05:50:20 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 05:50:24 (24148): Guest Log: 00:27:52.904317 timesync vgsvcTimeSyncWorker: Radical host time change: 2 171 473 000 000ns (HostNow=1 739 616 624 076 000 000 ns HostLast=1 739 614 452 603 000 000 ns)
2025-02-15 05:50:30 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 06:01:00 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 06:01:04 (24148): Guest Log: 00:28:02.905482 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 941 893 285 000ns (GuestNow=1 739 616 634 076 846 000 ns GuestLast=1 739 613 692 183 561 000 ns fSetTimeLastLoop=true )
2025-02-15 06:01:10 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 06:46:52 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 06:46:56 (24148): Guest Log: 00:28:12.908387 timesync vgsvcTimeSyncWorker: Radical host time change: 2 752 154 000 000ns (HostNow=1 739 620 016 544 000 000 ns HostLast=1 739 617 264 390 000 000 ns)
2025-02-15 06:47:02 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 07:01:03 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 07:01:07 (24148): Guest Log: 00:28:22.908667 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 382 464 637 000ns (GuestNow=1 739 620 026 544 531 000 ns GuestLast=1 739 616 644 079 894 000 ns fSetTimeLastLoop=true )
2025-02-15 07:01:13 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 07:14:03 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 07:14:14 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 07:15:24 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 07:15:34 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 07:16:04 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 07:16:14 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 07:16:54 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 07:17:04 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 07:28:04 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 07:28:14 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 07:58:06 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 07:58:09 (24148): Guest Log: 00:29:22.925943 timesync vgsvcTimeSyncWorker: Radical host time change: 1 801 509 000 000ns (HostNow=1 739 624 288 723 000 000 ns HostLast=1 739 622 487 214 000 000 ns)
2025-02-15 07:58:16 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 07:58:46 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 07:58:49 (24148): Guest Log: 00:29:32.927035 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 601 187 188 000ns (GuestNow=1 739 624 298 723 902 000 ns GuestLast=1 739 621 697 536 714 000 ns fSetTimeLastLoop=true )
2025-02-15 07:58:56 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 20:01:03 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 20:01:07 (24148): Guest Log: 00:29:43.421462 timesync vgsvcTimeSyncWorker: Radical host time change: 43 337 453 000 000ns (HostNow=1 739 667 666 083 000 000 ns HostLast=1 739 624 328 630 000 000 ns)
2025-02-15 20:01:13 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 20:04:53 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 20:04:57 (24148): Guest Log: 00:29:53.428601 timesync vgsvcTimeSyncWorker: Radical guest time change: 43 367 857 510 000ns (GuestNow=1 739 667 676 583 145 000 ns GuestLast=1 739 624 308 725 635 000 ns fSetTimeLastLoop=true )
2025-02-15 20:05:03 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 20:05:23 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 20:05:33 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 20:27:44 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 20:27:54 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 20:28:24 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 20:28:34 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 20:34:44 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 20:34:54 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 20:35:24 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 20:35:34 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 20:41:34 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 20:41:45 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 20:51:55 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 20:52:05 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 20:52:25 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 20:52:35 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 20:53:25 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 20:53:35 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 21:00:26 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 21:00:36 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 21:00:56 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 21:01:06 (24148): VM state change detected. (old = 'running', new = 'paused')
2025-02-15 21:07:16 (24148): VM state change detected. (old = 'paused', new = 'running')
2025-02-15 21:07:22 (24148): Guest Log:  *** Job finished ***
2025-02-15 21:07:22 (24148): Guest Log:  *** The last 20 lines of the pilot log: ***
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:44,634 | INFO     | [data] queue_monitor thread has finished
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:44,951 | INFO     | only monitor.control thread still running - safe to abort: ['<_MainThread(MainThread, started 140557460449088)>', '<ExcThread(monitor, started 140556856436480)>']
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:45,279 | WARNING  | job_aborted has been set - aborting pilot monitoring
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:45,279 | INFO     | [monitor] control thread has ended
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:49,956 | INFO     | all workflow threads have been joined
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:49,956 | INFO     | end of generic workflow (traces error code: 1150)
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:49,957 | INFO     | traces error code: 1150
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:49,957 | INFO     | an exit code was already set: 1150 (will be converted to a standard shell code)
2025-02-15 21:07:22 (24148): Guest Log: no translation to shell exit code for error code 1150
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:49,957 | INFO     | pilot has finished (exit code=1150, shell exit code=1)
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:50,141 [wrapper] ==== pilot stdout END ====
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:50,147 [wrapper] ==== wrapper stdout RESUME ====
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:50,152 [wrapper] pilotpid: 6365
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:50,157 [wrapper] Pilot exit status: 1
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:50,449 [wrapper] pandaids: 6511676170
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:50,489 [wrapper] cleanup supervisor_pilot  5419 6366
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:50,495 [wrapper] Test setup, not cleaning
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:50,507 [wrapper] apfmon messages muted
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:50,513 [wrapper] ==== wrapper stdout END ====
2025-02-15 21:07:22 (24148): Guest Log: 2025-02-16 01:52:50,519 [wrapper] ==== wrapper stderr END ====
2025-02-15 21:07:22 (24148): Guest Log:  *** Error codes and diagnostics ***
2025-02-15 21:07:22 (24148): Guest Log:     "exeErrorCode": 0,
2025-02-15 21:07:22 (24148): Guest Log:     "exeErrorDiag": "",
2025-02-15 21:07:22 (24148): Guest Log:     "pilotErrorCode": 1150,
2025-02-15 21:07:22 (24148): Guest Log:     "pilotErrorDiag": "Looping job killed by pilot",
2025-02-15 21:07:22 (24148): Guest Log:  *** Listing of results directory ***
2025-02-15 21:07:22 (24148): Guest Log: total 4380
2025-02-15 21:07:22 (24148): Guest Log: -rw-r--r--. 1 atlas atlas  491065 Feb 13 01:09 pilot3.tar.gz
2025-02-15 21:07:22 (24148): Guest Log: -rw-r--r--. 1 atlas atlas    5118 Feb 13 01:41 queuedata.json
2025-02-15 21:07:22 (24148): Guest Log: -rwx------. 1 atlas atlas   34924 Feb 13 01:43 runpilot2-wrapper.sh
2025-02-15 21:07:22 (24148): Guest Log: -rwxr-xr-x. 1 atlas atlas    8613 Feb 13 09:30 init_data.xml
2025-02-15 21:07:22 (24148): Guest Log: -rwxr-xr-x. 1 atlas atlas  503498 Feb 13 09:30 input.tar.gz
2025-02-15 21:07:22 (24148): Guest Log: -rwxr-xr-x. 1 atlas atlas   17569 Feb 13 09:30 start_atlas.sh
2025-02-15 21:07:22 (24148): Guest Log: lrwxrwxrwx. 1 atlas atlas      20 Feb 13 09:30 EVNT.43092757._000222.pool.root.1 -> /data/./ATLAS.root_0
2025-02-15 21:07:22 (24148): Guest Log: -rw-r--r--. 1 atlas atlas    2555 Feb 13 12:01 pandaJob.out
2025-02-15 21:07:22 (24148): Guest Log: -rw-------. 1 atlas atlas     424 Feb 13 12:01 setup.sh.local
2025-02-15 21:07:22 (24148): Guest Log: -rw-------. 1 atlas atlas  986937 Feb 15 01:01 agis_schedconf.cvmfs.json
2025-02-15 21:07:22 (24148): Guest Log: drwx------. 4 atlas atlas    4096 Feb 15 01:01 pilot3
2025-02-15 21:07:22 (24148): Guest Log: -rw-------. 1 atlas atlas    1022 Feb 16 01:28 memory_monitor_summary.json
2025-02-15 21:07:22 (24148): Guest Log: -rw-------. 1 atlas atlas  135782 Feb 16 01:28 log.43205075._020871.job.log.tgz.1
2025-02-15 21:07:22 (24148): Guest Log: -rw-------. 1 atlas atlas     114 Feb 16 01:51 pilot_heartbeat.json
2025-02-15 21:07:22 (24148): Guest Log: -rw-------. 1 atlas atlas 1593946 Feb 16 01:52 agis_ddmendpoints.agis.ALL.json
2025-02-15 21:07:22 (24148): Guest Log: -rw-------. 1 atlas atlas    2730 Feb 16 01:52 heartbeat.json
2025-02-15 21:07:22 (24148): Guest Log: -rw-------. 1 atlas atlas    4524 Feb 16 01:52 pilotlog.txt
2025-02-15 21:07:22 (24148): Guest Log: -rw-------. 1 atlas atlas  237902 Feb 16 01:52 log.43205075._020871.job.log.1
2025-02-15 21:07:22 (24148): Guest Log: -rw-------. 1 atlas atlas     188 Feb 16 01:52 output.list
2025-02-15 21:07:22 (24148): Guest Log: -rw-r--r--. 1 atlas atlas     620 Feb 16 01:52 runtime_log
2025-02-15 21:07:22 (24148): Guest Log: -rw-------. 1 atlas atlas  389120 Feb 16 01:52 result.tar.gz
2025-02-15 21:07:22 (24148): Guest Log: -rw-r--r--. 1 atlas atlas   10803 Feb 16 01:52 runtime_log.err
2025-02-15 21:07:22 (24148): Guest Log: -rw-------. 1 atlas atlas     653 Feb 16 01:52 jAfLDmQRd26nsSi4ap6QjLDmwznN0nGgGQJmkKkKDmhhZKDmE4xkan.diag
2025-02-15 21:07:22 (24148): Guest Log: Looking for outputfile HITS.43205075._020871.pool.root.1
2025-02-15 21:07:22 (24148): Guest Log: No HITS file was produced
2025-02-15 21:07:22 (24148): Guest Log: Successfully finished the ATLAS job!
2025-02-15 21:07:22 (24148): Guest Log: Copying the results back to the shared directory!
2025-02-15 21:07:22 (24148): Guest Log:  *** Contents of shared directory: ***
2025-02-15 21:07:22 (24148): Guest Log: total 335788
2025-02-15 21:07:22 (24148): Guest Log: -rwxrwxrwx. 1 root root 342920538 Feb 13 05:49 ATLAS.root_0
2025-02-15 21:07:22 (24148): Guest Log: -rwxrwxrwx. 1 root root      8613 Feb 13 05:49 init_data.xml
2025-02-15 21:07:22 (24148): Guest Log: -rwxrwxrwx. 1 root root    503498 Feb 13 05:01 input.tar.gz
2025-02-15 21:07:22 (24148): Guest Log: -rwxrwxrwx. 1 root root    389120 Feb 16  2025 result.tar.gz
2025-02-15 21:07:22 (24148): Guest Log: -rwxrwxrwx. 1 root root     17569 Feb 13 05:01 start_atlas.sh
2025-02-15 21:07:22 (24148): Guest Log:  *** Success! Shutting down the machine. ***
2025-02-15 21:07:22 (24148): VM Completion File Detected.
2025-02-15 21:07:22 (24148): Powering off VM.
2025-02-15 21:07:23 (24148): Successfully stopped VM.
2025-02-15 21:07:23 (24148): Deregistering VM. (boinc_e64d5d2102081322, slot#0)
2025-02-15 21:07:23 (24148): Removing network bandwidth throttle group from VM.
2025-02-15 21:07:23 (24148): Removing VM from VirtualBox.
21:07:29 (24148): called boinc_finish(0)

</stderr_txt>
]]>

©2025 CERN