[
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)
