Paperclip 4.11 / Climate_control 0.3 problem with Jenkins - postmortem

In case we need to deal with this again or somebody else bumps into it...

Situation:
Having just completed manual testing on a branch of our Proposals application that moves it from Rails 3.2 to 4.0.9, with other gems upgraded. Ruby is still on 1.9.3 in this project, with Ruby upgrade probably next on the list before dealing with remaining deprecations to lift Rails into the 4.1s or 4.2s. I merged the Rails4 branch into the dev branch and pushed, which means for us that as a deployment candidate, it starts getting run by the Jenkins continuous integration server. All the tests were succeeding there except for a set that had to do with file uploads using Paperclip. Paperclip and its dependencies from the Gemfile.lock:


    paperclip (4.1.1)
      activemodel (>= 3.0.0)
      activesupport (>= 3.0.0)
      cocaine (~> 0.5.3)
      mime-types

    cocaine (0.5.4)
      climate_control (>= 0.0.3, < 1.0)

   climate_control (0.0.3)

Representative error (43 more like it, testing various things about attachments):

 [1000D [?25l [31m1229/1464: 1.2k/1.4k, 83%, 2.4/s, elapsed: 00:05:54, ETA: 00:01:39
sh: file: No such file or directory
 [31mERROR [0m SupportingFileTest#test_supporting_file_passes_validation_with_unique_filename (0.07s) [K
  Errno::EINVAL:   Invalid argument - setenv
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/climate_control-0.0.3/lib/climate_control/modifier.rb:57:in `[]='
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/climate_control-0.0.3/lib/climate_control/modifier.rb:57:in `block in revert_changed_keys'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/climate_control-0.0.3/lib/climate_control/modifier.rb:56:in `each'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/climate_control-0.0.3/lib/climate_control/modifier.rb:56:in `revert_changed_keys'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/climate_control-0.0.3/lib/climate_control/modifier.rb:17:in `process'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/climate_control-0.0.3/lib/climate_control.rb:6:in `modify'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/cocaine-0.5.4/lib/cocaine/command_line/runners/process_runner.rb:44:in `with_modified_environment'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/cocaine-0.5.4/lib/cocaine/command_line/runners/process_runner.rb:21:in `call'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/cocaine-0.5.4/lib/cocaine/command_line.rb:122:in `execute'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/cocaine-0.5.4/lib/cocaine/command_line.rb:79:in `run'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/paperclip-4.1.1/lib/paperclip/helpers.rb:31:in `run'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/paperclip-4.1.1/lib/paperclip/file_command_content_type_detector.rb:18:in `type_from_file_command'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/paperclip-4.1.1/lib/paperclip/file_command_content_type_detector.rb:10:in `detect'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/paperclip-4.1.1/lib/paperclip/content_type_detector.rb:61:in `type_from_file_command'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/paperclip-4.1.1/lib/paperclip/content_type_detector.rb:57:in `block in calculated_type_matches'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/paperclip-4.1.1/lib/paperclip/content_type_detector.rb:57:in `select'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/paperclip-4.1.1/lib/paperclip/content_type_detector.rb:57:in `calculated_type_matches'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/paperclip-4.1.1/lib/paperclip/content_type_detector.rb:33:in `detect'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/paperclip-4.1.1/lib/paperclip/io_adapters/file_adapter.rb:14:in `cache_current_values'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/paperclip-4.1.1/lib/paperclip/io_adapters/file_adapter.rb:5:in `initialize'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/paperclip-4.1.1/lib/paperclip/io_adapters/registry.rb:29:in `new'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/paperclip-4.1.1/lib/paperclip/io_adapters/registry.rb:29:in `for'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/paperclip-4.1.1/lib/paperclip/attachment.rb:98:in `assign'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/vendor/ruby/1.9.1/gems/paperclip-4.1.1/lib/paperclip/has_attached_file.rb:66:in `block in define_setter'
  /scratch/rails/.hudson/jobs/wip_bb/workspace/test/unit/file_attachments/supporting_file_test.rb:14:in `setup'

Reading the trace and inspection of code around the error did not get me too far. Standard rake test from the workspace directory worked correctly, so it had something to do with Jenkins or its configuration.

Insertion of debug "puts" statements showed that the problem in climate_control revert_changed_keys where it was restoring potentially changed enviroment variables cropped up against an environment variable at the head of the array of keys, that had the key of "", which setenv behind ENV[]= could not handle. So where does the weird empty string key come from? This env var had PATH-like contents, but a lot at a level that appeared to be for Jenkins and not for our application. When we looked at the environment variables listing from the most recent Jenkins build of the app, it showed up at the head of the list, above the _ one. Looking at the environment variables lists for earlier runs it does not show up. So apparently it is there for Jenkins and only displays for the most recent run. Got Jenkins to run green again by hacking the vendored climate_control gem (bundle install --path vendor is a build step before running tests).

Here is the change to the gem that fixed it:
climate_control(v0.0.3)/lib/climate_control/modifier.rb line 56:

  (@original_env.keys - keys_changed_by_block).each do |key|

changed to

(@original_env.keys - [""] - keys_changed_by_block).each do |key|

Thanks to David Hays who paired with me on sorting this one out.