googleapis / google-cloud-ruby

Google Cloud Client Library for Ruby
https://googleapis.github.io/google-cloud-ruby/
Apache License 2.0
1.35k stars 545 forks source link

rails errors in stackdriver only contain stack trace, not error name #1724

Closed sam0x17 closed 6 years ago

sam0x17 commented 7 years ago

Using the 'stackdriver' gem with a new rails 5 app results in errors being reported to stackdriver, however the error name is not recorded. Here is a side-by-side comparison of an error from Cloud Functions (which is formatted correctly) and an error from rails, which only shows the stack trace and forces me to go into the logs to see the actual error:

screenshot from 2017-09-15 17-13-29

I would like it if this was fixed at the gem level, however barring that is there a way I can fix this myself in the mean time?

sam0x17 commented 7 years ago

Note that even if I click on the error and view the raw payload, only the stack trace is included -- only by going into the logs can I see the actual error, which is pretty annoying

sam0x17 commented 7 years ago

Here is the full output of raw for that error in stackdriver, notice that the error name is missing:

vendor/bundle/ruby/2.3.0/gems/actionpack-5.1.3/lib/action_dispatch/middleware/debug_exceptions.rb:63:in `call'
vendor/bundle/ruby/2.3.0/gems/actionpack-5.1.3/lib/action_dispatch/middleware/show_exceptions.rb:31:in `call'
vendor/bundle/ruby/2.3.0/gems/railties-5.1.3/lib/rails/rack/logger.rb:36:in `call_app'
vendor/bundle/ruby/2.3.0/gems/railties-5.1.3/lib/rails/rack/logger.rb:26:in `call'
vendor/bundle/ruby/2.3.0/gems/google-cloud-logging-1.2.2/lib/google/cloud/logging/middleware.rb:89:in `call'
vendor/bundle/ruby/2.3.0/gems/actionpack-5.1.3/lib/action_dispatch/middleware/remote_ip.rb:79:in `call'
vendor/bundle/ruby/2.3.0/gems/actionpack-5.1.3/lib/action_dispatch/middleware/request_id.rb:25:in `call'
vendor/bundle/ruby/2.3.0/gems/rack-2.0.3/lib/rack/method_override.rb:22:in `call'
vendor/bundle/ruby/2.3.0/gems/rack-2.0.3/lib/rack/runtime.rb:22:in `call'
vendor/bundle/ruby/2.3.0/gems/google-cloud-trace-0.27.1/lib/google/cloud/trace/middleware.rb:156:in `block in call'
vendor/bundle/ruby/2.3.0/gems/google-cloud-trace-0.27.1/lib/google/cloud/trace.rb:335:in `block in in_span'
vendor/bundle/ruby/2.3.0/gems/google-cloud-trace-0.27.1/lib/google/cloud/trace/trace_record.rb:230:in `in_span'
vendor/bundle/ruby/2.3.0/gems/google-cloud-trace-0.27.1/lib/google/cloud/trace.rb:332:in `in_span'
vendor/bundle/ruby/2.3.0/gems/google-cloud-trace-0.27.1/lib/google/cloud/trace/middleware.rb:154:in `call'
vendor/bundle/ruby/2.3.0/gems/activesupport-5.1.3/lib/active_support/cache/strategy/local_cache_middleware.rb:27:in `call'
vendor/bundle/ruby/2.3.0/gems/actionpack-5.1.3/lib/action_dispatch/middleware/executor.rb:12:in `call'
vendor/bundle/ruby/2.3.0/gems/actionpack-5.1.3/lib/action_dispatch/middleware/static.rb:125:in `call'
vendor/bundle/ruby/2.3.0/gems/rack-2.0.3/lib/rack/sendfile.rb:111:in `call'
vendor/bundle/ruby/2.3.0/gems/railties-5.1.3/lib/rails/engine.rb:522:in `call'
vendor/bundle/ruby/2.3.0/gems/puma-3.10.0/lib/puma/configuration.rb:225:in `call'
vendor/bundle/ruby/2.3.0/gems/puma-3.10.0/lib/puma/server.rb:605:in `handle_request'
vendor/bundle/ruby/2.3.0/gems/puma-3.10.0/lib/puma/server.rb:437:in `process_client'
vendor/bundle/ruby/2.3.0/gems/puma-3.10.0/lib/puma/server.rb:301:in `block in run'
vendor/bundle/ruby/2.3.0/gems/puma-3.10.0/lib/puma/thread_pool.rb:120:in `block in spawn_thread'

