sensu-client resource leak

Greetings. I want to say I am very excited about this project. I have been following for a little while and I have decided to finally try it out. Unfortunately, I am having major resource leakage on the sensu-client 0.14.0-1 release on Ubuntu 12.04.5. Almost immediately after launch, the sensu-client uses 100% CPU and starts consuming memory very quickly. I can’t figure out why this is happening. I turned off SSL on the client for the time being, but the same thing was happening with it enabled. I am trying to start with a simple metric that grabs the CPU utilization of a ROS node using SNMP and logs it in a redis database with a timestamp.

My client.json:

{
“client”: {
“name”: "client.example.tld,
“address”: “10.35.10.88”,
“subscriptions”: [ “ui” ]
}
}

``

My rabbitmq.json:

{
“rabbitmq”: {
“host”: “server.example.tld”,
“port”: 5672,
“vhost”: “/sensu”,
“user”: “sensu”,
“password”: “REDACTED”
}
}

``

My simple plugin (client_redis.py)

#!/usr/bin/python
import sys
import json
from redis.client import Redis

r = Redis(host=‘localhost’, port=6379, db=0)
def print_data(pattern):
for key in r.keys(pattern):
json_data = json.loads(r.get(key))
val = json_data[‘value’]
timestamp = int(json_data[‘timestamp’])
print("%s %s %s" % (key,val,timestamp))

print_data(sys.argv[1])

``

Example use of the plugin:

sensu@client:/etc/sensu/plugins$ ./client_redis.py “*./NODE.cpu_usage”
client./NODE.cpu_usage 1.867 1414511902

``

My check (cpu_usage_metrics.json)

{
“checks”: {
“cpu_usage_metrics”: {
“type”: “metric”,
“command”: “client_redis.py “*./NODE.cpu_usage””,
“subscribers”: [
“ui”
],
“interval”: 15
}
}
}

``

sensu-client.log:

{“timestamp”:“2014-10-28T16:46:09.457313-0400”,“level”:“warn”,“message”:“config file does not exist or is not readable”,“file”:"/etc/sensu/config.json"}
{“timestamp”:“2014-10-28T16:46:09.457404-0400”,“level”:“warn”,“message”:“ignoring config file”,“file”:"/etc/sensu/config.json"}
{“timestamp”:“2014-10-28T16:46:09.457452-0400”,“level”:“warn”,“message”:“loading config files from directory”,“directory”:"/etc/sensu/conf.d"}
{“timestamp”:“2014-10-28T16:46:09.457503-0400”,“level”:“warn”,“message”:“loading config file”,“file”:"/etc/sensu/conf.d/rabbitmq.json"}
{“timestamp”:“2014-10-28T16:46:09.457544-0400”,“level”:“warn”,“message”:“loading config file”,“file”:"/etc/sensu/conf.d/client.json"}
{“timestamp”:“2014-10-28T16:46:09.457603-0400”,“level”:“warn”,“message”:“config file applied changes”,“file”:"/etc/sensu/conf.d/client.json",“changes”:{“client”:[null,{“name”:“client.example.tld”,“address”:“10.35.10.88”,“subscriptions”:[“ui”]}]}}
{“timestamp”:“2014-10-28T16:46:09.459447-0400”,“level”:“warn”,“message”:“loading extension files from directory”,“directory”:"/etc/sensu/extensions"}
{“timestamp”:“2014-10-28T16:46:09.472502-0400”,“level”:“debug”,“message”:“connecting to transport”,“name”:“rabbitmq”,“settings”:{“host”:“vm-server.example.tld”,“port”:5672,“vhost”:"/sensu",“user”:“sensu”,“password”:“REDACTED”}}
{“timestamp”:“2014-10-28T16:46:09.529060-0400”,“level”:“debug”,“message”:“scheduling keepalives”}
{“timestamp”:“2014-10-28T16:46:09.529271-0400”,“level”:“debug”,“message”:“publishing keepalive”,“payload”:{“name”:“client.example.tld”,“address”:“10.35.10.88”,“subscriptions”:[“ui”],“version”:“0.14.0”,“timestamp”:1414529169}}
{“timestamp”:“2014-10-28T16:46:09.529609-0400”,“level”:“debug”,“message”:“subscribing to client subscriptions”}
{“timestamp”:“2014-10-28T16:46:09.529695-0400”,“level”:“debug”,“message”:“subscribing to a subscription”,“subscription”:“ui”}
{“timestamp”:“2014-10-28T16:46:09.529914-0400”,“level”:“debug”,“message”:“scheduling standalone checks”}
{“timestamp”:“2014-10-28T16:46:09.530026-0400”,“level”:“debug”,“message”:“binding client tcp and udp sockets”,“options”:{“bind”:“127.0.0.1”,“port”:3030}}
from /opt/sensu/bin/sensu-client:23:in <main>' from /opt/sensu/bin/sensu-client:23:inload’
from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/sensu-0.14.0/bin/sensu-client:10:in <top (required)>' from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/sensu-0.14.0/lib/sensu/client.rb:12:inrun’
from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/sensu-em-2.4.0/lib/eventmachine.rb:187:in run' from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/sensu-em-2.4.0/lib/eventmachine.rb:187:inrun_machine’
from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amqp-1.3.0/lib/amqp/session.rb:659:in receive_data' from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amqp-1.3.0/lib/amqp/session.rb:921:inreceive_frame’
from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amqp-1.3.0/lib/amqp/session.rb:947:in receive_frameset' from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amqp-1.3.0/lib/amqp/session.rb:947:incall’
from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amqp-1.3.0/lib/amqp/channel.rb:1476:in block in <class:Channel>' from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amqp-1.3.0/lib/amqp/channel.rb:1450:inhandle_open_ok’
from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amqp-1.3.0/lib/amqp/callbacks.rb:59:in exec_callback_once_yielding_self' from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amqp-1.3.0/lib/amqp/callbacks.rb:59:ineach’
from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amqp-1.3.0/lib/amqp/callbacks.rb:59:in block in exec_callback_once_yielding_self' from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amqp-1.3.0/lib/amqp/callbacks.rb:59:incall’
from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amqp-1.3.0/lib/amqp/channel.rb:289:in block (2 levels) in initialize' from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/sensu-em-2.4.0/lib/em/deferrable.rb:191:insucceed’
from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/sensu-em-2.4.0/lib/em/deferrable.rb:151:in set_deferred_status' from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/sensu-em-2.4.0/lib/em/deferrable.rb:151:incall’
from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amqp-1.3.0/lib/amqp/channel.rb:936:in block in once_open' from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amqp-1.3.0/lib/amqp/channel.rb:936:incall’
from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amqp-1.3.0/lib/amqp/exchange.rb:539:in block in publish' from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amqp-1.3.0/lib/amqp/exchange.rb:772:inbasic_publish’
from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb:1741:in encode' from /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb:182:inencode_body’
4529169}
8075491

