 |
 |
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 or view it on GitHub: https://github.com/xrootd/xrootd/issues/692#issuecomment-385606772 ######################################################################## 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