Possible error in cta-taped logs - vid value in tapepool key

General Discussion
1

Dear CTA team,

I amb putting together all the pieces to get a monitoring system that suits our needs and, after being able to send all logs to a central server and then all logs to our Elasticsearch instance, looking to the values to think about some plots, I saw some tapepool fields values with tape vid. Some of the lines have the tapepool correctly though.

ctatps002/cta-taped.log:Jan 19 12:50:51.328201 ctatps002 cta-taped: LVL="INFO" PID="29644" TID="29644" MSG="In ContainerTraits<ArchiveQueue_t,ArchiveQueue>::trimContainerIfNeeded(): deleted empty queue" thread="MainThread" tapeDrive="IBML8234" tapeVid="V03648" mountId="1263" tapepool="dcache" queueObject="ArchiveQueueToTransferForUser-dcache-Frontend-ctafrontend01.pic.es-25104-20240119-11:39:31-0-5" queueUnlockTime="0.000445" rootEntryLockTime="0.000866" rootEntryFetchTime="0.000400" rootEntryRemoveArchiveQueueAndCommitTime="0.106847"
ctatps002/cta-taped.log:Jan 19 12:50:51.329145 ctatps002 cta-taped: LVL="INFO" PID="29644" TID="29644" MSG="In Algorithms::popNextBatch(): did one round of elements retrieval." thread="MainThread" tapeDrive="IBML8234" tapeVid="V03648" mountId="1263" C="ArchiveQueueToTransferForUser" tapepool="dcache" containerAddress="ArchiveQueueToTransferForUser-dcache-Frontend-ctafrontend01.pic.es-25104-20240119-11:39:31-0-5" filesAdded="2" bytesAdded="651852944" filesBefore="0" bytesBefore="0" filesAfter="2" bytesAfter="651852944" queueJobsBefore="2" queueBytesBefore="651852944" queueJobsAfter="0" queueBytesAfter="0" findLockFetchQueueTime="0.001721" jobSelectionTime="0.007174" ownershipAdditionTime="0.000039" asyncUpdateLaunchTime="0.004867" asyncUpdateCompletionTime="0.014479" updateResultProcessingTime="0.000093" containerUpdateTime="0.003809" containerTrimmingTime="0.109397" containerUnlockTime="0.000007" structureProcessingTime="0.000051"
ctatps002/cta-taped.log:Jan 19 12:50:51.330065 ctatps002 cta-taped: LVL="INFO" PID="29644" TID="29644" MSG="In Algorithms::popNextBatch(): elements retrieval complete." thread="MainThread" tapeDrive="IBML8234" tapeVid="V03648" mountId="1263" C="ArchiveQueueToTransferForUser" tapepool="dcache" files="2" findLockFetchQueueTime="0.001721" jobSelectionTime="0.007174" ownershipAdditionTime="0.000039" asyncUpdateLaunchTime="0.004867" asyncUpdateCompletionTime="0.014479" updateResultProcessingTime="0.000093" containerUpdateTime="0.003809" containerTrimmingTime="0.109397" containerUnlockTime="0.000007" structureProcessingTime="0.000051" schedulerDbTime="0.142830" iterationCount="1"
ctatps002/cta-taped.log:Jan 19 12:52:42.499223 ctatps002 cta-taped: LVL="INFO" PID="29644" TID="2447" MSG="In ContainerAlgorithms::referenceAndSwitchOwnership(): Requeued a batch of elements." thread="MainThread" tapeDrive="IBML8234" mountId="1263" C="ArchiveQueueToReportForUser" tapepool="V03648" containerAddress="ArchiveQueueToReportForUser-V03648-DriveProcess-IBML8234-ctatps002.pic.es-29644-20240119-12:18:18-0-0" queueJobsBefore="0" queueBytesBefore="0" queueJobsAfter="2" queueBytesAfter="651852944" queueLockFetchTime="0.029306" queueProcessAndCommitTime="0.003185" asyncUpdateLaunchTime="0.000151" asyncUpdateCompletionTime="0.047975" requestsUpdatingTime="0.000095" queueUnlockTime="0.000371"
ctatps002/cta-taped.log:Jan 19 12:52:45.815817 ctatps002 cta-taped: LVL="INFO" PID="11405" TID="11405" MSG="In ContainerTraits<ArchiveQueue_t,ArchiveQueue>::trimContainerIfNeeded(): deleted empty queue" SubprocessName="maintenanceHandler" tapepool="V03648" queueObject="ArchiveQueueToReportForUser-V03648-DriveProcess-IBML8234-ctatps002.pic.es-29644-20240119-12:18:18-0-0" queueUnlockTime="0.000457" rootEntryLockTime="0.000882" rootEntryFetchTime="0.000412" rootEntryRemoveArchiveQueueAndCommitTime="0.107488"
ctatps002/cta-taped.log:Jan 19 12:52:45.816772 ctatps002 cta-taped: LVL="INFO" PID="11405" TID="11405" MSG="In Algorithms::popNextBatch(): did one round of elements retrieval." SubprocessName="maintenanceHandler" C="ArchiveQueueToReportForUser" tapepool="V03648" containerAddress="ArchiveQueueToReportForUser-V03648-DriveProcess-IBML8234-ctatps002.pic.es-29644-20240119-12:18:18-0-0" filesAdded="2" filesBefore="0" filesAfter="2" queueJobsBefore="2" queueBytesBefore="651852944" queueJobsAfter="0" queueBytesAfter="0" findLockFetchQueueTime="0.001545" jobSelectionTime="0.000838" ownershipAdditionTime="0.000027" asyncUpdateLaunchTime="0.004954" asyncUpdateCompletionTime="0.005849" updateResultProcessingTime="0.000050" containerUpdateTime="0.003439" containerTrimmingTime="0.110013" containerUnlockTime="0.000017" structureProcessingTime="0.000038"
ctatps002/cta-taped.log:Jan 19 12:52:45.817550 ctatps002 cta-taped: LVL="INFO" PID="11405" TID="11405" MSG="In Algorithms::popNextBatch(): elements retrieval complete." SubprocessName="maintenanceHandler" C="ArchiveQueueToReportForUser" tapepool="V03648" files="2" findLockFetchQueueTime="0.001545" jobSelectionTime="0.000838" ownershipAdditionTime="0.000027" asyncUpdateLaunchTime="0.004954" asyncUpdateCompletionTime="0.005849" updateResultProcessingTime="0.000050" containerUpdateTime="0.003439" containerTrimmingTime="0.110013" containerUnlockTime="0.000017" structureProcessingTime="0.000038" schedulerDbTime="0.127765" iterationCount="1"

I guess this is not supposed to be like this, but I wanted to ask if you noticed that or for some reason it is supposed to be like this. Maybe you already noticed and it is fixed in newer versions, we are using version 5.8.7.

Cheers,

Jordi

2

Hello Jordi,

this is a side effect of how the ToReport queues were implemented. Every queue has an identifier, archive queues have tapepools as identifier and retrieve queues use the VID. When reporting for user success of an archive the queue uses the VID as identifier but the key of the identifier in the logs (tapepool) remains the same. Which can lead to confusion.

Fixing this is on our list of things to be done, but not a priority right now.

Cheers,
Pablo.

3

Hi Pablo,

Thanks for your answer.
Well, ok, good to know it is in the roadmap.

Cheers,

Jordi