Stderr output

<core_client_version>7.16.11</core_client_version>
<![CDATA[
<stderr_txt>
2021-02-28 23:15:19 (18376): Detected: vboxwrapper 26197
2021-02-28 23:15:19 (18376): Detected: BOINC client v7.7
2021-02-28 23:15:19 (18376): Detected: VirtualBox VboxManage Interface (Version: 6.1.12)
2021-02-28 23:15:20 (18376): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2021-02-28 23:15:20 (18376): Successfully copied 'init_data.xml' to the shared directory.
2021-02-28 23:15:20 (18376): Successfully copied 'input' to the shared directory.
2021-02-28 23:15:21 (18376): Create VM. (boinc_89633152a84c1ae6, slot#4)
2021-02-28 23:15:21 (18376): Setting Memory Size for VM. (630MB)
2021-02-28 23:15:22 (18376): Setting CPU Count for VM. (1)
2021-02-28 23:15:22 (18376): Setting Chipset Options for VM.
2021-02-28 23:15:23 (18376): Setting Boot Options for VM.
2021-02-28 23:15:23 (18376): Setting Network Configuration for NAT.
2021-02-28 23:15:23 (18376): Enabling VM Network Access.
2021-02-28 23:15:24 (18376): Disabling USB Support for VM.
2021-02-28 23:15:24 (18376): Disabling COM Port Support for VM.
2021-02-28 23:15:24 (18376): Disabling LPT Port Support for VM.
2021-02-28 23:15:24 (18376): Disabling Audio Support for VM.
2021-02-28 23:15:25 (18376): Disabling Clipboard Support for VM.
2021-02-28 23:15:25 (18376): Disabling Drag and Drop Support for VM.
2021-02-28 23:15:25 (18376): Adding storage controller(s) to VM.
2021-02-28 23:15:25 (18376): Adding virtual disk drive to VM. (vm_image.vdi)
2021-02-28 23:15:26 (18376): Adding VirtualBox Guest Additions to VM.
2021-02-28 23:15:27 (18376): Adding network bandwidth throttle group to VM. (Defaulting to 1024GB)
2021-02-28 23:15:27 (18376): forwarding host port 52283 to guest port 80
2021-02-28 23:15:27 (18376): Enabling remote desktop for VM.
2021-02-28 23:15:28 (18376): Enabling shared directory for VM.
2021-02-28 23:15:29 (18376): Starting VM using VBoxManage interface. (boinc_89633152a84c1ae6, slot#4)
2021-02-28 23:15:37 (18376): Successfully started VM. (PID = '18936')
2021-02-28 23:15:37 (18376): Reporting VM Process ID to BOINC.
2021-02-28 23:15:37 (18376): Guest Log: BIOS: VirtualBox 6.1.12

2021-02-28 23:15:37 (18376): Guest Log: CPUID EDX: 0x178bfbff

2021-02-28 23:15:37 (18376): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63

2021-02-28 23:15:37 (18376): VM state change detected. (old = 'PoweredOff', new = 'Running')
2021-02-28 23:15:37 (18376): Detected: Web Application Enabled (http://localhost:52283)
2021-02-28 23:15:37 (18376): Detected: Remote Desktop Enabled (localhost:52284)
2021-02-28 23:15:37 (18376): Preference change detected
2021-02-28 23:15:37 (18376): Setting CPU throttle for VM. (100%)
2021-02-28 23:15:38 (18376): Setting checkpoint interval to 1000 seconds. (Higher value of (Preference: 1000 seconds) or (Vbox_job.xml: 600 seconds))
2021-02-28 23:15:39 (18376): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032

2021-02-28 23:15:39 (18376): Guest Log: BIOS: Booting from Hard Disk...

2021-02-28 23:15:41 (18376): Guest Log: BIOS: KBD: unsupported int 16h function 03

2021-02-28 23:15:41 (18376): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 

2021-02-28 23:15:59 (18376): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds

2021-02-28 23:15:59 (18376): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)

2021-02-28 23:16:02 (18376): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log

2021-02-28 23:16:02 (18376): Guest Log: 00:00:00.000397 main     Log opened 2021-02-28T22:16:03.713355000Z

2021-02-28 23:16:02 (18376): Guest Log: 00:00:00.001006 main     OS Product: Linux

2021-02-28 23:16:02 (18376): Guest Log: 00:00:00.001086 main     OS Release: 4.14.76-13.cernvm.x86_64

2021-02-28 23:16:02 (18376): Guest Log: 00:00:00.001138 main     OS Version: #1 SMP Tue Oct 16 18:26:15 CEST 2018

2021-02-28 23:16:02 (18376): Guest Log: 00:00:00.001198 main     Executable: /usr/sbin/VBoxService

2021-02-28 23:16:02 (18376): Guest Log: 00:00:00.001199 main     Process ID: 3200

2021-02-28 23:16:02 (18376): Guest Log: 00:00:00.001200 main     Package type: LINUX_64BITS_GENERIC

2021-02-28 23:16:02 (18376): Guest Log: 00:00:00.004575 main     5.2.6 r120293 started. Verbose level = 0

2021-02-28 23:16:40 (18376): Guest Log: 23:16:40 CET +01:00 2021-02-28: cranky: [INFO] Detected Theory App

2021-02-28 23:16:40 (18376): Guest Log: 23:16:40 CET +01:00 2021-02-28: cranky: [INFO] Checking CVMFS.

2021-02-28 23:16:41 (18376): Guest Log: Probing /cvmfs/sft.cern.ch... OK

2021-02-28 23:16:42 (18376): 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-02-28 23:16:42 (18376): Guest Log: 2.5.2.0 4037 0 27220 19664 3 1 265427 4096000 0 65024 0 0 n/a 5 7 http://s1cern-cvmfs.openhtc.io/cvmfs/sft.cern.ch DIRECT 1

2021-02-28 23:16:44 (18376): Guest Log: Probing /cvmfs/grid.cern.ch... OK

2021-02-28 23:16:45 (18376): 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-02-28 23:16:45 (18376): Guest Log: 2.5.2.0 4112 0 27416 14563 3 2 265427 4096000 0 65024 0 2 -100 6415 771 http://s1cern-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 1

2021-02-28 23:16:47 (18376): Guest Log: Probing /cvmfs/cernvm-prod.cern.ch... OK

2021-02-28 23:16:48 (18376): 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-02-28 23:16:48 (18376): Guest Log: 2.5.2.0 4083 0 27228 261 3 1 265427 4096000 0 65024 0 0 n/a 4 6 http://s1unl-cvmfs.openhtc.io/cvmfs/cernvm-prod.cern.ch DIRECT 1

2021-02-28 23:16:50 (18376): Guest Log: Probing /cvmfs/alice.cern.ch... OK

2021-02-28 23:16:51 (18376): 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-02-28 23:16:51 (18376): Guest Log: 2.5.2.0 4059 0 31004 8737 3 1 265427 4096000 0 65024 0 0 n/a 4877 4583 http://s1ral-cvmfs.openhtc.io/cvmfs/alice.cern.ch DIRECT 1

2021-02-28 23:16:51 (18376): Guest Log: 23:16:52 CET +01:00 2021-02-28: cranky: [INFO] Checking runc.

2021-02-28 23:16:51 (18376): Guest Log: 23:16:52 CET +01:00 2021-02-28: cranky: [INFO] Creating the filesystem.

2021-02-28 23:16:51 (18376): Guest Log: 23:16:52 CET +01:00 2021-02-28: cranky: [INFO] Using /cvmfs/cernvm-prod.cern.ch/cvm3

2021-02-28 23:16:52 (18376): Guest Log: 23:16:52 CET +01:00 2021-02-28: cranky: [INFO] Updating config.json.

2021-02-28 23:16:52 (18376): Guest Log: 23:16:52 CET +01:00 2021-02-28: cranky: [INFO] Running Container 'runc'.

2021-02-28 23:16:55 (18376): Guest Log: job: htmld=/shared/html/job

2021-02-28 23:16:55 (18376): Guest Log: job: unpack exitcode=0

2021-02-28 23:16:56 (18376): Guest Log: 23:16:56 CET +01:00 2021-02-28: cranky: [INFO] ===> [runRivet] Sun Feb 28 22:16:56 UTC 2021 [boinc pp jets 7000 40,-,610 - pythia8 8.301 dire-default 31000 174]

2021-02-28 23:37:52 (18376): VM state change detected. (old = 'Running', new = 'Paused')
2021-03-01 01:29:59 (18376): VM state change detected. (old = 'Paused', new = 'Running')
2021-03-01 01:30:04 (18376): Guest Log: 00:21:30.462836 timesync vgsvcTimeSyncWorker: Radical host time change: 6 737 348 000 000ns (HostNow=1 614 558 604 052 000 000 ns HostLast=1 614 551 866 704 000 000 ns)

2021-03-01 01:30:15 (18376): Guest Log: 00:21:40.507575 timesync vgsvcTimeSyncWorker: Radical guest time change: 6 760 191 850 000ns (GuestNow=1 614 558 614 183 063 000 ns GuestLast=1 614 551 853 991 213 000 ns fSetTimeLastLoop=true )

2021-03-01 02:47:46 (18376): Status Report: Job Duration: '864000.000000'
2021-03-01 02:47:46 (18376): Status Report: Elapsed Time: '6000.000000'
2021-03-01 02:47:46 (18376): Status Report: CPU Time: '5848.664691'
2021-03-01 04:27:47 (18376): Status Report: Job Duration: '864000.000000'
2021-03-01 04:27:47 (18376): Status Report: Elapsed Time: '12000.000000'
2021-03-01 04:27:47 (18376): Status Report: CPU Time: '11848.634752'
2021-03-01 06:07:48 (18376): Status Report: Job Duration: '864000.000000'
2021-03-01 06:07:48 (18376): Status Report: Elapsed Time: '18000.000000'
2021-03-01 06:07:48 (18376): Status Report: CPU Time: '17849.150817'
2021-03-01 07:20:02 (18376): VM state change detected. (old = 'Running', new = 'Paused')
2021-03-01 19:20:01 (18376): VM state change detected. (old = 'Paused', new = 'Running')
2021-03-01 19:20:06 (18376): Guest Log: 06:05:05.478591 timesync vgsvcTimeSyncWorker: Radical host time change: 43 209 759 000 000ns (HostNow=1 614 622 806 764 000 000 ns HostLast=1 614 579 597 005 000 000 ns)

2021-03-01 19:20:16 (18376): Guest Log: 06:05:15.479548 timesync vgsvcTimeSyncWorker: Radical guest time change: 43 597 610 875 000ns (GuestNow=1 614 622 816 764 962 000 ns GuestLast=1 614 579 219 154 087 000 ns fSetTimeLastLoop=true )

2021-03-01 19:47:50 (18376): Status Report: Job Duration: '864000.000000'
2021-03-01 19:47:50 (18376): Status Report: Elapsed Time: '24000.000000'
2021-03-01 19:47:50 (18376): Status Report: CPU Time: '23856.499725'
2021-03-01 21:27:50 (18376): Status Report: Job Duration: '864000.000000'
2021-03-01 21:27:50 (18376): Status Report: Elapsed Time: '30000.000000'
2021-03-01 21:27:50 (18376): Status Report: CPU Time: '29847.998932'
2021-03-01 23:07:52 (18376): Status Report: Job Duration: '864000.000000'
2021-03-01 23:07:52 (18376): Status Report: Elapsed Time: '36000.000000'
2021-03-01 23:07:52 (18376): Status Report: CPU Time: '35811.527160'
2021-03-02 00:47:52 (18376): Status Report: Job Duration: '864000.000000'
2021-03-02 00:47:52 (18376): Status Report: Elapsed Time: '42000.000000'
2021-03-02 00:47:52 (18376): Status Report: CPU Time: '41799.890746'
2021-03-02 02:27:53 (18376): Status Report: Job Duration: '864000.000000'
2021-03-02 02:27:53 (18376): Status Report: Elapsed Time: '48000.000000'
2021-03-02 02:27:53 (18376): Status Report: CPU Time: '47785.602316'
2021-03-02 04:07:54 (18376): Status Report: Job Duration: '864000.000000'
2021-03-02 04:07:54 (18376): Status Report: Elapsed Time: '54000.000000'
2021-03-02 04:07:54 (18376): Status Report: CPU Time: '53777.491525'
2021-03-02 05:47:54 (18376): Status Report: Job Duration: '864000.000000'
2021-03-02 05:47:54 (18376): Status Report: Elapsed Time: '60000.000000'
2021-03-02 05:47:54 (18376): Status Report: CPU Time: '59776.899983'
2021-03-02 07:20:01 (18376): VM state change detected. (old = 'Running', new = 'Paused')
2021-03-02 19:20:01 (18376): Preference change detected
2021-03-02 19:20:01 (18376): Setting CPU throttle for VM. (100%)
2021-03-02 19:20:01 (18376): Setting checkpoint interval to 1000 seconds. (Higher value of (Preference: 1000 seconds) or (Vbox_job.xml: 600 seconds))
2021-03-02 19:20:02 (18376): VM state change detected. (old = 'Paused', new = 'Running')
2021-03-02 19:20:05 (18376): Guest Log: 17:51:44.990448 timesync vgsvcTimeSyncWorker: Radical host time change: 43 210 519 000 000ns (HostNow=1 614 709 204 502 000 000 ns HostLast=1 614 665 993 983 000 000 ns)

2021-03-02 19:20:15 (18376): Guest Log: 17:51:54.991405 timesync vgsvcTimeSyncWorker: Radical guest time change: 44 008 227 111 000ns (GuestNow=1 614 709 214 502 963 000 ns GuestLast=1 614 665 206 275 852 000 ns fSetTimeLastLoop=true )

2021-03-02 19:27:56 (18376): Status Report: Job Duration: '864000.000000'
2021-03-02 19:27:56 (18376): Status Report: Elapsed Time: '66000.000000'
2021-03-02 19:27:56 (18376): Status Report: CPU Time: '65770.910806'
2021-03-02 21:07:56 (18376): Status Report: Job Duration: '864000.000000'
2021-03-02 21:07:56 (18376): Status Report: Elapsed Time: '72000.000000'
2021-03-02 21:07:56 (18376): Status Report: CPU Time: '71767.090043'
2021-03-02 22:47:57 (18376): Status Report: Job Duration: '864000.000000'
2021-03-02 22:47:57 (18376): Status Report: Elapsed Time: '78000.000000'
2021-03-02 22:47:57 (18376): Status Report: CPU Time: '77757.419242'
2021-03-03 00:27:58 (18376): Status Report: Job Duration: '864000.000000'
2021-03-03 00:27:58 (18376): Status Report: Elapsed Time: '84000.000000'
2021-03-03 00:27:58 (18376): Status Report: CPU Time: '83753.972881'
2021-03-03 02:07:58 (18376): Status Report: Job Duration: '864000.000000'
2021-03-03 02:07:58 (18376): Status Report: Elapsed Time: '90000.000000'
2021-03-03 02:07:58 (18376): Status Report: CPU Time: '89750.167718'
2021-03-03 03:48:00 (18376): Status Report: Job Duration: '864000.000000'
2021-03-03 03:48:00 (18376): Status Report: Elapsed Time: '96000.000000'
2021-03-03 03:48:00 (18376): Status Report: CPU Time: '95746.643357'
2021-03-03 05:28:00 (18376): Status Report: Job Duration: '864000.000000'
2021-03-03 05:28:00 (18376): Status Report: Elapsed Time: '102000.000000'
2021-03-03 05:28:00 (18376): Status Report: CPU Time: '101744.757006'
2021-03-03 07:08:01 (18376): Status Report: Job Duration: '864000.000000'
2021-03-03 07:08:01 (18376): Status Report: Elapsed Time: '108000.000000'
2021-03-03 07:08:01 (18376): Status Report: CPU Time: '107744.805067'
2021-03-03 07:20:02 (18376): VM state change detected. (old = 'Running', new = 'Paused')
2021-03-03 19:20:00 (18376): Preference change detected
2021-03-03 19:20:00 (18376): Setting CPU throttle for VM. (100%)
2021-03-03 19:20:00 (18376): Setting checkpoint interval to 1000 seconds. (Higher value of (Preference: 1000 seconds) or (Vbox_job.xml: 600 seconds))
2021-03-03 19:20:01 (18376): Guest Log: 29:38:24.735455 timesync vgsvcTimeSyncWorker: Radical host time change: 43 209 358 000 000ns (HostNow=1 614 795 601 318 000 000 ns HostLast=1 614 752 391 960 000 000 ns)

2021-03-03 19:20:01 (18376): VM state change detected. (old = 'Paused', new = 'Running')
2021-03-03 19:20:12 (18376): Guest Log: 29:38:34.736441 timesync vgsvcTimeSyncWorker: Radical guest time change: 44 007 071 968 000ns (GuestNow=1 614 795 611 318 969 000 ns GuestLast=1 614 751 604 247 001 000 ns fSetTimeLastLoop=true )

2021-03-03 19:22:25 (18376): VM state change detected. (old = 'Running', new = 'Paused')
2021-03-08 19:20:02 (18376): Preference change detected
2021-03-08 19:20:02 (18376): Setting CPU throttle for VM. (100%)
2021-03-08 19:20:02 (18376): Setting checkpoint interval to 1000 seconds. (Higher value of (Preference: 1000 seconds) or (Vbox_job.xml: 600 seconds))
2021-03-08 19:20:02 (18376): VM state change detected. (old = 'Paused', new = 'Running')
2021-03-08 19:20:11 (18376): Guest Log: 29:40:54.760651 timesync vgsvcTimeSyncWorker: Radical host time change: 431 866 765 000 000ns (HostNow=1 615 227 610 747 000 000 ns HostLast=1 614 795 743 982 000 000 ns)

2021-03-08 19:20:22 (18376): Guest Log: 29:41:04.768568 timesync vgsvcTimeSyncWorker: Radical guest time change: 431 869 411 736 000ns (GuestNow=1 615 227 620 754 907 000 ns GuestLast=1 614 795 751 343 171 000 ns fSetTimeLastLoop=true )

2021-03-08 20:48:34 (18376): Status Report: Job Duration: '864000.000000'
2021-03-08 20:48:34 (18376): Status Report: Elapsed Time: '114000.517944'
2021-03-08 20:48:34 (18376): Status Report: CPU Time: '113896.891704'
2021-03-08 22:30:25 (18376): Status Report: Job Duration: '864000.000000'
2021-03-08 22:30:25 (18376): Status Report: Elapsed Time: '120000.706221'
2021-03-08 22:30:25 (18376): Status Report: CPU Time: '119983.411119'
2021-03-09 00:11:45 (18376): Status Report: Job Duration: '864000.000000'
2021-03-09 00:11:45 (18376): Status Report: Elapsed Time: '126000.713863'
2021-03-09 00:11:45 (18376): Status Report: CPU Time: '126041.397952'
2021-03-09 01:54:45 (18376): Status Report: Job Duration: '864000.000000'
2021-03-09 01:54:45 (18376): Status Report: Elapsed Time: '132001.451593'
2021-03-09 01:54:45 (18376): Status Report: CPU Time: '132198.398620'
2021-03-09 03:36:49 (18376): Status Report: Job Duration: '864000.000000'
2021-03-09 03:36:49 (18376): Status Report: Elapsed Time: '138001.629503'
2021-03-09 03:36:49 (18376): Status Report: CPU Time: '138298.022120'
2021-03-09 05:18:32 (18376): Status Report: Job Duration: '864000.000000'
2021-03-09 05:18:32 (18376): Status Report: Elapsed Time: '144001.714911'
2021-03-09 05:18:32 (18376): Status Report: CPU Time: '144375.337477'
2021-03-09 07:00:39 (18376): Status Report: Job Duration: '864000.000000'
2021-03-09 07:00:39 (18376): Status Report: Elapsed Time: '150002.696424'
2021-03-09 07:00:39 (18376): Status Report: CPU Time: '150479.001403'
2021-03-09 07:20:02 (18376): VM state change detected. (old = 'Running', new = 'Paused')
2021-03-09 19:20:02 (18376): VM state change detected. (old = 'Paused', new = 'Running')
2021-03-09 19:20:10 (18376): Guest Log: 41:27:35.670773 timesync vgsvcTimeSyncWorker: Radical host time change: 43 210 286 000 000ns (HostNow=1 615 314 009 648 000 000 ns HostLast=1 615 270 799 362 000 000 ns)

2021-03-09 19:20:20 (18376): Guest Log: 41:27:45.671485 timesync vgsvcTimeSyncWorker: Radical guest time change: 44 007 991 575 000ns (GuestNow=1 615 314 019 648 717 000 ns GuestLast=1 615 270 011 657 142 000 ns fSetTimeLastLoop=true )

2021-03-09 20:33:17 (18376): Guest Log: job: run exitcode=0

2021-03-09 20:33:17 (18376): Guest Log: job: diskusage=2532

2021-03-09 20:33:17 (18376): Guest Log: job: logsize=60 k

2021-03-09 20:33:17 (18376): Guest Log: job: times=

2021-03-09 20:33:17 (18376): Guest Log: 0m0.011s 0m0.021s

2021-03-09 20:33:17 (18376): Guest Log: 2514m22.603s 12m8.923s

2021-03-09 20:33:17 (18376): Guest Log: job: cpuusage=151592

2021-03-09 20:33:18 (18376): Guest Log: 20:31:57 CET +01:00 2021-03-09: cranky: [INFO] Container 'runc' finished with status code 0.

2021-03-09 20:33:18 (18376): Guest Log: 20:31:57 CET +01:00 2021-03-09: cranky: [INFO] Preparing output.

2021-03-09 20:33:20 (18376): Guest Log: [INFO] Job Finished

2021-03-09 20:33:20 (18376): Guest Log: [INFO] Shutting Down.

2021-03-09 20:33:20 (18376): VM Completion File Detected.
2021-03-09 20:33:20 (18376): VM Completion Message: Job Finished
.
2021-03-09 20:33:20 (18376): Powering off VM.
2021-03-09 20:38:21 (18376): VM did not power off when requested.
2021-03-09 20:38:21 (18376): VM was successfully terminated.
2021-03-09 20:38:21 (18376): Deregistering VM. (boinc_89633152a84c1ae6, slot#4)
2021-03-09 20:38:21 (18376): Removing network bandwidth throttle group from VM.
2021-03-09 20:38:21 (18376): Removing VM from VirtualBox.
20:38:27 (18376): called boinc_finish(0)

</stderr_txt>
]]>

©2024 CERN