kafka-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Alla Tumarkin (JIRA)" <j...@apache.org>
Subject [jira] [Created] (KAFKA-5709) Improve logging to include errors from state-change log in server log
Date Mon, 07 Aug 2017 20:21:00 GMT
Alla Tumarkin created KAFKA-5709:
------------------------------------

             Summary: Improve logging to include errors from state-change log in server log
                 Key: KAFKA-5709
                 URL: https://issues.apache.org/jira/browse/KAFKA-5709
             Project: Kafka
          Issue Type: Improvement
          Components: log
    Affects Versions: 0.10.2.0
            Reporter: Alla Tumarkin


Problem
The following message was generated over and over again when running kafka-console-producer
or kafka-console-consumer with SSL and ACLs enabled
{code}
WARN Error while fetching metadata with correlation id 1 : {test=LEADER_NOT_AVAILABLE} (org.apache.kafka.clients.NetworkClient)`
endlessly when I run kafka-console-producer or kafka-console-consumer
{code}
however server log (or authorizer log) did not indicate any problem.

Background
1) Initially, security.inter.broker.protocol setting was missing in server.properties, so
connection was falling back to using plaintext port (9092), and only state-change.log actually
contained the underlying error:
{code}
[2017-08-04 13:40:48,536] TRACE Controller 0 epoch 6 received response {error_code=31,partitions=[{topic=test,partition=0,error_code=31},{topic=__confluent.support.metrics,partition=0,error_code=31}]}
for a request sent to broker localhost:9092 (id: 0 rack: null) (state.change.logger)
{code}
as per
https://kafka.apache.org/protocol#protocol_error_codes
{code}
CLUSTER_AUTHORIZATION_FAILED	31	False	Cluster authorization failed.
{code}

2) After setting "security.inter.broker.protocol=SSL" the port changed to secure (9093) yet
the error in state-change log did not go away:
{code}
[2017-08-04 13:49:38,462] TRACE Controller 0 epoch 7 received response {error_code=31} for
a request sent to broker localhost:9093 (id: 0 rack: null) (state.change.logger)
{code}
and LEADER_NOT_AVAILABLE was still generated.

This time though, kafka-authorizer.log had a better indication of the problem:
{code}
[2017-08-04 18:17:46,770] DEBUG No acl found for resource Cluster:kafka-cluster, authorized
= false (kafka.authorizer.logger)
[2017-08-04 18:17:46,770] DEBUG Principal = User:CN=Unknown,OU=Unknown,O=Unknown,L=Unknown,ST=Unknown,C=Unknown
is Denied Operation = ClusterAction from host = 127.0.0.1 on resource = Cluster:kafka-cluster
(kafka.authorizer.logger)
{code}
The issue being that topic metadata is not propagated successfully from controller to broker
since the broker user doesn't have ClusterAction permission.
Fixed by
{code}
bin/kafka-acls --authorizer-properties zookeeper.connect=localhost:2181 --add --allow-principal
"User:CN=Unknown,OU=Unknown,O=Unknown,L=Unknown,ST=Unknown,C=Unknown" --operation ClusterAction
--cluster
{code}

Request
The debugging is tricky since the controller to broker logging is done in controller/state-change
log, not in the main server log.
We need to improve the logging on this.



--
This message was sent by Atlassian JIRA
(v6.4.14#64029)

Mime
View raw message