https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 Michael Wilde <[email protected]> changed: What |Removed |Added ---------------------------------------------------------------------------- Priority|P2 |P1 Status|NEW |ASSIGNED CC| |[email protected] Severity|normal |critical --- Comment #1 from Michael Wilde <[email protected]> 2012-01-25 08:41:56 --- Ketan, your initial decsription is good. Mihael, are you able to reproduce this? If not, Ketan, please try to replicate this in in script that doesnt use GWMS, and ideally can be run between local systems. If not, then between the easiest/fastest set of remote systems possible. The sooner Mihael can actual reproduce the problem the sooner it can be fixed. -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #3 from David Kelly <[email protected]> 2012-02-07 11:01:41 --- Ketan, I'm trying again to reproduce this issue using the MCS workstations. In the example you mention, you were using 100 10MB files. Can you please tell me approximately how many tasks were active at once, and the number of nodes you were using? Thanks, David -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #5 from David Kelly <[email protected]> 2012-02-08 16:21:25 --- Ketan, I tried running several more tests today on MCS. I tried 100 files x 10MB, then increased to 1000 files x 10MB, and then finally 10000 files x 10MB. These were run with similar throttle values/#nodes. All these tests completed. One obvious difference in this setup is the network speed. The MCS workstations are all connected via very high speed network connections. I will try running some tests tonight from my home internet to MCS and see what happens. Do you have any other ideas on possible setup differences? Are you running the latest/official 0.93 release, or 0.93.1? Can you please also send the sites.xml, cf, tc.data, and the version of catsn you are running? Thanks, David -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #7 from David Kelly <[email protected]> 2012-02-09 09:54:21 --- I can reproduce this pretty reliably now by doing the following steps: 1) Login to communicado 2) Ensure you have the following environment variables defined: GLOBUS_HOSTNAME=communicado.ci.uchicago.edu GLOBUS_TCP_SRC_RANGE=50000,51000 GLOBUS_TCP_PORT_RANGE=50000,51000 Firewall restrictions will prevent connections outside of this port range. 3) Start coaster service. 4) Run a dummy swift script, then start workers on each of the 10 MCS workstations - crush, thwomp, stomp, crank, steamroller, grind, churn, trounce, thrash, and vanquish. Note: the order of this is important. If you start the workers before running your first script, you will only get 1 worker per node - see bug #467. 5) cd /autonfs/gpfs-pads/projects/CI-CCR000013/davidk/coaster-stress-tests 6) swift -sites.file sites.xml -tc.file tc.data -config cf catsn_random.swift. The error should occur within 10 minutes. There are 500 files in the data directory, each 10MB. This seems to be enough to consistently cause failures. Here are the logs from my latest run this morning: Swift log: http://www.ci.uchicago.edu/~davidk/logs/catsncommunicado_to_mcs.log.gz Coaster service log: http://www.ci.uchicago.edu/~davidk/logs/coaster-communicado_to_mcs.log.gz Worker logs: http://www.ci.uchicago.edu/~davidk/logs/communicado-to-mcs_worker_logs.tar.g... -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #8 from Mihael Hategan <[email protected]> 2012-02-10 12:54:18 --- I'm probably going to need worker logs at DEBUG level, timestamps on the service log and DEBUG enabled on coaster stuff (that also goes for the swift log). -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #10 from Mihael Hategan <[email protected]> 2012-02-10 20:23:21 --- Looks like everything just stops at around 14:11. Can you send me jstacks of swift and the coaster service when timeouts start to occur? -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #12 from Mihael Hategan <[email protected]> 2012-02-11 13:32:52 --- I looks like one of the workers stops processing data and things get filled up on the service side. The system should be robust to individual worker lockups and be able to continue working with the good workers. I'll start cooking up a solution, but we should probably also look at why the worker stops working. In this case, the bad worker is the one on thwomp. You can see how the "bad behaviour" looks like by looking at the last lines of its log. It might be useful if, when you see something like that again, get a stack trace of such a worker with gdb. -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #14 from Mihael Hategan <[email protected]> 2012-02-13 20:08:03 --- I keep looking at these logs and keep wondering how it can be that the service sees the TCP connections as going bad (no route to host, connection timed out, etc.) So I'm trying to distinguish between a genuine network problem and the workers dying. There is nothing in the worker logs that would suggest that they are dying, but that information typically goes on stdout. However, since these workers are started manually, that's not in the service log. So do you happen to have the stdout/stderr of the workers? -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #16 from Mihael Hategan <[email protected]> 2012-02-14 12:13:07 --- The workers aren't dying. As far as I can tell, all that is left is something that prevents network packets from flowing properly. It looks completely unrelated to the code. Only triggered by it somehow. Can you ask the admin folks for system logs surrounding the time of the run and whether there are any local firewall rules related to network traffic? -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #18 from David Kelly <[email protected]> 2012-02-15 12:05:35 --- I can reproduce this issue now using only 1 worker host and 1 worker per node. I see it in both 0.93 and trunk. This morning I wanted to test and see if I could reproduce issues with large file transfers between thwomp and communicado using only netcat. I created a single large data file which is approximately 5 gigs. On communicado: $ cat /autonfs/gpfs-pads/projects/CI-CCR000013/davidk/largefile |nc -l 50009 On thwomp: $ nc communicado.ci.uchicago.edu 50009 > data.out The transfer starts and typically completes somewhere on the range of 1-3 gigs. Then it freezes and no more progress is made. I have sent this information to MCS network and CI support. -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #20 from David Kelly <[email protected]> 2012-02-15 15:06:38 --- The issues I have been seeing between the MCS workstations and communicado have been resolved. Corby Schmitz at MCS network support has been working with me on this issue. After his modifications to some firewall rules, my netcat tests complete. I re-ran the Swift test, and for the first time ever, it has successfully completed all 500 tasks. One thing that is unclear to me at the moment is the scope of these changes. I am not sure if these changes are limited to traffic between MCS and CI, or if it affects all traffic to/from communicado. I explained to him how we have seen similar situations with workers running on OSG. I'm waiting to hear back about this. Here is the original email from Corby. ---- This is very helpful information. I am taking a diagnostic step to see if we can isolate the problem. I have created a set of firewall rules to bypass the reflexive rules we have in place. They are prone to problems with long-term transfers of this nature. The rules are as follows: CHANGE: vlan-808-incoming CHANGE: diff from archive copy to push copy CHANGE: 13a14 CHANGE: > permit tcp any host 128.135.125.17 range 50000 51000 CHANGE: vlan-808-outgoing CHANGE: diff from archive copy to push copy CHANGE: 60a61 CHANGE: > permit tcp host 128.135.125.17 range 50000 51000 any This covers all the servers you initially listed. Can you run your netcat test again and let me know how the results pan out? -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #22 from Mihael Hategan <[email protected]> 2012-02-15 15:24:02 --- Can you ask Corby why they are doing this in the first place? Is it to optimize the TCP window size? -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #24 from Michael Wilde <[email protected]> 2012-02-15 18:58:44 --- Ketan, can you coordinate with David regarding what data transfer endpoints your tests were failing with, and whether, based on the latest info posted to this ticket, you might now be able to run? David, Mihael: I dont understand the last few entries in this ticket regarding whether we know why coaster provider staging transfers were failing in the SCEC runs. It seems only firewall settings at Argonne were changed. David and I discussed some tests to try to recreate the problem between other WAN-connected endpoints, and also seeing is manually setting a TCO window size on the connection might help. -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #26 from Michael Wilde <[email protected]> 2012-02-20 13:14:13 --- David, doesnt this experiment contradict what Corby described? Ie, I though he said that the window kept *growing* and then the firewall shut down the connection. Can you work with him to see what the firewall is saying when you run this latest test? -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #28 from David Kelly <[email protected]> 2012-02-21 10:41:14 --- I will email Corby today. Setting SO_SNDBUF and SO_RCVBUF are only suggestions to the kernel about how to set the window size. I don't have the information about what is actually happening at that level yet. I will run a packet sniffer to see how these suggestions actually affect the tcp window size. To run the packet sniffer I needed root access, so I am using my laptop as a server, and thwomp as the client. I am using my internet connection from home to bypass the Argonne firewall so that clients can connect to my server. I will send an update when I have some more results. -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #30 from David Kelly <[email protected]> 2012-02-24 16:57:08 --- I wrote a test to simulate the SCEC workflow. Each task stages in 200MB, sleeps, then stages out 10MB. I ran this on OSG with about 200 active workers and saw the timeouts. I tried the same test on MCS and saw the same timeout failure. I scaled it down to the point where I can see timeouts using only 1 workers with 4 jobs per node. The logs for my latest run can be found at http://www.ci.uchicago.edu/~davidk/logs/pcatsn-pm802hl8.tar.gz (the CI site has been up and down all day, but the data should be there when it returns) Also, this can be reproduced even more simply by starting swift, coaster-service and worker.pl on the same machine (set jobs per node = 4). Staging out seems more likely to trigger these freezes than staging in. The freezes seem to happen at the very beginning of the staging out. The file often gets created, but is 0 bytes. Right before the freezes start, I see a large amount of packets with a 0-byte window size. It never recovers.. nothing else gets sent. Sidenote: Would coasters benefit from using two connections - one for control commands, and one for data? This is very similar to what FTP does. The control channel would be used for simple commands and heartbeats. The data channel would be used for transferring files only. I think it might also help in terms of performance. On the control channel you would want smaller, more frequent packets and TCP_NO_DELAY. On the data channel, you would want larger packets and more optimization. -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #32 from David Kelly <[email protected]> 2012-04-04 01:58:46 --- Here is a recent jstack from using provider staging with 0.93 on MCS ( also can be found at http://www.ci.uchicago.edu/~davidk/logs/jstack-staging.log ) 2012-04-04 01:54:16 Full thread dump Java HotSpot(TM) 64-Bit Server VM (21.1-b02 mixed mode): "Attach Listener" daemon prio=10 tid=0x0000000000ce7000 nid=0x7906 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "Timer-3" daemon prio=10 tid=0x0000000000c5e800 nid=0x42ff in Object.wait() [0x00007ff3e6839000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.util.TimerThread.mainLoop(Timer.java:552) - locked <0x000000078812cb00> (a java.util.TaskQueue) at java.util.TimerThread.run(Timer.java:505) Locked ownable synchronizers: - None "I/O Queue" daemon prio=10 tid=0x0000000000d9d800 nid=0x42f9 in Object.wait() [0x00007ff3e693a000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at org.globus.cog.abstraction.impl.file.coaster.buffers.Buffers.run(Buffers.java:178) - locked <0x0000000788150000> (a org.globus.cog.abstraction.impl.file.coaster.buffers.Buffers) Locked ownable synchronizers: - None "I/O Queue" daemon prio=10 tid=0x0000000000d9c800 nid=0x42f8 in Object.wait() [0x00007ff3e6a3b000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at org.globus.cog.abstraction.impl.file.coaster.buffers.Buffers.run(Buffers.java:178) - locked <0x0000000788148518> (a org.globus.cog.abstraction.impl.file.coaster.buffers.Buffers) Locked ownable synchronizers: - None "Sender WorkerChannel" daemon prio=10 tid=0x0000000000d98800 nid=0x42f7 runnable [0x00007ff3e6b3c000] java.lang.Thread.State: RUNNABLE at java.net.SocketOutputStream.socketWrite0(Native Method) at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109) at java.net.SocketOutputStream.write(SocketOutputStream.java:141) at org.globus.cog.karajan.workflow.service.channels.AbstractStreamKarajanChannel$Sender.send(AbstractStreamKarajanChannel.java:331) - locked <0x0000000788148648> (a java.net.SocketOutputStream) at org.globus.cog.karajan.workflow.service.channels.AbstractStreamKarajanChannel$Sender.run(AbstractStreamKarajanChannel.java:273) Locked ownable synchronizers: - None "PullThread" daemon prio=10 tid=0x0000000000da2800 nid=0x42f6 in Object.wait() [0x00007ff3e6c3d000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at org.globus.cog.abstraction.coaster.service.job.manager.PullThread.mwait(PullThread.java:118) at org.globus.cog.abstraction.coaster.service.job.manager.PullThread.run(PullThread.java:89) - locked <0x00000007881500a0> (a org.globus.cog.abstraction.coaster.service.job.manager.PullThread) Locked ownable synchronizers: - None "Timer-2" daemon prio=10 tid=0x0000000000c82800 nid=0x40e2 in Object.wait() [0x00007ff3e6d3e000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0000000788160080> (a java.util.TaskQueue) at java.lang.Object.wait(Object.java:503) at java.util.TimerThread.mainLoop(Timer.java:526) - locked <0x0000000788160080> (a java.util.TaskQueue) at java.util.TimerThread.run(Timer.java:505) Locked ownable synchronizers: - None "Sender TCPChannel" daemon prio=10 tid=0x00007ff3e80f9800 nid=0x40e1 waiting on condition [0x00007ff3e6e3f000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000007881ce090> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.globus.cog.karajan.workflow.service.channels.AbstractStreamKarajanChannel$Sender.run(AbstractStreamKarajanChannel.java:265) Locked ownable synchronizers: - None "Channel multiplexer 1" daemon prio=10 tid=0x0000000000d96000 nid=0x40e0 waiting on condition [0x00007ff3e6f40000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at org.globus.cog.karajan.workflow.service.channels.AbstractStreamKarajanChannel$Multiplexer.run(AbstractStreamKarajanChannel.java:443) Locked ownable synchronizers: - None "Channel multiplexer 0" daemon prio=10 tid=0x0000000000e8d000 nid=0x40df in Object.wait() [0x00007ff3e7041000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0000000788148518> (a org.globus.cog.abstraction.impl.file.coaster.buffers.Buffers) at java.lang.Object.wait(Object.java:503) at org.globus.cog.abstraction.impl.file.coaster.buffers.Buffers.request(Buffers.java:140) - locked <0x0000000788148518> (a org.globus.cog.abstraction.impl.file.coaster.buffers.Buffers) at org.globus.cog.abstraction.impl.file.coaster.handlers.providers.ProxyIOProvider$CWriteBuffer.write(ProxyIOProvider.java:423) at org.globus.cog.abstraction.impl.file.coaster.commands.GetFileCommand.addInData(GetFileCommand.java:62) at org.globus.cog.karajan.workflow.service.commands.Command.dataReceived(Command.java:82) at org.globus.cog.karajan.workflow.service.commands.Command.replyReceived(Command.java:86) at org.globus.cog.karajan.workflow.service.channels.AbstractKarajanChannel.handleReply(AbstractKarajanChannel.java:394) at org.globus.cog.karajan.workflow.service.channels.AbstractStreamKarajanChannel.step(AbstractStreamKarajanChannel.java:176) at org.globus.cog.karajan.workflow.service.channels.AbstractStreamKarajanChannel$Multiplexer.run(AbstractStreamKarajanChannel.java:404) Locked ownable synchronizers: - None "Timer-1" daemon prio=10 tid=0x0000000000e93800 nid=0x40de in Object.wait() [0x00007ff3e7142000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.util.TimerThread.mainLoop(Timer.java:552) - locked <0x0000000788160108> (a java.util.TaskQueue) at java.util.TimerThread.run(Timer.java:505) Locked ownable synchronizers: - None "Passive Queue Processor" prio=10 tid=0x0000000000e3b800 nid=0x3de0 in Object.wait() [0x00007ff3e7243000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at org.globus.cog.abstraction.coaster.service.job.manager.BlockQueueProcessor.run(BlockQueueProcessor.java:116) - locked <0x0000000788160238> (a java.util.ArrayList) Locked ownable synchronizers: - None "Local Queue Processor" prio=10 tid=0x0000000000e3e000 nid=0x3ddf in Object.wait() [0x00007ff3e7344000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000007881602c8> (a org.globus.cog.karajan.util.Queue) at java.lang.Object.wait(Object.java:503) at org.globus.cog.karajan.util.Queue.take(Queue.java:46) - locked <0x00000007881602c8> (a org.globus.cog.karajan.util.Queue) at org.globus.cog.abstraction.coaster.service.job.manager.AbstractQueueProcessor.take(AbstractQueueProcessor.java:51) at org.globus.cog.abstraction.coaster.service.job.manager.LocalQueueProcessor.run(LocalQueueProcessor.java:37) Locked ownable synchronizers: - None "Server: http://140.221.9.237:53562" daemon prio=10 tid=0x00007ff3e8342800 nid=0x3dde runnable [0x00007ff3e7445000] java.lang.Thread.State: RUNNABLE at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:396) at java.net.ServerSocket.implAccept(ServerSocket.java:522) at java.net.ServerSocket.accept(ServerSocket.java:490) at org.globus.net.BaseServer.run(BaseServer.java:226) at java.lang.Thread.run(Thread.java:722) Locked ownable synchronizers: - None "Server: http://140.221.9.237:55514" daemon prio=10 tid=0x00007ff3e8348000 nid=0x3ddd runnable [0x00007ff3e7546000] java.lang.Thread.State: RUNNABLE at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:396) at java.net.ServerSocket.implAccept(ServerSocket.java:522) at java.net.ServerSocket.accept(ServerSocket.java:490) at org.globus.net.BaseServer.run(BaseServer.java:226) at java.lang.Thread.run(Thread.java:722) Locked ownable synchronizers: - None "Timer-0" prio=10 tid=0x00007ff3e8322000 nid=0x3ddc in Object.wait() [0x00007ff3e7882000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.util.TimerThread.mainLoop(Timer.java:552) - locked <0x0000000788160658> (a java.util.TaskQueue) at java.util.TimerThread.run(Timer.java:505) Locked ownable synchronizers: - None "Service Thread" daemon prio=10 tid=0x00007ff3e80d7800 nid=0x3dcd runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "C2 CompilerThread1" daemon prio=10 tid=0x00007ff3e80d5000 nid=0x3dcc waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "C2 CompilerThread0" daemon prio=10 tid=0x00007ff3e80d2000 nid=0x3dcb waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "Signal Dispatcher" daemon prio=10 tid=0x00007ff3e80d0000 nid=0x3dca runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "Finalizer" daemon prio=10 tid=0x00007ff3e807d000 nid=0x3dc9 in Object.wait() [0x00007ff3ec5aa000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000007881782a8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135) - locked <0x00000007881782a8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:177) Locked ownable synchronizers: - None "Reference Handler" daemon prio=10 tid=0x00007ff3e807b000 nid=0x3dc8 in Object.wait() [0x00007ff3ec6ab000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0000000788146130> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:503) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) - locked <0x0000000788146130> (a java.lang.ref.Reference$Lock) Locked ownable synchronizers: - None "main" prio=10 tid=0x0000000000bec000 nid=0x3db7 in Object.wait() [0x00007ff3f4cb4000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at org.globus.cog.abstraction.coaster.service.CoasterService.waitFor(CoasterService.java:215) - locked <0x00000007881781b8> (a org.globus.cog.abstraction.coaster.service.CoasterPersistentService) at org.globus.cog.abstraction.coaster.service.CoasterPersistentService.main(CoasterPersistentService.java:153) Locked ownable synchronizers: - None "VM Thread" prio=10 tid=0x00007ff3e8073800 nid=0x3dc7 runnable "GC task thread#0 (ParallelGC)" prio=10 tid=0x0000000000bf7000 nid=0x3db8 runnable "GC task thread#1 (ParallelGC)" prio=10 tid=0x0000000000bf9000 nid=0x3db9 runnable "GC task thread#2 (ParallelGC)" prio=10 tid=0x0000000000bfa800 nid=0x3dba runnable "GC task thread#3 (ParallelGC)" prio=10 tid=0x0000000000bfc800 nid=0x3dbb runnable "GC task thread#4 (ParallelGC)" prio=10 tid=0x0000000000bfe800 nid=0x3dbc runnable "GC task thread#5 (ParallelGC)" prio=10 tid=0x0000000000c00000 nid=0x3dbd runnable "GC task thread#6 (ParallelGC)" prio=10 tid=0x0000000000c02000 nid=0x3dbe runnable "GC task thread#7 (ParallelGC)" prio=10 tid=0x0000000000c04000 nid=0x3dbf runnable "GC task thread#8 (ParallelGC)" prio=10 tid=0x0000000000c05800 nid=0x3dc0 runnable "GC task thread#9 (ParallelGC)" prio=10 tid=0x0000000000c07800 nid=0x3dc1 runnable "GC task thread#10 (ParallelGC)" prio=10 tid=0x0000000000c09800 nid=0x3dc2 runnable "GC task thread#11 (ParallelGC)" prio=10 tid=0x0000000000c0b800 nid=0x3dc3 runnable "GC task thread#12 (ParallelGC)" prio=10 tid=0x0000000000c0d000 nid=0x3dc4 runnable "VM Periodic Task Thread" prio=10 tid=0x00007ff3e80e2800 nid=0x3dce waiting on condition JNI global references: 175 david@rogue:~$ cat jstack-staging.log david@rogue:~$ cat jstack-staging.log 2012-04-04 01:54:16 Full thread dump Java HotSpot(TM) 64-Bit Server VM (21.1-b02 mixed mode): "Attach Listener" daemon prio=10 tid=0x0000000000ce7000 nid=0x7906 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "Timer-3" daemon prio=10 tid=0x0000000000c5e800 nid=0x42ff in Object.wait() [0x00007ff3e6839000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.util.TimerThread.mainLoop(Timer.java:552) - locked <0x000000078812cb00> (a java.util.TaskQueue) at java.util.TimerThread.run(Timer.java:505) Locked ownable synchronizers: - None "I/O Queue" daemon prio=10 tid=0x0000000000d9d800 nid=0x42f9 in Object.wait() [0x00007ff3e693a000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at org.globus.cog.abstraction.impl.file.coaster.buffers.Buffers.run(Buffers.java:178) - locked <0x0000000788150000> (a org.globus.cog.abstraction.impl.file.coaster.buffers.Buffers) Locked ownable synchronizers: - None "I/O Queue" daemon prio=10 tid=0x0000000000d9c800 nid=0x42f8 in Object.wait() [0x00007ff3e6a3b000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at org.globus.cog.abstraction.impl.file.coaster.buffers.Buffers.run(Buffers.java:178) - locked <0x0000000788148518> (a org.globus.cog.abstraction.impl.file.coaster.buffers.Buffers) Locked ownable synchronizers: - None "Sender WorkerChannel" daemon prio=10 tid=0x0000000000d98800 nid=0x42f7 runnable [0x00007ff3e6b3c000] java.lang.Thread.State: RUNNABLE at java.net.SocketOutputStream.socketWrite0(Native Method) at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109) at java.net.SocketOutputStream.write(SocketOutputStream.java:141) at org.globus.cog.karajan.workflow.service.channels.AbstractStreamKarajanChannel$Sender.send(AbstractStreamKarajanChannel.java:331) - locked <0x0000000788148648> (a java.net.SocketOutputStream) at org.globus.cog.karajan.workflow.service.channels.AbstractStreamKarajanChannel$Sender.run(AbstractStreamKarajanChannel.java:273) Locked ownable synchronizers: - None "PullThread" daemon prio=10 tid=0x0000000000da2800 nid=0x42f6 in Object.wait() [0x00007ff3e6c3d000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at org.globus.cog.abstraction.coaster.service.job.manager.PullThread.mwait(PullThread.java:118) at org.globus.cog.abstraction.coaster.service.job.manager.PullThread.run(PullThread.java:89) - locked <0x00000007881500a0> (a org.globus.cog.abstraction.coaster.service.job.manager.PullThread) Locked ownable synchronizers: - None "Timer-2" daemon prio=10 tid=0x0000000000c82800 nid=0x40e2 in Object.wait() [0x00007ff3e6d3e000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0000000788160080> (a java.util.TaskQueue) at java.lang.Object.wait(Object.java:503) at java.util.TimerThread.mainLoop(Timer.java:526) - locked <0x0000000788160080> (a java.util.TaskQueue) at java.util.TimerThread.run(Timer.java:505) Locked ownable synchronizers: - None "Sender TCPChannel" daemon prio=10 tid=0x00007ff3e80f9800 nid=0x40e1 waiting on condition [0x00007ff3e6e3f000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00000007881ce090> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.globus.cog.karajan.workflow.service.channels.AbstractStreamKarajanChannel$Sender.run(AbstractStreamKarajanChannel.java:265) Locked ownable synchronizers: - None "Channel multiplexer 1" daemon prio=10 tid=0x0000000000d96000 nid=0x40e0 waiting on condition [0x00007ff3e6f40000] java.lang.Thread.State: TIMED_WAITING (sleeping) at java.lang.Thread.sleep(Native Method) at org.globus.cog.karajan.workflow.service.channels.AbstractStreamKarajanChannel$Multiplexer.run(AbstractStreamKarajanChannel.java:443) Locked ownable synchronizers: - None "Channel multiplexer 0" daemon prio=10 tid=0x0000000000e8d000 nid=0x40df in Object.wait() [0x00007ff3e7041000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0000000788148518> (a org.globus.cog.abstraction.impl.file.coaster.buffers.Buffers) at java.lang.Object.wait(Object.java:503) at org.globus.cog.abstraction.impl.file.coaster.buffers.Buffers.request(Buffers.java:140) - locked <0x0000000788148518> (a org.globus.cog.abstraction.impl.file.coaster.buffers.Buffers) at org.globus.cog.abstraction.impl.file.coaster.handlers.providers.ProxyIOProvider$CWriteBuffer.write(ProxyIOProvider.java:423) at org.globus.cog.abstraction.impl.file.coaster.commands.GetFileCommand.addInData(GetFileCommand.java:62) at org.globus.cog.karajan.workflow.service.commands.Command.dataReceived(Command.java:82) at org.globus.cog.karajan.workflow.service.commands.Command.replyReceived(Command.java:86) at org.globus.cog.karajan.workflow.service.channels.AbstractKarajanChannel.handleReply(AbstractKarajanChannel.java:394) at org.globus.cog.karajan.workflow.service.channels.AbstractStreamKarajanChannel.step(AbstractStreamKarajanChannel.java:176) at org.globus.cog.karajan.workflow.service.channels.AbstractStreamKarajanChannel$Multiplexer.run(AbstractStreamKarajanChannel.java:404) Locked ownable synchronizers: - None "Timer-1" daemon prio=10 tid=0x0000000000e93800 nid=0x40de in Object.wait() [0x00007ff3e7142000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.util.TimerThread.mainLoop(Timer.java:552) - locked <0x0000000788160108> (a java.util.TaskQueue) at java.util.TimerThread.run(Timer.java:505) Locked ownable synchronizers: - None "Passive Queue Processor" prio=10 tid=0x0000000000e3b800 nid=0x3de0 in Object.wait() [0x00007ff3e7243000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at org.globus.cog.abstraction.coaster.service.job.manager.BlockQueueProcessor.run(BlockQueueProcessor.java:116) - locked <0x0000000788160238> (a java.util.ArrayList) Locked ownable synchronizers: - None "Local Queue Processor" prio=10 tid=0x0000000000e3e000 nid=0x3ddf in Object.wait() [0x00007ff3e7344000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000007881602c8> (a org.globus.cog.karajan.util.Queue) at java.lang.Object.wait(Object.java:503) at org.globus.cog.karajan.util.Queue.take(Queue.java:46) - locked <0x00000007881602c8> (a org.globus.cog.karajan.util.Queue) at org.globus.cog.abstraction.coaster.service.job.manager.AbstractQueueProcessor.take(AbstractQueueProcessor.java:51) at org.globus.cog.abstraction.coaster.service.job.manager.LocalQueueProcessor.run(LocalQueueProcessor.java:37) Locked ownable synchronizers: - None "Server: http://140.221.9.237:53562" daemon prio=10 tid=0x00007ff3e8342800 nid=0x3dde runnable [0x00007ff3e7445000] java.lang.Thread.State: RUNNABLE at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:396) at java.net.ServerSocket.implAccept(ServerSocket.java:522) at java.net.ServerSocket.accept(ServerSocket.java:490) at org.globus.net.BaseServer.run(BaseServer.java:226) at java.lang.Thread.run(Thread.java:722) Locked ownable synchronizers: - None "Server: http://140.221.9.237:55514" daemon prio=10 tid=0x00007ff3e8348000 nid=0x3ddd runnable [0x00007ff3e7546000] java.lang.Thread.State: RUNNABLE at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:396) at java.net.ServerSocket.implAccept(ServerSocket.java:522) at java.net.ServerSocket.accept(ServerSocket.java:490) at org.globus.net.BaseServer.run(BaseServer.java:226) at java.lang.Thread.run(Thread.java:722) Locked ownable synchronizers: - None "Timer-0" prio=10 tid=0x00007ff3e8322000 nid=0x3ddc in Object.wait() [0x00007ff3e7882000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at java.util.TimerThread.mainLoop(Timer.java:552) - locked <0x0000000788160658> (a java.util.TaskQueue) at java.util.TimerThread.run(Timer.java:505) Locked ownable synchronizers: - None "Service Thread" daemon prio=10 tid=0x00007ff3e80d7800 nid=0x3dcd runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "C2 CompilerThread1" daemon prio=10 tid=0x00007ff3e80d5000 nid=0x3dcc waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "C2 CompilerThread0" daemon prio=10 tid=0x00007ff3e80d2000 nid=0x3dcb waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "Signal Dispatcher" daemon prio=10 tid=0x00007ff3e80d0000 nid=0x3dca runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE Locked ownable synchronizers: - None "Finalizer" daemon prio=10 tid=0x00007ff3e807d000 nid=0x3dc9 in Object.wait() [0x00007ff3ec5aa000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00000007881782a8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135) - locked <0x00000007881782a8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:177) Locked ownable synchronizers: - None "Reference Handler" daemon prio=10 tid=0x00007ff3e807b000 nid=0x3dc8 in Object.wait() [0x00007ff3ec6ab000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0000000788146130> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:503) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133) - locked <0x0000000788146130> (a java.lang.ref.Reference$Lock) Locked ownable synchronizers: - None "main" prio=10 tid=0x0000000000bec000 nid=0x3db7 in Object.wait() [0x00007ff3f4cb4000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at org.globus.cog.abstraction.coaster.service.CoasterService.waitFor(CoasterService.java:215) - locked <0x00000007881781b8> (a org.globus.cog.abstraction.coaster.service.CoasterPersistentService) at org.globus.cog.abstraction.coaster.service.CoasterPersistentService.main(CoasterPersistentService.java:153) Locked ownable synchronizers: - None "VM Thread" prio=10 tid=0x00007ff3e8073800 nid=0x3dc7 runnable "GC task thread#0 (ParallelGC)" prio=10 tid=0x0000000000bf7000 nid=0x3db8 runnable "GC task thread#1 (ParallelGC)" prio=10 tid=0x0000000000bf9000 nid=0x3db9 runnable "GC task thread#2 (ParallelGC)" prio=10 tid=0x0000000000bfa800 nid=0x3dba runnable "GC task thread#3 (ParallelGC)" prio=10 tid=0x0000000000bfc800 nid=0x3dbb runnable "GC task thread#4 (ParallelGC)" prio=10 tid=0x0000000000bfe800 nid=0x3dbc runnable "GC task thread#5 (ParallelGC)" prio=10 tid=0x0000000000c00000 nid=0x3dbd runnable "GC task thread#6 (ParallelGC)" prio=10 tid=0x0000000000c02000 nid=0x3dbe runnable "GC task thread#7 (ParallelGC)" prio=10 tid=0x0000000000c04000 nid=0x3dbf runnable "GC task thread#8 (ParallelGC)" prio=10 tid=0x0000000000c05800 nid=0x3dc0 runnable "GC task thread#9 (ParallelGC)" prio=10 tid=0x0000000000c07800 nid=0x3dc1 runnable "GC task thread#10 (ParallelGC)" prio=10 tid=0x0000000000c09800 nid=0x3dc2 runnable "GC task thread#11 (ParallelGC)" prio=10 tid=0x0000000000c0b800 nid=0x3dc3 runnable "GC task thread#12 (ParallelGC)" prio=10 tid=0x0000000000c0d000 nid=0x3dc4 runnable "VM Periodic Task Thread" prio=10 tid=0x00007ff3e80e2800 nid=0x3dce waiting on condition JNI global references: 175 -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #34 from Michael Wilde <[email protected]> 2012-04-09 10:40:03 --- (In reply to comment #33)

