Logs

Like a typical rails app, Umlaut logs to the ./logs directory, in development.log or production.log etc, depending on what environment you are running under.

Checking for Errors

Rails logger (or any ruby Logger) can log messages with different severity levels: FATAL, ERROR, WARN, INFO, DEBUG.

The default Rails production environment log includes INFO lines for every request. It also includes FATAL lines for any unexpected exceptions (bugs).

In addition, Umlaut will log ERROR or WARN for any service errors -- which could be caused by a third party service being down or returning an expected result, or could be caused by a bug in Umlaut's service plugin code.

Unfortunately, Rails by default does not actually include the severity of logged messages in it's log file, doh.

You can install the Rails gem jrochkind wrote, https://github.com/jrochkind/formatted_rails_logger, to have Rails log with severity.

Then you might want to periodically grep your log file for ERROR|WARN|FATAL to see if there are any problems going on you should know about.

(TODO: We could hypothetically write an admin interface which shows you any recent failed service executions, as failed services are also recorded in the database dispatched_services table (staying there until that table is purged by nightly_maintenance task). Is there interest? )

Turn off database logging in development

The database logging turned on in development is rather verbose. It's by default not present in a production environment, but sometimes you want to turn it off in development so you can examine the other logging, such as umlaut's own service logging.

Add this to an environment file, such as ./environments/development.rb

config.active_record.logger = nil

Rails 3.2 by default turned on 'auto explain logging for long queries'. However, this does not seem to work properly under Umlaut's multi-threaded use of ActiveRecord, and also seems to have a bug where it conflicts with disabling the AR log. So you may want to find and comment out this line in ./config/environments/development/rb, and will have to if you disable active_record_logger as above. Even if you leave AR logging on in general, my impression is that this feature produces false positives in Umlaut due to multi-threaded AR use, and is not useful.

#   config.active_record.auto_explain_threshold_in_seconds = 0.5

Service Errors reported in Web interface

If a service fails with an exception, it'll be listed in the 'errors' block in the lower right corner of the screen.

If you click on the tiny "[D]" link in the footer, it will toggle visible some formerly hidden debug info next to that error report. Looking something like, for example:

technical error information
NoMethodError
undefined method `inner_text' for nil:NilClass
dispatched service id: 1302

If you go directly into your database and look for the DispatchedService object with that id, you will generally find a stack trace and other info about the exception raised, and the status of the service execution.

select * from dispatched_services where id = 1302;

I am considering writing a web admin layer for viewing recent failed services with their context like this, mention if you are interested in seeing it (or writing it!).

Service Logging

Umlaut will log when each service wave (priority) begins and ends, and elapsed time, and how long each service within a wave takes to execute.

This can be useful for jrochkind trying to investigate Umlaut performance, or for you trying to figure out if you should arrange your services in waves differently for better overall responsiveness.

By default, this is only on in development, but you can turn it on or off altogether with Umlaut config (in UmlautController), log_service_timing [true|false].

It will be output with ansi terminal colors, as yellow, to make finding it in the logs easier -- by default only when Rails app standard config.colorize_logging is true, which is generally in development and not production.

SEE ALSO An interactive report of recent service values, in Admin Functions