Problems reading Enstore tapes

ewv · 2 August 2022 21:28

Part B

Aug 02 15:58:52 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="857" MSG="Catalogue - system modified tape - mountedForRetrieve" vid="VR5775" lastReadDrive="LTO8D1" lastReadTime="1659473932"
Aug 02 15:58:52 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="857" MSG="In RetrieveMount::setTapeMounted(): success." thread="TapeRead" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" vo="vo" mediaType="LTO8" tapePool="ctasystest" logicalLibrary="TS4500G1" mountType="Retrieve" labelFormat="0x02" vendor="ibm" capacityInBytes="12000000000000" catalogueTime="0.003840"
Aug 02 15:58:52 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="857" MSG="Drive encryption not enabled for this mount" thread="TapeRead" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" vo="vo" mediaType="LTO8" tapePool="ctasystest" logicalLibrary="TS4500G1" mountType="Retrieve" labelFormat="0x02" vendor="ibm" capacityInBytes="12000000000000" encryption="off"
Aug 02 15:58:57 gmv18018.fnal.gov cta-taped[245606]: LVL="DEBUG" PID="245606" TID="245606" MSG="In MaintenanceHandler::exceptionThrowingRunChild(): About to do a maintenance pass." SubprocessName="maintenanceHandler"
Aug 02 15:58:57 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="869" MSG="Error while fetching the limitUDS for RAO enterprise drive. Will run a CTA RAO." thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96" exceptionMessage="SCSI error in DriveGeneric::getLimitUDS status=0x2 host_status=0 driver_status=0x8: SCSI command failed with status CHECK CONDITION: Sense Information: Illegal Request: Invalid field in cdb"
Aug 02 15:58:57 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="869" MSG="Performing RAO reordering" thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96"
Aug 02 15:58:58 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="857" MSG="Tape read session session without LBP successfully started" thread="TapeRead" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" vo="vo" mediaType="LTO8" tapePool="ctasystest" logicalLibrary="TS4500G1" mountType="Retrieve" labelFormat="0x02" vendor="ibm" capacityInBytes="12000000000000" positionTime="5.410211" useLbp="1" detectedLbp="0"
Aug 02 15:58:58 gmv18018.fnal.gov cta-taped[245605]: LVL="WARN" PID="245605" TID="869" MSG="In RAOManager::queryRAO(), failed to instanciate the RAO algorithm, will perform a linear RAO." thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96" errorMsg="In InterpolationFilePositionEstimator::checkMediaTypeConsistency(), the media type (LTO8) associated to the tape does not give informations about the minLPos and maxLPos." raoAlgorithmName="sltf" raoAlgorithmOptions="cost_heuristic_name:cta" useRAO="1" vid="VR5775"
Aug 02 15:58:58 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="869" MSG="In RAOManager::queryRAO(), successfully performed RAO." thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96" executedRAOAlgorithm="linear" vectorInitializationTime="0.000033" vectorSortingTime="0.000119" RAOAlgorithmTime="0.000157" totalTime="0.112583"
Aug 02 15:58:58 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="869" MSG="In RecallTaskInjector::reserveSpaceForNextJobBatch(): Disk space reservation for next job batch succeeded" thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96"
Aug 02 15:58:58 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="869" MSG="Created tasks for recalling a file" thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96"
Aug 02 15:58:58 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="869" MSG="Recall order of FSEQs using RAO: 1" thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96"
Aug 02 15:58:58 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="869" MSG="Finished processing batch of recall tasks from client" thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96" nbFile="1"
Aug 02 15:58:58 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="857" MSG="In RecallReportPacker::reportDriveStatus(), pushing a report." thread="TapeRead" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" vo="vo" mediaType="LTO8" tapePool="ctasystest" logicalLibrary="TS4500G1" mountType="Retrieve" labelFormat="0x02" vendor="ibm" capacityInBytes="12000000000000" type="ReportDriveStatus" Status="Transfer"
Aug 02 15:58:58 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="868" MSG="In RecallReportPacker::WorkerThread::run(): Got a new report." thread="RecallReportPacker" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" typeId="castor::tape::tapeserver::daemon::RecallReportPacker::ReportDriveStatus"
Aug 02 15:58:58 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="869" MSG="RecallJobInjector:run: about to call client interface" thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96"
Aug 02 15:58:58 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="868" MSG="In RecallReportPacker::ReportDriveStatus::execute(): reporting drive status." thread="RecallReportPacker" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" status="Transfer"
Aug 02 15:58:58 gmv18018.fnal.gov cta-taped[245603]: LVL="INFO" PID="245603" TID="245603" MSG="In DriveHandler::processEvent(): changing session state" tapeDrive="LTO8D1" PreviousState="Mounting" PreviousType="Retrieve" NewState="Running" NewType="Retrieve"
Aug 02 15:58:58 gmv18018.fnal.gov cta-taped[245603]: LVL="DEBUG" PID="245603" TID="245603" MSG="Computed new timeout" PreviousState="Mounting" PreviousType="Retrieve" NewState="Running" NewType="Retrieve" TimeoutType="Heartbeat" LastStateChangeTime="101285" LastHeartBeatTime="101285" LastDataMovementTime="101285" Now="101285" Timeout="101345"
Aug 02 15:58:58 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="869" MSG="No files left to recall on the queue or in the injector" thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96" transactionId="96"
Aug 02 15:58:58 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="869" MSG="Performing RAO reordering" thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96" transactionId="96"
Aug 02 15:59:03 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="856" MSG="going to report" thread="Watchdog" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96"
Aug 02 15:59:03 gmv18018.fnal.gov cta-taped[245603]: LVL="DEBUG" PID="245603" TID="245603" MSG="Computed new timeout" tapeDrive="LTO8D1" TimeoutType="Heartbeat" LastStateChangeTime="101285" LastHeartBeatTime="101290" LastDataMovementTime="101285" Now="101290" Timeout="101350"
Aug 02 15:59:03 gmv18018.fnal.gov cta-taped[245603]: LVL="DEBUG" PID="245603" TID="245603" MSG="Computed new timeout" tapeDrive="LTO8D1" TimeoutType="Heartbeat" LastStateChangeTime="101285" LastHeartBeatTime="101290" LastDataMovementTime="101285" Now="101290" Timeout="101350"
Aug 02 15:59:06 gmv18018.fnal.gov cta-taped[245606]: LVL="DEBUG" PID="245606" TID="245606" MSG="In MaintenanceHandler::exceptionThrowingRunChild(): About to do a maintenance pass." SubprocessName="maintenanceHandler"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="857" MSG="Successfully opened the tape file" thread="TapeRead" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" vo="vo" mediaType="LTO8" tapePool="ctasystest" logicalLibrary="TS4500G1" mountType="Retrieve" labelFormat="0x02" vendor="ibm" capacityInBytes="12000000000000" fileId="161" BlockId="1" fSeq="1" dstURL="root://storagedev201.fnal.gov//eos/archive/pnfs/fs/usr/cms/WAX/11/store/mc/RunIISummer19UL17HLT/GluGluToHiggs0PL1ToZZTo2mu2tau_M125_GaSM_13TeV_MCFM701_pythia8/GEN-SIM-RAW/94X_mc2017_realistic_v15-v2/260000/3C103261-CDB7-E911-A053-0CC47AFC3D32.root?eos.lfn=fxid:21&eos.ruid=0&eos.rgid=0&eos.injection=1&eos.workflow=retrieve_written&eos.space=default&oss.asize=2769204577" isRepack="0" isVerifyOnly="0"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="857" MSG="Timed free memory" thread="TapeRead" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" vo="vo" mediaType="LTO8" tapePool="ctasystest" logicalLibrary="TS4500G1" mountType="Retrieve" labelFormat="0x02" vendor="ibm" capacityInBytes="12000000000000" fileId="161" BlockId="1" fSeq="1" dstURL="root://storagedev201.fnal.gov//eos/archive/pnfs/fs/usr/cms/WAX/11/store/mc/RunIISummer19UL17HLT/GluGluToHiggs0PL1ToZZTo2mu2tau_M125_GaSM_13TeV_MCFM701_pythia8/GEN-SIM-RAW/94X_mc2017_realistic_v15-v2/260000/3C103261-CDB7-E911-A053-0CC47AFC3D32.root?eos.lfn=fxid:21&eos.ruid=0&eos.rgid=0&eos.injection=1&eos.workflow=retrieve_written&eos.space=default&oss.asize=2769204577" isRepack="0" isVerifyOnly="0"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="WARN" PID="245605" TID="869" MSG="In RAOManager::queryRAO(), failed to instanciate the RAO algorithm, will perform a linear RAO." thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96" transactionId="96" errorMsg="In InterpolationFilePositionEstimator::checkMediaTypeConsistency(), the media type (LTO8) associated to the tape does not give informations about the minLPos and maxLPos." raoAlgorithmName="sltf" raoAlgorithmOptions="cost_heuristic_name:cta" useRAO="1" vid="VR5775"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="869" MSG="In RAOManager::queryRAO(), successfully performed RAO." thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96" transactionId="96" executedRAOAlgorithm="linear" vectorInitializationTime="0.000005" vectorSortingTime="0.000025" RAOAlgorithmTime="0.000034" totalTime="9.005544"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="869" MSG="In RecallTaskInjector::reserveSpaceForNextJobBatch(): Disk space reservation for next job batch succeeded" thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96" transactionId="96"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="869" MSG="Recall order of FSEQs using RAO:" thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96" transactionId="96"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="869" MSG="Finished processing batch of recall tasks from client" thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96" transactionId="96" nbFile="0"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="869" MSG="No more file to recall: triggering the end of session." thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96" transactionId="96"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="869" MSG="Finishing RecallTaskInjector thread" thread="RecallTaskInjector" tapeDrive="LTO8D1" mountId="96"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="863" MSG="DiskWriteWorkerThread exiting: no more work" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="5"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="859" MSG="DiskWriteWorkerThread exiting: no more work" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="1"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="864" MSG="DiskWriteWorkerThread exiting: no more work" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="6"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="865" MSG="DiskWriteWorkerThread exiting: no more work" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="7"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="860" MSG="DiskWriteWorkerThread exiting: no more work" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="2"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="862" MSG="DiskWriteWorkerThread exiting: no more work" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="4"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="861" MSG="DiskWriteWorkerThread exiting: no more work" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="3"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="866" MSG="DiskWriteWorkerThread exiting: no more work" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="8"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="867" MSG="DiskWriteWorkerThread exiting: no more work" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="9"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="865" MSG="Finishing DiskWriteWorkerThread" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="7" threadReadWriteTime="0.000000" threadChecksumingTime="0.000000" threadWaitDataTime="0.000000" threadWaitReportingTime="0.000000" threadCheckingErrorTime="0.000000" threadOpeningTime="0.000000" threadClosingTime="0.000000" threadTransferTime="0.000000" threadTotalTime="33.978818" threadDataVolume="0" threadFileCount="0" threadGlobalPayloadTransferSpeedMBps="0.000000" threadAverageDiskPerformanceMBps="0.000000" threadOpenRWCloseToTransferTimeRatio="0.000000"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="863" MSG="Finishing DiskWriteWorkerThread" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="5" threadReadWriteTime="0.000000" threadChecksumingTime="0.000000" threadWaitDataTime="0.000000" threadWaitReportingTime="0.000000" threadCheckingErrorTime="0.000000" threadOpeningTime="0.000000" threadClosingTime="0.000000" threadTransferTime="0.000000" threadTotalTime="33.978843" threadDataVolume="0" threadFileCount="0" threadGlobalPayloadTransferSpeedMBps="0.000000" threadAverageDiskPerformanceMBps="0.000000" threadOpenRWCloseToTransferTimeRatio="0.000000"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="862" MSG="Finishing DiskWriteWorkerThread" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="4" threadReadWriteTime="0.000000" threadChecksumingTime="0.000000" threadWaitDataTime="0.000000" threadWaitReportingTime="0.000000" threadCheckingErrorTime="0.000000" threadOpeningTime="0.000000" threadClosingTime="0.000000" threadTransferTime="0.000000" threadTotalTime="33.978959" threadDataVolume="0" threadFileCount="0" threadGlobalPayloadTransferSpeedMBps="0.000000" threadAverageDiskPerformanceMBps="0.000000" threadOpenRWCloseToTransferTimeRatio="0.000000"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="866" MSG="Finishing DiskWriteWorkerThread" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="8" threadReadWriteTime="0.000000" threadChecksumingTime="0.000000" threadWaitDataTime="0.000000" threadWaitReportingTime="0.000000" threadCheckingErrorTime="0.000000" threadOpeningTime="0.000000" threadClosingTime="0.000000" threadTransferTime="0.000000" threadTotalTime="33.978733" threadDataVolume="0" threadFileCount="0" threadGlobalPayloadTransferSpeedMBps="0.000000" threadAverageDiskPerformanceMBps="0.000000" threadOpenRWCloseToTransferTimeRatio="0.000000"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="860" MSG="Finishing DiskWriteWorkerThread" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="2" threadReadWriteTime="0.000000" threadChecksumingTime="0.000000" threadWaitDataTime="0.000000" threadWaitReportingTime="0.000000" threadCheckingErrorTime="0.000000" threadOpeningTime="0.000000" threadClosingTime="0.000000" threadTransferTime="0.000000" threadTotalTime="33.979592" threadDataVolume="0" threadFileCount="0" threadGlobalPayloadTransferSpeedMBps="0.000000" threadAverageDiskPerformanceMBps="0.000000" threadOpenRWCloseToTransferTimeRatio="0.000000"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="864" MSG="Finishing DiskWriteWorkerThread" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="6" threadReadWriteTime="0.000000" threadChecksumingTime="0.000000" threadWaitDataTime="0.000000" threadWaitReportingTime="0.000000" threadCheckingErrorTime="0.000000" threadOpeningTime="0.000000" threadClosingTime="0.000000" threadTransferTime="0.000000" threadTotalTime="33.978938" threadDataVolume="0" threadFileCount="0" threadGlobalPayloadTransferSpeedMBps="0.000000" threadAverageDiskPerformanceMBps="0.000000" threadOpenRWCloseToTransferTimeRatio="0.000000"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="861" MSG="Finishing DiskWriteWorkerThread" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="3" threadReadWriteTime="0.000000" threadChecksumingTime="0.000000" threadWaitDataTime="0.000000" threadWaitReportingTime="0.000000" threadCheckingErrorTime="0.000000" threadOpeningTime="0.000000" threadClosingTime="0.000000" threadTransferTime="0.000000" threadTotalTime="33.979210" threadDataVolume="0" threadFileCount="0" threadGlobalPayloadTransferSpeedMBps="0.000000" threadAverageDiskPerformanceMBps="0.000000" threadOpenRWCloseToTransferTimeRatio="0.000000"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="867" MSG="Finishing DiskWriteWorkerThread" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="9" threadReadWriteTime="0.000000" threadChecksumingTime="0.000000" threadWaitDataTime="0.000000" threadWaitReportingTime="0.000000" threadCheckingErrorTime="0.000000" threadOpeningTime="0.000000" threadClosingTime="0.000000" threadTransferTime="0.000000" threadTotalTime="33.978733" threadDataVolume="0" threadFileCount="0" threadGlobalPayloadTransferSpeedMBps="0.000000" threadAverageDiskPerformanceMBps="0.000000" threadOpenRWCloseToTransferTimeRatio="0.000000"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="INFO" PID="245605" TID="859" MSG="Finishing DiskWriteWorkerThread" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="1" threadReadWriteTime="0.000000" threadChecksumingTime="0.000000" threadWaitDataTime="0.000000" threadWaitReportingTime="0.000000" threadCheckingErrorTime="0.000000" threadOpeningTime="0.000000" threadClosingTime="0.000000" threadTransferTime="0.000000" threadTotalTime="33.979085" threadDataVolume="0" threadFileCount="0" threadGlobalPayloadTransferSpeedMBps="0.000000" threadAverageDiskPerformanceMBps="0.000000" threadOpenRWCloseToTransferTimeRatio="0.000000"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="ERROR" PID="245605" TID="857" MSG="Error reading a file in TapeReadFileTask" thread="TapeRead" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" vo="vo" mediaType="LTO8" tapePool="ctasystest" logicalLibrary="TS4500G1" mountType="Retrieve" labelFormat="0x02" vendor="ibm" capacityInBytes="12000000000000" fileId="161" BlockId="1" fSeq="1" dstURL="root://storagedev201.fnal.gov//eos/archive/pnfs/fs/usr/cms/WAX/11/store/mc/RunIISummer19UL17HLT/GluGluToHiggs0PL1ToZZTo2mu2tau_M125_GaSM_13TeV_MCFM701_pythia8/GEN-SIM-RAW/94X_mc2017_realistic_v15-v2/260000/3C103261-CDB7-E911-A053-0CC47AFC3D32.root?eos.lfn=fxid:21&eos.ruid=0&eos.rgid=0&eos.injection=1&eos.workflow=retrieve_written&eos.space=default&oss.asize=2769204577" isRepack="0" isVerifyOnly="0" fileBlock="1" ErrorMessage="Checksum value (blob) expected=0xfeb896d9 actual=0x00000001" EWVSize="0"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="857" MSG="No more files to read from tape" thread="TapeRead" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" vo="vo" mediaType="LTO8" tapePool="ctasystest" logicalLibrary="TS4500G1" mountType="Retrieve" labelFormat="0x02" vendor="ibm" capacityInBytes="12000000000000"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="ERROR" PID="245605" TID="858" MSG="Checksum value (blob) expected=0xfeb896d9 actual=0x00000001" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="0" fileId="161" dstURL="root://storagedev201.fnal.gov//eos/archive/pnfs/fs/usr/cms/WAX/11/store/mc/RunIISummer19UL17HLT/GluGluToHiggs0PL1ToZZTo2mu2tau_M125_GaSM_13TeV_MCFM701_pythia8/GEN-SIM-RAW/94X_mc2017_realistic_v15-v2/260000/3C103261-CDB7-E911-A053-0CC47AFC3D32.root?eos.lfn=fxid:21&eos.ruid=0&eos.rgid=0&eos.injection=1&eos.workflow=retrieve_written&eos.space=default&oss.asize=2769204577" fSeq="1" received_archiveFileID="161" expected_NSBLOCKId="0" received_NSBLOCKId="-1" failed_Status="1"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="857" MSG="In RecallReportPacker::reportDriveStatus(), pushing a report." thread="TapeRead" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" type="ReportDriveStatus" Status="CleanUp"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="857" MSG="Starting read session cleanup. Signalled end of session to task injector." thread="TapeRead" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="868" MSG="In RecallReportPacker::WorkerThread::run(): Got a new report." thread="RecallReportPacker" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" typeId="castor::tape::tapeserver::daemon::RecallReportPacker::ReportDriveStatus"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="DEBUG" PID="245605" TID="868" MSG="In RecallReportPacker::ReportDriveStatus::execute(): reporting drive status." thread="RecallReportPacker" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" status="CleanUp"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="ERROR" PID="245605" TID="858" MSG="File writing to disk failed" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="0" fileId="161" dstURL="root://storagedev201.fnal.gov//eos/archive/pnfs/fs/usr/cms/WAX/11/store/mc/RunIISummer19UL17HLT/GluGluToHiggs0PL1ToZZTo2mu2tau_M125_GaSM_13TeV_MCFM701_pythia8/GEN-SIM-RAW/94X_mc2017_realistic_v15-v2/260000/3C103261-CDB7-E911-A053-0CC47AFC3D32.root?eos.lfn=fxid:21&eos.ruid=0&eos.rgid=0&eos.injection=1&eos.workflow=retrieve_written&eos.space=default&oss.asize=2769204577" fSeq="1" errorMessage="Checksum value (blob) expected=0xfeb896d9 actual=0x00000001" readWriteTime="0.000000" checksumingTime="0.000000" waitDataTime="9.130139" waitReportingTime="0.001754" checkingErrorTime="0.000000" openingTime="0.000000" closingTime="0.000000" transferTime="0.000000" totalTime="0.000000" dataVolume="0" globalPayloadTransferSpeedMBps="0.000000" diskPerformanceMBps="0.000000" openRWCloseToTransferTimeRatio="0.000000"
Aug 02 15:59:07 gmv18018.fnal.gov cta-taped[245605]: LVL="ERROR" PID="245605" TID="858" MSG="Stack trace" thread="DiskWrite" tapeDrive="LTO8D1" tapeVid="VR5775" mountId="96" threadCount="10" threadID="0" fSeq="1" errorMessage="Checksum value (blob) expected=0xfeb896d9 actual=0x00000001" traceFrameNumber="0" traceFrame="/lib64/libctacommon.so.0(cta::exception::Backtrace::Backtrace(bool)+0x69) [0x7f2ec3507cbd]"