 |
 |
I've figured out how I can reproduce it. If I restart the server and copy the file it works. But if I don't remove the existing local file and try to copy over it I get the hang (which is something I keep doing accidentally). After that all transfers are stuck
[illingwo@fermicloud126 ~]$ xrdcp -d2 root://localhost//public/blast/data/drosoph.aa.phr /tmp
[2015-05-28 13:52:44.785589 -0500][Debug ][Utility ] CopyProcess: 2 jobs to prepare
[2015-05-28 13:52:44.785728 -0500][Debug ][Utility ] Creating a classic copy job, from root://localhost:1094//public/blast/data/drosoph.aa.phr to file:///tmp//drosoph.aa.phr
[2015-05-28 13:52:44.785763 -0500][Debug ][Utility ] Monitor library name not set. No monitoring
[2015-05-28 13:52:44.785814 -0500][Debug ][Utility ] Opening root://localhost:1094//public/blast/data/drosoph.aa.phr for reading
[2015-05-28 13:52:44.785974 -0500][Debug ][File ] [0x1bea760@root://localhost:1094//public/blast/data/drosoph.aa.phr] Sending an open command
[2015-05-28 13:52:44.786023 -0500][Debug ][Poller ] Available pollers: built-in
[2015-05-28 13:52:44.786034 -0500][Debug ][Poller ] Attempting to create a poller according to preference: built-in,libevent
[2015-05-28 13:52:44.786044 -0500][Debug ][Poller ] Creating poller: built-in
[2015-05-28 13:52:44.786053 -0500][Debug ][Poller ] Creating and starting the built-in poller...
[2015-05-28 13:52:44.786133 -0500][Debug ][TaskMgr ] Starting the task manager...
[2015-05-28 13:52:44.786176 -0500][Debug ][TaskMgr ] Task manager started
[2015-05-28 13:52:44.786190 -0500][Debug ][JobMgr ] Starting the job manager...
[2015-05-28 13:52:44.786263 -0500][Debug ][JobMgr ] Job manager started, 3 workers
[2015-05-28 13:52:44.786280 -0500][Debug ][TaskMgr ] Registering task: "FileTimer task" to be run at: [2015-05-28 13:52:44 -0500]
[2015-05-28 13:52:44.786312 -0500][Debug ][PostMaster ] Creating new channel to: localhost:1094 1 stream(s)
[2015-05-28 13:52:44.786345 -0500][Debug ][PostMaster ] [localhost:1094 #0] Stream parameters: Network Stack: IPAuto, Connection Window: 120, ConnectionRetry: 5, Stream Error Widnow: 1800
[2015-05-28 13:52:44.787284 -0500][Debug ][TaskMgr ] Registering task: "TickGeneratorTask for: localhost:1094" to be run at: [2015-05-28 13:52:59 -0500]
[2015-05-28 13:52:44.787408 -0500][Debug ][PostMaster ] [localhost:1094] Found 1 address(es): [::ffff:127.0.0.1]:1094
[2015-05-28 13:52:44.787441 -0500][Debug ][AsyncSock ] [localhost:1094 #0.0] Attempting connection to [::ffff:127.0.0.1]:1094
[2015-05-28 13:52:44.787513 -0500][Debug ][Poller ] Adding socket 0x1befdf0 to the poller
[2015-05-28 13:52:44.788023 -0500][Debug ][AsyncSock ] [localhost:1094 #0.0] Async connection call returned
[2015-05-28 13:52:44.788057 -0500][Debug ][XRootDTransport ] [localhost:1094 #0.0] Sending out the initial hand shake + kXR_protocol
[2015-05-28 13:52:44.788265 -0500][Debug ][XRootDTransport ] [localhost:1094 #0.0] Got the server hand shake response (type: server [], protocol version 300)
[2015-05-28 13:52:44.788291 -0500][Debug ][XRootDTransport ] [localhost:1094 #0.0] kXR_protocol successful (type: server [], protocol version 300)
[2015-05-28 13:52:44.791703 -0500][Debug ][XRootDTransport ] [localhost:1094 #0.0] Sending out kXR_login request, username: illingwo, cgi: ?xrd.cc=us&xrd.tz=-6&xrd.appname=xrdcp&xrd.info=&xrd.hostname=fermicloud126.fnal.gov, dual-stack: false, private IPv4: false, private IPv6: false
[2015-05-28 13:52:44.791963 -0500][Debug ][XRootDTransport ] [localhost:1094 #0.0] Logged in, session: 01000000b20a00000700000001000000
[2015-05-28 13:52:44.791989 -0500][Debug ][PostMaster ] [localhost:1094 #0] Stream 0 connected.
[2015-05-28 13:52:47.085138 -0500][Debug ][File ] [0x1bea760@root://localhost:1094//public/blast/data/drosoph.aa.phr] Open has returned with status [SUCCESS]
[2015-05-28 13:52:47.085180 -0500][Debug ][File ] [0x1bea760@root://localhost:1094//public/blast/data/drosoph.aa.phr] successfully opened at localhost:1094, handle: 0x0, session id: 1
[2015-05-28 13:52:47.085220 -0500][Debug ][Utility ] Opening /tmp//drosoph.aa.phr for writing
[2015-05-28 13:52:47.085299 -0500][Debug ][File ] [0x1bea760@root://localhost:1094//public/blast/data/drosoph.aa.phr] Sending a read command for handle 0x0 to localhost:1094
[1.699MB/1.699MB][100%][==================================================][580kB/s] [2015-05-28 13:52:47.090811 -0500][Debug ][File ] [0x1bea760@root://localhost:1094//public/blast/data/drosoph.aa.phr] Sending a close command for handle 0x0 to localhost:1094
[2015-05-28 13:52:47.384986 -0500][Debug ][File ] [0x1bea760@root://localhost:1094//public/blast/data/drosoph.aa.phr] Close returned from localhost:1094 with: [SUCCESS]
[1.699MB/1.699MB][100%][==================================================][580kB/s]
[2015-05-28 13:52:47.385145 -0500][Debug ][JobMgr ] Stopping the job manager...
[2015-05-28 13:52:47.385371 -0500][Debug ][JobMgr ] Job manager stopped
[2015-05-28 13:52:47.385388 -0500][Debug ][TaskMgr ] Stopping the task manager...
[2015-05-28 13:52:47.385464 -0500][Debug ][TaskMgr ] Task manager stopped
[2015-05-28 13:52:47.385480 -0500][Debug ][Poller ] Stopping the poller...
[2015-05-28 13:52:47.385556 -0500][Debug ][TaskMgr ] Requesting unregistration of: "TickGeneratorTask for: localhost:1094"
[2015-05-28 13:52:47.385573 -0500][Debug ][AsyncSock ] [localhost:1094 #0.0] Closing the socket
[2015-05-28 13:52:47.385583 -0500][Debug ][Poller ] <[::ffff:127.0.0.1]:32953><--><[::ffff:127.0.0.1]:1094> Removing socket from the poller
[2015-05-28 13:52:47.385767 -0500][Debug ][PostMaster ] [localhost:1094 #0] Destroying stream
[2015-05-28 13:52:47.385784 -0500][Debug ][AsyncSock ] [localhost:1094 #0.0] Closing the socket
[illingwo@fermicloud126 ~]$ xrdcp -d2 root://localhost//public/blast/data/drosoph.aa.phr /tmp
[2015-05-28 13:52:53.705630 -0500][Debug ][Utility ] CopyProcess: 2 jobs to prepare
[2015-05-28 13:52:53.705755 -0500][Debug ][Utility ] Creating a classic copy job, from root://localhost:1094//public/blast/data/drosoph.aa.phr to file:///tmp//drosoph.aa.phr
[2015-05-28 13:52:53.705787 -0500][Debug ][Utility ] Monitor library name not set. No monitoring
[2015-05-28 13:52:53.705951 -0500][Debug ][Utility ] Opening root://localhost:1094//public/blast/data/drosoph.aa.phr for reading
[2015-05-28 13:52:53.706000 -0500][Debug ][File ] [0x18d2760@root://localhost:1094//public/blast/data/drosoph.aa.phr] Sending an open command
[2015-05-28 13:52:53.706045 -0500][Debug ][Poller ] Available pollers: built-in
[2015-05-28 13:52:53.706055 -0500][Debug ][Poller ] Attempting to create a poller according to preference: built-in,libevent
[2015-05-28 13:52:53.706070 -0500][Debug ][Poller ] Creating poller: built-in
[2015-05-28 13:52:53.706082 -0500][Debug ][Poller ] Creating and starting the built-in poller...
[2015-05-28 13:52:53.706168 -0500][Debug ][TaskMgr ] Starting the task manager...
[2015-05-28 13:52:53.706212 -0500][Debug ][TaskMgr ] Task manager started
[2015-05-28 13:52:53.706227 -0500][Debug ][JobMgr ] Starting the job manager...
[2015-05-28 13:52:53.706298 -0500][Debug ][JobMgr ] Job manager started, 3 workers
[2015-05-28 13:52:53.706314 -0500][Debug ][TaskMgr ] Registering task: "FileTimer task" to be run at: [2015-05-28 13:52:53 -0500]
[2015-05-28 13:52:53.706347 -0500][Debug ][PostMaster ] Creating new channel to: localhost:1094 1 stream(s)
[2015-05-28 13:52:53.706382 -0500][Debug ][PostMaster ] [localhost:1094 #0] Stream parameters: Network Stack: IPAuto, Connection Window: 120, ConnectionRetry: 5, Stream Error Widnow: 1800
[2015-05-28 13:52:53.707284 -0500][Debug ][TaskMgr ] Registering task: "TickGeneratorTask for: localhost:1094" to be run at: [2015-05-28 13:53:08 -0500]
[2015-05-28 13:52:53.707403 -0500][Debug ][PostMaster ] [localhost:1094] Found 1 address(es): [::ffff:127.0.0.1]:1094
[2015-05-28 13:52:53.707436 -0500][Debug ][AsyncSock ] [localhost:1094 #0.0] Attempting connection to [::ffff:127.0.0.1]:1094
[2015-05-28 13:52:53.707502 -0500][Debug ][Poller ] Adding socket 0x18d7df0 to the poller
[2015-05-28 13:52:53.707770 -0500][Debug ][AsyncSock ] [localhost:1094 #0.0] Async connection call returned
[2015-05-28 13:52:53.707802 -0500][Debug ][XRootDTransport ] [localhost:1094 #0.0] Sending out the initial hand shake + kXR_protocol
[2015-05-28 13:52:53.708131 -0500][Debug ][XRootDTransport ] [localhost:1094 #0.0] Got the server hand shake response (type: server [], protocol version 300)
[2015-05-28 13:52:53.708158 -0500][Debug ][XRootDTransport ] [localhost:1094 #0.0] kXR_protocol successful (type: server [], protocol version 300)
[2015-05-28 13:52:53.710948 -0500][Debug ][XRootDTransport ] [localhost:1094 #0.0] Sending out kXR_login request, username: illingwo, cgi: ?xrd.cc=us&xrd.tz=-6&xrd.appname=xrdcp&xrd.info=&xrd.hostname=fermicloud126.fnal.gov, dual-stack: false, private IPv4: false, private IPv6: false
[2015-05-28 13:52:53.711086 -0500][Debug ][XRootDTransport ] [localhost:1094 #0.0] Logged in, session: 02000000b20a00001900000002000000
[2015-05-28 13:52:53.711110 -0500][Debug ][PostMaster ] [localhost:1094 #0] Stream 0 connected.
[2015-05-28 13:52:53.726693 -0500][Debug ][File ] [0x18d2760@root://localhost:1094//public/blast/data/drosoph.aa.phr] Open has returned with status [SUCCESS]
[2015-05-28 13:52:53.726712 -0500][Debug ][File ] [0x18d2760@root://localhost:1094//public/blast/data/drosoph.aa.phr] successfully opened at localhost:1094, handle: 0x0, session id: 1
[2015-05-28 13:52:53.726739 -0500][Debug ][Utility ] Opening /tmp//drosoph.aa.phr for writing
[2015-05-28 13:52:53.726764 -0500][Debug ][Utility ] Unable to open /tmp//drosoph.aa.phr: File exists
[2015-05-28 13:52:53.726779 -0500][Debug ][File ] [0x18d2760@root://localhost:1094//public/blast/data/drosoph.aa.phr] Sending a close command for handle 0x0 to localhost:1094
[2015-05-28 13:53:53.787431 -0500][Debug ][AsyncSock ] [localhost:1094 #0.0] Closing the socket
[2015-05-28 13:53:53.787489 -0500][Debug ][Poller ] <[::ffff:127.0.0.1]:32957><--><[::ffff:127.0.0.1]:1094> Removing socket from the poller
[2015-05-28 13:53:53.787578 -0500][Debug ][PostMaster ] [localhost:1094 #0] Recovering error for stream #0: [ERROR] Socket error.
[2015-05-28 13:53:53.787590 -0500][Debug ][PostMaster ] [localhost:1094 #0] Reporting disconnection to queued message handlers.
[2015-05-28 13:53:53.787603 -0500][Error ][XRootD ] [localhost:1094] Handling error while processing kXR_close (handle: 0x00000000): [ERROR] Socket error.
[2015-05-28 13:53:53.787612 -0500][Error ][XRootD ] [localhost:1094] Unable to get the response to request kXR_close (handle: 0x00000000)
[2015-05-28 13:53:53.787628 -0500][Debug ][File ] [0x18d2760@root://localhost:1094//public/blast/data/drosoph.aa.phr] Close returned from localhost:1094 with: [ERROR] Socket error
[0B/0B][100%][==================================================][0B/s]
Run: [ERROR] OS Error: File exists
[2015-05-28 13:53:53.787891 -0500][Debug ][JobMgr ] Stopping the job manager...
[2015-05-28 13:53:53.788290 -0500][Debug ][JobMgr ] Job manager stopped
[2015-05-28 13:53:53.788309 -0500][Debug ][TaskMgr ] Stopping the task manager...
[2015-05-28 13:53:53.788391 -0500][Debug ][TaskMgr ] Task manager stopped
[2015-05-28 13:53:53.788407 -0500][Debug ][Poller ] Stopping the poller...
[2015-05-28 13:53:53.788482 -0500][Debug ][TaskMgr ] Requesting unregistration of: "TickGeneratorTask for: localhost:1094"
[2015-05-28 13:53:53.788498 -0500][Debug ][AsyncSock ] [localhost:1094 #0.0] Closing the socket
[2015-05-28 13:53:53.788507 -0500][Debug ][PostMaster ] [localhost:1094 #0] Destroying stream
[2015-05-28 13:53:53.788515 -0500][Debug ][AsyncSock ] [localhost:1094 #0.0] Closing the socket
(Notice there's a minute delay after the Sending a close command for handle 0x0 to localhost:1094 in the second copy.)
150528 13:52:44 2745 XrdInet: Accepted connection from [log in to unmask]
150528 13:52:44 2744 XrdSched: Now have 3 workers
150528 13:52:44 2744 XrdSched: running main accept inq=0
150528 13:52:44 2745 XrdProtocol: matched protocol xrootd
150528 13:52:44 2745 ?:[log in to unmask] XrdPoll: FD 7 attached to poller 0; num=1
150528 13:52:44 2745 XrootdXeq: illingwo.2844:[log in to unmask] pvt IPv4 login
150528 13:52:44 2745 illingwo.2844:[log in to unmask] ofs_open: 0-600 fn=/public/blast/data/drosoph.aa.phr
150528 13:52:47 2745 illingwo.2844:[log in to unmask] ofs_fstat: fn=/public/blast/data/drosoph.aa.phr
150528 13:52:47 2745 illingwo.2844:[log in to unmask] ofs_read: 1781790@0 fn=/public/blast/data/drosoph.aa.phr
150528 13:52:47 2745 illingwo.2844:[log in to unmask] ofs_close: use=1 fn=/public/blast/data/drosoph.aa.phr
150528 13:52:47 2745 illingwo.2844:[log in to unmask] ofs_close: use=0 fn=dummy
150528 13:52:47 2745 XrootdXeq: illingwo.2844:[log in to unmask] disc 0:00:03
150528 13:52:47 2745 illingwo.2844:[log in to unmask] XrdPoll: FD 7 detached from poller 0; num=0
150528 13:52:53 2744 XrdInet: Accepted connection from [log in to unmask]
150528 13:52:53 2850 XrdSched: running main accept inq=0
150528 13:52:53 2744 XrdProtocol: matched protocol xrootd
150528 13:52:53 2744 ?:[log in to unmask] XrdPoll: FD 25 attached to poller 0; num=1
150528 13:52:53 2744 XrootdXeq: illingwo.2852:[log in to unmask] pvt IPv4 login
150528 13:52:53 2744 illingwo.2852:[log in to unmask] ofs_open: 0-600 fn=/public/blast/data/drosoph.aa.phr
150528 13:52:53 2744 illingwo.2852:[log in to unmask] ofs_fstat: fn=/public/blast/data/drosoph.aa.phr
150528 13:52:53 2744 illingwo.2852:[log in to unmask] ofs_close: use=1 fn=/public/blast/data/drosoph.aa.phr
—
Reply to this email directly or view it on GitHub.
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