Commit 53ff8b55 authored by Walter Lampl's avatar Walter Lampl
Browse files

Merge branch 'BMK-968' into 'atlUseWalltime'

# Conflicts:
#   alice/gen-sim-reco-run3/alice-gen-sim-reco-run3.spec
#   alice/gen-sim-reco-run3/alice-gen-sim-reco-run3/alice-gen-sim-reco-run3-bmk.sh
#   alice/gen-sim-reco-run3/alice-gen-sim-reco-run3/parseResults.sh
#   alice/gen-sim-reco-run3/alice_spec_custom.txt
parents 52e6491e 076600d2
Pipeline #4106854 failed with stage
in 2 seconds
......@@ -3,7 +3,7 @@ HEPWL_BMKOPTS="-t 2 -c 1 -e 2 -m none"
HEPWL_BMKDIR=alice-gen-sim-reco-run3
HEPWL_BMKDESCRIPTION="ALICE pp GEN-SIM"
HEPWL_DOCKERIMAGENAME=alice-gen-sim-reco-run3-bmk
HEPWL_DOCKERIMAGETAG=ci-v0.5-aod
HEPWL_DOCKERIMAGETAG=ci-v0.6-aod
HEPWL_CVMFSREPOS=alice.cern.ch
HEPWL_BMKOS="gitlab-registry.cern.ch/linuxsupport/cc7-base:20211101-1.x86_64"
HEPWL_EXTEND_ALICE_SPEC=./alice_spec_custom.txt
......@@ -24,10 +24,10 @@ function doOne(){
# Background events are reused across timeframes.
#
#export ALIENV_DEBUG=1
/cvmfs/alice.cern.ch/bin/alienv printenv O2sim/v20220421-1 &> environment
/cvmfs/alice.cern.ch/bin/alienv printenv O2sim/v20220608-2 &> environment
source environment
export HEPSCORE_CCDB_ROOT=/cvmfs/alice.cern.ch/el7-x86_64/Packages/HEPscore-CCDB/v0.1.1-test-1
export HEPSCORE_CCDB_ROOT=/cvmfs/alice.cern.ch/el7-x86_64/Packages/HEPscore-CCDB/v0.1.2-test-1
export ROOT_INCLUDE_PATH=${ROOT_INCLUDE_PATH}:/cvmfs/alice.cern.ch/el7-x86_64/Packages/TBB/v2021.5.0-8/include
# make sure O2DPG + O2 is loaded
......@@ -50,7 +50,7 @@ function doOne(){
-tf ${NTIMEFRAMES} -nb ${NBKGEVENTS} \
-ns ${NSIGEVENTS} -e ${SIMENGINE} \
-j ${NWORKERS} --embedding -interactionRate 50000 \
--timestamp 1635659148972 -seed 1 > out_$1.log 2>&1
-run -1 -seed 1 --timestamp 1550600800000 > out_$1.log 2>&1
# copy CCDB snapshot to workdir
......@@ -62,8 +62,28 @@ function doOne(){
cp ${HEPSCORE_CCDB_ROOT}/data/matbud.root .
# run workflow
${O2DPG_ROOT}/MC/bin/o2_dpg_workflow_runner.py -f workflow.json --cpu-limit ${CPULIMIT} -tt aod_ >> out_$1.log 2>&1
${O2DPG_ROOT}/MC/bin/o2_dpg_workflow_runner.py -f workflow.json --cpu-limit ${CPULIMIT} -tt aod_ --retry-on-failure 1 >> out_$1.log 2>&1
status=${?}
# Calculate some relative activity numbers per category (SIM, DIGI, RECO, AOD),
# not really weighting according to internal multi-core behaviour, though.
# Also, the sampling is rather crude and numbers only a rough estimate.
TOTAL=`awk 'BEGIN{c=0} /iter/ { c+=1 } END {print 5*c}' pipeline_metric_*.log`
RECOTIME=`awk 'BEGIN{c=0} /RECO/ { c+=1 } END {print 5*c}' pipeline_metric_*.log`
DIGITIME=`awk 'BEGIN{c=0} /DIGI/ { c+=1 } END {print 5*c}' pipeline_metric_*.log`
SIMTIME=`awk 'BEGIN{c=0} /GEANT/ { c+=1 } END {print 5*c}' pipeline_metric_*.log`
AODTIME=`awk 'BEGIN{c=0} /AOD/ { c+=1 } END {print 5*c}' pipeline_metric_*.log`
RECOFRACTION=$(awk -v "t=${TOTAL}" -v "r=${RECOTIME}" 'BEGIN { print (r/t); }')
SIMFRACTION=$(awk -v "t=${TOTAL}" -v "s=${SIMTIME}" 'BEGIN { print (s/t); }')
DIGIFRACTION=$(awk -v "t=${TOTAL}" -v "d=${DIGITIME}" 'BEGIN { print (d/t); }')
AODFRACTION=$(awk -v "t=${TOTAL}" -v "a=${AODTIME}" 'BEGIN { print (a/t); }')
echo "sim time ${SIMTIME}s; sim active fraction ~${SIMFRACTION}%" >> out_$1.log
echo "digi time ${DIGITIME}s; digi active fraction ~${DIGIFRACTION}%" >> out_$1.log
echo "reco time ${RECOTIME}s; reco active fraction ~${RECOFRACTION}%" >> out_$1.log
echo "aod time ${AODTIME}s; aod active fraction ~${AODFRACTION}%" >> out_$1.log
# Note that these timings will not add up to the total walltime of the workflow
# due to an interleaving + parallel nature.
echo "[doOne ($1)] $(date) completed (status=$status)"
# Return 0 if this workload copy was successful, 1 otherwise
return $status
......
{
"run_info": {
"copies": 1,
"threads_per_copy": 2,
"events_per_thread": 2
},
"report": {
"wl-scores": {
"gen-sim-digi-reco": 0.0031,
"sim": 0.0032,
"digi": 0.0198,
"reco": 0.0115
},
"wl-stats": {
"gen-sim-digi-reco": {
"avg": 0.0031,
"median": 0.0031,
"min": 0.0031,
"max": 0.0031,
"count": 1
},
"sim": {
"avg": 0.0032,
"median": 0.0032,
"min": 0.0032,
"max": 0.0032,
"count": 1
},
"digi": {
"avg": 0.0198,
"median": 0.0198,
"min": 0.0198,
"max": 0.0198,
"count": 1
},
"reco": {
"avg": 0.0115,
"median": 0.0115,
"min": 0.0115,
"max": 0.0115,
"count": 1
}
},
"log": "ok"
},
"app": {
"version": "ci-v0.6-aod",
"description": "ALICE pp GEN-SIM",
"cvmfs_checksum": "9a6f83303c8086fa10e39beb42610ed7",
"bmkdata_checksum": "68794e67e9f53683dd09bcf5a71a3237",
"bmk_checksum": "b6951f75f353380cfd09950a4fcc2b64",
"containment": "docker"
}
}
\ No newline at end of file
{"wl-scores": { "gen-sim-digi-reco": 0.0031, "sim": 0.0032, "digi": 0.0198, "reco": 0.0115 }, "wl-stats": { "gen-sim-digi-reco": { "avg": 0.0031, "median": 0.0031, "min": 0.0031, "max": 0.0031, "count": 1 }, "sim": { "avg": 0.0032, "median": 0.0032, "min": 0.0032, "max": 0.0032, "count": 1 }, "digi": { "avg": 0.0198, "median": 0.0198, "min": 0.0198, "max": 0.0198, "count": 1 }, "reco": { "avg": 0.0115, "median": 0.0115, "min": 0.0115, "max": 0.0115, "count": 1 } }}
Running: TIME="#walltime %e\n#systime %S\n#usertime %U" /usr/bin/time --output=bkgsim.log_time ./bkgsim.log_tmp.sh
[INFO] This is o2-sim version 1.2.0 (6631a8738)
[INFO] Built by ALIBUILD:v1.11.3, ALIDIST-REV:363dbd71afbf7a7f5bc1fff7c8d44166e13ccf9e on OS:Linux-3.10.0-1160.59.1.el7.x86_64
[INFO] BINDING TO ADDRESS ipc:///tmp/o2sim-notifications-330 type pub
[INFO] Running with 2 sim workers
[INFO] CREATING SIM SHARED MEM SEGMENT FOR 2 WORKERS
Spawning particle server on PID 340; Redirect output to bkg_serverlog
Spawning sim worker 0 on PID 342; Redirect output to bkg_workerlog0
Spawning hit merger on PID 343; Redirect output to bkg_mergerlog
[INFO] DISTRIBUTING EVENT : 1
[INFO] DISTRIBUTING EVENT : 2
[INFO] EVENT FINISHED : 1
[INFO] DISTRIBUTING EVENT : 3
[INFO] EVENT FINISHED : 2
[INFO] EVENT FINISHED : 3
[INFO] DISTRIBUTING EVENT : 4
[INFO] EVENT FINISHED : 4
[INFO] SIMULATION IS DONE. INITIATING SHUTDOWN.
[INFO] Merger process 343 returned
[INFO] Simulation process took 730.663 s
[INFO] SHUTTING DOWN CHILD PROCESS 340
[INFO] SHUTTING DOWN CHILD PROCESS 342
[INFO] SIMULATION RETURNED SUCCESFULLY
TASK-EXIT-CODE: 0
[doOneWrapper (1)] Mon Jun 13 14:23:14 CEST 2022 : process 1 configured
[doOneWrapper (1)] HOME=/results/alice-gen-sim-reco-run3-c1-e2-1655122994_1825/proc_1/HOME
[doOneWrapper (1)] current process pid is 49
[doOneWrapper (1)] run doOne as bmkuser
[doOne (1)] Mon Jun 13 14:23:14 CEST 2022 starting in /results/alice-gen-sim-reco-run3-c1-e2-1655122994_1825/proc_1
Setting CCDB cache to /results/alice-gen-sim-reco-run3-c1-e2-1655122994_1825/proc_1/.ccdb
[doOne (1)] Mon Jun 13 14:45:02 CEST 2022 completed (status=0)
[doOneWrapper (1)] Mon Jun 13 14:45:02 CEST 2022 : process 1 (pid=49) completed ok
Running: TIME="#walltime %e\n#systime %S\n#usertime %U" /usr/bin/time --output=genbkgconf.log_time ./genbkgconf.log_tmp.sh
TASK-EXIT-CODE: 0
Running: TIME="#walltime %e\n#systime %S\n#usertime %U" /usr/bin/time --output=matbuddownloader.log_time ./matbuddownloader.log_tmp.sh
TASK-EXIT-CODE: 0
{
"fairMQOptions":{
"devices":[
{
"id":"worker",
"channels":[
{
"name":"primary-get",
"sockets":[
{
"type":"req",
"method":"connect",
"address":"ipc:///tmp/o2sim-primary-get-330",
"sndBufSize":"100000",
"rcvBufSize":"100000",
"rateLogging":"0"
}
]
},
{
"name":"o2sim-primserv-info",
"sockets":[
{
"type":"req",
"method":"connect",
"address":"ipc:///tmp/o2sim-primserv-info-330",
"sndBufSize":"1000",
"rcvBufSize":"1000",
"rateLogging":"0"
}
]
},
{
"name":"simdata",
"sockets":[
{
"type":"push",
"method":"connect",
"address":"ipc:///tmp/o2sim-hitmerger-simdata-330",
"sndBufSize":1000,
"rcvBufSize":1000,
"rateLogging":0
}
]
}
]
},
{
"id":"primary-server",
"channels":[
{
"name":"primary-get",
"sockets":[
{
"type":"rep",
"method":"bind",
"address":"ipc:///tmp/o2sim-primary-get-330",
"sndBufSize":100000,
"rcvBufSize":100000,
"rateLogging":0
}
]
},
{
"name":"o2sim-primserv-info",
"sockets":[
{
"type":"rep",
"method":"bind",
"address":"ipc:///tmp/o2sim-primserv-info-330",
"sndBufSize":1000,
"rcvBufSize":1000,
"rateLogging":0
}
]
},
{
"name":"primary-notifications",
"sockets":[
{
"type":"pub",
"method":"bind",
"address":"ipc:///tmp/o2sim-primary-notifications-330",
"sndBufSize":1000,
"rcvBufSize":1000,
"rateLogging":0
}
]
}
]
},
{
"id":"hitmerger",
"channels":[
{
"name":"primary-get",
"sockets":[
{
"type":"req",
"method":"connect",
"address":"ipc:///tmp/o2sim-primary-get-330",
"sndBufSize":"1000",
"rcvBufSize":"1000",
"rateLogging":"0"
}
]
},
{
"name":"o2sim-primserv-info",
"sockets":[
{
"type":"req",
"method":"connect",
"address":"ipc:///tmp/o2sim-primserv-info-330",
"sndBufSize":"1000",
"rcvBufSize":"1000",
"rateLogging":"0"
}
]
},
{
"name":"simdata",
"sockets":[
{
"type":"pull",
"method":"bind",
"address":"ipc:///tmp/o2sim-hitmerger-simdata-330",
"sndBufSize":1000,
"rcvBufSize":1000,
"rateLogging":0
}
]
},
{
"name":"merger-notifications",
"sockets":[
{
"type":"pub",
"method":"bind",
"address":"ipc:///tmp/o2sim-merger-notifications-330",
"sndBufSize":1000,
"rcvBufSize":1000,
"rateLogging":0
}
]
}
]
}
]
}
}
Namespace(anchor_config='', bcPatternFile='', col='pp', colBkg='PbPb', combine_tpc_clusterization=False, confKey='', confKeyBkg='', e='TGeant4', eA=-1, eB=-1, eCM='5020', early_tf_cleanup=False, embeddPattern='@0:e1', embedding=True, field='ccdb', first_orbit=0, fwdmatching_assessment_full=False, fwdmatching_save_trainingdata=False, gen='pythia8', genBkg='pythia8', include_analysis=False, include_local_qc=False, include_qc=False, ini='', iniBkg='${O2DPG_ROOT}/MC/config/common/ini/basic.ini', interactionRate='50000', j=2, mft_assessment_full=False, mft_reco_full=False, mod='--skipModules ZDC', nb='4', noIPC=None, no_combine_dpl_devices=False, no_combine_smaller_digi=False, ns='4', o='workflow.json', proc='ccbar', procBkg='heavy_ion', productionTag='unknown', production_offset=0, ptHatMax=-1, ptHatMin=0, run=310000, run_anchored=False, seed='1', tf='2', timestamp=-1, trigger='', upload_bkg_to=None, use_bkg_from=None, weightPow=-1, with_ZDC=False)
** Using generic config **
Using initialisation seed: 1
Background generator seed: 513514878
Timeframe 1 seed: 513514879
Timeframe 2 seed: 513514880
=== There are 0 warnings ===
=== There are 0 errors ===
===> The workflow looks sane
Workflow saved at workflow.json
Launching task: ${O2DPG_ROOT}/MC/config/common/pythia8/utils/mkpy8cfg.py --output=pythia8bkg.cfg --seed=513514878 --idA=1000822080 --idB=1000822080 --eCM=5020.0 --eA=-1.0 --eB=-1.0 --process=heavy_ion &> genbkgconf.log &
Launching task: [ -f matbud.root ] || ${O2_ROOT}/bin/o2-ccdb-downloadccdbfile --host http://alice-ccdb.cern.ch/ -p GLO/Param/MatLUT -o matbud.root --no-preserve-path --timestamp 1550600800000 &> matbuddownloader.log &
Launching task: ${O2DPG_ROOT}/MC/config/common/pythia8/utils/mkpy8cfg.py --output=pythia8.cfg --seed=513514879 --idA=2212 --idB=2212 --eCM=5020.0 --eA=-1.0 --eB=-1.0 --process=ccbar --ptHatMin=0.0 --ptHatMax=-1.0 &> gensgnconf_1.log &
Launching task: ${O2DPG_ROOT}/MC/config/common/pythia8/utils/mkpy8cfg.py --output=pythia8.cfg --seed=513514880 --idA=2212 --idB=2212 --eCM=5020.0 --eA=-1.0 --eB=-1.0 --process=ccbar --ptHatMin=0.0 --ptHatMax=-1.0 &> gensgnconf_2.log &
Launching task: ${O2_ROOT}/bin/o2-sim -e TGeant4 -j 2 -n 4 -g pythia8 --skipModules ZDC -o bkg --configFile ${O2DPG_ROOT}/MC/config/common/ini/basic.ini --field ccdb --configKeyValues "GeneratorPythia8.config=pythia8bkg.cfg;" --timestamp 1550600800000 --run 310000 &> bkgsim.log &
Launching task: ${O2_ROOT}/bin/o2-sim -e TGeant4 --skipModules ZDC -n 4 --seed 513514879 --field ccdb -j 2 -g pythia8 --configKeyValues "GeneratorPythia8.config=pythia8.cfg;" -o sgn_1 --embedIntoFile ../bkg_MCHeader.root --timestamp 1550600800000 --run 310000 &> sgnsim_1.log &
Launching task: ln -nsf ../bkg_grp.root o2sim_grp.root; ln -nsf ../bkg_grpecs.root o2sim_grpecs.root; ln -nsf ../bkg_geometry.root o2sim_geometry.root; ln -nsf ../bkg_geometry.root bkg_geometry.root; ln -nsf ../bkg_geometry-aligned.root bkg_geometry-aligned.root; ln -nsf ../bkg_geometry-aligned.root o2sim_geometry-aligned.root; ln -nsf ../bkg_MCHeader.root bkg_MCHeader.root; ln -nsf ../bkg_grp.root bkg_grp.root; ln -nsf ../bkg_grpecs.root bkg_grpecs.root &> linkGRP_1.log &
Launching task: ${O2_ROOT}/bin/o2-sim -e TGeant4 --skipModules ZDC -n 4 --seed 513514880 --field ccdb -j 2 -g pythia8 --configKeyValues "GeneratorPythia8.config=pythia8.cfg;" -o sgn_2 --embedIntoFile ../bkg_MCHeader.root --timestamp 1550600800000 --run 310000 &> sgnsim_2.log &
Launching task: ln -nsf ../bkg_grp.root o2sim_grp.root; ln -nsf ../bkg_grpecs.root o2sim_grpecs.root; ln -nsf ../bkg_geometry.root o2sim_geometry.root; ln -nsf ../bkg_geometry.root bkg_geometry.root; ln -nsf ../bkg_geometry-aligned.root bkg_geometry-aligned.root; ln -nsf ../bkg_geometry-aligned.root o2sim_geometry-aligned.root; ln -nsf ../bkg_MCHeader.root bkg_MCHeader.root; ln -nsf ../bkg_grp.root bkg_grp.root; ln -nsf ../bkg_grpecs.root bkg_grpecs.root &> linkGRP_2.log &
Launching task: ${O2_ROOT}/bin/o2-sim-digitizer-workflow --only-context --interactionRate 50000 -b --run -n 4 --sims bkg,sgn_1 --configKeyValues "HBFUtils.orbitFirstSampled=0;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000";${O2_ROOT}/bin/o2-steer-colcontexttool -i bkg,50000,4:4 sgn_1,@0:e1 --show-context --timeframeID 0 --orbitsPerTF 256 &> digicontext_1.log &
Launching task: ${O2_ROOT}/bin/o2-sim-digitizer-workflow --only-context --interactionRate 50000 -b --run -n 4 --sims bkg,sgn_2 --configKeyValues "HBFUtils.orbitFirstSampled=256;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000";${O2_ROOT}/bin/o2-steer-colcontexttool -i bkg,50000,4:4 sgn_2,@0:e1 --show-context --timeframeID 1 --orbitsPerTF 256 &> digicontext_2.log &
Launching task: ln -nfs ../bkg_Hits*.root . ;${O2_ROOT}/bin/o2-sim-digitizer-workflow -b --run -n 4 --sims bkg,sgn_1 --interactionRate 50000 --incontext collisioncontext.root --disable-write-ini --configKeyValues "HBFUtils.orbitFirstSampled=0;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" --onlyDet ITS,TOF,FDD,MCH,MID,MFT,HMP,EMC,PHS,CPV --ccdb-tof-sa --combine-devices &> restdigi_1.log &
Launching task: ln -nfs ../bkg_HitsFT0.root . ; ln -nfs ../bkg_HitsFV0.root . ;${O2_ROOT}/bin/o2-sim-digitizer-workflow -b --run -n 4 --sims bkg,sgn_1 --onlyDet FT0,FV0,CTP --interactionRate 50000 --incontext collisioncontext.root --disable-write-ini --configKeyValues "HBFUtils.orbitFirstSampled=0;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" --combine-devices &> ft0fv0ctp_digi_1.log &
Launching task: ${O2_ROOT}/bin/o2-its-reco-workflow --trackerCA --tracking-mode async -b --run --configKeyValues "HBFUtils.orbitFirstSampled=0;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000;NameConf.mDirMatLUT=.." &> itsreco_1.log &
Launching task: ${O2_ROOT}/bin/o2-mft-reco-workflow -b --run --configKeyValues "HBFUtils.orbitFirstSampled=0;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> mftreco_1.log &
Launching task: ln -nfs ../bkg_Kine.root . ;${O2_ROOT}/bin/o2-mch-reco-workflow -b --run --configKeyValues "HBFUtils.orbitFirstSampled=0;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> mchreco_1.log &
Launching task: ${O2_ROOT}/bin/o2-mid-digits-reader-workflow | ${O2_ROOT}/bin/o2-mid-reco-workflow -b --run --configKeyValues "HBFUtils.orbitFirstSampled=0;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> midreco_1.log &
Launching task: ${O2_ROOT}/bin/o2-fdd-reco-workflow -b --run --configKeyValues "HBFUtils.orbitFirstSampled=0;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> fddreco_1.log &
Launching task: ${O2_ROOT}/bin/o2-emcal-reco-workflow --input-type digits --output-type cells --infile emcaldigits.root -b --run --configKeyValues "HBFUtils.orbitFirstSampled=0;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> emcalreco_1.log &
Launching task: ${O2_ROOT}/bin/o2-phos-reco-workflow -b --run --configKeyValues "HBFUtils.orbitFirstSampled=0;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> phsreco_1.log &
Launching task: ${O2_ROOT}/bin/o2-cpv-reco-workflow -b --run --configKeyValues "HBFUtils.orbitFirstSampled=0;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> cpvreco_1.log &
Launching task: ${O2_ROOT}/bin/o2-ft0-reco-workflow -b --run --configKeyValues "HBFUtils.orbitFirstSampled=0;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> ft0reco_1.log &
Launching task: ${O2_ROOT}/bin/o2-fv0-reco-workflow -b --run --configKeyValues "HBFUtils.orbitFirstSampled=0;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> fv0reco_1.log &
Launching task: ${O2_ROOT}/bin/o2-muon-tracks-matcher-workflow -b --run &> mchmidMatch_1.log &
Launching task: ${O2_ROOT}/bin/o2-globalfwd-matcher-workflow --configKeyValues "HBFUtils.orbitFirstSampled=0;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000;FwdMatching.useMIDMatch=true" -b --run &> mftmchMatch_1.log &
Launching task: ln -nfs ../bkg_Hits*.root . ;${O2_ROOT}/bin/o2-sim-digitizer-workflow -b --run -n 4 --sims bkg,sgn_2 --interactionRate 50000 --incontext collisioncontext.root --disable-write-ini --configKeyValues "HBFUtils.orbitFirstSampled=256;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" --onlyDet ITS,TOF,FDD,MCH,MID,MFT,HMP,EMC,PHS,CPV --ccdb-tof-sa --combine-devices &> restdigi_2.log &
Launching task: ln -nfs ../bkg_HitsFT0.root . ; ln -nfs ../bkg_HitsFV0.root . ;${O2_ROOT}/bin/o2-sim-digitizer-workflow -b --run -n 4 --sims bkg,sgn_2 --onlyDet FT0,FV0,CTP --interactionRate 50000 --incontext collisioncontext.root --disable-write-ini --configKeyValues "HBFUtils.orbitFirstSampled=256;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" --combine-devices &> ft0fv0ctp_digi_2.log &
Launching task: ${O2_ROOT}/bin/o2-its-reco-workflow --trackerCA --tracking-mode async -b --run --configKeyValues "HBFUtils.orbitFirstSampled=256;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000;NameConf.mDirMatLUT=.." &> itsreco_2.log &
Launching task: ${O2_ROOT}/bin/o2-mft-reco-workflow -b --run --configKeyValues "HBFUtils.orbitFirstSampled=256;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> mftreco_2.log &
Launching task: ln -nfs ../bkg_Kine.root . ;${O2_ROOT}/bin/o2-mch-reco-workflow -b --run --configKeyValues "HBFUtils.orbitFirstSampled=256;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> mchreco_2.log &
Launching task: ${O2_ROOT}/bin/o2-mid-digits-reader-workflow | ${O2_ROOT}/bin/o2-mid-reco-workflow -b --run --configKeyValues "HBFUtils.orbitFirstSampled=256;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> midreco_2.log &
Launching task: ${O2_ROOT}/bin/o2-fdd-reco-workflow -b --run --configKeyValues "HBFUtils.orbitFirstSampled=256;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> fddreco_2.log &
Launching task: ${O2_ROOT}/bin/o2-emcal-reco-workflow --input-type digits --output-type cells --infile emcaldigits.root -b --run --configKeyValues "HBFUtils.orbitFirstSampled=256;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> emcalreco_2.log &
Launching task: ${O2_ROOT}/bin/o2-phos-reco-workflow -b --run --configKeyValues "HBFUtils.orbitFirstSampled=256;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> phsreco_2.log &
Launching task: ${O2_ROOT}/bin/o2-cpv-reco-workflow -b --run --configKeyValues "HBFUtils.orbitFirstSampled=256;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> cpvreco_2.log &
Launching task: ${O2_ROOT}/bin/o2-ft0-reco-workflow -b --run --configKeyValues "HBFUtils.orbitFirstSampled=256;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> ft0reco_2.log &
Launching task: ${O2_ROOT}/bin/o2-fv0-reco-workflow -b --run --configKeyValues "HBFUtils.orbitFirstSampled=256;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000" &> fv0reco_2.log &
Launching task: ${O2_ROOT}/bin/o2-muon-tracks-matcher-workflow -b --run &> mchmidMatch_2.log &
Launching task: ${O2_ROOT}/bin/o2-globalfwd-matcher-workflow --configKeyValues "HBFUtils.orbitFirstSampled=256;HBFUtils.nHBFPerTF=256;HBFUtils.orbitFirst=0;HBFUtils.runNumber=310000;HBFUtils.startTime=1550600800000;FwdMatching.useMIDMatch=true" -b --run &> mftmchMatch_2.log &
Stop on failure True
**** Pipeline done success (global_runtime : 1296.602s) *****
sim time 1232s; sim active fraction ~0.692958%
digi time 202s; digi active fraction ~0.112676%
reco time 347s; reco active fraction ~0.194366%
aod time 0s; aod active fraction ~0%
Running: TIME="#walltime %e\n#systime %S\n#usertime %U" /usr/bin/time --output=digicontext_1.log_time ./digicontext_1.log_tmp.sh
Run: 310000
Fill: 0
Period: , isMC:0
LHC State:
Start: Thu Aug 2 14:26:40 51106
End : Thu Sep 13 06:26:40 51106
1st orbit: 0, 256 orbits per TF
Beam0: Z:A = 0: 0, Energy = 0.000
Beam1: Z:A = 0: 0, Energy = 0.000
sqrt[s] = 0.000
crossing angle (radian) = 0.000000e+00
magnet currents (A) L3 = 12000.000, Dipole = 6000
Detectors: Cont.RO Triggers
ITS: - -
TPC: - -
TRD: - -
TOF: - -
PHS: - -
CPV: - -
EMC: - -
HMP: - -
MFT: - -
MCH: - -
MID: - -
FT0: - -
FV0: - -
FDD: - -
TST: - -
CTP: - -
[INFO] Publishing master key O2SIMDIGIINTERNAL_849_GRPTIMESTART
[INFO] MC-TRUTH 1
[INFO] Initialising O2 Data Processing Layer. Driver PID: 849.
[INFO] Rate limiting set up at 500MB distributed over 1 readers
[INFO] O2 Data Processing Layer initialised. We brake for nobody.
[INFO] Optimised build. O2DEBUG / LOG(debug) / LOGF(debug) / assert statement will not be shown.
[INFO] Redeployment of configuration asked.
[INFO] Starting internal-dpl-clock on pid 940
[INFO] Starting SimReader on pid 942
[INFO] Starting internal-dpl-injected-dummy-sink on pid 944
[INFO] Redeployment of configuration done.
[942:SimReader]: [INFO] Init CcdApi with UserAgentID: 279e322adafb-1655124024-Al0bJ8, Host: http://alice-ccdb.cern.ch/(cache snapshots to dir=/results/alice-gen-sim-reco-run3-c1-e2-1655122994_1825/proc_1/.ccdb, prefer if available)
[942:SimReader]: [INFO] MC-TRUTH 1
[942:SimReader]: [INFO] Instrumenting crash signals
[942:SimReader]: [INFO] Spawing new device SimReader in process with pid 942
[944:internal-dpl-injected-dummy-sink]: [INFO] MC-TRUTH 1
[944:internal-dpl-injected-dummy-sink]: [INFO] Instrumenting crash signals
[942:SimReader]: [14:40:24][INFO]
[942:SimReader]: ______ _ _______ _________
[942:SimReader]: / ____/___ _(_)_______ |/ /_ __ \ version 1.4.51
[942:SimReader]: / /_ / __ `/ / ___/__ /|_/ /_ / / / build RELWITHDEBINFO
[942:SimReader]: / __/ / /_/ / / / _ / / / / /_/ / https://github.com/FairRootGroup/FairMQ
[942:SimReader]: /_/ \__,_/_/_/ /_/ /_/ \___\_\ LGPL-3.0 © 2012-2022 GSI
[942:SimReader]:
[942:SimReader]: [14:40:24][STATE] Starting FairMQ state machine --> IDLE
[944:internal-dpl-injected-dummy-sink]: [INFO] Spawing new device internal-dpl-injected-dummy-sink in process with pid 944
[944:internal-dpl-injected-dummy-sink]: [14:40:24][INFO]
[944:internal-dpl-injected-dummy-sink]: ______ _ _______ _________
[944:internal-dpl-injected-dummy-sink]: / ____/___ _(_)_______ |/ /_ __ \ version 1.4.51
[944:internal-dpl-injected-dummy-sink]: / /_ / __ `/ / ___/__ /|_/ /_ / / / build RELWITHDEBINFO
[944:internal-dpl-injected-dummy-sink]: / __/ / /_/ / / / _ / / / / /_/ / https://github.com/FairRootGroup/FairMQ
[944:internal-dpl-injected-dummy-sink]: /_/ \__,_/_/_/ /_/ /_/ \___\_\ LGPL-3.0 © 2012-2022 GSI
[944:internal-dpl-injected-dummy-sink]:
[944:internal-dpl-injected-dummy-sink]: [14:40:24][STATE] Starting FairMQ state machine --> IDLE
[942:SimReader]: [14:40:24][WARN] Unable to communicate with driver because client does not exist. Continuing connection attempts.
[942:SimReader]: [14:40:24][STATE] IDLE ---> INITIALIZING DEVICE
[944:internal-dpl-injected-dummy-sink]: [14:40:24][WARN] Unable to communicate with driver because client does not exist. Continuing connection attempts.
[942:SimReader]: [14:40:24][INFO] adding bkg
[942:SimReader]:
[942:SimReader]: [14:40:24][INFO] INCONTEXTSTRING
[942:SimReader]: [14:40:24][INFO] Imposing hadronic interaction rate 50000Hz
[942:SimReader]: HBFUtils.nHBFPerTF : 256 [ RT ]
[942:SimReader]: HBFUtils.obligatorySOR : false [ CODE ]
[942:SimReader]: HBFUtils.orbitFirst : 0 [ RT ]
[942:SimReader]: HBFUtils.runNumber : 310000 [ RT ]
[942:SimReader]: HBFUtils.orbitFirstSampled : 0 [ RT ]
[942:SimReader]: HBFUtils.maxNOrbits : 4294967295 [ CODE ]
[942:SimReader]: HBFUtils.startTime : 1550600800000 [ RT ]
[942:SimReader]: [14:40:24][WARN] No bunch filling provided, impose default one
[942:SimReader]: [14:40:24][INFO] Deducing mu=0.00771915 per BC from IR=50000 with 576 BCs
[942:SimReader]: [14:40:24][INFO] InteractionSampler with 576 colliding BCs, mu(BC)= 0.00771915 -> total IR= 50000
[942:SimReader]: [14:40:24][INFO] Current BCid: 4 Orbit: 0 |T in BC(ns): 0.000(0 coll left)
[942:SimReader]: [14:40:24][INFO] setting up 2 chains
[944:internal-dpl-injected-dummy-sink]: [14:40:24][STATE] IDLE ---> INITIALIZING DEVICE
[944:internal-dpl-injected-dummy-sink]: [14:40:24][STATE] INITIALIZING DEVICE ---> INITIALIZED
[944:internal-dpl-injected-dummy-sink]: [14:40:24][STATE] INITIALIZED ---> BINDING
[944:internal-dpl-injected-dummy-sink]: [14:40:24][STATE] BINDING ---> BOUND
[944:internal-dpl-injected-dummy-sink]: [14:40:24][STATE] BOUND ---> CONNECTING
[944:internal-dpl-injected-dummy-sink]: [14:40:24][STATE] CONNECTING ---> DEVICE READY
[944:internal-dpl-injected-dummy-sink]: [14:40:24][STATE] DEVICE READY ---> INITIALIZING TASK
[944:internal-dpl-injected-dummy-sink]: [14:40:24][STATE] INITIALIZING TASK ---> READY
[944:internal-dpl-injected-dummy-sink]: [14:40:24][STATE] READY ---> RUNNING
[944:internal-dpl-injected-dummy-sink]: [14:40:24][INFO] fair::mq::Device running...
[944:internal-dpl-injected-dummy-sink]: [14:40:24][WARN] LHCPeriod is not available, using current month JUN
[940:internal-dpl-clock]: [INFO] MC-TRUTH 1
[944:internal-dpl-injected-dummy-sink]: [14:40:24][WARN] Unable to communicate with driver because client is not connected. Continuing connection attempts.
[944:internal-dpl-injected-dummy-sink]: [14:40:24][INFO] Correctly handshaken websocket connection.
[944:internal-dpl-injected-dummy-sink]: [14:40:24][WARN] DriverClient connected successfully. Flushing message backlog of 8616 messages. All is good.
[940:internal-dpl-clock]: [INFO] Instrumenting crash signals
[940:internal-dpl-clock]: [INFO] Spawing new device internal-dpl-clock in process with pid 940
[940:internal-dpl-clock]: [14:40:24][INFO]
[940:internal-dpl-clock]: ______ _ _______ _________
[940:internal-dpl-clock]: / ____/___ _(_)_______ |/ /_ __ \ version 1.4.51
[940:internal-dpl-clock]: / /_ / __ `/ / ___/__ /|_/ /_ / / / build RELWITHDEBINFO
[940:internal-dpl-clock]: / __/ / /_/ / / / _ / / / / /_/ / https://github.com/FairRootGroup/FairMQ
[940:internal-dpl-clock]: /_/ \__,_/_/_/ /_/ /_/ \___\_\ LGPL-3.0 © 2012-2022 GSI
[940:internal-dpl-clock]:
[940:internal-dpl-clock]: [14:40:24][STATE] Starting FairMQ state machine --> IDLE
[940:internal-dpl-clock]: [14:40:24][WARN] Unable to communicate with driver because client does not exist. Continuing connection attempts.
[940:internal-dpl-clock]: [14:40:24][STATE] IDLE ---> INITIALIZING DEVICE
[940:internal-dpl-clock]: [14:40:24][STATE] INITIALIZING DEVICE ---> INITIALIZED
[940:internal-dpl-clock]: [14:40:24][STATE] INITIALIZED ---> BINDING
[940:internal-dpl-clock]: [14:40:24][STATE] BINDING ---> BOUND
[940:internal-dpl-clock]: [14:40:24][STATE] BOUND ---> CONNECTING
[940:internal-dpl-clock]: [14:40:24][STATE] CONNECTING ---> DEVICE READY
[940:internal-dpl-clock]: [14:40:24][STATE] DEVICE READY ---> INITIALIZING TASK
[940:internal-dpl-clock]: [14:40:24][STATE] INITIALIZING TASK ---> READY
[940:internal-dpl-clock]: [14:40:24][STATE] READY ---> RUNNING
[940:internal-dpl-clock]: [14:40:24][INFO] fair::mq::Device running...
[940:internal-dpl-clock]: [14:40:24][WARN] LHCPeriod is not available, using current month JUN
[940:internal-dpl-clock]: [14:40:24][WARN] Unable to communicate with driver because client is not connected. Continuing connection attempts.
[940:internal-dpl-clock]: [14:40:24][INFO] Correctly handshaken websocket connection.
[940:internal-dpl-clock]: [14:40:24][WARN] DriverClient connected successfully. Flushing message backlog of 28713 messages. All is good.
[942:SimReader]: Summary of DigitizationContext --
[942:SimReader]: Maximal parts per collision 2
[942:SimReader]: Collision parts taken from simulations specified by prefix:
[942:SimReader]: Number of Collisions 4
[942:SimReader]: Collision 0 TIME BCid: 1166 Orbit: 0 |T in BC(ns): -0.055 (0 , 0) (1 , 0)
[942:SimReader]: Collision 1 TIME BCid: 2172 Orbit: 0 |T in BC(ns): -0.036 (0 , 1) (1 , 1)
[942:SimReader]: Collision 2 TIME BCid: 582 Orbit: 1 |T in BC(ns): 0.185 (0 , 2) (1 , 2)
[942:SimReader]: Collision 3 TIME BCid: 654 Orbit: 1 |T in BC(ns): 0.026 (0 , 3) (1 , 3)
[942:SimReader]: [14:40:26][INFO] Initializing Spec ... have 4 times
[942:SimReader]: [14:40:26][INFO] Serializing Context for later reuse
[942:SimReader]: [14:40:26][STATE] INITIALIZING DEVICE ---> INITIALIZED
[942:SimReader]: [14:40:26][STATE] INITIALIZED ---> BINDING
[942:SimReader]: [14:40:26][STATE] BINDING ---> BOUND
[942:SimReader]: [14:40:26][STATE] BOUND ---> CONNECTING
[942:SimReader]: [14:40:26][STATE] CONNECTING ---> DEVICE READY
[942:SimReader]: [14:40:26][STATE] DEVICE READY ---> INITIALIZING TASK
[942:SimReader]: [14:40:26][STATE] INITIALIZING TASK ---> READY
[942:SimReader]: [14:40:26][STATE] READY ---> RUNNING
[942:SimReader]: [14:40:26][INFO] fair::mq::Device running...
[942:SimReader]: [14:40:26][WARN] LHCPeriod is not available, using current month JUN
[942:SimReader]: [14:40:26][INFO] Setting firstTFOrbit to 0
[942:SimReader]: [14:40:26][INFO] Setting runNumber to 310000
[942:SimReader]: [14:40:26][INFO] Setting timeframe creation time to 1550600800000
[942:SimReader]: [14:40:26][WARN] Unable to communicate with driver because client is not connected. Continuing connection attempts.
[942:SimReader]: [14:40:26][INFO] Sending end-of-stream message to channel from_SimReader_to_internal-dpl-injected-dummy-sink
[942:SimReader]: [14:40:26][INFO] Correctly handshaken websocket connection.
[942:SimReader]: [14:40:26][WARN] DriverClient connected successfully. Flushing message backlog of 8638 messages. All is good.
[INFO] Quitting
[INFO] QUIT_REQUESTED
[942:SimReader]: [14:40:26][INFO] Received device shutdown request (signal 15).
[942:SimReader]: [14:40:26][INFO] Waiting for graceful device shutdown. Hit Ctrl-C again to abort immediately.
[942:SimReader]: [14:40:26][INFO] New state requested. No timeout set, quitting immediately as per --completion-policy
[942:SimReader]: [14:40:26][STATE] RUNNING ---> READY
[942:SimReader]: [14:40:26][STATE] READY ---> RESETTING TASK
[942:SimReader]: [14:40:26][STATE] RESETTING TASK ---> DEVICE READY
[942:SimReader]: [14:40:26][STATE] DEVICE READY ---> RESETTING DEVICE
[942:SimReader]: [14:40:26][STATE] RESETTING DEVICE ---> IDLE
[942:SimReader]: [14:40:26][STATE] IDLE ---> EXITING
[942:SimReader]: [14:40:26][STATE] Exiting FairMQ state machine
[944:internal-dpl-injected-dummy-sink]: [14:40:26][INFO] Received device shutdown request (signal 15).
[944:internal-dpl-injected-dummy-sink]: [14:40:26][INFO] Waiting for graceful device shutdown. Hit Ctrl-C again to abort immediately.
[944:internal-dpl-injected-dummy-sink]: [14:40:26][INFO] New state requested. No timeout set, quitting immediately as per --completion-policy
[944:internal-dpl-injected-dummy-sink]: [14:40:26][STATE] RUNNING ---> READY
[944:internal-dpl-injected-dummy-sink]: [14:40:26][STATE] READY ---> RESETTING TASK
[944:internal-dpl-injected-dummy-sink]: [14:40:26][STATE] RESETTING TASK ---> DEVICE READY
[944:internal-dpl-injected-dummy-sink]: [14:40:26][STATE] No transition from state DEVICE_READY on transition AUTO
[944:internal-dpl-injected-dummy-sink]: [14:40:26][STATE] DEVICE READY ---> RESETTING DEVICE
[944:internal-dpl-injected-dummy-sink]: [14:40:26][STATE] RESETTING DEVICE ---> IDLE
[944:internal-dpl-injected-dummy-sink]: [14:40:26][STATE] IDLE ---> EXITING
[944:internal-dpl-injected-dummy-sink]: [14:40:26][STATE] Exiting FairMQ state machine
[940:internal-dpl-clock]: [14:40:26][INFO] Received device shutdown request (signal 15).
[940:internal-dpl-clock]: [14:40:26][INFO] Waiting for graceful device shutdown. Hit Ctrl-C again to abort immediately.
[940:internal-dpl-clock]: [14:40:26][INFO] New state requested. No timeout set, quitting immediately as per --completion-policy
[940:internal-dpl-clock]: [14:40:26][STATE] RUNNING ---> READY