Task 2979153

Name	CMS_908262_1624006353.901766_0
Workunit	2084026
Created	18 Jun 2021, 8:52:39 UTC
Sent	18 Jun 2021, 20:22:33 UTC
Report deadline	25 Jun 2021, 20:22:33 UTC
Received	22 Jun 2021, 19:53:36 UTC
Server state	Over
Outcome	Success
Client state	Done
Exit status	0 (0x00000000)
Computer ID	4274
Run time	8 hours 49 min 56 sec
CPU time	8 hours 16 min 57 sec
Validate state	Valid
Credit	205.05
Device peak FLOPS	2.81 GFLOPS
Application version	CMS Simulation v50.00 (vbox64_mt_mcore_cms) windows_x86_64
Peak working set size	78.36 MB
Peak swap size	87.82 MB
Peak disk usage	4.44 GB
Stderr output

<core_client_version>7.16.11</core_client_version>
<![CDATA[
<stderr_txt>
2021-06-18 17:02:42 (7628): Detected: vboxwrapper 26197
2021-06-18 17:02:42 (7628): Detected: BOINC client v7.7
2021-06-18 17:02:42 (7628): Detected: VirtualBox VboxManage Interface (Version: 5.2.44)
2021-06-18 17:02:43 (7628): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2021-06-18 17:02:43 (7628): Successfully copied 'init_data.xml' to the shared directory.
2021-06-18 17:02:44 (7628): Create VM. (boinc_1896b2bdad7b3252, slot#11)
2021-06-18 17:02:44 (7628): Setting Memory Size for VM. (1896MB)
2021-06-18 17:02:45 (7628): Setting CPU Count for VM. (1)
2021-06-18 17:02:45 (7628): Setting Chipset Options for VM.
2021-06-18 17:02:45 (7628): Setting Boot Options for VM.
2021-06-18 17:02:46 (7628): Setting Network Configuration for NAT.
2021-06-18 17:02:46 (7628): Enabling VM Network Access.
2021-06-18 17:02:46 (7628): Disabling USB Support for VM.
2021-06-18 17:02:46 (7628): Disabling COM Port Support for VM.
2021-06-18 17:02:47 (7628): Disabling LPT Port Support for VM.
2021-06-18 17:02:47 (7628): Disabling Audio Support for VM.
2021-06-18 17:02:47 (7628): Disabling Clipboard Support for VM.
2021-06-18 17:02:47 (7628): Disabling Drag and Drop Support for VM.
2021-06-18 17:02:48 (7628): Adding storage controller(s) to VM.
2021-06-18 17:02:48 (7628): Adding virtual disk drive to VM. (vm_image.vdi)
2021-06-18 17:02:48 (7628): Adding VirtualBox Guest Additions to VM.
2021-06-18 17:02:49 (7628): Adding network bandwidth throttle group to VM. (Defaulting to 1024GB)
2021-06-18 17:02:49 (7628): forwarding host port 49207 to guest port 80
2021-06-18 17:02:49 (7628): Enabling remote desktop for VM.
2021-06-18 17:02:49 (7628): Required extension pack not installed, remote desktop not enabled.
2021-06-18 17:02:49 (7628): Enabling shared directory for VM.
2021-06-18 17:02:50 (7628): Starting VM using VBoxManage interface. (boinc_1896b2bdad7b3252, slot#11)
2021-06-18 17:02:56 (7628): Successfully started VM. (PID = '7700')
2021-06-18 17:02:56 (7628): Reporting VM Process ID to BOINC.
2021-06-18 17:02:56 (7628): Guest Log: BIOS: VirtualBox 5.2.44

2021-06-18 17:02:56 (7628): Guest Log: CPUID EDX: 0x078bfbff

2021-06-18 17:02:56 (7628): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63

2021-06-18 17:02:56 (7628): VM state change detected. (old = 'PoweredOff', new = 'Running')
2021-06-18 17:02:56 (7628): Detected: Web Application Enabled (http://localhost:49207)
2021-06-18 17:02:56 (7628): Preference change detected
2021-06-18 17:02:56 (7628): Setting CPU throttle for VM. (100%)
2021-06-18 17:02:56 (7628): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2021-06-18 17:02:58 (7628): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032

2021-06-18 17:02:58 (7628): Guest Log: BIOS: Booting from Hard Disk...

2021-06-18 17:03:01 (7628): Guest Log: BIOS: KBD: unsupported int 16h function 03

2021-06-18 17:03:01 (7628): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 

2021-06-18 17:03:21 (7628): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds

2021-06-18 17:03:21 (7628): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)

2021-06-18 17:03:58 (7628): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log

2021-06-18 17:03:58 (7628): Guest Log: 00:00:00.000552 main     Log opened 2021-06-18T21:03:57.271672000Z

2021-06-18 17:03:58 (7628): Guest Log: 00:00:00.000986 main     OS Product: Linux

2021-06-18 17:03:58 (7628): Guest Log: 00:00:00.001114 main     OS Release: 4.14.157-17.cernvm.x86_64

2021-06-18 17:03:58 (7628): Guest Log: 00:00:00.001155 main     OS Version: #1 SMP Wed Dec 4 17:26:45 CET 2019

2021-06-18 17:03:58 (7628): Guest Log: 00:00:00.001224 main     Executable: /usr/share/vboxguest52/usr/sbin/VBoxService

2021-06-18 17:03:58 (7628): Guest Log: 00:00:00.001226 main     Process ID: 2971

2021-06-18 17:03:58 (7628): Guest Log: 00:00:00.001227 main     Package type: LINUX_64BITS_GENERIC

2021-06-18 17:03:58 (7628): Guest Log: 00:00:00.003390 main     5.2.6 r120293 started. Verbose level = 0

2021-06-18 17:04:33 (7628): Guest Log: [INFO] Mounting the shared directory

2021-06-18 17:04:33 (7628): Guest Log: [INFO] Shared directory mounted, enabling vboxmonitor

2021-06-18 17:04:33 (7628): Guest Log: [DEBUG] Testing network connection to cern.ch on port 80

2021-06-18 17:04:34 (7628): Guest Log: [DEBUG] Connection to cern.ch 80 port [tcp/http] succeeded!

2021-06-18 17:04:34 (7628): Guest Log: [DEBUG] 0

2021-06-18 17:04:34 (7628): Guest Log: [DEBUG] Testing VCCS connection to vccs.cern.ch on port 443

2021-06-18 17:04:35 (7628): Guest Log: [DEBUG] Connection to vccs.cern.ch 443 port [tcp/https] succeeded!

2021-06-18 17:04:35 (7628): Guest Log: [DEBUG] 0

2021-06-18 17:04:35 (7628): Guest Log: [DEBUG] Testing connection to Condor server on port 9618

2021-06-18 17:04:35 (7628): Guest Log: [DEBUG] Connection to vocms0840.cern.ch 9618 port [tcp/condor] succeeded!

2021-06-18 17:04:36 (7628): Guest Log: [DEBUG] 0

2021-06-18 17:04:36 (7628): Guest Log: [DEBUG] Testing connection to WMAgent server on port 4080

2021-06-18 17:04:36 (7628): Guest Log: [DEBUG] Connection to vocms0267.cern.ch 4080 port [tcp/lorica-in] succeeded!

2021-06-18 17:04:36 (7628): Guest Log: [DEBUG] 0

2021-06-18 17:04:36 (7628): Guest Log: [DEBUG] Testing connection to Frontier server on port 8080

2021-06-18 17:04:37 (7628): Guest Log: [DEBUG] Connection to cms-frontier.openhtc.io 8080 port [tcp/webcache] succeeded!

2021-06-18 17:04:37 (7628): Guest Log: [DEBUG] 0

2021-06-18 17:04:38 (7628): Guest Log: [INFO] CVMFS and Frontier will use DIRECT instead of an HTTP proxy.

2021-06-18 17:04:38 (7628): Guest Log: [INFO] A local HTTP proxy could help making the network usage

2021-06-18 17:04:39 (7628): Guest Log: [INFO] of this application more efficient. It would also help to

2021-06-18 17:04:39 (7628): Guest Log: [INFO] offload the project servers.

2021-06-18 17:04:39 (7628): Guest Log: [INFO] Details can be found in the project forum.

2021-06-18 17:04:59 (7628): Guest Log: [INFO] Reloading the CVMFS configuration (can take a while) ...

2021-06-18 17:06:21 (7628): Guest Log: [INFO] Probing CVMFS ...

2021-06-18 17:06:35 (7628): 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-06-18 17:06:35 (7628): Guest Log: 2.4.4.0 3753 2 25860 15481 3 1 1243072 4096000 2 65024 0 2 100 0 0 http://s1bnl-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1

2021-06-18 17:06:57 (7628): Guest Log: [INFO] Reading volunteer information

2021-06-18 17:06:58 (7628): Guest Log: [INFO] Volunteer: Contact (21)

2021-06-18 17:06:58 (7628): Guest Log: [INFO] VMID: 49b2fac1-df25-48d2-a4ee-4612ca6a31f8

2021-06-18 17:06:59 (7628): Guest Log: [INFO] Requesting an X509 credential from LHC@home

2021-06-18 17:07:00 (7628): Guest Log: [INFO] Requesting an X509 credential from vLHC@home-dev

2021-06-18 17:07:03 (7628): Guest Log: [INFO] Running the fast benchmark.

2021-06-18 17:08:06 (7628): Guest Log: [INFO] Machine performance 8.29 HEPSPEC06

2021-06-18 17:08:06 (7628): Guest Log: [INFO] CMS application starting. Check log files.

2021-06-18 17:08:09 (7628): Guest Log: [DEBUG] HTCondor ping

2021-06-18 17:08:12 (7628): Guest Log: [DEBUG] 0

2021-06-18 18:02:52 (7628): Stopping VM.
2021-06-18 18:03:41 (7628): Error in stop VM for VM: -182
Command:
VBoxManage -q controlvm "boinc_1896b2bdad7b3252" savestate
Output:
0%...10%...20%...30%...40%...50%...60%...70%...80%...90%...
2021-06-18 18:03:42 (7628): VM did not stop when requested.
2021-06-18 18:03:42 (7628): VM was successfully terminated.
2021-06-18 18:23:15 (6316): Detected: vboxwrapper 26197
2021-06-18 18:23:15 (6316): Detected: BOINC client v7.7
2021-06-18 18:23:16 (6316): Detected: VirtualBox VboxManage Interface (Version: 5.2.44)
2021-06-18 18:23:16 (6316): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2021-06-18 18:23:16 (6316): Starting VM using VBoxManage interface. (boinc_1896b2bdad7b3252, slot#11)
2021-06-18 18:23:22 (6316): Successfully started VM. (PID = '4224')
2021-06-18 18:23:22 (6316): Reporting VM Process ID to BOINC.
2021-06-18 18:23:22 (6316): Guest Log: BIOS: VirtualBox 5.2.44

2021-06-18 18:23:22 (6316): Guest Log: CPUID EDX: 0x078bfbff

2021-06-18 18:23:22 (6316): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63

2021-06-18 18:23:22 (6316): VM state change detected. (old = 'PoweredOff', new = 'Running')
2021-06-18 18:23:22 (6316): Detected: Web Application Enabled (http://localhost:49207)
2021-06-18 18:23:22 (6316): Preference change detected
2021-06-18 18:23:22 (6316): Setting CPU throttle for VM. (100%)
2021-06-18 18:23:22 (6316): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2021-06-18 18:23:24 (6316): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032

2021-06-18 18:23:24 (6316): Guest Log: BIOS: Booting from Hard Disk...

2021-06-18 18:23:29 (6316): Guest Log: BIOS: KBD: unsupported int 16h function 03

2021-06-18 18:23:29 (6316): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 

2021-06-18 18:23:51 (6316): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds

2021-06-18 18:23:51 (6316): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)

2021-06-18 18:24:32 (6316): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log

2021-06-18 18:24:32 (6316): Guest Log: 00:00:00.000520 main     Log opened 2021-06-18T22:24:31.333784000Z

2021-06-18 18:24:32 (6316): Guest Log: 00:00:00.000926 main     OS Product: Linux

2021-06-18 18:24:32 (6316): Guest Log: 00:00:00.001036 main     OS Release: 4.14.157-17.cernvm.x86_64

2021-06-18 18:24:32 (6316): Guest Log: 00:00:00.001314 main     OS Version: #1 SMP Wed Dec 4 17:26:45 CET 2019

2021-06-18 18:24:32 (6316): Guest Log: 00:00:00.001377 main     Executable: /usr/share/vboxguest52/usr/sbin/VBoxService

2021-06-18 18:24:32 (6316): Guest Log: 00:00:00.001378 main     Process ID: 2907

2021-06-18 18:24:32 (6316): Guest Log: 00:00:00.001379 main     Package type: LINUX_64BITS_GENERIC

2021-06-18 18:24:32 (6316): Guest Log: 00:00:00.003276 main     5.2.6 r120293 started. Verbose level = 0

2021-06-18 18:25:22 (6316): Guest Log: [INFO] Mounting the shared directory

2021-06-18 18:25:23 (6316): Guest Log: [INFO] Shared directory mounted, enabling vboxmonitor

2021-06-18 18:25:23 (6316): Guest Log: [DEBUG] Testing network connection to cern.ch on port 80

2021-06-18 18:25:23 (6316): Guest Log: [DEBUG] Connection to cern.ch 80 port [tcp/http] succeeded!

2021-06-18 18:25:23 (6316): Guest Log: [DEBUG] 0

2021-06-18 18:25:24 (6316): Guest Log: [DEBUG] Testing VCCS connection to vccs.cern.ch on port 443

2021-06-18 18:25:25 (6316): Guest Log: [DEBUG] Connection to vccs.cern.ch 443 port [tcp/https] succeeded!

2021-06-18 18:25:25 (6316): Guest Log: [DEBUG] 0

2021-06-18 18:25:25 (6316): Guest Log: [DEBUG] Testing connection to Condor server on port 9618

2021-06-18 18:25:25 (6316): Guest Log: [DEBUG] Connection to vocms0840.cern.ch 9618 port [tcp/condor] succeeded!

2021-06-18 18:25:25 (6316): Guest Log: [DEBUG] 0

2021-06-18 18:25:26 (6316): Guest Log: [DEBUG] Testing connection to WMAgent server on port 4080

2021-06-18 18:25:26 (6316): Guest Log: [DEBUG] Connection to vocms0267.cern.ch 4080 port [tcp/lorica-in] succeeded!

2021-06-18 18:25:26 (6316): Guest Log: [DEBUG] 0

2021-06-18 18:25:26 (6316): Guest Log: [DEBUG] Testing connection to Frontier server on port 8080

2021-06-18 18:25:26 (6316): Guest Log: [DEBUG] Connection to cms-frontier.openhtc.io 8080 port [tcp/webcache] succeeded!

2021-06-18 18:25:27 (6316): Guest Log: [DEBUG] 0

2021-06-18 18:25:27 (6316): Guest Log: [INFO] CVMFS and Frontier will use DIRECT instead of an HTTP proxy.

2021-06-18 18:25:27 (6316): Guest Log: [INFO] A local HTTP proxy could help making the network usage

2021-06-18 18:25:27 (6316): Guest Log: [INFO] of this application more efficient. It would also help to

2021-06-18 18:25:27 (6316): Guest Log: [INFO] offload the project servers.

2021-06-18 18:25:27 (6316): Guest Log: [INFO] Details can be found in the project forum.

2021-06-18 18:25:44 (6316): Guest Log: [INFO] Reloading the CVMFS configuration (can take a while) ...

2021-06-18 18:26:04 (6316): Guest Log: [INFO] Probing CVMFS ...

2021-06-18 18:26:16 (6316): 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-06-18 18:26:16 (6316): Guest Log: 2.4.4.0 3673 1 25756 15481 3 1 1670989 4096000 2 65024 0 2 100 0 0 http://s1bnl-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1

2021-06-18 18:26:19 (6316): Guest Log: [INFO] Reading volunteer information

2021-06-18 18:26:19 (6316): Guest Log: [INFO] Volunteer: Contact (21)

2021-06-18 18:26:19 (6316): Guest Log: [INFO] VMID: 49b2fac1-df25-48d2-a4ee-4612ca6a31f8

2021-06-18 18:26:20 (6316): Guest Log: [INFO] Requesting an X509 credential from LHC@home

2021-06-18 18:26:22 (6316): Guest Log: [INFO] Requesting an X509 credential from vLHC@home-dev

2021-06-18 18:26:24 (6316): Guest Log: [INFO] Running the fast benchmark.

2021-06-18 18:27:22 (6316): Guest Log: [INFO] Machine performance 8.86 HEPSPEC06

2021-06-18 18:27:22 (6316): Guest Log: [INFO] CMS application starting. Check log files.

2021-06-18 18:27:25 (6316): Guest Log: [DEBUG] HTCondor ping

2021-06-18 18:27:28 (6316): Guest Log: [DEBUG] 0

2021-06-18 19:04:07 (6316): Status Report: Job Duration: '64800.000000'
2021-06-18 19:04:07 (6316): Status Report: Elapsed Time: '6000.615885'
2021-06-18 19:04:07 (6316): Status Report: CPU Time: '4353.921875'
2021-06-18 19:14:24 (6480): Detected: vboxwrapper 26197
2021-06-18 19:14:24 (6480): Detected: BOINC client v7.7
2021-06-18 19:14:26 (6480): Detected: VirtualBox VboxManage Interface (Version: 5.2.44)
2021-06-18 19:14:26 (6480): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2021-06-18 19:14:27 (6480): Starting VM using VBoxManage interface. (boinc_1896b2bdad7b3252, slot#11)
2021-06-18 19:14:36 (6480): Successfully started VM. (PID = '4668')
2021-06-18 19:14:36 (6480): Reporting VM Process ID to BOINC.
2021-06-18 19:14:36 (6480): Guest Log: BIOS: VirtualBox 5.2.44

2021-06-18 19:14:36 (6480): Guest Log: CPUID EDX: 0x078bfbff

2021-06-18 19:14:36 (6480): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63

2021-06-18 19:14:36 (6480): VM state change detected. (old = 'PoweredOff', new = 'Running')
2021-06-18 19:14:36 (6480): Detected: Web Application Enabled (http://localhost:49207)
2021-06-18 19:14:36 (6480): Status Report: Job Duration: '64800.000000'
2021-06-18 19:14:36 (6480): Status Report: Elapsed Time: '6254.615885'
2021-06-18 19:14:36 (6480): Status Report: CPU Time: '4603.812500'
2021-06-18 19:14:36 (6480): Preference change detected
2021-06-18 19:14:36 (6480): Setting CPU throttle for VM. (100%)
2021-06-18 19:14:36 (6480): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2021-06-18 19:14:38 (6480): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032

2021-06-18 19:14:38 (6480): Guest Log: BIOS: Booting from Hard Disk...

2021-06-18 19:14:44 (6480): Guest Log: BIOS: KBD: unsupported int 16h function 03

2021-06-18 19:14:44 (6480): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 

2021-06-18 19:15:14 (6480): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds

2021-06-18 19:15:14 (6480): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)

2021-06-18 19:15:51 (6480): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log

2021-06-18 19:15:51 (6480): Guest Log: 00:00:00.000325 main     Log opened 2021-06-18T23:15:49.761596000Z

2021-06-18 19:15:51 (6480): Guest Log: 00:00:00.000672 main     OS Product: Linux

2021-06-18 19:15:51 (6480): Guest Log: 00:00:00.000828 main     OS Release: 4.14.157-17.cernvm.x86_64

2021-06-18 19:15:51 (6480): Guest Log: 00:00:00.000864 main     OS Version: #1 SMP Wed Dec 4 17:26:45 CET 2019

2021-06-18 19:15:51 (6480): Guest Log: 00:00:00.000895 main     Executable: /usr/share/vboxguest52/usr/sbin/VBoxService

2021-06-18 19:15:51 (6480): Guest Log: 00:00:00.000897 main     Process ID: 2906

2021-06-18 19:15:51 (6480): Guest Log: 00:00:00.000898 main     Package type: LINUX_64BITS_GENERIC

2021-06-18 19:15:51 (6480): Guest Log: 00:00:00.002165 main     5.2.6 r120293 started. Verbose level = 0

2021-06-18 19:17:20 (6480): Guest Log: [INFO] Mounting the shared directory

2021-06-18 19:17:20 (6480): Guest Log: [INFO] Shared directory mounted, enabling vboxmonitor

2021-06-18 19:17:21 (6480): Guest Log: [DEBUG] Testing network connection to cern.ch on port 80

2021-06-18 19:17:22 (6480): Guest Log: [DEBUG] Connection to cern.ch 80 port [tcp/http] succeeded!

2021-06-18 19:17:22 (6480): Guest Log: [DEBUG] 0

2021-06-18 19:17:22 (6480): Guest Log: [DEBUG] Testing VCCS connection to vccs.cern.ch on port 443

2021-06-18 19:17:23 (6480): Guest Log: [DEBUG] Connection to vccs.cern.ch 443 port [tcp/https] succeeded!

2021-06-18 19:17:23 (6480): Guest Log: [DEBUG] 0

2021-06-18 19:17:23 (6480): Guest Log: [DEBUG] Testing connection to Condor server on port 9618

2021-06-18 19:17:24 (6480): Guest Log: [DEBUG] Connection to vocms0840.cern.ch 9618 port [tcp/condor] succeeded!

2021-06-18 19:17:24 (6480): Guest Log: [DEBUG] 0

2021-06-18 19:17:24 (6480): Guest Log: [DEBUG] Testing connection to WMAgent server on port 4080

2021-06-18 19:17:25 (6480): Guest Log: [DEBUG] Connection to vocms0267.cern.ch 4080 port [tcp/lorica-in] succeeded!

2021-06-18 19:17:25 (6480): Guest Log: [DEBUG] 0

2021-06-18 19:17:25 (6480): Guest Log: [DEBUG] Testing connection to Frontier server on port 8080

2021-06-18 19:17:25 (6480): Guest Log: [DEBUG] Connection to cms-frontier.openhtc.io 8080 port [tcp/webcache] succeeded!

2021-06-18 19:17:26 (6480): Guest Log: [DEBUG] 0

2021-06-18 19:17:31 (6480): Guest Log: [INFO] CVMFS and Frontier will use DIRECT instead of an HTTP proxy.

2021-06-18 19:17:31 (6480): Guest Log: [INFO] A local HTTP proxy could help making the network usage

2021-06-18 19:17:31 (6480): Guest Log: [INFO] of this application more efficient. It would also help to

2021-06-18 19:17:31 (6480): Guest Log: [INFO] offload the project servers.

2021-06-18 19:17:31 (6480): Guest Log: [INFO] Details can be found in the project forum.

2021-06-18 19:17:50 (6480): Guest Log: [INFO] Reloading the CVMFS configuration (can take a while) ...

2021-06-18 19:18:08 (6480): Guest Log: [INFO] Probing CVMFS ...

2021-06-18 19:18:20 (6480): 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-06-18 19:18:20 (6480): Guest Log: 2.4.4.0 3671 1 25288 15481 3 1 1690879 4096000 2 65024 0 2 100 0 0 http://s1bnl-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1

2021-06-18 19:18:21 (6480): Guest Log: [INFO] Reading volunteer information

2021-06-18 19:18:22 (6480): Guest Log: [INFO] Volunteer: Contact (21)

2021-06-18 19:18:22 (6480): Guest Log: [INFO] VMID: 49b2fac1-df25-48d2-a4ee-4612ca6a31f8

2021-06-18 19:18:22 (6480): Guest Log: [INFO] Requesting an X509 credential from LHC@home

2021-06-18 19:18:24 (6480): Guest Log: [INFO] Requesting an X509 credential from vLHC@home-dev

2021-06-18 19:18:26 (6480): Guest Log: [INFO] Running the fast benchmark.

2021-06-18 19:19:25 (6480): Guest Log: [INFO] Machine performance 8.58 HEPSPEC06

2021-06-18 19:19:25 (6480): Guest Log: [INFO] CMS application starting. Check log files.

2021-06-18 19:19:28 (6480): Guest Log: [DEBUG] HTCondor ping

2021-06-18 19:19:31 (6480): Guest Log: [DEBUG] 0

2021-06-18 20:56:01 (6480): Status Report: Job Duration: '64800.000000'
2021-06-18 20:56:01 (6480): Status Report: Elapsed Time: '12255.615885'
2021-06-18 20:56:01 (6480): Status Report: CPU Time: '9895.171875'
2021-06-18 22:10:15 (6480): Stopping VM.
2021-06-19 01:50:16 (3264): Detected: vboxwrapper 26197
2021-06-19 01:50:16 (3264): Detected: BOINC client v7.7
2021-06-19 01:50:16 (3264): Detected: VirtualBox VboxManage Interface (Version: 5.2.44)
2021-06-19 01:50:17 (3264): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2021-06-19 01:50:17 (3264): Starting VM using VBoxManage interface. (boinc_1896b2bdad7b3252, slot#11)
2021-06-19 01:51:50 (3264): Successfully started VM. (PID = '1820')
2021-06-19 01:51:50 (3264): Reporting VM Process ID to BOINC.
2021-06-19 01:51:50 (3264): VM state change detected. (old = 'PoweredOff', new = 'Running')
2021-06-19 01:51:50 (3264): Detected: Web Application Enabled (http://localhost:49207)
2021-06-19 01:51:50 (3264): Status Report: Job Duration: '64800.000000'
2021-06-19 01:51:50 (3264): Status Report: Elapsed Time: '16608.722904'
2021-06-19 01:51:50 (3264): Status Report: CPU Time: '14287.875000'
2021-06-19 01:51:50 (3264): Preference change detected
2021-06-19 01:51:50 (3264): Setting CPU throttle for VM. (100%)
2021-06-19 01:51:51 (3264): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2021-06-19 01:51:53 (3264): Guest Log: 02:54:30.477993 timesync vgsvcTimeSyncWorker: Radical host time change: 13 301 880 000 000ns (HostNow=1 624 081 912 849 000 000 ns HostLast=1 624 068 610 969 000 000 ns)

2021-06-19 01:52:03 (3264): Guest Log: 02:54:40.478574 timesync vgsvcTimeSyncWorker: Radical guest time change: 13 302 298 008 000ns (GuestNow=1 624 081 922 849 626 000 ns GuestLast=1 624 068 620 551 618 000 ns fSetTimeLastLoop=true )

2021-06-19 02:50:11 (3264): Stopping VM.
2021-06-19 03:51:16 (480): Detected: vboxwrapper 26197
2021-06-19 03:51:16 (480): Detected: BOINC client v7.7
2021-06-19 03:51:17 (480): Detected: VirtualBox VboxManage Interface (Version: 5.2.44)
2021-06-19 03:51:18 (480): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2021-06-19 03:51:18 (480): Starting VM using VBoxManage interface. (boinc_1896b2bdad7b3252, slot#11)
2021-06-19 03:51:42 (480): Successfully started VM. (PID = '6892')
2021-06-19 03:51:42 (480): Reporting VM Process ID to BOINC.
2021-06-19 03:51:42 (480): Guest Log: 03:52:50.874738 timesync vgsvcTimeSyncWorker: Radical host time change: 3 698 310 000 000ns (HostNow=1 624 089 101 423 000 000 ns HostLast=1 624 085 403 113 000 000 ns)

2021-06-19 03:51:42 (480): VM state change detected. (old = 'PoweredOff', new = 'Running')
2021-06-19 03:51:42 (480): Detected: Web Application Enabled (http://localhost:49207)
2021-06-19 03:51:42 (480): Status Report: Job Duration: '64800.000000'
2021-06-19 03:51:42 (480): Status Report: Elapsed Time: '20105.722904'
2021-06-19 03:51:42 (480): Status Report: CPU Time: '17071.421875'
2021-06-19 03:51:42 (480): Preference change detected
2021-06-19 03:51:43 (480): Setting CPU throttle for VM. (100%)
2021-06-19 03:51:44 (480): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2021-06-19 03:51:52 (480): Guest Log: 03:53:01.180007 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 698 502 038 000ns (GuestNow=1 624 089 111 738 040 000 ns GuestLast=1 624 085 413 236 002 000 ns fSetTimeLastLoop=true )

2021-06-19 04:50:40 (480): Stopping VM.
2021-06-19 05:52:12 (7096): Detected: vboxwrapper 26197
2021-06-19 05:52:12 (7096): Detected: BOINC client v7.7
2021-06-19 05:52:13 (7096): Detected: VirtualBox VboxManage Interface (Version: 5.2.44)
2021-06-19 05:52:13 (7096): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2021-06-19 05:52:14 (7096): Starting VM using VBoxManage interface. (boinc_1896b2bdad7b3252, slot#11)
2021-06-19 05:52:50 (7096): Successfully started VM. (PID = '8052')
2021-06-19 05:52:50 (7096): Reporting VM Process ID to BOINC.
2021-06-19 05:52:50 (7096): Guest Log: 04:51:53.169468 timesync vgsvcTimeSyncWorker: Radical host time change: 3 736 155 000 000ns (HostNow=1 624 096 368 299 000 000 ns HostLast=1 624 092 632 144 000 000 ns)

2021-06-19 05:52:50 (7096): VM state change detected. (old = 'PoweredOff', new = 'Running')
2021-06-19 05:52:50 (7096): Detected: Web Application Enabled (http://localhost:49207)
2021-06-19 05:52:50 (7096): Status Report: Job Duration: '64800.000000'
2021-06-19 05:52:50 (7096): Status Report: Elapsed Time: '23641.069626'
2021-06-19 05:52:50 (7096): Status Report: CPU Time: '20263.656250'
2021-06-19 05:52:50 (7096): Preference change detected
2021-06-19 05:52:51 (7096): Setting CPU throttle for VM. (100%)
2021-06-19 05:52:56 (7096): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2021-06-19 05:53:01 (7096): Guest Log: 04:52:03.522292 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 739 253 910 000ns (GuestNow=1 624 096 380 492 103 000 ns GuestLast=1 624 092 641 238 193 000 ns fSetTimeLastLoop=true )

2021-06-19 06:52:22 (7096): Stopping VM.
2021-06-19 06:53:10 (7096): Error in stop VM for VM: -182
Command:
VBoxManage -q controlvm "boinc_1896b2bdad7b3252" savestate
Output:
0%...10%...20%...30%...40%...50%...60%...70%...80%...
2021-06-19 06:53:10 (7096): VM did not stop when requested.
2021-06-19 06:53:10 (7096): VM was successfully terminated.
2021-06-19 07:59:03 (2872): Detected: vboxwrapper 26197
2021-06-19 07:59:03 (2872): Detected: BOINC client v7.7
2021-06-19 07:59:03 (2872): Detected: VirtualBox VboxManage Interface (Version: 5.2.44)
2021-06-19 07:59:03 (2872): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2021-06-19 07:59:05 (2872): Starting VM using VBoxManage interface. (boinc_1896b2bdad7b3252, slot#11)
2021-06-19 07:59:37 (2872): Successfully started VM. (PID = '7116')
2021-06-19 07:59:37 (2872): Reporting VM Process ID to BOINC.
2021-06-19 07:59:37 (2872): Guest Log: BIOS: VirtualBox 5.2.44

2021-06-19 07:59:37 (2872): Guest Log: CPUID EDX: 0x078bfbff

2021-06-19 07:59:37 (2872): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63

2021-06-19 07:59:37 (2872): VM state change detected. (old = 'PoweredOff', new = 'Running')
2021-06-19 07:59:37 (2872): Detected: Web Application Enabled (http://localhost:49207)
2021-06-19 07:59:37 (2872): Status Report: Job Duration: '64800.000000'
2021-06-19 07:59:37 (2872): Status Report: Elapsed Time: '27209.737261'
2021-06-19 07:59:37 (2872): Status Report: CPU Time: '23503.859375'
2021-06-19 07:59:37 (2872): Preference change detected
2021-06-19 07:59:37 (2872): Setting CPU throttle for VM. (100%)
2021-06-19 07:59:37 (2872): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2021-06-19 07:59:39 (2872): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032

2021-06-19 07:59:39 (2872): Guest Log: BIOS: Booting from Hard Disk...

2021-06-19 07:59:43 (2872): Guest Log: BIOS: KBD: unsupported int 16h function 03

2021-06-19 07:59:43 (2872): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 

2021-06-19 08:00:06 (2872): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds

2021-06-19 08:00:06 (2872): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)

2021-06-19 08:00:43 (2872): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log

2021-06-19 08:00:43 (2872): Guest Log: 00:00:00.000761 main     Log opened 2021-06-19T12:00:40.992333000Z

2021-06-19 08:00:43 (2872): Guest Log: 00:00:00.001226 main     OS Product: Linux

2021-06-19 08:00:43 (2872): Guest Log: 00:00:00.001337 main     OS Release: 4.14.157-17.cernvm.x86_64

2021-06-19 08:00:43 (2872): Guest Log: 00:00:00.001373 main     OS Version: #1 SMP Wed Dec 4 17:26:45 CET 2019

2021-06-19 08:00:43 (2872): Guest Log: 00:00:00.001405 main     Executable: /usr/share/vboxguest52/usr/sbin/VBoxService

2021-06-19 08:00:43 (2872): Guest Log: 00:00:00.001406 main     Process ID: 2905

2021-06-19 08:00:43 (2872): Guest Log: 00:00:00.001408 main     Package type: LINUX_64BITS_GENERIC

2021-06-19 08:00:43 (2872): Guest Log: 00:00:00.003806 main     5.2.6 r120293 started. Verbose level = 0

2021-06-19 08:01:18 (2872): Guest Log: [INFO] Mounting the shared directory

2021-06-19 08:01:18 (2872): Guest Log: [INFO] Shared directory mounted, enabling vboxmonitor

2021-06-19 08:01:18 (2872): Guest Log: [DEBUG] Testing network connection to cern.ch on port 80

2021-06-19 08:01:19 (2872): Guest Log: [DEBUG] Connection to cern.ch 80 port [tcp/http] succeeded!

2021-06-19 08:01:19 (2872): Guest Log: [DEBUG] 0

2021-06-19 08:01:19 (2872): Guest Log: [DEBUG] Testing VCCS connection to vccs.cern.ch on port 443

2021-06-19 08:01:20 (2872): Guest Log: [DEBUG] Connection to vccs.cern.ch 443 port [tcp/https] succeeded!

2021-06-19 08:01:20 (2872): Guest Log: [DEBUG] 0

2021-06-19 08:01:20 (2872): Guest Log: [DEBUG] Testing connection to Condor server on port 9618

2021-06-19 08:01:20 (2872): Guest Log: [DEBUG] Connection to vocms0840.cern.ch 9618 port [tcp/condor] succeeded!

2021-06-19 08:01:20 (2872): Guest Log: [DEBUG] 0

2021-06-19 08:01:20 (2872): Guest Log: [DEBUG] Testing connection to WMAgent server on port 4080

2021-06-19 08:01:21 (2872): Guest Log: [DEBUG] Connection to vocms0267.cern.ch 4080 port [tcp/lorica-in] succeeded!

2021-06-19 08:01:21 (2872): Guest Log: [DEBUG] 0

2021-06-19 08:01:21 (2872): Guest Log: [DEBUG] Testing connection to Frontier server on port 8080

2021-06-19 08:01:21 (2872): Guest Log: [DEBUG] Connection to cms-frontier.openhtc.io 8080 port [tcp/webcache] succeeded!

2021-06-19 08:01:21 (2872): Guest Log: [DEBUG] 0

2021-06-19 08:01:22 (2872): Guest Log: [INFO] CVMFS and Frontier will use DIRECT instead of an HTTP proxy.

2021-06-19 08:01:22 (2872): Guest Log: [INFO] A local HTTP proxy could help making the network usage

2021-06-19 08:01:22 (2872): Guest Log: [INFO] of this application more efficient. It would also help to

2021-06-19 08:01:22 (2872): Guest Log: [INFO] offload the project servers.

2021-06-19 08:01:22 (2872): Guest Log: [INFO] Details can be found in the project forum.

2021-06-19 08:01:35 (2872): Guest Log: [INFO] Reloading the CVMFS configuration (can take a while) ...

2021-06-19 08:01:54 (2872): Guest Log: [INFO] Probing CVMFS ...

2021-06-19 08:02:08 (2872): 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-06-19 08:02:08 (2872): Guest Log: 2.4.4.0 3682 1 25756 15485 3 1 1770954 4096001 2 65024 0 2 100 0 0 http://s1bnl-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1

2021-06-19 08:02:11 (2872): Guest Log: [INFO] Reading volunteer information

2021-06-19 08:02:12 (2872): Guest Log: [INFO] Volunteer: Contact (21)

2021-06-19 08:02:12 (2872): Guest Log: [INFO] VMID: 49b2fac1-df25-48d2-a4ee-4612ca6a31f8

2021-06-19 08:02:12 (2872): Guest Log: [INFO] Requesting an X509 credential from LHC@home

2021-06-19 08:02:14 (2872): Guest Log: [INFO] Requesting an X509 credential from vLHC@home-dev

2021-06-19 08:02:16 (2872): Guest Log: [INFO] Running the fast benchmark.

2021-06-19 08:03:12 (2872): Guest Log: [INFO] Machine performance 9.08 HEPSPEC06

2021-06-19 08:03:12 (2872): Guest Log: [INFO] CMS application starting. Check log files.

2021-06-19 08:03:14 (2872): Guest Log: [DEBUG] HTCondor ping

2021-06-19 08:03:17 (2872): Guest Log: [DEBUG] 0

2021-06-19 08:59:12 (2872): Stopping VM.
2021-06-19 10:01:30 (4644): Detected: vboxwrapper 26197
2021-06-19 10:01:30 (4644): Detected: BOINC client v7.7
2021-06-19 10:01:31 (4644): Detected: VirtualBox VboxManage Interface (Version: 5.2.44)
2021-06-19 10:01:33 (4644): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2021-06-19 10:01:34 (4644): Starting VM using VBoxManage interface. (boinc_1896b2bdad7b3252, slot#11)
2021-06-19 10:02:17 (4644): Successfully started VM. (PID = '5212')
2021-06-19 10:02:17 (4644): Reporting VM Process ID to BOINC.
2021-06-19 10:02:17 (4644): VM state change detected. (old = 'PoweredOff', new = 'Running')
2021-06-19 10:02:17 (4644): Detected: Web Application Enabled (http://localhost:49207)
2021-06-19 10:02:17 (4644): Status Report: Job Duration: '64800.000000'
2021-06-19 10:02:17 (4644): Status Report: Elapsed Time: '30782.737261'
2021-06-19 10:02:17 (4644): Status Report: CPU Time: '26707.968750'
2021-06-19 10:02:17 (4644): Preference change detected
2021-06-19 10:02:17 (4644): Setting CPU throttle for VM. (100%)
2021-06-19 10:02:18 (4644): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2021-06-19 10:02:26 (4644): Guest Log: 00:58:40.154023 timesync vgsvcTimeSyncWorker: Radical host time change: 3 792 213 000 000ns (HostNow=1 624 111 345 240 000 000 ns HostLast=1 624 107 553 027 000 000 ns)

2021-06-19 10:02:36 (4644): Guest Log: 00:58:50.234209 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 793 562 657 000ns (GuestNow=1 624 111 355 320 250 000 ns GuestLast=1 624 107 561 757 593 000 ns fSetTimeLastLoop=true )

2021-06-19 11:01:13 (4644): Stopping VM.
2021-06-22 15:37:20 (6136): Detected: vboxwrapper 26197
2021-06-22 15:37:20 (6136): Detected: BOINC client v7.7
2021-06-22 15:37:20 (6136): Detected: VirtualBox VboxManage Interface (Version: 5.2.44)
2021-06-22 15:37:21 (6136): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2021-06-22 15:37:21 (6136): Starting VM using VBoxManage interface. (boinc_1896b2bdad7b3252, slot#11)
2021-06-22 15:37:51 (6136): Successfully started VM. (PID = '4512')
2021-06-22 15:37:51 (6136): Reporting VM Process ID to BOINC.
2021-06-22 15:37:51 (6136): VM state change detected. (old = 'PoweredOff', new = 'Running')
2021-06-22 15:37:51 (6136): Detected: Web Application Enabled (http://localhost:49207)
2021-06-22 15:37:51 (6136): Status Report: Job Duration: '64800.000000'
2021-06-22 15:37:51 (6136): Status Report: Elapsed Time: '34287.737261'
2021-06-22 15:37:51 (6136): Status Report: CPU Time: '29771.218750'
2021-06-22 15:37:51 (6136): Preference change detected
2021-06-22 15:37:51 (6136): Setting CPU throttle for VM. (100%)
2021-06-22 15:37:59 (6136): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2021-06-22 15:37:59 (6136): Guest Log: 01:57:41.205203 timesync vgsvcTimeSyncWorker: Radical host time change: 275 791 247 000 000ns (HostNow=1 624 390 666 874 000 000 ns HostLast=1 624 114 875 627 000 000 ns)

2021-06-22 15:38:03 (6136): Guest Log: 01:57:51.445219 timesync vgsvcTimeSyncWorker: Radical guest time change: 275 793 707 335 000ns (GuestNow=1 624 390 677 917 117 000 ns GuestLast=1 624 114 884 209 782 000 ns fSetTimeLastLoop=true )

2021-06-22 15:48:12 (6136): Guest Log: [INFO] Condor exited with return value N/A.

2021-06-22 15:48:12 (6136): Guest Log: [INFO] Shutting Down.

2021-06-22 15:48:13 (6136): VM Completion File Detected.
2021-06-22 15:48:13 (6136): VM Completion Message: Condor exited with return value N/A.
.
2021-06-22 15:48:13 (6136): Powering off VM.
2021-06-22 15:53:20 (6136): VM did not power off when requested.
2021-06-22 15:53:20 (6136): VM was successfully terminated.
2021-06-22 15:53:20 (6136): Deregistering VM. (boinc_1896b2bdad7b3252, slot#11)
2021-06-22 15:53:20 (6136): Removing network bandwidth throttle group from VM.
2021-06-22 15:53:21 (6136): Removing VM from VirtualBox.
15:53:26 (6136): called boinc_finish(0)

</stderr_txt>
]]>
Development for LHC@home

Stderr output
