TNetXNGFile Socket error: No route to host

mwilkins · October 11, 2017, 11:40am

I am trying to access an EOS file from my MacBook (macOS High Sierra) and get the following error:

$ root -l "root://eoslhcb.cern.ch/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root"
root [0] 
Attaching file root://eoslhcb.cern.ch/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root as _file0...
Error in <TNetXNGFile::Open>: [FATAL] Socket error: No route to host
(TFile *) nullptr

and if I try a secure connection:

$ root -l "roots://eoslhcb.cern.ch/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root"
SysError in <TUnixSystem::UnixRecv>: recv (Connection reset by peer)
Error in <TFTP::TFTP>: can't open connection to rootd on host eoslhcb.cern.ch at port 1094
root [0] 
Attaching file roots://eoslhcb.cern.ch/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root as _file0...
SysError in <TUnixSystem::UnixRecv>: recv (Connection reset by peer)
Error in <TNetFile::TNetFile>: can't open connection to rootd on host eoslhcb.cern.ch at port 1094
Error in <TNetFile::Create>: server does not accept connection from this host: contact server administrator
Error in <TNetFile::Create>: failing on file roots://eoslhcb.cern.ch/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root
(TFile *) nullptr

or

$ root -l "rootk://mwilkins@eoslhcb.cern.ch/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root"
SysError in <TUnixSystem::UnixRecv>: recv (Connection reset by peer)
Error in <TFTP::TFTP>: can't open connection to rootd on host eoslhcb.cern.ch at port 1094
root [0] 
Attaching file rootk://mwilkins@eoslhcb.cern.ch/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root as _file0...
SysError in <TUnixSystem::UnixRecv>: recv (Connection reset by peer)
Error in <TNetFile::TNetFile>: can't open connection to rootd on host eoslhcb.cern.ch at port 1094
Error in <TNetFile::Create>: server does not accept connection from this host: contact server administrator
Error in <TNetFile::Create>: failing on file rootk://mwilkins@eoslhcb.cern.ch/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root
(TFile *) nullptr

I… really don’t know what to do about this. I can ping just fine:

$ ping eoslhcb.cern.ch
PING eoslhcb.cern.ch (188.184.38.44): 56 data bytes
64 bytes from 188.184.38.44: icmp_seq=0 ttl=60 time=1.665 ms
64 bytes from 188.184.38.44: icmp_seq=1 ttl=60 time=2.395 ms
^C
--- eoslhcb.cern.ch ping statistics ---
2 packets transmitted, 2 packets received, 0.0% packet loss
round-trip min/avg/max/stddev = 1.665/2.030/2.395/0.365 ms

If I do klist, I have a valid token.
Help?

ganis · October 11, 2017, 12:23pm

Dear mwilkins,

Can you set

 $ export XRD_LOGLEVEL="Debug"

and post what you get on the screen (can be very verbose)?

G Ganis

mwilkins · October 11, 2017, 2:40pm

I’m sorry, but see on the screen when? The output when starting a root session seems unchanged.

ganis · October 11, 2017, 3:03pm

Starting a ROOT session you should get something like this:

