Message boards :
ATLAS application :
Sometimes no Hits-file produced according to stderr log for vbox tasks
Message board moderation
Author | Message |
---|---|
Send message Joined: 28 Sep 04 Posts: 674 Credit: 43,168,451 RAC: 16,096 |
Lately I have seen some odd lines in the stderr which might relate to not properly ending of an Atlas task. First a snippet of what looks like a normal stderr from task:https://lhcathome.cern.ch/lhcathome/result.php?resultid=246079279 2019-09-19 15:16:46 (9800): Status Report: Elapsed Time: '6004.295595' 2019-09-19 15:16:46 (9800): Status Report: CPU Time: '19444.359375' 2019-09-19 16:56:50 (9800): Status Report: Elapsed Time: '12008.635559' 2019-09-19 16:56:50 (9800): Status Report: CPU Time: '39400.656250' 2019-09-19 18:36:55 (9800): Status Report: Elapsed Time: '18013.250986' 2019-09-19 18:36:55 (9800): Status Report: CPU Time: '61188.125000' 2019-09-19 20:16:59 (9800): Status Report: Elapsed Time: '24017.511396' 2019-09-19 20:16:59 (9800): Status Report: CPU Time: '82512.296875' 2019-09-19 21:57:03 (9800): Status Report: Elapsed Time: '30021.766174' 2019-09-19 21:57:03 (9800): Status Report: CPU Time: '105783.328125' 2019-09-19 23:37:08 (9800): Status Report: Elapsed Time: '36026.391401' 2019-09-19 23:37:08 (9800): Status Report: CPU Time: '126439.234375' 2019-09-20 00:54:31 (9800): Guest Log: The last 10 lines of the pilot log. 2019-09-20 00:54:31 (9800): Guest Log: -rw------- 1 atlas01 atlas01 760 Aug 22 12:01 setup.py 2019-09-20 00:54:31 (9800): Guest Log: -rw------- 1 atlas01 atlas01 221 Jul 25 17:38 TODO.md 2019-09-20 00:54:31 (9800): Guest Log: -rw------- 1 atlas01 atlas01 11 Sep 19 13:37 /home/atlas01/RunAtlas/pilot2/pandaIDs.out 2019-09-20 00:54:31 (9800): Guest Log: 4483542698 2019-09-20 00:54:31 (9800): Guest Log: 2019-09-19 21:53:30 UTC [wrapper] Test setup, not cleaning 2019-09-20 00:54:31 (9800): Guest Log: 2019-09-19 21:53:30 UTC [wrapper] ==== wrapper stdout END ==== 2019-09-20 00:54:31 (9800): Guest Log: 2019-09-19 21:53:30 UTC [wrapper] ==== wrapper stderr END ==== 2019-09-20 00:54:31 (9800): Guest Log: 2019-09-19 21:53:30 UTC [wrapper] wrapper wrapperexiting ec=0, duration=40626 2019-09-20 00:54:31 (9800): Guest Log: 2019-09-19 21:53:30 UTC [wrapper] apfmon messages muted 2019-09-20 00:54:31 (9800): Guest Log: Listing of results directory 2019-09-20 00:54:31 (9800): Guest Log: total 538796 2019-09-20 00:54:31 (9800): Guest Log: -rw-r--r-- 1 atlas01 atlas01 259319 Sep 18 16:25 pilot2.tar.gz 2019-09-20 00:54:31 (9800): Guest Log: -rw-r--r-- 1 atlas01 atlas01 4480 Sep 18 17:05 queuedata.json 2019-09-20 00:54:31 (9800): Guest Log: -rwx------ 1 atlas01 atlas01 12641 Sep 18 17:05 runpilot2-wrapper.sh 2019-09-20 00:54:31 (9800): Guest Log: -rw------- 1 atlas01 atlas01 2839 Sep 18 17:05 pandaJobData.out 2019-09-20 00:54:31 (9800): Guest Log: -rwxr-xr-x 1 atlas01 atlas01 272885263 Sep 19 13:36 EVNT.18605762._000055.pool.root.1 2019-09-20 00:54:31 (9800): Guest Log: -rwxr-xr-x 1 atlas01 atlas01 8593 Sep 19 13:36 init_data.xml 2019-09-20 00:54:31 (9800): Guest Log: -rwxr-xr-x 1 atlas01 atlas01 267471 Sep 19 13:36 input.tar.gz 2019-09-20 00:54:31 (9800): Guest Log: -rwxr-xr-x 1 atlas01 atlas01 812 Sep 19 13:36 RTE.tar.gz 2019-09-20 00:54:31 (9800): Guest Log: -rwxr-xr-x 1 atlas01 atlas01 14022 Sep 19 13:36 start_atlas.sh 2019-09-20 00:54:31 (9800): Guest Log: drwxr-xr-x 3 atlas01 atlas01 4096 Sep 19 13:36 APPS 2019-09-20 00:54:31 (9800): Guest Log: -rw------- 1 atlas01 atlas01 4050984 Sep 19 13:36 agis_schedconf.cvmfs.json 2019-09-20 00:54:31 (9800): Guest Log: -rw------- 1 atlas01 atlas01 7561623 Sep 19 13:37 agis_ddmendpoints.json 2019-09-20 00:54:31 (9800): Guest Log: drwx------ 3 atlas01 atlas01 4096 Sep 19 13:37 pilot2 2019-09-20 00:54:31 (9800): Guest Log: -rw------- 1 atlas01 atlas01 258970875 Sep 20 00:49 HITS.19056259._002750.pool.root.1 2019-09-20 00:54:31 (9800): Guest Log: -rw------- 1 atlas01 atlas01 869188 Sep 20 00:52 log.19056259._002750.job.log.tgz.1 2019-09-20 00:54:31 (9800): Guest Log: -rw------- 1 atlas01 atlas01 72926 Sep 20 00:52 heartbeat.json 2019-09-20 00:54:31 (9800): Guest Log: -rw------- 1 atlas01 atlas01 13637 Sep 20 00:53 pilotlog.txt 2019-09-20 00:54:31 (9800): Guest Log: -rw------- 1 atlas01 atlas01 1893846 Sep 20 00:53 log.19056259._002750.job.log.1 2019-09-20 00:54:31 (9800): Guest Log: -rw------- 1 atlas01 atlas01 463 Sep 20 00:53 output.list 2019-09-20 00:54:31 (9800): Guest Log: -rw-r--r-- 1 atlas01 atlas01 692 Sep 20 00:53 runtime_log 2019-09-20 00:54:31 (9800): Guest Log: -rw------- 1 atlas01 atlas01 4741120 Sep 20 00:53 result.tar.gz 2019-09-20 00:54:31 (9800): Guest Log: -rw-r--r-- 1 atlas01 atlas01 6851 Sep 20 00:53 runtime_log.err 2019-09-20 00:54:31 (9800): Guest Log: -rw------- 1 atlas01 atlas01 531 Sep 20 00:53 qgfMDmNlpUvn9Rq4apoT9bVoABFKDmABFKDmDn7aDmABFKDmC0c7em.diag 2019-09-20 00:54:31 (9800): Guest Log: HITS file was successfully produced 2019-09-20 00:54:31 (9800): Guest Log: -rw------- 1 atlas01 atlas01 258970875 Sep 20 00:49 /home/atlas01/RunAtlas/HITS.19056259._002750.pool.root.1 2019-09-20 00:54:31 (9800): Guest Log: Successfully finished the ATLAS job! 2019-09-20 00:54:31 (9800): Guest Log: Copying the results back to the shared directory! 2019-09-20 00:54:31 (9800): Guest Log: Copied the result file back to the shared directory and created atlas_done file! 2019-09-20 00:54:31 (9800): Guest Log: Success! Shutting down the machine. And here is an output that looks a bit odd from task:https://lhcathome.cern.ch/lhcathome/result.php?resultid=246093757 2019-09-19 15:56:17 (14864): Status Report: Elapsed Time: '6004.350254' 2019-09-19 15:56:17 (14864): Status Report: CPU Time: '18572.750000' 2019-09-19 17:36:21 (14864): Status Report: Elapsed Time: '12008.812870' 2019-09-19 17:36:21 (14864): Status Report: CPU Time: '40275.218750' 2019-09-19 19:16:26 (14864): Status Report: Elapsed Time: '18013.299120' 2019-09-19 19:16:26 (14864): Status Report: CPU Time: '60527.515625' 2019-09-19 20:56:30 (14864): Status Report: Elapsed Time: '24017.753424' 2019-09-19 20:56:30 (14864): Status Report: CPU Time: '83031.171875' 2019-09-19 22:36:35 (14864): Status Report: Elapsed Time: '30022.301228' 2019-09-19 22:36:35 (14864): Status Report: CPU Time: '105165.078125' 2019-09-19 23:36:48 (14864): Guest Log: BIOS: AX=0305 BX=0000 CX=0000 DX=0000 2019-09-20 00:16:40 (14864): Status Report: Elapsed Time: '36027.152363' 2019-09-20 00:16:40 (14864): Status Report: CPU Time: '126463.218750' 2019-09-20 01:56:44 (14864): Status Report: Elapsed Time: '42031.612814' 2019-09-20 01:56:44 (14864): Status Report: CPU Time: '148069.406250' 2019-09-20 03:36:49 (14864): Status Report: Elapsed Time: '48036.180416' 2019-09-20 03:36:49 (14864): Status Report: CPU Time: '168851.828125' 2019-09-20 04:03:10 (14864): VM Completion File Detected. 2019-09-20 04:03:10 (14864): Powering off VM. 2019-09-20 04:03:11 (14864): Successfully stopped VM. Both tasks validate normally. So far I have found that if the 'Status Report' section has 'Guest Log: BIOS' line in the middle, the log is missing the section of file listing and the mention about HITS file. So what can cause the odd 'Guest Log: BIOS ...' line here? The information on this line varies, sometimes it is like shown above but sometimes it has other information. Anyway if there is that kind of line the HITS file is not mentioned and the output is not complete. This is a Win 10 machine with Boinc 7.6.33 and virtualbox 5.1.30 and this started to happen for task during last week. I don't remember seeing this before that. |
©2024 CERN