Hi Heiko,
Please look at the xrd.delay option (specifically, lookup and qdl). This is a detailed explanation in the subsequent section. Changing the default parameters is not something we recommend and can lead to aberrant behavior.
http://xrootd.org/doc/dev49/cms_config.htm#_Toc506069425
Andy
From: hds1
Sent: Monday, April 30, 2018 11:09 PM
To: xrootd/xrootd
Cc: Andrew Hanushevsky ; Comment
Subject: Re: [xrootd/xrootd] v4.8.3-rc1 stalling client (#692)
Hello Andy,
thank you very much for clarification. Could you pls tell me what the
configurable variable is ?
I'am not sure that i do understand the docs correctly.
Best
Heiko
Am 01.05.2018 um 00:32 schrieb xrootd-dev:
> Hi Heiko,
>
> The logs together show a completely normal interaction:
> a) Client comes in does a stat() on a non-existent file. It takes a bit a time to resolve this so the client is asked to wait 5 seconds (configurable).
> b) The client comes back and re-issues the stat() and get the expected “file not found”.
> c) The client then opens the file for writing and is redirected to an appropriate server.
>
> There is nothing wrong here. Everything is as expected.
>
> Andy
>
> From: hds1
> Sent: Friday, April 27, 2018 11:23 PM
> To: xrootd/xrootd
> Cc: xrootd-dev ; Comment
> Subject: Re: [xrootd/xrootd] v4.8.3-rc1 stalling client (#692)
>
> Sorr for the confusion. What i meant was the comments in github not in
> one mail. To stop the confusion i inserted both log in this mail.
>
> Best
> Heiko
>
>
> CMSD LOG:
> 180426 11:39:55 6048 Starting on Linux 4.13.0-38-generic
> Copr. 2004-2012 Stanford University, xrd version v4.8.3-rc1
> ++++++ cmsd anon@REDIRECTOR initialization started.
> Config using configuration file /etc/xrootd/xrootd.cf
> =====> xrd.port 1094
> Config maximum number of connections restricted to 4096
> Config maximum number of threads restricted to 15569
> 180426 11:39:55 6048 XrdConfig: sendfile enabled.
> 180426 11:39:55 6048 XrdSched: scheduling underused thread monitor in
> 780 seconds
> 180426 11:39:55 6048 XrdSched: Starting with 2 workers
> 180426 11:39:55 6048 XrdLink: Allocating 8 link objects at a time
> 180426 11:39:55 6048 XrdPoll: Starting poller 0
> 180426 11:39:55 6054 XrdXeq: Poller thread started
> 180426 11:39:55 6048 XrdPoll: Starting poller 1
> 180426 11:39:55 6053 XrdXeq: Worker thread started
> 180426 11:39:55 6052 XrdXeq: Worker thread started
> 180426 11:39:55 6055 XrdXeq: Poller thread started
> 180426 11:39:55 6048 XrdPoll: Starting poller 2
> 180426 11:39:55 6051 XrdXeq: Time scheduler thread started
> 180426 11:39:55 6056 XrdXeq: Poller thread started
> 180426 11:39:55 6048 XrdProtocol: getting port from protocol cmsd
> Copr. 2007 Stanford University/SLAC cmsd.
> ++++++ anon@REDIRECTOR phase 1 initialization started.
> =====> all.export /xrootd
> 180426 11:39:55 6050 XrdXeq: Buffer Manager reshaper thread started
> =====> all.manager REDIRECTOR:3121
> =====> cms.allow host *
> =====> all.role manager
> 180426 11:39:55 6048 Export: warning, invalid path option rw
> =====> oss.defaults rw
> ------ anon@REDIRECTOR phase 1 manager initialization completed.
> 180426 11:39:55 6048 XrdConfig: LCL port 3121 wsz=87380 (87380)
> 180426 11:39:55 6048 XrdProtocol: getting protocol object cmsd
> ++++++ anon@REDIRECTOR phase 2 manager initialization started.
> 180426 11:39:55 6048 Replenish old free 0 + 4096 = 4096
> Config warning: adminpath resides in /tmp and may be unstable!
> 180426 11:39:55 6048 Configure2 Global System Identification: anon-m
> 3121REDIRECTOR
> ++++++ Storage system initialization started.
> =====> all.export /xrootd
> 180426 11:39:55 6048 oss_Export: warning, invalid path option rw
> =====> oss.defaults rw
> ++++++ Configuring standalone mode . . .
> 180426 11:39:55 6048 oss_AioInit: started AIO read signal thread;
> tid=1245079296
> 180426 11:39:55 6048 oss_AioInit: started AIO write signal thread;
> tid=1244026624
> Config effective /etc/xrootd/xrootd.cf oss configuration:
> oss.alloc 0 0 0
> oss.cachescan 600
> oss.fdlimit 2048 4096
> oss.maxsize 0
> oss.trace fff
> oss.xfr 1 deny 10800 keep 1200
> oss.memfile off max 2067851264
> oss.defaults r/w nocheck nodread nomig norcreate nopurge
> nostage xattr
> oss.path /xrootd r/w nocheck nodread nomig norcreate nopurge
> nostage xattr
> ------ Storage system initialization completed.
> 180426 11:39:55 6048 Start Srv=0 dfs=0 lcl=0 Pre=1 dmLife=0 0
> 180426 11:39:55 6048 Start Lim=0 0 fix=0 Qmax=1
> Config round robin scheduling in effect.
> 180426 11:39:55 6048 Update FrontEnd Parm1=1 Parm2=0
> ------ anon@REDIRECTOR phase 2 manager initialization completed.
> 180426 11:39:55 6057 XrdXeq: Cache Clock thread started
> 180426 11:39:55 6060 XrdXeq: Performance monitor thread started
> ------ cmsd anon@REDIRECTOR:3121 initialization completed.
> 180426 11:39:55 6052 XrdSched: running cmsd startup inq=1
> 180426 11:39:55 6053 XrdSched: Now have 3 workers
> 180426 11:39:55 6053 XrdSched: running main accept inq=0
> 180426 11:39:55 6065 XrdXeq: Admin traffic thread started
> 180426 11:39:55 6066 XrdXeq: Worker thread started
> 180426 11:39:55 6063 XrdXeq: Request Timeout thread started
> 180426 11:39:55 6068 XrdXeq: State monitor thread started
> 180426 11:39:55 6062 XrdXeq: Request Responder thread started
> 180426 11:39:55 6061 XrdXeq: Refcount monitor thread started
> 180426 11:39:55 6064 XrdXeq: Prep handler thread started
> 180426 11:39:55 6066 XrdSched: Now have 4 workers
> 180426 11:39:55 6066 XrdSched: running main accept inq=0
> 180426 11:39:55 6114 XrdXeq: Worker thread started
> 180426 11:39:55 6053 XrdInet: Accepted connection from 7@REDIRECTOR
> 180426 11:39:55 6053 XrdProtocol: matched protocol cmsd
> 180426 11:39:55 6053 ?:7@REDIRECTOR XrdPoll: FD 7 attached to poller 0;
> num=1
> 180426 11:39:55 6053 Protocol: redirector.6099:7@REDIRECTOR logged in.
> 180426 11:39:55 6053 Admit_Redirector redirector.6099:7@REDIRECTOR
> assigned slot 1
> 180426 11:40:03 6114 XrdSched: Now have 5 workers
> 180426 11:40:03 6114 XrdSched: running main accept inq=0
> 180426 11:40:03 6165 XrdXeq: Worker thread started
> 180426 11:40:03 6165 XrdSched: Now have 6 workers
> 180426 11:40:03 6165 XrdSched: running main accept inq=0
> 180426 11:40:03 6166 XrdXeq: Worker thread started
> 180426 11:40:03 6166 XrdSched: Now have 7 workers
> 180426 11:40:03 6166 XrdSched: running main accept inq=0
> 180426 11:40:03 6167 XrdXeq: Worker thread started
> 180426 11:40:03 6167 XrdSched: Now have 8 workers
> 180426 11:40:03 6167 XrdSched: running main accept inq=0
> 180426 11:40:03 6168 XrdXeq: Worker thread started
> 180426 11:40:03 6168 XrdSched: Now have 9 workers
> 180426 11:40:03 6168 XrdSched: running main accept inq=0
> 180426 11:40:03 6169 XrdXeq: Worker thread started
> 180426 11:40:03 6169 XrdSched: Now have 10 workers
> 180426 11:40:03 6169 XrdSched: running main accept inq=0
> 180426 11:40:03 6170 XrdXeq: Worker thread started
> 180426 11:40:03 6170 XrdSched: Now have 11 workers
> 180426 11:40:03 6170 XrdSched: running main accept inq=0
> 180426 11:40:03 6171 XrdXeq: Worker thread started
> 180426 11:40:03 6171 XrdSched: Now have 12 workers
> 180426 11:40:03 6171 XrdSched: running main accept inq=0
> 180426 11:40:03 6172 XrdXeq: Worker thread started
> 180426 11:40:03 6172 XrdSched: Now have 13 workers
> 180426 11:40:03 6172 XrdSched: running main accept inq=0
> 180426 11:40:03 6173 XrdXeq: Worker thread started
> 180426 11:40:03 6173 XrdSched: Now have 14 workers
> 180426 11:40:03 6173 XrdSched: running main accept inq=0
> 180426 11:40:03 6174 XrdXeq: Worker thread started
> 180426 11:40:03 6174 XrdSched: Now have 15 workers
> 180426 11:40:03 6174 XrdSched: running main accept inq=0
> 180426 11:40:03 6175 XrdXeq: Worker thread started
> 180426 11:40:03 6175 XrdSched: Now have 16 workers
> 180426 11:40:03 6175 XrdSched: running main accept inq=0
> 180426 11:40:03 6176 XrdXeq: Worker thread started
> 180426 11:40:03 6066 XrdInet: Accepted connection from 18@DATASERVER28
> 180426 11:40:03 6066 XrdProtocol: matched protocol cmsd
> 180426 11:40:03 6066 ?:18@DATASERVER28 XrdPoll: FD 18 attached to poller
> 1; num=1
> 180426 11:40:03 6114 XrdInet: Accepted connection from 20@DATASERVER21
> 180426 11:40:03 6114 XrdProtocol: matched protocol cmsd
> 180426 11:40:03 6114 ?:20@DATASERVER21 XrdPoll: FD 20 attached to poller
> 2; num=1
> 180426 11:40:03 6165 XrdInet: Accepted connection from 22@DATASERVER36
> 180426 11:40:03 6165 XrdProtocol: matched protocol cmsd
> 180426 11:40:03 6165 ?:22@DATASERVER36 XrdPoll: FD 22 attached to poller
> 0; num=2
> 180426 11:40:03 6167 XrdInet: Accepted connection from 25@DATASERVER37
> 180426 11:40:03 6166 XrdInet: Accepted connection from 24@DATASERVER22
> 180426 11:40:03 6167 XrdProtocol: matched protocol cmsd
> 180426 11:40:03 6166 XrdProtocol: matched protocol cmsd
> 180426 11:40:03 6167 ?:25@DATASERVER37 XrdPoll: FD 25 attached to poller
> 1; num=2
> 180426 11:40:03 6166 ?:24@DATASERVER22 XrdPoll: FD 24 attached to poller
> 2; num=2
> 180426 11:40:03 6168 XrdInet: Accepted connection from 28@DATASERVER23
> 180426 11:40:03 6168 XrdProtocol: matched protocol cmsd
> 180426 11:40:03 6168 ?:28@DATASERVER23 XrdPoll: FD 28 attached to poller
> 0; num=3
> 180426 11:40:03 6169 XrdInet: Accepted connection from 29@DATASERVER29
> 180426 11:40:03 6169 XrdProtocol: matched protocol cmsd
> 180426 11:40:03 6169 ?:29@DATASERVER29 XrdPoll: FD 29 attached to poller
> 1; num=3
> 180426 11:40:03 6172 XrdInet: Accepted connection from 36@DATASERVER25
> 180426 11:40:03 6172 XrdProtocol: matched protocol cmsd
> 180426 11:40:03 6172 ?:36@DATASERVER25 XrdPoll: FD 36 attached to poller
> 2; num=3
> 180426 11:40:03 6170 XrdInet: Accepted connection from 31@DATASERVER32
> 180426 11:40:03 6170 XrdProtocol: matched protocol cmsd
> 180426 11:40:03 6170 ?:31@DATASERVER32 XrdPoll: FD 31 attached to poller
> 0; num=4
> 180426 11:40:03 6171 XrdInet: Accepted connection from 33@DATASERVER30
> 180426 11:40:03 6171 XrdProtocol: matched protocol cmsd
> 180426 11:40:03 6171 ?:33@DATASERVER30 XrdPoll: FD 33 attached to poller
> 1; num=4
> 180426 11:40:03 6173 XrdInet: Accepted connection from 38@DATASERVER20
> 180426 11:40:03 6173 XrdProtocol: matched protocol cmsd
> 180426 11:40:03 6173 ?:38@DATASERVER20 XrdPoll: FD 38 attached to poller
> 2; num=4
> 180426 11:40:03 6174 XrdInet: Accepted connection from 40@DATASERVER31
> 180426 11:40:03 6174 XrdProtocol: matched protocol cmsd
> 180426 11:40:03 6174 ?:40@DATASERVER31 XrdPoll: FD 40 attached to poller
> 0; num=5
> 180426 11:40:03 6066 AddNode srv server.1614:18@DATASERVER28:1094
> cluster 3121REDIRECTOR mask=1 anum=0
> 180426 11:40:03 6066 Add server.1614:18@DATASERVER28:1094 to cluster
> anon-s 3121REDIRECTOR slot 0.2 (nodecnt=1 supn=1)
> 180426 11:40:03 6066 Update Counts Parm1=1 Parm2=0
> 180426 11:40:03 6066 Admit DATASERVER28 TSpace=53406728GB NumFS=1
> FSpace=10026659MB MinFR=102400 MB Util=82 Share=100 TZone=1
> 180426 11:40:03 6066 Admit DATASERVER28 adding path: w /xrootd
> 180426 11:40:03 6114 AddNode srv server.1510:20@DATASERVER21:1094
> cluster 3121REDIRECTOR mask=3 anum=0
> 180426 11:40:03 6114 Add server.1510:20@DATASERVER21:1094 to cluster
> anon-s 3121REDIRECTOR slot 1.3 (nodecnt=2 supn=1)
> 180426 11:40:03 6114 Update Counts Parm1=1 Parm2=0
> 180426 11:40:03 6114 Admit DATASERVER21 TSpace=62941192GB NumFS=1
> FSpace=32219949MB MinFR=102400 MB Util=49 Share=100 TZone=1
> 180426 11:40:03 6114 Admit DATASERVER21 adding path: w /xrootd
> 180426 11:40:03 6165 AddNode srv server.1531:22@DATASERVER36:1094
> cluster 3121REDIRECTOR mask=7 anum=0
> 180426 11:40:03 6165 Add server.1531:22@DATASERVER36:1094 to cluster
> anon-s 3121REDIRECTOR slot 2.4 (nodecnt=3 supn=2)
> 180426 11:40:03 6165 Update Counts Parm1=1 Parm2=0
> 180426 11:40:03 6165 Admit DATASERVER36 TSpace=20978570GB NumFS=1
> FSpace=5317670MB MinFR=102400 MB Util=75 Share=100 TZone=1
> 180426 11:40:03 6165 Admit DATASERVER36 adding path: w /xrootd
> 180426 11:40:03 6167 AddNode srv server.1520:25@DATASERVER37:1094
> cluster 3121REDIRECTOR mask=f anum=0
> 180426 11:40:03 6167 Add server.1520:25@DATASERVER37:1094 to cluster
> anon-s 3121REDIRECTOR slot 3.5 (nodecnt=4 supn=3)
> 180426 11:40:03 6167 Update Counts Parm1=1 Parm2=0
> 180426 11:40:03 6167 Admit DATASERVER37 TSpace=62941192GB NumFS=1
> FSpace=19975075MB MinFR=102400 MB Util=69 Share=100 TZone=1
> 180426 11:40:03 6167 Admit DATASERVER37 adding path: w /xrootd
> 180426 11:40:03 6166 AddNode srv server.1401:24@DATASERVER22:1094
> cluster 3121REDIRECTOR mask=1f anum=0
> 180426 11:40:03 6166 Add server.1401:24@DATASERVER22:1094 to cluster
> anon-s 3121REDIRECTOR slot 4.6 (nodecnt=5 supn=4)
> 180426 11:40:03 6166 Update Counts Parm1=1 Parm2=0
> 180426 11:40:03 6166 Admit DATASERVER22 TSpace=13349258GB NumFS=1
> FSpace=666816MB MinFR=102400 MB Util=96 Share=100 TZone=1
> 180426 11:40:03 6166 Admit DATASERVER22 adding path: w /xrootd
> 180426 11:40:03 6168 AddNode srv server.1602:28@DATASERVER23:1094
> cluster 3121REDIRECTOR mask=3f anum=0
> 180426 11:40:03 6168 Add server.1602:28@DATASERVER23:1094 to cluster
> anon-s 3121REDIRECTOR slot 5.7 (nodecnt=6 supn=4)
> 180426 11:40:03 6168 Update Counts Parm1=1 Parm2=0
> 180426 11:40:03 6168 Admit DATASERVER23 TSpace=40052744GB NumFS=1
> FSpace=7139949MB MinFR=102400 MB Util=83 Share=100 TZone=1
> 180426 11:40:03 6168 Admit DATASERVER23 adding path: w /xrootd
> 180426 11:40:03 6169 AddNode srv server.1650:29@DATASERVER29:1094
> cluster 3121REDIRECTOR mask=7f anum=0
> 180426 11:40:03 6169 Add server.1650:29@DATASERVER29:1094 to cluster
> anon-s 3121REDIRECTOR slot 6.8 (nodecnt=7 supn=5)
> 180426 11:40:03 6169 Update Counts Parm1=1 Parm2=0
> 180426 11:40:03 6169 Admit DATASERVER29 TSpace=53406728GB NumFS=1
> FSpace=22214021MB MinFR=102400 MB Util=59 Share=100 TZone=1
> 180426 11:40:03 6169 Admit DATASERVER29 adding path: w /xrootd
> 180426 11:40:03 6172 AddNode srv server.1498:36@DATASERVER25:1094
> cluster 3121REDIRECTOR mask=ff anum=0
> 180426 11:40:03 6172 Add server.1498:36@DATASERVER25:1094 to cluster
> anon-s 3121REDIRECTOR slot 7.9 (nodecnt=8 supn=6)
> 180426 11:40:03 6172 Update Counts Parm1=1 Parm2=0
> 180426 11:40:03 6172 Admit DATASERVER25 TSpace=95368200GB NumFS=1
> FSpace=87200133MB MinFR=102400 MB Util=9 Share=100 TZone=1
> 180426 11:40:03 6172 Admit DATASERVER25 adding path: w /xrootd
> 180426 11:40:03 6170 AddNode srv server.1453:31@DATASERVER32:1094
> cluster 3121REDIRECTOR mask=1ff anum=0
> 180426 11:40:03 6170 Add server.1453:31@DATASERVER32:1094 to cluster
> anon-s 3121REDIRECTOR slot 8.10 (nodecnt=9 supn=7)
> 180426 11:40:03 6170 Update Counts Parm1=1 Parm2=0
> 180426 11:40:03 6170 Admit DATASERVER32 TSpace=30519426GB NumFS=1
> FSpace=4808549MB MinFR=102400 MB Util=85 Share=100 TZone=1
> 180426 11:40:03 6170 Admit DATASERVER32 adding path: w /xrootd
> 180426 11:40:03 6171 AddNode srv server.1395:33@DATASERVER30:1094
> cluster 3121REDIRECTOR mask=3ff anum=0
> 180426 11:40:03 6171 Add server.1395:33@DATASERVER30:1094 to cluster
> anon-s 3121REDIRECTOR slot 9.11 (nodecnt=10 supn=8)
> 180426 11:40:03 6171 Update Counts Parm1=1 Parm2=0
> 180426 11:40:03 6171 Admit DATASERVER30 TSpace=133516296GB NumFS=1
> FSpace=23452231MB MinFR=102400 MB Util=83 Share=100 TZone=1
> 180426 11:40:03 6171 Admit DATASERVER30 adding path: w /xrootd
> 180426 11:40:03 6173 AddNode srv server.4128:38@DATASERVER20:1094
> cluster 3121REDIRECTOR mask=7ff anum=0
> 180426 11:40:03 6173 Add server.4128:38@DATASERVER20:1094 to cluster
> anon-s 3121REDIRECTOR slot 10.12 (nodecnt=11 supn=8)
> 180426 11:40:03 6173 Update Counts Parm1=1 Parm2=0
> 180426 11:40:03 6173 Admit DATASERVER20 TSpace=53406728GB NumFS=1
> FSpace=6878907MB MinFR=102400 MB Util=88 Share=100 TZone=1
> 180426 11:40:03 6173 Admit DATASERVER20 adding path: w /xrootd
> 180426 11:40:03 6174 AddNode srv server.1386:40@DATASERVER31:1094
> cluster 3121REDIRECTOR mask=fff anum=0
> 180426 11:40:03 6174 Add server.1386:40@DATASERVER31:1094 to cluster
> anon-s 3121REDIRECTOR slot 11.13 (nodecnt=12 supn=9)
> 180426 11:40:03 6174 Update Counts Parm1=1 Parm2=0
> 180426 11:40:03 6174 Admit DATASERVER31 TSpace=30519426GB NumFS=1
> FSpace=9967539MB MinFR=102400 MB Util=68 Share=100 TZone=1
> 180426 11:40:03 6170 server.1453:31@DATASERVER32:1094 do_Space:
> 87200133MB free; 9% util
> 180426 11:40:03 6114 Protocol: Primary server.1510:20@DATASERVER21:1094
> logged in.
> 180426 11:40:03 6171 server.1395:33@DATASERVER30:1094 do_Space:
> 87200133MB free; 9% util
> 180426 11:40:03 6167 server.1520:25@DATASERVER37:1094 do_Space:
> 87200133MB free; 9% util
> 180426 11:40:03 6166 server.1401:24@DATASERVER22:1094 do_Space:
> 87200133MB free; 9% util
> 180426 11:40:03 6169 server.1650:29@DATASERVER29:1094 do_Space:
> 87200133MB free; 9% util
> 180426 11:40:03 6172 Protocol: Primary server.1498:36@DATASERVER25:1094
> logged in.
> 180426 11:40:03 6168 server.1602:28@DATASERVER23:1094 do_Space:
> 87200133MB free; 9% util
> 180426 11:40:03 6174 Admit DATASERVER31 adding path: w /xrootd
> 180426 11:40:03 6174 server.1386:40@DATASERVER31:1094 do_Space:
> 87200133MB free; 9% util
> 180426 11:40:03 6170 Protocol: Primary server.1453:31@DATASERVER32:1094
> logged in.
> =====> Routing for 192.168.16.121: local pub4 prv4
> 180426 11:40:03 6165 server.1531:22@DATASERVER36:1094 do_Space:
> 87200133MB free; 9% util
> 180426 11:40:03 6171 Protocol: Primary server.1395:33@DATASERVER30:1094
> logged in.
> 180426 11:40:03 6173 server.4128:38@DATASERVER20:1094 do_Space:
> 87200133MB free; 9% util
> 180426 11:40:03 6167 Protocol: Primary server.1520:25@DATASERVER37:1094
> logged in.
> 180426 11:40:03 6166 Protocol: Primary server.1401:24@DATASERVER22:1094
> logged in.
> 180426 11:40:03 6169 Protocol: Primary server.1650:29@DATASERVER29:1094
> logged in.
> =====> Routing for 192.168.16.127: local pub4 prv4
> 180426 11:40:03 6168 Protocol: Primary server.1602:28@DATASERVER23:1094
> logged in.
> 180426 11:40:03 6066 server.1614:18@DATASERVER28:1094 do_Space:
> 87200133MB free; 9% util
> 180426 11:40:03 6174 Protocol: Primary server.1386:40@DATASERVER31:1094
> logged in.
> =====> Routing for 192.168.16.147: local pub4 prv4
> =====> Route all4: 192.168.16.121 Dest=[::192.168.16.121]:1094
> 180426 11:40:03 6165 Protocol: Primary server.1531:22@DATASERVER36:1094
> logged in.
> =====> Routing for 192.168.16.144: local pub4 prv4
> 180426 11:40:03 6173 Protocol: Primary server.4128:38@DATASERVER20:1094
> logged in.
> =====> Routing for 192.168.16.196: local pub4 prv4
> =====> Routing for 192.168.16.97: local pub4 prv4
> =====> Routing for 192.168.16.139: local pub4 prv4
> =====> Route all4: 192.168.16.127 Dest=[::192.168.16.127]:1094
> =====> Routing for 192.168.16.134: local pub4 prv4
> 180426 11:40:03 6066 Protocol: Primary server.1614:18@DATASERVER28:1094
> logged in.
> =====> Routing for 192.168.16.146: local pub4 prv4
> =====> Route all4: 192.168.16.147 Dest=[::192.168.16.147]:1094
> =====> Routing for 192.168.16.195: local pub4 prv4
> =====> Route all4: 192.168.16.144 Dest=[::192.168.16.144]:1094
> =====> Routing for 192.168.16.120: local pub4 prv4
> =====> Route all4: 192.168.16.196 Dest=[::192.168.16.196]:1094
> =====> Route all4: 192.168.16.97 Dest=[::192.168.16.97]:1094
> =====> Route all4: 192.168.16.139 Dest=[::192.168.16.139]:1094
> =====> Route all4: 192.168.16.134 Dest=[::192.168.16.134]:1094
> =====> Routing for 192.168.16.217: local pub4 prv4
> =====> Route all4: 192.168.16.146 Dest=[::192.168.16.146]:1094
> =====> Route all4: 192.168.16.195 Dest=[::192.168.16.195]:1094
> =====> Route all4: 192.168.16.120 Dest=[::192.168.16.120]:1094
> =====> Route all4: 192.168.16.217 Dest=[::192.168.16.217]:1094
> 180426 11:40:55 6176 XrdSched: Now have 17 workers
> 180426 11:40:55 6188 XrdXeq: Worker thread started
> 180426 11:41:25 6052 Update Stage Parm1=-1 Parm2=0
> 180426 11:41:25 6052 Update Active Parm1=-1 Parm2=0
> 180426 11:41:25 6052 Config: manager service enabled.
> 180426 11:41:25 6068 State: Status changed to active + nostaging
> 180426 11:41:25 6068 Send status to redirector.6099:7@REDIRECTOR
> 180426 11:41:42 6053 Dispatch redirector.6099:7@REDIRECTOR for select
> dlen=63
> 180426 11:41:42 6053 redirector.6099:7@REDIRECTOR XrdLink: Setting ref
> to 1+1 post=0
> 180426 11:41:42 6176 XrdSched: running redirector inq=0
> 180426 11:41:42 6176 schroete.289158:7@CLIENT do_Select: Px
> /xrootd/schroete/willi.dat
> 180426 11:41:42 6176 WT4File rc=0 path=/xrootd/schroete/willi.dat
> 180426 11:41:42 6176 Select seeking /xrootd/schroete/willi.dat
> 180426 11:41:42 6176 redirector.6099:7@REDIRECTOR XrdLink: Setting ref
> to 2+-1 post=0
> 180426 11:41:47 6053 Dispatch redirector.6099:7@REDIRECTOR for select
> dlen=63
> 180426 11:41:47 6053 redirector.6099:7@REDIRECTOR XrdLink: Setting ref
> to 1+1 post=0
> 180426 11:41:47 6188 XrdSched: running redirector inq=0
> 180426 11:41:47 6188 schroete.289158:7@CLIENT do_Select: Px
> /xrootd/schroete/willi.dat
> 180426 11:41:47 6188 schroete.289158:7@CLIENT do_Select: failed; No
> servers are available to read the file. /xrootd/schroete/willi.dat
> 180426 11:41:47 6188 redirector.6099:7@REDIRECTOR XrdLink: Setting ref
> to 2+-1 post=0
> 180426 11:41:47 6053 Dispatch redirector.6099:7@REDIRECTOR for select
> dlen=78
> 180426 11:41:47 6053 redirector.6099:7@REDIRECTOR XrdLink: Setting ref
> to 1+1 post=0
> 180426 11:41:47 6052 XrdSched: running redirector inq=0
> 180426 11:41:47 6052 schroete.289158:7@CLIENT do_Select: Pwc
> /xrootd/schroete/willi.dat
> 180426 11:41:47 6052 SelNode 192.168.16.217 assigned
> /xrootd/schroete/willi.dat
> 180426 11:41:47 6052 schroete.289158:7@CLIENT do_Select: Redirect ->
> 192.168.16.217:1094 for /xrootd/schroete/willi.dat
> 180426 11:41:47 6052 redirector.6099:7@REDIRECTOR XrdLink: Setting ref
> to 2+-1 post=0
> 180426 11:41:47 6066 Dispatch server.1614:18@DATASERVER28:1094 for have
> dlen=27
> 180426 11:41:47 6066 server.1614:18@DATASERVER28 XrdLink: Setting ref to
> 1+1 post=0
> 180426 11:41:47 6176 XrdSched: running server inq=0
> 180426 11:41:47 6176 server.1614:18@DATASERVER28:1094 do_Have:
> /xrootd/schroete/willi.dat
> 180426 11:41:47 6176 server.1614:18@DATASERVER28 XrdLink: Setting ref to
> 2+-1 post=0
>
>
> XROOTD.LOG
> 180426 11:39:55 6099 Starting on Linux 4.13.0-38-generic
> Copr. 2004-2012 Stanford University, xrd version v4.8.3-rc1
> ++++++ xrootd anon@REDIRECTOR initialization started.
> Config using configuration file /etc/xrootd/xrootd.cf
> =====> xrd.port 1094
> Config maximum number of connections restricted to 4096
> Config maximum number of threads restricted to 15569
> 180426 11:39:55 6099 XrdConfig: sendfile enabled.
> 180426 11:39:55 6101 XrdXeq: Buffer Manager reshaper thread started
> 180426 11:39:55 6099 XrdSched: scheduling underused thread monitor in
> 780 seconds
> 180426 11:39:55 6102 XrdXeq: Time scheduler thread started
> 180426 11:39:55 6103 XrdXeq: Worker thread started
> 180426 11:39:55 6099 XrdSched: Starting with 2 workers
> 180426 11:39:55 6104 XrdXeq: Worker thread started
> 180426 11:39:55 6099 XrdLink: Allocating 8 link objects at a time
> 180426 11:39:55 6099 XrdPoll: Starting poller 0
> 180426 11:39:55 6105 XrdXeq: Poller thread started
> 180426 11:39:55 6099 XrdPoll: Starting poller 1
> 180426 11:39:55 6106 XrdXeq: Poller thread started
> 180426 11:39:55 6099 XrdPoll: Starting poller 2
> 180426 11:39:55 6107 XrdXeq: Poller thread started
> 180426 11:39:55 6099 XrdProtocol: getting port from protocol xrootd
> 180426 11:39:55 6099 XrdConfig: LCL port 1094 wsz=87380 (87380)
> 180426 11:39:55 6099 XrdProtocol: getting protocol object xrootd
> Copr. 2012 Stanford University, xrootd protocol 3.1.0 version v4.8.3-rc1
> ++++++ xrootd protocol initialization started.
> =====> all.export /xrootd
> =====> xrootd.fsoverload stall 1
> Config exporting /xrootd
> Config warning: 'xrootd.seclib' not specified; strong authentication
> disabled!
> Config Routing for 192.168.16.124: local pub4 prv4
> Config Route all4: 192.168.16.124 Dest=[::192.168.16.124]:1094
> ++++++ File system initialization started.
> =====> all.role manager
> ++++++ Storage system initialization started.
> =====> all.export /xrootd
> 180426 11:39:55 6099 oss_Export: warning, invalid path option rw
> =====> oss.defaults rw
> 180426 11:39:55 6099 oss_AioInit: started AIO read signal thread;
> tid=499631872
> 180426 11:39:55 6099 oss_AioInit: started AIO write signal thread;
> tid=498579200
> 180426 11:39:55 6110 XrdXeq: cache scan thread started
> Config effective /etc/xrootd/xrootd.cf oss configuration:
> oss.alloc 0 0 0
> oss.cachescan 600
> oss.fdlimit 2048 4096
> oss.maxsize 0
> oss.trace fff
> oss.xfr 1 deny 10800 keep 1200
> oss.memfile off max 2067851264
> oss.defaults r/w nocheck nodread nomig norcreate nopurge
> nostage xattr
> oss.path /xrootd r/w nocheck nodread nomig norcreate nopurge
> nostage xattr
> ------ Storage system initialization completed.
> ++++++ Configuring manager role. . .
> =====> all.manager REDIRECTOR:3121
> 180426 11:39:55 6099 Configure Global System Identification: anon-m
> 3121REDIRECTOR
> Config 1 manager(s) started.
> 180426 11:39:55 6111 XrdXeq: REDIRECTOR thread started
> Config effective /etc/xrootd/xrootd.cf ofs configuration:
> all.role manager
> ofs.maxdelay 60
> ofs.persist manual hold 600 logdir /tmp/.ofs/posc.log
> ofs.trace bfcd
> ------ File system manager initialization completed.
> 180426 11:39:55 6099 XrootdAioReq: Max aio/req=8; aio/srv=4096;
> Quantum=131072
> 180426 11:39:55 6099 XrootdAioReq: Adding 18 aioreq objects.
> 180426 11:39:55 6099 XrootdAio: Adding 18 aio objects; 4096 pending.
> 180426 11:39:55 6099 XrdSched: scheduling xrootd protocol anchor in 3600
> seconds
> 180426 11:39:55 6099 XrdSched: scheduling transit protocol anchor in
> 3600 seconds
> Config warning: 'xrootd.prepare logdir' not specified; prepare tracking
> disabled.
> ------ xrootd protocol initialization completed.
> 180426 11:39:55 6111 XrdInet: Connected to REDIRECTOR:3121
> 180426 11:39:55 6111 cms_ClientMan: Connected to suspended REDIRECTOR v 3
> 180426 11:39:55 6111 Hookup REDIRECTOR qt=178ms rw=2
> ------ xrootd anon@REDIRECTOR:1094 initialization completed.
> 180426 11:39:55 6103 XrdSched: running main accept inq=0
> 180426 11:39:55 6113 XrdXeq: Admin traffic thread started
> 180426 11:39:55 6112 XrdXeq: async callback thread started
> 180426 11:41:25 6111 Receive REDIRECTOR 0 bytes on 0
> 180426 11:41:25 6111 setStatus REDIRECTOR sent resume event
> 180426 11:41:25 6111 cms_setStatus: Manager REDIRECTOR resumed
>
> 180426 11:41:42 6104 XrdSched: Now have 3 workers
> 180426 11:41:42 6104 XrdSched: running main accept inq=0
> 180426 11:41:42 6103 XrdInet: Accepted connection from 7@CLIENT
> 180426 11:41:42 6103 XrdProtocol: matched protocol xrootd
> 180426 11:41:42 6103 ?:7@CLIENT XrdPoll: FD 7 attached to poller 0; num=1
> 180426 11:41:42 6103 ?:7@CLIENT XrootdProtocol: 0000 req=login dlen=101
> 180426 11:41:42 6103 schroete.289158:7@CLIENT XrootdResponse: 0000
> sending 16 data bytes
> 180426 11:41:42 6103 XrootdXeq: schroete.289158:7@CLIENT pvt IPv4 login
> 180426 11:41:42 6193 XrdXeq: Worker thread started
> 180426 11:41:42 6103 schroete.289158:7@CLIENT XrootdProtocol: 0100
> req=stat dlen=26
> 180426 11:41:42 6103 schroete.289158:7@CLIENT ofs_stat:
> fn=/xrootd/schroete/willi.dat
> 180426 11:41:42 6111 Receive REDIRECTOR 4 bytes on 3071
> 180426 11:41:42 6111 Decode REDIRECTOR delays schroete.289158:7@CLIENT 5
> /xrootd/schroete/willi.dat
> 180426 11:41:42 6103 schroete.289158:7@CLIENT XrootdProtocol: 0100 rc=5
> stat /xrootd/schroete/willi.dat
> 180426 11:41:42 6103 schroete.289158:7@CLIENT XrootdProtocol: 0100
> stalling client for 5 sec
> 180426 11:41:42 6103 schroete.289158:7@CLIENT XrootdResponse: 0100
> sending 4 data bytes; status=4005
> 180426 11:41:45 6103 schroete.289158:7@CLIENT XrootdProtocol: 0100
> request timeout; read 0 of 24 bytes
> 180426 11:41:45 6103 XrdPoll: Poller 0 enabled schroete.289158:7@CLIENT
> 180426 11:41:47 6193 XrdSched: running schroete.289158:7@CLIENT inq=0
> 180426 11:41:47 6193 schroete.289158:7@CLIENT XrootdProtocol: 0100
> req=stat dlen=26
> 180426 11:41:47 6193 schroete.289158:7@CLIENT ofs_stat:
> fn=/xrootd/schroete/willi.dat
> 180426 11:41:47 6111 Receive REDIRECTOR 47 bytes on 4095
> 180426 11:41:47 6111 Decode REDIRECTOR gave schroete.289158:7@CLIENT err
> -2 'No servers are available to read the file.' /xrootd/schroete/willi.dat
> 180426 11:41:47 6193 schroete.289158:7@CLIENT XrootdProtocol: 0100 rc=-1
> stat /xrootd/schroete/willi.dat
> 180426 11:41:47 6193 schroete.289158:7@CLIENT XrootdResponse: 0100
> sending err 3011: No servers are available to read the file.
> 180426 11:41:47 6193 schroete.289158:7@CLIENT XrootdProtocol: 0100
> req=open dlen=40
> 180426 11:41:47 6193 schroete.289158:7@CLIENT XrootdProtocol: 0100 open
> unmat /xrootd/schroete/willi.dat?oss.asize=226
> 180426 11:41:47 6193 schroete.289158:7@CLIENT ofs_open: 102-40644
> fn=/xrootd/schroete/willi.dat
> 180426 11:41:47 6111 Receive REDIRECTOR 19 bytes on 5119
> 180426 11:41:47 6111 Decode REDIRECTOR redirects
> schroete.289158:7@CLIENT to 192.168.16.217:1094 /xrootd/schroete/willi.dat
> 180426 11:41:47 6193 schroete.289158:7@CLIENT XrootdProtocol: 0100
> redirecting to 192.168.16.217:1094
> 180426 11:41:47 6193 schroete.289158:7@CLIENT XrootdResponse: 0100
> sending 18 data bytes; status=4004
> 180426 11:41:47 6193 schroete.289158:7@CLIENT ofs_close: use=0 fn=dummy
> 180426 11:41:47 6193 XrootdXeq: schroete.289158:7@CLIENT disc 0:00:05
> 180426 11:41:47 6193 schroete.289158:7@CLIENT XrdPoll: FD 7 detached
> from poller 0; num=0
>
>
>
> Am 28.04.2018 um 04:30 schrieb xrootd-dev:
>> OK, below is what I got. Note that it starts with "XROOTD log:" there is
>> no hint of a cmsd log anywhere that I can see. If there is could you
>> cl;early indicate which one is which.
>>
>> Andy
>
> —
> You are receiving this because you commented.
> Reply to this email directly, view it on GitHub, or mute the thread.
>
>
>
> --------------------------------------------------------------------------------
>
> Use REPLY-ALL to reply to list
>
> To unsubscribe from the XROOTD-DEV list, click the following link:
> https://listserv.slac.stanford.edu/cgi-bin/wa?SUBED1=XROOTD-DEV&A=1
>
>
—
You are receiving this because you commented.
Reply to this email directly, view it on GitHub, or mute the thread.
—
You are receiving this because you commented.
Reply to this email directly, view it on GitHub, or mute the thread.
{"api_version":"1.0","publisher":{"api_key":"05dde50f1d1a384dd78767c55493e4bb","name":"GitHub"},"entity":{"external_key":"github/xrootd/xrootd","title":"xrootd/xrootd","subtitle":"GitHub repository","main_image_url":"https://cloud.githubusercontent.com/assets/143418/17495839/a5054eac-5d88-11e6-95fc-7290892c7bb5.png","avatar_image_url":"https://cloud.githubusercontent.com/assets/143418/15842166/7c72db34-2c0b-11e6-9aed-b52498112777.png","action":{"name":"Open in GitHub","url":"https://github.com/xrootd/xrootd"}},"updates":{"snippets":[{"icon":"PERSON","message":"@abh3 in #692: Hi Heiko,\n\nPlease look at the xrd.delay option (specifically, lookup and qdl). This is a detailed explanation in the subsequent section. Changing the default parameters is not something we recommend and can lead to aberrant behavior.\n\nhttp://xrootd.org/doc/dev49/cms_config.htm#_Toc506069425\n\nAndy\n\nFrom: hds1 \nSent: Monday, April 30, 2018 11:09 PM\nTo: xrootd/xrootd \nCc: Andrew Hanushevsky ; Comment \nSubject: Re: [xrootd/xrootd] v4.8.3-rc1 stalling client (#692)\n\nHello Andy,\n\nthank you very much for clarification. Could you pls tell me what the \nconfigurable variable is ?\nI'am not sure that i do understand the docs correctly.\n\nBest\nHeiko\n\n\nAm 01.05.2018 um 00:32 schrieb xrootd-dev:\n\u003e Hi Heiko,\n\u003e \n\u003e The logs together show a completely normal interaction:\n\u003e a) Client comes in does a stat() on a non-existent file. It takes a bit a time to resolve this so the client is asked to wait 5 seconds (configurable).\n\u003e b) The client comes back and re-issues the stat() and get the expected “file not found”.\n\u003e c) The client then opens the file for writing and is redirected to an appropriate server.\n\u003e \n\u003e There is nothing wrong here. Everything is as expected.\n\u003e \n\u003e Andy\n\u003e \n\u003e From: hds1\n\u003e Sent: Friday, April 27, 2018 11:23 PM\n\u003e To: xrootd/xrootd\n\u003e Cc: xrootd-dev ; Comment\n\u003e Subject: Re: [xrootd/xrootd] v4.8.3-rc1 stalling client (#692)\n\u003e \n\u003e Sorr for the confusion. What i meant was the comments in github not in\n\u003e one mail. To stop the confusion i inserted both log in this mail.\n\u003e \n\u003e Best\n\u003e Heiko\n\u003e \n\u003e \n\u003e CMSD LOG:\n\u003e 180426 11:39:55 6048 Starting on Linux 4.13.0-38-generic\n\u003e Copr. 2004-2012 Stanford University, xrd version v4.8.3-rc1\n\u003e ++++++ cmsd anon@REDIRECTOR initialization started.\n\u003e Config using configuration file /etc/xrootd/xrootd.cf\n\u003e =====\u003e xrd.port 1094\n\u003e Config maximum number of connections restricted to 4096\n\u003e Config maximum number of threads restricted to 15569\n\u003e 180426 11:39:55 6048 XrdConfig: sendfile enabled.\n\u003e 180426 11:39:55 6048 XrdSched: scheduling underused thread monitor in\n\u003e 780 seconds\n\u003e 180426 11:39:55 6048 XrdSched: Starting with 2 workers\n\u003e 180426 11:39:55 6048 XrdLink: Allocating 8 link objects at a time\n\u003e 180426 11:39:55 6048 XrdPoll: Starting poller 0\n\u003e 180426 11:39:55 6054 XrdXeq: Poller thread started\n\u003e 180426 11:39:55 6048 XrdPoll: Starting poller 1\n\u003e 180426 11:39:55 6053 XrdXeq: Worker thread started\n\u003e 180426 11:39:55 6052 XrdXeq: Worker thread started\n\u003e 180426 11:39:55 6055 XrdXeq: Poller thread started\n\u003e 180426 11:39:55 6048 XrdPoll: Starting poller 2\n\u003e 180426 11:39:55 6051 XrdXeq: Time scheduler thread started\n\u003e 180426 11:39:55 6056 XrdXeq: Poller thread started\n\u003e 180426 11:39:55 6048 XrdProtocol: getting port from protocol cmsd\n\u003e Copr. 2007 Stanford University/SLAC cmsd.\n\u003e ++++++ anon@REDIRECTOR phase 1 initialization started.\n\u003e =====\u003e all.export /xrootd\n\u003e 180426 11:39:55 6050 XrdXeq: Buffer Manager reshaper thread started\n\u003e =====\u003e all.manager REDIRECTOR:3121\n\u003e =====\u003e cms.allow host *\n\u003e =====\u003e all.role manager\n\u003e 180426 11:39:55 6048 Export: warning, invalid path option rw\n\u003e =====\u003e oss.defaults rw\n\u003e ------ anon@REDIRECTOR phase 1 manager initialization completed.\n\u003e 180426 11:39:55 6048 XrdConfig: LCL port 3121 wsz=87380 (87380)\n\u003e 180426 11:39:55 6048 XrdProtocol: getting protocol object cmsd\n\u003e ++++++ anon@REDIRECTOR phase 2 manager initialization started.\n\u003e 180426 11:39:55 6048 Replenish old free 0 + 4096 = 4096\n\u003e Config warning: adminpath resides in /tmp and may be unstable!\n\u003e 180426 11:39:55 6048 Configure2 Global System Identification: anon-m\n\u003e 3121REDIRECTOR\n\u003e ++++++ Storage system initialization started.\n\u003e =====\u003e all.export /xrootd\n\u003e 180426 11:39:55 6048 oss_Export: warning, invalid path option rw\n\u003e =====\u003e oss.defaults rw\n\u003e ++++++ Configuring standalone mode . . .\n\u003e 180426 11:39:55 6048 oss_AioInit: started AIO read signal thread;\n\u003e tid=1245079296\n\u003e 180426 11:39:55 6048 oss_AioInit: started AIO write signal thread;\n\u003e tid=1244026624\n\u003e Config effective /etc/xrootd/xrootd.cf oss configuration:\n\u003e oss.alloc 0 0 0\n\u003e oss.cachescan 600\n\u003e oss.fdlimit 2048 4096\n\u003e oss.maxsize 0\n\u003e oss.trace fff\n\u003e oss.xfr 1 deny 10800 keep 1200\n\u003e oss.memfile off max 2067851264\n\u003e oss.defaults r/w nocheck nodread nomig norcreate nopurge\n\u003e nostage xattr\n\u003e oss.path /xrootd r/w nocheck nodread nomig norcreate nopurge\n\u003e nostage xattr\n\u003e ------ Storage system initialization completed.\n\u003e 180426 11:39:55 6048 Start Srv=0 dfs=0 lcl=0 Pre=1 dmLife=0 0\n\u003e 180426 11:39:55 6048 Start Lim=0 0 fix=0 Qmax=1\n\u003e Config round robin scheduling in effect.\n\u003e 180426 11:39:55 6048 Update FrontEnd Parm1=1 Parm2=0\n\u003e ------ anon@REDIRECTOR phase 2 manager initialization completed.\n\u003e 180426 11:39:55 6057 XrdXeq: Cache Clock thread started\n\u003e 180426 11:39:55 6060 XrdXeq: Performance monitor thread started\n\u003e ------ cmsd anon@REDIRECTOR:3121 initialization completed.\n\u003e 180426 11:39:55 6052 XrdSched: running cmsd startup inq=1\n\u003e 180426 11:39:55 6053 XrdSched: Now have 3 workers\n\u003e 180426 11:39:55 6053 XrdSched: running main accept inq=0\n\u003e 180426 11:39:55 6065 XrdXeq: Admin traffic thread started\n\u003e 180426 11:39:55 6066 XrdXeq: Worker thread started\n\u003e 180426 11:39:55 6063 XrdXeq: Request Timeout thread started\n\u003e 180426 11:39:55 6068 XrdXeq: State monitor thread started\n\u003e 180426 11:39:55 6062 XrdXeq: Request Responder thread started\n\u003e 180426 11:39:55 6061 XrdXeq: Refcount monitor thread started\n\u003e 180426 11:39:55 6064 XrdXeq: Prep handler thread started\n\u003e 180426 11:39:55 6066 XrdSched: Now have 4 workers\n\u003e 180426 11:39:55 6066 XrdSched: running main accept inq=0\n\u003e 180426 11:39:55 6114 XrdXeq: Worker thread started\n\u003e 180426 11:39:55 6053 XrdInet: Accepted connection from 7@REDIRECTOR\n\u003e 180426 11:39:55 6053 XrdProtocol: matched protocol cmsd\n\u003e 180426 11:39:55 6053 ?:7@REDIRECTOR XrdPoll: FD 7 attached to poller 0;\n\u003e num=1\n\u003e 180426 11:39:55 6053 Protocol: redirector.6099:7@REDIRECTOR logged in.\n\u003e 180426 11:39:55 6053 Admit_Redirector redirector.6099:7@REDIRECTOR\n\u003e assigned slot 1\n\u003e 180426 11:40:03 6114 XrdSched: Now have 5 workers\n\u003e 180426 11:40:03 6114 XrdSched: running main accept inq=0\n\u003e 180426 11:40:03 6165 XrdXeq: Worker thread started\n\u003e 180426 11:40:03 6165 XrdSched: Now have 6 workers\n\u003e 180426 11:40:03 6165 XrdSched: running main accept inq=0\n\u003e 180426 11:40:03 6166 XrdXeq: Worker thread started\n\u003e 180426 11:40:03 6166 XrdSched: Now have 7 workers\n\u003e 180426 11:40:03 6166 XrdSched: running main accept inq=0\n\u003e 180426 11:40:03 6167 XrdXeq: Worker thread started\n\u003e 180426 11:40:03 6167 XrdSched: Now have 8 workers\n\u003e 180426 11:40:03 6167 XrdSched: running main accept inq=0\n\u003e 180426 11:40:03 6168 XrdXeq: Worker thread started\n\u003e 180426 11:40:03 6168 XrdSched: Now have 9 workers\n\u003e 180426 11:40:03 6168 XrdSched: running main accept inq=0\n\u003e 180426 11:40:03 6169 XrdXeq: Worker thread started\n\u003e 180426 11:40:03 6169 XrdSched: Now have 10 workers\n\u003e 180426 11:40:03 6169 XrdSched: running main accept inq=0\n\u003e 180426 11:40:03 6170 XrdXeq: Worker thread started\n\u003e 180426 11:40:03 6170 XrdSched: Now have 11 workers\n\u003e 180426 11:40:03 6170 XrdSched: running main accept inq=0\n\u003e 180426 11:40:03 6171 XrdXeq: Worker thread started\n\u003e 180426 11:40:03 6171 XrdSched: Now have 12 workers\n\u003e 180426 11:40:03 6171 XrdSched: running main accept inq=0\n\u003e 180426 11:40:03 6172 XrdXeq: Worker thread started\n\u003e 180426 11:40:03 6172 XrdSched: Now have 13 workers\n\u003e 180426 11:40:03 6172 XrdSched: running main accept inq=0\n\u003e 180426 11:40:03 6173 XrdXeq: Worker thread started\n\u003e 180426 11:40:03 6173 XrdSched: Now have 14 workers\n\u003e 180426 11:40:03 6173 XrdSched: running main accept inq=0\n\u003e 180426 11:40:03 6174 XrdXeq: Worker thread started\n\u003e 180426 11:40:03 6174 XrdSched: Now have 15 workers\n\u003e 180426 11:40:03 6174 XrdSched: running main accept inq=0\n\u003e 180426 11:40:03 6175 XrdXeq: Worker thread started\n\u003e 180426 11:40:03 6175 XrdSched: Now have 16 workers\n\u003e 180426 11:40:03 6175 XrdSched: running main accept inq=0\n\u003e 180426 11:40:03 6176 XrdXeq: Worker thread started\n\u003e 180426 11:40:03 6066 XrdInet: Accepted connection from 18@DATASERVER28\n\u003e 180426 11:40:03 6066 XrdProtocol: matched protocol cmsd\n\u003e 180426 11:40:03 6066 ?:18@DATASERVER28 XrdPoll: FD 18 attached to poller\n\u003e 1; num=1\n\u003e 180426 11:40:03 6114 XrdInet: Accepted connection from 20@DATASERVER21\n\u003e 180426 11:40:03 6114 XrdProtocol: matched protocol cmsd\n\u003e 180426 11:40:03 6114 ?:20@DATASERVER21 XrdPoll: FD 20 attached to poller\n\u003e 2; num=1\n\u003e 180426 11:40:03 6165 XrdInet: Accepted connection from 22@DATASERVER36\n\u003e 180426 11:40:03 6165 XrdProtocol: matched protocol cmsd\n\u003e 180426 11:40:03 6165 ?:22@DATASERVER36 XrdPoll: FD 22 attached to poller\n\u003e 0; num=2\n\u003e 180426 11:40:03 6167 XrdInet: Accepted connection from 25@DATASERVER37\n\u003e 180426 11:40:03 6166 XrdInet: Accepted connection from 24@DATASERVER22\n\u003e 180426 11:40:03 6167 XrdProtocol: matched protocol cmsd\n\u003e 180426 11:40:03 6166 XrdProtocol: matched protocol cmsd\n\u003e 180426 11:40:03 6167 ?:25@DATASERVER37 XrdPoll: FD 25 attached to poller\n\u003e 1; num=2\n\u003e 180426 11:40:03 6166 ?:24@DATASERVER22 XrdPoll: FD 24 attached to poller\n\u003e 2; num=2\n\u003e 180426 11:40:03 6168 XrdInet: Accepted connection from 28@DATASERVER23\n\u003e 180426 11:40:03 6168 XrdProtocol: matched protocol cmsd\n\u003e 180426 11:40:03 6168 ?:28@DATASERVER23 XrdPoll: FD 28 attached to poller\n\u003e 0; num=3\n\u003e 180426 11:40:03 6169 XrdInet: Accepted connection from 29@DATASERVER29\n\u003e 180426 11:40:03 6169 XrdProtocol: matched protocol cmsd\n\u003e 180426 11:40:03 6169 ?:29@DATASERVER29 XrdPoll: FD 29 attached to poller\n\u003e 1; num=3\n\u003e 180426 11:40:03 6172 XrdInet: Accepted connection from 36@DATASERVER25\n\u003e 180426 11:40:03 6172 XrdProtocol: matched protocol cmsd\n\u003e 180426 11:40:03 6172 ?:36@DATASERVER25 XrdPoll: FD 36 attached to poller\n\u003e 2; num=3\n\u003e 180426 11:40:03 6170 XrdInet: Accepted connection from 31@DATASERVER32\n\u003e 180426 11:40:03 6170 XrdProtocol: matched protocol cmsd\n\u003e 180426 11:40:03 6170 ?:31@DATASERVER32 XrdPoll: FD 31 attached to poller\n\u003e 0; num=4\n\u003e 180426 11:40:03 6171 XrdInet: Accepted connection from 33@DATASERVER30\n\u003e 180426 11:40:03 6171 XrdProtocol: matched protocol cmsd\n\u003e 180426 11:40:03 6171 ?:33@DATASERVER30 XrdPoll: FD 33 attached to poller\n\u003e 1; num=4\n\u003e 180426 11:40:03 6173 XrdInet: Accepted connection from 38@DATASERVER20\n\u003e 180426 11:40:03 6173 XrdProtocol: matched protocol cmsd\n\u003e 180426 11:40:03 6173 ?:38@DATASERVER20 XrdPoll: FD 38 attached to poller\n\u003e 2; num=4\n\u003e 180426 11:40:03 6174 XrdInet: Accepted connection from 40@DATASERVER31\n\u003e 180426 11:40:03 6174 XrdProtocol: matched protocol cmsd\n\u003e 180426 11:40:03 6174 ?:40@DATASERVER31 XrdPoll: FD 40 attached to poller\n\u003e 0; num=5\n\u003e 180426 11:40:03 6066 AddNode srv server.1614:18@DATASERVER28:1094\n\u003e cluster 3121REDIRECTOR mask=1 anum=0\n\u003e 180426 11:40:03 6066 Add server.1614:18@DATASERVER28:1094 to cluster\n\u003e anon-s 3121REDIRECTOR slot 0.2 (nodecnt=1 supn=1)\n\u003e 180426 11:40:03 6066 Update Counts Parm1=1 Parm2=0\n\u003e 180426 11:40:03 6066 Admit DATASERVER28 TSpace=53406728GB NumFS=1\n\u003e FSpace=10026659MB MinFR=102400 MB Util=82 Share=100 TZone=1\n\u003e 180426 11:40:03 6066 Admit DATASERVER28 adding path: w /xrootd\n\u003e 180426 11:40:03 6114 AddNode srv server.1510:20@DATASERVER21:1094\n\u003e cluster 3121REDIRECTOR mask=3 anum=0\n\u003e 180426 11:40:03 6114 Add server.1510:20@DATASERVER21:1094 to cluster\n\u003e anon-s 3121REDIRECTOR slot 1.3 (nodecnt=2 supn=1)\n\u003e 180426 11:40:03 6114 Update Counts Parm1=1 Parm2=0\n\u003e 180426 11:40:03 6114 Admit DATASERVER21 TSpace=62941192GB NumFS=1\n\u003e FSpace=32219949MB MinFR=102400 MB Util=49 Share=100 TZone=1\n\u003e 180426 11:40:03 6114 Admit DATASERVER21 adding path: w /xrootd\n\u003e 180426 11:40:03 6165 AddNode srv server.1531:22@DATASERVER36:1094\n\u003e cluster 3121REDIRECTOR mask=7 anum=0\n\u003e 180426 11:40:03 6165 Add server.1531:22@DATASERVER36:1094 to cluster\n\u003e anon-s 3121REDIRECTOR slot 2.4 (nodecnt=3 supn=2)\n\u003e 180426 11:40:03 6165 Update Counts Parm1=1 Parm2=0\n\u003e 180426 11:40:03 6165 Admit DATASERVER36 TSpace=20978570GB NumFS=1\n\u003e FSpace=5317670MB MinFR=102400 MB Util=75 Share=100 TZone=1\n\u003e 180426 11:40:03 6165 Admit DATASERVER36 adding path: w /xrootd\n\u003e 180426 11:40:03 6167 AddNode srv server.1520:25@DATASERVER37:1094\n\u003e cluster 3121REDIRECTOR mask=f anum=0\n\u003e 180426 11:40:03 6167 Add server.1520:25@DATASERVER37:1094 to cluster\n\u003e anon-s 3121REDIRECTOR slot 3.5 (nodecnt=4 supn=3)\n\u003e 180426 11:40:03 6167 Update Counts Parm1=1 Parm2=0\n\u003e 180426 11:40:03 6167 Admit DATASERVER37 TSpace=62941192GB NumFS=1\n\u003e FSpace=19975075MB MinFR=102400 MB Util=69 Share=100 TZone=1\n\u003e 180426 11:40:03 6167 Admit DATASERVER37 adding path: w /xrootd\n\u003e 180426 11:40:03 6166 AddNode srv server.1401:24@DATASERVER22:1094\n\u003e cluster 3121REDIRECTOR mask=1f anum=0\n\u003e 180426 11:40:03 6166 Add server.1401:24@DATASERVER22:1094 to cluster\n\u003e anon-s 3121REDIRECTOR slot 4.6 (nodecnt=5 supn=4)\n\u003e 180426 11:40:03 6166 Update Counts Parm1=1 Parm2=0\n\u003e 180426 11:40:03 6166 Admit DATASERVER22 TSpace=13349258GB NumFS=1\n\u003e FSpace=666816MB MinFR=102400 MB Util=96 Share=100 TZone=1\n\u003e 180426 11:40:03 6166 Admit DATASERVER22 adding path: w /xrootd\n\u003e 180426 11:40:03 6168 AddNode srv server.1602:28@DATASERVER23:1094\n\u003e cluster 3121REDIRECTOR mask=3f anum=0\n\u003e 180426 11:40:03 6168 Add server.1602:28@DATASERVER23:1094 to cluster\n\u003e anon-s 3121REDIRECTOR slot 5.7 (nodecnt=6 supn=4)\n\u003e 180426 11:40:03 6168 Update Counts Parm1=1 Parm2=0\n\u003e 180426 11:40:03 6168 Admit DATASERVER23 TSpace=40052744GB NumFS=1\n\u003e FSpace=7139949MB MinFR=102400 MB Util=83 Share=100 TZone=1\n\u003e 180426 11:40:03 6168 Admit DATASERVER23 adding path: w /xrootd\n\u003e 180426 11:40:03 6169 AddNode srv server.1650:29@DATASERVER29:1094\n\u003e cluster 3121REDIRECTOR mask=7f anum=0\n\u003e 180426 11:40:03 6169 Add server.1650:29@DATASERVER29:1094 to cluster\n\u003e anon-s 3121REDIRECTOR slot 6.8 (nodecnt=7 supn=5)\n\u003e 180426 11:40:03 6169 Update Counts Parm1=1 Parm2=0\n\u003e 180426 11:40:03 6169 Admit DATASERVER29 TSpace=53406728GB NumFS=1\n\u003e FSpace=22214021MB MinFR=102400 MB Util=59 Share=100 TZone=1\n\u003e 180426 11:40:03 6169 Admit DATASERVER29 adding path: w /xrootd\n\u003e 180426 11:40:03 6172 AddNode srv server.1498:36@DATASERVER25:1094\n\u003e cluster 3121REDIRECTOR mask=ff anum=0\n\u003e 180426 11:40:03 6172 Add server.1498:36@DATASERVER25:1094 to cluster\n\u003e anon-s 3121REDIRECTOR slot 7.9 (nodecnt=8 supn=6)\n\u003e 180426 11:40:03 6172 Update Counts Parm1=1 Parm2=0\n\u003e 180426 11:40:03 6172 Admit DATASERVER25 TSpace=95368200GB NumFS=1\n\u003e FSpace=87200133MB MinFR=102400 MB Util=9 Share=100 TZone=1\n\u003e 180426 11:40:03 6172 Admit DATASERVER25 adding path: w /xrootd\n\u003e 180426 11:40:03 6170 AddNode srv server.1453:31@DATASERVER32:1094\n\u003e cluster 3121REDIRECTOR mask=1ff anum=0\n\u003e 180426 11:40:03 6170 Add server.1453:31@DATASERVER32:1094 to cluster\n\u003e anon-s 3121REDIRECTOR slot 8.10 (nodecnt=9 supn=7)\n\u003e 180426 11:40:03 6170 Update Counts Parm1=1 Parm2=0\n\u003e 180426 11:40:03 6170 Admit DATASERVER32 TSpace=30519426GB NumFS=1\n\u003e FSpace=4808549MB MinFR=102400 MB Util=85 Share=100 TZone=1\n\u003e 180426 11:40:03 6170 Admit DATASERVER32 adding path: w /xrootd\n\u003e 180426 11:40:03 6171 AddNode srv server.1395:33@DATASERVER30:1094\n\u003e cluster 3121REDIRECTOR mask=3ff anum=0\n\u003e 180426 11:40:03 6171 Add server.1395:33@DATASERVER30:1094 to cluster\n\u003e anon-s 3121REDIRECTOR slot 9.11 (nodecnt=10 supn=8)\n\u003e 180426 11:40:03 6171 Update Counts Parm1=1 Parm2=0\n\u003e 180426 11:40:03 6171 Admit DATASERVER30 TSpace=133516296GB NumFS=1\n\u003e FSpace=23452231MB MinFR=102400 MB Util=83 Share=100 TZone=1\n\u003e 180426 11:40:03 6171 Admit DATASERVER30 adding path: w /xrootd\n\u003e 180426 11:40:03 6173 AddNode srv server.4128:38@DATASERVER20:1094\n\u003e cluster 3121REDIRECTOR mask=7ff anum=0\n\u003e 180426 11:40:03 6173 Add server.4128:38@DATASERVER20:1094 to cluster\n\u003e anon-s 3121REDIRECTOR slot 10.12 (nodecnt=11 supn=8)\n\u003e 180426 11:40:03 6173 Update Counts Parm1=1 Parm2=0\n\u003e 180426 11:40:03 6173 Admit DATASERVER20 TSpace=53406728GB NumFS=1\n\u003e FSpace=6878907MB MinFR=102400 MB Util=88 Share=100 TZone=1\n\u003e 180426 11:40:03 6173 Admit DATASERVER20 adding path: w /xrootd\n\u003e 180426 11:40:03 6174 AddNode srv server.1386:40@DATASERVER31:1094\n\u003e cluster 3121REDIRECTOR mask=fff anum=0\n\u003e 180426 11:40:03 6174 Add server.1386:40@DATASERVER31:1094 to cluster\n\u003e anon-s 3121REDIRECTOR slot 11.13 (nodecnt=12 supn=9)\n\u003e 180426 11:40:03 6174 Update Counts Parm1=1 Parm2=0\n\u003e 180426 11:40:03 6174 Admit DATASERVER31 TSpace=30519426GB NumFS=1\n\u003e FSpace=9967539MB MinFR=102400 MB Util=68 Share=100 TZone=1\n\u003e 180426 11:40:03 6170 server.1453:31@DATASERVER32:1094 do_Space:\n\u003e 87200133MB free; 9% util\n\u003e 180426 11:40:03 6114 Protocol: Primary server.1510:20@DATASERVER21:1094\n\u003e logged in.\n\u003e 180426 11:40:03 6171 server.1395:33@DATASERVER30:1094 do_Space:\n\u003e 87200133MB free; 9% util\n\u003e 180426 11:40:03 6167 server.1520:25@DATASERVER37:1094 do_Space:\n\u003e 87200133MB free; 9% util\n\u003e 180426 11:40:03 6166 server.1401:24@DATASERVER22:1094 do_Space:\n\u003e 87200133MB free; 9% util\n\u003e 180426 11:40:03 6169 server.1650:29@DATASERVER29:1094 do_Space:\n\u003e 87200133MB free; 9% util\n\u003e 180426 11:40:03 6172 Protocol: Primary server.1498:36@DATASERVER25:1094\n\u003e logged in.\n\u003e 180426 11:40:03 6168 server.1602:28@DATASERVER23:1094 do_Space:\n\u003e 87200133MB free; 9% util\n\u003e 180426 11:40:03 6174 Admit DATASERVER31 adding path: w /xrootd\n\u003e 180426 11:40:03 6174 server.1386:40@DATASERVER31:1094 do_Space:\n\u003e 87200133MB free; 9% util\n\u003e 180426 11:40:03 6170 Protocol: Primary server.1453:31@DATASERVER32:1094\n\u003e logged in.\n\u003e =====\u003e Routing for 192.168.16.121: local pub4 prv4\n\u003e 180426 11:40:03 6165 server.1531:22@DATASERVER36:1094 do_Space:\n\u003e 87200133MB free; 9% util\n\u003e 180426 11:40:03 6171 Protocol: Primary server.1395:33@DATASERVER30:1094\n\u003e logged in.\n\u003e 180426 11:40:03 6173 server.4128:38@DATASERVER20:1094 do_Space:\n\u003e 87200133MB free; 9% util\n\u003e 180426 11:40:03 6167 Protocol: Primary server.1520:25@DATASERVER37:1094\n\u003e logged in.\n\u003e 180426 11:40:03 6166 Protocol: Primary server.1401:24@DATASERVER22:1094\n\u003e logged in.\n\u003e 180426 11:40:03 6169 Protocol: Primary server.1650:29@DATASERVER29:1094\n\u003e logged in.\n\u003e =====\u003e Routing for 192.168.16.127: local pub4 prv4\n\u003e 180426 11:40:03 6168 Protocol: Primary server.1602:28@DATASERVER23:1094\n\u003e logged in.\n\u003e 180426 11:40:03 6066 server.1614:18@DATASERVER28:1094 do_Space:\n\u003e 87200133MB free; 9% util\n\u003e 180426 11:40:03 6174 Protocol: Primary server.1386:40@DATASERVER31:1094\n\u003e logged in.\n\u003e =====\u003e Routing for 192.168.16.147: local pub4 prv4\n\u003e =====\u003e Route all4: 192.168.16.121 Dest=[::192.168.16.121]:1094\n\u003e 180426 11:40:03 6165 Protocol: Primary server.1531:22@DATASERVER36:1094\n\u003e logged in.\n\u003e =====\u003e Routing for 192.168.16.144: local pub4 prv4\n\u003e 180426 11:40:03 6173 Protocol: Primary server.4128:38@DATASERVER20:1094\n\u003e logged in.\n\u003e =====\u003e Routing for 192.168.16.196: local pub4 prv4\n\u003e =====\u003e Routing for 192.168.16.97: local pub4 prv4\n\u003e =====\u003e Routing for 192.168.16.139: local pub4 prv4\n\u003e =====\u003e Route all4: 192.168.16.127 Dest=[::192.168.16.127]:1094\n\u003e =====\u003e Routing for 192.168.16.134: local pub4 prv4\n\u003e 180426 11:40:03 6066 Protocol: Primary server.1614:18@DATASERVER28:1094\n\u003e logged in.\n\u003e =====\u003e Routing for 192.168.16.146: local pub4 prv4\n\u003e =====\u003e Route all4: 192.168.16.147 Dest=[::192.168.16.147]:1094\n\u003e =====\u003e Routing for 192.168.16.195: local pub4 prv4\n\u003e =====\u003e Route all4: 192.168.16.144 Dest=[::192.168.16.144]:1094\n\u003e =====\u003e Routing for 192.168.16.120: local pub4 prv4\n\u003e =====\u003e Route all4: 192.168.16.196 Dest=[::192.168.16.196]:1094\n\u003e =====\u003e Route all4: 192.168.16.97 Dest=[::192.168.16.97]:1094\n\u003e =====\u003e Route all4: 192.168.16.139 Dest=[::192.168.16.139]:1094\n\u003e =====\u003e Route all4: 192.168.16.134 Dest=[::192.168.16.134]:1094\n\u003e =====\u003e Routing for 192.168.16.217: local pub4 prv4\n\u003e =====\u003e Route all4: 192.168.16.146 Dest=[::192.168.16.146]:1094\n\u003e =====\u003e Route all4: 192.168.16.195 Dest=[::192.168.16.195]:1094\n\u003e =====\u003e Route all4: 192.168.16.120 Dest=[::192.168.16.120]:1094\n\u003e =====\u003e Route all4: 192.168.16.217 Dest=[::192.168.16.217]:1094\n\u003e 180426 11:40:55 6176 XrdSched: Now have 17 workers\n\u003e 180426 11:40:55 6188 XrdXeq: Worker thread started\n\u003e 180426 11:41:25 6052 Update Stage Parm1=-1 Parm2=0\n\u003e 180426 11:41:25 6052 Update Active Parm1=-1 Parm2=0\n\u003e 180426 11:41:25 6052 Config: manager service enabled.\n\u003e 180426 11:41:25 6068 State: Status changed to active + nostaging\n\u003e 180426 11:41:25 6068 Send status to redirector.6099:7@REDIRECTOR\n\u003e 180426 11:41:42 6053 Dispatch redirector.6099:7@REDIRECTOR for select\n\u003e dlen=63\n\u003e 180426 11:41:42 6053 redirector.6099:7@REDIRECTOR XrdLink: Setting ref\n\u003e to 1+1 post=0\n\u003e 180426 11:41:42 6176 XrdSched: running redirector inq=0\n\u003e 180426 11:41:42 6176 schroete.289158:7@CLIENT do_Select: Px\n\u003e /xrootd/schroete/willi.dat\n\u003e 180426 11:41:42 6176 WT4File rc=0 path=/xrootd/schroete/willi.dat\n\u003e 180426 11:41:42 6176 Select seeking /xrootd/schroete/willi.dat\n\u003e 180426 11:41:42 6176 redirector.6099:7@REDIRECTOR XrdLink: Setting ref\n\u003e to 2+-1 post=0\n\u003e 180426 11:41:47 6053 Dispatch redirector.6099:7@REDIRECTOR for select\n\u003e dlen=63\n\u003e 180426 11:41:47 6053 redirector.6099:7@REDIRECTOR XrdLink: Setting ref\n\u003e to 1+1 post=0\n\u003e 180426 11:41:47 6188 XrdSched: running redirector inq=0\n\u003e 180426 11:41:47 6188 schroete.289158:7@CLIENT do_Select: Px\n\u003e /xrootd/schroete/willi.dat\n\u003e 180426 11:41:47 6188 schroete.289158:7@CLIENT do_Select: failed; No\n\u003e servers are available to read the file. /xrootd/schroete/willi.dat\n\u003e 180426 11:41:47 6188 redirector.6099:7@REDIRECTOR XrdLink: Setting ref\n\u003e to 2+-1 post=0\n\u003e 180426 11:41:47 6053 Dispatch redirector.6099:7@REDIRECTOR for select\n\u003e dlen=78\n\u003e 180426 11:41:47 6053 redirector.6099:7@REDIRECTOR XrdLink: Setting ref\n\u003e to 1+1 post=0\n\u003e 180426 11:41:47 6052 XrdSched: running redirector inq=0\n\u003e 180426 11:41:47 6052 schroete.289158:7@CLIENT do_Select: Pwc\n\u003e /xrootd/schroete/willi.dat\n\u003e 180426 11:41:47 6052 SelNode 192.168.16.217 assigned\n\u003e /xrootd/schroete/willi.dat\n\u003e 180426 11:41:47 6052 schroete.289158:7@CLIENT do_Select: Redirect -\u003e\n\u003e 192.168.16.217:1094 for /xrootd/schroete/willi.dat\n\u003e 180426 11:41:47 6052 redirector.6099:7@REDIRECTOR XrdLink: Setting ref\n\u003e to 2+-1 post=0\n\u003e 180426 11:41:47 6066 Dispatch server.1614:18@DATASERVER28:1094 for have\n\u003e dlen=27\n\u003e 180426 11:41:47 6066 server.1614:18@DATASERVER28 XrdLink: Setting ref to\n\u003e 1+1 post=0\n\u003e 180426 11:41:47 6176 XrdSched: running server inq=0\n\u003e 180426 11:41:47 6176 server.1614:18@DATASERVER28:1094 do_Have:\n\u003e /xrootd/schroete/willi.dat\n\u003e 180426 11:41:47 6176 server.1614:18@DATASERVER28 XrdLink: Setting ref to\n\u003e 2+-1 post=0\n\u003e \n\u003e \n\u003e XROOTD.LOG\n\u003e 180426 11:39:55 6099 Starting on Linux 4.13.0-38-generic\n\u003e Copr. 2004-2012 Stanford University, xrd version v4.8.3-rc1\n\u003e ++++++ xrootd anon@REDIRECTOR initialization started.\n\u003e Config using configuration file /etc/xrootd/xrootd.cf\n\u003e =====\u003e xrd.port 1094\n\u003e Config maximum number of connections restricted to 4096\n\u003e Config maximum number of threads restricted to 15569\n\u003e 180426 11:39:55 6099 XrdConfig: sendfile enabled.\n\u003e 180426 11:39:55 6101 XrdXeq: Buffer Manager reshaper thread started\n\u003e 180426 11:39:55 6099 XrdSched: scheduling underused thread monitor in\n\u003e 780 seconds\n\u003e 180426 11:39:55 6102 XrdXeq: Time scheduler thread started\n\u003e 180426 11:39:55 6103 XrdXeq: Worker thread started\n\u003e 180426 11:39:55 6099 XrdSched: Starting with 2 workers\n\u003e 180426 11:39:55 6104 XrdXeq: Worker thread started\n\u003e 180426 11:39:55 6099 XrdLink: Allocating 8 link objects at a time\n\u003e 180426 11:39:55 6099 XrdPoll: Starting poller 0\n\u003e 180426 11:39:55 6105 XrdXeq: Poller thread started\n\u003e 180426 11:39:55 6099 XrdPoll: Starting poller 1\n\u003e 180426 11:39:55 6106 XrdXeq: Poller thread started\n\u003e 180426 11:39:55 6099 XrdPoll: Starting poller 2\n\u003e 180426 11:39:55 6107 XrdXeq: Poller thread started\n\u003e 180426 11:39:55 6099 XrdProtocol: getting port from protocol xrootd\n\u003e 180426 11:39:55 6099 XrdConfig: LCL port 1094 wsz=87380 (87380)\n\u003e 180426 11:39:55 6099 XrdProtocol: getting protocol object xrootd\n\u003e Copr. 2012 Stanford University, xrootd protocol 3.1.0 version v4.8.3-rc1\n\u003e ++++++ xrootd protocol initialization started.\n\u003e =====\u003e all.export /xrootd\n\u003e =====\u003e xrootd.fsoverload stall 1\n\u003e Config exporting /xrootd\n\u003e Config warning: 'xrootd.seclib' not specified; strong authentication\n\u003e disabled!\n\u003e Config Routing for 192.168.16.124: local pub4 prv4\n\u003e Config Route all4: 192.168.16.124 Dest=[::192.168.16.124]:1094\n\u003e ++++++ File system initialization started.\n\u003e =====\u003e all.role manager\n\u003e ++++++ Storage system initialization started.\n\u003e =====\u003e all.export /xrootd\n\u003e 180426 11:39:55 6099 oss_Export: warning, invalid path option rw\n\u003e =====\u003e oss.defaults rw\n\u003e 180426 11:39:55 6099 oss_AioInit: started AIO read signal thread;\n\u003e tid=499631872\n\u003e 180426 11:39:55 6099 oss_AioInit: started AIO write signal thread;\n\u003e tid=498579200\n\u003e 180426 11:39:55 6110 XrdXeq: cache scan thread started\n\u003e Config effective /etc/xrootd/xrootd.cf oss configuration:\n\u003e oss.alloc 0 0 0\n\u003e oss.cachescan 600\n\u003e oss.fdlimit 2048 4096\n\u003e oss.maxsize 0\n\u003e oss.trace fff\n\u003e oss.xfr 1 deny 10800 keep 1200\n\u003e oss.memfile off max 2067851264\n\u003e oss.defaults r/w nocheck nodread nomig norcreate nopurge\n\u003e nostage xattr\n\u003e oss.path /xrootd r/w nocheck nodread nomig norcreate nopurge\n\u003e nostage xattr\n\u003e ------ Storage system initialization completed.\n\u003e ++++++ Configuring manager role. . .\n\u003e =====\u003e all.manager REDIRECTOR:3121\n\u003e 180426 11:39:55 6099 Configure Global System Identification: anon-m\n\u003e 3121REDIRECTOR\n\u003e Config 1 manager(s) started.\n\u003e 180426 11:39:55 6111 XrdXeq: REDIRECTOR thread started\n\u003e Config effective /etc/xrootd/xrootd.cf ofs configuration:\n\u003e all.role manager\n\u003e ofs.maxdelay 60\n\u003e ofs.persist manual hold 600 logdir /tmp/.ofs/posc.log\n\u003e ofs.trace bfcd\n\u003e ------ File system manager initialization completed.\n\u003e 180426 11:39:55 6099 XrootdAioReq: Max aio/req=8; aio/srv=4096;\n\u003e Quantum=131072\n\u003e 180426 11:39:55 6099 XrootdAioReq: Adding 18 aioreq objects.\n\u003e 180426 11:39:55 6099 XrootdAio: Adding 18 aio objects; 4096 pending.\n\u003e 180426 11:39:55 6099 XrdSched: scheduling xrootd protocol anchor in 3600\n\u003e seconds\n\u003e 180426 11:39:55 6099 XrdSched: scheduling transit protocol anchor in\n\u003e 3600 seconds\n\u003e Config warning: 'xrootd.prepare logdir' not specified; prepare tracking\n\u003e disabled.\n\u003e ------ xrootd protocol initialization completed.\n\u003e 180426 11:39:55 6111 XrdInet: Connected to REDIRECTOR:3121\n\u003e 180426 11:39:55 6111 cms_ClientMan: Connected to suspended REDIRECTOR v 3\n\u003e 180426 11:39:55 6111 Hookup REDIRECTOR qt=178ms rw=2\n\u003e ------ xrootd anon@REDIRECTOR:1094 initialization completed.\n\u003e 180426 11:39:55 6103 XrdSched: running main accept inq=0\n\u003e 180426 11:39:55 6113 XrdXeq: Admin traffic thread started\n\u003e 180426 11:39:55 6112 XrdXeq: async callback thread started\n\u003e 180426 11:41:25 6111 Receive REDIRECTOR 0 bytes on 0\n\u003e 180426 11:41:25 6111 setStatus REDIRECTOR sent resume event\n\u003e 180426 11:41:25 6111 cms_setStatus: Manager REDIRECTOR resumed\n\u003e \n\u003e 180426 11:41:42 6104 XrdSched: Now have 3 workers\n\u003e 180426 11:41:42 6104 XrdSched: running main accept inq=0\n\u003e 180426 11:41:42 6103 XrdInet: Accepted connection from 7@CLIENT\n\u003e 180426 11:41:42 6103 XrdProtocol: matched protocol xrootd\n\u003e 180426 11:41:42 6103 ?:7@CLIENT XrdPoll: FD 7 attached to poller 0; num=1\n\u003e 180426 11:41:42 6103 ?:7@CLIENT XrootdProtocol: 0000 req=login dlen=101\n\u003e 180426 11:41:42 6103 schroete.289158:7@CLIENT XrootdResponse: 0000\n\u003e sending 16 data bytes\n\u003e 180426 11:41:42 6103 XrootdXeq: schroete.289158:7@CLIENT pvt IPv4 login\n\u003e 180426 11:41:42 6193 XrdXeq: Worker thread started\n\u003e 180426 11:41:42 6103 schroete.289158:7@CLIENT XrootdProtocol: 0100\n\u003e req=stat dlen=26\n\u003e 180426 11:41:42 6103 schroete.289158:7@CLIENT ofs_stat:\n\u003e fn=/xrootd/schroete/willi.dat\n\u003e 180426 11:41:42 6111 Receive REDIRECTOR 4 bytes on 3071\n\u003e 180426 11:41:42 6111 Decode REDIRECTOR delays schroete.289158:7@CLIENT 5\n\u003e /xrootd/schroete/willi.dat\n\u003e 180426 11:41:42 6103 schroete.289158:7@CLIENT XrootdProtocol: 0100 rc=5\n\u003e stat /xrootd/schroete/willi.dat\n\u003e 180426 11:41:42 6103 schroete.289158:7@CLIENT XrootdProtocol: 0100\n\u003e stalling client for 5 sec\n\u003e 180426 11:41:42 6103 schroete.289158:7@CLIENT XrootdResponse: 0100\n\u003e sending 4 data bytes; status=4005\n\u003e 180426 11:41:45 6103 schroete.289158:7@CLIENT XrootdProtocol: 0100\n\u003e request timeout; read 0 of 24 bytes\n\u003e 180426 11:41:45 6103 XrdPoll: Poller 0 enabled schroete.289158:7@CLIENT\n\u003e 180426 11:41:47 6193 XrdSched: running schroete.289158:7@CLIENT inq=0\n\u003e 180426 11:41:47 6193 schroete.289158:7@CLIENT XrootdProtocol: 0100\n\u003e req=stat dlen=26\n\u003e 180426 11:41:47 6193 schroete.289158:7@CLIENT ofs_stat:\n\u003e fn=/xrootd/schroete/willi.dat\n\u003e 180426 11:41:47 6111 Receive REDIRECTOR 47 bytes on 4095\n\u003e 180426 11:41:47 6111 Decode REDIRECTOR gave schroete.289158:7@CLIENT err\n\u003e -2 'No servers are available to read the file.' /xrootd/schroete/willi.dat\n\u003e 180426 11:41:47 6193 schroete.289158:7@CLIENT XrootdProtocol: 0100 rc=-1\n\u003e stat /xrootd/schroete/willi.dat\n\u003e 180426 11:41:47 6193 schroete.289158:7@CLIENT XrootdResponse: 0100\n\u003e sending err 3011: No servers are available to read the file.\n\u003e 180426 11:41:47 6193 schroete.289158:7@CLIENT XrootdProtocol: 0100\n\u003e req=open dlen=40\n\u003e 180426 11:41:47 6193 schroete.289158:7@CLIENT XrootdProtocol: 0100 open\n\u003e unmat /xrootd/schroete/willi.dat?oss.asize=226\n\u003e 180426 11:41:47 6193 schroete.289158:7@CLIENT ofs_open: 102-40644\n\u003e fn=/xrootd/schroete/willi.dat\n\u003e 180426 11:41:47 6111 Receive REDIRECTOR 19 bytes on 5119\n\u003e 180426 11:41:47 6111 Decode REDIRECTOR redirects\n\u003e schroete.289158:7@CLIENT to 192.168.16.217:1094 /xrootd/schroete/willi.dat\n\u003e 180426 11:41:47 6193 schroete.289158:7@CLIENT XrootdProtocol: 0100\n\u003e redirecting to 192.168.16.217:1094\n\u003e 180426 11:41:47 6193 schroete.289158:7@CLIENT XrootdResponse: 0100\n\u003e sending 18 data bytes; status=4004\n\u003e 180426 11:41:47 6193 schroete.289158:7@CLIENT ofs_close: use=0 fn=dummy\n\u003e 180426 11:41:47 6193 XrootdXeq: schroete.289158:7@CLIENT disc 0:00:05\n\u003e 180426 11:41:47 6193 schroete.289158:7@CLIENT XrdPoll: FD 7 detached\n\u003e from poller 0; num=0\n\u003e \n\u003e \n\u003e \n\u003e Am 28.04.2018 um 04:30 schrieb xrootd-dev:\n\u003e\u003e OK, below is what I got. Note that it starts with \"XROOTD log:\" there is\n\u003e\u003e no hint of a cmsd log anywhere that I can see. If there is could you\n\u003e\u003e cl;early indicate which one is which.\n\u003e\u003e\n\u003e\u003e Andy\n\u003e \n\u003e —\n\u003e You are receiving this because you commented.\n\u003e Reply to this email directly, view it on GitHub, or mute the thread.\n\u003e \n\u003e \n\u003e \n\u003e --------------------------------------------------------------------------------\n\u003e \n\u003e Use REPLY-ALL to reply to list\n\u003e \n\u003e To unsubscribe from the XROOTD-DEV list, click the following link:\n\u003e https://listserv.slac.stanford.edu/cgi-bin/wa?SUBED1=XROOTD-DEV\u0026A=1\n\u003e \n\u003e \n\n\n—\nYou are receiving this because you commented.\nReply to this email directly, view it on GitHub, or mute the thread.\n"}],"action":{"name":"View Issue","url":"https://github.com/xrootd/xrootd/issues/692#issuecomment-385792192"}}}
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
