instana / ruby-sensor

💎 Ruby Distributed Tracing & Metrics Sensor for Instana
https://www.instana.com/
MIT License
26 stars 25 forks source link

Failed to dump StringIO Object to JSON in strict mode #138

Closed scalp42 closed 5 years ago

scalp42 commented 5 years ago

When enabling debug, we can see the following:

06:28:25 api.1  | 73.202.244.47, 10.22.229.131 - - [12/Jun/2019:06:28:25 +0000] "GET /v1/user/list HTTP/1.1" 200 20 0.0050
06:28:25 api.1  | 73.202.244.47, 10.22.229.131 - - [12/Jun/2019:06:28:25 +0000] "GET /v1/user/list HTTP/1.1" 200 20 0.0050
06:28:25 api.1  | 73.202.244.47, 10.22.229.131 - - [12/Jun/2019:06:28:25 +0000] "GET /v1/user/list HTTP/1.1" 200 20 0.0101
06:28:25 api.1  | 73.202.244.47, 10.22.229.131 - - [12/Jun/2019:06:28:25 +0000] "GET /v1/user/list HTTP/1.1" 200 20 0.0049
06:28:26 api.1  | D, [2019-06-12T06:28:26.029890 #7] DEBUG -- : Instana: report_spans:agent.rb:307: Failed to dump StringIO Object to JSON in strict mode.
06:28:26 api.1  | 
06:28:26 api.1  | D, [2019-06-12T06:28:26.029984 #7] DEBUG -- : Instana: /usr/local/bundle/gems/instana-1.9.5/lib/instana/agent.rb:295:in `dump'
06:28:26 api.1  | /usr/local/bundle/gems/instana-1.9.5/lib/instana/agent.rb:295:in `report_spans'
06:28:26 api.1  | /usr/local/bundle/gems/instana-1.9.5/lib/instana/tracing/processor.rb:101:in `send'
06:28:26 api.1  | /usr/local/bundle/gems/instana-1.9.5/lib/instana/agent.rb:142:in `block in setup'
06:28:26 api.1  | /usr/local/bundle/gems/timers-4.3.0/lib/timers/timer.rb:104:in `fire'
06:28:26 api.1  | /usr/local/bundle/gems/timers-4.3.0/lib/timers/events.rb:49:in `fire'
06:28:26 api.1  | /usr/local/bundle/gems/timers-4.3.0/lib/timers/events.rb:90:in `fire'
06:28:26 api.1  | /usr/local/bundle/gems/timers-4.3.0/lib/timers/group.rb:100:in `fire'
06:28:26 api.1  | /usr/local/bundle/gems/timers-4.3.0/lib/timers/group.rb:85:in `wait'
06:28:26 api.1  | /usr/local/bundle/gems/instana-1.9.5/lib/instana/agent.rb:167:in `block in start'
06:28:26 api.1  | /usr/local/bundle/gems/instana-1.9.5/lib/instana/agent.rb:159:in `loop'
06:28:26 api.1  | /usr/local/bundle/gems/instana-1.9.5/lib/instana/agent.rb:159:in `start'
06:28:26 api.1  | /usr/local/bundle/gems/instana-1.9.5/lib/instana/agent.rb:103:in `block (2 levels) in spawn_background_thread'
06:28:26 api.1  | 10.22.43.246 - - [12/Jun/2019:06:28:26 +0000] "GET /v1/ping HTTP/1.1" 200 4 0.0007

Any idea?

pglombardo commented 5 years ago

Hi @scalp42 - thanks for pointing this out. Maybe there is some payload in the span or that StringIO object that it's choking on?

I'll test some variations and update here again soon.

This shouldn't affect the application I would think. The only symptom was the ugly backtrace correct? (and probably missing trace in the dashboard)

pglombardo commented 5 years ago

Hi @scalp42 - this can be reproduced but we shouldn't ever be capturing StringIO objects in traces. Is this still happening for you?

scalp42 commented 5 years ago

Hi @pglombardo sorry for the delay here, we haven't tried again. I'll close for now.