[Bug 1347] New: Channel timeouts on Midway
https://bugzilla.mcs.anl.gov/swift/show_bug.cgi?id=1347 Summary: Channel timeouts on Midway Product: Swift Version: 0.95 Platform: PC OS/Version: Mac OS Status: NEW Severity: normal Priority: P2 Component: General AssignedTo: [email protected] ReportedBy: [email protected] We started to see this just recently on Midway after upgrading to 0.95. Halfway through a run, all of the active nodes will drop at once. In the logs, there are messages about channel timeouts that seem to happen about the same time. The messages look like this: globus.cog.coaster.TimeoutException: Channel timed out. lastTime=141010-130754.016, now=141010-130954.196, channel=TCPChannel [type: server, contact: 1010-0811220-000095-000000] at org.globus.cog.coaster.channels.AbstractCoasterChannel.checkTimeouts(AbstractCoasterChannel.java:133) at org.globus.cog.coaster.channels.AbstractCoasterChannel$1.run(AbstractCoasterChannel.java:124) at java.util.TimerThread.mainLoop(Timer.java:555) at java.util.TimerThread.run(Timer.java:505) Swift log at http://web.ci.uchicago.edu/~davidk/logs/RunpSIMS-20141010-1107-xgj80xg2.log This has happened for a few different large runs we've done recently in 0.95. I'll try to get a good set of worker logs soon. -- 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=1347 --- Comment #1 from David Kelly <[email protected]> 2014-10-11 15:52:46 --- Here is some additional information about this problem. http://web.ci.uchicago.edu/~davidk/logs/run186/swift.out http://web.ci.uchicago.edu/~davidk/logs/run186/RunpSIMS-20141011-1534-pjh92y... http://web.ci.uchicago.edu/~davidk/logs/run186/workerlogs.tar.gz http://web.ci.uchicago.edu/~davidk/logs/run186/globus-logs.tar.gz You can see in swift.out, around 16:22:53 workers start disconnecting, and by 16:24:05 there are no active workers. In the Swift log, the first channel timeouts appear at 16:27:11. The first error is: 2014-10-11 16:27:11,186+0000 INFO ChannelContext Notifying commands and handlers about exception org.globus.cog.coaster.TimeoutException: Channel timed out. lastTime=141011-162510.870, now=141011-162711.185, channel=TCPChannel [type: server, contact: 1011-3403290-000001-000000] at org.globus.cog.coaster.channels.AbstractCoasterChannel.checkTimeouts(AbstractCoasterChannel.java:133) at org.globus.cog.coaster.channels.AbstractCoasterChannel$1.run(AbstractCoasterChannel.java:124) at java.util.TimerThread.mainLoop(Timer.java:555) at java.util.TimerThread.run(Timer.java:505) I took a quick look at worker-1011-3403290-000001.log but didn't see anything obvious. For coaster block 1011-3403290-000001, the corresponding Slurm submit script is Slurm8783344603467000006.submit. The only thing listed in that stderr is: Use of uninitialized value $s in concatenation (.) or string . . . cscript3769894414609412298.pl at line 2220. This happens pretty consistently, I'd say on average it happens once per run. After some time, new workers start and the run finishes, but Midway has been pretty congested recently, so the delay in waiting for new workers to start can take a lot of time. This has started happening in the last week or 2, around the time we upgraded to Swift 0.95 (possibly just a coincidence though) -- 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=1347 --- Comment #2 from David Kelly <[email protected]> 2014-10-20 13:03:38 --- I will test this on 0.96/trunk soon to see if the problem still exists there -- 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=1347 Yadu Nand <[email protected]> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |[email protected] Severity|normal |blocker -- 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=1347 --- Comment #3 from Mihael Hategan <[email protected]> 2014-11-01 01:28:46 --- It looks like the timeouts occur after workers are shut down, which is to be expected. Here's an example for the first two timeout exceptions in the coaster log, but all I checked are like that: 2014/10/11 11:25:10.000 INFO 000000 Acknowledged shutdown. 2014/10/11 11:25:10.000 INFO 000000 Ran a total of 560 jobs 2014/10/11 11:25:11.000 INFO 000000 Exiting 2014-10-11 16:27:11,186+0000 INFO ChannelContext Notifying commands and handlers about exception org.globus.cog.coaster.TimeoutException: Channel timed out. lastTime=141011-162510.870, now=141011-162711.185, channel=TCPChannel [type: server, contact: 1011-3403290-000001-000000] ----------------------- 2014/10/11 11:25:13.000 INFO 000000 Acknowledged shutdown. 2014/10/11 11:25:13.000 INFO 000000 Ran a total of 560 jobs 2014/10/11 11:25:14.000 INFO 000000 Exiting 2014-10-11 16:27:14,187+0000 INFO ChannelContext Notifying commands and handlers about exception org.globus.cog.coaster.TimeoutException: Channel timed out. lastTime=141011-162513.871, now=141011-162714.187, channel=TCPChannel [type: server, contact: 1011-3403290-000000-000000] ----------------------- I committed (r4045) a patch to disable the timeout checks when a channel is closed. So unless there is another error here that I'm missing, I would close this as not much of a bug. -- 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=1347 David Kelly <[email protected]> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |RESOLVED Resolution| |FIXED --- Comment #4 from David Kelly <[email protected]> 2014-11-01 07:50:25 --- Yep, I think the channel timeouts were a bit of a red herring here. The real issue is that the workers are shutting down before I want them to. At 16:27 there are still 17K+ more tasks to be completed. I just realized that the reason workers are getting shut down early is because of walltime strangeness. In sites.xml I have maxtime set to 12 hours, but the walltime in the Slurm jobs are getting set to 1 hour. The workers are not timing out or dropping, they're getting killed by Slurm. I just need to remember to set lowOverAllocation and highOverAllocation so that it honors my maxtime request. Thanks for your help in tracking this one down. -- Configure bugmail: https://bugzilla.mcs.anl.gov/swift/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
participants (1)
-
bugzilla-daemon@mcs.anl.gov