[erlang-questions] SOLVED - no logger output using ?LOG macros in release

[Mark Geib]

Just to follow up. 

Spent yesterday tracking this all down and there is no issue with the logging macros, etc.
I was not explicitly specifying versions in my rebar.conf and late last week, while I was migrating my 
logging to use the macros a new RC release of a dependency was pushed to the HEX repo. This is apparently 
when my logging stopped working. Because I do my prod builds with an erlang docker image it was always
grabbing the latest release of all the dependencies, thus getting this new RC release. In dev of course
rebar3 locks the versions used in builds. I also failed to include the rebar.lock file in my repo.

Lesson learned, always use explicit versions of dependencies, and in addition add the rebar.lock to the repo.

Sorry for all the confusion and misleading information.

Mark.

> On Mar 26, 2019, at 4:51 AM, Siri Hansen <erlangsiri@REDACTED> wrote:
> 
> Hi Mark,
> 
> I'm not sure what the difference could be between dev an prod here, but if you can access your node, did you check that the logger configuration is as expected? logger:i() in OTP-21.3, or else logger:get_config(). Just to make sure nothing failed silently during startup. 
> 
> Another thing though - are you using run_erl with your prod release? If so, given the file name specified for the default handler, you must make sure that run_erl does not have the same log directory as you handler, or else they will attempt writing to the same file. logger_disk_log_h has no mechanism to ensure that it's file descriptor is fresh (the inode has not been changed), so if run_erl writes something to the same file, then the next log event from logger_disk_log_h will just disappear :(  (logger_std_h has better protection against this, and from OTP-21.3 it also has log rotation.) But this is of course not related to the macros at all, so if everything works ok with logger:info(..) but not with the macro, then there must be something else going on anyway.
> 
> Regards
> /siri
> 
> Den man. 25. mar. 2019 kl. 20:49 skrev Mark Geib <mark.geib.44@REDACTED <mailto:mark.geib.44@REDACTED>>:
> Yes, here is the bottom of my sys.config.
> 
> {kernel,
>     [{logger_level, info}, {logger,
>       [{handler, default, logger_disk_log_h,
>        #{config => #{file => "/var/log/asp2aj/erlang.log", type => wrap, max_no_files => 10, max_no_bytes => 1000000000},
>          formatter => {logger_formatter, #{single_line => true, template => [time," ",mfa,":",line," ",pid," [",level,"] ",msg,"\n"]}}}
>       }]
>     }]
>   }].
> 
> Mark.
> 
> 
>> On Mar 25, 2019, at 1:44 PM, Steve Strong <steve@REDACTED <mailto:steve@REDACTED>> wrote:
>> 
>> Do you have the logger_level value set in your sys.config (or are you setting it in code)?  The ?LOG macros check that before logging…
>> 
>> -define(DO_LOG(Level,Args),
>>         case logger:allow(Level,?MODULE) of
>>             true ->
>>                 apply(logger,macro_log,[?LOCATION,Level|Args]);
>>             false ->
>>                 ok
>>         end).
>> -endif.
>> 
>> Cheers,
>> 
>> Steve
>> 
>>> On 25 Mar 2019, at 19:41, Mark Geib <mark.geib.44@REDACTED <mailto:mark.geib.44@REDACTED>> wrote:
>>> 
>>> I am using the default handler and formatter, i.e.: 
>>> 
>>> [{handler, default, logger_disk_log_h,  % handler, HandlerId, Module,
>>>   #{config => #{file => "/var/log/asp2aj/erlang.log", type => wrap, max_no_files => 10, max_no_bytes => 1000000000},
>>>     formatter => {logger_formatter, #{single_line => true, template => [time," ",mfa,":",line," ",pid," [",level,"] ",msg,"\n"]}}}
>>>  }]
>>> 
>>> 
>>> And my logging works fine previously when I was doing logger:info()...
>>> 
>>> Thanks,
>>> Mark.
>>> 
>>> 
>>>> On Mar 25, 2019, at 1:32 PM, Fred Hebert <mononcqc@REDACTED <mailto:mononcqc@REDACTED>> wrote:
>>>> 
>>>> See if you are using any log formatters or handlers -- those may not be direct dependencies of your application, and therefore do not get included in the final release. You will need to add these dependencies to the release independently so that they are present to run and handle output.
>>>> 
>>>> The rebar3 shell and other interactive modes can dynamically load libraries from disk and won't show that little gotcha at all.
>>>> 
>>>> On Mon, Mar 25, 2019 at 1:47 PM Mark Geib <mark.geib.44@REDACTED <mailto:mark.geib.44@REDACTED>> wrote:
>>>> I have a problem where I see no logger output in a release built with rebar3 using the new ?LOG macros. If I use the logger: functions
>>>> everything is working fine. Decided to change to use the macros in order to get able to include MFA, line number, etc. in templates.
>>>> 
>>>> Also, doing a dev release build and then running interactively everything works fine with the ?LOG macros. It’s like the
>>>> prod builds are missing something compared to dev build.
>>>> 
>>>> Thanks in advance for any help.
>>>> 
>>>> Mark.
>>>> _______________________________________________
>>>> erlang-questions mailing list
>>>> erlang-questions@REDACTED <mailto:erlang-questions@REDACTED>
>>>> http://erlang.org/mailman/listinfo/erlang-questions <http://erlang.org/mailman/listinfo/erlang-questions>
>>> 
>>> _______________________________________________
>>> erlang-questions mailing list
>>> erlang-questions@REDACTED <mailto:erlang-questions@REDACTED>
>>> http://erlang.org/mailman/listinfo/erlang-questions <http://erlang.org/mailman/listinfo/erlang-questions>
>> 
> 
> _______________________________________________
> erlang-questions mailing list
> erlang-questions@REDACTED <mailto:erlang-questions@REDACTED>
> http://erlang.org/mailman/listinfo/erlang-questions <http://erlang.org/mailman/listinfo/erlang-questions>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://erlang.org/pipermail/erlang-questions/attachments/20190327/c8411126/attachment.htm>