Commit 94dbfa3 causes hanging on executing a process (OSX 10.7.4)

[jonhyman]

I just upgraded to cocaine 0.3.0 and tracked down code hanging from commit 94dbfa3. I'm running optipng to compress an image that I save using paperclip. Here's the output from paperclip after running convert. I added some puts() so you can see what's going on.

Executing convert /var/folders/5y/ln69d3vd6p39pdh7ksj6jkjr0000gn/T/jonathan20120831-8061-1mektr9.png

/var/folders/5y/ln69d3vd6p39pdh7ksj6jkjr0000gn/T/jonathan20120831-8061-1mektr920120831-8061-1coei2w.png in {"PATH"=>"/Users/jonathan/.rvm/gems/ruby-1.9.3-p125/bin:/Users/jonathan/Android/android-sdk-macosx/platform-tools:/Users/jonathan/Android/android-sdk-macosx/tools:/Users/jonathan/.rvm/gems/ruby-1.9.3-p125@global/bin:/Users/jonathan/.rvm/rubies/ruby-1.9.3-p125/bin:/Users/jonathan/.rvm/bin:/opt/local/bin:/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/bin:/usr/X11/bin:~/.rvm/bin:/usr/local/mongo/bin:/usr/local/git/bin:/usr/local/bin/"}

Finished

Executing optipng -zc1-9 -zm1-9 -zs0-2 -f0-5 /var/folders/5y/ln69d3vd6p39pdh7ksj6jkjr0000gn/T/jonathan20120831-8061-1mektr920120831-8061-1coei2w.png in {"PATH"=>"/Users/jonathan/.rvm/gems/ruby-1.9.3-p125/bin:/Users/jonathan/Android/android-sdk-macosx/platform-tools:/Users/jonathan/Android/android-sdk-macosx/tools:/Users/jonathan/.rvm/gems/ruby-1.9.3-p125@global/bin:/Users/jonathan/.rvm/rubies/ruby-1.9.3-p125/bin:/Users/jonathan/.rvm/bin:/opt/local/bin:/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/bin:/usr/X11/bin:~/.rvm/bin:/usr/local/mongo/bin:/usr/local/git/bin:/usr/local/bin/"}

The last command hangs. If I run the command myself in a console, it works fine. If I bump down to 2cfec9cce0, it works fine.

Cocaine 0.3.0 works great on my Mountain Lion 10.8.1 Macbook Pro, but our build agents are on Mac Minis that are still on Lion, OS X 10.7.4.

@jyurek, any thoughts on what could be causing this? If I do ps aux | grep optipng, I see the optipng process there but it's not doing anything.

[jyurek]

Well, that's odd. You said you can run it manually, but did you try running it with the modified PATH? Is it possible that one of those other directories have optipng installed in them, and it's somehow using the wrong binary? What happens if you run /Users/jonathan/.rvm/gems/ruby-1.9.3-p125/bin:/Users/jonathan/Android/android-sdk-macosx/platform-tools:/Users/jonathan/Android/android-sdk-macosx/tools:/Users/jonathan/.rvm/gems/ruby-1.9.3-p125@global/bin:/Users/jonathan/.rvm/rubies/ruby-1.9.3-p125/bin:/Users/jonathan/.rvm/bin:/opt/local/bin:/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/bin:/usr/X11/bin:~/.rvm/bin:/usr/local/mongo/bin:/usr/local/git/bin:/usr/local/bin/ which optipng -a (you may need to escape some characters in there)

[jonhyman]

Thanks for the suggestion. optipng is only installed in /opt/local/bin, however.

[jyurek]

Nuts. I see you're using 1.9.3. Are you using the posix_spawn gem?

[jonhyman]

Nope, and it's not in my Gemfile.lock. If need be and you're up to it, I'd be happy to screen share on Skype later next week so you can get on my build agent and step through the code.

[jyurek]

Hmm, perhaps you can give that gem a whirl. Maybe it'll help?

[jyurek]

@jonhyman, have you tried posix_spawn to see if that helps?

[jonhyman]

Not yet. Been gone for Labor Day. Will try it on Friday when back in town and update the issue.

Sent from my mobile device. On Sep 4, 2012 10:02 AM, "Jon Yurek" notifications@github.com wrote:

@jonhyman https://github.com/jonhyman, have you tried posix_spawn to see if that helps?

— Reply to this email directly or view it on GitHubhttps://github.com/thoughtbot/cocaine/issues/21#issuecomment-8270663.

[jonhyman]

No dice. I still have the same issue even with posix-spawn.

[jyurek]

