Spring hangs a lot

[mockdeep]

We've been having a lot of problems with spring hanging on our systems. I started outputting to a log and here's what I see:

[2015-03-19 14:27:01 -0700] [21417] [application:test] initialized -> running
/home/fletch/.rvm/gems/ruby-2.1.5/gems/spring-1.3.3/lib/spring/application.rb:286:in `read': stream closed (IOError)
    from /home/fletch/.rvm/gems/ruby-2.1.5/gems/spring-1.3.3/lib/spring/application.rb:286:in `block (2 levels) in with_pty'
[2015-03-19 14:27:01 -0700] [12838] [application_manager:test] child 21417 shutdown
[2015-03-19 14:27:01 -0700] [21531] [application:test] preloading app
[2015-03-19 14:27:06 -0700] [21531] [application:test] initialized -> running
/home/fletch/.rvm/gems/ruby-2.1.5/gems/spring-1.3.3/lib/spring/application.rb:286:in `read': stream closed (IOError)
    from /home/fletch/.rvm/gems/ruby-2.1.5/gems/spring-1.3.3/lib/spring/application.rb:286:in `block (2 levels) in with_pty'

I haven't got a strong idea of what is causing it just yet, though it seems to come up if we change git branches and the like, so maybe some sort of file changes are causing it to just lock up. We have to run spring stop and start over.

[ulfmagnetics]

+1 also seeing a lot of hangs on OS X Yosemite.

[mockdeep]

I'm on Linux Mint, though other users at our company are seeing it on Mac as well. Something as simple as changing branches can cause it:

[2015-03-26 12:20:36 -0700] [10899] [application:development] running -> watcher_stale
[2015-03-26 12:20:36 -0700] [10899] [application:development] watcher_stale -> exiting
[2015-03-26 12:20:36 -0700] [10896] [application_manager:development] child 10899 shutdown
[2015-03-26 12:20:36 -0700] [11147] [application:development] preloading app
[2015-03-26 12:20:42 -0700] [11147] [application:development] initialized -> running
/home/fletch/.rvm/gems/ruby-2.1.5/gems/spring-1.3.3/lib/spring/application.rb:286:in `read': stream closed (IOError)
    from /home/fletch/.rvm/gems/ruby-2.1.5/gems/spring-1.3.3/lib/spring/application.rb:286:in `block (2 levels) in with_pty'
[2015-03-26 12:20:53 -0700] [10896] [server] accepted client
[2015-03-26 12:20:53 -0700] [10896] [server] running command rails_console
[2015-03-26 12:20:53 -0700] [11180] [client] sending command

[mockdeep]

Ctrl+C won't get me out of it, either. I have to kill the process from elsewhere.

[ulfmagnetics]

Yes, this is exactly my issue. When I log to a file by setting SPRING_LOG, then change branches, I see the above sequence of messages appear (running -> watcher_stale, watcher_stale -> exiting, preloading app, etc.) After that, a call to bin/rspec hard-hangs and has to be killed from another shell.

23:05:13 john ~/src/sandbox [master] $ ruby -v
ruby 2.1.5p273 (2014-11-13 revision 48405) [x86_64-darwin14.0]
23:09:06 john ~/src/sandbox [master] $ spring --version
Spring version 1.2.0

[mscoutermarsh]

This is happening to me as well. For now I've added a post-checkout hook to call spring stop.

[sunnyrjuneja]

I am also experiencing this problem. I have to kill Spring processes that are consuming a lot of CPU even though bin/spring stop says there are no spring processes running.

[bborn]

+1 Spring status says Spring is not running (because I stopped it), but ps shows Spring processes still going.

[terracatta]

though it seems to come up if we change git branches and the like, so maybe some sort of file changes are causing it to just lock up

+1

Can confirm switching branches in our app (which has "a lot" of stuff in /lib) causing spring to hang even on rake commands. I have to run spring stop in another terminal tab to kill the process so I can proceed. Also considering a post-checkout hook to call spring stop

[jafrog]

After a lot of tinkering I was able to figure out why it happens, at least in my case.

First, Spring hangs when checking out a branch that has changes in one of the monitored files: Gemfile or config files. In this case Spring reloads an application on background. If your application prints any warnings on initialise the process will wait to access STDOUT which never happens as Spring's application process runs on background. In my case the solution was to disable warnings with $VERBOSE=nil on top of the config/application.rb because the app wasn't trying to print anything but warnings. But of course it won't do if you want to keep seeing warnings.

[jonleighton]

@jafrog can you point to the line of code where spring hangs?

[jafrog]

