You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@zookeeper.apache.org by "Christopher Tubbs (Jira)" <ji...@apache.org> on 2022/06/14 08:28:00 UTC

[jira] [Commented] (ZOOKEEPER-4557) MDC for myid is missing in children threads due to log4j vs logback incompatibility

    [ https://issues.apache.org/jira/browse/ZOOKEEPER-4557?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17553977#comment-17553977 ] 

Christopher Tubbs commented on ZOOKEEPER-4557:
----------------------------------------------

The MDC feature has always been very fragile in SLF4J, as it depends on the underlying logging runtime to support it. I don't think ZooKeeper should use this SLF4J feature at all, given how flaky the support is for it in the available logging runtimes.

One possible alternative would be to have ZooKeeper set a system property. That might work with some logging runtimes if they have late binding for system properties declared in the logging pattern.

> MDC for myid is missing in children threads due to log4j vs logback incompatibility
> -----------------------------------------------------------------------------------
>
>                 Key: ZOOKEEPER-4557
>                 URL: https://issues.apache.org/jira/browse/ZOOKEEPER-4557
>             Project: ZooKeeper
>          Issue Type: Bug
>    Affects Versions: 3.8.0
>            Reporter: Shinya Yoshida
>            Priority: Major
>
> In 3.8.0, zookeeper migrated from log4j to logback in ZOOKEEPER-4427.
> Unfortunately, logback doesn't use InheritableThreadLocal for MDC implementation because it's too dangerous unlike log4j does.
> https://jira.qos.ch/browse/LOGBACK-422
> https://jira.qos.ch/browse/LOGBACK-624
> This causes incompatibility of logging behavior.
> Now we missed pretty myid MDC in the logs.
> You can easily reproduce this issue by just downloading the zookeeper artifact and start-up locally.
> Zookeeper 3.7.1:
> {code:java}
> 2022-06-14 15:28:04,279 [myid:1] - INFO  [ListenerHandler-localhost/127.0.0.1:3888:QuorumCnxManager$Listener$ListenerHandler@1071] - 1 is accepting connections now, my election bind port: localhost/127.0.0.1:3888
> 2022-06-14 15:28:04,280 [myid:1] - INFO  [main:ZKAuditProvider@42] - ZooKeeper audit is disabled.
> 2022-06-14 15:28:04,284 [myid:1] - INFO  [QuorumPeer[myid=1](plain=[0:0:0:0:0:0:0:0]:2181)(secure=disabled):QuorumPeer@1438] - LOOKING
> 2022-06-14 15:28:04,284 [myid:1] - INFO  [QuorumPeer[myid=1](plain=[0:0:0:0:0:0:0:0]:2181)(secure=disabled):FastLeaderElection@945] - New election. My id = 1, proposed zxid=0x0
> 2022-06-14 15:28:04,290 [myid:1] - INFO  [WorkerReceiver[myid=1]:FastLeaderElection$Messenger$WorkerReceiver@390] - Notification: my state:LOOKING; n.sid:1, n.state:LOOKING, n.leader:1, n.round:0x1, n.peerEpoch:0x0, n.zxid:0x0, message format version:0x2, n.config version:0x0
> 2022-06-14 15:28:04,292 [myid:1] - WARN  [QuorumConnectionThread-[myid=1]-2:QuorumCnxManager@401] - Cannot open channel to 3 at election address localhost/127.0.0.1:3890
> {code}
> zookeeper 3.8.0
> {code:java}
> 2022-06-14 15:28:51,461 [myid:] - INFO  [ListenerHandler-localhost/127.0.0.1:3888:o.a.z.s.q.QuorumCnxManager$Listener$ListenerHandler@1071] - 1 is accepting connections now, my election bind port: localhost/127.0.0.1:3888
> 2022-06-14 15:28:51,463 [myid:1] - INFO  [main:o.a.z.a.ZKAuditProvider@42] - ZooKeeper audit is disabled.
> 2022-06-14 15:28:51,467 [myid:] - INFO  [QuorumPeer[myid=1](plain=[0:0:0:0:0:0:0:0]:2181)(secure=disabled):o.a.z.s.q.QuorumPeer@1455] - LOOKING
> 2022-06-14 15:28:51,467 [myid:] - INFO  [QuorumPeer[myid=1](plain=[0:0:0:0:0:0:0:0]:2181)(secure=disabled):o.a.z.s.q.FastLeaderElection@946] - New election. My id = 1, proposed zxid=0x0
> 2022-06-14 15:28:51,469 [myid:] - INFO  [WorkerReceiver[myid=1]:o.a.z.s.q.FastLeaderElection$Messenger$WorkerReceiver@391] - Notification: my state:LOOKING; n.sid:1, n.state:LOOKING, n.leader:1, n.round:0x1, n.peerEpoch:0x0, n.zxid:0x0, message format version:0x2, n.config version:0x0
> 2022-06-14 15:28:51,475 [myid:] - WARN  [QuorumConnectionThread-[myid=1]-1:o.a.z.s.q.QuorumCnxManager@401] - Cannot open channel to 2 at election address localhost/127.0.0.1:3889
> {code}
> Now we couldn't see myid in the most of logs.
> We need to propagate myid MDC to other threads in the code.



--
This message was sent by Atlassian Jira
(v8.20.7#820007)