$ export XRD_LOGLEVEL="Debug"
$ root -l root://eoslhcb.cern.ch/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root
[2017-10-11 17:01:15.899039 +0200][Warning][Utility           ] Unable to process global config file: [ERROR] OS Error: No such file or directory
[2017-10-11 17:01:15.899102 +0200][Debug  ][Utility           ] Unable to process user config file: [ERROR] OS Error: No such file or directory
[2017-10-11 17:01:15.899173 +0200][Debug  ][PlugInMgr         ] Initializing plug-in manager...
[2017-10-11 17:01:15.899183 +0200][Debug  ][PlugInMgr         ] No default plug-in, loading plug-in configs...
[2017-10-11 17:01:15.899191 +0200][Debug  ][PlugInMgr         ] Processing plug-in definitions in /etc/xrootd/client.plugins.d...
[2017-10-11 17:01:15.899203 +0200][Debug  ][PlugInMgr         ] Unable to process directory /etc/xrootd/client.plugins.d: [ERROR] OS Error: No such file or directory
[2017-10-11 17:01:15.899235 +0200][Debug  ][PlugInMgr         ] Processing plug-in definitions in /home/ganis/.xrootd/client.plugins.d...
[2017-10-11 17:01:15.899245 +0200][Debug  ][PlugInMgr         ] Unable to process directory /home/ganis/.xrootd/client.plugins.d: [ERROR] OS Error: No such file or directory
[2017-10-11 17:01:15.920853 +0200][Debug  ][Poller            ] Available pollers: built-in
[2017-10-11 17:01:15.920876 +0200][Debug  ][Poller            ] Attempting to create a poller according to preference: built-in
[2017-10-11 17:01:15.920882 +0200][Debug  ][Poller            ] Creating poller: built-in
[2017-10-11 17:01:15.920890 +0200][Debug  ][Poller            ] Creating and starting the built-in poller...
[2017-10-11 17:01:15.921015 +0200][Debug  ][Poller            ] Using 1 poller threads
[2017-10-11 17:01:15.921031 +0200][Debug  ][TaskMgr           ] Starting the task manager...
[2017-10-11 17:01:15.921070 +0200][Debug  ][TaskMgr           ] Task manager started
[2017-10-11 17:01:15.921080 +0200][Debug  ][JobMgr            ] Starting the job manager...
[2017-10-11 17:01:15.921131 +0200][Debug  ][JobMgr            ] Job manager started, 3 workers
[2017-10-11 17:01:15.921141 +0200][Debug  ][TaskMgr           ] Registering task: "FileTimer task" to be run at: [2017-10-11 17:01:15 +0200]
[2017-10-11 17:01:15.921168 +0200][Debug  ][PostMaster        ] Creating new channel to: eoslhcb.cern.ch:1094 1 stream(s)
[2017-10-11 17:01:15.921190 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Stream parameters: Network Stack: IPAuto, Connection Window: 120, ConnectionRetry: 5, Stream Error Widnow: 1800
[2017-10-11 17:01:15.921249 +0200][Debug  ][TaskMgr           ] Registering task: "TickGeneratorTask for: eoslhcb.cern.ch:1094" to be run at: [2017-10-11 17:01:30 +0200]
[2017-10-11 17:01:15.922022 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094] Found 1 address(es): [::ffff:188.184.38.44]:1094
[2017-10-11 17:01:15.922046 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Attempting connection to [::ffff:188.184.38.44]:1094
[2017-10-11 17:01:15.922077 +0200][Debug  ][Poller            ] Adding socket 0x300daf0 to the poller
[2017-10-11 17:01:15.922352 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Async connection call returned
[2017-10-11 17:01:15.922381 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Sending out the initial hand shake + kXR_protocol
[2017-10-11 17:01:15.922622 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Got the server hand shake response (type: manager [], protocol version 310)
[2017-10-11 17:01:15.922642 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] kXR_protocol successful (type: manager [], protocol version 310)
[2017-10-11 17:01:15.922749 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Sending out kXR_login request, username: ganis, cgi: ?xrd.cc=us&xrd.tz=1&xrd.appname=root.exe&xrd.info=&xrd.hostname=pcphsft64&xrd.rn=v4.6.1, dual-stack: false, private IPv4: true, private IPv6: false
[2017-10-11 17:01:15.923005 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Logged in, session: 37052a00a36c0000bf0d0000fd052a00
[2017-10-11 17:01:15.923036 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Authentication is required: &P=krb5,xrootd/eoslhcb.cern.ch@CERN.CH&P=gsi,v:10300,c:ssl,ca:5168735f.0|4339b4bc.0&P=unix&P=sss,0.13:/etc/eos.keytab
[2017-10-11 17:01:15.923045 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Sending authentication data
[2017-10-11 17:01:15.923932 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Trying to authenticate using krb5
[2017-10-11 17:01:15.924093 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Cannot get credentials for protocol krb5: Seckrb5: No or invalid credentials; No credentials cache found (p=xrootd/eoslhcb.cern.ch@CERN.CH).
[2017-10-11 17:01:15.925168 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Trying to authenticate using gsi
[2017-10-11 17:01:15.945509 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Sending more authentication data for gsi
[2017-10-11 17:01:15.948701 +0200][Error  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Authentication with gsi failed:
[2017-10-11 17:01:15.948822 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Trying to authenticate using unix
[2017-10-11 17:01:15.949341 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Authenticated with unix.
[2017-10-11 17:01:15.949358 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Stream 0 connected.
[2017-10-11 17:01:15.949366 +0200][Debug  ][Utility           ] Monitor library name not set. No monitoring
[2017-10-11 17:01:15.949798 +0200][Debug  ][XRootD            ] [eoslhcb.cern.ch:1094] Handling error while processing kXR_stat (path: eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, flags: none): [ERROR] Error response: Permission denied.
root [0]
Attaching file root://eoslhcb.cern.ch/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root as _file0...
[2017-10-11 17:01:16.044643 +0200][Debug  ][Utility           ] Env: overriding entry: MultiProtocol=0 with 1
[2017-10-11 17:01:16.044734 +0200][Debug  ][File              ] [0x313ce60@root://eoslhcb.cern.ch:1094/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] Sending an open command
[2017-10-11 17:01:16.045176 +0200][Debug  ][XRootD            ] [eoslhcb.cern.ch:1094] Handling error while processing kXR_open (file: eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ): [ERROR] Error response: Permission denied.
[2017-10-11 17:01:16.045233 +0200][Debug  ][File              ] [0x313ce60@root://eoslhcb.cern.ch:1094/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] Open has returned with status [ERROR] Server responded with an error: [3010] Opening relative path 'eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root' is disallowed.
[2017-10-11 17:01:16.045243 +0200][Debug  ][File              ] [0x313ce60@root://eoslhcb.cern.ch:1094/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] Error while opening at eoslhcb.cern.ch:1094: [ERROR] Server responded with an error: [3010] Opening relative path 'eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root' is disallowed.
Error in <TNetXNGFile::Open>: [ERROR] Server responded with an error: [3010] Opening relative path 'eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root' is disallowed.

(TFile *) nullptr
root [1]

(In my case it fails because I am not allowed, but you see that the socket is open).

G Ganis

mwilkins · October 12, 2017, 7:35am

Ah–for whatever reason it gave the output this time:

$ root -l root://eoslhcb.cern.ch/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root
[2017-10-12 09:34:41.606091 +0200][Warning][Utility           ] Unable to process global config file: [ERROR] OS Error: No such file or directory
[2017-10-12 09:34:41.606290 +0200][Debug  ][Utility           ] Unable to process user config file: [ERROR] OS Error: No such file or directory
[2017-10-12 09:34:41.607112 +0200][Debug  ][PlugInMgr         ] Initializing plug-in manager...
[2017-10-12 09:34:41.607168 +0200][Debug  ][PlugInMgr         ] No default plug-in, loading plug-in configs...
[2017-10-12 09:34:41.607180 +0200][Debug  ][PlugInMgr         ] Processing plug-in definitions in /etc/xrootd/client.plugins.d...
[2017-10-12 09:34:41.607216 +0200][Debug  ][PlugInMgr         ] Unable to process directory /etc/xrootd/client.plugins.d: [ERROR] OS Error: No such file or directory
[2017-10-12 09:34:41.607235 +0200][Debug  ][PlugInMgr         ] Processing plug-in definitions in /Users/michael/.xrootd/client.plugins.d...
[2017-10-12 09:34:41.607264 +0200][Debug  ][PlugInMgr         ] Unable to process directory /Users/michael/.xrootd/client.plugins.d: [ERROR] OS Error: No such file or directory
[2017-10-12 09:34:41.607272 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSeckrb5.so
[2017-10-12 09:34:41.609980 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsi.so
[2017-10-12 09:34:41.617449 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsiAuthzVO.so
[2017-10-12 09:34:41.620075 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsiGMAPDN.so
[2017-10-12 09:34:41.623408 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecpwd.so
[2017-10-12 09:34:41.626222 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecsss.so
[2017-10-12 09:34:41.629311 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecunix.so
[2017-10-12 09:34:41.682169 +0200][Debug  ][Poller            ] Available pollers: built-in
[2017-10-12 09:34:41.682204 +0200][Debug  ][Poller            ] Attempting to create a poller according to preference: built-in
[2017-10-12 09:34:41.682215 +0200][Debug  ][Poller            ] Creating poller: built-in
[2017-10-12 09:34:41.682223 +0200][Debug  ][Poller            ] Creating and starting the built-in poller...
[2017-10-12 09:34:41.682456 +0200][Debug  ][Poller            ] Using 1 poller threads
[2017-10-12 09:34:41.682488 +0200][Debug  ][TaskMgr           ] Starting the task manager...
[2017-10-12 09:34:41.682551 +0200][Debug  ][TaskMgr           ] Task manager started
[2017-10-12 09:34:41.682572 +0200][Debug  ][JobMgr            ] Starting the job manager...
[2017-10-12 09:34:41.682657 +0200][Debug  ][JobMgr            ] Job manager started, 3 workers
[2017-10-12 09:34:41.682699 +0200][Debug  ][TaskMgr           ] Registering task: "FileTimer task" to be run at: [2017-10-12 09:34:41 +0200]
[2017-10-12 09:34:41.682731 +0200][Debug  ][PostMaster        ] Creating new channel to: eoslhcb.cern.ch:1094 1 stream(s)
[2017-10-12 09:34:41.682750 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Stream parameters: Network Stack: IPAuto, Connection Window: 120, ConnectionRetry: 5, Stream Error Widnow: 1800
[2017-10-12 09:34:41.683611 +0200][Debug  ][TaskMgr           ] Registering task: "TickGeneratorTask for: eoslhcb.cern.ch:1094" to be run at: [2017-10-12 09:34:56 +0200]
[2017-10-12 09:34:41.692108 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094] Found 2 address(es): [2001:1458:201:c0::100:c]:1094, [::ffff:188.184.38.44]:1094
[2017-10-12 09:34:41.692338 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Attempting connection to [2001:1458:201:c0::100:c]:1094
[2017-10-12 09:34:41.692549 +0200][Error  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Unable to initiate the connection: [ERROR] Socket error: No route to host
[2017-10-12 09:34:41.692600 +0200][Error  ][XRootD            ] [eoslhcb.cern.ch:1094] Unable to send the message kXR_stat (path: eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, flags: none): [FATAL] Socket error: No route to host
root [0] 
Attaching file root://eoslhcb.cern.ch/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root as _file0...
[2017-10-12 09:34:41.877857 +0200][Debug  ][Utility           ] Env: overriding entry: MultiProtocol=0 with 1
[2017-10-12 09:34:41.877945 +0200][Debug  ][File              ] [0x802147c0@root://eoslhcb.cern.ch:1094/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] Sending an open command
[2017-10-12 09:34:41.878652 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094] Found 2 address(es): [2001:1458:201:c0::100:c]:1094, [::ffff:188.184.38.44]:1094
[2017-10-12 09:34:41.878680 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Attempting connection to [2001:1458:201:c0::100:c]:1094
[2017-10-12 09:34:41.878710 +0200][Error  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Unable to initiate the connection: [ERROR] Socket error: No route to host
[2017-10-12 09:34:41.878719 +0200][Error  ][XRootD            ] [eoslhcb.cern.ch:1094] Unable to send the message kXR_open (file: eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ): [FATAL] Socket error: No route to host
Error in <TNetXNGFile::Open>: [FATAL] Socket error: No route to host
[2017-10-12 09:34:41.878840 +0200][Debug  ][Utility           ] Monitor library name not set. No monitoring
(TFile *) nullptr
root [1] .q
[2017-10-12 09:34:45.036262 +0200][Debug  ][JobMgr            ] Stopping the job manager...
[2017-10-12 09:34:45.036462 +0200][Debug  ][JobMgr            ] Job manager stopped
[2017-10-12 09:34:45.036479 +0200][Debug  ][TaskMgr           ] Stopping the task manager...
[2017-10-12 09:34:45.036518 +0200][Debug  ][TaskMgr           ] Task manager stopped
[2017-10-12 09:34:45.036535 +0200][Debug  ][Poller            ] Stopping the poller...
[2017-10-12 09:34:45.036635 +0200][Debug  ][TaskMgr           ] Requesting unregistration of: "TickGeneratorTask for: eoslhcb.cern.ch:1094"
[2017-10-12 09:34:45.036648 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Closing the socket
[2017-10-12 09:34:45.036656 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Destroying stream
[2017-10-12 09:34:45.036662 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Closing the socket

ganis · October 12, 2017, 8:35am

Looks like it using only the IPv6 address. Can you try by forcing to use IPv4 with

 export XRD_NETWORKSTACK="IPv4"

?

G Ganis

Ps: of course, if this is the reason, it looks like a bug, which I will report …

mwilkins · October 12, 2017, 9:23am

Yup. That seems to be the case. But it’s now giving me the same error it gave you and I have to figure out why I’m not allowed to open my own file…

$ root -l root://eoslhcb.cern.ch//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root
[2017-10-12 11:22:00.078553 +0200][Warning][Utility           ] Unable to process global config file: [ERROR] OS Error: No such file or directory
[2017-10-12 11:22:00.078681 +0200][Debug  ][Utility           ] Unable to process user config file: [ERROR] OS Error: No such file or directory
[2017-10-12 11:22:00.078734 +0200][Info   ][Utility           ] Env: Importing from shell XRD_NETWORKSTACK=IPv4 as NetworkStack
[2017-10-12 11:22:00.078757 +0200][Debug  ][PlugInMgr         ] Initializing plug-in manager...
[2017-10-12 11:22:00.078773 +0200][Debug  ][PlugInMgr         ] No default plug-in, loading plug-in configs...
[2017-10-12 11:22:00.078779 +0200][Debug  ][PlugInMgr         ] Processing plug-in definitions in /etc/xrootd/client.plugins.d...
[2017-10-12 11:22:00.078793 +0200][Debug  ][PlugInMgr         ] Unable to process directory /etc/xrootd/client.plugins.d: [ERROR] OS Error: No such file or directory
[2017-10-12 11:22:00.078799 +0200][Debug  ][PlugInMgr         ] Processing plug-in definitions in /Users/michael/.xrootd/client.plugins.d...
[2017-10-12 11:22:00.078805 +0200][Debug  ][PlugInMgr         ] Unable to process directory /Users/michael/.xrootd/client.plugins.d: [ERROR] OS Error: No such file or directory
[2017-10-12 11:22:00.078810 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSeckrb5.so
[2017-10-12 11:22:00.079617 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsi.so
[2017-10-12 11:22:00.080765 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsiAuthzVO.so
[2017-10-12 11:22:00.081715 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsiGMAPDN.so
[2017-10-12 11:22:00.082690 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecpwd.so
[2017-10-12 11:22:00.083595 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecsss.so
[2017-10-12 11:22:00.084450 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecunix.so
[2017-10-12 11:22:00.108430 +0200][Debug  ][Poller            ] Available pollers: built-in
[2017-10-12 11:22:00.108449 +0200][Debug  ][Poller            ] Attempting to create a poller according to preference: built-in
[2017-10-12 11:22:00.108455 +0200][Debug  ][Poller            ] Creating poller: built-in
[2017-10-12 11:22:00.108477 +0200][Debug  ][Poller            ] Creating and starting the built-in poller...
[2017-10-12 11:22:00.108649 +0200][Debug  ][Poller            ] Using 1 poller threads
[2017-10-12 11:22:00.108661 +0200][Debug  ][TaskMgr           ] Starting the task manager...
[2017-10-12 11:22:00.108687 +0200][Debug  ][TaskMgr           ] Task manager started
[2017-10-12 11:22:00.108694 +0200][Debug  ][JobMgr            ] Starting the job manager...
[2017-10-12 11:22:00.108724 +0200][Debug  ][JobMgr            ] Job manager started, 3 workers
[2017-10-12 11:22:00.108736 +0200][Debug  ][TaskMgr           ] Registering task: "FileTimer task" to be run at: [2017-10-12 11:22:00 +0200]
[2017-10-12 11:22:00.108787 +0200][Debug  ][PostMaster        ] Creating new channel to: eoslhcb.cern.ch:1094 1 stream(s)
[2017-10-12 11:22:00.108799 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Stream parameters: Network Stack: IPv4, Connection Window: 120, ConnectionRetry: 5, Stream Error Widnow: 1800
[2017-10-12 11:22:00.109596 +0200][Debug  ][TaskMgr           ] Registering task: "TickGeneratorTask for: eoslhcb.cern.ch:1094" to be run at: [2017-10-12 11:22:15 +0200]
[2017-10-12 11:22:00.112370 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094] Found 1 address(es): [::ffff:188.184.38.44]:1094
[2017-10-12 11:22:00.112483 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Attempting connection to [::ffff:188.184.38.44]:1094
[2017-10-12 11:22:00.112625 +0200][Debug  ][Poller            ] Adding socket 0x92a33c80 to the poller
[2017-10-12 11:22:00.113879 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Async connection call returned
[2017-10-12 11:22:00.113943 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Sending out the initial hand shake + kXR_protocol
[2017-10-12 11:22:00.115497 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Got the server hand shake response (type: manager [], protocol version 310)
[2017-10-12 11:22:00.115518 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] kXR_protocol successful (type: manager [], protocol version 310)
[2017-10-12 11:22:00.117251 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Sending out kXR_login request, username: michael, cgi: ?xrd.cc=ch&xrd.tz=1&xrd.appname=root.exe&xrd.info=&xrd.hostname=michaelsmacbookpro.dyndns.cern.ch&xrd.rn=v4.6.1, dual-stack: false, private IPv4: false, private IPv6: false
[2017-10-12 11:22:00.118702 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Logged in, session: 0ad72c00a36c0000ed060000d1d72c00
[2017-10-12 11:22:00.118717 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Authentication is required: &P=krb5,xrootd/eoslhcb.cern.ch@CERN.CH&P=gsi,v:10300,c:ssl,ca:5168735f.0|4339b4bc.0&P=unix&P=sss,0.13:/etc/eos.keytab
[2017-10-12 11:22:00.118726 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Sending authentication data
[2017-10-12 11:22:00.119838 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Trying to authenticate using krb5
[2017-10-12 11:22:00.134703 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Cannot get credentials for protocol krb5: Seckrb5: No or invalid credentials; No credentials cache file found (p=xrootd/eoslhcb.cern.ch@CERN.CH).
Plugin version SecClnt v4.6.1 is incompatible with secgsi v4.7.0 (must be <= 4.6.x) in sec.protocol libXrdSecgsi-4.so
[2017-10-12 11:22:00.134899 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Trying to authenticate using unix
[2017-10-12 11:22:00.136858 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Authenticated with unix.
[2017-10-12 11:22:00.136934 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Stream 0 connected.
[2017-10-12 11:22:00.136964 +0200][Debug  ][Utility           ] Monitor library name not set. No monitoring
root [0] 
Attaching file root://eoslhcb.cern.ch//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root as _file0...
[2017-10-12 11:22:00.253681 +0200][Debug  ][Utility           ] Env: overriding entry: MultiProtocol=0 with 1
[2017-10-12 11:22:00.253764 +0200][Debug  ][File              ] [0x9068f4b0@root://eoslhcb.cern.ch:1094//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] Sending an open command
[2017-10-12 11:22:00.257165 +0200][Debug  ][XRootD            ] [eoslhcb.cern.ch:1094] Handling error while processing kXR_open (file: /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ): [ERROR] Error response: Permission denied.
[2017-10-12 11:22:00.257214 +0200][Debug  ][File              ] [0x9068f4b0@root://eoslhcb.cern.ch:1094//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] Open has returned with status [ERROR] Server responded with an error: [3010] Unable to open file /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root; Operation not permitted
[2017-10-12 11:22:00.257233 +0200][Debug  ][File              ] [0x9068f4b0@root://eoslhcb.cern.ch:1094//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] Error while opening at eoslhcb.cern.ch:1094: [ERROR] Server responded with an error: [3010] Unable to open file /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root; Operation not permitted
Error in <TNetXNGFile::Open>: [ERROR] Server responded with an error: [3010] Unable to open file /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root; Operation not permitted

(TFile *) nullptr
root [1] .q
[2017-10-12 11:22:07.326588 +0200][Debug  ][JobMgr            ] Stopping the job manager...
[2017-10-12 11:22:07.326804 +0200][Debug  ][JobMgr            ] Job manager stopped
[2017-10-12 11:22:07.326827 +0200][Debug  ][TaskMgr           ] Stopping the task manager...
[2017-10-12 11:22:07.326872 +0200][Debug  ][TaskMgr           ] Task manager stopped
[2017-10-12 11:22:07.326887 +0200][Debug  ][Poller            ] Stopping the poller...
[2017-10-12 11:22:07.326970 +0200][Debug  ][TaskMgr           ] Requesting unregistration of: "TickGeneratorTask for: eoslhcb.cern.ch:1094"
[2017-10-12 11:22:07.326990 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Closing the socket
[2017-10-12 11:22:07.327000 +0200][Debug  ][Poller            ] <[::ffff:128.141.131.193]:57009><--><[::ffff:188.184.38.44]:1094> Removing socket from the poller
[2017-10-12 11:22:07.327165 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Destroying stream
[2017-10-12 11:22:07.327181 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Closing the socket

ganis · October 12, 2017, 9:57am

It tries to connect as ‘michael’

Can you try to force login as mwilkins, your CERN username:

  root -l root://mwilkins@eoslhcb.cern.ch//eos/lhcb/...

?

mwilkins · October 12, 2017, 11:42am

Same thing:

$ root -l root://mwilkins@eoslhcb.cern.ch//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root
[2017-10-12 13:41:47.020211 +0200][Warning][Utility           ] Unable to process global config file: [ERROR] OS Error: No such file or directory
[2017-10-12 13:41:47.020273 +0200][Debug  ][Utility           ] Unable to process user config file: [ERROR] OS Error: No such file or directory
[2017-10-12 13:41:47.020329 +0200][Info   ][Utility           ] Env: Importing from shell XRD_NETWORKSTACK=IPv4 as NetworkStack
[2017-10-12 13:41:47.020357 +0200][Debug  ][PlugInMgr         ] Initializing plug-in manager...
[2017-10-12 13:41:47.020373 +0200][Debug  ][PlugInMgr         ] No default plug-in, loading plug-in configs...
[2017-10-12 13:41:47.020380 +0200][Debug  ][PlugInMgr         ] Processing plug-in definitions in /etc/xrootd/client.plugins.d...
[2017-10-12 13:41:47.020410 +0200][Debug  ][PlugInMgr         ] Unable to process directory /etc/xrootd/client.plugins.d: [ERROR] OS Error: No such file or directory
[2017-10-12 13:41:47.020426 +0200][Debug  ][PlugInMgr         ] Processing plug-in definitions in /Users/michael/.xrootd/client.plugins.d...
[2017-10-12 13:41:47.020438 +0200][Debug  ][PlugInMgr         ] Unable to process directory /Users/michael/.xrootd/client.plugins.d: [ERROR] OS Error: No such file or directory
[2017-10-12 13:41:47.020445 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSeckrb5.so
[2017-10-12 13:41:47.021289 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsi.so
[2017-10-12 13:41:47.022497 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsiAuthzVO.so
[2017-10-12 13:41:47.023475 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsiGMAPDN.so
[2017-10-12 13:41:47.024440 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecpwd.so
[2017-10-12 13:41:47.025266 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecsss.so
[2017-10-12 13:41:47.026181 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecunix.so
[2017-10-12 13:41:47.051291 +0200][Debug  ][Poller            ] Available pollers: built-in
[2017-10-12 13:41:47.051317 +0200][Debug  ][Poller            ] Attempting to create a poller according to preference: built-in
[2017-10-12 13:41:47.051325 +0200][Debug  ][Poller            ] Creating poller: built-in
[2017-10-12 13:41:47.051331 +0200][Debug  ][Poller            ] Creating and starting the built-in poller...
[2017-10-12 13:41:47.051493 +0200][Debug  ][Poller            ] Using 1 poller threads
[2017-10-12 13:41:47.051508 +0200][Debug  ][TaskMgr           ] Starting the task manager...
[2017-10-12 13:41:47.051537 +0200][Debug  ][TaskMgr           ] Task manager started
[2017-10-12 13:41:47.051545 +0200][Debug  ][JobMgr            ] Starting the job manager...
[2017-10-12 13:41:47.051575 +0200][Debug  ][JobMgr            ] Job manager started, 3 workers
[2017-10-12 13:41:47.051587 +0200][Debug  ][TaskMgr           ] Registering task: "FileTimer task" to be run at: [2017-10-12 13:41:47 +0200]
[2017-10-12 13:41:47.051609 +0200][Debug  ][PostMaster        ] Creating new channel to: mwilkins@eoslhcb.cern.ch:1094 1 stream(s)
[2017-10-12 13:41:47.051622 +0200][Debug  ][PostMaster        ] [mwilkins@eoslhcb.cern.ch:1094 #0] Stream parameters: Network Stack: IPv4, Connection Window: 120, ConnectionRetry: 5, Stream Error Widnow: 1800
[2017-10-12 13:41:47.052464 +0200][Debug  ][TaskMgr           ] Registering task: "TickGeneratorTask for: mwilkins@eoslhcb.cern.ch:1094" to be run at: [2017-10-12 13:42:02 +0200]
[2017-10-12 13:41:47.052710 +0200][Debug  ][PostMaster        ] [mwilkins@eoslhcb.cern.ch:1094] Found 1 address(es): [::ffff:188.184.38.44]:1094
[2017-10-12 13:41:47.052756 +0200][Debug  ][AsyncSock         ] [mwilkins@eoslhcb.cern.ch:1094 #0.0] Attempting connection to [::ffff:188.184.38.44]:1094
[2017-10-12 13:41:47.052878 +0200][Debug  ][Poller            ] Adding socket 0x21c9d6a0 to the poller
[2017-10-12 13:41:47.108544 +0200][Debug  ][AsyncSock         ] [mwilkins@eoslhcb.cern.ch:1094 #0.0] Async connection call returned
[2017-10-12 13:41:47.108757 +0200][Debug  ][XRootDTransport   ] [mwilkins@eoslhcb.cern.ch:1094 #0.0] Sending out the initial hand shake + kXR_protocol
[2017-10-12 13:41:47.110624 +0200][Debug  ][XRootDTransport   ] [mwilkins@eoslhcb.cern.ch:1094 #0.0] Got the server hand shake response (type: manager [], protocol version 310)
[2017-10-12 13:41:47.110697 +0200][Debug  ][XRootDTransport   ] [mwilkins@eoslhcb.cern.ch:1094 #0.0] kXR_protocol successful (type: manager [], protocol version 310)
[2017-10-12 13:41:47.114371 +0200][Debug  ][XRootDTransport   ] [mwilkins@eoslhcb.cern.ch:1094 #0.0] Sending out kXR_login request, username: mwilkins, cgi: ?xrd.cc=ch&xrd.tz=1&xrd.appname=root.exe&xrd.info=&xrd.hostname=michaelsmacbookpro.dyndns.cern.ch&xrd.rn=v4.6.1, dual-stack: false, private IPv4: false, private IPv6: false
[2017-10-12 13:41:47.121307 +0200][Debug  ][XRootDTransport   ] [mwilkins@eoslhcb.cern.ch:1094 #0.0] Logged in, session: b8302d00a36c0000830300007f312d00
[2017-10-12 13:41:47.121382 +0200][Debug  ][XRootDTransport   ] [mwilkins@eoslhcb.cern.ch:1094 #0.0] Authentication is required: &P=krb5,xrootd/eoslhcb.cern.ch@CERN.CH&P=gsi,v:10300,c:ssl,ca:5168735f.0|4339b4bc.0&P=unix&P=sss,0.13:/etc/eos.keytab
[2017-10-12 13:41:47.121412 +0200][Debug  ][XRootDTransport   ] [mwilkins@eoslhcb.cern.ch:1094 #0.0] Sending authentication data
[2017-10-12 13:41:47.123651 +0200][Debug  ][XRootDTransport   ] [mwilkins@eoslhcb.cern.ch:1094 #0.0] Trying to authenticate using krb5
[2017-10-12 13:41:47.138358 +0200][Debug  ][XRootDTransport   ] [mwilkins@eoslhcb.cern.ch:1094 #0.0] Cannot get credentials for protocol krb5: Seckrb5: No or invalid credentials; No credentials cache file found (p=xrootd/eoslhcb.cern.ch@CERN.CH).
Plugin version SecClnt v4.6.1 is incompatible with secgsi v4.7.0 (must be <= 4.6.x) in sec.protocol libXrdSecgsi-4.so
[2017-10-12 13:41:47.138453 +0200][Debug  ][XRootDTransport   ] [mwilkins@eoslhcb.cern.ch:1094 #0.0] Trying to authenticate using unix
[2017-10-12 13:41:47.195092 +0200][Debug  ][XRootDTransport   ] [mwilkins@eoslhcb.cern.ch:1094 #0.0] Authenticated with unix.
[2017-10-12 13:41:47.195281 +0200][Debug  ][PostMaster        ] [mwilkins@eoslhcb.cern.ch:1094 #0] Stream 0 connected.
[2017-10-12 13:41:47.195331 +0200][Debug  ][Utility           ] Monitor library name not set. No monitoring
root [0] 
Attaching file root://mwilkins@eoslhcb.cern.ch//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root as _file0...
[2017-10-12 13:41:47.555409 +0200][Debug  ][Utility           ] Env: overriding entry: MultiProtocol=0 with 1
[2017-10-12 13:41:47.555482 +0200][Debug  ][File              ] [0x21cd4100@root://mwilkins@eoslhcb.cern.ch:1094//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] Sending an open command
[2017-10-12 13:41:47.560522 +0200][Debug  ][XRootD            ] [mwilkins@eoslhcb.cern.ch:1094] Handling error while processing kXR_open (file: /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ): [ERROR] Error response: Permission denied.
[2017-10-12 13:41:47.560637 +0200][Debug  ][File              ] [0x21cd4100@root://mwilkins@eoslhcb.cern.ch:1094//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] Open has returned with status [ERROR] Server responded with an error: [3010] Unable to open file /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root; Operation not permitted
[2017-10-12 13:41:47.560682 +0200][Debug  ][File              ] [0x21cd4100@root://mwilkins@eoslhcb.cern.ch:1094//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] Error while opening at mwilkins@eoslhcb.cern.ch:1094: [ERROR] Server responded with an error: [3010] Unable to open file /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root; Operation not permitted
Error in <TNetXNGFile::Open>: [ERROR] Server responded with an error: [3010] Unable to open file /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root; Operation not permitted

(TFile *) nullptr
root [1] .q
[2017-10-12 13:42:01.376438 +0200][Debug  ][JobMgr            ] Stopping the job manager...
[2017-10-12 13:42:01.376834 +0200][Debug  ][JobMgr            ] Job manager stopped
[2017-10-12 13:42:01.376881 +0200][Debug  ][TaskMgr           ] Stopping the task manager...
[2017-10-12 13:42:01.376974 +0200][Debug  ][TaskMgr           ] Task manager stopped
[2017-10-12 13:42:01.377014 +0200][Debug  ][Poller            ] Stopping the poller...
[2017-10-12 13:42:01.377148 +0200][Debug  ][TaskMgr           ] Requesting unregistration of: "TickGeneratorTask for: mwilkins@eoslhcb.cern.ch:1094"
[2017-10-12 13:42:01.377198 +0200][Debug  ][AsyncSock         ] [mwilkins@eoslhcb.cern.ch:1094 #0.0] Closing the socket
[2017-10-12 13:42:01.377215 +0200][Debug  ][Poller            ] <[::ffff:128.141.169.92]:59062><--><[::ffff:188.184.38.44]:1094> Removing socket from the poller
[2017-10-12 13:42:01.377385 +0200][Debug  ][PostMaster        ] [mwilkins@eoslhcb.cern.ch:1094 #0] Destroying stream
[2017-10-12 13:42:01.377446 +0200][Debug  ][AsyncSock         ] [mwilkins@eoslhcb.cern.ch:1094 #0.0] Closing the socket

mwilkins · October 12, 2017, 11:44am

Ah–my kinit had expired. If I kinit first, it works!

$ root -l root://eoslhcb.cern.ch//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root
[2017-10-12 13:43:59.953835 +0200][Warning][Utility           ] Unable to process global config file: [ERROR] OS Error: No such file or directory
[2017-10-12 13:43:59.953975 +0200][Debug  ][Utility           ] Unable to process user config file: [ERROR] OS Error: No such file or directory
[2017-10-12 13:43:59.954061 +0200][Info   ][Utility           ] Env: Importing from shell XRD_NETWORKSTACK=IPv4 as NetworkStack
[2017-10-12 13:43:59.954095 +0200][Debug  ][PlugInMgr         ] Initializing plug-in manager...
[2017-10-12 13:43:59.954121 +0200][Debug  ][PlugInMgr         ] No default plug-in, loading plug-in configs...
[2017-10-12 13:43:59.954135 +0200][Debug  ][PlugInMgr         ] Processing plug-in definitions in /etc/xrootd/client.plugins.d...
[2017-10-12 13:43:59.954156 +0200][Debug  ][PlugInMgr         ] Unable to process directory /etc/xrootd/client.plugins.d: [ERROR] OS Error: No such file or directory
[2017-10-12 13:43:59.954181 +0200][Debug  ][PlugInMgr         ] Processing plug-in definitions in /Users/michael/.xrootd/client.plugins.d...
[2017-10-12 13:43:59.954199 +0200][Debug  ][PlugInMgr         ] Unable to process directory /Users/michael/.xrootd/client.plugins.d: [ERROR] OS Error: No such file or directory
[2017-10-12 13:43:59.954208 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSeckrb5.so
[2017-10-12 13:43:59.955333 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsi.so
[2017-10-12 13:43:59.956721 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsiAuthzVO.so
[2017-10-12 13:43:59.957670 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsiGMAPDN.so
[2017-10-12 13:43:59.958613 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecpwd.so
[2017-10-12 13:43:59.959456 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecsss.so
[2017-10-12 13:43:59.960319 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecunix.so
[2017-10-12 13:43:59.987903 +0200][Debug  ][Poller            ] Available pollers: built-in
[2017-10-12 13:43:59.987959 +0200][Debug  ][Poller            ] Attempting to create a poller according to preference: built-in
[2017-10-12 13:43:59.987983 +0200][Debug  ][Poller            ] Creating poller: built-in
[2017-10-12 13:43:59.987990 +0200][Debug  ][Poller            ] Creating and starting the built-in poller...
[2017-10-12 13:43:59.988146 +0200][Debug  ][Poller            ] Using 1 poller threads
[2017-10-12 13:43:59.988159 +0200][Debug  ][TaskMgr           ] Starting the task manager...
[2017-10-12 13:43:59.988188 +0200][Debug  ][TaskMgr           ] Task manager started
[2017-10-12 13:43:59.988195 +0200][Debug  ][JobMgr            ] Starting the job manager...
[2017-10-12 13:43:59.988231 +0200][Debug  ][JobMgr            ] Job manager started, 3 workers
[2017-10-12 13:43:59.988242 +0200][Debug  ][TaskMgr           ] Registering task: "FileTimer task" to be run at: [2017-10-12 13:43:59 +0200]
[2017-10-12 13:43:59.988259 +0200][Debug  ][PostMaster        ] Creating new channel to: eoslhcb.cern.ch:1094 1 stream(s)
[2017-10-12 13:43:59.988270 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Stream parameters: Network Stack: IPv4, Connection Window: 120, ConnectionRetry: 5, Stream Error Widnow: 1800
[2017-10-12 13:43:59.989510 +0200][Debug  ][TaskMgr           ] Registering task: "TickGeneratorTask for: eoslhcb.cern.ch:1094" to be run at: [2017-10-12 13:44:14 +0200]
[2017-10-12 13:43:59.990140 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094] Found 1 address(es): [::ffff:188.184.38.44]:1094
[2017-10-12 13:43:59.990219 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Attempting connection to [::ffff:188.184.38.44]:1094
[2017-10-12 13:43:59.990337 +0200][Debug  ][Poller            ] Adding socket 0xd26f9ae0 to the poller
[2017-10-12 13:44:00.006571 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Async connection call returned
[2017-10-12 13:44:00.006764 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Sending out the initial hand shake + kXR_protocol
[2017-10-12 13:44:00.007821 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Got the server hand shake response (type: manager [], protocol version 310)
[2017-10-12 13:44:00.007855 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] kXR_protocol successful (type: manager [], protocol version 310)
[2017-10-12 13:44:00.009673 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Sending out kXR_login request, username: michael, cgi: ?xrd.cc=ch&xrd.tz=1&xrd.appname=root.exe&xrd.info=&xrd.hostname=michaelsmacbookpro.dyndns.cern.ch&xrd.rn=v4.6.1, dual-stack: false, private IPv4: false, private IPv6: false
[2017-10-12 13:44:00.011012 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Logged in, session: c0312d00a36c0000a904000087322d00
[2017-10-12 13:44:00.011035 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Authentication is required: &P=krb5,xrootd/eoslhcb.cern.ch@CERN.CH&P=gsi,v:10300,c:ssl,ca:5168735f.0|4339b4bc.0&P=unix&P=sss,0.13:/etc/eos.keytab
[2017-10-12 13:44:00.011045 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Sending authentication data
[2017-10-12 13:44:00.012580 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Trying to authenticate using krb5
[2017-10-12 13:44:00.038605 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Authenticated with krb5.
[2017-10-12 13:44:00.038694 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Stream 0 connected.
[2017-10-12 13:44:00.038708 +0200][Debug  ][Utility           ] Monitor library name not set. No monitoring
root [0] 
Attaching file root://eoslhcb.cern.ch//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root as _file0...
[2017-10-12 13:44:00.185783 +0200][Debug  ][Utility           ] Env: overriding entry: MultiProtocol=0 with 1
[2017-10-12 13:44:00.185857 +0200][Debug  ][File              ] [0xd4a42720@root://eoslhcb.cern.ch:1094//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] Sending an open command
[2017-10-12 13:44:00.188332 +0200][Debug  ][PostMaster        ] Creating new channel to: p05153074065039.cern.ch:1095 1 stream(s)
[2017-10-12 13:44:00.188359 +0200][Debug  ][PostMaster        ] [p05153074065039.cern.ch:1095 #0] Stream parameters: Network Stack: IPv4, Connection Window: 120, ConnectionRetry: 5, Stream Error Widnow: 1800
[2017-10-12 13:44:00.189256 +0200][Debug  ][TaskMgr           ] Registering task: "TickGeneratorTask for: p05153074065039.cern.ch:1095" to be run at: [2017-10-12 13:44:15 +0200]
[2017-10-12 13:44:00.189577 +0200][Debug  ][PostMaster        ] [p05153074065039.cern.ch:1095] Found 1 address(es): [::ffff:128.142.24.12]:1095
[2017-10-12 13:44:00.189612 +0200][Debug  ][AsyncSock         ] [p05153074065039.cern.ch:1095 #0.0] Attempting connection to [::ffff:128.142.24.12]:1095
[2017-10-12 13:44:00.189670 +0200][Debug  ][Poller            ] Adding socket 0xd2549df0 to the poller
[2017-10-12 13:44:00.191887 +0200][Debug  ][AsyncSock         ] [p05153074065039.cern.ch:1095 #0.0] Async connection call returned
[2017-10-12 13:44:00.191932 +0200][Debug  ][XRootDTransport   ] [p05153074065039.cern.ch:1095 #0.0] Sending out the initial hand shake + kXR_protocol
[2017-10-12 13:44:00.201120 +0200][Debug  ][XRootDTransport   ] [p05153074065039.cern.ch:1095 #0.0] Got the server hand shake response (type: server [], protocol version 310)
[2017-10-12 13:44:00.201210 +0200][Debug  ][XRootDTransport   ] [p05153074065039.cern.ch:1095 #0.0] kXR_protocol successful (type: server [], protocol version 310)
[2017-10-12 13:44:00.204085 +0200][Debug  ][XRootDTransport   ] [p05153074065039.cern.ch:1095 #0.0] Sending out kXR_login request, username: michael, cgi: ?xrd.cc=ch&xrd.tz=1&xrd.appname=root.exe&xrd.info=&xrd.hostname=michaelsmacbookpro.dyndns.cern.ch&xrd.rn=v4.6.1, dual-stack: false, private IPv4: false, private IPv6: false
[2017-10-12 13:44:00.205469 +0200][Debug  ][XRootDTransport   ] [p05153074065039.cern.ch:1095 #0.0] Logged in, session: a6640100c71f0000b8000000a6640100
[2017-10-12 13:44:00.205548 +0200][Debug  ][XRootDTransport   ] [p05153074065039.cern.ch:1095 #0.0] Authentication is required: &P=unix&P=sss,0.13:/etc/eos.keytab
[2017-10-12 13:44:00.205580 +0200][Debug  ][XRootDTransport   ] [p05153074065039.cern.ch:1095 #0.0] Sending authentication data
[2017-10-12 13:44:00.205750 +0200][Debug  ][XRootDTransport   ] [p05153074065039.cern.ch:1095 #0.0] Trying to authenticate using unix
[2017-10-12 13:44:00.208326 +0200][Debug  ][XRootDTransport   ] [p05153074065039.cern.ch:1095 #0.0] Authenticated with unix.
[2017-10-12 13:44:00.208394 +0200][Debug  ][PostMaster        ] [p05153074065039.cern.ch:1095 #0] Stream 0 connected.
[2017-10-12 13:44:00.215117 +0200][Debug  ][File              ] [0xd4a42720@root://eoslhcb.cern.ch:1094//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] Open has returned with status [SUCCESS] 
[2017-10-12 13:44:00.215185 +0200][Debug  ][File              ] [0xd4a42720@root://eoslhcb.cern.ch:1094//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] successfully opened at p05153074065039.cern.ch:1095, handle: 0x0, session id: 1
[2017-10-12 13:44:00.215336 +0200][Debug  ][File              ] [0xd4a42720@root://eoslhcb.cern.ch:1094//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] Sending a read command for handle 0x0 to p05153074065039.cern.ch:1095
[2017-10-12 13:44:00.220366 +0200][Debug  ][File              ] [0xd4a42720@root://eoslhcb.cern.ch:1094//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] Sending a read command for handle 0x0 to p05153074065039.cern.ch:1095
[2017-10-12 13:44:00.221736 +0200][Debug  ][File              ] [0xd4a42720@root://eoslhcb.cern.ch:1094//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] Sending a read command for handle 0x0 to p05153074065039.cern.ch:1095
(TFile *) 0x7fa4d4a4e500
root [1] .q
[2017-10-12 13:44:01.312285 +0200][Debug  ][File              ] [0xd4a42720@root://eoslhcb.cern.ch:1094//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] Sending a close command for handle 0x0 to p05153074065039.cern.ch:1095
[2017-10-12 13:44:01.329142 +0200][Debug  ][File              ] [0xd4a42720@root://eoslhcb.cern.ch:1094//eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root] Close returned from p05153074065039.cern.ch:1095 with: [SUCCESS] 
[2017-10-12 13:44:01.332328 +0200][Debug  ][JobMgr            ] Stopping the job manager...
[2017-10-12 13:44:01.332458 +0200][Debug  ][JobMgr            ] Job manager stopped
[2017-10-12 13:44:01.332474 +0200][Debug  ][TaskMgr           ] Stopping the task manager...
[2017-10-12 13:44:01.332505 +0200][Debug  ][TaskMgr           ] Task manager stopped
[2017-10-12 13:44:01.332515 +0200][Debug  ][Poller            ] Stopping the poller...
[2017-10-12 13:44:01.332600 +0200][Debug  ][TaskMgr           ] Requesting unregistration of: "TickGeneratorTask for: eoslhcb.cern.ch:1094"
[2017-10-12 13:44:01.332611 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Closing the socket
[2017-10-12 13:44:01.332619 +0200][Debug  ][Poller            ] <[::ffff:128.141.169.92]:59118><--><[::ffff:188.184.38.44]:1094> Removing socket from the poller
[2017-10-12 13:44:01.332740 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Destroying stream
[2017-10-12 13:44:01.332750 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Closing the socket
[2017-10-12 13:44:01.332763 +0200][Debug  ][TaskMgr           ] Requesting unregistration of: "TickGeneratorTask for: p05153074065039.cern.ch:1095"
[2017-10-12 13:44:01.332771 +0200][Debug  ][AsyncSock         ] [p05153074065039.cern.ch:1095 #0.0] Closing the socket
[2017-10-12 13:44:01.332778 +0200][Debug  ][Poller            ] <[::ffff:128.141.169.92]:59119><--><[::ffff:128.142.24.12]:1095> Removing socket from the poller
[2017-10-12 13:44:01.332799 +0200][Debug  ][PostMaster        ] [p05153074065039.cern.ch:1095 #0] Destroying stream
[2017-10-12 13:44:01.332807 +0200][Debug  ][AsyncSock         ] [p05153074065039.cern.ch:1095 #0.0] Closing the socket

Thanks much.

simonm · October 12, 2017, 12:23pm

Dear mwilkins,

Which version of XRootD client are you using?
Could you try to access the file with xrdfs:
xrdfs eoslhcb.cern.ch stat /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root
(please turn on the log messages: export XRD_LOGLEVEL=Dump)

Thanks,
Michal

mwilkins · October 12, 2017, 12:45pm

$ xrootd -v
v4.6.1

$ xrdfs eoslhcb.cern.ch stat /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root
[2017-10-12 14:43:32.393605 +0200][Warning][Utility           ] Unable to process global config file: [ERROR] OS Error: No such file or directory
[2017-10-12 14:43:32.394616 +0200][Debug  ][Utility           ] Unable to process user config file: [ERROR] OS Error: No such file or directory
[2017-10-12 14:43:32.394707 +0200][Info   ][Utility           ] Env: Importing from shell XRD_NETWORKSTACK=IPv4 as NetworkStack
[2017-10-12 14:43:32.394744 +0200][Debug  ][PlugInMgr         ] Initializing plug-in manager...
[2017-10-12 14:43:32.394758 +0200][Debug  ][PlugInMgr         ] No default plug-in, loading plug-in configs...
[2017-10-12 14:43:32.394762 +0200][Debug  ][PlugInMgr         ] Processing plug-in definitions in /etc/xrootd/client.plugins.d...
[2017-10-12 14:43:32.394786 +0200][Debug  ][PlugInMgr         ] Unable to process directory /etc/xrootd/client.plugins.d: [ERROR] OS Error: No such file or directory
[2017-10-12 14:43:32.394797 +0200][Debug  ][PlugInMgr         ] Processing plug-in definitions in /Users/michael/.xrootd/client.plugins.d...
[2017-10-12 14:43:32.394808 +0200][Debug  ][PlugInMgr         ] Unable to process directory /Users/michael/.xrootd/client.plugins.d: [ERROR] OS Error: No such file or directory
[2017-10-12 14:43:32.394815 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSeckrb5.so
[2017-10-12 14:43:32.401866 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsi.so
[2017-10-12 14:43:32.403511 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsiAuthzVO.so
[2017-10-12 14:43:32.405088 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsiGMAPDN.so
[2017-10-12 14:43:32.406333 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecpwd.so
[2017-10-12 14:43:32.407491 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecsss.so
[2017-10-12 14:43:32.408899 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecunix.so
[2017-10-12 14:43:32.415759 +0200][Dump   ][Utility           ] URL: eoslhcb.cern.ch
[2017-10-12 14:43:32.415759 +0200][Dump   ][Utility           ] Protocol:  root
[2017-10-12 14:43:32.415759 +0200][Dump   ][Utility           ] User Name: 
[2017-10-12 14:43:32.415759 +0200][Dump   ][Utility           ] Password:  
[2017-10-12 14:43:32.415759 +0200][Dump   ][Utility           ] Host Name: eoslhcb.cern.ch
[2017-10-12 14:43:32.415759 +0200][Dump   ][Utility           ] Port:      1094
[2017-10-12 14:43:32.415759 +0200][Dump   ][Utility           ] Path:      
[2017-10-12 14:43:32.416350 +0200][Dump   ][Utility           ] URL: root://eoslhcb.cern.ch:1094/
[2017-10-12 14:43:32.416350 +0200][Dump   ][Utility           ] Protocol:  root
[2017-10-12 14:43:32.416350 +0200][Dump   ][Utility           ] User Name: 
[2017-10-12 14:43:32.416350 +0200][Dump   ][Utility           ] Password:  
[2017-10-12 14:43:32.416350 +0200][Dump   ][Utility           ] Host Name: eoslhcb.cern.ch
[2017-10-12 14:43:32.416350 +0200][Dump   ][Utility           ] Port:      1094
[2017-10-12 14:43:32.416350 +0200][Dump   ][Utility           ] Path:      
[2017-10-12 14:43:32.416375 +0200][Dump   ][Utility           ] URL: root://eoslhcb.cern.ch:1094/
[2017-10-12 14:43:32.416375 +0200][Dump   ][Utility           ] Protocol:  root
[2017-10-12 14:43:32.416375 +0200][Dump   ][Utility           ] User Name: 
[2017-10-12 14:43:32.416375 +0200][Dump   ][Utility           ] Password:  
[2017-10-12 14:43:32.416375 +0200][Dump   ][Utility           ] Host Name: eoslhcb.cern.ch
[2017-10-12 14:43:32.416375 +0200][Dump   ][Utility           ] Port:      1094
[2017-10-12 14:43:32.416375 +0200][Dump   ][Utility           ] Path:      
[2017-10-12 14:43:32.416432 +0200][Debug  ][App               ] Executing: stat /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root 
[2017-10-12 14:43:32.416442 +0200][Dump   ][App               ] Param #00: 'stat'
[2017-10-12 14:43:32.416449 +0200][Dump   ][App               ] Param #01: '/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root'
[2017-10-12 14:43:32.416636 +0200][Dump   ][FileSystem        ] [0xd95034b0@eoslhcb.cern.ch:1094] Sending kXR_stat (path: /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, flags: none)
[2017-10-12 14:43:32.416655 +0200][Debug  ][Poller            ] Available pollers: built-in
[2017-10-12 14:43:32.416662 +0200][Debug  ][Poller            ] Attempting to create a poller according to preference: built-in
[2017-10-12 14:43:32.416670 +0200][Debug  ][Poller            ] Creating poller: built-in
[2017-10-12 14:43:32.416677 +0200][Debug  ][Poller            ] Creating and starting the built-in poller...
[2017-10-12 14:43:32.416868 +0200][Debug  ][Poller            ] Using 1 poller threads
[2017-10-12 14:43:32.416880 +0200][Debug  ][TaskMgr           ] Starting the task manager...
[2017-10-12 14:43:32.416911 +0200][Debug  ][TaskMgr           ] Task manager started
[2017-10-12 14:43:32.416918 +0200][Debug  ][JobMgr            ] Starting the job manager...
[2017-10-12 14:43:32.416947 +0200][Debug  ][JobMgr            ] Job manager started, 3 workers
[2017-10-12 14:43:32.416959 +0200][Debug  ][TaskMgr           ] Registering task: "FileTimer task" to be run at: [2017-10-12 14:43:32 +0200]
[2017-10-12 14:43:32.416967 +0200][Dump   ][XRootD            ] [eoslhcb.cern.ch:1094] Sending message kXR_stat (path: /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, flags: none)
[2017-10-12 14:43:32.416984 +0200][Dump   ][Utility           ] URL: eoslhcb.cern.ch:1094
[2017-10-12 14:43:32.416984 +0200][Dump   ][Utility           ] Protocol:  root
[2017-10-12 14:43:32.416984 +0200][Dump   ][Utility           ] User Name: 
[2017-10-12 14:43:32.416984 +0200][Dump   ][Utility           ] Password:  
[2017-10-12 14:43:32.416984 +0200][Dump   ][Utility           ] Host Name: eoslhcb.cern.ch
[2017-10-12 14:43:32.416984 +0200][Dump   ][Utility           ] Port:      1094
[2017-10-12 14:43:32.416984 +0200][Dump   ][Utility           ] Path:      
[2017-10-12 14:43:32.417002 +0200][Debug  ][PostMaster        ] Creating new channel to: eoslhcb.cern.ch:1094 1 stream(s)
[2017-10-12 14:43:32.417019 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Stream parameters: Network Stack: IPv4, Connection Window: 120, ConnectionRetry: 5, Stream Error Widnow: 1800
[2017-10-12 14:43:32.419647 +0200][Debug  ][TaskMgr           ] Registering task: "TickGeneratorTask for: eoslhcb.cern.ch:1094" to be run at: [2017-10-12 14:43:47 +0200]
[2017-10-12 14:43:32.419690 +0200][Dump   ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Sending message kXR_stat (path: /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, flags: none) (0xd97003e0) through substream 0 expecting answer at 0
[2017-10-12 14:43:32.421632 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094] Found 1 address(es): [::ffff:188.184.38.44]:1094
[2017-10-12 14:43:32.421740 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Attempting connection to [::ffff:188.184.38.44]:1094
[2017-10-12 14:43:32.421920 +0200][Debug  ][Poller            ] Adding socket 0xd9504280 to the poller
[2017-10-12 14:43:32.438530 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Async connection call returned
[2017-10-12 14:43:32.438726 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Sending out the initial hand shake + kXR_protocol
[2017-10-12 14:43:32.438971 +0200][Dump   ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Wrote a message:  (0xd9409ff0), 44 bytes
[2017-10-12 14:43:32.454598 +0200][Dump   ][XRootDTransport   ] [msg: 0xd97009b0] Expecting 8 bytes of message body
[2017-10-12 14:43:32.454723 +0200][Dump   ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Received message header, size: 8
[2017-10-12 14:43:32.454838 +0200][Dump   ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Received a message of 16 bytes
[2017-10-12 14:43:32.454974 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Got the server hand shake response (type: manager [], protocol version 310)
[2017-10-12 14:43:32.455027 +0200][Dump   ][XRootDTransport   ] [msg: 0xd97009b0] Expecting 8 bytes of message body
[2017-10-12 14:43:32.455053 +0200][Dump   ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Received message header, size: 8
[2017-10-12 14:43:32.455076 +0200][Dump   ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Received a message of 16 bytes
[2017-10-12 14:43:32.455091 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] kXR_protocol successful (type: manager [], protocol version 310)
[2017-10-12 14:43:32.460045 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Sending out kXR_login request, username: michael, cgi: ?xrd.cc=ch&xrd.tz=1&xrd.appname=xrdfs&xrd.info=&xrd.hostname=michaelsmacbookpro.dyndns.cern.ch&xrd.rn=v4.6.1, dual-stack: false, private IPv4: false, private IPv6: false
[2017-10-12 14:43:32.460137 +0200][Dump   ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Wrote a message:  (0xd960eab0), 132 bytes
[2017-10-12 14:43:32.460961 +0200][Dump   ][XRootDTransport   ] [msg: 0xd960eab0] Expecting 133 bytes of message body
[2017-10-12 14:43:32.461015 +0200][Dump   ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Received message header, size: 8
[2017-10-12 14:43:32.461032 +0200][Dump   ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Received a message of 141 bytes
[2017-10-12 14:43:32.461050 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Logged in, session: 6d562d00a36c0000eb06000034572d00
[2017-10-12 14:43:32.461058 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Authentication is required: &P=krb5,xrootd/eoslhcb.cern.ch@CERN.CH&P=gsi,v:10300,c:ssl,ca:5168735f.0|4339b4bc.0&P=unix&P=sss,0.13:/etc/eos.keytab
[2017-10-12 14:43:32.461066 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Sending authentication data
[2017-10-12 14:43:32.462336 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Trying to authenticate using krb5
[2017-10-12 14:43:32.490778 +0200][Dump   ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Wrote a message:  (0xd940bc50), 2243 bytes
[2017-10-12 14:43:32.492115 +0200][Dump   ][XRootDTransport   ] [msg: 0xd95048d0] Expecting 0 bytes of message body
[2017-10-12 14:43:32.492157 +0200][Dump   ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Received message header, size: 8
[2017-10-12 14:43:32.492167 +0200][Dump   ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Received a message of 8 bytes
[2017-10-12 14:43:32.492203 +0200][Debug  ][XRootDTransport   ] [eoslhcb.cern.ch:1094 #0.0] Authenticated with krb5.
[2017-10-12 14:43:32.492228 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Stream 0 connected.
[2017-10-12 14:43:32.492236 +0200][Debug  ][Utility           ] Monitor library name not set. No monitoring
[2017-10-12 14:43:32.492270 +0200][Dump   ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Wrote a message: kXR_stat (path: /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, flags: none) (0xd97003e0), 99 bytes
[2017-10-12 14:43:32.492283 +0200][Dump   ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Successfully sent message: kXR_stat (path: /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, flags: none) (0xd97003e0).
[2017-10-12 14:43:32.492323 +0200][Dump   ][XRootD            ] [eoslhcb.cern.ch:1094] Message kXR_stat (path: /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, flags: none) has been successfully sent.
[2017-10-12 14:43:32.492334 +0200][Dump   ][PostMaster        ] [eoslhcb.cern.ch:1094 #0.0] All messages consumed, disable uplink
[2017-10-12 14:43:32.494508 +0200][Dump   ][XRootDTransport   ] [msg: 0xd9505040] Expecting 43 bytes of message body
[2017-10-12 14:43:32.494533 +0200][Dump   ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Received message header for 0xd9505040 size: 8
[2017-10-12 14:43:32.494550 +0200][Dump   ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Received message 0xd9505040 of 51 bytes
[2017-10-12 14:43:32.494558 +0200][Dump   ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Handling received message: 0xd9505040.
[2017-10-12 14:43:32.494591 +0200][Dump   ][XRootD            ] [eoslhcb.cern.ch:1094] Got a kXR_ok response to request kXR_stat (path: /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, flags: none)
[2017-10-12 14:43:32.494614 +0200][Dump   ][XRootD            ] [eoslhcb.cern.ch:1094] Parsing the response to kXR_stat (path: /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, flags: none) as StatInfo: -1152921504606795009 1891839 17 1507211942
Path:   /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root
Id:     -1152921504606795009
Size:   1891839
MTime:  2017-10-05 13:59:02
Flags:  17 (XBitSet|IsReadable)
[2017-10-12 14:43:32.494834 +0200][Debug  ][JobMgr            ] Stopping the job manager...
[2017-10-12 14:43:32.494844 +0200][Dump   ][JobMgr            ] Stopping worker #0...
[2017-10-12 14:43:32.494912 +0200][Dump   ][JobMgr            ] Worker #0 stopped
[2017-10-12 14:43:32.494922 +0200][Dump   ][JobMgr            ] Stopping worker #1...
[2017-10-12 14:43:32.494945 +0200][Dump   ][JobMgr            ] Worker #1 stopped
[2017-10-12 14:43:32.494954 +0200][Dump   ][JobMgr            ] Stopping worker #2...
[2017-10-12 14:43:32.494976 +0200][Dump   ][JobMgr            ] Worker #2 stopped
[2017-10-12 14:43:32.494984 +0200][Debug  ][JobMgr            ] Job manager stopped
[2017-10-12 14:43:32.494989 +0200][Debug  ][TaskMgr           ] Stopping the task manager...
[2017-10-12 14:43:32.495013 +0200][Debug  ][TaskMgr           ] Task manager stopped
[2017-10-12 14:43:32.495022 +0200][Debug  ][Poller            ] Stopping the poller...
[2017-10-12 14:43:32.495069 +0200][Debug  ][TaskMgr           ] Requesting unregistration of: "TickGeneratorTask for: eoslhcb.cern.ch:1094"
[2017-10-12 14:43:32.495079 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Closing the socket
[2017-10-12 14:43:32.495086 +0200][Debug  ][Poller            ] <[::ffff:128.141.59.21]:60401><--><[::ffff:188.184.38.44]:1094> Removing socket from the poller
[2017-10-12 14:43:32.495123 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Destroying stream
[2017-10-12 14:43:32.495133 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Closing the socket

simonm · October 12, 2017, 1:23pm

Do you have the envar XRD_NETWORKSTACK exported?
Could you try with XRD_NETWORKSTACK=IPAuto?

Thanks,
Michal

mwilkins · October 12, 2017, 7:29pm

With that environment variable, I’m back to “no route to host” if I try a root session. Here’s the output from the xrdfs command:

$ xrdfs eoslhcb.cern.ch stat /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root
[2017-10-12 21:28:12.955971 +0200][Warning][Utility           ] Unable to process global config file: [ERROR] OS Error: No such file or directory
[2017-10-12 21:28:12.958722 +0200][Debug  ][Utility           ] Unable to process user config file: [ERROR] OS Error: No such file or directory
[2017-10-12 21:28:12.959035 +0200][Info   ][Utility           ] Env: Importing from shell XRD_NETWORKSTACK=IPAuto as NetworkStack
[2017-10-12 21:28:12.959144 +0200][Debug  ][PlugInMgr         ] Initializing plug-in manager...
[2017-10-12 21:28:12.959198 +0200][Debug  ][PlugInMgr         ] No default plug-in, loading plug-in configs...
[2017-10-12 21:28:12.959220 +0200][Debug  ][PlugInMgr         ] Processing plug-in definitions in /etc/xrootd/client.plugins.d...
[2017-10-12 21:28:12.959269 +0200][Debug  ][PlugInMgr         ] Unable to process directory /etc/xrootd/client.plugins.d: [ERROR] OS Error: No such file or directory
[2017-10-12 21:28:12.959291 +0200][Debug  ][PlugInMgr         ] Processing plug-in definitions in /Users/michael/.xrootd/client.plugins.d...
[2017-10-12 21:28:12.959310 +0200][Debug  ][PlugInMgr         ] Unable to process directory /Users/michael/.xrootd/client.plugins.d: [ERROR] OS Error: No such file or directory
[2017-10-12 21:28:12.959324 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSeckrb5.so
[2017-10-12 21:28:12.971735 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsi.so
[2017-10-12 21:28:12.972960 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsiAuthzVO.so
[2017-10-12 21:28:12.973930 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecgsiGMAPDN.so
[2017-10-12 21:28:12.974845 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecpwd.so
[2017-10-12 21:28:12.975679 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecsss.so
[2017-10-12 21:28:12.976880 +0200][Debug  ][Utility           ] Attempting to pre-load: libXrdSecunix.so
[2017-10-12 21:28:12.978429 +0200][Dump   ][Utility           ] URL: eoslhcb.cern.ch
[2017-10-12 21:28:12.978429 +0200][Dump   ][Utility           ] Protocol:  root
[2017-10-12 21:28:12.978429 +0200][Dump   ][Utility           ] User Name: 
[2017-10-12 21:28:12.978429 +0200][Dump   ][Utility           ] Password:  
[2017-10-12 21:28:12.978429 +0200][Dump   ][Utility           ] Host Name: eoslhcb.cern.ch
[2017-10-12 21:28:12.978429 +0200][Dump   ][Utility           ] Port:      1094
[2017-10-12 21:28:12.978429 +0200][Dump   ][Utility           ] Path:      
[2017-10-12 21:28:12.979108 +0200][Dump   ][Utility           ] URL: root://eoslhcb.cern.ch:1094/
[2017-10-12 21:28:12.979108 +0200][Dump   ][Utility           ] Protocol:  root
[2017-10-12 21:28:12.979108 +0200][Dump   ][Utility           ] User Name: 
[2017-10-12 21:28:12.979108 +0200][Dump   ][Utility           ] Password:  
[2017-10-12 21:28:12.979108 +0200][Dump   ][Utility           ] Host Name: eoslhcb.cern.ch
[2017-10-12 21:28:12.979108 +0200][Dump   ][Utility           ] Port:      1094
[2017-10-12 21:28:12.979108 +0200][Dump   ][Utility           ] Path:      
[2017-10-12 21:28:12.979148 +0200][Dump   ][Utility           ] URL: root://eoslhcb.cern.ch:1094/
[2017-10-12 21:28:12.979148 +0200][Dump   ][Utility           ] Protocol:  root
[2017-10-12 21:28:12.979148 +0200][Dump   ][Utility           ] User Name: 
[2017-10-12 21:28:12.979148 +0200][Dump   ][Utility           ] Password:  
[2017-10-12 21:28:12.979148 +0200][Dump   ][Utility           ] Host Name: eoslhcb.cern.ch
[2017-10-12 21:28:12.979148 +0200][Dump   ][Utility           ] Port:      1094
[2017-10-12 21:28:12.979148 +0200][Dump   ][Utility           ] Path:      
[2017-10-12 21:28:12.979291 +0200][Debug  ][App               ] Executing: stat /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root 
[2017-10-12 21:28:12.979312 +0200][Dump   ][App               ] Param #00: 'stat'
[2017-10-12 21:28:12.979317 +0200][Dump   ][App               ] Param #01: '/eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root'
[2017-10-12 21:28:12.979917 +0200][Dump   ][FileSystem        ] [0xdac0fa60@eoslhcb.cern.ch:1094] Sending kXR_stat (path: /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, flags: none)
[2017-10-12 21:28:12.979969 +0200][Debug  ][Poller            ] Available pollers: built-in
[2017-10-12 21:28:12.980004 +0200][Debug  ][Poller            ] Attempting to create a poller according to preference: built-in
[2017-10-12 21:28:12.980019 +0200][Debug  ][Poller            ] Creating poller: built-in
[2017-10-12 21:28:12.980033 +0200][Debug  ][Poller            ] Creating and starting the built-in poller...
[2017-10-12 21:28:12.980277 +0200][Debug  ][Poller            ] Using 1 poller threads
[2017-10-12 21:28:12.980303 +0200][Debug  ][TaskMgr           ] Starting the task manager...
[2017-10-12 21:28:12.980343 +0200][Debug  ][TaskMgr           ] Task manager started
[2017-10-12 21:28:12.980355 +0200][Debug  ][JobMgr            ] Starting the job manager...
[2017-10-12 21:28:12.980406 +0200][Debug  ][JobMgr            ] Job manager started, 3 workers
[2017-10-12 21:28:12.980426 +0200][Debug  ][TaskMgr           ] Registering task: "FileTimer task" to be run at: [2017-10-12 21:28:12 +0200]
[2017-10-12 21:28:12.980451 +0200][Dump   ][XRootD            ] [eoslhcb.cern.ch:1094] Sending message kXR_stat (path: /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, flags: none)
[2017-10-12 21:28:12.980474 +0200][Dump   ][Utility           ] URL: eoslhcb.cern.ch:1094
[2017-10-12 21:28:12.980474 +0200][Dump   ][Utility           ] Protocol:  root
[2017-10-12 21:28:12.980474 +0200][Dump   ][Utility           ] User Name: 
[2017-10-12 21:28:12.980474 +0200][Dump   ][Utility           ] Password:  
[2017-10-12 21:28:12.980474 +0200][Dump   ][Utility           ] Host Name: eoslhcb.cern.ch
[2017-10-12 21:28:12.980474 +0200][Dump   ][Utility           ] Port:      1094
[2017-10-12 21:28:12.980474 +0200][Dump   ][Utility           ] Path:      
[2017-10-12 21:28:12.980499 +0200][Debug  ][PostMaster        ] Creating new channel to: eoslhcb.cern.ch:1094 1 stream(s)
[2017-10-12 21:28:12.980549 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Stream parameters: Network Stack: IPAuto, Connection Window: 120, ConnectionRetry: 5, Stream Error Widnow: 1800
[2017-10-12 21:28:12.981490 +0200][Debug  ][TaskMgr           ] Registering task: "TickGeneratorTask for: eoslhcb.cern.ch:1094" to be run at: [2017-10-12 21:28:27 +0200]
[2017-10-12 21:28:12.981524 +0200][Dump   ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Sending message kXR_stat (path: /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, flags: none) (0xdad01d10) through substream 0 expecting answer at 0
[2017-10-12 21:28:12.982214 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094] Found 2 address(es): [2001:1458:201:c0::100:c]:1094, [::ffff:188.184.38.44]:1094
[2017-10-12 21:28:12.982270 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Attempting connection to [2001:1458:201:c0::100:c]:1094
[2017-10-12 21:28:12.982322 +0200][Error  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Unable to initiate the connection: [ERROR] Socket error: No route to host
[2017-10-12 21:28:12.982357 +0200][Error  ][XRootD            ] [eoslhcb.cern.ch:1094] Unable to send the message kXR_stat (path: /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root, flags: none): [FATAL] Socket error: No route to host
[2017-10-12 21:28:12.982395 +0200][Error  ][App               ] Unable stat /eos/lhcb/user/m/mwilkins/bfractions_fromGanga/MC/Up16/579.0/DVnTuples.root: [FATAL] Socket error: No route to host
[FATAL] Socket error: No route to host
[2017-10-12 21:28:12.982430 +0200][Debug  ][JobMgr            ] Stopping the job manager...
[2017-10-12 21:28:12.982448 +0200][Dump   ][JobMgr            ] Stopping worker #0...
[2017-10-12 21:28:12.982517 +0200][Dump   ][JobMgr            ] Worker #0 stopped
[2017-10-12 21:28:12.982525 +0200][Dump   ][JobMgr            ] Stopping worker #1...
[2017-10-12 21:28:12.982545 +0200][Dump   ][JobMgr            ] Worker #1 stopped
[2017-10-12 21:28:12.982552 +0200][Dump   ][JobMgr            ] Stopping worker #2...
[2017-10-12 21:28:12.982570 +0200][Dump   ][JobMgr            ] Worker #2 stopped
[2017-10-12 21:28:12.982578 +0200][Debug  ][JobMgr            ] Job manager stopped
[2017-10-12 21:28:12.982582 +0200][Debug  ][TaskMgr           ] Stopping the task manager...
[2017-10-12 21:28:12.982605 +0200][Debug  ][TaskMgr           ] Task manager stopped
[2017-10-12 21:28:12.982611 +0200][Debug  ][Poller            ] Stopping the poller...
[2017-10-12 21:28:12.982686 +0200][Debug  ][TaskMgr           ] Requesting unregistration of: "TickGeneratorTask for: eoslhcb.cern.ch:1094"
[2017-10-12 21:28:12.982696 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Closing the socket
[2017-10-12 21:28:12.982704 +0200][Debug  ][PostMaster        ] [eoslhcb.cern.ch:1094 #0] Destroying stream
[2017-10-12 21:28:12.982712 +0200][Debug  ][Utility           ] Monitor library name not set. No monitoring
[2017-10-12 21:28:12.982719 +0200][Debug  ][AsyncSock         ] [eoslhcb.cern.ch:1094 #0.0] Closing the socket

system · October 26, 2017, 7:43pm

This topic was automatically closed 14 days after the last reply. New replies are no longer allowed.