| Name | Theory_2390-1134264-376_1 |
| Workunit | 209426107 |
| Created | 26 Mar 2023, 22:17:15 UTC |
| Sent | 27 Mar 2023, 1:26:29 UTC |
| Report deadline | 7 Apr 2023, 1:26:29 UTC |
| Received | 7 Apr 2023, 18:10:36 UTC |
| Server state | Over |
| Outcome | Success |
| Client state | Done |
| Exit status | 0 (0x00000000) |
| Computer ID | 10803056 |
| Run time | 3 days 13 hours 14 min 52 sec |
| CPU time | 2 days 3 hours 28 min 53 sec |
| Validate state | Valid |
| Credit | 3,860.63 |
| Device peak FLOPS | 5.43 GFLOPS |
| Application version | Theory Simulation v300.07 (vbox64_theory) windows_x86_64 |
| Peak working set size | 80.94 MB |
| Peak swap size | 76.55 MB |
| Peak disk usage | 1.90 GB |
Stderr output
<core_client_version>7.20.2</core_client_version> <![CDATA[ <stderr_txt> = 'running') 2023-04-01 21:02:45 (21360): VM state change detected. (old = 'running', new = 'paused') 2023-04-02 07:29:01 (21360): Error in resume VM for VM: -2135228414 Command: VBoxManage -q controlvm "boinc_c59f0c2c80aefa92" resume Output: VBoxManage.exe: error: Cannot resume the machine as it is not paused (machine state: Running) VBoxManage.exe: error: Details: code VBOX_E_INVALID_VM_STATE (0x80bb0002), component ConsoleWrap, interface IConsole, callee IUnknown VBoxManage.exe: error: Context: "Resume()" at line 410 of file VBoxManageControlVM.cpp 2023-04-02 07:29:02 (21360): Guest Log: 24:02:50.039858 timesync vgsvcTimeSyncWorker: Radical host time change: 37 583 377 000 000ns (HostNow=1 680 445 741 944 000 000 ns HostLast=1 680 408 158 567 000 000 ns) 2023-04-02 07:29:02 (21360): VM state change detected. (old = 'paused', new = 'running') 2023-04-02 07:29:12 (21360): Guest Log: 24:03:00.047317 timesync vgsvcTimeSyncWorker: Radical guest time change: 37 740 141 232 000ns (GuestNow=1 680 445 751 951 480 000 ns GuestLast=1 680 408 011 810 248 000 ns fSetTimeLastLoop=true ) 2023-04-02 07:29:38 (21360): VM state change detected. (old = 'running', new = 'paused') 2023-04-02 07:29:48 (21360): VM state change detected. (old = 'paused', new = 'running') 2023-04-02 08:20:52 (21360): VM state change detected. (old = 'running', new = 'paused') 2023-04-02 08:21:02 (21360): VM state change detected. (old = 'paused', new = 'running') 2023-04-02 08:26:42 (21360): VM state change detected. (old = 'running', new = 'paused') 2023-04-02 08:26:52 (21360): VM state change detected. (old = 'paused', new = 'running') 2023-04-02 08:29:09 (21360): Status Report: Job Duration: '864000.000000' 2023-04-02 08:29:09 (21360): Status Report: Elapsed Time: '90000.000000' 2023-04-02 08:29:09 (21360): Status Report: CPU Time: '53636.828125' 2023-04-02 08:31:02 (21360): VM state change detected. (old = 'running', new = 'paused') 2023-04-02 08:31:12 (21360): VM state change detected. (old = 'paused', new = 'running') 2023-04-02 08:32:44 (21360): VM state change detected. (old = 'running', new = 'paused') 2023-04-02 08:32:54 (21360): VM state change detected. (old = 'paused', new = 'running') 2023-04-02 08:39:14 (21360): VM state change detected. (old = 'running', new = 'paused') 2023-04-02 08:39:24 (21360): VM state change detected. (old = 'paused', new = 'running') 2023-04-02 09:57:17 (21360): Stopping VM. 2023-04-02 09:57:17 (21360): Error in stop VM for VM: -108 Command: VBoxManage -q controlvm "boinc_c59f0c2c80aefa92" savestate Output: 2023-04-02 09:57:17 (21360): VM did not stop when requested. 2023-04-02 09:57:17 (21360): VM was successfully terminated. 2023-04-02 09:58:31 (13416): Detected: vboxwrapper 26206 2023-04-02 09:58:31 (13416): Detected: BOINC client v7.20.2 2023-04-02 09:58:32 (13416): Detected: VirtualBox VboxManage Interface (Version: 6.1.26) 2023-04-02 09:58:33 (13416): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2023-04-02 09:58:33 (13416): Guest Log: BIOS: VirtualBox 6.1.26 2023-04-02 09:58:33 (13416): Guest Log: CPUID EDX: 0x178bfbff 2023-04-02 09:58:33 (13416): Guest Log: BIOS: No PCI IDE controller, not probing IDE 2023-04-02 09:58:33 (13416): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors 2023-04-02 09:58:33 (13416): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032 2023-04-02 09:58:33 (13416): Guest Log: BIOS: Booting from Hard Disk... 2023-04-02 09:58:33 (13416): Guest Log: BIOS: KBD: unsupported int 16h function 03 2023-04-02 09:58:33 (13416): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 2023-04-02 09:58:33 (13416): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds 2023-04-02 09:58:33 (13416): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000) 2023-04-02 09:58:33 (13416): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log 2023-04-02 09:58:33 (13416): Guest Log: 00:00:00.000058 main Log opened 2023-03-27T03:26:25.006090000Z 2023-04-02 09:58:33 (13416): Guest Log: 00:00:00.000134 main OS Product: Linux 2023-04-02 09:58:33 (13416): Guest Log: 00:00:00.000168 main OS Release: 4.14.76-13.cernvm.x86_64 2023-04-02 09:58:33 (13416): Guest Log: 00:00:00.000200 main OS Version: #1 SMP Tue Oct 16 18:26:15 CEST 2018 2023-04-02 09:58:33 (13416): Guest Log: 00:00:00.000227 main Executable: /usr/sbin/VBoxService 2023-04-02 09:58:33 (13416): Guest Log: 00:00:00.000228 main Process ID: 3214 2023-04-02 09:58:33 (13416): Guest Log: 00:00:00.000228 main Package type: LINUX_64BITS_GENERIC 2023-04-02 09:58:33 (13416): Guest Log: 00:00:00.003601 main 5.2.6 r120293 started. Verbose level = 0 2023-04-02 09:58:33 (13416): Guest Log: 05:26:45 CEST +02:00 2023-03-27: cranky: [INFO] Detected Theory App 2023-04-02 09:58:33 (13416): Guest Log: 05:26:45 CEST +02:00 2023-03-27: cranky: [INFO] Checking CVMFS. 2023-04-02 09:58:33 (13416): Guest Log: Probing /cvmfs/sft.cern.ch... OK 2023-04-02 09:58:33 (13416): 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 2023-04-02 09:58:33 (13416): Guest Log: 2.5.2.0 4042 0 28424 25511 3 1 267325 4096000 0 65024 0 0 n/a 5 5 http://s1unl-cvmfs.openhtc.io/cvmfs/sft.cern.ch DIRECT 1 2023-04-02 09:58:33 (13416): Guest Log: Probing /cvmfs/grid.cern.ch... OK 2023-04-02 09:58:33 (13416): 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 2023-04-02 09:58:33 (13416): Guest Log: 2.5.2.0 4088 0 27384 20843 3 2 267325 4096000 0 65024 0 2 -100 7814 5093 http://s1unl-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1 2023-04-02 09:58:33 (13416): Guest Log: Probing /cvmfs/cernvm-prod.cern.ch... OK 2023-04-02 09:58:33 (13416): 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 2023-04-02 09:58:33 (13416): Guest Log: 2.5.2.0 4114 0 28392 268 3 1 267325 4096000 0 65024 0 0 n/a 4 3 http://s1unl-cvmfs.openhtc.io/cvmfs/cernvm-prod.cern.ch DIRECT 1 2023-04-02 09:58:33 (13416): Guest Log: Probing /cvmfs/alice.cern.ch... OK 2023-04-02 09:58:33 (13416): 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 2023-04-02 09:58:33 (13416): Guest Log: 2.5.2.0 4064 0 34868 15008 3 1 267325 4096000 0 65024 0 0 n/a 3711 1237 http://s1ral-cvmfs.openhtc.io/cvmfs/alice.cern.ch DIRECT 1 2023-04-02 09:58:33 (13416): Guest Log: 05:26:48 CEST +02:00 2023-03-27: cranky: [INFO] Checking runc. 2023-04-02 09:58:33 (13416): Guest Log: 05:26:48 CEST +02:00 2023-03-27: cranky: [INFO] Creating the filesystem. 2023-04-02 09:58:33 (13416): Guest Log: 05:26:48 CEST +02:00 2023-03-27: cranky: [INFO] Using /cvmfs/cernvm-prod.cern.ch/cvm3 2023-04-02 09:58:33 (13416): Guest Log: 05:26:48 CEST +02:00 2023-03-27: cranky: [INFO] Updating config.json. 2023-04-02 09:58:33 (13416): Guest Log: 05:26:48 CEST +02:00 2023-03-27: cranky: [INFO] Running Container 'runc'. 2023-04-02 09:58:33 (13416): Guest Log: job: htmld=/shared/html/job 2023-04-02 09:58:33 (13416): Guest Log: job: unpack exitcode=0 2023-04-02 09:58:33 (13416): Guest Log: 05:26:50 CEST +02:00 2023-03-27: cranky: [INFO] ===> [runRivet] Mon Mar 27 03:26:49 UTC 2023 [boinc pp jets 8000 350 - pythia8 8.301 dire-default 50000 376] 2023-04-02 09:58:33 (13416): Guest Log: 00:37:35.899878 timesync vgsvcTimeSyncWorker: Radical host time change: 43 168 940 000 000ns (HostNow=1 679 933 008 845 000 000 ns HostLast=1 679 889 839 905 000 000 ns) 2023-04-02 09:58:33 (13416): Guest Log: 00:37:45.935198 timesync vgsvcTimeSyncWorker: Radical guest time change: 43 178 303 519 000ns (GuestNow=1 679 933 018 959 764 000 ns GuestLast=1 679 889 840 656 245 000 ns fSetTimeLastLoop=true ) 2023-04-02 09:58:33 (13416): Guest Log: 00:42:36.440014 timesync vgsvcTimeSyncWorker: Radical host time change: 14 795 638 000 000ns (HostNow=1 679 948 105 052 000 000 ns HostLast=1 679 933 309 414 000 000 ns) 2023-04-02 09:58:33 (13416): Guest Log: 00:42:46.459367 timesync vgsvcTimeSyncWorker: Radical guest time change: 14 805 606 786 000ns (GuestNow=1 679 948 115 071 363 000 ns GuestLast=1 679 933 309 464 577 000 ns fSetTimeLastLoop=true ) 2023-04-02 09:58:33 (13416): Guest Log: 02:01:14.344928 timesync vgsvcTimeSyncWorker: Radical host time change: 3 570 574 000 000ns (HostNow=1 679 956 411 102 000 000 ns HostLast=1 679 952 840 528 000 000 ns) 2023-04-02 09:58:33 (13416): Guest Log: 02:01:24.345757 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 598 145 930 000ns (GuestNow=1 679 956 421 102 841 000 ns GuestLast=1 679 952 822 956 911 000 ns fSetTimeLastLoop=true ) 2023-04-02 09:58:33 (13416): Guest Log: 02:09:05.276015 timesync vgsvcTimeSyncWorker: Radical host time change: 3 745 640 000 000ns (HostNow=1 679 960 617 631 000 000 ns HostLast=1 679 956 871 991 000 000 ns) 2023-04-02 09:58:33 (13416): Guest Log: 02:09:15.301258 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 745 623 249 000ns (GuestNow=1 679 960 627 656 278 000 ns GuestLast=1 679 956 882 033 029 000 ns fSetTimeLastLoop=true ) 2023-04-02 09:58:33 (13416): Guest Log: 02:12:25.648600 timesync vgsvcTimeSyncWorker: Radical host time change: 3 612 448 000 000ns (HostNow=1 679 964 420 418 000 000 ns HostLast=1 679 960 807 970 000 000 ns) 2023-04-02 09:58:33 (13416): Guest Log: 02:12:35.721219 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 612 487 015 000ns (GuestNow=1 679 964 430 490 623 000 ns GuestLast=1 679 960 818 003 608 000 ns fSetTimeLastLoop=true ) 2023-04-02 09:58:33 (13416): Guest Log: 02:16:46.184213 timesync vgsvcTimeSyncWorker: Radical host time change: 3 731 523 000 000ns (HostNow=1 679 968 412 312 000 000 ns HostLast=1 679 964 680 789 000 000 ns) 2023-04-02 09:58:33 (13416): Guest Log: 02:16:56.193240 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 741 367 434 000ns (GuestNow=1 679 968 422 321 038 000 ns GuestLast=1 679 964 680 953 604 000 ns fSetTimeLastLoop=true ) 2023-04-02 09:58:33 (13416): Guest Log: 02:19:26.544200 timesync vgsvcTimeSyncWorker: Radical host time change: 310 055 778 000 000ns (HostNow=1 680 278 618 432 000 000 ns HostLast=1 679 968 562 654 000 000 ns) 2023-04-02 09:58:33 (13416): Guest Log: 02:19:36.560682 timesync vgsvcTimeSyncWorker: Radical guest time change: 310 055 776 522 000ns (GuestNow=1 680 278 628 448 498 000 ns GuestLast=1 679 968 572 671 976 000 ns fSetTimeLastLoop=true ) 2023-04-02 09:58:33 (13416): Guest Log: 14:03:35.770654 timesync vgsvcTimeSyncWorker: Radical host time change: 43 810 310 000 000ns (HostNow=1 680 364 763 449 000 000 ns HostLast=1 680 320 953 139 000 000 ns) 2023-04-02 09:58:33 (13416): Guest Log: 14:03:45.780390 timesync vgsvcTimeSyncWorker: Radical guest time change: 43 905 800 304 000ns (GuestNow=1 680 364 773 458 752 000 ns GuestLast=1 680 320 867 658 448 000 ns fSetTimeLastLoop=true ) 2023-04-02 09:58:33 (13416): Guest Log: 16:41:28.812586 timesync vgsvcTimeSyncWorker: Radical host time change: 7 278 450 000 000ns (HostNow=1 680 381 530 583 000 000 ns HostLast=1 680 374 252 133 000 000 ns) 2023-04-02 09:58:33 (13416): Guest Log: 16:41:38.820482 timesync vgsvcTimeSyncWorker: Radical guest time change: 7 304 099 953 000ns (GuestNow=1 680 381 540 590 900 000 ns GuestLast=1 680 374 236 490 947 000 ns fSetTimeLastLoop=true ) 2023-04-02 09:58:33 (13416): Guest Log: 24:02:50.039858 timesync vgsvcTimeSyncWorker: Radical host time change: 37 583 377 000 000ns (HostNow=1 680 445 741 944 000 000 ns HostLast=1 680 408 158 567 000 000 ns) 2023-04-02 09:58:33 (13416): Guest Log: 24:03:00.047317 timesync vgsvcTimeSyncWorker: Radical guest time change: 37 740 141 232 000ns (GuestNow=1 680 445 751 951 480 000 ns GuestLast=1 680 408 011 810 248 000 ns fSetTimeLastLoop=true ) 2023-04-02 09:58:33 (13416): Starting VM using VBoxManage interface. (boinc_c59f0c2c80aefa92, slot#6) 2023-04-02 09:58:39 (13416): Successfully started VM. (PID = '16984') 2023-04-02 09:58:39 (13416): Reporting VM Process ID to BOINC. 2023-04-02 09:58:39 (13416): Guest Log: BIOS: VirtualBox 6.1.26 2023-04-02 09:58:39 (13416): Guest Log: CPUID EDX: 0x178bfbff 2023-04-02 09:58:39 (13416): Guest Log: BIOS: No PCI IDE controller, not probing IDE 2023-04-02 09:58:39 (13416): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors 2023-04-02 09:58:39 (13416): VM state change detected. (old = 'poweredoff', new = 'running') 2023-04-02 09:58:39 (13416): Detected: Web Application Enabled (http://localhost:53068) 2023-04-02 09:58:39 (13416): Status Report: Job Duration: '864000.000000' 2023-04-02 09:58:39 (13416): Status Report: Elapsed Time: '95250.000000' 2023-04-02 09:58:39 (13416): Status Report: CPU Time: '56778.812500' 2023-04-02 09:58:39 (13416): Preference change detected 2023-04-02 09:58:39 (13416): Setting CPU throttle for VM. (50%) 2023-04-02 09:58:39 (13416): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds)) 2023-04-02 09:58:41 (13416): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032 2023-04-02 09:58:41 (13416): Guest Log: BIOS: Booting from Hard Disk... 2023-04-02 09:58:43 (13416): Guest Log: BIOS: KBD: unsupported int 16h function 03 2023-04-02 09:58:43 (13416): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 2023-04-02 09:59:06 (13416): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds 2023-04-02 09:59:06 (13416): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000) 2023-04-02 09:59:08 (13416): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log 2023-04-02 09:59:08 (13416): Guest Log: 00:00:00.000043 main Log opened 2023-04-02T16:59:08.612844000Z 2023-04-02 09:59:08 (13416): Guest Log: 00:00:00.000098 main OS Product: Linux 2023-04-02 09:59:08 (13416): Guest Log: 00:00:00.000118 main OS Release: 4.14.76-13.cernvm.x86_64 2023-04-02 09:59:08 (13416): Guest Log: 00:00:00.000140 main OS Version: #1 SMP Tue Oct 16 18:26:15 CEST 2018 2023-04-02 09:59:08 (13416): Guest Log: 00:00:00.000169 main Executable: /usr/sbin/VBoxService 2023-04-02 09:59:08 (13416): Guest Log: 00:00:00.000170 main Process ID: 3216 2023-04-02 09:59:08 (13416): Guest Log: 00:00:00.000170 main Package type: LINUX_64BITS_GENERIC 2023-04-02 09:59:08 (13416): Guest Log: 00:00:00.002215 main 5.2.6 r120293 started. Verbose level = 0 2023-04-02 09:59:29 (13416): Guest Log: 11:59:29 CDT -05:00 2023-04-02: cranky: [INFO] Detected Theory App 2023-04-02 09:59:29 (13416): Guest Log: 11:59:29 CDT -05:00 2023-04-02: cranky: [INFO] Checking CVMFS. 2023-04-02 09:59:30 (13416): Guest Log: Probing /cvmfs/sft.cern.ch... OK 2023-04-02 09:59:30 (13416): 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 2023-04-02 09:59:30 (13416): Guest Log: 2.5.2.0 4089 0 28464 25560 3 1 1023259 4096001 0 65024 0 0 n/a 0 0 http://s1ral-cvmfs.openhtc.io/cvmfs/sft.cern.ch DIRECT 1 2023-04-02 09:59:31 (13416): Guest Log: Probing /cvmfs/grid.cern.ch... OK 2023-04-02 09:59:31 (13416): 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 2023-04-02 09:59:31 (13416): Guest Log: 2.5.2.0 4046 0 25608 20895 3 2 1023259 4096001 0 65024 0 2 0 5676 3280 http://s1cern-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1 2023-04-02 09:59:31 (13416): Guest Log: Probing /cvmfs/cernvm-prod.cern.ch... OK 2023-04-02 09:59:32 (13416): 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 2023-04-02 09:59:32 (13416): Guest Log: 2.5.2.0 4069 0 27216 268 3 1 1023259 4096001 0 65024 0 0 n/a 0 0 http://s1bnl-cvmfs.openhtc.io/cvmfs/cernvm-prod.cern.ch DIRECT 1 2023-04-02 09:59:32 (13416): Guest Log: Probing /cvmfs/alice.cern.ch... OK 2023-04-02 09:59:32 (13416): 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 2023-04-02 09:59:32 (13416): Guest Log: 2.5.2.0 4119 0 32860 15060 3 1 1023259 4096001 0 65024 0 0 n/a 3739 408 http://s1cern-cvmfs.openhtc.io/cvmfs/alice.cern.ch DIRECT 1 2023-04-02 09:59:32 (13416): Guest Log: 11:59:32 CDT -05:00 2023-04-02: cranky: [INFO] Checking runc. 2023-04-02 09:59:32 (13416): Guest Log: 11:59:32 CDT -05:00 2023-04-02: cranky: [INFO] Creating the filesystem. 2023-04-02 09:59:33 (13416): Guest Log: 11:59:32 CDT -05:00 2023-04-02: cranky: [INFO] Using /cvmfs/cernvm-prod.cern.ch/cvm3 2023-04-02 09:59:33 (13416): Guest Log: 11:59:33 CDT -05:00 2023-04-02: cranky: [INFO] Updating config.json. 2023-04-02 09:59:33 (13416): Guest Log: 11:59:33 CDT -05:00 2023-04-02: cranky: [INFO] Running Container 'runc'. 2023-04-02 09:59:33 (13416): Guest Log: job: htmld=/shared/html/job 2023-04-02 09:59:33 (13416): Guest Log: job: unpack exitcode=0 2023-04-02 09:59:35 (13416): Guest Log: 11:59:35 CDT -05:00 2023-04-02: cranky: [INFO] ===> [runRivet] Sun Apr 2 16:59:33 UTC 2023 [boinc pp jets 8000 350 - pythia8 8.301 dire-default 50000 376] 2023-04-02 10:11:09 (12808): Detected: vboxwrapper 26206 2023-04-02 10:11:09 (12808): Detected: BOINC client v7.20.2 2023-04-02 10:11:10 (12808): Detected: VirtualBox VboxManage Interface (Version: 6.1.26) 2023-04-02 10:11:10 (12808): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2023-04-02 10:11:11 (12808): Guest Log: BIOS: VirtualBox 6.1.26 2023-04-02 10:11:11 (12808): Guest Log: CPUID EDX: 0x178bfbff 2023-04-02 10:11:11 (12808): Guest Log: BIOS: No PCI IDE controller, not probing IDE 2023-04-02 10:11:11 (12808): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors 2023-04-02 10:11:11 (12808): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032 2023-04-02 10:11:11 (12808): Guest Log: BIOS: Booting from Hard Disk... 2023-04-02 10:11:11 (12808): Guest Log: BIOS: KBD: unsupported int 16h function 03 2023-04-02 10:11:11 (12808): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 2023-04-02 10:11:11 (12808): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds 2023-04-02 10:11:11 (12808): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000) 2023-04-02 10:11:11 (12808): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log 2023-04-02 10:11:11 (12808): Guest Log: 00:00:00.000043 main Log opened 2023-04-02T16:59:08.612844000Z 2023-04-02 10:11:11 (12808): Guest Log: 00:00:00.000098 main OS Product: Linux 2023-04-02 10:11:11 (12808): Guest Log: 00:00:00.000118 main OS Release: 4.14.76-13.cernvm.x86_64 2023-04-02 10:11:11 (12808): Guest Log: 00:00:00.000140 main OS Version: #1 SMP Tue Oct 16 18:26:15 CEST 2018 2023-04-02 10:11:11 (12808): Guest Log: 00:00:00.000169 main Executable: /usr/sbin/VBoxService 2023-04-02 10:11:11 (12808): Guest Log: 00:00:00.000170 main Process ID: 3216 2023-04-02 10:11:11 (12808): Guest Log: 00:00:00.000170 main Package type: LINUX_64BITS_GENERIC 2023-04-02 10:11:11 (12808): Guest Log: 00:00:00.002215 main 5.2.6 r120293 started. Verbose level = 0 2023-04-02 10:11:11 (12808): Guest Log: 11:59:29 CDT -05:00 2023-04-02: cranky: [INFO] Detected Theory App 2023-04-02 10:11:11 (12808): Guest Log: 11:59:29 CDT -05:00 2023-04-02: cranky: [INFO] Checking CVMFS. 2023-04-02 10:11:11 (12808): Guest Log: Probing /cvmfs/sft.cern.ch... OK 2023-04-02 10:11:11 (12808): 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 2023-04-02 10:11:11 (12808): Guest Log: 2.5.2.0 4089 0 28464 25560 3 1 1023259 4096001 0 65024 0 0 n/a 0 0 http://s1ral-cvmfs.openhtc.io/cvmfs/sft.cern.ch DIRECT 1 2023-04-02 10:11:11 (12808): Guest Log: Probing /cvmfs/grid.cern.ch... OK 2023-04-02 10:11:11 (12808): 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 2023-04-02 10:11:11 (12808): Guest Log: 2.5.2.0 4046 0 25608 20895 3 2 1023259 4096001 0 65024 0 2 0 5676 3280 http://s1cern-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1 2023-04-02 10:11:11 (12808): Guest Log: Probing /cvmfs/cernvm-prod.cern.ch... OK 2023-04-02 10:11:11 (12808): 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 2023-04-02 10:11:11 (12808): Guest Log: 2.5.2.0 4069 0 27216 268 3 1 1023259 4096001 0 65024 0 0 n/a 0 0 http://s1bnl-cvmfs.openhtc.io/cvmfs/cernvm-prod.cern.ch DIRECT 1 2023-04-02 10:11:11 (12808): Guest Log: Probing /cvmfs/alice.cern.ch... OK 2023-04-02 10:11:11 (12808): 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 2023-04-02 10:11:11 (12808): Guest Log: 2.5.2.0 4119 0 32860 15060 3 1 1023259 4096001 0 65024 0 0 n/a 3739 408 http://s1cern-cvmfs.openhtc.io/cvmfs/alice.cern.ch DIRECT 1 2023-04-02 10:11:11 (12808): Guest Log: 11:59:32 CDT -05:00 2023-04-02: cranky: [INFO] Checking runc. 2023-04-02 10:11:11 (12808): Guest Log: 11:59:32 CDT -05:00 2023-04-02: cranky: [INFO] Creating the filesystem. 2023-04-02 10:11:11 (12808): Guest Log: 11:59:32 CDT -05:00 2023-04-02: cranky: [INFO] Using /cvmfs/cernvm-prod.cern.ch/cvm3 2023-04-02 10:11:11 (12808): Guest Log: 11:59:33 CDT -05:00 2023-04-02: cranky: [INFO] Updating config.json. 2023-04-02 10:11:11 (12808): Guest Log: 11:59:33 CDT -05:00 2023-04-02: cranky: [INFO] Running Container 'runc'. 2023-04-02 10:11:11 (12808): Guest Log: job: htmld=/shared/html/job 2023-04-02 10:11:11 (12808): Guest Log: job: unpack exitcode=0 2023-04-02 10:11:11 (12808): Guest Log: 11:59:35 CDT -05:00 2023-04-02: cranky: [INFO] ===> [runRivet] Sun Apr 2 16:59:33 UTC 2023 [boinc pp jets 8000 350 - pythia8 8.301 dire-default 50000 376] 2023-04-02 10:11:11 (12808): Starting VM using VBoxManage interface. (boinc_c59f0c2c80aefa92, slot#6) 2023-04-02 10:11:16 (12808): Successfully started VM. (PID = '14768') 2023-04-02 10:11:16 (12808): Reporting VM Process ID to BOINC. 2023-04-02 10:11:16 (12808): Guest Log: BIOS: VirtualBox 6.1.26 2023-04-02 10:11:16 (12808): Guest Log: CPUID EDX: 0x178bfbff 2023-04-02 10:11:16 (12808): Guest Log: BIOS: No PCI IDE controller, not probing IDE 2023-04-02 10:11:16 (12808): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors 2023-04-02 10:11:16 (12808): VM state change detected. (old = 'poweredoff', new = 'running') 2023-04-02 10:11:16 (12808): Detected: Web Application Enabled (http://localhost:53068) 2023-04-02 10:11:16 (12808): Status Report: Job Duration: '864000.000000' 2023-04-02 10:11:16 (12808): Status Report: Elapsed Time: '95906.000000' 2023-04-02 10:11:16 (12808): Status Report: CPU Time: '57145.187500' 2023-04-02 10:11:16 (12808): Preference change detected 2023-04-02 10:11:16 (12808): Setting CPU throttle for VM. (50%) 2023-04-02 10:11:16 (12808): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds)) 2023-04-02 10:11:18 (12808): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032 2023-04-02 10:11:18 (12808): Guest Log: BIOS: Booting from Hard Disk... 2023-04-02 10:11:21 (12808): Guest Log: BIOS: KBD: unsupported int 16h function 03 2023-04-02 10:11:21 (12808): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 2023-04-02 10:11:47 (12808): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds 2023-04-02 10:11:47 (12808): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000) 2023-04-02 10:11:49 (12808): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log 2023-04-02 10:11:49 (12808): Guest Log: 00:00:00.014662 main Log opened 2023-04-02T17:11:49.883004000Z 2023-04-02 10:11:49 (12808): Guest Log: 00:00:00.016848 main OS Product: Linux 2023-04-02 10:11:49 (12808): Guest Log: 00:00:00.017061 main OS Release: 4.14.76-13.cernvm.x86_64 2023-04-02 10:11:49 (12808): Guest Log: 00:00:00.017172 main OS Version: #1 SMP Tue Oct 16 18:26:15 CEST 2018 2023-04-02 10:11:49 (12808): Guest Log: 00:00:00.017302 main Executable: /usr/sbin/VBoxService 2023-04-02 10:11:49 (12808): Guest Log: 00:00:00.017303 main Process ID: 3222 2023-04-02 10:11:49 (12808): Guest Log: 00:00:00.017303 main Package type: LINUX_64BITS_GENERIC 2023-04-02 10:11:49 (12808): Guest Log: 00:00:00.018662 main 5.2.6 r120293 started. Verbose level = 0 2023-04-02 10:12:09 (12808): Guest Log: 12:12:09 CDT -05:00 2023-04-02: cranky: [INFO] Detected Theory App 2023-04-02 10:12:09 (12808): Guest Log: 12:12:09 CDT -05:00 2023-04-02: cranky: [INFO] Checking CVMFS. 2023-04-02 10:12:09 (12808): Guest Log: Probing /cvmfs/sft.cern.ch... OK 2023-04-02 10:12:09 (12808): 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 2023-04-02 10:12:09 (12808): Guest Log: 2.5.2.0 4055 0 28332 25560 3 1 1023277 4096001 0 65024 0 0 n/a 0 0 http://s1cern-cvmfs.openhtc.io/cvmfs/sft.cern.ch DIRECT 1 2023-04-02 10:12:09 (12808): Guest Log: Probing /cvmfs/grid.cern.ch... OK 2023-04-02 10:12:10 (12808): 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 2023-04-02 10:12:10 (12808): Guest Log: 2.5.2.0 4123 0 27456 20895 3 2 1023277 4096001 0 65024 0 2 100 0 0 http://s1unl-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1 2023-04-02 10:12:10 (12808): Guest Log: Probing /cvmfs/cernvm-prod.cern.ch... OK 2023-04-02 10:12:11 (12808): 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 2023-04-02 10:12:11 (12808): Guest Log: 2.5.2.0 4078 0 27212 268 3 1 1023277 4096001 0 65024 0 0 n/a 0 0 http://s1cern-cvmfs.openhtc.io/cvmfs/cernvm-prod.cern.ch DIRECT 1 2023-04-02 10:12:11 (12808): Guest Log: Probing /cvmfs/alice.cern.ch... OK 2023-04-02 10:12:12 (12808): 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 2023-04-02 10:12:12 (12808): Guest Log: 2.5.2.0 4102 0 34888 15060 3 1 1023277 4096001 0 65024 0 0 n/a 0 0 http://s1cern-cvmfs.openhtc.io/cvmfs/alice.cern.ch DIRECT 1 2023-04-02 10:12:12 (12808): Guest Log: 12:12:12 CDT -05:00 2023-04-02: cranky: [INFO] Checking runc. 2023-04-02 10:12:12 (12808): Guest Log: 12:12:12 CDT -05:00 2023-04-02: cranky: [INFO] Creating the filesystem. 2023-04-02 10:12:12 (12808): Guest Log: 12:12:12 CDT -05:00 2023-04-02: cranky: [INFO] Using /cvmfs/cernvm-prod.cern.ch/cvm3 2023-04-02 10:12:12 (12808): Guest Log: 12:12:12 CDT -05:00 2023-04-02: cranky: [INFO] Updating config.json. 2023-04-02 10:12:12 (12808): Guest Log: 12:12:12 CDT -05:00 2023-04-02: cranky: [INFO] Running Container 'runc'. 2023-04-02 10:12:12 (12808): Guest Log: job: htmld=/shared/html/job 2023-04-02 10:12:12 (12808): Guest Log: job: unpack exitcode=0 2023-04-02 10:12:14 (12808): Guest Log: 12:12:14 CDT -05:00 2023-04-02: cranky: [INFO] ===> [runRivet] Sun Apr 2 17:12:12 UTC 2023 [boinc pp jets 8000 350 - pythia8 8.301 dire-default 50000 376] 2023-04-02 11:51:20 (12808): Status Report: Job Duration: '864000.000000' 2023-04-02 11:51:20 (12808): Status Report: Elapsed Time: '101906.000000' 2023-04-02 11:51:20 (12808): Status Report: CPU Time: '60747.296875' 2023-04-02 13:31:23 (12808): Status Report: Job Duration: '864000.000000' 2023-04-02 13:31:23 (12808): Status Report: Elapsed Time: '107906.000000' 2023-04-02 13:31:23 (12808): Status Report: CPU Time: '64411.890625' 2023-04-02 15:11:27 (12808): Status Report: Job Duration: '864000.000000' 2023-04-02 15:11:27 (12808): Status Report: Elapsed Time: '113906.000000' 2023-04-02 15:11:27 (12808): Status Report: CPU Time: '68081.531250' 2023-04-02 16:51:31 (12808): Status Report: Job Duration: '864000.000000' 2023-04-02 16:51:31 (12808): Status Report: Elapsed Time: '119906.000000' 2023-04-02 16:51:31 (12808): Status Report: CPU Time: '71755.562500' 2023-04-02 18:31:34 (12808): Status Report: Job Duration: '864000.000000' 2023-04-02 18:31:34 (12808): Status Report: Elapsed Time: '125906.000000' 2023-04-02 18:31:34 (12808): Status Report: CPU Time: '75430.218750' 2023-04-02 19:12:58 (12808): VM state change detected. (old = 'running', new = 'paused') 2023-04-02 19:13:08 (12808): VM state change detected. (old = 'paused', new = 'running') 2023-04-02 20:11:49 (12808): Status Report: Job Duration: '864000.000000' 2023-04-02 20:11:49 (12808): Status Report: Elapsed Time: '131906.000000' 2023-04-02 20:11:49 (12808): Status Report: CPU Time: '79105.281250' 2023-04-02 20:33:33 (3532): Detected: vboxwrapper 26206 2023-04-02 20:33:33 (3532): Detected: BOINC client v7.20.2 2023-04-02 20:33:34 (3532): Detected: VirtualBox VboxManage Interface (Version: 6.1.26) 2023-04-02 20:33:34 (3532): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2023-04-02 20:33:35 (3532): Guest Log: BIOS: VirtualBox 6.1.26 2023-04-02 20:33:35 (3532): Guest Log: CPUID EDX: 0x178bfbff 2023-04-02 20:33:35 (3532): Guest Log: BIOS: No PCI IDE controller, not probing IDE 2023-04-02 20:33:35 (3532): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors 2023-04-02 20:33:35 (3532): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032 2023-04-02 20:33:35 (3532): Guest Log: BIOS: Booting from Hard Disk... 2023-04-02 20:33:35 (3532): Guest Log: BIOS: KBD: unsupported int 16h function 03 2023-04-02 20:33:35 (3532): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 2023-04-02 20:33:35 (3532): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds 2023-04-02 20:33:35 (3532): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000) 2023-04-02 20:33:35 (3532): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log 2023-04-02 20:33:35 (3532): Guest Log: 00:00:00.014662 main Log opened 2023-04-02T17:11:49.883004000Z 2023-04-02 20:33:35 (3532): Guest Log: 00:00:00.016848 main OS Product: Linux 2023-04-02 20:33:35 (3532): Guest Log: 00:00:00.017061 main OS Release: 4.14.76-13.cernvm.x86_64 2023-04-02 20:33:35 (3532): Guest Log: 00:00:00.017172 main OS Version: #1 SMP Tue Oct 16 18:26:15 CEST 2018 2023-04-02 20:33:35 (3532): Guest Log: 00:00:00.017302 main Executable: /usr/sbin/VBoxService 2023-04-02 20:33:35 (3532): Guest Log: 00:00:00.017303 main Process ID: 3222 2023-04-02 20:33:35 (3532): Guest Log: 00:00:00.017303 main Package type: LINUX_64BITS_GENERIC 2023-04-02 20:33:35 (3532): Guest Log: 00:00:00.018662 main 5.2.6 r120293 started. Verbose level = 0 2023-04-02 20:33:35 (3532): Guest Log: 12:12:09 CDT -05:00 2023-04-02: cranky: [INFO] Detected Theory App 2023-04-02 20:33:35 (3532): Guest Log: 12:12:09 CDT -05:00 2023-04-02: cranky: [INFO] Checking CVMFS. 2023-04-02 20:33:35 (3532): Guest Log: Probing /cvmfs/sft.cern.ch... OK 2023-04-02 20:33:35 (3532): 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 2023-04-02 20:33:35 (3532): Guest Log: 2.5.2.0 4055 0 28332 25560 3 1 1023277 4096001 0 65024 0 0 n/a 0 0 http://s1cern-cvmfs.openhtc.io/cvmfs/sft.cern.ch DIRECT 1 2023-04-02 20:33:35 (3532): Guest Log: Probing /cvmfs/grid.cern.ch... OK 2023-04-02 20:33:35 (3532): 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 2023-04-02 20:33:35 (3532): Guest Log: 2.5.2.0 4123 0 27456 20895 3 2 1023277 4096001 0 65024 0 2 100 0 0 http://s1unl-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1 2023-04-02 20:33:35 (3532): Guest Log: Probing /cvmfs/cernvm-prod.cern.ch... OK 2023-04-02 20:33:35 (3532): 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 2023-04-02 20:33:35 (3532): Guest Log: 2.5.2.0 4078 0 27212 268 3 1 1023277 4096001 0 65024 0 0 n/a 0 0 http://s1cern-cvmfs.openhtc.io/cvmfs/cernvm-prod.cern.ch DIRECT 1 2023-04-02 20:33:35 (3532): Guest Log: Probing /cvmfs/alice.cern.ch... OK 2023-04-02 20:33:35 (3532): 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 2023-04-02 20:33:35 (3532): Guest Log: 2.5.2.0 4102 0 34888 15060 3 1 1023277 4096001 0 65024 0 0 n/a 0 0 http://s1cern-cvmfs.openhtc.io/cvmfs/alice.cern.ch DIRECT 1 2023-04-02 20:33:35 (3532): Guest Log: 12:12:12 CDT -05:00 2023-04-02: cranky: [INFO] Checking runc. 2023-04-02 20:33:35 (3532): Guest Log: 12:12:12 CDT -05:00 2023-04-02: cranky: [INFO] Creating the filesystem. 2023-04-02 20:33:35 (3532): Guest Log: 12:12:12 CDT -05:00 2023-04-02: cranky: [INFO] Using /cvmfs/cernvm-prod.cern.ch/cvm3 2023-04-02 20:33:35 (3532): Guest Log: 12:12:12 CDT -05:00 2023-04-02: cranky: [INFO] Updating config.json. 2023-04-02 20:33:35 (3532): Guest Log: 12:12:12 CDT -05:00 2023-04-02: cranky: [INFO] Running Container 'runc'. 2023-04-02 20:33:35 (3532): Guest Log: job: htmld=/shared/html/job 2023-04-02 20:33:35 (3532): Guest Log: job: unpack exitcode=0 2023-04-02 20:33:35 (3532): Guest Log: 12:12:14 CDT -05:00 2023-04-02: cranky: [INFO] ===> [runRivet] Sun Apr 2 17:12:12 UTC 2023 [boinc pp jets 8000 350 - pythia8 8.301 dire-default 50000 376] 2023-04-02 20:33:35 (3532): Starting VM using VBoxManage interface. (boinc_c59f0c2c80aefa92, slot#6) 2023-04-02 20:33:40 (3532): Successfully started VM. (PID = '15508') 2023-04-02 20:33:40 (3532): Reporting VM Process ID to BOINC. 2023-04-02 20:33:40 (3532): Guest Log: BIOS: VirtualBox 6.1.26 2023-04-02 20:33:40 (3532): Guest Log: CPUID EDX: 0x178bfbff 2023-04-02 20:33:40 (3532): Guest Log: BIOS: No PCI IDE controller, not probing IDE 2023-04-02 20:33:40 (3532): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors 2023-04-02 20:33:40 (3532): VM state change detected. (old = 'poweredoff', new = 'running') 2023-04-02 20:33:40 (3532): Detected: Web Application Enabled (http://localhost:53068) 2023-04-02 20:33:40 (3532): Status Report: Job Duration: '864000.000000' 2023-04-02 20:33:40 (3532): Status Report: Elapsed Time: '133032.000000' 2023-04-02 20:33:40 (3532): Status Report: CPU Time: '79786.812500' 2023-04-02 20:33:40 (3532): Preference change detected 2023-04-02 20:33:40 (3532): Setting CPU throttle for VM. (50%) 2023-04-02 20:33:41 (3532): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds)) 2023-04-02 20:33:42 (3532): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032 2023-04-02 20:33:42 (3532): Guest Log: BIOS: Booting from Hard Disk... 2023-04-02 20:33:45 (3532): Guest Log: BIOS: KBD: unsupported int 16h function 03 2023-04-02 20:33:45 (3532): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 2023-04-02 20:34:05 (3532): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds 2023-04-02 20:34:05 (3532): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000) 2023-04-02 20:34:07 (3532): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log 2023-04-02 20:34:07 (3532): Guest Log: 00:00:00.000049 main Log opened 2023-04-03T03:34:07.608472000Z 2023-04-02 20:34:07 (3532): Guest Log: 00:00:00.000114 main OS Product: Linux 2023-04-02 20:34:07 (3532): Guest Log: 00:00:00.000142 main OS Release: 4.14.76-13.cernvm.x86_64 2023-04-02 20:34:07 (3532): Guest Log: 00:00:00.000170 main OS Version: #1 SMP Tue Oct 16 18:26:15 CEST 2018 2023-04-02 20:34:07 (3532): Guest Log: 00:00:00.000197 main Executable: /usr/sbin/VBoxService 2023-04-02 20:34:07 (3532): Guest Log: 00:00:00.000198 main Process ID: 3216 2023-04-02 20:34:07 (3532): Guest Log: 00:00:00.000198 main Package type: LINUX_64BITS_GENERIC 2023-04-02 20:34:07 (3532): Guest Log: 00:00:00.002990 main 5.2.6 r120293 started. Verbose level = 0 2023-04-02 20:34:25 (3532): Guest Log: 22:34:26 CDT -05:00 2023-04-02: cranky: [INFO] Detected Theory App 2023-04-02 20:34:25 (3532): Guest Log: 22:34:26 CDT -05:00 2023-04-02: cranky: [INFO] Checking CVMFS. 2023-04-02 20:34:26 (3532): Guest Log: Probing /cvmfs/sft.cern.ch... OK 2023-04-02 20:34:26 (3532): 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 2023-04-02 20:34:26 (3532): Guest Log: 2.5.2.0 4051 0 28304 25566 3 1 1045725 4096001 0 65024 0 0 n/a 0 0 http://s1unl-cvmfs.openhtc.io/cvmfs/sft.cern.ch DIRECT 1 2023-04-02 20:34:26 (3532): Guest Log: Probing /cvmfs/grid.cern.ch... OK 2023-04-02 20:34:28 (3532): 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 2023-04-02 20:34:28 (3532): Guest Log: 2.5.2.0 4074 0 28128 20899 3 2 1045725 4096001 0 65024 0 2 0 5675 2991 http://s1bnl-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1 2023-04-02 20:34:28 (3532): Guest Log: Probing /cvmfs/cernvm-prod.cern.ch... OK 2023-04-02 20:34:29 (3532): 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 2023-04-02 20:34:29 (3532): Guest Log: 2.5.2.0 4095 0 28300 268 3 1 1045725 4096001 0 65024 0 0 n/a 0 0 http://s1ihep-cvmfs.openhtc.io/cvmfs/cernvm-prod.cern.ch DIRECT 1 2023-04-02 20:34:29 (3532): Guest Log: Probing /cvmfs/alice.cern.ch... OK 2023-04-02 20:34:29 (3532): 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 2023-04-02 20:34:29 (3532): Guest Log: 2.5.2.0 4116 0 34912 15064 3 1 1045725 4096001 0 65024 0 0 n/a 3740 2919 http://s1fnal-cvmfs.openhtc.io/cvmfs/alice.cern.ch DIRECT 1 2023-04-02 20:34:29 (3532): Guest Log: 22:34:30 CDT -05:00 2023-04-02: cranky: [INFO] Checking runc. 2023-04-02 20:34:29 (3532): Guest Log: 22:34:30 CDT -05:00 2023-04-02: cranky: [INFO] Creating the filesystem. 2023-04-02 20:34:29 (3532): Guest Log: 22:34:30 CDT -05:00 2023-04-02: cranky: [INFO] Using /cvmfs/cernvm-prod.cern.ch/cvm3 2023-04-02 20:34:29 (3532): Guest Log: 22:34:30 CDT -05:00 2023-04-02: cranky: [INFO] Updating config.json. 2023-04-02 20:34:29 (3532): Guest Log: 22:34:30 CDT -05:00 2023-04-02: cranky: [INFO] Running Container 'runc'. 2023-04-02 20:34:30 (3532): Guest Log: job: htmld=/shared/html/job 2023-04-02 20:34:30 (3532): Guest Log: job: unpack exitcode=0 2023-04-02 20:34:31 (3532): Guest Log: 22:34:32 CDT -05:00 2023-04-02: cranky: [INFO] ===> [runRivet] Mon Apr 3 03:34:30 UTC 2023 [boinc pp jets 8000 350 - pythia8 8.301 dire-default 50000 376] 2023-04-02 21:16:10 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-03 07:55:15 (3532): Error in resume VM for VM: -2135228414 Command: VBoxManage -q controlvm "boinc_c59f0c2c80aefa92" resume Output: VBoxManage.exe: error: Cannot resume the machine as it is not paused (machine state: Running) VBoxManage.exe: error: Details: code VBOX_E_INVALID_VM_STATE (0x80bb0002), component ConsoleWrap, interface IConsole, callee IUnknown VBoxManage.exe: error: Context: "Resume()" at line 410 of file VBoxManageControlVM.cpp 2023-04-03 07:55:16 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-03 07:55:17 (3532): Guest Log: 00:42:06.740765 timesync vgsvcTimeSyncWorker: Radical host time change: 38 352 722 000 000ns (HostNow=1 680 533 716 723 000 000 ns HostLast=1 680 495 364 001 000 000 ns) 2023-04-03 07:55:27 (3532): Guest Log: 00:42:16.871127 timesync vgsvcTimeSyncWorker: Radical guest time change: 38 352 892 337 000ns (GuestNow=1 680 533 726 937 942 000 ns GuestLast=1 680 495 374 045 605 000 ns fSetTimeLastLoop=true ) 2023-04-03 08:52:51 (3532): Status Report: Job Duration: '864000.000000' 2023-04-03 08:52:51 (3532): Status Report: Elapsed Time: '139032.000000' 2023-04-03 08:52:51 (3532): Status Report: CPU Time: '83371.250000' 2023-04-03 10:32:55 (3532): Status Report: Job Duration: '864000.000000' 2023-04-03 10:32:55 (3532): Status Report: Elapsed Time: '145032.000000' 2023-04-03 10:32:55 (3532): Status Report: CPU Time: '87029.796875' 2023-04-03 12:12:59 (3532): Status Report: Job Duration: '864000.000000' 2023-04-03 12:12:59 (3532): Status Report: Elapsed Time: '151032.000000' 2023-04-03 12:12:59 (3532): Status Report: CPU Time: '90697.375000' 2023-04-03 13:45:31 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-03 13:45:41 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-03 13:53:14 (3532): Status Report: Job Duration: '864000.000000' 2023-04-03 13:53:14 (3532): Status Report: Elapsed Time: '157032.000000' 2023-04-03 13:53:14 (3532): Status Report: CPU Time: '94346.187500' 2023-04-03 15:33:18 (3532): Status Report: Job Duration: '864000.000000' 2023-04-03 15:33:18 (3532): Status Report: Elapsed Time: '163032.000000' 2023-04-03 15:33:18 (3532): Status Report: CPU Time: '98019.406250' 2023-04-03 17:13:21 (3532): Status Report: Job Duration: '864000.000000' 2023-04-03 17:13:21 (3532): Status Report: Elapsed Time: '169032.000000' 2023-04-03 17:13:21 (3532): Status Report: CPU Time: '101694.015625' 2023-04-03 18:53:26 (3532): Status Report: Job Duration: '864000.000000' 2023-04-03 18:53:26 (3532): Status Report: Elapsed Time: '175032.000000' 2023-04-03 18:53:26 (3532): Status Report: CPU Time: '105357.468750' 2023-04-03 20:22:21 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-03 20:22:31 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-03 20:27:22 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-03 20:27:32 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-03 20:33:53 (3532): Status Report: Job Duration: '864000.000000' 2023-04-03 20:33:53 (3532): Status Report: Elapsed Time: '181032.000000' 2023-04-03 20:33:53 (3532): Status Report: CPU Time: '109027.500000' 2023-04-03 20:44:23 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-04 08:48:17 (3532): Error in resume VM for VM: -2135228414 Command: VBoxManage -q controlvm "boinc_c59f0c2c80aefa92" resume Output: VBoxManage.exe: error: Cannot resume the machine as it is not paused (machine state: Running) VBoxManage.exe: error: Details: code VBOX_E_INVALID_VM_STATE (0x80bb0002), component ConsoleWrap, interface IConsole, callee IUnknown VBoxManage.exe: error: Context: "Resume()" at line 410 of file VBoxManageControlVM.cpp 2023-04-04 08:48:18 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-04 08:48:23 (3532): Guest Log: 13:31:01.753559 timesync vgsvcTimeSyncWorker: Radical host time change: 43 440 353 000 000ns (HostNow=1 680 623 301 400 000 000 ns HostLast=1 680 579 861 047 000 000 ns) 2023-04-04 08:48:31 (3532): Guest Log: 13:31:11.756422 timesync vgsvcTimeSyncWorker: Radical guest time change: 43 459 582 497 000ns (GuestNow=1 680 623 311 402 872 000 ns GuestLast=1 680 579 851 820 375 000 ns fSetTimeLastLoop=true ) 2023-04-04 10:17:52 (3532): Status Report: Job Duration: '864000.000000' 2023-04-04 10:17:52 (3532): Status Report: Elapsed Time: '187032.214325' 2023-04-04 10:17:52 (3532): Status Report: CPU Time: '112649.484375' 2023-04-04 11:57:56 (3532): Status Report: Job Duration: '864000.000000' 2023-04-04 11:57:56 (3532): Status Report: Elapsed Time: '193032.214325' 2023-04-04 11:57:56 (3532): Status Report: CPU Time: '116278.046875' 2023-04-04 13:38:00 (3532): Status Report: Job Duration: '864000.000000' 2023-04-04 13:38:00 (3532): Status Report: Elapsed Time: '199032.214325' 2023-04-04 13:38:00 (3532): Status Report: CPU Time: '119930.984375' 2023-04-04 15:18:04 (3532): Status Report: Job Duration: '864000.000000' 2023-04-04 15:18:04 (3532): Status Report: Elapsed Time: '205032.214325' 2023-04-04 15:18:04 (3532): Status Report: CPU Time: '123582.859375' 2023-04-04 16:58:09 (3532): Status Report: Job Duration: '864000.000000' 2023-04-04 16:58:09 (3532): Status Report: Elapsed Time: '211032.214325' 2023-04-04 16:58:09 (3532): Status Report: CPU Time: '127221.500000' 2023-04-04 17:48:35 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-04 17:48:45 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-04 18:38:23 (3532): Status Report: Job Duration: '864000.000000' 2023-04-04 18:38:23 (3532): Status Report: Elapsed Time: '217032.214325' 2023-04-04 18:38:23 (3532): Status Report: CPU Time: '130892.859375' 2023-04-04 20:18:27 (3532): Status Report: Job Duration: '864000.000000' 2023-04-04 20:18:27 (3532): Status Report: Elapsed Time: '223032.214325' 2023-04-04 20:18:27 (3532): Status Report: CPU Time: '134568.281250' 2023-04-04 20:54:05 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-05 07:05:01 (3532): Error in resume VM for VM: -2135228414 Command: VBoxManage -q controlvm "boinc_c59f0c2c80aefa92" resume Output: VBoxManage.exe: error: Cannot resume the machine as it is not paused (machine state: Running) VBoxManage.exe: error: Details: code VBOX_E_INVALID_VM_STATE (0x80bb0002), component ConsoleWrap, interface IConsole, callee IUnknown VBoxManage.exe: error: Context: "Resume()" at line 410 of file VBoxManageControlVM.cpp 2023-04-05 07:05:02 (3532): Guest Log: 25:36:41.516953 timesync vgsvcTimeSyncWorker: Radical host time change: 36 661 628 000 000ns (HostNow=1 680 703 497 087 000 000 ns HostLast=1 680 666 835 459 000 000 ns) 2023-04-05 07:05:02 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-05 07:05:07 (3532): Guest Log: 25:36:51.528335 timesync vgsvcTimeSyncWorker: Radical guest time change: 36 665 935 046 000ns (GuestNow=1 680 703 507 098 414 000 ns GuestLast=1 680 666 841 163 368 000 ns fSetTimeLastLoop=true ) 2023-04-05 08:09:28 (3532): Status Report: Job Duration: '864000.000000' 2023-04-05 08:09:28 (3532): Status Report: Elapsed Time: '229032.214325' 2023-04-05 08:09:28 (3532): Status Report: CPU Time: '138211.921875' 2023-04-05 09:15:04 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-05 09:15:14 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-05 09:25:44 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-05 09:25:54 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-05 09:49:53 (3532): Status Report: Job Duration: '864000.000000' 2023-04-05 09:49:53 (3532): Status Report: Elapsed Time: '235032.214325' 2023-04-05 09:49:53 (3532): Status Report: CPU Time: '141886.953125' 2023-04-05 10:03:47 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-05 10:03:57 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-05 10:10:07 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-05 10:10:17 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-05 11:30:19 (3532): Status Report: Job Duration: '864000.000000' 2023-04-05 11:30:19 (3532): Status Report: Elapsed Time: '241032.214325' 2023-04-05 11:30:19 (3532): Status Report: CPU Time: '145551.328125' 2023-04-05 12:27:45 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-05 12:27:55 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-05 13:10:35 (3532): Status Report: Job Duration: '864000.000000' 2023-04-05 13:10:35 (3532): Status Report: Elapsed Time: '247032.214325' 2023-04-05 13:10:35 (3532): Status Report: CPU Time: '149157.187500' 2023-04-05 14:20:52 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-05 14:21:02 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-05 14:50:50 (3532): Status Report: Job Duration: '864000.000000' 2023-04-05 14:50:50 (3532): Status Report: Elapsed Time: '253032.214325' 2023-04-05 14:50:50 (3532): Status Report: CPU Time: '152790.437500' 2023-04-05 15:11:24 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-05 15:11:34 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-05 15:46:16 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-05 15:46:26 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-05 16:15:37 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-05 16:15:48 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-05 16:31:28 (3532): Status Report: Job Duration: '864000.000000' 2023-04-05 16:31:28 (3532): Status Report: Elapsed Time: '259032.214325' 2023-04-05 16:31:28 (3532): Status Report: CPU Time: '156444.437500' 2023-04-05 18:00:33 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-05 18:00:43 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-05 18:02:53 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-05 18:03:03 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-05 18:11:54 (3532): Status Report: Job Duration: '864000.000000' 2023-04-05 18:11:54 (3532): Status Report: Elapsed Time: '265032.214325' 2023-04-05 18:11:54 (3532): Status Report: CPU Time: '160090.984375' 2023-04-05 19:51:58 (3532): Status Report: Job Duration: '864000.000000' 2023-04-05 19:51:58 (3532): Status Report: Elapsed Time: '271032.214325' 2023-04-05 19:51:58 (3532): Status Report: CPU Time: '163718.843750' 2023-04-05 20:32:03 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-05 20:32:13 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-05 20:47:11 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 07:27:58 (3532): Error in resume VM for VM: -2135228414 Command: VBoxManage -q controlvm "boinc_c59f0c2c80aefa92" resume Output: VBoxManage.exe: error: Cannot resume the machine as it is not paused (machine state: Running) VBoxManage.exe: error: Details: code VBOX_E_INVALID_VM_STATE (0x80bb0002), component ConsoleWrap, interface IConsole, callee IUnknown VBoxManage.exe: error: Context: "Resume()" at line 410 of file VBoxManageControlVM.cpp 2023-04-06 07:27:59 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 07:28:00 (3532): Guest Log: 39:17:22.498556 timesync vgsvcTimeSyncWorker: Radical host time change: 38 452 644 000 000ns (HostNow=1 680 791 280 358 000 000 ns HostLast=1 680 752 827 714 000 000 ns) 2023-04-06 07:28:10 (3532): Guest Log: 39:17:32.504664 timesync vgsvcTimeSyncWorker: Radical guest time change: 38 552 295 484 000ns (GuestNow=1 680 791 290 364 112 000 ns GuestLast=1 680 752 738 068 628 000 ns fSetTimeLastLoop=true ) 2023-04-06 07:28:34 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 07:28:44 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 07:36:14 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 07:36:25 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 08:01:09 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 13:27:51 (3532): Error in resume VM for VM: -2135228414 Command: VBoxManage -q controlvm "boinc_c59f0c2c80aefa92" resume Output: VBoxManage.exe: error: Cannot resume the machine as it is not paused (machine state: Running) VBoxManage.exe: error: Details: code VBOX_E_INVALID_VM_STATE (0x80bb0002), component ConsoleWrap, interface IConsole, callee IUnknown VBoxManage.exe: error: Context: "Resume()" at line 410 of file VBoxManageControlVM.cpp 2023-04-06 13:27:51 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 13:27:52 (3532): Guest Log: 39:50:18.001675 timesync vgsvcTimeSyncWorker: Radical host time change: 19 607 518 000 000ns (HostNow=1 680 812 872 234 000 000 ns HostLast=1 680 793 264 716 000 000 ns) 2023-04-06 13:28:02 (3532): Guest Log: 39:50:28.006355 timesync vgsvcTimeSyncWorker: Radical guest time change: 19 626 377 555 000ns (GuestNow=1 680 812 882 238 673 000 ns GuestLast=1 680 793 255 861 118 000 ns fSetTimeLastLoop=true ) 2023-04-06 13:29:56 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 13:30:06 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 13:33:27 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 13:33:37 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 13:40:29 (3532): Status Report: Job Duration: '864000.000000' 2023-04-06 13:40:29 (3532): Status Report: Elapsed Time: '277032.214325' 2023-04-06 13:40:29 (3532): Status Report: CPU Time: '167363.859375' 2023-04-06 14:04:19 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 14:04:29 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 15:20:44 (3532): Status Report: Job Duration: '864000.000000' 2023-04-06 15:20:44 (3532): Status Report: Elapsed Time: '283032.214325' 2023-04-06 15:20:44 (3532): Status Report: CPU Time: '171007.343750' 2023-04-06 16:23:56 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 16:24:06 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 16:40:27 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 16:40:37 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 16:41:17 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 16:41:27 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 16:42:27 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 16:42:37 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 16:43:47 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 16:43:58 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 16:45:47 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 16:45:58 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 17:01:55 (3532): Status Report: Job Duration: '864000.000000' 2023-04-06 17:01:55 (3532): Status Report: Elapsed Time: '289032.214325' 2023-04-06 17:01:55 (3532): Status Report: CPU Time: '174677.203125' 2023-04-06 17:09:09 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 17:09:19 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 17:27:19 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 17:27:29 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 17:54:10 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 17:54:20 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 18:42:32 (3532): Status Report: Job Duration: '864000.000000' 2023-04-06 18:42:32 (3532): Status Report: Elapsed Time: '295032.214325' 2023-04-06 18:42:32 (3532): Status Report: CPU Time: '178352.718750' 2023-04-06 19:03:55 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 19:04:05 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 19:39:16 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 19:39:26 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 19:48:17 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 19:48:27 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 19:49:07 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 19:49:27 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 19:49:57 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 19:50:07 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 19:50:27 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 19:50:37 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 19:50:57 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 19:51:07 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 19:51:47 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 19:51:58 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 19:52:27 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 19:52:38 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 19:52:47 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 19:52:58 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 19:54:28 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 19:54:38 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 19:54:58 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 19:55:08 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 19:55:28 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 19:55:38 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 19:56:58 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 19:57:08 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 19:57:28 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 19:57:38 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 19:58:08 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 19:58:18 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 20:19:59 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 20:20:09 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 20:22:39 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 20:22:49 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 20:22:59 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-06 20:23:09 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-06 20:26:18 (3532): Status Report: Job Duration: '864000.000000' 2023-04-06 20:26:18 (3532): Status Report: Elapsed Time: '301032.214325' 2023-04-06 20:26:18 (3532): Status Report: CPU Time: '182035.625000' 2023-04-06 20:39:28 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-07 09:51:04 (3532): Error in resume VM for VM: -2135228414 Command: VBoxManage -q controlvm "boinc_c59f0c2c80aefa92" resume Output: VBoxManage.exe: error: Cannot resume the machine as it is not paused (machine state: Running) VBoxManage.exe: error: Details: code VBOX_E_INVALID_VM_STATE (0x80bb0002), component ConsoleWrap, interface IConsole, callee IUnknown VBoxManage.exe: error: Context: "Resume()" at line 410 of file VBoxManageControlVM.cpp 2023-04-07 09:51:05 (3532): Guest Log: 46:56:48.224846 timesync vgsvcTimeSyncWorker: Radical host time change: 47 497 558 000 000ns (HostNow=1 680 886 260 319 000 000 ns HostLast=1 680 838 762 761 000 000 ns) 2023-04-07 09:51:05 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-07 09:51:10 (3532): Guest Log: 46:56:58.235768 timesync vgsvcTimeSyncWorker: Radical guest time change: 47 807 872 770 000ns (GuestNow=1 680 886 270 329 932 000 ns GuestLast=1 680 838 462 457 162 000 ns fSetTimeLastLoop=true ) 2023-04-07 09:51:26 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-07 09:51:36 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-07 09:58:18 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-07 09:58:28 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-07 10:05:58 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-07 10:06:08 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-07 10:13:38 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-07 10:13:48 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-07 10:15:08 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-07 10:15:18 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-07 10:28:09 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-07 10:28:19 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-07 10:45:20 (3532): VM state change detected. (old = 'running', new = 'paused') 2023-04-07 10:45:30 (3532): VM state change detected. (old = 'paused', new = 'running') 2023-04-07 11:10:17 (3532): Guest Log: job: run exitcode=0 2023-04-07 11:10:17 (3532): Guest Log: job: diskusage=3028 2023-04-07 11:10:17 (3532): Guest Log: job: logsize=64 k 2023-04-07 11:10:17 (3532): Guest Log: job: times= 2023-04-07 11:10:17 (3532): Guest Log: 0m0.008s 0m0.000s 2023-04-07 11:10:17 (3532): Guest Log: 2863m12.163s 9m15.617s 2023-04-07 11:10:17 (3532): Guest Log: job: cpuusage=172348 2023-04-07 11:10:17 (3532): Guest Log: 13:09:10 CDT -05:00 2023-04-07: cranky: [INFO] Container 'runc' finished with status code 0. 2023-04-07 11:10:17 (3532): Guest Log: 13:09:10 CDT -05:00 2023-04-07: cranky: [INFO] Preparing output. 2023-04-07 11:10:17 (3532): Guest Log: [INFO] Job Finished 2023-04-07 11:10:17 (3532): Guest Log: [INFO] Shutting Down. 2023-04-07 11:10:17 (3532): VM Completion File Detected. 2023-04-07 11:10:17 (3532): VM Completion Message: Job Finished . 2023-04-07 11:10:17 (3532): Powering off VM. 2023-04-07 11:10:17 (3532): Successfully stopped VM. 2023-04-07 11:10:17 (3532): Deregistering VM. (boinc_c59f0c2c80aefa92, slot#6) 2023-04-07 11:10:17 (3532): Removing network bandwidth throttle group from VM. 2023-04-07 11:10:18 (3532): Removing VM from VirtualBox. 11:10:23 (3532): called boinc_finish(0) </stderr_txt> ]]>
©2024 CERN