| Name | iF1NDmkZBavnShfckohDCDFpABFKDmABFKDmTuvUDmABFKDm5kynTm_1 |
| Workunit | 1943037 |
| Created | 4 Oct 2019, 8:03:22 UTC |
| Sent | 7 Oct 2019, 10:14:11 UTC |
| Report deadline | 14 Oct 2019, 10:14:11 UTC |
| Received | 8 Oct 2019, 7:46:59 UTC |
| Server state | Over |
| Outcome | Success |
| Client state | Done |
| Exit status | 0 (0x00000000) |
| Computer ID | 3682 |
| Run time | 5 hours 47 min 34 sec |
| CPU time | 22 hours 48 min 4 sec |
| Validate state | Valid |
| Credit | 860.51 |
| Device peak FLOPS | 17.83 GFLOPS |
| Application version | ATLAS Simulation v0.74 (native_mt) x86_64-pc-linux-gnu |
| Peak working set size | 1.80 GB |
| Peak swap size | 2.58 GB |
| Peak disk usage | 650.86 MB |
Stderr output
<core_client_version>7.16.1</core_client_version>
<![CDATA[
<stderr_txt>
03:59:15 (399207): wrapper (7.7.26015): starting
03:59:15 (399207): wrapper: running run_atlas (--nthreads 4)
2019-10-08 03:59:15,509: singularity image is /cvmfs/atlas.cern.ch/repo/containers/images/singularity/x86_64-centos7.img
2019-10-08 03:59:15,509: sys.argv = ['run_atlas', '--nthreads', '4']
2019-10-08 03:59:15,510: THREADS=4
2019-10-08 03:59:15,510: Checking for CVMFS
2019-10-08 03:59:16,179: CVMFS is installed
2019-10-08 03:59:16,179: Checking Singularity...
2019-10-08 03:59:16,203: Singularity is installed, version singularity version 3.4.0-1.2.el7
2019-10-08 03:59:16,203: Testing the function of Singularity...
2019-10-08 03:59:16,203: Checking singularity with cmd:singularity exec -B /cvmfs /cvmfs/atlas.cern.ch/repo/containers/images/singularity/x86_64-centos7.img hostname
2019-10-08 03:59:16,299: Singularity Works...
2019-10-08 03:59:16,299: copy /home/dcameron/boinc/slots/1/shared/ATLAS.root_0
2019-10-08 03:59:16,738: copy /home/dcameron/boinc/slots/1/shared/input.tar.gz
2019-10-08 03:59:16,738: copy /home/dcameron/boinc/slots/1/shared/RTE.tar.gz
2019-10-08 03:59:16,738: copy /home/dcameron/boinc/slots/1/shared/start_atlas.sh
2019-10-08 03:59:16,738: export ATHENA_PROC_NUMBER=4;
2019-10-08 03:59:16,750: start atlas job with PandaID=4495528160
2019-10-08 03:59:16,751: cmd = singularity exec --pwd /home/dcameron/boinc/slots/1 -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-08 09:46:46,375: running cmd return value is 0
2019-10-08 09:46:46,376: Moving ./HITS.19056367._006186.pool.root.1 to shared/HITS.pool.root.1
2019-10-08 09:46:46,376: HITS result file:
2019-10-08 09:46:46,381: -rw-------. 1 dcameron zp 242345156 Oct 8 09:45 shared/HITS.pool.root.1
2019-10-08 09:46:46,382: *****************The last 200 lines of the pilot log******************
2019-10-08 09:46:46,385: "wallTime": 1
},
"total": {
"cpuTime": 46,
"wallTime": 78
},
"validation": {
"cpuTime": 0,
"wallTime": 0
},
"wallTime": 76
}
},
"machine": {
"cpu_family": "6",
"linux_distribution": [
"CentOS Linux",
"7.6.1810",
"Core"
],
"model": "60",
"model_name": "Intel(R) Core(TM) i7-4790 CPU @ 3.60GHz",
"node": "pcoslo5.cern.ch",
"platform": "Linux-3.10.0-1062.1.1.el7.x86_64-x86_64-with-centos-7.6.1810-Core"
},
"transform": {
"cpuEfficiency": 0.9871,
"cpuPWEfficiency": 0.9889,
"cpuTime": 5,
"cpuTimeTotal": 82095,
"externalCpuTime": 174,
"processedEvents": 200,
"trfPredata": null,
"wallTime": 20738
}
}
}
2019-10-08 07:45:42,909 | DEBUG | queue_monitor | pilot.util.auxiliary.4495528160 | update_server | xml:will send fileinfo
2019-10-08 07:45:42,909 | INFO | queue_monitor | pilot.control.job.4495528160 | send_state | pilot will not update the server (heartbeat message will be written to file)
2019-10-08 07:45:42,909 | INFO | queue_monitor | pilot.control.job.4495528160 | send_state | job 4495528160 has finished - writing final server update
2019-10-08 07:45:42,911 | WARNING | queue_monitor | pilot.api.analytics | get_fitted_data | wrong length of table data, x=[1570499986.0, 1570500047.0, 1570500108.0, 1570500169.0, 1570500230.0, 1570500291.0, 1570500352.0, 1570500413.0, 1570500474.0, 1570500535.0, 1570500596.0, 1570500657.0, 1570500718.0, 1570500779.0, 1570500840.0, 1570500901.0, 1570500962.0, 1570501023.0, 1570501084.0, 1570501145.0, 1570501206.0, 1570501267.0, 1570501328.0, 1570501389.0, 1570501450.0, 1570501511.0, 1570501572.0, 1570501633.0, 1570501694.0, 1570501755.0, 1570501816.0, 1570501877.0, 1570501938.0, 1570501999.0, 1570502060.0, 1570502121.0, 1570502182.0, 1570502243.0, 1570502304.0, 1570502365.0, 1570502426.0, 1570502487.0, 1570502548.0, 1570502609.0, 1570502670.0, 1570502731.0, 1570502792.0, 1570502853.0, 1570502914.0, 1570502975.0, 1570503036.0, 1570503097.0, 1570503158.0, 1570503219.0, 1570503280.0, 1570503341.0, 1570503402.0, 1570503463.0, 1570503524.0, 1570503585.0, 1570503646.0, 1570503707.0, 1570503768.0, 1570503829.0, 1570503890.0, 1570503951.0, 1570504012.0, 1570504073.0, 1570504134.0, 1570504195.0, 1570504256.0, 1570504317.0, 1570504378.0, 1570504439.0, 1570504500.0, 1570504561.0, 1570504622.0, 1570504683.0, 1570504744.0, 1570504805.0, 1570504866.0, 1570504927.0, 1570504988.0, 1570505049.0, 1570505110.0, 1570505171.0, 1570505232.0, 1570505293.0, 1570505354.0, 1570505415.0, 1570505476.0, 1570505537.0, 1570505598.0, 1570505659.0, 1570505720.0, 1570505781.0, 1570505842.0, 1570505903.0, 1570505964.0, 1570506025.0, 1570506086.0, 1570506147.0, 1570506208.0, 1570506269.0, 1570506330.0, 1570506391.0, 1570506452.0, 1570506513.0, 1570506574.0, 1570506635.0, 1570506696.0, 1570506757.0, 1570506818.0, 1570506879.0, 1570506940.0, 1570507001.0, 1570507062.0, 1570507123.0, 1570507184.0, 1570507245.0, 1570507306.0, 1570507367.0, 1570507428.0, 1570507489.0, 1570507550.0, 1570507611.0, 1570507672.0, 1570507733.0, 1570507794.0, 1570507855.0, 1570507916.0, 1570507977.0, 1570508038.0, 1570508099.0, 1570508160.0, 1570508221.0, 1570508282.0, 1570508343.0, 1570508404.0, 1570508465.0, 1570508526.0, 1570508587.0, 1570508648.0, 1570508709.0, 1570508770.0, 1570508831.0, 1570508892.0, 1570508953.0, 1570509014.0, 1570509075.0, 1570509136.0, 1570509197.0, 1570509258.0, 1570509319.0, 1570509380.0, 1570509441.0, 1570509502.0, 1570509563.0, 1570509624.0, 1570509685.0, 1570509746.0, 1570509807.0, 1570509868.0, 1570509929.0, 1570509990.0, 1570510051.0, 1570510112.0, 1570510173.0, 1570510234.0, 1570510295.0, 1570510356.0, 1570510417.0, 1570510478.0, 1570510539.0, 1570510600.0, 1570510661.0, 1570510722.0, 1570510783.0, 1570510844.0, 1570510905.0, 1570510966.0, 1570511027.0, 1570511088.0, 1570511149.0, 1570511210.0, 1570511271.0, 1570511332.0, 1570511393.0, 1570511454.0, 1570511515.0, 1570511576.0, 1570511637.0, 1570511698.0, 1570511759.0, 1570511820.0, 1570511881.0, 1570511942.0, 1570512003.0, 1570512064.0, 1570512125.0, 1570512186.0, 1570512247.0, 1570512308.0, 1570512369.0, 1570512430.0, 1570512491.0, 1570512552.0, 1570512613.0, 1570512674.0, 1570512735.0, 1570512796.0, 1570512857.0, 1570512918.0, 1570512979.0, 1570513040.0, 1570513101.0, 1570513162.0, 1570513223.0, 1570513284.0, 1570513345.0, 1570513406.0, 1570513467.0, 1570513528.0, 1570513589.0, 1570513650.0, 1570513711.0, 1570513772.0, 1570513833.0, 1570513894.0, 1570513955.0, 1570514016.0, 1570514077.0, 1570514138.0, 1570514199.0, 1570514260.0, 1570514321.0, 1570514382.0, 1570514443.0, 1570514504.0, 1570514565.0, 1570514626.0, 1570514687.0, 1570514748.0, 1570514809.0, 1570514870.0, 1570514931.0, 1570514992.0, 1570515053.0, 1570515114.0, 1570515175.0, 1570515236.0, 1570515297.0, 1570515358.0, 1570515419.0, 1570515480.0, 1570515541.0, 1570515602.0, 1570515663.0, 1570515724.0, 1570515785.0, 1570515846.0, 1570515907.0, 1570515968.0, 1570516029.0, 1570516090.0, 1570516151.0, 1570516212.0, 1570516273.0, 1570516334.0, 1570516395.0, 1570516456.0, 1570516517.0, 1570516578.0, 1570516639.0, 1570516700.0, 1570516761.0, 1570516822.0, 1570516883.0, 1570516944.0, 1570517005.0, 1570517066.0, 1570517127.0, 1570517188.0, 1570517249.0, 1570517310.0, 1570517371.0, 1570517432.0, 1570517493.0, 1570517554.0, 1570517615.0, 1570517676.0, 1570517737.0, 1570517798.0, 1570517859.0, 1570517920.0, 1570517981.0, 1570518042.0, 1570518103.0, 1570518164.0, 1570518225.0, 1570518286.0, 1570518347.0, 1570518408.0, 1570518469.0, 1570518530.0, 1570518591.0, 1570518652.0, 1570518713.0, 1570518774.0, 1570518835.0, 1570518896.0, 1570518957.0, 1570519018.0, 1570519079.0, 1570519140.0, 1570519201.0, 1570519262.0, 1570519323.0, 1570519384.0, 1570519445.0, 1570519506.0, 1570519567.0, 1570519628.0, 1570519689.0, 1570519750.0, 1570519811.0, 1570519872.0, 1570519933.0, 1570519994.0, 1570520055.0, 1570520116.0, 1570520177.0, 1570520238.0, 1570520299.0, 1570520360.0, 1570520421.0, 1570520482.0, 1570520543.0, 1570520604.0, 1570520665.0, 1570520726.0], y=[] (must be same and length>=2)
2019-10-08 07:45:42,911 | DEBUG | queue_monitor | pilot.util.auxiliary.4495528160 | get_job_metrics | job metrics="coreCount=4 actualCoreCount=4 nEvents=200 workDirSize=48997467"
2019-10-08 07:45:42,911 | INFO | queue_monitor | pilot.control.job.4495528160 | get_data_structure | total number of processed events: 200 (read)
2019-10-08 07:45:42,912 | INFO | queue_monitor | pilot.user.atlas.utilities | get_memory_values | using path: /home/dcameron/boinc/slots/1/PanDA_Pilot-4495528160/memory_monitor_summary.json (trf name=prmon)
2019-10-08 07:45:42,912 | DEBUG | queue_monitor | pilot.user.atlas.utilities | get_memory_monitor_info | summary_dictionary={'Max': {'rx_packets': 894184, 'nprocs': 12, 'nthreads': 1, 'rx_bytes': 1154033721, 'wtime': 20745, 'rss': 9412332, 'write_bytes': 0, 'vmem': 14141832, 'read_bytes': 0, 'stime': 164, 'tx_bytes': 916530194, 'pss': 2699830, 'wchar': 0, 'rchar': 0, 'tx_packets': 573333, 'swap': 0, 'utime': 82722}, 'Avg': {'write_bytes': 0, 'nprocs': 8, 'nthreads': 0, 'rx_bytes': 55627, 'rx_packets': 43, 'vmem': 13874811, 'read_bytes': 0, 'swap': 0, 'tx_bytes': 44179, 'pss': 2597040, 'wchar': 0, 'rchar': 0, 'tx_packets': 27, 'rss': 9223178}}
2019-10-08 07:45:42,912 | INFO | queue_monitor | pilot.user.atlas.utilities | get_memory_monitor_info | extracted standard info from prmon json
2019-10-08 07:45:42,912 | INFO | queue_monitor | pilot.user.atlas.utilities | get_memory_monitor_info | extracted standard memory fields from prmon json
2019-10-08 07:45:42,912 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | ..............................
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | . Timing measurements:
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | . get job = 0 s
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | . initial setup = 0 s
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | . payload setup = 0 s
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | . total setup = 0 s
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | . stage-in = 0 s
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | . payload execution = 20757 s
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | . stage-out = 1 s
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | ..............................
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | get_log_extracts | building log extracts (sent to the server as 'pilotLog')
2019-10-08 07:45:42,913 | DEBUG | queue_monitor | pilot.util.auxiliary.4495528160 | get_panda_tracer_log | PanDA tracer log does not exist: /home/dcameron/boinc/slots/1/PanDA_Pilot-4495528160/pandatracerlog.txt (ignoring)
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.container | execute | executing command: tail -n 20 /home/dcameron/boinc/slots/1/PanDA_Pilot-4495528160/pilotlog.txt
2019-10-08 07:45:42,924 | WARNING | queue_monitor | pilot.util.auxiliary.4495528160 | get_log_extracts | detected the following tail of warning/fatal messages in the pilot log:
- Log from pilotlog.txt -2019-10-08 07:45:42,911 | WARNING | queue_monitor | pilot.api.analytics | get_fitted_data | wrong length of table data, x=[1570499986.0, 1570500047.0, 1570500108.0, 1570500169.0, 1570500230.0, 1570500291.0, 1570500352.0, 1570500413.0, 1570500474.0, 1570500535.0, 1570500596.0, 1570500657.0, 1570500718.0, 1570500779.0, 1570500840.0, 1570500901.0, 1570500962.0, 1570501023.0, 1570501084.0, 1570501145.0, 1570501206.0, 1570501267.0, 1570501328.0, 1570501389.0, 1570501450.0, 1570501511.0, 1570501572.0, 1570501633.0, 1570501694.0, 1570501755.0, 1570501816.0, 1570501877.0, 1570501938.0, 1570501999.0, 1570502060.0, 1570502121.0, 1570502182.0, 1570502243.0, 1570502304.0, 1570502365.0, 1570502426.0, 1570502487.0, 1570502548.0, 1570502609.0, 1570502670.0, 1570502731.0, 1570502792.0, 1570502853.0, 1570502914.0, 1570502975.0, 1570503036.0, 1570503097.0, 1570503158.0, 1570503219.0, 1570503280.0, 1570503341.0, 1570503402.0, 1570503463.0, 1570503524.0, 1570503585.0, 1570503646.0, 1570503707.0, 1570503768.0, 1570503829.0, 1570503890.0, 1570503951.0, 1570504012.0, 1570504073.0, 1570504134.0, 1570504195.0, 1570504256.0, 1570504317.0, 1570504378.0, 1570504439.0, 1570504500.0, 1570504561.0, 1570504622.0, 1570504683.0, 1570504744.0, 1570504805.0, 1570504866.0, 1570504927.0, 1570504988.0, 1570505049.0, 1570505110.0, 1570505171.0, 1570505232.0, 1570505293.0, 1570505354.0, 1570505415.0, 1570505476.0, 1570505537.0, 1570505598.0, 1570505659.0, 1570505720.0, 1570505781.0, 1570505842.0, 1570505903.0, 1570505964.0, 1570506025.0, 1570506086.0, 1570506147.0, 1570506208.0, 1570506269.0, 1570506330.0, 1570506391.0, 1570506452.0, 1570506513.0, 1570506574.0, 1570506635.0, 1570506696.0, 1570506757.0, 1570506818.0, 1570506879.0, 1570506940.0, 1570507001.0, 1570507062.0, 1570507123.0, 1570507184.0, 1570507245.0, 1570507306.0, 1570507367.0, 1570507428.0, 1570507489.0, 1570507550.0, 1570507611.0, 1570507672.0, 1570507733.0, 1570507794.0, 1570507855.0, 1570507916.0, 1570507977.0, 1570508038.0, 1570508099.0, 1570508160.0, 1570508221.0, 1570508282.0, 1570508343.0, 1570508404.0, 1570508465.0, 1570508526.0, 1570508587.0, 1570508648.0, 1570508709.0, 1570508770.0, 1570508831.0, 1570508892.0, 1570508953.0, 1570509014.0, 1570509075.0, 1570509136.0, 1570509197.0, 1570509258.0, 1570509319.0, 1570509380.0, 1570509441.0, 1570509502.0, 1570509563.0, 1570509624.0, 1570509685.0, 1570509746.0, 1570509807.0, 1570509868.0, 1570509929.0, 1570509990.0, 1570510051.0, 1570510112.0, 1570510173.0, 1570510234.0, 1570510295.0, 1570510356.0, 1570510417.0, 1570510478.0, 1570510539.0, 1570510600.0, 1570510661.0, 1570510722.0, 1570510783.0, 1570510844.0, 1570510905.0, 1570510966.0, 1570511027.0, 1570511088.0, 1570511149.0, 1570511210.0, 1570511271.0, 1570511332.0, 1570511393.0, 1570511454.0, 1570511515.0, 1570511576.0, 1570511637.0, 1570511698.0, 1570511759.0, 1570511820.0, 1570511881.0, 1570511942.0, 1570512003.0, 1570512064.0, 1570512125.0, 1570512186.0, 1570512247.0, 1570512308.0, 1570512369.0, 1570512430.0, 1570512491.0, 1570512552.0, 1570512613.0, 1570512674.0, 1570512735.0, 1570512796.0, 1570512857.0, 1570512918.0, 1570512979.0, 1570513040.0, 1570513101.0, 1570513162.0, 1570513223.0, 1570513284.0, 1570513345.0, 1570513406.0, 1570513467.0, 1570513528.0, 1570513589.0, 1570513650.0, 1570513711.0, 1570513772.0, 1570513833.0, 1570513894.0, 1570513955.0, 1570514016.0, 1570514077.0, 1570514138.0, 1570514199.0, 1570514260.0, 1570514321.0, 1570514382.0, 1570514443.0, 1570514504.0, 1570514565.0, 1570514626.0, 1570514687.0, 1570514748.0, 1570514809.0, 1570514870.0, 1570514931.0, 1570514992.0, 1570515053.0, 1570515114.0, 1570515175.0, 1570515236.0, 1570515297.0, 1570515358.0, 1570515419.0, 1570515480.0, 1570515541.0, 1570515602.0, 1570515663.0, 1570515724.0, 1570515785.0, 1570515846.0, 1570515907.0, 1570515968.0, 1570516029.0, 1570516090.0, 1570516151.0, 1570516212.0, 1570516273.0, 1570516334.0, 1570516395.0, 1570516456.0, 1570516517.0, 1570516578.0, 1570516639.0, 1570516700.0, 1570516761.0, 1570516822.0, 1570516883.0, 1570516944.0, 1570517005.0, 1570517066.0, 1570517127.0, 1570517188.0, 1570517249.0, 1570517310.0, 1570517371.0, 1570517432.0, 1570517493.0, 1570517554.0, 1570517615.0, 1570517676.0, 1570517737.0, 1570517798.0, 1570517859.0, 1570517920.0, 1570517981.0, 1570518042.0, 1570518103.0, 1570518164.0, 1570518225.0, 1570518286.0, 1570518347.0, 1570518408.0, 1570518469.0, 1570518530.0, 1570518591.0, 1570518652.0, 1570518713.0, 1570518774.0, 1570518835.0, 1570518896.0, 1570518957.0, 1570519018.0, 1570519079.0, 1570519140.0, 1570519201.0, 1570519262.0, 1570519323.0, 1570519384.0, 1570519445.0, 1570519506.0, 1570519567.0, 1570519628.0, 1570519689.0, 1570519750.0, 1570519811.0, 1570519872.0, 1570519933.0, 1570519994.0, 1570520055.0, 1570520116.0, 1570520177.0, 1570520238.0, 1570520299.0, 1570520360.0, 1570520421.0, 1570520482.0, 1570520543.0, 1570520604.0, 1570520665.0, 1570520726.0], y=[] (must be same and length>=2)
2019-10-08 07:45:42,911 | DEBUG | queue_monitor | pilot.util.auxiliary.4495528160 | get_job_metrics | job metrics="coreCount=4 actualCoreCount=4 nEvents=200 workDirSize=48997467"
2019-10-08 07:45:42,911 | INFO | queue_monitor | pilot.control.job.4495528160 | get_data_structure | total number of processed events: 200 (read)
2019-10-08 07:45:42,912 | INFO | queue_monitor | pilot.user.atlas.utilities | get_memory_values | using path: /home/dcameron/boinc/slots/1/PanDA_Pilot-4495528160/memory_monitor_summary.json (trf name=prmon)
2019-10-08 07:45:42,912 | DEBUG | queue_monitor | pilot.user.atlas.utilities | get_memory_monitor_info | summary_dictionary={'Max': {'rx_packets': 894184, 'nprocs': 12, 'nthreads': 1, 'rx_bytes': 1154033721, 'wtime': 20745, 'rss': 9412332, 'write_bytes': 0, 'vmem': 14141832, 'read_bytes': 0, 'stime': 164, 'tx_bytes': 916530194, 'pss': 2699830, 'wchar': 0, 'rchar': 0, 'tx_packets': 573333, 'swap': 0, 'utime': 82722}, 'Avg': {'write_bytes': 0, 'nprocs': 8, 'nthreads': 0, 'rx_bytes': 55627, 'rx_packets': 43, 'vmem': 13874811, 'read_bytes': 0, 'swap': 0, 'tx_bytes': 44179, 'pss': 2597040, 'wchar': 0, 'rchar': 0, 'tx_packets': 27, 'rss': 9223178}}
2019-10-08 07:45:42,912 | INFO | queue_monitor | pilot.user.atlas.utilities | get_memory_monitor_info | extracted standard info from prmon json
2019-10-08 07:45:42,912 | INFO | queue_monitor | pilot.user.atlas.utilities | get_memory_monitor_info | extracted standard memory fields from prmon json
2019-10-08 07:45:42,912 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | ..............................
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | . Timing measurements:
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | . get job = 0 s
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | . initial setup = 0 s
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | . payload setup = 0 s
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | . total setup = 0 s
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | . stage-in = 0 s
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | . payload execution = 20757 s
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | . stage-out = 1 s
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | timing_report | ..............................
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.auxiliary.4495528160 | get_log_extracts | building log extracts (sent to the server as 'pilotLog')
2019-10-08 07:45:42,913 | DEBUG | queue_monitor | pilot.util.auxiliary.4495528160 | get_panda_tracer_log | PanDA tracer log does not exist: /home/dcameron/boinc/slots/1/PanDA_Pilot-4495528160/pandatracerlog.txt (ignoring)
2019-10-08 07:45:42,913 | INFO | queue_monitor | pilot.util.container | execute | executing command: tail -n 20 /home/dcameron/boinc/slots/1/PanDA_Pilot-4495528160/pilotlog.txt
2019-10-08 07:45:42,925 | DEBUG | queue_monitor | pilot.control.job.4495528160 | send_state | wrote heartbeat to file /home/dcameron/boinc/slots/1/heartbeat.json
2019-10-08 07:45:42,925 | INFO | queue_monitor | pilot.control.job | queue_monitor | job 4495528160 was dequeued from the monitored payloads queue
2019-10-08 07:45:43,522 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report |
2019-10-08 07:45:43,522 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | job summary report
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | --------------------------------------------------
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | PanDA job id: 4495528160
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | task id: 19056367
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | errors: (none)
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | status: LOG_TRANSFER = DONE
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | pilot state: finished
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | transexitcode: 0
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | exeerrorcode: 0
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | exeerrordiag:
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | exitcode: 0
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | exitmsg: OK
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | cpuconsumptiontime: 82421 s
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | nevents: 200
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | neventsw: 0
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | pid: 406113
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | pgrp: 406113
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | corecount: 4
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | event service: False
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report | --------------------------------------------------
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.util.auxiliary.4495528160 | make_job_report |
2019-10-08 07:45:43,523 | INFO | retrieve | pilot.control.job.4495528160 | has_job_completed | job 4495528160 has completed
2019-10-08 07:45:43,524 | INFO | retrieve | pilot.util.processes | cleanup | overall cleanup function is called
2019-10-08 07:45:43,527 | DEBUG | retrieve | pilot.util.processes | cleanup | work directory was removed: /home/dcameron/boinc/slots/1/PanDA_Pilot-4495528160
2019-10-08 07:45:44,532 | INFO | retrieve | pilot.info.jobdata | collect_zombies | --- collectZombieJob: --- 10, [406113]
2019-10-08 07:45:44,532 | INFO | retrieve | pilot.info.jobdata | collect_zombies | zombie collector trying to kill pid 406113
2019-10-08 07:45:44,532 | INFO | retrieve | pilot.info.jobdata | collect_zombies | harmless exception when collecting zombies: [Errno 10] No child processes
2019-10-08 07:45:44,616 | WARNING | job_monitor | pilot.control.job | check_job_monitor_waiting_time | no jobs in monitored_payloads queue (waited for 72 s)
2019-10-08 07:45:45,536 | INFO | retrieve | pilot.util.processes | cleanup | collected zombie processes
2019-10-08 07:45:45,536 | INFO | retrieve | pilot.util.processes | cleanup | will now attempt to kill all subprocesses of pid=406113
2019-10-08 07:45:45,605 | INFO | retrieve | pilot.util.processes | kill_processes | process IDs to be killed: [406113] (in reverse order)
2019-10-08 07:45:45,638 | WARNING | retrieve | pilot.util.processes | kill_processes | found no corresponding commands to process id(s)
2019-10-08 07:45:45,638 | INFO | retrieve | pilot.util.processes | kill_orphans | Do not look for orphan processes in BOINC jobs
2019-10-08 07:45:45,638 | INFO | retrieve | pilot.control.job | retrieve | ready for new job
2019-10-08 07:45:45,638 | 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-08 07:45:45,640 | INFO | retrieve | pilot.util.auxiliary | pilot_version_banner | *****************************************
2019-10-08 07:45:45,640 | INFO | retrieve | pilot.util.auxiliary | pilot_version_banner | *** PanDA Pilot version 2.1.25 (11) ***
2019-10-08 07:45:45,640 | INFO | retrieve | pilot.util.auxiliary | pilot_version_banner | *****************************************
2019-10-08 07:45:45,640 | INFO | retrieve | pilot.util.auxiliary | pilot_version_banner |
2019-10-08 07:45:45,641 | INFO | retrieve | pilot.util.auxiliary | display_architecture_info | architecture information:
2019-10-08 07:45:45,676 | 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-08 07:45:45,677 | INFO | retrieve | pilot.util.auxiliary | pilot_version_banner | *****************************************
2019-10-08 07:45:46,179 | DEBUG | retrieve | pilot.util.monitoring | check_local_space | checking local space on /home/dcameron/boinc/slots/1
2019-10-08 07:45:46,191 | INFO | retrieve | pilot.util.monitoring | check_local_space | sufficient remaining disk space (70701285376 B)
2019-10-08 07:45:46,191 | WARNING | retrieve | pilot.control.job | proceed_with_getjob | since timefloor is set to 0, pilot was only allowed to run one job
2019-10-08 07:45:46,191 | DEBUG | retrieve | pilot.control.job | retrieve | [job] retrieve thread has finished
2019-10-08 07:45:46,211 | DEBUG | create_data_payload | pilot.control.job | create_data_payload | [job] create_data_payload thread has finished
2019-10-08 07:45:46,212 | INFO | validate_pre | pilot.control.payload | validate_pre | [payload] validate_pre thread has finished
2019-10-08 07:45:46,212 | DEBUG | copytool_in | pilot.control.data | copytool_in | [data] copytool_in thread has finished
2019-10-08 07:45:46,220 | WARNING | copytool_out | pilot.util.common | should_abort | data:copytool_out:received graceful stop - abort after this iteration
2019-10-08 07:45:46,234 | INFO | monitor | pilot.control.monitor | control | [monitor] control thread has ended
2019-10-08 07:45:46,497 | INFO | execute_payloads | pilot.control.payload | execute_payloads | [payload] execute_payloads thread has finished
2019-10-08 07:45:46,509 | DEBUG | validate | pilot.control.job | validate | [job] validate thread has finished
2019-10-08 07:45:46,532 | DEBUG | MainThread | pilot.workflow.generic | run | thread count now at 10 threads
2019-10-08 07:45:46,532 | DEBUG | MainThread | pilot.workflow.generic | run | enumerate: [<_MainThread(MainThread, started 140087538149184)>, <ExcThread(job, started 140087376516864)>, <ExcThread(job_monitor, started 140086523979520)>, <ExcThread(payload, started 140087136352000)>, <ExcThread(validate_post, started 140087085995776)>, <ExcThread(failed_post, started 140086515586816)>, <ExcThread(queue_monitor, started 140086507194112)>, <ExcThread(queue_monitoring, started 140087119566592)>, <ExcThread(data, started 140087359731456)>, <ExcThread(copytool_out, started 140087127959296)>]
2019-10-08 07:45:47,036 | DEBUG | data | pilot.control.data | control | data control ending since graceful_stop has been set
2019-10-08 07:45:47,036 | DEBUG | data | pilot.control.data | control | [data] control thread has finished
2019-10-08 07:45:47,221 | DEBUG | copytool_out | pilot.control.data | copytool_out | [data] copytool_out thread has finished
2019-10-08 07:45:47,234 | DEBUG | MainThread | pilot.workflow.generic | run | thread count now at 8 threads
2019-10-08 07:45:47,235 | DEBUG | MainThread | pilot.workflow.generic | run | enumerate: [<_MainThread(MainThread, started 140087538149184)>, <ExcThread(job, started 140087376516864)>, <ExcThread(job_monitor, started 140086523979520)>, <ExcThread(payload, started 140087136352000)>, <ExcThread(validate_post, started 140087085995776)>, <ExcThread(failed_post, started 140086515586816)>, <ExcThread(queue_monitor, started 140086507194112)>, <ExcThread(queue_monitoring, started 140087119566592)>]
2019-10-08 07:45:47,252 | DEBUG | payload | pilot.control.payload | control | payload control ending since graceful_stop has been set
2019-10-08 07:45:47,252 | DEBUG | payload | pilot.control.payload | control | [payload] control thread has finished
2019-10-08 07:45:47,291 | WARNING | queue_monitor | pilot.util.common | should_abort | job:queue_monitor:received graceful stop - abort after this iteration
2019-10-08 07:45:47,291 | DEBUG | queue_monitor | pilot.control.job | queue_monitor | [job] queue monitor thread has finished
2019-10-08 07:45:47,362 | WARNING | queue_monitoring | pilot.util.common | should_abort | data:queue_monitoring:received graceful stop - abort after this iteration
2019-10-08 07:45:47,435 | DEBUG | MainThread | pilot.workflow.generic | run | thread count now at 6 threads
2019-10-08 07:45:47,435 | DEBUG | MainThread | pilot.workflow.generic | run | enumerate: [<_MainThread(MainThread, started 140087538149184)>, <ExcThread(job, started 140087376516864)>, <ExcThread(job_monitor, started 140086523979520)>, <ExcThread(validate_post, started 140087085995776)>, <ExcThread(failed_post, started 140086515586816)>, <ExcThread(queue_monitoring, started 140087119566592)>]
2019-10-08 07:45:47,484 | DEBUG | job | pilot.control.job | control | job control ending since graceful_stop has been set
2019-10-08 07:45:47,484 | DEBUG | job | pilot.control.job | control | [job] control thread has finished
2019-10-08 07:45:47,520 | INFO | validate_post | pilot.control.payload | validate_post | [payload] validate_post thread has finished
2019-10-08 07:45:47,536 | DEBUG | MainThread | pilot.workflow.generic | run | thread count now at 4 threads
2019-10-08 07:45:47,536 | DEBUG | MainThread | pilot.workflow.generic | run | enumerate: [<_MainThread(MainThread, started 140087538149184)>, <ExcThread(job_monitor, started 140086523979520)>, <ExcThread(failed_post, started 140086515586816)>, <ExcThread(queue_monitoring, started 140087119566592)>]
2019-10-08 07:45:47,591 | INFO | failed_post | pilot.control.payload | failed_post | [payload] failed_post thread has finished
2019-10-08 07:45:47,636 | DEBUG | MainThread | pilot.workflow.generic | run | thread count now at 3 threads
2019-10-08 07:45:47,637 | DEBUG | MainThread | pilot.workflow.generic | run | enumerate: [<_MainThread(MainThread, started 140087538149184)>, <ExcThread(job_monitor, started 140086523979520)>, <ExcThread(queue_monitoring, started 140087119566592)>]
2019-10-08 07:45:50,363 | DEBUG | queue_monitoring | pilot.control.data | queue_monitoring | [data] queue_monitor thread has finished
2019-10-08 07:45:50,454 | DEBUG | MainThread | pilot.workflow.generic | run | thread count now at 2 threads
2019-10-08 07:45:50,454 | DEBUG | MainThread | pilot.workflow.generic | run | enumerate: [<_MainThread(MainThread, started 140087538149184)>, <ExcThread(job_monitor, started 140086523979520)>]
2019-10-08 07:46:46,192 | WARNING | job_monitor | pilot.control.job | check_job_monitor_waiting_time | no jobs in monitored_payloads queue (waited for 134 s)
2019-10-08 07:46:46,192 | DEBUG | job_monitor | pilot.control.job | job_monitor | [job] job monitor thread has finished
2019-10-08 07:46:46,211 | INFO | MainThread | pilot.workflow.generic | run | end of generic workflow (traces error code: 0)
2019-10-08 07:46:46,212 | INFO | MainThread | root | wrap_up | traces error code: 0
2019-10-08 07:46:46,212 | INFO | MainThread | root | wrap_up | pilot has finished
2019-10-08 07:46:46 UTC [wrapper] ==== pilot stdout END ====
2019-10-08 07:46:46 UTC [wrapper] ==== wrapper stdout RESUME ====
2019-10-08 07:46:46 UTC [wrapper] Pilot exit status: 0
2019-10-08 07:46:46 UTC [wrapper] STATUSCODE: 0
2019-10-08 07:46:46 UTC [wrapper] apfmon messages muted
---- find pandaIDs.out ----
total 56
-rw-------. 1 dcameron zp 11357 Jul 25 16:38 LICENSE
-rw-------. 1 dcameron zp 20 Sep 9 13:04 MANIFEST.IN
-rw-------. 1 dcameron zp 11 Oct 8 03:59 pandaIDs.out
drwx------. 14 dcameron zp 216 Oct 8 03:59 pilot
-rwx------. 1 dcameron zp 20136 Sep 9 13:04 pilot.py
-rw-------. 1 dcameron zp 9 Sep 9 13:04 PILOTVERSION
-rw-------. 1 dcameron zp 2251 Jul 25 16:38 README.md
-rw-------. 1 dcameron zp 760 Aug 22 11:01 setup.py
-rw-------. 1 dcameron zp 221 Jul 25 16:38 TODO.md
2019-10-08 07:46:46 UTC [wrapper] pandaIDs.out files:
-rw-------. 1 dcameron zp 11 Oct 8 03:59 /home/dcameron/boinc/slots/1/pilot2/pandaIDs.out
2019-10-08 07:46:46 UTC [wrapper] pandaIDs.out content:
4495528160
2019-10-08 07:46:46 UTC [wrapper] Test setup, not cleaning
2019-10-08 07:46:46 UTC [wrapper] ==== wrapper stdout END ====
2019-10-08 07:46:46 UTC [wrapper] ==== wrapper stderr END ====
2019-10-08 07:46:46 UTC [wrapper] wrapper wrapperexiting ec=0, duration=20850
2019-10-08 07:46:46 UTC [wrapper] apfmon messages muted
2019-10-08 09:46:46,388: ***************diag file************
2019-10-08 09:46:46,388: runtimeenvironments=APPS/HEP/ATLAS-SITE;
Processors=1
WallTime=20849.45s
KernelTime=515.04s
UserTime=82084.58s
CPUUsage=396%
MaxResidentMemory=1947636kB
AverageResidentMemory=0kB
AverageTotalMemory=0kB
AverageUnsharedMemory=0kB
AverageUnsharedStack=0kB
AverageSharedMemory=0kB
PageSize=4096B
MajorPageFaults=25628
MinorPageFaults=22216611
Swaps=0
ForcedSwitches=562792
WaitSwitches=11930780
Inputs=8154730
Outputs=1021800
SocketReceived=0
SocketSent=0
Signals=0
nodename=David_Cameron@pcoslo5.cern.ch
exitcode=0
2019-10-08 09:46:46,392: ******************************WorkDir***********************
2019-10-08 09:46:46,392: total 220768
drwxrwx--x. 7 dcameron zp 4096 Oct 8 09:46 .
drwxrwx--x. 4 dcameron zp 24 Oct 7 12:10 ..
-rw-------. 1 dcameron zp 7595462 Oct 8 03:59 agis_ddmendpoints.json
-rw-------. 1 dcameron zp 3936675 Oct 8 03:59 agis_schedconf.cvmfs.json
drwx------. 2 dcameron zp 6 Oct 8 03:59 .alrb
drwxr-xr-x. 3 dcameron zp 17 Oct 8 03:59 APPS
-rw-------. 1 dcameron zp 548 Oct 8 03:59 .asetup
-rw-------. 1 dcameron zp 4130 Oct 8 03:59 .asetup.save
drwx------. 2 dcameron zp 6 Oct 8 03:59 .asetup-sysbin_406116
-rw-r--r--. 1 dcameron zp 0 Oct 8 03:59 boinc_lockfile
-rw-r--r--. 1 dcameron zp 8192 Oct 8 09:46 boinc_mmap_file
-rw-r--r--. 1 dcameron zp 537 Oct 8 09:40 boinc_task_state.xml
-rw-r--r--. 1 dcameron zp 211651493 Oct 8 03:59 EVNT.18605811._000120.pool.root.1
-rw-------. 1 dcameron zp 71035 Oct 8 09:45 heartbeat.json
-rw-------. 1 dcameron zp 513 Oct 8 09:46 iF1NDmkZBavnShfckohDCDFpABFKDmABFKDmTuvUDmABFKDm5kynTm.diag
-rw-r--r--. 1 dcameron zp 6245 Oct 8 03:59 init_data.xml
-rw-r--r--. 1 dcameron zp 267513 Oct 8 03:59 input.tar.gz
-rw-r--r--. 1 dcameron zp 112 Oct 8 03:59 job.xml
-rw-------. 1 dcameron zp 1195523 Oct 8 09:46 log.19056367._006186.job.log.1
-rw-------. 1 dcameron zp 882402 Oct 8 09:45 log.19056367._006186.job.log.tgz.1
-rw-------. 1 dcameron zp 797 Oct 8 09:45 memory_monitor_summary.json
-rw-------. 1 dcameron zp 463 Oct 8 09:46 output.list
-rw-------. 1 dcameron zp 2886 Oct 3 10:23 pandaJobData.out
drwx------. 3 dcameron zp 229 Oct 8 03:59 pilot2
-rw-r--r--. 1 dcameron zp 259319 Oct 3 09:27 pilot2.tar.gz
-rw-------. 1 dcameron zp 9465 Oct 8 09:46 pilotlog.txt
-rw-r--r--. 1 dcameron zp 4480 Oct 3 10:22 queuedata.json
-rw-r--r--. 1 dcameron zp 815 Oct 8 03:59 RTE.tar.gz
-rwxr-xr-x. 1 dcameron zp 7950 Oct 8 03:59 run_atlas
-rwx------. 1 dcameron zp 12762 Oct 3 10:23 runpilot2-wrapper.sh
-rw-r--r--. 1 dcameron zp 692 Oct 8 09:46 runtime_log
-rw-r--r--. 1 dcameron zp 8048 Oct 8 09:46 runtime_log.err
-rw-------. 1 dcameron zp 240 Oct 8 03:59 setup.sh.local
drwxrwx--x. 2 dcameron zp 131 Oct 8 09:46 shared
-rw-r--r--. 1 dcameron zp 8688 Oct 8 03:59 start_atlas.sh
-rw-r--r--. 1 dcameron zp 38136 Oct 8 09:46 stderr.txt
-rw-r--r--. 1 dcameron zp 107 Oct 8 03:59 wrapper_26015_x86_64-pc-linux-gnu
-rw-r--r--. 1 dcameron zp 28 Oct 8 09:46 wrapper_checkpoint.txt
2019-10-08 09:46:46,392: running start_atlas return value is 0
2019-10-08 09:46:46,392: Parent exit 0
2019-10-08 09:46:46,392: child process exit 0
09:46:46 (399207): run_atlas exited; CPU time 82084.892452
09:46:46 (399207): called boinc_finish(0)
</stderr_txt>
]]>
©2024 CERN