So this looks like one of the worker sockets is full and not getting any better. We should find out why (1)

Do you mean by this that you've determine that the worker is hanging in the process of staging an output file back to the coaster service?

However, this shows a problem with the way things are implemented: if one of the sockets is blocked, that stops all worker traffic. This can be improved. So I started to rewrite that portion to use selectable NIO channels such that a blocked socket won't affect the other sockets and traffic can still flow on the working sockets (2)

I'm doing (2). I need help with (1).

Before we test with the new NIO-based code, do we already have sufficient worker logs to diagnose (1), or is that what you need when you say "I need help with (1)"? I see from comment #30, David, that you can reproduce this with one worker. Can you reproduce it with jobPerNode=1? Or only with 4 as I think you state in that comment? In either case, would getting a selective strace on the worker, along with DEBUG or TRACE worker logs, help? (Ie just strace IO and Socket syscalls)? Can we tell, when the worker hangs, how far it has gotten in any files it is in the process of staging out to the coaster service (if this is indeed what you think is happening)? -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #36 from David Kelly <[email protected]> 2012-04-09 20:28:25 ---

From another run tonight (on 2 MCS machines, 500 tasks, 10 megs per file, jobs per node=4)

Swift log: http://www.ci.uchicago.edu/~davidk/logs/catsn_random-20120409-1958-cdly3zl6.... Worker log: http://www.ci.uchicago.edu/~davidk/logs/worker-thwomp-20120409.log jstack: http://www.ci.uchicago.edu/~davidk/logs/jstack-20120409.log strace of worker.pl: http://www.ci.uchicago.edu/~davidk/logs/strace-20120409.log.gz -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #38 from Michael Wilde <[email protected]> 2012-04-11 09:17:03 --- Im adding thsi comment to document several emails describing progress in past 24 hours. Mihael, is the fix to the scenario you describe in the first email below (Tuesday, April 10, 2012 7:04:56 PM) now comitted? David, is that what you tested? Or did this scenario not occur with the new NIO code in place? Also, David: your email below implies that some of these fixes are not in place for automatic coasters, but only for manual (as you say "latest update which fixes coaster-service") Can you both update this ticket to summarize the state of the fixes? Ie, are all the problems identified related to provider staging now fixed for all configs, or is there more known work needed to call this issue resolved? In any case, nice work guys - this is excellent news and excellent progress! - Mike --- ----- Forwarded Message ----- From: "Mihael Hategan" <[email protected]> To: "David Kelly" <[email protected]> Cc: "Swift Devel" <[email protected]> Sent: Tuesday, April 10, 2012 7:04:56 PM Subject: Re: [Swift-devel] coaster io with NIO. On Tue, 2012-04-10 at 17:25 -0500, David Kelly wrote:

