erlang-lager / lager

A logging framework for Erlang/OTP
Apache License 2.0
1.12k stars 455 forks source link

Lager parse transforms produce warnings with the latest Erlang 24 compiler #546

Closed michaelklishin closed 3 years ago

michaelklishin commented 3 years ago

Filing here per suggestion from @paulo-ferraz-oliveira. @lhoguin suggested this is not really a novel problem for Lager.

See https://github.com/erlang/otp/issues/4576 for the background. The below is true with a very recent Erlang 24 build (I built master with kerl a day ago, for example).

I don't have a way to reproduce this besides this:

source /path/to/kerl/installations/otp-24/activate

git clone https://github.com/rabbitmq/rabbitmq-server.git rabbitmq-monorepo
cd rabbitmq-monorepo
cd deps/rabbit
make

It will eventually produce warnings such as

 ERLC   app_utils.erl code_version.erl credit_flow.erl delegate.erl delegate_sup.erl file_handle_cache.erl file_handle_cache_stats.erl gen_server2.erl lager_forwarder_backend.erl mirrored_supervisor.erl mnesia_sync.erl pmon.erl priority_queue.erl rabbit_amqp_connection.erl rabbit_amqqueue_common.erl rabbit_auth_backend_dummy.erl rabbit_auth_mechanism.erl rabbit_authn_backend.erl rabbit_authz_backend.erl rabbit_basic_common.erl rabbit_binary_generator.erl rabbit_binary_parser.erl rabbit_cert_info.erl rabbit_channel_common.erl rabbit_command_assembler.erl rabbit_control_misc.erl rabbit_core_metrics.erl rabbit_data_coercion.erl rabbit_env.erl rabbit_error_logger_handler.erl rabbit_event.erl rabbit_exchange_type.erl rabbit_framing_amqp_0_8.erl rabbit_framing_amqp_0_9_1.erl rabbit_heartbeat.erl rabbit_http_util.erl rabbit_json.erl rabbit_log.erl rabbit_log_osiris_shim.erl rabbit_log_ra_shim.erl rabbit_misc.erl rabbit_msg_store_index.erl rabbit_net.erl rabbit_nodes_common.erl rabbit_numerical.erl rabbit_password_hashing.erl rabbit_pbe.erl rabbit_peer_discovery_backend.erl rabbit_policy_validator.erl rabbit_queue_collector.erl rabbit_registry.erl rabbit_registry_class.erl rabbit_resource_monitor_misc.erl rabbit_runtime.erl rabbit_runtime_parameter.erl rabbit_semver.erl rabbit_semver_parser.erl rabbit_ssl_options.erl rabbit_types.erl rabbit_writer.erl supervisor2.erl vm_memory_monitor.erl worker_pool.erl worker_pool_sup.erl worker_pool_worker.erl
compile: warnings being treated as errors
src/app_utils.erl:64:29: a term is constructed, but never used
%   64|                             rabbit_log:info("Stopping application '~s'", [App]),
%     |                             ^

rabbit_log is a module which is replaced by Lager parse transforms. Our best lead is that this code produces an expression which causes the cutting edge Erlang 24 compiler to emit warnings. With -Werror that means things no longer compile.

michaelklishin commented 3 years ago

I should mention that this is with Lager 3.9.1, so the latest there is.

paulo-ferraz-oliveira commented 3 years ago

Thanks, @michaelklishin. I've seen dialyzer complain about unmatched_returns in our lib.s, but never experienced what you describe. Does it happen with OTP 24-rc1 also?

michaelklishin commented 3 years ago

No, 24-rc.1 does not reproduce this. Our best guess is that this is new after https://github.com/erlang/otp/pull/4545 was merged.

Since it's not practical for even a moderately sized codebase to explicitly ignore the value returned by the transform-generated code, I'm afraid this has to be addressed in either Lager or erlc.

michaelklishin commented 3 years ago

Most logging function calls out there probably do not check the returned value. So Lager could assume the value should be ignored by default and introduce another set of functions that do return a value, for those who care enough to check it. I can't think of any other solution right now.

Vagabond commented 3 years ago

I think we should wait for the next RC before trying to address this. Chasing master is not interesting as a bunch of stuff seems to still be in flux there.

Vagabond commented 3 years ago

That said, this is caused by lager returning ok or an error if lager is not running. That error is probably not useful (I don't know if anyone has ever checked that result) so we could have lager calls always return ok even if lager is down.

paulo-ferraz-oliveira commented 3 years ago

Well, I can say that all our code does _ =, but it might not be practical to everybody, I understand.

paulo-ferraz-oliveira commented 3 years ago

That said, this is caused by lager returning ok or an error if lager is not running. That error is probably not useful (I don't know if anyone has ever checked that result) so we could have lager calls always return ok even if lager is down.

When you dialyzer with unmatched_returns you get this. But I can't replicate it yet, for what @michaelklishin is describing.

Do note it's "a term is constructed, but never used" which I've only seen before when we actually have a term that's not matched or returned.

michaelklishin commented 3 years ago

@Vagabond that's my point. The returned value is never checked and the scenario seems to be only likely early on application boot.

As for "chasing master", that's the only way our team knows with major OTP releases, begin chasing master a couple of months before the release. If we are a couple of weeks late, there will be users who will install the new release and then claim that RabbitMQ is "totally broken".

This is not currently blocking for RabbitMQ because we are switching to OTP logger in master (only to have one less dependency, we generally have been very happy with Lager). It would be great to address this and support OTP 24 in Lager for RabbitMQ 3.8 releases going forward, though :)

paulo-ferraz-oliveira commented 3 years ago

That error is probably not useful (I don't know if anyone has ever checked that result) so we could have lager calls always return ok even if lager is down.

Do you think it acceptable to have an option for this? I'd hate to break previous behaviour.

paulo-ferraz-oliveira commented 3 years ago

As @Vagabond stated, this is solved (I tested it in rabbit directly) by e.g. moving from an {error, _} to ok. I touched the line that states trick the linter into avoiding a 'term constructed but not used' error and well as one other further down which states something similar.