diff options
| -rw-r--r-- | .olddoc.yml | 21 | ||||
| -rwxr-xr-x | GIT-VERSION-GEN | 2 | ||||
| -rw-r--r-- | GNUmakefile | 2 | ||||
| -rw-r--r-- | README | 46 | ||||
| -rw-r--r-- | archive/rfmig.rb | 32 | ||||
| -rw-r--r-- | clogger.gemspec | 11 | ||||
| -rw-r--r-- | ext/clogger_ext/clogger.c | 96 | ||||
| -rw-r--r-- | lib/clogger.rb | 11 | ||||
| -rw-r--r-- | lib/clogger/pure.rb | 31 | ||||
| -rw-r--r-- | pkg.mk | 5 | ||||
| -rw-r--r-- | test/test_clogger.rb | 102 | ||||
| -rw-r--r-- | test/test_clogger_to_path.rb | 14 |
12 files changed, 248 insertions, 125 deletions
diff --git a/.olddoc.yml b/.olddoc.yml index fd7b52d..2ed15c3 100644 --- a/.olddoc.yml +++ b/.olddoc.yml @@ -1,12 +1,15 @@ --- -rdoc_url: https://bogomips.org/clogger/ -cgit_url: https://bogomips.org/clogger.git -git_url: git://bogomips.org/clogger.git -public_email: clogger-public@bogomips.org +rdoc_url: https://YHBT.net/clogger/ +cgit_url: https://YHBT.net/clogger.git +git_url: https://YHBT.net/clogger.git +public_email: clogger-public@YHBT.net ml_url: -- https://bogomips.org/clogger-public/ -- http://ou63pmih66umazou.onion/clogger-public/ -- nntp://news.public-inbox.org/inbox.comp.lang.ruby.clogger +- https://YHBT.net/clogger-public/ +- http://7fh6tueqddpjyxjmgtdiueylzoqt6pt7hec3pukyptlmohoowvhde4yd.onion/clogger-public/ +- imaps://YHBT.net/inbox.comp.lang.ruby.clogger.0 +- imap://7fh6tueqddpjyxjmgtdiueylzoqt6pt7hec3pukyptlmohoowvhde4yd.onion/inbox.comp.lang.ruby.clogger.0 +- nntps://news.public-inbox.org/inbox.comp.lang.ruby.clogger +- nntp://7fh6tueqddpjyxjmgtdiueylzoqt6pt7hec3pukyptlmohoowvhde4yd.onion/inbox.comp.lang.ruby.clogger source_code: -- git clone git://bogomips.org/clogger.git -- git clone https://bogomips.org/clogger.git +- git clone https://YHBT.net/clogger.git +- torsocks git clone http://7fh6tueqddpjyxjmgtdiueylzoqt6pt7hec3pukyptlmohoowvhde4yd.onion/clogger.git diff --git a/GIT-VERSION-GEN b/GIT-VERSION-GEN index 49932c7..8fc5dc1 100755 --- a/GIT-VERSION-GEN +++ b/GIT-VERSION-GEN @@ -1,7 +1,7 @@ #!/bin/sh GVF=GIT-VERSION-FILE -DEF_VER=v2.1.0 +DEF_VER=v2.4.0 LF=' ' diff --git a/GNUmakefile b/GNUmakefile index ab8b4fe..b75e10c 100644 --- a/GNUmakefile +++ b/GNUmakefile @@ -1,5 +1,5 @@ all:: -RSYNC_DEST := bogomips.org:/srv/bogomips/clogger/ +RSYNC_DEST := YHBT.net:/srv/yhbt/clogger/ rfpackage := clogger include pkg.mk test-ext: @@ -69,10 +69,12 @@ that receives a "<<" method: * $request_uri - the URI requested ($path_info?$query_string) * $request - the first line of the HTTP request ($request_method $request_uri $http_version) -* $request_time, $request_time{PRECISION} - time taken for request - (including response body iteration). PRECISION defaults to 3 - (milliseconds) if not specified but may be specified anywhere from - 0(seconds) to 6(microseconds). +* $request_time, $request_time{PRECISION}, $request_time{POWER,PRECISION} - + time taken for request (including response body iteration). PRECISION + defaults to 3 (milliseconds) if not specified but may be specified + anywhere from 0(seconds) to 6(microseconds). POWER will raise the time to + the provided power of 10, useful for converting to micro- or nanoseconds. + POWER defaults to 0 if not specified but may be specified any from 0 to 9 * $time_iso8601 - current local time in ISO 8601 format, e.g. "1970-01-01T00:00:00+00:00" * $time_local - current local time in Apache log format, @@ -87,7 +89,7 @@ that receives a "<<" method: * $ip - X-Forwarded-For request header if available, $remote_addr if not * $pid - process ID of the current process * $e{Thread.current} - Thread processing the request -* $e{Actor.current} - Actor processing the request (Revactor or Rubinius) +* $e{Fiber.current} - Fiber processing the request * $env{variable_name} - any Rack environment variable (e.g. rack.url_scheme) == REQUIREMENTS @@ -98,28 +100,40 @@ that receives a "<<" method: The latest development happens in git and is published to the following: - git clone git://bogomips.org/clogger.git - git clone git://repo.or.cz/clogger.git + git clone https://YHBT.net/clogger.git + git clone https://repo.or.cz/clogger.git You may also browse and download snapshot tarballs: -* https://bogomips.org/clogger.git -* http://repo.or.cz/w/clogger.git (gitweb) +* https://YHBT.net/clogger.git +* https://repo.or.cz/w/clogger.git (gitweb) -The mailing list (see below) is central for coordination and -development. Patches should always be sent inline -(git format-patch -M + git send-email) so we can reply to them inline. +We use email for coordination and development, see below: == CONTACT All feedback (bug reports, user/development discussion, patches, pull -requests) go to the public mailing list. +requests) is done via publicly-archived email: -* mailto:clogger-public@bogomips.org +* https://YHBT.net/clogger-public/ +* imaps://YHBT.net/inbox.comp.lang.ruby.clogger.0 +* nntps://news.public-inbox.org/inbox.comp.lang.ruby.clogger -Do not send HTML mail or attachments. Do not top post. +Tor users may also access HTTP, IMAP, and NNTP archives via .onion: -Homepage: https://bogomips.org/clogger/ +* http://7fh6tueqddpjyxjmgtdiueylzoqt6pt7hec3pukyptlmohoowvhde4yd.onion/clogger-public/ +* imap://7fh6tueqddpjyxjmgtdiueylzoqt6pt7hec3pukyptlmohoowvhde4yd.onion/inbox.comp.lang.ruby.clogger.0 +* nntp://7fh6tueqddpjyxjmgtdiueylzoqt6pt7hec3pukyptlmohoowvhde4yd.onion/inbox.comp.lang.ruby.clogger + +AUTH=ANONYMOUS is supported for IMAP and IMAPS, and any +username + password will work. + +No subscription or real names will ever be required to email us. +Do not send HTML email, do not top post. + +* mailto:clogger-public@YHBT.net + +Homepage: https://YHBT.net/clogger/ == INSTALL diff --git a/archive/rfmig.rb b/archive/rfmig.rb deleted file mode 100644 index 033051a..0000000 --- a/archive/rfmig.rb +++ /dev/null @@ -1,32 +0,0 @@ -#!/usr/bin/env ruby -require 'find' -require 'fileutils' -rfdir = 'rubyforge.org:/var/www/gforge-projects/clogger/' -newbase = 'http://clogger.bogomips.org/' -refresh = '<meta http-equiv="refresh" content="0; url=%s" />' -old = 'rf.old' -new = 'rf.new' -cmd = %W(rsync -av #{rfdir} #{old}/) -unless File.directory?(old) - system(*cmd) or abort "#{cmd.inspect} failed: #$?" -end - -Find.find(old) do |path| - path =~ /\.html\z/ or next - data = File.read(path) - tmp = path.split(%r{/}) - tmp.shift == old or abort "BUG" - dst = "#{new}/#{tmp.join('/')}" - - tmp[-1] = '' if tmp[-1] == "index.html" - url = "#{newbase}#{tmp.join('/')}" - meta = sprintf(refresh, url) - data.sub!(/(<head[^>]*>)/i, "#$1#{meta}") - data.sub!(/(<body[^>]*>)/i, - "#{$1}Redirecting to <a href=\"#{url}\">#{url}</a> ...<br/>") - FileUtils.mkdir_p(File.dirname(dst)) - File.open(dst, "w") { |fp| fp.write(data) } -end - -print "Verify results in #{new}/, then run:\n " -puts %W(rsync -av #{new}/ #{rfdir}).join(' ') diff --git a/clogger.gemspec b/clogger.gemspec index ebc0baf..7a08dc5 100644 --- a/clogger.gemspec +++ b/clogger.gemspec @@ -3,12 +3,12 @@ manifest = File.exist?('.manifest') ? Gem::Specification.new do |s| s.name = %q{clogger} - s.version = (ENV['VERSION'] || '2.1.0').dup - s.homepage = 'https://bogomips.org/clogger/' + s.version = (ENV['VERSION'] || '2.4.0').dup + s.homepage = 'https://YHBT.net/clogger/' s.authors = ["cloggers"] s.summary = 'configurable request logging for Rack' s.description = File.read('README').split("\n\n")[1] - s.email = %q{clogger-public@bogomips.org} + s.email = %q{clogger-public@YHBT.net} s.extra_rdoc_files = IO.readlines('.document').map!(&:chomp!).keep_if do |f| File.exist?(f) end @@ -16,8 +16,9 @@ Gem::Specification.new do |s| s.test_files = %w(test/test_clogger.rb test/test_clogger_to_path.rb) # HeaderHash wasn't case-insensitive in old versions - s.add_dependency(%q<rack>, ['>= 1.0', '< 3.0']) + s.add_dependency(%q<rack>, ['>= 1.0', '< 4.0']) s.add_development_dependency('test-unit', '~> 3.0') + s.add_development_dependency('rackup', '~> 2.0') s.extensions = %w(ext/clogger_ext/extconf.rb) - s.licenses = %w(LGPL-2.1+) + s.licenses = %w(LGPL-2.1-or-later) end diff --git a/ext/clogger_ext/clogger.c b/ext/clogger_ext/clogger.c index fdc23e3..cea4072 100644 --- a/ext/clogger_ext/clogger.c +++ b/ext/clogger_ext/clogger.c @@ -1,3 +1,6 @@ +/* quiet deprecation for _BSD_SOURCE and _SVID_SOURCE: */ +#define _DEFAULT_SOURCE 1 + #include <ruby.h> #ifdef HAVE_RUBY_IO_H # include <ruby/io.h> @@ -14,7 +17,7 @@ # include <fcntl.h> #endif #ifndef _POSIX_C_SOURCE -# define _POSIX_C_SOURCE 200112L +# define _POSIX_C_SOURCE 200809L #endif #include <time.h> #include <stdlib.h> @@ -133,7 +136,7 @@ static ID to_path_id; static ID respond_to_id; static VALUE cClogger; static VALUE mFormat; -static VALUE cHeaderHash; +static VALUE cRackHeaders; /* common hash lookup keys */ static VALUE g_HTTP_X_FORWARDED_FOR; @@ -169,6 +172,10 @@ static VALUE byte_xs(VALUE obj) { static const char esc[] = "0123456789ABCDEF"; unsigned char *new_ptr; + if (rb_obj_is_kind_of(obj, rb_cArray)) { + // Rack 3 + obj = rb_ary_join(obj, rb_str_new2("\n")); + } VALUE from = rb_obj_as_string(obj); const unsigned char *ptr = (const unsigned char *)RSTRING_PTR(from); long len = RSTRING_LEN(from); @@ -222,18 +229,28 @@ static void clogger_mark(void *ptr) rb_gc_mark(c->body); } +static size_t memsize(const void *ptr) +{ + return sizeof(struct clogger); +} + +static const rb_data_type_t clogger_type = { + "clogger", + { clogger_mark, RUBY_TYPED_DEFAULT_FREE, memsize, /* reserved */ }, +}; + static VALUE clogger_alloc(VALUE klass) { struct clogger *c; - return Data_Make_Struct(klass, struct clogger, clogger_mark, -1, c); + return TypedData_Make_Struct(klass, struct clogger, &clogger_type, c); } static struct clogger *clogger_get(VALUE self) { struct clogger *c; - Data_Get_Struct(self, struct clogger, c); + TypedData_Get_Struct(self, struct clogger, &clogger_type, c); assert(c); return c; } @@ -374,12 +391,39 @@ static void append_ts(struct clogger *c, VALUE op, struct timespec *ts) rb_str_buf_cat(c->log_buf, buf, nr); } +#define NANO_PER_SEC (1000 * 1000 * 1000) static void append_request_time_fmt(struct clogger *c, VALUE op) { struct timespec now; + unsigned long ipow = NUM2ULONG(rb_ary_entry(op, 3)); clock_gettime(hopefully_CLOCK_MONOTONIC, &now); clock_diff(&now, &c->ts_start); + if (ipow) { + unsigned long adj = 1; + int64_t now_sec = now.tv_sec, now_nsec = now.tv_nsec, + prev_sec = now.tv_sec; + + do { adj *= 10; } while (--ipow); + now_sec *= adj; + now_nsec *= adj; + if (now_nsec >= NANO_PER_SEC) { + int64_t add = now_nsec / NANO_PER_SEC; + now_sec += add; + now_nsec %= NANO_PER_SEC; + } + if (now_sec < prev_sec) { /* overflowed */ + now_nsec = NANO_PER_SEC - 1; + /* + * some platforms may use unsigned .tv_sec, but + * they're not worth supporting, so keep unsigned: + */ + now_sec = (time_t)(sizeof(now.tv_sec) == 4 ? + INT_MAX : LONG_MAX); + } + now.tv_sec = now_sec; + now.tv_nsec = now_nsec; + } append_ts(c, op, &now); } @@ -416,10 +460,11 @@ static void append_request(struct clogger *c) { VALUE tmp; - /* REQUEST_METHOD doesn't need escaping, Rack::Lint governs it */ tmp = rb_hash_aref(c->env, g_REQUEST_METHOD); - if (!NIL_P(tmp)) + if (!NIL_P(tmp)) { + tmp = byte_xs(tmp); rb_str_buf_append(c->log_buf, tmp); + } rb_str_buf_append(c->log_buf, g_space); @@ -444,9 +489,21 @@ static void append_request_length(struct clogger *c) } } +/* + * time(2) may slip backwards, so use CLOCK_REALTIME for accuracy + * https://lore.kernel.org/git/20230319064353.686226-3-eggert@cs.ucla.edu/T/ + */ +static time_t cur_time(void) +{ + struct timespec now; + + (void)clock_gettime(CLOCK_REALTIME, &now); + return now.tv_sec; +} + static long local_gmtoffset(struct tm *tm) { - time_t t = time(NULL); + time_t t = cur_time(); tzset(); localtime_r(&t, tm); @@ -506,7 +563,7 @@ static void append_time_utc(struct clogger *c) char buf[sizeof("01/Jan/1970:00:00:00 +0000")]; struct tm tm; int nr; - time_t t = time(NULL); + time_t t = cur_time(); gmtime_r(&t, &tm); nr = snprintf(buf, sizeof(buf), @@ -525,7 +582,7 @@ append_time(struct clogger *c, enum clogger_opcode op, VALUE fmt, VALUE buf) size_t buf_size = RSTRING_LEN(buf) + 1; /* "\0" */ size_t nr; struct tm tmp; - time_t t = time(NULL); + time_t t = cur_time(); if (op == CL_OP_TIME_LOCAL) localtime_r(&t, &tmp); @@ -585,7 +642,8 @@ static void append_response(struct clogger *c, VALUE key) { VALUE v; - assert(rb_obj_is_kind_of(c->headers, cHeaderHash) && "not HeaderHash"); + assert(rb_obj_is_kind_of(c->headers, cRackHeaders) + && "not Rack::Headers"); v = rb_funcall(c->headers, sq_brace_id, 1, key); v = NIL_P(v) ? g_dash : byte_xs(v); @@ -857,10 +915,9 @@ static VALUE ccall(struct clogger *c, VALUE env) rv = rb_ary_dup(rv); if (c->need_resp && - ! rb_obj_is_kind_of(c->headers, cHeaderHash)) { - c->headers = rb_funcall(cHeaderHash, new_id, 1, - c->headers); - rb_ary_store(rv, 1, c->headers); + ! rb_obj_is_kind_of(c->headers, cRackHeaders)) { + c->headers = rb_funcall(cRackHeaders, sq_brace_id, + 1, c->headers); } } else { VALUE tmp = rb_inspect(rv); @@ -1071,8 +1128,15 @@ void Init_clogger_ext(void) CONST_GLOBAL_STR2(rack_request_cookie_hash, "rack.request.cookie_hash"); tmp = rb_const_get(rb_cObject, rb_intern("Rack")); - tmp = rb_const_get(tmp, rb_intern("Utils")); - cHeaderHash = rb_const_get(tmp, rb_intern("HeaderHash")); + if (rb_const_defined(tmp, rb_intern("Headers"))) { + // Rack >= 3.0 + cRackHeaders = rb_const_get(tmp, rb_intern("Headers")); + } else { + // Rack < 3.0 + tmp = rb_const_get(tmp, rb_intern("Utils")); + cRackHeaders = rb_const_get(tmp, rb_intern("HeaderHash")); + } + rb_ary_push(mark_ary, cRackHeaders); rb_obj_freeze(mark_ary); } diff --git a/lib/clogger.rb b/lib/clogger.rb index be1bdce..7ce2b24 100644 --- a/lib/clogger.rb +++ b/lib/clogger.rb @@ -51,7 +51,7 @@ private SCAN = /([^$]*)(\$+(?:env\{\w+(?:\.[\w\.]+)?\}| e\{[^\}]+\}| - (?:request_)?time\{\d+\}| + (?:request_)?time\{\d+(?:,\d+)?\}| time_(?:utc|local)\{[^\}]+\}| \w*))?([^$]*)/x @@ -92,7 +92,14 @@ private when /\A\$time\{(\d+)\}\z/ rv << [ OP_TIME, *usec_conv_pair(tok, $1.to_i) ] when /\A\$request_time\{(\d+)\}\z/ - rv << [ OP_REQUEST_TIME, *usec_conv_pair(tok, $1.to_i) ] + rv << [ OP_REQUEST_TIME, *usec_conv_pair(tok, $1.to_i), 0 ] + when /\A\$request_time\{(\d+),(\d+)\}\z/ + ipow = $1.to_i + prec = $2.to_i + if ipow > 9 # nanosecond precision is the highest POSIX goes + raise ArgumentError, "#{tok}: too big: #{ipow} (max=9)" + end + rv << [ OP_REQUEST_TIME, *usec_conv_pair(tok, prec), ipow ] else tok_sym = tok[1..-1].to_sym if special_code = SPECIAL_VARS[tok_sym] diff --git a/lib/clogger/pure.rb b/lib/clogger/pure.rb index fddfe79..156f11e 100644 --- a/lib/clogger/pure.rb +++ b/lib/clogger/pure.rb @@ -8,10 +8,15 @@ class Clogger attr_accessor :env, :status, :headers, :body attr_writer :body_bytes_sent, :start - def initialize(app, opts = {}) - # trigger autoload to avoid thread-safety issues later on + RackHeaders = if Object.const_defined?("Rack::Headers") + # Rack >= 3.0 + Rack::Headers + else + # Rack < 3.0 Rack::Utils::HeaderHash + end + def initialize(app, opts = {}) @app = app @logger = opts[:logger] path = opts[:path] @@ -35,7 +40,7 @@ class Clogger raise TypeError, "app response not a 3 element Array: #{resp.inspect}" end status, headers, body = resp - headers = Rack::Utils::HeaderHash.new(headers) if @need_resp + headers = RackHeaders[headers] if @need_resp if @wrap_body @reentrant = env['rack.multithread'] if @reentrant.nil? wbody = @reentrant ? self.dup : self @@ -91,6 +96,9 @@ private def byte_xs(s) s = s.dup + if s.is_a?(Array) + s = s.join("\n") + end s.force_encoding(Encoding::BINARY) if defined?(Encoding::BINARY) s.gsub!(/(['"\x00-\x1f\x7f-\xff])/) do |x| "\\x#{$1.unpack('H2').first.upcase}" @@ -118,8 +126,7 @@ private version = env['HTTP_VERSION'] and version = " #{byte_xs(version)}" qs = env['QUERY_STRING'] qs.empty? or qs = "?#{byte_xs(qs)}" - "#{env['REQUEST_METHOD']} " \ - "#{request_uri(env)}#{version}" + "#{byte_xs(env['REQUEST_METHOD'] || '')} #{request_uri(env)}#{version}" when :request_uri request_uri(env) when :request_length @@ -134,17 +141,10 @@ private when :time_iso8601 Time.now.iso8601 when :time_local - t = Time.now - off = t.utc_offset - sign = off < 0 ? '-' : '+' - sprintf("%02d/%s/%d:%02d:%02d:%02d #{sign}%02d%02d", - t.mday, Time::RFC2822_MONTH_NAME[t.mon - 1], - t.year, t.hour, t.min, t.sec, *(off.abs / 60).divmod(60)) + # %b in Ruby is locale-independent, unlike strftime(3) in C + Time.now.strftime('%d/%b/%Y:%H:%M:%S %z') when :time_utc - t = Time.now.utc - sprintf("%02d/%s/%d:%02d:%02d:%02d +0000", - t.mday, Time::RFC2822_MONTH_NAME[t.mon - 1], - t.year, t.hour, t.min, t.sec) + Time.now.utc.strftime('%d/%b/%Y:%H:%M:%S %z') else raise "EDOOFUS #{special_nr}" end @@ -166,6 +166,7 @@ private when OP_TIME_UTC; Time.now.utc.strftime(op[1]) when OP_REQUEST_TIME t = mono_now - start + t = t * (10 ** op[3]) time_format(t.to_i, (t - t.to_i) * 1000000, op[1], op[2]) when OP_TIME t = Time.now @@ -60,7 +60,7 @@ doc:: .document .olddoc.yml $(pkg_extra) $(PLACEHOLDERS) -find lib -type f -name '*.rbc' -exec rm -f '{}' ';' -find ext -type f -name '*.rbc' -exec rm -f '{}' ';' $(RM) -r doc - $(RDOC) -f oldweb + $(RDOC) -f dark216 $(OLDDOC) merge install -m644 COPYING doc/COPYING install -m644 NEWS doc/NEWS @@ -127,7 +127,8 @@ publish_doc: -git set-file-times $(MAKE) doc $(MAKE) doc_gz - $(RSYNC) -av doc/ $(RSYNC_DEST)/ + $(RSYNC) -av doc/ $(RSYNC_DEST)/ \ + --exclude index.html* --exclude created.rid* git ls-files | xargs touch endif diff --git a/test/test_clogger.rb b/test/test_clogger.rb index ca3bd55..5646025 100644 --- a/test/test_clogger.rb +++ b/test/test_clogger.rb @@ -10,6 +10,16 @@ require "rack" require "clogger" +IS_RACK3 = Gem::Version.new(Rack.release) >= Gem::Version.new('3.0.0') + +RackHeaders = if Object.const_defined?("Rack::Headers") + # Rack >= 3.0 + Rack::Headers +else + # Rack < 3.0 + Rack::Utils::HeaderHash +end + # used to test subclasses class FooString < String end @@ -22,6 +32,7 @@ class TestClogger < Test::Unit::TestCase @nginx_fmt = "%d/%b/%Y:%H:%M:%S %z" @req = { "REQUEST_METHOD" => "GET", + "SERVER_PROTOCOL" => "HTTP/1.0", "HTTP_VERSION" => "HTTP/1.0", "HTTP_USER_AGENT" => 'echo and socat \o/', "PATH_INFO" => "/hello", @@ -85,13 +96,13 @@ class TestClogger < Test::Unit::TestCase def test_clen_stringio start = DateTime.now - 1 str = StringIO.new - app = lambda { |env| [ 301, {'Content-Length' => '5'}, ['abcde'] ] } + app = lambda { |env| [ 301, {'content-length' => '5'}, ['abcde'] ] } format = Common.dup assert format.gsub!(/response_length/, 'sent_http_content_length') cl = Clogger.new(app, :logger => str, :format => format) status, headers, body = cl.call(@req) assert_equal(301, status) - assert_equal({'Content-Length' => '5'}, headers) + assert_equal({'content-length' => '5'}, headers) body.each { |part| assert_equal('abcde', part) } str = str.string r = %r{\Ahome - - \[[^\]]+\] "GET /hello\?goodbye=true HTTP/1.0" 301 5\n\z} @@ -167,10 +178,11 @@ class TestClogger < Test::Unit::TestCase ary = compile_format( '$remote_addr - $remote_user [$time_local] ' \ '"$request" $status $body_bytes_sent "$http_referer" ' \ - '"$http_user_agent" "$http_cookie" $request_time ' \ + '"$http_user_agent" "$http_cookie" $request_time $request_time{6,0} ' \ '$env{rack.url_scheme}' \ "\n") } + expect = [ [ Clogger::OP_REQUEST, "REMOTE_ADDR" ], [ Clogger::OP_LITERAL, " - " ], @@ -190,7 +202,9 @@ class TestClogger < Test::Unit::TestCase [ Clogger::OP_LITERAL, "\" \"" ], [ Clogger::OP_REQUEST, "HTTP_COOKIE" ], [ Clogger::OP_LITERAL, "\" " ], - [ Clogger::OP_REQUEST_TIME, '%d.%03d', 1000 ], + [ Clogger::OP_REQUEST_TIME, '%d.%03d', 1000, 0], + [ Clogger::OP_LITERAL, " " ], + [ Clogger::OP_REQUEST_TIME, '%d', 1, 6], [ Clogger::OP_LITERAL, " " ], [ Clogger::OP_REQUEST, "rack.url_scheme" ], [ Clogger::OP_LITERAL, "\n" ], @@ -209,6 +223,22 @@ class TestClogger < Test::Unit::TestCase assert_equal "-#{current}-\n", str.string end + def test_fiber + begin + current = Fiber.current.to_s + rescue NameError => e + warn "your Ruby does not support fibers #{e}" + return + end + str = StringIO.new + app = lambda { |env| [ 302, {}, [] ] } + cl = Clogger.new(app, + :logger => str, + :format => "-$e{Fiber.current}-\n") + status, headers, body = cl.call(@req) + assert_equal "-#{current}-\n", str.string + end + def test_pid str = StringIO.new app = lambda { |env| [ 302, {}, [] ] } @@ -234,7 +264,7 @@ class TestClogger < Test::Unit::TestCase def test_rack_1_0 start = DateTime.now - 1 str = StringIO.new - app = lambda { |env| [ 200, {'Content-Length'=>'0'}, %w(a b c)] } + app = lambda { |env| [ 200, {'content-length'=>'0'}, %w(a b c)] } cl = Clogger.new(app, :logger => str, :format => Rack_1_0) status, headers, body = cl.call(@req) tmp = [] @@ -325,7 +355,7 @@ class TestClogger < Test::Unit::TestCase def test_combined start = DateTime.now - 1 str = StringIO.new - app = lambda { |env| [ 200, {'Content-Length'=>'3'}, %w(a b c)] } + app = lambda { |env| [ 200, {'content-length'=>'3'}, %w(a b c)] } cl = Clogger.new(app, :logger => str, :format => Combined) status, headers, body = cl.call(@req) tmp = [] @@ -346,7 +376,7 @@ class TestClogger < Test::Unit::TestCase def test_rack_errors_fallback err = StringIO.new - app = lambda { |env| [ 200, {'Content-Length'=>'3'}, %w(a b c)] } + app = lambda { |env| [ 200, {'content-length'=>'3'}, %w(a b c)] } cl = Clogger.new(app, :format => '$pid') req = @req.merge('rack.errors' => err) status, headers, body = cl.call(req) @@ -355,7 +385,7 @@ class TestClogger < Test::Unit::TestCase def test_body_close s_body = StringIO.new(%w(a b c).join("\n")) - app = lambda { |env| [ 200, {'Content-Length'=>'5'}, s_body] } + app = lambda { |env| [ 200, {'content-length'=>'5'}, s_body] } cl = Clogger.new(app, :logger => [], :format => '$pid') status, headers, body = cl.call(@req) assert ! s_body.closed? @@ -365,7 +395,7 @@ class TestClogger < Test::Unit::TestCase def test_escape str = StringIO.new - app = lambda { |env| [ 200, {'Content-Length'=>'5'}, [] ] } + app = lambda { |env| [ 200, {'content-length'=>'5'}, [] ] } cl = Clogger.new(app, :logger => str, :format => '$http_user_agent "$request"') @@ -379,13 +409,21 @@ class TestClogger < Test::Unit::TestCase assert_equal expect, str.string end - # rack allows repeated headers with "\n": - # { 'Set-Cookie' => "a\nb" } => - # Set-Cookie: a - # Set-Cookie: b - def test_escape_header_newlines - str = StringIO.new - app = lambda { |env| [302, { 'Set-Cookie' => "a\nb" }, [] ] } + # rack >= 3 allows repeated headers with array: + # { 'set-cookie' => ["a","b"] } => + # set-cookie: a + # set-cookie: b + # rack < 3 allows repeated headers with "\n": + # { 'set-cookie' => "a\nb" } => + # set-cookie: a + # set-cookie: b + def test_multiheader + str = StringIO.new + if IS_RACK3 then + app = lambda { |env| [302, { 'set-cookie' => ["a","b"] }, [] ] } + else + app = lambda { |env| [302, { 'set-cookie' => "a\nb" }, [] ] } + end cl = Clogger.new(app, :logger => str, :format => '$sent_http_set_cookie') cl.call(@req) assert_equal "a\\x0Ab\n", str.string @@ -444,12 +482,16 @@ class TestClogger < Test::Unit::TestCase str = StringIO.new app = lambda { |env| [302, [ %w(a) ], []] } cl = Clogger.new(app, :logger => str, :format => '$sent_http_set_cookie') - assert_nothing_raised { cl.call(@req) } + if IS_RACK3 then + assert_raise(ArgumentError) { cl.call(@req) } + else + assert_nothing_raised { cl.call(@req) } + end end def test_subclass_hash str = StringIO.new - req = Rack::Utils::HeaderHash.new(@req) + req = RackHeaders[@req] app = lambda { |env| [302, [ %w(a) ], []] } cl = Clogger.new(app, :logger => str, :format => Rack_1_0) assert_nothing_raised { cl.call(req).last.each {}.close } @@ -721,6 +763,24 @@ class TestClogger < Test::Unit::TestCase assert s[-1].to_f <= 0.110 end + def test_request_time_with_multiplier + s = [] + app = lambda { |env| sleep(0.1) ; [302, [], [] ] } + cl = Clogger.new(app, :logger => s, :format => "$request_time{9,0}") + status, headers, body = cl.call(@req) + assert_nothing_raised { body.each { |x| } ; body.close } + assert s[-1].to_f >= 100000000 + assert s[-1].to_f <= 300000000 + end + + def test_request_time_with_invalid_multiplier + s = [] + app = lambda { |env| sleep(0.1) ; [302, [], [] ] } + assert_raise(ArgumentError) { + cl = Clogger.new(app, :logger => s, :format => "$request_time{10,0}") + } + end + def test_insanely_long_time_format s = [] app = lambda { |env| [200, [], [] ] } @@ -840,19 +900,21 @@ class TestClogger < Test::Unit::TestCase end def test_lint_error_wrapper - require 'rack/lobster' + require 'rackup/lobster' @req["SERVER_NAME"] = "FOO" @req["SERVER_PORT"] = "666" @req["rack.version"] = [1,1] @req["rack.multithread"] = true @req["rack.multiprocess"] = true @req["rack.run_once"] = false - app = Rack::ContentLength.new(Rack::ContentType.new(Rack::Lobster.new)) + app = Rack::ContentLength.new(Rack::ContentType.new(Rackup::Lobster.new)) cl = Clogger.new(app, :format => :Combined) @req["rack.errors"] = err = StringIO.new status, headers, body = r = Rack::Lint.new(cl).call(@req) body.each { |x| assert_kind_of String, x.to_str } body.close # might raise here assert_match(%r{GET /hello}, err.string) + rescue LoadError, Gem::ConflictError + # This test only works on Rack >= 3.0 end end diff --git a/test/test_clogger_to_path.rb b/test/test_clogger_to_path.rb index f74b991..4cc1738 100644 --- a/test/test_clogger_to_path.rb +++ b/test/test_clogger_to_path.rb @@ -3,6 +3,7 @@ $stderr.sync = $stdout.sync = true require "test/unit" require "date" require "stringio" +require "tempfile" require "rack" require "clogger" @@ -26,6 +27,7 @@ class TestCloggerToPath < Test::Unit::TestCase @req = { "REQUEST_METHOD" => "GET", "HTTP_VERSION" => "HTTP/1.0", + "SERVER_PROTOCOL" => "HTTP/1.0", "HTTP_USER_AGENT" => 'echo and socat \o/', "PATH_INFO" => "/", "QUERY_STRING" => "", @@ -50,8 +52,8 @@ class TestCloggerToPath < Test::Unit::TestCase app = Rack::Builder.new do tmp.syswrite(' ' * 365) h = { - 'Content-Length' => '0', - 'Content-Type' => 'text/plain', + 'content-length' => '0', + 'content-type' => 'text/plain', } use Clogger, :logger => logger, @@ -82,8 +84,8 @@ class TestCloggerToPath < Test::Unit::TestCase app = Rack::Builder.new do tmp.syswrite(' ' * 365) h = { - 'Content-Length' => '0', - 'Content-Type' => 'text/plain', + 'content-length' => '0', + 'content-type' => 'text/plain', } use Clogger, :logger => logger, @@ -106,8 +108,8 @@ class TestCloggerToPath < Test::Unit::TestCase logger = StringIO.new app = Rack::Builder.new do h = { - 'Content-Length' => '3', - 'Content-Type' => 'text/plain', + 'content-length' => '3', + 'content-type' => 'text/plain', } use Clogger, :logger => logger, |