``

The second to last line was the value of “body” during runtime and seems to be the timestamp on the keepalive message. The last is the number of elements in “array”

gdb – following this: https://blog.nelhage.com/2013/03/tracking-an-eventmachine-leak/

0x00007ff18450e10e in rb_class_of () from /opt/sensu/embedded/lib/libruby.so.2.0
(gdb) next
Single stepping until exit from function rb_class_of,
which has no line number information.
0x00007ff18450e483 in rb_obj_class () from /opt/sensu/embedded/lib/libruby.so.2.0
(gdb) next
Single stepping until exit from function rb_obj_class,
which has no line number information.
0x00007ff184510367 in rb_obj_alloc () from /opt/sensu/embedded/lib/libruby.so.2.0
(gdb) next
Single stepping until exit from function rb_obj_alloc,
which has no line number information.
0x00007ff1845103ea in rb_class_new_instance () from /opt/sensu/embedded/lib/libruby.so.2.0
(gdb) next
Single stepping until exit from function rb_class_new_instance,
which has no line number information.
0x00007ff1845f3ba3 in call_cfunc_m1 () from /opt/sensu/embedded/lib/libruby.so.2.0
(gdb) next
Single stepping until exit from function call_cfunc_m1,
which has no line number information.
0x00007ff1845f47a9 in vm_call_cfunc_with_frame () from /opt/sensu/embedded/lib/libruby.so.2.0
(gdb) next
Single stepping until exit from function vm_call_cfunc_with_frame,
which has no line number information.
0x00007ff1845f48e3 in vm_call_cfunc () from /opt/sensu/embedded/lib/libruby.so.2.0
(gdb) next
Single stepping until exit from function vm_call_cfunc,
which has no line number information.
0x00007ff1845f95ef in vm_exec_core () from /opt/sensu/embedded/lib/libruby.so.2.0
(gdb) p rb_eval_string(“GC.start”)
$1 = 8
(gdb) p rb_eval_string("$gdb_objs = Hash.new 0")
$2 = 56869760
(gdb) p rb_eval_string(“ObjectSpace.each_object {|o| $gdb_objs[o.class] += 1}”)
$3 = 16202367
(gdb) p rb_backtrace()
$4 = 26
(gdb) p rb_eval_string("$stderr.puts(body)")
$5 = 8

(gdb) p rb_eval_string("$stderr.puts(array.length)")
$10 =8

``

rabbitmq log

=INFO REPORT==== 28-Oct-2014::16:46:09 ===

accepting AMQP connection <0.13215.0> (10.35.10.88:38877 -> 192.168.9.210:5672)

``

sensu-server log

{“timestamp”:“2014-10-28T16:39:24.914565-0400”,“level”:“warn”,“message”:“config file does not exist or is not readable”,“file”:"/etc/sensu/config.json"}

{“timestamp”:“2014-10-28T16:39:24.918690-0400”,“level”:“warn”,“message”:“ignoring config file”,“file”:"/etc/sensu/config.json"}

{“timestamp”:“2014-10-28T16:39:24.918900-0400”,“level”:“warn”,“message”:“loading config files from directory”,“directory”:"/etc/sensu/conf.d"}

{“timestamp”:“2014-10-28T16:39:24.919069-0400”,“level”:“warn”,“message”:“loading config file”,“file”:"/etc/sensu/conf.d/rabbitmq.json"}

{“timestamp”:“2014-10-28T16:39:24.919225-0400”,“level”:“warn”,“message”:“loading config file”,“file”:"/etc/sensu/conf.d/api.json"}

