Hi,
Just an example how the sample log looks:
# Logfile created on 2012-06-27 13:15:17 +0200 by logger.rb/31641
Verbose enabled:
127.0.0.1 - - [27/Jun/2012 13:15:17] "POST
/api?param1=1{"test":"1","test2":"1"} HTTP/1.1" mock - 301 - 0.0269
127.0.0.1 - - [27/Jun/2012 13:15:18] "POST
/api?param1=1{"test":"1","test2":"1"} HTTP/1.1" mock - 301 - 0.0056
127.0.0.1 - - [27/Jun/2012 13:15:18] "POST
/api?param1=1{"test":"1","test2":"1"} HTTP/1.1" mock - 301 - 0.0066
127.0.0.1 - - [27/Jun/2012 13:15:43] "POST /api?param1=1
{"test":"1","test2":"1"} HTTP/1.1" mock - 301 - 0.0284
127.0.0.1 - - [27/Jun/2012 13:15:43] "POST /api?param1=1
{"test":"1","test2":"1"} HTTP/1.1" mock - 301 - 0.0077
127.0.0.1 - - [27/Jun/2012 13:15:43] "POST /api?param1=1
{"test":"1","test2":"1"} HTTP/1.1" mock - 301 - 0.0065
127.0.0.1 - - [27/Jun/2012 13:15:49] "GET /api/instances HTTP/1.1" mock - 200
3827 0.0525
'mock' is the driver used in HTTP request, the '-' after mock is the provider
value.
The JSON after route contains POST parameters used for the request.
Normal log:
127.0.0.1 - - [27/Jun/2012 13:16:02] "POST /api?param1=1 HTTP/1.1" 301 - 0.0284
127.0.0.1 - - [27/Jun/2012 13:16:02] "POST /api?param1=1 HTTP/1.1" 301 - 0.0089
127.0.0.1 - - [27/Jun/2012 13:16:02] "POST /api?param1=1 HTTP/1.1" 301 - 0.0060
Michal Fojtik
http://deltacloud.org
[email protected]
On Jun 27, 2012, at 1:20 PM, [email protected] wrote:
> From: Michal Fojtik <[email protected]>
>
> User can now start Deltacloud using -L option and specify the full path
> to the log file. All requests will be then logged into this file instead of
> STDOUT.
>
> This patch also fix the -V (verbose) option and will force DC to produce
> detailed logs, which include POST params, driver and provider.
>
> Signed-off-by: Michal fojtik <[email protected]>
> ---
> server/bin/deltacloudd | 1 +
> server/config.ru | 3 +
> server/lib/cimi/server.rb | 2 +-
> server/lib/deltacloud/server.rb | 2 +-
> server/lib/deltacloud_rack.rb | 8 +++
> server/lib/ec2/server.rb | 2 +-
> server/lib/sinatra/rack_logger.rb | 127 +++++++++++++++++++++++++++++++++++++
> 7 files changed, 142 insertions(+), 3 deletions(-)
> create mode 100644 server/lib/sinatra/rack_logger.rb
>
> diff --git a/server/bin/deltacloudd b/server/bin/deltacloudd
> index 08be61c..81488a1 100755
> --- a/server/bin/deltacloudd
> +++ b/server/bin/deltacloudd
> @@ -75,6 +75,7 @@ BANNER
> opts.on( '-g', '--group GROUP', 'Group to run daemon as. Use with -d
> (default: "nobody")') { |group| options[:group] = group }
> opts.on( '-b', '--pid PID', 'File to store PID (default:
> tmp/pids/thin.pid)') { |pid| options[:pid] = pid }
> opts.on( '-l', '--drivers', 'List available drivers') { |env|
> options[:drivers] = true }
> + opts.on( '-L', '--log FILE', 'Log requests to a file (default: disabled)')
> { |log| ENV['API_LOG'] = log }
> opts.on( '-s', '--ssl', 'Enable SSL (default: disabled)') { |ssl|
> options[:ssl] = true }
> opts.on( '-k', '--ssl-key KEY', 'SSL key file to use') { |key|
> options[:ssl_key] = key }
> opts.on( '-C', '--ssl-cert CERT', 'SSL certificate file to use') { |cert|
> options[:ssl_cert] = cert }
> diff --git a/server/config.ru b/server/config.ru
> index 2c06a68..254baf2 100644
> --- a/server/config.ru
> +++ b/server/config.ru
> @@ -26,18 +26,21 @@ Deltacloud::configure do |server|
> server.root_url '/api'
> server.version '1.0.0'
> server.klass 'Deltacloud::API'
> + server.logger Rack::DeltacloudLogger.setup(ENV['API_LOG'],
> ENV['API_VERBOSE'])
> end
>
> Deltacloud::configure(:cimi) do |server|
> server.root_url '/cimi'
> server.version '1.0.0'
> server.klass 'CIMI::API'
> + server.logger Rack::DeltacloudLogger.setup(ENV['API_LOG'],
> ENV['API_VERBOSE'])
> end
>
> Deltacloud::configure(:ec2) do |server|
> server.root_url '/'
> server.version '2012-04-01'
> server.klass 'Deltacloud::EC2::API'
> + server.logger Rack::DeltacloudLogger.setup(ENV['API_LOG'],
> ENV['API_VERBOSE'])
> end
>
> routes = {}
> diff --git a/server/lib/cimi/server.rb b/server/lib/cimi/server.rb
> index 4e612f4..0c78a2a 100644
> --- a/server/lib/cimi/server.rb
> +++ b/server/lib/cimi/server.rb
> @@ -31,7 +31,7 @@ module CIMI
> class API < Collections::Base
>
> # Enable logging
> - use Rack::CommonLogger
> + use Deltacloud[:cimi].logger
> use Rack::Date
> use Rack::ETag
> use Rack::MatrixParams
> diff --git a/server/lib/deltacloud/server.rb b/server/lib/deltacloud/server.rb
> index 32acb38..9f00ca1 100644
> --- a/server/lib/deltacloud/server.rb
> +++ b/server/lib/deltacloud/server.rb
> @@ -31,7 +31,7 @@ module Deltacloud
> class API < Collections::Base
>
> # Enable logging
> - use Rack::CommonLogger
> + use Deltacloud[:deltacloud].logger
> use Rack::Date
> use Rack::ETag
> use Rack::MatrixParams
> diff --git a/server/lib/deltacloud_rack.rb b/server/lib/deltacloud_rack.rb
> index 2c55b29..1c1301d 100644
> --- a/server/lib/deltacloud_rack.rb
> +++ b/server/lib/deltacloud_rack.rb
> @@ -22,6 +22,7 @@ unless Kernel.respond_to?(:require_relative)
> end
>
> require_relative './deltacloud/core_ext'
> +require_relative './sinatra/rack_logger'
>
> module Deltacloud
>
> @@ -50,11 +51,13 @@ module Deltacloud
> attr_reader :root_url
> attr_reader :version
> attr_reader :klass
> + attr_reader :logger
>
> def initialize(opts={}, &block)
> @root_url = opts[:root_url]
> @version = opts[:version]
> @klass = opts[:klass]
> + @logger = opts[:logger] || Rack::DeltacloudLogger
> instance_eval(&block)
> end
>
> @@ -74,6 +77,11 @@ module Deltacloud
> @klass = k
> end
>
> + def logger(logger=nil)
> + return @logger if logger.nil?
> + @logger = logger
> + end
> +
> end
>
> end
> diff --git a/server/lib/ec2/server.rb b/server/lib/ec2/server.rb
> index 52f3993..1e9e23a 100644
> --- a/server/lib/ec2/server.rb
> +++ b/server/lib/ec2/server.rb
> @@ -29,7 +29,7 @@ module Deltacloud::EC2
> extend Deltacloud::Helpers::Drivers
>
> use Rack::ETag
> - use Rack::CommonLogger
> + use Deltacloud[:ec2].logger
>
> helpers Sinatra::AuthHelper
> helpers Deltacloud::Helpers::Drivers
> diff --git a/server/lib/sinatra/rack_logger.rb
> b/server/lib/sinatra/rack_logger.rb
> new file mode 100644
> index 0000000..5056493
> --- /dev/null
> +++ b/server/lib/sinatra/rack_logger.rb
> @@ -0,0 +1,127 @@
> +# Licensed to the Apache Software Foundation (ASF) under one or more
> +# contributor license agreements. See the NOTICE file distributed with
> +# this work for additional information regarding copyright ownership. The
> +# ASF licenses this file to you 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
> +#
> +# http://www.apache.org/licenses/LICENSE-2.0
> +#
> +# Unless required by applicable law or agreed to in writing, software
> +# distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
> +# WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
> +# License for the specific language governing permissions and limitations
> +# under the License.
> +
> +require 'rack/body_proxy'
> +
> +# This module is based on Rack::CommonLogger[1]
> +# Copyright (C) 2007, 2008, 2009, 2010 Christian Neukirchen
> <purl.org/net/chneukirchen>
> +#
> +# [1] https://github.com/rack/rack/blob/master/lib/rack/commonlogger.rb
> +
> +module Rack
> + # Rack::CommonLogger forwards every request to an +app+ given, and
> + # logs a line in the Apache common log format to the +logger+, or
> + # rack.errors by default.
> + class DeltacloudLogger
> +
> + def self.log_path(path=nil)
> + @log_file ||= path
> + end
> +
> + def self.verbose?
> + @verbose
> + end
> +
> + def self.verbose(v=nil)
> + @verbose ||= v
> + end
> +
> + def self.setup(path, be_verbose=false)
> + verbose(be_verbose)
> + return self if path.nil?
> + dir = ::File.dirname(path)
> + if ::File.exists?(dir) and ::File.writable?(dir)
> + log_path(path)
> + else
> + warn "Warning: The log directory (#{dir}) is not writeable."
> + end
> + self
> + end
> +
> + # Common Log Format: http://httpd.apache.org/docs/1.3/logs.html#common
> + # lilith.local - - [07/Aug/2006 23:58:02] "GET / HTTP/1.1" 500 -
> + # %{%s - %s [%s] "%s %s%s %s" %d %s\n} %
> + FORMAT = %{%s - %s [%s] "%s %s%s %s" %d %s %0.4f\n}
> +
> + VERBOSE_FORMAT = %{%s - %s [%s] "%s %s%s%s %s" %s %s %d %s %0.4f\n}
> +
> + def initialize(app, logger=nil)
> + @app = app
> + unless self.class.log_path.nil?
> + @logger = ::Logger.new(self.class.log_path)
> + else
> + @logger = logger
> + end
> + end
> +
> + def call(env)
> + began_at = Time.now
> + status, header, body = @app.call(env)
> + header = Utils::HeaderHash.new(header)
> + body = BodyProxy.new(body) do
> + self.class.verbose? ? verbose_log(env, status, header, began_at) :
> log(env, status, header, began_at)
> + end
> + [status, header, body]
> + end
> +
> + private
> +
> + def verbose_log(env, status, header, began_at)
> + now = Time.now
> + length = extract_content_length(header)
> + params = env['rack.request.form_hash'].nil? ? '' : '
> '+env['rack.request.form_hash'].to_json
> +
> + logger = @logger || env['rack.errors']
> + logger << VERBOSE_FORMAT % [
> + env['HTTP_X_FORWARDED_FOR'] || env["REMOTE_ADDR"] || "-",
> + env["REMOTE_USER"] || "-",
> + now.strftime("%d/%b/%Y %H:%M:%S"),
> + env["REQUEST_METHOD"],
> + env["PATH_INFO"],
> + env["QUERY_STRING"].empty? ? '' : "?"+env["QUERY_STRING"],
> + params,
> + env["HTTP_VERSION"],
> + env['HTTP_X_DELTACLOUD_DRIVER'] || ENV['API_DRIVER'] || 'mock',
> + env['HTTP_X_DELTACLOUD_PROVIDER'] || ENV['API_PROVIDER'] || '-',
> + status.to_s[0..3],
> + length,
> + now - began_at ]
> + end
> +
> + def log(env, status, header, began_at)
> + now = Time.now
> + length = extract_content_length(header)
> +
> + logger = @logger || env['rack.errors']
> + logger << FORMAT % [
> + env['HTTP_X_FORWARDED_FOR'] || env["REMOTE_ADDR"] || "-",
> + env["REMOTE_USER"] || "-",
> + now.strftime("%d/%b/%Y %H:%M:%S"),
> + env["REQUEST_METHOD"],
> + env["PATH_INFO"],
> + env["QUERY_STRING"].empty? ? "" : "?"+env["QUERY_STRING"],
> + env["HTTP_VERSION"],
> + status.to_s[0..3],
> + length,
> + now - began_at ]
> + end
> +
> + def extract_content_length(headers)
> + value = headers['Content-Length'] or return '-'
> + value.to_s == '0' ? '-' : value
> + end
> + end
> +end
> +
> --
> 1.7.10.2
>