From ab15a702a68baff5dc8434f5e0868e8df4724ae5 Mon Sep 17 00:00:00 2001 From: Yoann Lecuyer Date: Mon, 10 Jun 2019 22:22:16 +0200 Subject: [PATCH 01/11] Allow to define a custom formatter for logs --- History.md | 1 + lib/puma/dsl.rb | 4 ++++ lib/puma/events.rb | 10 ++++++++++ lib/puma/launcher.rb | 10 ++++++---- test/test_events.rb | 2 +- 5 files changed, 22 insertions(+), 5 deletions(-) diff --git a/History.md b/History.md index 059bf12006..18b0af221c 100644 --- a/History.md +++ b/History.md @@ -8,6 +8,7 @@ * Min worker timeout (#1716) * Add option to suppress SignalException on SIGTERM (#1690) * Allow mutual TLS CA to be set using `ssl_bind` DSL (#1689) + * Add log_formatter configuration * x bugfixes * Do not accept new requests on shutdown (#1685) * Fix 3 corner cases when request body is chunked (#1508) diff --git a/lib/puma/dsl.rb b/lib/puma/dsl.rb index c6dcd31f64..f5ab4ae519 100644 --- a/lib/puma/dsl.rb +++ b/lib/puma/dsl.rb @@ -282,6 +282,10 @@ def stdout_redirect(stdout=nil, stderr=nil, append=false) @options[:redirect_append] = append end + def log_formatter(&block) + @options[:log_formatter] = block + end + # Configure +min+ to be the minimum number of threads to use to answer # requests and +max+ the maximum. # diff --git a/lib/puma/events.rb b/lib/puma/events.rb index 721cb64ad6..04308e2fa2 100644 --- a/lib/puma/events.rb +++ b/lib/puma/events.rb @@ -23,6 +23,16 @@ def call(str) end end + class CustomFormatter + def initialize(formatter) + @formatter = formatter + end + + def call(str) + @formatter.call(str) + end + end + include Const # Create an Events object that prints to +stdout+ and +stderr+. diff --git a/lib/puma/launcher.rb b/lib/puma/launcher.rb index b06558a8fb..cd00e2376c 100644 --- a/lib/puma/launcher.rb +++ b/lib/puma/launcher.rb @@ -50,9 +50,6 @@ def initialize(conf, launcher_args={}) @original_argv = @argv.dup @config = conf - @binder = Binder.new(@events) - @binder.import_from_env - @environment = conf.environment # Advertise the Configuration @@ -63,6 +60,11 @@ def initialize(conf, launcher_args={}) @options = @config.options @config.clamp + @events.formatter = Events::CustomFormatter.new(@options[:log_formatter]) if @options[:log_formatter] + + @binder = Binder.new(@events) + @binder.import_from_env + generate_restart_data if clustered? && !Process.respond_to?(:fork) @@ -81,7 +83,7 @@ def initialize(conf, launcher_args={}) set_rack_environment if clustered? - @events.formatter = Events::PidFormatter.new + @events.formatter = Events::PidFormatter.new unless @options[:log_formatter] @options[:logger] = @events @runner = Cluster.new(self, @events) diff --git a/test/test_events.rb b/test/test_events.rb index 61d3c02160..8b91a69f84 100644 --- a/test/test_events.rb +++ b/test/test_events.rb @@ -144,7 +144,7 @@ def test_pid_formatter end def test_custom_log_formatter - custom_formatter = proc { |str| "-> #{ str }" } + custom_formatter = Puma::Events::CustomFormatter.new(Proc.new { |str| "-> #{str}" }) out, _ = capture_io do events = Puma::Events.stdio From 409743d01b9cc4b027354d9fbf02e447e65cbae5 Mon Sep 17 00:00:00 2001 From: Yoann Lecuyer Date: Sun, 28 Jul 2019 18:18:24 +0200 Subject: [PATCH 02/11] Add tests --- test/config/custom_log_formatter.rb | 3 +++ test/test_cli.rb | 20 ++++++++++++++++++++ 2 files changed, 23 insertions(+) create mode 100644 test/config/custom_log_formatter.rb diff --git a/test/config/custom_log_formatter.rb b/test/config/custom_log_formatter.rb new file mode 100644 index 0000000000..234748b373 --- /dev/null +++ b/test/config/custom_log_formatter.rb @@ -0,0 +1,3 @@ +log_formatter do |str| + "[#{Process.pid}] [#{Socket.gethostname}] #{Time.now}: #{str}" +end diff --git a/test/test_cli.rb b/test/test_cli.rb index 5140138665..05581360d0 100644 --- a/test/test_cli.rb +++ b/test/test_cli.rb @@ -253,6 +253,26 @@ def test_state_file_callback_filtering assert_empty keys_not_stripped end + def test_log_formatter_default_single + cli = Puma::CLI.new [ ] + assert_instance_of Puma::Events::DefaultFormatter, cli.launcher.events.formatter + end + + def test_log_formatter_default_clustered + cli = Puma::CLI.new [ "-w 2" ] + assert_instance_of Puma::Events::PidFormatter, cli.launcher.events.formatter + end + + def test_log_formatter_custom_single + cli = Puma::CLI.new [ "--config", "test/config/custom_log_formatter.rb" ] + assert_instance_of Puma::Events::CustomFormatter, cli.launcher.events.formatter + end + + def test_log_formatter_custom_clustered + cli = Puma::CLI.new [ "--config", "test/config/custom_log_formatter.rb", "-w 2" ] + assert_instance_of Puma::Events::CustomFormatter, cli.launcher.events.formatter + end + def test_state url = "tcp://127.0.0.1:#{next_port}" cli = Puma::CLI.new ["--state", @tmp_path, "--control", url] From 57fa2f09b456b46ee0dba48e9d8ee51ab378bec0 Mon Sep 17 00:00:00 2001 From: Yoann Lecuyer Date: Sun, 28 Jul 2019 18:33:48 +0200 Subject: [PATCH 03/11] skip clustered tests on jruby and windows --- test/test_cli.rb | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/test/test_cli.rb b/test/test_cli.rb index 05581360d0..03eb716283 100644 --- a/test/test_cli.rb +++ b/test/test_cli.rb @@ -259,6 +259,8 @@ def test_log_formatter_default_single end def test_log_formatter_default_clustered + skip_on :jruby, :windows + cli = Puma::CLI.new [ "-w 2" ] assert_instance_of Puma::Events::PidFormatter, cli.launcher.events.formatter end @@ -269,6 +271,8 @@ def test_log_formatter_custom_single end def test_log_formatter_custom_clustered + skip_on :jruby, :windows + cli = Puma::CLI.new [ "--config", "test/config/custom_log_formatter.rb", "-w 2" ] assert_instance_of Puma::Events::CustomFormatter, cli.launcher.events.formatter end From 19e9d3b4b3916b471c3e1e60be8468513767d479 Mon Sep 17 00:00:00 2001 From: Yoann Lecuyer Date: Sun, 28 Jul 2019 22:44:43 +0200 Subject: [PATCH 04/11] Revert wrong history change --- History.md | 2 ++ 1 file changed, 2 insertions(+) diff --git a/History.md b/History.md index ad9670a161..def7298cbe 100644 --- a/History.md +++ b/History.md @@ -11,6 +11,8 @@ * 2 bugfixes * Fix socket removed after reload - should fix problems with systemd socket activation. (#1829) * Add extconf tests for DTLS_method & TLS_server_method, use in minissl.rb. Should fix "undefined symbol: DTLS_method" when compiling against old OpenSSL versions. (#1832) +* 1 other + * Removed unnecessary RUBY_VERSION checks. (#1827) ## 4.0.0 / 2019-06-25 From 03607149221e78e2b27db889fad3c8f89836d290 Mon Sep 17 00:00:00 2001 From: Yoann Lecuyer Date: Sun, 28 Jul 2019 22:45:51 +0200 Subject: [PATCH 05/11] remove useless line --- History.md | 1 - 1 file changed, 1 deletion(-) diff --git a/History.md b/History.md index def7298cbe..ad105af465 100644 --- a/History.md +++ b/History.md @@ -14,7 +14,6 @@ * 1 other * Removed unnecessary RUBY_VERSION checks. (#1827) - ## 4.0.0 / 2019-06-25 * 9 features From 70c1340ec406ce68e2b4d3254c26db8cf0a1ef02 Mon Sep 17 00:00:00 2001 From: Yoann Lecuyer Date: Sun, 28 Jul 2019 22:47:18 +0200 Subject: [PATCH 06/11] Remove useless class --- lib/puma/events.rb | 10 ---------- 1 file changed, 10 deletions(-) diff --git a/lib/puma/events.rb b/lib/puma/events.rb index 148926cb95..63271e0967 100644 --- a/lib/puma/events.rb +++ b/lib/puma/events.rb @@ -23,16 +23,6 @@ def call(str) end end - class CustomFormatter - def initialize(formatter) - @formatter = formatter - end - - def call(str) - @formatter.call(str) - end - end - include Const # Create an Events object that prints to +stdout+ and +stderr+. From 3ceadb2f235fde5c7f32c72fbb5a895042a6f657 Mon Sep 17 00:00:00 2001 From: Yoann Lecuyer Date: Sun, 28 Jul 2019 22:49:35 +0200 Subject: [PATCH 07/11] revert test --- test/test_events.rb | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/test_events.rb b/test/test_events.rb index 98f3446d33..676ece6af1 100644 --- a/test/test_events.rb +++ b/test/test_events.rb @@ -152,7 +152,7 @@ def test_pid_formatter end def test_custom_log_formatter - custom_formatter = Puma::Events::CustomFormatter.new(Proc.new { |str| "-> #{str}" }) + custom_formatter = proc { |str| "-> #{ str }" } out, _ = capture_io do events = Puma::Events.stdio From 0edd1f464f47f2b5c4a1d970dfd5137646789f88 Mon Sep 17 00:00:00 2001 From: Yoann Lecuyer Date: Sun, 28 Jul 2019 22:58:07 +0200 Subject: [PATCH 08/11] better --- lib/puma/launcher.rb | 13 ++++++++----- 1 file changed, 8 insertions(+), 5 deletions(-) diff --git a/lib/puma/launcher.rb b/lib/puma/launcher.rb index fffe30bc40..517b813023 100644 --- a/lib/puma/launcher.rb +++ b/lib/puma/launcher.rb @@ -50,6 +50,9 @@ def initialize(conf, launcher_args={}) @original_argv = @argv.dup @config = conf + @binder = Binder.new(@events) + @binder.import_from_env + @environment = conf.environment # Advertise the Configuration @@ -60,10 +63,11 @@ def initialize(conf, launcher_args={}) @options = @config.options @config.clamp - @events.formatter = Events::CustomFormatter.new(@options[:log_formatter]) if @options[:log_formatter] - - @binder = Binder.new(@events) - @binder.import_from_env + @events.formatter = if @options[:log_formatter] + options[:log_formatter] + elsif clustered? + Events::PidFormattere + end generate_restart_data @@ -83,7 +87,6 @@ def initialize(conf, launcher_args={}) set_rack_environment if clustered? - @events.formatter = Events::PidFormatter.new unless @options[:log_formatter] @options[:logger] = @events @runner = Cluster.new(self, @events) From 42bcdd7ee1d801f6b5db858a1184e46cfae853c4 Mon Sep 17 00:00:00 2001 From: Yoann Lecuyer Date: Sun, 28 Jul 2019 22:58:21 +0200 Subject: [PATCH 09/11] better skip --- test/test_cli.rb | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/test/test_cli.rb b/test/test_cli.rb index 03eb716283..41c0d5ef68 100644 --- a/test/test_cli.rb +++ b/test/test_cli.rb @@ -259,7 +259,7 @@ def test_log_formatter_default_single end def test_log_formatter_default_clustered - skip_on :jruby, :windows + skip NO_FORK_MSG unless HAS_FORK cli = Puma::CLI.new [ "-w 2" ] assert_instance_of Puma::Events::PidFormatter, cli.launcher.events.formatter @@ -271,7 +271,7 @@ def test_log_formatter_custom_single end def test_log_formatter_custom_clustered - skip_on :jruby, :windows + skip NO_FORK_MSG unless HAS_FORK cli = Puma::CLI.new [ "--config", "test/config/custom_log_formatter.rb", "-w 2" ] assert_instance_of Puma::Events::CustomFormatter, cli.launcher.events.formatter From 5796d4509299182764e27f4477fd4f6c7073c86e Mon Sep 17 00:00:00 2001 From: Yoann Lecuyer Date: Sun, 28 Jul 2019 23:47:12 +0200 Subject: [PATCH 10/11] better condition --- lib/puma/launcher.rb | 7 ++----- 1 file changed, 2 insertions(+), 5 deletions(-) diff --git a/lib/puma/launcher.rb b/lib/puma/launcher.rb index 517b813023..1f275f6930 100644 --- a/lib/puma/launcher.rb +++ b/lib/puma/launcher.rb @@ -63,11 +63,8 @@ def initialize(conf, launcher_args={}) @options = @config.options @config.clamp - @events.formatter = if @options[:log_formatter] - options[:log_formatter] - elsif clustered? - Events::PidFormattere - end + @events.formatter = Events::PidFormatter.new if clustered? + @events.formatter = options[:log_formatter] if @options[:log_formatter] generate_restart_data From 52bd2e23ff4c6d10dba16475bb039946e682aabe Mon Sep 17 00:00:00 2001 From: Yoann Lecuyer Date: Sun, 28 Jul 2019 23:47:18 +0200 Subject: [PATCH 11/11] better tests --- test/test_cli.rb | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/test/test_cli.rb b/test/test_cli.rb index 41c0d5ef68..571c7999cf 100644 --- a/test/test_cli.rb +++ b/test/test_cli.rb @@ -267,14 +267,16 @@ def test_log_formatter_default_clustered def test_log_formatter_custom_single cli = Puma::CLI.new [ "--config", "test/config/custom_log_formatter.rb" ] - assert_instance_of Puma::Events::CustomFormatter, cli.launcher.events.formatter + assert_instance_of Proc, cli.launcher.events.formatter + assert_match(/^\[.*\] \[.*\] .*: test$/, cli.launcher.events.format('test')) end def test_log_formatter_custom_clustered skip NO_FORK_MSG unless HAS_FORK cli = Puma::CLI.new [ "--config", "test/config/custom_log_formatter.rb", "-w 2" ] - assert_instance_of Puma::Events::CustomFormatter, cli.launcher.events.formatter + assert_instance_of Proc, cli.launcher.events.formatter + assert_match(/^\[.*\] \[.*\] .*: test$/, cli.launcher.events.format('test')) end def test_state