[Bug] Skylight failed to fetch native extension on server

[johannesluedke]

Locally the install succeeds, but on the server, there is an error when trying to install the native extension:

ERROR -- : [SKYLIGHT] failed to fetch native extension; uri=https://s3.amazonaws.com/skylight-agent-packages/skylight-native/3.1.0-8051462/skylight_x86_64-linux.tar.gz; msg="\x8B" from ASCII-8BIT to UTF-8; remaining-attempts=0

Note:
this is the output of skylight doctor:

SKYLIGHT_REQUIRED=true bundle exec skylight doctor
bundler: failed to load command: skylight (/var/lib/nginx/webroot/shared/bundle/ruby/2.6.0/bin/skylight)

Skylight version: 3.1.2
Ruby version: 2.6.0 (via rvm)
system: CentOS Linux release 7.2.1511 (Core) / uname -r 2.6.32-042stab120.6

[johannesluedke]

I think uninstalling the gem and rerunning bundle install fixed it, it might have been a temporary issue 🤔

[wagenet]

Yeah, it's likely there was a brief network problem. In that case we let bundler continue so your app can boot, but data will obviously not be reported! If you see this happening again, let us know.

[johannesluedke]

@wagenet Just to let you know: When deploying to production I had the exact same issue -- maybe it is not that temporary after all 🤔
I am wondering if it could be related to https://mensfeld.pl/2019/01/exploring-a-critical-netprotocol-issue-in-ruby-2-6-0p0-and-how-it-can-lead-to-a-security-problem/

[wagenet]

@johannesluedke I don't think we're using del anywhere here so it's probably not that issue, though I guess maybe there could be another related issue. The triggering line is here: https://github.com/tildeio/direwolf-agent/blame/master/lib/skylight/native_ext_fetcher.rb#L115.

[wagenet]

Also, do you happen to have a backtrace? It looks like one should be getting logged.

[johannesluedke]

@wagenet I guess you mean
</path/to/dir>/shared/bundle/ruby/2.6.0/gems/skylight-3.1.2/ext/install.log?
That got overwritten on the subsequent succesful install

[johannesluedke]

@wagenet I got hold of a copy of it

