Google-cloud-ruby: FATAL errors are not being displayed as ERROR on GCP stack driver

[BrunoQuaresma]

FATAL errors are being displayed as info logs instead of errors or warning logs.

My application.rb

# frozen_string_literal: true

require_relative 'boot'

require 'rails'
# Pick the frameworks you want:
require 'active_model/railtie'
# require "active_job/railtie"
# require "active_record/railtie"
require 'active_storage/engine'
require 'action_controller/railtie'
require 'action_mailer/railtie'
require 'action_view/railtie'
# require "action_cable/engine"
# require "sprockets/railtie"
require 'rails/test_unit/railtie'
require 'stackdriver'

# Require the gems listed in Gemfile, including any gems
# you've limited to :test, :development, or :production.
Bundler.require(*Rails.groups)

module AuthService
  class Application < Rails::Application
    # Initialize configuration defaults for originally generated Rails version.
    config.load_defaults 5.2

    # Settings in config/environments/* take precedence over those specified here.
    # Application configuration can go into files in config/initializers
    # -- all .rb files in that directory are automatically loaded after loading
    # the framework and any gems in your application.

    # Only loads a smaller set of middleware suitable for API only apps.
    # Middleware like session, flash, cookies can be added back manually.
    # Skip views, helpers and assets when generating a new resource.
    config.api_only = false
    config.eager_load_paths += %W[#{config.root}/app]
    config.time_zone = 'Etc/UTC'
    config.reload_controllers = !Rails.env.production?
  end
end

How can I change fatal errors to be ERRORs?

[blowmage]

Looking at the image you shared, I see that Rails logs a message that it received a GET request for /jsjsjsd, and then 2 milliseconds later it logs another message that there is no route for /jsjsjsd. Those look like two different messages to me. The first is INFO, the second is FATAL.

When the message is sent to Google Cloud Logging, those messages logged with FATAL (Logger::FATAL) will be stored as CRITICAL severity, which is a higher severity than ERROR (Logger::ERROR/ERROR severity).

[dazuma]

A couple of questions:

• Where are you deployed? App Engine? (If so, Flexible or Standard?) Kubernetes Engine? Cloud Run? Something else?
• What's your RAILS_ENV?

[BrunoQuaresma]

The issue is those FATAL errors are not being stored as CRITICAL severity. They are being stored as INFO and I do not know why. I just followed the gem guide for rails.

[BrunoQuaresma]

@dazuma

1. Deployed on GCP - K8s
2. RAILS_ENV - production

[blowmage]

It looks like you aren't loading the Rails instrumentation. Did you try adding the following to config/application.rb:

require "google/cloud/logging/rails"

[BrunoQuaresma]

@blowmage I followed those instructions:
https://github.com/googleapis/google-cloud-ruby/tree/master/stackdriver#instrument-your-code

So, should I remove the stackdriver gem and use only the google-cloud one?

[blowmage]

@dazuma Do you know if the "basic diagnostics" in the previous link includes Logging?

[BrunoQuaresma]

Should be I think since it is on description. (the third bullet point)

https://github.com/googleapis/google-cloud-ruby/tree/master/stackdriver#stackdriver

Specifically, this gem is a convenience package that loads and automatically activates the instrumentation features of the following gems:

• google-cloud-debugger which enables remote debugging using Stackdriver Debugger
• google-cloud-error_reporting which reports unhandled exceptions and other errors to Stackdriver Error Reporting
• google-cloud-logging which collects application logs in Stackdriver logging
• google-cloud-trace which reports distributed latency traces to Stackdriver Trace

[dazuma]

Including require "stackdriver" in application.rb (as described in https://github.com/googleapis/google-cloud-ruby/tree/master/stackdriver#instrument-your-code) should be sufficient. That file automatically loads the railties if it detects Rails. (i.e. it will automatically require "google/cloud/logging/rails" if ::Rails is defined.)

Deployment to K8s/GKE, with RAILS_ENV=production, should work. The only thing I can think of is maybe your application (or some other gem you have installed) is overriding or otherwise customizing the Rails logger.

[blowmage]

@BrunoQuaresma I would like to know if adding the require "google/cloud/logging/rails" require fixes this for you. The stackdriver gem should load this. So if you add the logging require explicitly and it doesn't work then the issue isn't in the require but somewhere else.

[BrunoQuaresma]

More context. Even after add require "google/cloud/logging/rails" stills not working. Extra context:

• I'm using K8s on GCP
• I'm seeing the logs on container logs view
• I'm using Rails 5.2.1
• I'm using RAILS_LOG_TO_STDOUT=true. If I remove this logs are not displayed at all

Thoughts?

[SehiiRohoza]

Have a look at the documentation Cloud Logging for Legacy Logging and Monitoring section Best practices:

Severities: By default, logs written to the standard output are on the
INFO level and logs written to the standard error are on the ERROR
level. Structured logs can include a severity field, which defines the
log's severity.

and because you're using RAILS_LOG_TO_STDOUT=true log events generated by Ruby you can see with severity INFO.

Keep in mind that you should migrate to Kubernetes Engine Monitoring:

Warning: Legacy Logging and Monitoring support for Google Kubernetes
Engine is deprecated. If you are using Legacy Logging and Monitoring,
then you must migrate to Kubernetes Engine Monitoring before support
for Legacy Logging and Monitoring is removed.

it's better to return to this "issue" after migration.

[BrunoQuaresma]

I migrated the logging and monitoring service but stills not working. I followed all the steps on docs and stackdriver gem README but errors are still displayed as INFO.

[BrunoQuaresma]

When I remove RAILS_LOG_TO_STDOUT logs are not displayed at all. 😢

[BrunoQuaresma]

I got this working changing the log format:

config.log_formatter = proc do |severity, datetime, progname, msg|
    message = msg
    message << " from #{progname}" if progname.present?
    content = JSON.dump(timestamp: datetime.to_s, severity: severity, message: message)
    content << "\n"
    content
  end

[lucasgomide]

@BrunoQuaresma By changing the config.log_formmater was enough to capture FATAL errors?
Have you removed the google_cloud * gems?