Dominick Madden created STREAMPIPES-574:
-------------------------------------------
Summary: MQTT Adapter Suddently Unable to Connect due to
Authorization Issue
Key: STREAMPIPES-574
URL: https://issues.apache.org/jira/browse/STREAMPIPES-574
Project: StreamPipes
Issue Type: Bug
Components: Connect
Reporter: Dominick Madden
h1. Issue
One of our MQTT Adapters we use as a data source for one of our production
pipelines stopped delivering data. After checking the logs (see below) it was
found that the MQTT client was unable to connect to the broker on account of an
authorization problem.
After double-checking that the credentials did not change (via an MQTT command
line client), the pipeline was stopped and the adapter restarted. This did not
solve the issue. Checking the logs verified that the same error occured.
A newly created Adapter (with the same URL, username and password) turned out
to work fine again.
h1. Extra Info
We have had a couple of Kubernetes Node problems lately which might have
randomly deleted / rescheduled Pods onto other Nodes.
h2. Connect Worker Logs:
{noformat}
❯ ks2 logs connect-worker-7c9569d477-kv4qp
14:52:35,928 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could
NOT find resource [logback-test.xml]
14:52:35,929 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could
NOT find resource [logback.groovy]
14:52:35,929 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found
resource [logback.xml] at [jar:file:/streampipes-connect
-adapters.jar!/BOOT-INF/lib/streampipes-commons-0.68.0.jar!/logback.xml]
14:52:35,932 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource
[logback.xml] occurs multiple times on the classpath.
14:52:35,932 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource
[logback.xml] occurs at [jar:file:/streampipes-connec
t-adapters.jar!/BOOT-INF/lib/streampipes-commons-0.68.0.jar!/logback.xml]
14:52:35,932 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource
[logback.xml] occurs at [jar:file:/streampipes-connec
t-adapters.jar!/BOOT-INF/lib/plc4j-driver-s7-0.8.0.jar!/logback.xml]
14:52:35,959 |-INFO in
ch.qos.logback.core.joran.spi.ConfigurationWatchList@612d8c37 - URL
[jar:file:/streampipes-connect-adapters.ja
r!/BOOT-INF/lib/streampipes-commons-0.68.0.jar!/logback.xml] is not of type file
14:52:36,012 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction
- debug attribute not set
14:52:36,016 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About
to instantiate appender of type [ch.qos.logback.core.C
onsoleAppender]
14:52:36,024 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming
appender as [STDOUT]
14:52:36,076 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - This
appender no longer admits a layout as a sub-component, set
an encoder instead.
14:52:36,077 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - To ensure
compatibility, wrapping your layout in LayoutWrappingE
ncoder.
14:52:36,077 |-WARN in ch.qos.logback.core.ConsoleAppender[STDOUT] - See also
http://logback.qos.ch/codes.html#layoutInsteadOfEncoder
for details
14:52:36,078 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction -
Setting level of logger [org.apache.streampipes] to INFO
14:52:36,078 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction -
Setting level of logger [org.lightcouch] to ERROR
14:52:36,078 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction -
Setting level of logger [org.apache.kafka] to ERROR
14:52:36,078 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction -
Setting level of ROOT logger to INFO
14:52:36,078 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction -
Attaching appender named [STDOUT] to Logger[ROOT]
14:52:36,078 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction
- End of configuration.
14:52:36,080 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@895f9399
- Registering current configuration as safe fallback p
oint14:52:36.157 SP [main] INFO o.a.s.config.consul.ConsulSpConfig - Trying to
connect to Consul to register config items
14:52:36.167 SP [main] INFO o.a.s.config.consul.ConsulSpConfig - Successfully
connected to Consul
14:52:37.315 SP [main] INFO o.a.s.c.c.w.i.AdapterWorkerContainer - Started
StreamPipes Connect Resource in WORKER mode
_______ __ ______ __
| __| |_.----.-----.---.-.--------.| __ \__|.-----.-----.-----.
|__ | _| _| -__| _ | || __/ || _ | -__|__ --|
|_______|____|__| |_____|___._|__|__|__||___| |__|| __|_____|_____|
|__|
** StreamPipes Connect Worker **log4j:WARN No appenders could be found for
logger (org.jboss.logging).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more
info.
14:52:38.132 SP [main] INFO o.a.s.connect.ConnectAdapterInit - Starting
ConnectAdapterInit v0.68.0 using Java 1.8.0_292 on connect-w
orker-7c9569d477-kv4qp with PID 1 (/streampipes-connect-adapters.jar started by
root in /)
14:52:38.137 SP [main] INFO o.a.s.connect.ConnectAdapterInit - No active
profile set, falling back to default profiles: default
14:52:39.667 SP [main] INFO o.s.b.w.s.c.ServletWebServerApplicationContext -
Root WebApplicationContext: initialization completed in
1452 ms
14:52:40.307 SP [main] INFO o.s.b.w.e.undertow.UndertowWebServer - Undertow
started on port(s) 8098 (http)
14:52:40.319 SP [main] INFO o.a.s.connect.ConnectAdapterInit - Started
ConnectAdapterInit in 2.834 seconds (JVM running for 4.912)
14:52:40.322 SP [main] INFO o.a.s.c.c.w.i.AdapterWorkerContainer - Trying to
connect to master: http://backend:8030/streampipes-back
end
14:52:42.426 SP [XNIO-1 task-1] INFO o.a.s.config.consul.ConsulSpConfig -
Trying to connect to Consul to register config items
14:52:42.428 SP [XNIO-1 task-1] INFO o.a.s.config.consul.ConsulSpConfig -
Successfully connected to Consul
14:52:42.488 SP [XNIO-1 task-1] INFO o.a.s.m.kafka.SpKafkaProducer - Kafka
producer: Connecting to org.apache.streampipes.connect.73
653e0e-b5d5-4af0-b071-65897410604a
14:52:43.004 SP [XNIO-1 task-1] ERROR o.a.s.m.kafka.SpKafkaProducer - Could not
create topic: org.apache.streampipes.connect.73653e0e
-b5d5-4af0-b071-65897410604a on broker null:0
14:52:43.084 SP [XNIO-1 task-1] INFO o.a.s.c.c.worker.rest.WorkerResource -
Stream adapter with id http://backend:8030/streampipes-b
ackend/api/v2/connect/[email protected]/master/sources/9030f401-a579-4b9a-bb8b-44bb3d3d0ae5
successfully started
14:52:43.239 SP [XNIO-1 task-1] INFO o.a.s.m.kafka.SpKafkaProducer - Kafka
producer: Connecting to org.apache.streampipes.connect.eb
1b01e3-38c7-4e03-a738-f36a49a21436
14:52:43.255 SP [XNIO-1 task-1] ERROR o.a.s.m.kafka.SpKafkaProducer - Could not
create topic: org.apache.streampipes.connect.eb1b01e3
-38c7-4e03-a738-f36a49a21436 on broker null:0
14:52:43.262 SP [XNIO-1 task-1] INFO o.a.s.c.c.worker.rest.WorkerResource -
Stream adapter with id http://backend:8030/streampipes-b
ackend/api/v2/connect/[email protected]/master/sources/86488fd5-8ff5-42b3-b23d-9e3229c6c7ab
successfully started
14:52:43.369 SP [main] INFO o.a.s.c.c.w.i.AdapterWorkerContainer -
Successfully connected to master: http://backend:8030/streampipes
-backend Worker is now running.
14:52:48.456 SP [XNIO-1 task-1] INFO o.a.s.m.kafka.SpKafkaProducer - Kafka
producer: Connecting to org.apache.streampipes.connect.73
653e0e-b5d5-4af0-b071-65897410604a
14:52:48.478 SP [XNIO-1 task-1] ERROR o.a.s.m.kafka.SpKafkaProducer - Could not
create topic: org.apache.streampipes.connect.73653e0e
-b5d5-4af0-b071-65897410604a on broker null:0
14:52:48.487 SP [XNIO-1 task-1] INFO o.a.s.c.c.worker.rest.WorkerResource -
Stream adapter with id http://backend:8030/streampipes-b
ackend/api/v2/connect/[email protected]/master/sources/9030f401-a579-4b9a-bb8b-44bb3d3d0ae5
successfully started
14:53:07.013 SP [XNIO-1 task-1] INFO o.a.s.c.c.worker.rest.WorkerResource -
Stream adapter with id http://backend:8030/streampipes-b
ackend/api/v2/connect/[email protected]/master/sources/9030f401-a579-4b9a-bb8b-44bb3d3d0ae5
successfully stopped
14:53:08.402 SP [XNIO-1 task-1] INFO o.a.s.c.c.worker.rest.WorkerResource -
Stream adapter with id http://backend:8030/streampipes-b
ackend/api/v2/connect/[email protected]/master/sources/86488fd5-8ff5-42b3-b23d-9e3229c6c7ab
successfully stopped
14:53:14.544 SP [XNIO-1 task-5] INFO o.a.s.m.kafka.SpKafkaProducer - Kafka
producer: Connecting to org.apache.streampipes.connect.73
653e0e-b5d5-4af0-b071-65897410604a
14:53:14.572 SP [XNIO-1 task-5] ERROR o.a.s.m.kafka.SpKafkaProducer - Could not
create topic: org.apache.streampipes.connect.73653e0e
-b5d5-4af0-b071-65897410604a on broker null:0
14:53:14.585 SP [XNIO-1 task-5] INFO o.a.s.c.c.worker.rest.WorkerResource -
Stream adapter with id http://backend:8030/streampipes-b
ackend/api/v2/connect/[email protected]/master/sources/9030f401-a579-4b9a-bb8b-44bb3d3d0ae5
successfully started
14:53:15.971 SP [XNIO-1 task-5] INFO o.a.s.m.kafka.SpKafkaProducer - Kafka
producer: Connecting to org.apache.streampipes.connect.eb
1b01e3-38c7-4e03-a738-f36a49a21436
14:53:16.025 SP [XNIO-1 task-5] ERROR o.a.s.m.kafka.SpKafkaProducer - Could not
create topic: org.apache.streampipes.connect.eb1b01e3
-38c7-4e03-a738-f36a49a21436 on broker null:0
14:53:16.034 SP [XNIO-1 task-5] INFO o.a.s.c.c.worker.rest.WorkerResource -
Stream adapter with id http://backend:8030/streampipes-b
ackend/api/v2/connect/[email protected]/master/sources/86488fd5-8ff5-42b3-b23d-9e3229c6c7ab
successfully started
org.fusesource.mqtt.client.MQTTException: Could not connect:
CONNECTION_REFUSED_NOT_AUTHORIZED
at
org.fusesource.mqtt.client.CallbackConnection$LoginHandler$1.onTransportCommand(CallbackConnection.java:362)
at
org.fusesource.hawtdispatch.transport.TcpTransport.drainInbound(TcpTransport.java:713)
at
org.fusesource.hawtdispatch.transport.TcpTransport$6.run(TcpTransport.java:592)
at
org.fusesource.hawtdispatch.internal.NioDispatchSource$3.run(NioDispatchSource.java:209)
at
org.fusesource.hawtdispatch.internal.SerialDispatchQueue.run(SerialDispatchQueue.java:100)
at
org.fusesource.hawtdispatch.internal.pool.SimpleThread.run(SimpleThread.java:77)
09:47:47.921 SP [XNIO-1 task-4] INFO o.a.s.c.c.worker.rest.WorkerResource -
Stream adapter with id http://backend:8030/streampipes-b
ackend/api/v2/connect/[email protected]/master/sources/86488fd5-8ff5-42b3-b23d-9e3229c6c7ab
successfully stopped
09:47:49.882 SP [XNIO-1 task-4] INFO o.a.s.m.kafka.SpKafkaProducer - Kafka
producer: Connecting to org.apache.streampipes.connect.eb
1b01e3-38c7-4e03-a738-f36a49a21436
09:47:49.904 SP [XNIO-1 task-4] ERROR o.a.s.m.kafka.SpKafkaProducer - Could not
create topic: org.apache.streampipes.connect.eb1b01e3
-38c7-4e03-a738-f36a49a21436 on broker null:0
09:47:49.912 SP [XNIO-1 task-4] INFO o.a.s.c.c.worker.rest.WorkerResource -
Stream adapter with id http://backend:8030/streampipes-b
ackend/api/v2/connect/[email protected]/master/sources/86488fd5-8ff5-42b3-b23d-9e3229c6c7ab
successfully started
org.fusesource.mqtt.client.MQTTException: Could not connect:
CONNECTION_REFUSED_NOT_AUTHORIZED
at
org.fusesource.mqtt.client.CallbackConnection$LoginHandler$1.onTransportCommand(CallbackConnection.java:362)
at
org.fusesource.hawtdispatch.transport.TcpTransport.drainInbound(TcpTransport.java:713)
at
org.fusesource.hawtdispatch.transport.TcpTransport$6.run(TcpTransport.java:592)
at
org.fusesource.hawtdispatch.internal.NioDispatchSource$3.run(NioDispatchSource.java:209)
at
org.fusesource.hawtdispatch.internal.SerialDispatchQueue.run(SerialDispatchQueue.java:100)
at
org.fusesource.hawtdispatch.internal.pool.SimpleThread.run(SimpleThread.java:77)
09:16:55.959 SP [XNIO-1 task-1] INFO o.a.s.c.c.worker.rest.WorkerResource -
Stream adapter with id http://backend:8030/streampipes-b
ackend/api/v2/connect/[email protected]/master/sources/86488fd5-8ff5-42b3-b23d-9e3229c6c7ab
successfully stopped
09:17:29.645 SP [XNIO-1 task-1] INFO o.a.s.m.kafka.SpKafkaProducer - Kafka
producer: Connecting to org.apache.streampipes.connect.eb
1b01e3-38c7-4e03-a738-f36a49a21436
09:17:29.668 SP [XNIO-1 task-1] ERROR o.a.s.m.kafka.SpKafkaProducer - Could not
create topic: org.apache.streampipes.connect.eb1b01e3
-38c7-4e03-a738-f36a49a21436 on broker null:0
09:17:29.675 SP [XNIO-1 task-1] INFO o.a.s.c.c.worker.rest.WorkerResource -
Stream adapter with id http://backend:8030/streampipes-b
ackend/api/v2/connect/[email protected]/master/sources/86488fd5-8ff5-42b3-b23d-9e3229c6c7ab
successfully started
org.fusesource.mqtt.client.MQTTException: Could not connect:
CONNECTION_REFUSED_NOT_AUTHORIZED
at
org.fusesource.mqtt.client.CallbackConnection$LoginHandler$1.onTransportCommand(CallbackConnection.java:362)
at
org.fusesource.hawtdispatch.transport.TcpTransport.drainInbound(TcpTransport.java:713)
at
org.fusesource.hawtdispatch.transport.TcpTransport$6.run(TcpTransport.java:592)
at
org.fusesource.hawtdispatch.internal.NioDispatchSource$3.run(NioDispatchSource.java:209)
at
org.fusesource.hawtdispatch.internal.SerialDispatchQueue.run(SerialDispatchQueue.java:100)
at
org.fusesource.hawtdispatch.internal.pool.SimpleThread.run(SimpleThread.java:77)
09:17:31.744 SP [XNIO-1 task-1] INFO o.a.s.c.c.worker.rest.WorkerResource -
Stream adapter with id http://backend:8030/streampipes-b
ackend/api/v2/connect/[email protected]/master/sources/86488fd5-8ff5-42b3-b23d-9e3229c6c7ab
successfully stopped
09:18:00.892 SP [XNIO-1 task-2] INFO o.a.s.m.kafka.SpKafkaProducer - Kafka
producer: Connecting to org.apache.streampipes.connect.eb
1b01e3-38c7-4e03-a738-f36a49a21436
09:18:00.916 SP [XNIO-1 task-2] ERROR o.a.s.m.kafka.SpKafkaProducer - Could not
create topic: org.apache.streampipes.connect.eb1b01e3
-38c7-4e03-a738-f36a49a21436 on broker null:0
09:18:00.924 SP [XNIO-1 task-2] INFO o.a.s.c.c.worker.rest.WorkerResource -
Stream adapter with id http://backend:8030/streampipes-b
ackend/api/v2/connect/[email protected]/master/sources/86488fd5-8ff5-42b3-b23d-9e3229c6c7ab
successfully started
org.fusesource.mqtt.client.MQTTException: Could not connect:
CONNECTION_REFUSED_NOT_AUTHORIZED
at
org.fusesource.mqtt.client.CallbackConnection$LoginHandler$1.onTransportCommand(CallbackConnection.java:362)
at
org.fusesource.hawtdispatch.transport.TcpTransport.drainInbound(TcpTransport.java:713)
at
org.fusesource.hawtdispatch.transport.TcpTransport$6.run(TcpTransport.java:592)
at
org.fusesource.hawtdispatch.internal.NioDispatchSource$3.run(NioDispatchSource.java:209)
at
org.fusesource.hawtdispatch.internal.SerialDispatchQueue.run(SerialDispatchQueue.java:100)
at
org.fusesource.hawtdispatch.internal.pool.SimpleThread.run(SimpleThread.java:77)
{noformat}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