I, [2019-01-10T12:45:47.471521 #889]  INFO -- : SKYLIGHT_HDR_PATH=<path/to/dir>/shared/bundle/ruby/2.6.0/gems/skylight-3.1.2/ext; SKYLIGHT_LIB_PATH=<path/to/dir>/shared/bundle/ruby/2.6.0/gems/skylight-3.1.2/lib/skylight/native/x86_64-linux
I, [2019-01-10T12:45:47.472038 #889]  INFO -- : [SKYLIGHT] fetching native ext; curr-platform=x86_64-linux; requested-arch=x86_64-linux; version=3.1.0-8051462
I, [2019-01-10T12:45:47.472198 #889]  INFO -- : [SKYLIGHT] attempting to fetch from remote; uri=https://s3.amazonaws.com/skylight-agent-packages/skylight-native/3.1.0-8051462/skylight_x86_64-linux.tar.gz
E, [2019-01-10T12:45:47.906661 #889] ERROR -- : [SKYLIGHT] failed to fetch native extension; uri=https://s3.amazonaws.com/skylight-agent-packages/skylight-native/3.1.0-8051462/skylight_x86_64-linux.tar.gz; msg="\x8B" from ASCII-8BIT to UTF-8; remaining-attempts=2
<path/to/dir>/shared/bundle/ruby/2.6.0/gems/skylight-3.1.2/lib/skylight/native_ext_fetcher.rb:170:in `write'
<path/to/dir>/shared/bundle/ruby/2.6.0/gems/skylight-3.1.2/lib/skylight/native_ext_fetcher.rb:170:in `block (3 levels) in http_get'
/usr/lib/rvm/rubies/ruby-2.6.0/lib/ruby/2.6.0/net/protocol.rb:497:in `call_block'
/usr/lib/rvm/rubies/ruby-2.6.0/lib/ruby/2.6.0/net/protocol.rb:488:in `<<'
/usr/lib/rvm/rubies/ruby-2.6.0/lib/ruby/2.6.0/net/protocol.rb:158:in `read'
/usr/lib/rvm/rubies/ruby-2.6.0/lib/ruby/2.6.0/net/http/response.rb:293:in `block in read_body_0'
/usr/lib/rvm/rubies/ruby-2.6.0/lib/ruby/2.6.0/net/http/response.rb:278:in `inflater'
/usr/lib/rvm/rubies/ruby-2.6.0/lib/ruby/2.6.0/net/http/response.rb:283:in `read_body_0'
/usr/lib/rvm/rubies/ruby-2.6.0/lib/ruby/2.6.0/net/http/response.rb:204:in `read_body'
<path/to/dir>/shared/bundle/ruby/2.6.0/gems/skylight-3.1.2/lib/skylight/native_ext_fetcher.rb:168:in `block (2 levels) in http_get'
/usr/lib/rvm/rubies/ruby-2.6.0/lib/ruby/2.6.0/net/http.rb:1518:in `block in transport_request'
/usr/lib/rvm/rubies/ruby-2.6.0/lib/ruby/2.6.0/net/http/response.rb:165:in `reading_body'
/usr/lib/rvm/rubies/ruby-2.6.0/lib/ruby/2.6.0/net/http.rb:1517:in `transport_request'
/usr/lib/rvm/rubies/ruby-2.6.0/lib/ruby/2.6.0/net/http.rb:1479:in `request'
/usr/lib/rvm/rubies/ruby-2.6.0/lib/ruby/2.6.0/net/http.rb:1380:in `request_get'
<path/to/dir>/shared/bundle/ruby/2.6.0/gems/skylight-3.1.2/lib/skylight/native_ext_fetcher.rb:163:in `block in http_get'
/usr/lib/rvm/rubies/ruby-2.6.0/lib/ruby/2.6.0/net/http.rb:920:in `start'
/usr/lib/rvm/rubies/ruby-2.6.0/lib/ruby/2.6.0/net/http.rb:605:in `start'
<path/to/dir>/shared/bundle/ruby/2.6.0/gems/skylight-3.1.2/lib/skylight/native_ext_fetcher.rb:162:in `http_get'
<path/to/dir>/shared/bundle/ruby/2.6.0/gems/skylight-3.1.2/lib/skylight/native_ext_fetcher.rb:107:in `block (2 levels) in fetch_native_ext'
<path/to/dir>/shared/bundle/ruby/2.6.0/gems/skylight-3.1.2/lib/skylight/native_ext_fetcher.rb:106:in `open'
<path/to/dir>/shared/bundle/ruby/2.6.0/gems/skylight-3.1.2/lib/skylight/native_ext_fetcher.rb:106:in `block in fetch_native_ext'
<path/to/dir>/shared/bundle/ruby/2.6.0/gems/skylight-3.1.2/lib/skylight/native_ext_fetcher.rb:94:in `times'
<path/to/dir>/shared/bundle/ruby/2.6.0/gems/skylight-3.1.2/lib/skylight/native_ext_fetcher.rb:94:in `fetch_native_ext'
<path/to/dir>/shared/bundle/ruby/2.6.0/gems/skylight-3.1.2/lib/skylight/native_ext_fetcher.rb:71:in `fetch'
<path/to/dir>/shared/bundle/ruby/2.6.0/gems/skylight-3.1.2/lib/skylight/native_ext_fetcher.rb:35:in `fetch'
extconf.rb:155:in `<main>'

[wagenet]

At the moment, my best guess is that some bad data is coming through Net::HTTP. I don't know of anything that we can do to fix this, but I'll leave the issue open for now. It's definitely plausible that it's a Ruby 2.6 issue, since I haven't seen this one before.