README.md in semantic_logger-2.0.0 vs README.md in semantic_logger-2.1.0

- old
+ new

@@ -7,11 +7,11 @@ ### Note: As of SemanticLogger V2.0 the Rails logging is no longer automatically replaced when including SemanticLogger. Include the [rails_semantic_logger](http://github.com/ClarityServices/rails_semantic_logger) -to replace the Rails default logger with SemanticLogger +gem to replace the Rails default logger with SemanticLogger ### Overview Semantic Logger takes logging in Ruby to a new level by adding several new capabilities to the commonly used Logging API: @@ -59,17 +59,10 @@ * Simple drop-in replacement for the Ruby, or the Rails loggers * Supports current common logging interface * No changes to existing to code to use new logger ( other than replacing the logger ) -Rails 2 & 3 Support - -* Just include the semantic_logger gem into Rails and it will immediately - replace the existing loggers to improve performance and information - in the log files -* The Rails 3 Tagged logging feature is already available for Rails 2 by use Semantic Logger - Thread Aware * Includes the process and thread id information in every log entry * If running JRuby it will also include the name of the thread for every log entry @@ -170,11 +163,11 @@ similar text output. This can be changed over time to: ```ruby -Rails.logger.info("Queried table", +logger.info("Queried table", :duration => duration, :result => result, :table => "users", :action => "query") ``` @@ -238,11 +231,11 @@ logger.debug { "A total of #{result.inject(0) {|sum, i| i+sum }} were processed" } ``` ### Exceptions -The Semantic Logger adds an extra parameter to the existing log methods so that +The Semantic Logger adds an optional parameter to the existing log methods so that a corresponding Exception can be logged in a standard way ```ruby begin # ... Code that can raise an exception @@ -348,11 +341,11 @@ When Semantic Logger is included in a Rails project it automatically replaces the loggers for Rails, ActiveRecord::Base, ActionController::Base, and ActiveResource::Base with wrappers that set their Class name. For example in semantic_logger/railtie.rb: ```ruby -ActiveRecord::Base.logger = SemanticLogger::Logger.new(ActiveRecord) +ActiveRecord::Base.logger = SemanticLogger[ActiveRecord] ``` By replacing their loggers we now get the class name in the text logging output: 2012-08-30 15:24:13.439 D [47900:main] ActiveRecord -- SQL (12.0ms) SELECT `schema_migrations`.`version` FROM `schema_migrations` @@ -380,33 +373,10 @@ This will result in the log output identifying the log entry as from the ExternalSupplier class 2012-08-30 15:37:29.474 I [48308:ScriptThreadProcess: script/rails] (5.2ms) ExternalSupplier -- Calling external interface -[SyncAttr](https://github.com/ClarityServices/sync_attr) is a gem that supports -lazy loading and thread-safe initialization of class attributes - -Extract from a Rails log file after adding the semantic_logger gem: - -``` -2012-10-19 12:05:46.736 I [35940:JRubyWorker-10] Rails -- - -Started GET "/" for 127.0.0.1 at 2012-10-19 12:05:46 +0000 -2012-10-19 12:05:47.318 I [35940:JRubyWorker-10] ActionController -- Processing by AdminController#index as HTML -2012-10-19 12:05:47.633 D [35940:JRubyWorker-10] ActiveRecord -- User Load (2.0ms) SELECT `users`.* FROM `users` WHERE `users`.`id` = 1 LIMIT 1 -2012-10-19 12:05:49.833 D [35940:JRubyWorker-10] ActiveRecord -- Role Load (2.0ms) SELECT `roles`.* FROM `roles` -2012-10-19 12:05:49.868 D [35940:JRubyWorker-10] ActiveRecord -- Role Load (1.0ms) SELECT * FROM `roles` INNER JOIN `roles_users` ON `roles`.id = `roles_users`.role_id WHERE (`roles_users`.user_id = 1 ) -2012-10-19 12:05:49.885 I [35940:JRubyWorker-10] ActionController -- Rendered menus/_control_system.html.erb (98.0ms) -2012-10-19 12:05:51.014 I [35940:JRubyWorker-10] ActionController -- Rendered layouts/_top_bar.html.erb (386.0ms) -2012-10-19 12:05:51.071 D [35940:JRubyWorker-10] ActiveRecord -- Announcement Load (20.0ms) SELECT `announcements`.* FROM `announcements` WHERE `announcements`.`active` = 1 ORDER BY created_at desc -2012-10-19 12:05:51.072 I [35940:JRubyWorker-10] ActionController -- Rendered layouts/_announcement.html.erb (26.0ms) -2012-10-19 12:05:51.083 I [35940:JRubyWorker-10] ActionController -- Rendered layouts/_flash.html.erb (4.0ms) -2012-10-19 12:05:51.109 I [35940:JRubyWorker-10] ActionController -- Rendered layouts/_footer.html.erb (16.0ms) -2012-10-19 12:05:51.109 I [35940:JRubyWorker-10] ActionController -- Rendered admin/index.html.erb within layouts/base (1329.0ms) -2012-10-19 12:05:51.113 I [35940:JRubyWorker-10] ActionController -- Completed 200 OK in 3795ms (Views: 1349.0ms | ActiveRecord: 88.0ms | Mongo: 0.0ms) -``` - #### Tagged Logging Semantic Logger allows any Ruby or Rails program to also include tagged logging. This means that any logging performed within a block, including any called @@ -437,80 +407,144 @@ logger.debug("Hello World") # ... end ``` -### Using SemanticLogger standalone +### Using SemanticLogger -Example: +When using SemanticLogger inside of Rails all we need to do is include the +rails_semantic_logger gem and the default Rails logger will be replaced with +Semantic Logger. +In a stand-alone or non-rails environment we can easily log to a file called +'development.log' as follows: ```ruby require 'semantic_logger' +SemanticLogger.add_appender('development.log') -# Set the log level to log everything -SemanticLogger::Logger.default_level = :trace +logger = SemanticLogger['Example'] +logger.info "Hello World" +``` -# Add a file appender to log everything to a file -SemanticLogger::Logger.appenders << SemanticLogger::Appender::File.new('dev.log') +By default it will only log :info and above, to log everything to the log file: +```ruby +require 'semantic_logger' +SemanticLogger.default_level = :trace +SemanticLogger.add_appender('development.log') -# Add an appender to only log :info and above to standard out -SemanticLogger::Logger.appenders << SemanticLogger::Appender::File.new(STDOUT, :info) - -logger = SemanticLogger::Logger.new('Example') +logger = SemanticLogger['Example'] logger.info "Hello World" +logger.trace "Low level trace information" ``` -### Configuration +By supplying multiple appenders Semantic Logger can write to multiple destinations +at the same time. For example, log to a file and the screen: +```ruby +require 'semantic_logger' +SemanticLogger.default_level = :trace +SemanticLogger.add_appender('development.log') +SemanticLogger.add_appender(STDOUT) -The Semantic Logger follows the principle where multiple appenders can be active -at the same time. For example, this allows one to log to MongoDB and the Rails -log file at the same time. +logger = SemanticLogger['Example'] +logger.info "Hello World" +logger.trace "Low level trace information" +``` -#### Rails Configuration +To reduce the log level of logging to STDOUT to just :info and above, add the +log_level such as :info as the second parameter when adding the appender: +```ruby +require 'semantic_logger' +SemanticLogger.default_level = :trace +SemanticLogger.add_appender('development.log') +SemanticLogger.add_appender(STDOUT, :info) -Add the following line to Gemfile +logger = SemanticLogger['Example'] +logger.info "Hello World" +logger.trace "Low level trace information" +``` +To log :debug and above to a log file, :error and above to $stderr, and :info +and above to MongoDB: ```ruby -gem 'rails_semantic_logger' -``` +require 'semantic_logger' +require 'mongo' -Also add the following line to Gemfile if you want to log to MongoDB +SemanticLogger.default_level = :debug +SemanticLogger.add_appender('development.log') +SemanticLogger.add_appender($stderr, :error) -```ruby -gem 'mongo' +mongo_appender = SemanticLogger::Appender::MongoDB.new( + :db => Mongodb::Connection.new['production_logging'], + :collection_size => 25.gigabytes +) +SemanticLogger.add_appender(mongo_appender, :info) + +logger = SemanticLogger['Example'] +logger.info "Hello World" +logger.trace "Low level trace information" +logger.error "Oops an error occurred" +logger.info("Login time", :user => 'Mary', :duration => 230, :ip_address=>'192.168.0.1') ``` -Install required gems with bundler +When starting out with Semantic Logger it can be useful to gain all the benefits +of Semantic Logger and still continue to log to an existing logger: +```ruby +require 'logger' +require 'semantic_logger' - bundle install +# Built-in Ruby logger +log = Logger.new(STDOUT) +log.level = Logger::DEBUG -This will automatically replace the standard Rails logger with Semantic Logger -which will write all log data to the configured Rails logger. +SemanticLogger.default_level = :debug +SemanticLogger.add_appender(log) -By default Semantic Logger will detect the log level from Rails. To set the -log level explicitly, add the following line to -config/environments/production.rb inside the Application.configure block +logger = SemanticLogger['Example'] +logger.info "Hello World" +logger.debug("Login time", :user => 'Joe', :duration => 100, :ip_address=>'127.0.0.1') +``` +It is recommended that every class or module have it's own logging instance. +This can be achieved by including SemanticLogger::Loggable: ```ruby -config.log_level = :trace -``` +require 'semantic_logger' +SemanticLogger.default_level = :trace +SemanticLogger.add_appender('development.log') -To log to both the Rails logger and MongoDB add the following lines to -config/environments/production.rb inside the Application.configure block +class ExternalSupplier + # Makes available a class and instance level logger + # ExternalSupplier.logger and ExternalSupplier#logger + include SemanticLogger::Loggable -```ruby -config.after_initialize do - # Re-use the existing MongoDB connection, or create a new one here - db = Mongo::Connection.new['production_logging'] + # logger class method example + def self.hostname=(hostname) + logger.debug "Setting hostname to #{hostname}" + @@hostname = hostname + end - # Besides logging to the standard Rails logger, also log to MongoDB - config.semantic_logger.appenders << SemanticLogger::Appender::MongoDB.new( - :db => db, - :collection_size => 25.gigabytes - ) + # logger instance method example + def call_supplier(amount, name) + logger.debug "Calculating with amount", { :amount => amount, :name => name } + + # Measure and log on completion how long the call took to the external supplier + logger.benchmark_info "Calling external interface" do + # Code to call the external supplier ... + end + end end ``` + +### Configuration + +The Semantic Logger follows the principle where multiple appenders can be active +at the same time. For example, this allows one to log to MongoDB and the Rails +log file at the same time. + +#### Rails Configuration + +To automatically replace the Rails logger with Semantic Logger use the gem [rails_semantic_logger](http://github.com/ClarityServices/rails_semantic_logger) + ### Log Struct Internally all log messages are passed around in a Log Struct. In order to write your own custom formatter or log appender it is necessary to understand the fields: @@ -563,79 +597,75 @@ Example: Formatter that just returns the Log Struct ```ruby require 'semantic_logger' -SemanticLogger::Logger.default_level = :trace +SemanticLogger.default_level = :trace -appender = SemanticLogger::Appender::File.new(STDOUT) do |log| +SemanticLogger.add_appender(STDOUT) do |log| # This formatter just returns the log struct as a string log.inspect end -SemanticLogger::Logger.appenders << appender - -logger = SemanticLogger::Logger.new('Hello') +logger = SemanticLogger['Hello'] logger.info "Hello World" ``` Output: #<struct SemanticLogger::Base::Log level=:info, thread_name=70167090649820, name="Hello", message="Hello World", payload=nil, time=2012-10-24 10:09:33 -0400, duration=nil, tags=nil, level_index=2> -Example: Replace the Rails log formatter, in the environment configuration file: +Example: Replace the default log file formatter ```ruby - config.after_initialize do - # Since the Rails logger is already initialized, replace its default formatter - config.semantic_logger.appenders.first.formatter = Proc.new do |log| - tags = log.tags.collect { |tag| "[#{tag}]" }.join(" ") + " " if log.tags && (log.tags.size > 0) +require 'semantic_logger' +SemanticLogger.default_level = :trace - message = log.message.to_s - message << " -- " << log.payload.inspect if log.payload - message << " -- " << "#{log.exception.class}: #{log.exception.message}\n#{(log.exception.backtrace || []).join("\n")}" if log.exception +SemanticLogger.add_appender('development.log') do |log| +tags = log.tags.collect { |tag| "[#{tag}]" }.join(" ") + " " if log.tags && (log.tags.size > 0) - duration_str = log.duration ? "(#{'%.1f' % log.duration}ms) " : '' +message = log.message.to_s +message << " -- " << log.payload.inspect if log.payload +message << " -- " << "#{log.exception.class}: #{log.exception.message}\n#{(log.exception.backtrace || []).join("\n")}" if log.exception - "#{SemanticLogger::Appender::Base.formatted_time(log.time)} #{log.level.to_s[0..0].upcase} [#{$$}:#{log.thread_name}] #{tags}#{duration_str}#{log.name} -- #{message}" - end - end +duration_str = log.duration ? "(#{'%.1f' % log.duration}ms) " : '' + +"#{SemanticLogger::Appender::Base.formatted_time(log.time)} #{log.level.to_s[0..0].upcase} [#{$$}:#{log.thread_name}] #{tags}#{duration_str}#{log.name} -- #{message}" +end ``` -Example: Replace the MongoDB formatter, in the environment configuration file: +Example: Replace the default MongoDB formatter ```ruby - config.after_initialize do - # Log to MongoDB and supply a custom document formatter - mongodb_appender = SemanticLogger::Appender::MongoDB.new( - :db => Cache::Work.db, - :collection_size => 25.gigabytes - ) do |log| - # Return a document (Hash) of the data to be saved to MongoDB - document = { - :time => log.time, - :host_name => SemanticLogger::Appender::MongoDB.host_name, - :pid => $PID, - :thread_name => log.thread_name, - :name => log.name, - :level => log.level, - :level_index => log.level_index, - } - document[:application] = 'MyApplication' - document[:message] = SemanticLogger::Appender::MongoDB.strip_colorizing(log.message) if log.message - document[:duration] = log.duration if log.duration - document[:tags] = log.tags if log.tags && (log.tags.size > 0) - document[:payload] = log.payload if log.payload - document[:exception] = { - :name => log.exception.class.name, - :message => log.exception.message, - :stack_trace => log.exception.backtrace - } if log.exception - document - end - config.semantic_logger.appenders << mongodb_appender - end +# Log to MongoDB and supply a custom document formatter +mongodb_appender = SemanticLogger::Appender::MongoDB.new( + :db => Cache::Work.db, + :collection_size => 25.gigabytes +) do |log| + # Return a document (Hash) of the data to be saved to MongoDB + document = { + :time => log.time, + :host_name => SemanticLogger::Appender::MongoDB.host_name, + :pid => $PID, + :thread_name => log.thread_name, + :name => log.name, + :level => log.level, + :level_index => log.level_index, + } + document[:application] = 'MyApplication' + document[:message] = SemanticLogger::Appender::MongoDB.strip_colorizing(log.message) if log.message + document[:duration] = log.duration if log.duration + document[:tags] = log.tags if log.tags && (log.tags.size > 0) + document[:payload] = log.payload if log.payload + document[:exception] = { + :name => log.exception.class.name, + :message => log.exception.message, + :stack_trace => log.exception.backtrace + } if log.exception + document +end +SemanticLogger.add_appender(mongodb_appender) ``` ### SysLog and other standard loggers To write log entries to a Syslog logger or any other logger of your choice, @@ -690,18 +720,15 @@ In this way formatting and disk or network write delays will not affect the performance of the application. Also adding more than one appender does not affect the runtime performance of the application. -The additional thread is automatically started on initialization. When the program -terminates it will complete writing out all log data and flush the appenders before -the program exits. +The logging thread is automatically started on initialization. When the program +terminates it will call flush on each of the appenders. Calling SemanticLogger::Logger#flush will wait until all outstanding log messages have been written and flushed to their respective appenders before returning. -Since all logging is now from this thread calling flush is no longer thread -specific. ### Write your own Appender To write your own appender it should meet the following requirements: @@ -737,17 +764,17 @@ end ``` Sample program calling the above appender: ```ruby -SemanticLogger::Logger.default_level = :trace +SemanticLogger.default_level = :trace # Log to file dev.log -SemanticLogger::Logger.appenders << SemanticLogger::Appender::File.new('dev.log') +SemanticLogger.add_appender('dev.log') # Also log the above sample appender -SemanticLogger::Logger.appenders << SimpleAppender.new +SemanticLogger.add_appender(SimpleAppender.new) -logger = SemanticLogger::Logger.new('Hello') +logger = SemanticLogger['Hello'] logger.info "Hello World" ``` Look at the [existing appenders](https://github.com/ClarityServices/semantic_logger/tree/master/lib/semantic_logger/appender) for good examples @@ -773,40 +800,16 @@ - Add support for a configuration file that can set log level by class name - Configuration file to support adding appenders - Based on end-user demand add appenders for: Syslog, hadoop, redis, etc.. -Development ------------ - -Want to contribute to Semantic Logger? - -First clone the repo and run the tests: - - git clone git://github.com/ClarityServices/semantic_logger.git - cd semantic_logger - rake test - -Feel free to ping the mailing list with any issues and we'll try to resolve it. - -Contributing ------------- - -Once you've made your great commits: - -1. [Fork](http://help.github.com/forking/) semantic_logger -2. Create a topic branch - `git checkout -b my_branch` -3. Push to your branch - `git push origin my_branch` -4. Create an [Issue](http://github.com/ClarityServices/semantic_logger/issues) with a link to your branch -5. That's it! - Meta ---- * Code: `git clone git://github.com/ClarityServices/semantic_logger.git` * Home: <https://github.com/ClarityServices/semantic_logger> -* Bugs: <http://github.com/reidmorrison/semantic_logger/issues> +* Bugs: <http://github.com/ClarityServices/semantic_logger/issues> * Gems: <http://rubygems.org/gems/semantic_logger> This project uses [Semantic Versioning](http://semver.org/). Authors @@ -815,10 +818,10 @@ Reid Morrison :: reidmo@gmail.com :: @reidmorrison License ------- -Copyright 2012 Clarity Services, Inc. +Copyright 2012,2013 Clarity Services, Inc. Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except in compliance with the License. You may obtain a copy of the License at