Fwd: Authentication issues using cyrus-sasl from librdkafka on CentOSVM with Kerberos
Marcel Gutsche
mail at marcelgutsche.de
Mon Jan 15 09:32:54 EST 2018
Ah I still had a bug, not pointing to the correct keytab_file. Also
discussed here https://github.com/edenhill/librdkafka/issues/1630 and here
https://github.com/cyrusimap/cyrus-sasl/issues/501
It now hangs at an GSSAPI step 1.
```
Using python-kafka: ('0.11.0', 720896) and librdkafka
('0.11.1-109-g6f0750', 721407)
%7|1516023480.330|SASL|rdkafka#consumer-1| [thrd:app]: Selected
provider Cyrus for SASL mechanism GSSAPI
%7|1516023480.330|MEMBERID|rdkafka#consumer-1| [thrd:app]: Group
"user-cctv_python_rhel": updating member id "(not-set)" -> ""
%7|1516023480.332|BRKREASSIGN|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel" management reassigned from broker (none) to
:0/internal
%7|1516023480.332|CGRPSTATE|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel" changed state init -> wait-broker (v1,
join-state init)
%7|1516023480.332|BRKASSIGN|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel" management assigned to broker :0/internal
%7|1516023480.332|CGRPOP|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel" received op SUBSCRIBE (v0) in state
wait-broker (join state init, v1 vs 0)
%7|1516023480.332|SUBSCRIBE|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel": subscribe to new subscription of 1 topics
(join state init)
%7|1516023480.332|UNSUBSCRIBE|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel": unsubscribe from current unset subscription
of 0 topics (leave group=no, join state init, v1)
%7|1516023480.332|GRPLEADER|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel": resetting group leader info: unsubscribe
%7|1516023480.332|CGRPJOINSTATE|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel" changed join state init -> wait-unassign (v1,
state wait-broker)
%7|1516023480.332|UNASSIGN|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel": unassign done in state wait-broker (join
state wait-unassign): without new assignment: unassign (no previous
assignment)
%7|1516023480.332|CGRPJOINSTATE|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel" changed join state wait-unassign -> init (v1,
state wait-broker)
%7|1516023480.332|CGRPQUERY|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel": no broker available for coordinator query:
intervaled in state wait-broker
%7|1516023480.385|CONNECTED|rdkafka#consumer-1|
[thrd:sasl_plaintext://host2:9092/bootstrap]:
sasl_plaintext://host2:9092/bootstrap: Connected (#1)
%7|1516023480.385|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
%7|1516023480.385|CONNECTED|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Connected (#1)
%7|1516023480.385|FEATURE|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Updated enabled protocol
features +ApiVersion to ApiVersion
%3|1516023480.385|FAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: Connect to
ipv4#XXX.XXX.XXX.237:9092 failed: Connection refused
%3|1516023480.385|ERROR|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: Connect to
ipv4#XXX.XXX.XXX.237:9092 failed: Connection refused
%7|1516023480.385|FEATURE|rdkafka#consumer-1|
[thrd:sasl_plaintext://host2:9092/bootstrap]:
sasl_plaintext://host2:9092/bootstrap: Updated enabled protocol
features +ApiVersion to ApiVersion
%7|1516023480.385|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host2:9092/bootstrap]:
sasl_plaintext://host2:9092/bootstrap: Sent ApiVersionRequest (v0, 25
bytes @ 0, CorrId 1)
%7|1516023480.385|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Sent ApiVersionRequest (v0, 25
bytes @ 0, CorrId 1)
%7|1516023480.433|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Received ApiVersionResponse
(v0, 132 bytes, CorrId 1, rtt 47.80ms)
%7|1516023480.433|AUTH|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Auth in state APIVERSION_QUERY
(handshake supported)
%7|1516023480.433|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host2:9092/bootstrap]:
sasl_plaintext://host2:9092/bootstrap: Received ApiVersionResponse
(v0, 132 bytes, CorrId 1, rtt 47.92ms)
%7|1516023480.433|AUTH|rdkafka#consumer-1|
[thrd:sasl_plaintext://host2:9092/bootstrap]:
sasl_plaintext://host2:9092/bootstrap: Auth in state APIVERSION_QUERY
(handshake supported)
%7|1516023480.433|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Sent SaslHandshakeRequest (v0,
29 bytes @ 0, CorrId 2)
%7|1516023480.433|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host2:9092/bootstrap]:
sasl_plaintext://host2:9092/bootstrap: Sent SaslHandshakeRequest (v0,
29 bytes @ 0, CorrId 2)
%7|1516023480.481|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Received SaslHandshakeResponse
(v0, 14 bytes, CorrId 2, rtt 47.78ms)
%7|1516023480.481|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host2:9092/bootstrap]:
sasl_plaintext://host2:9092/bootstrap: Received SaslHandshakeResponse
(v0, 14 bytes, CorrId 2, rtt 47.75ms)
%7|1516023480.481|SASLMECHS|rdkafka#consumer-1|
[thrd:sasl_plaintext://host2:9092/bootstrap]:
sasl_plaintext://host2:9092/bootstrap: Broker supported SASL
mechanisms: GSSAPI
%7|1516023480.481|AUTH|rdkafka#consumer-1|
[thrd:sasl_plaintext://host2:9092/bootstrap]:
sasl_plaintext://host2:9092/bootstrap: Auth in state AUTH_HANDSHAKE
(handshake supported)
%7|1516023480.481|SASL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host2:9092/bootstrap]:
sasl_plaintext://host2:9092/bootstrap: Initializing SASL client:
service name kafka, hostname host2, mechanisms GSSAPI, provider Cyrus
%7|1516023480.481|SASLREFRESH|rdkafka#consumer-1|
[thrd:sasl_plaintext://host2:9092/bootstrap]:
sasl_plaintext://host2:9092/bootstrap: Refreshing SASL keys with
command: KRB5_TRACE=/dev/stdout kinit -kt /root/user.keytab
user at PRINCIPAL
%7|1516023480.481|SASLMECHS|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Broker supported SASL
mechanisms: GSSAPI
%7|1516023480.481|AUTH|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Auth in state AUTH_HANDSHAKE
(handshake supported)
%7|1516023480.481|SASL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Initializing SASL client:
service name kafka, hostname host3, mechanisms GSSAPI, provider Cyrus
%7|1516023480.481|SASLREFRESH|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Refreshing SASL keys with
command: KRB5_TRACE=/dev/stdout kinit -kt /root/user.keytab
user at PRINCIPAL
[24032] 1516023480.505296: Getting initial credentials for user at PRINCIPAL
[24032] 1516023480.511157: Looked up etypes in keytab: aes256-cts,
rc4-hmac, des3-cbc-sha1, des-cbc-crc
[24032] 1516023480.511341: Sending request (176 bytes) to PRINCIPAL
[24032] 1516023480.511883: Resolving hostname XXX.XXX.XXX.168
[24032] 1516023480.512229: Sending initial UDP request to dgram
XXX.XXX.XXX.168:88
[24032] 1516023480.560726: Received answer (327 bytes) from dgram
XXX.XXX.XXX.168:88
[24032] 1516023480.560830: Response was not from master KDC
[24032] 1516023480.560927: Received error from KDC:
-1765328359/Additional pre-authentication required
[24032] 1516023480.561108: Processing preauth types: 136, 19, 2, 133
[24032] 1516023480.561134: Selected etype info: etype aes256-cts, salt
"PRINCIPALuser", params ""
[24032] 1516023480.561145: Received cookie: MIT
[24032] 1516023480.561298: Retrieving user at PRINCIPAL from
FILE:/root/user.keytab (vno 0, enctype aes256-cts) with result:
0/Success
[24032] 1516023480.561357: AS key obtained for encrypted timestamp:
aes256-cts/114F
[24032] 1516023480.561566: Encrypted timestamp (for
1516023524.856095): plain 301AA011180xxxxxxxxxx, encrypted
C9AF43C25442F3xxxxxxxxxx
[24032] 1516023480.561754: Preauth module encrypted_timestamp (2)
(real) returned: 0/Success
[24032] 1516023480.561766: Produced preauth for next request: 133, 2
[24032] 1516023480.561811: Sending request (271 bytes) to PRINCIPAL
[24032] 1516023480.561861: Resolving hostname XXX.XXX.XXX.168
[24032] 1516023480.562076: Sending initial UDP request to dgram
XXX.XXX.XXX.168:88
[24032] 1516023480.662874: Received answer (765 bytes) from dgram
XXX.XXX.XXX.168:88
[24032] 1516023480.663083: Response was not from master KDC
[24032] 1516023480.663143: Processing preauth types: 19
[24032] 1516023480.663161: Selected etype info: etype aes256-cts, salt
"PRINCIPALuser", params ""
[24032] 1516023480.663175: Produced preauth for next request: (empty)
[24032] 1516023480.663195: AS key determined by preauth: aes256-cts/114F
[24032] 1516023480.663319: Decrypted AS reply; session key is: aes256-cts/38D6
[24032] 1516023480.663361: FAST negotiation: available
[24032] 1516023480.663411: Initializing FILE:/tmp/krb5cc_0 with
default princ user at PRINCIPAL
[24032] 1516023480.664114: Storing user at PRINCIPAL ->
krbtgt/PRINCIPAL at PRINCIPAL in FILE:/tmp/krb5cc_0
[24032] 1516023480.664252: Storing config in FILE:/tmp/krb5cc_0 for
krbtgt/PRINCIPAL at PRINCIPAL: fast_avail: yes
[24032] 1516023480.664332: Storing user at PRINCIPAL ->
krb5_ccache_conf_data/fast_avail/krbtgt\/PRINCIPAL\@PRINCIPAL at X-CACHECONF:
in FILE:/tmp/krb5cc_0
[24032] 1516023480.664402: Storing config in FILE:/tmp/krb5cc_0 for
krbtgt/PRINCIPAL at PRINCIPAL: pa_type: 2
[24032] 1516023480.664459: Storing user at PRINCIPAL ->
krb5_ccache_conf_data/pa_type/krbtgt\/PRINCIPAL\@PRINCIPAL at X-CACHECONF:
in FILE:/tmp/krb5cc_0
%7|1516023480.665|SASLREFRESH|rdkafka#consumer-1|
[thrd:sasl_plaintext://host2:9092/bootstrap]:
sasl_plaintext://host2:9092/bootstrap: SASL key refreshed
%7|1516023480.666|SASL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host2:9092/bootstrap]:
sasl_plaintext://host2:9092/bootstrap: My supported SASL mechanisms:
GS2-IAKERB GS2-KRB5 SCRAM-SHA-1 GSSAPI GSS-SPNEGO DIGEST-MD5 EXTERNAL
OTP CRAM-MD5 PLAIN ANONYMOUS
%5|1516023480.667|LIBSASL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host2:9092/bootstrap]:
sasl_plaintext://host2:9092/bootstrap: GSSAPI client step 1
[24033] 1516023480.682361: Getting initial credentials for user at PRINCIPAL
[24033] 1516023480.687733: Looked up etypes in keytab: aes256-cts,
rc4-hmac, des3-cbc-sha1, des-cbc-crc
[24033] 1516023480.687910: Sending request (176 bytes) to PRINCIPAL
[24033] 1516023480.688224: Resolving hostname XXX.XXX.XXX.168
[24033] 1516023480.688563: Sending initial UDP request to dgram
XXX.XXX.XXX.168:88
[24033] 1516023480.737062: Received answer (326 bytes) from dgram
XXX.XXX.XXX.168:88
[24033] 1516023480.737149: Response was not from master KDC
[24033] 1516023480.737245: Received error from KDC:
-1765328359/Additional pre-authentication required
[24033] 1516023480.737326: Processing preauth types: 136, 19, 2, 133
[24033] 1516023480.737346: Selected etype info: etype aes256-cts, salt
"PRINCIPALuser", params ""
[24033] 1516023480.737358: Received cookie: MIT
[24033] 1516023480.737471: Retrieving user at PRINCIPAL from
FILE:/root/user.keytab (vno 0, enctype aes256-cts) with result:
0/Success
[24033] 1516023480.737518: AS key obtained for encrypted timestamp:
aes256-cts/114F
[24033] 1516023480.737640: Encrypted timestamp (for 1516023525.32174):
plain 3019A01118xx, encrypted 32A7BD9DDA3xxx
[24033] 1516023480.737665: Preauth module encrypted_timestamp (2)
(real) returned: 0/Success
[24033] 1516023480.737674: Produced preauth for next request: 133, 2
[24033] 1516023480.737705: Sending request (270 bytes) to PRINCIPAL
[24033] 1516023480.737736: Resolving hostname XXX.XXX.XXX.168
[24033] 1516023480.737929: Sending initial UDP request to dgram
XXX.XXX.XXX.168:88
[24033] 1516023480.830272: Received answer (765 bytes) from dgram
XXX.XXX.XXX.168:88
[24033] 1516023480.830434: Response was not from master KDC
[24033] 1516023480.830492: Processing preauth types: 19
[24033] 1516023480.830509: Selected etype info: etype aes256-cts, salt
"PRINCIPALuser", params ""
[24033] 1516023480.830523: Produced preauth for next request: (empty)
[24033] 1516023480.830541: AS key determined by preauth: aes256-cts/114F
[24033] 1516023480.830666: Decrypted AS reply; session key is: aes256-cts/05B5
[24033] 1516023480.830711: FAST negotiation: available
[24033] 1516023480.830760: Initializing FILE:/tmp/krb5cc_0 with
default princ user at PRINCIPAL
[24033] 1516023480.831344: Storing user at PRINCIPAL ->
krbtgt/PRINCIPAL at PRINCIPAL in FILE:/tmp/krb5cc_0
[24033] 1516023480.831551: Storing config in FILE:/tmp/krb5cc_0 for
krbtgt/PRINCIPAL at PRINCIPAL: fast_avail: yes
[24033] 1516023480.831636: Storing user at PRINCIPAL ->
krb5_ccache_conf_data/fast_avail/krbtgt\/PRINCIPAL\@PRINCIPAL at X-CACHECONF:
in FILE:/tmp/krb5cc_0
[24033] 1516023480.831708: Storing config in FILE:/tmp/krb5cc_0 for
krbtgt/PRINCIPAL at PRINCIPAL: pa_type: 2
[24033] 1516023480.831766: Storing user at PRINCIPAL ->
krb5_ccache_conf_data/pa_type/krbtgt\/PRINCIPAL\@PRINCIPAL at X-CACHECONF:
in FILE:/tmp/krb5cc_0
%7|1516023480.832|SASLREFRESH|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: SASL key refreshed
%7|1516023480.832|SASL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: My supported SASL mechanisms:
GS2-IAKERB GS2-KRB5 SCRAM-SHA-1 GSSAPI GSS-SPNEGO DIGEST-MD5 EXTERNAL
OTP CRAM-MD5 PLAIN ANONYMOUS
%5|1516023480.832|LIBSASL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: GSSAPI client step 1
%7|1516023480.894|LIBSASL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: CB_CANON: flags 0x3,
"user at PRINCIPAL" @ "(null)": returning "user at PRINCIPAL"
%7|1516023480.894|SASL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Selected SASL mechanism: GSSAPI
(wanted GSSAPI)
%7|1516023480.894|SASL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Send SASL frame to broker (605
bytes)
%7|1516023480.943|SASL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Received SASL frame from broker
(36 bytes)
%5|1516023480.943|LIBSASL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: GSSAPI client step 2
%7|1516023480.943|SASL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Send SASL frame to broker (32
bytes)
%7|1516023480.944|SASL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Authenticated as user at PRINCIPAL
using GSSAPI (gssapiv2)
%7|1516023480.944|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Sent MetadataRequest (v2, 25
bytes @ 0, CorrId 3)
%7|1516023481.076|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/bootstrap: Received MetadataResponse (v2,
80 bytes, CorrId 3, rtt 132.29ms)
%7|1516023481.076|SUBSCRIPTION|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel": no topics in metadata matched subscription
%7|1516023481.076|BRKREASSIGN|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel" management reassigned from broker :0/internal
to sasl_plaintext://host3:9092/bootstrap
%7|1516023481.076|BRKUNASSIGN|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel" management unassigned from broker handle
:0/internal
%7|1516023481.076|BRKASSIGN|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel" management assigned to broker
sasl_plaintext://host3:9092/bootstrap
%7|1516023481.076|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/bootstrap: Group "user-cctv_python_rhel":
querying for coordinator: intervaled in state wait-broker
%7|1516023481.077|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Sent GroupCoordinatorRequest (v0, 46
bytes @ 0, CorrId 4)
%7|1516023481.125|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Received GroupCoordinatorResponse (v0,
22 bytes, CorrId 4, rtt 48.33ms)
%7|1516023481.125|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel"
coordinator is host2:9092 id 2
%7|1516023481.125|CGRPCOORD|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel" changing coordinator -1 -> 2
%7|1516023481.435|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
%7|1516023482.331|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel": querying
for coordinator: intervaled in state wait-broker
%7|1516023482.331|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Sent GroupCoordinatorRequest (v0, 46
bytes @ 0, CorrId 5)
%7|1516023482.379|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Received GroupCoordinatorResponse (v0,
22 bytes, CorrId 5, rtt 48.04ms)
%7|1516023482.379|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel"
coordinator is host2:9092 id 2
%7|1516023482.483|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
%7|1516023483.332|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel": querying
for coordinator: intervaled in state wait-broker
%7|1516023483.332|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Sent GroupCoordinatorRequest (v0, 46
bytes @ 0, CorrId 6)
%7|1516023483.380|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Received GroupCoordinatorResponse (v0,
22 bytes, CorrId 6, rtt 47.82ms)
%7|1516023483.380|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel"
coordinator is host2:9092 id 2
%7|1516023483.531|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
%7|1516023484.332|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel": querying
for coordinator: intervaled in state wait-broker
%7|1516023484.332|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Sent GroupCoordinatorRequest (v0, 46
bytes @ 0, CorrId 7)
%7|1516023484.380|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Received GroupCoordinatorResponse (v0,
22 bytes, CorrId 7, rtt 47.90ms)
%7|1516023484.380|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel"
coordinator is host2:9092 id 2
%7|1516023484.579|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
%7|1516023485.330|COMMIT|rdkafka#consumer-1| [thrd:main]: OffsetCommit
internal error: Local: No offset stored
%7|1516023485.330|COMMIT|rdkafka#consumer-1| [thrd:main]: OffsetCommit
for -1 partition(s): cgrp auto commit timer: returned: Local: No
offset stored
%7|1516023485.330|UNASSIGN|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel": unassign done in state wait-broker (join
state init): without new assignment: OffsetCommit done (__NO_OFFSET)
%7|1516023485.332|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel": querying
for coordinator: intervaled in state wait-broker
%7|1516023485.332|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Sent GroupCoordinatorRequest (v0, 46
bytes @ 0, CorrId 8)
%7|1516023485.380|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Received GroupCoordinatorResponse (v0,
22 bytes, CorrId 8, rtt 47.95ms)
%7|1516023485.380|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel"
coordinator is host2:9092 id 2
%7|1516023485.627|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
%7|1516023486.332|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel": querying
for coordinator: intervaled in state wait-broker
%7|1516023486.332|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Sent GroupCoordinatorRequest (v0, 46
bytes @ 0, CorrId 9)
%7|1516023486.380|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Received GroupCoordinatorResponse (v0,
22 bytes, CorrId 9, rtt 48.03ms)
%7|1516023486.380|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel"
coordinator is host2:9092 id 2
%7|1516023486.675|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
%7|1516023487.332|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel": querying
for coordinator: intervaled in state wait-broker
%7|1516023487.332|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Sent GroupCoordinatorRequest (v0, 46
bytes @ 0, CorrId 10)
%7|1516023487.380|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Received GroupCoordinatorResponse (v0,
22 bytes, CorrId 10, rtt 47.92ms)
%7|1516023487.380|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel"
coordinator is host2:9092 id 2
%7|1516023487.723|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
%7|1516023488.332|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel": querying
for coordinator: intervaled in state wait-broker
%7|1516023488.332|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Sent GroupCoordinatorRequest (v0, 46
bytes @ 0, CorrId 11)
%7|1516023488.380|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Received GroupCoordinatorResponse (v0,
22 bytes, CorrId 11, rtt 47.85ms)
%7|1516023488.380|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel"
coordinator is host2:9092 id 2
%7|1516023488.770|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
%7|1516023489.332|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel": querying
for coordinator: intervaled in state wait-broker
%7|1516023489.332|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Sent GroupCoordinatorRequest (v0, 46
bytes @ 0, CorrId 12)
%7|1516023489.380|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Received GroupCoordinatorResponse (v0,
22 bytes, CorrId 12, rtt 48.05ms)
%7|1516023489.380|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel"
coordinator is host2:9092 id 2
%7|1516023489.818|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
%7|1516023490.330|COMMIT|rdkafka#consumer-1| [thrd:main]: OffsetCommit
internal error: Local: No offset stored
%7|1516023490.331|COMMIT|rdkafka#consumer-1| [thrd:main]: OffsetCommit
for -1 partition(s): cgrp auto commit timer: returned: Local: No
offset stored
%7|1516023490.331|UNASSIGN|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel": unassign done in state wait-broker (join
state init): without new assignment: OffsetCommit done (__NO_OFFSET)
%7|1516023490.332|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel": querying
for coordinator: intervaled in state wait-broker
%7|1516023490.332|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Sent GroupCoordinatorRequest (v0, 46
bytes @ 0, CorrId 13)
%7|1516023490.380|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Received GroupCoordinatorResponse (v0,
22 bytes, CorrId 13, rtt 47.85ms)
%7|1516023490.380|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel"
coordinator is host2:9092 id 2
%7|1516023490.866|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
%7|1516023491.332|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel": querying
for coordinator: intervaled in state wait-broker
%7|1516023491.332|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Sent GroupCoordinatorRequest (v0, 46
bytes @ 0, CorrId 14)
%7|1516023491.380|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Received GroupCoordinatorResponse (v0,
22 bytes, CorrId 14, rtt 47.97ms)
%7|1516023491.380|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel"
coordinator is host2:9092 id 2
%7|1516023491.913|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
%7|1516023492.332|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel": querying
for coordinator: intervaled in state wait-broker
%7|1516023492.332|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Sent GroupCoordinatorRequest (v0, 46
bytes @ 0, CorrId 15)
%7|1516023492.380|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Received GroupCoordinatorResponse (v0,
22 bytes, CorrId 15, rtt 48.20ms)
%7|1516023492.380|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel"
coordinator is host2:9092 id 2
%7|1516023492.961|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
%7|1516023493.332|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel": querying
for coordinator: intervaled in state wait-broker
%7|1516023493.332|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Sent GroupCoordinatorRequest (v0, 46
bytes @ 0, CorrId 16)
%7|1516023493.380|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Received GroupCoordinatorResponse (v0,
22 bytes, CorrId 16, rtt 47.94ms)
%7|1516023493.380|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel"
coordinator is host2:9092 id 2
%7|1516023494.009|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
%7|1516023494.332|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel": querying
for coordinator: intervaled in state wait-broker
%7|1516023494.332|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Sent GroupCoordinatorRequest (v0, 46
bytes @ 0, CorrId 17)
%7|1516023494.380|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Received GroupCoordinatorResponse (v0,
22 bytes, CorrId 17, rtt 48.04ms)
%7|1516023494.380|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel"
coordinator is host2:9092 id 2
%7|1516023495.056|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
%7|1516023495.331|COMMIT|rdkafka#consumer-1| [thrd:main]: OffsetCommit
internal error: Local: No offset stored
%7|1516023495.331|COMMIT|rdkafka#consumer-1| [thrd:main]: OffsetCommit
for -1 partition(s): cgrp auto commit timer: returned: Local: No
offset stored
%7|1516023495.331|UNASSIGN|rdkafka#consumer-1| [thrd:main]: Group
"user-cctv_python_rhel": unassign done in state wait-broker (join
state init): without new assignment: OffsetCommit done (__NO_OFFSET)
%7|1516023495.332|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel": querying
for coordinator: intervaled in state wait-broker
%7|1516023495.332|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Sent GroupCoordinatorRequest (v0, 46
bytes @ 0, CorrId 18)
%7|1516023495.380|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Received GroupCoordinatorResponse (v0,
22 bytes, CorrId 18, rtt 47.87ms)
%7|1516023495.380|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel"
coordinator is host2:9092 id 2
^C%7|1516023496.105|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
^C^C%7|1516023496.332|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel": querying
for coordinator: intervaled in state wait-broker
%7|1516023496.332|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Sent GroupCoordinatorRequest (v0, 46
bytes @ 0, CorrId 19)
%7|1516023496.380|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Received GroupCoordinatorResponse (v0,
22 bytes, CorrId 19, rtt 47.91ms)
%7|1516023496.380|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel"
coordinator is host2:9092 id 2
^C%7|1516023497.152|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
%7|1516023497.332|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel": querying
for coordinator: intervaled in state wait-broker
%7|1516023497.332|SEND|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Sent GroupCoordinatorRequest (v0, 46
bytes @ 0, CorrId 20)
%7|1516023497.380|RECV|rdkafka#consumer-1|
[thrd:sasl_plaintext://host3:9092/bootstrap]:
sasl_plaintext://host3:9092/3: Received GroupCoordinatorResponse (v0,
22 bytes, CorrId 20, rtt 47.98ms)
%7|1516023497.380|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
sasl_plaintext://host3:9092/3: Group "user-cctv_python_rhel"
coordinator is host2:9092 id 2
%7|1516023498.200|BROKERFAIL|rdkafka#consumer-1|
[thrd:sasl_plaintext://host1:9092/bootstrap]:
sasl_plaintext://host1:9092/bootstrap: failed: err: Local: Broker
transport failure: (errno: Connection refused)
Terminated
```
2018-01-15 11:06 GMT+01:00 Marcel Gutsche <mail at marcelgutsche.de>:
> Thanks for all the suggestions.
> I got rid of the "-S kafka/host" part, which also removed the credential
> not found error. But I still cannot connect to the KafkaServer using the
> VM. Maybe someone of you knows if the following log relates to a finally
> successful authorization, or if there is still something missing.
>
> ```
> %7|1516010149.485|SASL|rdkafka#consumer-1| [thrd:app]: Selected provider
> Cyrus for SASL mechanism GSSAPI
> %7|1516010149.485|MEMBERID|rdkafka#consumer-1| [thrd:app]: Group
> "user_python_rhel": updating member id "(not-set)" -> ""
> %7|1516010149.485|BRKREASSIGN|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel" management reassigned from broker (none) to :0/internal
> %7|1516010149.485|CGRPSTATE|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel" changed state init -> wait-broker (v1, join-state init)
> %7|1516010149.485|BRKASSIGN|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel" management assigned to broker :0/internal
> %7|1516010149.486|CGRPOP|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel" received op SUBSCRIBE (v0) in state wait-broker (join
> state init, v1 vs 0)
> %7|1516010149.486|SUBSCRIBE|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel": subscribe to new subscription of 1 topics (join state
> init)
> %7|1516010149.486|UNSUBSCRIBE|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel": unsubscribe from current unset subscription of 0 topics
> (leave group=no, join state init, v1)
> %7|1516010149.486|GRPLEADER|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel": resetting group leader info: unsubscribe
> %7|1516010149.486|CGRPJOINSTATE|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel" changed join state init -> wait-unassign (v1, state
> wait-broker)
> %7|1516010149.486|UNASSIGN|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel": unassign done in state wait-broker (join state
> wait-unassign): without new assignment: unassign (no previous assignment)
> %7|1516010149.486|CGRPJOINSTATE|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel" changed join state wait-unassign -> init (v1, state
> wait-broker)
> %7|1516010149.486|CGRPQUERY|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel": no broker available for coordinator query: intervaled
> in state wait-broker
> %3|1516010149.537|FAIL|rdkafka#consumer-1| [thrd:sasl_plaintext://host1:9092/bootstrap]:
> sasl_plaintext://host1:9092/bootstrap: Connect to
> ipv4#XXX.XXX.XXX.XXX:PPPP failed: Connection refused
> %3|1516010149.537|ERROR|rdkafka#consumer-1| [thrd:sasl_plaintext://host1:9092/bootstrap]:
> sasl_plaintext://host1:9092/bootstrap: Connect to
> ipv4#XXX.XXX.XXX.XXX:PPPP failed: Connection refused
> %7|1516010149.585|AUTH|rdkafka#consumer-1| [thrd:sasl_plaintext://host3:9092/bootstrap]:
> sasl_plaintext://host3:9092/bootstrap: Auth in state APIVERSION_QUERY
> (handshake supported)
> %7|1516010149.585|AUTH|rdkafka#consumer-1| [thrd:sasl_plaintext://host2:9092/bootstrap]:
> sasl_plaintext://host2:9092/bootstrap: Auth in state APIVERSION_QUERY
> (handshake supported)
> %7|1516010149.633|SASLMECHS|rdkafka#consumer-1|
> [thrd:sasl_plaintext://host3:9092/bootstrap]: sasl_plaintext://host3:9092/bootstrap:
> Broker supported SASL mechanisms: GSSAPI
> %7|1516010149.634|AUTH|rdkafka#consumer-1| [thrd:sasl_plaintext://host3:9092/bootstrap]:
> sasl_plaintext://host3:9092/bootstrap: Auth in state AUTH_HANDSHAKE
> (handshake supported)
> %7|1516010149.634|SASLMECHS|rdkafka#consumer-1|
> [thrd:sasl_plaintext://host2:9092/bootstrap]: sasl_plaintext://host2:9092/bootstrap:
> Broker supported SASL mechanisms: GSSAPI
> %7|1516010149.634|AUTH|rdkafka#consumer-1| [thrd:sasl_plaintext://host2:9092/bootstrap]:
> sasl_plaintext://host2:9092/bootstrap: Auth in state AUTH_HANDSHAKE
> (handshake supported)
> %7|1516010149.634|SASL|rdkafka#consumer-1| [thrd:sasl_plaintext://host2:9092/bootstrap]:
> sasl_plaintext://host2:9092/bootstrap: Initializing SASL client: service
> name kafka, hostname host2, mechanisms GSSAPI, provider Cyrus
> %7|1516010149.634|SASLREFRESH|rdkafka#consumer-1|
> [thrd:sasl_plaintext://host2:9092/bootstrap]: sasl_plaintext://host2:9092/bootstrap:
> Refreshing SASL keys with command: kinit -kt {} user at PRINCIPAL
> %7|1516010149.634|SASL|rdkafka#consumer-1| [thrd:sasl_plaintext://host3:9092/bootstrap]:
> sasl_plaintext://host3:9092/bootstrap: Initializing SASL client: service
> name kafka, hostname host3, mechanisms GSSAPI, provider Cyrus
> %7|1516010149.634|SASLREFRESH|rdkafka#consumer-1|
> [thrd:sasl_plaintext://host3:9092/bootstrap]: sasl_plaintext://host3:9092/bootstrap:
> Refreshing SASL keys with command: kinit -kt {} user at PRINCIPAL
> kinit: Pre-authentication failed: Key table file '{}' not found while
> getting initial credentials
> %3|1516010149.700|SASLREFRESH|rdkafka#consumer-1|
> [thrd:sasl_plaintext://host2:9092/bootstrap]: sasl_plaintext://host2:9092/bootstrap:
> SASL key refresh failed: kinit -kt {} user at PRINCIPAL: exited with code 1
> %7|1516010149.701|SASL|rdkafka#consumer-1| [thrd:sasl_plaintext://host2:9092/bootstrap]:
> sasl_plaintext://host2:9092/bootstrap: My supported SASL mechanisms:
> GS2-IAKERB GS2-KRB5 SCRAM-SHA-1 GSSAPI GSS-SPNEGO DIGEST-MD5 EXTERNAL OTP
> CRAM-MD5 PLAIN ANONYMOUS
> %5|1516010149.701|LIBSASL|rdkafka#consumer-1|
> [thrd:sasl_plaintext://host2:9092/bootstrap]: sasl_plaintext://host2:9092/bootstrap:
> GSSAPI client step 1
> kinit: Pre-authentication failed: Key table file '{}' not found while
> getting initial credentials
> %3|1516010149.764|SASLREFRESH|rdkafka#consumer-1|
> [thrd:sasl_plaintext://host3:9092/bootstrap]: sasl_plaintext://host3:9092/bootstrap:
> SASL key refresh failed: kinit -kt {} user at PRINCIPAL: exited with code 1
> %7|1516010149.764|SASL|rdkafka#consumer-1| [thrd:sasl_plaintext://host3:9092/bootstrap]:
> sasl_plaintext://host3:9092/bootstrap: My supported SASL mechanisms:
> GS2-IAKERB GS2-KRB5 SCRAM-SHA-1 GSSAPI GSS-SPNEGO DIGEST-MD5 EXTERNAL OTP
> CRAM-MD5 PLAIN ANONYMOUS
> %5|1516010149.764|LIBSASL|rdkafka#consumer-1|
> [thrd:sasl_plaintext://host3:9092/bootstrap]: sasl_plaintext://host3:9092/bootstrap:
> GSSAPI client step 1
> %7|1516010149.816|LIBSASL|rdkafka#consumer-1|
> [thrd:sasl_plaintext://host3:9092/bootstrap]: sasl_plaintext://host3:9092/bootstrap:
> CB_CANON: flags 0x3, "user at PRINCIPAL" @ "(null)": returning
> "user at PRINCIPAL"
> %7|1516010149.816|SASL|rdkafka#consumer-1| [thrd:sasl_plaintext://host3:9092/bootstrap]:
> sasl_plaintext://host3:9092/bootstrap: Selected SASL mechanism: GSSAPI
> (wanted GSSAPI)
> %7|1516010149.816|SASL|rdkafka#consumer-1| [thrd:sasl_plaintext://host3:9092/bootstrap]:
> sasl_plaintext://host3:9092/bootstrap: Send SASL frame to broker (624
> bytes)
> %7|1516010149.865|SASL|rdkafka#consumer-1| [thrd:sasl_plaintext://host3:9092/bootstrap]:
> sasl_plaintext://host3:9092/bootstrap: Received SASL frame from broker
> (36 bytes)
> %5|1516010149.865|LIBSASL|rdkafka#consumer-1|
> [thrd:sasl_plaintext://host3:9092/bootstrap]: sasl_plaintext://host3:9092/bootstrap:
> GSSAPI client step 2
> %7|1516010149.865|SASL|rdkafka#consumer-1| [thrd:sasl_plaintext://host3:9092/bootstrap]:
> sasl_plaintext://host3:9092/bootstrap: Send SASL frame to broker (32
> bytes)
> %7|1516010149.865|SASL|rdkafka#consumer-1| [thrd:sasl_plaintext://host3:9092/bootstrap]:
> sasl_plaintext://host3:9092/bootstrap: Authenticated as user at PRINCIPAL
> using GSSAPI (gssapiv2)
> %7|1516010149.999|SUBSCRIPTION|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel": no topics in metadata matched subscription
> %7|1516010149.999|BRKREASSIGN|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel" management reassigned from broker :0/internal to
> sasl_plaintext://host3:9092/3
> %7|1516010149.999|BRKUNASSIGN|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel" management unassigned from broker handle :0/internal
> %7|1516010149.999|BRKASSIGN|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel" management assigned to broker
> sasl_plaintext://host3:9092/3
> %7|1516010149.999|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel": querying for
> coordinator: intervaled in state wait-broker
> %7|1516010150.048|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel" coordinator is
> host2:9092 id 2
> %7|1516010150.048|CGRPCOORD|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel" changing coordinator -1 -> 2
> %7|1516010151.484|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel": querying for
> coordinator: intervaled in state wait-broker
> %7|1516010151.533|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel" coordinator is
> host2:9092 id 2
> %7|1516010152.485|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel": querying for
> coordinator: intervaled in state wait-broker
> %7|1516010152.533|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel" coordinator is
> host2:9092 id 2
> %7|1516010153.485|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel": querying for
> coordinator: intervaled in state wait-broker
> %7|1516010153.533|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel" coordinator is
> host2:9092 id 2
> %7|1516010154.485|COMMIT|rdkafka#consumer-1| [thrd:main]: OffsetCommit
> internal error: Local: No offset stored
> %7|1516010154.485|COMMIT|rdkafka#consumer-1| [thrd:main]: OffsetCommit
> for -1 partition(s): cgrp auto commit timer: returned: Local: No offset
> stored
> %7|1516010154.485|UNASSIGN|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel": unassign done in state wait-broker (join state init):
> without new assignment: OffsetCommit done (__NO_OFFSET)
> %7|1516010154.485|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel": querying for
> coordinator: intervaled in state wait-broker
> %7|1516010154.533|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel" coordinator is
> host2:9092 id 2
> %7|1516010155.485|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel": querying for
> coordinator: intervaled in state wait-broker
> %7|1516010155.534|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel" coordinator is
> host2:9092 id 2
> %7|1516010156.485|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel": querying for
> coordinator: intervaled in state wait-broker
> %7|1516010156.534|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel" coordinator is
> host2:9092 id 2
> %7|1516010157.485|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel": querying for
> coordinator: intervaled in state wait-broker
> %7|1516010157.534|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel" coordinator is
> host2:9092 id 2
> %7|1516010158.485|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel": querying for
> coordinator: intervaled in state wait-broker
> %7|1516010158.534|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel" coordinator is
> host2:9092 id 2
> %7|1516010159.485|COMMIT|rdkafka#consumer-1| [thrd:main]: OffsetCommit
> internal error: Local: No offset stored
> %7|1516010159.485|COMMIT|rdkafka#consumer-1| [thrd:main]: OffsetCommit
> for -1 partition(s): cgrp auto commit timer: returned: Local: No offset
> stored
> %7|1516010159.485|UNASSIGN|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel": unassign done in state wait-broker (join state init):
> without new assignment: OffsetCommit done (__NO_OFFSET)
> %7|1516010159.485|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel": querying for
> coordinator: intervaled in state wait-broker
> %7|1516010159.533|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel" coordinator is
> host2:9092 id 2
> %7|1516010160.485|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel": querying for
> coordinator: intervaled in state wait-broker
> %7|1516010160.534|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel" coordinator is
> host2:9092 id 2
> %7|1516010161.485|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel": querying for
> coordinator: intervaled in state wait-broker
> %7|1516010161.534|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel" coordinator is
> host2:9092 id 2
> %7|1516010162.485|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel": querying for
> coordinator: intervaled in state wait-broker
> %7|1516010162.534|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel" coordinator is
> host2:9092 id 2
> ^C^C%7|1516010163.485|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel": querying for
> coordinator: intervaled in state wait-broker
> %7|1516010163.534|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel" coordinator is
> host2:9092 id 2
> ^C^C%7|1516010164.485|COMMIT|rdkafka#consumer-1| [thrd:main]:
> OffsetCommit internal error: Local: No offset stored
> %7|1516010164.485|COMMIT|rdkafka#consumer-1| [thrd:main]: OffsetCommit
> for -1 partition(s): cgrp auto commit timer: returned: Local: No offset
> stored
> %7|1516010164.485|UNASSIGN|rdkafka#consumer-1| [thrd:main]: Group
> "user_python_rhel": unassign done in state wait-broker (join state init):
> without new assignment: OffsetCommit done (__NO_OFFSET)
> %7|1516010164.485|CGRPQUERY|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel": querying for
> coordinator: intervaled in state wait-broker
> %7|1516010164.534|CGRPCOORD|rdkafka#consumer-1| [thrd:main]:
> sasl_plaintext://host3:9092/3: Group "user_python_rhel" coordinator is
> host2:9092 id 2
> ```
>
> As you can see I am still stuck and waiting for the broker, but that might
> be unrelated to the kerberos authorization process. To lift the confusion
> about DNS and PRINCIPAL and hosts I also add my /etc/hosts and my krb5.conf
> file:
>
> /etc/hosts
>
> ```
> 127.0.0.1 localhost localhost.localdomain localhost4
> localhost4.localdomain4
> ::1 localhost localhost.localdomain localhost6
> localhost6.localdomain6
> XXX.XXX.67.237 host1
> XXX.XXX.67.168 principal host2 PRINCIPAL
> XXX.XXX.67.184 host3
> ```
> krb5.conf
> ```
> [libdefaults]
> default_realm = PRINCIPAL
> dns_lookup_kdc = false
>
>
> [realms]
> KDDLAB.KRB.GR = {
> kdc = XXX.XXX.67.168
> admin_server = XXX.XXX.67.168
> }
>
> [domain_realm]
>
> [logging]
> kdc = SYSLOG:INFO
> admin_server = FILE=/var/log/kadm5.log
>
> ```
>
> 2018-01-14 9:43 GMT+01:00 Fabiano Tarlao <ftarlao at gmail.com>:
>
>> I'm a newbie and had a similar issue, in order to find out the right
>> principal for a service, I executed Wireshark on client or server node in a
>> test env... Wireshark kerberos dissector works quite well and tuo can see
>> details of requests, principals too. Perhaps this ke obvious but.. Not for
>> me :-(
>>
>> Il 13 gen 2018 17:46, "Greg Hudson" <ghudson at mit.edu> ha scritto:
>>
>>> My best guess is that there is a disagreement between the server
>>> principal name passed to kinit -S ("kafka/host") and the server
>>> principal name chosen by SASL GSSAPI. At least, that's the most obvious
>>> way I can find to get a "Matching credential not found" error message
>>> from MIT krb5's GSSAPI library. It's hard for me to be sure since I'm
>>> not seeing any krb5 trace logs resulting from the SASL operation, only
>>> from the kinit operation. (I would expect to see at least trace logs
>>> like "Getting credentials <clientprinc> -> <serverprinc> using ccache
>>> <ccache>" and "Retrieving <clientprinc> -> <serverprinc> from <ccache>
>>> with result: ...")
>>>
>>> If you can configure rdkafka to acquire a TGT from the keytab instead of
>>> directly acquiring a service ticket (by removing "-S kafka/host" from
>>> the kinit command line), you could verify that this is the problem and
>>> to determine (using klist) what service ticket is acquired during
>>> authentication.
>>>
>>> ________________________________________________
>>> Kerberos mailing list Kerberos at mit.edu
>>> https://mailman.mit.edu/mailman/listinfo/kerberos
>>>
>>
>
More information about the Kerberos
mailing list