{“timestamp”:“2014-10-28T16:39:24.919491-0400”,“level”:“warn”,“message”:“config file applied changes”,“file”:"/etc/sensu/conf.d/api.json",“changes”:{“api”:[null,{“host”:“localhost”,“port”:4567,“user”:"ad

min",“password”:“REDACTED”}]}}

{“timestamp”:“2014-10-28T16:39:24.919673-0400”,“level”:“warn”,“message”:“loading config file”,“file”:"/etc/sensu/conf.d/client.json"}

{“timestamp”:“2014-10-28T16:39:24.919957-0400”,“level”:“warn”,“message”:“config file applied changes”,“file”:"/etc/sensu/conf.d/client.json",“changes”:{“client”:[null,{“name”:“client.example.tld”,"addre

ss":“10.35.10.88”,“subscriptions”:[“ui”]}]}}

{“timestamp”:“2014-10-28T16:39:24.920129-0400”,“level”:“warn”,“message”:“loading config file”,“file”:"/etc/sensu/conf.d/redis.json"}

{“timestamp”:“2014-10-28T16:39:24.920370-0400”,“level”:“warn”,“message”:“config file applied changes”,“file”:"/etc/sensu/conf.d/redis.json",“changes”:{“redis”:[null,{“host”:“localhost”,“port”:6379}]}}

{“timestamp”:“2014-10-28T16:39:24.920545-0400”,“level”:“warn”,“message”:“loading config file”,“file”:"/etc/sensu/conf.d/cpu_usage_metrics.json"}

{“timestamp”:“2014-10-28T16:39:24.920797-0400”,“level”:“warn”,“message”:“config file applied changes”,“file”:"/etc/sensu/conf.d/cpu_usage_metrics.json",“changes”:{“checks”:{“cpu_usage_metrics”:[null,{“type”:“metric”,“command”:“client_redis.py “*./NODE.cpu_usage””,“subscribers”:[“ui”],“interval”:15}]}}}

{“timestamp”:“2014-10-28T16:39:24.941037-0400”,“level”:“warn”,“message”:“loading extension files from directory”,“directory”:"/etc/sensu/extensions"}

{“timestamp”:“2014-10-28T16:39:24.941576-0400”,“level”:“warn”,“message”:“loaded extension”,“type”:“mutator”,“name”:“ruby_hash”,“description”:“returns ruby hash event data”}

{“timestamp”:“2014-10-28T16:39:24.941778-0400”,“level”:“warn”,“message”:“loaded extension”,“type”:“mutator”,“name”:“json”,“description”:“returns JSON formatted event data”}

{“timestamp”:“2014-10-28T16:39:24.941950-0400”,“level”:“warn”,“message”:“loaded extension”,“type”:“mutator”,“name”:“only_check_output”,“description”:“returns check output”}

{“timestamp”:“2014-10-28T16:39:24.942111-0400”,“level”:“warn”,“message”:“loaded extension”,“type”:“handler”,“name”:“debug”,“description”:“returns raw event data”}

{“timestamp”:“2014-10-28T16:39:24.973848-0400”,“level”:“debug”,“message”:“connecting to redis”,“settings”:{“host”:“localhost”,“port”:6379}}

{“timestamp”:“2014-10-28T16:39:24.977841-0400”,“level”:“debug”,“message”:“connecting to transport”,“name”:“rabbitmq”,“settings”:{“ssl”:{“cert_chain_file”:"/etc/sensu/ssl/chain.pem",“private_key_file”:"/etc/sensu/ssl/key.pem"},“host”:“server.example.tld”,“port”:5671,“vhost”:"/sensu",“user”:“sensu”,“password”:“REDACTED”}}

{“timestamp”:“2014-10-28T16:39:25.217859-0400”,“level”:“debug”,“message”:“subscribing to keepalives”}

{“timestamp”:“2014-10-28T16:39:25.218411-0400”,“level”:“debug”,“message”:“subscribing to results”}

{“timestamp”:“2014-10-28T16:39:25.229265-0400”,“level”:“info”,“message”:“i am now the master”}

{“timestamp”:“2014-10-28T16:39:25.229518-0400”,“level”:“debug”,“message”:“scheduling check requests”}

{“timestamp”:“2014-10-28T16:39:25.229781-0400”,“level”:“debug”,“message”:“monitoring clients”}

{“timestamp”:“2014-10-28T16:39:25.229955-0400”,“level”:“debug”,“message”:“pruning aggregations”}

{“timestamp”:“2014-10-28T16:39:35.220621-0400”,“level”:“debug”,“message”:“updated master lock timestamp”}

{“timestamp”:“2014-10-28T16:39:42.231363-0400”,“level”:“info”,“message”:“publishing check request”,“payload”:{“name”:“cpu_usage_metrics”,“issued”:1414528782,“command”:“client_redis.py “*./NODE.cpu_usage””},“subscribers”:[“ui”]}

``

pmap:

root@client:/etc/sensu/conf.d# pmap -x pidof /opt/sensu/embedded/bin/ruby
13490: /opt/sensu/embedded/bin/ruby /opt/sensu/bin/sensu-client -b -c /etc/sensu/config.json -d /etc/sensu/conf.d -e /etc/sensu/extensions -p /var/run/sensu/sensu-client.pid -l /var/log/sensu/sensu-client.log -L DEBUG
Address Kbytes RSS Dirty Mode Mapping
0000000000400000 0 4 4 r-x-- ruby
0000000000600000 0 4 4 r---- ruby
0000000000601000 0 4 4 rw— ruby
00000000023c1000 0 12960 12960 rw— [ anon ]
000000000306a000 0 517308 517308 rw— [ anon ]
00007ff179d48000 0 63092 63092 rw— [ anon ]
00007ff180221000 0 56 0 r-x-- libresolv-2.15.so
00007ff180239000 0 0 0 ----- libresolv-2.15.so

``

Has anyone seen an issue like this before?

I figured it out… and I decided to be a good OP and post how:

I installed pry-byebug with:
PATH=/opt/sensu/embedded/bin/:$PATH RUBYLIB=/opt/sensu/embedded/lib/ruby/ gem install pry-byebug

``

I found where the memory is all going:

···

From: /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb @ line 168 AMQ::Protocol::Method.encode_body:

166: def self.encode_body(body, channel, frame_size)

167:   binding.pry

=> 168: return if body.empty?

169:

170:   # 8 = 1 + 2 + 4 + 1

171:   # 1 byte of frame type

172:   # 2 bytes of channel number

173:   # 4 bytes of frame payload length

174:   # 1 byte of payload trailer FRAME_END byte

175:   limit        = frame_size - 8

176:   return [BodyFrame.new(body, channel)] if body.bytesize < limit

177:

178:   # Otherwise String#slice on 1.9 will operate with code points,

179:   # and we need bytes. MK.

180:   body.force_encoding("ASCII-8BIT") if RUBY_VERSION.to_f >= 1.9

181:

182:   array = Array.new

183:   while body && !body.empty?

184:     payload, body = body[0, limit], body[limit, body.length - limit]

185:     array << BodyFrame.new(payload, channel)

186:   end

187:

188:   array

189: end

[1] pry(basic.publish)> break 185 if array.length > 2**22

History not saved; unable to open your history file for writing.

Breakpoint 1: /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb @ 185 (Enabled) :

Condition: array.length > 2**22

182:         array = Array.new

183:         while body && !body.empty?

184:           payload, body = body[0, limit], body[limit, body.length - limit]

=> 185: array << BodyFrame.new(payload, channel)

186:         end

187:

188:         array

[2] pry(basic.publish)> continue

Breakpoint 1. First hit

Condition: array.length > 2**22

From: /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb @ line 185 AMQ::Protocol::Method.encode_body:

166: def self.encode_body(body, channel, frame_size)

167:   binding.pry

168:   return [] if body.empty?

169:

170:   # 8 = 1 + 2 + 4 + 1

171:   # 1 byte of frame type

172:   # 2 bytes of channel number

173:   # 4 bytes of frame payload length

174:   # 1 byte of payload trailer FRAME_END byte

175:   limit        = frame_size - 8

176:   return [BodyFrame.new(body, channel)] if body.bytesize < limit

177:

178:   # Otherwise String#slice on 1.9 will operate with code points,

179:   # and we need bytes. MK.

180:   body.force_encoding("ASCII-8BIT") if RUBY_VERSION.to_f >= 1.9

181:

182:   array = Array.new

183:   while body && !body.empty?

184:     payload, body = body[0, limit], body[limit, body.length - limit]

=> 185: array << BodyFrame.new(payload, channel)

186:   end

187:

188:   array

189: end

[1] pry(basic.publish):1>

``

pmap diff:

— /tmp/pmap1 2014-10-29 11:23:31.652890861 -0400

+++ /tmp/pmap2 2014-10-29 11:29:52.218328701 -0400

@@ -3,7 +3,8 @@

0000000000400000 0 4 0 r-x-- ruby

0000000000600000 0 4 4 r---- ruby

0000000000601000 0 4 4 rw— ruby

-00000000013fc000 0 28696 28696 rw— [ anon ]

+00000000013fc000 0 419388 419388 rw— [ anon ]

+00007f74e26d5000 0 32772 32772 rw— [ anon ]

00007f74e537f000 0 12 0 r-x-- console.so

00007f74e5382000 0 0 0 ----- console.so

00007f74e5581000 0 4 4 r---- console.so

@@ -137,7 +138,7 @@

00007f74e974d000 0 0 0 ----- [ anon ]

00007f74e974e000 0 24 24 rw— [ anon ]

00007f74e9852000 0 44 0 r---- locale-archive

-00007f74e9b5c000 0 676 0 r-x-- libc-2.15.so

+00007f74e9b5c000 0 680 0 r-x-- libc-2.15.so

00007f74e9d11000 0 0 0 ----- libc-2.15.so

00007f74e9f10000 0 16 16 r---- libc-2.15.so

00007f74e9f14000 0 8 8 rw— libc-2.15.so

@@ -170,6 +171,7 @@

00007f74eaf00000 0 16 16 rw— libruby.so.2.0.0

00007f74eaf04000 0 128 128 rw— [ anon ]

00007f74eaf26000 0 112 0 r-x-- ld-2.15.so

+00007f74eb0dc000 0 132 132 rw— [ anon ]

00007f74eb121000 0 20 20 rw— [ anon ]

00007f74eb145000 0 12 12 rw— [ anon ]

00007f74eb148000 0 4 4 r---- ld-2.15.so

@@ -178,4 +180,4 @@

00007fff1df6a000 0 4 0 r-x-- [ anon ]

ffffffffff600000 0 0 0 r-x-- [ anon ]


-total kB 123012 35488 29752

+total kB 552288 459088 453348

``

I think I am stuck in an infinite loop at the bottom level of that traceback because the first call to encode_body has a frame_size of 0.

From: /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb @ line 168 AMQ::Protocol::Method.encode_body:

166: def self.encode_body(body, channel, frame_size)

167:   binding.pry

=> 168: return if body.empty?

169:

170:   # 8 = 1 + 2 + 4 + 1

171:   # 1 byte of frame type

172:   # 2 bytes of channel number

173:   # 4 bytes of frame payload length

174:   # 1 byte of payload trailer FRAME_END byte

175:   limit        = frame_size - 8

176:   return [BodyFrame.new(body, channel)] if body.bytesize < limit

177:

178:   # Otherwise String#slice on 1.9 will operate with code points,

179:   # and we need bytes. MK.

180:   body.force_encoding("ASCII-8BIT") if RUBY_VERSION.to_f >= 1.9

181:

182:   array = Array.new

183:   while body && !body.empty?

184:     payload, body = body[0, limit], body[limit, body.length - limit]

185:     array << BodyFrame.new(payload, channel)

186:   end

187:

188:   array

189: end

[1] pry(basic.publish)> frame_size

History not saved; unable to open your history file for writing.

=> 0

[2] pry(basic.publish)> body

=> “{“name”:“client0.example.tld”,“address”:“10.35.10.88”,“subscriptions”:[“ui”],“version”:“0.14.0”,“timestamp”:1414593463}”

[3] pry(basic.publish)> channel

=> 1

``

With the frame size being 0, the ‘limit’ ends up being -8 bytes so we will never end up returning the single-element array.

From: /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb @ line 176 AMQ::Protocol::Method.encode_body:

166: def self.encode_body(body, channel, frame_size)

167:   binding.pry   

168:   return [] if body.empty?

169:

170:   # 8 = 1 + 2 + 4 + 1

171:   # 1 byte of frame type

172:   # 2 bytes of channel number

173:   # 4 bytes of frame payload length

174:   # 1 byte of payload trailer FRAME_END byte

175:   limit        = frame_size - 8

=> 176: return [BodyFrame.new(body, channel)] if body.bytesize < limit

177:

178:   # Otherwise String#slice on 1.9 will operate with code points,

179:   # and we need bytes. MK.

180:   body.force_encoding("ASCII-8BIT") if RUBY_VERSION.to_f >= 1.9

181:

182:   array = Array.new

183:   while body && !body.empty?

184:     payload, body = body[0, limit], body[limit, body.length - limit]

185:     array << BodyFrame.new(payload, channel)

186:   end

187:

188:   array

189: end

[5] pry(basic.publish)> limit

=> -8

[6] pry(basic.publish)> body.bytesize

=> 119

``

Then we get stuck:

[8] pry(basic.publish)> body

=> "{“name”:“client0.example.tld”,“address”:“10.35.10.88”,“subscriptions”:[“ui”],“version”:“0.14.0”,"timestamp

“:1414593463}”

[9] pry(basic.publish)> next

From: /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb @ line 184 AMQ::Protocol::Meth

od.encode_body:

166: def self.encode_body(body, channel, frame_size)

167:   binding.pry   

168:   return [] if body.empty?

169:

170:   # 8 = 1 + 2 + 4 + 1

171:   # 1 byte of frame type

172:   # 2 bytes of channel number

173:   # 4 bytes of frame payload length

174:   # 1 byte of payload trailer FRAME_END byte

175:   limit        = frame_size - 8

176:   return [BodyFrame.new(body, channel)] if body.bytesize < limit

177:

178:   # Otherwise String#slice on 1.9 will operate with code points,

179:   # and we need bytes. MK.

180:   body.force_encoding("ASCII-8BIT") if RUBY_VERSION.to_f >= 1.9

181:

182:   array = Array.new

183:   while body && !body.empty?

=> 184: payload, body = body[0, limit], body[limit, body.length - limit]

185:     array << BodyFrame.new(payload, channel)

186:   end

187:

188:   array

189: end

[9] pry(basic.publish)> next

From: /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb @ line 185 AMQ::Protocol::Meth

od.encode_body:

166: def self.encode_body(body, channel, frame_size)

167:   binding.pry   

168:   return [] if body.empty?

169:

170:   # 8 = 1 + 2 + 4 + 1

171:   # 1 byte of frame type

172:   # 2 bytes of channel number

173:   # 4 bytes of frame payload length

174:   # 1 byte of payload trailer FRAME_END byte

175:   limit        = frame_size - 8

176:   return [BodyFrame.new(body, channel)] if body.bytesize < limit

177:

178:   # Otherwise String#slice on 1.9 will operate with code points,

179:   # and we need bytes. MK.

180:   body.force_encoding("ASCII-8BIT") if RUBY_VERSION.to_f >= 1.9

181:

182:   array = Array.new

183:   while body && !body.empty?

184:     payload, body = body[0, limit], body[limit, body.length - limit]

=> 185: array << BodyFrame.new(payload, channel)

186:   end

187:

188:   array

189: end

[9] pry(basic.publish)> payload

=> nil

[10] pry(basic.publish)> body

=> “4593463}”

From: /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb @ line 184 AMQ::Protocol::Method.encode_body:

166: def self.encode_body(body, channel, frame_size)

167: binding.pry

168: return if body.empty?

169:

170: # 8 = 1 + 2 + 4 + 1

171: # 1 byte of frame type

172: # 2 bytes of channel number

173: # 4 bytes of frame payload length

174: # 1 byte of payload trailer FRAME_END byte

175: limit = frame_size - 8

176: return [BodyFrame.new(body, channel)] if body.bytesize < limit

177:

178: # Otherwise String#slice on 1.9 will operate with code points,

179: # and we need bytes. MK.

180: body.force_encoding(“ASCII-8BIT”) if RUBY_VERSION.to_f >= 1.9

181:

182: array = Array.new

183: while body && !body.empty?

=> 184: payload, body = body[0, limit], body[limit, body.length - limit]

185: array << BodyFrame.new(payload, channel)

186: end

187:

188: array

189: end

[11] pry(basic.publish)> array.length

=> 1

[12] pry(basic.publish)> next

From: /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb @ line 185 AMQ::Protocol::Method.encode_body:

166: def self.encode_body(body, channel, frame_size)

167: binding.pry

168: return if body.empty?

169:

170: # 8 = 1 + 2 + 4 + 1

171: # 1 byte of frame type

172: # 2 bytes of channel number

173: # 4 bytes of frame payload length

174: # 1 byte of payload trailer FRAME_END byte

175: limit = frame_size - 8

176: return [BodyFrame.new(body, channel)] if body.bytesize < limit

177:

178: # Otherwise String#slice on 1.9 will operate with code points,

179: # and we need bytes. MK.

180: body.force_encoding(“ASCII-8BIT”) if RUBY_VERSION.to_f >= 1.9

181:

182: array = Array.new

183: while body && !body.empty?

184: payload, body = body[0, limit], body[limit, body.length - limit]

=> 185: array << BodyFrame.new(payload, channel)

186: end

187:

188: array

189: end

[12] pry(basic.publish)> payload

=> nil

[13] pry(basic.publish)> body

=> “4593463}”

[14] pry(basic.publish)> next

From: /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb @ line 184 AMQ::Protocol::Method.encode_body:

166: def self.encode_body(body, channel, frame_size)

167: binding.pry

168: return if body.empty?

169:

170: # 8 = 1 + 2 + 4 + 1

171: # 1 byte of frame type

172: # 2 bytes of channel number

173: # 4 bytes of frame payload length

174: # 1 byte of payload trailer FRAME_END byte

175: limit = frame_size - 8

176: return [BodyFrame.new(body, channel)] if body.bytesize < limit

177:

178: # Otherwise String#slice on 1.9 will operate with code points,

179: # and we need bytes. MK.

180: body.force_encoding(“ASCII-8BIT”) if RUBY_VERSION.to_f >= 1.9

181:

182: array = Array.new

183: while body && !body.empty?

=> 184: payload, body = body[0, limit], body[limit, body.length - limit]

185: array << BodyFrame.new(payload, channel)

186: end

187:

188: array

189: end

[14] pry(basic.publish)> next

From: /opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb @ line 185 AMQ::Protocol::Method.encode_body:

166: def self.encode_body(body, channel, frame_size)

167: binding.pry

168: return if body.empty?

169:

170: # 8 = 1 + 2 + 4 + 1

171: # 1 byte of frame type

172: # 2 bytes of channel number

173: # 4 bytes of frame payload length

174: # 1 byte of payload trailer FRAME_END byte

175: limit = frame_size - 8

176: return [BodyFrame.new(body, channel)] if body.bytesize < limit

177:

178: # Otherwise String#slice on 1.9 will operate with code points,

179: # and we need bytes. MK.

180: body.force_encoding(“ASCII-8BIT”) if RUBY_VERSION.to_f >= 1.9

181:

182: array = Array.new

183: while body && !body.empty?

184: payload, body = body[0, limit], body[limit, body.length - limit]

=> 185: array << BodyFrame.new(payload, channel)

186: end

187:

188: array

189: end

[14] pry(basic.publish)> body

=> “4593463}”

[15] pry(basic.publish)> payload

=> nil

[11] pry(basic.publish)> next

``

So I was digging around and found this reference: https://www.rabbitmq.com/amqp-0-9-1-reference.html

long frame-max

The largest frame size that the server proposes for the connection, including frame header and end-byte. The client can negotiate a lower value. Zero means that the server does not impose any specific limit but may reject very large frames if it cannot allocate resources for them.

  • Until the frame-max has been negotiated, both peers MUST accept frames of up to frame-min-size octets large, and the minimum negotiated value for frame-max is also frame-min-size.

``

I adjusted the frame_max on my rabbitmq server configuration which was indeed set to ‘0’ – and now the keepalives are publishing properly. It seems this could be an issue with https://github.com/ruby-amqp/amq-protocol 1.9.2 not being able to handle a frame size of zero.

Regards,

Vince

Vince,
This is pretty impressive.
Do you think anything needs to change that is sensu-specific here?
It looks like the default setting for frame_max on the server is
131072, and the docs warn against triggering bugs if set to 0:
Configuration — RabbitMQ so I guess if everyone else is
using default there isn't much to worry about?
Kyle

···

On Wed, Oct 29, 2014 at 8:50 AM, Vincent Newell <vince.newell@gmail.com> wrote:

I figured it out.... and I decided to be a good OP and post how:

I installed pry-byebug with:
PATH=/opt/sensu/embedded/bin/:$PATH RUBYLIB=/opt/sensu/embedded/lib/ruby/
gem install pry-byebug

I found where the memory is all going:
From:
/opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb
@ line 168 AMQ::Protocol::Method.encode_body:

    166: def self.encode_body(body, channel, frame_size)
    167: binding.pry
=> 168: return if body.empty?
    169:
    170: # 8 = 1 + 2 + 4 + 1
    171: # 1 byte of frame type
    172: # 2 bytes of channel number
    173: # 4 bytes of frame payload length
    174: # 1 byte of payload trailer FRAME_END byte
    175: limit = frame_size - 8
    176: return [BodyFrame.new(body, channel)] if body.bytesize < limit
    177:
    178: # Otherwise String#slice on 1.9 will operate with code points,
    179: # and we need bytes. MK.
    180: body.force_encoding("ASCII-8BIT") if RUBY_VERSION.to_f >= 1.9
    181:
    182: array = Array.new
    183: while body && !body.empty?
    184: payload, body = body[0, limit], body[limit, body.length -
limit]
    185: array << BodyFrame.new(payload, channel)
    186: end
    187:
    188: array
    189: end

[1] pry(basic.publish)> break 185 if array.length > 2**22
History not saved; unable to open your history file for writing.
Breakpoint 1:
/opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb
@ 185 (Enabled) :
Condition: array.length > 2**22

    182: array = Array.new
    183: while body && !body.empty?
    184: payload, body = body[0, limit], body[limit, body.length -
limit]
=> 185: array << BodyFrame.new(payload, channel)
    186: end
    187:
    188: array

[2] pry(basic.publish)> continue

Breakpoint 1. First hit
Condition: array.length > 2**22

From:
/opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb
@ line 185 AMQ::Protocol::Method.encode_body:

    166: def self.encode_body(body, channel, frame_size)
    167: binding.pry
    168: return if body.empty?
    169:
    170: # 8 = 1 + 2 + 4 + 1
    171: # 1 byte of frame type
    172: # 2 bytes of channel number
    173: # 4 bytes of frame payload length
    174: # 1 byte of payload trailer FRAME_END byte
    175: limit = frame_size - 8
    176: return [BodyFrame.new(body, channel)] if body.bytesize < limit
    177:
    178: # Otherwise String#slice on 1.9 will operate with code points,
    179: # and we need bytes. MK.
    180: body.force_encoding("ASCII-8BIT") if RUBY_VERSION.to_f >= 1.9
    181:
    182: array = Array.new
    183: while body && !body.empty?
    184: payload, body = body[0, limit], body[limit, body.length -
limit]
=> 185: array << BodyFrame.new(payload, channel)
    186: end
    187:
    188: array
    189: end

[1] pry(basic.publish):1>

pmap diff:
--- /tmp/pmap1 2014-10-29 11:23:31.652890861 -0400
+++ /tmp/pmap2 2014-10-29 11:29:52.218328701 -0400
@@ -3,7 +3,8 @@
0000000000400000 0 4 0 r-x-- ruby
0000000000600000 0 4 4 r---- ruby
0000000000601000 0 4 4 rw--- ruby
-00000000013fc000 0 28696 28696 rw--- [ anon ]
+00000000013fc000 0 419388 419388 rw--- [ anon ]
+00007f74e26d5000 0 32772 32772 rw--- [ anon ]
00007f74e537f000 0 12 0 r-x-- console.so
00007f74e5382000 0 0 0 ----- console.so
00007f74e5581000 0 4 4 r---- console.so
@@ -137,7 +138,7 @@
00007f74e974d000 0 0 0 ----- [ anon ]
00007f74e974e000 0 24 24 rw--- [ anon ]
00007f74e9852000 0 44 0 r---- locale-archive
-00007f74e9b5c000 0 676 0 r-x-- libc-2.15.so
+00007f74e9b5c000 0 680 0 r-x-- libc-2.15.so
00007f74e9d11000 0 0 0 ----- libc-2.15.so
00007f74e9f10000 0 16 16 r---- libc-2.15.so
00007f74e9f14000 0 8 8 rw--- libc-2.15.so
@@ -170,6 +171,7 @@
00007f74eaf00000 0 16 16 rw--- libruby.so.2.0.0
00007f74eaf04000 0 128 128 rw--- [ anon ]
00007f74eaf26000 0 112 0 r-x-- ld-2.15.so
+00007f74eb0dc000 0 132 132 rw--- [ anon ]
00007f74eb121000 0 20 20 rw--- [ anon ]
00007f74eb145000 0 12 12 rw--- [ anon ]
00007f74eb148000 0 4 4 r---- ld-2.15.so
@@ -178,4 +180,4 @@
00007fff1df6a000 0 4 0 r-x-- [ anon ]
ffffffffff600000 0 0 0 r-x-- [ anon ]
---------------- ------ ------ ------
-total kB 123012 35488 29752
+total kB 552288 459088 453348

I think I am stuck in an infinite loop at the bottom level of that traceback
because the first call to encode_body has a frame_size of 0.

From:
/opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb
@ line 168 AMQ::Protocol::Method.encode_body:

    166: def self.encode_body(body, channel, frame_size)
    167: binding.pry
=> 168: return if body.empty?
    169:
    170: # 8 = 1 + 2 + 4 + 1
    171: # 1 byte of frame type
    172: # 2 bytes of channel number
    173: # 4 bytes of frame payload length
    174: # 1 byte of payload trailer FRAME_END byte
    175: limit = frame_size - 8
    176: return [BodyFrame.new(body, channel)] if body.bytesize < limit
    177:
    178: # Otherwise String#slice on 1.9 will operate with code points,
    179: # and we need bytes. MK.
    180: body.force_encoding("ASCII-8BIT") if RUBY_VERSION.to_f >= 1.9
    181:
    182: array = Array.new
    183: while body && !body.empty?
    184: payload, body = body[0, limit], body[limit, body.length -
limit]
    185: array << BodyFrame.new(payload, channel)
    186: end
    187:
    188: array
    189: end

[1] pry(basic.publish)> frame_size
History not saved; unable to open your history file for writing.
=> 0
[2] pry(basic.publish)> body
=>
"{\"name\":\"client0.example.tld\",\"address\":\"10.35.10.88\",\"subscriptions\":[\"ui\"],\"version\":\"0.14.0\",\"timestamp\":1414593463}"
[3] pry(basic.publish)> channel
=> 1

With the frame size being 0, the 'limit' ends up being -8 bytes so we will
never end up returning the single-element array.

From:
/opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb
@ line 176 AMQ::Protocol::Method.encode_body:

    166: def self.encode_body(body, channel, frame_size)
    167: binding.pry
    168: return if body.empty?
    169:
    170: # 8 = 1 + 2 + 4 + 1
    171: # 1 byte of frame type
    172: # 2 bytes of channel number
    173: # 4 bytes of frame payload length
    174: # 1 byte of payload trailer FRAME_END byte
    175: limit = frame_size - 8
=> 176: return [BodyFrame.new(body, channel)] if body.bytesize < limit
    177:
    178: # Otherwise String#slice on 1.9 will operate with code points,
    179: # and we need bytes. MK.
    180: body.force_encoding("ASCII-8BIT") if RUBY_VERSION.to_f >= 1.9
    181:
    182: array = Array.new
    183: while body && !body.empty?
    184: payload, body = body[0, limit], body[limit, body.length -
limit]
    185: array << BodyFrame.new(payload, channel)
    186: end
    187:
    188: array
    189: end

[5] pry(basic.publish)> limit
=> -8
[6] pry(basic.publish)> body.bytesize
=> 119

Then we get stuck:
[8] pry(basic.publish)> body
=>
"{\"name\":\"client0.example.tld\",\"address\":\"10.35.10.88\",\"subscriptions\":[\"ui\"],\"version\":\"0.14.0\",\"timestamp
\":1414593463}"
[9] pry(basic.publish)> next

From:
/opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb
@ line 184 AMQ::Protocol::Meth
od.encode_body:

    166: def self.encode_body(body, channel, frame_size)
    167: binding.pry
    168: return if body.empty?
    169:
    170: # 8 = 1 + 2 + 4 + 1
    171: # 1 byte of frame type
    172: # 2 bytes of channel number
    173: # 4 bytes of frame payload length
    174: # 1 byte of payload trailer FRAME_END byte
    175: limit = frame_size - 8
    176: return [BodyFrame.new(body, channel)] if body.bytesize < limit
    177:
    178: # Otherwise String#slice on 1.9 will operate with code points,
    179: # and we need bytes. MK.
    180: body.force_encoding("ASCII-8BIT") if RUBY_VERSION.to_f >= 1.9
    181:
    182: array = Array.new
    183: while body && !body.empty?
=> 184: payload, body = body[0, limit], body[limit, body.length -
limit]
    185: array << BodyFrame.new(payload, channel)
    186: end
    187:
    188: array
    189: end

[9] pry(basic.publish)> next

From:
/opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb
@ line 185 AMQ::Protocol::Meth
od.encode_body:

    166: def self.encode_body(body, channel, frame_size)
    167: binding.pry
    168: return if body.empty?
    169:
    170: # 8 = 1 + 2 + 4 + 1
    171: # 1 byte of frame type
    172: # 2 bytes of channel number
    173: # 4 bytes of frame payload length
    174: # 1 byte of payload trailer FRAME_END byte
    175: limit = frame_size - 8
    176: return [BodyFrame.new(body, channel)] if body.bytesize < limit
    177:
    178: # Otherwise String#slice on 1.9 will operate with code points,
    179: # and we need bytes. MK.
    180: body.force_encoding("ASCII-8BIT") if RUBY_VERSION.to_f >= 1.9
    181:
    182: array = Array.new
    183: while body && !body.empty?
    184: payload, body = body[0, limit], body[limit, body.length -
limit]
=> 185: array << BodyFrame.new(payload, channel)
    186: end
    187:
    188: array
    189: end

[9] pry(basic.publish)> payload
=> nil
[10] pry(basic.publish)> body
=> "4593463}"
[11] pry(basic.publish)> next
From:
/opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb
@ line 184 AMQ::Protocol::Method.encode_body:

    166: def self.encode_body(body, channel, frame_size)
    167: binding.pry
    168: return if body.empty?
    169:
    170: # 8 = 1 + 2 + 4 + 1
    171: # 1 byte of frame type
    172: # 2 bytes of channel number
    173: # 4 bytes of frame payload length
    174: # 1 byte of payload trailer FRAME_END byte
    175: limit = frame_size - 8
    176: return [BodyFrame.new(body, channel)] if body.bytesize < limit
    177:
    178: # Otherwise String#slice on 1.9 will operate with code points,
    179: # and we need bytes. MK.
    180: body.force_encoding("ASCII-8BIT") if RUBY_VERSION.to_f >= 1.9
    181:
    182: array = Array.new
    183: while body && !body.empty?
=> 184: payload, body = body[0, limit], body[limit, body.length -
limit]
    185: array << BodyFrame.new(payload, channel)
    186: end
    187:
    188: array
    189: end

[11] pry(basic.publish)> array.length
=> 1
[12] pry(basic.publish)> next

From:
/opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb
@ line 185 AMQ::Protocol::Method.encode_body:

    166: def self.encode_body(body, channel, frame_size)
    167: binding.pry
    168: return if body.empty?
    169:
    170: # 8 = 1 + 2 + 4 + 1
    171: # 1 byte of frame type
    172: # 2 bytes of channel number
    173: # 4 bytes of frame payload length
    174: # 1 byte of payload trailer FRAME_END byte
    175: limit = frame_size - 8
    176: return [BodyFrame.new(body, channel)] if body.bytesize < limit
    177:
    178: # Otherwise String#slice on 1.9 will operate with code points,
    179: # and we need bytes. MK.
    180: body.force_encoding("ASCII-8BIT") if RUBY_VERSION.to_f >= 1.9
    181:
    182: array = Array.new
    183: while body && !body.empty?
    184: payload, body = body[0, limit], body[limit, body.length -
limit]
=> 185: array << BodyFrame.new(payload, channel)
    186: end
    187:
    188: array
    189: end

[12] pry(basic.publish)> payload
=> nil
[13] pry(basic.publish)> body
=> "4593463}"
[14] pry(basic.publish)> next

From:
/opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb
@ line 184 AMQ::Protocol::Method.encode_body:

    166: def self.encode_body(body, channel, frame_size)
    167: binding.pry
    168: return if body.empty?
    169:
    170: # 8 = 1 + 2 + 4 + 1
    171: # 1 byte of frame type
    172: # 2 bytes of channel number
    173: # 4 bytes of frame payload length
    174: # 1 byte of payload trailer FRAME_END byte
    175: limit = frame_size - 8
    176: return [BodyFrame.new(body, channel)] if body.bytesize < limit
    177:
    178: # Otherwise String#slice on 1.9 will operate with code points,
    179: # and we need bytes. MK.
    180: body.force_encoding("ASCII-8BIT") if RUBY_VERSION.to_f >= 1.9
    181:
    182: array = Array.new
    183: while body && !body.empty?
=> 184: payload, body = body[0, limit], body[limit, body.length -
limit]
    185: array << BodyFrame.new(payload, channel)
    186: end
    187:
    188: array
    189: end

[14] pry(basic.publish)> next

From:
/opt/sensu/embedded/lib/ruby/gems/2.0.0/gems/amq-protocol-1.9.2/lib/amq/protocol/client.rb
@ line 185 AMQ::Protocol::Method.encode_body:

    166: def self.encode_body(body, channel, frame_size)
    167: binding.pry
    168: return if body.empty?
    169:
    170: # 8 = 1 + 2 + 4 + 1
    171: # 1 byte of frame type
    172: # 2 bytes of channel number
    173: # 4 bytes of frame payload length
    174: # 1 byte of payload trailer FRAME_END byte
    175: limit = frame_size - 8
    176: return [BodyFrame.new(body, channel)] if body.bytesize < limit
    177:
    178: # Otherwise String#slice on 1.9 will operate with code points,
    179: # and we need bytes. MK.
    180: body.force_encoding("ASCII-8BIT") if RUBY_VERSION.to_f >= 1.9
    181:
    182: array = Array.new
    183: while body && !body.empty?
    184: payload, body = body[0, limit], body[limit, body.length -
limit]
=> 185: array << BodyFrame.new(payload, channel)
    186: end
    187:
    188: array
    189: end

[14] pry(basic.publish)> body
=> "4593463}"
[15] pry(basic.publish)> payload
=> nil

So I was digging around and found this reference:
AMQP 0-9-1 Complete Reference Guide — RabbitMQ

long frame-max

The largest frame size that the server proposes for the connection,
including frame header and end-byte. The client can negotiate a lower value.
Zero means that the server does not impose any specific limit but may reject
very large frames if it cannot allocate resources for them.

Until the frame-max has been negotiated, both peers MUST accept frames of up
to frame-min-size octets large, and the minimum negotiated value for
frame-max is also frame-min-size.

I adjusted the frame_max on my rabbitmq server configuration which was
indeed set to '0' -- and now the keepalives are publishing properly. It
seems this could be an issue with GitHub - ruby-amqp/amq-protocol: AMQP 0.9.1 protocol serialization and deserialization implementation for Ruby (2.0+)
1.9.2 not being able to handle a frame size of zero.

Regards,
Vince