http
http copied to clipboard
httprb
Seeing a Segfault
This library is generating a segfault for me when I do this - HTTP.get(s3_object_public_url).body.to_s
This is on our Heroku workers, they keep crashing with Segfault. Please see details below.
Its starts with the following error -
2019-11-14T21:40:44.777135+00:00 app[worker_a.2]: pid=4 tid=grp4a8ox4 WARN: HTTP::ConnectionError: couldn't read response headers
2019-11-14T21:40:44.777281+00:00 app[worker_a.2]: pid=4 tid=grp4a8ox4 WARN: /app/vendor/bundle/ruby/2.6.0/gems/http-4.2.0/lib/http/connection.rb:104:in `read_headers!'
2019-11-14T21:40:44.777285+00:00 app[worker_a.2]: /app/vendor/bundle/ruby/2.6.0/gems/http-4.2.0/lib/http/client.rb:75:in `perform'
2019-11-14T21:40:44.777287+00:00 app[worker_a.2]: /app/vendor/bundle/ruby/2.6.0/gems/http-4.2.0/lib/http/client.rb:31:in `request'
2019-11-14T21:40:44.777289+00:00 app[worker_a.2]: /app/vendor/bundle/ruby/2.6.0/gems/http-4.2.0/lib/http/chainable.rb:75:in `request'
2019-11-14T21:40:44.777291+00:00 app[worker_a.2]: /app/vendor/bundle/ruby/2.6.0/gems/http-4.2.0/lib/http/chainable.rb:20:in `get'
Versions -
- gem 'http', '4.2.0'
- gem 'rails', '6.0.1'
- ruby '2.6.5'
- Deployed on Heroku
Segfault -
2019-11-15T03:04:25.870353+00:00 app[worker_a.17]: -- Control frame information -----------------------------------------------
2019-11-15T03:04:25.870365+00:00 app[worker_a.17]: c:0047 p:---- s:0249 e:000248 CFUNC :http_parser_execute
2019-11-15T03:04:25.870382+00:00 app[worker_a.17]: c:0046 p:0025 s:0241 e:000240 METHOD /app/vendor/bundle/ruby/2.6.0/gems/http-parser-1.2.1/lib/http-parser/parser.rb:222
2019-11-15T03:04:25.870386+00:00 app[worker_a.17]: c:0045 p:0011 s:0235 e:000234 METHOD /app/vendor/bundle/ruby/2.6.0/gems/http-4.2.0/lib/http/response/parser.rb:29
2019-11-15T03:04:25.870390+00:00 app[worker_a.17]: c:0044 p:0057 s:0230 e:000229 METHOD /app/vendor/bundle/ruby/2.6.0/gems/http-4.2.0/lib/http/connection.rb:217
2019-11-15T03:04:25.870393+00:00 app[worker_a.17]: c:0043 p:0039 s:0223 e:000222 METHOD /app/vendor/bundle/ruby/2.6.0/gems/http-4.2.0/lib/http/connection.rb:92
2019-11-15T03:04:25.870395+00:00 app[worker_a.17]: c:0042 p:0090 s:0216 e:000215 METHOD /app/vendor/bundle/ruby/2.6.0/gems/http-4.2.0/lib/http/response/body.rb:51
@tarcieri Might be.
@kapso Which heroku build-pack are you using? I want to try to reproduce it.
@ixti
heroku/ruby - this is the default build pack for rails/ruby apps
The stack is Heroku-18 which is Ubuntu 18.04, you can read more here - https://devcenter.heroku.com/articles/heroku-18-stack
@kapso Please provide Gemfile.lock (don't forget to filter out any sensitive info).
@ixti here you go - https://gist.github.com/kapso/e8c6df153bf96d32876710fd426e8b4d
NOTE - rest-client was only added after the crash issue, it wasn't part of Gemfile during Segfault
Curious, if there's a fix coming for this? We are ready to push code to production and switched to RestClient in the interim. But obviously would prefer HTTP.
@kapso if possible, can you come up with a reproduction of this bug or capture it in gdb and get a C stack frame level backtrace?
Sorry, got really busy days lately and was not able to reproduce the error so far, so yeah, any help in reproducing it or analysing why it fails - will help significantly.
Hey @ixti, unfortunately, I can't replicate that. I remember we were running a massive batch process with reading millions of S3 objects (in background Sidekiq jobs) which was causing the issue. Let me check with the team if we can run it again, though I doubt it since its an expensive process : )
No need to apologize, thanks a lot for your work 👍
We're running into occasional segfaults as well at seemingly the same spot. We can't reproduce, but it appears to happen once every 10,000+ client.request(verb, uri, opts) calls.
I'm 99% sure this started happening after upgrading from 4.1.1 to 4.4.1. (http_parser dependency went from 0.6.0 -> 1.2.1 at the same time)
We just reverted back to 4.1.1. I'll report if it happens again after reverting.
Logs:
Oct 1 10:06:46 app[worker] info /app/vendor/bundle/ruby/2.6.0/gems/http-parser-1.2.1/lib/http-parser/parser.rb:222: [BUG] Segmentation fault at 0x00007f2804fa3000
Oct 1 10:06:46 app[worker] info ruby 2.6.6p146 (2020-03-31 revision 67876) [x86_64-linux]
Oct 1 10:06:46 app[worker] info
Oct 1 10:06:46 app[worker] info -- Control frame information -----------------------------------------------
Oct 1 10:06:46 app[worker] info c:0016 p:---- s:0086 e:000085 CFUNC :http_parser_execute
Oct 1 10:06:46 app[worker] info c:0015 p:0025 s:0078 e:000077 METHOD /app/vendor/bundle/ruby/2.6.0/gems/http-parser-1.2.1/lib/http-parser/parser.rb:222
Oct 1 10:06:46 app[worker] info c:0014 p:0011 s:0072 e:000071 METHOD /app/vendor/bundle/ruby/2.6.0/gems/http-4.4.1/lib/http/response/parser.rb:29
Oct 1 10:06:46 app[worker] info c:0013 p:0057 s:0067 e:000066 METHOD /app/vendor/bundle/ruby/2.6.0/gems/http-4.4.1/lib/http/connection.rb:217
Oct 1 10:06:46 app[worker] info c:0012 p:0017 s:0060 e:000059 METHOD /app/vendor/bundle/ruby/2.6.0/gems/http-4.4.1/lib/http/connection.rb:103
Oct 1 10:06:46 app[worker] info c:0011 p:0073 s:0055 e:000054 METHOD /app/vendor/bundle/ruby/2.6.0/gems/http-4.4.1/lib/http/client.rb:75
Oct 1 10:06:46 app[worker] info c:0010 p:0034 s:0048 e:000047 METHOD /app/vendor/bundle/ruby/2.6.0/gems/http-4.4.1/lib/http/client.rb:31
Oct 1 10:06:46 app[worker] info c:0009 p:0017 s:0039 e:000038 METHOD /app/app/services/http_client.rb:8
Oct 1 10:06:46 app[worker] info c:0008 p:0009 s:0032 e:000031 BLOCK /app/app/services/http_client.rb:106
Oct 1 10:06:46 app[worker] info c:0007 p:0005 s:0028 e:000027 BLOCK /app/vendor/bundle/ruby/2.6.0/gems/connection_pool-2.2.3/lib/connection_pool.rb:63 [FINISH]
Oct 1 10:06:46 app[worker] info c:0006 p:---- s:0025 e:000024 CFUNC :handle_interrupt
Oct 1 10:06:46 app[worker] info c:0005 p:0031 s:0020 e:000019 BLOCK /app/vendor/bundle/ruby/2.6.0/gems/connection_pool-2.2.3/lib/connection_pool.rb:62 [FINISH]
Oct 1 10:06:46 app[worker] info c:0004 p:---- s:0016 e:000015 CFUNC :handle_interrupt
Oct 1 10:06:46 app[worker] info c:0003 p:0026 s:0011 e:000010 METHOD /app/vendor/bundle/ruby/2.6.0/gems/connection_pool-2.2.3/lib/connection_pool.rb:59
Oct 1 10:06:46 app[worker] info c:0002 p:0008 s:0006 e:000005 BLOCK /app/app/services/http_client.rb:105 [FINISH]
Oct 1 10:06:46 app[worker] info c:0001 p:---- s:0003 e:000002 (none) [FINISH]
Oct 1 10:06:46 app[worker] info
Oct 1 10:06:46 app[worker] info -- Ruby level backtrace information ----------------------------------------
Oct 1 10:06:46 app[worker] info /app/app/services/http_client.rb:105:in `block (2 levels) in REDACTED'
Oct 1 10:06:46 app[worker] info /app/vendor/bundle/ruby/2.6.0/gems/connection_pool-2.2.3/lib/connection_pool.rb:59:in `with'
Oct 1 10:06:46 app[worker] info /app/vendor/bundle/ruby/2.6.0/gems/connection_pool-2.2.3/lib/connection_pool.rb:59:in `handle_interrupt'
Oct 1 10:06:46 app[worker] info /app/vendor/bundle/ruby/2.6.0/gems/connection_pool-2.2.3/lib/connection_pool.rb:62:in `block in with'
Oct 1 10:06:46 app[worker] info /app/vendor/bundle/ruby/2.6.0/gems/connection_pool-2.2.3/lib/connection_pool.rb:62:in `handle_interrupt'
Oct 1 10:06:46 app[worker] info /app/vendor/bundle/ruby/2.6.0/gems/connection_pool-2.2.3/lib/connection_pool.rb:63:in `block (2 levels) in with'
Oct 1 10:06:46 app[worker] info /app/app/services/http_client.rb:106:in `block (3 levels) in REDACTED'
Oct 1 10:06:46 app[worker] info /app/app/services/http_client.rb:8:in `execute!'
Oct 1 10:06:46 app[worker] info /app/vendor/bundle/ruby/2.6.0/gems/http-4.4.1/lib/http/client.rb:31:in `request'
Oct 1 10:06:46 app[worker] info /app/vendor/bundle/ruby/2.6.0/gems/http-4.4.1/lib/http/client.rb:75:in `perform'
Oct 1 10:06:46 app[worker] info /app/vendor/bundle/ruby/2.6.0/gems/http-4.4.1/lib/http/connection.rb:103:in `read_headers!'
Oct 1 10:06:46 app[worker] info /app/vendor/bundle/ruby/2.6.0/gems/http-4.4.1/lib/http/connection.rb:217:in `read_more'
Oct 1 10:06:46 app[worker] info /app/vendor/bundle/ruby/2.6.0/gems/http-4.4.1/lib/http/response/parser.rb:29:in `add'
Oct 1 10:06:46 app[worker] info /app/vendor/bundle/ruby/2.6.0/gems/http-parser-1.2.1/lib/http-parser/parser.rb:222:in `parse'
Oct 1 10:06:46 app[worker] info /app/vendor/bundle/ruby/2.6.0/gems/http-parser-1.2.1/lib/http-parser/parser.rb:222:in `http_parser_execute'
Oct 1 10:06:46 app[worker] info
Oct 1 10:06:46 app[worker] info -- Machine register context ------------------------------------------------
Oct 1 10:06:46 app[worker] info RIP: 0x00007f2804fa3000 RBP: 0x00007f27e52cca40 RSP: 0x00007f27e52cc988
Oct 1 10:06:46 app[worker] info RAX: 0x00007f27edd9c720 RBX: 0x00007f27d0c47ff5 RCX: 0x00007f27f3f20220
Oct 1 10:06:46 app[worker] info RDX: 0x0000000000000004 RDI: 0x00007f27e0f927b0 RSI: 0x00007f27d0c47ff1
Oct 1 10:06:46 app[worker] info R8: 0x00007f27f3f203cb R9: 0x00007f27e0f927b0 R10: 0x00007f27f3f203d3
Oct 1 10:06:46 app[worker] info R11: 0x000000000000002c R12: 0x00007f27d0c48554 R13: 0x00007f27f3f1f7b0
Oct 1 10:06:46 app[worker] info R14: 0x00007f27d0c47ff6 R15: 0x0000000000000016 EFL: 0x0000000000010202
Oct 1 10:06:46 app[worker] info
Oct 1 10:06:46 app[worker] info -- C level backtrace information -------------------------------------------
Oct 1 10:06:46 app[worker] info /app/vendor/ruby-2.6.6/bin/../lib/libruby.so.2.6(rb_vm_bugreport+0x769) [0x7f2804bea259] vm_dump.c:715
Oct 1 10:06:46 app[worker] info /app/vendor/ruby-2.6.6/bin/../lib/libruby.so.2.6(rb_bug_context+0xe7) [0x7f2804a2c177] error.c:609
Oct 1 10:06:46 app[worker] info /app/vendor/ruby-2.6.6/bin/../lib/libruby.so.2.6(sigsegv+0x42) [0x7f2804b51422] signal.c:998
Oct 1 10:06:46 app[worker] info /lib/x86_64-linux-gnu/libc.so.6(0x7f28045bcfd0) [0x7f28045bcfd0]
Oct 1 10:06:46 app[worker] info [0x7f2804fa3000]
Thanks for the great gem.
