slog icon indicating copy to clipboard operation
slog copied to clipboard

Deadlock in slog-rs when logging a structure which logs in Debug / Display

Open richardwhiuk opened this issue 4 years ago • 1 comments

I've noted this on the slog gitter, but raising an issue here to track the problem.

If you log (using error!, info!, warn! or debug!) when implementing Debug or Display, then when you log the structure (with info!(logger, "Logging: {:?}", struct); ) then slog may deadlock.

There's a full stack at: https://gist.github.com/richardwhiuk/c53a19c4b92d6e33dab17c615f1b3001

but the key parts are:

#5  _$LT$std..sync..mutex..Mutex$LT$D$GT$$u20$as$u20$slog..Drain$GT$::log::h1a8c2cc72bb29644 (self=0x564d8943dcc0, record=0x7ff4454ce598, logger_values=0x564d8943de70)
    at /opt/rust/registry/src/crates-27bb2a0041c1489d/slog-2.5.2/src/lib.rs:2035
#6  0x0000564d86e3eed5 in _$LT$slog..Fuse$LT$D$GT$$u20$as$u20$slog..Drain$GT$::log::he38f0b0d96904e9b (self=0x80, record=0x0, logger_values=0x7ff44769610d <__lll_lock_wait+29>)
    at /opt/rust/registry/src/crates-27bb2a0041c1489d/slog-2.5.2/src/lib.rs:1912

which attempts to grab the lock and:

#24 _$LT$slog_json..SerdeSerializer$LT$S$GT$$u20$as$u20$slog..Serializer$GT$::emit_arguments::_$u7b$$u7b$closure$u7d$$u7d$::h52bb2c0438e0f6aa (buf=0x7ff4454d14f0)
    at /opt/rust/registry/src/crates-27bb2a0041c1489d/slog-json-2.3.0/lib.rs:147

where slog-json calls into a user specified Debug function.

richardwhiuk avatar Feb 13 '20 08:02 richardwhiuk

If you log (using error!, info!, warn! or debug!) when implementing Debug or Display,

I'd say ... don't do it. :D

dpc avatar Feb 13 '20 18:02 dpc