And here is what it looks like in the logs:

screenshot from 2017-09-15 17-20-39

So my expectation is that it would display ActionController::RoutingError (No route matches [GET] "/settings") as the name for the error

hxiong388 commented 7 years ago

@sam0x17 Thanks for submitting this issue.

This is a known problem where these Error Events are auto-generated by backend Stackdriver Logging service from parsing the application logs. The Stackdriver Logging log parser currently doesn't fully translate Ruby Exception logs, as you've noticed. We have an internal ticket tracking this issue.

cc/ @dazuma ref b/37483336

hxiong388 commented 7 years ago

Will be fixed by https://github.com/GoogleCloudPlatform/fluent-plugin-detect-exceptions/pull/17

igorpeshansky commented 7 years ago

This is fixed in fluent-plugin-detect-exceptions v0.0.6.

hxiong388 commented 7 years ago

@igorpeshansky I just tested again with a Rails app on GAE Flex, seems like the problem still persists. Do you know when will GAE Flex upgrade to use the latest fluent-plugin-detect-exceptions v0.0.6 gem?

igorpeshansky commented 7 years ago

@hxiong388 I'm trying to find that out. Will ping this issue when I know more.

sam0x17 commented 7 years ago

@igorpeshansky any updates?

igorpeshansky commented 7 years ago

The fix is in and expected to roll out within the next two weeks.

sam0x17 commented 7 years ago

great thanks! 👍

quartzmo commented 6 years ago

@igorpeshansky Has the fix for this been rolled out as expected? Can we close this issue?

igorpeshansky commented 6 years ago

This should have been rolled out in GAE Flex on October 10. @sam0x17, could you please verify and confirm here? Thanks.

sam0x17 commented 6 years ago

Still experiencing the old behavior, and I re-deployed and updated all my gems three days ago. @igorpeshansky @quartzmo

igorpeshansky commented 6 years ago

@sam0x17, are you able to verify the version of the fluent-plugin-detect-exceptions gem on your GAE Flex nodes?

sam0x17 commented 6 years ago

I don't see that gem anywhere in Gemfile.lock:

sam:blockvue$ grep stackdriver Gemfile.lock
      stackdriver-core (~> 1.2)
      stackdriver-core (~> 1.2)
      stackdriver-core (~> 1.2)
      stackdriver-core (~> 1.2)
    stackdriver (0.10.0)
    stackdriver-core (1.2.0)
  stackdriver
sam:blockvue$ grep fluent Gemfile.lock
sam:blockvue$ 

@igorpeshansky

igorpeshansky commented 6 years ago

google-fluentd uses a different Ruby path. Try running /opt/google-fluentd/embedded/bin/gem list fluent-plugin-detect-exceptions. @sam0x17

sam0x17 commented 6 years ago

@igorpeshansky I was unable to find that directory, in fact sudo find / -name google-fluentd comes up empty.

Here is the list of local gems for the app if that helps:

