 |
 |
I am trying to support a user that from inside a singularity container in a Grid job is trying to open a file using the xrootd protocol. The test program is simply
source /cvmfs/sft.cern.ch/lcg/views/LCG_95apython3/x86_64-centos7-gcc8-opt/setup.sh
python -c "import ROOT; ROOT.TFile.Open('root://gfe02.grid.hep.ph.ic.ac.uk/pnfs/hep.ph.ic.ac.uk/data/lz/lz/data/MDC3/calibration/LZAP-4.3.1/20180201/lz_20180201234_lzap.root').Get('Events')"
This works for the jobs on most sites, but on a fair number of sites, the test fails with
Error in <TNetXNGFile::Open>: [ERROR] Server responded with an error: [3010] Request lacks the org.dcache.uuid property.
The full output from setting export XRD_LOGLEVEL="Debug" is given below. Any idea what the problem is?
Ulrik.
[2020-05-20 17:27:14.761227 +0100][Debug ][Utility ] Unable to find user home directory.
[2020-05-20 17:27:14.761803 +0100][Debug ][PlugInMgr ] Initializing plug-in manager...
[2020-05-20 17:27:14.761907 +0100][Debug ][PlugInMgr ] No default plug-in, loading plug-in configs...
[2020-05-20 17:27:14.762003 +0100][Debug ][PlugInMgr ] Processing plug-in definitions in /etc/xrootd/client.plugins.d...
[2020-05-20 17:27:15.009549 +0100][Debug ][Poller ] Available pollers: built-in
[2020-05-20 17:27:15.009861 +0100][Debug ][Poller ] Attempting to create a poller according to preference: built-in
[2020-05-20 17:27:15.009961 +0100][Debug ][Poller ] Creating poller: built-in
[2020-05-20 17:27:15.010067 +0100][Debug ][Poller ] Creating and starting the built-in poller...
[2020-05-20 17:27:15.010444 +0100][Debug ][Poller ] Using 1 poller threads
[2020-05-20 17:27:15.010469 +0100][Debug ][TaskMgr ] Starting the task manager...
[2020-05-20 17:27:15.010518 +0100][Debug ][TaskMgr ] Task manager started
[2020-05-20 17:27:15.010542 +0100][Debug ][JobMgr ] Starting the job manager...
[2020-05-20 17:27:15.010646 +0100][Debug ][JobMgr ] Job manager started, 3 workers
[2020-05-20 17:27:15.010681 +0100][Debug ][TaskMgr ] Registering task: "FileTimer task" to be run at: [2020-05-20 17:27:15 +0100]
[2020-05-20 17:27:15.010804 +0100][Debug ][Utility ] Env: overriding entry: MultiProtocol=0 with 1
[2020-05-20 17:27:15.011181 +0100][Debug ][File ] [0x525f5f0@root://gfe02.grid.hep.ph.ic.ac.uk:1094/pnfs/hep.ph.ic.ac.uk/data/lz/lz/data/MDC3/calibration/LZAP-4.3.1/20180201/lz_20180201234_lzap.root] Sending an open command
[2020-05-20 17:27:15.011338 +0100][Debug ][PostMaster ] Creating new channel to: gfe02.grid.hep.ph.ic.ac.uk:1094 1 stream(s)
[2020-05-20 17:27:15.011398 +0100][Debug ][PostMaster ] [gfe02.grid.hep.ph.ic.ac.uk:1094 #0] Stream parameters: Network Stack: IPAuto, Connection Window: 120, ConnectionRetry: 5, Stream Error Widnow: 1800
[2020-05-20 17:27:15.012202 +0100][Debug ][TaskMgr ] Registering task: "TickGeneratorTask for: gfe02.grid.hep.ph.ic.ac.uk:1094" to be run at: [2020-05-20 17:27:30 +0100]
[2020-05-20 17:27:15.013435 +0100][Debug ][PostMaster ] [gfe02.grid.hep.ph.ic.ac.uk:1094] Found 2 address(es): [::ffff:146.179.232.84]:1094, [2a0c:5bc0:c8:2:a236:9fff:feed:7228]:1094
[2020-05-20 17:27:15.013499 +0100][Debug ][AsyncSock ] [gfe02.grid.hep.ph.ic.ac.uk:1094 #0.0] Attempting connection to [2a0c:5bc0:c8:2:a236:9fff:feed:7228]:1094
[2020-05-20 17:27:15.013573 +0100][Debug ][Poller ] Adding socket 0x5260050 to the poller
[2020-05-20 17:27:15.013799 +0100][Debug ][AsyncSock ] [gfe02.grid.hep.ph.ic.ac.uk:1094 #0.0] Async connection call returned
[2020-05-20 17:27:15.013939 +0100][Debug ][XRootDTransport ] [gfe02.grid.hep.ph.ic.ac.uk:1094 #0.0] Sending out the initial hand shake + kXR_protocol
[2020-05-20 17:27:15.014320 +0100][Debug ][XRootDTransport ] [gfe02.grid.hep.ph.ic.ac.uk:1094 #0.0] Got the server hand shake response (type: manager [], protocol version 400)
[2020-05-20 17:27:15.014463 +0100][Debug ][XRootDTransport ] [gfe02.grid.hep.ph.ic.ac.uk:1094 #0.0] kXR_protocol successful (type: server [], protocol version 400)
[2020-05-20 17:27:15.017543 +0100][Debug ][XRootDTransport ] [gfe02.grid.hep.ph.ic.ac.uk:1094 #0.0] Sending out kXR_login request, username: ????, cgi: ?xrd.cc=uk&xrd.tz=0&xrd.appname=python3.6&xrd.info=&xrd.hostname=wg45.grid.hep.ph.ic.ac.uk&xrd.rn=v4.8.4, dual-stack: true, private IPv4: false, private IPv6: false
[2020-05-20 17:27:15.018087 +0100][Debug ][XRootDTransport ] [gfe02.grid.hep.ph.ic.ac.uk:1094 #0.0] Logged in, session: baf2fbf8ec4ebdef112fd1c3113555d6
[2020-05-20 17:27:15.018175 +0100][Debug ][XRootDTransport ] [gfe02.grid.hep.ph.ic.ac.uk:1094 #0.0] Authentication is required: &P=gsi,v:10400,c:ssl,ca:ffc3d59b
[2020-05-20 17:27:15.018269 +0100][Debug ][XRootDTransport ] [gfe02.grid.hep.ph.ic.ac.uk:1094 #0.0] Sending authentication data
[2020-05-20 17:27:15.119615 +0100][Debug ][XRootDTransport ] [gfe02.grid.hep.ph.ic.ac.uk:1094 #0.0] Trying to authenticate using gsi
[2020-05-20 17:27:15.185929 +0100][Debug ][XRootDTransport ] [gfe02.grid.hep.ph.ic.ac.uk:1094 #0.0] Sending more authentication data for gsi
[2020-05-20 17:27:15.220114 +0100][Debug ][XRootDTransport ] [gfe02.grid.hep.ph.ic.ac.uk:1094 #0.0] Authenticated with gsi.
[2020-05-20 17:27:15.220310 +0100][Debug ][PostMaster ] [gfe02.grid.hep.ph.ic.ac.uk:1094 #0] Stream 0 connected.
[2020-05-20 17:27:15.220418 +0100][Debug ][Utility ] Monitor library name not set. No monitoring
[2020-05-20 17:27:15.273009 +0100][Debug ][PostMaster ] Creating new channel to: [2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718 1 stream(s)
[2020-05-20 17:27:15.273066 +0100][Debug ][PostMaster ] [[2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718 #0] Stream parameters: Network Stack: IPAuto, Connection Window: 120, ConnectionRetry: 5, Stream Error Widnow: 1800
[2020-05-20 17:27:15.274008 +0100][Debug ][TaskMgr ] Registering task: "TickGeneratorTask for: [2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718" to be run at: [2020-05-20 17:27:30 +0100]
[2020-05-20 17:27:15.274166 +0100][Debug ][PostMaster ] [[2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718] Found 1 address(es): [2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718
[2020-05-20 17:27:15.274213 +0100][Debug ][AsyncSock ] [[2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718 #0.0] Attempting connection to [2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718
[2020-05-20 17:27:15.274387 +0100][Debug ][Poller ] Adding socket 0x840018f0 to the poller
[2020-05-20 17:27:15.274686 +0100][Debug ][AsyncSock ] [[2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718 #0.0] Async connection call returned
[2020-05-20 17:27:15.274786 +0100][Debug ][XRootDTransport ] [[2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718 #0.0] Sending out the initial hand shake + kXR_protocol
[2020-05-20 17:27:15.276971 +0100][Debug ][XRootDTransport ] [[2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718 #0.0] Got the server hand shake response (type: server [], protocol version 400)
[2020-05-20 17:27:15.277103 +0100][Debug ][XRootDTransport ] [[2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718 #0.0] kXR_protocol successful (type: server [], protocol version 400)
[2020-05-20 17:27:15.278755 +0100][Debug ][XRootDTransport ] [[2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718 #0.0] Sending out kXR_login request, username: ????, cgi: ?xrd.cc=uk&xrd.tz=0&xrd.appname=python3.6&xrd.info=&xrd.hostname=wg45.grid.hep.ph.ic.ac.uk&xrd.rn=v4.8.4, dual-stack: true, private IPv4: false, private IPv6: false
[2020-05-20 17:27:15.279225 +0100][Debug ][XRootDTransport ] [[2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718 #0.0] Logged in, session: bebdeec19a84defa728553f50332881e
[2020-05-20 17:27:15.279313 +0100][Debug ][PostMaster ] [[2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718 #0] Stream 0 connected.
[2020-05-20 17:27:15.280759 +0100][Debug ][XRootD ] [[2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718] Handling error while processing kXR_open (file: pnfs/hep.ph.ic.ac.uk/data/lz/lz/data/MDC3/calibration/LZAP-4.3.1/20180201/lz_20180201234_lzap.root?org.dcache.xrootd.client=, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ): [ERROR] Error response: Permission denied.
[2020-05-20 17:27:15.280977 +0100][Debug ][File ] [0x525f5f0@root://gfe02.grid.hep.ph.ic.ac.uk:1094/pnfs/hep.ph.ic.ac.uk/data/lz/lz/data/MDC3/calibration/LZAP-4.3.1/20180201/lz_20180201234_lzap.root] Open has returned with status [ERROR] Server responded with an error: [3010] Request lacks the org.dcache.uuid property.
[2020-05-20 17:27:15.280997 +0100][Debug ][File ] [0x525f5f0@root://gfe02.grid.hep.ph.ic.ac.uk:1094/pnfs/hep.ph.ic.ac.uk/data/lz/lz/data/MDC3/calibration/LZAP-4.3.1/20180201/lz_20180201234_lzap.root] Error while opening at [2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718: [ERROR] Server responded with an error: [3010] Request lacks the org.dcache.uuid property.
Error in <TNetXNGFile::Open>: [ERROR] Server responded with an error: [3010] Request lacks the org.dcache.uuid property.
Traceback (most recent call last):
File "<string>", line 1, in <module>
ReferenceError: attempt to access a null-pointer
[2020-05-20 17:27:15.306374 +0100][Debug ][JobMgr ] Stopping the job manager...
[2020-05-20 17:27:15.307050 +0100][Debug ][JobMgr ] Job manager stopped
[2020-05-20 17:27:15.307147 +0100][Debug ][TaskMgr ] Stopping the task manager...
[2020-05-20 17:27:15.307295 +0100][Debug ][TaskMgr ] Task manager stopped
[2020-05-20 17:27:15.307374 +0100][Debug ][Poller ] Stopping the poller...
[2020-05-20 17:27:15.307553 +0100][Debug ][TaskMgr ] Requesting unregistration of: "TickGeneratorTask for: [2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718"
[2020-05-20 17:27:15.307649 +0100][Debug ][AsyncSock ] [[2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718 #0.0] Closing the socket
[2020-05-20 17:27:15.307741 +0100][Debug ][Poller ] <[2a0c:5bc0:c8:2:d6ae:52ff:fe6a:ab5]:53010><--><[2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718> Removing socket from the poller
[2020-05-20 17:27:15.307885 +0100][Debug ][PostMaster ] [[2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718 #0] Destroying stream
[2020-05-20 17:27:15.307977 +0100][Debug ][AsyncSock ] [[2a0c:5bc0:c8:2:266e:96ff:fe14:f78]:24718 #0.0] Closing the socket
[2020-05-20 17:27:15.308071 +0100][Debug ][TaskMgr ] Requesting unregistration of: "TickGeneratorTask for: gfe02.grid.hep.ph.ic.ac.uk:1094"
[2020-05-20 17:27:15.308146 +0100][Debug ][AsyncSock ] [gfe02.grid.hep.ph.ic.ac.uk:1094 #0.0] Closing the socket
[2020-05-20 17:27:15.308218 +0100][Debug ][Poller ] <[2a0c:5bc0:c8:2:d6ae:52ff:fe6a:ab5]:56958><--><[2a0c:5bc0:c8:2:a236:9fff:feed:7228]:1094> Removing socket from the poller
[2020-05-20 17:27:15.308313 +0100][Debug ][PostMaster ] [gfe02.grid.hep.ph.ic.ac.uk:1094 #0] Destroying stream
[2020-05-20 17:27:15.308388 +0100][Debug ][AsyncSock ] [gfe02.grid.hep.ph.ic.ac.uk:1094 #0.0] Closing the socket
ROOT Version: 6.16.00-08816
Platform: centos7
Compiler: gcc8
Original issue is ganga-devs/ganga#1672
—
You are receiving this because you are subscribed to this thread.
Reply to this email directly, view it on GitHub, or unsubscribe.
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