| Name | JS9LDmN8nx6n9Rq4apOajLDm4fhM0noT9bVoFjIUDmMiJKDmLUS5cn_0 |
| Workunit | 230072197 |
| Created | 30 Jan 2025, 18:08:08 UTC |
| Sent | 30 Jan 2025, 21:25:45 UTC |
| Report deadline | 7 Feb 2025, 21:25:45 UTC |
| Received | 1 Feb 2025, 4:28:55 UTC |
| Server state | Over |
| Outcome | Success |
| Client state | Done |
| Exit status | 0 (0x00000000) |
| Computer ID | 10825486 |
| Run time | 16 hours 0 min 6 sec |
| CPU time | 1 days 10 hours 45 min 45 sec |
| Validate state | Valid |
| Credit | 5,311.22 |
| Device peak FLOPS | 15.97 GFLOPS |
| Application version | ATLAS Simulation v3.01 (vbox64_mt_mcore_atlas) windows_x86_64 |
| Peak working set size | 91.53 MB |
| Peak swap size | 88.67 MB |
| Peak disk usage | 2.92 GB |
Stderr output
<core_client_version>8.0.2</core_client_version> <![CDATA[ <stderr_txt> 2025-01-31 07:29:45 (27024): Detected: vboxwrapper 26206 2025-01-31 07:29:45 (27024): Detected: BOINC client v8.0.2 2025-01-31 07:29:45 (27024): Detected: VirtualBox VboxManage Interface (Version: 7.0.20) 2025-01-31 07:29:46 (27024): Successfully copied 'init_data.xml' to the shared directory. 2025-01-31 07:29:46 (27024): Create VM. (boinc_c4d94cf2229587eb, slot#2) 2025-01-31 07:29:47 (27024): Setting Memory Size for VM. (4300MB) 2025-01-31 07:29:47 (27024): Setting CPU Count for VM. (3) 2025-01-31 07:29:47 (27024): Setting Chipset Options for VM. 2025-01-31 07:29:47 (27024): Setting Graphics Controller Options for VM. 2025-01-31 07:29:48 (27024): Setting Boot Options for VM. 2025-01-31 07:29:48 (27024): Setting Network Configuration for NAT. 2025-01-31 07:29:48 (27024): Enabling VM Network Access. 2025-01-31 07:29:48 (27024): Disabling USB Support for VM. 2025-01-31 07:29:49 (27024): Disabling COM Port Support for VM. 2025-01-31 07:29:49 (27024): Disabling LPT Port Support for VM. 2025-01-31 07:29:49 (27024): Disabling Audio Support for VM. 2025-01-31 07:29:49 (27024): Disabling Clipboard Support for VM. 2025-01-31 07:29:50 (27024): Disabling Drag and Drop Support for VM. 2025-01-31 07:29:50 (27024): Adding storage controller(s) to VM. 2025-01-31 07:29:50 (27024): Adding virtual disk drive to VM. (ATLAS_vbox_3.01_image.vdi) 2025-01-31 07:29:51 (27024): Adding VirtualBox Guest Additions to VM. 2025-01-31 07:29:51 (27024): Adding network bandwidth throttle group to VM. (Defaulting to 1024GB) 2025-01-31 07:29:51 (27024): forwarding host port 55550 to guest port 80 2025-01-31 07:29:52 (27024): Enabling remote desktop for VM. 2025-01-31 07:29:52 (27024): Required extension pack not installed, remote desktop not enabled. 2025-01-31 07:29:52 (27024): Enabling shared directory for VM. 2025-01-31 07:29:52 (27024): Starting VM using VBoxManage interface. (boinc_c4d94cf2229587eb, slot#2) 2025-01-31 07:29:58 (27024): Successfully started VM. (PID = '21156') 2025-01-31 07:29:58 (27024): Reporting VM Process ID to BOINC. 2025-01-31 07:29:58 (27024): Guest Log: BIOS: VirtualBox 7.0.20 2025-01-31 07:29:58 (27024): Guest Log: CPUID EDX: 0x178bfbff 2025-01-31 07:29:58 (27024): Guest Log: BIOS: No PCI IDE controller, not probing IDE 2025-01-31 07:29:58 (27024): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors 2025-01-31 07:29:58 (27024): VM state change detected. (old = 'poweredoff', new = 'running') 2025-01-31 07:29:58 (27024): Detected: Web Application Enabled (http://localhost:55550) 2025-01-31 07:29:58 (27024): Preference change detected 2025-01-31 07:29:58 (27024): Setting CPU throttle for VM. (75%) 2025-01-31 07:29:59 (27024): Setting checkpoint interval to 900 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 900 seconds)) 2025-01-31 07:30:00 (27024): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032 2025-01-31 07:30:00 (27024): Guest Log: BIOS: Booting from Hard Disk... 2025-01-31 07:30:03 (27024): Guest Log: BIOS: KBD: unsupported int 16h function 03 2025-01-31 07:30:03 (27024): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=81 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=81 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=82 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=82 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=83 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=83 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=84 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=84 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=85 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=85 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=86 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=86 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=87 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=87 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=88 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=88 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=89 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=89 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8a 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8a 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8b 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8b 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8c 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8c 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8d 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8d 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8e 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8e 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8f 2025-01-31 07:30:03 (27024): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8f 2025-01-31 07:30:12 (27024): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds 2025-01-31 07:30:12 (27024): Guest Log: vboxguest: misc device minor 58, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000) 2025-01-31 07:30:23 (27024): Guest Log: VBoxService 5.2.32 r132073 (verbosity: 0) linux.amd64 (Jul 12 2019 10:32:28) release log 2025-01-31 07:30:23 (27024): Guest Log: 00:00:00.000253 main Log opened 2025-01-31T07:30:21.025004000Z 2025-01-31 07:30:23 (27024): Guest Log: 00:00:00.000497 main OS Product: Linux 2025-01-31 07:30:23 (27024): Guest Log: 00:00:00.000552 main OS Release: 3.10.0-957.27.2.el7.x86_64 2025-01-31 07:30:23 (27024): Guest Log: 00:00:00.000575 main OS Version: #1 SMP Mon Jul 29 17:46:05 UTC 2019 2025-01-31 07:30:23 (27024): Guest Log: 00:00:00.000596 main Executable: /opt/VBoxGuestAdditions-5.2.32/sbin/VBoxService 2025-01-31 07:30:23 (27024): Guest Log: 00:00:00.000597 main Process ID: 1283 2025-01-31 07:30:23 (27024): Guest Log: 00:00:00.000597 main Package type: LINUX_64BITS_GENERIC 2025-01-31 07:30:23 (27024): Guest Log: 00:00:00.001736 main 5.2.32 r132073 started. Verbose level = 0 2025-01-31 07:30:23 (27024): Guest Log: [INFO] Probing /cvmfs/atlas.cern.ch... 2025-01-31 07:30:23 (27024): Guest Log: [INFO] Mounting shared directory 2025-01-31 07:30:23 (27024): Guest Log: [INFO] Checking for init_data.xml 2025-01-31 07:30:29 (27024): Guest Log: [INFO] Probing /cvmfs/atlas.cern.ch... OK 2025-01-31 07:30:29 (27024): Guest Log: [INFO] Detected branch: prod 2025-01-31 07:30:29 (27024): Guest Log: This is the prod version of the ATLAS job wrapper 2025-01-31 07:30:29 (27024): Guest Log: Copying input files 2025-01-31 07:30:31 (27024): Guest Log: Copied input files into RunAtlas. 2025-01-31 07:30:31 (27024): Guest Log: This VM did not configure a local http proxy via BOINC. 2025-01-31 07:30:31 (27024): Guest Log: Small home clusters do not require a local http proxy but it is suggested if 2025-01-31 07:30:31 (27024): Guest Log: more than 10 cores throughout the same LAN segment are regularly running ATLAS like tasks. 2025-01-31 07:30:31 (27024): Guest Log: Further information can be found at the LHC@home message board. 2025-01-31 07:30:33 (27024): Guest Log: 00:00:10.007014 timesync vgsvcTimeSyncWorker: Radical guest time change: -3 587 800 998 000ns (GuestNow=1 738 305 033 229 849 000 ns GuestLast=1 738 308 621 030 847 000 ns fSetTimeLastLoop=true ) 2025-01-31 07:30:41 (27024): Guest Log: Running cvmfs_config stat atlas.cern.ch 2025-01-31 07:30:44 (27024): 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 2025-01-31 07:30:44 (27024): Guest Log: 2.6.3.0 1559 0 30016 142162 4 1 3117296 4096000 0 65024 0 0 n/a 0 0 http://s1fnal-cvmfs.openhtc.io:8080/cvmfs/atlas.cern.ch DIRECT 1 2025-01-31 07:30:47 (27024): Guest Log: copied the webapp to /var/www 2025-01-31 07:30:47 (27024): Guest Log: ATHENA_PROC_NUMBER=3 2025-01-31 07:30:47 (27024): Guest Log: ATHENA_CORE_NUMBER=3 2025-01-31 07:30:47 (27024): Guest Log: Apptainer command /cvmfs/atlas.cern.ch/repo/containers/sw/apptainer/x86_64-el7/current/bin/apptainer exec -B /cvmfs,/data,/home/atlas/RunAtlas /cvmfs/atlas.cern.ch/repo/containers/fs/singularity/x86_64-centos7 2025-01-31 07:30:47 (27024): Guest Log: *** Starting ATLAS job. (PandaID=6495987081 taskID=43092792) *** 2025-01-31 08:33:25 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 08:46:59 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 09:23:40 (27024): Status Report: Elapsed Time: '6000.000000' 2025-01-31 09:23:40 (27024): Status Report: CPU Time: '11169.265625' 2025-01-31 09:27:24 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 09:31:43 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 09:31:57 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 10:11:17 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 10:11:19 (27024): Guest Log: 01:43:44.519548 timesync vgsvcTimeSyncWorker: Radical host time change: 2 369 742 000 000ns (HostNow=1 738 314 679 018 000 000 ns HostLast=1 738 312 309 276 000 000 ns) 2025-01-31 10:11:29 (27024): Guest Log: 01:43:54.525882 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 441 282 119 000ns (GuestNow=1 738 314 689 024 451 000 ns GuestLast=1 738 311 247 742 332 000 ns fSetTimeLastLoop=true ) 2025-01-31 10:11:39 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 10:17:43 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 10:18:18 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 10:25:01 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 10:27:02 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 10:28:17 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 10:30:57 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 10:36:01 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 10:42:18 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 11:09:04 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 11:09:22 (27024): Guest Log: 01:55:55.209941 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 762 049 503 000ns (GuestNow=1 738 318 161 754 001 000 ns GuestLast=1 738 315 399 704 498 000 ns fSetTimeLastLoop=true ) 2025-01-31 11:09:52 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 11:30:44 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 12:24:03 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 12:34:11 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 12:36:10 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 12:37:23 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 12:40:10 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 12:53:11 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 12:54:35 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 13:08:17 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 13:11:22 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 13:19:10 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 13:19:45 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 13:24:55 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 13:26:55 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 13:28:14 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 13:31:54 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 13:34:15 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 13:36:16 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 13:38:30 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 13:51:23 (27024): Status Report: Elapsed Time: '12000.000000' 2025-01-31 13:51:23 (27024): Status Report: CPU Time: '24748.546875' 2025-01-31 14:38:03 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 14:38:24 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 14:47:05 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 14:47:25 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 14:57:58 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 14:58:18 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 15:11:20 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 15:40:26 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 15:40:41 (27024): Guest Log: 04:39:23.542699 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 476 789 855 000ns (GuestNow=1 738 334 440 511 799 000 ns GuestLast=1 738 331 963 721 944 000 ns fSetTimeLastLoop=true ) 2025-01-31 16:01:43 (27024): Status Report: Elapsed Time: '18000.000000' 2025-01-31 16:01:43 (27024): Status Report: CPU Time: '38310.906250' 2025-01-31 16:03:04 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 16:03:24 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 16:03:49 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 16:08:49 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 16:12:07 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 16:12:36 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 16:13:18 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 16:45:01 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 16:45:03 (27024): Guest Log: 05:06:15.178881 timesync vgsvcTimeSyncWorker: Radical host time change: 1 913 070 000 000ns (HostNow=1 738 338 303 234 000 000 ns HostLast=1 738 336 390 164 000 000 ns) 2025-01-31 16:45:13 (27024): Guest Log: 05:06:25.181702 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 261 088 896 000ns (GuestNow=1 738 338 313 236 850 000 ns GuestLast=1 738 336 052 147 954 000 ns fSetTimeLastLoop=true ) 2025-01-31 17:09:31 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 17:09:53 (27024): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 18:19:48 (27024): Status Report: Elapsed Time: '24000.000000' 2025-01-31 18:19:48 (27024): Status Report: CPU Time: '51874.734375' 2025-01-31 19:03:22 (27024): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 19:04:30 (27024): VM state change detected. (old = 'paused', new = 'stopping') 2025-01-31 19:04:30 (27024): Stopping VM. 2025-01-31 19:04:31 (27024): Error in stop VM for VM: -108 Command: VBoxManage -q controlvm "boinc_c4d94cf2229587eb" savestate Output: 2025-01-31 19:04:31 (27024): VM did not stop when requested. 2025-01-31 19:04:31 (27024): VM was NOT successfully terminated. 2025-01-31 20:14:59 (24596): Detected: vboxwrapper 26206 2025-01-31 20:14:59 (24596): Detected: BOINC client v8.0.2 2025-01-31 20:15:00 (24596): Detected: VirtualBox VboxManage Interface (Version: 7.0.20) 2025-01-31 20:15:00 (24596): Register VM. (boinc_c4d94cf2229587eb, slot#2) 2025-01-31 20:15:01 (24596): Guest Log: BIOS: VirtualBox 7.0.20 2025-01-31 20:15:01 (24596): Guest Log: CPUID EDX: 0x178bfbff 2025-01-31 20:15:01 (24596): Guest Log: BIOS: No PCI IDE controller, not probing IDE 2025-01-31 20:15:01 (24596): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors 2025-01-31 20:15:01 (24596): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032 2025-01-31 20:15:01 (24596): Guest Log: BIOS: Booting from Hard Disk... 2025-01-31 20:15:01 (24596): Guest Log: BIOS: KBD: unsupported int 16h function 03 2025-01-31 20:15:01 (24596): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=81 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=81 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=82 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=82 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=83 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=83 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=84 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=84 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=85 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=85 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=86 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=86 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=87 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=87 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=88 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=88 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=89 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=89 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8a 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8a 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8b 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8b 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8c 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8c 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8d 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8d 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8e 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8e 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8f 2025-01-31 20:15:01 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8f 2025-01-31 20:15:01 (24596): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds 2025-01-31 20:15:01 (24596): Guest Log: vboxguest: misc device minor 58, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000) 2025-01-31 20:15:01 (24596): Guest Log: VBoxService 5.2.32 r132073 (verbosity: 0) linux.amd64 (Jul 12 2019 10:32:28) release log 2025-01-31 20:15:01 (24596): Guest Log: 00:00:00.000253 main Log opened 2025-01-31T07:30:21.025004000Z 2025-01-31 20:15:01 (24596): Guest Log: 00:00:00.000497 main OS Product: Linux 2025-01-31 20:15:01 (24596): Guest Log: 00:00:00.000552 main OS Release: 3.10.0-957.27.2.el7.x86_64 2025-01-31 20:15:01 (24596): Guest Log: 00:00:00.000575 main OS Version: #1 SMP Mon Jul 29 17:46:05 UTC 2019 2025-01-31 20:15:01 (24596): Guest Log: 00:00:00.000596 main Executable: /opt/VBoxGuestAdditions-5.2.32/sbin/VBoxService 2025-01-31 20:15:01 (24596): Guest Log: 00:00:00.000597 main Process ID: 1283 2025-01-31 20:15:01 (24596): Guest Log: 00:00:00.000597 main Package type: LINUX_64BITS_GENERIC 2025-01-31 20:15:01 (24596): Guest Log: 00:00:00.001736 main 5.2.32 r132073 started. Verbose level = 0 2025-01-31 20:15:01 (24596): Guest Log: [INFO] Probing /cvmfs/atlas.cern.ch... 2025-01-31 20:15:01 (24596): Guest Log: [INFO] Mounting shared directory 2025-01-31 20:15:01 (24596): Guest Log: [INFO] Checking for init_data.xml 2025-01-31 20:15:01 (24596): Guest Log: [INFO] Probing /cvmfs/atlas.cern.ch... OK 2025-01-31 20:15:01 (24596): Guest Log: [INFO] Detected branch: prod 2025-01-31 20:15:01 (24596): Guest Log: This is the prod version of the ATLAS job wrapper 2025-01-31 20:15:01 (24596): Guest Log: Copying input files 2025-01-31 20:15:01 (24596): Guest Log: Copied input files into RunAtlas. 2025-01-31 20:15:01 (24596): Guest Log: This VM did not configure a local http proxy via BOINC. 2025-01-31 20:15:01 (24596): Guest Log: Small home clusters do not require a local http proxy but it is suggested if 2025-01-31 20:15:01 (24596): Guest Log: more than 10 cores throughout the same LAN segment are regularly running ATLAS like tasks. 2025-01-31 20:15:01 (24596): Guest Log: Further information can be found at the LHC@home message board. 2025-01-31 20:15:01 (24596): Guest Log: 00:00:10.007014 timesync vgsvcTimeSyncWorker: Radical guest time change: -3 587 800 998 000ns (GuestNow=1 738 305 033 229 849 000 ns GuestLast=1 738 308 621 030 847 000 ns fSetTimeLastLoop=true ) 2025-01-31 20:15:01 (24596): Guest Log: Running cvmfs_config stat atlas.cern.ch 2025-01-31 20:15:01 (24596): 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 2025-01-31 20:15:01 (24596): Guest Log: 2.6.3.0 1559 0 30016 142162 4 1 3117296 4096000 0 65024 0 0 n/a 0 0 http://s1fnal-cvmfs.openhtc.io:8080/cvmfs/atlas.cern.ch DIRECT 1 2025-01-31 20:15:01 (24596): Guest Log: copied the webapp to /var/www 2025-01-31 20:15:01 (24596): Guest Log: ATHENA_PROC_NUMBER=3 2025-01-31 20:15:01 (24596): Guest Log: ATHENA_CORE_NUMBER=3 2025-01-31 20:15:01 (24596): Guest Log: Apptainer command /cvmfs/atlas.cern.ch/repo/containers/sw/apptainer/x86_64-el7/current/bin/apptainer exec -B /cvmfs,/data,/home/atlas/RunAtlas /cvmfs/atlas.cern.ch/repo/containers/fs/singularity/x86_64-centos7 2025-01-31 20:15:01 (24596): Guest Log: *** Starting ATLAS job. (PandaID=6495987081 taskID=43092792) *** 2025-01-31 20:15:01 (24596): Guest Log: 01:43:44.519548 timesync vgsvcTimeSyncWorker: Radical host time change: 2 369 742 000 000ns (HostNow=1 738 314 679 018 000 000 ns HostLast=1 738 312 309 276 000 000 ns) 2025-01-31 20:15:01 (24596): Guest Log: 01:43:54.525882 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 441 282 119 000ns (GuestNow=1 738 314 689 024 451 000 ns GuestLast=1 738 311 247 742 332 000 ns fSetTimeLastLoop=true ) 2025-01-31 20:15:01 (24596): Guest Log: 01:55:55.209941 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 762 049 503 000ns (GuestNow=1 738 318 161 754 001 000 ns GuestLast=1 738 315 399 704 498 000 ns fSetTimeLastLoop=true ) 2025-01-31 20:15:01 (24596): Guest Log: 04:39:23.542699 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 476 789 855 000ns (GuestNow=1 738 334 440 511 799 000 ns GuestLast=1 738 331 963 721 944 000 ns fSetTimeLastLoop=true ) 2025-01-31 20:15:01 (24596): Guest Log: 05:06:15.178881 timesync vgsvcTimeSyncWorker: Radical host time change: 1 913 070 000 000ns (HostNow=1 738 338 303 234 000 000 ns HostLast=1 738 336 390 164 000 000 ns) 2025-01-31 20:15:01 (24596): Guest Log: 05:06:25.181702 timesync vgsvcTimeSyncWorker: Radical guest time change: 2 261 088 896 000ns (GuestNow=1 738 338 313 236 850 000 ns GuestLast=1 738 336 052 147 954 000 ns fSetTimeLastLoop=true ) 2025-01-31 20:15:01 (24596): Starting VM using VBoxManage interface. (boinc_c4d94cf2229587eb, slot#2) 2025-01-31 20:15:06 (24596): Successfully started VM. (PID = '14804') 2025-01-31 20:15:06 (24596): Reporting VM Process ID to BOINC. 2025-01-31 20:15:06 (24596): Guest Log: BIOS: VirtualBox 7.0.20 2025-01-31 20:15:06 (24596): Guest Log: CPUID EDX: 0x178bfbff 2025-01-31 20:15:06 (24596): Guest Log: BIOS: No PCI IDE controller, not probing IDE 2025-01-31 20:15:06 (24596): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors 2025-01-31 20:15:06 (24596): VM state change detected. (old = 'poweredoff', new = 'running') 2025-01-31 20:15:06 (24596): Detected: Web Application Enabled (http://localhost:55550) 2025-01-31 20:15:07 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 20:15:23 (24596): Status Report: Elapsed Time: '26609.000000' 2025-01-31 20:15:23 (24596): Status Report: CPU Time: '57742.328125' 2025-01-31 20:15:23 (24596): Preference change detected 2025-01-31 20:15:23 (24596): Setting CPU throttle for VM. (75%) 2025-01-31 20:15:24 (24596): Setting checkpoint interval to 900 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 900 seconds)) 2025-01-31 20:15:24 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 20:15:25 (24596): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032 2025-01-31 20:15:25 (24596): Guest Log: BIOS: Booting from Hard Disk... 2025-01-31 20:15:28 (24596): Guest Log: BIOS: KBD: unsupported int 16h function 03 2025-01-31 20:15:28 (24596): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=81 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=81 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=82 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=82 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=83 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=83 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=84 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=84 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=85 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=85 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=86 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=86 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=87 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=87 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=88 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=88 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=89 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=89 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8a 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8a 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8b 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8b 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8c 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8c 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8d 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8d 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8e 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8e 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8f 2025-01-31 20:15:28 (24596): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8f 2025-01-31 20:15:36 (24596): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds 2025-01-31 20:15:36 (24596): Guest Log: vboxguest: misc device minor 58, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000) 2025-01-31 20:15:45 (24596): Guest Log: VBoxService 5.2.32 r132073 (verbosity: 0) linux.amd64 (Jul 12 2019 10:32:28) release log 2025-01-31 20:15:45 (24596): Guest Log: 00:00:00.000153 main Log opened 2025-01-31T20:15:26.654775000Z 2025-01-31 20:15:45 (24596): Guest Log: 00:00:00.000255 main OS Product: Linux 2025-01-31 20:15:45 (24596): Guest Log: 00:00:00.000279 main OS Release: 3.10.0-957.27.2.el7.x86_64 2025-01-31 20:15:45 (24596): Guest Log: 00:00:00.000296 main OS Version: #1 SMP Mon Jul 29 17:46:05 UTC 2019 2025-01-31 20:15:45 (24596): Guest Log: 00:00:00.000315 main Executable: /opt/VBoxGuestAdditions-5.2.32/sbin/VBoxService 2025-01-31 20:15:45 (24596): Guest Log: 00:00:00.000315 main Process ID: 1284 2025-01-31 20:15:45 (24596): Guest Log: 00:00:00.000315 main Package type: LINUX_64BITS_GENERIC 2025-01-31 20:15:45 (24596): Guest Log: 00:00:00.001385 main 5.2.32 r132073 started. Verbose level = 0 2025-01-31 20:15:46 (24596): Guest Log: [INFO] Probing /cvmfs/atlas.cern.ch... 2025-01-31 20:15:46 (24596): Guest Log: [INFO] Mounting shared directory 2025-01-31 20:15:46 (24596): Guest Log: [INFO] Checking for init_data.xml 2025-01-31 20:15:50 (24596): Guest Log: [INFO] Probing /cvmfs/atlas.cern.ch... OK 2025-01-31 20:15:50 (24596): Guest Log: [INFO] Detected branch: prod 2025-01-31 20:15:50 (24596): Guest Log: This is the prod version of the ATLAS job wrapper 2025-01-31 20:15:50 (24596): Guest Log: Copying input files 2025-01-31 20:15:55 (24596): Guest Log: 00:00:10.003501 timesync vgsvcTimeSyncWorker: Radical guest time change: -3 571 219 710 000ns (GuestNow=1 738 350 955 438 178 000 ns GuestLast=1 738 354 526 657 888 000 ns fSetTimeLastLoop=true ) 2025-01-31 20:15:56 (24596): Guest Log: Copied input files into RunAtlas. 2025-01-31 20:15:56 (24596): Guest Log: This VM did not configure a local http proxy via BOINC. 2025-01-31 20:15:56 (24596): Guest Log: Small home clusters do not require a local http proxy but it is suggested if 2025-01-31 20:15:56 (24596): Guest Log: more than 10 cores throughout the same LAN segment are regularly running ATLAS like tasks. 2025-01-31 20:15:56 (24596): Guest Log: Further information can be found at the LHC@home message board. 2025-01-31 20:16:05 (24596): Guest Log: Running cvmfs_config stat atlas.cern.ch 2025-01-31 20:16:06 (24596): 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 2025-01-31 20:16:06 (24596): Guest Log: 2.6.3.0 1558 0 29948 142171 4 1 2249985 4096000 0 65024 0 0 n/a 0 0 http://s1fnal-cvmfs.openhtc.io:8080/cvmfs/atlas.cern.ch DIRECT 1 2025-01-31 20:16:07 (24596): Guest Log: copied the webapp to /var/www 2025-01-31 20:16:07 (24596): Guest Log: ATHENA_PROC_NUMBER=3 2025-01-31 20:16:07 (24596): Guest Log: ATHENA_CORE_NUMBER=3 2025-01-31 20:16:07 (24596): Guest Log: Apptainer command /cvmfs/atlas.cern.ch/repo/containers/sw/apptainer/x86_64-el7/current/bin/apptainer exec -B /cvmfs,/data,/home/atlas/RunAtlas /cvmfs/atlas.cern.ch/repo/containers/fs/singularity/x86_64-centos7 2025-01-31 20:16:07 (24596): Guest Log: *** Starting ATLAS job. (PandaID=6495987081 taskID=43092792) *** 2025-01-31 20:24:46 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 20:25:06 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 20:26:14 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 20:28:28 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 20:28:37 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 20:28:57 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 20:43:43 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 20:44:03 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 21:17:17 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 21:17:37 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 21:46:20 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 21:46:41 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 21:59:29 (24596): Status Report: Elapsed Time: '32609.000000' 2025-01-31 21:59:29 (24596): Status Report: CPU Time: '69297.312500' 2025-01-31 22:27:27 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 22:27:47 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 22:31:47 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 22:32:07 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 23:00:31 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 23:00:51 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 23:11:07 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 23:11:27 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 23:22:08 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 23:22:29 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-01-31 23:41:20 (24596): Status Report: Elapsed Time: '38609.000000' 2025-01-31 23:41:20 (24596): Status Report: CPU Time: '82845.000000' 2025-01-31 23:53:32 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-01-31 23:53:53 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 00:00:33 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 00:00:53 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 00:07:43 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 00:08:04 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 00:10:25 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 00:10:45 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 00:41:49 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 00:42:09 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 00:47:59 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 00:48:19 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 01:02:05 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 01:02:25 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 01:23:54 (24596): Status Report: Elapsed Time: '44609.000000' 2025-02-01 01:23:54 (24596): Status Report: CPU Time: '96392.062500' 2025-02-01 01:27:58 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 01:28:18 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 01:40:30 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 01:40:50 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 01:47:01 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 01:47:21 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 02:10:36 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 02:10:56 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 02:28:28 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 02:28:48 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 02:31:58 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 02:32:18 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 02:56:00 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 02:56:20 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 03:06:26 (24596): Status Report: Elapsed Time: '50609.000000' 2025-02-01 03:06:26 (24596): Status Report: CPU Time: '109943.109375' 2025-02-01 03:14:42 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 03:15:02 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 03:22:44 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 03:23:04 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 03:45:17 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 03:45:37 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 03:49:47 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 03:50:07 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 03:58:58 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 03:59:18 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 04:15:02 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 04:15:22 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 04:26:33 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 04:26:53 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 04:45:05 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 04:45:25 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 04:49:24 (24596): Status Report: Elapsed Time: '56609.000000' 2025-02-01 04:49:24 (24596): Status Report: CPU Time: '123485.906250' 2025-02-01 04:57:57 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 04:58:17 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 05:04:10 (24596): VM state change detected. (old = 'running', new = 'paused') 2025-02-01 05:04:31 (24596): VM state change detected. (old = 'paused', new = 'running') 2025-02-01 05:04:42 (24596): Guest Log: *** Job finished *** 2025-02-01 05:04:42 (24596): Guest Log: *** The last 20 lines of the pilot log: *** 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:04,607 | INFO | [data] copytool_out thread has finished 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:05,079 | INFO | [payload] control thread has finished 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:07,891 | INFO | [data] queue_monitor thread has finished 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:09,924 | INFO | only monitor.control thread still running - safe to abort: ['<_MainThread(MainThread, started 139635758548800)>', '<ExcThread(monitor, started 139635451733760)>'] 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:10,616 | WARNING | job_aborted has been set - aborting pilot monitoring 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:10,616 | INFO | [monitor] control thread has ended 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:14,930 | INFO | all workflow threads have been joined 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:14,930 | INFO | end of generic workflow (traces error code: 0) 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:14,930 | INFO | traces error code: 0 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:14,930 | INFO | pilot has finished (exit code=0, shell exit code=0) 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:15,025 [wrapper] ==== pilot stdout END ==== 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:15,029 [wrapper] ==== wrapper stdout RESUME ==== 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:15,032 [wrapper] pilotpid: 5893 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:15,036 [wrapper] Pilot exit status: 0 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:15,410 [wrapper] pandaids: 6495987081 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:15,427 [wrapper] cleanup supervisor_pilot 31023 5894 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:15,433 [wrapper] Test setup, not cleaning 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:15,438 [wrapper] apfmon messages muted 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:15,440 [wrapper] ==== wrapper stdout END ==== 2025-02-01 05:04:42 (24596): Guest Log: 2025-02-01 03:51:15,443 [wrapper] ==== wrapper stderr END ==== 2025-02-01 05:04:42 (24596): Guest Log: *** Error codes and diagnostics *** 2025-02-01 05:04:42 (24596): Guest Log: "exeErrorCode": 0, 2025-02-01 05:04:42 (24596): Guest Log: "exeErrorDiag": "", 2025-02-01 05:04:42 (24596): Guest Log: "pilotErrorCode": 0, 2025-02-01 05:04:42 (24596): Guest Log: "pilotErrorDiag": "", 2025-02-01 05:04:42 (24596): Guest Log: *** Listing of results directory *** 2025-02-01 05:04:42 (24596): Guest Log: total 356928 2025-02-01 05:04:42 (24596): Guest Log: -rw-r--r--. 1 atlas atlas 491065 Jan 30 17:42 pilot3.tar.gz 2025-02-01 05:04:42 (24596): Guest Log: -rw-r--r--. 1 atlas atlas 5117 Jan 30 18:07 queuedata.json 2025-02-01 05:04:42 (24596): Guest Log: -rwx------. 1 atlas atlas 34924 Jan 30 18:07 runpilot2-wrapper.sh 2025-02-01 05:04:42 (24596): Guest Log: -rwxr-xr-x. 1 atlas atlas 12509 Jan 31 19:15 init_data.xml 2025-02-01 05:04:42 (24596): Guest Log: -rwxr-xr-x. 1 atlas atlas 503502 Jan 31 19:15 input.tar.gz 2025-02-01 05:04:42 (24596): Guest Log: -rwxr-xr-x. 1 atlas atlas 17569 Jan 31 19:15 start_atlas.sh 2025-02-01 05:04:42 (24596): Guest Log: lrwxrwxrwx. 1 atlas atlas 20 Jan 31 19:15 EVNT.43092790._000028.pool.root.1 -> /data/./ATLAS.root_0 2025-02-01 05:04:42 (24596): Guest Log: -rw-r--r--. 1 atlas atlas 2551 Jan 31 19:16 pandaJob.out 2025-02-01 05:04:42 (24596): Guest Log: -rw-------. 1 atlas atlas 424 Jan 31 19:16 setup.sh.local 2025-02-01 05:04:42 (24596): Guest Log: -rw-------. 1 atlas atlas 968472 Jan 31 19:16 agis_schedconf.cvmfs.json 2025-02-01 05:04:42 (24596): Guest Log: drwx------. 4 atlas atlas 4096 Jan 31 19:16 pilot3 2025-02-01 05:04:42 (24596): Guest Log: -rw-------. 1 atlas atlas 355319229 Feb 1 03:49 HITS.43092792._001485.pool.root.1 2025-02-01 05:04:42 (24596): Guest Log: -rw-------. 1 atlas atlas 95 Feb 1 03:50 pilot_heartbeat.json 2025-02-01 05:04:42 (24596): Guest Log: -rw-------. 1 atlas atlas 1020 Feb 1 03:50 memory_monitor_summary.json 2025-02-01 05:04:42 (24596): Guest Log: -rw-------. 1 atlas atlas 1580185 Feb 1 03:50 agis_ddmendpoints.agis.ALL.json 2025-02-01 05:04:42 (24596): Guest Log: -rw-------. 1 atlas atlas 466229 Feb 1 03:50 log.43092792._001485.job.log.tgz.1 2025-02-01 05:04:42 (24596): Guest Log: -rw-------. 1 atlas atlas 7711 Feb 1 03:51 heartbeat.json 2025-02-01 05:04:42 (24596): Guest Log: -rw-------. 1 atlas atlas 4398 Feb 1 03:51 pilotlog.txt 2025-02-01 05:04:42 (24596): Guest Log: -rw-------. 1 atlas atlas 2760756 Feb 1 03:51 log.43092792._001485.job.log.1 2025-02-01 05:04:42 (24596): Guest Log: -rw-------. 1 atlas atlas 357 Feb 1 03:51 output.list 2025-02-01 05:04:42 (24596): Guest Log: -rw-r--r--. 1 atlas atlas 620 Feb 1 03:51 runtime_log 2025-02-01 05:04:42 (24596): Guest Log: -rw-------. 1 atlas atlas 3246080 Feb 1 03:51 result.tar.gz 2025-02-01 05:04:42 (24596): Guest Log: -rw-r--r--. 1 atlas atlas 10936 Feb 1 03:51 runtime_log.err 2025-02-01 05:04:42 (24596): Guest Log: -rw-------. 1 atlas atlas 657 Feb 1 03:51 JS9LDmN8nx6n9Rq4apOajLDm4fhM0noT9bVoFjIUDmMiJKDmLUS5cn.diag 2025-02-01 05:04:42 (24596): Guest Log: Looking for outputfile HITS.43092792._001485.pool.root.1 2025-02-01 05:04:42 (24596): Guest Log: HITS file was successfully produced 2025-02-01 05:04:42 (24596): Guest Log: -rw-------. 1 atlas atlas 355319229 Feb 1 03:49 /home/atlas/RunAtlas/HITS.43092792._001485.pool.root.1 2025-02-01 05:04:43 (24596): Guest Log: Successfully finished the ATLAS job! 2025-02-01 05:04:43 (24596): Guest Log: Copying the results back to the shared directory! 2025-02-01 05:04:43 (24596): Guest Log: *** Contents of shared directory: *** 2025-02-01 05:04:43 (24596): Guest Log: total 688976 2025-02-01 05:04:43 (24596): Guest Log: -rwxrwxrwx. 1 root root 346400613 Jan 31 06:29 ATLAS.root_0 2025-02-01 05:04:43 (24596): Guest Log: -rwxrwxrwx. 1 root root 355319229 Feb 1 2025 HITS.pool.root.1 2025-02-01 05:04:43 (24596): Guest Log: -rwxrwxrwx. 1 root root 12509 Jan 31 06:29 init_data.xml 2025-02-01 05:04:43 (24596): Guest Log: -rwxrwxrwx. 1 root root 503502 Jan 30 21:25 input.tar.gz 2025-02-01 05:04:43 (24596): Guest Log: -rwxrwxrwx. 1 root root 3246080 Feb 1 2025 result.tar.gz 2025-02-01 05:04:43 (24596): Guest Log: -rwxrwxrwx. 1 root root 17569 Jan 30 21:25 start_atlas.sh 2025-02-01 05:04:43 (24596): Guest Log: *** Success! Shutting down the machine. *** 2025-02-01 05:04:44 (24596): VM Completion File Detected. 2025-02-01 05:04:44 (24596): Powering off VM. 2025-02-01 05:04:45 (24596): Successfully stopped VM. 2025-02-01 05:04:45 (24596): Deregistering VM. (boinc_c4d94cf2229587eb, slot#2) 2025-02-01 05:04:45 (24596): Removing network bandwidth throttle group from VM. 2025-02-01 05:04:45 (24596): Removing VM from VirtualBox. 05:04:50 (24596): called boinc_finish(0) </stderr_txt> ]]>
©2025 CERN