$ bundle list
Gems included by the bundle:
  * actioncable (5.1.4)
  * actionmailer (5.1.4)
  * actionpack (5.1.4)
  * actionview (5.1.4)
  * activejob (5.1.4)
  * activemodel (5.1.4)
  * activerecord (5.1.4)
  * activesupport (5.1.4)
  * addressable (2.5.2)
  * archive-zip (0.7.0)
  * arel (8.0.0)
  * awesome_print (1.8.0)
  * aws-partitions (1.34.0)
  * aws-sdk (3.0.1)
  * aws-sdk-acm (1.1.0)
  * aws-sdk-apigateway (1.2.0)
  * aws-sdk-applicationautoscaling (1.4.0)
  * aws-sdk-applicationdiscoveryservice (1.0.0)
  * aws-sdk-appstream (1.2.0)
  * aws-sdk-athena (1.0.0)
  * aws-sdk-autoscaling (1.3.0)
  * aws-sdk-batch (1.2.0)
  * aws-sdk-budgets (1.2.0)
  * aws-sdk-clouddirectory (1.0.0)
  * aws-sdk-cloudformation (1.2.0)
  * aws-sdk-cloudfront (1.1.0)
  * aws-sdk-cloudhsm (1.3.0)
  * aws-sdk-cloudhsmv2 (1.1.0)
  * aws-sdk-cloudsearch (1.0.0)
  * aws-sdk-cloudsearchdomain (1.0.0)
  * aws-sdk-cloudtrail (1.0.0)
  * aws-sdk-cloudwatch (1.2.0)
  * aws-sdk-cloudwatchevents (1.1.0)
  * aws-sdk-cloudwatchlogs (1.2.0)
  * aws-sdk-codebuild (1.3.0)
  * aws-sdk-codecommit (1.1.0)
  * aws-sdk-codedeploy (1.0.0)
  * aws-sdk-codepipeline (1.1.0)
  * aws-sdk-codestar (1.1.0)
  * aws-sdk-cognitoidentity (1.0.0)
  * aws-sdk-cognitoidentityprovider (1.0.0)
  * aws-sdk-cognitosync (1.0.0)
  * aws-sdk-configservice (1.4.0)
  * aws-sdk-core (3.7.0)
  * aws-sdk-costandusagereportservice (1.0.0)
  * aws-sdk-databasemigrationservice (1.2.0)
  * aws-sdk-datapipeline (1.0.0)
  * aws-sdk-dax (1.0.0)
  * aws-sdk-devicefarm (1.2.0)
  * aws-sdk-directconnect (1.1.0)
  * aws-sdk-directoryservice (1.0.0)
  * aws-sdk-dynamodb (1.2.0)
  * aws-sdk-dynamodbstreams (1.0.0)
  * aws-sdk-ec2 (1.17.0)
  * aws-sdk-ecr (1.2.0)
  * aws-sdk-ecs (1.3.0)
  * aws-sdk-efs (1.0.0)
  * aws-sdk-elasticache (1.3.0)
  * aws-sdk-elasticbeanstalk (1.2.0)
  * aws-sdk-elasticloadbalancing (1.1.0)
  * aws-sdk-elasticloadbalancingv2 (1.5.0)
  * aws-sdk-elasticsearchservice (1.2.0)
  * aws-sdk-elastictranscoder (1.0.0)
  * aws-sdk-emr (1.0.0)
  * aws-sdk-firehose (1.0.0)
  * aws-sdk-gamelift (1.1.0)
  * aws-sdk-glacier (1.4.0)
  * aws-sdk-glue (1.1.0)
  * aws-sdk-greengrass (1.1.0)
  * aws-sdk-health (1.0.0)
  * aws-sdk-iam (1.3.0)
  * aws-sdk-importexport (1.0.0)
  * aws-sdk-inspector (1.1.0)
  * aws-sdk-iot (1.0.0)
  * aws-sdk-iotdataplane (1.0.0)
  * aws-sdk-kinesis (1.0.0)
  * aws-sdk-kinesisanalytics (1.1.0)
  * aws-sdk-kms (1.3.0)
  * aws-sdk-lambda (1.0.0)
  * aws-sdk-lambdapreview (1.0.0)
  * aws-sdk-lex (1.2.0)
  * aws-sdk-lexmodelbuildingservice (1.2.0)
  * aws-sdk-lightsail (1.1.0)
  * aws-sdk-machinelearning (1.0.0)
  * aws-sdk-marketplacecommerceanalytics (1.0.0)
  * aws-sdk-marketplaceentitlementservice (1.0.0)
  * aws-sdk-marketplacemetering (1.0.0)
  * aws-sdk-migrationhub (1.0.0)
  * aws-sdk-mobile (1.0.0)
  * aws-sdk-mturk (1.1.0)
  * aws-sdk-opsworks (1.1.0)
  * aws-sdk-opsworkscm (1.1.0)
  * aws-sdk-organizations (1.6.0)
  * aws-sdk-pinpoint (1.2.0)
  * aws-sdk-polly (1.3.0)
  * aws-sdk-pricing (1.0.0)
  * aws-sdk-rds (1.7.0)
  * aws-sdk-redshift (1.1.0)
  * aws-sdk-rekognition (1.0.0)
  * aws-sdk-resourcegroupstaggingapi (1.0.0)
  * aws-sdk-resources (3.2.0)
  * aws-sdk-route53 (1.3.0)
  * aws-sdk-route53domains (1.1.0)
  * aws-sdk-s3 (1.6.0)
  * aws-sdk-servicecatalog (1.1.0)
  * aws-sdk-ses (1.3.0)
  * aws-sdk-shield (1.0.0)
  * aws-sdk-simpledb (1.0.0)
  * aws-sdk-sms (1.0.0)
  * aws-sdk-snowball (1.1.0)
  * aws-sdk-sns (1.1.0)
  * aws-sdk-sqs (1.3.0)
  * aws-sdk-ssm (1.3.0)
  * aws-sdk-states (1.1.0)
  * aws-sdk-storagegateway (1.1.0)
  * aws-sdk-support (1.0.0)
  * aws-sdk-swf (1.0.0)
  * aws-sdk-waf (1.2.0)
  * aws-sdk-wafregional (1.2.0)
  * aws-sdk-workdocs (1.0.0)
  * aws-sdk-workspaces (1.0.0)
  * aws-sdk-xray (1.0.0)
  * aws-sigv2 (1.0.1)
  * aws-sigv4 (1.0.2)
  * bcrypt (3.1.11)
  * binding_of_caller (0.7.3)
  * bootstrap_form (2.7.0)
  * builder (3.2.3)
  * bundler (1.15.4)
  * byebug (9.1.0)
  * capybara (2.15.4)
  * capybara-selenium (0.0.6)
  * childprocess (0.8.0)
  * chromedriver-helper (1.1.0)
  * coderay (1.1.2)
  * commonjs (0.2.7)
  * concurrent-ruby (1.0.5)
  * countries (2.1.2)
  * country_select (3.1.1)
  * crass (1.0.2)
  * debug_inspector (0.0.3)
  * devise (4.3.0)
  * diff-lcs (1.3)
  * erubi (1.7.0)
  * erubis (2.7.0)
  * execjs (2.7.0)
  * faraday (0.13.1)
  * fastimage (2.1.0)
  * ffi (1.9.18)
  * globalid (0.4.1)
  * google-cloud-core (1.0.0)
  * google-cloud-debugger (0.28.2)
  * google-cloud-env (1.0.1)
  * google-cloud-error_reporting (0.27.0)
  * google-cloud-logging (1.2.3)
  * google-cloud-trace (0.27.2)
  * google-gax (0.8.12)
  * google-protobuf (3.4.1.1)
  * googleapis-common-protos (1.3.7)
  * googleapis-common-protos-types (1.0.1)
  * googleauth (0.5.3)
  * grpc (1.6.7)
  * haml (5.0.4)
  * haml-rails (1.0.0)
  * html2haml (2.2.0)
  * i18n (0.9.1)
  * i18n_data (0.8.0)
  * io-like (0.3.0)
  * jbuilder (2.7.0)
  * jmespath (1.3.1)
  * jquery-rails (4.3.1)
  * jwt (1.5.6)
  * less (2.6.0)
  * less-rails (2.8.0)
  * libv8 (3.16.14.19)
  * listen (3.1.5)
  * little-plugger (1.1.4)
  * logging (2.2.2)
  * loofah (2.1.1)
  * mail (2.7.0)
  * memoist (0.16.0)
  * method_source (0.9.0)
  * mini_mime (1.0.0)
  * mini_portile2 (2.3.0)
  * minitest (5.10.3)
  * money (6.10.0)
  * multi_json (1.12.2)
  * multipart-post (2.0.0)
  * nio4r (2.1.0)
  * nokogiri (1.8.1)
  * orm_adapter (0.5.0)
  * os (0.9.6)
  * pg (0.21.0)
  * pry (0.11.2)
  * public_suffix (3.0.1)
  * puma (3.10.0)
  * rack (2.0.3)
  * rack-test (0.7.0)
  * rails (5.1.4)
  * rails-dom-testing (2.0.3)
  * rails-html-sanitizer (1.0.3)
  * railties (5.1.4)
  * rake (12.2.1)
  * rb-fsevent (0.10.2)
  * rb-inotify (0.9.10)
  * ref (2.0.0)
  * responders (2.4.0)
  * rly (0.2.3)
  * rspec-core (3.7.0)
  * rspec-expectations (3.7.0)
  * rspec-mocks (3.7.0)
  * rspec-rails (3.7.1)
  * rspec-support (3.7.0)
  * ruby_dep (1.5.0)
  * ruby_parser (3.10.1)
  * rubyzip (1.2.1)
  * sass (3.5.3)
  * sass-listen (4.0.0)
  * sass-rails (5.0.6)
  * selenium-webdriver (3.7.0)
  * sexp_processor (4.10.0)
  * signet (0.8.1)
  * simple_form (3.5.0)
  * sixarm_ruby_unaccent (1.2.0)
  * sort_alphabetical (1.1.0)
  * sprockets (3.7.1)
  * sprockets-rails (3.2.1)
  * stackdriver (0.10.0)
  * stackdriver-core (1.2.0)
  * temple (0.8.0)
  * therubyracer (0.12.3)
  * thor (0.20.0)
  * thread_safe (0.3.6)
  * tilt (2.0.8)
  * turbolinks (5.0.1)
  * turbolinks-source (5.0.3)
  * twitter-bootstrap-rails (4.0.0)
  * tzinfo (1.2.4)
  * uglifier (3.2.0)
  * unicode_utils (1.4.0)
  * warden (1.2.7)
  * websocket-driver (0.6.5)
  * websocket-extensions (0.1.2)
  * xpath (2.1.0)