@jonleighton For me it was here, right when Rails app is loaded

[jafrog]

Looks like the bug was related to STDERR buffer overflow with warnings and was fixed in 1.3.0 (acceptance test) I was able to reproduce it with 1.2.0 but 1.3.6 works fine.

[mockdeep]

Hmm, I'm still seeing some hangs. I just changed branches and ran spring rake db:migrate and after a few minutes nothing had happened. Running version 1.3.6. Here are the logs just before the most recent lock up. The stack trace is when I ran spring stop from another terminal:

[2015-05-27 12:02:20 -0700] [20277] [server] accepted client
[2015-05-27 12:02:20 -0700] [20277] [server] running command rake
[2015-05-27 12:02:20 -0700] [20708] [client] sending command
[2015-05-27 12:02:20 -0700] [20281] [application:development] got client
[2015-05-27 12:02:20 -0700] [20281] [application:development] forked 20712
[2015-05-27 12:02:20 -0700] [20277] [application_manager:development] got worker pid 20712
[2015-05-27 12:02:20 -0700] [20708] [client] got pid: 20712
[2015-05-27 12:02:36 -0700] [20281] [application:development] 20712 exited with 0
[2015-05-27 12:02:36 -0700] [20708] [client] got exit status 0
[2015-05-27 12:29:23 -0700] [20281] [application:development] running -> watcher_stale
[2015-05-27 12:29:23 -0700] [20281] [application:development] watcher_stale -> exiting
[2015-05-27 12:29:23 -0700] [20277] [application_manager:development] child 20281 shutdown
[2015-05-27 12:29:23 -0700] [22234] [application:development] preloading app
[2015-05-27 12:29:29 -0700] [22234] [application:development] initialized -> running
/home/fletch/.rvm/gems/ruby-2.1.6/gems/spring-1.3.6/lib/spring/application.rb:286:in `read': stream closed (IOError)
    from /home/fletch/.rvm/gems/ruby-2.1.6/gems/spring-1.3.6/lib/spring/application.rb:286:in `block (2 levels) in with_pty'
[2015-05-27 12:29:38 -0700] [20277] [server] accepted client
[2015-05-27 12:29:38 -0700] [20277] [server] running command rake
[2015-05-27 12:29:38 -0700] [22310] [client] sending command
[2015-05-27 12:32:26 -0700] [20277] [server] shutting down
[2015-05-27 12:32:26 -0700] [20277] [application_manager:development] stopping
/home/fletch/.rvm/gems/ruby-2.1.6/gems/spring-1.3.6/lib/spring/application_manager.rb:22:in `unlock': Attempt to unlock a mutex which is locked by another thread (ThreadError)
    from /home/fletch/.rvm/gems/ruby-2.1.6/gems/spring-1.3.6/lib/spring/application_manager.rb:22:in `ensure in synchronize'
    from /home/fletch/.rvm/gems/ruby-2.1.6/gems/spring-1.3.6/lib/spring/application_manager.rb:22:in `synchronize'
    from /home/fletch/.rvm/gems/ruby-2.1.6/gems/spring-1.3.6/lib/spring/application_manager.rb:39:in `with_child'
    from /home/fletch/.rvm/gems/ruby-2.1.6/gems/spring-1.3.6/lib/spring/application_manager.rb:60:in `run'
    from /home/fletch/.rvm/gems/ruby-2.1.6/gems/spring-1.3.6/lib/spring/server.rb:59:in `serve'
    from /home/fletch/.rvm/gems/ruby-2.1.6/gems/spring-1.3.6/lib/spring/server.rb:44:in `block in start_server'
    from /home/fletch/.rvm/gems/ruby-2.1.6/gems/spring-1.3.6/lib/spring/server.rb:44:in `loop'
    from /home/fletch/.rvm/gems/ruby-2.1.6/gems/spring-1.3.6/lib/spring/server.rb:44:in `start_server'
    from /home/fletch/.rvm/gems/ruby-2.1.6/gems/spring-1.3.6/lib/spring/server.rb:38:in `boot'
    from /home/fletch/.rvm/gems/ruby-2.1.6/gems/spring-1.3.6/lib/spring/server.rb:14:in `boot'
    from -e:1:in `<main>'
[2015-05-27 12:32:26 -0700] [22310] [client] got no pid

[sgonyea]

Even on a brand new Rails project, I still see orphaned Spring 'app' processes hanging around, sipping around 6% CPU. I have to kill -9 them. This is without doing any sort of git branching.

In an older (Rails 3) project, I see the same thing but with git branch I get orphaned 'server' processes too.

(This is on OS X Yosemite)