Open belforte opened 7 years ago
e.g. see this https://hypernews.cern.ch/HyperNews/CMS/get/computing-tools/2389/1/3.html cmscp stars with remote (direct) stageout. If fails. But exit code 60311 is assigned. And should not. Then cmscp tries local (via ASO) stageout, which succeed, but the final exit code 0 is not sent to dashboard. No good :-( Since stdout does not stay forever on schedd, I will copy/pate relevant part in next comment.
trimmed stdout from the job reported about in previous comment
======== gWMS-CMSRunAnalysis.sh STARTING at Wed Dec 7 06:01:34 GMT 2016 on wn161.lcg.cscs.ch ========
Local time : Wed Dec 7 07:01:34 CET 2016
Current system : Linux wn161.lcg.cscs.ch 2.6.32-642.6.2.el6.x86_64 #1 SMP Tue Oct 25 15:06:33 CDT 2016 x86_64 x86_64 x86_64 GNU/Linux
Arguments are -a sandbox.tar.gz --sourceURL=https://cmsweb.cern.ch/crabcache --jobNumber=1 --cmsswVersion=CMSSW_8_0_20 --scramArch=slc6_amd64_gcc530 --inputFile=job_input_file_list_1.txt --runAndLumis=job_lumis_1.json --lheInputFiles=False --firstEvent=None --firstLumi=None --lastEvent=None --firstRun=None --seeding=AutomaticSeeding --scriptExe=None --eventsPerLumi=None --maxRuntime=-1 --scriptArgs=[] -o {}
SCRAM_ARCH=slc6_amd64_gcc530
======== HTCONDOR JOB SUMMARY at Wed Dec 7 06:01:34 GMT 2016 START ========
CRAB ID: 1
Execution site: T2_CH_CSCS
Current hostname: wn161.lcg.cscs.ch
Output files: RUNFullAnalysis_TTv02.root=RUNFullAnalysis_TTv02_1.root
==== HTCONDOR JOB AD CONTENTS START ====
==== CMSRunAnalysis.py STARTING at Wed Dec 7 06:01:35 2016 ====
Local time : Wed Dec 7 07:01:35 2016
Dashboard early startup params: {'MonitorID': '161206_175417:algomez_crab_TTv02', 'MonitorJobID': '1_https://glidein.cern.ch/1/161206:175417:algomez:crab:TTv02_0', 'SyncCE': 'arc03.lcg.cscs.ch', 'OverflowFlag': 0, 'SyncSite': 'T2_CH_CSCS', 'SyncGridJobId': 'https://glidein.cern.ch/1/161206:175417:algomez:crab:TTv02', 'WNHostName': 'wn161.lcg.cscs.ch'}
==== Parameters Dump at Wed Dec 7 06:01:35 2016 ===
archiveJob: sandbox.tar.gz
runDir: /scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669
sourceURL: https://cmsweb.cern.ch/crabcache
jobNumber: 1
cmsswVersion: CMSSW_8_0_20
scramArch: slc6_amd64_gcc530
inputFile job_input_file_list_1.txt
outFiles: {}
runAndLumis: job_lumis_1.json
lheInputFiles: False
firstEvent: None
firstLumi: None
eventsPerLumi: None
lastEvent: None
firstRun: None
seeding: AutomaticSeeding
userFiles: None
oneEventMode: 0
scriptExe: None
scriptArgs: []
maxRuntime: -1
===================
==== Sandbox preparation STARTING at Wed Dec 7 06:01:35 2016 ====
Sandbox sandbox.tar.gz already exists, skipping
==== Sandbox preparation FINISHING at Wed Dec 7 06:01:37 2016 ====
==== WMCore filesystem preparation STARTING at Wed Dec 7 06:01:37 2016 ====
==== WMCore filesystem preparation FINISHING at Wed Dec 7 06:01:37 2016 ====
Dashboard startup parameters: {'MonitorID': '161206_175417:algomez_crab_TTv02', 'MonitorJobID': '1_https://glidein.cern.ch/1/161206:175417:algomez:crab:TTv02_0', 'WNHostName': 'wn161.lcg.cscs.ch', 'ExeStart': 'cmsRun'}
==== CMSSW Stack Execution STARTING at Wed Dec 7 06:01:37 2016 ====
==== SCRAM Obj CREATED at Wed Dec 7 06:01:37 2016 ====
==== CMSSW JOB Execution started at Wed Dec 7 06:01:41 2016 ====
2016-12-07 06:01:41,841:INFO:Scram: Invoking command: python -c 'from PSetTweaks.WMTweak import makeTweak;config = __import__("WMTaskSpace.cmsRun.PSet", globals(), locals(), ["process"], -1);tweakJson = makeTweak(config.process).jsondictionary();print tweakJson["process"]["outputModules_"]'
2016-12-07 06:01:42,376:INFO:CMSSW:User files are
2016-12-07 06:01:42,377:INFO:CMSSW:User sandboxes are sandbox.tar.gz
2016-12-07 06:01:42,377:INFO:CMSSW:CMSSW configured for 1 cores
2016-12-07 06:01:42,377:INFO:CMSSW:Executing CMSSW step
2016-12-07 06:01:42,378:INFO:CMSSW:Runing SCRAM
2016-12-07 06:01:43,030:INFO:CMSSW:Running PRE scripts
2016-12-07 06:01:43,031:INFO:CMSSW:RUNNING SCRAM SCRIPTS
2016-12-07 06:01:43,054:INFO:Scram: Invoking command: python /scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/TweakPSet.py --location=/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669 --inputFile='job_input_file_list_1.txt' --runAndLumis='job_lumis_1.json' --firstEvent=None --lastEvent=None --firstLumi=None --firstRun=None --seeding=AutomaticSeeding --lheInputFiles=False --oneEventMode=0 --eventsPerLumi=None --maxRuntime=-1
2016-12-07 06:01:46,444:INFO:CMSSW:Executing CMSSW. args: ['/bin/bash', '/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/cmsRun-main.sh', '', 'slc6_amd64_gcc530', 'scramv1', 'CMSSW', 'CMSSW_8_0_20', 'FrameworkJobReport.xml', 'cmsRun', 'PSet.py', 'sandbox.tar.gz', '', '']
Job exit code: 0
==== CMSSW Stack Execution FINISHING at Wed Dec 7 06:19:05 2016 ====
======== CMSSW OUTPUT STARTING ========
NOTICE: lines longer than 3000 characters will be truncated
== CMSSW: Beginning CMSSW wrapper script
== CMSSW: slc6_amd64_gcc530 scramv1 CMSSW
== CMSSW: Performing SCRAM setup...
== CMSSW: Completed SCRAM setup
== CMSSW: Retrieving SCRAM project...
== CMSSW: Untarring /scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/sandbox.tar.gz
== CMSSW: Completed SCRAM project
== CMSSW: Executing CMSSW
== CMSSW: cmsRun -j FrameworkJobReport.xml PSet.py
== CMSSW: 07-Dec-2016 07:01:53 CET Initiating request to open file dcap://storage01.lcg.cscs.ch/pnfs/lcg.cscs.ch/cms/trivcat/store/user/grauco/B2GAnaFW/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/B2GAnaFW_80X_V2p1/161021_085128/0001/B2GEDMNtuple_1044.root
== CMSSW: 07-Dec-2016 07:01:56 CET Successfully opened file dcap://storage01.lcg.cscs.ch/pnfs/lcg.cscs.ch/cms/trivcat/store/user/grauco/B2GAnaFW/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/B2GAnaFW_80X_V2p1/161021_085128/0001/B2GEDMNtuple_1044.root
== CMSSW: Lumi/Pileup Reweighting: Computed Weights per In-Time Nint
== CMSSW: 0 0.00850606
== CMSSW: process id is 157058 status is 0
======== CMSSW OUTPUT FINSHING ========
==== Report file creation STARTING at Wed Dec 7 06:19:05 2016 ====
==== Checksum STARTING at Wed Dec 7 06:19:05 2016 ====
== Filename: /scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/RUNFullAnalysis_TTv02.root
==== Checksum FINISHING at Wed Dec 7 06:19:05 2016 ====
== Execution site from site-local-config.xml: T2_CH_CSCS
Dashboard end parameters: {'MonitorID': '161206_175417:algomez_crab_TTv02', 'CRABUserReadMB': 146.88831599999997, 'MonitorJobID': '1_https://glidein.cern.ch/1/161206:175417:algomez:crab:TTv02_0', 'CrabCpuPercentage': 0.9853951219512195, 'CRABUserWriteMB': 0.000779152, 'CrabUserCpuTime': 1010.03, 'NEventsProcessed': 20000, 'ExeTime': 1025, 'JobExitCode': 0, 'CRABUserPeakRss': 371.426, 'ExeExitCode': 0}
Dashboard popularity report: {'Basename': '/store/user/grauco/B2GAnaFW/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/B2GAnaFW_80X_V2p1/161021_085128/0001', 'inputFiles': '/B2GEDMNtuple_1044.root::1::EDM::Local::1', 'BasenameParent': '', 'inputBlocks': '/TT_TuneCUETP8M1_13TeV-powheg-pythia8/grauco-B2GAnaFW_80X_V2p1-edbed0685401a5848e7d61871b3a63d8/USER#9f390ad8-6573-4ae7-8771-554fc86dd7bf', 'parentFiles': ''}
==== Report file creation FINISHING at Wed Dec 7 06:19:06 2016 ====
==== CMSRunAnalysis.py FINISHING at Wed Dec 7 06:19:06 2016 ====
Local time : Wed Dec 7 07:19:06 2016
+ jobrc=0
+ set +x
== The job had an exit code of 0
======== CMSRunAnalysis.py FINISHING at Wed Dec 7 06:19:06 GMT 2016 ========
==== SCRAM interaction log contents dump STARTING ====
Log for recording SCRAM command-line output
-------------------------------------------
Beginning TweakPSet
arguments: ['/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/TweakPSet.py', '--location=/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669', '--inputFile=job_input_file_list_1.txt', '--runAndLumis=job_lumis_1.json', '--firstEvent=None', '--lastEvent=None', '--firstLumi=None', '--firstRun=None', '--seeding=AutomaticSeeding', '--lheInputFiles=False', '--oneEventMode=0', '--eventsPerLumi=None', '--maxRuntime=-1']
One event mode disabled until we can put together a decent version of WMCore.
TweakPSet.py is going to force one event mode
Tag chirp updates from CMSSW with _cmsRun_
No value for numberOfCores. Not setting
==== SCRAM interaction log contents dump FINISHING ====
real 17m31.167s
user 16m56.930s
sys 0m13.303s
CMSRunAnalysis.sh complete at Wed Dec 7 06:19:06 GMT 2016 with (short) exit status 0
======== CMSRunAnalsysis.sh at Wed Dec 7 06:19:06 GMT 2016 FINISHING ========
======== python2.6 bootstrap for stageout at Wed Dec 7 06:19:06 GMT 2016 STARTING ========
+ '[' -f /cvmfs/cms.cern.ch/cmsset_default.sh ']'
+ set +x
+ '[' -e /cvmfs/cms.cern.ch/COMP/slc6_amd64_gcc493/external/python/2.7.6/etc/profile.d/init.sh ']'
+ set +x
+ command -v python2.7
+ rc=0
+ set +x
Found python2.7 at:
/cvmfs/cms.cern.ch/COMP/slc6_amd64_gcc493/external/python/2.7.6/bin/python2.7
======== python2.7 bootstrap for stageout at Wed Dec 7 06:19:06 GMT 2016 FINISHING ========
======== Attempting to notify HTCondor of file stageout ========
Error: 22 (Invalid argument)
======== Stageout at Wed Dec 7 06:19:06 GMT 2016 STARTING ========
====== Wed Dec 7 06:19:06 2016: cmscp.py STARTING.
The user has not specified to transfer the log files. No log files stageout (nor log files metadata upload) will be performed.
Stageout policy: remote, local
====== Wed Dec 7 06:19:06 2016: Starting job report validation.
Job report seems ok (it has the expected structure).
Retrieved payload exit code ('jobExitCode') = 0 from job report.
Retrieved job wrapper exit code ('exitCode') = 0 from job report.
====== Wed Dec 7 06:19:06 2016: Finished job report validation (status 0).
====== Wed Dec 7 06:19:06 2016: Starting to check if user output files exist.
Output file RUNFullAnalysis_TTv02.root exists.
====== Wed Dec 7 06:19:06 2016: Finished to check if user output files exist (status 0).
====== Wed Dec 7 06:19:06 2016: Starting to check if user output files are in job report.
Output file RUNFullAnalysis_TTv02.root found in job report.
====== Wed Dec 7 06:19:06 2016: Finished to check if user output files are in job report (status 0).
====== Wed Dec 7 06:19:06 2016: Starting initialization of stageout manager for local stageouts.
-----> Stageout manager log start
StageOutMgr::__init__()
==== Stageout configuration start ====
Local Stage Out Implementation to be used is: gfal2
Local Stage Out PNN to be used is T2_CH_CSCS
Local Stage Out Catalog to be used is trivialcatalog_file:/cvmfs/cms.cern.ch/SITECONF/local/PhEDEx/storage.xml?protocol=srmv2
Trivial File Catalog has been loaded:
lfn-to-pfn: protocol=direct path-match-re=/+store/PhEDEx_LoadTest07/LoadTest07_[^/]+_CSCS/[^/]+/[^/]+/(.*)_.*_.* result=/pnfs/lcg.cscs.ch/cms/trivcat/store/phedex_monarctest/monarctest_CSCS-DISK1/$1
lfn-to-pfn: protocol=direct path-match-re=/+(.*) result=/pnfs/lcg.cscs.ch/cms/trivcat/$1
lfn-to-pfn: protocol=direct path-match-re=/+(.*) result=/pnfs/lcg.cscs.ch/cms/trivcat/$1
lfn-to-pfn: protocol=dcap path-match-re=/+(.*) result=dcap://storage01.lcg.cscs.ch/$1 chain=direct
lfn-to-pfn: protocol=srm path-match-re=/+(.*) result=srm://storage01.lcg.cscs.ch:8443/srm/managerv1?SFN=/$1 chain=direct
lfn-to-pfn: protocol=srmv2 path-match-re=/+(.*) result=srm://storage01.lcg.cscs.ch:8443/srm/managerv2?SFN=/$1 chain=direct
lfn-to-pfn: protocol=xrootd path-match-re=/+store/(.*) result=root://xrootd-cms.infn.it//store/$1
pfn-to-lfn: protocol=direct path-match-re=/pnfs/lcg.cscs.ch/cms/trivcat/(.*) result=/$1
pfn-to-lfn: protocol=dcap path-match-re=dcap://storage01.lcg.cscs.ch(.*) result=$1 chain=direct
pfn-to-lfn: protocol=srm path-match-re=srm://storage01.lcg.cscs.ch:8443/srm/managerv1\?SFN=/pnfs/lcg.cscs.ch/cms/trivcat/(.*) result=/$1
pfn-to-lfn: protocol=srmv2 path-match-re=srm://storage01.lcg.cscs.ch:8443/srm/managerv2\?SFN=/pnfs/lcg.cscs.ch/cms/trivcat/(.*) result=/$1
There are 1 fallback stage out definitions.
Fallback to : T2_DE_DESY using: gfal2
==== Stageout configuration finish ====
<----- Stageout manager log finish
Initialization was ok.
====== Wed Dec 7 06:19:06 2016: Finished initialization of stageout manager for local stageouts (status 0).
Will use gfal2 commands for direct stageout.
====== Wed Dec 7 06:19:06 2016: Starting initialization of stageout implementation for direct stageouts.
Initialization was ok.
====== Wed Dec 7 06:19:06 2016: Finished initialization of stageout implementation for direct stageouts (status 0).
====== Wed Dec 7 06:19:06 2016: Starting remote stageout of user output files.
-----> Wed Dec 7 06:19:06 2016: Starting remote stageout of RUNFullAnalysis_TTv02.root.
-----> Stageout implementation log start
2016-12-07T07:19:06 : Creating output directory...
2016-12-07T07:19:06 : Running the stage out...
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 4: BASHOPTS: readonly variable
Wed Dec 7 07:19:06 CET 2016
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 11: BASH_VERSINFO: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 27: EUID: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 108: PPID: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 117: SHELLOPTS: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 160: UID: readonly variable
gfal-copy error: 22 (Invalid argument) - TRANSFER CHECKSUM MISMATCH Source and destination checksums do not match 2db53211 != a30fe445f7b6d96d909858b92c9fab68
Copying 606536 bytes file:///scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/RUNFullAnalysis_TTv02.root => srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root
gfal-copy exit status: 22
Non-zero gfal-copy Exit status!!!
Cleaning up failed file:
Wed Dec 7 07:19:11 CET 2016
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 4: BASHOPTS: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 11: BASH_VERSINFO: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 27: EUID: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 108: PPID: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 117: SHELLOPTS: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 160: UID: readonly variable
srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root MISSING
2016-12-07T07:19:12 : Command exited with status: 23
ERROR: Exception During Stage Out:
2016-12-07T07:19:12 : Command exited non-zero
Attempt 1 to stage out failed.
Automatically retrying in 60 secs
Error details:
StageOutError
Message: 2016-12-07T07:19:12 : Command exited non-zero
ErrorCode : 60311
ModuleName : None
MethodName : __init__
ErrorType : GeneralStageOutFailure
ClassInstance : None
FileName : /build/dmwmbld/srv/state/dmwmbld/builds/comp_gcc493/w/BUILD/slc6_amd64_gcc493/cms/crabtaskworker/3.3.1612.rc5/WMCore-1.0.21.crab4/build/lib/WMCore/Storage/StageOutError.py
ClassName : None
Command : #!/bin/bash
env -i X509_USER_PROXY=$X509_USER_PROXY JOBSTARTDIR=$JOBSTARTDIR bash -c '. $JOBSTARTDIR/startup_environment.sh; date; gfal-copy -t 2400 -T 2400 -p -K adler32 file:///scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/RUNFullAnalysis_TTv02.root srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root'
EXIT_STATUS=$?
echo "gfal-copy exit status: $EXIT_STATUS"
if [[ $EXIT_STATUS != 0 ]]; then
echo "Non-zero gfal-copy Exit status!!!"
echo "Cleaning up failed file:"
env -i X509_USER_PROXY=$X509_USER_PROXY JOBSTARTDIR=$JOBSTARTDIR bash -c '. $JOBSTARTDIR/startup_environment.sh; date; gfal-rm -t 600 srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root '
exit 60311
fi
exit 0
LineNumber : 32
ErrorNr : 0
ExitCode : 23
Traceback:
2016-12-07T07:20:12 : Running the stage out...
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 4: BASHOPTS: readonly variable
Wed Dec 7 07:20:12 CET 2016
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 11: BASH_VERSINFO: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 27: EUID: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 108: PPID: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 117: SHELLOPTS: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 160: UID: readonly variable
gfal-copy error: 22 (Invalid argument) - TRANSFER CHECKSUM MISMATCH Source and destination checksums do not match 2db53211 != a30fe445f7b6d96d909858b92c9fab68
Copying 606536 bytes file:///scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/RUNFullAnalysis_TTv02.root => srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root
gfal-copy exit status: 22
Non-zero gfal-copy Exit status!!!
Cleaning up failed file:
Wed Dec 7 07:20:17 CET 2016
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 4: BASHOPTS: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 11: BASH_VERSINFO: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 27: EUID: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 108: PPID: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 117: SHELLOPTS: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 160: UID: readonly variable
srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root MISSING
2016-12-07T07:20:18 : Command exited with status: 23
ERROR: Exception During Stage Out:
2016-12-07T07:20:18 : Command exited non-zero
Attempt 2 to stage out failed.
Automatically retrying in 60 secs
Error details:
StageOutError
Message: 2016-12-07T07:20:18 : Command exited non-zero
ErrorCode : 60311
ModuleName : None
MethodName : __init__
ErrorType : GeneralStageOutFailure
ClassInstance : None
FileName : /build/dmwmbld/srv/state/dmwmbld/builds/comp_gcc493/w/BUILD/slc6_amd64_gcc493/cms/crabtaskworker/3.3.1612.rc5/WMCore-1.0.21.crab4/build/lib/WMCore/Storage/StageOutError.py
ClassName : None
Command : #!/bin/bash
env -i X509_USER_PROXY=$X509_USER_PROXY JOBSTARTDIR=$JOBSTARTDIR bash -c '. $JOBSTARTDIR/startup_environment.sh; date; gfal-copy -t 2400 -T 2400 -p -K adler32 file:///scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/RUNFullAnalysis_TTv02.root srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root'
EXIT_STATUS=$?
echo "gfal-copy exit status: $EXIT_STATUS"
if [[ $EXIT_STATUS != 0 ]]; then
echo "Non-zero gfal-copy Exit status!!!"
echo "Cleaning up failed file:"
env -i X509_USER_PROXY=$X509_USER_PROXY JOBSTARTDIR=$JOBSTARTDIR bash -c '. $JOBSTARTDIR/startup_environment.sh; date; gfal-rm -t 600 srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root '
exit 60311
fi
exit 0
LineNumber : 32
ErrorNr : 0
ExitCode : 23
Traceback:
File "/build/dmwmbld/srv/state/dmwmbld/builds/comp_gcc493/w/BUILD/slc6_amd64_gcc493/cms/crabtaskworker/3.3.1612.rc5/WMCore-1.0.21.crab4/build/lib/WMCore/Storage/StageOutImpl.py", line 213, in __call__
self.executeCommand(command)
File "/build/dmwmbld/srv/state/dmwmbld/builds/comp_gcc493/w/BUILD/slc6_amd64_gcc493/cms/crabtaskworker/3.3.1612.rc5/WMCore-1.0.21.crab4/build/lib/WMCore/Storage/StageOutImpl.py", line 91, in executeCommand
raise StageOutError(msg, Command=command, ExitCode=exitCode)
Dashboard stageout failure parameters: {'MonitorID': '161206_175417:algomez_crab_TTv02', 'MonitorJobID': '1_https://glidein.cern.ch/1/161206:175417:algomez:crab:TTv02_0', 'JobExitCode': 60311, 'StageOutReport': [{'PSN': 'T2_CH_CSCS', 'StageOutType': 'DIRECT', 'LFN': 'srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root', 'StageOutExit': 60311, 'PNN': 'T3_US_Rutgers', 'StageOutCommand': 'gfal2'}]}
Error during direct stageout:
StageOutFailure
Message: Failure in direct stage out:
StageOutError
Message: 2016-12-07T07:20:18 : Command exited non-zero
ErrorCode : 60311
ModuleName : None
MethodName : __init__
ErrorType : GeneralStageOutFailure
ClassInstance : None
FileName : /build/dmwmbld/srv/state/dmwmbld/builds/comp_gcc493/w/BUILD/slc6_amd64_gcc493/cms/crabtaskworker/3.3.1612.rc5/WMCore-1.0.21.crab4/build/lib/WMCore/Storage/StageOutError.py
ClassName : None
Command : #!/bin/bash
env -i X509_USER_PROXY=$X509_USER_PROXY JOBSTARTDIR=$JOBSTARTDIR bash -c '. $JOBSTARTDIR/startup_environment.sh; date; gfal-copy -t 2400 -T 2400 -p -K adler32 file:///scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/RUNFullAnalysis_TTv02.root srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root'
EXIT_STATUS=$?
echo "gfal-copy exit status: $EXIT_STATUS"
if [[ $EXIT_STATUS != 0 ]]; then
echo "Non-zero gfal-copy Exit status!!!"
echo "Cleaning up failed file:"
env -i X509_USER_PROXY=$X509_USER_PROXY JOBSTARTDIR=$JOBSTARTDIR bash -c '. $JOBSTARTDIR/startup_environment.sh; date; gfal-rm -t 600 srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root '
exit 60311
fi
exit 0
LineNumber : 32
ErrorNr : 0
ExitCode : 23
Traceback:
File "/build/dmwmbld/srv/state/dmwmbld/builds/comp_gcc493/w/BUILD/slc6_amd64_gcc493/cms/crabtaskworker/3.3.1612.rc5/WMCore-1.0.21.crab4/build/lib/WMCore/Storage/StageOutImpl.py", line 213, in __call__
self.executeCommand(command)
File "/build/dmwmbld/srv/state/dmwmbld/builds/comp_gcc493/w/BUILD/slc6_amd64_gcc493/cms/crabtaskworker/3.3.1612.rc5/WMCore-1.0.21.crab4/build/lib/WMCore/Storage/StageOutImpl.py", line 91, in executeCommand
raise StageOutError(msg, Command=command, ExitCode=exitCode)
Traceback (most recent call last):
File "cmscp.py", line 737, in perform_direct_stageout
source_file, dest_pfn, None, None)
File "/build/dmwmbld/srv/state/dmwmbld/builds/comp_gcc493/w/BUILD/slc6_amd64_gcc493/cms/crabtaskworker/3.3.1612.rc5/WMCore-1.0.21.crab4/build/lib/WMCore/Storage/StageOutImpl.py", line 224, in __call__
raise ex
StageOutError: StageOutError
Message: 2016-12-07T07:20:18 : Command exited non-zero
ErrorCode : 60311
ModuleName : None
MethodName : __init__
ErrorType : GeneralStageOutFailure
ClassInstance : None
FileName : /build/dmwmbld/srv/state/dmwmbld/builds/comp_gcc493/w/BUILD/slc6_amd64_gcc493/cms/crabtaskworker/3.3.1612.rc5/WMCore-1.0.21.crab4/build/lib/WMCore/Storage/StageOutError.py
ClassName : None
Command : #!/bin/bash
env -i X509_USER_PROXY=$X509_USER_PROXY JOBSTARTDIR=$JOBSTARTDIR bash -c '. $JOBSTARTDIR/startup_environment.sh; date; gfal-copy -t 2400 -T 2400 -p -K adler32 file:///scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/RUNFullAnalysis_TTv02.root srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root'
EXIT_STATUS=$?
echo "gfal-copy exit status: $EXIT_STATUS"
if [[ $EXIT_STATUS != 0 ]]; then
echo "Non-zero gfal-copy Exit status!!!"
echo "Cleaning up failed file:"
env -i X509_USER_PROXY=$X509_USER_PROXY JOBSTARTDIR=$JOBSTARTDIR bash -c '. $JOBSTARTDIR/startup_environment.sh; date; gfal-rm -t 600 srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root '
exit 60311
fi
exit 0
LineNumber : 32
ErrorNr : 0
ExitCode : 23
Traceback:
File "/build/dmwmbld/srv/state/dmwmbld/builds/comp_gcc493/w/BUILD/slc6_amd64_gcc493/cms/crabtaskworker/3.3.1612.rc5/WMCore-1.0.21.crab4/build/lib/WMCore/Storage/StageOutImpl.py", line 213, in __call__
self.executeCommand(command)
File "/build/dmwmbld/srv/state/dmwmbld/builds/comp_gcc493/w/BUILD/slc6_amd64_gcc493/cms/crabtaskworker/3.3.1612.rc5/WMCore-1.0.21.crab4/build/lib/WMCore/Storage/StageOutImpl.py", line 91, in executeCommand
raise StageOutError(msg, Command=command, ExitCode=exitCode)
TargetPFN : srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root
ErrorCode : 60311
ModuleName : None
MethodName : __init__
LFN : srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root
ClassInstance : None
FileName : /build/dmwmbld/srv/state/dmwmbld/builds/comp_gcc493/w/BUILD/slc6_amd64_gcc493/cms/crabtaskworker/3.3.1612.rc5/WMCore-1.0.21.crab4/build/lib/WMCore/Storage/StageOutError.py
ClassName : None
Command : gfal2
LineNumber : 32
InputPFN : RUNFullAnalysis_TTv02.root
Protocol : srmv2
ErrorNr : 0
ErrorType : GeneralStageOutFailure
Traceback:
File "cmscp.py", line 737, in perform_direct_stageout
source_file, dest_pfn, None, None)
File "/build/dmwmbld/srv/state/dmwmbld/builds/comp_gcc493/w/BUILD/slc6_amd64_gcc493/cms/crabtaskworker/3.3.1612.rc5/WMCore-1.0.21.crab4/build/lib/WMCore/Storage/StageOutImpl.py", line 224, in __call__
raise ex
<----- Stageout implementation log finish
Dashboard stageout failure parameters: {'MonitorID': '161206_175417:algomez_crab_TTv02', 'MonitorJobID': '1_https://glidein.cern.ch/1/161206:175417:algomez:crab:TTv02_0', 'JobExitCode': 60311, 'StageOutReport': [{'PSN': 'T2_CH_CSCS', 'StageOutType': 'DIRECT', 'LFN': 'srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root', 'StageOutExit': 60311, 'PNN': 'T3_US_Rutgers', 'StageOutCommand': 'gfal2'}]}
<----- Wed Dec 7 06:20:20 2016: Finished remote stageout of RUNFullAnalysis_TTv02.root (status 60311).
Remote stageout of RUNFullAnalysis_TTv02.root failed. Will not attempt remote stageout for any other output files (if any).
====== Wed Dec 7 06:20:20 2016: Finished remote stageout of user output files (status 60311).
====== Wed Dec 7 06:20:20 2016: Starting to clean remote stageout area.
Will remove 1 file from permanent storage at T3_US_Rutgers.
Setting direct_stageout = False for file RUNFullAnalysis_TTv02.root in job report.
Attempting to remove PFN srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root from permanent storage at T3_US_Rutgers.
-----> Stageout implementation log start
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 4: BASHOPTS: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 11: BASH_VERSINFO: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 27: EUID: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 108: PPID: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 117: SHELLOPTS: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 160: UID: readonly variable
Wed Dec 7 07:20:20 CET 2016
srm://ruhex-osgce.rutgers.edu:8443/srm/v2/server?SFN=/cms/se/phedex/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root MISSING
2016-12-07T07:20:21 : Command exited with status: 0
<----- Stageout implementation log finish
File successfully removed.
====== Wed Dec 7 06:20:21 2016: Finished to clean remote stageout area.
====== Wed Dec 7 06:20:21 2016: Starting local stageout of user output files.
-----> Wed Dec 7 06:20:21 2016: Starting local stageout of RUNFullAnalysis_TTv02.root.
-----> Stageout manager log start
==>Working on file: /store/temp/user/algomez.51cf0e6c066a508ad54e565663a53d172c9418c0/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root
===> Attempting Local Stage Out.
LFN to PFN match made:
LFN: /store/temp/user/algomez.51cf0e6c066a508ad54e565663a53d172c9418c0/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root
PFN: srm://storage01.lcg.cscs.ch:8443/srm/managerv2?SFN=/pnfs/lcg.cscs.ch/cms/trivcat/store/temp/user/algomez.51cf0e6c066a508ad54e565663a53d172c9418c0/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root
2016-12-07T07:20:21 : Creating output directory...
2016-12-07T07:20:21 : Running the stage out...
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 4: BASHOPTS: readonly variable
Wed Dec 7 07:20:21 CET 2016
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 11: BASH_VERSINFO: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 27: EUID: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 108: PPID: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 117: SHELLOPTS: readonly variable
/scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/startup_environment.sh: line 160: UID: readonly variable
Copying 606536 bytes file:///scratch/lcg/scratch/phoenix4/ARC_sessiondir/XBQODmwggYpndvtIepYPV1GmABFKDmABFKDmomQKDmABFKDmaDmthn/glide_f0N0Yr/execute/dir_145669/RUNFullAnalysis_TTv02.root => srm://storage01.lcg.cscs.ch:8443/srm/managerv2?SFN=/pnfs/lcg.cscs.ch/cms/trivcat/store/temp/user/algomez.51cf0e6c066a508ad54e565663a53d172c9418c0/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root
gfal-copy exit status: 0
2016-12-07T07:20:22 : Command exited with status: 0
===> Stage Out Successful: {'LFN': '/store/temp/user/algomez.51cf0e6c066a508ad54e565663a53d172c9418c0/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root', 'PNN': 'T2_CH_CSCS', 'StageOutCommand': 'gfal2', 'StageOutReport': [], 'PFN': 'srm://storage01.lcg.cscs.ch:8443/srm/managerv2?SFN=/pnfs/lcg.cscs.ch/cms/trivcat/store/temp/user/algomez.51cf0e6c066a508ad54e565663a53d172c9418c0/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root'}
<----- Stageout manager log finish
INFO: PNN is defined in site-local-config. T2_CH_CSCS changed to T2_CH_CSCS
Setting temp_storage_site = 'T2_CH_CSCS', storage_site = 'T3_US_Rutgers', local_stageout = True for file RUNFullAnalysis_TTv02.root in job report.
Dashboard stageout failure parameters: {'MonitorID': '161206_175417:algomez_crab_TTv02', 'MonitorJobID': '1_https://glidein.cern.ch/1/161206:175417:algomez:crab:TTv02_0', 'JobExitCode': 0, 'StageOutReport': [{'StageOutType': 'LOCAL', 'LFN': '/store/temp/user/algomez.51cf0e6c066a508ad54e565663a53d172c9418c0/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root', 'StageOutExit': 0, 'StageOutCommand': None, 'PNN': 'T2_CH_CSCS'}]}
<----- Wed Dec 7 06:20:23 2016: Finished local stageout of RUNFullAnalysis_TTv02.root (status 0).
====== Wed Dec 7 06:20:23 2016: Finished local stageout of user output files (status 0).
====== Wed Dec 7 06:20:23 2016: Starting injection of transfer requests to ASO.
Will inject 1 document.
Will use ASO server at https://cmsweb.cern.ch/couchdb2.ASO db name is asodb2.
-----> Wed Dec 7 06:20:23 2016: Starting injection for RUNFullAnalysis_TTv02_1.root.
Stageout request document so far:
{'checksums': {u'adler32': u'2db53211', u'cksum': u'2696282757'},
'destination': 'T3_US_Rutgers',
'end_time': '',
'failure_reason': [],
'job_end_time': '2016-12-07 07:20:23',
'job_retry_count': 0,
'last_update': 1481091623,
'lfn': '/store/temp/user/algomez.51cf0e6c066a508ad54e565663a53d172c9418c0/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root',
'retry_count': [],
'size': 606536,
'source': 'T2_CH_CSCS',
'start_time': '2016-12-07 07:20:23.463718',
'state': 'new'}
LFN /store/temp/user/algomez.51cf0e6c066a508ad54e565663a53d172c9418c0/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root (id 77a49de05b8a0dd4f51643cfc11d20b9b1c76fef11a76a7a7fdf8f63) is not yet in ASO database. Uploading new stageout request.
Final stageout job description:
{'_id': '77a49de05b8a0dd4f51643cfc11d20b9b1c76fef11a76a7a7fdf8f63',
'checksums': {u'adler32': u'2db53211', u'cksum': u'2696282757'},
'dbs_url': 'https://cmsweb.cern.ch/dbs/prod/phys03/DBSReader',
'destination': 'T3_US_Rutgers',
'destination_lfn': '/store/user/algomez/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root',
'end_time': '',
'failure_reason': [],
'group': '',
'inputdataset': '/TT_TuneCUETP8M1_13TeV-powheg-pythia8/grauco-B2GAnaFW_80X_V2p1-edbed0685401a5848e7d61871b3a63d8/USER',
'job_end_time': '2016-12-07 07:20:23',
'job_retry_count': 0,
'jobid': '1',
'last_update': 1481091623,
'lfn': '/store/temp/user/algomez.51cf0e6c066a508ad54e565663a53d172c9418c0/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root',
'publication_retry_count': [],
'publication_state': 'not_published',
'publish': 0,
'rest_host': 'cmsweb.cern.ch',
'rest_uri': '/crabserver/prod',
'retry_count': [],
'role': '',
'size': 606536,
'source': 'T2_CH_CSCS',
'source_lfn': '/store/temp/user/algomez.51cf0e6c066a508ad54e565663a53d172c9418c0/myArea/EOS/B2GAnaFW_80X_V2p1/TT_TuneCUETP8M1_13TeV-powheg-pythia8/crab_TTv02/161206_175417/0000/RUNFullAnalysis_TTv02_1.root',
'start_time': '2016-12-07 07:20:23.463718',
'state': 'new',
'type': 'output',
'user': 'algomez',
'workflow': '161206_175417:algomez_crab_TTv02'}
Setting aso_start_time = 2016-12-07 07:20:23.463718 and aso_start_time_stamp = 1481091623 in job report.
<----- Wed Dec 7 06:20:23 2016: Finished injection for RUNFullAnalysis_TTv02_1.root (status 0).
====== Wed Dec 7 06:20:23 2016: Finished injection of transfer requests to ASO (status 0).
====== Wed Dec 7 06:20:23 2016: cmscp.py FINISHING (status 0).
======== Stageout at Wed Dec 7 06:20:23 GMT 2016 FINISHING (short status 0) ========
======== gWMS-CMSRunAnalysis.sh FINISHING at Wed Dec 7 06:20:23 GMT 2016 on wn161.lcg.cscs.ch with (short) status 0 ========
Local time: Wed Dec 7 07:20:23 CET 2016
Short exit status: 0
======== Figuring out long exit code of the job for condor_chirp ========
==== Long exit code of the job is 0 ====
======== Finished condor_chirp -ing the exit code of the job. Exit code of condor_chirp: 0 ========
Job Running time in seconds: 1131
Job runtime is less than 20minutes. Sleeping 1
Many jobs now a days fail with 60311 which is listed as site failure. But this seems sort of catch all for various errors that need to be better classified. In paricular problem appears in connection with issue described in #5156
Overall a good cleanup of cmscp.py is overdue