igorpeshansky commented 6 years ago

@sam0x17, just confirmed that you'll need to run that command via docker exec, i.e.:

docker exec -ti fluentd_logger "/opt/google-fluentd/embedded/bin/gem list fluent-plugin-detect-exceptions"
sam0x17 commented 6 years ago

@igorpeshansky I don't have docker set up to talk to GAE -- just been using gcloud app deploy... do you have a one liner I can enter from the root of my project? Right now of course I just get Error: No such container: fluentd_logger

I'm not sure how to set up docker to talk to GAE

igorpeshansky commented 6 years ago

@sam0x17 I think you have to connect to the instance in debug mode to run that command.

sam0x17 commented 6 years ago

cool -- never tried this before -- will get back to you

sam0x17 commented 6 years ago

@igorpeshansky from within the instance:

$ sudo docker exec -ti fluentd_logger "/opt/google-fluentd/embedded/bin/gem list fluent-plugin-detect-exceptions"
rpc error: code = 2 desc = "oci runtime error: exec failed: exec: \"/opt/google-fluentd/embedded/bin/gem list fluent-plugin-detect-exceptions\": stat /opt/google-fluentd/embedded/bin/gem list fluent-plugin-detect-exceptions: no such file or direc
tory"
igorpeshansky commented 6 years ago

