 |
 |
In an attempt to get eyes on this and make this easier to debug, here is some specific output
.065583 +0000][Dump ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Stream inactive since 1001 seconds, TTL: 7200, allocated SIDs: 1, open files: 0
[2022-01-24 21:07:50.065648 +0000][Dump ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Stream inactive since 1001 seconds, stream timeout: 7200, allocated SIDs: 1, wait barrier: 2022-01-24 19:44:30 +0000
[2022-01-24 21:07:52.240803 +0000][Error ][AsyncSock ] [fndca1.fnal.gov:1096.0] Socket error encountered: [ERROR] Internal error: connection timed out
[2022-01-24 21:07:52.242016 +0000][Debug ][AsyncSock ] [fndca1.fnal.gov:1096.0] Closing the socket
[2022-01-24 21:07:52.245735 +0000][Debug ][Poller ] <[2001:1458:301:4a::100:78]:57072><--><[2620:6a:0:4812:f0:0:69:121]:1096> Removing socket from the poller
[2022-01-24 21:07:52.245827 +0000][Debug ][PostMaster ] [fndca1.fnal.gov:1096] Recovering error for stream #0: [ERROR] Internal error: connection timed out.
[2022-01-24 21:07:52.246869 +0000][Debug ][PostMaster ] [fndca1.fnal.gov:1096] Reporting disconnection to queued message handlers.
[2022-01-24 21:07:52.247233 +0000][Dump ][XRootD ] [fndca1.fnal.gov:1096] Stream event reported for msg kXR_open (file: pnfs/fnal.gov/usr/dune/tape_backed/dunepro/protodune-sp/full-reconstructed/2021/mc/out1/PDSPProd4a/45/65/94/31/PDSPProd4a_protoDUNE_sp_reco_stage1_p2GeV_35ms_sce_datadriven_45659431_184_20210607T104924Z.root?, mode: 00, flags: kXR_open_read kXR_async kXR_retstat )
[2022-01-24 21:07:52.247255 +0000][Debug ][XRootD ] [fndca1.fnal.gov:1096] Handling error while processing kXR_open (file: pnfs/fnal.gov/usr/dune/tape_backed/dunepro/protodune-sp/full-reconstructed/2021/mc/out1/PDSPProd4a/45/65/94/31/PDSPProd4a_protoDUNE_sp_reco_stage1_p2GeV_35ms_sce_datadriven_45659431_184_20210607T104924Z.root?, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ): [ERROR] Internal error: connection timed out.
[2022-01-24 21:07:52.247589 +0000][Info ][XRootD ] [fndca1.fnal.gov:1096] Retrying request: kXR_open (file: pnfs/fnal.gov/usr/dune/tape_backed/dunepro/protodune-sp/full-reconstructed/2021/mc/out1/PDSPProd4a/45/65/94/31/PDSPProd4a_protoDUNE_sp_reco_stage1_p2GeV_35ms_sce_datadriven_45659431_184_20210607T104924Z.root?, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ).
[2022-01-24 21:07:52.247666 +0000][Dump ][Utility ] URL: root://fndca1.fnal.gov:1096/pnfs/fnal.gov/usr/dune/tape_backed/dunepro/protodune-sp/full-reconstructed/2021/mc/out1/PDSPProd4a/45/65/94/31/PDSPProd4a_protoDUNE_sp_reco_stage1_p2GeV_35ms_sce_datadriven_45659431_184_20210607T104924Z.root
[2022-01-24 21:07:52.247666 +0000][Dump ][Utility ] Protocol: root
[2022-01-24 21:07:52.247666 +0000][Dump ][Utility ] User Name:
[2022-01-24 21:07:52.247666 +0000][Dump ][Utility ] Password:
[2022-01-24 21:07:52.247666 +0000][Dump ][Utility ] Host Name: fndca1.fnal.gov
[2022-01-24 21:07:52.247666 +0000][Dump ][Utility ] Port: 1096
[2022-01-24 21:07:52.247666 +0000][Dump ][Utility ] Path: pnfs/fnal.gov/usr/dune/tape_backed/dunepro/protodune-sp/full-reconstructed/2021/mc/out1/PDSPProd4a/45/65/94/31/PDSPProd4a_protoDUNE_sp_reco_stage1_p2GeV_35ms_sce_datadriven_45659431_184_20210607T104924Z.root
[2022-01-24 21:07:52.247706 +0000][Dump ][Utility ] URL: root://fndca1.fnal.gov:1096/pnfs/fnal.gov/usr/dune/tape_backed/dunepro/protodune-sp/full-reconstructed/2021/mc/out1/PDSPProd4a/45/65/94/31/PDSPProd4a_protoDUNE_sp_reco_stage1_p2GeV_35ms_sce_datadriven_45659431_184_20210607T104924Z.root
[2022-01-24 21:07:52.247706 +0000][Dump ][Utility ] Protocol: root
[2022-01-24 21:07:52.247706 +0000][Dump ][Utility ] User Name:
[2022-01-24 21:07:52.247706 +0000][Dump ][Utility ] Password:
[2022-01-24 21:07:52.247706 +0000][Dump ][Utility ] Host Name: fndca1.fnal.gov
[2022-01-24 21:07:52.247706 +0000][Dump ][Utility ] Port: 1096
[2022-01-24 21:07:52.247706 +0000][Dump ][Utility ] Path: pnfs/fnal.gov/usr/dune/tape_backed/dunepro/protodune-sp/full-reconstructed/2021/mc/out1/PDSPProd4a/45/65/94/31/PDSPProd4a_protoDUNE_sp_reco_stage1_p2GeV_35ms_sce_datadriven_45659431_184_20210607T104924Z.root
[2022-01-24 21:07:52.247737 +0000][Debug ][ExDbgMsg ] [fndca1.fnal.gov:1096] Retry at server MsgHandler: 0x3a4cf100 (message: kXR_open (file: pnfs/fnal.gov/usr/dune/tape_backed/dunepro/protodune-sp/full-reconstructed/2021/mc/out1/PDSPProd4a/45/65/94/31/PDSPProd4a_protoDUNE_sp_reco_stage1_p2GeV_35ms_sce_datadriven_45659431_184_20210607T104924Z.root?, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ) ).
[2022-01-24 21:07:52.247758 +0000][Dump ][PostMaster ] [fndca1.fnal.gov:1096] Sending message kXR_open (file: pnfs/fnal.gov/usr/dune/tape_backed/dunepro/protodune-sp/full-reconstructed/2021/mc/out1/PDSPProd4a/45/65/94/31/PDSPProd4a_protoDUNE_sp_reco_stage1_p2GeV_35ms_sce_datadriven_45659431_184_20210607T104924Z.root?, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ) (0x77040190) through substream 0 expecting answer at 0
[2022-01-24 21:07:52.250308 +0000][Debug ][PostMaster ] [fndca1.fnal.gov:1096] Found 2 address(es): [::ffff:131.225.69.121]:1096, [2620:6a:0:4812:f0:0:69:121]:1096
[2022-01-24 21:07:52.250360 +0000][Debug ][AsyncSock ] [fndca1.fnal.gov:1096.0] Attempting connection to [2620:6a:0:4812:f0:0:69:121]:1096
[2022-01-24 21:07:52.250424 +0000][Debug ][Poller ] Adding socket 0xd04ef60 to the poller
[2022-01-24 21:07:52.353082 +0000][Debug ][AsyncSock ] [fndca1.fnal.gov:1096.0] Async connection call returned
[2022-01-24 21:07:52.353169 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Sending out the initial hand shake + kXR_protocol
[2022-01-24 21:07:52.353227 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Wrote a message: (0x770289e0), 44 bytes
[2022-01-24 21:07:52.456422 +0000][Dump ][XRootDTransport ] [msg: 0x770289e0] Expecting 8 bytes of message body
[2022-01-24 21:07:52.456482 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Received message header, size: 8
[2022-01-24 21:07:52.456525 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Received a message of 16 bytes
[2022-01-24 21:07:52.456549 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Got the server hand shake response (type: manager [], protocol version 500)
[2022-01-24 21:07:52.456586 +0000][Dump ][XRootDTransport ] [msg: 0x770289e0] Expecting 8 bytes of message body
[2022-01-24 21:07:52.456597 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Received message header, size: 8
[2022-01-24 21:07:52.456608 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Received a message of 16 bytes
[2022-01-24 21:07:52.456623 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] kXR_protocol successful (type: manager [], protocol version 500)
[2022-01-24 21:07:52.465822 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Sending out kXR_login request, username: dune021, cgi: ?xrd.cc=ch&xrd.tz=0&xrd.appname=lar&xrd.info=&xrd.hostname=b7s11p6463.cern.ch&xrd.rn=v5.1.0, dual-stack: true, private IPv4: false, private IPv6: false
[2022-01-24 21:07:52.465911 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Wrote a message: (0x77079860), 115 bytes
[2022-01-24 21:07:52.584421 +0000][Dump ][XRootDTransport ] [msg: 0x77079860] Expecting 49 bytes of message body
[2022-01-24 21:07:52.584482 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Received message header, size: 8
[2022-01-24 21:07:52.584501 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Received a message of 57 bytes
[2022-01-24 21:07:52.584522 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Logged in, session: 1147ac672d24fc30bca8ec5ba69a3bcb
[2022-01-24 21:07:52.584533 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Authentication is required: &P=gsi,v:10400,c:ssl,ca:f5f0dfc2
[2022-01-24 21:07:52.584548 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Sending authentication data
[2022-01-24 21:07:52.593089 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Trying to authenticate using gsi
[2022-01-24 21:07:52.616394 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Wrote a message: (0x537756c0), 136 bytes
[2022-01-24 21:07:52.744731 +0000][Dump ][XRootDTransport ] [msg: 0x537756c0] Expecting 3309 bytes of message body
[2022-01-24 21:07:52.744786 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Received message header, size: 8
[2022-01-24 21:07:52.744811 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Received a message of 3317 bytes
[2022-01-24 21:07:52.744825 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Sending more authentication data for gsi
[2022-01-24 21:07:52.744906 +0000][Error ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Auth protocol handler for gsi refuses to give us more credentials Secgsi: ErrParseBuffer: no common cipher algorithm: kXGS_cert
[2022-01-24 21:07:52.745454 +0000][Error ][AsyncSock ] [fndca1.fnal.gov:1096.0] Socket error while handshaking: [FATAL] Auth failed
[2022-01-24 21:07:52.745821 +0000][Debug ][AsyncSock ] [fndca1.fnal.gov:1096.0] Closing the socket
[2022-01-24 21:07:52.745864 +0000][Debug ][Poller ] <[2001:1458:301:4a::100:78]:36296><--><[2620:6a:0:4812:f0:0:69:121]:1096> Removing socket from the poller
[2022-01-24 21:07:52.745931 +0000][Error ][PostMaster ] [fndca1.fnal.gov:1096] elapsed = 0, pConnectionWindow = 30 seconds.
[2022-01-24 21:07:52.746014 +0000][Debug ][AsyncSock ] [fndca1.fnal.gov:1096.0] Attempting connection to [::ffff:131.225.69.121]:1096
[2022-01-24 21:07:52.746080 +0000][Debug ][Poller ] Adding socket 0xd04ef60 to the poller
[2022-01-24 21:07:52.851413 +0000][Debug ][AsyncSock ] [fndca1.fnal.gov:1096.0] Async connection call returned
[2022-01-24 21:07:52.851490 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Sending out the initial hand shake + kXR_protocol
[2022-01-24 21:07:52.851558 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Wrote a message: (0x77025e00), 44 bytes
[2022-01-24 21:07:52.956423 +0000][Dump ][XRootDTransport ] [msg: 0x77025e00] Expecting 8 bytes of message body
[2022-01-24 21:07:52.956486 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Received message header, size: 8
[2022-01-24 21:07:52.956502 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Received a message of 16 bytes
[2022-01-24 21:07:52.956528 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Got the server hand shake response (type: manager [], protocol version 500)
[2022-01-24 21:07:52.957499 +0000][Dump ][XRootDTransport ] [msg: 0x77025e00] Expecting 8 bytes of message body
[2022-01-24 21:07:52.957539 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Received message header, size: 8
[2022-01-24 21:07:52.957551 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Received a message of 16 bytes
[2022-01-24 21:07:52.957565 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] kXR_protocol successful (type: manager [], protocol version 500)
[2022-01-24 21:07:52.958153 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Sending out kXR_login request, username: dune021, cgi: ?xrd.cc=ch&xrd.tz=0&xrd.appname=lar&xrd.info=&xrd.hostname=b7s11p6463.cern.ch&xrd.rn=v5.1.0, dual-stack: true, private IPv4: false, private IPv6: false
[2022-01-24 21:07:52.958192 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Wrote a message: (0x7705d4e0), 115 bytes
[2022-01-24 21:07:53.061769 +0000][Dump ][XRootDTransport ] [msg: 0x7705d4e0] Expecting 49 bytes of message body
[2022-01-24 21:07:53.061831 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Received message header, size: 8
[2022-01-24 21:07:53.061849 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Received a message of 57 bytes
[2022-01-24 21:07:53.061871 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Logged in, session: 5314a83cfdc9d3dd01bfe3e7ee8a939c
[2022-01-24 21:07:53.061883 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Authentication is required: &P=gsi,v:10400,c:ssl,ca:f5f0dfc2
[2022-01-24 21:07:53.061893 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Sending authentication data
[2022-01-24 21:07:53.061975 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Trying to authenticate using gsi
[2022-01-24 21:07:53.075381 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Wrote a message: (0x26cf75e0), 136 bytes
[2022-01-24 21:07:53.203989 +0000][Dump ][XRootDTransport ] [msg: 0x26cf75e0] Expecting 3309 bytes of message body
[2022-01-24 21:07:53.204047 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Received message header, size: 8
[2022-01-24 21:07:53.204070 +0000][Dump ][AsyncSock ] [fndca1.fnal.gov:1096.0] Received a message of 3317 bytes
[2022-01-24 21:07:53.204083 +0000][Debug ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Sending more authentication data for gsi
[2022-01-24 21:07:53.204139 +0000][Error ][XRootDTransport ] [fndca1.fnal.gov:1096.0] Auth protocol handler for gsi refuses to give us more credentials Secgsi: ErrParseBuffer: no common cipher algorithm: kXGS_cert
[2022-01-24 21:07:53.204178 +0000][Error ][AsyncSock ] [fndca1.fnal.gov:1096.0] Socket error while handshaking: [FATAL] Auth failed
[2022-01-24 21:07:53.204188 +0000][Debug ][AsyncSock ] [fndca1.fnal.gov:1096.0] Closing the socket
[2022-01-24 21:07:53.204205 +0000][Debug ][Poller ] <[::ffff:188.184.162.126]:51276><--><[::ffff:131.225.69.121]:1096> Removing socket from the poller
[2022-01-24 21:07:53.204285 +0000][Error ][PostMaster ] [fndca1.fnal.gov:1096] elapsed = 1, pConnectionWindow = 30 seconds.
[2022-01-24 21:07:53.204641 +0000][Error ][PostMaster ] [fndca1.fnal.gov:1096] Unable to recover: [FATAL] Auth failed.
[2022-01-24 21:07:53.204655 +0000][Error ][XRootD ] [fndca1.fnal.gov:1096] Impossible to send message kXR_open (file: pnfs/fnal.gov/usr/dune/tape_backed/dunepro/protodune-sp/full-reconstructed/2021/mc/out1/PDSPProd4a/45/65/94/31/PDSPProd4a_protoDUNE_sp_reco_stage1_p2GeV_35ms_sce_datadriven_45659431_184_20210607T104924Z.root?, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ). Trying to recover.
[2022-01-24 21:07:53.204677 +0000][Debug ][XRootD ] [fndca1.fnal.gov:1096] Handling error while processing kXR_open (file: pnfs/fnal.gov/usr/dune/tape_backed/dunepro/protodune-sp/full-reconstructed/2021/mc/out1/PDSPProd4a/45/65/94/31/PDSPProd4a_protoDUNE_sp_reco_stage1_p2GeV_35ms_sce_datadriven_45659431_184_20210607T104924Z.root?, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ): [FATAL] Auth failed.
[2022-01-24 21:07:53.204891 +0000][Debug ][ExDbgMsg ] [fndca1.fnal.gov:1096] Passing to the thread-pool MsgHandler: 0x3a4cf100 (message: kXR_open (file: pnfs/fnal.gov/usr/dune/tape_backed/dunepro/protodune-sp/full-reconstructed/2021/mc/out1/PDSPProd4a/45/65/94/31/PDSPProd4a_protoDUNE_sp_reco_stage1_p2GeV_35ms_sce_datadriven_45659431_184_20210607T104924Z.root?, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ) ).
[2022-01-24 21:07:53.205507 +0000][Debug ][ExDbgMsg ] [fndca1.fnal.gov:1096] Calling MsgHandler: 0x3a4cf100 (message: kXR_open (file: pnfs/fnal.gov/usr/dune/tape_backed/dunepro/protodune-sp/full-reconstructed/2021/mc/out1/PDSPProd4a/45/65/94/31/PDSPProd4a_protoDUNE_sp_reco_stage1_p2GeV_35ms_sce_datadriven_45659431_184_20210607T104924Z.root?, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ) ) with status: [FATAL] Auth failed.
[2022-01-24 21:07:53.205612 +0000][Debug ][File ] [0x759cc730@root://fndca1.fnal.gov:1096/pnfs/fnal.gov/usr/dune/tape_backed/dunepro/protodune-sp/full-reconstructed/2021/mc/out1/PDSPProd4a/45/65/94/31/PDSPProd4a_protoDUNE_sp_reco_stage1_p2GeV_35ms_sce_datadriven_45659431_184_20210607T104924Z.root?xrdcl.requuid=1c4fa624-7019-4ea0-b736-fc677b8a06aa] Open has returned with status [FATAL] Auth failed
[2022-01-24 21:07:53.205642 +0000][Debug ][File ] [0x759cc730@root://fndca1.fnal.gov:1096/pnfs/fnal.gov/usr/dune/tape_backed/dunepro/protodune-sp/full-reconstructed/2021/mc/out1/PDSPProd4a/45/65/94/31/PDSPProd4a_protoDUNE_sp_reco_stage1_p2GeV_35ms_sce_datadriven_45659431_184_20210607T104924Z.root?xrdcl.requuid=1c4fa624-7019-4ea0-b736-fc677b8a06aa] Error while opening at fndca1.fnal.gov:1096: [FATAL] Auth failed
[2022-01-24 21:07:53.205977 +0000][Debug ][XRootD ] Redirect trace-back:
[2022-01-24 21:07:53.205977 +0000][Debug ][XRootD ] 0. Retrying: root://fndca1.fnal.gov:1096/pnfs/fnal.gov/usr/dune/tape_backed/dunepro/protodune-sp/full-reconstructed/2021/mc/out1/PDSPProd4a/45/65/94/31/PDSPProd4a_protoDUNE_sp_reco_stage1_p2GeV_35ms_sce_datadriven_45659431_184_20210607T104924Z.root
[2022-01-24 21:07:53.206003 +0000][Debug ][ExDbgMsg ] [fndca1.fnal.gov:1096] Destroying MsgHandler: 0x3a4cf100.
—
Reply to this email directly, view it on GitHub, or unsubscribe.
Triage notifications on the go with GitHub Mobile for iOS or Android.
You are receiving this because you are subscribed to this thread.
Use REPLY-ALL to reply to list
To unsubscribe from the XROOTD-DEV list, click the following link:
https://listserv.slac.stanford.edu/cgi-bin/wa?SUBED1=XROOTD-DEV&A=1