Name CMS_3503297_1566688461.537727_0
Workunit 1922846
Created 24 Aug 2019, 23:14:23 UTC
Sent 26 Aug 2019, 3:43:25 UTC
Report deadline 2 Sep 2019, 3:43:25 UTC
Received 26 Aug 2019, 22:49:56 UTC
Server state Over
Outcome Computation error
Client state Compute error
Exit status 1 (0x00000001) Unknown error code
Computer ID 799
Run time 53 min 51 sec
CPU time 30 min 41 sec
Validate state Invalid
Credit 0.00
Device peak FLOPS 15.28 GFLOPS
Application version CMS Simulation v49.00 (vbox64_mt_mcore_cms)
windows_x86_64
Peak working set size 87.52 MB
Peak swap size 98.36 MB
Peak disk usage 3.00 GB

Stderr output

<core_client_version>7.14.2</core_client_version>
<![CDATA[
<message>
Incorrect function.
 (0x1) - exit code 1 (0x1)</message>
<stderr_txt>
2019-08-26 05:44:10 (1532): Detected: vboxwrapper 26197
2019-08-26 05:44:10 (1532): Detected: BOINC client v7.7
2019-08-26 05:44:12 (1532): Detected: VirtualBox VboxManage Interface (Version: 5.2.8)
2019-08-26 05:44:12 (1532): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2019-08-26 05:44:12 (1532): Successfully copied 'init_data.xml' to the shared directory.
2019-08-26 05:44:14 (1532): Create VM. (boinc_41e91aa9fa2d839f, slot#2)
2019-08-26 05:44:14 (1532): Setting Memory Size for VM. (4584MB)
2019-08-26 05:44:15 (1532): Setting CPU Count for VM. (4)
2019-08-26 05:44:15 (1532): Setting Chipset Options for VM.
2019-08-26 05:44:15 (1532): Setting Boot Options for VM.
2019-08-26 05:44:16 (1532): Setting Network Configuration for NAT.
2019-08-26 05:44:16 (1532): Enabling VM Network Access.
2019-08-26 05:44:16 (1532): Disabling USB Support for VM.
2019-08-26 05:44:16 (1532): Disabling COM Port Support for VM.
2019-08-26 05:44:17 (1532): Disabling LPT Port Support for VM.
2019-08-26 05:44:17 (1532): Disabling Audio Support for VM.
2019-08-26 05:44:17 (1532): Disabling Clipboard Support for VM.
2019-08-26 05:44:18 (1532): Disabling Drag and Drop Support for VM.
2019-08-26 05:44:18 (1532): Adding storage controller(s) to VM.
2019-08-26 05:44:18 (1532): Adding virtual disk drive to VM. (vm_image.vdi)
2019-08-26 05:44:19 (1532): Adding VirtualBox Guest Additions to VM.
2019-08-26 05:44:19 (1532): Adding network bandwidth throttle group to VM. (Defaulting to 1024GB)
2019-08-26 05:44:19 (1532): forwarding host port 51614 to guest port 80
2019-08-26 05:44:20 (1532): Enabling remote desktop for VM.
2019-08-26 05:44:20 (1532): Required extension pack not installed, remote desktop not enabled.
2019-08-26 05:44:20 (1532): Enabling shared directory for VM.
2019-08-26 05:44:20 (1532): Starting VM using VBoxManage interface. (boinc_41e91aa9fa2d839f, slot#2)
2019-08-26 05:44:26 (1532): Successfully started VM. (PID = '4268')
2019-08-26 05:44:26 (1532): Reporting VM Process ID to BOINC.
2019-08-26 05:44:26 (1532): Guest Log: BIOS: VirtualBox 5.2.8

2019-08-26 05:44:26 (1532): Guest Log: CPUID EDX: 0x178bfbff

2019-08-26 05:44:26 (1532): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63

2019-08-26 05:44:26 (1532): VM state change detected. (old = 'PoweredOff', new = 'Running')
2019-08-26 05:44:26 (1532): Detected: Web Application Enabled (http://localhost:51614)
2019-08-26 05:44:26 (1532): Preference change detected
2019-08-26 05:44:26 (1532): Setting CPU throttle for VM. (60%)
2019-08-26 05:44:26 (1532): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2019-08-26 05:44:28 (1532): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032

2019-08-26 05:44:28 (1532): Guest Log: BIOS: Booting from Hard Disk...

2019-08-26 05:44:30 (1532): Guest Log: BIOS: KBD: unsupported int 16h function 03

2019-08-26 05:44:30 (1532): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 

2019-08-26 05:45:36 (1532): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds

2019-08-26 05:45:36 (1532): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)

2019-08-26 05:46:58 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 05:49:59 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 05:50:17 (1532): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log

2019-08-26 05:50:17 (1532): Guest Log: 00:00:00.001513 main     Log opened 2019-08-26T03:47:13.415039000Z

2019-08-26 05:50:17 (1532): Guest Log: 00:00:00.002216 main     OS Product: Linux

2019-08-26 05:50:17 (1532): Guest Log: 00:00:00.002291 main     OS Release: 4.14.44-11.cernvm.x86_64

2019-08-26 05:50:17 (1532): Guest Log: 00:00:00.002354 main     OS Version: #1 SMP Mon May 28 16:49:00 CEST 2018

2019-08-26 05:50:17 (1532): Guest Log: 00:00:00.002405 main     Executable: /usr/share/vboxguest52/usr/sbin/VBoxService

2019-08-26 05:50:17 (1532): Guest Log: 00:00:00.002405 main     Process ID: 3063

2019-08-26 05:50:17 (1532): Guest Log: 00:00:00.002406 main     Package type: LINUX_64BITS_GENERIC

2019-08-26 05:50:17 (1532): Guest Log: 00:00:00.004776 main     5.2.6 r120293 started. Verbose level = 0

2019-08-26 05:51:26 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 05:53:06 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 05:53:09 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 05:58:53 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 06:00:07 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 06:11:52 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 06:13:09 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 06:16:20 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 06:16:35 (1532): Guest Log: [INFO] Mounting the shared directory

2019-08-26 06:16:36 (1532): Guest Log: [INFO] Shared directory mounted, enabling vboxmonitor

2019-08-26 06:16:36 (1532): Guest Log: [DEBUG] Testing network connection to cern.ch on port 80

2019-08-26 06:16:42 (1532): Guest Log: [DEBUG] Connection to cern.ch 80 port [tcp/http] succeeded!

2019-08-26 06:16:42 (1532): Guest Log: [DEBUG] 0

2019-08-26 06:16:42 (1532): Guest Log: [DEBUG] Testing VCCS connection to vccs.cern.ch on port 443

2019-08-26 06:16:48 (1532): Guest Log: [DEBUG] Connection to vccs.cern.ch 443 port [tcp/https] succeeded!

2019-08-26 06:16:48 (1532): Guest Log: [DEBUG] 0

2019-08-26 06:16:48 (1532): Guest Log: [DEBUG] Testing connection to Condor server on port 9618

2019-08-26 06:16:54 (1532): Guest Log: [DEBUG] Connection to vccondor01.cern.ch 9618 port [tcp/condor] succeeded!

2019-08-26 06:16:54 (1532): Guest Log: [DEBUG] 0

2019-08-26 06:17:39 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 06:18:49 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 06:18:59 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 06:19:29 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 06:19:39 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 06:25:49 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 06:27:02 (1532): Guest Log: [DEBUG] Probing CVMFS ...

2019-08-26 06:27:22 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 06:30:24 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 06:30:47 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 06:33:48 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 06:33:53 (1532): Guest Log: Probing /cvmfs/grid.cern.ch... OK

2019-08-26 06:34:14 (1532): 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

2019-08-26 06:34:14 (1532): Guest Log: 2.4.4.0 3819 26 27836 10081 2 1 1454385 10240001 2 65024 0 3 100 0 0 http://s1cern-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 0

2019-08-26 06:34:25 (1532): Guest Log: [INFO] Reading volunteer information

2019-08-26 06:34:27 (1532): Guest Log: [INFO] Volunteer: SquirrelCmD (322)

2019-08-26 06:34:28 (1532): Guest Log: [INFO] VMID: c5ab4400-4ef6-44a9-aaed-bee78432355d

2019-08-26 06:34:31 (1532): Guest Log: [INFO] Requesting an X509 credential from LHC@home

2019-08-26 06:34:37 (1532): Guest Log: [INFO] Requesting an X509 credential from vLHC@home-dev

2019-08-26 06:34:48 (1532): Guest Log: [INFO] Running the fast benchmark.

2019-08-26 06:35:11 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 06:36:51 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 06:37:11 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 06:43:22 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 06:44:32 (1532): Guest Log: [INFO] Machine performance 18.66 HEPSPEC06

2019-08-26 06:44:32 (1532): Guest Log: [INFO] CMS application starting. Check log files.

2019-08-26 06:44:45 (1532): Guest Log: [DEBUG] HTCondor ping

2019-08-26 06:45:09 (1532): Guest Log: [DEBUG] 0

2019-08-26 06:45:44 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 06:48:45 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 06:49:43 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 06:52:46 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 06:52:48 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 06:55:48 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 06:57:03 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 07:07:06 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 07:08:23 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 07:19:45 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 07:21:05 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 07:34:04 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 07:34:23 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 07:37:23 (1532): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 07:38:34 (1532): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 07:38:41 (1532): Stopping VM.
2019-08-26 07:38:44 (1532): Error in stop VM for VM: -108
Command:
VBoxManage -q controlvm "boinc_41e91aa9fa2d839f" savestate
Output:
0%...10%...20%...
2019-08-26 07:38:44 (1532): VM did not stop when requested.
2019-08-26 07:38:44 (1532): VM was NOT successfully terminated.
2019-08-26 23:10:13 (6756): Detected: vboxwrapper 26197
2019-08-26 23:10:13 (6756): Detected: BOINC client v7.7
2019-08-26 23:10:15 (6756): Detected: VirtualBox VboxManage Interface (Version: 5.2.8)
2019-08-26 23:10:15 (6756): Detected: Heartbeat check (file: 'heartbeat' every 1200.000000 seconds)
2019-08-26 23:10:15 (6756): Starting VM using VBoxManage interface. (boinc_41e91aa9fa2d839f, slot#2)
2019-08-26 23:10:20 (6756): Successfully started VM. (PID = '3316')
2019-08-26 23:10:20 (6756): Reporting VM Process ID to BOINC.
2019-08-26 23:10:20 (6756): Guest Log: BIOS: VirtualBox 5.2.8

2019-08-26 23:10:20 (6756): Guest Log: CPUID EDX: 0x178bfbff

2019-08-26 23:10:20 (6756): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63

2019-08-26 23:10:20 (6756): VM state change detected. (old = 'PoweredOff', new = 'Running')
2019-08-26 23:10:20 (6756): Detected: Web Application Enabled (http://localhost:51614)
2019-08-26 23:10:20 (6756): Preference change detected
2019-08-26 23:10:20 (6756): Setting CPU throttle for VM. (60%)
2019-08-26 23:10:21 (6756): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2019-08-26 23:10:22 (6756): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032

2019-08-26 23:10:22 (6756): Guest Log: BIOS: Booting from Hard Disk...

2019-08-26 23:10:25 (6756): Guest Log: BIOS: KBD: unsupported int 16h function 03

2019-08-26 23:10:25 (6756): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 

2019-08-26 23:10:43 (6756): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 23:22:17 (6756): Preference change detected
2019-08-26 23:22:17 (6756): Setting CPU throttle for VM. (60%)
2019-08-26 23:22:18 (6756): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2019-08-26 23:22:18 (6756): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 23:23:14 (6756): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds

2019-08-26 23:23:14 (6756): Guest Log: vboxguest: misc device minor 56, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)

2019-08-26 23:23:23 (6756): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 23:24:03 (6756): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 23:25:02 (6756): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 23:35:49 (6756): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 23:36:11 (6756): Guest Log: VBoxService 5.2.6 r120293 (verbosity: 0) linux.amd64 (Jan 15 2018 14:51:00) release log

2019-08-26 23:36:11 (6756): Guest Log: 00:00:00.001808 main     Log opened 2019-08-26T21:25:22.039212000Z

2019-08-26 23:36:11 (6756): Guest Log: 00:00:00.002379 main     OS Product: Linux

2019-08-26 23:36:11 (6756): Guest Log: 00:00:00.002446 main     OS Release: 4.14.44-11.cernvm.x86_64

2019-08-26 23:36:11 (6756): Guest Log: 00:00:00.002510 main     OS Version: #1 SMP Mon May 28 16:49:00 CEST 2018

2019-08-26 23:36:11 (6756): Guest Log: 00:00:00.002677 main     Executable: /usr/share/vboxguest52/usr/sbin/VBoxService

2019-08-26 23:36:11 (6756): Guest Log: 00:00:00.002678 main     Process ID: 3000

2019-08-26 23:36:11 (6756): Guest Log: 00:00:00.002679 main     Package type: LINUX_64BITS_GENERIC

2019-08-26 23:36:11 (6756): Guest Log: 00:00:00.005305 main     5.2.6 r120293 started. Verbose level = 0

2019-08-26 23:38:47 (6756): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 23:43:16 (6756): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 23:44:14 (6756): Guest Log: [INFO] Mounting the shared directory

2019-08-26 23:44:15 (6756): Guest Log: [INFO] Shared directory mounted, enabling vboxmonitor

2019-08-26 23:44:15 (6756): Guest Log: [DEBUG] Testing network connection to cern.ch on port 80

2019-08-26 23:44:21 (6756): Guest Log: [DEBUG] Connection to cern.ch 80 port [tcp/http] succeeded!

2019-08-26 23:44:21 (6756): Guest Log: [DEBUG] 0

2019-08-26 23:44:21 (6756): Guest Log: [DEBUG] Testing VCCS connection to vccs.cern.ch on port 443

2019-08-26 23:44:27 (6756): Guest Log: [DEBUG] Connection to vccs.cern.ch 443 port [tcp/https] succeeded!

2019-08-26 23:44:27 (6756): Guest Log: [DEBUG] 0

2019-08-26 23:44:27 (6756): Guest Log: [DEBUG] Testing connection to Condor server on port 9618

2019-08-26 23:44:33 (6756): Guest Log: [DEBUG] Connection to vccondor01.cern.ch 9618 port [tcp/condor] succeeded!

2019-08-26 23:44:33 (6756): Guest Log: [DEBUG] 0

2019-08-26 23:44:57 (6756): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-26 23:50:41 (6756): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-26 23:52:29 (6756): Guest Log: [DEBUG] Probing CVMFS ...

2019-08-26 23:53:09 (6756): Guest Log: Probing /cvmfs/grid.cern.ch... OK

2019-08-26 23:53:28 (6756): 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

2019-08-26 23:53:28 (6756): Guest Log: 2.4.4.0 3726 3 27808 10087 3 1 1455278 10240000 2 65024 0 3 100 0 0 http://s1cern-cvmfs.openhtc.io/cvmfs/grid.cern.ch DIRECT 0

2019-08-26 23:53:35 (6756): Guest Log: [INFO] Reading volunteer information

2019-08-26 23:53:38 (6756): Guest Log: [INFO] Volunteer: SquirrelCmD (322)

2019-08-26 23:53:38 (6756): Guest Log: [INFO] VMID: c5ab4400-4ef6-44a9-aaed-bee78432355d

2019-08-26 23:53:42 (6756): Guest Log: [INFO] Requesting an X509 credential from LHC@home

2019-08-26 23:53:48 (6756): Guest Log: [INFO] Requesting an X509 credential from vLHC@home-dev

2019-08-26 23:54:10 (6756): Guest Log: [INFO] Running the fast benchmark.

2019-08-26 23:55:59 (6756): Guest Log: [INFO] Machine performance 19.11 HEPSPEC06

2019-08-26 23:55:59 (6756): Guest Log: [INFO] CMS application starting. Check log files.

2019-08-26 23:56:11 (6756): Guest Log: [DEBUG] HTCondor ping

2019-08-26 23:56:28 (6756): Guest Log: [DEBUG] 0

2019-08-26 23:59:59 (6756): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-27 00:03:09 (6756): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-27 00:04:26 (6756): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-27 00:11:33 (6756): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-27 00:11:34 (6756): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-27 00:17:05 (6756): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-27 00:17:33 (6756): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-27 00:20:34 (6756): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-27 00:28:23 (6756): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-27 00:31:24 (6756): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-27 00:33:02 (6756): VM state change detected. (old = 'Running', new = 'Paused')
2019-08-27 00:39:36 (6756): VM state change detected. (old = 'Paused', new = 'Running')
2019-08-27 00:42:47 (6756): Guest Log: [ERROR] Condor ended after 2629 seconds.

2019-08-27 00:42:47 (6756): Guest Log: [INFO] Shutting Down.

2019-08-27 00:42:47 (6756): VM Completion File Detected.
2019-08-27 00:42:47 (6756): VM Completion Message: Condor ended after 2629 seconds.
.
2019-08-27 00:42:47 (6756): Powering off VM.
2019-08-27 00:47:48 (6756): VM did not power off when requested.
2019-08-27 00:47:48 (6756): VM was successfully terminated.
2019-08-27 00:47:48 (6756): Deregistering VM. (boinc_41e91aa9fa2d839f, slot#2)
2019-08-27 00:47:49 (6756): Removing network bandwidth throttle group from VM.
2019-08-27 00:47:49 (6756): Removing VM from VirtualBox.
00:47:54 (6756): called boinc_finish(1)

</stderr_txt>
]]>


©2024 CERN