Name CMS_753253_1628687405.744261_0
Workunit 2118632
Created 11 Aug 2021, 13:10:06 UTC
Sent 13 Aug 2021, 22:26:23 UTC
Report deadline 20 Aug 2021, 22:26:23 UTC
Received 20 Aug 2021, 3:54:09 UTC
Server state Over
Outcome Success
Client state Done
Exit status 0 (0x00000000)
Computer ID 4405
Run time 13 hours 40 min 47 sec
CPU time 15 hours 23 min 38 sec
Validate state Valid
Credit 7,109.41
Device peak FLOPS 16.40 GFLOPS
Application version CMS Simulation v60.50 (vbox64_mt_mcore_cms)
windows_x86_64
Peak working set size 60.42 MB
Peak swap size 64.37 MB
Peak disk usage 3.87 GB

Stderr output

<core_client_version>7.16.11</core_client_version>
<![CDATA[
<stderr_txt>
2021-08-19 07:31:51 (2980): Detected: vboxwrapper 26197
2021-08-19 07:31:51 (2980): Detected: BOINC client v7.7
2021-08-19 07:31:53 (2980): Detected: VirtualBox VboxManage Interface (Version: 6.1.12)
2021-08-19 07:31:53 (2980): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2021-08-19 07:31:53 (2980): Successfully copied 'init_data.xml' to the shared directory.
2021-08-19 07:31:58 (2980): Create VM. (boinc_caf140c058a1e812, slot#1)
2021-08-19 07:31:59 (2980): Setting Memory Size for VM. (4584MB)
2021-08-19 07:32:00 (2980): Setting CPU Count for VM. (4)
2021-08-19 07:32:00 (2980): Setting Chipset Options for VM.
2021-08-19 07:32:00 (2980): Setting Boot Options for VM.
2021-08-19 07:32:01 (2980): Setting Network Configuration for NAT.
2021-08-19 07:32:01 (2980): Enabling VM Network Access.
2021-08-19 07:32:01 (2980): Disabling USB Support for VM.
2021-08-19 07:32:02 (2980): Disabling COM Port Support for VM.
2021-08-19 07:32:02 (2980): Disabling LPT Port Support for VM.
2021-08-19 07:32:02 (2980): Disabling Audio Support for VM.
2021-08-19 07:32:03 (2980): Disabling Clipboard Support for VM.
2021-08-19 07:32:03 (2980): Disabling Drag and Drop Support for VM.
2021-08-19 07:32:04 (2980): Adding storage controller(s) to VM.
2021-08-19 07:32:04 (2980): Adding virtual disk drive to VM. (vm_image.vdi)
2021-08-19 07:32:04 (2980): Adding VirtualBox Guest Additions to VM.
2021-08-19 07:32:05 (2980): Adding network bandwidth throttle group to VM. (Defaulting to 1024GB)
2021-08-19 07:32:05 (2980): forwarding host port 54497 to guest port 80
2021-08-19 07:32:06 (2980): Enabling remote desktop for VM.
2021-08-19 07:32:06 (2980): Required extension pack not installed, remote desktop not enabled.
2021-08-19 07:32:06 (2980): Enabling shared directory for VM.
2021-08-19 07:32:06 (2980): Starting VM using VBoxManage interface. (boinc_caf140c058a1e812, slot#1)
2021-08-19 07:32:11 (2980): Successfully started VM. (PID = '1372')
2021-08-19 07:32:11 (2980): Reporting VM Process ID to BOINC.
2021-08-19 07:32:11 (2980): Guest Log: BIOS: VirtualBox 6.1.12

2021-08-19 07:32:11 (2980): Guest Log: CPUID EDX: 0x178bfbff

2021-08-19 07:32:11 (2980): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63

2021-08-19 07:32:11 (2980): VM state change detected. (old = 'PoweredOff', new = 'Running')
2021-08-19 07:32:11 (2980): Detected: Web Application Enabled (http://localhost:54497)
2021-08-19 07:32:11 (2980): Preference change detected
2021-08-19 07:32:11 (2980): Setting CPU throttle for VM. (100%)
2021-08-19 07:32:12 (2980): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 120 seconds) or (Vbox_job.xml: 600 seconds))
2021-08-19 07:32:13 (2980): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032

2021-08-19 07:32:13 (2980): Guest Log: BIOS: Booting from Hard Disk...

2021-08-19 07:32:15 (2980): Guest Log: BIOS: KBD: unsupported int 16h function 03

2021-08-19 07:32:15 (2980): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 

2021-08-19 07:32:45 (2980): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds

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

2021-08-19 07:32:47 (2980): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log

2021-08-19 07:32:47 (2980): Guest Log: 00:00:00.000374 main     Log opened 2021-08-19T12:32:47.340777000Z

2021-08-19 07:32:47 (2980): Guest Log: 00:00:00.000517 main     OS Product: Linux

2021-08-19 07:32:47 (2980): Guest Log: 00:00:00.000662 main     OS Release: 4.14.232-19.cernvm.x86_64

2021-08-19 07:32:47 (2980): Guest Log: 00:00:00.000724 main     OS Version: #1 SMP Fri Apr 30 17:12:25 CEST 2021

2021-08-19 07:32:47 (2980): Guest Log: 00:00:00.000780 main     Executable: /usr/sbin/VBoxService

2021-08-19 07:32:47 (2980): Guest Log: 00:00:00.000781 main     Process ID: 2270

2021-08-19 07:32:47 (2980): Guest Log: 00:00:00.000783 main     Package type: LINUX_64BITS_GENERIC

2021-08-19 07:32:47 (2980): Guest Log: 00:00:00.006275 main     5.2.6 r120293 started. Verbose level = 0

2021-08-19 07:33:06 (2980): Guest Log: [INFO] Mounting the shared directory

2021-08-19 07:33:06 (2980): Guest Log: [INFO] Shared directory mounted, enabling vboxmonitor

2021-08-19 07:33:07 (2980): Guest Log: [INFO] Sourcing essential functions from /cvmfs/grid.cern.ch

2021-08-19 07:33:07 (2980): Guest Log: [INFO] Testing connection to cern.ch

2021-08-19 07:33:07 (2980): Guest Log: [INFO] Testing connection to VCCS

2021-08-19 07:33:08 (2980): Guest Log: [INFO] Testing connection to HTCondor

2021-08-19 07:33:08 (2980): Guest Log: [INFO] Testing connection to WMAgent

2021-08-19 07:33:09 (2980): Guest Log: [INFO] Testing connection to Frontier

2021-08-19 07:33:09 (2980): Guest Log: [INFO] Could not find a local HTTP proxy

2021-08-19 07:33:09 (2980): Guest Log: [INFO] CVMFS and Frontier will have to use DIRECT connections

2021-08-19 07:33:10 (2980): Guest Log: [INFO] This makes the application less efficient

2021-08-19 07:33:10 (2980): Guest Log: [INFO] It also puts higher load on the project servers

2021-08-19 07:33:10 (2980): Guest Log: [INFO] Setting up a local HTTP proxy is highly recommended

2021-08-19 07:33:10 (2980): Guest Log: [INFO] Advice can be found in the project forum

2021-08-19 07:33:10 (2980): Guest Log: [INFO] Reloading and probing the CVMFS configuration

2021-08-19 07:33:18 (2980): Guest Log: Probing /cvmfs/cvmfs-config.cern.ch... OK

2021-08-19 07:33:18 (2980): Guest Log: Probing /cvmfs/grid.cern.ch... OK

2021-08-19 07:33:24 (2980): Guest Log: Probing /cvmfs/cms.cern.ch... OK

2021-08-19 07:33:24 (2980): Guest Log: Probing /cvmfs/singularity.opensciencegrid.org... OK

2021-08-19 07:33:24 (2980): Guest Log: Probing /cvmfs/oasis.opensciencegrid.org... OK

2021-08-19 07:33:24 (2980): Guest Log: Probing /cvmfs/cms-ib.cern.ch... OK

2021-08-19 07:33:25 (2980): 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-08-19 07:33:25 (2980): Guest Log: 2.7.2.0 2963 0 28544 16005 3 2 2080541 10240000 2 65024 0 30 23.3333 150 220 http://s1fnal-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1

2021-08-19 07:33:32 (2980): Guest Log: [INFO] Reading volunteer information

2021-08-19 07:33:33 (2980): Guest Log: [INFO] Requesting an X509 credential from LHC@home

2021-08-19 07:33:35 (2980): Guest Log: [INFO] Requesting an X509 credential from vLHC@home-dev

2021-08-19 07:33:36 (2980): Guest Log: [INFO] CMS application starting. Check log files.

2021-08-19 07:45:01 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 08:15:02 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 08:15:08 (2980): Guest Log: 00:12:20.203168 timesync vgsvcTimeSyncWorker: Radical host time change: 1 810 517 000 000ns (HostNow=1 629 378 907 922 000 000 ns HostLast=1 629 377 097 405 000 000 ns)

2021-08-19 08:15:18 (2980): Guest Log: 00:12:30.203462 timesync vgsvcTimeSyncWorker: Radical guest time change: 1 810 378 949 000ns (GuestNow=1 629 378 917 922 415 000 ns GuestLast=1 629 377 107 543 466 000 ns fSetTimeLastLoop=true )

2021-08-19 09:42:18 (2980): Status Report: Job Duration: '64800.000000'
2021-08-19 09:42:18 (2980): Status Report: Elapsed Time: '6000.000000'
2021-08-19 09:42:18 (2980): Status Report: CPU Time: '7015.218750'
2021-08-19 10:03:25 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 10:51:40 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 10:51:45 (2980): Guest Log: 02:00:41.840619 timesync vgsvcTimeSyncWorker: Radical host time change: 2 904 745 000 000ns (HostNow=1 629 388 304 330 000 000 ns HostLast=1 629 385 399 585 000 000 ns)

2021-08-19 10:51:55 (2980): Guest Log: 02:00:51.841175 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 904 771 374 000ns (GuestNow=1 629 388 314 330 746 000 ns GuestLast=1 629 385 409 559 372 000 ns fSetTimeLastLoop=true )

2021-08-19 11:01:42 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 11:02:42 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 11:21:46 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 11:22:45 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 11:45:50 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 11:46:49 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 12:10:54 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 12:11:55 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 12:14:44 (2980): Status Report: Job Duration: '64800.000000'
2021-08-19 12:14:44 (2980): Status Report: Elapsed Time: '12000.000000'
2021-08-19 12:14:44 (2980): Status Report: CPU Time: '13924.609375'
2021-08-19 12:37:00 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 12:37:59 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 13:03:05 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 13:04:05 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 13:34:09 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 13:35:09 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 13:57:51 (2980): Status Report: Job Duration: '64800.000000'
2021-08-19 13:57:51 (2980): Status Report: Elapsed Time: '18000.000000'
2021-08-19 13:57:51 (2980): Status Report: CPU Time: '20318.156250'
2021-08-19 14:02:14 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 14:03:14 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 14:34:17 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 14:35:18 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 15:05:22 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 15:06:22 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 15:37:28 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 15:38:28 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 15:42:02 (2980): Status Report: Job Duration: '64800.000000'
2021-08-19 15:42:02 (2980): Status Report: Elapsed Time: '24000.000000'
2021-08-19 15:42:02 (2980): Status Report: CPU Time: '27195.578125'
2021-08-19 16:10:33 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 16:11:33 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 16:42:38 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 16:43:38 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 17:16:43 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 17:17:43 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 17:25:10 (2980): Status Report: Job Duration: '64800.000000'
2021-08-19 17:25:10 (2980): Status Report: Elapsed Time: '30000.000000'
2021-08-19 17:25:10 (2980): Status Report: CPU Time: '34103.765625'
2021-08-19 17:50:49 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 17:51:49 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 18:23:55 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 18:24:55 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 18:57:59 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 18:58:59 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 19:08:19 (2980): Status Report: Job Duration: '64800.000000'
2021-08-19 19:08:19 (2980): Status Report: Elapsed Time: '36000.000000'
2021-08-19 19:08:19 (2980): Status Report: CPU Time: '40836.500000'
2021-08-19 19:33:08 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 19:34:08 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 20:08:12 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 20:09:12 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 20:43:17 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 20:44:17 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 20:51:28 (2980): Status Report: Job Duration: '64800.000000'
2021-08-19 20:51:28 (2980): Status Report: Elapsed Time: '42000.000000'
2021-08-19 20:51:28 (2980): Status Report: CPU Time: '47779.671875'
2021-08-19 21:19:21 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 21:20:22 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 21:54:26 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 21:55:26 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 22:30:31 (2980): VM state change detected. (old = 'Running', new = 'Paused')
2021-08-19 22:31:31 (2980): VM state change detected. (old = 'Paused', new = 'Running')
2021-08-19 22:34:38 (2980): Status Report: Job Duration: '64800.000000'
2021-08-19 22:34:38 (2980): Status Report: Elapsed Time: '48000.000000'
2021-08-19 22:34:38 (2980): Status Report: CPU Time: '54692.421875'
2021-08-19 22:48:50 (2980): Guest Log: [INFO] glidein exited with return value 0.

2021-08-19 22:48:50 (2980): Guest Log: [INFO] Shutting Down.

2021-08-19 22:48:50 (2980): VM Completion File Detected.
2021-08-19 22:48:50 (2980): VM Completion Message: glidein exited with return value 0.
.
2021-08-19 22:48:50 (2980): Powering off VM.
2021-08-19 22:53:52 (2980): VM did not power off when requested.
2021-08-19 22:53:52 (2980): VM was successfully terminated.
2021-08-19 22:53:52 (2980): Deregistering VM. (boinc_caf140c058a1e812, slot#1)
2021-08-19 22:53:53 (2980): Removing network bandwidth throttle group from VM.
2021-08-19 22:53:53 (2980): Removing VM from VirtualBox.
22:53:59 (2980): called boinc_finish(0)

</stderr_txt>
]]>


©2024 CERN