Name zIPKDmO3YqunShfckohDCDFpABFKDmABFKDmjnFRDmABFKDmAWLvAn_0
Workunit 1901370
Created 30 May 2019, 12:09:41 UTC
Sent 31 May 2019, 1:47:26 UTC
Report deadline 7 Jun 2019, 1:47:26 UTC
Received 31 May 2019, 12:13:07 UTC
Server state Over
Outcome Success
Client state Done
Exit status 0 (0x00000000)
Computer ID 2244
Run time 10 hours 25 min 41 sec
CPU time 10 hours 46 min 53 sec
Validate state Valid
Credit 173.76
Device peak FLOPS 2.00 GFLOPS
Application version ATLAS Simulation v0.62 (native_mt)
x86_64-pc-linux-gnu
Peak working set size 1.91 GB
Peak swap size 2.45 GB
Peak disk usage 844.96 MB

Stderr output

<core_client_version>7.5.1</core_client_version>
<![CDATA[
<stderr_txt>
15:57:11 (15296): wrapper (7.7.26015): starting
15:57:11 (15296): wrapper: running run_atlas (--nthreads 1)
singularity image is /cvmfs/atlas.cern.ch/repo/containers/images/singularity/x86_64-slc6.img
sys.argv = ['run_atlas', '--nthreads', '1']
THREADS=1
Checking for CVMFS
CVMFS is installed
OS:Scientific Linux release 6.10 (Carbon)

This is SLC or CentOS release 6, run the atlas job without Singularity
copy /root/Downloads/BOINC/slots/26/shared/input.tar.gz
copy /root/Downloads/BOINC/slots/26/shared/start_atlas.sh
copy /root/Downloads/BOINC/slots/26/shared/ATLAS.root_0
copy /root/Downloads/BOINC/slots/26/shared/RTE.tar.gz
start atlas job with 
cmd = sh start_atlas.sh > runtime_log 2> runtime_log.err
running cmd return value is 0
Moving ./HITS.18099229._052981.pool.root.1 to shared/HITS.pool.root.1
*****************The last 100 lines of the pilot log******************
2019-06-01 00:38:15,867 | DEBUG    | queue_monitor       | pilot.util.auxiliary             | get_job_metrics           | job metrics="coreCount=1 leak=3.44"
2019-06-01 00:38:15,867 | INFO     | queue_monitor       | pilot.control.job                | get_data_structure        | payload/TRF did not report the number of read events
2019-06-01 00:38:15,869 | INFO     | queue_monitor       | pilot.user.atlas.utilities       | get_memory_values         | using path: /root/Downloads/BOINC/slots/26/PanDA_Pilot-4364228668/memory_monitor_summary.json
2019-06-01 00:38:15,870 | DEBUG    | queue_monitor       | pilot.user.atlas.utilities       | get_memory_monitor_info   | summary_dictionary={'Max': {'maxRSS': 2119752, 'maxSwap': 0, 'totRCHAR': 1649372007, 'totRBYTES': 1636704256, 'totWCHAR': 114468064, 'totWBYTES': 124862464, 'maxVMEM': 3222544, 'maxPSS': 2111304}, 'Avg': {'avgRSS': 2079185, 'rateWCHAR': 2991, 'avgVMEM': 3176384, 'avgPSS': 2070578, 'rateRCHAR': 43105, 'avgSwap': 0, 'rateRBYTES': 42773, 'rateWBYTES': 3263}}
2019-06-01 00:38:15,870 | INFO     | queue_monitor       | pilot.user.atlas.utilities       | get_memory_monitor_info   | extracted standard info from memory monitor json
2019-06-01 00:38:15,870 | INFO     | queue_monitor       | pilot.user.atlas.utilities       | get_memory_monitor_info   | extracted standard memory fields from memory monitor json
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | ..............................
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | . Timing measurements:
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | . get job = 9 s
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | . initial setup = 16 s
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | . payload setup = 0 s
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | . total setup = 16 s
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | . stage-in = 8 s
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | . payload execution = 38352 s
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | . stage-out = 29 s
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | ..............................
2019-06-01 00:38:15,872 | INFO     | queue_monitor       | pilot.util.auxiliary             | get_log_extracts          | building log extracts (sent to the server as 'pilotLog')
2019-06-01 00:38:15,872 | DEBUG    | queue_monitor       | pilot.util.auxiliary             | get_panda_tracer_log      | PanDA tracer log does not exist: /root/Downloads/BOINC/slots/26/PanDA_Pilot-4364228668/pandatracerlog.txt (ignoring)
2019-06-01 00:38:15,872 | INFO     | queue_monitor       | pilot.util.container             | execute                   | executing command: tail -n 20 /root/Downloads/BOINC/slots/26/PanDA_Pilot-4364228668/pilotlog.txt
2019-06-01 00:38:16,011 | DEBUG    | queue_monitor       | pilot.util.auxiliary             | get_pilot_log_extracts    | dumping warning messages from pilotlog.txt:

2019-06-01 00:38:16,097 | WARNING  | queue_monitor       | pilot.util.auxiliary             | get_log_extracts          | detected the following tail of warning/fatal messages in the pilot log:
- Log from pilotlog.txt -2019-06-01 00:38:15,867 | INFO     | queue_monitor       | pilot.api.analytics              | get_fitted_data           | current memory leak: 3.44 B/s (using 617 data points, chi2=-18623716293.945877)
2019-06-01 00:38:15,867 | DEBUG    | queue_monitor       | pilot.util.auxiliary             | get_job_metrics           | job metrics="coreCount=1 leak=3.44"
2019-06-01 00:38:15,867 | INFO     | queue_monitor       | pilot.control.job                | get_data_structure        | payload/TRF did not report the number of read events
2019-06-01 00:38:15,869 | INFO     | queue_monitor       | pilot.user.atlas.utilities       | get_memory_values         | using path: /root/Downloads/BOINC/slots/26/PanDA_Pilot-4364228668/memory_monitor_summary.json
2019-06-01 00:38:15,870 | DEBUG    | queue_monitor       | pilot.user.atlas.utilities       | get_memory_monitor_info   | summary_dictionary={'Max': {'maxRSS': 2119752, 'maxSwap': 0, 'totRCHAR': 1649372007, 'totRBYTES': 1636704256, 'totWCHAR': 114468064, 'totWBYTES': 124862464, 'maxVMEM': 3222544, 'maxPSS': 2111304}, 'Avg': {'avgRSS': 2079185, 'rateWCHAR': 2991, 'avgVMEM': 3176384, 'avgPSS': 2070578, 'rateRCHAR': 43105, 'avgSwap': 0, 'rateRBYTES': 42773, 'rateWBYTES': 3263}}
2019-06-01 00:38:15,870 | INFO     | queue_monitor       | pilot.user.atlas.utilities       | get_memory_monitor_info   | extracted standard info from memory monitor json
2019-06-01 00:38:15,870 | INFO     | queue_monitor       | pilot.user.atlas.utilities       | get_memory_monitor_info   | extracted standard memory fields from memory monitor json
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | ..............................
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | . Timing measurements:
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | . get job = 9 s
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | . initial setup = 16 s
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | . payload setup = 0 s
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | . total setup = 16 s
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | . stage-in = 8 s
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | . payload execution = 38352 s
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | . stage-out = 29 s
2019-06-01 00:38:15,871 | INFO     | queue_monitor       | pilot.util.auxiliary             | timing_report             | ..............................
2019-06-01 00:38:15,872 | INFO     | queue_monitor       | pilot.util.auxiliary             | get_log_extracts          | building log extracts (sent to the server as 'pilotLog')
2019-06-01 00:38:15,872 | DEBUG    | queue_monitor       | pilot.util.auxiliary             | get_panda_tracer_log      | PanDA tracer log does not exist: /root/Downloads/BOINC/slots/26/PanDA_Pilot-4364228668/pandatracerlog.txt (ignoring)
2019-06-01 00:38:15,872 | INFO     | queue_monitor       | pilot.util.container             | execute                   | executing command: tail -n 20 /root/Downloads/BOINC/slots/26/PanDA_Pilot-4364228668/pilotlog.txt
- Error messages from pilotlog.txt -
          "CRITICAL": 0, 

          "ERROR": 0, 

          "FATAL": 0, 


2019-06-01 00:38:16,100 | DEBUG    | queue_monitor       | pilot.control.job                | send_state                | wrote heartbeat to file /root/Downloads/BOINC/slots/26/heartbeat.json
2019-06-01 00:38:16,101 | INFO     | queue_monitor       | pilot.control.job                | queue_monitor             | job 4364228668 was dequeued from the monitored payloads queue
2019-06-01 00:38:17,164 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | 
2019-06-01 00:38:17,165 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | job summary report
2019-06-01 00:38:17,165 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | --------------------------------------------------
2019-06-01 00:38:17,165 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | PanDA job id: 4364228668
2019-06-01 00:38:17,165 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | task id: 18099229
2019-06-01 00:38:17,165 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | errors: (none)
2019-06-01 00:38:17,165 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | status: LOG_TRANSFER = DONE 
2019-06-01 00:38:17,165 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | pilot state: finished 
2019-06-01 00:38:17,166 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | transexitcode: 0
2019-06-01 00:38:17,166 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | exeerrorcode: 0
2019-06-01 00:38:17,166 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | exeerrordiag: 
2019-06-01 00:38:17,166 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | exitcode: 0
2019-06-01 00:38:17,166 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | exitmsg: OK
2019-06-01 00:38:17,166 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | cpuconsumptiontime: 38552 s
2019-06-01 00:38:17,166 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | nevents: 0
2019-06-01 00:38:17,166 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | neventsw: 0
2019-06-01 00:38:17,166 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | pid: 21479
2019-06-01 00:38:17,166 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | pgrp: None
2019-06-01 00:38:17,167 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | corecount: 1
2019-06-01 00:38:17,167 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | event service: False
2019-06-01 00:38:17,167 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | --------------------------------------------------
2019-06-01 00:38:17,167 | INFO     | retrieve            | pilot.util.auxiliary             | make_job_report           | 
2019-06-01 00:38:17,167 | INFO     | retrieve            | pilot.control.job                | has_job_completed         | job 4364228668 has completed
2019-06-01 00:38:17,167 | INFO     | retrieve            | pilot.control.job                | retrieve                  | ready for new job
2019-06-01 00:38:17,167 | DEBUG    | retrieve            | pilot.control.job                | retrieve                  | getjob_requests=1
2019-06-01 00:38:27,208 | DEBUG    | retrieve            | pilot.control.job                | proceed_with_getjob       | proceed_with_getjob called with getjob_requests=1
2019-06-01 00:38:27,209 | DEBUG    | retrieve            | pilot.util.monitoring            | check_local_space         | checking local space on /root/Downloads/BOINC/slots/26
2019-06-01 00:38:27,239 | INFO     | retrieve            | pilot.util.monitoring            | check_local_space         | sufficient remaining disk space (14323548160 B)
2019-06-01 00:38:27,239 | WARNING  | retrieve            | pilot.control.job                | proceed_with_getjob       | since timefloor is set to 0, pilot was only allowed to run one job
2019-06-01 00:38:27,345 | WARNING  | copytool_out        | pilot.util.common                | should_abort              | data:copytool_out:received graceful stop - abort after this iteration
2019-06-01 00:38:27,348 | DEBUG    | copytool_out        | pilot.control.data               | copytool_out              | will abort 
2019-06-01 00:38:27,347 | DEBUG    | job                 | pilot.control.job                | control                   | job control ending since graceful_stop has been set
2019-06-01 00:38:27,448 | DEBUG    | data                | pilot.control.data               | control                   | data control ending since graceful_stop has been set
2019-06-01 00:38:27,471 | INFO     | validate_post       | pilot.control.payload            | validate_post             | validate_post has finished
2019-06-01 00:38:27,753 | DEBUG    | payload             | pilot.control.payload            | control                   | payload control ending since graceful_stop has been set
2019-06-01 00:38:27,861 | DEBUG    | copytool_in         | pilot.control.data               | copytool_in               | copytool_in ended since graceful_stop has been set
2019-06-01 00:38:28,241 | INFO     | monitor             | pilot.control.monitor            | control                   | monitor control has ended
2019-06-01 00:38:28,354 | DEBUG    | copytool_out        | pilot.control.data               | copytool_out              | aborting
2019-06-01 00:38:28,355 | DEBUG    | copytool_out        | pilot.control.data               | copytool_out              | copytool_out has finished
2019-06-01 00:38:28,758 | WARNING  | queue_monitoring    | pilot.util.common                | should_abort              | data:queue_monitoring:received graceful stop - abort after this iteration
2019-06-01 00:38:29,135 | WARNING  | queue_monitor       | pilot.util.common                | should_abort              | job:queue_monitor:received graceful stop - abort after this iteration
2019-06-01 00:38:29,136 | INFO     | queue_monitor       | pilot.control.job                | queue_monitor             | [job] queue monitor has finished
2019-06-01 00:38:31,810 | INFO     | queue_monitoring    | pilot.control.data               | queue_monitoring          | [data] queue monitor has finished
2019-06-01 00:38:49,369 | WARNING  | job_monitor         | pilot.control.job                | check_job_monitor_waiting_time | no jobs in monitored_payloads queue (waited for 61 s)
2019-06-01 00:38:49,370 | INFO     | job_monitor         | pilot.control.job                | job_monitor               | job monitor has finished
2019-06-01 00:38:49,371 | INFO     | MainThread          | pilot.workflow.generic           | run                       | end of generic workflow (traces error code: 0)
2019-06-01 00:38:49,371 | INFO     | MainThread          | root                             | wrap_up                   | traces error code: 0
2019-06-01 00:38:49,372 | INFO     | MainThread          | root                             | wrap_up                   | pilot has finished
***************diag file************
runtimeenvironments=APPS/HEP/ATLAS-SITE;
Processors=1
WallTime=38493.30s
KernelTime=920.44s
UserTime=38485.46s
CPUUsage=102%
MaxResidentMemory=2010732kB
AverageResidentMemory=0kB
AverageTotalMemory=0kB
AverageUnsharedMemory=0kB
AverageUnsharedStack=0kB
AverageSharedMemory=0kB
PageSize=4096B
MajorPageFaults=9623
MinorPageFaults=15856343
Swaps=0
ForcedSwitches=412308
WaitSwitches=19216667
Inputs=3347600
Outputs=303368
SocketReceived=0
SocketSent=0
Signals=0

nodename=maeax@APU8S
exitcode=0
******************************WorkDir***********************
insgesamt 387116
drwxrwx--x.  7 root root      4096  1. Jun 02:38 .
drwxr-x--x. 29 root root      4096 31. Mai 15:57 ..
-rw-------.  1 root root   7284719 31. Mai 15:57 agis_ddmendpoints.json
-rw-------.  1 root root   4801035 31. Mai 15:57 agis_schedconf.cvmfs.json
drwx------.  2 root root      4096 31. Mai 15:57 .alrb
drwxr-xr-x.  3 root root      4096 31. Mai 15:57 APPS
-rw-------.  1 root root       550 31. Mai 15:57 .asetup
-rw-------.  1 root root      2986 31. Mai 15:58 .asetup.save
-rw-r--r--.  1 root root         0 31. Mai 15:57 boinc_lockfile
-rw-r--r--.  1 root root      8192  1. Jun 02:38 boinc_mmap_file
-rw-r--r--.  1 root root       537  1. Jun 02:37 boinc_task_state.xml
-rw-r--r--.  1 root root 379712305 31. Mai 15:57 EVNT.17323923._001013.pool.root.1
-rw-------.  1 root root     59650  1. Jun 02:38 heartbeat.json
-rw-r--r--.  1 root root      5470 31. Mai 15:57 init_data.xml
-rw-r--r--.  1 root root    249687 31. Mai 15:57 input.tar.gz
-rw-r--r--.  1 root root       112 31. Mai 15:57 job.xml
-rw-------.  1 root root   1773300  1. Jun 02:38 log.18099229._052981.job.log.1
-rw-------.  1 root root    324420  1. Jun 02:37 log.18099229._052981.job.log.tgz.1
-rw-------.  1 root root       306  1. Jun 02:37 memory_monitor_summary.json
-rw-------.  1 root root       391  1. Jun 02:38 output.list
-rw-------.  1 4871 1028      2886 30. Mai 14:09 pandaJobData.out
drwxrwx---.  2 root root      4096  1. Jun 02:38 PanDA_Pilot-4364228668
drwxr-xr-x.  3 1700 1332      4096 20. Mai 09:54 pilot2
-rw-r--r--.  1 root root    240831 24. Mai 16:04 pilot2.tar.gz
-rw-------.  1 root root   1758212  1. Jun 02:38 pilotlog.txt
-rw-r--r--.  1 root root      4444 30. Mai 14:05 queuedata.json
-rw-r--r--.  1 root root       786 31. Mai 15:57 RTE.tar.gz
-rwxr-xr-x.  1 root root      8512 31. Mai 15:57 run_atlas
-rwx------.  1 4871 1028     14753 30. Mai 14:09 runpilot2-wrapper.sh
-rw-r--r--.  1 root root       692  1. Jun 02:38 runtime_log
-rw-r--r--.  1 root root      7355  1. Jun 02:38 runtime_log.err
drwxrwx--x.  2 root root      4096  1. Jun 02:38 shared
-rw-r--r--.  1 root root      8714 31. Mai 15:57 start_atlas.sh
-rw-r--r--.  1 root root     16744  1. Jun 02:38 stderr.txt
-rw-r--r--.  1 root root       107 31. Mai 15:57 wrapper_26015_x86_64-pc-linux-gnu
-rw-r--r--.  1 root root        28  1. Jun 02:38 wrapper_checkpoint.txt
-rw-------.  1 root root       493  1. Jun 02:38 zIPKDmO3YqunShfckohDCDFpABFKDmABFKDmjnFRDmABFKDmAWLvAn.diag
running start_atlas return value is 0
Parent exit 0
child process exit 0
02:38:50 (15296): run_atlas exited; CPU time 38486.013236
02:38:50 (15296): called boinc_finish(0)

</stderr_txt>
]]>


©2024 CERN