{"action":"created","issue":{"url":"https://api.github.com/repos/eclipse/hono/issues/1097","repository_url":"https://api.github.com/repos/eclipse/hono","labels_url":"https://api.github.com/repos/eclipse/hono/issues/1097/labels{/name}","comments_url":"https://api.github.com/repos/eclipse/hono/issues/1097/comments","events_url":"https://api.github.com/repos/eclipse/hono/issues/1097/events","html_url":"https://github.com/eclipse/hono/issues/1097","id":422831470,"node_id":"MDU6SXNzdWU0MjI4MzE0NzA=","number":1097,"title":"Investigate slow 'testUploadMessagesWithTtdThatReplyWithCommand' test","user":{"login":"calohmn","id":891931,"node_id":"MDQ6VXNlcjg5MTkzMQ==","avatar_url":"https://avatars3.githubusercontent.com/u/891931?v=4","gravatar_id":"","url":"https://api.github.com/users/calohmn","html_url":"https://github.com/calohmn","followers_url":"https://api.github.com/users/calohmn/followers","following_url":"https://api.github.com/users/calohmn/following{/other_user}","gists_url":"https://api.github.com/users/calohmn/gists{/gist_id}","starred_url":"https://api.github.com/users/calohmn/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/calohmn/subscriptions","organizations_url":"https://api.github.com/users/calohmn/orgs","repos_url":"https://api.github.com/users/calohmn/repos","events_url":"https://api.github.com/users/calohmn/events{/privacy}","received_events_url":"https://api.github.com/users/calohmn/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":1,"created_at":"2019-03-19T16:28:46Z","updated_at":"2019-03-20T07:27:44Z","closed_at":null,"author_association":"CONTRIBUTOR","body":"The `testUploadMessagesWithTtdThatReplyWithCommand` test method in `HttpTestBase` seems to take a very long time.\r\nExcerpt from travis:\r\n````\r\n14:46:43.151 [Time-limited test] INFO  o.e.hono.tests.http.TelemetryHttpIT - running testUploadMessagesWithTtdThatReplyWithCommand\r\n14:46:43.151 [Time-limited test] INFO  o.e.hono.tests.http.TelemetryHttpIT - using HTTP adapter [host: localhost, http port: 32777, https port: 32775]\r\nHTTP14:46:43.639 [vert.x-eventloop-thread-0] INFO  o.e.h.c.i.AbstractRequestResponseClient - enabling caching of responses from registration/ae97cf44-431b-4532-bfd5-48307e15192e\r\n14:46:48.613 [Time-limited test] INFO  o.e.hono.tests.http.TelemetryHttpIT - messages sent: 20\r\n14:46:48.743 [vert.x-eventloop-thread-2] INFO  o.e.hono.tests.http.TelemetryHttpIT - messages received: 20\r\n14:46:53.706 [Time-limited test] INFO  o.e.hono.tests.http.TelemetryHttpIT - messages sent: 40\r\n14:46:53.833 [vert.x-eventloop-thread-2] INFO  o.e.hono.tests.http.TelemetryHttpIT - messages received: 40\r\n14:46:58.542 [Time-limited test] INFO  o.e.hono.tests.http.TelemetryHttpIT - messages sent: 60\r\n14:46:58.655 [vert.x-eventloop-thread-2] INFO  o.e.hono.tests.http.TelemetryHttpIT - messages received: 60\r\n14:46:58.799 [Time-limited test] INFO  o.e.hono.tests.http.TelemetryHttpIT - sent 60 and received 60 messages after 15313 milliseconds\r\n````\r\nor\r\n````\r\n14:47:34.159 [Time-limited test] INFO  o.e.hono.tests.http.EventHttpIT - running testUploadMessagesWithTtdThatReplyWithCommand\r\n14:47:34.159 [Time-limited test] INFO  o.e.hono.tests.http.EventHttpIT - using HTTP adapter [host: localhost, http port: 32777, https port: 32775]\r\nHTTP14:47:34.697 [vert.x-eventloop-thread-0] INFO  o.e.h.c.i.AbstractRequestResponseClient - enabling caching of responses from registration/44340935-7c81-413b-8c49-99f8e1c6b417\r\n14:47:39.114 [Time-limited test] INFO  o.e.hono.tests.http.EventHttpIT - messages sent: 20\r\n14:47:39.237 [vert.x-eventloop-thread-3] INFO  o.e.hono.tests.http.EventHttpIT - messages received: 20\r\n14:47:44.038 [Time-limited test] INFO  o.e.hono.tests.http.EventHttpIT - messages sent: 40\r\n14:47:44.173 [vert.x-eventloop-thread-3] INFO  o.e.hono.tests.http.EventHttpIT - messages received: 40\r\n14:47:48.817 [Time-limited test] INFO  o.e.hono.tests.http.EventHttpIT - messages sent: 60\r\n14:47:48.941 [vert.x-eventloop-thread-3] INFO  o.e.hono.tests.http.EventHttpIT - messages received: 60\r\n14:47:49.088 [Time-limited test] INFO  o.e.hono.tests.http.EventHttpIT - sent 60 and received 60 messages after 14537 milliseconds\r\n````\r\n\r\nIt should be investigated why that is the case."},"comment":{"url":"https://api.github.com/repos/eclipse/hono/issues/comments/474717157","html_url":"https://github.com/eclipse/hono/issues/1097#issuecomment-474717157","issue_url":"https://api.github.com/repos/eclipse/hono/issues/1097","id":474717157,"node_id":"MDEyOklzc3VlQ29tbWVudDQ3NDcxNzE1Nw==","user":{"login":"calohmn","id":891931,"node_id":"MDQ6VXNlcjg5MTkzMQ==","avatar_url":"https://avatars3.githubusercontent.com/u/891931?v=4","gravatar_id":"","url":"https://api.github.com/users/calohmn","html_url":"https://github.com/calohmn","followers_url":"https://api.github.com/users/calohmn/followers","following_url":"https://api.github.com/users/calohmn/following{/other_user}","gists_url":"https://api.github.com/users/calohmn/gists{/gist_id}","starred_url":"https://api.github.com/users/calohmn/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/calohmn/subscriptions","organizations_url":"https://api.github.com/users/calohmn/orgs","repos_url":"https://api.github.com/users/calohmn/repos","events_url":"https://api.github.com/users/calohmn/events{/privacy}","received_events_url":"https://api.github.com/users/calohmn/received_events","type":"User","site_admin":false},"created_at":"2019-03-20T07:27:44Z","updated_at":"2019-03-20T07:27:44Z","author_association":"CONTRIBUTOR","body":"@sophokles73 `CommandConnectionImpl.getCommandResponseSender` doesn't seem to take long in comparison. Local test run output:\r\n````\r\n07:00:03.719 - getCommandResponseSender: BEGIN tenant=b0fd66af-82e9-4cef-8e16-491833f458ff, replyId=3afb390a-38ed-4357-8284-d4814b7ea52f/178faede-5cf7-4189-b9c3-c54cd4767645\r\n07:00:03.719 - getCommandResponseSender: invoke CommandResponseSenderImpl.create; tenant=b0fd66af-82e9-4cef-8e16-491833f458ff, replyId=3afb390a-38ed-4357-8284-d4814b7ea52f/178faede-5cf7-4189-b9c3-c54cd4767645\r\n07:00:03.722 - sender open [target: control/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f/178faede-5cf7-4189-b9c3-c54cd4767645, sendQueueFull: false]\r\n07:00:03.722 - getCommandResponseSender: DONE WITH CommandResponseSenderImpl.create; tenant=b0fd66af-82e9-4cef-8e16-491833f458ff, replyId=3afb390a-38ed-4357-8284-d4814b7ea52f/178faede-5cf7-4189-b9c3-c54cd4767645\r\n````\r\n\r\nHere's a log excerpt of a complete local test run, containing a single loop run (i.e. one message being processed) in `HttpTestBase.testUploadMessages`:\r\n````\r\n08:00:03.466 [Time-limited test] INFO  o.e.hono.tests.http.TelemetryHttpIT - ###### START with #10 ######\r\n08:00:03.466 [Time-limited test] INFO  o.e.hono.tests.http.TelemetryHttpIT - send message 10 via httpClient\r\n   HTTP07:00:03.464 [vert.x-eventloop-thread-0] TRACE o.e.h.a.h.i.VertxBasedHttpProtocolAdapter - delivered command response [command-request-id: 1010e683e150-4ac6-4073-995a-f42a319b3de4] to application\r\n   HTTP07:00:03.465 [vert.x-eventloop-thread-0] TRACE o.e.h.a.h.ComponentMetaDataDecorator - setting status code of response to request [method: POST, URI: https://localhost:32792/control/res/1010e683e150-4ac6-4073-995a-f42a319b3de4\r\n   HTTP07:00:03.479 [vert.x-eventloop-thread-0] TRACE o.e.h.a.h.ComponentMetaDataDecorator - starting span for request [method: POST, URI: https://localhost:32792/telemetry\r\n   HTTP07:00:03.479 [vert.x-eventloop-thread-0] INFO  o.e.h.adapter.http.X509AuthHandler - parseCredentials: BEGIN\r\n   HTTP07:00:03.480 [vert.x-eventloop-thread-0] DEBUG o.e.h.adapter.http.X509AuthHandler - could not retrieve client certificate from request: peer not verified\r\n   HTTP07:00:03.480 [vert.x-eventloop-thread-0] INFO  o.e.h.adapter.http.X509AuthHandler - parseCredentials: END\r\n   HTTP07:00:03.482 [vert.x-eventloop-thread-0] DEBUG o.e.hono.client.impl.HonoClientImpl - reusing existing client [target: credentials/b0fd66af-82e9-4cef-8e16-491833f458ff]\r\n   HTTP07:00:03.483 [vert.x-eventloop-thread-0] DEBUG o.e.h.c.i.AbstractRequestResponseClient - sent request [target address: credentials/b0fd66af-82e9-4cef-8e16-491833f458ff, subject: get, correlation ID: cred-client-1766e5e2-6815-4da6-8fa9-66755572fc09] to service\r\n   HTTP07:00:03.487 [vert.x-eventloop-thread-0] TRACE o.e.h.c.i.AbstractRequestResponseClient - service has accepted request [target address: credentials/b0fd66af-82e9-4cef-8e16-491833f458ff, subject: get, correlation ID: cred-client-1766e5e2-6815-4da6-8fa9-66755572fc09]\r\n   HTTP07:00:03.489 [vert.x-eventloop-thread-0] DEBUG o.e.h.c.i.AbstractRequestResponseClient - received response [reply-to: credentials/b0fd66af-82e9-4cef-8e16-491833f458ff/07cc153e-3129-4c2a-9972-918ba9ac73b9, subject: null, correlation ID: cred-client-1766e5e2-6815-4da6-8fa9-66755572fc09, status: 200]\r\n   \r\n   HTTP07:00:03.489 [vert.x-worker-thread-8] DEBUG o.e.h.s.a.d.UsernamePasswordAuthProvider - validating password hash on vert.x worker thread [vert.x-worker-thread-8]\r\n   HTTP07:00:03.490 [vert.x-eventloop-thread-0] TRACE o.e.h.client.impl.AbstractHonoClient - handling message received on credentials/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f [remotely settled: false, queued messages: 0, remaining credit: 199]\r\n   HTTP07:00:03.576 [vert.x-worker-thread-8] DEBUG o.e.h.s.a.d.UsernamePasswordAuthProvider - DONE validating password hash\r\n   => validating password hash took 87ms\r\n\r\n   HTTP07:00:03.578 [vert.x-eventloop-thread-0] INFO  o.e.h.a.h.i.VertxBasedHttpProtocolAdapter - uploadTelemetryMessage\r\n   HTTP07:00:03.578 [vert.x-eventloop-thread-0] DEBUG o.e.hono.client.impl.HonoClientImpl - reusing existing message sender [target: TelemetrySenderImpl#telemetry/b0fd66af-82e9-4cef-8e16-491833f458ff, credit: 250]\r\n   HTTP07:00:03.578 [vert.x-eventloop-thread-0] INFO  o.e.h.a.h.i.VertxBasedHttpProtocolAdapter - doUploadMessage: BEGIN\r\n   HTTP07:00:03.578 [vert.x-eventloop-thread-0] DEBUG o.e.hono.client.impl.HonoClientImpl - reusing existing client [target: registration/b0fd66af-82e9-4cef-8e16-491833f458ff]\r\n   HTTP07:00:03.579 [vert.x-eventloop-thread-0] TRACE o.e.h.s.c.SpringBasedExpiringValueCache - cache hit [key: TriTuple[one: assert, two: 3afb390a-38ed-4357-8284-d4814b7ea52f, three: null]]\r\n   HTTP07:00:03.579 [vert.x-eventloop-thread-0] DEBUG o.e.hono.client.impl.HonoClientImpl - reusing existing client [target: tenant]\r\n   HTTP07:00:03.579 [vert.x-eventloop-thread-0] TRACE o.e.h.s.c.SpringBasedExpiringValueCache - cache hit [key: TriTuple[one: get, two: b0fd66af-82e9-4cef-8e16-491833f458ff, three: null]]\r\n   HTTP07:00:03.579 [vert.x-eventloop-thread-0] DEBUG o.e.h.a.h.i.VertxBasedHttpProtocolAdapter - protocol adapter [hono-http] is enabled for tenant [b0fd66af-82e9-4cef-8e16-491833f458ff]\r\n   HTTP07:00:03.579 [vert.x-eventloop-thread-0] INFO  o.e.h.a.h.i.VertxBasedHttpProtocolAdapter - doUploadMessage GOT registration assertion and tenant config\r\n   HTTP07:00:03.579 [vert.x-eventloop-thread-0] INFO  o.e.h.a.h.i.VertxBasedHttpProtocolAdapter - doUploadMessage: createCommandConsumer\r\n08:00:03.584 [vert.x-eventloop-thread-2] TRACE o.e.hono.tests.http.TelemetryHttpIT - received Message{properties=Properties{messageId=TelemetrySenderImpl-28, userId=null, to='telemetry/b0fd66af-82e9-4cef-8e16-491833f458ff', subject='null', replyTo='null', correlationId=null, contentType=text/plain, contentEncoding=null, absoluteExpiryTime=null, creationTime=Wed Mar 20 08:00:03 CET 2019, groupId='null', groupSequence=null, replyToGroupId='null'}message_annotations=MessageAnnotations{{tenant_id=b0fd66af-82e9-4cef-8e16-491833f458ff, device_id=3afb390a-38ed-4357-8284-d4814b7ea52f, resource=telemetry/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f}}body=Data{hello 10}}\r\n   HTTP07:00:03.579 [vert.x-eventloop-thread-0] TRACE o.e.hono.client.CommandConsumer - creating new command consumer [tenant-id: b0fd66af-82e9-4cef-8e16-491833f458ff, device-id: 3afb390a-38ed-4357-8284-d4814b7ea52f]\r\n   HTTP07:00:03.581 [vert.x-eventloop-thread-0] DEBUG o.e.h.client.impl.AbstractHonoClient - receiver open [source: control/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f]\r\n   HTTP07:00:03.581 [vert.x-eventloop-thread-0] DEBUG o.e.hono.client.CommandConsumer - successfully created command consumer [control/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f]\r\n08:00:03.584 [vert.x-eventloop-thread-2] TRACE o.e.hono.tests.http.TelemetryHttpIT - received piggy backed message [ttd: 2]: Message{properties=Properties{messageId=TelemetrySenderImpl-28, userId=null, to='telemetry/b0fd66af-82e9-4cef-8e16-491833f458ff', subject='null', replyTo='null', correlationId=null, contentType=text/plain, contentEncoding=null, absoluteExpiryTime=null, creationTime=Wed Mar 20 08:00:03 CET 2019, groupId='null', groupSequence=null, replyToGroupId='null'}message_annotations=MessageAnnotations{{tenant_id=b0fd66af-82e9-4cef-8e16-491833f458ff, device_id=3afb390a-38ed-4357-8284-d4814b7ea52f, resource=telemetry/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f}}body=Data{hello 10}}\r\n   HTTP07:00:03.581 [vert.x-eventloop-thread-0] TRACE o.e.h.a.h.i.VertxBasedHttpProtocolAdapter - adding command reception timer [id: 165]\r\n08:00:03.586 [vert.x-eventloop-thread-2] DEBUG o.e.hono.client.impl.HonoClientImpl - get or create command client for [tenantId: b0fd66af-82e9-4cef-8e16-491833f458ff, deviceId: 3afb390a-38ed-4357-8284-d4814b7ea52f, replyId: 178faede-5cf7-4189-b9c3-c54cd4767645]\r\n08:00:03.586 [vert.x-eventloop-thread-2] DEBUG o.e.hono.client.impl.HonoClientImpl - creating new client [target: control/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f]\r\n08:00:03.588 [vert.x-eventloop-thread-2] INFO  o.e.hono.tests.http.TelemetryHttpIT - messages received: 10\r\n08:00:03.589 [vert.x-eventloop-thread-2] TRACE o.e.h.client.impl.AbstractHonoClient - handling message received on telemetry/b0fd66af-82e9-4cef-8e16-491833f458ff [remotely settled: false, queued messages: 0, remaining credit: 199]\r\n   HTTP07:00:03.581 [vert.x-eventloop-thread-0] INFO  o.e.h.a.h.i.VertxBasedHttpProtocolAdapter - doUploadMessage: GOT sender and commandConsumer\r\n   HTTP07:00:03.581 [vert.x-eventloop-thread-0] INFO  o.e.h.a.h.i.VertxBasedHttpProtocolAdapter - doUploadMessage: send downstream message\r\n08:00:03.591 [vert.x-eventloop-thread-2] DEBUG o.e.h.client.impl.AbstractHonoClient - receiver open [source: control/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f/178faede-5cf7-4189-b9c3-c54cd4767645]\r\n   HTTP07:00:03.582 [vert.x-eventloop-thread-0] TRACE o.e.h.c.impl.TelemetrySenderImpl - sent message [ID: TelemetrySenderImpl-28], remaining credit: 249, queued messages: 0\r\n08:00:03.595 [vert.x-eventloop-thread-2] DEBUG o.e.h.client.impl.AbstractHonoClient - sender open [target: control/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f, sendQueueFull: false]\r\n08:00:03.595 [vert.x-eventloop-thread-2] DEBUG o.e.h.c.i.AbstractRequestResponseClient - request-response client for peer [Hono.Example.Router] created\r\n08:00:03.596 [vert.x-eventloop-thread-2] DEBUG o.e.h.client.impl.CommandClientImpl - successfully created command client for [b0fd66af-82e9-4cef-8e16-491833f458ff]\r\n08:00:03.596 [vert.x-eventloop-thread-2] DEBUG o.e.hono.client.impl.HonoClientImpl - successfully created new client [target: control/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f]\r\n08:00:03.596 [vert.x-eventloop-thread-2] TRACE o.e.h.tests.IntegrationTestSupport - sending command [name: setBrightness, contentType: application/json, payload: {\"brightness\":0}]\r\n08:00:03.598 [vert.x-eventloop-thread-2] DEBUG o.e.h.c.i.AbstractRequestResponseClient - sent request [target address: control/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f, subject: setBrightness, correlation ID: 0] to service\r\n   HTTP07:00:03.591 [vert.x-eventloop-thread-0] TRACE o.e.h.c.impl.TelemetrySenderImpl - message [message ID: TelemetrySenderImpl-28] accepted by peer\r\n   HTTP07:00:03.601 [vert.x-eventloop-thread-0] TRACE o.e.h.a.h.i.VertxBasedHttpProtocolAdapter - Cancelled timer id 165\r\n   HTTP07:00:03.602 [vert.x-eventloop-thread-0] TRACE o.e.h.a.h.i.VertxBasedHttpProtocolAdapter - adding command [name: setBrightness, request-id: 1010178faede-5cf7-4189-b9c3-c54cd4767645] to response for device [tenant-id: b0fd66af-82e9-4cef-8e16-491833f458ff, device-id: 3afb390a-38ed-4357-8284-d4814b7ea52f]\r\n08:00:03.603 [vert.x-eventloop-thread-1] TRACE o.eclipse.hono.tests.CrudHttpClient - response status code 200\r\n08:00:03.603 [vert.x-eventloop-thread-1] INFO  o.e.hono.tests.http.TelemetryHttpIT - got response for message 10\r\n08:00:03.605 [vert.x-eventloop-thread-1] DEBUG o.e.hono.tests.http.TelemetryHttpIT - posting response to command [uri: /control/res/1010178faede-5cf7-4189-b9c3-c54cd4767645]\r\n   HTTP07:00:03.605 [vert.x-eventloop-thread-0] TRACE o.e.h.a.h.i.VertxBasedHttpProtocolAdapter - successfully processed [TELEMETRY] message for device [tenantId: b0fd66af-82e9-4cef-8e16-491833f458ff, deviceId: 3afb390a-38ed-4357-8284-d4814b7ea52f]\r\n   HTTP07:00:03.605 [vert.x-eventloop-thread-0] TRACE o.eclipse.hono.client.CommandContext - accepting command message [Command [name: setBrightness, tenant-id: b0fd66af-82e9-4cef-8e16-491833f458ff, device-id 3afb390a-38ed-4357-8284-d4814b7ea52f, request-id: 1010178faede-5cf7-4189-b9c3-c54cd4767645]]\r\n08:00:03.614 [vert.x-eventloop-thread-2] TRACE o.e.h.c.i.AbstractRequestResponseClient - service has accepted request [target address: control/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f, subject: setBrightness, correlation ID: 0]\r\n   HTTP07:00:03.606 [vert.x-eventloop-thread-0] DEBUG o.e.h.client.impl.AbstractHonoClient - locally closing receiver link [control/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f]\r\n   HTTP07:00:03.607 [vert.x-eventloop-thread-0] TRACE o.e.h.a.h.ComponentMetaDataDecorator - setting status code of response to request [method: POST, URI: https://localhost:32792/telemetry\r\n   HTTP07:00:03.607 [vert.x-eventloop-thread-0] TRACE o.e.h.client.impl.AbstractHonoClient - handling message received on null [remotely settled: false, queued messages: 0, remaining credit: 0]\r\n   HTTP07:00:03.616 [vert.x-eventloop-thread-0] TRACE o.e.h.a.h.ComponentMetaDataDecorator - starting span for request [method: POST, URI: https://localhost:32792/control/res/1010178faede-5cf7-4189-b9c3-c54cd4767645\r\n   HTTP07:00:03.618 [vert.x-eventloop-thread-0] INFO  o.e.h.adapter.http.X509AuthHandler - parseCredentials: BEGIN\r\n   HTTP07:00:03.621 [vert.x-eventloop-thread-0] DEBUG o.e.h.adapter.http.X509AuthHandler - could not retrieve client certificate from request: peer not verified\r\n   HTTP07:00:03.621 [vert.x-eventloop-thread-0] INFO  o.e.h.adapter.http.X509AuthHandler - parseCredentials: END\r\n   HTTP07:00:03.621 [vert.x-eventloop-thread-0] DEBUG o.e.hono.client.impl.HonoClientImpl - reusing existing client [target: credentials/b0fd66af-82e9-4cef-8e16-491833f458ff]\r\n   HTTP07:00:03.625 [vert.x-eventloop-thread-0] DEBUG o.e.h.c.i.AbstractRequestResponseClient - sent request [target address: credentials/b0fd66af-82e9-4cef-8e16-491833f458ff, subject: get, correlation ID: cred-client-9daa8082-907c-40fd-9286-33c7fdbd1d23] to service\r\n   HTTP07:00:03.626 [vert.x-eventloop-thread-0] DEBUG o.e.hono.client.CommandConsumer - command receiver link [tenant-id: b0fd66af-82e9-4cef-8e16-491833f458ff, device-id: 3afb390a-38ed-4357-8284-d4814b7ea52f] closed locally\r\n   HTTP07:00:03.626 [vert.x-eventloop-thread-0] TRACE o.e.h.c.i.AbstractRequestResponseClient - service has accepted request [target address: credentials/b0fd66af-82e9-4cef-8e16-491833f458ff, subject: get, correlation ID: cred-client-9daa8082-907c-40fd-9286-33c7fdbd1d23]\r\n   HTTP07:00:03.627 [vert.x-eventloop-thread-0] DEBUG o.e.h.c.i.AbstractRequestResponseClient - received response [reply-to: credentials/b0fd66af-82e9-4cef-8e16-491833f458ff/07cc153e-3129-4c2a-9972-918ba9ac73b9, subject: null, correlation ID: cred-client-9daa8082-907c-40fd-9286-33c7fdbd1d23, status: 200]\r\n   \r\n   HTTP07:00:03.627 [vert.x-worker-thread-9] DEBUG o.e.h.s.a.d.UsernamePasswordAuthProvider - validating password hash on vert.x worker thread [vert.x-worker-thread-9]\r\n   HTTP07:00:03.627 [vert.x-eventloop-thread-0] TRACE o.e.h.client.impl.AbstractHonoClient - handling message received on credentials/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f [remotely settled: false, queued messages: 0, remaining credit: 199]\r\n   HTTP07:00:03.718 [vert.x-worker-thread-9] DEBUG o.e.h.s.a.d.UsernamePasswordAuthProvider - DONE validating password hash\r\n   => validating password hash took 91ms\r\n\r\n   HTTP07:00:03.719 [vert.x-eventloop-thread-0] DEBUG o.e.h.a.h.i.VertxBasedHttpProtocolAdapter - processing response to command [tenantId: b0fd66af-82e9-4cef-8e16-491833f458ff, deviceId: 3afb390a-38ed-4357-8284-d4814b7ea52f, cmd-req-id: 1010178faede-5cf7-4189-b9c3-c54cd4767645, status code: 200]\r\n   HTTP07:00:03.719 [vert.x-eventloop-thread-0] DEBUG o.e.hono.client.impl.HonoClientImpl - reusing existing client [target: registration/b0fd66af-82e9-4cef-8e16-491833f458ff]\r\n   HTTP07:00:03.719 [vert.x-eventloop-thread-0] TRACE o.e.h.s.c.SpringBasedExpiringValueCache - cache hit [key: TriTuple[one: assert, two: 3afb390a-38ed-4357-8284-d4814b7ea52f, three: null]]\r\n   HTTP07:00:03.719 [vert.x-eventloop-thread-0] DEBUG o.e.hono.client.impl.HonoClientImpl - reusing existing client [target: tenant]\r\n   HTTP07:00:03.719 [vert.x-eventloop-thread-0] TRACE o.e.h.s.c.SpringBasedExpiringValueCache - cache hit [key: TriTuple[one: get, two: b0fd66af-82e9-4cef-8e16-491833f458ff, three: null]]\r\n   HTTP07:00:03.719 [vert.x-eventloop-thread-0] DEBUG o.e.h.a.h.i.VertxBasedHttpProtocolAdapter - protocol adapter [hono-http] is enabled for tenant [b0fd66af-82e9-4cef-8e16-491833f458ff]\r\n   HTTP07:00:03.719 [vert.x-eventloop-thread-0] INFO  o.e.hono.client.impl.HonoClientImpl - getCommandResponseSender: tenant=b0fd66af-82e9-4cef-8e16-491833f458ff, replyId=3afb390a-38ed-4357-8284-d4814b7ea52f/178faede-5cf7-4189-b9c3-c54cd4767645\r\n   HTTP07:00:03.719 [vert.x-eventloop-thread-0] INFO  o.e.hono.client.impl.HonoClientImpl - getCommandResponseSender: invoke CommandResponseSenderImpl.create; tenant=b0fd66af-82e9-4cef-8e16-491833f458ff, replyId=3afb390a-38ed-4357-8284-d4814b7ea52f/178faede-5cf7-4189-b9c3-c54cd4767645\r\n   HTTP07:00:03.722 [vert.x-eventloop-thread-0] DEBUG o.e.h.client.impl.AbstractHonoClient - sender open [target: control/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f/178faede-5cf7-4189-b9c3-c54cd4767645, sendQueueFull: false]\r\n   HTTP07:00:03.722 [vert.x-eventloop-thread-0] INFO  o.e.hono.client.impl.HonoClientImpl - getCommandResponseSender: DONE WITH CommandResponseSenderImpl.create; tenant=b0fd66af-82e9-4cef-8e16-491833f458ff, replyId=3afb390a-38ed-4357-8284-d4814b7ea52f/178faede-5cf7-4189-b9c3-c54cd4767645\r\n08:00:03.726 [vert.x-eventloop-thread-2] DEBUG o.e.h.c.i.AbstractRequestResponseClient - received response [reply-to: control/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f/178faede-5cf7-4189-b9c3-c54cd4767645, subject: null, correlation ID: 0, status: 200]\r\n08:00:03.726 [vert.x-eventloop-thread-2] DEBUG o.e.h.tests.IntegrationTestSupport - successfully sent command [name: setBrightness, payload: {\"brightness\":0}] and received response [payload: org.eclipse.hono.util.BufferResult@42e64b72]\r\n08:00:03.726 [vert.x-eventloop-thread-2] DEBUG o.e.h.c.i.AbstractRequestResponseClient - closing request-response client ...\r\n08:00:03.726 [vert.x-eventloop-thread-2] DEBUG o.e.h.client.impl.AbstractHonoClient - locally closing sender link [control/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f]\r\n08:00:03.727 [vert.x-eventloop-thread-2] TRACE o.e.h.client.impl.AbstractHonoClient - handling message received on control/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f/178faede-5cf7-4189-b9c3-c54cd4767645 [remotely settled: false, queued messages: 0, remaining credit: 199]\r\n   HTTP07:00:03.724 [vert.x-eventloop-thread-0] TRACE o.e.h.c.i.CommandResponseSenderImpl - sent message [ID: CommandResponseSenderImpl-29], remaining credit: 249, queued messages: 0\r\n08:00:03.729 [vert.x-eventloop-thread-2] DEBUG o.e.h.client.impl.AbstractHonoClient - locally closing receiver link [control/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f/178faede-5cf7-4189-b9c3-c54cd4767645]\r\n   HTTP07:00:03.729 [vert.x-eventloop-thread-0] TRACE o.e.h.c.i.CommandResponseSenderImpl - message [message ID: CommandResponseSenderImpl-29] accepted by peer\r\n   HTTP07:00:03.730 [vert.x-eventloop-thread-0] TRACE o.e.h.c.i.CommandResponseSenderImpl - message [ID: CommandResponseSenderImpl-29] accepted by peer\r\n   HTTP07:00:03.730 [vert.x-eventloop-thread-0] DEBUG o.e.h.c.i.CommandResponseSenderImpl - closing sender ...\r\n   HTTP07:00:03.731 [vert.x-eventloop-thread-0] DEBUG o.e.h.client.impl.AbstractHonoClient - locally closing sender link [control/b0fd66af-82e9-4cef-8e16-491833f458ff/3afb390a-38ed-4357-8284-d4814b7ea52f/178faede-5cf7-4189-b9c3-c54cd4767645]\r\n   HTTP07:00:03.734 [vert.x-eventloop-thread-0] TRACE o.e.h.a.h.i.VertxBasedHttpProtocolAdapter - delivered command response [command-request-id: 1010178faede-5cf7-4189-b9c3-c54cd4767645] to application\r\n   HTTP07:00:03.735 [vert.x-eventloop-thread-0] TRACE o.e.h.a.h.ComponentMetaDataDecorator - setting status code of response to request [method: POST, URI: https://localhost:32792/control/res/1010178faede-5cf7-4189-b9c3-c54cd4767645\r\n08:00:03.736 [vert.x-eventloop-thread-1] TRACE o.eclipse.hono.tests.CrudHttpClient - response status code 202\r\n08:00:03.736 [vert.x-eventloop-thread-1] DEBUG o.e.hono.tests.http.TelemetryHttpIT - sent message 10\r\n08:00:03.739 [Time-limited test] INFO  o.e.hono.tests.http.TelemetryHttpIT - ###### DONE with #10 in 273ms ######\r\n````\r\nOf the 278ms total, 178ms (=87ms+91ms) was spent in the HTTP adapter in `UsernamePasswordAuthProvider` for validating the password hash (once for the telemetry request, once for the command request).\r\n"}}
{"actor":{"display_login":"calohmn"}}