Name 0WiKDmk5czvnShfckohDCDFpABFKDmABFKDmRVuaDmABFKDmewrRHo_0
Workunit 1960160
Created 12 Dec 2019, 12:49:50 UTC
Sent 12 Dec 2019, 14:45:33 UTC
Report deadline 19 Dec 2019, 14:45:33 UTC
Received 12 Dec 2019, 15:24:34 UTC
Server state Over
Outcome Success
Client state Done
Exit status 0 (0x00000000)
Computer ID 3682
Run time 13 min 17 sec
CPU time 26 min 12 sec
Validate state Valid
Credit 32.50
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.21 MB

Stderr output

<core_client_version>7.16.1</core_client_version>
<![CDATA[
<stderr_txt>
16:11:11 (2584462): wrapper (7.7.26015): starting
16:11:11 (2584462): wrapper: running run_atlas (--nthreads 4)
Thu Dec 12 16:11:11 CET 2019: Using singularity image /cvmfs/atlas.cern.ch/repo/containers/images/singularity/x86_64-centos7.img
Thu Dec 12 16:11:11 CET 2019: Arguments: --nthreads 4
Thu Dec 12 16:11:11 CET 2019: Threads: 4
Thu Dec 12 16:11:11 CET 2019: Checking for CVMFS
Thu Dec 12 16:11:11 CET 2019: Probing /cvmfs/atlas.cern.ch... OK
Thu Dec 12 16:11:11 CET 2019: Probing /cvmfs/atlas-condb.cern.ch... OK
Thu Dec 12 16:11:12 CET 2019: Probing /cvmfs/grid.cern.ch... OK
Thu Dec 12 16:11:12 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 16:11:12 CET 2019: 2.5.1.0 2362617 152 41020 57873 3 78 7543208 10240001 0 65024 0 253433 99.998 61265 81577 http://cvmfs-stratum-one.cern.ch/cvmfs/atlas.cern.ch http://137.138.149.107:3128 1
Thu Dec 12 16:11:12 CET 2019: CVMFS is ok
Thu Dec 12 16:11:12 CET 2019: Checking for singularity binary...
Thu Dec 12 16:11:12 CET 2019: Using singularity found in PATH at /usr/bin/singularity
Thu Dec 12 16:11:12 CET 2019: Running /usr/bin/singularity --version
Thu Dec 12 16:11:12 CET 2019: singularity version 3.4.2-1.1.el7
Thu Dec 12 16:11:12 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 16:11:12 CET 2019: pcoslo5.cern.ch
Thu Dec 12 16:11:12 CET 2019: Singularity works
Thu Dec 12 16:11:13 CET 2019: Set ATHENA_PROC_NUMBER=4
Thu Dec 12 16:11:13 CET 2019: Starting ATLAS job with PandaID=4002876565
Thu Dec 12 16:11:13 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 16:24:25 CET 2019:  *** The last 200 lines of the pilot log: ***
Thu Dec 12 16:24:25 CET 2019:             "avgPSS": 647, 
Thu Dec 12 16:24:25 CET 2019:             "avgRSS": 1628, 
Thu Dec 12 16:24:25 CET 2019:             "avgSwap": 0, 
Thu Dec 12 16:24:25 CET 2019:             "avgVMEM": 9768, 
Thu Dec 12 16:24:25 CET 2019:             "rateRBYTES": 0, 
Thu Dec 12 16:24:25 CET 2019:             "rateRCHAR": 64, 
Thu Dec 12 16:24:25 CET 2019:             "rateWBYTES": 0, 
Thu Dec 12 16:24:25 CET 2019:             "rateWCHAR": 0
Thu Dec 12 16:24:25 CET 2019:           }, 
Thu Dec 12 16:24:25 CET 2019:           "Max": {
Thu Dec 12 16:24:25 CET 2019:             "maxPSS": 647, 
Thu Dec 12 16:24:25 CET 2019:             "maxRSS": 1628, 
Thu Dec 12 16:24:25 CET 2019:             "maxSwap": 0, 
Thu Dec 12 16:24:25 CET 2019:             "maxVMEM": 9768, 
Thu Dec 12 16:24:25 CET 2019:             "totRBYTES": 0, 
Thu Dec 12 16:24:25 CET 2019:             "totRCHAR": 5844, 
Thu Dec 12 16:24:25 CET 2019:             "totWBYTES": 0, 
Thu Dec 12 16:24:25 CET 2019:             "totWCHAR": 89
Thu Dec 12 16:24:25 CET 2019:           }
Thu Dec 12 16:24:25 CET 2019:         }, 
Thu Dec 12 16:24:25 CET 2019:         "postExe": {
Thu Dec 12 16:24:25 CET 2019:           "cpuTime": 0, 
Thu Dec 12 16:24:25 CET 2019:           "wallTime": 1
Thu Dec 12 16:24:25 CET 2019:         }, 
Thu Dec 12 16:24:25 CET 2019:         "preExe": {
Thu Dec 12 16:24:25 CET 2019:           "cpuTime": 0, 
Thu Dec 12 16:24:25 CET 2019:           "wallTime": 1
Thu Dec 12 16:24:25 CET 2019:         }, 
Thu Dec 12 16:24:25 CET 2019:         "total": {
Thu Dec 12 16:24:25 CET 2019:           "cpuTime": 32, 
Thu Dec 12 16:24:25 CET 2019:           "wallTime": 65
Thu Dec 12 16:24:25 CET 2019:         }, 
Thu Dec 12 16:24:25 CET 2019:         "validation": {
Thu Dec 12 16:24:25 CET 2019:           "cpuTime": 0, 
Thu Dec 12 16:24:25 CET 2019:           "wallTime": 0
Thu Dec 12 16:24:25 CET 2019:         }, 
Thu Dec 12 16:24:25 CET 2019:         "wallTime": 64
Thu Dec 12 16:24:25 CET 2019:       }
Thu Dec 12 16:24:25 CET 2019:     }, 
Thu Dec 12 16:24:25 CET 2019:     "machine": {
Thu Dec 12 16:24:25 CET 2019:       "cpu_family": "6", 
Thu Dec 12 16:24:25 CET 2019:       "linux_distribution": [
Thu Dec 12 16:24:25 CET 2019:         "CentOS Linux", 
Thu Dec 12 16:24:25 CET 2019:         "7.6.1810", 
Thu Dec 12 16:24:25 CET 2019:         "Core"
Thu Dec 12 16:24:25 CET 2019:       ], 
Thu Dec 12 16:24:25 CET 2019:       "model": "60", 
Thu Dec 12 16:24:25 CET 2019:       "model_name": "Intel(R) Core(TM) i7-4790 CPU @ 3.60GHz", 
Thu Dec 12 16:24:25 CET 2019:       "node": "pcoslo5.cern.ch", 
Thu Dec 12 16:24:25 CET 2019:       "platform": "Linux-3.10.0-1062.4.3.el7.x86_64-x86_64-with-centos-7.6.1810-Core"
Thu Dec 12 16:24:25 CET 2019:     }, 
Thu Dec 12 16:24:25 CET 2019:     "transform": {
Thu Dec 12 16:24:25 CET 2019:       "cpuEfficiency": 0.5704, 
Thu Dec 12 16:24:25 CET 2019:       "cpuPWEfficiency": 0.6073, 
Thu Dec 12 16:24:25 CET 2019:       "cpuTime": 3, 
Thu Dec 12 16:24:25 CET 2019:       "cpuTimeTotal": 1596, 
Thu Dec 12 16:24:25 CET 2019:       "externalCpuTime": 4, 
Thu Dec 12 16:24:25 CET 2019:       "processedEvents": 10, 
Thu Dec 12 16:24:25 CET 2019:       "trfPredata": null, 
Thu Dec 12 16:24:25 CET 2019:       "wallTime": 685
Thu Dec 12 16:24:25 CET 2019:     }
Thu Dec 12 16:24:25 CET 2019:   }
Thu Dec 12 16:24:25 CET 2019: }
Thu Dec 12 16:24:25 CET 2019: 2019-12-12 15:23:51,493 | DEBUG    | queue_monitor       | pilot.util.auxiliary.4002876565  | update_server             | xml:will send fileinfo
Thu Dec 12 16:24:25 CET 2019: 2019-12-12 15:23:51,493 | 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 16:24:25 CET 2019: 2019-12-12 15:23:51,493 | INFO     | queue_monitor       | pilot.control.job.4002876565     | send_state                | job 4002876565 has finished - writing final server update
Thu Dec 12 16:24:25 CET 2019: 2019-12-12 15:23:51,493 | DEBUG    | queue_monitor       | pilot.control.job.4002876565     | get_data_structure        | building data structure to be sent to server with heartbeat
Thu Dec 12 16:24:25 CET 2019: 2019-12-12 15:23:51,493 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | get_job_metrics           | will not add max space = -350973533 B to job metrics
Thu Dec 12 16:24:25 CET 2019: 2019-12-12 15:23:51,494 | DEBUG    | queue_monitor       | pilot.api.analytics              | get_fitted_data           | removing tails from data to be fitted
Thu Dec 12 16:24:25 CET 2019: 2019-12-12 15:23:51,494 | WARNING  | queue_monitor       | pilot.api.analytics              | get_fitted_data           | wrong length of table data, x=[1576163806.0, 1576163867.0, 1576163928.0, 1576163989.0, 1576164050.0], y=[2425388.0, 2473129.0, 2496341.0, 2372339.0, 2090673.0] (must be same and length>=4)
Thu Dec 12 16:24:25 CET 2019: 2019-12-12 15:23:51,494 | DEBUG    | queue_monitor       | pilot.util.auxiliary.4002876565  | get_job_metrics           | job metrics="coreCount=4 actualCoreCount=1 nEvents=10"
Thu Dec 12 16:24:25 CET 2019: 2019-12-12 15:23:51,494 | INFO     | queue_monitor       | pilot.control.job.4002876565     | get_data_structure        | total number of processed events: 10 (read)
Thu Dec 12 16:24:25 CET 2019: 2019-12-12 15:23:51,494 | 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 16:24:25 CET 2019: 2019-12-12 15:23:51,495 | DEBUG    | queue_monitor       | pilot.user.atlas.utilities       | get_memory_monitor_info   | summary_dictionary={'Max': {'rx_packets': 69299, 'nprocs': 9, 'nthreads': 1, 'rx_bytes': 58715141, 'wtime': 676, 'rss': 9413184, 'write_bytes': 16900096, 'vmem': 14016300, 'read_bytes': 3093306368, 'stime': 16, 'tx_bytes': 12284304, 'pss': 2496341, 'wchar': 24072640, 'rchar': 1006760393, 'tx_packets': 39592, 'swap': 0, 'utime': 1566}, 'Avg': {'write_bytes': 24964, 'nprocs': 6, 'nthreads': 0, 'rx_bytes': 86733, 'rx_packets': 102, 'vmem': 8350259, 'read_bytes': 4569407, 'swap': 0, 'tx_bytes': 18146, 'pss': 1804813, 'wchar': 35559, 'rchar': 1487178, 'tx_packets': 58, 'rss': 5416283}}
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,495 | INFO     | queue_monitor       | pilot.user.atlas.utilities       | get_memory_monitor_info   | extracted standard info from prmon json
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,495 | INFO     | queue_monitor       | pilot.user.atlas.utilities       | get_memory_monitor_info   | extracted standard memory fields from prmon json
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,495 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | ..............................
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,495 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | . Timing measurements:
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,495 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | . get job = 0 s
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,495 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | . initial setup = 0 s
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,495 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | . payload setup = 0 s
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,495 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | . total setup = 0 s
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,495 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | . stage-in = 0 s
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,495 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | . payload execution = 730 s
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,495 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | . stage-out = 1 s
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,495 | INFO     | queue_monitor       | pilot.util.auxiliary.4002876565  | timing_report             | ..............................
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,496 | DEBUG    | queue_monitor       | pilot.control.job.4002876565     | send_state                | wrote heartbeat to file /home/dcameron/boinc/slots/0/heartbeat.json
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,496 | DEBUG    | queue_monitor       | pilot.control.job                | queue_monitor             | job 4002876565 was dequeued from the monitored payloads queue
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,496 | DEBUG    | queue_monitor       | pilot.control.job                | queue_monitor             | tmp job object deleted
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,790 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | 
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,790 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | job summary report
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,790 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | --------------------------------------------------
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,790 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | PanDA job id: 4002876565
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,790 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | task id: 000649-3918786-1514
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,790 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | errors: (none)
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,790 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | status: LOG_TRANSFER = DONE 
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,790 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | pilot state: finished 
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,790 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | transexitcode: 0
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,790 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | exeerrorcode: 0
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,790 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | exeerrordiag: 
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,790 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | exitcode: 0
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,791 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | exitmsg: OK
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,791 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | cpuconsumptiontime: 1586 s
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,791 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | nevents: 10
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,791 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | neventsw: 0
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,791 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | pid: 2591437
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,791 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | pgrp: 2591437
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,791 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | corecount: 4
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,791 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | event service: False
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,791 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | --------------------------------------------------
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,791 | INFO     | retrieve            | pilot.util.auxiliary.4002876565  | make_job_report           | 
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,791 | INFO     | retrieve            | pilot.control.job.4002876565     | has_job_completed         | job 4002876565 has completed
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,791 | INFO     | retrieve            | pilot.util.processes             | cleanup                   | overall cleanup function is called
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:51,795 | DEBUG    | retrieve            | pilot.util.processes             | cleanup                   | work directory was removed: /home/dcameron/boinc/slots/0/PanDA_Pilot-4002876565
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:52,797 | INFO     | retrieve            | pilot.info.jobdata               | collect_zombies           | --- collectZombieJob: --- 10, [2591437]
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:52,797 | INFO     | retrieve            | pilot.info.jobdata               | collect_zombies           | zombie collector trying to kill pid 2591437
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:52,797 | INFO     | retrieve            | pilot.info.jobdata               | collect_zombies           | harmless exception when collecting zombies: [Errno 10] No child processes
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:53,802 | INFO     | retrieve            | pilot.util.processes             | cleanup                   | collected zombie processes
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:53,802 | INFO     | retrieve            | pilot.util.processes             | cleanup                   | will now attempt to kill all subprocesses of pid=2591437
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:53,867 | INFO     | retrieve            | pilot.util.processes             | kill_processes            | process IDs to be killed: [2591437] (in reverse order)
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:53,898 | WARNING  | retrieve            | pilot.util.processes             | kill_processes            | found no corresponding commands to process id(s)
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:53,898 | INFO     | retrieve            | pilot.util.processes             | kill_orphans              | Do not look for orphan processes in BOINC jobs
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:53,899 | INFO     | retrieve            | pilot.util.processes             | cleanup                   | resetting job object
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:53,899 | INFO     | retrieve            | pilot.control.job                | retrieve                  | ready for new job
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:53,899 | INFO     | retrieve            | root                             | retrieve                  | pilot has finished for previous job - re-establishing logging
Thu Dec 12 16:24:26 CET 2019: mpi4py not found
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:53,900 | INFO     | retrieve            | pilot.util.auxiliary             | pilot_version_banner      | ****************************************
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:53,900 | INFO     | retrieve            | pilot.util.auxiliary             | pilot_version_banner      | ***  PanDA Pilot version 2.3.3 (16)  ***
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:53,900 | INFO     | retrieve            | pilot.util.auxiliary             | pilot_version_banner      | ****************************************
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:53,900 | INFO     | retrieve            | pilot.util.auxiliary             | pilot_version_banner      | 
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:53,901 | INFO     | retrieve            | pilot.util.auxiliary             | display_architecture_info | architecture information:
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:53,933 | INFO     | retrieve            | pilot.util.auxiliary             | display_architecture_info | 
Thu Dec 12 16:24:26 CET 2019: LSB Version:	:core-4.1-amd64:core-4.1-noarch
Thu Dec 12 16:24:26 CET 2019: Distributor ID:	CentOS
Thu Dec 12 16:24:26 CET 2019: Description:	CentOS Linux release 7.6.1810 (Core) 
Thu Dec 12 16:24:26 CET 2019: Release:	7.6.1810
Thu Dec 12 16:24:26 CET 2019: Codename:	Core
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:53,934 | INFO     | retrieve            | pilot.util.auxiliary             | pilot_version_banner      | ****************************************
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:54,436 | DEBUG    | retrieve            | pilot.util.monitoring            | check_local_space         | checking local space on /home/dcameron/boinc/slots/0
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:54,445 | INFO     | retrieve            | pilot.util.monitoring            | check_local_space         | sufficient remaining disk space (37587255296 B)
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:54,445 | 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 16:24:26 CET 2019: 2019-12-12 15:23:54,446 | DEBUG    | retrieve            | pilot.control.job                | retrieve                  | [job] retrieve thread has finished
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:54,457 | WARNING  | monitor             | pilot.control.monitor            | control                   | aborting monitor loop since graceful_stop has been set
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:54,458 | INFO     | monitor             | pilot.control.monitor            | control                   | [monitor] control thread has ended
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:54,475 | WARNING  | copytool_out        | pilot.util.common                | should_abort              | data:copytool_out:received graceful stop - abort after this iteration
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:54,574 | DEBUG    | payload             | pilot.control.payload            | control                   | payload control ending since graceful_stop has been set
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:54,574 | DEBUG    | payload             | pilot.control.payload            | control                   | [payload] control thread has finished
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:54,644 | DEBUG    | create_data_payload | pilot.control.job                | create_data_payload       | [job] create_data_payload thread has finished
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:54,657 | INFO     | failed_post         | pilot.control.payload            | failed_post               | [payload] failed_post thread has finished
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:54,661 | DEBUG    | MainThread          | pilot.workflow.generic           | run                       | thread count now at 12 threads
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:54,662 | DEBUG    | MainThread          | pilot.workflow.generic           | run                       | enumerate: [<_MainThread(MainThread, started 140290896516928)>, <ExcThread(job, started 140290734098176)>, <ExcThread(validate_pre, started 140290308421376)>, <ExcThread(copytool_out, started 140290700527360)>, <ExcThread(job_monitor, started 140290325206784)>, <ExcThread(data, started 140290717312768)>, <ExcThread(queue_monitor, started 140289738012416)>, <ExcThread(validate, started 140290725705472)>, <ExcThread(copytool_in, started 140290300028672)>, <ExcThread(queue_monitoring, started 140290333599488)>, <ExcThread(execute_payloads, started 140289721227008)>, <ExcThread(validate_post, started 140290291635968)>]
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:54,663 | DEBUG    | validate            | pilot.control.job                | validate                  | [job] validate thread has finished
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:54,844 | INFO     | validate_pre        | pilot.control.payload            | validate_pre              | [payload] validate_pre thread has finished
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:54,875 | DEBUG    | job                 | pilot.control.job                | control                   | job control ending since graceful_stop has been set
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:54,876 | DEBUG    | job                 | pilot.control.job                | control                   | [job] control thread has finished
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:55,046 | DEBUG    | copytool_in         | pilot.control.data               | copytool_in               | [data] copytool_in thread has finished
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:55,345 | INFO     | validate_post       | pilot.control.payload            | validate_post             | [payload] validate_post thread has finished
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:55,475 | DEBUG    | copytool_out        | pilot.control.data               | copytool_out              | [data] copytool_out thread has finished
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:55,478 | DEBUG    | data                | pilot.control.data               | control                   | data control ending since graceful_stop has been set
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:55,478 | DEBUG    | data                | pilot.control.data               | control                   | [data] control thread has finished
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:55,620 | INFO     | execute_payloads    | pilot.control.payload            | execute_payloads          | [payload] execute_payloads thread has finished
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:55,667 | DEBUG    | MainThread          | pilot.workflow.generic           | run                       | thread count now at 4 threads
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:55,667 | DEBUG    | MainThread          | pilot.workflow.generic           | run                       | enumerate: [<_MainThread(MainThread, started 140290896516928)>, <ExcThread(job_monitor, started 140290325206784)>, <ExcThread(queue_monitor, started 140289738012416)>, <ExcThread(queue_monitoring, started 140290333599488)>]
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:55,841 | WARNING  | queue_monitoring    | pilot.util.common                | should_abort              | data:queue_monitoring:received graceful stop - abort after this iteration
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:56,507 | WARNING  | queue_monitor       | pilot.util.common                | should_abort              | job:queue_monitor:received graceful stop - abort after this iteration
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:56,507 | DEBUG    | queue_monitor       | pilot.control.job                | queue_monitor             | [job] queue monitor thread has finished
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:56,672 | DEBUG    | MainThread          | pilot.workflow.generic           | run                       | thread count now at 3 threads
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:56,672 | DEBUG    | MainThread          | pilot.workflow.generic           | run                       | enumerate: [<_MainThread(MainThread, started 140290896516928)>, <ExcThread(job_monitor, started 140290325206784)>, <ExcThread(queue_monitoring, started 140290333599488)>]
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:58,842 | DEBUG    | queue_monitoring    | pilot.control.data               | queue_monitoring          | [data] queue_monitor thread has finished
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:59,688 | DEBUG    | MainThread          | pilot.workflow.generic           | run                       | thread count now at 2 threads
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:23:59,688 | DEBUG    | MainThread          | pilot.workflow.generic           | run                       | enumerate: [<_MainThread(MainThread, started 140290896516928)>, <ExcThread(job_monitor, started 140290325206784)>]
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:24:25,681 | WARNING  | job_monitor         | pilot.control.job                | check_job_monitor_waiting_time | no jobs in monitored_payloads queue (waited for 72 s)
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:24:25,681 | DEBUG    | job_monitor         | pilot.control.job                | job_monitor               | [job] job monitor thread has finished
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:24:25,792 | INFO     | MainThread          | pilot.workflow.generic           | run                       | end of generic workflow (traces error code: 0)
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:24:25,792 | INFO     | MainThread          | root                             | wrap_up                   | traces error code: 0
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:24:25,792 | INFO     | MainThread          | root                             | wrap_up                   | pilot has finished
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:24:25 UTC [wrapper] ==== pilot stdout END ====
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:24:25 UTC [wrapper] ==== wrapper stdout RESUME ====
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:24:25 UTC [wrapper] Pilot exit status: 0
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:24:25 UTC [wrapper] STATUSCODE: 0
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:24:25 UTC [wrapper] apfmon messages muted
Thu Dec 12 16:24:26 CET 2019: ---- find pandaID.out ----
Thu Dec 12 16:24:26 CET 2019: total 60
Thu Dec 12 16:24:26 CET 2019: -rw-------.  1 dcameron zp 11357 Jul 25 16:38 LICENSE
Thu Dec 12 16:24:26 CET 2019: -rw-------.  1 dcameron zp    20 Sep  9 13:04 MANIFEST.IN
Thu Dec 12 16:24:26 CET 2019: -rw-------.  1 dcameron zp    11 Dec 12 16:11 pandaIDs.out
Thu Dec 12 16:24:26 CET 2019: drwx------. 14 dcameron zp   216 Dec 12 16:11 pilot
Thu Dec 12 16:24:26 CET 2019: -rwx------.  1 dcameron zp 20750 Dec  2 11:02 pilot.py
Thu Dec 12 16:24:26 CET 2019: -rw-------.  1 dcameron zp     8 Dec  2 11:02 PILOTVERSION
Thu Dec 12 16:24:26 CET 2019: -rw-------.  1 dcameron zp  2212 Nov 14 11:01 README.md
Thu Dec 12 16:24:26 CET 2019: -rw-------.  1 dcameron zp   766 Oct 10 16:01 setup.py
Thu Dec 12 16:24:26 CET 2019: -rw-------.  1 dcameron zp   221 Jul 25 16:38 TODO.md
Thu Dec 12 16:24:26 CET 2019: -rw-------. 1 dcameron zp 11 Dec 12 16:11 /home/dcameron/boinc/slots/0/pilot2/pandaIDs.out
Thu Dec 12 16:24:26 CET 2019: 4002876565
Thu Dec 12 16:24:26 CET 2019: 
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:24:25 UTC [wrapper] Test setup, not cleaning
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:24:25 UTC [wrapper] ==== wrapper stdout END ====
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:24:25 UTC [wrapper] ==== wrapper stderr END ====
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:24:25 UTC [wrapper] wrapper wrapperexiting ec=0, duration=792
Thu Dec 12 16:24:26 CET 2019: 2019-12-12 15:24:25 UTC [wrapper] apfmon messages muted
Thu Dec 12 16:24:26 CET 2019:  *** Error codes and diagnostics ***
Thu Dec 12 16:24:26 CET 2019:     "exeErrorCode": 0,
Thu Dec 12 16:24:26 CET 2019:     "exeErrorDiag": "",
Thu Dec 12 16:24:26 CET 2019:     "pilotErrorCode": 0,
Thu Dec 12 16:24:26 CET 2019:     "pilotErrorDiag": "",
Thu Dec 12 16:24:26 CET 2019:  *** Listing of results directory ***
Thu Dec 12 16:24:26 CET 2019: total 379296
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp    266835 Dec 12 13:26 pilot2.tar.gz
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp      4492 Dec 12 13:46 queuedata.json
Thu Dec 12 16:24:26 CET 2019: -rwx------. 1 dcameron zp     12641 Dec 12 13:49 runpilot2-wrapper.sh
Thu Dec 12 16:24:26 CET 2019: -rw-------. 1 dcameron zp      2948 Dec 12 13:49 pandaJobData.out
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp       107 Dec 12 16:11 wrapper_26015_x86_64-pc-linux-gnu
Thu Dec 12 16:24:26 CET 2019: -rwxr-xr-x. 1 dcameron zp      4813 Dec 12 16:11 run_atlas
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp       112 Dec 12 16:11 job.xml
Thu Dec 12 16:24:26 CET 2019: drwxrwx--x. 2 dcameron zp        86 Dec 12 16:11 shared
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp      6274 Dec 12 16:11 init_data.xml
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp         0 Dec 12 16:11 boinc_lockfile
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp 365251149 Dec 12 16:11 EVNT.14296418._001447.pool.root.1
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp       815 Dec 12 16:11 RTE.tar.gz
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp    275004 Dec 12 16:11 input.tar.gz
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp      8577 Dec 12 16:11 start_atlas.sh
Thu Dec 12 16:24:26 CET 2019: drwxr-xr-x. 3 dcameron zp        17 Dec 12 16:11 APPS
Thu Dec 12 16:24:26 CET 2019: -rw-------. 1 dcameron zp   3742538 Dec 12 16:11 agis_schedconf.cvmfs.json
Thu Dec 12 16:24:26 CET 2019: -rw-------. 1 dcameron zp   7755224 Dec 12 16:11 agis_ddmendpoints.json
Thu Dec 12 16:24:26 CET 2019: drwx------. 3 dcameron zp       229 Dec 12 16:11 pilot2
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp       534 Dec 12 16:19 boinc_task_state.xml
Thu Dec 12 16:24:26 CET 2019: -rw-------. 1 dcameron zp   9151504 Dec 12 16:23 HITS.000649-3918786-1514._078090.pool.root.1
Thu Dec 12 16:24:26 CET 2019: -rw-------. 1 dcameron zp       839 Dec 12 16:23 memory_monitor_summary.json
Thu Dec 12 16:24:26 CET 2019: -rw-------. 1 dcameron zp    718782 Dec 12 16:23 log.000649-3918786-1514._078090.job.log.tgz.1
Thu Dec 12 16:24:26 CET 2019: -rw-------. 1 dcameron zp     15050 Dec 12 16:23 heartbeat.json
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp      8192 Dec 12 16:24 boinc_mmap_file
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp        25 Dec 12 16:24 wrapper_checkpoint.txt
Thu Dec 12 16:24:26 CET 2019: -rw-------. 1 dcameron zp      8464 Dec 12 16:24 pilotlog.txt
Thu Dec 12 16:24:26 CET 2019: -rw-------. 1 dcameron zp    163200 Dec 12 16:24 log.000649-3918786-1514._078090.job.log.1
Thu Dec 12 16:24:26 CET 2019: -rw-------. 1 dcameron zp       504 Dec 12 16:24 0WiKDmk5czvnShfckohDCDFpABFKDmABFKDmRVuaDmABFKDmewrRHo.diag
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp      7461 Dec 12 16:24 runtime_log.err
Thu Dec 12 16:24:26 CET 2019: -rw-------. 1 dcameron zp       496 Dec 12 16:24 output.list
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp       739 Dec 12 16:24 runtime_log
Thu Dec 12 16:24:26 CET 2019: -rw-------. 1 dcameron zp    911360 Dec 12 16:24 result.tar.gz
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp      2119 Dec 12 16:24 stderr.txt
Thu Dec 12 16:24:26 CET 2019: HITS file was successfully produced:
Thu Dec 12 16:24:26 CET 2019: -rw-------. 1 dcameron zp 9151504 Dec 12 16:23 shared/HITS.pool.root.1
Thu Dec 12 16:24:26 CET 2019:  *** Contents of shared directory: ***
Thu Dec 12 16:24:26 CET 2019: total 366812
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp      8549 Dec 12 16:11 start_atlas.sh
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp       815 Dec 12 16:11 RTE.tar.gz
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp    275004 Dec 12 16:11 input.tar.gz
Thu Dec 12 16:24:26 CET 2019: -rw-r--r--. 1 dcameron zp 365251149 Dec 12 16:11 ATLAS.root_0
Thu Dec 12 16:24:26 CET 2019: -rw-------. 1 dcameron zp   9151504 Dec 12 16:23 HITS.pool.root.1
Thu Dec 12 16:24:26 CET 2019: -rw-------. 1 dcameron zp    911360 Dec 12 16:24 result.tar.gz
16:24:26 (2584462): run_atlas exited; CPU time 1572.959151
16:24:26 (2584462): called boinc_finish(0)

</stderr_txt>
]]>


©2024 CERN