ngx_mruby
ngx_mruby copied to clipboard
NOTICE logs printed when log level set to warn
Hi,
I see that mruby
module doesn't respect the error_log
setting. In the /etc/nginx/nginx.conf
I set log level like so: error_log /var/log/nginx/error.log warn;
, but I still see notice
logs specifically from mruby
module. See examples below. What could be the reason?
For example
/etc/nginx # nginx -t
2017/11/01 22:02:13 [notice] 23#23: ngx_mruby/1.20.1 (mruby/1.3.0) mechanism enabled in /etc/nginx/nginx.conf:34
nginx: the configuration file /etc/nginx/nginx.conf syntax is ok
nginx: configuration file /etc/nginx/nginx.conf test is successful
Or:
/etc/nginx/conf.d # nginx -g 'daemon off;'
2017/11/01 21:25:17 [notice] 42#42: ngx_mruby NOTICE ngx_http_mruby_shared_state_compile:1026: compile info: code->code.string=(
if server_name == "NGINX"
Server = Nginx
elsif server_name == "Apache"
Server = Apache
end
Server::rputs JSON::stringify({"foo"=>"bar"})
) code->cache=(1) in /etc/nginx/conf.d/default.conf:24
2017/11/01 21:25:17 [notice] 42#42: ngx_mruby/1.20.1 (mruby/1.3.0) mechanism enabled in /etc/nginx/nginx.conf:34
127.0.0.1 - - [01/Nov/2017:21:25:22 +0000] "GET /test HTTP/1.1" 200 13 "-" "curl/7.56.1" "-"
Thank you for your report. This behavior seems to be a matter of setting nginx itself. The log, "ngx_mruby/1.20.1 (mruby/1.3.0) mechanism enabled " is server context logs. Please check it.
That's what I thought too, but seem like it isn't. [notice]
logs only from mruby
module are printed, for example perl
module doesn't print anything , see config below ...
Here is my nginx.conf
load_module modules/ngx_http_perl_module.so;
load_module modules/ngx_http_mruby_module.so;
user nginx;
worker_processes auto;
error_log /var/log/nginx/error.log warn;
pid /var/run/nginx.pid;
events { worker_connections 1024; }
http {
include /etc/nginx/mime.types;
default_type application/octet-stream;
log_format main '$remote_addr - $remote_user [$time_local] "$request" '
'$status $body_bytes_sent "$http_referer" '
'"$http_user_agent" "$http_x_forwarded_for"';
access_log /var/log/nginx/access.log main;
server {
listen 80;
server_name localhost;
location / {
mruby_content_handler_code 'Nginx::rputs "Hello world!"';
}
}
}
And here is the output from /var/log/nginx/error.log
:
2017/11/06 08:28:03 [notice] 52#52: ngx_mruby NOTICE ngx_http_mruby_shared_state_compile:1026: compile info: code->code.string=(Nginx::rputs "Hello world!") code->cache=(1) in /etc/nginx/nginx.conf:27
2017/11/06 08:28:03 [notice] 52#52: ngx_mruby/1.20.1 (mruby/1.3.0) mechanism enabled in /etc/nginx/nginx.conf:30
fmm, I can't reproduced this behavior.
git clone [email protected]:matsumotory/ngx_mruby.git
cd ngx_mruby
sh test.sh
-
vi build/nginx/conf/nginx.conf
events {
worker_connections 1024;
}
worker_processes auto;
error_log logs/error_log_test warn;
http {
include mime.types;
mruby_init_code 'p "[#{Process.pid}] init master process"';
mruby_init_worker_code 'p "[#{Process.pid}] init worker process from inline code";';
mruby_exit_worker_code 'p "[#{Process.pid}] exit worker process from inline code"';
server {
listen 58081;
server_name localhost;
location / {
mruby_content_handler_code "Nginx.rputs 'proxy test ok'";
}
}
}
$ ./build/nginx/sbin/nginx -g 'daemon off;'
"[14561] init master process"
"[14562] init worker process from inline code"
"[14563] init worker process from inline code"
Please check it.
@matsumotory I can reproduce it.
% sh test.sh
% rm build/nginx/logs/*
% cp build/nginx/conf/nginx.conf build/nginx/conf/nginx.conf.orig
% vi build/nginx/conf/nginx.conf
% diff -u build/nginx/conf/nginx.conf.orig build/nginx/conf/nginx.conf
--- build/nginx/conf/nginx.conf.orig 2017-12-20 01:18:21.501413133 -0500
+++ build/nginx/conf/nginx.conf 2017-12-20 01:18:37.611413133 -0500
@@ -5,7 +5,7 @@
daemon off;
master_process off;
-error_log logs/error.log debug;
+error_log logs/error.log notice;
http {
include mime.types;
% ./build/nginx/sbin/nginx
"[16762] init master process"
"ngx_mruby: STREAM: mruby_stream_init_code"
"[16762] init worker process from inline code"
"ngx_mruby: STREAM: mruby_stream_init_worker_code"
^C"[16762] exit worker process from inline code"
"ngx_mruby: STREAM: mruby_stream_exit_worker_code"
I can see the mechanism enabled message and other notice messages in build/nginx/logs/error.log:
2017/12/20 01:18:58 [notice] 16762#0: ngx_mruby/1.20.1 (mruby/1.3.0) mechanism enabled in /home/vagrant/ngx_mruby/build/nginx/conf/nginx.conf:817
2017/12/20 01:18:58 [notice] 16762#0: ngx_mruby-stream-module NOTICE ngx_stream_mruby_shared_state_compile:405: compile info: code->code.string=(
p "ngx_mruby: STREAM: mruby_stream_init_code"
Userdata.new.new_upstream = "127.0.0.1:58081"
) in /home/vagrant/ngx_mruby/build/nginx/conf/nginx.conf:834
Oops, the above configuration was wrong. I can reproduce it with warn level too.
% diff -u build/nginx/conf/nginx.conf.orig build/nginx/conf/nginx.conf
--- build/nginx/conf/nginx.conf.orig 2017-12-20 01:18:21.501413133 -0500
+++ build/nginx/conf/nginx.conf 2017-12-20 03:07:44.188186619 -0500
@@ -5,7 +5,7 @@
daemon off;
master_process off;
-error_log logs/error.log debug;
+error_log logs/error.log warn;
http {
include mime.types;