Name yQuMDmp5czvnShfckohDCDFpABFKDmABFKDmYpuaDmABFKDmnpQYQm_0
Workunit 1960165
Created 12 Dec 2019, 12:49:55 UTC
Sent 12 Dec 2019, 12:52:10 UTC
Report deadline 19 Dec 2019, 12:52:10 UTC
Received 12 Dec 2019, 13:31:17 UTC
Server state Over
Outcome Success
Client state Done
Exit status 0 (0x00000000)
Computer ID 3682
Run time 13 min 20 sec
CPU time 24 min 48 sec
Validate state Valid
Credit 32.62
Device peak FLOPS 17.61 GFLOPS
Application version ATLAS Simulation v0.92 (native_mt)
x86_64-pc-linux-gnu
Peak working set size 1.79 GB
Peak swap size 2.55 GB
Peak disk usage 720.20 MB

Stderr output

<core_client_version>7.16.1</core_client_version>
<![CDATA[
<stderr_txt>
13:52:27 (2381575): wrapper (7.7.26015): starting
13:52:27 (2381575): wrapper: running run_atlas (--nthreads 4)
Thu Dec 12 13:52:27 CET 2019: Using singularity image /cvmfs/atlas.cern.ch/repo/containers/images/singularity/x86_64-centos7.img
Thu Dec 12 13:52:27 CET 2019: Arguments: --nthreads 4
Thu Dec 12 13:52:27 CET 2019: Threads: 4
Thu Dec 12 13:52:27 CET 2019: Checking for CVMFS
Thu Dec 12 13:52:27 CET 2019: Probing /cvmfs/atlas.cern.ch... OK
Thu Dec 12 13:52:27 CET 2019: Probing /cvmfs/atlas-condb.cern.ch... OK
Thu Dec 12 13:52:28 CET 2019: Probing /cvmfs/grid.cern.ch... OK
Thu Dec 12 13:52:28 CET 2019: 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
Thu Dec 12 13:52:28 CET 2019: 2.5.1.0 2362617 13 36688 57871 2 78 7405823 10240001 0 65024 0 21134 99.9905 20484 86067 http://cvmfs-stratum-one.cern.ch/cvmfs/atlas.cern.ch http://137.138.149.107:3128 1
Thu Dec 12 13:52:28 CET 2019: CVMFS is ok
Thu Dec 12 13:52:28 CET 2019: Checking for singularity binary...
Thu Dec 12 13:52:28 CET 2019: Using singularity found in PATH at /usr/bin/singularity
Thu Dec 12 13:52:28 CET 2019: Running /usr/bin/singularity --version
Thu Dec 12 13:52:28 CET 2019: singularity version 3.4.2-1.1.el7
Thu Dec 12 13:52:28 CET 2019: Checking singularity works with /usr/bin/singularity exec -B /cvmfs /cvmfs/atlas.cern.ch/repo/containers/images/singularity/x86_64-centos7.img hostname
Thu Dec 12 13:52:28 CET 2019: pcoslo5.cern.ch
Thu Dec 12 13:52:28 CET 2019: Singularity works
Thu Dec 12 13:52:32 CET 2019: Set ATHENA_PROC_NUMBER=4
Thu Dec 12 13:52:32 CET 2019: Starting ATLAS job with PandaID=4002876565
Thu Dec 12 13:52:32 CET 2019: Running command: /usr/bin/singularity exec --pwd /home/dcameron/boinc/slots/0 -B /cvmfs,/home /cvmfs/atlas.cern.ch/repo/containers/images/singularity/x86_64-centos7.img sh start_atlas.sh
Thu Dec 12 14:05:45 CET 2019:  *** The last 200 lines of the pilot log: ***
Thu Dec 12 14:05:45 CET 2019:             "avgPSS": 643, 
Thu Dec 12 14:05:45 CET 2019:             "avgRSS": 1632, 
Thu Dec 12 14:05:45 CET 2019:             "avgSwap": 0, 
Thu Dec 12 14:05:45 CET 2019:             "avgVMEM": 9768, 
Thu Dec 12 14:05:45 CET 2019:             "rateRBYTES": 0, 
Thu Dec 12 14:05:45 CET 2019:             "rateRCHAR": 64, 
Thu Dec 12 14:05:45 CET 2019:             "rateWBYTES": 0, 
Thu Dec 12 14:05:45 CET 2019:             "rateWCHAR": 0
Thu Dec 12 14:05:45 CET 2019:           }, 
Thu Dec 12 14:05:45 CET 2019:           "Max": {
Thu Dec 12 14:05:45 CET 2019:             "maxPSS": 648, 
Thu Dec 12 14:05:45 CET 2019:             "maxRSS": 1632, 
Thu Dec 12 14:05:45 CET 2019:             "maxSwap": 0, 
Thu Dec 12 14:05:45 CET 2019:             "maxVMEM": 9768, 
Thu Dec 12 14:05:45 CET 2019:             "totRBYTES": 0, 
Thu Dec 12 14:05:45 CET 2019:             "totRCHAR": 5844, 
Thu Dec 12 14:05:45 CET 2019:             "totWBYTES": 0, 
Thu Dec 12 14:05:45 CET 2019:             "totWCHAR": 89
Thu Dec 12 14:05:45 CET 2019:           }
Thu Dec 12 14:05:45 CET 2019:         }, 
Thu Dec 12 14:05:45 CET 2019:         "postExe": {
Thu Dec 12 14:05:45 CET 2019:           "cpuTime": 0, 
Thu Dec 12 14:05:45 CET 2019:           "wallTime": 1
Thu Dec 12 14:05:45 CET 2019:         }, 
Thu Dec 12 14:05:45 CET 2019:         "preExe": {
Thu Dec 12 14:05:45 CET 2019:           "cpuTime": 0, 
Thu Dec 12 14:05:45 CET 2019:           "wallTime": 1
Thu Dec 12 14:05:45 CET 2019:         }, 
Thu Dec 12 14:05:45 CET 2019:         "total": {
Thu Dec 12 14:05:45 CET 2019:           "cpuTime": 32, 
Thu Dec 12 14:05:45 CET 2019:           "wallTime": 66
Thu Dec 12 14:05:45 CET 2019:         }, 
Thu Dec 12 14:05:45 CET 2019:         "validation": {
Thu Dec 12 14:05:45 CET 2019:           "cpuTime": 0, 
Thu Dec 12 14:05:45 CET 2019:           "wallTime": 0
Thu Dec 12 14:05:45 CET 2019:         }, 
Thu Dec 12 14:05:45 CET 2019:         "wallTime": 64
Thu Dec 12 14:05:45 CET 2019:       }
Thu Dec 12 14:05:45 CET 2019:     }, 
Thu Dec 12 14:05:45 CET 2019:     "machine": {
Thu Dec 12 14:05:45 CET 2019:       "cpu_family": "6", 
Thu Dec 12 14:05:45 CET 2019:       "linux_distribution": [
Thu Dec 12 14:05:45 CET 2019:         "CentOS Linux", 
Thu Dec 12 14:05:45 CET 2019:         "7.6.1810", 
Thu Dec 12 14:05:45 CET 2019:         "Core"
Thu Dec 12 14:05:45 CET 2019:       ], 
Thu Dec 12 14:05:45 CET 2019:       "model": "60", 
Thu Dec 12 14:05:45 CET 2019:       "model_name": "Intel(R) Core(TM) i7-4790 CPU @ 3.60GHz", 
Thu Dec 12 14:05:45 CET 2019:       "node": "pcoslo5.cern.ch", 
Thu Dec 12 14:05:45 CET 2019:       "platform": "Linux-3.10.0-1062.4.3.el7.x86_64-x86_64-with-centos-7.6.1810-Core"
Thu Dec 12 14:05:45 CET 2019:     }, 
Thu Dec 12 14:05:45 CET 2019:     "transform": {
Thu Dec 12 14:05:45 CET 2019:       "cpuEfficiency": 0.5564, 
Thu Dec 12 14:05:45 CET 2019:       "cpuPWEfficiency": 0.5955, 
Thu Dec 12 14:05:45 CET 2019:       "cpuTime": 3, 
Thu Dec 12 14:05:45 CET 2019:       "cpuTimeTotal": 1512, 
Thu Dec 12 14:05:45 CET 2019:       "externalCpuTime": 3, 
Thu Dec 12 14:05:45 CET 2019:       "processedEvents": 10, 
Thu Dec 12 14:05:45 CET 2019:       "trfPredata": null, 
Thu Dec 12 14:05:45 CET 2019:       "wallTime": 665
Thu Dec 12 14:05:45 CET 2019:     }
Thu Dec 12 14:05:45 CET 2019:   }
Thu Dec 12 14:05:45 CET 2019: }
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,022 | DEBUG    | queue_monitor       | pilot.util.auxiliary.4002876565  | update_server             | xml:will send fileinfo
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,022 | INFO     | queue_monitor       | pilot.control.job.4002876565     | send_state                | pilot will not update the server (heartbeat message will be written to file)
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,022 | INFO     | queue_monitor       | pilot.control.job.4002876565     | send_state                | job 4002876565 has finished - writing final server update
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,022 | DEBUG    | queue_monitor       | pilot.control.job.4002876565     | get_data_structure        | building data structure to be sent to server with heartbeat
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,023 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | get_job_metrics           | will not add max space = -350977418 B to job metrics
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,023 | DEBUG    | queue_monitor       | pilot.api.analytics              | get_fitted_data           | removing tails from data to be fitted
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,023 | WARNING  | queue_monitor       | pilot.api.analytics              | get_fitted_data           | wrong length of table data, x=[1576155486.0, 1576155547.0, 1576155608.0, 1576155669.0, 1576155730.0], y=[2450954.0, 2489426.0, 2503451.0, 2089232.0, 2092104.0] (must be same and length>=4)
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,023 | DEBUG    | queue_monitor       | pilot.util.auxiliary.4002876565  | get_job_metrics           | job metrics="coreCount=4 actualCoreCount=1 nEvents=10"
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,023 | INFO     | queue_monitor       | pilot.control.job.4002876565     | get_data_structure        | total number of processed events: 10 (read)
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,024 | INFO     | queue_monitor       | pilot.user.atlas.utilities       | get_memory_values         | using path: /home/dcameron/boinc/slots/0/PanDA_Pilot-4002876565/memory_monitor_summary.json (trf name=prmon)
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,024 | DEBUG    | queue_monitor       | pilot.user.atlas.utilities       | get_memory_monitor_info   | summary_dictionary={'Max': {'rx_packets': 39388, 'nprocs': 9, 'nthreads': 1, 'rx_bytes': 32016117, 'wtime': 677, 'rss': 9420716, 'write_bytes': 0, 'vmem': 14017560, 'read_bytes': 0, 'stime': 16, 'tx_bytes': 30030035, 'pss': 2503451, 'wchar': 0, 'rchar': 0, 'tx_packets': 36727, 'swap': 0, 'utime': 1485}, 'Avg': {'write_bytes': 0, 'nprocs': 6, 'nthreads': 0, 'rx_bytes': 47260, 'rx_packets': 58, 'vmem': 7536041, 'read_bytes': 0, 'swap': 0, 'tx_bytes': 44328, 'pss': 1631527, 'wchar': 0, 'rchar': 0, 'tx_packets': 54, 'rss': 4816104}}
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,025 | INFO     | queue_monitor       | pilot.user.atlas.utilities       | get_memory_monitor_info   | extracted standard info from prmon json
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,025 | INFO     | queue_monitor       | pilot.user.atlas.utilities       | get_memory_monitor_info   | extracted standard memory fields from prmon json
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,025 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | ..............................
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,025 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | . Timing measurements:
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,025 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | . get job = 0 s
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,025 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | . initial setup = 0 s
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,025 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | . payload setup = 0 s
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,025 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | . total setup = 0 s
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,025 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | . stage-in = 0 s
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,025 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | . payload execution = 730 s
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,025 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | . stage-out = 1 s
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,025 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | ..............................
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,026 | DEBUG    | queue_monitor       | pilot.control.job.4002876565     | send_state                | wrote heartbeat to file /home/dcameron/boinc/slots/0/heartbeat.json
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,026 | DEBUG    | queue_monitor       | pilot.control.job                | queue_monitor             | job 4002876565 was dequeued from the monitored payloads queue
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,026 | DEBUG    | queue_monitor       | pilot.control.job                | queue_monitor             | tmp job object deleted
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | 
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | job summary report
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | --------------------------------------------------
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | PanDA job id: 4002876565
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | task id: 000649-3918984-31974
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | errors: (none)
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | status: LOG_TRANSFER = DONE 
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | pilot state: finished 
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | transexitcode: 0
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | exeerrorcode: 0
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | exeerrordiag: 
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | exitcode: 0
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | exitmsg: OK
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | cpuconsumptiontime: 1501 s
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | nevents: 10
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | neventsw: 0
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | pid: 2388539
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | pgrp: 2388539
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,107 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | corecount: 4
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,108 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | event service: False
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,108 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | --------------------------------------------------
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,108 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | 
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,108 | INFO     | retrieve            | pilot.control.job.4002876565     | has_job_completed         | job 4002876565 has completed
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,108 | INFO     | retrieve            | pilot.util.processes             | cleanup                   | overall cleanup function is called
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:11,111 | DEBUG    | retrieve            | pilot.util.processes             | cleanup                   | work directory was removed: /home/dcameron/boinc/slots/0/PanDA_Pilot-4002876565
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:12,117 | INFO     | retrieve            | pilot.info.jobdata               | collect_zombies           | --- collectZombieJob: --- 10, [2388539]
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:12,117 | INFO     | retrieve            | pilot.info.jobdata               | collect_zombies           | zombie collector trying to kill pid 2388539
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:12,117 | INFO     | retrieve            | pilot.info.jobdata               | collect_zombies           | harmless exception when collecting zombies: [Errno 10] No child processes
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,120 | INFO     | retrieve            | pilot.util.processes             | cleanup                   | collected zombie processes
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,120 | INFO     | retrieve            | pilot.util.processes             | cleanup                   | will now attempt to kill all subprocesses of pid=2388539
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,182 | INFO     | retrieve            | pilot.util.processes             | kill_processes            | process IDs to be killed: [2388539] (in reverse order)
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,213 | WARNING  | retrieve            | pilot.util.processes             | kill_processes            | found no corresponding commands to process id(s)
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,213 | INFO     | retrieve            | pilot.util.processes             | kill_orphans              | Do not look for orphan processes in BOINC jobs
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,213 | INFO     | retrieve            | pilot.util.processes             | cleanup                   | resetting job object
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,213 | INFO     | retrieve            | pilot.control.job                | retrieve                  | ready for new job
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,213 | INFO     | retrieve            | root                             | retrieve                  | pilot has finished for previous job - re-establishing logging
Thu Dec 12 14:05:45 CET 2019: mpi4py not found
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,216 | INFO     | retrieve            | pilot.util.auxiliary             | pilot_version_banner      | ****************************************
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,216 | INFO     | retrieve            | pilot.util.auxiliary             | pilot_version_banner      | ***  PanDA Pilot version 2.3.3 (16)  ***
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,216 | INFO     | retrieve            | pilot.util.auxiliary             | pilot_version_banner      | ****************************************
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,216 | INFO     | retrieve            | pilot.util.auxiliary             | pilot_version_banner      | 
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,216 | INFO     | retrieve            | pilot.util.auxiliary             | display_architecture_info | architecture information:
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,249 | INFO     | retrieve            | pilot.util.auxiliary             | display_architecture_info | 
Thu Dec 12 14:05:45 CET 2019: LSB Version:	:core-4.1-amd64:core-4.1-noarch
Thu Dec 12 14:05:45 CET 2019: Distributor ID:	CentOS
Thu Dec 12 14:05:45 CET 2019: Description:	CentOS Linux release 7.6.1810 (Core) 
Thu Dec 12 14:05:45 CET 2019: Release:	7.6.1810
Thu Dec 12 14:05:45 CET 2019: Codename:	Core
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,249 | INFO     | retrieve            | pilot.util.auxiliary             | pilot_version_banner      | ****************************************
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,752 | DEBUG    | retrieve            | pilot.util.monitoring            | check_local_space         | checking local space on /home/dcameron/boinc/slots/0
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,762 | INFO     | retrieve            | pilot.util.monitoring            | check_local_space         | sufficient remaining disk space (36487299072 B)
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,762 | WARNING  | retrieve            | pilot.control.job                | proceed_with_getjob       | since timefloor is set to 0, pilot was only allowed to run one job
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,763 | DEBUG    | retrieve            | pilot.control.job                | retrieve                  | [job] retrieve thread has finished
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,796 | WARNING  | monitor             | pilot.control.monitor            | control                   | aborting monitor loop since graceful_stop has been set
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,797 | INFO     | monitor             | pilot.control.monitor            | control                   | [monitor] control thread has ended
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,809 | WARNING  | copytool_out        | pilot.util.common                | should_abort              | data:copytool_out:received graceful stop - abort after this iteration
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,860 | DEBUG    | data                | pilot.control.data               | control                   | data control ending since graceful_stop has been set
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,861 | DEBUG    | data                | pilot.control.data               | control                   | [data] control thread has finished
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,963 | DEBUG    | payload             | pilot.control.payload            | control                   | payload control ending since graceful_stop has been set
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:13,963 | DEBUG    | payload             | pilot.control.payload            | control                   | [payload] control thread has finished
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:14,062 | DEBUG    | MainThread          | pilot.workflow.generic           | run                       | thread count now at 13 threads
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:14,062 | DEBUG    | MainThread          | pilot.workflow.generic           | run                       | enumerate: [<_MainThread(MainThread, started 140701108262720)>, <ExcThread(job, started 140700945843968)>, <ExcThread(validate_post, started 140700159039232)>, <ExcThread(queue_monitoring, started 140700687517440)>, <ExcThread(job_monitor, started 140700175824640)>, <ExcThread(copytool_in, started 140700167431936)>, <ExcThread(validate, started 140700937451264)>, <ExcThread(copytool_out, started 140700712695552)>, <ExcThread(queue_monitor, started 140700150646528)>, <ExcThread(validate_pre, started 140700670732032)>, <ExcThread(failed_post, started 140700142253824)>, <ExcThread(create_data_payload, started 140700695910144)>, <ExcThread(execute_payloads, started 140700133861120)>]
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:14,147 | INFO     | failed_post         | pilot.control.payload            | failed_post               | [payload] failed_post thread has finished
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:14,161 | DEBUG    | validate            | pilot.control.job                | validate                  | [job] validate thread has finished
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:14,185 | INFO     | validate_pre        | pilot.control.payload            | validate_pre              | [payload] validate_pre thread has finished
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:14,341 | DEBUG    | create_data_payload | pilot.control.job                | create_data_payload       | [job] create_data_payload thread has finished
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:14,466 | DEBUG    | job                 | pilot.control.job                | control                   | job control ending since graceful_stop has been set
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:14,466 | DEBUG    | job                 | pilot.control.job                | control                   | [job] control thread has finished
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:14,538 | DEBUG    | copytool_in         | pilot.control.data               | copytool_in               | [data] copytool_in thread has finished
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:14,810 | DEBUG    | copytool_out        | pilot.control.data               | copytool_out              | [data] copytool_out thread has finished
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:14,859 | INFO     | validate_post       | pilot.control.payload            | validate_post             | [payload] validate_post thread has finished
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:15,067 | DEBUG    | MainThread          | pilot.workflow.generic           | run                       | thread count now at 5 threads
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:15,068 | DEBUG    | MainThread          | pilot.workflow.generic           | run                       | enumerate: [<_MainThread(MainThread, started 140701108262720)>, <ExcThread(queue_monitoring, started 140700687517440)>, <ExcThread(job_monitor, started 140700175824640)>, <ExcThread(queue_monitor, started 140700150646528)>, <ExcThread(execute_payloads, started 140700133861120)>]
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:15,130 | INFO     | execute_payloads    | pilot.control.payload            | execute_payloads          | [payload] execute_payloads thread has finished
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:15,337 | WARNING  | queue_monitoring    | pilot.util.common                | should_abort              | data:queue_monitoring:received graceful stop - abort after this iteration
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:16,032 | WARNING  | queue_monitor       | pilot.util.common                | should_abort              | job:queue_monitor:received graceful stop - abort after this iteration
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:16,032 | DEBUG    | queue_monitor       | pilot.control.job                | queue_monitor             | [job] queue monitor thread has finished
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:16,068 | DEBUG    | MainThread          | pilot.workflow.generic           | run                       | thread count now at 3 threads
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:16,068 | DEBUG    | MainThread          | pilot.workflow.generic           | run                       | enumerate: [<_MainThread(MainThread, started 140701108262720)>, <ExcThread(queue_monitoring, started 140700687517440)>, <ExcThread(job_monitor, started 140700175824640)>]
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:18,338 | DEBUG    | queue_monitoring    | pilot.control.data               | queue_monitoring          | [data] queue_monitor thread has finished
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:19,080 | DEBUG    | MainThread          | pilot.workflow.generic           | run                       | thread count now at 2 threads
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:19,080 | DEBUG    | MainThread          | pilot.workflow.generic           | run                       | enumerate: [<_MainThread(MainThread, started 140701108262720)>, <ExcThread(job_monitor, started 140700175824640)>]
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:44,865 | WARNING  | job_monitor         | pilot.control.job                | check_job_monitor_waiting_time | no jobs in monitored_payloads queue (waited for 71 s)
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:44,865 | DEBUG    | job_monitor         | pilot.control.job                | job_monitor               | [job] job monitor thread has finished
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:45,159 | INFO     | MainThread          | pilot.workflow.generic           | run                       | end of generic workflow (traces error code: 0)
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:45,159 | INFO     | MainThread          | root                             | wrap_up                   | traces error code: 0
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:45,159 | INFO     | MainThread          | root                             | wrap_up                   | pilot has finished
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:45 UTC [wrapper] ==== pilot stdout END ====
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:45 UTC [wrapper] ==== wrapper stdout RESUME ====
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:45 UTC [wrapper] Pilot exit status: 0
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:45 UTC [wrapper] STATUSCODE: 0
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:45 UTC [wrapper] apfmon messages muted
Thu Dec 12 14:05:45 CET 2019: ---- find pandaID.out ----
Thu Dec 12 14:05:45 CET 2019: total 60
Thu Dec 12 14:05:45 CET 2019: -rw-------.  1 dcameron zp 11357 Jul 25 16:38 LICENSE
Thu Dec 12 14:05:45 CET 2019: -rw-------.  1 dcameron zp    20 Sep  9 13:04 MANIFEST.IN
Thu Dec 12 14:05:45 CET 2019: -rw-------.  1 dcameron zp    11 Dec 12 13:52 pandaIDs.out
Thu Dec 12 14:05:45 CET 2019: drwx------. 14 dcameron zp   216 Dec 12 13:52 pilot
Thu Dec 12 14:05:45 CET 2019: -rwx------.  1 dcameron zp 20750 Dec  2 11:02 pilot.py
Thu Dec 12 14:05:45 CET 2019: -rw-------.  1 dcameron zp     8 Dec  2 11:02 PILOTVERSION
Thu Dec 12 14:05:45 CET 2019: -rw-------.  1 dcameron zp  2212 Nov 14 11:01 README.md
Thu Dec 12 14:05:45 CET 2019: -rw-------.  1 dcameron zp   766 Oct 10 16:01 setup.py
Thu Dec 12 14:05:45 CET 2019: -rw-------.  1 dcameron zp   221 Jul 25 16:38 TODO.md
Thu Dec 12 14:05:45 CET 2019: -rw-------. 1 dcameron zp 11 Dec 12 13:52 /home/dcameron/boinc/slots/0/pilot2/pandaIDs.out
Thu Dec 12 14:05:45 CET 2019: 4002876565
Thu Dec 12 14:05:45 CET 2019: 
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:45 UTC [wrapper] Test setup, not cleaning
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:45 UTC [wrapper] ==== wrapper stdout END ====
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:45 UTC [wrapper] ==== wrapper stderr END ====
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:45 UTC [wrapper] wrapper wrapperexiting ec=0, duration=793
Thu Dec 12 14:05:45 CET 2019: 2019-12-12 13:05:45 UTC [wrapper] apfmon messages muted
Thu Dec 12 14:05:45 CET 2019:  *** Error codes and diagnostics ***
Thu Dec 12 14:05:45 CET 2019:     "exeErrorCode": 0,
Thu Dec 12 14:05:45 CET 2019:     "exeErrorDiag": "",
Thu Dec 12 14:05:45 CET 2019:     "pilotErrorCode": 0,
Thu Dec 12 14:05:45 CET 2019:     "pilotErrorDiag": "",
Thu Dec 12 14:05:45 CET 2019:  *** Listing of results directory ***
Thu Dec 12 14:05:45 CET 2019: total 379280
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp    266835 Dec 12 13:26 pilot2.tar.gz
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp      4492 Dec 12 13:46 queuedata.json
Thu Dec 12 14:05:45 CET 2019: -rw-------. 1 dcameron zp      2958 Dec 12 13:49 pandaJobData.out
Thu Dec 12 14:05:45 CET 2019: -rwx------. 1 dcameron zp     12641 Dec 12 13:49 runpilot2-wrapper.sh
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp       107 Dec 12 13:52 wrapper_26015_x86_64-pc-linux-gnu
Thu Dec 12 14:05:45 CET 2019: -rwxr-xr-x. 1 dcameron zp      4813 Dec 12 13:52 run_atlas
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp       112 Dec 12 13:52 job.xml
Thu Dec 12 14:05:45 CET 2019: drwxrwx--x. 2 dcameron zp        86 Dec 12 13:52 shared
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp      6274 Dec 12 13:52 init_data.xml
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp         0 Dec 12 13:52 boinc_lockfile
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp 365251149 Dec 12 13:52 EVNT.14296418._001447.pool.root.1
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp       815 Dec 12 13:52 RTE.tar.gz
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp    275010 Dec 12 13:52 input.tar.gz
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp      8581 Dec 12 13:52 start_atlas.sh
Thu Dec 12 14:05:45 CET 2019: drwxr-xr-x. 3 dcameron zp        17 Dec 12 13:52 APPS
Thu Dec 12 14:05:45 CET 2019: -rw-------. 1 dcameron zp   3742492 Dec 12 13:52 agis_schedconf.cvmfs.json
Thu Dec 12 14:05:45 CET 2019: -rw-------. 1 dcameron zp   7755224 Dec 12 13:52 agis_ddmendpoints.json
Thu Dec 12 14:05:45 CET 2019: drwx------. 3 dcameron zp       229 Dec 12 13:52 pilot2
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp       534 Dec 12 14:00 boinc_task_state.xml
Thu Dec 12 14:05:45 CET 2019: -rw-------. 1 dcameron zp   9151293 Dec 12 14:04 HITS.000649-3918984-31974._078090.pool.root.1
Thu Dec 12 14:05:45 CET 2019: -rw-------. 1 dcameron zp       786 Dec 12 14:05 memory_monitor_summary.json
Thu Dec 12 14:05:45 CET 2019: -rw-------. 1 dcameron zp    713905 Dec 12 14:05 log.000649-3918984-31974._078090.job.log.tgz.1
Thu Dec 12 14:05:45 CET 2019: -rw-------. 1 dcameron zp     15005 Dec 12 14:05 heartbeat.json
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp      8192 Dec 12 14:05 boinc_mmap_file
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp        25 Dec 12 14:05 wrapper_checkpoint.txt
Thu Dec 12 14:05:45 CET 2019: -rw-------. 1 dcameron zp      8586 Dec 12 14:05 pilotlog.txt
Thu Dec 12 14:05:45 CET 2019: -rw-------. 1 dcameron zp    163260 Dec 12 14:05 log.000649-3918984-31974._078090.job.log.1
Thu Dec 12 14:05:45 CET 2019: -rw-------. 1 dcameron zp       504 Dec 12 14:05 yQuMDmp5czvnShfckohDCDFpABFKDmABFKDmYpuaDmABFKDmnpQYQm.diag
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp      7492 Dec 12 14:05 runtime_log.err
Thu Dec 12 14:05:45 CET 2019: -rw-------. 1 dcameron zp       499 Dec 12 14:05 output.list
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp       742 Dec 12 14:05 runtime_log
Thu Dec 12 14:05:45 CET 2019: -rw-------. 1 dcameron zp    901120 Dec 12 14:05 result.tar.gz
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp      2235 Dec 12 14:05 stderr.txt
Thu Dec 12 14:05:45 CET 2019: HITS file was successfully produced:
Thu Dec 12 14:05:45 CET 2019: -rw-------. 1 dcameron zp 9151293 Dec 12 14:04 shared/HITS.pool.root.1
Thu Dec 12 14:05:45 CET 2019:  *** Contents of shared directory: ***
Thu Dec 12 14:05:45 CET 2019: total 366800
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp      8553 Dec 12 13:52 start_atlas.sh
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp       815 Dec 12 13:52 RTE.tar.gz
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp    275010 Dec 12 13:52 input.tar.gz
Thu Dec 12 14:05:45 CET 2019: -rw-r--r--. 1 dcameron zp 365251149 Dec 12 13:52 ATLAS.root_0
Thu Dec 12 14:05:45 CET 2019: -rw-------. 1 dcameron zp   9151293 Dec 12 14:04 HITS.pool.root.1
Thu Dec 12 14:05:45 CET 2019: -rw-------. 1 dcameron zp    901120 Dec 12 14:05 result.tar.gz
14:05:45 (2381575): run_atlas exited; CPU time 1488.973738
14:05:45 (2381575): called boinc_finish(0)

</stderr_txt>
]]>


©2024 CERN