gem --list hangs - need a way to set a timeout

[amosshapira]

We've been bitten for a second time now by Puppet hanging on the gem list --remote ^sensu-plugin$ call from inside the Puppet module, here is what pstree shows:

  |-puppet,3760 /usr/bin/puppet agent
  |   |-puppet,15592
  |   |   |-gem,16191 /opt/sensu/embedded/bin/gem list --remote ^sensu-plugin$
  |   |   |   `-{gem},16194

As far as I can tell, the problem is in the sensu_gem package provider at https://github.com/sensu/sensu-puppet/blob/master/lib/puppet/provider/package/sensu_gem.rb#L19, this call needs some way to specify a timeout and fail.

In case this helps, here is lsof output on the gem process:

# lsof -np 16191
COMMAND   PID USER   FD   TYPE  DEVICE SIZE/OFF    NODE NAME
gem     16191 root  cwd    DIR   202,1     4096       2 /
gem     16191 root  rtd    DIR   202,1     4096       2 /
gem     16191 root  txt    REG   202,1     8695  275214 /opt/sensu/embedded/bin/ruby
gem     16191 root  mem    REG   202,1   101240  396102 /lib/x86_64-linux-gnu/libresolv-2.19.so
gem     16191 root  mem    REG   202,1    22952  396080 /lib/x86_64-linux-gnu/libnss_dns-2.19.so
gem     16191 root  mem    REG   202,1    47712  396081 /lib/x86_64-linux-gnu/libnss_files-2.19.so
gem     16191 root  mem    REG   202,1    85060  397734 /opt/sensu/embedded/lib/ruby/2.0.0/x86_64-linux/zlib.so
gem     16191 root  mem    REG   202,1    24407  397762 /opt/sensu/embedded/lib/ruby/2.0.0/x86_64-linux/digest.so
gem     16191 root  mem    REG   202,1   126609  275219 /opt/sensu/embedded/lib/libz.so.1.2.8
gem     16191 root  mem    REG   202,1  2220710  275217 /opt/sensu/embedded/lib/libcrypto.so.1.0.0
gem     16191 root  mem    REG   202,1   492997  275222 /opt/sensu/embedded/lib/libssl.so.1.0.0
gem     16191 root  mem    REG   202,1   476503  397728 /opt/sensu/embedded/lib/ruby/2.0.0/x86_64-linux/openssl.so
gem     16191 root  mem    REG   202,1     8001  397822 /opt/sensu/embedded/lib/ruby/2.0.0/x86_64-linux/fcntl.so
gem     16191 root  mem    REG   202,1   206760  397726 /opt/sensu/embedded/lib/ruby/2.0.0/x86_64-linux/socket.so
gem     16191 root  mem    REG   202,1   270594  397760 /opt/sensu/embedded/lib/ruby/2.0.0/x86_64-linux/date_core.so
gem     16191 root  mem    REG   202,1    33515  397752 /opt/sensu/embedded/lib/ruby/2.0.0/x86_64-linux/strscan.so
gem     16191 root  mem    REG   202,1    43883  397748 /opt/sensu/embedded/lib/ruby/2.0.0/x86_64-linux/stringio.so
gem     16191 root  mem    REG   202,1   326804  275221 /opt/sensu/embedded/lib/libyaml-0.so.2.0.2
gem     16191 root  mem    REG   202,1    40739  397754 /opt/sensu/embedded/lib/ruby/2.0.0/x86_64-linux/psych.so
gem     16191 root  mem    REG   202,1    19348  397735 /opt/sensu/embedded/lib/ruby/2.0.0/x86_64-linux/etc.so
gem     16191 root  mem    REG   202,1    16154  397782 /opt/sensu/embedded/lib/ruby/2.0.0/x86_64-linux/enc/trans/transdb.so
gem     16191 root  mem    REG   202,1    12295  397788 /opt/sensu/embedded/lib/ruby/2.0.0/x86_64-linux/enc/encdb.so
gem     16191 root  mem    REG   202,1  1840928  396047 /lib/x86_64-linux-gnu/libc-2.19.so
gem     16191 root  mem    REG   202,1  1071552  396070 /lib/x86_64-linux-gnu/libm-2.19.so
gem     16191 root  mem    REG   202,1    43368  396052 /lib/x86_64-linux-gnu/libcrypt-2.19.so
gem     16191 root  mem    REG   202,1    14664  396056 /lib/x86_64-linux-gnu/libdl-2.19.so
gem     16191 root  mem    REG   202,1    31792  396103 /lib/x86_64-linux-gnu/librt-2.19.so
gem     16191 root  mem    REG   202,1   141574  396100 /lib/x86_64-linux-gnu/libpthread-2.19.so
gem     16191 root  mem    REG   202,1  2977882  275232 /opt/sensu/embedded/lib/libruby.so.2.0.0
gem     16191 root  mem    REG   202,1   149120  396037 /lib/x86_64-linux-gnu/ld-2.19.so
gem     16191 root    0r   CHR     1,3      0t0    5430 /dev/null
gem     16191 root    1u   REG   202,1        0   28008 /tmp/puppet20151130-15592-1769jcu
gem     16191 root    2u   REG   202,1        0   28008 /tmp/puppet20151130-15592-1769jcu
gem     16191 root    3r  FIFO     0,8      0t0 5943270 pipe
gem     16191 root    4w  FIFO     0,8      0t0 5943270 pipe
gem     16191 root    5r  FIFO     0,8      0t0 5943271 pipe
gem     16191 root    6w  FIFO     0,8      0t0 5943271 pipe
gem     16191 root    7u  IPv4 5943276      0t0     TCP 172.18.1.76:44039->54.186.104.15:https (CLOSE_WAIT)
gem     16191 root    8u  IPv4 5943282      0t0     TCP 172.18.1.76:60348->199.27.76.249:https (ESTABLISHED)

[jlambert121]

Interesting. Are you using a proxy or anything like that or is this native gem to rubygems.org?

[amosshapira]

We aren't using a proxy. The machine sits behind a regular NAT instance inside an AWS VPC and the lsof output above shows that it established a direct connection to the gem server (I.e. there was successful 2-way traffic)

[jaxxstorm]

@amosshapira as far as I know, there's no way to set a timeout on the gem list command, and until then I don't know how this will be possible.

It's worth noting that even the puppet local gem provider doesn't support this:
https://github.com/puppetlabs/puppet/blob/master/lib/puppet/provider/package/gem.rb

I'm going to close this as I don't think it's possible, and seems like a rare enough edge case.

[amosshapira]

Thanks for looking at this.
When it happens (and it seems to happen once in a while) it hangs our puppet run on an entire segment (e.g. an AWS region).

Since we intend to move away from Puppet to immutable servers, hopefully this will be less of an issue.