Segmentation fault in test server

[tilsammans]

I've started seeing segmentation faults during test runs of the Grocer server on our CI platform. These do not appear locally, and so far not on production either. The CI and production platform are Ubuntu 12.04 and the Ruby version is identical for all, 2.1.1.

Is this a problem in Grocer or do I have to look elsewhere?

/home/rof/.rvm/rubies/ruby-2.1.1/lib/ruby/2.1.0/openssl/buffering.rb:61: [BUG] Segmentation fault at 0x007f26d801dcb0
ruby 2.1.1p76 (2014-02-24 revision 45161) [x86_64-linux]

-- Control frame information -----------------------------------------------
c:0007 p:---- s:0029 e:000028 CFUNC  :sysread
c:0006 p:0019 s:0025 e:000023 METHOD /home/rof/.rvm/rubies/ruby-2.1.1/lib/ruby/2.1.0/openssl/buffering.rb:61
c:0005 p:0085 s:0021 e:000020 METHOD /home/rof/.rvm/rubies/ruby-2.1.1/lib/ruby/2.1.0/openssl/buffering.rb:102
c:0004 p:0010 s:0015 e:000014 METHOD /home/rof/cache/bundler/ruby/2.1.0/gems/grocer-0.6.0/lib/grocer/notification_reader.rb:21
c:0003 p:0020 s:0008 e:000007 METHOD /home/rof/cache/bundler/ruby/2.1.0/gems/grocer-0.6.0/lib/grocer/notification_reader.rb:13
c:0002 p:0026 s:0004 e:000003 BLOCK  /home/rof/cache/bundler/ruby/2.1.0/gems/grocer-0.6.0/lib/grocer/server.rb:25 [FINISH]
c:0001 p:---- s:0002 e:000001 TOP    [FINISH]

-- Ruby level backtrace information ----------------------------------------
/home/rof/cache/bundler/ruby/2.1.0/gems/grocer-0.6.0/lib/grocer/server.rb:25:in `block (3 levels) in accept'
/home/rof/cache/bundler/ruby/2.1.0/gems/grocer-0.6.0/lib/grocer/notification_reader.rb:13:in `each'
/home/rof/cache/bundler/ruby/2.1.0/gems/grocer-0.6.0/lib/grocer/notification_reader.rb:21:in `read_notification'
/home/rof/.rvm/rubies/ruby-2.1.1/lib/ruby/2.1.0/openssl/buffering.rb:102:in `read'
/home/rof/.rvm/rubies/ruby-2.1.1/lib/ruby/2.1.0/openssl/buffering.rb:61:in `fill_rbuff'
/home/rof/.rvm/rubies/ruby-2.1.1/lib/ruby/2.1.0/openssl/buffering.rb:61:in `sysread'

-- C level backtrace information -------------------------------------------
/home/rof/.rvm/rubies/ruby-2.1.1/lib/libruby.so.2.1(+0x1c73dc) [0x7f26ec4a23dc] vm_dump.c:685
/home/rof/.rvm/rubies/ruby-2.1.1/lib/libruby.so.2.1(+0x74410) [0x7f26ec34f410] error.c:307
/home/rof/.rvm/rubies/ruby-2.1.1/lib/libruby.so.2.1(rb_bug+0xb3) [0x7f26ec3500c3] error.c:334
/home/rof/.rvm/rubies/ruby-2.1.1/lib/libruby.so.2.1(+0x148dde) [0x7f26ec423dde] signal.c:704
/lib/x86_64-linux-gnu/libc.so.6(+0x36c30) [0x7f26ebf4bc30] array.c:759
[0x7f26d801dcb0]

[nonsense]

I am having the same problem.

/usr/local/rvm/rubies/ruby-2.1.2/lib/ruby/2.1.0/openssl/buffering.rb:61: [BUG] Segmentation fault at 0x00000000000000
ruby 2.1.2p95 (2014-05-08 revision 45877) [x86_64-linux]

