2022-10-28T12:11:30.0390301Z tests_1 | === RUN TestLogHandlerAccept
2022-10-28T12:11:30.0391132Z tests_1 | logger.go:41: [subscription] INFO Forwarded new subscription {"clientId":"dummy","timestamp":"2021-11-03T19:04:23Z","topicId":"c//Testing:Logs/q/#","topicReal":"command//Testing:Logs/req/#"}
2022-10-28T12:11:30.0392165Z tests_1 | logger.go:41: [subscription] INFO The same subscription exists {"clientId":"dummy","timestamp":"2021-11-03T19:04:23Z","topicId":"c//Testing:Logs/q/#","topicReal":"command//Testing:Logs/req/#"}, no action
2022-10-28T12:11:30.0393131Z tests_1 | logger.go:41: [subscription] INFO Forwarded unsubscribe {"clientId":"dummy","timestamp":"2021-11-03T19:04:23Z","topicId":"c//Testing:Logs/q/#","topicReal":"command//Testing:Logs/req/#"}
2022-10-28T12:11:30.0394433Z tests_1 | logger.go:41: [subscription] INFO Forwarded new subscription {"clientId":"dummy1","timestamp":"2021-11-03T19:04:23Z","topicId":"c//Testing:Logs/q/#","topicReal":"command//Testing:Logs/req/#"}
2022-10-28T12:11:30.0395467Z tests_1 | logger.go:41: [subscription] INFO Forward unsubscribe {"clientId":"dummy1","timestamp":"2021-11-03T19:04:23Z","topicId":"c//Testing:Logs/q/#","topicReal":"command//Testing:Logs/req/#"} due to 3
2022-10-28T12:11:30.0396439Z tests_1 | logger.go:41: [subscription] INFO Forwarded new subscription {"clientId":"dummy2","timestamp":"2021-11-03T19:04:23Z","topicId":"c//Testing:Logs/q/#","topicReal":"command//Testing:Logs/req/#"}
2022-10-28T12:11:30.0397415Z tests_1 | logger.go:41: [subscription] INFO Forward unsubscribe {"clientId":"dummy2","timestamp":"2021-11-03T19:04:23Z","topicId":"c//Testing:Logs/q/#","topicReal":"command//Testing:Logs/req/#"} due to 2
2022-10-28T12:11:30.0398368Z tests_1 | logger.go:41: [subscription] INFO Forwarded new subscription {"clientId":"dummy3","timestamp":"2021-11-03T19:04:23Z","topicId":"c//Testing:Logs/q/#","topicReal":"command//Testing:Logs/req/#"}
2022-10-28T12:11:30.0399928Z tests_1 | logger.go:41: [subscription] INFO Subscription with different format or client exist {"clientId":"dummy3","timestamp":"2021-11-03T19:04:23Z","topicId":"c//Testing:Logs/q/#","topicReal":"command//Testing:Logs/req/#"}, replaced and forwarded the new routing.SubscriptionItem{ClientID:"dummy4", Timestamp:time.Date(2021, time.November, 3, 19, 4, 23, 0, time.Local), TopicID:"c//Testing:Logs/q/#", TopicReal:"command//Testing:Logs/req/#"}
2022-10-28T12:11:30.0401200Z tests_1 | --- PASS: TestLogHandlerAccept (0.00s)
2022-10-28T12:11:30.0401552Z tests_1 | === RUN TestLogHandlerReject
2022-10-28T12:11:30.0401977Z tests_1 | --- PASS: TestLogHandlerReject (0.00s)
2022-10-28T12:11:30.0402255Z tests_1 | PASS
2022-10-28T12:11:30.0416836Z tests_1 | panic: Log in goroutine after TestServiceRouter has completed: [testing] INFO Connected clean_session=true client_id=KcF8ShTdRU4xA5pzveD5CB mqtt_url=tcp://mosquitto:1883
2022-10-28T12:11:30.0417349Z tests_1 |
2022-10-28T12:11:30.0417580Z tests_1 |
2022-10-28T12:11:30.0417827Z tests_1 | goroutine 93 [running]:
2022-10-28T12:11:30.0418194Z tests_1 | testing.(*common).logDepth(0xc0001af040, {0xc00011fdc0, 0x6e}, 0x3)
2022-10-28T12:11:30.0418600Z tests_1 | /usr/local/go/src/testing/testing.go:779 +0x4c9
2022-10-28T12:11:30.0418919Z tests_1 | testing.(*common).log(...)
2022-10-28T12:11:30.0419261Z tests_1 | /usr/local/go/src/testing/testing.go:761
2022-10-28T12:11:30.0419636Z tests_1 | testing.(*common).Log(0x40ab07, {0xc0002864e0, 0x78f480, 0x1})
2022-10-28T12:11:30.0420018Z tests_1 | /usr/local/go/src/testing/testing.go:800 +0x45
2022-10-28T12:11:30.0420742Z tests_1 | github.com/eclipse-kanto/suite-connector/testutil.(*testExporter).Export(0xc0001fd200, 0x20, {0xc00019cc00, 0x78f640})
2022-10-28T12:11:30.0421186Z tests_1 | /src/testutil/logger.go:41 +0x1bf
2022-10-28T12:11:30.0421852Z tests_1 | github.com/eclipse-kanto/suite-connector/logger.(*loggerExt).log(0xc0001fd220, 0x40ab07, {0x7ffb1a, 0x78f480}, 0xc0001bbd40)
2022-10-28T12:11:30.0422290Z tests_1 | /src/logger/logger.go:182 +0x4b9
2022-10-28T12:11:30.0422870Z tests_1 | github.com/eclipse-kanto/suite-connector/logger.(*loggerExt).Info(0x7bb1e0, {0x7ffb1a, 0x8015f6}, 0xd)
2022-10-28T12:11:30.0423292Z tests_1 | /src/logger/logger.go:102 +0x51
2022-10-28T12:11:30.0423897Z tests_1 | github.com/eclipse-kanto/suite-connector/connector.(*MQTTConnection).onConnected(0xc0001038c0, {0x0, 0x0})
2022-10-28T12:11:30.0424337Z tests_1 | /src/connector/connection.go:340 +0x1b4
2022-10-28T12:11:30.0424795Z tests_1 | created by github.com/eclipse/paho%2emqtt%2egolang.(*client).startCommsWorkers
2022-10-28T12:11:30.0425275Z tests_1 | /go/pkg/mod/github.com/eclipse/[email protected]/client.go:573 +0x4a5
2022-10-28T12:11:30.0512749Z tests_1 | FAIL github.com/eclipse-kanto/suite-connector/routing 0.024s
2022-10-28T12:11:30.0513396Z tests_1 | FAIL
2022-10-28T12:11:30.3094054Z tests_1 | exit status 1docker_tests_1 exited with code 1