Re: Formatting unicorn logs in json format for $stderr

[Cenon Del Rosario <cdelrosario@publishing.nine.com.au>]

> I suspect that needs "logger()" around it, like so:
>     logger(Logger.new($stderr).tap do |newlgr|
>       newlgr.formatter = JsonLogFormatter.new
>     end)

Sorry for incomplete code snippets but yes I do have this (I was doing
it for either stdout or stderr) and it did not make a difference.

On Tue, 6 Jul 2021 at 20:41, Eric Wong <e@80x24.org> wrote:
>
> Cenon Del Rosario <cdelrosario@publishing.nine.com.au> wrote:
> > Hi,
> >
> > I am using rails 3.2.22 / ruby 2.1.8 and am trying to reformat the
> > unicorn log output from stderr into json format and have had partial
> > success.
> >
> > I have a basic json formatter:
> > class JsonLogFormatter < Logger::Formatter
> >   def call(severity, datetime, progname, msg)
> >     log_msg = {
> >       time: "#{datetime}",
> >       severity: "#{severity}",
> >       source: "#{progname}"
> >     }
> >     msg.is_a?(Hash) ? log_msg.merge!(msg) : log_msg.merge!(message: "#{msg}")
> >     "#{log_msg.to_json}\n"
> >   end
> > end
> >
> > I have this in my unicorn config:
> > Logger.new($stderr).tap do |newlgr|
> >   newlgr.formatter = JsonLogFormatter.new
> > end
>
> I suspect that needs "logger()" around it, like so:
>
>     logger(Logger.new($stderr).tap do |newlgr|
>       newlgr.formatter = JsonLogFormatter.new
>     end)
>
> cf. https://urldefense.com/v3/__https://yhbt.net/unicorn/Unicorn/Configurator.html*method-i-logger__;Iw!!LBk0ZmAmG_H4m2o!9io6HA1SNuu8dkgdMRtwNuyjMJZwMCtZCUQsYqfcIvMvaFlkjfE17UHZSB15oiNN9YiW_Lm-hw$
>
> > For the most part it works and I get the stdout and stderr in json but
> > I also see some other non-json formatted messages, for example:
> > {"time":"2021-07-06 17:14:01
> > +1000","severity":"INFO","source":"","message":"Started GET \"/admin\"
> > for 127.0.0.1 at 2021-07-06 17:14:01 +1000"}
> > 127.0.0.1 - - [06/Jul/2021 17:14:01] "GET /admin HTTP/1.1" 301 102 0.4243
>
> I suspect one of those lines could be the result of
> Rack::CommonLogger from RACK_ENV=deployment or similar
> (which matched "rackup" defaults back in 2009).
>
> Personally, I always used something non-standard like "RACK_ENV=none"
> to disable all default Rack middleware (--no-default-middleware
> exists nowadays, too).
>
> > It seems that rails logs are working and then the unicorn process
> > itself is outputting its own logs because I can see duplicates of the
> > same log message one in json and the other in plain text.
> >
> > Just want to know if there is a way to get this working consistently?
>
> I've never used the "logger" directive much myself; maybe others
> here can chime in with experience using non-standard loggers.

-- 
The information contained in this e-mail message and any accompanying files 
is or may be confidential. If you are not the intended recipient, any use, 
dissemination, reliance, forwarding, printing or copying of this e-mail or 
any attached files is unauthorised. This e-mail is subject to copyright. No 
part of it should be reproduced, adapted or communicated without the 
written consent of the copyright owner. If you have received this e-mail in 
error please advise the sender immediately by return e-mail or telephone 
and delete all copies. Nine Group does not guarantee the accuracy or 
completeness of any information contained in this e-mail or attached files. 
Internet communications are not secure, therefore Nine Group does not 
accept legal responsibility for the contents of this message or attached 
files.