Yep, I gave it a try with automatic coasters, but am still seeing the timeouts.

I think I see the problem. With multiple jobs per worker the situation may such be that both a stagein and a stageout happen at the same time (on the same TCP connection). If the stageout runs out of buffers the writing to the socket on the worker side blocks causing the read loop to not happen. This eventually fills the other direction on the TCP link and everything deadlocks. --- ----- Forwarded Message ----- From: "Mihael Hategan" <[email protected]> To: "Michael Wilde" <[email protected]> Cc: "Swift Devel" <[email protected]>, "David Kelly" <[email protected]> Sent: Tuesday, April 10, 2012 9:13:03 PM Subject: Re: [Swift-devel] coaster io with NIO. On Tue, 2012-04-10 at 21:07 -0500, Michael Wilde wrote:

Mihael, while the scenario below seems plausible, I thought that the timeout problem was first detected on OSG nodes, which should have been running with jobsPerNode=1.

It's possible that there is another problem. However, David's latest logs (posted in bug 690) show this: - read from worker socket thread blocked on allocation of buffers - worker blocked in send() (thus unable to recv()). - service blocked in send() to worker Part of this should be addressed by the NIO stuff, so we'll need new logs. --- ----- Forwarded Message ----- From: "Ketan Maheshwari" <[email protected]> To: "Michael Wilde" <[email protected]> Sent: Tuesday, April 10, 2012 9:31:34 PM Subject: Re: [Swift-devel] coaster io with NIO. Jobspernode setting were indeed 1 on the tests done on osg. I do not recall seeing the blocking messages seen by David's current/recent tests. --- ----- Forwarded Message ----- From: "David Kelly" <[email protected]> To: "Michael Wilde" <[email protected]> Cc: "Swift Devel" <[email protected]>, "Ketan Maheshwari" <[email protected]> Sent: Tuesday, April 10, 2012 11:33:20 PM Subject: Re: [Swift-devel] coaster io with NIO. Since the latest update which fixes coaster-service, I have tested with two configurations: 1 machine only, 4 jobs per node, 100 200MB files (ran twice, passed twice) 2 MCS machines - swift and coaster-service running on one machine, 1 worker, 4 jobs per node, 500 20MB files (also ran twice, passed twice) These tests were failing pretty consistently yesterday. I am not positive it is completely fixed yet, but things have definitely improved. I have never been able to reproduce provider staging problems using jobs per node set of 1. It was only when I got to a value of 4 that I started seeing issues. I will write a test tonight that runs on OSG and let you know what happens. David --- ----- Forwarded Message ----- From: "David Kelly" <[email protected]> To: "Michael Wilde" <[email protected]> Cc: "Swift Devel" <[email protected]> Sent: Wednesday, April 11, 2012 1:00:36 AM Subject: Re: [Swift-devel] coaster io with NIO. I just ran a test on OSG similar to what Ketan described in the initial entry for ticket #690: Submit host: communicado using data on GPFS 100 nodes using Condor GlideinWMS 500 jobs 10MB data files The test completed without errors. -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #40 from David Kelly <[email protected]> 2012-04-12 00:20:14 --- Every test I have ran since r3371 (the second update last night) has passed. I've tried different combinations of systems (locally on my laptop, MCS, communicado, bridled, OSG), different values for jobs per node, and a varying number of tasks. I have tested with automatic and manual coasters. I have only seen two small issues. The first is that GLOBUS_TCP_PORT_RANGE does not seem to be honored. The second is that I am getting a small number of failures, maybe 5% of the total number of tasks, which I did not see before. The tasks fail with exit code 521 (timeout while staging out). But, they will almost always finish on the second try. -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #42 from Mihael Hategan <[email protected]> 2012-04-12 19:28:10 --- I committed the non-blocking socket I/O worker code (cog trunk r3373). This, together with the NIO stuff, should fix the deadlocking behavior. The NIO stuff by itself should reduce the incidence of deadlocks, so it may have appeared as though it has fixed the issue. -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #44 from David Kelly <[email protected]> 2012-04-15 15:53:24 --- The issue with a large amount of socket related exceptions has been fixed. From the swift-devel meeting last Friday, the plan is to continue with testing to determine any issues. -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #46 from David Kelly <[email protected]> 2012-04-20 08:34:02 --- I tried the updated version, but still see a few exceptions at the start. Probably not a huge deal since it seems to continue past these fine. The link to the logs are below. Just wanted to give a quick update on the tests that I have done this week. When using 1 job per node, everything seems to work fine. I have tested with large amounts of data on MCS and not run into any issues. I have also tested this on OSG and it seems fine. I am still running into some issues when testing with large data and 4 jobs per node. Looking through the logs, I see messages about the channels dying and then I get an out of memory exception. I am running with both Swift and coaster-service heap max at 8G (staging 500 files at 200MB each across 10 nodes with jobs per node at 4). The logs for this are at http://www.ci.uchicago.edu/~davidk/logs/logs-2012-04-20.tar.gz (17MB). -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #48 from Mihael Hategan <[email protected]> 2012-04-25 00:29:11 --- (In reply to comment #47)