-- Control frame information -----------------------------------------------
c:0007 p:---- s:0029 e:000028 CFUNC  :sysread
c:0006 p:0019 s:0025 e:000023 METHOD /usr/local/rvm/rubies/ruby-2.1.2/lib/ruby/2.1.0/openssl/buffering.rb:61
c:0005 p:0085 s:0021 e:000020 METHOD /usr/local/rvm/rubies/ruby-2.1.2/lib/ruby/2.1.0/openssl/buffering.rb:102
c:0004 p:0010 s:0015 e:000014 METHOD /usr/local/rvm/gems/ruby-2.1.2/gems/grocer-0.6.0/lib/grocer/notification_reader.rb:21
c:0003 p:0020 s:0008 e:000007 METHOD /usr/local/rvm/gems/ruby-2.1.2/gems/grocer-0.6.0/lib/grocer/notification_reader.rb:13
c:0002 p:0026 s:0004 e:000003 BLOCK  /usr/local/rvm/gems/ruby-2.1.2/gems/grocer-0.6.0/lib/grocer/server.rb:25 [FINISH]
c:0001 p:---- s:0002 e:000001 TOP    [FINISH]

-- Ruby level backtrace information ----------------------------------------
/usr/local/rvm/gems/ruby-2.1.2/gems/grocer-0.6.0/lib/grocer/server.rb:25:in `block (3 levels) in accept'
/usr/local/rvm/gems/ruby-2.1.2/gems/grocer-0.6.0/lib/grocer/notification_reader.rb:13:in `each'
/usr/local/rvm/gems/ruby-2.1.2/gems/grocer-0.6.0/lib/grocer/notification_reader.rb:21:in `read_notification'
/usr/local/rvm/rubies/ruby-2.1.2/lib/ruby/2.1.0/openssl/buffering.rb:102:in `read'
/usr/local/rvm/rubies/ruby-2.1.2/lib/ruby/2.1.0/openssl/buffering.rb:61:in `fill_rbuff'
/usr/local/rvm/rubies/ruby-2.1.2/lib/ruby/2.1.0/openssl/buffering.rb:61:in `sysread'

[stevenharman]

Is this a problem in Grocer or do I have to look elsewhere?

These are the first reports of this; I'm not aware of any outstanding/known bugs. Please do investigate, and if you can create a minimal, reproducible example, I might be able to help track down the problem.

[tilsammans]

I can't reproduce the problem on Nitrous. I'll see if I can find a VM image where it happens.

[nonsense]

Unfortunately I cant reproduce it consistently either... it fails "sometimes" - 1 out of 3-4 test runs.

[bayan]

tl;dr Start and stop a single Grocer server for all tests.

I encountered this same issue when running specs on my local Ubuntu VM.
The developer that pushed the code was able to run through the specs on his mac fine.

I noticed that a Grocer server would be initialized and closed for the specs that were failing:

server = Grocer.server(port:2195)
server.accept
  ...
server.close

When I ran each spec individually, I had no issues. But when I ran the whole suite, I was able to consistently get seg faults.

So I moved the grocer server code into a before and after all block in my spec config:

config.before(:all) do
  @grocer_server = Grocer.server(port:2195)
  @grocer_server.accept
end

config.after(:all) do
  @grocer_server.close
end

And now my specs all pass without seg faults.

[nonsense]

Thanks for the update! Apparently this solved it for you, since all your tests that use Grocer are inside one spec file. If they are spread through many spec files, config.before(:all) doesn't work. I had to wrap the Grocer server/client objects in a singleton, since I couldn't get an instance variable inside config.before(:suite)

[tilsammans]

I had to go with the singleton too.

# spec/support/grocer.rb
class GrocerServer
  include Singleton

  def server
    Grocer.server(port: 2195)
  end
end

RSpec.describe "class" do
  let(:grocer_server) { GrocerServer.instance.server }

  before do
    grocer_server.accept
  end

  after do
    grocer_server.close
  end
end

now the segfaults don't appear any more.

[stevenharman]

