| Name | ZgGODmHae46n9Rq4apOajLDm4fhM0noT9bVoFjIUDmpOZKDm0h8kCo_0 |
| Workunit | 230440015 |
| Created | 18 Feb 2025, 15:21:15 UTC |
| Sent | 18 Feb 2025, 18:53:46 UTC |
| Report deadline | 26 Feb 2025, 18:53:46 UTC |
| Received | 22 Feb 2025, 4:59:39 UTC |
| Server state | Over |
| Outcome | Success |
| Client state | Done |
| Exit status | 0 (0x00000000) |
| Computer ID | 10774714 |
| Run time | 19 hours 20 min 31 sec |
| CPU time | 18 hours 42 min 54 sec |
| Validate state | Valid |
| Credit | 767.30 |
| Device peak FLOPS | 3.85 GFLOPS |
| Application version | ATLAS Simulation v3.01 (vbox64_mt_mcore_atlas) windows_x86_64 |
| Peak working set size | 86.55 MB |
| Peak swap size | 86.43 MB |
| Peak disk usage | 2.61 GB |
Stderr output
<core_client_version>8.0.2</core_client_version> <![CDATA[ <stderr_txt> 2025-02-18 22:07:44 (1316): Detected: vboxwrapper 26206 2025-02-18 22:07:44 (1316): Detected: BOINC client v8.0.2 2025-02-18 22:07:46 (1316): Detected: VirtualBox VboxManage Interface (Version: 7.0.6) 2025-02-18 22:07:47 (1316): Successfully copied 'init_data.xml' to the shared directory. 2025-02-18 22:07:47 (1316): Create VM. (boinc_112bc1f508f5d5bc, slot#1) 2025-02-18 22:07:48 (1316): Setting Memory Size for VM. (4100MB) 2025-02-18 22:07:48 (1316): Setting CPU Count for VM. (1) 2025-02-18 22:07:48 (1316): Setting Chipset Options for VM. 2025-02-18 22:07:48 (1316): Setting Graphics Controller Options for VM. 2025-02-18 22:07:49 (1316): Setting Boot Options for VM. 2025-02-18 22:07:49 (1316): Setting Network Configuration for NAT. 2025-02-18 22:07:49 (1316): Enabling VM Network Access. 2025-02-18 22:07:49 (1316): Disabling USB Support for VM. 2025-02-18 22:07:50 (1316): Disabling COM Port Support for VM. 2025-02-18 22:07:50 (1316): Disabling LPT Port Support for VM. 2025-02-18 22:07:50 (1316): Disabling Audio Support for VM. 2025-02-18 22:07:51 (1316): Disabling Clipboard Support for VM. 2025-02-18 22:07:51 (1316): Disabling Drag and Drop Support for VM. 2025-02-18 22:07:51 (1316): Adding storage controller(s) to VM. 2025-02-18 22:07:51 (1316): Adding virtual disk drive to VM. (ATLAS_vbox_3.01_image.vdi) 2025-02-18 22:07:54 (1316): Adding VirtualBox Guest Additions to VM. 2025-02-18 22:07:55 (1316): Adding network bandwidth throttle group to VM. (Defaulting to 1024GB) 2025-02-18 22:07:55 (1316): forwarding host port 54144 to guest port 80 2025-02-18 22:07:55 (1316): Enabling remote desktop for VM. 2025-02-18 22:07:56 (1316): Enabling shared directory for VM. 2025-02-18 22:07:56 (1316): Starting VM using VBoxManage interface. (boinc_112bc1f508f5d5bc, slot#1) 2025-02-18 22:08:06 (1316): Successfully started VM. (PID = '3196') 2025-02-18 22:08:06 (1316): Reporting VM Process ID to BOINC. 2025-02-18 22:08:06 (1316): Guest Log: BIOS: VirtualBox 7.0.6 2025-02-18 22:08:06 (1316): Guest Log: CPUID EDX: 0x178bfbff 2025-02-18 22:08:06 (1316): Guest Log: BIOS: No PCI IDE controller, not probing IDE 2025-02-18 22:08:06 (1316): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors 2025-02-18 22:08:06 (1316): VM state change detected. (old = 'poweredoff', new = 'running') 2025-02-18 22:08:06 (1316): Detected: Web Application Enabled (http://localhost:54144) 2025-02-18 22:08:06 (1316): Detected: Remote Desktop Enabled (localhost:54145) 2025-02-18 22:08:06 (1316): Preference change detected 2025-02-18 22:08:06 (1316): Setting CPU throttle for VM. (100%) 2025-02-18 22:08:06 (1316): Setting checkpoint interval to 900 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 900 seconds)) 2025-02-18 22:08:08 (1316): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032 2025-02-18 22:08:08 (1316): Guest Log: BIOS: Booting from Hard Disk... 2025-02-18 22:08:11 (1316): Guest Log: BIOS: KBD: unsupported int 16h function 03 2025-02-18 22:08:11 (1316): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=81 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=81 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=82 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=82 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=83 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=83 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=84 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=84 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=85 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=85 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=86 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=86 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=87 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=87 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=88 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=88 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=89 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=89 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8a 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8a 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8b 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8b 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8c 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8c 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8d 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8d 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8e 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8e 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8f 2025-02-18 22:08:11 (1316): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8f 2025-02-18 22:08:16 (1316): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds 2025-02-18 22:08:16 (1316): Guest Log: vboxguest: misc device minor 58, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000) 2025-02-18 22:08:27 (1316): Guest Log: VBoxService 5.2.32 r132073 (verbosity: 0) linux.amd64 (Jul 12 2019 10:32:28) release log 2025-02-18 22:08:27 (1316): Guest Log: 00:00:00.000224 main Log opened 2025-02-18T22:08:25.874192000Z 2025-02-18 22:08:27 (1316): Guest Log: 00:00:00.000377 main OS Product: Linux 2025-02-18 22:08:27 (1316): Guest Log: 00:00:00.000417 main OS Release: 3.10.0-957.27.2.el7.x86_64 2025-02-18 22:08:27 (1316): Guest Log: 00:00:00.000486 main OS Version: #1 SMP Mon Jul 29 17:46:05 UTC 2019 2025-02-18 22:08:27 (1316): Guest Log: 00:00:00.000523 main Executable: /opt/VBoxGuestAdditions-5.2.32/sbin/VBoxService 2025-02-18 22:08:27 (1316): Guest Log: 00:00:00.000524 main Process ID: 1252 2025-02-18 22:08:27 (1316): Guest Log: 00:00:00.000525 main Package type: LINUX_64BITS_GENERIC 2025-02-18 22:08:27 (1316): Guest Log: 00:00:00.001868 main 5.2.32 r132073 started. Verbose level = 0 2025-02-18 22:08:28 (1316): Guest Log: [INFO] Probing /cvmfs/atlas.cern.ch... 2025-02-18 22:08:28 (1316): Guest Log: [INFO] Mounting shared directory 2025-02-18 22:08:28 (1316): Guest Log: [INFO] Checking for init_data.xml 2025-02-18 22:08:32 (1316): Guest Log: [INFO] Probing /cvmfs/atlas.cern.ch... OK 2025-02-18 22:08:32 (1316): Guest Log: [INFO] Detected branch: prod 2025-02-18 22:08:33 (1316): Guest Log: This is the prod version of the ATLAS job wrapper 2025-02-18 22:08:33 (1316): Guest Log: Copying input files 2025-02-18 22:08:35 (1316): Guest Log: Copied input files into RunAtlas. 2025-02-18 22:08:35 (1316): Guest Log: This VM did not configure a local http proxy via BOINC. 2025-02-18 22:08:35 (1316): Guest Log: Small home clusters do not require a local http proxy but it is suggested if 2025-02-18 22:08:35 (1316): Guest Log: more than 10 cores throughout the same LAN segment are regularly running ATLAS like tasks. 2025-02-18 22:08:35 (1316): Guest Log: Further information can be found at the LHC@home message board. 2025-02-18 22:08:37 (1316): Guest Log: 00:00:10.027878 timesync vgsvcTimeSyncWorker: Radical guest time change: -10 788 571 812 000ns (GuestNow=1 739 905 717 329 487 000 ns GuestLast=1 739 916 505 901 299 000 ns fSetTimeLastLoop=true ) 2025-02-18 22:08:45 (1316): Guest Log: Running cvmfs_config stat atlas.cern.ch 2025-02-18 22:08:45 (1316): 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-02-18 22:08:45 (1316): Guest Log: 2.6.3.0 1521 0 30080 142798 4 1 3117296 4096000 0 65024 0 0 n/a 1 0 http://s1ral-cvmfs.openhtc.io/cvmfs/atlas.cern.ch DIRECT 1 2025-02-18 22:08:47 (1316): Guest Log: copied the webapp to /var/www 2025-02-18 22:08:47 (1316): Guest Log: core_number=1 2025-02-18 22:08:48 (1316): 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-02-18 22:08:48 (1316): Guest Log: *** Starting ATLAS job. (PandaID=6518301004 taskID=43078919) *** 2025-02-18 22:49:47 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-18 22:50:07 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-18 23:22:55 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-19 07:59:36 (1316): Guest Log: 01:14:12.046549 timesync vgsvcTimeSyncWorker: Radical host time change: 31 005 089 000 000ns (HostNow=1 739 941 173 438 000 000 ns HostLast=1 739 910 168 349 000 000 ns) 2025-02-19 07:59:36 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-19 07:59:39 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-19 08:00:15 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-19 08:00:21 (1316): Guest Log: 01:14:22.050793 timesync vgsvcTimeSyncWorker: Radical guest time change: 31 024 094 119 000ns (GuestNow=1 739 941 183 442 280 000 ns GuestLast=1 739 910 159 348 161 000 ns fSetTimeLastLoop=true ) 2025-02-19 08:08:34 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-19 08:08:54 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-19 08:09:13 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-19 08:15:14 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-19 08:15:24 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-19 08:15:44 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-19 08:15:54 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-19 08:16:14 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-19 08:17:34 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-19 08:17:54 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-19 08:18:14 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-19 08:18:34 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-19 08:20:54 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-19 08:21:14 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-19 08:32:45 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-19 08:33:05 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-19 08:34:19 (1316): Status Report: Elapsed Time: '6000.464905' 2025-02-19 08:34:19 (1316): Status Report: CPU Time: '5112.281250' 2025-02-19 09:00:47 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-19 09:01:07 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-19 09:29:48 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-19 09:30:08 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-19 10:15:04 (1316): Status Report: Elapsed Time: '12000.464905' 2025-02-19 10:15:04 (1316): Status Report: CPU Time: '11033.640625' 2025-02-19 10:26:32 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-19 10:26:52 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-19 11:23:05 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-19 11:23:25 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-19 11:24:48 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 07:59:38 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 07:59:40 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 08:00:01 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 08:00:05 (1316): Guest Log: 04:29:18.645631 timesync vgsvcTimeSyncWorker: Radical host time change: 74 122 027 000 000ns (HostNow=1 740 027 605 489 000 000 ns HostLast=1 739 953 483 462 000 000 ns) 2025-02-20 08:00:16 (1316): Guest Log: 04:29:29.175876 timesync vgsvcTimeSyncWorker: Radical guest time change: 74 735 982 215 000ns (GuestNow=1 740 027 616 019 290 000 ns GuestLast=1 739 952 880 037 075 000 ns fSetTimeLastLoop=true ) 2025-02-20 08:08:31 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 08:08:51 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 08:09:21 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 08:09:41 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 08:09:51 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 08:10:31 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 08:10:42 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 08:13:22 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 08:35:08 (1316): Status Report: Elapsed Time: '18000.491205' 2025-02-20 08:35:08 (1316): Status Report: CPU Time: '16991.156250' 2025-02-20 08:58:05 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 08:58:26 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 09:39:09 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 09:39:29 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 09:59:44 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 10:46:18 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 10:46:22 (1316): Guest Log: 06:24:23.033213 timesync vgsvcTimeSyncWorker: Radical host time change: 2 804 575 000 000ns (HostNow=1 740 037 581 990 000 000 ns HostLast=1 740 034 777 415 000 000 ns) 2025-02-20 10:46:25 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 10:46:45 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 10:46:52 (1316): Guest Log: 06:24:33.043819 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 082 124 451 000ns (GuestNow=1 740 037 592 000 631 000 ns GuestLast=1 740 034 509 876 180 000 ns fSetTimeLastLoop=true ) 2025-02-20 11:02:51 (1316): Status Report: Elapsed Time: '24000.491205' 2025-02-20 11:02:51 (1316): Status Report: CPU Time: '22939.406250' 2025-02-20 11:33:28 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 11:33:48 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 12:30:22 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 12:30:42 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 12:43:37 (1316): Status Report: Elapsed Time: '30000.491205' 2025-02-20 12:43:37 (1316): Status Report: CPU Time: '28898.000000' 2025-02-20 13:05:34 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 14:31:06 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 14:31:15 (1316): Guest Log: 08:42:47.714700 timesync vgsvcTimeSyncWorker: Radical host time change: 5 142 668 000 000ns (HostNow=1 740 051 075 155 000 000 ns HostLast=1 740 045 932 487 000 000 ns) 2025-02-20 14:31:25 (1316): Guest Log: 08:42:57.716764 timesync vgsvcTimeSyncWorker: Radical guest time change: 5 198 485 564 000ns (GuestNow=1 740 051 085 157 073 000 ns GuestLast=1 740 045 886 671 509 000 ns fSetTimeLastLoop=true ) 2025-02-20 14:59:29 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 14:59:48 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 15:38:33 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 15:38:53 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 15:49:55 (1316): Status Report: Elapsed Time: '36000.491205' 2025-02-20 15:49:55 (1316): Status Report: CPU Time: '34850.718750' 2025-02-20 16:01:26 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:01:46 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 16:03:46 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:05:36 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 16:05:46 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:06:06 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 16:06:16 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:06:36 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 16:06:46 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:07:06 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 16:07:16 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:07:36 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 16:07:46 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:08:06 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 16:08:16 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:08:36 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 16:08:46 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:09:06 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 16:09:16 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:09:36 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 16:09:46 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:10:06 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 16:10:16 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:10:36 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 16:10:46 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:11:06 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 16:11:16 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:11:36 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 16:11:46 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:12:06 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 16:12:16 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:12:36 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 16:12:46 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:13:06 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 16:56:57 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 16:58:56 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 17:39:41 (1316): Status Report: Elapsed Time: '42000.558569' 2025-02-20 17:39:41 (1316): Status Report: CPU Time: '40792.000000' 2025-02-20 18:42:05 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 18:42:25 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 18:59:31 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-20 20:59:44 (1316): VM state change detected. (old = 'paused', new = 'running') 2025-02-20 20:59:47 (1316): Guest Log: 13:01:06.417823 timesync vgsvcTimeSyncWorker: Radical host time change: 7 222 516 000 000ns (HostNow=1 740 074 386 450 000 000 ns HostLast=1 740 067 163 934 000 000 ns) 2025-02-20 20:59:57 (1316): Guest Log: 13:01:16.427980 timesync vgsvcTimeSyncWorker: Radical guest time change: 7 822 602 047 000ns (GuestNow=1 740 074 396 460 166 000 ns GuestLast=1 740 066 573 858 119 000 ns fSetTimeLastLoop=true ) 2025-02-20 21:20:19 (1316): Status Report: Elapsed Time: '48000.558569' 2025-02-20 21:20:19 (1316): Status Report: CPU Time: '46700.203125' 2025-02-20 21:54:34 (1316): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 10:56:41 (10968): Detected: vboxwrapper 26206 2025-02-21 10:56:41 (10968): Detected: BOINC client v8.0.2 2025-02-21 10:56:43 (10968): Detected: VirtualBox VboxManage Interface (Version: 7.0.6) 2025-02-21 10:56:44 (10968): Guest Log: BIOS: VirtualBox 7.0.6 2025-02-21 10:56:44 (10968): Guest Log: CPUID EDX: 0x178bfbff 2025-02-21 10:56:44 (10968): Guest Log: BIOS: No PCI IDE controller, not probing IDE 2025-02-21 10:56:44 (10968): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors 2025-02-21 10:56:44 (10968): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032 2025-02-21 10:56:44 (10968): Guest Log: BIOS: Booting from Hard Disk... 2025-02-21 10:56:44 (10968): Guest Log: BIOS: KBD: unsupported int 16h function 03 2025-02-21 10:56:44 (10968): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=81 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=81 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=82 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=82 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=83 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=83 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=84 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=84 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=85 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=85 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=86 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=86 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=87 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=87 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=88 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=88 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=89 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=89 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8a 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8a 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8b 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8b 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8c 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8c 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8d 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8d 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8e 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8e 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8f 2025-02-21 10:56:44 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8f 2025-02-21 10:56:44 (10968): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds 2025-02-21 10:56:44 (10968): Guest Log: vboxguest: misc device minor 58, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000) 2025-02-21 10:56:44 (10968): Guest Log: VBoxService 5.2.32 r132073 (verbosity: 0) linux.amd64 (Jul 12 2019 10:32:28) release log 2025-02-21 10:56:44 (10968): Guest Log: 00:00:00.000224 main Log opened 2025-02-18T22:08:25.874192000Z 2025-02-21 10:56:44 (10968): Guest Log: 00:00:00.000377 main OS Product: Linux 2025-02-21 10:56:44 (10968): Guest Log: 00:00:00.000417 main OS Release: 3.10.0-957.27.2.el7.x86_64 2025-02-21 10:56:44 (10968): Guest Log: 00:00:00.000486 main OS Version: #1 SMP Mon Jul 29 17:46:05 UTC 2019 2025-02-21 10:56:44 (10968): Guest Log: 00:00:00.000523 main Executable: /opt/VBoxGuestAdditions-5.2.32/sbin/VBoxService 2025-02-21 10:56:44 (10968): Guest Log: 00:00:00.000524 main Process ID: 1252 2025-02-21 10:56:44 (10968): Guest Log: 00:00:00.000525 main Package type: LINUX_64BITS_GENERIC 2025-02-21 10:56:44 (10968): Guest Log: 00:00:00.001868 main 5.2.32 r132073 started. Verbose level = 0 2025-02-21 10:56:44 (10968): Guest Log: [INFO] Probing /cvmfs/atlas.cern.ch... 2025-02-21 10:56:44 (10968): Guest Log: [INFO] Mounting shared directory 2025-02-21 10:56:44 (10968): Guest Log: [INFO] Checking for init_data.xml 2025-02-21 10:56:44 (10968): Guest Log: [INFO] Probing /cvmfs/atlas.cern.ch... OK 2025-02-21 10:56:44 (10968): Guest Log: [INFO] Detected branch: prod 2025-02-21 10:56:44 (10968): Guest Log: This is the prod version of the ATLAS job wrapper 2025-02-21 10:56:44 (10968): Guest Log: Copying input files 2025-02-21 10:56:44 (10968): Guest Log: Copied input files into RunAtlas. 2025-02-21 10:56:44 (10968): Guest Log: This VM did not configure a local http proxy via BOINC. 2025-02-21 10:56:44 (10968): Guest Log: Small home clusters do not require a local http proxy but it is suggested if 2025-02-21 10:56:44 (10968): Guest Log: more than 10 cores throughout the same LAN segment are regularly running ATLAS like tasks. 2025-02-21 10:56:44 (10968): Guest Log: Further information can be found at the LHC@home message board. 2025-02-21 10:56:44 (10968): Guest Log: 00:00:10.027878 timesync vgsvcTimeSyncWorker: Radical guest time change: -10 788 571 812 000ns (GuestNow=1 739 905 717 329 487 000 ns GuestLast=1 739 916 505 901 299 000 ns fSetTimeLastLoop=true ) 2025-02-21 10:56:44 (10968): Guest Log: Running cvmfs_config stat atlas.cern.ch 2025-02-21 10:56:44 (10968): 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-02-21 10:56:44 (10968): Guest Log: 2.6.3.0 1521 0 30080 142798 4 1 3117296 4096000 0 65024 0 0 n/a 1 0 http://s1ral-cvmfs.openhtc.io/cvmfs/atlas.cern.ch DIRECT 1 2025-02-21 10:56:44 (10968): Guest Log: copied the webapp to /var/www 2025-02-21 10:56:44 (10968): Guest Log: core_number=1 2025-02-21 10:56:44 (10968): 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-02-21 10:56:44 (10968): Guest Log: *** Starting ATLAS job. (PandaID=6518301004 taskID=43078919) *** 2025-02-21 10:56:44 (10968): Guest Log: 01:14:12.046549 timesync vgsvcTimeSyncWorker: Radical host time change: 31 005 089 000 000ns (HostNow=1 739 941 173 438 000 000 ns HostLast=1 739 910 168 349 000 000 ns) 2025-02-21 10:56:44 (10968): Guest Log: 01:14:22.050793 timesync vgsvcTimeSyncWorker: Radical guest time change: 31 024 094 119 000ns (GuestNow=1 739 941 183 442 280 000 ns GuestLast=1 739 910 159 348 161 000 ns fSetTimeLastLoop=true ) 2025-02-21 10:56:44 (10968): Guest Log: 04:29:18.645631 timesync vgsvcTimeSyncWorker: Radical host time change: 74 122 027 000 000ns (HostNow=1 740 027 605 489 000 000 ns HostLast=1 739 953 483 462 000 000 ns) 2025-02-21 10:56:44 (10968): Guest Log: 04:29:29.175876 timesync vgsvcTimeSyncWorker: Radical guest time change: 74 735 982 215 000ns (GuestNow=1 740 027 616 019 290 000 ns GuestLast=1 739 952 880 037 075 000 ns fSetTimeLastLoop=true ) 2025-02-21 10:56:44 (10968): Guest Log: 06:24:23.033213 timesync vgsvcTimeSyncWorker: Radical host time change: 2 804 575 000 000ns (HostNow=1 740 037 581 990 000 000 ns HostLast=1 740 034 777 415 000 000 ns) 2025-02-21 10:56:44 (10968): Guest Log: 06:24:33.043819 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 082 124 451 000ns (GuestNow=1 740 037 592 000 631 000 ns GuestLast=1 740 034 509 876 180 000 ns fSetTimeLastLoop=true ) 2025-02-21 10:56:44 (10968): Guest Log: 08:42:47.714700 timesync vgsvcTimeSyncWorker: Radical host time change: 5 142 668 000 000ns (HostNow=1 740 051 075 155 000 000 ns HostLast=1 740 045 932 487 000 000 ns) 2025-02-21 10:56:44 (10968): Guest Log: 08:42:57.716764 timesync vgsvcTimeSyncWorker: Radical guest time change: 5 198 485 564 000ns (GuestNow=1 740 051 085 157 073 000 ns GuestLast=1 740 045 886 671 509 000 ns fSetTimeLastLoop=true ) 2025-02-21 10:56:44 (10968): Guest Log: 13:01:06.417823 timesync vgsvcTimeSyncWorker: Radical host time change: 7 222 516 000 000ns (HostNow=1 740 074 386 450 000 000 ns HostLast=1 740 067 163 934 000 000 ns) 2025-02-21 10:56:44 (10968): Guest Log: 13:01:16.427980 timesync vgsvcTimeSyncWorker: Radical guest time change: 7 822 602 047 000ns (GuestNow=1 740 074 396 460 166 000 ns GuestLast=1 740 066 573 858 119 000 ns fSetTimeLastLoop=true ) 2025-02-21 10:56:44 (10968): Starting VM using VBoxManage interface. (boinc_112bc1f508f5d5bc, slot#1) 2025-02-21 10:56:53 (10968): Successfully started VM. (PID = '4108') 2025-02-21 10:56:53 (10968): Reporting VM Process ID to BOINC. 2025-02-21 10:56:53 (10968): Guest Log: BIOS: VirtualBox 7.0.6 2025-02-21 10:56:53 (10968): Guest Log: CPUID EDX: 0x178bfbff 2025-02-21 10:56:53 (10968): Guest Log: BIOS: No PCI IDE controller, not probing IDE 2025-02-21 10:56:53 (10968): Guest Log: BIOS: AHCI 0-P#0: PCHS=16383/16/63 LCHS=1024/255/63 0x0000000002800000 sectors 2025-02-21 10:56:53 (10968): VM state change detected. (old = 'poweredoff', new = 'running') 2025-02-21 10:56:53 (10968): Detected: Web Application Enabled (http://localhost:54144) 2025-02-21 10:56:53 (10968): Detected: Remote Desktop Enabled (localhost:54145) 2025-02-21 10:56:54 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 10:57:07 (10968): Status Report: Elapsed Time: '50012.558569' 2025-02-21 10:57:07 (10968): Status Report: CPU Time: '48687.640625' 2025-02-21 10:57:07 (10968): Preference change detected 2025-02-21 10:57:07 (10968): Setting CPU throttle for VM. (100%) 2025-02-21 10:57:07 (10968): Setting checkpoint interval to 900 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 900 seconds)) 2025-02-21 10:57:08 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 10:57:09 (10968): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032 2025-02-21 10:57:09 (10968): Guest Log: BIOS: Booting from Hard Disk... 2025-02-21 10:57:12 (10968): Guest Log: BIOS: KBD: unsupported int 16h function 03 2025-02-21 10:57:12 (10968): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=81 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=81 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=82 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=82 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=83 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=83 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=84 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=84 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=85 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=85 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=86 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=86 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=87 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=87 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=88 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=88 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=89 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=89 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8a 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8a 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8b 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8b 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8c 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8c 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8d 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8d 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8e 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8e 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk_ext: function 41, unmapped device for ELDL=8f 2025-02-21 10:57:12 (10968): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=8f 2025-02-21 10:57:17 (10968): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds 2025-02-21 10:57:17 (10968): Guest Log: vboxguest: misc device minor 58, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000) 2025-02-21 10:57:29 (10968): Guest Log: VBoxService 5.2.32 r132073 (verbosity: 0) linux.amd64 (Jul 12 2019 10:32:28) release log 2025-02-21 10:57:29 (10968): Guest Log: 00:00:00.000215 main Log opened 2025-02-21T10:57:13.140031000Z 2025-02-21 10:57:29 (10968): Guest Log: 00:00:00.000362 main OS Product: Linux 2025-02-21 10:57:29 (10968): Guest Log: 00:00:00.000399 main OS Release: 3.10.0-957.27.2.el7.x86_64 2025-02-21 10:57:29 (10968): Guest Log: 00:00:00.000431 main OS Version: #1 SMP Mon Jul 29 17:46:05 UTC 2019 2025-02-21 10:57:29 (10968): Guest Log: 00:00:00.000496 main Executable: /opt/VBoxGuestAdditions-5.2.32/sbin/VBoxService 2025-02-21 10:57:29 (10968): Guest Log: 00:00:00.000497 main Process ID: 1253 2025-02-21 10:57:29 (10968): Guest Log: 00:00:00.000498 main Package type: LINUX_64BITS_GENERIC 2025-02-21 10:57:29 (10968): Guest Log: 00:00:00.001804 main 5.2.32 r132073 started. Verbose level = 0 2025-02-21 10:57:29 (10968): Guest Log: [INFO] Probing /cvmfs/atlas.cern.ch... 2025-02-21 10:57:29 (10968): Guest Log: [INFO] Mounting shared directory 2025-02-21 10:57:29 (10968): Guest Log: [INFO] Checking for init_data.xml 2025-02-21 10:57:34 (10968): Guest Log: [INFO] Probing /cvmfs/atlas.cern.ch... OK 2025-02-21 10:57:34 (10968): Guest Log: [INFO] Detected branch: prod 2025-02-21 10:57:34 (10968): Guest Log: This is the prod version of the ATLAS job wrapper 2025-02-21 10:57:34 (10968): Guest Log: Copying input files 2025-02-21 10:57:37 (10968): Guest Log: Copied input files into RunAtlas. 2025-02-21 10:57:37 (10968): Guest Log: This VM did not configure a local http proxy via BOINC. 2025-02-21 10:57:37 (10968): Guest Log: Small home clusters do not require a local http proxy but it is suggested if 2025-02-21 10:57:37 (10968): Guest Log: more than 10 cores throughout the same LAN segment are regularly running ATLAS like tasks. 2025-02-21 10:57:37 (10968): Guest Log: Further information can be found at the LHC@home message board. 2025-02-21 10:57:39 (10968): Guest Log: 00:00:10.030755 timesync vgsvcTimeSyncWorker: Radical guest time change: -10 774 764 483 000ns (GuestNow=1 740 124 658 405 510 000 ns GuestLast=1 740 135 433 169 993 000 ns fSetTimeLastLoop=true ) 2025-02-21 10:57:49 (10968): Guest Log: Running cvmfs_config stat atlas.cern.ch 2025-02-21 10:57:49 (10968): 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-02-21 10:57:49 (10968): Guest Log: 2.6.3.0 1522 0 32100 142895 4 1 3998488 4096000 0 65024 0 0 n/a 0 0 http://s1fnal-cvmfs.openhtc.io:8080/cvmfs/atlas.cern.ch DIRECT 1 2025-02-21 10:57:50 (10968): Guest Log: copied the webapp to /var/www 2025-02-21 10:57:51 (10968): Guest Log: core_number=1 2025-02-21 10:57:51 (10968): 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-02-21 10:57:51 (10968): Guest Log: *** Starting ATLAS job. (PandaID=6518301004 taskID=43078919) *** 2025-02-21 12:01:11 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 12:51:48 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 12:51:57 (10968): Guest Log: 01:03:51.579780 timesync vgsvcTimeSyncWorker: Radical host time change: 3 046 825 000 000ns (HostNow=1 740 131 516 722 000 000 ns HostLast=1 740 128 469 897 000 000 ns) 2025-02-21 12:52:07 (10968): Guest Log: 01:04:01.589559 timesync vgsvcTimeSyncWorker: Radical guest time change: 3 046 777 650 000ns (GuestNow=1 740 131 526 731 810 000 ns GuestLast=1 740 128 479 954 160 000 ns fSetTimeLastLoop=true ) 2025-02-21 13:08:29 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 13:08:49 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 13:28:09 (10968): Status Report: Elapsed Time: '56012.558569' 2025-02-21 13:28:09 (10968): Status Report: CPU Time: '54035.406250' 2025-02-21 14:52:28 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 16:31:52 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 16:32:02 (10968): Guest Log: 03:04:15.527849 timesync vgsvcTimeSyncWorker: Radical host time change: 5 973 733 000 000ns (HostNow=1 740 144 721 298 000 000 ns HostLast=1 740 138 747 565 000 000 ns) 2025-02-21 16:32:12 (10968): Guest Log: 03:04:25.536566 timesync vgsvcTimeSyncWorker: Radical guest time change: 5 990 636 765 000ns (GuestNow=1 740 144 731 306 790 000 ns GuestLast=1 740 138 740 670 025 000 ns fSetTimeLastLoop=true ) 2025-02-21 16:45:00 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 16:45:20 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 16:47:59 (10968): Status Report: Elapsed Time: '62012.558569' 2025-02-21 16:47:59 (10968): Status Report: CPU Time: '59986.171875' 2025-02-21 16:56:27 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 17:08:49 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 17:21:54 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 17:22:14 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 18:00:49 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 18:02:47 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 18:02:57 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 18:03:17 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 18:03:27 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 18:03:47 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 18:03:57 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 18:04:18 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 18:04:27 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 18:04:48 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 18:04:57 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 18:05:17 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 18:05:28 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 18:05:48 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 18:05:58 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 18:06:18 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 18:06:28 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 18:06:48 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 18:06:58 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 18:07:18 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 18:07:28 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 18:07:48 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 18:07:58 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 18:08:18 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 18:08:28 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 18:08:48 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 18:08:58 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 18:09:18 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 18:09:28 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 18:09:48 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 18:47:45 (10968): Status Report: Elapsed Time: '68012.558569' 2025-02-21 18:47:45 (10968): Status Report: CPU Time: '65963.421875' 2025-02-21 19:09:03 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 23:17:16 (10968): Guest Log: 05:21:40.018411 timesync vgsvcTimeSyncWorker: Radical host time change: 14 902 822 000 000ns (HostNow=1 740 169 036 050 000 000 ns HostLast=1 740 154 133 228 000 000 ns) 2025-02-21 23:17:16 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 23:17:21 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 23:17:41 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 23:17:46 (10968): Guest Log: 05:21:50.022174 timesync vgsvcTimeSyncWorker: Radical guest time change: 16 080 265 145 000ns (GuestNow=1 740 169 046 053 765 000 ns GuestLast=1 740 152 965 788 620 000 ns fSetTimeLastLoop=true ) 2025-02-21 23:18:35 (10968): VM state change detected. (old = 'running', new = 'paused') 2025-02-21 23:18:51 (10968): VM state change detected. (old = 'paused', new = 'running') 2025-02-21 23:20:50 (10968): Guest Log: *** Job finished *** 2025-02-21 23:20:50 (10968): Guest Log: *** The last 20 lines of the pilot log: *** 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:08,098 | INFO | [data] queue_monitor thread has finished 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:08,220 | INFO | only monitor.control thread still running - safe to abort: ['<_MainThread(MainThread, started 139975789131584)>', '<ExcThread(monitor, started 139975131657984)>'] 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:08,825 | WARNING | job_aborted has been set - aborting pilot monitoring 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:08,825 | INFO | [monitor] control thread has ended 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:13,226 | INFO | all workflow threads have been joined 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:13,227 | INFO | end of generic workflow (traces error code: 1150) 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:13,227 | INFO | traces error code: 1150 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:13,227 | INFO | an exit code was already set: 1150 (will be converted to a standard shell code) 2025-02-21 23:20:50 (10968): Guest Log: no translation to shell exit code for error code 1150 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:13,227 | INFO | pilot has finished (exit code=1150, shell exit code=1) 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:13,385 [wrapper] ==== pilot stdout END ==== 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:13,392 [wrapper] ==== wrapper stdout RESUME ==== 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:13,399 [wrapper] pilotpid: 5798 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:13,405 [wrapper] Pilot exit status: 1 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:14,256 [wrapper] pandaids: 6518301004 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:14,300 [wrapper] cleanup supervisor_pilot 18078 5799 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:14,309 [wrapper] Test setup, not cleaning 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:14,325 [wrapper] apfmon messages muted 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:14,333 [wrapper] ==== wrapper stdout END ==== 2025-02-21 23:20:50 (10968): Guest Log: 2025-02-21 20:20:14,339 [wrapper] ==== wrapper stderr END ==== 2025-02-21 23:20:50 (10968): Guest Log: *** Error codes and diagnostics *** 2025-02-21 23:20:50 (10968): Guest Log: "exeErrorCode": 0, 2025-02-21 23:20:50 (10968): Guest Log: "exeErrorDiag": "", 2025-02-21 23:20:50 (10968): Guest Log: "pilotErrorCode": 1150, 2025-02-21 23:20:50 (10968): Guest Log: "pilotErrorDiag": "Looping job killed by pilot", 2025-02-21 23:20:50 (10968): Guest Log: *** Listing of results directory *** 2025-02-21 23:20:50 (10968): Guest Log: total 8560 2025-02-21 23:20:50 (10968): Guest Log: -rw-r--r--. 1 atlas atlas 491065 Feb 18 15:18 pilot3.tar.gz 2025-02-21 23:20:50 (10968): Guest Log: -rwx------. 1 atlas atlas 35865 Feb 18 15:20 runpilot2-wrapper.sh 2025-02-21 23:20:50 (10968): Guest Log: -rw-r--r--. 1 atlas atlas 5118 Feb 18 15:20 queuedata.json 2025-02-21 23:20:50 (10968): Guest Log: -rwxr-xr-x. 1 atlas atlas 9008 Feb 21 07:57 init_data.xml 2025-02-21 23:20:50 (10968): Guest Log: -rwxr-xr-x. 1 atlas atlas 503555 Feb 21 07:57 input.tar.gz 2025-02-21 23:20:50 (10968): Guest Log: -rwxr-xr-x. 1 atlas atlas 17569 Feb 21 07:57 start_atlas.sh 2025-02-21 23:20:50 (10968): Guest Log: lrwxrwxrwx. 1 atlas atlas 20 Feb 21 07:57 EVNT.43078917._001552.pool.root.1 -> /data/./ATLAS.root_0 2025-02-21 23:20:50 (10968): Guest Log: -rw-r--r--. 1 atlas atlas 2547 Feb 21 07:57 pandaJob.out 2025-02-21 23:20:50 (10968): Guest Log: -rw-------. 1 atlas atlas 424 Feb 21 07:57 setup.sh.local 2025-02-21 23:20:50 (10968): Guest Log: -rw-------. 1 atlas atlas 994744 Feb 21 07:58 agis_schedconf.cvmfs.json 2025-02-21 23:20:50 (10968): Guest Log: drwx------. 4 atlas atlas 4096 Feb 21 07:58 pilot3 2025-02-21 23:20:50 (10968): Guest Log: -rw-------. 1 atlas atlas 98 Feb 21 20:19 pilot_heartbeat.json 2025-02-21 23:20:50 (10968): Guest Log: -rw-------. 1 atlas atlas 1027 Feb 21 20:19 memory_monitor_summary.json 2025-02-21 23:20:50 (10968): Guest Log: -rw-------. 1 atlas atlas 337608 Feb 21 20:19 log.43078919._072258.job.log.tgz.1 2025-02-21 23:20:50 (10968): Guest Log: -rw-------. 1 atlas atlas 1582569 Feb 21 20:19 agis_ddmendpoints.agis.ALL.json 2025-02-21 23:20:50 (10968): Guest Log: -rw-------. 1 atlas atlas 2743 Feb 21 20:20 heartbeat.json 2025-02-21 23:20:50 (10968): Guest Log: -rw-------. 1 atlas atlas 4524 Feb 21 20:20 pilotlog.txt 2025-02-21 23:20:50 (10968): Guest Log: -rw-------. 1 atlas atlas 2180223 Feb 21 20:20 log.43078919._072258.job.log.1 2025-02-21 23:20:50 (10968): Guest Log: -rw-------. 1 atlas atlas 188 Feb 21 20:20 output.list 2025-02-21 23:20:50 (10968): Guest Log: -rw-r--r--. 1 atlas atlas 620 Feb 21 20:20 runtime_log 2025-02-21 23:20:50 (10968): Guest Log: -rw-------. 1 atlas atlas 2529280 Feb 21 20:20 result.tar.gz 2025-02-21 23:20:50 (10968): Guest Log: -rw-------. 1 atlas atlas 653 Feb 21 20:20 ZgGODmHae46n9Rq4apOajLDm4fhM0noT9bVoFjIUDmpOZKDm0h8kCo.diag 2025-02-21 23:20:50 (10968): Guest Log: -rw-r--r--. 1 atlas atlas 10678 Feb 21 20:20 runtime_log.err 2025-02-21 23:20:50 (10968): Guest Log: Looking for outputfile HITS.43078919._072258.pool.root.1 2025-02-21 23:20:50 (10968): Guest Log: No HITS file was produced 2025-02-21 23:20:50 (10968): Guest Log: Successfully finished the ATLAS job! 2025-02-21 23:20:50 (10968): Guest Log: Copying the results back to the shared directory! 2025-02-21 23:20:50 (10968): Guest Log: *** Contents of shared directory: *** 2025-02-21 23:20:50 (10968): Guest Log: total 334796 2025-02-21 23:20:50 (10968): Guest Log: -rwxrwxrwx. 1 root root 339762733 Feb 18 19:07 ATLAS.root_0 2025-02-21 23:20:50 (10968): Guest Log: -rwxrwxrwx. 1 root root 9008 Feb 18 19:07 init_data.xml 2025-02-21 23:20:50 (10968): Guest Log: -rwxrwxrwx. 1 root root 503555 Feb 18 18:53 input.tar.gz 2025-02-21 23:20:50 (10968): Guest Log: -rwxrwxrwx. 1 root root 2529280 Feb 21 2025 result.tar.gz 2025-02-21 23:20:50 (10968): Guest Log: -rwxrwxrwx. 1 root root 17569 Feb 18 18:53 start_atlas.sh 2025-02-21 23:20:50 (10968): Guest Log: *** Success! Shutting down the machine. *** 2025-02-21 23:20:50 (10968): VM Completion File Detected. 2025-02-21 23:20:50 (10968): Powering off VM. 2025-02-21 23:20:52 (10968): Successfully stopped VM. 2025-02-21 23:20:52 (10968): Deregistering VM. (boinc_112bc1f508f5d5bc, slot#1) 2025-02-21 23:20:52 (10968): Removing network bandwidth throttle group from VM. 2025-02-21 23:20:52 (10968): Removing VM from VirtualBox. 23:20:57 (10968): called boinc_finish(0) </stderr_txt> ]]>
©2025 CERN