Yesterday, I tried a larger set of data on OSG using 1 worker per node and saw timeouts. I'll try again later to get a better set of worker logs (need to give them all a unique filename so they don't get overwritten when condor sends them back). The file below has the coaster service log, swift log, and 1 worker log.

http://www.ci.uchicago.edu/~davidk/logs/logs-2012-04-23.tar.gz

It's ok. I have enough to go with for now. -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #50 from Mihael Hategan <[email protected]> 2012-05-21 18:18:59 --- Regarding the timeouts, they seem to occur when one particular site starts complaining about the disk quota when the worker writes to a file. While the obvious solution is to not run on sites that have very limited space available, there needs to be a solution to this class of problem (workers dying in the middle of a stage-in). The problem actually occurs because when a worker fails catastrophically like that, the buffers currently in use by active transfers on that worker don't get properly released. I have been testing a bunch of fixes for that and related problems (e.g. once writing to a file fails in the worker, the client/service should stop sending data for that file). -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #52 from David Kelly <[email protected]> 2012-05-21 19:49:31 --- In previous coaster tests I was using on OSG, I also had the work directory set to /tmp I believe. This was because it wasn't easy to set the work directory to be an environment variable that was declared on the remote system. To get around this you would probably need to modify worker.pl to create a symlink from $OSG_WN_TMP to /tmp/somedirectory (or use the new run-a-script at launch option, which I still haven't had a chance to look at). I'll give this a try tomorrow and see what happens. -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #54 from David Kelly <[email protected]> 2012-05-22 10:52:05 --- I committed some changes this morning which should allow you to pretty easily use $OSG_WN_TMP as your work directory. To do this: --- Start your proxy Copy coaster-service.conf from /scratch3/davidk/coaster-stress-tests (or from swift, tests/sites/osg/coaster-service.conf) into your working directory. Adjust the value CONDOR_WORKERS in coaster-service.conf as needed Run start-coaster-service Run swift with the sites.xml, tc.data and cf that gets generated. You will have to run this on engage-submit3 only at the moment. (Run stop-coaster-service when done) --- The new scripts should also include full worker logs now, along with information about disk usage. I ran a few tests this morning. It worked fine on a small test I did. When I did a larger test (500 files x 200mb), I saw provider staging timeouts followed by no progress being made. I looked through the logs in /scratch3/davidk/coaster-stress-tests/condor and did not see anything obvious. As far as I can tell, none of the disks I was using was full. I did not see any errors related to quotas. -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #56 from Mihael Hategan <[email protected]> 2012-05-22 16:24:02 --- (In reply to comment #54)

I ran a few tests this morning. It worked fine on a small test I did. When I did a larger test (500 files x 200mb), I saw provider staging timeouts followed by no progress being made.

I haven't committed any fixes yet. -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #58 from David Kelly <[email protected]> 2012-05-28 17:58:05 --- I've been testing these changes over the weekend and this is all looking very good to me. I started with the 200MB test. This is 500 tasks, each task staging in and staging out 200MB. I ran this across 100 OSG nodes using GWMS. I ran this a few different times now and it seems to work fine. The second test was doing a real DSSAT run on OSG. This consists of ~120K tasks, staging in a total of 80gb, and staging out a total of 18gb. For each run I requested 1000 nodes, but usually got somewhere around 500-800. In each of the two cases, the runs got nearly done before running into a hang checker issue. Each got to exactly to task 119190 before exiting, so I believe this is just a case of some missing input data. I will try again with a different data set tomorrow to verify. -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 --- Comment #60 from Mihael Hategan <[email protected]> 2012-06-11 15:42:16 --- Can you file it separately? I'm getting tired of 690. True, it's in coaster staging, but it's a different problem. -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.

https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=690 Mihael Hategan <[email protected]> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|ASSIGNED |RESOLVED Resolution| |FIXED -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.