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: https://github.com/xrootd/xrootd/issues/239#issuecomment-106566432 ######################################################################## 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