Stderr output

<core_client_version>7.16.3</core_client_version>
<![CDATA[
<stderr_txt>
2020-02-22 20:25:00 (783615): vboxwrapper (7.7.26196): starting
2020-02-22 20:25:01 (783615): Feature: Checkpoint interval offset (281 seconds)
2020-02-22 20:25:01 (783615): Detected: VirtualBox VboxManage Interface (Version: 6.1.4)
2020-02-22 20:25:01 (783615): VBOX_JOB::parse(): unexpected text enable_screenshots_on_error/
2020-02-22 20:25:01 (783615): Detected: Minimum checkpoint interval (600.000000 seconds)
2020-02-22 20:25:01 (783615): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2020-02-22 20:25:01 (783615): Successfully copied 'init_data.xml' to the shared directory.
2020-02-22 20:25:01 (783615): Successfully copied 'input' to the shared directory.
2020-02-22 20:25:02 (783615): Create VM. (boinc_b11aa6da257fdb10, slot#14)
2020-02-22 20:25:03 (783615): Setting Memory Size for VM. (630MB)
2020-02-22 20:25:03 (783615): Setting CPU Count for VM. (1)
2020-02-22 20:25:03 (783615): Setting Chipset Options for VM.
2020-02-22 20:25:04 (783615): Setting Boot Options for VM.
2020-02-22 20:25:04 (783615): Setting Network Configuration for NAT.
2020-02-22 20:25:04 (783615): Enabling VM Network Access.
2020-02-22 20:25:05 (783615): Disabling USB Support for VM.
2020-02-22 20:25:05 (783615): Disabling COM Port Support for VM.
2020-02-22 20:25:05 (783615): Disabling LPT Port Support for VM.
2020-02-22 20:25:06 (783615): Disabling Audio Support for VM.
2020-02-22 20:25:06 (783615): Disabling Clipboard Support for VM.
2020-02-22 20:25:06 (783615): Disabling Drag and Drop Support for VM.
2020-02-22 20:25:07 (783615): Adding storage controller(s) to VM.
2020-02-22 20:25:07 (783615): Adding virtual disk drive to VM. (vm_image.vdi)
2020-02-22 20:25:07 (783615): Adding network bandwidth throttle group to VM. (Defaulting to 1024GB)
2020-02-22 20:25:07 (783615): forwarding host port 35535 to guest port 80
2020-02-22 20:25:08 (783615): Enabling remote desktop for VM.
2020-02-22 20:25:08 (783615): Enabling shared directory for VM.
2020-02-22 20:25:09 (783615): Starting VM. (boinc_b11aa6da257fdb10, slot#14)
2020-02-22 20:25:11 (783615): Successfully started VM. (PID = '784233')
2020-02-22 20:25:11 (783615): Reporting VM Process ID to BOINC.
2020-02-22 20:25:12 (783615): Guest Log: BIOS: VirtualBox 6.1.3
2020-02-22 20:25:12 (783615): Guest Log: CPUID EDX: 0x178bfbff
2020-02-22 20:25:12 (783615): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63
2020-02-22 20:25:12 (783615): VM state change detected. (old = 'poweroff', new = 'running')
2020-02-22 20:25:12 (783615): Detected: Web Application Enabled (http://localhost:35535)
2020-02-22 20:25:12 (783615): Detected: Remote Desktop Enabled (localhost:45481)
2020-02-22 20:25:13 (783615): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032
2020-02-22 20:25:13 (783615): Guest Log: BIOS: Booting from Hard Disk...
2020-02-22 20:25:13 (783615): Preference change detected
2020-02-22 20:25:13 (783615): Setting CPU throttle for VM. (100%)
2020-02-22 20:25:14 (783615): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 120 seconds) or (Vbox_job.xml: 600 seconds))
2020-02-22 20:25:16 (783615): Guest Log: BIOS: KBD: unsupported int 16h function 03
2020-02-22 20:25:16 (783615): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 
2020-02-22 20:25:53 (783615): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds
2020-02-22 20:25:53 (783615): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)
2020-02-22 20:26:05 (783615): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log
2020-02-22 20:26:05 (783615): Guest Log: 00:00:00.000400 main     Log opened 2020-02-22T19:26:05.452367000Z
2020-02-22 20:26:05 (783615): Guest Log: 00:00:00.001436 main     OS Product: Linux
2020-02-22 20:26:08 (783615): Guest Log: 00:00:00.005301 main     OS Release: 4.14.76-13.cernvm.x86_64
2020-02-22 20:26:08 (783615): Guest Log: 00:00:00.007447 main     OS Version: #1 SMP Tue Oct 16 18:26:15 CEST 2018
2020-02-22 20:26:08 (783615): Guest Log: 00:00:00.009548 main     Executable: /usr/sbin/VBoxService
2020-02-22 20:26:08 (783615): Guest Log: 00:00:00.009555 main     Process ID: 3162
2020-02-22 20:26:08 (783615): Guest Log: 00:00:00.009558 main     Package type: LINUX_64BITS_GENERIC
2020-02-22 20:26:08 (783615): Guest Log: 00:00:00.093070 main     5.2.6 r120293 started. Verbose level = 0
2020-02-22 20:27:15 (783615): Guest Log: 20:27:14 CET +01:00 2020-02-22: cranky: [INFO] Detected Theory App
2020-02-22 20:27:15 (783615): Guest Log: 20:27:14 CET +01:00 2020-02-22: cranky: [INFO] Checking CVMFS.
2020-02-22 20:27:59 (783615): Guest Log: 20:27:57 CET +01:00 2020-02-22: cranky: [INFO] Checking runc.
2020-02-22 20:27:59 (783615): Guest Log: 20:27:57 CET +01:00 2020-02-22: cranky: [INFO] Creating the filesystem.
2020-02-22 20:27:59 (783615): Guest Log: 20:27:57 CET +01:00 2020-02-22: cranky: [INFO] Using /cvmfs/cernvm-prod.cern.ch/cvm3
2020-02-22 20:27:59 (783615): Guest Log: 20:27:58 CET +01:00 2020-02-22: cranky: [INFO] Updating config.json.
2020-02-22 20:27:59 (783615): Guest Log: 20:27:58 CET +01:00 2020-02-22: cranky: [INFO] Running Container 'runc'.
2020-02-22 20:27:59 (783615): Guest Log: job: htmld=/shared/html/job
2020-02-22 20:27:59 (783615): Guest Log: job: unpack exitcode=0
2020-02-22 20:28:00 (783615): Guest Log: 20:28:00 CET +01:00 2020-02-22: cranky: [INFO] ===> [runRivet] Sat Feb 22 19:27:59 UTC 2020 [boinc pp jets 7000 28 - herwig7 7.2.0 softTune 100000 40]
2020-02-22 22:05:13 (783615): Status Report: Job Duration: '864000.000000'
2020-02-22 22:05:13 (783615): Status Report: Elapsed Time: '6000.024548'
2020-02-22 22:05:13 (783615): Status Report: CPU Time: '4096.300000'
2020-02-22 22:44:40 (783615): VM state change detected. (old = 'running', new = 'paused')
2020-02-23 20:58:19 (783615): VM state change detected. (old = 'paused', new = 'running')
2020-02-23 20:58:22 (783615): Guest Log: 02:18:36.476249 timesync vgsvcTimeSyncWorker: Radical host time change: 80 030 070 000 000ns (HostNow=1 582 487 901 805 000 000 ns HostLast=1 582 407 871 735 000 000 ns)
2020-02-23 20:58:34 (783615): Guest Log: 02:18:46.520165 timesync vgsvcTimeSyncWorker: Radical guest time change: 80 030 249 892 000ns (GuestNow=1 582 487 911 974 145 000 ns GuestLast=1 582 407 881 724 253 000 ns fSetTimeLastLoop=true )
2020-02-23 20:58:57 (783615): VM state change detected. (old = 'running', new = 'paused')
2020-02-23 21:06:03 (783615): VM state change detected. (old = 'paused', new = 'running')
2020-02-23 22:06:13 (783615): Status Report: Job Duration: '864000.000000'
2020-02-23 22:06:13 (783615): Status Report: Elapsed Time: '12003.876347'
2020-02-23 22:06:13 (783615): Status Report: CPU Time: '9479.420000'
2020-02-23 22:11:15 (783615): VM state change detected. (old = 'running', new = 'paused')
2020-02-24 09:18:32 (783615): Error in resume VM for VM: -2135228414
Command:
VBoxManage -q controlvm "boinc_b11aa6da257fdb10" resume
Output:
VBoxManage: error: VM is paused due to host power management
VBoxManage: error: Details: code VBOX_E_INVALID_VM_STATE (0x80bb0002), component ConsoleWrap, interface IConsole, callee nsISupports
VBoxManage: error: Context: "Resume()" at line 410 of file VBoxManageControlVM.cpp

2020-02-24 09:18:41 (783615): Error in resume VM for VM: -2135228414
Command:
VBoxManage -q controlvm "boinc_b11aa6da257fdb10" resume
Output:
VBoxManage: error: VM is paused due to host power management
VBoxManage: error: Details: code VBOX_E_INVALID_VM_STATE (0x80bb0002), component ConsoleWrap, interface IConsole, callee nsISupports
VBoxManage: error: Context: "Resume()" at line 410 of file VBoxManageControlVM.cpp

2020-02-24 09:18:46 (783615): VM state change detected. (old = 'paused', new = 'running')
2020-02-24 09:18:50 (783615): VM state change detected. (old = 'running', new = 'paused')
2020-02-24 09:41:36 (783615): VM state change detected. (old = 'paused', new = 'running')
2020-02-24 09:41:39 (783615): Guest Log: 03:24:30.053725 timesync vgsvcTimeSyncWorker: Radical host time change: 41 427 288 000 000ns (HostNow=1 582 533 697 818 000 000 ns HostLast=1 582 492 270 530 000 000 ns)
2020-02-24 09:41:49 (783615): Guest Log: 03:24:40.061047 timesync vgsvcTimeSyncWorker: Radical guest time change: 41 852 317 690 000ns (GuestNow=1 582 533 707 825 356 000 ns GuestLast=1 582 491 855 507 666 000 ns fSetTimeLastLoop=true )
2020-02-24 09:42:19 (783615): VM state change detected. (old = 'running', new = 'paused')
2020-02-24 10:41:18 (783615): VM state change detected. (old = 'paused', new = 'running')
2020-02-24 10:41:18 (783615): Guest Log: 03:25:10.097252 timesync vgsvcTimeSyncWorker: Radical host time change: 3 550 227 000 000ns (HostNow=1 582 537 278 067 000 000 ns HostLast=1 582 533 727 840 000 000 ns)
2020-02-24 10:41:28 (783615): Guest Log: 03:25:20.103643 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 550 211 804 000ns (GuestNow=1 582 537 288 073 303 000 ns GuestLast=1 582 533 737 861 499 000 ns fSetTimeLastLoop=true )
2020-02-24 12:15:33 (783615): Status Report: Job Duration: '864000.000000'
2020-02-24 12:15:33 (783615): Status Report: Elapsed Time: '18005.614852'
2020-02-24 12:15:33 (783615): Status Report: CPU Time: '14878.880000'
2020-02-24 13:55:28 (783615): Status Report: Job Duration: '864000.000000'
2020-02-24 13:55:28 (783615): Status Report: Elapsed Time: '24006.397373'
2020-02-24 13:55:28 (783615): Status Report: CPU Time: '20367.760000'
2020-02-24 15:35:26 (783615): Status Report: Job Duration: '864000.000000'
2020-02-24 15:35:26 (783615): Status Report: Elapsed Time: '30008.320016'
2020-02-24 15:35:26 (783615): Status Report: CPU Time: '25852.140000'
2020-02-24 17:15:25 (783615): Status Report: Job Duration: '864000.000000'
2020-02-24 17:15:25 (783615): Status Report: Elapsed Time: '36009.289691'
2020-02-24 17:15:25 (783615): Status Report: CPU Time: '31406.550000'
2020-02-24 18:55:26 (783615): Status Report: Job Duration: '864000.000000'
2020-02-24 18:55:26 (783615): Status Report: Elapsed Time: '42011.960736'
2020-02-24 18:55:26 (783615): Status Report: CPU Time: '36841.490000'
2020-02-24 20:35:27 (783615): Status Report: Job Duration: '864000.000000'
2020-02-24 20:35:27 (783615): Status Report: Elapsed Time: '48015.337089'
2020-02-24 20:35:27 (783615): Status Report: CPU Time: '42275.550000'
2020-02-24 22:15:26 (783615): Status Report: Job Duration: '864000.000000'
2020-02-24 22:15:26 (783615): Status Report: Elapsed Time: '54016.902720'
2020-02-24 22:15:26 (783615): Status Report: CPU Time: '47703.670000'
2020-02-24 23:55:27 (783615): Status Report: Job Duration: '864000.000000'
2020-02-24 23:55:27 (783615): Status Report: Elapsed Time: '60017.384675'
2020-02-24 23:55:27 (783615): Status Report: CPU Time: '53131.340000'
2020-02-25 00:04:45 (783615): VM state change detected. (old = 'running', new = 'paused')
2020-02-25 15:48:19 (783615): Error in resume VM for VM: -2135228414
Command:
VBoxManage -q controlvm "boinc_b11aa6da257fdb10" resume
Output:
VBoxManage: error: VM is paused due to host power management
VBoxManage: error: Details: code VBOX_E_INVALID_VM_STATE (0x80bb0002), component ConsoleWrap, interface IConsole, callee nsISupports
VBoxManage: error: Context: "Resume()" at line 410 of file VBoxManageControlVM.cpp

2020-02-25 15:48:27 (783615): Error in resume VM for VM: -2135228414
Command:
VBoxManage -q controlvm "boinc_b11aa6da257fdb10" resume
Output:
VBoxManage: error: Cannot resume the machine as it is not paused (machine state: Running)
VBoxManage: error: Details: code VBOX_E_INVALID_VM_STATE (0x80bb0002), component ConsoleWrap, interface IConsole, callee nsISupports
VBoxManage: error: Context: "Resume()" at line 410 of file VBoxManageControlVM.cpp

2020-02-25 15:48:30 (783615): VM state change detected. (old = 'paused', new = 'running')
2020-02-25 15:48:35 (783615): Guest Log: 16:48:45.354595 timesync vgsvcTimeSyncWorker: Radical host time change: 56 630 249 000 000ns (HostNow=1 582 642 113 136 000 000 ns HostLast=1 582 585 482 887 000 000 ns)
2020-02-25 15:48:44 (783615): Guest Log: 16:48:55.358524 timesync vgsvcTimeSyncWorker: Radical guest time change: 56 630 837 559 000ns (GuestNow=1 582 642 123 650 905 000 ns GuestLast=1 582 585 492 813 346 000 ns fSetTimeLastLoop=true )
2020-02-25 17:19:06 (783615): Status Report: Job Duration: '864000.000000'
2020-02-25 17:19:06 (783615): Status Report: Elapsed Time: '66018.525331'
2020-02-25 17:19:06 (783615): Status Report: CPU Time: '58419.370000'
2020-02-25 18:59:06 (783615): Status Report: Job Duration: '864000.000000'
2020-02-25 18:59:06 (783615): Status Report: Elapsed Time: '72020.974090'
2020-02-25 18:59:06 (783615): Status Report: CPU Time: '63876.800000'
2020-02-25 20:39:04 (783615): Status Report: Job Duration: '864000.000000'
2020-02-25 20:39:04 (783615): Status Report: Elapsed Time: '78021.273710'
2020-02-25 20:39:04 (783615): Status Report: CPU Time: '69365.900000'
2020-02-25 21:20:12 (783615): Guest Log: job: run exitcode=0
2020-02-25 21:20:12 (783615): Guest Log: job: diskusage=7364
2020-02-25 21:20:12 (783615): Guest Log: job: logsize=92 k
2020-02-25 21:20:12 (783615): Guest Log: job: times=
2020-02-25 21:20:12 (783615): Guest Log: 0m0.015s 0m0.036s
2020-02-25 21:20:12 (783615): Guest Log: 1276m54.558s 27m30.887s
2020-02-25 21:20:12 (783615): Guest Log: job: cpuusage=78265
2020-02-25 21:20:12 (783615): Guest Log: 21:20:12 CET +01:00 2020-02-25: cranky: [INFO] Container 'runc' finished with status code 0.
2020-02-25 21:20:13 (783615): Guest Log: 21:20:12 CET +01:00 2020-02-25: cranky: [INFO] Preparing output.
2020-02-25 21:20:15 (783615): Guest Log: [INFO] Job Finished
2020-02-25 21:20:15 (783615): Guest Log: [INFO] Shutting Down.
2020-02-25 21:20:15 (783615): VM Completion File Detected.
2020-02-25 21:20:15 (783615): VM Completion Message: Job Finished
.
2020-02-25 21:20:15 (783615): Powering off VM.
2020-02-25 21:20:17 (783615): Successfully stopped VM.
2020-02-25 21:20:17 (783615): Deregistering VM. (boinc_b11aa6da257fdb10, slot#14)
2020-02-25 21:20:18 (783615): Removing network bandwidth throttle group from VM.
2020-02-25 21:20:18 (783615): Removing storage controller(s) from VM.
2020-02-25 21:20:18 (783615): Removing VM from VirtualBox.
2020-02-25 21:20:18 (783615): Removing virtual disk drive from VirtualBox.
21:20:24 (783615): called boinc_finish(0)

</stderr_txt>
]]>

©2024 CERN