Job instance 288014699

Name	Theory_2390-1131086-54_0
Workunit	147561334
Created	18 Oct 2020, 15:43:02 UTC
Sent	18 Oct 2020, 18:07:59 UTC
Report deadline	29 Oct 2020, 18:07:59 UTC
Received	30 Oct 2020, 15:16:28 UTC
Server state	Over
Outcome	Success
Client state	Done
Exit status	0 (0x00000000)
Computer ID	10618956
Run time	1 days 0 hours 44 min 23 sec
CPU time	18 hours 44 min 31 sec
Priority	1603035780
Validate state	Valid
Credit	696.73
Device peak FLOPS	3.38 GFLOPS
Application version	Theory Simulation v300.06 (vbox64_theory) windows_x86_64
Peak working set size	70.38 MB
Peak swap size	74.66 MB
Peak disk usage	3.04 GB
Stderr output

<core_client_version>7.16.11</core_client_version>
<![CDATA[
<stderr_txt>
2020-10-21 12:03:54 (11052): Detected: vboxwrapper 26197
2020-10-21 12:03:54 (11052): Detected: BOINC client v7.7
2020-10-21 12:03:55 (11052): Detected: VirtualBox VboxManage Interface (Version: 6.0.14)
2020-10-21 12:03:55 (11052): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2020-10-21 12:03:55 (11052): Successfully copied 'init_data.xml' to the shared directory.
2020-10-21 12:03:55 (11052): Successfully copied 'input' to the shared directory.
2020-10-21 12:03:56 (11052): Create VM. (boinc_57d9607daee3f2eb, slot#18)
2020-10-21 12:03:57 (11052): Setting Memory Size for VM. (630MB)
2020-10-21 12:03:57 (11052): Setting CPU Count for VM. (1)
2020-10-21 12:03:58 (11052): Setting Chipset Options for VM.
2020-10-21 12:03:58 (11052): Setting Boot Options for VM.
2020-10-21 12:03:58 (11052): Setting Network Configuration for NAT.
2020-10-21 12:03:59 (11052): Enabling VM Network Access.
2020-10-21 12:03:59 (11052): Disabling USB Support for VM.
2020-10-21 12:03:59 (11052): Disabling COM Port Support for VM.
2020-10-21 12:03:59 (11052): Disabling LPT Port Support for VM.
2020-10-21 12:04:00 (11052): Disabling Audio Support for VM.
2020-10-21 12:04:00 (11052): Disabling Clipboard Support for VM.
2020-10-21 12:04:00 (11052): Disabling Drag and Drop Support for VM.
2020-10-21 12:04:00 (11052): Adding storage controller(s) to VM.
2020-10-21 12:04:01 (11052): Adding virtual disk drive to VM. (vm_image.vdi)
2020-10-21 12:04:01 (11052): Adding VirtualBox Guest Additions to VM.
2020-10-21 12:04:01 (11052): Adding network bandwidth throttle group to VM. (Defaulting to 1024GB)
2020-10-21 12:04:01 (11052): forwarding host port 52785 to guest port 80
2020-10-21 12:04:02 (11052): Enabling remote desktop for VM.
2020-10-21 12:04:02 (11052): Required extension pack not installed, remote desktop not enabled.
2020-10-21 12:04:02 (11052): Enabling shared directory for VM.
2020-10-21 12:04:02 (11052): Starting VM using VBoxManage interface. (boinc_57d9607daee3f2eb, slot#18)
2020-10-21 12:04:07 (11052): Successfully started VM. (PID = '5196')
2020-10-21 12:04:07 (11052): Reporting VM Process ID to BOINC.
2020-10-21 12:04:07 (11052): Guest Log: BIOS: VirtualBox 6.0.14

2020-10-21 12:04:07 (11052): Guest Log: CPUID EDX: 0x178bfbff

2020-10-21 12:04:07 (11052): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63

2020-10-21 12:04:07 (11052): VM state change detected. (old = 'PoweredOff', new = 'Running')
2020-10-21 12:04:07 (11052): Detected: Web Application Enabled (http://localhost:52785)
2020-10-21 12:04:07 (11052): Preference change detected
2020-10-21 12:04:07 (11052): Setting CPU throttle for VM. (75%)
2020-10-21 12:04:08 (11052): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2020-10-21 12:04:09 (11052): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032

2020-10-21 12:04:09 (11052): Guest Log: BIOS: Booting from Hard Disk...

2020-10-21 12:04:11 (11052): Guest Log: BIOS: KBD: unsupported int 16h function 03

2020-10-21 12:04:11 (11052): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 

2020-10-21 12:04:49 (11052): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds

2020-10-21 12:04:49 (11052): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)

2020-10-21 12:04:55 (11052): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log

2020-10-21 12:04:55 (11052): Guest Log: 00:00:00.000222 main     Log opened 2020-10-21T11:04:58.152062000Z

2020-10-21 12:04:55 (11052): Guest Log: 00:00:00.000441 main     OS Product: Linux

2020-10-21 12:04:55 (11052): Guest Log: 00:00:00.000514 main     OS Release: 4.14.76-13.cernvm.x86_64

2020-10-21 12:04:55 (11052): Guest Log: 00:00:00.000583 main     OS Version: #1 SMP Tue Oct 16 18:26:15 CEST 2018

2020-10-21 12:04:55 (11052): Guest Log: 00:00:00.000651 main     Executable: /usr/sbin/VBoxService

2020-10-21 12:04:55 (11052): Guest Log: 00:00:00.000654 main     Process ID: 3185

2020-10-21 12:04:55 (11052): Guest Log: 00:00:00.000655 main     Package type: LINUX_64BITS_GENERIC

2020-10-21 12:04:55 (11052): Guest Log: 00:00:00.005890 main     5.2.6 r120293 started. Verbose level = 0

2020-10-21 12:05:31 (11052): Guest Log: 12:05:34 BST +01:00 2020-10-21: cranky: [INFO] Detected Theory App

2020-10-21 12:05:31 (11052): Guest Log: 12:05:34 BST +01:00 2020-10-21: cranky: [INFO] Checking CVMFS.

2020-10-21 12:05:33 (11052): Guest Log: Probing /cvmfs/sft.cern.ch... OK

2020-10-21 12:05:34 (11052): 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

2020-10-21 12:05:34 (11052): Guest Log: 2.5.2.0 4066 0 27204 19144 3 1 264465 4096000 0 65024 0 0 n/a 5 13 http://s1ral-cvmfs.openhtc.io/cvmfs/sft.cern.ch DIRECT 1

2020-10-21 12:05:38 (11052): Guest Log: Probing /cvmfs/grid.cern.ch... OK

2020-10-21 12:05:39 (11052): 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

2020-10-21 12:05:39 (11052): Guest Log: 2.5.2.0 4091 0 25444 13505 3 2 264465 4096000 0 65024 0 2 -100 6412 3659 http://s1ral-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1

2020-10-21 12:05:41 (11052): Guest Log: Probing /cvmfs/cernvm-prod.cern.ch... OK

2020-10-21 12:05:42 (11052): 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

2020-10-21 12:05:42 (11052): Guest Log: 2.5.2.0 4044 0 25188 259 3 1 264465 4096000 0 65024 0 0 n/a 4 6 http://s1ral-cvmfs.openhtc.io/cvmfs/cernvm-prod.cern.ch DIRECT 1

2020-10-21 12:05:44 (11052): Guest Log: Probing /cvmfs/alice.cern.ch... OK

2020-10-21 12:05:45 (11052): 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

2020-10-21 12:05:45 (11052): Guest Log: 2.5.2.0 4114 0 28248 7753 3 1 264465 4096000 0 65024 0 0 n/a 4475 2089 http://s1ral-cvmfs.openhtc.io/cvmfs/alice.cern.ch DIRECT 1

2020-10-21 12:05:45 (11052): Guest Log: 12:05:46 BST +01:00 2020-10-21: cranky: [INFO] Checking runc.

2020-10-21 12:05:45 (11052): Guest Log: 12:05:47 BST +01:00 2020-10-21: cranky: [INFO] Creating the filesystem.

2020-10-21 12:05:45 (11052): Guest Log: 12:05:47 BST +01:00 2020-10-21: cranky: [INFO] Using /cvmfs/cernvm-prod.cern.ch/cvm3

2020-10-21 12:05:46 (11052): Guest Log: 12:05:47 BST +01:00 2020-10-21: cranky: [INFO] Updating config.json.

2020-10-21 12:05:46 (11052): Guest Log: 12:05:47 BST +01:00 2020-10-21: cranky: [INFO] Running Container 'runc'.

2020-10-21 12:05:51 (11052): Guest Log: job: htmld=/shared/html/job

2020-10-21 12:05:51 (11052): Guest Log: job: unpack exitcode=0

2020-10-21 12:05:52 (11052): Guest Log: 12:05:53 BST +01:00 2020-10-21: cranky: [INFO] ===> [runRivet] Wed Oct 21 11:05:53 UTC 2020 [boinc pp jets 8000 150,-,2360 - pythia8 8.244 fischerPP2 100000 54]

2020-10-21 13:44:13 (11052): Status Report: Job Duration: '864000.000000'
2020-10-21 13:44:13 (11052): Status Report: Elapsed Time: '6000.580839'
2020-10-21 13:44:13 (11052): Status Report: CPU Time: '4499.187500'
2020-10-21 13:48:53 (11052): Stopping VM.
2020-10-21 13:49:40 (11052): Error in stop VM for VM: -182
Command:
VBoxManage -q controlvm "boinc_57d9607daee3f2eb" savestate
Output:
0%...10%...20%...30%...40%...50%...60%...
2020-10-21 13:49:40 (11052): VM did not stop when requested.
2020-10-21 13:49:40 (11052): VM was successfully terminated.
2020-10-21 13:49:52 (3316): Detected: vboxwrapper 26197
2020-10-21 13:49:52 (3316): Detected: BOINC client v7.7
2020-10-21 13:49:55 (3316): Detected: VirtualBox VboxManage Interface (Version: 6.0.14)
2020-10-21 13:49:56 (3316): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2020-10-21 13:50:00 (3316): ERROR: VM failed to start
2020-10-21 13:50:05 (3316): 
   BOINC will be notified that it needs to clean up the environment.
 		    This is a temporary problem and so this job will be rescheduled for another time.

2020-10-21 14:09:57 (11184): Detected: vboxwrapper 26197
2020-10-21 14:09:57 (11184): Detected: BOINC client v7.7
2020-10-21 14:09:58 (11184): Detected: VirtualBox VboxManage Interface (Version: 6.0.14)
2020-10-21 14:10:00 (11184): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2020-10-21 14:10:01 (11184): Starting VM using VBoxManage interface. (boinc_57d9607daee3f2eb, slot#18)
2020-10-21 14:10:21 (11184): Successfully started VM. (PID = '5096')
2020-10-21 14:10:21 (11184): Reporting VM Process ID to BOINC.
2020-10-21 14:10:21 (11184): Guest Log: BIOS: VirtualBox 6.0.14

2020-10-21 14:10:21 (11184): Guest Log: CPUID EDX: 0x178bfbff

2020-10-21 14:10:21 (11184): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63

2020-10-21 14:10:21 (11184): VM state change detected. (old = 'PoweredOff', new = 'Running')
2020-10-21 14:10:21 (11184): Detected: Web Application Enabled (http://localhost:52785)
2020-10-21 14:10:22 (11184): VM state change detected. (old = 'Running', new = 'Paused')
2020-10-21 14:10:58 (11184): Status Report: Job Duration: '864000.000000'
2020-10-21 14:10:58 (11184): Status Report: Elapsed Time: '6279.580839'
2020-10-21 14:10:58 (11184): Status Report: CPU Time: '4702.046875'
2020-10-21 14:10:58 (11184): Preference change detected
2020-10-21 14:10:58 (11184): Setting CPU throttle for VM. (75%)
2020-10-21 14:11:00 (11184): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2020-10-21 14:11:00 (11184): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032

2020-10-21 14:11:00 (11184): Guest Log: BIOS: Booting from Hard Disk...

2020-10-21 14:11:00 (11184): VM state change detected. (old = 'Paused', new = 'Running')
2020-10-21 14:11:23 (11184): Guest Log: BIOS: KBD: unsupported int 16h function 03

2020-10-21 14:11:23 (11184): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 

2020-10-21 14:14:08 (11184): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds

2020-10-21 14:14:08 (11184): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)

2020-10-21 14:14:26 (11184): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log

2020-10-21 14:14:26 (11184): Guest Log: 00:00:00.013676 main     Log opened 2020-10-21T13:14:29.397293000Z

2020-10-21 14:14:26 (11184): Guest Log: 00:00:00.015297 main     OS Product: Linux

2020-10-21 14:14:26 (11184): Guest Log: 00:00:00.016046 main     OS Release: 4.14.76-13.cernvm.x86_64

2020-10-21 14:14:26 (11184): Guest Log: 00:00:00.016582 main     OS Version: #1 SMP Tue Oct 16 18:26:15 CEST 2018

2020-10-21 14:14:26 (11184): Guest Log: 00:00:00.016899 main     Executable: /usr/sbin/VBoxService

2020-10-21 14:14:26 (11184): Guest Log: 00:00:00.016901 main     Process ID: 3178

2020-10-21 14:14:26 (11184): Guest Log: 00:00:00.016903 main     Package type: LINUX_64BITS_GENERIC

2020-10-21 14:14:26 (11184): Guest Log: 00:00:00.020353 main     5.2.6 r120293 started. Verbose level = 0

2020-10-21 14:16:51 (11184): Guest Log: 14:16:53 BST +01:00 2020-10-21: cranky: [INFO] Detected Theory App

2020-10-21 14:16:51 (11184): Guest Log: 14:16:53 BST +01:00 2020-10-21: cranky: [INFO] Checking CVMFS.

2020-10-21 14:16:54 (11184): Guest Log: Probing /cvmfs/sft.cern.ch... OK

2020-10-21 14:16:55 (11184): 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

2020-10-21 14:16:55 (11184): Guest Log: 2.5.2.0 4120 1 25120 19144 3 1 1310358 4096001 0 65024 0 0 n/a 0 0 http://s1ral-cvmfs.openhtc.io/cvmfs/sft.cern.ch DIRECT 1

2020-10-21 14:16:58 (11184): Guest Log: Probing /cvmfs/grid.cern.ch... OK

2020-10-21 14:16:59 (11184): 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

2020-10-21 14:16:59 (11184): Guest Log: 2.5.2.0 4190 1 25548 13507 3 2 1310358 4096001 0 65024 0 2 0 4271 3365 http://s1cern-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1

2020-10-21 14:17:02 (11184): Guest Log: Probing /cvmfs/cernvm-prod.cern.ch... OK

2020-10-21 14:17:04 (11184): 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

2020-10-21 14:17:04 (11184): Guest Log: 2.5.2.0 4145 1 25164 259 3 1 1310358 4096001 0 65024 0 0 n/a 0 0 http://s1cern-cvmfs.openhtc.io/cvmfs/cernvm-prod.cern.ch DIRECT 1

2020-10-21 14:17:06 (11184): Guest Log: Probing /cvmfs/alice.cern.ch... OK

2020-10-21 14:17:08 (11184): 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

2020-10-21 14:17:08 (11184): Guest Log: 2.5.2.0 4167 1 29108 7755 3 1 1310358 4096001 0 65024 0 0 n/a 4476 3472 http://s1ral-cvmfs.openhtc.io/cvmfs/alice.cern.ch DIRECT 1

2020-10-21 14:17:08 (11184): Guest Log: 14:17:09 BST +01:00 2020-10-21: cranky: [INFO] Checking runc.

2020-10-21 14:17:16 (11184): Guest Log: 14:17:17 BST +01:00 2020-10-21: cranky: [INFO] Creating the filesystem.

2020-10-21 14:17:17 (11184): Guest Log: 14:17:18 BST +01:00 2020-10-21: cranky: [INFO] Using /cvmfs/cernvm-prod.cern.ch/cvm3

2020-10-21 14:17:17 (11184): Guest Log: 14:17:19 BST +01:00 2020-10-21: cranky: [INFO] Updating config.json.

2020-10-21 14:17:18 (11184): Guest Log: 14:17:19 BST +01:00 2020-10-21: cranky: [INFO] Running Container 'runc'.

2020-10-21 14:19:17 (11184): Guest Log: job: htmld=/shared/html/job

2020-10-21 14:19:20 (11184): Guest Log: job: unpack exitcode=0

2020-10-21 14:19:21 (11184): Guest Log: 14:19:23 BST +01:00 2020-10-21: cranky: [INFO] ===> [runRivet] Wed Oct 21 13:19:22 UTC 2020 [boinc pp jets 8000 150,-,2360 - pythia8 8.244 fischerPP2 100000 54]

2020-10-21 14:20:10 (11184): Stopping VM.
2020-10-24 13:02:53 (51776): Detected: vboxwrapper 26197
2020-10-24 13:02:53 (51776): Detected: BOINC client v7.7
2020-10-24 13:02:54 (51776): Detected: VirtualBox VboxManage Interface (Version: 6.0.14)
2020-10-24 13:02:54 (51776): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2020-10-24 13:02:55 (51776): Starting VM using VBoxManage interface. (boinc_57d9607daee3f2eb, slot#18)
2020-10-24 13:04:01 (51776): Successfully started VM. (PID = '52340')
2020-10-24 13:04:01 (51776): Reporting VM Process ID to BOINC.
2020-10-24 13:04:01 (51776): VM state change detected. (old = 'PoweredOff', new = 'Running')
2020-10-24 13:04:01 (51776): Detected: Web Application Enabled (http://localhost:52785)
2020-10-24 13:04:01 (51776): Status Report: Job Duration: '864000.000000'
2020-10-24 13:04:01 (51776): Status Report: Elapsed Time: '6763.796215'
2020-10-24 13:04:01 (51776): Status Report: CPU Time: '4784.421875'
2020-10-24 13:04:01 (51776): Preference change detected
2020-10-24 13:04:01 (51776): Setting CPU throttle for VM. (75%)
2020-10-24 13:04:02 (51776): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2020-10-24 13:04:02 (51776): Guest Log: 00:05:50.098586 timesync vgsvcTimeSyncWorker: Radical host time change: 254 634 826 000 000ns (HostNow=1 603 541 041 943 000 000 ns HostLast=1 603 286 407 117 000 000 ns)

2020-10-24 13:04:12 (51776): Guest Log: 00:06:00.099063 timesync vgsvcTimeSyncWorker: Radical guest time change: 254 632 461 450 000ns (GuestNow=1 603 541 051 943 536 000 ns GuestLast=1 603 286 419 482 086 000 ns fSetTimeLastLoop=true )

2020-10-24 13:06:31 (51776): Stopping VM.
2020-10-24 13:08:10 (53268): Detected: vboxwrapper 26197
2020-10-24 13:08:10 (53268): Detected: BOINC client v7.7
2020-10-24 13:08:11 (53268): Detected: VirtualBox VboxManage Interface (Version: 6.0.14)
2020-10-24 13:08:12 (53268): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2020-10-24 13:08:13 (53268): Starting VM using VBoxManage interface. (boinc_57d9607daee3f2eb, slot#18)
2020-10-24 13:08:24 (53268): Successfully started VM. (PID = '53408')
2020-10-24 13:08:24 (53268): Reporting VM Process ID to BOINC.
2020-10-24 13:08:24 (53268): VM state change detected. (old = 'PoweredOff', new = 'Running')
2020-10-24 13:08:24 (53268): Detected: Web Application Enabled (http://localhost:52785)
2020-10-24 13:08:24 (53268): Status Report: Job Duration: '864000.000000'
2020-10-24 13:08:24 (53268): Status Report: Elapsed Time: '6914.090959'
2020-10-24 13:08:24 (53268): Status Report: CPU Time: '4799.406250'
2020-10-24 13:08:24 (53268): Preference change detected
2020-10-24 13:08:24 (53268): Setting CPU throttle for VM. (75%)
2020-10-24 13:08:25 (53268): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2020-10-24 13:08:55 (53268): Stopping VM.
2020-10-25 13:47:11 (6592): Detected: vboxwrapper 26197
2020-10-25 13:47:11 (6592): Detected: BOINC client v7.7
2020-10-25 13:47:12 (6592): Detected: VirtualBox VboxManage Interface (Version: 6.0.14)
2020-10-25 13:47:12 (6592): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2020-10-25 13:47:12 (6592): Starting VM using VBoxManage interface. (boinc_57d9607daee3f2eb, slot#18)
2020-10-25 13:47:22 (6592): Successfully started VM. (PID = '5640')
2020-10-25 13:47:22 (6592): Reporting VM Process ID to BOINC.
2020-10-25 13:47:22 (6592): Guest Log: 00:09:04.838901 timesync vgsvcTimeSyncWorker: Radical host time change: 92 302 458 000 000ns (HostNow=1 603 633 635 655 000 000 ns HostLast=1 603 541 333 197 000 000 ns)

2020-10-25 13:47:22 (6592): VM state change detected. (old = 'PoweredOff', new = 'Running')
2020-10-25 13:47:22 (6592): Detected: Web Application Enabled (http://localhost:52785)
2020-10-25 13:47:22 (6592): Status Report: Job Duration: '864000.000000'
2020-10-25 13:47:22 (6592): Status Report: Elapsed Time: '6945.325162'
2020-10-25 13:47:22 (6592): Status Report: CPU Time: '4804.484375'
2020-10-25 13:47:22 (6592): Preference change detected
2020-10-25 13:47:22 (6592): Setting CPU throttle for VM. (75%)
2020-10-25 13:47:23 (6592): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2020-10-25 13:47:32 (6592): Guest Log: 00:09:14.839475 timesync vgsvcTimeSyncWorker: Radical guest time change: 92 307 134 737 000ns (GuestNow=1 603 633 645 655 626 000 ns GuestLast=1 603 541 338 520 889 000 ns fSetTimeLastLoop=true )

2020-10-25 14:48:26 (6592): Stopping VM.
2020-10-25 16:48:27 (776): Detected: vboxwrapper 26197
2020-10-25 16:48:27 (776): Detected: BOINC client v7.7
2020-10-25 16:48:28 (776): Detected: VirtualBox VboxManage Interface (Version: 6.0.14)
2020-10-25 16:48:28 (776): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2020-10-25 16:48:28 (776): Starting VM using VBoxManage interface. (boinc_57d9607daee3f2eb, slot#18)
2020-10-25 16:49:05 (776): Successfully started VM. (PID = '12188')
2020-10-25 16:49:05 (776): Reporting VM Process ID to BOINC.
2020-10-25 16:49:05 (776): VM state change detected. (old = 'PoweredOff', new = 'Running')
2020-10-25 16:49:05 (776): Detected: Web Application Enabled (http://localhost:52785)
2020-10-25 16:49:05 (776): Status Report: Job Duration: '864000.000000'
2020-10-25 16:49:05 (776): Status Report: Elapsed Time: '10605.957196'
2020-10-25 16:49:05 (776): Status Report: CPU Time: '7472.718750'
2020-10-25 16:49:05 (776): Preference change detected
2020-10-25 16:49:05 (776): Setting CPU throttle for VM. (75%)
2020-10-25 16:49:05 (776): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2020-10-25 16:49:12 (776): Guest Log: 01:10:19.254112 timesync vgsvcTimeSyncWorker: Radical host time change: 7 247 145 000 000ns (HostNow=1 603 644 551 967 000 000 ns HostLast=1 603 637 304 822 000 000 ns)

2020-10-25 16:49:22 (776): Guest Log: 01:10:29.257582 timesync vgsvcTimeSyncWorker: Radical guest time change: 7 252 147 504 000ns (GuestNow=1 603 644 562 094 118 000 ns GuestLast=1 603 637 309 946 614 000 ns fSetTimeLastLoop=true )

2020-10-25 17:59:23 (776): Stopping VM.
2020-10-25 18:03:32 (10404): Detected: vboxwrapper 26197
2020-10-25 18:03:32 (10404): Detected: BOINC client v7.7
2020-10-25 18:03:32 (10404): Detected: VirtualBox VboxManage Interface (Version: 6.0.14)
2020-10-25 18:03:32 (10404): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2020-10-25 18:03:33 (10404): Starting VM using VBoxManage interface. (boinc_57d9607daee3f2eb, slot#18)
2020-10-25 18:03:43 (10404): Successfully started VM. (PID = '11980')
2020-10-25 18:03:43 (10404): Reporting VM Process ID to BOINC.
2020-10-25 18:03:43 (10404): VM state change detected. (old = 'PoweredOff', new = 'Running')
2020-10-25 18:03:43 (10404): Detected: Web Application Enabled (http://localhost:52785)
2020-10-25 18:03:43 (10404): Status Report: Job Duration: '864000.000000'
2020-10-25 18:03:43 (10404): Status Report: Elapsed Time: '14820.482096'
2020-10-25 18:03:43 (10404): Status Report: CPU Time: '10640.750000'
2020-10-25 18:03:43 (10404): Preference change detected
2020-10-25 18:03:43 (10404): Setting CPU throttle for VM. (75%)
2020-10-25 18:03:44 (10404): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2020-10-25 18:22:09 (10404): Stopping VM.
2020-10-25 18:22:56 (10404): Error in stop VM for VM: -182
Command:
VBoxManage -q controlvm "boinc_57d9607daee3f2eb" savestate
Output:
0%...10%...20%...30%...40%...
2020-10-25 18:22:56 (10404): VM did not stop when requested.
2020-10-25 18:22:56 (10404): VM was successfully terminated.
2020-10-28 05:49:08 (12940): Detected: vboxwrapper 26197
2020-10-28 05:49:08 (12940): Detected: BOINC client v7.7
2020-10-28 05:49:09 (12940): Detected: VirtualBox VboxManage Interface (Version: 6.0.14)
2020-10-28 05:49:09 (12940): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2020-10-28 05:49:09 (12940): Starting VM using VBoxManage interface. (boinc_57d9607daee3f2eb, slot#18)
2020-10-28 05:49:15 (12940): Successfully started VM. (PID = '10560')
2020-10-28 05:49:15 (12940): Reporting VM Process ID to BOINC.
2020-10-28 05:49:15 (12940): Guest Log: BIOS: VirtualBox 6.0.14

2020-10-28 05:49:15 (12940): Guest Log: CPUID EDX: 0x178bfbff

2020-10-28 05:49:15 (12940): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63

2020-10-28 05:49:15 (12940): VM state change detected. (old = 'PoweredOff', new = 'Running')
2020-10-28 05:49:15 (12940): Detected: Web Application Enabled (http://localhost:52785)
2020-10-28 05:49:15 (12940): Status Report: Job Duration: '864000.000000'
2020-10-28 05:49:15 (12940): Status Report: Elapsed Time: '15924.482096'
2020-10-28 05:49:15 (12940): Status Report: CPU Time: '11478.656250'
2020-10-28 05:49:15 (12940): Preference change detected
2020-10-28 05:49:15 (12940): Setting CPU throttle for VM. (75%)
2020-10-28 05:49:16 (12940): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2020-10-28 05:49:17 (12940): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032

2020-10-28 05:49:17 (12940): Guest Log: BIOS: Booting from Hard Disk...

2020-10-28 05:49:35 (12940): Guest Log: BIOS: KBD: unsupported int 16h function 03

2020-10-28 05:49:35 (12940): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 

2020-10-28 05:54:48 (12940): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds

2020-10-28 05:54:48 (12940): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)

2020-10-28 05:54:48 (12940): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log

2020-10-28 05:54:48 (12940): Guest Log: 00:00:00.000250 main     Log opened 2020-10-28T05:55:11.392110000Z

2020-10-28 05:54:48 (12940): Guest Log: 00:00:00.000432 main     OS Product: Linux

2020-10-28 05:54:48 (12940): Guest Log: 00:00:00.000491 main     OS Release: 4.14.76-13.cernvm.x86_64

2020-10-28 05:54:48 (12940): Guest Log: 00:00:00.000546 main     OS Version: #1 SMP Tue Oct 16 18:26:15 CEST 2018

2020-10-28 05:54:48 (12940): Guest Log: 00:00:00.000623 main     Executable: /usr/sbin/VBoxService

2020-10-28 05:54:48 (12940): Guest Log: 00:00:00.000625 main     Process ID: 3229

2020-10-28 05:54:48 (12940): Guest Log: 00:00:00.000627 main     Package type: LINUX_64BITS_GENERIC

2020-10-28 05:54:48 (12940): Guest Log: 00:00:00.005116 main     5.2.6 r120293 started. Verbose level = 0

2020-10-28 05:57:58 (12940): Guest Log: 05:58:21 GMT +00:00 2020-10-28: cranky: [INFO] Detected Theory App

2020-10-28 05:57:58 (12940): Guest Log: 05:58:21 GMT +00:00 2020-10-28: cranky: [INFO] Checking CVMFS.

2020-10-28 05:58:00 (12940): Guest Log: Probing /cvmfs/sft.cern.ch... OK

2020-10-28 05:58:02 (12940): 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

2020-10-28 05:58:02 (12940): Guest Log: 2.5.2.0 4178 2 26276 19177 2 1 1640053 4096001 0 65024 0 0 n/a 5 1 http://s1ral-cvmfs.openhtc.io/cvmfs/sft.cern.ch DIRECT 1

2020-10-28 05:58:04 (12940): Guest Log: Probing /cvmfs/grid.cern.ch... OK

2020-10-28 05:58:05 (12940): 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

2020-10-28 05:58:05 (12940): Guest Log: 2.5.2.0 4222 2 27604 13559 2 2 1640053 4096001 0 65024 0 2 0 4273 459 http://s1ihep-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1

2020-10-28 05:58:08 (12940): Guest Log: Probing /cvmfs/cernvm-prod.cern.ch... OK

2020-10-28 05:58:09 (12940): 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

2020-10-28 05:58:09 (12940): Guest Log: 2.5.2.0 4153 2 25164 259 2 1 1640053 4096001 0 65024 0 0 n/a 0 0 http://s1ihep-cvmfs.openhtc.io/cvmfs/cernvm-prod.cern.ch DIRECT 1

2020-10-28 05:58:12 (12940): Guest Log: Probing /cvmfs/alice.cern.ch... OK

2020-10-28 05:58:13 (12940): 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

2020-10-28 05:58:13 (12940): Guest Log: 2.5.2.0 4199 2 30388 7831 2 1 1640053 4096001 0 65024 0 0 n/a 4517 1060 http://s1cern-cvmfs.openhtc.io/cvmfs/alice.cern.ch DIRECT 1

2020-10-28 05:58:13 (12940): Guest Log: 05:58:37 GMT +00:00 2020-10-28: cranky: [INFO] Checking runc.

2020-10-28 05:58:34 (12940): Guest Log: 05:58:58 GMT +00:00 2020-10-28: cranky: [INFO] Creating the filesystem.

2020-10-28 05:58:36 (12940): Guest Log: 05:59:00 GMT +00:00 2020-10-28: cranky: [INFO] Using /cvmfs/cernvm-prod.cern.ch/cvm3

2020-10-28 05:58:37 (12940): Guest Log: 05:59:01 GMT +00:00 2020-10-28: cranky: [INFO] Updating config.json.

2020-10-28 05:58:37 (12940): Guest Log: 05:59:01 GMT +00:00 2020-10-28: cranky: [INFO] Running Container 'runc'.

2020-10-28 05:59:19 (12940): Guest Log: job: htmld=/shared/html/job

2020-10-28 05:59:21 (12940): Guest Log: job: unpack exitcode=0

2020-10-28 05:59:23 (12940): Guest Log: 05:59:47 GMT +00:00 2020-10-28: cranky: [INFO] ===> [runRivet] Wed Oct 28 05:59:47 UTC 2020 [boinc pp jets 8000 150,-,2360 - pythia8 8.244 fischerPP2 100000 54]

2020-10-28 06:05:09 (12940): VM state change detected. (old = 'Running', new = 'Paused')
2020-10-28 06:05:14 (12940): VM state change detected. (old = 'Paused', new = 'Running')
2020-10-28 06:27:33 (12940): VM state change detected. (old = 'Running', new = 'Paused')
2020-10-28 06:27:42 (12940): VM state change detected. (old = 'Paused', new = 'Running')
2020-10-28 06:45:43 (12940): VM state change detected. (old = 'Running', new = 'Paused')
2020-10-28 06:45:52 (12940): VM state change detected. (old = 'Paused', new = 'Running')
2020-10-28 07:29:56 (12940): Status Report: Job Duration: '864000.000000'
2020-10-28 07:29:56 (12940): Status Report: Elapsed Time: '21924.804049'
2020-10-28 07:29:56 (12940): Status Report: CPU Time: '14572.390625'
2020-10-28 09:10:01 (12940): Status Report: Job Duration: '864000.000000'
2020-10-28 09:10:01 (12940): Status Report: Elapsed Time: '27924.804049'
2020-10-28 09:10:01 (12940): Status Report: CPU Time: '19079.468750'
2020-10-28 10:50:06 (12940): Status Report: Job Duration: '864000.000000'
2020-10-28 10:50:06 (12940): Status Report: Elapsed Time: '33924.804049'
2020-10-28 10:50:06 (12940): Status Report: CPU Time: '23586.546875'
2020-10-28 12:30:12 (12940): Status Report: Job Duration: '864000.000000'
2020-10-28 12:30:12 (12940): Status Report: Elapsed Time: '39924.804049'
2020-10-28 12:30:12 (12940): Status Report: CPU Time: '28093.890625'
2020-10-28 14:10:20 (12940): Status Report: Job Duration: '864000.000000'
2020-10-28 14:10:20 (12940): Status Report: Elapsed Time: '45924.804049'
2020-10-28 14:10:20 (12940): Status Report: CPU Time: '32601.265625'
2020-10-28 15:50:25 (12940): Status Report: Job Duration: '864000.000000'
2020-10-28 15:50:25 (12940): Status Report: Elapsed Time: '51924.804049'
2020-10-28 15:50:25 (12940): Status Report: CPU Time: '37109.718750'
2020-10-28 17:30:31 (12940): Status Report: Job Duration: '864000.000000'
2020-10-28 17:30:31 (12940): Status Report: Elapsed Time: '57924.804049'
2020-10-28 17:30:31 (12940): Status Report: CPU Time: '41617.328125'
2020-10-28 18:39:41 (12940): Stopping VM.
2020-10-30 06:05:56 (14240): Detected: vboxwrapper 26197
2020-10-30 06:05:56 (14240): Detected: BOINC client v7.7
2020-10-30 06:05:59 (14240): Detected: VirtualBox VboxManage Interface (Version: 6.0.14)
2020-10-30 06:05:59 (14240): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2020-10-30 06:05:59 (14240): Starting VM using VBoxManage interface. (boinc_57d9607daee3f2eb, slot#18)
2020-10-30 06:07:40 (14240): Successfully started VM. (PID = '12428')
2020-10-30 06:07:40 (14240): Reporting VM Process ID to BOINC.
2020-10-30 06:07:40 (14240): VM state change detected. (old = 'PoweredOff', new = 'Running')
2020-10-30 06:07:40 (14240): Detected: Web Application Enabled (http://localhost:52785)
2020-10-30 06:07:40 (14240): Status Report: Job Duration: '864000.000000'
2020-10-30 06:07:40 (14240): Status Report: Elapsed Time: '62070.804049'
2020-10-30 06:07:40 (14240): Status Report: CPU Time: '44726.671875'
2020-10-30 06:07:40 (14240): Preference change detected
2020-10-30 06:07:40 (14240): Setting CPU throttle for VM. (75%)
2020-10-30 06:07:40 (14240): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2020-10-30 06:07:48 (14240): Guest Log: 12:44:38.576628 timesync vgsvcTimeSyncWorker: Radical host time change: 127 687 692 000 000ns (HostNow=1 604 038 066 215 000 000 ns HostLast=1 603 910 378 523 000 000 ns)

2020-10-30 06:07:58 (14240): Guest Log: 12:44:48.980950 timesync vgsvcTimeSyncWorker: Radical guest time change: 127 689 021 672 000ns (GuestNow=1 604 038 077 543 566 000 ns GuestLast=1 603 910 388 521 894 000 ns fSetTimeLastLoop=true )

2020-10-30 06:22:30 (14240): VM state change detected. (old = 'Running', new = 'Paused')
2020-10-30 06:22:39 (14240): VM state change detected. (old = 'Paused', new = 'Running')
2020-10-30 07:39:00 (14240): Stopping VM.
2020-10-30 07:58:35 (3304): Detected: vboxwrapper 26197
2020-10-30 07:58:35 (3304): Detected: BOINC client v7.7
2020-10-30 07:58:36 (3304): Detected: VirtualBox VboxManage Interface (Version: 6.0.14)
2020-10-30 07:58:36 (3304): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2020-10-30 07:58:36 (3304): Starting VM using VBoxManage interface. (boinc_57d9607daee3f2eb, slot#18)
2020-10-30 07:58:48 (3304): Successfully started VM. (PID = '10072')
2020-10-30 07:58:48 (3304): Reporting VM Process ID to BOINC.
2020-10-30 07:58:48 (3304): VM state change detected. (old = 'PoweredOff', new = 'Running')
2020-10-30 07:58:48 (3304): Detected: Web Application Enabled (http://localhost:52785)
2020-10-30 07:58:48 (3304): Status Report: Job Duration: '864000.000000'
2020-10-30 07:58:48 (3304): Status Report: Elapsed Time: '67534.823021'
2020-10-30 07:58:48 (3304): Status Report: CPU Time: '48830.500000'
2020-10-30 07:58:48 (3304): Preference change detected
2020-10-30 07:58:48 (3304): Setting CPU throttle for VM. (75%)
2020-10-30 07:58:49 (3304): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2020-10-30 09:20:46 (3304): Stopping VM.
2020-10-30 09:39:02 (5884): Detected: vboxwrapper 26197
2020-10-30 09:39:02 (5884): Detected: BOINC client v7.7
2020-10-30 09:39:02 (5884): Detected: VirtualBox VboxManage Interface (Version: 6.0.14)
2020-10-30 09:39:03 (5884): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2020-10-30 09:39:03 (5884): Starting VM using VBoxManage interface. (boinc_57d9607daee3f2eb, slot#18)
2020-10-30 09:39:10 (5884): Successfully started VM. (PID = '8888')
2020-10-30 09:39:10 (5884): Reporting VM Process ID to BOINC.
2020-10-30 09:39:10 (5884): VM state change detected. (old = 'PoweredOff', new = 'Running')
2020-10-30 09:39:10 (5884): Detected: Web Application Enabled (http://localhost:52785)
2020-10-30 09:39:10 (5884): Status Report: Job Duration: '864000.000000'
2020-10-30 09:39:10 (5884): Status Report: Elapsed Time: '72447.823021'
2020-10-30 09:39:10 (5884): Status Report: CPU Time: '52529.734375'
2020-10-30 09:39:10 (5884): Preference change detected
2020-10-30 09:39:10 (5884): Setting CPU throttle for VM. (75%)
2020-10-30 09:39:10 (5884): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2020-10-30 11:19:15 (5884): Status Report: Job Duration: '864000.000000'
2020-10-30 11:19:15 (5884): Status Report: Elapsed Time: '78447.823021'
2020-10-30 11:19:15 (5884): Status Report: CPU Time: '57042.687500'
2020-10-30 12:59:21 (5884): Status Report: Job Duration: '864000.000000'
2020-10-30 12:59:21 (5884): Status Report: Elapsed Time: '84447.823021'
2020-10-30 12:59:21 (5884): Status Report: CPU Time: '61550.296875'
2020-10-30 14:39:26 (5884): Status Report: Job Duration: '864000.000000'
2020-10-30 14:39:26 (5884): Status Report: Elapsed Time: '90447.823021'
2020-10-30 14:39:26 (5884): Status Report: CPU Time: '66059.093750'
2020-10-30 15:10:52 (5884): Guest Log: job: run exitcode=0

2020-10-30 15:10:52 (5884): Guest Log: job: diskusage=2060

2020-10-30 15:10:52 (5884): Guest Log: job: logsize=68 k

2020-10-30 15:10:52 (5884): Guest Log: job: times=

2020-10-30 15:10:52 (5884): Guest Log: 0m0.089s 0m0.137s

2020-10-30 15:10:52 (5884): Guest Log: 1213m6.885s 9m16.084s

2020-10-30 15:10:53 (5884): Guest Log: job: cpuusage=73343

2020-10-30 15:10:53 (5884): Guest Log: 15:10:53 GMT +00:00 2020-10-30: cranky: [INFO] Container 'runc' finished with status code 0.

2020-10-30 15:10:53 (5884): Guest Log: 15:10:53 GMT +00:00 2020-10-30: cranky: [INFO] Preparing output.

2020-10-30 15:10:59 (5884): Guest Log: [INFO] Job Finished

2020-10-30 15:10:59 (5884): Guest Log: [INFO] Shutting Down.

2020-10-30 15:10:59 (5884): VM Completion File Detected.
2020-10-30 15:10:59 (5884): VM Completion Message: Job Finished
.
2020-10-30 15:10:59 (5884): Powering off VM.
2020-10-30 15:16:00 (5884): VM did not power off when requested.
2020-10-30 15:16:00 (5884): VM was successfully terminated.
2020-10-30 15:16:00 (5884): Deregistering VM. (boinc_57d9607daee3f2eb, slot#18)
2020-10-30 15:16:00 (5884): Removing network bandwidth throttle group from VM.
2020-10-30 15:16:00 (5884): Removing VM from VirtualBox.
15:16:05 (5884): called boinc_finish(0)

</stderr_txt>
]]>