Hello,
I have a weird issue with xrootd 5.2 + multiuser plugin. Here are some details below:
Setup is simple 1 redirector and 4 data servers behind.
listing directory fails using root protocol via redirector:
$ gfal-ls root://xrootd-redir.ultralight.org/store/user/jbalcas/
gfal-ls error: 115 (Operation now in progress) - Failed reading directory: [ERROR] Error response: No such file or directory (Unknown error 400)
But it works listing specific file via redirector:
-bash-4.2$ gfal-ls -l root://xrootd-redir.ultralight.org//store/user/jbalcas/1GB_File
-r-------- 1 3000 3000 1048576000 May 19 2020 root://xrootd-redir.ultralight.org//store/user/jbalcas/1GB_File
Directory listing works with davs protocol via redirector:
-bash-4.2$ gfal-ls -l davs://xrootd-redir.ultralight.org:1094/store/user/jbalcas/
drwxrwxrwx 0 0 0 5 Mar 18 18:09 core-dumps
-rwxrwxrwx 0 0 0 69465 May 1 2020 18Jan2019_job0_outHist.root
-rwxrwxrwx 0 0 0 1048576000 May 19 2020 1GB_File
-rwxrwxrwx 0 0 0 69465 May 1 2020 18Jan2019_job0_outHist.root1
drwxrwxrwx 0 0 0 2 Feb 22 07:15 for-xrootd-devs
drwxrwxrwx 0 0 0 0 May 4 13:11 test
Also, directory listing works using xrdfs via redirector:
-bash-4.2$ xrdfs xrootd-redir.ultralight.org
[xrootd-redir.ultralight.org:1094] / > ls -l /store/user/jbalcas/
-r-- 2020-05-01 20:17:28 69465 /store/user/jbalcas/18Jan2019_job0_outHist.root
-r-- 2020-05-01 20:19:49 69465 /store/user/jbalcas/18Jan2019_job0_outHist.root1
-r-- 2020-05-19 22:56:21 1048576000 /store/user/jbalcas/1GB_File
dr-x 2021-03-19 01:09:34 5 /store/user/jbalcas/core-dumps
dr-x 2021-02-22 15:15:31 2 /store/user/jbalcas/for-xrootd-devs
dr-x 2021-05-04 20:11:59 0 /store/user/jbalcas/test
[xrootd-redir.ultralight.org:1094] / > stat /store/user/jbalcas/1GB_File
Path: /store/user/jbalcas/1GB_File
Id: 983852453462060
Size: 1048576000
MTime: 2020-05-19 22:56:21
Flags: 16 (IsReadable)
Any directory or file listing via any of the 4 data servers works (root, davs, xrdfs). So something between redirector and data servers and especially using root protocol. With an increased debug, here is redirector log:
INFO in AuthzKey: Returning '/DC=ch/DC=cern/OU=Organic Units/OU=Users/CN=jbalcas/CN=751133/CN=Justas Balcas::cms:/cms,/cms/becms,/cms/dcms,/cms/escms,/cms/itcms,/cms/uscms,::' of length 145 as key.
210513 15:05:34 28510 jbalcas.3955907:[log in to unmask] XrootdResponse: 0000 sending OK
jbalcas.3955907:[log in to unmask] Protocol 'gsi'
jbalcas.3955907:[log in to unmask] Name 'jbalcas'
jbalcas.3955907:[log in to unmask] Host 'login-1.hep.caltech.edu'
jbalcas.3955907:[log in to unmask] Vorg 'cms'
jbalcas.3955907:[log in to unmask] Role ''
jbalcas.3955907:[log in to unmask] Grps '/cms /cms/becms /cms/dcms /cms/escms /cms/itcms /cms/uscms'
jbalcas.3955907:[log in to unmask] Caps ''
jbalcas.3955907:[log in to unmask] Pidn 'jbalcas.3955907:[log in to unmask]
jbalcas.3955907:[log in to unmask] Crlen 9266
jbalcas.3955907:[log in to unmask] ueid 23
jbalcas.3955907:[log in to unmask] uid 0
jbalcas.3955907:[log in to unmask] gid 0
210513 15:05:34 28510 XrootdMonitor: 367 bytes sent to 169.228.130.91:9930 rc=0
210513 15:05:34 28510 XrootdMonitor: 367 bytes sent to xrootd-mon.unl.edu:9930 rc=0
210513 15:05:34 28510 XrootdXeq: jbalcas.3955907:[log in to unmask] pub IPv4 login as jbalcas
210513 15:05:34 28510 jbalcas.3955907:[log in to unmask] XrootdProtocol: 0100 req=stat dlen=49
210513 15:05:34 28510 jbalcas.3955907:[log in to unmask] ofs_stat: fn=/store/
210513 15:05:34 28500 Receive localhost 30 bytes on 41983
210513 15:05:34 28500 Decode xrootd-redir redirects jbalcas.3955907:[log in to unmask] to transfer-8.ultralight.org:1094 /store/
210513 15:05:34 28510 jbalcas.3955907:[log in to unmask] XrootdProtocol: 0100 rc=-256 stat /store/
210513 15:05:34 28510 jbalcas.3955907:[log in to unmask] XrootdProtocol: 0100 redirecting to transfer-8.ultralight.org:1094
210513 15:05:34 28510 jbalcas.3955907:[log in to unmask] XrootdResponse: 0100 sending 29 data bytes; status=4004
210513 15:05:34 28510 jbalcas.3955907:[log in to unmask] XrootdProtocol: 0100 req=stat dlen=49
210513 15:05:34 28510 jbalcas.3955907:[log in to unmask] ofs_stat: fn=/store/
210513 15:05:34 28500 Receive localhost 31 bytes on 43007
210513 15:05:34 28500 Decode xrootd-redir redirects jbalcas.3955907:[log in to unmask] to transfer-10.ultralight.org:1094 /store/
210513 15:05:34 28510 jbalcas.3955907:[log in to unmask] XrootdProtocol: 0100 rc=-256 stat /store/
210513 15:05:34 28510 jbalcas.3955907:[log in to unmask] XrootdProtocol: 0100 redirecting to transfer-10.ultralight.org:1094
210513 15:05:34 28510 jbalcas.3955907:[log in to unmask] XrootdResponse: 0100 sending 30 data bytes; status=4004
210513 15:05:35 28510 jbalcas.3955907:[log in to unmask] XrootdProtocol: 0100 req=dirlist dlen=8
210513 15:05:35 28510 jbalcas.3955907:[log in to unmask] ofs_opendir: fn=/store/
210513 15:05:35 28510 jbalcas.3955907:[log in to unmask] oss_Opendir: lcl path /storage/cms/store/ (/store/)
210513 15:05:35 28510 ofs_opendir: jbalcas.3955907:[log in to unmask] Unable to open directory /store/; no such file or directory
210513 15:05:35 28510 jbalcas.3955907:[log in to unmask] XrootdResponse: 0100 sending err 3011: Unable to open directory /store/; no such file or directory
210513 15:05:35 28510 XrootdXeq: jbalcas.3955907:[log in to unmask] disc 0:00:01
210513 15:05:35 28510 XrootdMonitor: 56 bytes sent to 169.228.130.91:9930 rc=0
210513 15:05:35 28510 jbalcas.3955907:[log in to unmask] XrdPoll: Poller 2 removing FD 51
210513 15:05:35 28510 jbalcas.3955907:[log in to unmask] XrdPoll: FD 51 detached from poller 2; num=3
From data server:
INFO in AuthzKey: Returning '/DC=ch/DC=cern/OU=Organic Units/OU=Users/CN=jbalcas/CN=751133/CN=Justas Balcas::cms:/cms,/cms/becms,/cms/dcms,/cms/escms,/cms/itcms,/cms/uscms,::' of length 145 as key.
210513 08:05:35 372882 jbalcas.3955907:[log in to unmask] XrootdResponse: 0000 sending OK
jbalcas.3955907:[log in to unmask] Protocol 'gsi'
jbalcas.3955907:[log in to unmask] Name 'jbalcas'
jbalcas.3955907:[log in to unmask] Host 'login-1.hep.caltech.edu'
jbalcas.3955907:[log in to unmask] Vorg 'cms'
jbalcas.3955907:[log in to unmask] Role ''
jbalcas.3955907:[log in to unmask] Grps '/cms /cms/becms /cms/dcms /cms/escms /cms/itcms /cms/uscms'
jbalcas.3955907:[log in to unmask] Caps ''
jbalcas.3955907:[log in to unmask] Pidn 'jbalcas.3955907:[log in to unmask]
jbalcas.3955907:[log in to unmask] Crlen 9266
jbalcas.3955907:[log in to unmask] ueid 3
jbalcas.3955907:[log in to unmask] uid 0
jbalcas.3955907:[log in to unmask] gid 0
210513 08:05:35 372882 XrootdMonitor: 367 bytes sent to 169.228.130.91:9930 rc=0
210513 08:05:35 372882 XrootdMonitor: 367 bytes sent to xrootd-mon.unl.edu:9930 rc=0
210513 08:05:35 372882 XrootdXeq: jbalcas.3955907:[log in to unmask] pub IPv4 login as jbalcas
210513 08:05:35 372882 multiuser_UserSentry: Switching FS uid for user jbalcas
210513 08:05:35 372882 jbalcas.3955907:[log in to unmask] XrootdProtocol: 0100 req=stat dlen=49
210513 08:05:35 372882 jbalcas.3955907:[log in to unmask] ofs_stat: fn=/store/
210513 08:05:35 372882 multiuser_UserSentry: Switching FS uid for user jbalcas
210513 08:05:35 372882 jbalcas.3955907:[log in to unmask] XrootdProtocol: 0100 rc=0 stat /store/
210513 08:05:35 372882 jbalcas.3955907:[log in to unmask] XrootdResponse: 0100 sending 76 data bytes
210513 08:05:35 372882 XrootdXeq: jbalcas.3955907:[log in to unmask] disc 0:00:01
210513 08:05:35 372882 multiuser_UserSentry: Switching FS uid for user jbalcas
210513 08:05:35 372882 XrootdMonitor: 56 bytes sent to 169.228.130.91:9930 rc=0
210513 08:05:35 372882 jbalcas.3955907:[log in to unmask] XrdPoll: Poller 0 removing FD 41
210513 08:05:35 372882 jbalcas.3955907:[log in to unmask] XrdPoll: FD 41 detached from poller 0; num=0
And problematic detail seems to be here on redirector:
210512 20:44:56 25992 jbalcas.3134036:[log in to unmask] oss_Opendir: lcl path /storage/cms/store/ (/store/)
Whenever I do directory listing using root protocol, xrootd redirector does lcl path mapping and asks dataserver /store
and not /storage/cms/store/
. In the case of davs protocol - lcl is done not on the redirector side but done on an individual server.
In our xrootd redir config we have cms.dfs lookup distrib mdhold 20m redirect immed
- so that all lookups are redirected to data servers. Issues so far:
-bash-4.2$ gfal-ls -l davs://xrootd-redir.ultralight.org:1094/store/user/jbalcas/1GB_File
-rwxrwxrwx 0 0 0 1048576000 May 19 2020 davs://xrootd-redir.ultralight.org:1094/store/user/jbalcas/1GB_File
-bash-4.2$ gfal-ls -l davs://transfer-10.ultralight.org:1094/store/user/jbalcas/1GB_File
-rwxrwxrwx 0 0 0 1048576000 May 19 2020 davs://transfer-10.ultralight.org:1094/store/user/jbalcas/1GB_File
-bash-4.2$ gfal-ls -l root://xrootd-redir.ultralight.org:1094/store/user/jbalcas/1GB_File
-r-------- 1 3000 3000 1048576000 May 19 2020 root://xrootd-redir.ultralight.org:1094/store/user/jbalcas/1GB_File
-bash-4.2$ gfal-ls -l root://transfer-10.ultralight.org:1094/store/user/jbalcas/1GB_File
-r-------- 1 3000 3000 1048576000 May 19 2020 root://transfer-10.ultralight.org:1094/store/user/jbalcas/1GB_File
while correct permissions are:
[root@transfer-10 ~]# ll /storage/cms/store/user/jbalcas/1GB_File
-rw-rw-r-- 1 root jbalcas 1048576000 May 19 2020 /storage/cms/store/user/jbalcas/1GB_File
[root@transfer-10 ~]# stat /storage/cms/store/user/jbalcas/1GB_File
File: ‘/storage/cms/store/user/jbalcas/1GB_File’
Size: 1048576000 Blocks: 2048000 IO Block: 4194304 regular file
Device: 2ch/44d Inode: 1099511856847 Links: 1
Access: (0664/-rw-rw-r--) Uid: ( 0/ root) Gid: ( 3000/ jbalcas)
Access: 2021-05-10 15:40:00.427772762 -0700
Modify: 2020-05-19 15:56:21.000000000 -0700
Change: 2021-05-10 15:40:00.428772803 -0700
Birth: -
—
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