Can you paste your Paperclip config? Maybe there's something in there that will shed some light on this.

[jonhyman]

has_mongoid_attached_file :image,
                            {
                                :styles => {:ios  => { :format => :png,
                                                       :processors => [:png_optimize]
                                }
                                },
                              :default_url => ""
                            }

module Paperclip
  class PngOptimize < Processor
    attr_accessor :format

    def initialize(file, options = {}, attachment = nil)
      super
      @format         = options[:format] || :png
      @current_format = File.extname(@file.path)
      @basename       = File.basename(@file.path, @current_format)
    end

    def make
      src = @file
      src_path = File.expand_path(src.path)
      dst = Tempfile.new([@basename, @format ? ".#{@format}" : ''])
      dst.binmode
      dst_path = File.expand_path(dst.path)

      begin
        # Convert to PNG and resize before applying optimizations
        convert_options = self.options[:convert]

        # Build the argument string to send to convert
        arg_src_dst = "#{src_path} #{dst_path}"

        # If we don't have extra args, the arguments to convert are just src -> dest. We need to call convert
        # so that the output file is .png.
        convert_args = convert_options ? "#{convert_options} #{arg_src_dst}" : arg_src_dst
        Paperclip.run("convert", convert_args)

        # From http://www.ffnn.nl/pages/articles/media/png-optimization.php
        Paperclip.run("optipng", "-zc1-9 -zm1-9 -zs0-2 -f0-5 #{dst_path}")
        Paperclip.run("advpng", "-z4 #{dst_path}")
      rescue Exception => e
        Rails.logger.error("Error optimizing image: #{e}. #{e.backtrace}")
      end
      dst
    end
  end
end

[jyurek]

Hmm, it appears you're using mongoid-paperclip, which I don't maintain. But, anyway, I would recommend you change your calls to Paperclip.run to use the Cocaine method of interpolation, as it respects any possible shell command line issues that might arise. So, for example Paperclip.run("optipng", "-zc1-9 -zm1-9 -zs0-2 -f0-5 :dest", :dest => dst_path).

I'm not sure it would make a difference, but it might, depending on your filenames. Looking at the paste in the OP, it shouldn't make a difference, but it's worth trying anyway. I honestly don't know what else might be the problem without knowing more about optipng.

Perhaps this would be a good reason to add timeouts, should we be unable to find a better solution.

[jonhyman]

Updated, but unfortunately still have the issue. I'll keep my version capped at 0.2.1 for the time being. Perhaps it's a Lion thing, as it works fine on my Mountain Lion machine.

[jyurek]

Hmm, well, that doesn't help much, as I don't know why it's happening on Mountain Lion. It must have something to do with Process.spawn, though.

Actually, maybe you can try this, too. Change your Gemfile to use cocaine like this:

gem 'cocaine', :git => "http://github.com/thoughtbot/cocaine.git", :branch => "23-maybe-fix"

And remove the posix-spawn gem if you still have it. It's an attempt at a fix for another problem, but it might be related.

[jonhyman]

It still hangs.

[jyurek]

Well, shit. I'm at a loss. If it works in 0.2.1 and not 0.3.0 then it's got to be a problem with using Process.spawn, but I don't know what it could be at this point. I'll have to dig some more.

[cmaion]

Hi,

Not sure if this is the same issue, but upgrading from 0.2.1 to 0.3.x also give me hanged processes (with or without posix-spawn). It seems to be related to the amount of stuff written to stdout by the forked process. This happens on Ubuntu 12.04.

A quick strace on the forked process seems to indicate that it's blocked writing to stdout. I guess that the IO pipe between Cocaine & the forked process is blocking the forked process at some point? FYI, I can reproduce the issue with a forked process that outputs 130KB of data to stdout.

[jyurek]

That actually helps a lot. I think I know what to do now. Thanks very much.

[jyurek]

OK! So, I was able to replicate the problem and put into place a failing test. And so then I could fix that and see it working. I've pushed this up to https://github.com/thoughtbot/cocaine/tree/v0.3 (because master has some breaking changes on it). Please give this branch a whirl and let me know if it solves the problem.

You can use it in your Gemfile like so: gem 'cocaine', :git => "git://github.com/thoughtbot/cocaine.git", :branch => "v0.3"

[jonhyman]

Nice work! I confirmed on my end that v0.3 fixes the problem (as does master since you merged the fix in) while 4befe5 hangs my process.

[cmaion]

This solves the issue for me too ;) Thanks!

[jyurek]

Excellent. I've pushed 0.3.2 that includes this fix. Thanks for reporting back. Closing this issue.