Message boards : ATLAS application : Sometimes no Hits-file produced according to stderr log for vbox tasks
Message board moderation

To post messages, you must log in.

AuthorMessage
Harri Liljeroos
Avatar

Send message
Joined: 28 Sep 04
Posts: 795
Credit: 64,464,320
RAC: 32,406
Message 39978 - Posted: 20 Sep 2019, 7:20:24 UTC

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
[pre]
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.
[/pre]
And here is an output that looks a bit odd from task:https://lhcathome.cern.ch/lhcathome/result.php?resultid=246093757
[pre]
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.
[/pre]
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.
ID: 39978 · Report as offensive     Reply Quote

Message boards : ATLAS application : Sometimes no Hits-file produced according to stderr log for vbox tasks


©2026 CERN