Sorry, my fault. I inadvertently quoted the command — even the docker exec manual says that this won't work. The command should have been:

docker exec -ti fluentd_logger /opt/google-fluentd/embedded/bin/gem list fluent-plugin-detect-exceptions
sam0x17 commented 6 years ago

@igorpeshansky

$ sudo docker exec -ti fluentd_logger /opt/google-fluentd/embedded/bin/g
em list fluent-plugin-detect-exceptions

*** LOCAL GEMS ***

fluent-plugin-detect-exceptions (0.0.6, 0.0.5)
igorpeshansky commented 6 years ago

Ah, so for whatever reason they seem to have 2 versions of the gem... I suspect the logging agent is picking up the wrong version. I'll reopen the issue and ask them to remove the old version. Stay tuned.

sam0x17 commented 6 years ago

ok thanks!

quartzmo commented 6 years ago

Hi, has there been any resolution to this issue?

igorpeshansky commented 6 years ago

Not yet — I've been swamped. It's still on my radar, though...

quartzmo commented 6 years ago

@igorpeshansky Any update?

igorpeshansky commented 6 years ago

Looks like they've bumped the plugin version again (https://github.com/GoogleCloudPlatform/appengine-sidecars-docker/pull/80). Hopefully this time they'll only have one. @andrerod @Cynocracy for visibility.

sam0x17 commented 6 years ago

It is now working. Note that I had to re-enable the stackdriver API for some reason -- maybe the change they pushed disabled it.