| Name | kYHKDmezPZvnShfckohDCDFpABFKDmABFKDmDLkTDmABFKDmkYwhrm_1 |
| Workunit | 1942741 |
| Created | 4 Oct 2019, 5:47:57 UTC |
| Sent | 6 Oct 2019, 21:24:52 UTC |
| Report deadline | 13 Oct 2019, 21:24:52 UTC |
| Received | 7 Oct 2019, 11:08:40 UTC |
| Server state | Over |
| Outcome | Success |
| Client state | Done |
| Exit status | 0 (0x00000000) |
| Computer ID | 3911 |
| Run time | 6 hours 25 min 19 sec |
| CPU time | 1 days 0 hours 31 min 5 sec |
| Validate state | Valid |
| Credit | 622.75 |
| Device peak FLOPS | 11.64 GFLOPS |
| Application version | ATLAS Simulation v0.74 (native_mt) x86_64-pc-linux-gnu |
| Peak working set size | 1.81 GB |
| Peak swap size | 3.42 GB |
| Peak disk usage | 1,020.42 MB |
Stderr output
<core_client_version>7.7.0</core_client_version>
<![CDATA[
<stderr_txt>
06:43:06 (16215): wrapper (7.7.26015): starting
06:43:06 (16215): wrapper: running run_atlas (--nthreads 4)
2019-10-07 06:43:06,374: singularity image is /cvmfs/atlas.cern.ch/repo/containers/images/singularity/x86_64-centos7.img
2019-10-07 06:43:06,374: sys.argv = ['run_atlas', '--nthreads', '4']
2019-10-07 06:43:06,375: THREADS=4
2019-10-07 06:43:06,376: Checking for CVMFS
2019-10-07 06:43:08,233: CVMFS is installed
2019-10-07 06:43:08,233: Checking Singularity...
2019-10-07 06:43:08,653: Singularity is installed, version singularity version 3.2.1-1
2019-10-07 06:43:08,653: Testing the function of Singularity...
2019-10-07 06:43:08,653: Checking singularity with cmd:singularity exec -B /cvmfs /cvmfs/atlas.cern.ch/repo/containers/images/singularity/x86_64-centos7.img hostname
2019-10-07 06:43:18,423: Singularity Works...
2019-10-07 06:43:18,423: copy /home/grid/slots/0/shared/ATLAS.root_0
2019-10-07 06:43:18,835: copy /home/grid/slots/0/shared/input.tar.gz
2019-10-07 06:43:18,836: copy /home/grid/slots/0/shared/RTE.tar.gz
2019-10-07 06:43:18,837: copy /home/grid/slots/0/shared/start_atlas.sh
2019-10-07 06:43:18,837: export ATHENA_PROC_NUMBER=4;
2019-10-07 06:43:18,869: start atlas job with PandaID=4495188292
2019-10-07 06:43:18,869: cmd = singularity exec --pwd /home/grid/slots/0 -B /cvmfs,/home /cvmfs/atlas.cern.ch/repo/containers/images/singularity/x86_64-centos7.img sh start_atlas.sh > runtime_log 2> runtime_log.err
2019-10-07 13:08:21,737: running cmd return value is 0
2019-10-07 13:08:21,743: Moving ./HITS.19000468._021756.pool.root.1 to shared/HITS.pool.root.1
2019-10-07 13:08:21,743: HITS result file:
2019-10-07 13:08:21,759: -rw-------. 1 grid grid 250849615 Oct 7 13:06 shared/HITS.pool.root.1
2019-10-07 13:08:21,760: *****************The last 200 lines of the pilot log******************
2019-10-07 13:08:21,766: "wallTime": 3
},
"total": {
"cpuTime": 85,
"wallTime": 158
},
"validation": {
"cpuTime": 0,
"wallTime": 0
},
"wallTime": 154
}
},
"machine": {
"cpu_family": "6",
"linux_distribution": [
"CentOS Linux",
"7.6.1810",
"Core"
],
"model": "61",
"model_name": "Intel Core Processor (Broadwell, IBRS)",
"node": "dcameron04.cern.ch",
"platform": "Linux-3.10.0-957.el7.x86_64-x86_64-with-centos-7.6.1810-Core"
},
"transform": {
"cpuEfficiency": 0.9604,
"cpuPWEfficiency": 0.9634,
"cpuTime": 9,
"cpuTimeTotal": 88387,
"externalCpuTime": 186,
"processedEvents": 200,
"trfPredata": null,
"wallTime": 22939
}
}
}
2019-10-07 11:07:19,893 | DEBUG | queue_monitor | pilot.util.auxiliary.4495188292 | update_server | xml:will send fileinfo
2019-10-07 11:07:19,894 | INFO | queue_monitor | pilot.control.job.4495188292 | send_state | pilot will not update the server (heartbeat message will be written to file)
2019-10-07 11:07:19,894 | INFO | queue_monitor | pilot.control.job.4495188292 | send_state | job 4495188292 has finished - writing final server update
2019-10-07 11:07:19,899 | WARNING | queue_monitor | pilot.api.analytics | get_fitted_data | wrong length of table data, x=[1570423460.0, 1570423521.0, 1570423582.0, 1570423643.0, 1570423704.0, 1570423765.0, 1570423826.0, 1570423887.0, 1570423948.0, 1570424009.0, 1570424070.0, 1570424131.0, 1570424192.0, 1570424253.0, 1570424314.0, 1570424375.0, 1570424436.0, 1570424497.0, 1570424558.0, 1570424619.0, 1570424680.0, 1570424741.0, 1570424802.0, 1570424863.0, 1570424924.0, 1570424985.0, 1570425046.0, 1570425107.0, 1570425168.0, 1570425229.0, 1570425290.0, 1570425351.0, 1570425412.0, 1570425473.0, 1570425534.0, 1570425595.0, 1570425656.0, 1570425717.0, 1570425778.0, 1570425839.0, 1570425900.0, 1570425961.0, 1570426022.0, 1570426083.0, 1570426144.0, 1570426205.0, 1570426266.0, 1570426327.0, 1570426388.0, 1570426449.0, 1570426510.0, 1570426571.0, 1570426632.0, 1570426693.0, 1570426754.0, 1570426815.0, 1570426876.0, 1570426937.0, 1570426998.0, 1570427059.0, 1570427120.0, 1570427181.0, 1570427242.0, 1570427303.0, 1570427364.0, 1570427425.0, 1570427486.0, 1570427547.0, 1570427608.0, 1570427669.0, 1570427730.0, 1570427791.0, 1570427852.0, 1570427913.0, 1570427974.0, 1570428035.0, 1570428096.0, 1570428157.0, 1570428218.0, 1570428279.0, 1570428340.0, 1570428401.0, 1570428462.0, 1570428523.0, 1570428584.0, 1570428645.0, 1570428706.0, 1570428767.0, 1570428828.0, 1570428889.0, 1570428950.0, 1570429011.0, 1570429072.0, 1570429133.0, 1570429194.0, 1570429255.0, 1570429316.0, 1570429377.0, 1570429438.0, 1570429499.0, 1570429560.0, 1570429621.0, 1570429682.0, 1570429743.0, 1570429804.0, 1570429865.0, 1570429926.0, 1570429987.0, 1570430048.0, 1570430109.0, 1570430170.0, 1570430231.0, 1570430292.0, 1570430353.0, 1570430414.0, 1570430475.0, 1570430536.0, 1570430597.0, 1570430658.0, 1570430719.0, 1570430780.0, 1570430841.0, 1570430902.0, 1570430963.0, 1570431024.0, 1570431085.0, 1570431146.0, 1570431207.0, 1570431268.0, 1570431329.0, 1570431390.0, 1570431451.0, 1570431512.0, 1570431573.0, 1570431634.0, 1570431695.0, 1570431756.0, 1570431817.0, 1570431878.0, 1570431939.0, 1570432000.0, 1570432061.0, 1570432122.0, 1570432183.0, 1570432244.0, 1570432305.0, 1570432366.0, 1570432427.0, 1570432488.0, 1570432549.0, 1570432610.0, 1570432671.0, 1570432732.0, 1570432793.0, 1570432854.0, 1570432915.0, 1570432976.0, 1570433037.0, 1570433098.0, 1570433159.0, 1570433220.0, 1570433281.0, 1570433342.0, 1570433403.0, 1570433464.0, 1570433525.0, 1570433586.0, 1570433647.0, 1570433708.0, 1570433769.0, 1570433830.0, 1570433891.0, 1570433952.0, 1570434013.0, 1570434074.0, 1570434135.0, 1570434196.0, 1570434257.0, 1570434318.0, 1570434379.0, 1570434440.0, 1570434501.0, 1570434562.0, 1570434623.0, 1570434684.0, 1570434745.0, 1570434806.0, 1570434867.0, 1570434928.0, 1570434989.0, 1570435050.0, 1570435111.0, 1570435172.0, 1570435233.0, 1570435294.0, 1570435355.0, 1570435416.0, 1570435477.0, 1570435538.0, 1570435599.0, 1570435660.0, 1570435721.0, 1570435782.0, 1570435843.0, 1570435904.0, 1570435965.0, 1570436026.0, 1570436087.0, 1570436148.0, 1570436209.0, 1570436270.0, 1570436331.0, 1570436392.0, 1570436453.0, 1570436514.0, 1570436575.0, 1570436636.0, 1570436697.0, 1570436758.0, 1570436819.0, 1570436880.0, 1570436941.0, 1570437002.0, 1570437063.0, 1570437124.0, 1570437185.0, 1570437246.0, 1570437307.0, 1570437368.0, 1570437429.0, 1570437490.0, 1570437551.0, 1570437612.0, 1570437673.0, 1570437734.0, 1570437795.0, 1570437856.0, 1570437917.0, 1570437978.0, 1570438039.0, 1570438100.0, 1570438161.0, 1570438222.0, 1570438283.0, 1570438344.0, 1570438405.0, 1570438466.0, 1570438527.0, 1570438588.0, 1570438649.0, 1570438710.0, 1570438771.0, 1570438832.0, 1570438893.0, 1570438954.0, 1570439015.0, 1570439076.0, 1570439137.0, 1570439198.0, 1570439259.0, 1570439320.0, 1570439381.0, 1570439442.0, 1570439503.0, 1570439564.0, 1570439625.0, 1570439686.0, 1570439747.0, 1570439808.0, 1570439869.0, 1570439930.0, 1570439991.0, 1570440052.0, 1570440113.0, 1570440174.0, 1570440235.0, 1570440296.0, 1570440357.0, 1570440418.0, 1570440479.0, 1570440540.0, 1570440601.0, 1570440662.0, 1570440723.0, 1570440784.0, 1570440845.0, 1570440906.0, 1570440967.0, 1570441028.0, 1570441089.0, 1570441150.0, 1570441211.0, 1570441272.0, 1570441333.0, 1570441394.0, 1570441455.0, 1570441516.0, 1570441577.0, 1570441638.0, 1570441699.0, 1570441760.0, 1570441821.0, 1570441882.0, 1570441943.0, 1570442004.0, 1570442065.0, 1570442126.0, 1570442187.0, 1570442248.0, 1570442309.0, 1570442370.0, 1570442431.0, 1570442492.0, 1570442553.0, 1570442614.0, 1570442675.0, 1570442736.0, 1570442797.0, 1570442858.0, 1570442919.0, 1570442980.0, 1570443041.0, 1570443102.0, 1570443163.0, 1570443224.0, 1570443285.0, 1570443346.0, 1570443407.0, 1570443468.0, 1570443529.0, 1570443590.0, 1570443651.0, 1570443712.0, 1570443773.0, 1570443834.0, 1570443895.0, 1570443956.0, 1570444017.0, 1570444078.0, 1570444139.0, 1570444200.0, 1570444261.0, 1570444322.0, 1570444383.0, 1570444444.0, 1570444505.0, 1570444566.0, 1570444627.0, 1570444688.0, 1570444749.0, 1570444810.0, 1570444871.0, 1570444932.0, 1570444993.0, 1570445054.0, 1570445115.0, 1570445176.0, 1570445237.0, 1570445298.0, 1570445359.0, 1570445420.0, 1570445481.0, 1570445542.0, 1570445603.0, 1570445664.0, 1570445725.0, 1570445786.0, 1570445847.0, 1570445908.0, 1570445969.0, 1570446030.0, 1570446091.0, 1570446152.0, 1570446213.0, 1570446274.0, 1570446335.0, 1570446396.0], y=[] (must be same and length>=2)
2019-10-07 11:07:19,899 | DEBUG | queue_monitor | pilot.util.auxiliary.4495188292 | get_job_metrics | job metrics="coreCount=4 actualCoreCount=1 nEvents=200 workDirSize=11341072"
2019-10-07 11:07:19,899 | INFO | queue_monitor | pilot.control.job.4495188292 | get_data_structure | total number of processed events: 200 (read)
2019-10-07 11:07:19,900 | INFO | queue_monitor | pilot.user.atlas.utilities | get_memory_values | using path: /home/grid/slots/0/PanDA_Pilot-4495188292/memory_monitor_summary.json (trf name=prmon)
2019-10-07 11:07:19,901 | DEBUG | queue_monitor | pilot.user.atlas.utilities | get_memory_monitor_info | summary_dictionary={'Max': {'rx_packets': 1772814, 'nprocs': 12, 'nthreads': 1, 'rx_bytes': 662223494, 'wtime': 22949, 'rss': 9440728, 'write_bytes': 519794688, 'vmem': 14180892, 'read_bytes': 4440489984, 'stime': 234, 'tx_bytes': 46951576, 'pss': 2696934, 'wchar': 518182155, 'rchar': 3532879135, 'tx_packets': 352752, 'swap': 0, 'utime': 88974}, 'Avg': {'write_bytes': 22649, 'nprocs': 9, 'nthreads': 0, 'rx_bytes': 28855, 'rx_packets': 77, 'vmem': 13792462, 'read_bytes': 193490, 'swap': 0, 'tx_bytes': 2045, 'pss': 2572160, 'wchar': 22579, 'rchar': 153941, 'tx_packets': 15, 'rss': 9137228}}
2019-10-07 11:07:19,901 | INFO | queue_monitor | pilot.user.atlas.utilities | get_memory_monitor_info | extracted standard info from prmon json
2019-10-07 11:07:19,901 | INFO | queue_monitor | pilot.user.atlas.utilities | get_memory_monitor_info | extracted standard memory fields from prmon json
2019-10-07 11:07:19,901 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | ..............................
2019-10-07 11:07:19,901 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | . Timing measurements:
2019-10-07 11:07:19,901 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | . get job = 0 s
2019-10-07 11:07:19,901 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | . initial setup = 4 s
2019-10-07 11:07:19,902 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | . payload setup = 0 s
2019-10-07 11:07:19,902 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | . total setup = 4 s
2019-10-07 11:07:19,902 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | . stage-in = 0 s
2019-10-07 11:07:19,902 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | . payload execution = 22992 s
2019-10-07 11:07:19,902 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | . stage-out = 2 s
2019-10-07 11:07:19,902 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | ..............................
2019-10-07 11:07:19,902 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | get_log_extracts | building log extracts (sent to the server as 'pilotLog')
2019-10-07 11:07:19,902 | DEBUG | queue_monitor | pilot.util.auxiliary.4495188292 | get_panda_tracer_log | PanDA tracer log does not exist: /home/grid/slots/0/PanDA_Pilot-4495188292/pandatracerlog.txt (ignoring)
2019-10-07 11:07:19,902 | INFO | queue_monitor | pilot.util.container | execute | executing command: tail -n 20 /home/grid/slots/0/PanDA_Pilot-4495188292/pilotlog.txt
2019-10-07 11:07:19,926 | WARNING | queue_monitor | pilot.util.auxiliary.4495188292 | get_log_extracts | detected the following tail of warning/fatal messages in the pilot log:
- Log from pilotlog.txt -2019-10-07 11:07:19,899 | WARNING | queue_monitor | pilot.api.analytics | get_fitted_data | wrong length of table data, x=[1570423460.0, 1570423521.0, 1570423582.0, 1570423643.0, 1570423704.0, 1570423765.0, 1570423826.0, 1570423887.0, 1570423948.0, 1570424009.0, 1570424070.0, 1570424131.0, 1570424192.0, 1570424253.0, 1570424314.0, 1570424375.0, 1570424436.0, 1570424497.0, 1570424558.0, 1570424619.0, 1570424680.0, 1570424741.0, 1570424802.0, 1570424863.0, 1570424924.0, 1570424985.0, 1570425046.0, 1570425107.0, 1570425168.0, 1570425229.0, 1570425290.0, 1570425351.0, 1570425412.0, 1570425473.0, 1570425534.0, 1570425595.0, 1570425656.0, 1570425717.0, 1570425778.0, 1570425839.0, 1570425900.0, 1570425961.0, 1570426022.0, 1570426083.0, 1570426144.0, 1570426205.0, 1570426266.0, 1570426327.0, 1570426388.0, 1570426449.0, 1570426510.0, 1570426571.0, 1570426632.0, 1570426693.0, 1570426754.0, 1570426815.0, 1570426876.0, 1570426937.0, 1570426998.0, 1570427059.0, 1570427120.0, 1570427181.0, 1570427242.0, 1570427303.0, 1570427364.0, 1570427425.0, 1570427486.0, 1570427547.0, 1570427608.0, 1570427669.0, 1570427730.0, 1570427791.0, 1570427852.0, 1570427913.0, 1570427974.0, 1570428035.0, 1570428096.0, 1570428157.0, 1570428218.0, 1570428279.0, 1570428340.0, 1570428401.0, 1570428462.0, 1570428523.0, 1570428584.0, 1570428645.0, 1570428706.0, 1570428767.0, 1570428828.0, 1570428889.0, 1570428950.0, 1570429011.0, 1570429072.0, 1570429133.0, 1570429194.0, 1570429255.0, 1570429316.0, 1570429377.0, 1570429438.0, 1570429499.0, 1570429560.0, 1570429621.0, 1570429682.0, 1570429743.0, 1570429804.0, 1570429865.0, 1570429926.0, 1570429987.0, 1570430048.0, 1570430109.0, 1570430170.0, 1570430231.0, 1570430292.0, 1570430353.0, 1570430414.0, 1570430475.0, 1570430536.0, 1570430597.0, 1570430658.0, 1570430719.0, 1570430780.0, 1570430841.0, 1570430902.0, 1570430963.0, 1570431024.0, 1570431085.0, 1570431146.0, 1570431207.0, 1570431268.0, 1570431329.0, 1570431390.0, 1570431451.0, 1570431512.0, 1570431573.0, 1570431634.0, 1570431695.0, 1570431756.0, 1570431817.0, 1570431878.0, 1570431939.0, 1570432000.0, 1570432061.0, 1570432122.0, 1570432183.0, 1570432244.0, 1570432305.0, 1570432366.0, 1570432427.0, 1570432488.0, 1570432549.0, 1570432610.0, 1570432671.0, 1570432732.0, 1570432793.0, 1570432854.0, 1570432915.0, 1570432976.0, 1570433037.0, 1570433098.0, 1570433159.0, 1570433220.0, 1570433281.0, 1570433342.0, 1570433403.0, 1570433464.0, 1570433525.0, 1570433586.0, 1570433647.0, 1570433708.0, 1570433769.0, 1570433830.0, 1570433891.0, 1570433952.0, 1570434013.0, 1570434074.0, 1570434135.0, 1570434196.0, 1570434257.0, 1570434318.0, 1570434379.0, 1570434440.0, 1570434501.0, 1570434562.0, 1570434623.0, 1570434684.0, 1570434745.0, 1570434806.0, 1570434867.0, 1570434928.0, 1570434989.0, 1570435050.0, 1570435111.0, 1570435172.0, 1570435233.0, 1570435294.0, 1570435355.0, 1570435416.0, 1570435477.0, 1570435538.0, 1570435599.0, 1570435660.0, 1570435721.0, 1570435782.0, 1570435843.0, 1570435904.0, 1570435965.0, 1570436026.0, 1570436087.0, 1570436148.0, 1570436209.0, 1570436270.0, 1570436331.0, 1570436392.0, 1570436453.0, 1570436514.0, 1570436575.0, 1570436636.0, 1570436697.0, 1570436758.0, 1570436819.0, 1570436880.0, 1570436941.0, 1570437002.0, 1570437063.0, 1570437124.0, 1570437185.0, 1570437246.0, 1570437307.0, 1570437368.0, 1570437429.0, 1570437490.0, 1570437551.0, 1570437612.0, 1570437673.0, 1570437734.0, 1570437795.0, 1570437856.0, 1570437917.0, 1570437978.0, 1570438039.0, 1570438100.0, 1570438161.0, 1570438222.0, 1570438283.0, 1570438344.0, 1570438405.0, 1570438466.0, 1570438527.0, 1570438588.0, 1570438649.0, 1570438710.0, 1570438771.0, 1570438832.0, 1570438893.0, 1570438954.0, 1570439015.0, 1570439076.0, 1570439137.0, 1570439198.0, 1570439259.0, 1570439320.0, 1570439381.0, 1570439442.0, 1570439503.0, 1570439564.0, 1570439625.0, 1570439686.0, 1570439747.0, 1570439808.0, 1570439869.0, 1570439930.0, 1570439991.0, 1570440052.0, 1570440113.0, 1570440174.0, 1570440235.0, 1570440296.0, 1570440357.0, 1570440418.0, 1570440479.0, 1570440540.0, 1570440601.0, 1570440662.0, 1570440723.0, 1570440784.0, 1570440845.0, 1570440906.0, 1570440967.0, 1570441028.0, 1570441089.0, 1570441150.0, 1570441211.0, 1570441272.0, 1570441333.0, 1570441394.0, 1570441455.0, 1570441516.0, 1570441577.0, 1570441638.0, 1570441699.0, 1570441760.0, 1570441821.0, 1570441882.0, 1570441943.0, 1570442004.0, 1570442065.0, 1570442126.0, 1570442187.0, 1570442248.0, 1570442309.0, 1570442370.0, 1570442431.0, 1570442492.0, 1570442553.0, 1570442614.0, 1570442675.0, 1570442736.0, 1570442797.0, 1570442858.0, 1570442919.0, 1570442980.0, 1570443041.0, 1570443102.0, 1570443163.0, 1570443224.0, 1570443285.0, 1570443346.0, 1570443407.0, 1570443468.0, 1570443529.0, 1570443590.0, 1570443651.0, 1570443712.0, 1570443773.0, 1570443834.0, 1570443895.0, 1570443956.0, 1570444017.0, 1570444078.0, 1570444139.0, 1570444200.0, 1570444261.0, 1570444322.0, 1570444383.0, 1570444444.0, 1570444505.0, 1570444566.0, 1570444627.0, 1570444688.0, 1570444749.0, 1570444810.0, 1570444871.0, 1570444932.0, 1570444993.0, 1570445054.0, 1570445115.0, 1570445176.0, 1570445237.0, 1570445298.0, 1570445359.0, 1570445420.0, 1570445481.0, 1570445542.0, 1570445603.0, 1570445664.0, 1570445725.0, 1570445786.0, 1570445847.0, 1570445908.0, 1570445969.0, 1570446030.0, 1570446091.0, 1570446152.0, 1570446213.0, 1570446274.0, 1570446335.0, 1570446396.0], y=[] (must be same and length>=2)
2019-10-07 11:07:19,899 | DEBUG | queue_monitor | pilot.util.auxiliary.4495188292 | get_job_metrics | job metrics="coreCount=4 actualCoreCount=1 nEvents=200 workDirSize=11341072"
2019-10-07 11:07:19,899 | INFO | queue_monitor | pilot.control.job.4495188292 | get_data_structure | total number of processed events: 200 (read)
2019-10-07 11:07:19,900 | INFO | queue_monitor | pilot.user.atlas.utilities | get_memory_values | using path: /home/grid/slots/0/PanDA_Pilot-4495188292/memory_monitor_summary.json (trf name=prmon)
2019-10-07 11:07:19,901 | DEBUG | queue_monitor | pilot.user.atlas.utilities | get_memory_monitor_info | summary_dictionary={'Max': {'rx_packets': 1772814, 'nprocs': 12, 'nthreads': 1, 'rx_bytes': 662223494, 'wtime': 22949, 'rss': 9440728, 'write_bytes': 519794688, 'vmem': 14180892, 'read_bytes': 4440489984, 'stime': 234, 'tx_bytes': 46951576, 'pss': 2696934, 'wchar': 518182155, 'rchar': 3532879135, 'tx_packets': 352752, 'swap': 0, 'utime': 88974}, 'Avg': {'write_bytes': 22649, 'nprocs': 9, 'nthreads': 0, 'rx_bytes': 28855, 'rx_packets': 77, 'vmem': 13792462, 'read_bytes': 193490, 'swap': 0, 'tx_bytes': 2045, 'pss': 2572160, 'wchar': 22579, 'rchar': 153941, 'tx_packets': 15, 'rss': 9137228}}
2019-10-07 11:07:19,901 | INFO | queue_monitor | pilot.user.atlas.utilities | get_memory_monitor_info | extracted standard info from prmon json
2019-10-07 11:07:19,901 | INFO | queue_monitor | pilot.user.atlas.utilities | get_memory_monitor_info | extracted standard memory fields from prmon json
2019-10-07 11:07:19,901 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | ..............................
2019-10-07 11:07:19,901 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | . Timing measurements:
2019-10-07 11:07:19,901 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | . get job = 0 s
2019-10-07 11:07:19,901 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | . initial setup = 4 s
2019-10-07 11:07:19,902 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | . payload setup = 0 s
2019-10-07 11:07:19,902 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | . total setup = 4 s
2019-10-07 11:07:19,902 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | . stage-in = 0 s
2019-10-07 11:07:19,902 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | . payload execution = 22992 s
2019-10-07 11:07:19,902 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | . stage-out = 2 s
2019-10-07 11:07:19,902 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | timing_report | ..............................
2019-10-07 11:07:19,902 | INFO | queue_monitor | pilot.util.auxiliary.4495188292 | get_log_extracts | building log extracts (sent to the server as 'pilotLog')
2019-10-07 11:07:19,902 | DEBUG | queue_monitor | pilot.util.auxiliary.4495188292 | get_panda_tracer_log | PanDA tracer log does not exist: /home/grid/slots/0/PanDA_Pilot-4495188292/pandatracerlog.txt (ignoring)
2019-10-07 11:07:19,902 | INFO | queue_monitor | pilot.util.container | execute | executing command: tail -n 20 /home/grid/slots/0/PanDA_Pilot-4495188292/pilotlog.txt
2019-10-07 11:07:19,928 | DEBUG | queue_monitor | pilot.control.job.4495188292 | send_state | wrote heartbeat to file /home/grid/slots/0/heartbeat.json
2019-10-07 11:07:19,928 | INFO | queue_monitor | pilot.control.job | queue_monitor | job 4495188292 was dequeued from the monitored payloads queue
2019-10-07 11:07:20,548 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report |
2019-10-07 11:07:20,548 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | job summary report
2019-10-07 11:07:20,549 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | --------------------------------------------------
2019-10-07 11:07:20,549 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | PanDA job id: 4495188292
2019-10-07 11:07:20,549 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | task id: 19000468
2019-10-07 11:07:20,549 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | errors: (none)
2019-10-07 11:07:20,549 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | status: LOG_TRANSFER = DONE
2019-10-07 11:07:20,549 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | pilot state: finished
2019-10-07 11:07:20,549 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | transexitcode: 0
2019-10-07 11:07:20,549 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | exeerrorcode: 0
2019-10-07 11:07:20,549 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | exeerrordiag:
2019-10-07 11:07:20,549 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | exitcode: 0
2019-10-07 11:07:20,550 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | exitmsg: OK
2019-10-07 11:07:20,550 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | cpuconsumptiontime: 88670 s
2019-10-07 11:07:20,550 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | nevents: 200
2019-10-07 11:07:20,550 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | neventsw: 0
2019-10-07 11:07:20,550 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | pid: 23202
2019-10-07 11:07:20,550 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | pgrp: 23202
2019-10-07 11:07:20,550 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | corecount: 4
2019-10-07 11:07:20,550 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | event service: False
2019-10-07 11:07:20,550 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report | --------------------------------------------------
2019-10-07 11:07:20,550 | INFO | retrieve | pilot.util.auxiliary.4495188292 | make_job_report |
2019-10-07 11:07:20,550 | INFO | retrieve | pilot.control.job.4495188292 | has_job_completed | job 4495188292 has completed
2019-10-07 11:07:20,550 | INFO | retrieve | pilot.util.processes | cleanup | overall cleanup function is called
2019-10-07 11:07:20,563 | DEBUG | retrieve | pilot.util.processes | cleanup | work directory was removed: /home/grid/slots/0/PanDA_Pilot-4495188292
2019-10-07 11:07:21,568 | INFO | retrieve | pilot.info.jobdata | collect_zombies | --- collectZombieJob: --- 10, [23202]
2019-10-07 11:07:21,568 | INFO | retrieve | pilot.info.jobdata | collect_zombies | zombie collector trying to kill pid 23202
2019-10-07 11:07:21,569 | INFO | retrieve | pilot.info.jobdata | collect_zombies | harmless exception when collecting zombies: [Errno 10] No child processes
2019-10-07 11:07:22,571 | INFO | retrieve | pilot.util.processes | cleanup | collected zombie processes
2019-10-07 11:07:22,572 | INFO | retrieve | pilot.util.processes | cleanup | will now attempt to kill all subprocesses of pid=23202
2019-10-07 11:07:22,643 | INFO | retrieve | pilot.util.processes | kill_processes | process IDs to be killed: [23202] (in reverse order)
2019-10-07 11:07:22,683 | WARNING | retrieve | pilot.util.processes | kill_processes | found no corresponding commands to process id(s)
2019-10-07 11:07:22,683 | INFO | retrieve | pilot.util.processes | kill_orphans | Do not look for orphan processes in BOINC jobs
2019-10-07 11:07:22,683 | INFO | retrieve | pilot.control.job | retrieve | ready for new job
2019-10-07 11:07:22,684 | INFO | retrieve | root | retrieve | pilot has finished for previous job - re-establishing logging
No handlers could be found for logger "pilot.util.mpi"
2019-10-07 11:07:22,688 | INFO | retrieve | pilot.util.auxiliary | pilot_version_banner | *****************************************
2019-10-07 11:07:22,688 | INFO | retrieve | pilot.util.auxiliary | pilot_version_banner | *** PanDA Pilot version 2.1.25 (11) ***
2019-10-07 11:07:22,688 | INFO | retrieve | pilot.util.auxiliary | pilot_version_banner | *****************************************
2019-10-07 11:07:22,688 | INFO | retrieve | pilot.util.auxiliary | pilot_version_banner |
2019-10-07 11:07:22,688 | INFO | retrieve | pilot.util.auxiliary | pilot_version_banner | pilot is running in a VM
2019-10-07 11:07:22,689 | INFO | retrieve | pilot.util.auxiliary | display_architecture_info | architecture information:
2019-10-07 11:07:22,761 | INFO | retrieve | pilot.util.auxiliary | display_architecture_info |
LSB Version: :core-4.1-amd64:core-4.1-noarch
Distributor ID: CentOS
Description: CentOS Linux release 7.6.1810 (Core)
Release: 7.6.1810
Codename: Core
2019-10-07 11:07:22,761 | INFO | retrieve | pilot.util.auxiliary | pilot_version_banner | *****************************************
2019-10-07 11:07:23,264 | DEBUG | retrieve | pilot.util.monitoring | check_local_space | checking local space on /home/grid/slots/0
2019-10-07 11:07:23,284 | INFO | retrieve | pilot.util.monitoring | check_local_space | sufficient remaining disk space (20150484992 B)
2019-10-07 11:07:23,285 | WARNING | retrieve | pilot.control.job | proceed_with_getjob | since timefloor is set to 0, pilot was only allowed to run one job
2019-10-07 11:07:23,285 | DEBUG | retrieve | pilot.control.job | retrieve | [job] retrieve thread has finished
2019-10-07 11:07:23,327 | WARNING | copytool_out | pilot.util.common | should_abort | data:copytool_out:received graceful stop - abort after this iteration
2019-10-07 11:07:23,405 | INFO | monitor | pilot.control.monitor | control | [monitor] control thread has ended
2019-10-07 11:07:23,435 | DEBUG | MainThread | pilot.workflow.generic | run | thread count now at 15 threads
2019-10-07 11:07:23,436 | DEBUG | MainThread | pilot.workflow.generic | run | enumerate: [<_MainThread(MainThread, started 139944254940992)>, <ExcThread(job, started 139944093308672)>, <ExcThread(execute_payloads, started 139943280092928)>, <ExcThread(data, started 139944076523264)>, <ExcThread(validate, started 139944084915968)>, <ExcThread(queue_monitor, started 139943296878336)>, <ExcThread(payload, started 139943842141952)>, <ExcThread(validate_post, started 139943313663744)>, <ExcThread(copytool_in, started 139943322056448)>, <ExcThread(create_data_payload, started 139943858927360)>, <ExcThread(job_monitor, started 139943305271040)>, <ExcThread(queue_monitoring, started 139943816963840)>, <ExcThread(validate_pre, started 139943808571136)>, <ExcThread(copytool_out, started 139943850534656)>, <ExcThread(failed_post, started 139943288485632)>]
2019-10-07 11:07:23,530 | DEBUG | data | pilot.control.data | control | data control ending since graceful_stop has been set
2019-10-07 11:07:23,530 | DEBUG | data | pilot.control.data | control | [data] control thread has finished
2019-10-07 11:07:23,537 | DEBUG | job | pilot.control.job | control | job control ending since graceful_stop has been set
2019-10-07 11:07:23,538 | DEBUG | job | pilot.control.job | control | [job] control thread has finished
2019-10-07 11:07:23,554 | DEBUG | validate | pilot.control.job | validate | [job] validate thread has finished
2019-10-07 11:07:23,555 | INFO | execute_payloads | pilot.control.payload | execute_payloads | [payload] execute_payloads thread has finished
2019-10-07 11:07:23,638 | DEBUG | MainThread | pilot.workflow.generic | run | thread count now at 11 threads
2019-10-07 11:07:23,639 | DEBUG | MainThread | pilot.workflow.generic | run | enumerate: [<_MainThread(MainThread, started 139944254940992)>, <ExcThread(queue_monitor, started 139943296878336)>, <ExcThread(payload, started 139943842141952)>, <ExcThread(validate_post, started 139943313663744)>, <ExcThread(copytool_in, started 139943322056448)>, <ExcThread(create_data_payload, started 139943858927360)>, <ExcThread(job_monitor, started 139943305271040)>, <ExcThread(queue_monitoring, started 139943816963840)>, <ExcThread(validate_pre, started 139943808571136)>, <ExcThread(copytool_out, started 139943850534656)>, <ExcThread(failed_post, started 139943288485632)>]
2019-10-07 11:07:23,902 | DEBUG | create_data_payload | pilot.control.job | create_data_payload | [job] create_data_payload thread has finished
2019-10-07 11:07:23,903 | INFO | validate_pre | pilot.control.payload | validate_pre | [payload] validate_pre thread has finished
2019-10-07 11:07:23,903 | DEBUG | copytool_in | pilot.control.data | copytool_in | [data] copytool_in thread has finished
2019-10-07 11:07:23,903 | INFO | failed_post | pilot.control.payload | failed_post | [payload] failed_post thread has finished
2019-10-07 11:07:24,032 | DEBUG | payload | pilot.control.payload | control | payload control ending since graceful_stop has been set
2019-10-07 11:07:24,033 | DEBUG | payload | pilot.control.payload | control | [payload] control thread has finished
2019-10-07 11:07:24,041 | DEBUG | MainThread | pilot.workflow.generic | run | thread count now at 6 threads
2019-10-07 11:07:24,041 | DEBUG | MainThread | pilot.workflow.generic | run | enumerate: [<_MainThread(MainThread, started 139944254940992)>, <ExcThread(queue_monitor, started 139943296878336)>, <ExcThread(validate_post, started 139943313663744)>, <ExcThread(job_monitor, started 139943305271040)>, <ExcThread(queue_monitoring, started 139943816963840)>, <ExcThread(copytool_out, started 139943850534656)>]
2019-10-07 11:07:24,197 | WARNING | queue_monitoring | pilot.util.common | should_abort | data:queue_monitoring:received graceful stop - abort after this iteration
2019-10-07 11:07:24,328 | DEBUG | copytool_out | pilot.control.data | copytool_out | [data] copytool_out thread has finished
2019-10-07 11:07:24,343 | DEBUG | MainThread | pilot.workflow.generic | run | thread count now at 5 threads
2019-10-07 11:07:24,343 | DEBUG | MainThread | pilot.workflow.generic | run | enumerate: [<_MainThread(MainThread, started 139944254940992)>, <ExcThread(queue_monitor, started 139943296878336)>, <ExcThread(validate_post, started 139943313663744)>, <ExcThread(job_monitor, started 139943305271040)>, <ExcThread(queue_monitoring, started 139943816963840)>]
2019-10-07 11:07:24,444 | WARNING | queue_monitor | pilot.util.common | should_abort | job:queue_monitor:received graceful stop - abort after this iteration
2019-10-07 11:07:24,445 | DEBUG | queue_monitor | pilot.control.job | queue_monitor | [job] queue monitor thread has finished
2019-10-07 11:07:24,512 | INFO | validate_post | pilot.control.payload | validate_post | [payload] validate_post thread has finished
2019-10-07 11:07:24,545 | DEBUG | MainThread | pilot.workflow.generic | run | thread count now at 3 threads
2019-10-07 11:07:24,546 | DEBUG | MainThread | pilot.workflow.generic | run | enumerate: [<_MainThread(MainThread, started 139944254940992)>, <ExcThread(job_monitor, started 139943305271040)>, <ExcThread(queue_monitoring, started 139943816963840)>]
2019-10-07 11:07:27,198 | DEBUG | queue_monitoring | pilot.control.data | queue_monitoring | [data] queue_monitor thread has finished
2019-10-07 11:07:27,264 | DEBUG | MainThread | pilot.workflow.generic | run | thread count now at 2 threads
2019-10-07 11:07:27,264 | DEBUG | MainThread | pilot.workflow.generic | run | enumerate: [<_MainThread(MainThread, started 139944254940992)>, <ExcThread(job_monitor, started 139943305271040)>]
2019-10-07 11:08:17,488 | WARNING | job_monitor | pilot.control.job | check_job_monitor_waiting_time | no jobs in monitored_payloads queue (waited for 72 s)
2019-10-07 11:08:17,488 | DEBUG | job_monitor | pilot.control.job | job_monitor | [job] job monitor thread has finished
2019-10-07 11:08:17,516 | INFO | MainThread | pilot.workflow.generic | run | end of generic workflow (traces error code: 0)
2019-10-07 11:08:17,516 | INFO | MainThread | root | wrap_up | traces error code: 0
2019-10-07 11:08:17,516 | INFO | MainThread | root | wrap_up | pilot has finished
2019-10-07 11:08:17 UTC [wrapper] ==== pilot stdout END ====
2019-10-07 11:08:17 UTC [wrapper] ==== wrapper stdout RESUME ====
2019-10-07 11:08:17 UTC [wrapper] Pilot exit status: 0
2019-10-07 11:08:17 UTC [wrapper] STATUSCODE: 0
2019-10-07 11:08:17 UTC [wrapper] apfmon messages muted
---- find pandaIDs.out ----
total 56
-rw-------. 1 grid grid 11357 Jul 25 16:38 LICENSE
-rw-------. 1 grid grid 20 Sep 9 13:04 MANIFEST.IN
-rw-------. 1 grid grid 11 Oct 7 06:43 pandaIDs.out
drwx------. 14 grid grid 216 Oct 7 06:43 pilot
-rwx------. 1 grid grid 20136 Sep 9 13:04 pilot.py
-rw-------. 1 grid grid 9 Sep 9 13:04 PILOTVERSION
-rw-------. 1 grid grid 2251 Jul 25 16:38 README.md
-rw-------. 1 grid grid 760 Aug 22 11:01 setup.py
-rw-------. 1 grid grid 221 Jul 25 16:38 TODO.md
2019-10-07 11:08:17 UTC [wrapper] pandaIDs.out files:
-rw-------. 1 grid grid 11 Oct 7 06:43 /home/grid/slots/0/pilot2/pandaIDs.out
2019-10-07 11:08:17 UTC [wrapper] pandaIDs.out content:
4495188292
2019-10-07 11:08:17 UTC [wrapper] Test setup, not cleaning
2019-10-07 11:08:17 UTC [wrapper] ==== wrapper stdout END ====
2019-10-07 11:08:17 UTC [wrapper] ==== wrapper stderr END ====
2019-10-07 11:08:17 UTC [wrapper] wrapper wrapperexiting ec=0, duration=23093
2019-10-07 11:08:17 UTC [wrapper] apfmon messages muted
2019-10-07 13:08:21,770: ***************diag file************
2019-10-07 13:08:21,770: runtimeenvironments=APPS/HEP/ATLAS-SITE;
Processors=1
WallTime=23093.18s
KernelTime=688.80s
UserTime=88253.12s
CPUUsage=385%
MaxResidentMemory=1947108kB
AverageResidentMemory=0kB
AverageTotalMemory=0kB
AverageUnsharedMemory=0kB
AverageUnsharedStack=0kB
AverageSharedMemory=0kB
PageSize=4096B
MajorPageFaults=26858
MinorPageFaults=21956912
Swaps=0
ForcedSwitches=11004247
WaitSwitches=11395548
Inputs=8779344
Outputs=1062464
SocketReceived=0
SocketSent=0
Signals=0
nodename=David_Cameron@dcameron04.cern.ch
exitcode=0
2019-10-07 13:08:21,777: ******************************WorkDir***********************
2019-10-07 13:08:21,777: total 281352
drwxrwx--x. 7 grid grid 4096 Oct 7 13:08 .
drwxr-x--x. 6 grid grid 42 Sep 26 14:51 ..
-rw-------. 1 grid grid 7586632 Oct 7 06:43 agis_ddmendpoints.json
-rw-------. 1 grid grid 3957839 Oct 7 06:43 agis_schedconf.cvmfs.json
drwx------. 2 grid grid 6 Oct 7 06:43 .alrb
drwxr-xr-x. 3 grid grid 17 Oct 7 06:43 APPS
-rw-------. 1 grid grid 538 Oct 7 06:43 .asetup
-rw-------. 1 grid grid 4506 Oct 7 06:44 .asetup.save
drwx------. 2 grid grid 6 Oct 7 06:44 .asetup-sysbin_23203
-rw-rw-r--. 1 grid grid 0 Oct 7 06:43 boinc_lockfile
-rw-rw-r--. 1 grid grid 8192 Oct 7 13:08 boinc_mmap_file
-rw-rw-r--. 1 grid grid 537 Oct 7 12:59 boinc_task_state.xml
-rw-rw-r--. 1 grid grid 273683184 Oct 7 06:43 EVNT.18605543._000408.pool.root.1
-rw-------. 1 grid grid 88909 Oct 7 13:07 heartbeat.json
-rw-rw-r--. 1 grid grid 5865 Oct 7 06:43 init_data.xml
-rw-rw-r--. 1 grid grid 267503 Oct 7 06:43 input.tar.gz
-rw-rw-r--. 1 grid grid 112 Oct 7 06:43 job.xml
-rw-------. 1 grid grid 518 Oct 7 13:08 kYHKDmezPZvnShfckohDCDFpABFKDmABFKDmDLkTDmABFKDmkYwhrm.diag
-rw-------. 1 grid grid 1153654 Oct 7 13:08 log.19000468._021756.job.log.1
-rw-------. 1 grid grid 908891 Oct 7 13:07 log.19000468._021756.job.log.tgz.1
-rw-------. 1 grid grid 847 Oct 7 13:07 memory_monitor_summary.json
-rw-------. 1 grid grid 463 Oct 7 13:08 output.list
-rw-------. 1 grid grid 2843 Oct 1 07:35 pandaJobData.out
drwx------. 3 grid grid 229 Oct 7 06:43 pilot2
-rw-r--r--. 1 grid grid 259319 Oct 1 07:35 pilot2.tar.gz
-rw-------. 1 grid grid 10105 Oct 7 13:08 pilotlog.txt
-rw-r--r--. 1 grid grid 4480 Oct 1 07:35 queuedata.json
-rw-rw-r--. 1 grid grid 815 Oct 7 06:43 RTE.tar.gz
-rwxr-xr-x. 1 grid grid 7950 Oct 7 06:43 run_atlas
-rwx------. 1 grid grid 12762 Oct 1 07:35 runpilot2-wrapper.sh
-rw-rw-r--. 1 grid grid 692 Oct 7 13:08 runtime_log
-rw-rw-r--. 1 grid grid 6899 Oct 7 13:08 runtime_log.err
drwxrwx--x. 2 grid grid 131 Oct 7 13:08 shared
-rw-rw-r--. 1 grid grid 8688 Oct 7 06:43 start_atlas.sh
-rw-rw-r--. 1 grid grid 39531 Oct 7 13:08 stderr.txt
-rw-rw-r--. 1 grid grid 107 Oct 7 06:43 wrapper_26015_x86_64-pc-linux-gnu
-rw-rw-r--. 1 grid grid 28 Oct 7 13:08 wrapper_checkpoint.txt
2019-10-07 13:08:21,777: running start_atlas return value is 0
2019-10-07 13:08:21,777: Parent exit 0
2019-10-07 13:08:21,779: child process exit 0
13:08:22 (16215): run_atlas exited; CPU time 88265.588551
13:08:22 (16215): called boinc_finish(0)
</stderr_txt>
]]>
©2024 CERN