| Name | Theory_2390-1115168-162_1 |
| Workunit | 150178949 |
| Created | 1 Jan 2021, 12:56:28 UTC |
| Sent | 1 Jan 2021, 12:56:29 UTC |
| Report deadline | 12 Jan 2021, 12:56:29 UTC |
| Received | 20 Jan 2021, 23:30:09 UTC |
| Server state | Over |
| Outcome | Success |
| Client state | Done |
| Exit status | 0 (0x00000000) |
| Computer ID | 10639191 |
| Run time | 2 days 6 hours 5 min 23 sec |
| CPU time | 1 days 8 hours 46 min 6 sec |
| Validate state | Valid |
| Credit | 1,552.06 |
| Device peak FLOPS | 3.44 GFLOPS |
| Application version | Theory Simulation v300.06 (vbox64_theory) windows_x86_64 |
| Peak working set size | 65.61 MB |
| Peak swap size | 83.60 MB |
| Peak disk usage | 4.91 GB |
Stderr output
<core_client_version>7.16.11</core_client_version> <![CDATA[ <stderr_txt> 625' 2021-01-07 13:32:32 (2736): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-07 13:32:42 (2736): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-07 15:04:48 (2736): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-07 23:23:40 (2736): Stopping VM. 2021-01-10 15:10:01 (8108): Detected: vboxwrapper 26197 2021-01-10 15:10:01 (8108): Detected: BOINC client v7.7 2021-01-10 15:10:02 (8108): Detected: VirtualBox VboxManage Interface (Version: 6.1.12) 2021-01-10 15:10:03 (8108): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2021-01-10 15:10:03 (8108): Starting VM using VBoxManage interface. (boinc_277d89f062313ddf, slot#0) 2021-01-10 15:10:13 (8108): Successfully started VM. (PID = '10748') 2021-01-10 15:10:13 (8108): Reporting VM Process ID to BOINC. 2021-01-10 15:10:13 (8108): VM state change detected. (old = 'PoweredOff', new = 'Running') 2021-01-10 15:10:13 (8108): Detected: Web Application Enabled (http://localhost:54874) 2021-01-10 15:10:13 (8108): Detected: Remote Desktop Enabled (localhost:54875) 2021-01-10 15:10:14 (8108): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-10 15:10:22 (8108): Status Report: Job Duration: '864000.000000' 2021-01-10 15:10:22 (8108): Status Report: Elapsed Time: '11627.000000' 2021-01-10 15:10:22 (8108): Status Report: CPU Time: '6936.968750' 2021-01-10 15:10:22 (8108): Preference change detected 2021-01-10 15:10:22 (8108): Setting CPU throttle for VM. (60%) 2021-01-10 15:10:23 (8108): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 240 seconds) or (Vbox_job.xml: 600 seconds)) 2021-01-10 15:10:23 (8108): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-10 15:10:31 (8108): Guest Log: 02:00:07.060850 timesync vgsvcTimeSyncWorker: Radical host time change: 259 543 276 000 000ns (HostNow=1 610 287 830 461 000 000 ns HostLast=1 610 028 287 185 000 000 ns) 2021-01-10 15:10:41 (8108): Guest Log: 02:00:17.111499 timesync vgsvcTimeSyncWorker: Radical guest time change: 259 561 656 906 000ns (GuestNow=1 610 287 840 600 680 000 ns GuestLast=1 610 028 278 943 774 000 ns fSetTimeLastLoop=true ) 2021-01-10 15:21:54 (8108): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-10 15:22:04 (8108): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-10 15:48:55 (8108): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-10 15:49:05 (8108): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-10 16:51:05 (8108): Status Report: Job Duration: '864000.000000' 2021-01-10 16:51:05 (8108): Status Report: Elapsed Time: '17627.000000' 2021-01-10 16:51:05 (8108): Status Report: CPU Time: '10558.421875' 2021-01-10 18:16:45 (8108): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-10 18:16:52 (8108): Error in resume VM for VM: -2135228414 Command: VBoxManage -q controlvm "boinc_277d89f062313ddf" resume Output: VBoxManage.exe: error: VM is paused due to host power management VBoxManage.exe: error: Details: code VBOX_E_INVALID_VM_STATE (0x80bb0002), component ConsoleWrap, interface IConsole, callee IUnknown VBoxManage.exe: error: Context: "Resume()" at line 410 of file VBoxManageControlVM.cpp 2021-01-11 15:47:54 (8108): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-11 15:48:00 (8108): Guest Log: 05:06:13.749210 timesync vgsvcTimeSyncWorker: Radical host time change: 77 478 209 000 000ns (HostNow=1 610 376 480 094 000 000 ns HostLast=1 610 299 001 885 000 000 ns) 2021-01-11 15:48:05 (8108): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-11 15:48:15 (8108): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-11 15:48:20 (8108): Guest Log: 05:06:23.756507 timesync vgsvcTimeSyncWorker: Radical guest time change: 77 492 862 979 000ns (GuestNow=1 610 376 490 101 325 000 ns GuestLast=1 610 298 997 238 346 000 ns fSetTimeLastLoop=true ) 2021-01-11 16:02:49 (8108): Status Report: Job Duration: '864000.000000' 2021-01-11 16:02:49 (8108): Status Report: Elapsed Time: '23627.000000' 2021-01-11 16:02:49 (8108): Status Report: CPU Time: '14182.187500' 2021-01-11 16:37:02 (8108): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-11 16:37:18 (8108): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-11 17:43:32 (8108): Status Report: Job Duration: '864000.000000' 2021-01-11 17:43:32 (8108): Status Report: Elapsed Time: '29627.000000' 2021-01-11 17:43:32 (8108): Status Report: CPU Time: '17805.968750' 2021-01-11 17:46:13 (8108): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-11 17:46:23 (8108): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-11 18:45:26 (8108): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-11 18:45:37 (8108): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-11 18:50:37 (8108): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-11 18:50:47 (8108): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-11 19:24:26 (8108): Status Report: Job Duration: '864000.000000' 2021-01-11 19:24:26 (8108): Status Report: Elapsed Time: '35627.000000' 2021-01-11 19:24:26 (8108): Status Report: CPU Time: '21433.140625' 2021-01-11 19:59:11 (8108): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-11 19:59:21 (8108): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-11 21:04:56 (8108): Status Report: Job Duration: '864000.000000' 2021-01-11 21:04:56 (8108): Status Report: Elapsed Time: '41627.000000' 2021-01-11 21:04:56 (8108): Status Report: CPU Time: '25054.765625' 2021-01-11 21:56:45 (8108): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-11 21:56:52 (8108): Error in resume VM for VM: -2135228414 Command: VBoxManage -q controlvm "boinc_277d89f062313ddf" resume Output: VBoxManage.exe: error: VM is paused due to host power management VBoxManage.exe: error: Details: code VBOX_E_INVALID_VM_STATE (0x80bb0002), component ConsoleWrap, interface IConsole, callee IUnknown VBoxManage.exe: error: Context: "Resume()" at line 410 of file VBoxManageControlVM.cpp 2021-01-11 21:58:19 (8108): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-11 21:58:29 (8108): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-11 21:58:39 (8108): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-11 22:02:40 (8108): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-11 22:02:50 (8108): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-11 22:09:20 (8108): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-11 22:09:30 (8108): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-11 22:37:12 (8108): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-11 22:37:22 (8108): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-11 22:39:22 (8108): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-11 22:39:32 (8108): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-11 22:47:42 (8108): Status Report: Job Duration: '864000.000000' 2021-01-11 22:47:42 (8108): Status Report: Elapsed Time: '47627.000000' 2021-01-11 22:47:42 (8108): Status Report: CPU Time: '28678.250000' 2021-01-11 23:10:14 (8108): Stopping VM. 2021-01-11 23:10:16 (8108): Error in stop VM for VM: -108 Command: VBoxManage -q controlvm "boinc_277d89f062313ddf" savestate Output: 0%...10%...20%...30%...40%...50%...60%... 2021-01-11 23:10:16 (8108): VM did not stop when requested. 2021-01-11 23:10:16 (8108): VM was NOT successfully terminated. 2021-01-12 15:32:28 (13608): Detected: vboxwrapper 26197 2021-01-12 15:32:28 (13608): Detected: BOINC client v7.7 2021-01-12 15:32:46 (13608): Detected: VirtualBox VboxManage Interface (Version: 6.1.12) 2021-01-12 15:32:46 (13608): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2021-01-12 15:32:47 (13608): Starting VM using VBoxManage interface. (boinc_277d89f062313ddf, slot#0) 2021-01-12 15:32:53 (13608): Successfully started VM. (PID = '10296') 2021-01-12 15:32:53 (13608): Reporting VM Process ID to BOINC. 2021-01-12 15:32:53 (13608): Guest Log: BIOS: VirtualBox 6.1.12 2021-01-12 15:32:53 (13608): Guest Log: CPUID EDX: 0x178bfbff 2021-01-12 15:32:53 (13608): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63 2021-01-12 15:32:53 (13608): VM state change detected. (old = 'PoweredOff', new = 'Running') 2021-01-12 15:32:53 (13608): Detected: Web Application Enabled (http://localhost:54874) 2021-01-12 15:32:53 (13608): Detected: Remote Desktop Enabled (localhost:54875) 2021-01-12 15:32:53 (13608): Status Report: Job Duration: '864000.000000' 2021-01-12 15:32:53 (13608): Status Report: Elapsed Time: '48974.000000' 2021-01-12 15:32:53 (13608): Status Report: CPU Time: '29493.312500' 2021-01-12 15:32:53 (13608): Preference change detected 2021-01-12 15:32:53 (13608): Setting CPU throttle for VM. (60%) 2021-01-12 15:32:53 (13608): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 240 seconds) or (Vbox_job.xml: 600 seconds)) 2021-01-12 15:32:55 (13608): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032 2021-01-12 15:32:55 (13608): Guest Log: BIOS: Booting from Hard Disk... 2021-01-12 15:32:57 (13608): Guest Log: BIOS: KBD: unsupported int 16h function 03 2021-01-12 15:32:57 (13608): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 2021-01-12 15:33:22 (13608): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds 2021-01-12 15:33:22 (13608): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000) 2021-01-12 15:33:27 (13608): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log 2021-01-12 15:33:27 (13608): Guest Log: 00:00:00.000129 main Log opened 2021-01-12T14:33:26.324499000Z 2021-01-12 15:33:27 (13608): Guest Log: 00:00:00.000402 main OS Product: Linux 2021-01-12 15:33:27 (13608): Guest Log: 00:00:00.000450 main OS Release: 4.14.76-13.cernvm.x86_64 2021-01-12 15:33:27 (13608): Guest Log: 00:00:00.000491 main OS Version: #1 SMP Tue Oct 16 18:26:15 CEST 2018 2021-01-12 15:33:27 (13608): Guest Log: 00:00:00.000530 main Executable: /usr/sbin/VBoxService 2021-01-12 15:33:27 (13608): Guest Log: 00:00:00.000531 main Process ID: 3200 2021-01-12 15:33:27 (13608): Guest Log: 00:00:00.000532 main Package type: LINUX_64BITS_GENERIC 2021-01-12 15:33:27 (13608): Guest Log: 00:00:00.004227 main 5.2.6 r120293 started. Verbose level = 0 2021-01-12 15:34:01 (13608): Guest Log: 15:33:59 CET +01:00 2021-01-12: cranky: [INFO] Detected Theory App 2021-01-12 15:34:01 (13608): Guest Log: 15:33:59 CET +01:00 2021-01-12: cranky: [INFO] Checking CVMFS. 2021-01-12 15:34:03 (13608): Guest Log: Probing /cvmfs/sft.cern.ch... OK 2021-01-12 15:34:04 (13608): 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 2021-01-12 15:34:04 (13608): Guest Log: 2.5.2.0 4035 0 26336 19461 3 1 1989940 4096001 0 65024 0 0 n/a 5 16 http://s1cern-cvmfs.openhtc.io/cvmfs/sft.cern.ch DIRECT 1 2021-01-12 15:34:05 (13608): Guest Log: Probing /cvmfs/grid.cern.ch... OK 2021-01-12 15:34:06 (13608): 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 2021-01-12 15:34:06 (13608): Guest Log: 2.5.2.0 4109 0 27548 14173 3 2 1989940 4096001 0 65024 0 2 0 4281 2711 http://s1unl-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1 2021-01-12 15:34:08 (13608): Guest Log: Probing /cvmfs/cernvm-prod.cern.ch... OK 2021-01-12 15:34:08 (13608): 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 2021-01-12 15:34:08 (13608): Guest Log: 2.5.2.0 4083 0 25160 259 3 1 1989940 4096001 0 65024 0 0 n/a 0 0 http://s1cern-cvmfs.openhtc.io/cvmfs/cernvm-prod.cern.ch DIRECT 1 2021-01-12 15:34:10 (13608): Guest Log: Probing /cvmfs/alice.cern.ch... OK 2021-01-12 15:34:11 (13608): 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 2021-01-12 15:34:11 (13608): Guest Log: 2.5.2.0 4062 0 28872 8381 3 1 1989940 4096001 0 65024 0 0 n/a 4738 2813 http://s1cern-cvmfs.openhtc.io/cvmfs/alice.cern.ch DIRECT 1 2021-01-12 15:34:11 (13608): Guest Log: 15:34:10 CET +01:00 2021-01-12: cranky: [INFO] Checking runc. 2021-01-12 15:34:11 (13608): Guest Log: 15:34:10 CET +01:00 2021-01-12: cranky: [INFO] Creating the filesystem. 2021-01-12 15:34:11 (13608): Guest Log: 15:34:10 CET +01:00 2021-01-12: cranky: [INFO] Using /cvmfs/cernvm-prod.cern.ch/cvm3 2021-01-12 15:34:12 (13608): Guest Log: 15:34:10 CET +01:00 2021-01-12: cranky: [INFO] Updating config.json. 2021-01-12 15:34:12 (13608): Guest Log: 15:34:10 CET +01:00 2021-01-12: cranky: [INFO] Running Container 'runc'. 2021-01-12 15:34:12 (13608): Guest Log: job: htmld=/shared/html/job 2021-01-12 15:34:12 (13608): Guest Log: job: unpack exitcode=0 2021-01-12 15:34:14 (13608): Guest Log: 15:34:12 CET +01:00 2021-01-12: cranky: [INFO] ===> [runRivet] Tue Jan 12 14:34:11 UTC 2021 [boinc pp jets 7000 25,-,100 - pythia8 8.243 tune-AU2m 100000 162] 2021-01-12 15:43:20 (13608): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-12 15:43:40 (13608): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-12 17:13:41 (13608): Status Report: Job Duration: '864000.000000' 2021-01-12 17:13:41 (13608): Status Report: Elapsed Time: '54974.000000' 2021-01-12 17:13:41 (13608): Status Report: CPU Time: '33103.187500' 2021-01-12 18:54:01 (13608): Status Report: Job Duration: '864000.000000' 2021-01-12 18:54:01 (13608): Status Report: Elapsed Time: '60974.000000' 2021-01-12 18:54:01 (13608): Status Report: CPU Time: '36725.812500' 2021-01-12 20:34:17 (13608): Status Report: Job Duration: '864000.000000' 2021-01-12 20:34:17 (13608): Status Report: Elapsed Time: '66974.000000' 2021-01-12 20:34:17 (13608): Status Report: CPU Time: '40346.250000' 2021-01-12 21:42:26 (13608): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-12 21:42:32 (13608): Error in resume VM for VM: -2135228414 Command: VBoxManage -q controlvm "boinc_277d89f062313ddf" resume Output: VBoxManage.exe: error: VM is paused due to host power management VBoxManage.exe: error: Details: code VBOX_E_INVALID_VM_STATE (0x80bb0002), component ConsoleWrap, interface IConsole, callee IUnknown VBoxManage.exe: error: Context: "Resume()" at line 410 of file VBoxManageControlVM.cpp 2021-01-12 21:46:02 (13608): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-12 21:46:12 (13608): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-12 21:46:21 (13608): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-12 22:18:19 (13608): Status Report: Job Duration: '864000.000000' 2021-01-12 22:18:19 (13608): Status Report: Elapsed Time: '72974.000000' 2021-01-12 22:18:19 (13608): Status Report: CPU Time: '43965.859375' 2021-01-12 23:18:57 (13608): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-12 23:19:07 (13608): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-12 23:38:28 (13608): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-12 23:38:38 (13608): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-12 23:59:06 (13608): Status Report: Job Duration: '864000.000000' 2021-01-12 23:59:06 (13608): Status Report: Elapsed Time: '78974.000000' 2021-01-12 23:59:06 (13608): Status Report: CPU Time: '47599.531250' 2021-01-13 01:20:20 (13608): Stopping VM. 2021-01-13 20:43:21 (10776): Detected: vboxwrapper 26197 2021-01-13 20:43:21 (10776): Detected: BOINC client v7.7 2021-01-13 20:43:23 (10776): Detected: VirtualBox VboxManage Interface (Version: 6.1.12) 2021-01-13 20:43:24 (10776): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2021-01-13 20:43:25 (10776): Starting VM using VBoxManage interface. (boinc_277d89f062313ddf, slot#0) 2021-01-13 20:43:36 (10776): Successfully started VM. (PID = '10720') 2021-01-13 20:43:36 (10776): Reporting VM Process ID to BOINC. 2021-01-13 20:43:36 (10776): VM state change detected. (old = 'PoweredOff', new = 'Running') 2021-01-13 20:43:36 (10776): Detected: Web Application Enabled (http://localhost:54874) 2021-01-13 20:43:36 (10776): Detected: Remote Desktop Enabled (localhost:54875) 2021-01-13 20:43:36 (10776): Status Report: Job Duration: '864000.000000' 2021-01-13 20:43:36 (10776): Status Report: Elapsed Time: '83835.000000' 2021-01-13 20:43:36 (10776): Status Report: CPU Time: '50531.546875' 2021-01-13 20:43:36 (10776): Preference change detected 2021-01-13 20:43:36 (10776): Setting CPU throttle for VM. (60%) 2021-01-13 20:43:37 (10776): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 240 seconds) or (Vbox_job.xml: 600 seconds)) 2021-01-13 20:43:42 (10776): Guest Log: 09:42:54.531780 timesync vgsvcTimeSyncWorker: Radical host time change: 69 804 165 000 000ns (HostNow=1 610 567 021 863 000 000 ns HostLast=1 610 497 217 698 000 000 ns) 2021-01-13 20:43:54 (10776): Guest Log: 09:43:04.564163 timesync vgsvcTimeSyncWorker: Radical guest time change: 70 051 084 638 000ns (GuestNow=1 610 567 031 910 623 000 ns GuestLast=1 610 496 980 825 985 000 ns fSetTimeLastLoop=true ) 2021-01-13 20:51:16 (10776): Stopping VM. 2021-01-14 11:12:42 (2360): Detected: vboxwrapper 26197 2021-01-14 11:12:42 (2360): Detected: BOINC client v7.7 2021-01-14 11:12:45 (2360): Detected: VirtualBox VboxManage Interface (Version: 6.1.12) 2021-01-14 11:12:46 (2360): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2021-01-14 11:12:46 (2360): Starting VM using VBoxManage interface. (boinc_277d89f062313ddf, slot#0) 2021-01-14 11:12:51 (2360): Successfully started VM. (PID = '6924') 2021-01-14 11:12:51 (2360): Reporting VM Process ID to BOINC. 2021-01-14 11:12:51 (2360): Guest Log: BIOS: VirtualBox 6.1.12 2021-01-14 11:12:51 (2360): Guest Log: CPUID EDX: 0x178bfbff 2021-01-14 11:12:51 (2360): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63 2021-01-14 11:12:51 (2360): VM state change detected. (old = 'PoweredOff', new = 'Running') 2021-01-14 11:12:51 (2360): Detected: Web Application Enabled (http://localhost:54874) 2021-01-14 11:12:51 (2360): Detected: Remote Desktop Enabled (localhost:54875) 2021-01-14 11:12:51 (2360): Status Report: Job Duration: '864000.000000' 2021-01-14 11:12:51 (2360): Status Report: Elapsed Time: '84289.000000' 2021-01-14 11:12:51 (2360): Status Report: CPU Time: '50816.671875' 2021-01-14 11:12:51 (2360): Preference change detected 2021-01-14 11:12:51 (2360): Setting CPU throttle for VM. (60%) 2021-01-14 11:12:52 (2360): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 240 seconds) or (Vbox_job.xml: 600 seconds)) 2021-01-14 11:12:53 (2360): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032 2021-01-14 11:12:53 (2360): Guest Log: BIOS: Booting from Hard Disk... 2021-01-14 11:12:55 (2360): Guest Log: BIOS: KBD: unsupported int 16h function 03 2021-01-14 11:12:55 (2360): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 2021-01-14 11:13:18 (2360): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds 2021-01-14 11:13:18 (2360): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000) 2021-01-14 11:13:25 (2360): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log 2021-01-14 11:13:25 (2360): Guest Log: 00:00:00.000187 main Log opened 2021-01-14T10:13:23.891128000Z 2021-01-14 11:13:25 (2360): Guest Log: 00:00:00.000295 main OS Product: Linux 2021-01-14 11:13:25 (2360): Guest Log: 00:00:00.000416 main OS Release: 4.14.76-13.cernvm.x86_64 2021-01-14 11:13:25 (2360): Guest Log: 00:00:00.000460 main OS Version: #1 SMP Tue Oct 16 18:26:15 CEST 2018 2021-01-14 11:13:25 (2360): Guest Log: 00:00:00.000516 main Executable: /usr/sbin/VBoxService 2021-01-14 11:13:25 (2360): Guest Log: 00:00:00.000518 main Process ID: 3207 2021-01-14 11:13:25 (2360): Guest Log: 00:00:00.000519 main Package type: LINUX_64BITS_GENERIC 2021-01-14 11:13:25 (2360): Guest Log: 00:00:00.182120 main 5.2.6 r120293 started. Verbose level = 0 2021-01-14 11:13:53 (2360): Guest Log: 11:13:51 CET +01:00 2021-01-14: cranky: [INFO] Detected Theory App 2021-01-14 11:13:53 (2360): Guest Log: 11:13:51 CET +01:00 2021-01-14: cranky: [INFO] Checking CVMFS. 2021-01-14 11:13:54 (2360): Guest Log: Probing /cvmfs/sft.cern.ch... OK 2021-01-14 11:13:55 (2360): 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 2021-01-14 11:13:55 (2360): Guest Log: 2.5.2.0 4042 0 26248 19473 3 1 2486069 4096001 0 65024 0 0 n/a 0 0 http://s1cern-cvmfs.openhtc.io/cvmfs/sft.cern.ch DIRECT 1 2021-01-14 11:13:57 (2360): Guest Log: Probing /cvmfs/grid.cern.ch... OK 2021-01-14 11:13:58 (2360): 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 2021-01-14 11:13:58 (2360): Guest Log: 2.5.2.0 4089 0 27524 14187 3 2 2486069 4096001 0 65024 0 2 0 4281 4386 http://s1cern-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1 2021-01-14 11:13:59 (2360): Guest Log: Probing /cvmfs/cernvm-prod.cern.ch... OK 2021-01-14 11:14:00 (2360): 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 2021-01-14 11:14:00 (2360): Guest Log: 2.5.2.0 4065 0 27204 259 3 1 2486069 4096001 0 65024 0 0 n/a 0 0 http://s1cern-cvmfs.openhtc.io/cvmfs/cernvm-prod.cern.ch DIRECT 1 2021-01-14 11:14:02 (2360): Guest Log: Probing /cvmfs/alice.cern.ch... OK 2021-01-14 11:14:03 (2360): 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 2021-01-14 11:14:03 (2360): Guest Log: 2.5.2.0 4110 0 30808 8405 3 1 2486069 4096001 0 65024 0 0 n/a 4760 3956 http://s1cern-cvmfs.openhtc.io/cvmfs/alice.cern.ch DIRECT 1 2021-01-14 11:14:03 (2360): Guest Log: 11:14:02 CET +01:00 2021-01-14: cranky: [INFO] Checking runc. 2021-01-14 11:14:03 (2360): Guest Log: 11:14:02 CET +01:00 2021-01-14: cranky: [INFO] Creating the filesystem. 2021-01-14 11:14:03 (2360): Guest Log: 11:14:02 CET +01:00 2021-01-14: cranky: [INFO] Using /cvmfs/cernvm-prod.cern.ch/cvm3 2021-01-14 11:14:03 (2360): Guest Log: 11:14:02 CET +01:00 2021-01-14: cranky: [INFO] Updating config.json. 2021-01-14 11:14:03 (2360): Guest Log: 11:14:02 CET +01:00 2021-01-14: cranky: [INFO] Running Container 'runc'. 2021-01-14 11:14:04 (2360): Guest Log: job: htmld=/shared/html/job 2021-01-14 11:14:04 (2360): Guest Log: job: unpack exitcode=0 2021-01-14 11:14:06 (2360): Guest Log: 11:14:05 CET +01:00 2021-01-14: cranky: [INFO] ===> [runRivet] Thu Jan 14 10:14:03 UTC 2021 [boinc pp jets 7000 25,-,100 - pythia8 8.243 tune-AU2m 100000 162] 2021-01-14 11:14:34 (2360): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-14 11:14:44 (2360): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-14 11:24:19 (2360): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-14 11:24:35 (2360): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-14 12:54:03 (2360): Status Report: Job Duration: '864000.000000' 2021-01-14 12:54:03 (2360): Status Report: Elapsed Time: '90289.000000' 2021-01-14 12:54:03 (2360): Status Report: CPU Time: '54441.640625' 2021-01-14 12:57:34 (2360): Stopping VM. 2021-01-14 16:30:11 (9760): Detected: vboxwrapper 26197 2021-01-14 16:30:11 (9760): Detected: BOINC client v7.7 2021-01-14 16:30:14 (9760): Detected: VirtualBox VboxManage Interface (Version: 6.1.12) 2021-01-14 16:30:15 (9760): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2021-01-14 16:30:15 (9760): Starting VM using VBoxManage interface. (boinc_277d89f062313ddf, slot#0) 2021-01-14 16:30:24 (9760): Successfully started VM. (PID = '8456') 2021-01-14 16:30:24 (9760): Reporting VM Process ID to BOINC. 2021-01-14 16:30:24 (9760): VM state change detected. (old = 'PoweredOff', new = 'Running') 2021-01-14 16:30:24 (9760): Detected: Web Application Enabled (http://localhost:54874) 2021-01-14 16:30:24 (9760): Detected: Remote Desktop Enabled (localhost:54875) 2021-01-14 16:30:25 (9760): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-14 16:30:33 (9760): Status Report: Job Duration: '864000.000000' 2021-01-14 16:30:33 (9760): Status Report: Elapsed Time: '90500.000000' 2021-01-14 16:30:33 (9760): Status Report: CPU Time: '54568.421875' 2021-01-14 16:30:33 (9760): Preference change detected 2021-01-14 16:30:33 (9760): Setting CPU throttle for VM. (60%) 2021-01-14 16:30:33 (9760): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 240 seconds) or (Vbox_job.xml: 600 seconds)) 2021-01-14 16:30:33 (9760): Guest Log: 01:43:50.294573 timesync vgsvcTimeSyncWorker: Radical host time change: 12 787 070 000 000ns (HostNow=1 610 638 233 409 000 000 ns HostLast=1 610 625 446 339 000 000 ns) 2021-01-14 16:30:33 (9760): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-14 16:30:44 (9760): Guest Log: 01:44:00.329387 timesync vgsvcTimeSyncWorker: Radical guest time change: 12 809 434 604 000ns (GuestNow=1 610 638 243 505 310 000 ns GuestLast=1 610 625 434 070 706 000 ns fSetTimeLastLoop=true ) 2021-01-14 16:35:43 (9760): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-14 16:35:53 (9760): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-14 18:11:11 (9760): Status Report: Job Duration: '864000.000000' 2021-01-14 18:11:11 (9760): Status Report: Elapsed Time: '96500.000000' 2021-01-14 18:11:11 (9760): Status Report: CPU Time: '58204.656250' 2021-01-14 19:25:02 (9760): Stopping VM. 2021-01-14 19:25:04 (9760): Error in stop VM for VM: -108 Command: VBoxManage -q controlvm "boinc_277d89f062313ddf" savestate Output: 0%...10%...20%...30%...40%...50%...60%... 2021-01-14 19:25:04 (9760): VM did not stop when requested. 2021-01-14 19:25:04 (9760): VM was NOT successfully terminated. 2021-01-14 23:37:49 (7972): Detected: vboxwrapper 26197 2021-01-14 23:37:49 (7972): Detected: BOINC client v7.7 2021-01-14 23:37:53 (7972): Detected: VirtualBox VboxManage Interface (Version: 6.1.12) 2021-01-14 23:38:09 (7972): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2021-01-14 23:38:09 (7972): Starting VM using VBoxManage interface. (boinc_277d89f062313ddf, slot#0) 2021-01-14 23:38:15 (7972): Successfully started VM. (PID = '2476') 2021-01-14 23:38:15 (7972): Reporting VM Process ID to BOINC. 2021-01-14 23:38:15 (7972): Guest Log: BIOS: VirtualBox 6.1.12 2021-01-14 23:38:15 (7972): Guest Log: CPUID EDX: 0x178bfbff 2021-01-14 23:38:15 (7972): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63 2021-01-14 23:38:15 (7972): VM state change detected. (old = 'PoweredOff', new = 'Running') 2021-01-14 23:38:15 (7972): Detected: Web Application Enabled (http://localhost:54874) 2021-01-14 23:38:15 (7972): Detected: Remote Desktop Enabled (localhost:54875) 2021-01-14 23:38:15 (7972): Status Report: Job Duration: '864000.000000' 2021-01-14 23:38:15 (7972): Status Report: Elapsed Time: '100915.000000' 2021-01-14 23:38:15 (7972): Status Report: CPU Time: '60870.031250' 2021-01-14 23:38:15 (7972): Preference change detected 2021-01-14 23:38:15 (7972): Setting CPU throttle for VM. (60%) 2021-01-14 23:38:15 (7972): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 240 seconds) or (Vbox_job.xml: 600 seconds)) 2021-01-14 23:38:17 (7972): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032 2021-01-14 23:38:17 (7972): Guest Log: BIOS: Booting from Hard Disk... 2021-01-14 23:38:19 (7972): Guest Log: BIOS: KBD: unsupported int 16h function 03 2021-01-14 23:38:19 (7972): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 2021-01-14 23:38:40 (7972): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-14 23:38:50 (7972): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-14 23:38:53 (7972): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds 2021-01-14 23:38:53 (7972): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000) 2021-01-14 23:38:58 (7972): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log 2021-01-14 23:38:58 (7972): Guest Log: 00:00:00.003096 main Log opened 2021-01-14T22:38:46.165681000Z 2021-01-14 23:38:58 (7972): Guest Log: 00:00:00.005081 main OS Product: Linux 2021-01-14 23:38:58 (7972): Guest Log: 00:00:00.005484 main OS Release: 4.14.76-13.cernvm.x86_64 2021-01-14 23:38:58 (7972): Guest Log: 00:00:00.005822 main OS Version: #1 SMP Tue Oct 16 18:26:15 CEST 2018 2021-01-14 23:38:58 (7972): Guest Log: 00:00:00.006076 main Executable: /usr/sbin/VBoxService 2021-01-14 23:38:58 (7972): Guest Log: 00:00:00.006078 main Process ID: 3199 2021-01-14 23:38:58 (7972): Guest Log: 00:00:00.006079 main Package type: LINUX_64BITS_GENERIC 2021-01-14 23:38:58 (7972): Guest Log: 00:00:00.009112 main 5.2.6 r120293 started. Verbose level = 0 2021-01-14 23:39:35 (7972): Guest Log: 23:39:23 CET +01:00 2021-01-14: cranky: [INFO] Detected Theory App 2021-01-14 23:39:35 (7972): Guest Log: 23:39:23 CET +01:00 2021-01-14: cranky: [INFO] Checking CVMFS. 2021-01-14 23:39:36 (7972): Guest Log: Probing /cvmfs/sft.cern.ch... OK 2021-01-14 23:39:37 (7972): 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 2021-01-14 23:39:37 (7972): Guest Log: 2.5.2.0 4035 0 27208 19476 3 1 2636439 4096001 0 65024 0 0 n/a 5 9 http://s1cern-cvmfs.openhtc.io/cvmfs/sft.cern.ch DIRECT 1 2021-01-14 23:39:39 (7972): Guest Log: Probing /cvmfs/grid.cern.ch... OK 2021-01-14 23:39:40 (7972): 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 2021-01-14 23:39:40 (7972): Guest Log: 2.5.2.0 4061 0 27540 14191 3 2 2636439 4096001 0 65024 0 2 0 4282 4409 http://s1ral-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1 2021-01-14 23:39:42 (7972): Guest Log: Probing /cvmfs/cernvm-prod.cern.ch... OK 2021-01-14 23:39:43 (7972): 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 2021-01-14 23:39:43 (7972): Guest Log: 2.5.2.0 4081 0 28396 259 3 1 2636439 4096001 0 65024 0 0 n/a 0 0 http://s1cern-cvmfs.openhtc.io/cvmfs/cernvm-prod.cern.ch DIRECT 1 2021-01-14 23:39:44 (7972): Guest Log: Probing /cvmfs/alice.cern.ch... OK 2021-01-14 23:39:45 (7972): 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 2021-01-14 23:39:45 (7972): Guest Log: 2.5.2.0 4108 0 30772 8411 3 1 2636439 4096001 0 65024 0 0 n/a 4764 2318 http://s1cern-cvmfs.openhtc.io/cvmfs/alice.cern.ch DIRECT 1 2021-01-14 23:39:45 (7972): Guest Log: 23:39:34 CET +01:00 2021-01-14: cranky: [INFO] Checking runc. 2021-01-14 23:39:46 (7972): Guest Log: 23:39:35 CET +01:00 2021-01-14: cranky: [INFO] Creating the filesystem. 2021-01-14 23:39:46 (7972): Guest Log: 23:39:35 CET +01:00 2021-01-14: cranky: [INFO] Using /cvmfs/cernvm-prod.cern.ch/cvm3 2021-01-14 23:39:46 (7972): Guest Log: 23:39:35 CET +01:00 2021-01-14: cranky: [INFO] Updating config.json. 2021-01-14 23:39:46 (7972): Guest Log: 23:39:35 CET +01:00 2021-01-14: cranky: [INFO] Running Container 'runc'. 2021-01-14 23:39:47 (7972): Guest Log: job: htmld=/shared/html/job 2021-01-14 23:39:47 (7972): Guest Log: job: unpack exitcode=0 2021-01-14 23:39:48 (7972): Guest Log: 23:39:37 CET +01:00 2021-01-14: cranky: [INFO] ===> [runRivet] Thu Jan 14 22:39:36 UTC 2021 [boinc pp jets 7000 25,-,100 - pythia8 8.243 tune-AU2m 100000 162] 2021-01-14 23:57:03 (7972): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-14 23:57:13 (7972): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-15 01:19:09 (7972): Status Report: Job Duration: '864000.000000' 2021-01-15 01:19:09 (7972): Status Report: Elapsed Time: '106915.000000' 2021-01-15 01:19:09 (7972): Status Report: CPU Time: '64492.046875' 2021-01-15 01:40:29 (7972): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-15 01:40:39 (7972): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-15 01:41:42 (7972): Stopping VM. 2021-01-15 12:11:59 (7748): Detected: vboxwrapper 26197 2021-01-15 12:11:59 (7748): Detected: BOINC client v7.7 2021-01-15 12:12:01 (7748): Detected: VirtualBox VboxManage Interface (Version: 6.1.12) 2021-01-15 12:12:17 (7748): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2021-01-15 12:12:18 (7748): Starting VM using VBoxManage interface. (boinc_277d89f062313ddf, slot#0) 2021-01-15 12:12:25 (7748): Successfully started VM. (PID = '11092') 2021-01-15 12:12:25 (7748): Reporting VM Process ID to BOINC. 2021-01-15 12:12:25 (7748): VM state change detected. (old = 'PoweredOff', new = 'Running') 2021-01-15 12:12:25 (7748): Detected: Web Application Enabled (http://localhost:54874) 2021-01-15 12:12:25 (7748): Detected: Remote Desktop Enabled (localhost:54875) 2021-01-15 12:12:25 (7748): Status Report: Job Duration: '864000.000000' 2021-01-15 12:12:25 (7748): Status Report: Elapsed Time: '108251.000000' 2021-01-15 12:12:25 (7748): Status Report: CPU Time: '65297.484375' 2021-01-15 12:12:25 (7748): Preference change detected 2021-01-15 12:12:25 (7748): Setting CPU throttle for VM. (60%) 2021-01-15 12:12:26 (7748): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 240 seconds) or (Vbox_job.xml: 600 seconds)) 2021-01-15 12:12:28 (7748): Guest Log: 02:02:32.577073 timesync vgsvcTimeSyncWorker: Radical host time change: 37 852 157 000 000ns (HostNow=1 610 709 147 871 000 000 ns HostLast=1 610 671 295 714 000 000 ns) 2021-01-15 12:12:38 (7748): Guest Log: 02:02:42.646250 timesync vgsvcTimeSyncWorker: Radical guest time change: 37 879 392 291 000ns (GuestNow=1 610 709 157 978 699 000 ns GuestLast=1 610 671 278 586 408 000 ns fSetTimeLastLoop=true ) 2021-01-15 12:38:43 (7748): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-15 12:38:54 (7748): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-15 13:29:07 (7748): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-15 13:29:17 (7748): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-15 13:53:30 (7748): Status Report: Job Duration: '864000.000000' 2021-01-15 13:53:30 (7748): Status Report: Elapsed Time: '114251.000000' 2021-01-15 13:53:30 (7748): Status Report: CPU Time: '68939.453125' 2021-01-15 15:33:48 (7748): Status Report: Job Duration: '864000.000000' 2021-01-15 15:33:48 (7748): Status Report: Elapsed Time: '120251.000000' 2021-01-15 15:33:48 (7748): Status Report: CPU Time: '72566.156250' 2021-01-15 16:08:28 (7748): Stopping VM. 2021-01-16 11:21:51 (9308): Detected: vboxwrapper 26197 2021-01-16 11:21:51 (9308): Detected: BOINC client v7.7 2021-01-16 11:21:54 (9308): Detected: VirtualBox VboxManage Interface (Version: 6.1.12) 2021-01-16 11:22:09 (9308): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2021-01-16 11:22:10 (9308): Starting VM using VBoxManage interface. (boinc_277d89f062313ddf, slot#0) 2021-01-16 11:22:18 (9308): Successfully started VM. (PID = '10156') 2021-01-16 11:22:18 (9308): Reporting VM Process ID to BOINC. 2021-01-16 11:22:18 (9308): VM state change detected. (old = 'PoweredOff', new = 'Running') 2021-01-16 11:22:18 (9308): Detected: Web Application Enabled (http://localhost:54874) 2021-01-16 11:22:18 (9308): Detected: Remote Desktop Enabled (localhost:54875) 2021-01-16 11:22:18 (9308): Status Report: Job Duration: '864000.000000' 2021-01-16 11:22:18 (9308): Status Report: Elapsed Time: '122324.000000' 2021-01-16 11:22:18 (9308): Status Report: CPU Time: '73817.921875' 2021-01-16 11:22:18 (9308): Preference change detected 2021-01-16 11:22:18 (9308): Setting CPU throttle for VM. (60%) 2021-01-16 11:22:18 (9308): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 240 seconds) or (Vbox_job.xml: 600 seconds)) 2021-01-16 11:22:25 (9308): Guest Log: 05:58:25.857632 timesync vgsvcTimeSyncWorker: Radical host time change: 69 238 933 000 000ns (HostNow=1 610 792 544 716 000 000 ns HostLast=1 610 723 305 783 000 000 ns) 2021-01-16 11:22:35 (9308): Guest Log: 05:58:35.860665 timesync vgsvcTimeSyncWorker: Radical guest time change: 69 253 528 969 000ns (GuestNow=1 610 792 554 719 044 000 ns GuestLast=1 610 723 301 190 075 000 ns fSetTimeLastLoop=true ) 2021-01-16 11:24:43 (9308): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-16 11:24:53 (9308): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-16 11:53:11 (9308): Stopping VM. 2021-01-16 11:53:15 (9308): Error in stop VM for VM: -108 Command: VBoxManage -q controlvm "boinc_277d89f062313ddf" savestate Output: 0%...10%...20%...30%...40%...50%...60%...70%... 2021-01-16 11:53:15 (9308): VM did not stop when requested. 2021-01-16 11:53:15 (9308): VM was NOT successfully terminated. 2021-01-16 18:09:01 (11728): Detected: vboxwrapper 26197 2021-01-16 18:09:01 (11728): Detected: BOINC client v7.7 2021-01-16 18:09:02 (11728): Detected: VirtualBox VboxManage Interface (Version: 6.1.12) 2021-01-16 18:09:02 (11728): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2021-01-16 18:09:02 (11728): Starting VM using VBoxManage interface. (boinc_277d89f062313ddf, slot#0) 2021-01-16 18:09:09 (11728): Successfully started VM. (PID = '7564') 2021-01-16 18:09:09 (11728): Reporting VM Process ID to BOINC. 2021-01-16 18:09:09 (11728): Guest Log: BIOS: VirtualBox 6.1.12 2021-01-16 18:09:09 (11728): Guest Log: CPUID EDX: 0x178bfbff 2021-01-16 18:09:09 (11728): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63 2021-01-16 18:09:09 (11728): VM state change detected. (old = 'PoweredOff', new = 'Running') 2021-01-16 18:09:09 (11728): Detected: Web Application Enabled (http://localhost:54874) 2021-01-16 18:09:09 (11728): Detected: Remote Desktop Enabled (localhost:54875) 2021-01-16 18:09:09 (11728): Status Report: Job Duration: '864000.000000' 2021-01-16 18:09:09 (11728): Status Report: Elapsed Time: '124151.000000' 2021-01-16 18:09:09 (11728): Status Report: CPU Time: '74928.703125' 2021-01-16 18:09:09 (11728): Preference change detected 2021-01-16 18:09:09 (11728): Setting CPU throttle for VM. (60%) 2021-01-16 18:09:09 (11728): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 240 seconds) or (Vbox_job.xml: 600 seconds)) 2021-01-16 18:09:11 (11728): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032 2021-01-16 18:09:11 (11728): Guest Log: BIOS: Booting from Hard Disk... 2021-01-16 18:09:13 (11728): Guest Log: BIOS: KBD: unsupported int 16h function 03 2021-01-16 18:09:13 (11728): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 2021-01-16 18:11:01 (11728): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds 2021-01-16 18:11:01 (11728): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000) 2021-01-16 18:11:05 (11728): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log 2021-01-16 18:11:05 (11728): Guest Log: 00:00:00.000101 main Log opened 2021-01-16T17:11:11.957611000Z 2021-01-16 18:11:05 (11728): Guest Log: 00:00:00.000214 main OS Product: Linux 2021-01-16 18:11:05 (11728): Guest Log: 00:00:00.000267 main OS Release: 4.14.76-13.cernvm.x86_64 2021-01-16 18:11:05 (11728): Guest Log: 00:00:00.000322 main OS Version: #1 SMP Tue Oct 16 18:26:15 CEST 2018 2021-01-16 18:11:05 (11728): Guest Log: 00:00:00.000358 main Executable: /usr/sbin/VBoxService 2021-01-16 18:11:05 (11728): Guest Log: 00:00:00.000359 main Process ID: 3199 2021-01-16 18:11:05 (11728): Guest Log: 00:00:00.000360 main Package type: LINUX_64BITS_GENERIC 2021-01-16 18:11:05 (11728): Guest Log: 00:00:00.005108 main 5.2.6 r120293 started. Verbose level = 0 2021-01-16 18:11:33 (11728): Guest Log: 18:11:39 CET +01:00 2021-01-16: cranky: [INFO] Detected Theory App 2021-01-16 18:11:33 (11728): Guest Log: 18:11:39 CET +01:00 2021-01-16: cranky: [INFO] Checking CVMFS. 2021-01-16 18:11:35 (11728): Guest Log: Probing /cvmfs/sft.cern.ch... OK 2021-01-16 18:11:37 (11728): 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 2021-01-16 18:11:37 (11728): Guest Log: 2.5.2.0 4102 0 25652 19479 3 1 2663358 4096001 0 65024 0 0 n/a 0 0 http://s1cern-cvmfs.openhtc.io/cvmfs/sft.cern.ch DIRECT 1 2021-01-16 18:11:38 (11728): Guest Log: Probing /cvmfs/grid.cern.ch... OK 2021-01-16 18:11:39 (11728): 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 2021-01-16 18:11:39 (11728): Guest Log: 2.5.2.0 4059 0 25488 14205 3 2 2663358 4096001 0 65024 0 2 0 4281 1538 http://s1cern-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1 2021-01-16 18:11:41 (11728): Guest Log: Probing /cvmfs/cernvm-prod.cern.ch... OK 2021-01-16 18:11:42 (11728): 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 2021-01-16 18:11:42 (11728): Guest Log: 2.5.2.0 4035 0 27224 259 3 1 2663358 4096001 0 65024 0 0 n/a 0 0 http://s1cern-cvmfs.openhtc.io/cvmfs/cernvm-prod.cern.ch DIRECT 1 2021-01-16 18:11:44 (11728): Guest Log: Probing /cvmfs/alice.cern.ch... OK 2021-01-16 18:11:45 (11728): 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 2021-01-16 18:11:45 (11728): Guest Log: 2.5.2.0 4079 0 28764 8423 3 1 2663358 4096001 0 65024 0 0 n/a 4765 1851 http://s1ral-cvmfs.openhtc.io/cvmfs/alice.cern.ch DIRECT 1 2021-01-16 18:11:45 (11728): Guest Log: 18:11:51 CET +01:00 2021-01-16: cranky: [INFO] Checking runc. 2021-01-16 18:11:45 (11728): Guest Log: 18:11:51 CET +01:00 2021-01-16: cranky: [INFO] Creating the filesystem. 2021-01-16 18:11:45 (11728): Guest Log: 18:11:51 CET +01:00 2021-01-16: cranky: [INFO] Using /cvmfs/cernvm-prod.cern.ch/cvm3 2021-01-16 18:11:45 (11728): Guest Log: 18:11:51 CET +01:00 2021-01-16: cranky: [INFO] Updating config.json. 2021-01-16 18:11:45 (11728): Guest Log: 18:11:51 CET +01:00 2021-01-16: cranky: [INFO] Running Container 'runc'. 2021-01-16 18:11:46 (11728): Guest Log: job: htmld=/shared/html/job 2021-01-16 18:11:46 (11728): Guest Log: job: unpack exitcode=0 2021-01-16 18:11:47 (11728): Guest Log: 18:11:53 CET +01:00 2021-01-16: cranky: [INFO] ===> [runRivet] Sat Jan 16 17:11:52 UTC 2021 [boinc pp jets 7000 25,-,100 - pythia8 8.243 tune-AU2m 100000 162] 2021-01-16 18:23:04 (11728): Stopping VM. 2021-01-17 00:07:35 (9916): Detected: vboxwrapper 26197 2021-01-17 00:07:35 (9916): Detected: BOINC client v7.7 2021-01-17 00:07:36 (9916): Detected: VirtualBox VboxManage Interface (Version: 6.1.12) 2021-01-17 00:07:36 (9916): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2021-01-17 00:07:37 (9916): Starting VM using VBoxManage interface. (boinc_277d89f062313ddf, slot#0) 2021-01-17 00:07:46 (9916): Successfully started VM. (PID = '9400') 2021-01-17 00:07:46 (9916): Reporting VM Process ID to BOINC. 2021-01-17 00:07:46 (9916): VM state change detected. (old = 'PoweredOff', new = 'Running') 2021-01-17 00:07:46 (9916): Detected: Web Application Enabled (http://localhost:54874) 2021-01-17 00:07:46 (9916): Detected: Remote Desktop Enabled (localhost:54875) 2021-01-17 00:07:47 (9916): Guest Log: 00:12:01.316857 timesync vgsvcTimeSyncWorker: Radical host time change: 20 689 489 000 000ns (HostNow=1 610 838 466 025 000 000 ns HostLast=1 610 817 776 536 000 000 ns) 2021-01-17 00:07:47 (9916): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-17 00:07:56 (9916): Status Report: Job Duration: '864000.000000' 2021-01-17 00:07:56 (9916): Status Report: Elapsed Time: '124977.000000' 2021-01-17 00:07:56 (9916): Status Report: CPU Time: '75364.484375' 2021-01-17 00:07:56 (9916): Preference change detected 2021-01-17 00:07:56 (9916): Setting CPU throttle for VM. (60%) 2021-01-17 00:07:56 (9916): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 240 seconds) or (Vbox_job.xml: 600 seconds)) 2021-01-17 00:07:57 (9916): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-17 00:08:06 (9916): Guest Log: 00:12:11.345340 timesync vgsvcTimeSyncWorker: Radical guest time change: 20 683 093 080 000ns (GuestNow=1 610 838 476 147 826 000 ns GuestLast=1 610 817 793 054 746 000 ns fSetTimeLastLoop=true ) 2021-01-17 00:29:37 (9916): Stopping VM. 2021-01-17 20:35:36 (6740): Detected: vboxwrapper 26197 2021-01-17 20:35:36 (6740): Detected: BOINC client v7.7 2021-01-17 20:35:39 (6740): Detected: VirtualBox VboxManage Interface (Version: 6.1.12) 2021-01-17 20:35:55 (6740): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2021-01-17 20:35:56 (6740): Starting VM using VBoxManage interface. (boinc_277d89f062313ddf, slot#0) 2021-01-17 20:36:06 (6740): Successfully started VM. (PID = '12800') 2021-01-17 20:36:06 (6740): Reporting VM Process ID to BOINC. 2021-01-17 20:36:06 (6740): VM state change detected. (old = 'PoweredOff', new = 'Running') 2021-01-17 20:36:06 (6740): Detected: Web Application Enabled (http://localhost:54874) 2021-01-17 20:36:06 (6740): Detected: Remote Desktop Enabled (localhost:54875) 2021-01-17 20:36:06 (6740): Status Report: Job Duration: '864000.000000' 2021-01-17 20:36:06 (6740): Status Report: Elapsed Time: '126276.000000' 2021-01-17 20:36:06 (6740): Status Report: CPU Time: '76147.109375' 2021-01-17 20:36:06 (6740): Preference change detected 2021-01-17 20:36:06 (6740): Setting CPU throttle for VM. (60%) 2021-01-17 20:36:07 (6740): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 240 seconds) or (Vbox_job.xml: 600 seconds)) 2021-01-17 20:36:08 (6740): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-17 20:36:18 (6740): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-17 20:36:24 (6740): Guest Log: 00:33:52.759525 timesync vgsvcTimeSyncWorker: Radical host time change: 72 407 529 000 000ns (HostNow=1 610 912 184 417 000 000 ns HostLast=1 610 839 776 888 000 000 ns) 2021-01-17 20:36:34 (6740): Guest Log: 00:34:02.834178 timesync vgsvcTimeSyncWorker: Radical guest time change: 72 416 929 658 000ns (GuestNow=1 610 912 194 491 664 000 ns GuestLast=1 610 839 777 562 006 000 ns fSetTimeLastLoop=true ) 2021-01-17 21:50:24 (6740): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-17 21:50:34 (6740): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-17 22:16:49 (6740): Status Report: Job Duration: '864000.000000' 2021-01-17 22:16:49 (6740): Status Report: Elapsed Time: '132276.000000' 2021-01-17 22:16:49 (6740): Status Report: CPU Time: '79773.718750' 2021-01-17 22:43:47 (6740): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-17 22:43:57 (6740): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-17 23:05:49 (6740): Stopping VM. 2021-01-18 11:55:19 (8464): Detected: vboxwrapper 26197 2021-01-18 11:55:19 (8464): Detected: BOINC client v7.7 2021-01-18 11:55:20 (8464): Detected: VirtualBox VboxManage Interface (Version: 6.1.12) 2021-01-18 11:55:20 (8464): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2021-01-18 11:55:21 (8464): Starting VM using VBoxManage interface. (boinc_277d89f062313ddf, slot#0) 2021-01-18 11:55:30 (8464): Successfully started VM. (PID = '12048') 2021-01-18 11:55:30 (8464): Reporting VM Process ID to BOINC. 2021-01-18 11:55:30 (8464): VM state change detected. (old = 'PoweredOff', new = 'Running') 2021-01-18 11:55:30 (8464): Detected: Web Application Enabled (http://localhost:54874) 2021-01-18 11:55:30 (8464): Detected: Remote Desktop Enabled (localhost:54875) 2021-01-18 11:55:31 (8464): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-18 11:55:40 (8464): Status Report: Job Duration: '864000.000000' 2021-01-18 11:55:40 (8464): Status Report: Elapsed Time: '135197.000000' 2021-01-18 11:55:40 (8464): Status Report: CPU Time: '81534.437500' 2021-01-18 11:55:40 (8464): Preference change detected 2021-01-18 11:55:40 (8464): Setting CPU throttle for VM. (60%) 2021-01-18 11:55:40 (8464): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 240 seconds) or (Vbox_job.xml: 600 seconds)) 2021-01-18 11:55:41 (8464): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-18 11:55:45 (8464): Guest Log: 03:03:05.971854 timesync vgsvcTimeSyncWorker: Radical host time change: 46 198 994 000 000ns (HostNow=1 610 967 344 305 000 000 ns HostLast=1 610 921 145 311 000 000 ns) 2021-01-18 11:55:55 (8464): Guest Log: 03:03:15.973538 timesync vgsvcTimeSyncWorker: Radical guest time change: 46 216 677 357 000ns (GuestNow=1 610 967 354 306 690 000 ns GuestLast=1 610 921 137 629 333 000 ns fSetTimeLastLoop=true ) 2021-01-18 12:34:23 (8464): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-18 12:34:33 (8464): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-18 12:34:43 (8464): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-18 12:34:53 (8464): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-18 13:36:23 (8464): Status Report: Job Duration: '864000.000000' 2021-01-18 13:36:23 (8464): Status Report: Elapsed Time: '141197.000000' 2021-01-18 13:36:23 (8464): Status Report: CPU Time: '85161.546875' 2021-01-18 14:58:43 (8464): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-18 14:58:53 (8464): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-18 15:16:53 (8464): Status Report: Job Duration: '864000.000000' 2021-01-18 15:16:53 (8464): Status Report: Elapsed Time: '147197.000000' 2021-01-18 15:16:53 (8464): Status Report: CPU Time: '88775.593750' 2021-01-18 15:56:17 (8464): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-18 15:56:27 (8464): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-18 15:57:37 (8464): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-18 15:57:47 (8464): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-18 16:57:32 (8464): Status Report: Job Duration: '864000.000000' 2021-01-18 16:57:32 (8464): Status Report: Elapsed Time: '153197.000000' 2021-01-18 16:57:32 (8464): Status Report: CPU Time: '92389.406250' 2021-01-18 18:37:42 (8464): Status Report: Job Duration: '864000.000000' 2021-01-18 18:37:42 (8464): Status Report: Elapsed Time: '159197.000000' 2021-01-18 18:37:42 (8464): Status Report: CPU Time: '96002.437500' 2021-01-18 19:00:36 (8464): Stopping VM. 2021-01-18 19:04:52 (7596): Detected: vboxwrapper 26197 2021-01-18 19:04:52 (7596): Detected: BOINC client v7.7 2021-01-18 19:04:53 (7596): Detected: VirtualBox VboxManage Interface (Version: 6.1.12) 2021-01-18 19:04:53 (7596): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2021-01-18 19:04:54 (7596): Starting VM using VBoxManage interface. (boinc_277d89f062313ddf, slot#0) 2021-01-18 19:05:04 (7596): Successfully started VM. (PID = '7072') 2021-01-18 19:05:04 (7596): Reporting VM Process ID to BOINC. 2021-01-18 19:05:04 (7596): VM state change detected. (old = 'PoweredOff', new = 'Running') 2021-01-18 19:05:04 (7596): Detected: Web Application Enabled (http://localhost:54874) 2021-01-18 19:05:04 (7596): Detected: Remote Desktop Enabled (localhost:54875) 2021-01-18 19:05:05 (7596): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-18 19:05:13 (7596): Status Report: Job Duration: '864000.000000' 2021-01-18 19:05:13 (7596): Status Report: Elapsed Time: '160568.000000' 2021-01-18 19:05:13 (7596): Status Report: CPU Time: '96828.843750' 2021-01-18 19:05:13 (7596): Preference change detected 2021-01-18 19:05:13 (7596): Setting CPU throttle for VM. (60%) 2021-01-18 19:05:13 (7596): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 240 seconds) or (Vbox_job.xml: 600 seconds)) 2021-01-18 19:05:13 (7596): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-18 19:05:47 (7596): Stopping VM. 2021-01-19 15:05:31 (4060): Detected: vboxwrapper 26197 2021-01-19 15:05:31 (4060): Detected: BOINC client v7.7 2021-01-19 15:05:32 (4060): Detected: VirtualBox VboxManage Interface (Version: 6.1.12) 2021-01-19 15:05:33 (4060): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2021-01-19 15:05:35 (4060): Starting VM using VBoxManage interface. (boinc_277d89f062313ddf, slot#0) 2021-01-19 15:05:48 (4060): Successfully started VM. (PID = '11892') 2021-01-19 15:05:48 (4060): Reporting VM Process ID to BOINC. 2021-01-19 15:05:48 (4060): Guest Log: 10:07:57.421495 timesync vgsvcTimeSyncWorker: Radical host time change: 72 008 107 000 000ns (HostNow=1 611 065 146 650 000 000 ns HostLast=1 610 993 138 543 000 000 ns) 2021-01-19 15:05:48 (4060): VM state change detected. (old = 'PoweredOff', new = 'Running') 2021-01-19 15:05:48 (4060): Detected: Web Application Enabled (http://localhost:54874) 2021-01-19 15:05:48 (4060): Detected: Remote Desktop Enabled (localhost:54875) 2021-01-19 15:05:49 (4060): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-19 15:05:52 (4060): Status Report: Job Duration: '864000.000000' 2021-01-19 15:05:52 (4060): Status Report: Elapsed Time: '160602.000000' 2021-01-19 15:05:52 (4060): Status Report: CPU Time: '96856.687500' 2021-01-19 15:05:52 (4060): Preference change detected 2021-01-19 15:05:52 (4060): Setting CPU throttle for VM. (60%) 2021-01-19 15:05:53 (4060): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 240 seconds) or (Vbox_job.xml: 600 seconds)) 2021-01-19 15:05:53 (4060): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-19 15:06:00 (4060): Guest Log: 10:08:07.437179 timesync vgsvcTimeSyncWorker: Radical guest time change: 72 008 121 480 000ns (GuestNow=1 611 065 156 665 685 000 ns GuestLast=1 610 993 148 544 205 000 ns fSetTimeLastLoop=true ) 2021-01-19 16:46:11 (4060): Status Report: Job Duration: '864000.000000' 2021-01-19 16:46:11 (4060): Status Report: Elapsed Time: '166602.125557' 2021-01-19 16:46:11 (4060): Status Report: CPU Time: '100492.500000' 2021-01-19 17:10:12 (4060): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-19 17:10:32 (4060): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-19 17:36:10 (4060): Stopping VM. 2021-01-19 21:03:24 (7620): Detected: vboxwrapper 26197 2021-01-19 21:03:24 (7620): Detected: BOINC client v7.7 2021-01-19 21:03:25 (7620): Detected: VirtualBox VboxManage Interface (Version: 6.1.12) 2021-01-19 21:03:25 (7620): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2021-01-19 21:03:26 (7620): Starting VM using VBoxManage interface. (boinc_277d89f062313ddf, slot#0) 2021-01-19 21:03:37 (7620): Successfully started VM. (PID = '3236') 2021-01-19 21:03:37 (7620): Reporting VM Process ID to BOINC. 2021-01-19 21:03:37 (7620): VM state change detected. (old = 'PoweredOff', new = 'Running') 2021-01-19 21:03:37 (7620): Detected: Web Application Enabled (http://localhost:54874) 2021-01-19 21:03:37 (7620): Detected: Remote Desktop Enabled (localhost:54875) 2021-01-19 21:03:37 (7620): Status Report: Job Duration: '864000.000000' 2021-01-19 21:03:37 (7620): Status Report: Elapsed Time: '169567.125557' 2021-01-19 21:03:37 (7620): Status Report: CPU Time: '102286.546875' 2021-01-19 21:03:37 (7620): Preference change detected 2021-01-19 21:03:37 (7620): Setting CPU throttle for VM. (60%) 2021-01-19 21:03:38 (7620): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 240 seconds) or (Vbox_job.xml: 600 seconds)) 2021-01-19 21:03:43 (7620): Guest Log: 12:38:09.052636 timesync vgsvcTimeSyncWorker: Radical host time change: 12 456 224 000 000ns (HostNow=1 611 086 623 128 000 000 ns HostLast=1 611 074 166 904 000 000 ns) 2021-01-19 21:03:53 (7620): Guest Log: 12:38:19.090183 timesync vgsvcTimeSyncWorker: Radical guest time change: 12 474 884 444 000ns (GuestNow=1 611 086 633 165 571 000 ns GuestLast=1 611 074 158 281 127 000 ns fSetTimeLastLoop=true ) 2021-01-19 22:44:00 (7620): Status Report: Job Duration: '864000.000000' 2021-01-19 22:44:00 (7620): Status Report: Elapsed Time: '175567.125557' 2021-01-19 22:44:00 (7620): Status Report: CPU Time: '105927.281250' 2021-01-19 22:50:45 (7620): Stopping VM. 2021-01-20 17:05:12 (9112): Detected: vboxwrapper 26197 2021-01-20 17:05:13 (9112): Detected: BOINC client v7.7 2021-01-20 17:05:14 (9112): Detected: VirtualBox VboxManage Interface (Version: 6.1.12) 2021-01-20 17:05:31 (9112): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds) 2021-01-20 17:05:31 (9112): Starting VM using VBoxManage interface. (boinc_277d89f062313ddf, slot#0) 2021-01-20 17:05:40 (9112): Successfully started VM. (PID = '10224') 2021-01-20 17:05:40 (9112): Reporting VM Process ID to BOINC. 2021-01-20 17:05:40 (9112): VM state change detected. (old = 'PoweredOff', new = 'Running') 2021-01-20 17:05:40 (9112): Detected: Web Application Enabled (http://localhost:54874) 2021-01-20 17:05:40 (9112): Detected: Remote Desktop Enabled (localhost:54875) 2021-01-20 17:05:40 (9112): Status Report: Job Duration: '864000.000000' 2021-01-20 17:05:40 (9112): Status Report: Elapsed Time: '175970.125557' 2021-01-20 17:05:40 (9112): Status Report: CPU Time: '106169.296875' 2021-01-20 17:05:40 (9112): Preference change detected 2021-01-20 17:05:40 (9112): Setting CPU throttle for VM. (60%) 2021-01-20 17:05:40 (9112): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 240 seconds) or (Vbox_job.xml: 600 seconds)) 2021-01-20 17:05:48 (9112): Guest Log: 14:25:20.271069 timesync vgsvcTimeSyncWorker: Radical host time change: 65 704 004 000 000ns (HostNow=1 611 158 747 627 000 000 ns HostLast=1 611 093 043 623 000 000 ns) 2021-01-20 17:05:58 (9112): Guest Log: 14:25:30.285957 timesync vgsvcTimeSyncWorker: Radical guest time change: 65 703 295 448 000ns (GuestNow=1 611 158 757 641 889 000 ns GuestLast=1 611 093 054 346 441 000 ns fSetTimeLastLoop=true ) 2021-01-20 18:21:32 (9112): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-20 18:21:39 (9112): Error in resume VM for VM: -2135228414 Command: VBoxManage -q controlvm "boinc_277d89f062313ddf" resume Output: VBoxManage.exe: error: VM is paused due to host power management VBoxManage.exe: error: Details: code VBOX_E_INVALID_VM_STATE (0x80bb0002), component ConsoleWrap, interface IConsole, callee IUnknown VBoxManage.exe: error: Context: "Resume()" at line 410 of file VBoxManageControlVM.cpp 2021-01-20 20:13:08 (9112): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-20 20:13:10 (9112): Guest Log: 15:41:07.841883 timesync vgsvcTimeSyncWorker: Radical host time change: 6 704 912 000 000ns (HostNow=1 611 169 990 076 000 000 ns HostLast=1 611 163 285 164 000 000 ns) 2021-01-20 20:13:17 (9112): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-20 20:13:27 (9112): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-20 20:13:30 (9112): Guest Log: 15:41:17.849338 timesync vgsvcTimeSyncWorker: Radical guest time change: 6 704 885 666 000ns (GuestNow=1 611 170 000 083 466 000 ns GuestLast=1 611 163 295 197 800 000 ns fSetTimeLastLoop=true ) 2021-01-20 20:37:41 (9112): Status Report: Job Duration: '864000.000000' 2021-01-20 20:37:41 (9112): Status Report: Elapsed Time: '181970.125557' 2021-01-20 20:37:41 (9112): Status Report: CPU Time: '109792.843750' 2021-01-20 20:54:50 (9112): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-20 20:55:00 (9112): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-20 22:18:08 (9112): Status Report: Job Duration: '864000.000000' 2021-01-20 22:18:08 (9112): Status Report: Elapsed Time: '187970.125557' 2021-01-20 22:18:08 (9112): Status Report: CPU Time: '113414.734375' 2021-01-20 23:01:09 (9112): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-20 23:01:19 (9112): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-20 23:58:29 (9112): Status Report: Job Duration: '864000.000000' 2021-01-20 23:58:29 (9112): Status Report: Elapsed Time: '193970.125557' 2021-01-20 23:58:29 (9112): Status Report: CPU Time: '117031.125000' 2021-01-21 00:12:44 (9112): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-21 00:12:54 (9112): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-21 00:16:14 (9112): VM state change detected. (old = 'Running', new = 'Paused') 2021-01-21 00:16:24 (9112): VM state change detected. (old = 'Paused', new = 'Running') 2021-01-21 00:24:45 (9112): Guest Log: job: run exitcode=0 2021-01-21 00:24:45 (9112): Guest Log: job: diskusage=2508 2021-01-21 00:24:45 (9112): Guest Log: job: logsize=80 k 2021-01-21 00:24:45 (9112): Guest Log: job: times= 2021-01-21 00:24:45 (9112): Guest Log: 0m0.010s 0m0.017s 2021-01-21 00:24:45 (9112): Guest Log: 1173m37.347s 6m30.357s 2021-01-21 00:24:45 (9112): Guest Log: job: cpuusage=70808 2021-01-21 00:24:45 (9112): Guest Log: 00:24:03 CET +01:00 2021-01-21: cranky: [INFO] Container 'runc' finished with status code 0. 2021-01-21 00:24:45 (9112): Guest Log: 00:24:03 CET +01:00 2021-01-21: cranky: [INFO] Preparing output. 2021-01-21 00:24:47 (9112): Guest Log: [INFO] Job Finished 2021-01-21 00:24:47 (9112): Guest Log: [INFO] Shutting Down. 2021-01-21 00:24:47 (9112): VM Completion File Detected. 2021-01-21 00:24:47 (9112): VM Completion Message: Job Finished . 2021-01-21 00:24:47 (9112): Powering off VM. 2021-01-21 00:29:48 (9112): VM did not power off when requested. 2021-01-21 00:29:48 (9112): VM was successfully terminated. 2021-01-21 00:29:48 (9112): Deregistering VM. (boinc_277d89f062313ddf, slot#0) 2021-01-21 00:29:48 (9112): Removing network bandwidth throttle group from VM. 2021-01-21 00:29:48 (9112): Removing VM from VirtualBox. 00:29:54 (9112): called boinc_finish(0) </stderr_txt> ]]>
©2025 CERN