Thanks for all of the investigation, all. While not ideal, I'm glad you found a work around. If anyone would like, we'd certainly love to have someone investigate the root cause so we can fix the server code and not have to rely on these workarounds. Anyone have bandwidth to take a deeper dive?

[nonsense]

I am sorry, but I will be unable to do that at the moment. I don't have much experience with APNS and iOS, and unfortunately I don't have the time to dive into this now. In case things change on my end, I will create a PR to let you know.

[danbartlett]

I am encountering the same error after adding rspec tests for push notifications.

$ rspec
....................................................................................../home/dan/.rvm/rubies/ruby-2.1.1/lib/ruby/2.1.0/openssl/buffering.rb:61: [BUG] Segmentation fault at 0x00000000000001
ruby 2.1.1p76 (2014-02-24 revision 45161) [x86_64-linux]

-- Control frame information -----------------------------------------------
c:0007 p:---- s:0029 e:000028 CFUNC  :sysread
c:0006 p:0019 s:0025 e:000023 METHOD /home/dan/.rvm/rubies/ruby-2.1.1/lib/ruby/2.1.0/openssl/buffering.rb:61
c:0005 p:0085 s:0021 e:000020 METHOD /home/dan/.rvm/rubies/ruby-2.1.1/lib/ruby/2.1.0/openssl/buffering.rb:102
c:0004 p:0010 s:0015 e:000014 METHOD /home/dan/.rvm/gems/ruby-2.1.1/gems/grocer-0.6.0/lib/grocer/notification_reader.rb:21
c:0003 p:0020 s:0008 e:000007 METHOD /home/dan/.rvm/gems/ruby-2.1.1/gems/grocer-0.6.0/lib/grocer/notification_reader.rb:13
c:0002 p:0026 s:0004 e:000003 BLOCK  /home/dan/.rvm/gems/ruby-2.1.1/gems/grocer-0.6.0/lib/grocer/server.rb:25 [FINISH]
c:0001 p:---- s:0002 e:000001 TOP    [FINISH]

-- Ruby level backtrace information ----------------------------------------
/home/dan/.rvm/gems/ruby-2.1.1/gems/grocer-0.6.0/lib/grocer/server.rb:25:in `block (3 levels) in accept'
/home/dan/.rvm/gems/ruby-2.1.1/gems/grocer-0.6.0/lib/grocer/notification_reader.rb:13:in `each'
/home/dan/.rvm/gems/ruby-2.1.1/gems/grocer-0.6.0/lib/grocer/notification_reader.rb:21:in `read_notification'
/home/dan/.rvm/rubies/ruby-2.1.1/lib/ruby/2.1.0/openssl/buffering.rb:102:in `read'
/home/dan/.rvm/rubies/ruby-2.1.1/lib/ruby/2.1.0/openssl/buffering.rb:61:in `fill_rbuff'
/home/dan/.rvm/rubies/ruby-2.1.1/lib/ruby/2.1.0/openssl/buffering.rb:61:in `sysread'

-- C level backtrace information -------------------------------------------
[1]    29349 segmentation fault (core dumped)  rspec

I have tried the above suggestion:

pusher_notification_spec.rb

require 'timeout'
require 'rails_helper'

describe "apple push notifications" do
  let(:grocer_server) { GrocerServer.instance.server }

  before do
    grocer_server.accept
  end

  after do
    grocer_server.close
  end

  # my tests
end

...and added the spec/support/grocer.rb file

All my grocer tests are in one file. When I run the file individually, there is no issues. When I run the whole suite I get a segfault every time. Does anyone have any further suggestions? At the moment my only option is to comment out the tests, as we need to run the whole suite regularly.

[varunlalan]

Segmentation failure is also happening on my machine and also on CI platforms.

/home/varun/.rvm/rubies/ruby-2.1.5/lib/ruby/2.1.0/openssl/buffering.rb:61: [BUG] Segmentation fault at 0x736f7288
ruby 2.1.5p273 (2014-11-13 revision 48405) [i686-linux]

-- Control frame information -----------------------------------------------
c:0007 p:---- s:0029 e:000028 CFUNC  :sysread
c:0006 p:0019 s:0025 e:000023 METHOD /home/kiprosh007/.rvm/rubies/ruby-2.1.5/lib/ruby/2.1.0/openssl/buffering.rb:61
c:0005 p:0085 s:0021 e:000020 METHOD /home/kiprosh007/.rvm/rubies/ruby-2.1.5/lib/ruby/2.1.0/openssl/buffering.rb:102
c:0004 p:0010 s:0015 e:000014 METHOD /home/kiprosh007/.rvm/gems/ruby-2.1.5@gogovan/gems/grocer-0.6.0/lib/grocer/notification_reader.rb:21
c:0003 p:0020 s:0008 e:000007 METHOD /home/kiprosh007/.rvm/gems/ruby-2.1.5@gogovan/gems/grocer-0.6.0/lib/grocer/notification_reader.rb:13
c:0002 p:0026 s:0004 e:000003 BLOCK  /home/kiprosh007/.rvm/gems/ruby-2.1.5@gogovan/gems/grocer-0.6.0/lib/grocer/server.rb:25 [FINISH]
c:0001 p:---- s:0002 e:000001 TOP    [FINISH]

/home/kiprosh007/.rvm/gems/ruby-2.1.5@gogovan/gems/grocer-0.6.0/lib/grocer/server.rb:25:in `block (3 levels) in accept'
/home/kiprosh007/.rvm/gems/ruby-2.1.5@gogovan/gems/grocer-0.6.0/lib/grocer/notification_reader.rb:13:in `each'
/home/kiprosh007/.rvm/gems/ruby-2.1.5@gogovan/gems/grocer-0.6.0/lib/grocer/notification_reader.rb:21:in `read_notification'
/home/kiprosh007/.rvm/rubies/ruby-2.1.5/lib/ruby/2.1.0/openssl/buffering.rb:102:in `read'
/home/kiprosh007/.rvm/rubies/ruby-2.1.5/lib/ruby/2.1.0/openssl/buffering.rb:61:in `fill_rbuff'
/home/kiprosh007/.rvm/rubies/ruby-2.1.5/lib/ruby/2.1.0/openssl/buffering.rb:61:in `sysread'

-- C level backtrace information -------------------------------------------
/home/kiprosh007/.rvm/rubies/ruby-2.1.5/lib/libruby.so.2.1(+0x1ea390) [0xb760b390] vm_dump.c:690
/home/kiprosh007/.rvm/rubies/ruby-2.1.5/lib/libruby.so.2.1(+0x6c18d) [0xb748d18d] error.c:312
/home/kiprosh007/.rvm/rubies/ruby-2.1.5/lib/libruby.so.2.1(rb_bug+0x40) [0xb748dc40] error.c:339
/home/kiprosh007/.rvm/rubies/ruby-2.1.5/lib/libruby.so.2.1(+0x159883) [0xb757a883] signal.c:812

All the backtraces have one thing in common - Linux machine (I am sure you guys have also observed it). Not sure if that is the cause of this. Does anyone have any further suggestions?

[stevenharman]

@varunlalan I was going to link to some Issues I've found in other Ruby gems that point to a problem with OpenSSL and or the certificiates, but no I see you've already opened an issue on OpenSSL. 😄 I'm at a loss for where to start as I've never seen this error myself, and am unsure how to reproduce it.

[adamniedzielski]

I have one test case when I am using mock server and one test case when I am using Apple development server. The segfault happens only when these two tests are executed together.
I removed @server.close and it resolved the issue. Let's see whether it does not have any further negative consequences.

[kushkella]

I was having the same problem, and the only solution I came across was mocking the Grocer::Pusher class as follows:

module Grocer
  class Pusher
    class_attribute :notifications

    def push(notification)
      self.class.notifications ||= []
      self.class.notifications << notification
    end
  end
end

I'm accessing stored notifications using Grocer::Pusher.notifications and it works for my case. I understand that this isn't the right way of testing the grocer push notifications, but I can't figure out any other solution that works reliably. I really appreciate if somebody could please tell a reliable way of handling this error.