Event hub client - Unauthorized access due to "InvalidOperationError: $cbs node has already been opened" when renewing token #186

ramya-rao-a · 2019-02-01T18:50:35Z

2019-02-01T14:57:14.582Z rhea:io [connection-4] read 65 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-4] got frame of size 65
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:6 <- attach#12 {"name":"7834e55f-16d1-2b46-bbf0-485ca6f3472d","role":true,"source":null,"target":null} 
2019-02-01T14:57:14.582Z rhea:events [connection-4] Link got event: sender_open
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 110 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-4] got frame of size 110
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:6 <- detach#16 {"closed":true,"error":{"condition":"amqp:not-allowed","description":"A link to connection '304158961' $cbs node has already been opened."}} 
2019-02-01T14:57:14.582Z rhea:events [connection-4] Link got event: sender_error
2019-02-01T14:57:14.582Z rhea:events [connection-4] Link got event: sender_close
2019-02-01T14:57:14.582Z rhea-promise:error [connection-4] Error occurred while creating a sender over amqp connection: c {
  value: 
   [ Typed { type: [Object], value: 'amqp:not-allowed' },
     Typed {
       type: [Object],
       value: 'A link to connection \'304158961\' $cbs node has already been opened.' },
     Typed { type: [Object], value: null } ] }.
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:6 -> detach#16 {"closed":true} 
2019-02-01T14:57:14.598Z azure:event-hubs:error [connection-4] ManagementClient '97817dae-56f5-4399-bdb4-abea430bba64' with address $management, an error occurred while renewing the token: { InvalidOperationError: A link to connection '304158961' $cbs node has already been opened.
    at Object.translate (service\node_modules\@azure\amqp-common\lib\errors.ts:537:13)
    at CbsClient.<anonymous> (service\node_modules\@azure\amqp-common\lib\cbs.ts:118:13)
    at Generator.throw (<anonymous>)
    at rejected (service\node_modules\tslib\tslib.js:105:69)
    at <anonymous>
    at process._tickCallback (internal/process/next_tick.js:189:7)
  name: 'InvalidOperationError',
  translated: true,
  retryable: false,
  info: null,
  condition: 'amqp:not-allowed' }
2019-02-01T14:57:14.805Z rhea:io [connection-4] read 65 bytes
2019-02-01T14:57:14.805Z rhea:io [connection-4] got frame of size 65
2019-02-01T14:57:14.805Z rhea:frames [connection-4]:1 <- attach#12 {"name":"d6ca97e3-a73a-431b-8c42-13851f2b8ca7","source":null,"target":null} 
2019-02-01T14:57:14.805Z rhea:events [connection-4] Link got event: receiver_open
2019-02-01T14:57:14.805Z rhea:frames [connection-4]:1 -> flow#13 {"incoming_window":2048,"outgoing_window":4294967295,"link_credit":1000} 
2019-02-01T14:57:14.805Z rhea:io [connection-4] read 2072 bytes
2019-02-01T14:57:14.805Z rhea:io [connection-4] got frame of size 65
2019-02-01T14:57:14.805Z rhea:frames [connection-4]:2 <- attach#12 {"name":"a88ecb69-84c9-4987-b96c-a219cf19d74a","source":null,"target":null} 
2019-02-01T14:57:14.805Z rhea:events [connection-4] Link got event: receiver_open
2019-02-01T14:57:14.805Z rhea:io [connection-4] got frame of size 362
2019-02-01T14:57:14.805Z rhea:frames [connection-4]:2 <- detach#16 {"closed":true,"error":{"condition":"amqp:unauthorized-access","description":"Unauthorized access. 'Listen' claim(s) are required to perform this operation. Resource: 'sb://connection-link/event-hub/consumergroups/$default/partitions/7'. TrackingId:14543c918d7a4802940d936328fea36d_G13, SystemTracker:gateway5, Timestamp:2019-02-01T14:57:14"}} 
2019-02-01T14:57:14.805Z rhea:events [connection-4] Link got event: receiver_error
2019-02-01T14:57:14.805Z azure:event-hubs:error [connection-4] An error occurred for Receiver '6c9959e4-0976-4197-9e7f-64ceda1dc35d': { UnauthorizedError: Unauthorized access. 'Listen' claim(s) are required to perform this operation. Resource: 'sb://connection-link/event-hub/consumergroups/$default/partitions/7'. TrackingId:14543c918d7a4802940d936328fea36d_G13, SystemTracker:gateway5, Timestamp:2019-02-01T14:57:14
    at Object.translate (service\node_modules\@azure\amqp-common\lib\errors.ts:537:13)
    at Receiver.EventHubReceiver._onAmqpError (service\node_modules\@azure\event-hubs\lib\eventHubReceiver.ts:225:25)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at emit (service\node_modules\rhea-promise\lib\util\utils.ts:183:20)
    at Object.emitEvent (service\node_modules\rhea-promise\lib\util\utils.ts:195:5)
    at Receiver._link.on (service\node_modules\rhea-promise\lib\link.ts:292:11)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at Receiver.link.dispatch (service\node_modules\rhea\lib\link.js:59:37)
  name: 'UnauthorizedError',
  translated: true,
  retryable: false,
  info: null,
  condition: 'amqp:unauthorized-access' }.
2019-02-01T14:57:14.805Z azure:event-hubs:error [connection-4] Since the user did not close the receiver and the error is not retryable, we let the user know about it by calling the user's error handler.
{ UnauthorizedError: Unauthorized access. 'Listen' claim(s) are required to perform this operation. Resource: 'sb://connection-link/event-hub/consumergroups/$default/partitions/7'. TrackingId:14543c918d7a4802940d936328fea36d_G13, SystemTracker:gateway5, Timestamp:2019-02-01T14:57:14
    at Object.translate (service\node_modules\@azure\amqp-common\lib\errors.ts:537:13)
    at Receiver.EventHubReceiver._onAmqpError (service\node_modules\@azure\event-hubs\lib\eventHubReceiver.ts:225:25)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at emit (service\node_modules\rhea-promise\lib\util\utils.ts:183:20)
    at Object.emitEvent (service\node_modules\rhea-promise\lib\util\utils.ts:195:5)
    at Receiver._link.on (service\node_modules\rhea-promise\lib\link.ts:292:11)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at Receiver.link.dispatch (service\node_modules\rhea\lib\link.js:59:37)
  name: 'UnauthorizedError',
  translated: true,
  retryable: false,
  info: null,
  condition: 'amqp:unauthorized-access' }
2019-02-01T14:57:14.805Z rhea:events [connection-4] Link got event: receiver_close
2019-02-01T14:57:14.805Z azure:event-hubs:error [connection-4] 'receiver_close' event occurred for receiver '6c9959e4-0976-4197-9e7f-64ceda1dc35d' with address 'event-hub/ConsumerGroups/$default/Partitions/7'. The associated error is: c {
  value: 
   [ Typed { type: [Object], value: 'amqp:unauthorized-access' },
     Typed {
       type: [Object],
       value: 'Unauthorized access. \'Listen\' claim(s) are required to perform this operation. Resource: \'sb://connection-link/event-hub/consumergroups/$default/partitions/7\'. TrackingId:14543c918d7a4802940d936328fea36d_G13, SystemTracker:gateway5, Timestamp:2019-02-01T14:57:14' },
     Typed { type: [Object], value: null } ] }
2019-02-01T14:57:14.805Z azure:event-hubs:error [connection-4] 'receiver_close' event occurred on the receiver '6c9959e4-0976-4197-9e7f-64ceda1dc35d' with address 'event-hub/ConsumerGroups/$default/Partitions/7' and the sdk did not initiate this. The receiver is not reconnecting. Hence, calling detached from the _onAmqpClose() handler.
2019-02-01T14:57:14.805Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:57:14.805Z rhea:io [connection-4] got frame of size 65
2019-02-01T14:57:14.805Z rhea:frames [connection-4]:3 <- attach#12 {"name":"2fadec42-2806-454d-8584-7366278cf2d6","source":null,"target":null} 
2019-02-01T14:57:14.805Z rhea:events [connection-4] Link got event: receiver_open
2019-02-01T14:57:14.805Z rhea:io [connection-4] got frame of size 362
2019-02-01T14:57:14.805Z rhea:frames [connection-4]:3 <- detach#16 {"closed":true,"error":{"condition":"amqp:unauthorized-access","description":"Unauthorized access. 'Listen' claim(s) are required to perform this operation. Resource: 'sb://connection-link/event-hub/consumergroups/$default/partitions/8'. TrackingId:14543c918d7a4802940d936328fea36d_G13, SystemTracker:gateway5, Timestamp:2019-02-01T14:57:14"}} 
2019-02-01T14:57:14.805Z rhea:events [connection-4] Link got event: receiver_error
2019-02-01T14:57:14.805Z azure:event-hubs:error [connection-4] An error occurred for Receiver 'ada48e56-235d-4a03-bf2b-c9172b1dbaa0': { UnauthorizedError: Unauthorized access. 'Listen' claim(s) are required to perform this operation. Resource: 'sb://connection-link/event-hub/consumergroups/$default/partitions/8'. TrackingId:14543c918d7a4802940d936328fea36d_G13, SystemTracker:gateway5, Timestamp:2019-02-01T14:57:14
    at Object.translate (service\node_modules\@azure\amqp-common\lib\errors.ts:537:13)
    at Receiver.EventHubReceiver._onAmqpError (service\node_modules\@azure\event-hubs\lib\eventHubReceiver.ts:225:25)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at emit (service\node_modules\rhea-promise\lib\util\utils.ts:183:20)
    at Object.emitEvent (service\node_modules\rhea-promise\lib\util\utils.ts:195:5)
    at Receiver._link.on (service\node_modules\rhea-promise\lib\link.ts:292:11)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at Receiver.link.dispatch (service\node_modules\rhea\lib\link.js:59:37)
  name: 'UnauthorizedError',
  translated: true,
  retryable: false,
  info: null,
  condition: 'amqp:unauthorized-access' }.
2019-02-01T14:57:14.805Z azure:event-hubs:error [connection-4] Since the user did not close the receiver and the error is not retryable, we let the user know about it by calling the user's error handler.
{ UnauthorizedError: Unauthorized access. 'Listen' claim(s) are required to perform this operation. Resource: 'sb://connection-link/event-hub/consumergroups/$default/partitions/8'. TrackingId:14543c918d7a4802940d936328fea36d_G13, SystemTracker:gateway5, Timestamp:2019-02-01T14:57:14
    at Object.translate (service\node_modules\@azure\amqp-common\lib\errors.ts:537:13)
    at Receiver.EventHubReceiver._onAmqpError (service\node_modules\@azure\event-hubs\lib\eventHubReceiver.ts:225:25)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at emit (service\node_modules\rhea-promise\lib\util\utils.ts:183:20)
    at Object.emitEvent (service\node_modules\rhea-promise\lib\util\utils.ts:195:5)
    at Receiver._link.on (service\node_modules\rhea-promise\lib\link.ts:292:11)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at Receiver.link.dispatch (service\node_modules\rhea\lib\link.js:59:37)
  name: 'UnauthorizedError',
  translated: true,
  retryable: false,
  info: null,
  condition: 'amqp:unauthorized-access' }
2019-02-01T14:57:14.805Z rhea:events [connection-4] Link got event: receiver_close
2019-02-01T14:57:14.805Z azure:event-hubs:error [connection-4] 'receiver_close' event occurred for receiver 'ada48e56-235d-4a03-bf2b-c9172b1dbaa0' with address 'event-hub/ConsumerGroups/$default/Partitions/8'. The associated error is: c {
  value: 
   [ Typed { type: [Object], value: 'amqp:unauthorized-access' },
     Typed {
       type: [Object],
       value: 'Unauthorized access. \'Listen\' claim(s) are required to perform this operation. Resource: \'sb://connection-link/event-hub/consumergroups/$default/partitions/8\'. TrackingId:14543c918d7a4802940d936328fea36d_G13, SystemTracker:gateway5, Timestamp:2019-02-01T14:57:14' },
     Typed { type: [Object], value: null } ] }
2019-02-01T14:57:14.805Z azure:event-hubs:error [connection-4] 'receiver_close' event occurred on the receiver 'ada48e56-235d-4a03-bf2b-c9172b1dbaa0' with address 'event-hub/ConsumerGroups/$default/Partitions/8' and the sdk did not initiate this. The receiver is not reconnecting. Hence, calling detached from the _onAmqpClose() handler.
2019-02-01T14:57:14.805Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:57:14.805Z rhea:io [connection-4] got frame of size 65
2019-02-01T14:57:14.805Z rhea:frames [connection-4]:4 <- attach#12 {"name":"ee445d8f-4bb5-423b-a5be-c80cc805450a","source":null,"target":null} 
2019-02-01T14:57:14.805Z rhea:events [connection-4] Link got event: receiver_open
2019-02-01T14:57:14.805Z rhea:io [connection-4] got frame of size 362
2019-02-01T14:57:14.805Z rhea:frames [connection-4]:1 <- detach#16 {"closed":true,"error":{"condition":"amqp:unauthorized-access","description":"Unauthorized access. 'Listen' claim(s) are required to perform this operation. Resource: 'sb://connection-link/event-hub/consumergroups/$default/partitions/6'. TrackingId:14543c918d7a4802940d936328fea36d_G13, SystemTracker:gateway5, Timestamp:2019-02-01T14:57:14"}} 
2019-02-01T14:57:14.805Z rhea:events [connection-4] Link got event: receiver_error
2019-02-01T14:57:14.805Z azure:event-hubs:error [connection-4] An error occurred for Receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d': { UnauthorizedError: Unauthorized access. 'Listen' claim(s) are required to perform this operation. Resource: 'sb://connection-link/event-hub/consumergroups/$default/partitions/6'. TrackingId:14543c918d7a4802940d936328fea36d_G13, SystemTracker:gateway5, Timestamp:2019-02-01T14:57:14
    at Object.translate (service\node_modules\@azure\amqp-common\lib\errors.ts:537:13)
    at Receiver.EventHubReceiver._onAmqpError (service\node_modules\@azure\event-hubs\lib\eventHubReceiver.ts:225:25)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at emit (service\node_modules\rhea-promise\lib\util\utils.ts:183:20)
    at Object.emitEvent (service\node_modules\rhea-promise\lib\util\utils.ts:195:5)
    at Receiver._link.on (service\node_modules\rhea-promise\lib\link.ts:292:11)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at Receiver.link.dispatch (service\node_modules\rhea\lib\link.js:59:37)
  name: 'UnauthorizedError',
  translated: true,
  retryable: false,
  info: null,
  condition: 'amqp:unauthorized-access' }.
2019-02-01T14:57:14.805Z azure:event-hubs:error [connection-4] Since the user did not close the receiver and the error is not retryable, we let the user know about it by calling the user's error handler.
{ UnauthorizedError: Unauthorized access. 'Listen' claim(s) are required to perform this operation. Resource: 'sb://connection-link/event-hub/consumergroups/$default/partitions/6'. TrackingId:14543c918d7a4802940d936328fea36d_G13, SystemTracker:gateway5, Timestamp:2019-02-01T14:57:14
    at Object.translate (service\node_modules\@azure\amqp-common\lib\errors.ts:537:13)
    at Receiver.EventHubReceiver._onAmqpError (service\node_modules\@azure\event-hubs\lib\eventHubReceiver.ts:225:25)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at emit (service\node_modules\rhea-promise\lib\util\utils.ts:183:20)
    at Object.emitEvent (service\node_modules\rhea-promise\lib\util\utils.ts:195:5)
    at Receiver._link.on (service\node_modules\rhea-promise\lib\link.ts:292:11)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at Receiver.link.dispatch (service\node_modules\rhea\lib\link.js:59:37)
  name: 'UnauthorizedError',
  translated: true,
  retryable: false,
  info: null,
  condition: 'amqp:unauthorized-access' }
2019-02-01T14:57:14.805Z rhea:events [connection-4] Link got event: receiver_close
2019-02-01T14:57:14.805Z azure:event-hubs:error [connection-4] 'receiver_close' event occurred for receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with address 'event-hub/ConsumerGroups/$default/Partitions/6'. The associated error is: c {
  value: 
   [ Typed { type: [Object], value: 'amqp:unauthorized-access' },
     Typed {
       type: [Object],
       value: 'Unauthorized access. \'Listen\' claim(s) are required to perform this operation. Resource: \'sb://connection-link/event-hub/consumergroups/$default/partitions/6\'. TrackingId:14543c918d7a4802940d936328fea36d_G13, SystemTracker:gateway5, Timestamp:2019-02-01T14:57:14' },
     Typed { type: [Object], value: null } ] }

The text was updated successfully, but these errors were encountered:

ramya-rao-a · 2019-02-01T19:05:44Z

@MatejSkrbis What majority of your logs is showing is the AMQP link throwing the Unauthorized access error and the subsequent closing of the link. This is happening for 3 of the receiver links.

Before that, there is an error when trying to renew the token (see below), because there is already a request in flight to do the same.

{"condition":"amqp:not-allowed","description":"A link to connection '304158961' $cbs node has already been opened."}} 
2019-02-01T14:57:14.582Z rhea:events [connection-4] Link got event: sender_error
2019-02-01T14:57:14.582Z rhea:events [connection-4] Link got event: sender_close
2019-02-01T14:57:14.582Z rhea-promise:error [connection-4] Error occurred while creating a sender over amqp connection: c {
  value: 
   [ Typed { type: [Object], value: 'amqp:not-allowed' },
     Typed {
       type: [Object],
       value: 'A link to connection \'304158961\' $cbs node has already been opened.' },
     Typed { type: [Object], value: null } ] }.
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:6 -> detach#16 {"closed":true} 
2019-02-01T14:57:14.598Z azure:event-hubs:error [connection-4] ManagementClient '97817dae-56f5-4399-bdb4-abea430bba64' with address $management, an error occurred while renewing the token: { InvalidOperationError: A link to connection '304158961' $cbs node has already been opened.
    at Object.translate (service\node_modules\@azure\amqp-common\lib\errors.ts:537:13)
    at CbsClient.<anonymous> (service\node_modules\@azure\amqp-common\lib\cbs.ts:118:13)
    at Generator.throw (<anonymous>)
    at rejected (service\node_modules\tslib\tslib.js:105:69)
    at <anonymous>
    at process._tickCallback (internal/process/next_tick.js:189:7)
  name: 'InvalidOperationError',
  translated: true,
  retryable: false,
  info: null,
  condition: 'amqp:not-allowed' }

Can you provide logs that include the above as well as what happened before that?
Also, what is the value of the DEBUG env variable that you have set?

MatejSkrbis · 2019-02-04T07:36:58Z

I had DEBUG set to "azure:event-hubs:error,azure-amqp-common:error,rhea-promise:error,rhea:events,rhea:frames,rhea:io,rhea:flow".

These are logs 10 minutes before Unauthorized error:

2019-02-01T14:47:07.357Z rhea:io [connection-2] read 34 bytes
2019-02-01T14:47:07.357Z rhea:io [connection-2] got frame of size 34
2019-02-01T14:47:07.357Z rhea:frames [connection-2]:6 <- begin#11 {"remote_channel":6,"next_outgoing_id":1,"incoming_window":5000,"outgoing_window":2048,"handle_max":255} 
2019-02-01T14:47:07.357Z rhea:events [connection-2] Session got event: session_open
2019-02-01T14:47:07.357Z rhea:frames [connection-2]:6 -> attach#12 {"name":"9556c09e-dafd-46d6-aef0-d0d45ba36d5a","role":true,"source":["event-hub1/ConsumerGroups/$default/Partitions/10",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547088068241'"]],"target":[]} 
2019-02-01T14:47:44.066Z rhea:io [connection-1] read 41 bytes
2019-02-01T14:47:44.066Z rhea:io [connection-1] got frame of size 41
2019-02-01T14:47:44.066Z rhea:frames [connection-1]:0 <- flow#13 {"next_incoming_id":3189,"incoming_window":5000,"next_outgoing_id":3190,"outgoing_window":1858,"echo":true} 
2019-02-01T14:47:47.545Z rhea:io [connection-3] read 41 bytes
2019-02-01T14:47:47.545Z rhea:io [connection-3] got frame of size 41
2019-02-01T14:47:47.545Z rhea:frames [connection-3]:0 <- flow#13 {"next_incoming_id":3184,"incoming_window":5000,"next_outgoing_id":3185,"outgoing_window":1863,"echo":true} 
2019-02-01T14:47:47.672Z rhea:io [connection-2] read 41 bytes
2019-02-01T14:47:47.672Z rhea:io [connection-2] got frame of size 41
2019-02-01T14:47:47.672Z rhea:frames [connection-2]:0 <- flow#13 {"next_incoming_id":3185,"incoming_window":5000,"next_outgoing_id":3186,"outgoing_window":1862,"echo":true} 
2019-02-01T14:48:03.706Z rhea-promise:error [connection-2] Unable to create the amqp receiver cce50b0f-3922-4296-871f-6fa391aabad0 due to operation timeout.
2019-02-01T14:48:03.706Z azure:event-hubs:error [connection-2] An error occured while creating the receiver 'cce50b0f-3922-4296-871f-6fa391aabad0': { OperationTimeoutError: Unable to create the amqp receiver cce50b0f-3922-4296-871f-6fa391aabad0 due to operation timeout.
    at Timeout.actionAfterTimeout (service\node_modules\rhea-promise\lib\session.ts:258:23)
    at ontimeout (timers.js:498:11)
    at tryOnTimeout (timers.js:323:5)
    at Timer.listOnTimeout (timers.js:290:5)
  name: 'OperationTimeoutError',
  translated: true,
  retryable: false,
  info: undefined,
  condition: 'amqp:operation-timeout' }
2019-02-01T14:48:03.706Z azure:event-hubs:error [connection-2] An error occurred while processing detached() of Receiver 'cce50b0f-3922-4296-871f-6fa391aabad0' with address 'event-hub1/ConsumerGroups/$default/Partitions/7': { OperationTimeoutError: Unable to create the amqp receiver cce50b0f-3922-4296-871f-6fa391aabad0 due to operation timeout.
    at Timeout.actionAfterTimeout (service\node_modules\rhea-promise\lib\session.ts:258:23)
    at ontimeout (timers.js:498:11)
    at tryOnTimeout (timers.js:323:5)
    at Timer.listOnTimeout (timers.js:290:5)
  name: 'OperationTimeoutError',
  translated: true,
  retryable: false,
  info: undefined,
  condition: 'amqp:operation-timeout' }
2019-02-01T14:48:03.706Z rhea-promise:error [connection-3] Unable to create the amqp receiver bb2366b6-13fc-4ccb-b657-c27471421f67 due to operation timeout.
2019-02-01T14:48:03.706Z azure:event-hubs:error [connection-3] An error occured while creating the receiver 'bb2366b6-13fc-4ccb-b657-c27471421f67': { OperationTimeoutError: Unable to create the amqp receiver bb2366b6-13fc-4ccb-b657-c27471421f67 due to operation timeout.
    at Timeout.actionAfterTimeout (service\node_modules\rhea-promise\lib\session.ts:258:23)
    at ontimeout (timers.js:498:11)
    at tryOnTimeout (timers.js:323:5)
    at Timer.listOnTimeout (timers.js:290:5)
  name: 'OperationTimeoutError',
  translated: true,
  retryable: false,
  info: undefined,
  condition: 'amqp:operation-timeout' }
2019-02-01T14:48:03.706Z azure:event-hubs:error [connection-3] An error occurred while processing detached() of Receiver 'bb2366b6-13fc-4ccb-b657-c27471421f67' with address 'event-hub2/ConsumerGroups/$default/Partitions/10': { OperationTimeoutError: Unable to create the amqp receiver bb2366b6-13fc-4ccb-b657-c27471421f67 due to operation timeout.
    at Timeout.actionAfterTimeout (service\node_modules\rhea-promise\lib\session.ts:258:23)
    at ontimeout (timers.js:498:11)
    at tryOnTimeout (timers.js:323:5)
    at Timer.listOnTimeout (timers.js:290:5)
  name: 'OperationTimeoutError',
  translated: true,
  retryable: false,
  info: undefined,
  condition: 'amqp:operation-timeout' }
2019-02-01T14:48:03.909Z rhea:io [connection-3] read 65 bytes
2019-02-01T14:48:03.909Z rhea:io [connection-3] got frame of size 65
2019-02-01T14:48:03.909Z rhea:frames [connection-3]:6 <- attach#12 {"name":"bb2366b6-13fc-4ccb-b657-c27471421f67","source":null,"target":null} 
2019-02-01T14:48:03.909Z rhea:events [connection-3] Link got event: receiver_open
2019-02-01T14:48:03.909Z rhea:frames [connection-3]:6 -> flow#13 {"incoming_window":2048,"outgoing_window":4294967295,"link_credit":1000} 
2019-02-01T14:48:03.909Z rhea:io [connection-3] read 370 bytes
2019-02-01T14:48:03.909Z rhea:io [connection-3] got frame of size 370
2019-02-01T14:48:03.909Z rhea:frames [connection-3]:6 <- detach#16 {"closed":true,"error":{"condition":"amqp:internal-error","description":"The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:da242be9354443d4abd0a9c01a3683ae_G3, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:03"}} 
2019-02-01T14:48:03.909Z rhea:events [connection-3] Link got event: receiver_error
2019-02-01T14:48:03.909Z azure:event-hubs:error [connection-3] An error occurred for Receiver 'bb2366b6-13fc-4ccb-b657-c27471421f67': { InternalServerError: The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:da242be9354443d4abd0a9c01a3683ae_G3, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:03
    at Object.translate (service\node_modules\@azure\amqp-common\lib\errors.ts:537:13)
    at Receiver.EventHubReceiver._onAmqpError (service\node_modules\@azure\event-hubs\lib\eventHubReceiver.ts:225:25)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at emit (service\node_modules\rhea-promise\lib\util\utils.ts:183:20)
    at Object.emitEvent (service\node_modules\rhea-promise\lib\util\utils.ts:195:5)
    at Receiver._link.on (service\node_modules\rhea-promise\lib\link.ts:292:11)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at Receiver.link.dispatch (service\node_modules\rhea\lib\link.js:59:37)
  name: 'InternalServerError',
  translated: true,
  retryable: true,
  info: null,
  condition: 'amqp:internal-error' }.
2019-02-01T14:48:03.909Z azure:event-hubs:error [connection-3] Since received error is retryable, we will NOT notify the user's error handler.
2019-02-01T14:48:03.909Z rhea:events [connection-3] Link got event: receiver_close
2019-02-01T14:48:03.909Z azure:event-hubs:error [connection-3] 'receiver_close' event occurred for receiver 'bb2366b6-13fc-4ccb-b657-c27471421f67' with address 'event-hub2/ConsumerGroups/$default/Partitions/10'. The associated error is: c {
  value: 
   [ Typed { type: [Object], value: 'amqp:internal-error' },
     Typed {
       type: [Object],
       value: 'The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:da242be9354443d4abd0a9c01a3683ae_G3, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:03' },
     Typed { type: [Object], value: null } ] }
2019-02-01T14:48:03.909Z azure:event-hubs:error [connection-3] 'receiver_close' event occurred on the receiver 'bb2366b6-13fc-4ccb-b657-c27471421f67' with address 'event-hub2/ConsumerGroups/$default/Partitions/10' because the sdk initiated it. Hence not calling detached from the _onAmqpClose() handler.
2019-02-01T14:48:03.909Z rhea:frames [connection-3]:6 -> detach#16 {"closed":true} 
2019-02-01T14:48:03.941Z rhea:io [connection-2] read 65 bytes
2019-02-01T14:48:03.941Z rhea:io [connection-2] got frame of size 65
2019-02-01T14:48:03.941Z rhea:frames [connection-2]:3 <- attach#12 {"name":"cce50b0f-3922-4296-871f-6fa391aabad0","source":null,"target":null} 
2019-02-01T14:48:03.941Z rhea:events [connection-2] Link got event: receiver_open
2019-02-01T14:48:03.941Z rhea:frames [connection-2]:3 -> flow#13 {"incoming_window":2048,"outgoing_window":4294967295,"link_credit":1000} 
2019-02-01T14:48:03.941Z rhea:io [connection-2] read 371 bytes
2019-02-01T14:48:03.941Z rhea:io [connection-2] got frame of size 371
2019-02-01T14:48:03.941Z rhea:frames [connection-2]:3 <- detach#16 {"closed":true,"error":{"condition":"amqp:internal-error","description":"The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:10e001ac18144698bf8210928ecb5c9e_G26, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:03"}} 
2019-02-01T14:48:03.941Z rhea:events [connection-2] Link got event: receiver_error
2019-02-01T14:48:03.941Z azure:event-hubs:error [connection-2] An error occurred for Receiver 'cce50b0f-3922-4296-871f-6fa391aabad0': { InternalServerError: The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:10e001ac18144698bf8210928ecb5c9e_G26, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:03
    at Object.translate (service\node_modules\@azure\amqp-common\lib\errors.ts:537:13)
    at Receiver.EventHubReceiver._onAmqpError (service\node_modules\@azure\event-hubs\lib\eventHubReceiver.ts:225:25)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at emit (service\node_modules\rhea-promise\lib\util\utils.ts:183:20)
    at Object.emitEvent (service\node_modules\rhea-promise\lib\util\utils.ts:195:5)
    at Receiver._link.on (service\node_modules\rhea-promise\lib\link.ts:292:11)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at Receiver.link.dispatch (service\node_modules\rhea\lib\link.js:59:37)
  name: 'InternalServerError',
  translated: true,
  retryable: true,
  info: null,
  condition: 'amqp:internal-error' }.
2019-02-01T14:48:03.941Z azure:event-hubs:error [connection-2] Since received error is retryable, we will NOT notify the user's error handler.
2019-02-01T14:48:03.941Z rhea:events [connection-2] Link got event: receiver_close
2019-02-01T14:48:03.941Z azure:event-hubs:error [connection-2] 'receiver_close' event occurred for receiver 'cce50b0f-3922-4296-871f-6fa391aabad0' with address 'event-hub1/ConsumerGroups/$default/Partitions/7'. The associated error is: c {
  value: 
   [ Typed { type: [Object], value: 'amqp:internal-error' },
     Typed {
       type: [Object],
       value: 'The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:10e001ac18144698bf8210928ecb5c9e_G26, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:03' },
     Typed { type: [Object], value: null } ] }
2019-02-01T14:48:03.941Z azure:event-hubs:error [connection-2] 'receiver_close' event occurred on the receiver 'cce50b0f-3922-4296-871f-6fa391aabad0' with address 'event-hub1/ConsumerGroups/$default/Partitions/7' because the sdk initiated it. Hence not calling detached from the _onAmqpClose() handler.
2019-02-01T14:48:03.941Z rhea:frames [connection-2]:3 -> detach#16 {"closed":true} 
2019-02-01T14:48:06.557Z rhea-promise:error [connection-1] Unable to create the amqp receiver c1a73413-88ec-45eb-84a2-90be43c132da due to operation timeout.
2019-02-01T14:48:06.557Z azure:event-hubs:error [connection-1] An error occured while creating the receiver 'c1a73413-88ec-45eb-84a2-90be43c132da': { OperationTimeoutError: Unable to create the amqp receiver c1a73413-88ec-45eb-84a2-90be43c132da due to operation timeout.
    at Timeout.actionAfterTimeout (service\node_modules\rhea-promise\lib\session.ts:258:23)
    at ontimeout (timers.js:498:11)
    at tryOnTimeout (timers.js:323:5)
    at Timer.listOnTimeout (timers.js:290:5)
  name: 'OperationTimeoutError',
  translated: true,
  retryable: false,
  info: undefined,
  condition: 'amqp:operation-timeout' }
2019-02-01T14:48:06.557Z azure:event-hubs:error [connection-1] An error occurred while processing detached() of Receiver 'c1a73413-88ec-45eb-84a2-90be43c132da' with address 'event-hub3/ConsumerGroups/$default/Partitions/7': { OperationTimeoutError: Unable to create the amqp receiver c1a73413-88ec-45eb-84a2-90be43c132da due to operation timeout.
    at Timeout.actionAfterTimeout (service\node_modules\rhea-promise\lib\session.ts:258:23)
    at ontimeout (timers.js:498:11)
    at tryOnTimeout (timers.js:323:5)
    at Timer.listOnTimeout (timers.js:290:5)
  name: 'OperationTimeoutError',
  translated: true,
  retryable: false,
  info: undefined,
  condition: 'amqp:operation-timeout' }
2019-02-01T14:48:06.651Z rhea-promise:error [connection-1] Unable to create the amqp receiver a236457c-34e2-4d60-b1ab-6ce90d005561 due to operation timeout.
2019-02-01T14:48:06.651Z azure:event-hubs:error [connection-1] An error occured while creating the receiver 'a236457c-34e2-4d60-b1ab-6ce90d005561': { OperationTimeoutError: Unable to create the amqp receiver a236457c-34e2-4d60-b1ab-6ce90d005561 due to operation timeout.
    at Timeout.actionAfterTimeout (service\node_modules\rhea-promise\lib\session.ts:258:23)
    at ontimeout (timers.js:498:11)
    at tryOnTimeout (timers.js:323:5)
    at Timer.listOnTimeout (timers.js:290:5)
  name: 'OperationTimeoutError',
  translated: true,
  retryable: false,
  info: undefined,
  condition: 'amqp:operation-timeout' }
2019-02-01T14:48:06.651Z azure:event-hubs:error [connection-1] An error occurred while processing detached() of Receiver 'a236457c-34e2-4d60-b1ab-6ce90d005561' with address 'event-hub3/ConsumerGroups/$default/Partitions/10': { OperationTimeoutError: Unable to create the amqp receiver a236457c-34e2-4d60-b1ab-6ce90d005561 due to operation timeout.
    at Timeout.actionAfterTimeout (service\node_modules\rhea-promise\lib\session.ts:258:23)
    at ontimeout (timers.js:498:11)
    at tryOnTimeout (timers.js:323:5)
    at Timer.listOnTimeout (timers.js:290:5)
  name: 'OperationTimeoutError',
  translated: true,
  retryable: false,
  info: undefined,
  condition: 'amqp:operation-timeout' }
2019-02-01T14:48:06.776Z rhea:io [connection-1] read 65 bytes
2019-02-01T14:48:06.776Z rhea:io [connection-1] got frame of size 65
2019-02-01T14:48:06.776Z rhea:frames [connection-1]:3 <- attach#12 {"name":"c1a73413-88ec-45eb-84a2-90be43c132da","source":null,"target":null} 
2019-02-01T14:48:06.776Z rhea:events [connection-1] Link got event: receiver_open
2019-02-01T14:48:06.776Z rhea:frames [connection-1]:3 -> flow#13 {"incoming_window":2048,"outgoing_window":4294967295,"link_credit":1000} 
2019-02-01T14:48:06.792Z rhea:io [connection-1] read 807 bytes
2019-02-01T14:48:06.792Z rhea:io [connection-1] got frame of size 371
2019-02-01T14:48:06.792Z rhea:frames [connection-1]:3 <- detach#16 {"closed":true,"error":{"condition":"amqp:internal-error","description":"The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:7a43db5463bc4622b705269dc82ea11d_G27, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:06"}} 
2019-02-01T14:48:06.792Z rhea:events [connection-1] Link got event: receiver_error
2019-02-01T14:48:06.792Z azure:event-hubs:error [connection-1] An error occurred for Receiver 'c1a73413-88ec-45eb-84a2-90be43c132da': { InternalServerError: The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:7a43db5463bc4622b705269dc82ea11d_G27, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:06
    at Object.translate (service\node_modules\@azure\amqp-common\lib\errors.ts:537:13)
    at Receiver.EventHubReceiver._onAmqpError (service\node_modules\@azure\event-hubs\lib\eventHubReceiver.ts:225:25)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at emit (service\node_modules\rhea-promise\lib\util\utils.ts:183:20)
    at Object.emitEvent (service\node_modules\rhea-promise\lib\util\utils.ts:195:5)
    at Receiver._link.on (service\node_modules\rhea-promise\lib\link.ts:292:11)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at Receiver.link.dispatch (service\node_modules\rhea\lib\link.js:59:37)
  name: 'InternalServerError',
  translated: true,
  retryable: true,
  info: null,
  condition: 'amqp:internal-error' }.
2019-02-01T14:48:06.792Z azure:event-hubs:error [connection-1] Since received error is retryable, we will NOT notify the user's error handler.
2019-02-01T14:48:06.792Z rhea:events [connection-1] Link got event: receiver_close
2019-02-01T14:48:06.792Z azure:event-hubs:error [connection-1] 'receiver_close' event occurred for receiver 'c1a73413-88ec-45eb-84a2-90be43c132da' with address 'event-hub3/ConsumerGroups/$default/Partitions/7'. The associated error is: c {
  value: 
   [ Typed { type: [Object], value: 'amqp:internal-error' },
     Typed {
       type: [Object],
       value: 'The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:7a43db5463bc4622b705269dc82ea11d_G27, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:06' },
     Typed { type: [Object], value: null } ] }
2019-02-01T14:48:06.792Z azure:event-hubs:error [connection-1] 'receiver_close' event occurred on the receiver 'c1a73413-88ec-45eb-84a2-90be43c132da' with address 'event-hub3/ConsumerGroups/$default/Partitions/7' because the sdk initiated it. Hence not calling detached from the _onAmqpClose() handler.
2019-02-01T14:48:06.792Z rhea:io [connection-1] got frame of size 65
2019-02-01T14:48:06.792Z rhea:frames [connection-1]:6 <- attach#12 {"name":"a236457c-34e2-4d60-b1ab-6ce90d005561","source":null,"target":null} 
2019-02-01T14:48:06.792Z rhea:events [connection-1] Link got event: receiver_open
2019-02-01T14:48:06.792Z rhea:io [connection-1] got frame of size 371
2019-02-01T14:48:06.792Z rhea:frames [connection-1]:6 <- detach#16 {"closed":true,"error":{"condition":"amqp:internal-error","description":"The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:7a43db5463bc4622b705269dc82ea11d_G27, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:06"}} 
2019-02-01T14:48:06.792Z rhea:events [connection-1] Link got event: receiver_error
2019-02-01T14:48:06.792Z azure:event-hubs:error [connection-1] An error occurred for Receiver 'a236457c-34e2-4d60-b1ab-6ce90d005561': { InternalServerError: The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:7a43db5463bc4622b705269dc82ea11d_G27, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:06
    at Object.translate (service\node_modules\@azure\amqp-common\lib\errors.ts:537:13)
    at Receiver.EventHubReceiver._onAmqpError (service\node_modules\@azure\event-hubs\lib\eventHubReceiver.ts:225:25)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at emit (service\node_modules\rhea-promise\lib\util\utils.ts:183:20)
    at Object.emitEvent (service\node_modules\rhea-promise\lib\util\utils.ts:195:5)
    at Receiver._link.on (service\node_modules\rhea-promise\lib\link.ts:292:11)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at Receiver.link.dispatch (service\node_modules\rhea\lib\link.js:59:37)
  name: 'InternalServerError',
  translated: true,
  retryable: true,
  info: null,
  condition: 'amqp:internal-error' }.
2019-02-01T14:48:06.792Z azure:event-hubs:error [connection-1] Since received error is retryable, we will NOT notify the user's error handler.
2019-02-01T14:48:06.792Z rhea:events [connection-1] Link got event: receiver_close
2019-02-01T14:48:06.792Z azure:event-hubs:error [connection-1] 'receiver_close' event occurred for receiver 'a236457c-34e2-4d60-b1ab-6ce90d005561' with address 'event-hub3/ConsumerGroups/$default/Partitions/10'. The associated error is: c {
  value: 
   [ Typed { type: [Object], value: 'amqp:internal-error' },
     Typed {
       type: [Object],
       value: 'The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:7a43db5463bc4622b705269dc82ea11d_G27, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:06' },
     Typed { type: [Object], value: null } ] }
2019-02-01T14:48:06.792Z azure:event-hubs:error [connection-1] 'receiver_close' event occurred on the receiver 'a236457c-34e2-4d60-b1ab-6ce90d005561' with address 'event-hub3/ConsumerGroups/$default/Partitions/10' because the sdk initiated it. Hence not calling detached from the _onAmqpClose() handler.
2019-02-01T14:48:06.792Z rhea:frames [connection-1]:3 -> detach#16 {"closed":true} 
2019-02-01T14:48:06.792Z rhea:frames [connection-1]:6 -> flow#13 {"incoming_window":2048,"outgoing_window":4294967295,"link_credit":1000} 
2019-02-01T14:48:06.792Z rhea:frames [connection-1]:6 -> detach#16 {"closed":true} 
2019-02-01T14:48:07.354Z rhea-promise:error [connection-3] Unable to create the amqp receiver 83143c52-2129-4ee9-acb1-e7e43c75b127 due to operation timeout.
2019-02-01T14:48:07.354Z azure:event-hubs:error [connection-3] An error occured while creating the receiver '83143c52-2129-4ee9-acb1-e7e43c75b127': { OperationTimeoutError: Unable to create the amqp receiver 83143c52-2129-4ee9-acb1-e7e43c75b127 due to operation timeout.
    at Timeout.actionAfterTimeout (service\node_modules\rhea-promise\lib\session.ts:258:23)
    at ontimeout (timers.js:498:11)
    at tryOnTimeout (timers.js:323:5)
    at Timer.listOnTimeout (timers.js:290:5)
  name: 'OperationTimeoutError',
  translated: true,
  retryable: false,
  info: undefined,
  condition: 'amqp:operation-timeout' }
2019-02-01T14:48:07.354Z azure:event-hubs:error [connection-3] An error occurred while processing detached() of Receiver '83143c52-2129-4ee9-acb1-e7e43c75b127' with address 'event-hub2/ConsumerGroups/$default/Partitions/7': { OperationTimeoutError: Unable to create the amqp receiver 83143c52-2129-4ee9-acb1-e7e43c75b127 due to operation timeout.
    at Timeout.actionAfterTimeout (service\node_modules\rhea-promise\lib\session.ts:258:23)
    at ontimeout (timers.js:498:11)
    at tryOnTimeout (timers.js:323:5)
    at Timer.listOnTimeout (timers.js:290:5)
  name: 'OperationTimeoutError',
  translated: true,
  retryable: false,
  info: undefined,
  condition: 'amqp:operation-timeout' }
2019-02-01T14:48:07.370Z rhea-promise:error [connection-2] Unable to create the amqp receiver 9556c09e-dafd-46d6-aef0-d0d45ba36d5a due to operation timeout.
2019-02-01T14:48:07.370Z azure:event-hubs:error [connection-2] An error occured while creating the receiver '9556c09e-dafd-46d6-aef0-d0d45ba36d5a': { OperationTimeoutError: Unable to create the amqp receiver 9556c09e-dafd-46d6-aef0-d0d45ba36d5a due to operation timeout.
    at Timeout.actionAfterTimeout (service\node_modules\rhea-promise\lib\session.ts:258:23)
    at ontimeout (timers.js:498:11)
    at tryOnTimeout (timers.js:323:5)
    at Timer.listOnTimeout (timers.js:290:5)
  name: 'OperationTimeoutError',
  translated: true,
  retryable: false,
  info: undefined,
  condition: 'amqp:operation-timeout' }
2019-02-01T14:48:07.370Z azure:event-hubs:error [connection-2] An error occurred while processing detached() of Receiver '9556c09e-dafd-46d6-aef0-d0d45ba36d5a' with address 'event-hub1/ConsumerGroups/$default/Partitions/10': { OperationTimeoutError: Unable to create the amqp receiver 9556c09e-dafd-46d6-aef0-d0d45ba36d5a due to operation timeout.
    at Timeout.actionAfterTimeout (service\node_modules\rhea-promise\lib\session.ts:258:23)
    at ontimeout (timers.js:498:11)
    at tryOnTimeout (timers.js:323:5)
    at Timer.listOnTimeout (timers.js:290:5)
  name: 'OperationTimeoutError',
  translated: true,
  retryable: false,
  info: undefined,
  condition: 'amqp:operation-timeout' }
2019-02-01T14:48:07.557Z rhea:io [connection-3] read 65 bytes
2019-02-01T14:48:07.557Z rhea:io [connection-3] got frame of size 65
2019-02-01T14:48:07.557Z rhea:frames [connection-3]:3 <- attach#12 {"name":"83143c52-2129-4ee9-acb1-e7e43c75b127","source":null,"target":null} 
2019-02-01T14:48:07.557Z rhea:events [connection-3] Link got event: receiver_open
2019-02-01T14:48:07.557Z rhea:frames [connection-3]:3 -> flow#13 {"incoming_window":2048,"outgoing_window":4294967295,"link_credit":1000} 
2019-02-01T14:48:07.557Z rhea:io [connection-3] read 370 bytes
2019-02-01T14:48:07.557Z rhea:io [connection-3] got frame of size 370
2019-02-01T14:48:07.557Z rhea:frames [connection-3]:3 <- detach#16 {"closed":true,"error":{"condition":"amqp:internal-error","description":"The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:da242be9354443d4abd0a9c01a3683ae_G3, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:07"}} 
2019-02-01T14:48:07.557Z rhea:events [connection-3] Link got event: receiver_error
2019-02-01T14:48:07.557Z azure:event-hubs:error [connection-3] An error occurred for Receiver '83143c52-2129-4ee9-acb1-e7e43c75b127': { InternalServerError: The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:da242be9354443d4abd0a9c01a3683ae_G3, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:07
    at Object.translate (service\node_modules\@azure\amqp-common\lib\errors.ts:537:13)
    at Receiver.EventHubReceiver._onAmqpError (service\node_modules\@azure\event-hubs\lib\eventHubReceiver.ts:225:25)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at emit (service\node_modules\rhea-promise\lib\util\utils.ts:183:20)
    at Object.emitEvent (service\node_modules\rhea-promise\lib\util\utils.ts:195:5)
    at Receiver._link.on (service\node_modules\rhea-promise\lib\link.ts:292:11)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at Receiver.link.dispatch (service\node_modules\rhea\lib\link.js:59:37)
  name: 'InternalServerError',
  translated: true,
  retryable: true,
  info: null,
  condition: 'amqp:internal-error' }.
2019-02-01T14:48:07.557Z azure:event-hubs:error [connection-3] Since received error is retryable, we will NOT notify the user's error handler.
2019-02-01T14:48:07.557Z rhea:events [connection-3] Link got event: receiver_close
2019-02-01T14:48:07.557Z azure:event-hubs:error [connection-3] 'receiver_close' event occurred for receiver '83143c52-2129-4ee9-acb1-e7e43c75b127' with address 'event-hub2/ConsumerGroups/$default/Partitions/7'. The associated error is: c {
  value: 
   [ Typed { type: [Object], value: 'amqp:internal-error' },
     Typed {
       type: [Object],
       value: 'The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:da242be9354443d4abd0a9c01a3683ae_G3, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:07' },
     Typed { type: [Object], value: null } ] }
2019-02-01T14:48:07.557Z azure:event-hubs:error [connection-3] 'receiver_close' event occurred on the receiver '83143c52-2129-4ee9-acb1-e7e43c75b127' with address 'event-hub2/ConsumerGroups/$default/Partitions/7' because the sdk initiated it. Hence not calling detached from the _onAmqpClose() handler.
2019-02-01T14:48:07.557Z rhea:frames [connection-3]:3 -> detach#16 {"closed":true} 
2019-02-01T14:48:07.573Z rhea:io [connection-2] read 65 bytes
2019-02-01T14:48:07.573Z rhea:io [connection-2] got frame of size 65
2019-02-01T14:48:07.573Z rhea:frames [connection-2]:6 <- attach#12 {"name":"9556c09e-dafd-46d6-aef0-d0d45ba36d5a","source":null,"target":null} 
2019-02-01T14:48:07.573Z rhea:events [connection-2] Link got event: receiver_open
2019-02-01T14:48:07.573Z rhea:frames [connection-2]:6 -> flow#13 {"incoming_window":2048,"outgoing_window":4294967295,"link_credit":1000} 
2019-02-01T14:48:07.573Z rhea:io [connection-2] read 371 bytes
2019-02-01T14:48:07.573Z rhea:io [connection-2] got frame of size 371
2019-02-01T14:48:07.573Z rhea:frames [connection-2]:6 <- detach#16 {"closed":true,"error":{"condition":"amqp:internal-error","description":"The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:10e001ac18144698bf8210928ecb5c9e_G26, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:07"}} 
2019-02-01T14:48:07.573Z rhea:events [connection-2] Link got event: receiver_error
2019-02-01T14:48:07.573Z azure:event-hubs:error [connection-2] An error occurred for Receiver '9556c09e-dafd-46d6-aef0-d0d45ba36d5a': { InternalServerError: The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:10e001ac18144698bf8210928ecb5c9e_G26, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:07
    at Object.translate (service\node_modules\@azure\amqp-common\lib\errors.ts:537:13)
    at Receiver.EventHubReceiver._onAmqpError (service\node_modules\@azure\event-hubs\lib\eventHubReceiver.ts:225:25)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at emit (service\node_modules\rhea-promise\lib\util\utils.ts:183:20)
    at Object.emitEvent (service\node_modules\rhea-promise\lib\util\utils.ts:195:5)
    at Receiver._link.on (service\node_modules\rhea-promise\lib\link.ts:292:11)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at Receiver.link.dispatch (service\node_modules\rhea\lib\link.js:59:37)
  name: 'InternalServerError',
  translated: true,
  retryable: true,
  info: null,
  condition: 'amqp:internal-error' }.
2019-02-01T14:48:07.573Z azure:event-hubs:error [connection-2] Since received error is retryable, we will NOT notify the user's error handler.
2019-02-01T14:48:07.573Z rhea:events [connection-2] Link got event: receiver_close
2019-02-01T14:48:07.573Z azure:event-hubs:error [connection-2] 'receiver_close' event occurred for receiver '9556c09e-dafd-46d6-aef0-d0d45ba36d5a' with address 'event-hub1/ConsumerGroups/$default/Partitions/10'. The associated error is: c {
  value: 
   [ Typed { type: [Object], value: 'amqp:internal-error' },
     Typed {
       type: [Object],
       value: 'The service was unable to process the request; please retry the operation. For more information on exception types and proper exception handling, please refer to http://go.microsoft.com/fwlink/?LinkId=761101 TrackingId:10e001ac18144698bf8210928ecb5c9e_G26, SystemTracker:gateway5, Timestamp:2019-02-01T14:48:07' },
     Typed { type: [Object], value: null } ] }
2019-02-01T14:48:07.573Z azure:event-hubs:error [connection-2] 'receiver_close' event occurred on the receiver '9556c09e-dafd-46d6-aef0-d0d45ba36d5a' with address 'event-hub1/ConsumerGroups/$default/Partitions/10' because the sdk initiated it. Hence not calling detached from the _onAmqpClose() handler.
2019-02-01T14:48:07.573Z rhea:frames [connection-2]:6 -> detach#16 {"closed":true} 
2019-02-01T14:50:06.797Z rhea:frames [connection-1]:0 -> empty
2019-02-01T14:50:07.583Z rhea:frames [connection-3]:0 -> empty
2019-02-01T14:50:07.583Z rhea:frames [connection-2]:0 -> empty
2019-02-01T14:50:44.041Z rhea:io [connection-1] read 41 bytes
2019-02-01T14:50:44.041Z rhea:io [connection-1] got frame of size 41
2019-02-01T14:50:44.041Z rhea:frames [connection-1]:0 <- flow#13 {"next_incoming_id":3189,"incoming_window":5000,"next_outgoing_id":3190,"outgoing_window":1858,"echo":true} 
2019-02-01T14:50:47.488Z rhea:io [connection-3] read 41 bytes
2019-02-01T14:50:47.488Z rhea:io [connection-3] got frame of size 41
2019-02-01T14:50:47.488Z rhea:frames [connection-3]:0 <- flow#13 {"next_incoming_id":3184,"incoming_window":5000,"next_outgoing_id":3185,"outgoing_window":1863,"echo":true} 
2019-02-01T14:50:47.676Z rhea:io [connection-2] read 41 bytes
2019-02-01T14:50:47.676Z rhea:io [connection-2] got frame of size 41
2019-02-01T14:50:47.676Z rhea:frames [connection-2]:0 <- flow#13 {"next_incoming_id":3185,"incoming_window":5000,"next_outgoing_id":3186,"outgoing_window":1862,"echo":true} 
2019-02-01T14:52:06.808Z rhea:frames [connection-1]:0 -> empty
2019-02-01T14:52:07.592Z rhea:frames [connection-3]:0 -> empty
2019-02-01T14:52:07.592Z rhea:frames [connection-2]:0 -> empty
2019-02-01T14:53:44.025Z rhea:io [connection-1] read 41 bytes
2019-02-01T14:53:44.025Z rhea:io [connection-1] got frame of size 41
2019-02-01T14:53:44.025Z rhea:frames [connection-1]:0 <- flow#13 {"next_incoming_id":3189,"incoming_window":5000,"next_outgoing_id":3190,"outgoing_window":1858,"echo":true} 
2019-02-01T14:53:47.444Z rhea:io [connection-3] read 41 bytes
2019-02-01T14:53:47.444Z rhea:io [connection-3] got frame of size 41
2019-02-01T14:53:47.444Z rhea:frames [connection-3]:0 <- flow#13 {"next_incoming_id":3184,"incoming_window":5000,"next_outgoing_id":3185,"outgoing_window":1863,"echo":true} 
2019-02-01T14:53:47.650Z rhea:io [connection-2] read 41 bytes
2019-02-01T14:53:47.650Z rhea:io [connection-2] got frame of size 41
2019-02-01T14:53:47.650Z rhea:frames [connection-2]:0 <- flow#13 {"next_incoming_id":3185,"incoming_window":5000,"next_outgoing_id":3186,"outgoing_window":1862,"echo":true} 
2019-02-01T14:54:06.810Z rhea:frames [connection-1]:0 -> empty
2019-02-01T14:54:07.597Z rhea:frames [connection-3]:0 -> empty
2019-02-01T14:54:07.597Z rhea:frames [connection-2]:0 -> empty
2019-02-01T14:55:54.974Z rhea:frames [connection-3]:0 -> transfer#14 {"delivery_id":3184,"delivery_tag":{"type":"Buffer","data":[51,49,56,52]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 5c 00 00 00 05 a1 24 30 33 37 35 36 32 31 33 2d 37 63 61 61 2d 34 62 34 35 2d 62 62 32 33 2d 66 61 37 61 33 33 31 36 ... >
2019-02-01T14:55:54.974Z rhea:io [connection-3] read 27 bytes
2019-02-01T14:55:54.974Z rhea:io [connection-3] got frame of size 27
2019-02-01T14:55:54.974Z rhea:frames [connection-3]:0 <- disposition#15 {"role":true,"first":3184,"settled":true,"state":[]} 
2019-02-01T14:55:54.974Z rhea:events [connection-3] Received disposition for outgoing transfers
2019-02-01T14:55:54.974Z rhea:events [connection-3] Link got event: accepted
2019-02-01T14:55:54.974Z rhea:events [connection-3] Link got event: settled
2019-02-01T14:55:54.974Z rhea:io [connection-3] read 145 bytes
2019-02-01T14:55:54.974Z rhea:io [connection-3] got frame of size 145
2019-02-01T14:55:54.974Z rhea:frames [connection-3]:0 <- transfer#14 {"handle":1,"delivery_id":3184,"delivery_tag":{"type":"Buffer","data":[113,12,0,0]}} <Buffer 00 53 73 c0 33 0d 40 40 40 40 40 a1 24 30 33 37 35 36 32 31 33 2d 37 63 61 61 2d 34 62 34 35 2d 62 62 32 33 2d 66 61 37 61 33 33 31 36 39 66 61 34 40 ... >
2019-02-01T14:55:54.974Z rhea:events [connection-3] Link got event: message
2019-02-01T14:55:54.974Z rhea:frames [connection-3]:0 -> disposition#15 {"role":true,"first":3184,"last":3184,"settled":true,"state":[]} 
2019-02-01T14:55:55.288Z rhea:frames [connection-2]:0 -> transfer#14 {"delivery_id":3185,"delivery_tag":{"type":"Buffer","data":[51,49,56,53]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 5c 00 00 00 05 a1 24 30 32 64 65 62 62 30 61 2d 39 36 32 34 2d 31 31 34 64 2d 61 39 32 33 2d 39 31 38 63 32 36 63 30 ... >
2019-02-01T14:55:55.288Z rhea:io [connection-2] read 27 bytes
2019-02-01T14:55:55.288Z rhea:io [connection-2] got frame of size 27
2019-02-01T14:55:55.288Z rhea:frames [connection-2]:0 <- disposition#15 {"role":true,"first":3185,"settled":true,"state":[]} 
2019-02-01T14:55:55.288Z rhea:events [connection-2] Received disposition for outgoing transfers
2019-02-01T14:55:55.288Z rhea:events [connection-2] Link got event: accepted
2019-02-01T14:55:55.288Z rhea:events [connection-2] Link got event: settled
2019-02-01T14:55:55.288Z rhea:io [connection-2] read 145 bytes
2019-02-01T14:55:55.288Z rhea:io [connection-2] got frame of size 145
2019-02-01T14:55:55.288Z rhea:frames [connection-2]:0 <- transfer#14 {"handle":1,"delivery_id":3185,"delivery_tag":{"type":"Buffer","data":[114,12,0,0]}} <Buffer 00 53 73 c0 33 0d 40 40 40 40 40 a1 24 30 32 64 65 62 62 30 61 2d 39 36 32 34 2d 31 31 34 64 2d 61 39 32 33 2d 39 31 38 63 32 36 63 30 32 39 64 35 40 ... >
2019-02-01T14:55:55.288Z rhea:events [connection-2] Link got event: message
2019-02-01T14:55:55.288Z rhea:frames [connection-2]:0 -> disposition#15 {"role":true,"first":3185,"last":3185,"settled":true,"state":[]} 
2019-02-01T14:55:56.479Z rhea:frames [connection-3]:0 -> transfer#14 {"delivery_id":3185,"delivery_tag":{"type":"Buffer","data":[51,49,56,53]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 5c 00 00 00 05 a1 24 37 63 33 30 30 32 35 32 2d 32 38 62 65 2d 33 64 34 61 2d 61 66 33 66 2d 39 34 35 62 66 64 32 36 ... >
2019-02-01T14:55:56.479Z rhea:io [connection-3] read 27 bytes
2019-02-01T14:55:56.479Z rhea:io [connection-3] got frame of size 27
2019-02-01T14:55:56.479Z rhea:frames [connection-3]:0 <- disposition#15 {"role":true,"first":3185,"settled":true,"state":[]} 
2019-02-01T14:55:56.479Z rhea:events [connection-3] Received disposition for outgoing transfers
2019-02-01T14:55:56.479Z rhea:events [connection-3] Link got event: accepted
2019-02-01T14:55:56.479Z rhea:events [connection-3] Link got event: settled
2019-02-01T14:55:56.479Z rhea:io [connection-3] read 145 bytes
2019-02-01T14:55:56.479Z rhea:io [connection-3] got frame of size 145
2019-02-01T14:55:56.479Z rhea:frames [connection-3]:0 <- transfer#14 {"handle":1,"delivery_id":3185,"delivery_tag":{"type":"Buffer","data":[114,12,0,0]}} <Buffer 00 53 73 c0 33 0d 40 40 40 40 40 a1 24 37 63 33 30 30 32 35 32 2d 32 38 62 65 2d 33 64 34 61 2d 61 66 33 66 2d 39 34 35 62 66 64 32 36 65 64 32 36 40 ... >
2019-02-01T14:55:56.479Z rhea:events [connection-3] Link got event: message
2019-02-01T14:55:56.479Z rhea:frames [connection-3]:0 -> disposition#15 {"role":true,"first":3185,"last":3185,"settled":true,"state":[]} 
2019-02-01T14:55:56.705Z rhea:frames [connection-1]:0 -> transfer#14 {"delivery_id":3189,"delivery_tag":{"type":"Buffer","data":[51,49,56,57]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 5c 00 00 00 05 a1 24 38 30 61 38 35 35 63 38 2d 65 30 61 62 2d 30 31 34 65 2d 61 62 66 63 2d 33 61 38 62 39 64 31 64 ... >
2019-02-01T14:55:56.705Z rhea:io [connection-1] read 27 bytes
2019-02-01T14:55:56.705Z rhea:io [connection-1] got frame of size 27
2019-02-01T14:55:56.705Z rhea:frames [connection-1]:0 <- disposition#15 {"role":true,"first":3189,"settled":true,"state":[]} 
2019-02-01T14:55:56.705Z rhea:events [connection-1] Received disposition for outgoing transfers
2019-02-01T14:55:56.705Z rhea:events [connection-1] Link got event: accepted
2019-02-01T14:55:56.705Z rhea:events [connection-1] Link got event: settled
2019-02-01T14:55:56.705Z rhea:io [connection-1] read 145 bytes
2019-02-01T14:55:56.705Z rhea:io [connection-1] got frame of size 145
2019-02-01T14:55:56.705Z rhea:frames [connection-1]:0 <- transfer#14 {"handle":1,"delivery_id":3189,"delivery_tag":{"type":"Buffer","data":[118,12,0,0]}} <Buffer 00 53 73 c0 33 0d 40 40 40 40 40 a1 24 38 30 61 38 35 35 63 38 2d 65 30 61 62 2d 30 31 34 65 2d 61 62 66 63 2d 33 61 38 62 39 64 31 64 64 39 36 34 40 ... >
2019-02-01T14:55:56.705Z rhea:events [connection-1] Link got event: message
2019-02-01T14:55:56.705Z rhea:frames [connection-1]:0 -> disposition#15 {"role":true,"first":3189,"last":3189,"settled":true,"state":[]} 
2019-02-01T14:55:56.736Z rhea:frames [connection-1]:0 -> transfer#14 {"delivery_id":3190,"delivery_tag":{"type":"Buffer","data":[51,49,57,48]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 5c 00 00 00 05 a1 24 65 63 35 36 33 38 64 38 2d 65 36 66 63 2d 63 36 34 36 2d 39 30 39 38 2d 37 63 37 37 37 33 38 64 ... >
2019-02-01T14:55:56.736Z rhea:io [connection-1] read 27 bytes
2019-02-01T14:55:56.736Z rhea:io [connection-1] got frame of size 27
2019-02-01T14:55:56.736Z rhea:frames [connection-1]:0 <- disposition#15 {"role":true,"first":3190,"settled":true,"state":[]} 
2019-02-01T14:55:56.736Z rhea:events [connection-1] Received disposition for outgoing transfers
2019-02-01T14:55:56.736Z rhea:events [connection-1] Link got event: accepted
2019-02-01T14:55:56.736Z rhea:events [connection-1] Link got event: settled
2019-02-01T14:55:56.736Z rhea:io [connection-1] read 145 bytes
2019-02-01T14:55:56.736Z rhea:io [connection-1] got frame of size 145
2019-02-01T14:55:56.736Z rhea:frames [connection-1]:0 <- transfer#14 {"handle":1,"delivery_id":3190,"delivery_tag":{"type":"Buffer","data":[119,12,0,0]}} <Buffer 00 53 73 c0 33 0d 40 40 40 40 40 a1 24 65 63 35 36 33 38 64 38 2d 65 36 66 63 2d 63 36 34 36 2d 39 30 39 38 2d 37 63 37 37 37 33 38 64 65 35 35 33 40 ... >
2019-02-01T14:55:56.736Z rhea:events [connection-1] Link got event: message
2019-02-01T14:55:56.736Z rhea:frames [connection-1]:0 -> disposition#15 {"role":true,"first":3190,"last":3190,"settled":true,"state":[]} 
2019-02-01T14:55:56.987Z rhea:frames [connection-2]:0 -> transfer#14 {"delivery_id":3186,"delivery_tag":{"type":"Buffer","data":[51,49,56,54]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 5c 00 00 00 05 a1 24 36 35 30 33 38 39 33 37 2d 32 65 36 65 2d 34 35 34 39 2d 39 66 63 64 2d 35 65 63 37 34 66 35 64 ... >
2019-02-01T14:55:56.987Z rhea:io [connection-2] read 27 bytes
2019-02-01T14:55:56.987Z rhea:io [connection-2] got frame of size 27
2019-02-01T14:55:56.987Z rhea:frames [connection-2]:0 <- disposition#15 {"role":true,"first":3186,"settled":true,"state":[]} 
2019-02-01T14:55:56.987Z rhea:events [connection-2] Received disposition for outgoing transfers
2019-02-01T14:55:56.987Z rhea:events [connection-2] Link got event: accepted
2019-02-01T14:55:56.987Z rhea:events [connection-2] Link got event: settled
2019-02-01T14:55:56.987Z rhea:io [connection-2] read 145 bytes
2019-02-01T14:55:56.987Z rhea:io [connection-2] got frame of size 145
2019-02-01T14:55:56.987Z rhea:frames [connection-2]:0 <- transfer#14 {"handle":1,"delivery_id":3186,"delivery_tag":{"type":"Buffer","data":[115,12,0,0]}} <Buffer 00 53 73 c0 33 0d 40 40 40 40 40 a1 24 36 35 30 33 38 39 33 37 2d 32 65 36 65 2d 34 35 34 39 2d 39 66 63 64 2d 35 65 63 37 34 66 35 64 63 34 63 63 40 ... >
2019-02-01T14:55:56.987Z rhea:events [connection-2] Link got event: message
2019-02-01T14:55:56.987Z rhea:frames [connection-2]:0 -> disposition#15 {"role":true,"first":3186,"last":3186,"settled":true,"state":[]} 
2019-02-01T14:56:44.018Z rhea:io [connection-1] read 41 bytes
2019-02-01T14:56:44.018Z rhea:io [connection-1] got frame of size 41
2019-02-01T14:56:44.018Z rhea:frames [connection-1]:0 <- flow#13 {"next_incoming_id":3191,"incoming_window":5000,"next_outgoing_id":3192,"outgoing_window":1856,"echo":true} 
2019-02-01T14:56:47.435Z rhea:io [connection-3] read 41 bytes
2019-02-01T14:56:47.435Z rhea:io [connection-3] got frame of size 41
2019-02-01T14:56:47.435Z rhea:frames [connection-3]:0 <- flow#13 {"next_incoming_id":3186,"incoming_window":5000,"next_outgoing_id":3187,"outgoing_window":1861,"echo":true} 
2019-02-01T14:56:47.576Z rhea:io [connection-2] read 41 bytes
2019-02-01T14:56:47.576Z rhea:io [connection-2] got frame of size 41
2019-02-01T14:56:47.576Z rhea:frames [connection-2]:0 <- flow#13 {"next_incoming_id":3187,"incoming_window":5000,"next_outgoing_id":3188,"outgoing_window":1860,"echo":true} 
2019-02-01T14:57:14.503Z rhea:frames [connection-3]:0 -> transfer#14 {"delivery_id":3186,"delivery_tag":{"type":"Buffer","data":[51,49,56,54]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 5c 00 00 00 05 a1 24 61 34 35 38 31 34 36 37 2d 37 63 37 62 2d 38 65 34 31 2d 39 61 66 37 2d 61 38 39 37 33 64 64 39 ... >
2019-02-01T14:57:14.503Z rhea:io [connection-3] read 27 bytes
2019-02-01T14:57:14.503Z rhea:io [connection-3] got frame of size 27
2019-02-01T14:57:14.503Z rhea:frames [connection-3]:0 <- disposition#15 {"role":true,"first":3186,"settled":true,"state":[]} 
2019-02-01T14:57:14.503Z rhea:events [connection-3] Received disposition for outgoing transfers
2019-02-01T14:57:14.503Z rhea:events [connection-3] Link got event: accepted
2019-02-01T14:57:14.503Z rhea:events [connection-3] Link got event: settled
2019-02-01T14:57:14.503Z rhea:io [connection-3] read 145 bytes
2019-02-01T14:57:14.503Z rhea:io [connection-3] got frame of size 145
2019-02-01T14:57:14.503Z rhea:frames [connection-3]:0 <- transfer#14 {"handle":1,"delivery_id":3186,"delivery_tag":{"type":"Buffer","data":[115,12,0,0]}} <Buffer 00 53 73 c0 33 0d 40 40 40 40 40 a1 24 61 34 35 38 31 34 36 37 2d 37 63 37 62 2d 38 65 34 31 2d 39 61 66 37 2d 61 38 39 37 33 64 64 39 66 37 33 31 40 ... >
2019-02-01T14:57:14.503Z rhea:events [connection-3] Link got event: message
2019-02-01T14:57:14.503Z rhea:frames [connection-3]:0 -> disposition#15 {"role":true,"first":3186,"last":3186,"settled":true,"state":[]} 
2019-02-01T14:57:14.582Z rhea:io [connection-4] connected 10.5.0.5:62778 -> 104.208.16.3:5671
2019-02-01T14:57:14.582Z rhea:frames [connection-4] -> { protocol_id: 3, major: 1, minor: 0, revision: 0 }
2019-02-01T14:57:14.582Z rhea:frames [connection-1]:0 -> transfer#14 {"delivery_id":3191,"delivery_tag":{"type":"Buffer","data":[51,49,57,49]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 5c 00 00 00 05 a1 24 39 63 64 33 66 31 65 65 2d 37 38 62 37 2d 38 39 34 32 2d 39 61 39 65 2d 33 31 62 61 39 64 31 36 ... >
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 8 bytes
2019-02-01T14:57:14.582Z rhea:frames [connection-4] <- { protocol_id: 3, major: 1, minor: 0, revision: 0 }
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 63 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-4] got frame of size 63
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:0 <- sasl_mechanisms#40 {"sasl_server_mechanisms":["MSSBCBS","PLAIN","ANONYMOUS","EXTERNAL"]} 
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:0 -> sasl_init#41 {"mechanism":"ANONYMOUS","initial_response":{"type":"Buffer","data":[0,82,111,111,116,77,97,110,97,103,101,83,104,97,114,101,100,65,99,99,101,115,115,75,101,121]},"hostname":"host-name.servicebus.windows.net"} 
2019-02-01T14:57:14.582Z rhea:io [connection-1] read 27 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-1] got frame of size 27
2019-02-01T14:57:14.582Z rhea:frames [connection-1]:0 <- disposition#15 {"role":true,"first":3191,"settled":true,"state":[]} 
2019-02-01T14:57:14.582Z rhea:events [connection-1] Received disposition for outgoing transfers
2019-02-01T14:57:14.582Z rhea:events [connection-1] Link got event: accepted
2019-02-01T14:57:14.582Z rhea:events [connection-1] Link got event: settled
2019-02-01T14:57:14.582Z rhea:io [connection-1] read 145 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-1] got frame of size 145
2019-02-01T14:57:14.582Z rhea:frames [connection-1]:0 <- transfer#14 {"handle":1,"delivery_id":3191,"delivery_tag":{"type":"Buffer","data":[120,12,0,0]}} <Buffer 00 53 73 c0 33 0d 40 40 40 40 40 a1 24 39 63 64 33 66 31 65 65 2d 37 38 62 37 2d 38 39 34 32 2d 39 61 39 65 2d 33 31 62 61 39 64 31 36 62 30 37 39 40 ... >
2019-02-01T14:57:14.582Z rhea:events [connection-1] Link got event: message
2019-02-01T14:57:14.582Z rhea:frames [connection-1]:0 -> disposition#15 {"role":true,"first":3191,"last":3191,"settled":true,"state":[]} 
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 26 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-4] got frame of size 26
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:0 <- sasl_outcome#44 {"additional_data":{"type":"Buffer","data":[87,101,108,99,111,109,101,33]}} 
2019-02-01T14:57:14.582Z rhea:frames [connection-4] -> { protocol_id: 0, major: 1, minor: 0, revision: 0 }
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:0 -> open#10 {"transport":"tls","host":"host-name.servicebus.windows.net","username":"RootManageSharedAccessKey","port":5671,"operationTimeoutInSeconds":60,"servername":"host-name.servicebus.windows.net","id":"connection-4","container_id":"a698da97-093d-7040-b9b0-b4011ef269a1","hostname":"host-name.servicebus.windows.net","properties":{"product":"MSJSClient","version":"1.0.5","user-agent":"/js-event-hubs","platform":"(x64-Windows_NT-6.3.9600)","framework":"Node/v8.12.0"}} 
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:0 -> begin#11 {"incoming_window":2048,"outgoing_window":4294967295} 
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:0 -> attach#12 {"name":"064515c0-887e-3849-a412-7b4b430c4fa7","source":[],"target":["$cbs"]} 
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:0 -> attach#12 {"name":"cbs-5614cd32-444e-2c49-9914-1ae209812ec0","handle":1,"role":true,"source":["$cbs"],"target":[]} 
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:1 -> begin#11 {"incoming_window":2048,"outgoing_window":4294967295} 
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:1 -> attach#12 {"name":"d6ca97e3-a73a-431b-8c42-13851f2b8ca7","role":true,"source":["event-hub4/ConsumerGroups/$default/Partitions/6",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547803620125'"]],"target":[]} 
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:2 -> begin#11 {"incoming_window":2048,"outgoing_window":4294967295} 
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:2 -> attach#12 {"name":"a88ecb69-84c9-4987-b96c-a219cf19d74a","role":true,"source":["event-hub4/ConsumerGroups/$default/Partitions/7",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547803620141'"]],"target":[]} 
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:3 -> begin#11 {"incoming_window":2048,"outgoing_window":4294967295} 
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:3 -> attach#12 {"name":"2fadec42-2806-454d-8584-7366278cf2d6","role":true,"source":["event-hub4/ConsumerGroups/$default/Partitions/8",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547803620156'"]],"target":[]} 
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:4 -> begin#11 {"incoming_window":2048,"outgoing_window":4294967295} 
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:4 -> attach#12 {"name":"ee445d8f-4bb5-423b-a5be-c80cc805450a","role":true,"source":["event-hub4/ConsumerGroups/$default/Partitions/10",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547803620172'"]],"target":[]} 
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:5 -> begin#11 {"incoming_window":2048,"outgoing_window":4294967295} 
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:5 -> attach#12 {"name":"356c76a8-070a-47a0-844d-81a689ba793b","role":true,"source":["event-hub4/ConsumerGroups/$default/Partitions/11",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547803620172'"]],"target":[]} 
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 8 bytes
2019-02-01T14:57:14.582Z rhea:frames [connection-4] <- { protocol_id: 0, major: 1, minor: 0, revision: 0 }
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 71 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-4] got frame of size 71
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:0 <- open#10 {"container_id":"14543c918d7a4802940d936328fea36d_G13","max_frame_size":65536,"channel_max":4999,"idle_time_out":240000} 
2019-02-01T14:57:14.582Z rhea:events [connection-4] Connection got event: connection_open
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:6 -> begin#11 {"incoming_window":2048,"outgoing_window":4294967295} 
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 34 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-4] got frame of size 34
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:0 <- begin#11 {"next_outgoing_id":1,"incoming_window":5000,"outgoing_window":2048,"handle_max":255} 
2019-02-01T14:57:14.582Z rhea:events [connection-4] Session got event: session_open
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 106 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-4] got frame of size 106
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:0 <- attach#12 {"name":"064515c0-887e-3849-a412-7b4b430c4fa7","role":true,"source":[null,null,null,null,null,null,null,null,null,null,null],"target":["$cbs",null,null,null,null,null,null],"max_message_size":{"type":"Buffer","data":[255,255,255,255,255,255,255,255]}} 
2019-02-01T14:57:14.582Z rhea:events [connection-4] Link got event: sender_open
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 35 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-4] got frame of size 35
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:0 <- flow#13 {"incoming_window":5000,"next_outgoing_id":1,"outgoing_window":2048,"link_credit":100} 
2019-02-01T14:57:14.582Z rhea:events [connection-4] Link got event: sender_flow
2019-02-01T14:57:14.582Z rhea:events [connection-4] Link got event: sendable
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 111 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-4] got frame of size 111
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:0 <- attach#12 {"name":"cbs-5614cd32-444e-2c49-9914-1ae209812ec0","handle":1,"source":["$cbs",null,null,null,null,null,null,null,null,null,null],"target":[null,null,null,null,null,null,null],"max_message_size":{"type":"Buffer","data":[255,255,255,255,255,255,255,255]}} 
2019-02-01T14:57:14.582Z rhea:events [connection-4] Link got event: receiver_open
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:0 -> flow#13 {"incoming_window":2048,"outgoing_window":4294967295,"handle":1,"link_credit":1000} 
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 34 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-4] got frame of size 34
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:1 <- begin#11 {"remote_channel":1,"next_outgoing_id":1,"incoming_window":5000,"outgoing_window":2048,"handle_max":255} 
2019-02-01T14:57:14.582Z rhea:events [connection-4] Session got event: session_open
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 34 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-4] got frame of size 34
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:2 <- begin#11 {"remote_channel":2,"next_outgoing_id":1,"incoming_window":5000,"outgoing_window":2048,"handle_max":255} 
2019-02-01T14:57:14.582Z rhea:events [connection-4] Session got event: session_open
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 34 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-4] got frame of size 34
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:3 <- begin#11 {"remote_channel":3,"next_outgoing_id":1,"incoming_window":5000,"outgoing_window":2048,"handle_max":255} 
2019-02-01T14:57:14.582Z rhea:events [connection-4] Session got event: session_open
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 34 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-4] got frame of size 34
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:4 <- begin#11 {"remote_channel":4,"next_outgoing_id":1,"incoming_window":5000,"outgoing_window":2048,"handle_max":255} 
2019-02-01T14:57:14.582Z rhea:events [connection-4] Session got event: session_open
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 34 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-4] got frame of size 34
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:5 <- begin#11 {"remote_channel":5,"next_outgoing_id":1,"incoming_window":5000,"outgoing_window":2048,"handle_max":255} 
2019-02-01T14:57:14.582Z rhea:events [connection-4] Session got event: session_open
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 34 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-4] got frame of size 34
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:6 <- begin#11 {"remote_channel":6,"next_outgoing_id":1,"incoming_window":5000,"outgoing_window":2048,"handle_max":255} 
2019-02-01T14:57:14.582Z rhea:events [connection-4] Session got event: session_open
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:6 -> attach#12 {"name":"7834e55f-16d1-2b46-bbf0-485ca6f3472d","source":[],"target":["$cbs"]} 
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 65 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-4] got frame of size 65
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:6 <- attach#12 {"name":"7834e55f-16d1-2b46-bbf0-485ca6f3472d","role":true,"source":null,"target":null} 
2019-02-01T14:57:14.582Z rhea:events [connection-4] Link got event: sender_open
2019-02-01T14:57:14.582Z rhea:io [connection-4] read 110 bytes
2019-02-01T14:57:14.582Z rhea:io [connection-4] got frame of size 110
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:6 <- detach#16 {"closed":true,"error":{"condition":"amqp:not-allowed","description":"A link to connection '304158961' $cbs node has already been opened."}} 
2019-02-01T14:57:14.582Z rhea:events [connection-4] Link got event: sender_error
2019-02-01T14:57:14.582Z rhea:events [connection-4] Link got event: sender_close
2019-02-01T14:57:14.582Z rhea-promise:error [connection-4] Error occurred while creating a sender over amqp connection: c {
  value: 
   [ Typed { type: [Object], value: 'amqp:not-allowed' },
     Typed {
       type: [Object],
       value: 'A link to connection \'304158961\' $cbs node has already been opened.' },
     Typed { type: [Object], value: null } ] }.
2019-02-01T14:57:14.582Z rhea:frames [connection-4]:6 -> detach#16 {"closed":true} 
2019-02-01T14:57:14.598Z azure:event-hubs:error [connection-4] ManagementClient '97817dae-56f5-4399-bdb4-abea430bba64' with address $management, an error occurred while renewing the token: { InvalidOperationError: A link to connection '304158961' $cbs node has already been opened.
    at Object.translate (service\node_modules\@azure\amqp-common\lib\errors.ts:537:13)
    at CbsClient.<anonymous> (service\node_modules\@azure\amqp-common\lib\cbs.ts:118:13)
    at Generator.throw (<anonymous>)
    at rejected (service\node_modules\tslib\tslib.js:105:69)
    at <anonymous>
    at process._tickCallback (internal/process/next_tick.js:189:7)
  name: 'InvalidOperationError',
  translated: true,
  retryable: false,
  info: null,
  condition: 'amqp:not-allowed' }

MatejSkrbis · 2019-02-07T21:19:50Z

Today I am receiving those Unauthorized access errors like crazy. I got multiple event hubs and multiple event hub namespaces used by different server instances. I got them simultaneously with different servers using different event hub namespaces (probably located in same data center).

Might this error be connected to some underlying infrastructure problems?

I can provide more logs from today if needed,

ramya-rao-a · 2019-02-09T03:11:46Z

Thanks for the logs @MatejSkrbis

It looks there are a series of OperationTimeoutErrors for various receivers followed by a InternalServerError for the same receivers. And towards the end we have the $cbs node has already been opened. error which eventually causes the Unauthorized access errors because the token was not renewed in time.

The OperationTimeoutErrors and InternalServerError are definitely related to the Event Hubs service itself.

The $cbs node has already been opened. is caused by this SDK which I need some more time to look into.

Today I am receiving those Unauthorized access errors like crazy. I got multiple event hubs and multiple event hub namespaces used by different server instances. I got them simultaneously with different servers using different event hub namespaces (probably located in same data center).
Might this error be connected to some underlying infrastructure problems?

That could very much be possible. I'll try and reach out to folks and Event Hubs to see if they can help.

ramya-rao-a · 2019-02-11T02:46:48Z

@MatejSkrbis From your logs in
#186 (comment), I see the below:

For the 3 connections connection-1, connection-2 and connection-3, either there was a retryable error or a problem with the receiver links which resulted in the sdk trying to reconnect the receivers by creating new receiver
This attempt to re-create the receiver links failed with OperationTimeoutError for all 3 connections at around 2019-02-01T14:48:03.706Z .

Unable to create the amqp receiver cce50b0f-3922-4296-871f-6fa391aabad0 due to operation timeout.
Unable to create the amqp receiver c1a73413-88ec-45eb-84a2-90be43c132da due to operation timeout.
Unable to create the amqp receiver 83143c52-2129-4ee9-acb1-e7e43c75b127 due to operation timeout.

A fourth connection connection-4 is created. We then see frames activity to create the cbs session as well as receiver links for receivers for 5 partitions at around 2019-02-01T14:57:14.582Z

The cbs session, with its cbs sender/receiver is created successfully, but before any claims are actually negotiated, there is another request for the cbs session creation that results in the $cbs node has already been opened error.

We do use a lock on the cbsSession to avoid such scenarios, I will continue to look into how this could happen.

Meanwhile, a few follow up questions for you which can help shed more light on your exact scenario.
These would require you to look at the logs right before the point for which you have already shared.

It would be interesting to see the cause for the attempts to reconnect the receivers. Can you check the logs right before what you posted to see if there were any errors printed out for the 3 connections connection-1, connection-2 and connection-3?
I am surprised that for the newly created 4th connection connection-4, there is frame activity for 5 receivers immediately. Do you see any logs for these receivers before 2019-02-01T14:57:14.582Z? If yes, then which connection were they using?
- d6ca97e3-a73a-431b-8c42-13851f2b8ca7
- a88ecb69-84c9-4987-b96c-a219cf19d74a
- 2fadec42-2806-454d-8584-7366278cf2d6
- ee445d8f-4bb5-423b-a5be-c80cc805450a
- 356c76a8-070a-47a0-844d-81a689ba793b
Since you have logs only for "error", there is a chance that you won't find anything for the previous question. So, look for logs that have any of the below before 2019-02-01T14:57:14.582Z. If you do find them, then which connection were they using?
- event-hub4/ConsumerGroups/$default/Partitions/6
- event-hub4/ConsumerGroups/$default/Partitions/7
- event-hub4/ConsumerGroups/$default/Partitions/8
- event-hub4/ConsumerGroups/$default/Partitions/10
- event-hub4/ConsumerGroups/$default/Partitions/11

MatejSkrbis · 2019-02-13T07:56:11Z

Here are the logs for connection-2 of what was happening before logs I posted:

2019-02-01T14:28:16.003Z rhea:frames [connection-2]:0 -> empty
2019-02-01T14:29:47.865Z rhea:io [connection-2] read 41 bytes
2019-02-01T14:29:47.865Z rhea:io [connection-2] got frame of size 41
2019-02-01T14:29:47.865Z rhea:frames [connection-2]:0 <- flow#13 {"next_incoming_id":3182,"incoming_window":5000,"next_outgoing_id":3183,"outgoing_window":1865,"echo":true} 
2019-02-01T14:30:16.016Z rhea:frames [connection-2]:0 -> empty
2019-02-01T14:32:16.018Z rhea:frames [connection-2]:0 -> empty
2019-02-01T14:32:47.874Z rhea:io [connection-2] read 41 bytes
2019-02-01T14:32:47.874Z rhea:io [connection-2] got frame of size 41
2019-02-01T14:32:47.874Z rhea:frames [connection-2]:0 <- flow#13 {"next_incoming_id":3182,"incoming_window":5000,"next_outgoing_id":3183,"outgoing_window":1865,"echo":true} 
2019-02-01T14:34:16.028Z rhea:frames [connection-2]:0 -> empty
2019-02-01T14:35:47.867Z rhea:io [connection-2] read 41 bytes
2019-02-01T14:35:47.867Z rhea:io [connection-2] got frame of size 41
2019-02-01T14:35:47.867Z rhea:frames [connection-2]:0 <- flow#13 {"next_incoming_id":3182,"incoming_window":5000,"next_outgoing_id":3183,"outgoing_window":1865,"echo":true} 
2019-02-01T14:36:16.042Z rhea:frames [connection-2]:0 -> empty
2019-02-01T14:38:16.049Z rhea:frames [connection-2]:0 -> empty
2019-02-01T14:38:47.867Z rhea:io [connection-2] read 41 bytes
2019-02-01T14:38:47.867Z rhea:io [connection-2] got frame of size 41
2019-02-01T14:38:47.867Z rhea:frames [connection-2]:0 <- flow#13 {"next_incoming_id":3182,"incoming_window":5000,"next_outgoing_id":3183,"outgoing_window":1865,"echo":true} 
2019-02-01T14:41:47.777Z rhea:io [connection-2] read 41 bytes
2019-02-01T14:41:47.777Z rhea:io [connection-2] got frame of size 41
2019-02-01T14:41:47.777Z rhea:frames [connection-2]:0 <- flow#13 {"next_incoming_id":3182,"incoming_window":5000,"next_outgoing_id":3183,"outgoing_window":1865,"echo":true} 
2019-02-01T14:42:16.058Z rhea:frames [connection-2]:0 -> empty
2019-02-01T14:44:16.071Z rhea:frames [connection-2]:0 -> empty
2019-02-01T14:44:47.737Z rhea:io [connection-2] read 41 bytes
2019-02-01T14:44:47.737Z rhea:io [connection-2] got frame of size 41
2019-02-01T14:44:47.737Z rhea:frames [connection-2]:0 <- flow#13 {"next_incoming_id":3182,"incoming_window":5000,"next_outgoing_id":3183,"outgoing_window":1865,"echo":true} 
2019-02-01T14:46:16.076Z rhea:frames [connection-2]:0 -> empty
2019-02-01T14:47:03.626Z rhea:io [connection-2] read 17 bytes
2019-02-01T14:47:03.626Z rhea:io [connection-2] got frame of size 17
2019-02-01T14:47:03.626Z rhea:frames [connection-2]:3 <- detach#16 {"closed":true} 
2019-02-01T14:47:03.626Z rhea:events [connection-2] Link got event: receiver_close
2019-02-01T14:47:03.626Z azure:event-hubs:error [connection-2] 'receiver_close' event occurred on the receiver '5106507f-3d8a-45c4-99d7-595a323891bd' with address 'event-hub2/ConsumerGroups/$default/Partitions/7' and the sdk did not initiate this. The receiver is not reconnecting. Hence, calling detached from the _onAmqpClose() handler.
2019-02-01T14:47:03.626Z rhea-promise:error [connection-2] The receiver is open ? -> false
2019-02-01T14:47:03.626Z rhea:frames [connection-2]:3 -> detach#16 {"closed":true} 
2019-02-01T14:47:03.626Z rhea-promise:error [connection-2] The session is open ? -> true
2019-02-01T14:47:03.626Z rhea:frames [connection-2]:3 -> end#17 {} 
2019-02-01T14:47:03.657Z rhea:io [connection-2] read 15 bytes
2019-02-01T14:47:03.657Z rhea:io [connection-2] got frame of size 15
2019-02-01T14:47:03.657Z rhea:frames [connection-2]:3 <- end#17 {} 
2019-02-01T14:47:03.657Z rhea:events [connection-2] Session got event: session_close
2019-02-01T14:47:03.657Z azure:event-hubs:error [connection-2] 'session_close' event occurred on the session of receiver '5106507f-3d8a-45c4-99d7-595a323891bd' with address 'event-hub2/ConsumerGroups/$default/Partitions/7' because the sdk initiated it. Hence not calling detached from the _onSessionClose() handler.
2019-02-01T14:47:03.657Z azure:event-hubs:error [connection-2] close() method of Receiver '5106507f-3d8a-45c4-99d7-595a323891bd' with address 'event-hub2/ConsumerGroups/$default/Partitions/7' was not called. There was no accompanying error as well. This is a candidate for re-establishing the receiver link.
2019-02-01T14:47:03.657Z azure:event-hubs:error [connection-2] Receiver 'cce50b0f-3922-4296-871f-6fa391aabad0' with address 'event-hub2/ConsumerGroups/$default/Partitions/7' is open? -> false
2019-02-01T14:47:03.657Z azure:event-hubs:error [connection-2] The receiver 'cce50b0f-3922-4296-871f-6fa391aabad0' with address 'event-hub2/ConsumerGroups/$default/Partitions/7' is not open and is not currently establishing itself. Hence let's try to connect.
2019-02-01T14:47:03.657Z rhea:frames [connection-2]:0 -> transfer#14 {"delivery_id":3182,"delivery_tag":{"type":"Buffer","data":[51,49,56,50]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 5c 00 00 00 05 a1 24 32 35 61 35 63 65 33 63 2d 36 38 63 64 2d 32 37 34 34 2d 38 30 34 32 2d 35 32 62 37 38 61 65 35 ... >
2019-02-01T14:47:03.657Z rhea:io [connection-2] read 27 bytes
2019-02-01T14:47:03.657Z rhea:io [connection-2] got frame of size 27
2019-02-01T14:47:03.657Z rhea:frames [connection-2]:0 <- disposition#15 {"role":true,"first":3182,"settled":true,"state":[]} 
2019-02-01T14:47:03.657Z rhea:events [connection-2] Received disposition for outgoing transfers
2019-02-01T14:47:03.657Z rhea:events [connection-2] Link got event: accepted
2019-02-01T14:47:03.657Z rhea:events [connection-2] Link got event: settled
2019-02-01T14:47:03.673Z rhea:io [connection-2] read 145 bytes
2019-02-01T14:47:03.673Z rhea:io [connection-2] got frame of size 145
2019-02-01T14:47:03.673Z rhea:frames [connection-2]:0 <- transfer#14 {"handle":1,"delivery_id":3182,"delivery_tag":{"type":"Buffer","data":[111,12,0,0]}} <Buffer 00 53 73 c0 33 0d 40 40 40 40 40 a1 24 32 35 61 35 63 65 33 63 2d 36 38 63 64 2d 32 37 34 34 2d 38 30 34 32 2d 35 32 62 37 38 61 65 35 31 66 37 32 40 ... >
2019-02-01T14:47:03.673Z rhea:events [connection-2] Link got event: message
2019-02-01T14:47:03.673Z rhea:frames [connection-2]:0 -> disposition#15 {"role":true,"first":3182,"last":3182,"settled":true,"state":[]} 
2019-02-01T14:47:03.673Z azure:event-hubs:error [connection-2] Trying to create receiver 'cce50b0f-3922-4296-871f-6fa391aabad0' with options { name: 'cce50b0f-3922-4296-871f-6fa391aabad0',
  autoaccept: true,
  source: 
   { address: 'event-hub2/ConsumerGroups/$default/Partitions/7',
     filter: { 'apache.org:selector-filter:string': [Object] } },
  credit_window: 1000,
  onMessage: [Function],
  onError: [Function],
  onClose: [Function],
  onSessionError: [Function],
  onSessionClose: [Function] }
2019-02-01T14:47:03.673Z rhea:frames [connection-2]:3 -> begin#11 {"incoming_window":2048,"outgoing_window":4294967295} 
2019-02-01T14:47:03.689Z rhea:io [connection-2] read 34 bytes
2019-02-01T14:47:03.689Z rhea:io [connection-2] got frame of size 34
2019-02-01T14:47:03.689Z rhea:frames [connection-2]:3 <- begin#11 {"remote_channel":3,"next_outgoing_id":1,"incoming_window":5000,"outgoing_window":2048,"handle_max":255} 
2019-02-01T14:47:03.689Z rhea:events [connection-2] Session got event: session_open
2019-02-01T14:47:03.689Z rhea:frames [connection-2]:3 -> attach#12 {"name":"cce50b0f-3922-4296-871f-6fa391aabad0","role":true,"source":["event-hub2/ConsumerGroups/$default/Partitions/7",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547803620125'"]],"target":[]} 
2019-02-01T14:47:04.554Z rhea:io [connection-2] read 17 bytes
2019-02-01T14:47:04.554Z rhea:io [connection-2] got frame of size 17
2019-02-01T14:47:04.554Z rhea:frames [connection-2]:6 <- detach#16 {"closed":true} 
2019-02-01T14:47:04.554Z rhea:events [connection-2] Link got event: receiver_close
2019-02-01T14:47:04.554Z azure:event-hubs:error [connection-2] 'receiver_close' event occurred on the receiver '3db740f2-af90-48a5-b698-8919be355497' with address 'event-hub2/ConsumerGroups/$default/Partitions/10' and the sdk did not initiate this. The receiver is not reconnecting. Hence, calling detached from the _onAmqpClose() handler.
2019-02-01T14:47:04.554Z rhea-promise:error [connection-2] The receiver is open ? -> false
2019-02-01T14:47:04.554Z rhea:frames [connection-2]:6 -> detach#16 {"closed":true} 
2019-02-01T14:47:04.554Z rhea-promise:error [connection-2] The session is open ? -> true
2019-02-01T14:47:04.554Z rhea:frames [connection-2]:6 -> end#17 {} 
2019-02-01T14:47:04.569Z rhea:io [connection-2] read 15 bytes
2019-02-01T14:47:04.569Z rhea:io [connection-2] got frame of size 15
2019-02-01T14:47:04.569Z rhea:frames [connection-2]:6 <- end#17 {} 
2019-02-01T14:47:04.569Z rhea:events [connection-2] Session got event: session_close
2019-02-01T14:47:04.569Z azure:event-hubs:error [connection-2] 'session_close' event occurred on the session of receiver '3db740f2-af90-48a5-b698-8919be355497' with address 'event-hub2/ConsumerGroups/$default/Partitions/10' because the sdk initiated it. Hence not calling detached from the _onSessionClose() handler.
2019-02-01T14:47:04.585Z azure:event-hubs:error [connection-2] close() method of Receiver '3db740f2-af90-48a5-b698-8919be355497' with address 'event-hub2/ConsumerGroups/$default/Partitions/10' was not called. There was no accompanying error as well. This is a candidate for re-establishing the receiver link.
2019-02-01T14:47:04.585Z azure:event-hubs:error [connection-2] Receiver '6536a11d-0bda-4add-a924-d98e4cc8fee2' with address 'event-hub2/ConsumerGroups/$default/Partitions/10' is open? -> false
2019-02-01T14:47:04.585Z azure:event-hubs:error [connection-2] The receiver '6536a11d-0bda-4add-a924-d98e4cc8fee2' with address 'event-hub2/ConsumerGroups/$default/Partitions/10' is not open and is not currently establishing itself. Hence let's try to connect.
2019-02-01T14:47:04.585Z rhea:frames [connection-2]:0 -> transfer#14 {"delivery_id":3183,"delivery_tag":{"type":"Buffer","data":[51,49,56,51]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 5c 00 00 00 05 a1 24 64 33 39 36 35 37 65 62 2d 35 66 30 66 2d 31 37 34 33 2d 38 39 62 66 2d 39 38 66 31 33 65 64 36 ... >
2019-02-01T14:47:04.585Z rhea:io [connection-2] read 27 bytes
2019-02-01T14:47:04.585Z rhea:io [connection-2] got frame of size 27
2019-02-01T14:47:04.585Z rhea:frames [connection-2]:0 <- disposition#15 {"role":true,"first":3183,"settled":true,"state":[]} 
2019-02-01T14:47:04.585Z rhea:events [connection-2] Received disposition for outgoing transfers
2019-02-01T14:47:04.585Z rhea:events [connection-2] Link got event: accepted
2019-02-01T14:47:04.585Z rhea:events [connection-2] Link got event: settled
2019-02-01T14:47:04.601Z rhea:io [connection-2] read 145 bytes
2019-02-01T14:47:04.601Z rhea:io [connection-2] got frame of size 145
2019-02-01T14:47:04.601Z rhea:frames [connection-2]:0 <- transfer#14 {"handle":1,"delivery_id":3183,"delivery_tag":{"type":"Buffer","data":[112,12,0,0]}} <Buffer 00 53 73 c0 33 0d 40 40 40 40 40 a1 24 64 33 39 36 35 37 65 62 2d 35 66 30 66 2d 31 37 34 33 2d 38 39 62 66 2d 39 38 66 31 33 65 64 36 31 64 64 63 40 ... >
2019-02-01T14:47:04.601Z rhea:events [connection-2] Link got event: message
2019-02-01T14:47:04.601Z rhea:frames [connection-2]:0 -> disposition#15 {"role":true,"first":3183,"last":3183,"settled":true,"state":[]} 
2019-02-01T14:47:04.601Z azure:event-hubs:error [connection-2] Trying to create receiver '6536a11d-0bda-4add-a924-d98e4cc8fee2' with options { name: '6536a11d-0bda-4add-a924-d98e4cc8fee2',
  autoaccept: true,
  source: 
   { address: 'event-hub2/ConsumerGroups/$default/Partitions/10',
     filter: { 'apache.org:selector-filter:string': [Object] } },
  credit_window: 1000,
  onMessage: [Function],
  onError: [Function],
  onClose: [Function],
  onSessionError: [Function],
  onSessionClose: [Function] }
2019-02-01T14:47:04.601Z rhea:frames [connection-2]:6 -> begin#11 {"incoming_window":2048,"outgoing_window":4294967295} 
2019-02-01T14:47:04.601Z rhea:io [connection-2] read 34 bytes
2019-02-01T14:47:04.601Z rhea:io [connection-2] got frame of size 34
2019-02-01T14:47:04.601Z rhea:frames [connection-2]:6 <- begin#11 {"remote_channel":6,"next_outgoing_id":1,"incoming_window":5000,"outgoing_window":2048,"handle_max":255} 
2019-02-01T14:47:04.601Z rhea:events [connection-2] Session got event: session_open
2019-02-01T14:47:04.601Z rhea:frames [connection-2]:6 -> attach#12 {"name":"6536a11d-0bda-4add-a924-d98e4cc8fee2","role":true,"source":["event-hub2/ConsumerGroups/$default/Partitions/10",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547088068241'"]],"target":[]} 
2019-02-01T14:47:07.325Z rhea:io [connection-2] read 65 bytes
2019-02-01T14:47:07.325Z rhea:io [connection-2] got frame of size 65
2019-02-01T14:47:07.325Z rhea:frames [connection-2]:6 <- attach#12 {"name":"6536a11d-0bda-4add-a924-d98e4cc8fee2","source":null,"target":null} 
2019-02-01T14:47:07.325Z rhea:events [connection-2] Link got event: receiver_open
2019-02-01T14:47:07.325Z rhea:frames [connection-2]:6 -> flow#13 {"incoming_window":2048,"outgoing_window":4294967295,"link_credit":1000} 
2019-02-01T14:47:07.325Z azure:event-hubs:error [connection-2] Receiver '6536a11d-0bda-4add-a924-d98e4cc8fee2' with address 'event-hub2/ConsumerGroups/$default/Partitions/10' has established itself.
2019-02-01T14:47:07.325Z rhea:io [connection-2] read 183 bytes
2019-02-01T14:47:07.325Z rhea:io [connection-2] got frame of size 183
2019-02-01T14:47:07.325Z rhea:frames [connection-2]:6 <- detach#16 {"closed":true,"error":{"condition":"com.microsoft:operation-cancelled","description":"A task was canceled. TrackingId:10e001ac18144698bf8210928ecb5c9e_G26, SystemTracker:gateway5, Timestamp:2019-02-01T14:47:06"}} 
2019-02-01T14:47:07.325Z rhea:events [connection-2] Link got event: receiver_error
2019-02-01T14:47:07.325Z azure:event-hubs:error [connection-2] An error occurred for Receiver '6536a11d-0bda-4add-a924-d98e4cc8fee2': { OperationCancelledError: A task was canceled. TrackingId:10e001ac18144698bf8210928ecb5c9e_G26, SystemTracker:gateway5, Timestamp:2019-02-01T14:47:06
    at Object.translate (service\node_modules\@azure\amqp-common\lib\errors.ts:537:13)
    at Receiver.EventHubReceiver._onAmqpError (service\node_modules\@azure\event-hubs\lib\eventHubReceiver.ts:225:25)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at emit (service\node_modules\rhea-promise\lib\util\utils.ts:183:20)
    at Object.emitEvent (service\node_modules\rhea-promise\lib\util\utils.ts:195:5)
    at Receiver._link.on (service\node_modules\rhea-promise\lib\link.ts:292:11)
    at emitOne (events.js:116:13)
    at Receiver.emit (events.js:211:7)
    at Receiver.link.dispatch (service\node_modules\rhea\lib\link.js:59:37)
  name: 'OperationCancelledError',
  translated: true,
  retryable: true,
  info: null,
  condition: 'com.microsoft:operation-cancelled' }.
2019-02-01T14:47:07.325Z azure:event-hubs:error [connection-2] Since received error is retryable, we will NOT notify the user's error handler.
2019-02-01T14:47:07.325Z rhea:events [connection-2] Link got event: receiver_close
2019-02-01T14:47:07.325Z azure:event-hubs:error [connection-2] 'receiver_close' event occurred for receiver '6536a11d-0bda-4add-a924-d98e4cc8fee2' with address 'event-hub2/ConsumerGroups/$default/Partitions/10'. The associated error is: c {
  value: 
   [ Typed { type: [Object], value: 'com.microsoft:operation-cancelled' },
     Typed {
       type: [Object],
       value: 'A task was canceled. TrackingId:10e001ac18144698bf8210928ecb5c9e_G26, SystemTracker:gateway5, Timestamp:2019-02-01T14:47:06' },
     Typed { type: [Object], value: null } ] }
2019-02-01T14:47:07.325Z azure:event-hubs:error [connection-2] 'receiver_close' event occurred on the receiver '6536a11d-0bda-4add-a924-d98e4cc8fee2' with address 'event-hub2/ConsumerGroups/$default/Partitions/10' and the sdk did not initiate this. The receiver is not reconnecting. Hence, calling detached from the _onAmqpClose() handler.
2019-02-01T14:47:07.325Z rhea-promise:error [connection-2] The receiver is open ? -> false
2019-02-01T14:47:07.325Z rhea:frames [connection-2]:6 -> detach#16 {"closed":true} 
2019-02-01T14:47:07.325Z rhea-promise:error [connection-2] The session is open ? -> true
2019-02-01T14:47:07.325Z rhea:frames [connection-2]:6 -> end#17 {} 
2019-02-01T14:47:07.341Z rhea:io [connection-2] read 15 bytes
2019-02-01T14:47:07.341Z rhea:io [connection-2] got frame of size 15
2019-02-01T14:47:07.341Z rhea:frames [connection-2]:6 <- end#17 {} 
2019-02-01T14:47:07.341Z rhea:events [connection-2] Session got event: session_close
2019-02-01T14:47:07.341Z azure:event-hubs:error [connection-2] 'session_close' event occurred on the session of receiver '6536a11d-0bda-4add-a924-d98e4cc8fee2' with address 'event-hub2/ConsumerGroups/$default/Partitions/10' because the sdk initiated it. Hence not calling detached from the _onSessionClose() handler.
2019-02-01T14:47:07.341Z azure:event-hubs:error [connection-2] close() method of Receiver '6536a11d-0bda-4add-a924-d98e4cc8fee2' with address 'event-hub2/ConsumerGroups/$default/Partitions/10' was not called. There was an accompanying error and it is retryable. This is a candidate for re-establishing the receiver link.
2019-02-01T14:47:07.341Z azure:event-hubs:error [connection-2] Receiver '9556c09e-dafd-46d6-aef0-d0d45ba36d5a' with address 'event-hub2/ConsumerGroups/$default/Partitions/10' is open? -> false
2019-02-01T14:47:07.341Z azure:event-hubs:error [connection-2] The receiver '9556c09e-dafd-46d6-aef0-d0d45ba36d5a' with address 'event-hub2/ConsumerGroups/$default/Partitions/10' is not open and is not currently establishing itself. Hence let's try to connect.
2019-02-01T14:47:07.341Z rhea:frames [connection-2]:0 -> transfer#14 {"delivery_id":3184,"delivery_tag":{"type":"Buffer","data":[51,49,56,52]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 5c 00 00 00 05 a1 24 36 30 39 39 33 32 37 39 2d 30 65 35 66 2d 31 35 34 34 2d 62 35 66 39 2d 62 39 38 33 61 66 31 32 ... >
2019-02-01T14:47:07.341Z rhea:io [connection-2] read 27 bytes
2019-02-01T14:47:07.341Z rhea:io [connection-2] got frame of size 27
2019-02-01T14:47:07.341Z rhea:frames [connection-2]:0 <- disposition#15 {"role":true,"first":3184,"settled":true,"state":[]} 
2019-02-01T14:47:07.341Z rhea:events [connection-2] Received disposition for outgoing transfers
2019-02-01T14:47:07.341Z rhea:events [connection-2] Link got event: accepted
2019-02-01T14:47:07.341Z rhea:events [connection-2] Link got event: settled
2019-02-01T14:47:07.341Z rhea:io [connection-2] read 145 bytes
2019-02-01T14:47:07.341Z rhea:io [connection-2] got frame of size 145
2019-02-01T14:47:07.341Z rhea:frames [connection-2]:0 <- transfer#14 {"handle":1,"delivery_id":3184,"delivery_tag":{"type":"Buffer","data":[113,12,0,0]}} <Buffer 00 53 73 c0 33 0d 40 40 40 40 40 a1 24 36 30 39 39 33 32 37 39 2d 30 65 35 66 2d 31 35 34 34 2d 62 35 66 39 2d 62 39 38 33 61 66 31 32 31 37 34 38 40 ... >
2019-02-01T14:47:07.341Z rhea:events [connection-2] Link got event: message
2019-02-01T14:47:07.341Z rhea:frames [connection-2]:0 -> disposition#15 {"role":true,"first":3184,"last":3184,"settled":true,"state":[]} 
2019-02-01T14:47:07.341Z azure:event-hubs:error [connection-2] Trying to create receiver '9556c09e-dafd-46d6-aef0-d0d45ba36d5a' with options { name: '9556c09e-dafd-46d6-aef0-d0d45ba36d5a',
  autoaccept: true,
  source: 
   { address: 'event-hub2/ConsumerGroups/$default/Partitions/10',
     filter: { 'apache.org:selector-filter:string': [Object] } },
  credit_window: 1000,
  onMessage: [Function],
  onError: [Function],
  onClose: [Function],
  onSessionError: [Function],
  onSessionClose: [Function] }
2019-02-01T14:47:07.341Z rhea:frames [connection-2]:6 -> begin#11 {"incoming_window":2048,"outgoing_window":4294967295}

MatejSkrbis · 2019-02-13T08:07:39Z

Since you have logs only for "error", there is a chance that you won't find anything for the previous question. So, look for logs that have any of the below before 2019-02-01T14:57:14.582Z. If you do find them, then which connection were they using?

event-hub4/ConsumerGroups/$default/Partitions/6

event-hub4/ConsumerGroups/$default/Partitions/7

event-hub4/ConsumerGroups/$default/Partitions/8

event-hub4/ConsumerGroups/$default/Partitions/10

event-hub4/ConsumerGroups/$default/Partitions/11

Here are the logs when reading was started from event-hub4

2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] 'receiver_close' event occurred on the receiver 'c41fb645-bdb2-4643-a262-394ad752fb4a' with address 'event-hub4/ConsumerGroups/$default/Partitions/6' and the sdk did not initiate this. The receiver is not reconnecting. Hence, calling detached from the _onAmqpClose() handler.
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.008Z rhea:io [connection-4] got frame of size 15
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:2 <- end#17 {} 
2019-02-01T14:26:58.008Z rhea:events [connection-4] Session got event: session_close
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] 'session_close' event occurred on the session of receiver 'c41fb645-bdb2-4643-a262-394ad752fb4a' with address 'event-hub4/ConsumerGroups/$default/Partitions/6' and the sdk did not initiate this. Hence calling detached from the _onSessionClose() handler.
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.008Z rhea:io [connection-4] got frame of size 17
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:3 <- detach#16 {"closed":true} 
2019-02-01T14:26:58.008Z rhea:events [connection-4] Link got event: receiver_close
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] 'receiver_close' event occurred on the receiver '1291190f-5826-4bdd-a52c-899f10a9abae' with address 'event-hub4/ConsumerGroups/$default/Partitions/7' and the sdk did not initiate this. The receiver is not reconnecting. Hence, calling detached from the _onAmqpClose() handler.
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.008Z rhea:io [connection-4] got frame of size 15
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:3 <- end#17 {} 
2019-02-01T14:26:58.008Z rhea:events [connection-4] Session got event: session_close
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] 'session_close' event occurred on the session of receiver '1291190f-5826-4bdd-a52c-899f10a9abae' with address 'event-hub4/ConsumerGroups/$default/Partitions/7' and the sdk did not initiate this. Hence calling detached from the _onSessionClose() handler.
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.008Z rhea:io [connection-4] got frame of size 17
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:4 <- detach#16 {"closed":true} 
2019-02-01T14:26:58.008Z rhea:events [connection-4] Link got event: receiver_close
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] 'receiver_close' event occurred on the receiver 'f464f308-a70f-498b-b6c2-bd51eb9fd83a' with address 'event-hub4/ConsumerGroups/$default/Partitions/8' and the sdk did not initiate this. The receiver is not reconnecting. Hence, calling detached from the _onAmqpClose() handler.
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.008Z rhea:io [connection-4] got frame of size 15
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:4 <- end#17 {} 
2019-02-01T14:26:58.008Z rhea:events [connection-4] Session got event: session_close
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] 'session_close' event occurred on the session of receiver 'f464f308-a70f-498b-b6c2-bd51eb9fd83a' with address 'event-hub4/ConsumerGroups/$default/Partitions/8' and the sdk did not initiate this. Hence calling detached from the _onSessionClose() handler.
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.008Z rhea:io [connection-4] got frame of size 15
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:5 <- end#17 {} 
2019-02-01T14:26:58.008Z rhea:events [connection-4] Session got event: session_close
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] 'session_close' event occurred on the session of receiver 'a815f4db-7bd4-4a19-861f-9d68d508dda9' with address 'event-hub4/ConsumerGroups/$default/Partitions/9' and the sdk did not initiate this. Hence calling detached from the _onSessionClose() handler.
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.008Z rhea:io [connection-4] got frame of size 17
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:6 <- detach#16 {"closed":true} 
2019-02-01T14:26:58.008Z rhea:events [connection-4] Link got event: receiver_close
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] 'receiver_close' event occurred on the receiver '36ae0f6a-fc73-4940-8245-b9585ffd6436' with address 'event-hub4/ConsumerGroups/$default/Partitions/10' and the sdk did not initiate this. The receiver is not reconnecting. Hence, calling detached from the _onAmqpClose() handler.
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.008Z rhea:io [connection-4] got frame of size 15
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:6 <- end#17 {} 
2019-02-01T14:26:58.008Z rhea:events [connection-4] Session got event: session_close
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] 'session_close' event occurred on the session of receiver '36ae0f6a-fc73-4940-8245-b9585ffd6436' with address 'event-hub4/ConsumerGroups/$default/Partitions/10' and the sdk did not initiate this. Hence calling detached from the _onSessionClose() handler.
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.008Z rhea:io [connection-4] got frame of size 17
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:7 <- detach#16 {"closed":true} 
2019-02-01T14:26:58.008Z rhea:events [connection-4] Link got event: receiver_close
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] 'receiver_close' event occurred on the receiver '086889d4-c2e0-4871-81ef-59a505bbf600' with address 'event-hub4/ConsumerGroups/$default/Partitions/11' and the sdk did not initiate this. The receiver is not reconnecting. Hence, calling detached from the _onAmqpClose() handler.
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.008Z rhea:io [connection-4] got frame of size 15
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:7 <- end#17 {} 
2019-02-01T14:26:58.008Z rhea:events [connection-4] Session got event: session_close
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] 'session_close' event occurred on the session of receiver '086889d4-c2e0-4871-81ef-59a505bbf600' with address 'event-hub4/ConsumerGroups/$default/Partitions/11' and the sdk did not initiate this. Hence calling detached from the _onSessionClose() handler.
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.008Z rhea:io [connection-4] got frame of size 15
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:0 <- close#18 {} 
2019-02-01T14:26:58.008Z rhea:events [connection-4] Connection got event: connection_close
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:0 -> detach#16 {"handle":1,"closed":true} 
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:0 -> end#17 {} 
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:1 -> detach#16 {"closed":true} 
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:1 -> detach#16 {"handle":1,"closed":true} 
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:1 -> end#17 {} 
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:2 -> detach#16 {"closed":true} 
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:2 -> end#17 {} 
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:3 -> detach#16 {"closed":true} 
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:3 -> end#17 {} 
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:4 -> detach#16 {"closed":true} 
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:4 -> end#17 {} 
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:5 -> end#17 {} 
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:6 -> detach#16 {"closed":true} 
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:6 -> end#17 {} 
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:7 -> detach#16 {"closed":true} 
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:7 -> end#17 {} 
2019-02-01T14:26:58.008Z rhea:frames [connection-4]:0 -> close#18 {} 
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.008Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] close() method of Receiver 'c41fb645-bdb2-4643-a262-394ad752fb4a' with address 'event-hub4/ConsumerGroups/$default/Partitions/6' was not called. There was no accompanying error as well. This is a candidate for re-establishing the receiver link.
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] Receiver 'd6ca97e3-a73a-431b-8c42-13851f2b8ca7' with address 'event-hub4/ConsumerGroups/$default/Partitions/6' is open? -> false
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] The receiver 'd6ca97e3-a73a-431b-8c42-13851f2b8ca7' with address 'event-hub4/ConsumerGroups/$default/Partitions/6' is not open and is not currently establishing itself. Hence let's try to connect.
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] close() method of Receiver 'd6ca97e3-a73a-431b-8c42-13851f2b8ca7' with address 'event-hub4/ConsumerGroups/$default/Partitions/6' was not called. There was no accompanying error as well. This is a candidate for re-establishing the receiver link.
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] Receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with address 'event-hub4/ConsumerGroups/$default/Partitions/6' is open? -> false
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] Receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with address 'event-hub4/ConsumerGroups/$default/Partitions/6' is open? -> false
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] The receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with address 'event-hub4/ConsumerGroups/$default/Partitions/6' is open -> false and is connecting -> true. Hence not reconnecting.
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] close() method of Receiver '1291190f-5826-4bdd-a52c-899f10a9abae' with address 'event-hub4/ConsumerGroups/$default/Partitions/7' was not called. There was no accompanying error as well. This is a candidate for re-establishing the receiver link.
2019-02-01T14:26:58.008Z azure:event-hubs:error [connection-4] Receiver 'a88ecb69-84c9-4987-b96c-a219cf19d74a' with address 'event-hub4/ConsumerGroups/$default/Partitions/7' is open? -> false
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] The receiver 'a88ecb69-84c9-4987-b96c-a219cf19d74a' with address 'event-hub4/ConsumerGroups/$default/Partitions/7' is not open and is not currently establishing itself. Hence let's try to connect.
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] close() method of Receiver 'a88ecb69-84c9-4987-b96c-a219cf19d74a' with address 'event-hub4/ConsumerGroups/$default/Partitions/7' was not called. There was no accompanying error as well. This is a candidate for re-establishing the receiver link.
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] Receiver '6c9959e4-0976-4197-9e7f-64ceda1dc35d' with address 'event-hub4/ConsumerGroups/$default/Partitions/7' is open? -> false
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] Receiver '6c9959e4-0976-4197-9e7f-64ceda1dc35d' with address 'event-hub4/ConsumerGroups/$default/Partitions/7' is open? -> false
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] The receiver '6c9959e4-0976-4197-9e7f-64ceda1dc35d' with address 'event-hub4/ConsumerGroups/$default/Partitions/7' is open -> false and is connecting -> true. Hence not reconnecting.
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] close() method of Receiver 'f464f308-a70f-498b-b6c2-bd51eb9fd83a' with address 'event-hub4/ConsumerGroups/$default/Partitions/8' was not called. There was no accompanying error as well. This is a candidate for re-establishing the receiver link.
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] Receiver '2fadec42-2806-454d-8584-7366278cf2d6' with address 'event-hub4/ConsumerGroups/$default/Partitions/8' is open? -> false
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] The receiver '2fadec42-2806-454d-8584-7366278cf2d6' with address 'event-hub4/ConsumerGroups/$default/Partitions/8' is not open and is not currently establishing itself. Hence let's try to connect.
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] close() method of Receiver '2fadec42-2806-454d-8584-7366278cf2d6' with address 'event-hub4/ConsumerGroups/$default/Partitions/8' was not called. There was no accompanying error as well. This is a candidate for re-establishing the receiver link.
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] Receiver 'ada48e56-235d-4a03-bf2b-c9172b1dbaa0' with address 'event-hub4/ConsumerGroups/$default/Partitions/8' is open? -> false
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] Receiver 'ada48e56-235d-4a03-bf2b-c9172b1dbaa0' with address 'event-hub4/ConsumerGroups/$default/Partitions/8' is open? -> false
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] The receiver 'ada48e56-235d-4a03-bf2b-c9172b1dbaa0' with address 'event-hub4/ConsumerGroups/$default/Partitions/8' is open -> false and is connecting -> true. Hence not reconnecting.
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] Something is busted. State of Receiver 'a815f4db-7bd4-4a19-861f-9d68d508dda9' with address 'event-hub4/ConsumerGroups/$default/Partitions/9' is: { wasCloseInitiated: true,
  receiverError: null,
  _receiver: 
   Receiver {
     domain: null,
     _events: 
      { message: [Function],
        receiver_error: [Function],
        receiver_close: [Function] },
     _eventsCount: 3,
     _maxListeners: undefined,
     actionInitiated: 0,
     type: 'receiver',
     _session: 
      Session {
        domain: null,
        _events: [Object],
        _eventsCount: 2,
        _maxListeners: undefined,
        actionInitiated: 0,
        _connection: [Object],
        _session: [Object] },
     _link: 
      Receiver {
        session: [Object],
        connection: [Object],
        name: 'a815f4db-7bd4-4a19-861f-9d68d508dda9',
        options: [Object],
        state: [Object],
        issue_flow: false,
        local: [Object],
        remote: [Object],
        delivery_count: 0,
        credit: 1000,
        observers: [Object],
        drain: false,
        _events: [Object],
        _eventsCount: 7 },
     linkOptions: 
      { name: 'a815f4db-7bd4-4a19-861f-9d68d508dda9',
        autoaccept: true,
        source: [Object],
        credit_window: 1000,
        onMessage: [Function],
        onError: [Function],
        onClose: [Function],
        onSessionError: [Function],
        onSessionClose: [Function] } } }
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] close() method of Receiver '36ae0f6a-fc73-4940-8245-b9585ffd6436' with address 'event-hub4/ConsumerGroups/$default/Partitions/10' was not called. There was no accompanying error as well. This is a candidate for re-establishing the receiver link.
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] Receiver 'ee445d8f-4bb5-423b-a5be-c80cc805450a' with address 'event-hub4/ConsumerGroups/$default/Partitions/10' is open? -> false
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] The receiver 'ee445d8f-4bb5-423b-a5be-c80cc805450a' with address 'event-hub4/ConsumerGroups/$default/Partitions/10' is not open and is not currently establishing itself. Hence let's try to connect.
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] close() method of Receiver 'ee445d8f-4bb5-423b-a5be-c80cc805450a' with address 'event-hub4/ConsumerGroups/$default/Partitions/10' was not called. There was no accompanying error as well. This is a candidate for re-establishing the receiver link.
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] Receiver 'aecc7ce7-1ddb-4613-b266-a0a75c20a76a' with address 'event-hub4/ConsumerGroups/$default/Partitions/10' is open? -> false
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] Receiver 'aecc7ce7-1ddb-4613-b266-a0a75c20a76a' with address 'event-hub4/ConsumerGroups/$default/Partitions/10' is open? -> false
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] The receiver 'aecc7ce7-1ddb-4613-b266-a0a75c20a76a' with address 'event-hub4/ConsumerGroups/$default/Partitions/10' is open -> false and is connecting -> true. Hence not reconnecting.
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] close() method of Receiver '086889d4-c2e0-4871-81ef-59a505bbf600' with address 'event-hub4/ConsumerGroups/$default/Partitions/11' was not called. There was no accompanying error as well. This is a candidate for re-establishing the receiver link.
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] Receiver '356c76a8-070a-47a0-844d-81a689ba793b' with address 'event-hub4/ConsumerGroups/$default/Partitions/11' is open? -> false
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] The receiver '356c76a8-070a-47a0-844d-81a689ba793b' with address 'event-hub4/ConsumerGroups/$default/Partitions/11' is not open and is not currently establishing itself. Hence let's try to connect.
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] close() method of Receiver '356c76a8-070a-47a0-844d-81a689ba793b' with address 'event-hub4/ConsumerGroups/$default/Partitions/11' was not called. There was no accompanying error as well. This is a candidate for re-establishing the receiver link.
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] Receiver '05a1684b-0942-4942-8aba-b26b0a06efd9' with address 'event-hub4/ConsumerGroups/$default/Partitions/11' is open? -> false
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] Receiver '05a1684b-0942-4942-8aba-b26b0a06efd9' with address 'event-hub4/ConsumerGroups/$default/Partitions/11' is open? -> false
2019-02-01T14:26:58.023Z azure:event-hubs:error [connection-4] The receiver '05a1684b-0942-4942-8aba-b26b0a06efd9' with address 'event-hub4/ConsumerGroups/$default/Partitions/11' is open -> false and is connecting -> true. Hence not reconnecting.
2019-02-01T14:26:58.023Z rhea:frames [connection-4] -> { protocol_id: 3, major: 1, minor: 0, revision: 0 }
2019-02-01T14:26:58.070Z rhea:io [connection-4] connected 10.5.0.5:61933 -> 104.208.16.3:5671
2019-02-01T14:26:58.070Z rhea:io [connection-4] read 8 bytes
2019-02-01T14:26:58.070Z rhea:frames [connection-4] <- { protocol_id: 3, major: 1, minor: 0, revision: 0 }
2019-02-01T14:26:58.070Z rhea:io [connection-4] read 63 bytes
2019-02-01T14:26:58.070Z rhea:io [connection-4] got frame of size 63
2019-02-01T14:26:58.070Z rhea:frames [connection-4]:0 <- sasl_mechanisms#40 {"sasl_server_mechanisms":["MSSBCBS","PLAIN","ANONYMOUS","EXTERNAL"]} 
2019-02-01T14:26:58.070Z rhea:frames [connection-4]:0 -> sasl_init#41 {"mechanism":"ANONYMOUS","initial_response":{"type":"Buffer","data":[0,82,111,111,116,77,97,110,97,103,101,83,104,97,114,101,100,65,99,99,101,115,115,75,101,121]},"hostname":"host-name.servicebus.windows.net"} 
2019-02-01T14:26:58.070Z rhea:io [connection-4] read 26 bytes
2019-02-01T14:26:58.070Z rhea:io [connection-4] got frame of size 26
2019-02-01T14:26:58.070Z rhea:frames [connection-4]:0 <- sasl_outcome#44 {"additional_data":{"type":"Buffer","data":[87,101,108,99,111,109,101,33]}} 
2019-02-01T14:26:58.070Z rhea:frames [connection-4] -> { protocol_id: 0, major: 1, minor: 0, revision: 0 }
2019-02-01T14:26:58.070Z rhea:frames [connection-4]:0 -> open#10 {"transport":"tls","host":"host-name.servicebus.windows.net","username":"RootManageSharedAccessKey","port":5671,"operationTimeoutInSeconds":60,"servername":"host-name.servicebus.windows.net","id":"connection-4","container_id":"a698da97-093d-7040-b9b0-b4011ef269a1","hostname":"host-name.servicebus.windows.net","properties":{"product":"MSJSClient","version":"1.0.5","user-agent":"/js-event-hubs","platform":"(x64-Windows_NT-6.3.9600)","framework":"Node/v8.12.0"}} 
2019-02-01T14:26:58.070Z rhea:io [connection-4] read 8 bytes
2019-02-01T14:26:58.070Z rhea:frames [connection-4] <- { protocol_id: 0, major: 1, minor: 0, revision: 0 }
2019-02-01T14:26:58.070Z rhea:io [connection-4] read 71 bytes
2019-02-01T14:26:58.070Z rhea:io [connection-4] got frame of size 71
2019-02-01T14:26:58.070Z rhea:frames [connection-4]:0 <- open#10 {"container_id":"262f2c140b564b14911feae372bb2853_G24","max_frame_size":65536,"channel_max":4999,"idle_time_out":240000} 
2019-02-01T14:26:58.070Z rhea:events [connection-4] Connection got event: connection_open
2019-02-01T14:26:58.070Z rhea:frames [connection-4]:0 -> begin#11 {"incoming_window":2048,"outgoing_window":4294967295} 
2019-02-01T14:26:58.070Z rhea:io [connection-4] read 34 bytes
2019-02-01T14:26:58.070Z rhea:io [connection-4] got frame of size 34
2019-02-01T14:26:58.070Z rhea:frames [connection-4]:0 <- begin#11 {"next_outgoing_id":1,"incoming_window":5000,"outgoing_window":2048,"handle_max":255} 
2019-02-01T14:26:58.070Z rhea:events [connection-4] Session got event: session_open
2019-02-01T14:26:58.070Z rhea:frames [connection-4]:0 -> attach#12 {"name":"064515c0-887e-3849-a412-7b4b430c4fa7","source":[],"target":["$cbs"]} 
2019-02-01T14:26:58.086Z rhea:io [connection-4] read 106 bytes
2019-02-01T14:26:58.086Z rhea:io [connection-4] got frame of size 106
2019-02-01T14:26:58.086Z rhea:frames [connection-4]:0 <- attach#12 {"name":"064515c0-887e-3849-a412-7b4b430c4fa7","role":true,"source":[null,null,null,null,null,null,null,null,null,null,null],"target":["$cbs",null,null,null,null,null,null],"max_message_size":{"type":"Buffer","data":[255,255,255,255,255,255,255,255]}} 
2019-02-01T14:26:58.086Z rhea:events [connection-4] Link got event: sender_open
2019-02-01T14:26:58.086Z rhea:io [connection-4] read 35 bytes
2019-02-01T14:26:58.086Z rhea:io [connection-4] got frame of size 35
2019-02-01T14:26:58.086Z rhea:frames [connection-4]:0 <- flow#13 {"incoming_window":5000,"next_outgoing_id":1,"outgoing_window":2048,"link_credit":100} 
2019-02-01T14:26:58.086Z rhea:events [connection-4] Link got event: sender_flow
2019-02-01T14:26:58.086Z rhea:events [connection-4] Link got event: sendable
2019-02-01T14:26:58.086Z rhea:frames [connection-4]:0 -> attach#12 {"name":"cbs-5614cd32-444e-2c49-9914-1ae209812ec0","handle":1,"role":true,"source":["$cbs"],"target":[]} 
2019-02-01T14:26:58.086Z rhea:io [connection-4] read 111 bytes
2019-02-01T14:26:58.086Z rhea:io [connection-4] got frame of size 111
2019-02-01T14:26:58.086Z rhea:frames [connection-4]:0 <- attach#12 {"name":"cbs-5614cd32-444e-2c49-9914-1ae209812ec0","handle":1,"source":["$cbs",null,null,null,null,null,null,null,null,null,null],"target":[null,null,null,null,null,null,null],"max_message_size":{"type":"Buffer","data":[255,255,255,255,255,255,255,255]}} 
2019-02-01T14:26:58.086Z rhea:events [connection-4] Link got event: receiver_open
2019-02-01T14:26:58.086Z rhea:frames [connection-4]:0 -> flow#13 {"incoming_window":2048,"outgoing_window":4294967295,"handle":1,"link_credit":1000} 
2019-02-01T14:26:58.086Z rhea:frames [connection-4]:0 -> transfer#14 {"delivery_tag":{"type":"Buffer","data":[48]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 5c 00 00 00 05 a1 24 34 33 66 65 64 37 35 31 2d 30 33 61 63 2d 63 30 34 38 2d 39 64 61 36 2d 61 64 65 37 62 62 61 61 ... >
2019-02-01T14:26:58.117Z rhea:io [connection-4] read 23 bytes
2019-02-01T14:26:58.117Z rhea:io [connection-4] got frame of size 23
2019-02-01T14:26:58.117Z rhea:frames [connection-4]:0 <- disposition#15 {"role":true,"settled":true,"state":[]} 
2019-02-01T14:26:58.117Z rhea:events [connection-4] Received disposition for outgoing transfers
2019-02-01T14:26:58.117Z rhea:events [connection-4] Link got event: accepted
2019-02-01T14:26:58.117Z rhea:events [connection-4] Link got event: settled
2019-02-01T14:26:58.164Z rhea:io [connection-4] read 141 bytes
2019-02-01T14:26:58.164Z rhea:io [connection-4] got frame of size 141
2019-02-01T14:26:58.164Z rhea:frames [connection-4]:0 <- transfer#14 {"handle":1,"delivery_tag":{"type":"Buffer","data":[1,0,0,0]}} <Buffer 00 53 73 c0 33 0d 40 40 40 40 40 a1 24 34 33 66 65 64 37 35 31 2d 30 33 61 63 2d 63 30 34 38 2d 39 64 61 36 2d 61 64 65 37 62 62 61 61 31 63 37 66 40 ... >
2019-02-01T14:26:58.164Z rhea:events [connection-4] Link got event: message
2019-02-01T14:26:58.164Z rhea:frames [connection-4]:0 -> disposition#15 {"role":true,"settled":true,"state":[]} 
2019-02-01T14:26:58.164Z azure:event-hubs:error [connection-4] Trying to create receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with options { name: 'd6ca97e3-a73a-431b-8c42-13851f2b8ca7',
  autoaccept: true,
  source: 
   { address: 'event-hub4/ConsumerGroups/$default/Partitions/6',
     filter: { 'apache.org:selector-filter:string': [Object] } },
  credit_window: 1000,
  onMessage: [Function],
  onError: [Function],
  onClose: [Function],
  onSessionError: [Function],
  onSessionClose: [Function] }
2019-02-01T14:26:58.164Z rhea:frames [connection-4]:0 -> transfer#14 {"delivery_id":1,"delivery_tag":{"type":"Buffer","data":[49]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 5c 00 00 00 05 a1 24 64 63 39 36 36 37 37 31 2d 61 32 33 33 2d 38 62 34 32 2d 38 30 36 33 2d 61 63 30 37 66 65 34 61 ... >
2019-02-01T14:26:58.164Z rhea:frames [connection-4]:1 -> begin#11 {"incoming_window":2048,"outgoing_window":4294967295} 
2019-02-01T14:26:58.180Z rhea:io [connection-4] read 34 bytes
2019-02-01T14:26:58.180Z rhea:io [connection-4] got frame of size 34
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:1 <- begin#11 {"remote_channel":1,"next_outgoing_id":1,"incoming_window":5000,"outgoing_window":2048,"handle_max":255} 
2019-02-01T14:26:58.180Z rhea:events [connection-4] Session got event: session_open
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:1 -> attach#12 {"name":"d6ca97e3-a73a-431b-8c42-13851f2b8ca7","role":true,"source":["event-hub4/ConsumerGroups/$default/Partitions/6",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547803620125'"]],"target":[]} 
2019-02-01T14:26:58.180Z rhea:io [connection-4] read 24 bytes
2019-02-01T14:26:58.180Z rhea:io [connection-4] got frame of size 24
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:0 <- disposition#15 {"role":true,"first":1,"settled":true,"state":[]} 
2019-02-01T14:26:58.180Z rhea:events [connection-4] Received disposition for outgoing transfers
2019-02-01T14:26:58.180Z rhea:events [connection-4] Link got event: accepted
2019-02-01T14:26:58.180Z rhea:events [connection-4] Link got event: settled
2019-02-01T14:26:58.180Z rhea:io [connection-4] read 142 bytes
2019-02-01T14:26:58.180Z rhea:io [connection-4] got frame of size 142
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:0 <- transfer#14 {"handle":1,"delivery_id":1,"delivery_tag":{"type":"Buffer","data":[2,0,0,0]}} <Buffer 00 53 73 c0 33 0d 40 40 40 40 40 a1 24 64 63 39 36 36 37 37 31 2d 61 32 33 33 2d 38 62 34 32 2d 38 30 36 33 2d 61 63 30 37 66 65 34 61 31 34 65 38 40 ... >
2019-02-01T14:26:58.180Z rhea:events [connection-4] Link got event: message
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:0 -> disposition#15 {"role":true,"first":1,"last":1,"settled":true,"state":[]} 
2019-02-01T14:26:58.180Z azure:event-hubs:error [connection-4] Trying to create receiver '6c9959e4-0976-4197-9e7f-64ceda1dc35d' with options { name: 'a88ecb69-84c9-4987-b96c-a219cf19d74a',
  autoaccept: true,
  source: 
   { address: 'event-hub4/ConsumerGroups/$default/Partitions/7',
     filter: { 'apache.org:selector-filter:string': [Object] } },
  credit_window: 1000,
  onMessage: [Function],
  onError: [Function],
  onClose: [Function],
  onSessionError: [Function],
  onSessionClose: [Function] }
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:0 -> transfer#14 {"delivery_id":2,"delivery_tag":{"type":"Buffer","data":[50]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 5c 00 00 00 05 a1 24 31 37 66 63 64 35 64 35 2d 37 37 35 31 2d 36 62 34 64 2d 38 34 36 33 2d 65 66 34 39 37 30 38 37 ... >
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:2 -> begin#11 {"incoming_window":2048,"outgoing_window":4294967295} 
2019-02-01T14:26:58.180Z rhea:io [connection-4] read 255 bytes
2019-02-01T14:26:58.180Z rhea:io [connection-4] got frame of size 255
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:1 <- attach#12 {"name":"d6ca97e3-a73a-431b-8c42-13851f2b8ca7","snd_settle_mode":1,"source":["event-hub4/ConsumerGroups/$default/Partitions/6",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547803620125'"],null,null,null],"target":[null,null,null,null,null,null,null],"max_message_size":{"type":"Buffer","data":[255,255,255,255,255,255,255,255]}} 
2019-02-01T14:26:58.180Z rhea:events [connection-4] Link got event: receiver_open
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:1 -> flow#13 {"incoming_window":2048,"outgoing_window":4294967295,"link_credit":1000} 
2019-02-01T14:26:58.180Z azure:event-hubs:error [connection-4] Receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with address 'event-hub4/ConsumerGroups/$default/Partitions/6' has established itself.
2019-02-01T14:26:58.180Z rhea:io [connection-4] read 34 bytes
2019-02-01T14:26:58.180Z rhea:io [connection-4] got frame of size 34
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:2 <- begin#11 {"remote_channel":2,"next_outgoing_id":1,"incoming_window":5000,"outgoing_window":2048,"handle_max":255} 
2019-02-01T14:26:58.180Z rhea:events [connection-4] Session got event: session_open
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:2 -> attach#12 {"name":"a88ecb69-84c9-4987-b96c-a219cf19d74a","role":true,"source":["event-hub4/ConsumerGroups/$default/Partitions/7",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547803620141'"]],"target":[]} 
2019-02-01T14:26:58.180Z rhea:io [connection-4] read 24 bytes
2019-02-01T14:26:58.180Z rhea:io [connection-4] got frame of size 24
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:0 <- disposition#15 {"role":true,"first":2,"settled":true,"state":[]} 
2019-02-01T14:26:58.180Z rhea:events [connection-4] Received disposition for outgoing transfers
2019-02-01T14:26:58.180Z rhea:events [connection-4] Link got event: accepted
2019-02-01T14:26:58.180Z rhea:events [connection-4] Link got event: settled
2019-02-01T14:26:58.180Z rhea:io [connection-4] read 142 bytes
2019-02-01T14:26:58.180Z rhea:io [connection-4] got frame of size 142
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:0 <- transfer#14 {"handle":1,"delivery_id":2,"delivery_tag":{"type":"Buffer","data":[3,0,0,0]}} <Buffer 00 53 73 c0 33 0d 40 40 40 40 40 a1 24 31 37 66 63 64 35 64 35 2d 37 37 35 31 2d 36 62 34 64 2d 38 34 36 33 2d 65 66 34 39 37 30 38 37 37 65 30 39 40 ... >
2019-02-01T14:26:58.180Z rhea:events [connection-4] Link got event: message
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:0 -> disposition#15 {"role":true,"first":2,"last":2,"settled":true,"state":[]} 
2019-02-01T14:26:58.180Z azure:event-hubs:error [connection-4] Trying to create receiver 'ada48e56-235d-4a03-bf2b-c9172b1dbaa0' with options { name: '2fadec42-2806-454d-8584-7366278cf2d6',
  autoaccept: true,
  source: 
   { address: 'event-hub4/ConsumerGroups/$default/Partitions/8',
     filter: { 'apache.org:selector-filter:string': [Object] } },
  credit_window: 1000,
  onMessage: [Function],
  onError: [Function],
  onClose: [Function],
  onSessionError: [Function],
  onSessionClose: [Function] }
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:0 -> transfer#14 {"delivery_id":3,"delivery_tag":{"type":"Buffer","data":[51]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 5c 00 00 00 05 a1 24 35 63 62 62 38 38 39 38 2d 31 63 37 36 2d 61 39 34 66 2d 62 34 66 36 2d 38 34 63 33 63 64 30 33 ... >
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:3 -> begin#11 {"incoming_window":2048,"outgoing_window":4294967295} 
2019-02-01T14:26:58.180Z rhea:io [connection-4] read 255 bytes
2019-02-01T14:26:58.180Z rhea:io [connection-4] got frame of size 255
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:2 <- attach#12 {"name":"a88ecb69-84c9-4987-b96c-a219cf19d74a","snd_settle_mode":1,"source":["event-hub4/ConsumerGroups/$default/Partitions/7",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547803620141'"],null,null,null],"target":[null,null,null,null,null,null,null],"max_message_size":{"type":"Buffer","data":[255,255,255,255,255,255,255,255]}} 
2019-02-01T14:26:58.180Z rhea:events [connection-4] Link got event: receiver_open
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:2 -> flow#13 {"incoming_window":2048,"outgoing_window":4294967295,"link_credit":1000} 
2019-02-01T14:26:58.180Z azure:event-hubs:error [connection-4] Receiver '6c9959e4-0976-4197-9e7f-64ceda1dc35d' with address 'event-hub4/ConsumerGroups/$default/Partitions/7' has established itself.
2019-02-01T14:26:58.180Z rhea:io [connection-4] read 34 bytes
2019-02-01T14:26:58.180Z rhea:io [connection-4] got frame of size 34
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:3 <- begin#11 {"remote_channel":3,"next_outgoing_id":1,"incoming_window":5000,"outgoing_window":2048,"handle_max":255} 
2019-02-01T14:26:58.180Z rhea:events [connection-4] Session got event: session_open
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:3 -> attach#12 {"name":"2fadec42-2806-454d-8584-7366278cf2d6","role":true,"source":["event-hub4/ConsumerGroups/$default/Partitions/8",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547803620156'"]],"target":[]} 
2019-02-01T14:26:58.180Z rhea:io [connection-4] read 24 bytes
2019-02-01T14:26:58.180Z rhea:io [connection-4] got frame of size 24
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:0 <- disposition#15 {"role":true,"first":3,"settled":true,"state":[]} 
2019-02-01T14:26:58.180Z rhea:events [connection-4] Received disposition for outgoing transfers
2019-02-01T14:26:58.180Z rhea:events [connection-4] Link got event: accepted
2019-02-01T14:26:58.180Z rhea:events [connection-4] Link got event: settled
2019-02-01T14:26:58.180Z rhea:io [connection-4] read 142 bytes
2019-02-01T14:26:58.180Z rhea:io [connection-4] got frame of size 142
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:0 <- transfer#14 {"handle":1,"delivery_id":3,"delivery_tag":{"type":"Buffer","data":[4,0,0,0]}} <Buffer 00 53 73 c0 33 0d 40 40 40 40 40 a1 24 35 63 62 62 38 38 39 38 2d 31 63 37 36 2d 61 39 34 66 2d 62 34 66 36 2d 38 34 63 33 63 64 30 33 63 39 32 36 40 ... >
2019-02-01T14:26:58.180Z rhea:events [connection-4] Link got event: message
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:0 -> disposition#15 {"role":true,"first":3,"last":3,"settled":true,"state":[]} 
2019-02-01T14:26:58.180Z azure:event-hubs:error [connection-4] Trying to create receiver 'aecc7ce7-1ddb-4613-b266-a0a75c20a76a' with options { name: 'ee445d8f-4bb5-423b-a5be-c80cc805450a',
  autoaccept: true,
  source: 
   { address: 'event-hub4/ConsumerGroups/$default/Partitions/10',
     filter: { 'apache.org:selector-filter:string': [Object] } },
  credit_window: 1000,
  onMessage: [Function],
  onError: [Function],
  onClose: [Function],
  onSessionError: [Function],
  onSessionClose: [Function] }
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:0 -> transfer#14 {"delivery_id":4,"delivery_tag":{"type":"Buffer","data":[52]}} <Buffer 00 53 70 45 00 53 73 d0 00 00 00 5c 00 00 00 05 a1 24 66 35 36 64 31 64 30 37 2d 32 34 39 35 2d 66 37 34 39 2d 38 64 32 65 2d 37 30 62 63 62 38 32 34 ... >
2019-02-01T14:26:58.180Z rhea:frames [connection-4]:4 -> begin#11 {"incoming_window":2048,"outgoing_window":4294967295} 
2019-02-01T14:26:58.211Z rhea:io [connection-4] read 34 bytes
2019-02-01T14:26:58.211Z rhea:io [connection-4] got frame of size 34
2019-02-01T14:26:58.211Z rhea:frames [connection-4]:4 <- begin#11 {"remote_channel":4,"next_outgoing_id":1,"incoming_window":5000,"outgoing_window":2048,"handle_max":255} 
2019-02-01T14:26:58.211Z rhea:events [connection-4] Session got event: session_open
2019-02-01T14:26:58.211Z rhea:frames [connection-4]:4 -> attach#12 {"name":"ee445d8f-4bb5-423b-a5be-c80cc805450a","role":true,"source":["event-hub4/ConsumerGroups/$default/Partitions/10",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547803620172'"]],"target":[]} 
2019-02-01T14:26:58.211Z rhea:io [connection-4] read 24 bytes
2019-02-01T14:26:58.211Z rhea:io [connection-4] got frame of size 24
2019-02-01T14:26:58.211Z rhea:frames [connection-4]:0 <- disposition#15 {"role":true,"first":4,"settled":true,"state":[]} 
2019-02-01T14:26:58.211Z rhea:events [connection-4] Received disposition for outgoing transfers
2019-02-01T14:26:58.211Z rhea:events [connection-4] Link got event: accepted
2019-02-01T14:26:58.211Z rhea:events [connection-4] Link got event: settled
2019-02-01T14:26:58.211Z rhea:io [connection-4] read 142 bytes
2019-02-01T14:26:58.211Z rhea:io [connection-4] got frame of size 142
2019-02-01T14:26:58.211Z rhea:frames [connection-4]:0 <- transfer#14 {"handle":1,"delivery_id":4,"delivery_tag":{"type":"Buffer","data":[5,0,0,0]}} <Buffer 00 53 73 c0 33 0d 40 40 40 40 40 a1 24 66 35 36 64 31 64 30 37 2d 32 34 39 35 2d 66 37 34 39 2d 38 64 32 65 2d 37 30 62 63 62 38 32 34 31 33 37 36 40 ... >
2019-02-01T14:26:58.211Z rhea:events [connection-4] Link got event: message
2019-02-01T14:26:58.211Z rhea:frames [connection-4]:0 -> disposition#15 {"role":true,"first":4,"last":4,"settled":true,"state":[]} 
2019-02-01T14:26:58.211Z azure:event-hubs:error [connection-4] Trying to create receiver '05a1684b-0942-4942-8aba-b26b0a06efd9' with options { name: '356c76a8-070a-47a0-844d-81a689ba793b',
  autoaccept: true,
  source: 
   { address: 'event-hub4/ConsumerGroups/$default/Partitions/11',
     filter: { 'apache.org:selector-filter:string': [Object] } },
  credit_window: 1000,
  onMessage: [Function],
  onError: [Function],
  onClose: [Function],
  onSessionError: [Function],
  onSessionClose: [Function] }
2019-02-01T14:26:58.211Z rhea:frames [connection-4]:5 -> begin#11 {"incoming_window":2048,"outgoing_window":4294967295} 
2019-02-01T14:26:58.211Z rhea:io [connection-4] read 255 bytes
2019-02-01T14:26:58.211Z rhea:io [connection-4] got frame of size 255
2019-02-01T14:26:58.211Z rhea:frames [connection-4]:3 <- attach#12 {"name":"2fadec42-2806-454d-8584-7366278cf2d6","snd_settle_mode":1,"source":["event-hub4/ConsumerGroups/$default/Partitions/8",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547803620156'"],null,null,null],"target":[null,null,null,null,null,null,null],"max_message_size":{"type":"Buffer","data":[255,255,255,255,255,255,255,255]}} 
2019-02-01T14:26:58.211Z rhea:events [connection-4] Link got event: receiver_open
2019-02-01T14:26:58.211Z rhea:frames [connection-4]:3 -> flow#13 {"incoming_window":2048,"outgoing_window":4294967295,"link_credit":1000} 
2019-02-01T14:26:58.211Z azure:event-hubs:error [connection-4] Receiver 'ada48e56-235d-4a03-bf2b-c9172b1dbaa0' with address 'event-hub4/ConsumerGroups/$default/Partitions/8' has established itself.
2019-02-01T14:26:58.211Z rhea:io [connection-4] read 34 bytes
2019-02-01T14:26:58.211Z rhea:io [connection-4] got frame of size 34
2019-02-01T14:26:58.211Z rhea:frames [connection-4]:5 <- begin#11 {"remote_channel":5,"next_outgoing_id":1,"incoming_window":5000,"outgoing_window":2048,"handle_max":255} 
2019-02-01T14:26:58.211Z rhea:events [connection-4] Session got event: session_open
2019-02-01T14:26:58.211Z rhea:frames [connection-4]:5 -> attach#12 {"name":"356c76a8-070a-47a0-844d-81a689ba793b","role":true,"source":["event-hub4/ConsumerGroups/$default/Partitions/11",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547803620172'"]],"target":[]} 
2019-02-01T14:26:58.211Z rhea:io [connection-4] read 256 bytes
2019-02-01T14:26:58.211Z rhea:io [connection-4] got frame of size 256
2019-02-01T14:26:58.211Z rhea:frames [connection-4]:4 <- attach#12 {"name":"ee445d8f-4bb5-423b-a5be-c80cc805450a","snd_settle_mode":1,"source":["event-hub4/ConsumerGroups/$default/Partitions/10",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547803620172'"],null,null,null],"target":[null,null,null,null,null,null,null],"max_message_size":{"type":"Buffer","data":[255,255,255,255,255,255,255,255]}} 
2019-02-01T14:26:58.211Z rhea:events [connection-4] Link got event: receiver_open
2019-02-01T14:26:58.211Z rhea:frames [connection-4]:4 -> flow#13 {"incoming_window":2048,"outgoing_window":4294967295,"link_credit":1000} 
2019-02-01T14:26:58.211Z azure:event-hubs:error [connection-4] Receiver 'aecc7ce7-1ddb-4613-b266-a0a75c20a76a' with address 'event-hub4/ConsumerGroups/$default/Partitions/10' has established itself.
2019-02-01T14:26:58.211Z rhea:io [connection-4] read 256 bytes
2019-02-01T14:26:58.211Z rhea:io [connection-4] got frame of size 256
2019-02-01T14:26:58.211Z rhea:frames [connection-4]:5 <- attach#12 {"name":"356c76a8-070a-47a0-844d-81a689ba793b","snd_settle_mode":1,"source":["event-hub4/ConsumerGroups/$default/Partitions/11",null,null,null,null,null,null,["apache.org:selector-filter:string","amqp.annotation.x-opt-enqueued-time > '1547803620172'"],null,null,null],"target":[null,null,null,null,null,null,null],"max_message_size":{"type":"Buffer","data":[255,255,255,255,255,255,255,255]}} 
2019-02-01T14:26:58.211Z rhea:events [connection-4] Link got event: receiver_open
2019-02-01T14:26:58.211Z rhea:frames [connection-4]:5 -> flow#13 {"incoming_window":2048,"outgoing_window":4294967295,"link_credit":1000} 
2019-02-01T14:26:58.211Z azure:event-hubs:error [connection-4] Receiver '05a1684b-0942-4942-8aba-b26b0a06efd9' with address 'event-hub4/ConsumerGroups/$default/Partitions/11' has established itself.
2019-02-01T14:26:58.352Z rhea:events [connection-4] Connection got event: disconnected
2019-02-01T14:26:58.352Z azure:event-hubs:error [connection-4] state: { wasConnectionCloseCalled: false,
  numSenders: 0,
  numReceivers: 16 }
2019-02-01T14:26:58.352Z azure:event-hubs:error [connection-4] connection.close() was not called from the sdk and there were some sender or receiver links or both. We should reconnect.
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] calling detached on receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with address 'event-hub4/ConsumerGroups/$default/Partitions/6'.
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] calling detached on receiver '6c9959e4-0976-4197-9e7f-64ceda1dc35d' with address 'event-hub4/ConsumerGroups/$default/Partitions/7'.
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] calling detached on receiver 'ada48e56-235d-4a03-bf2b-c9172b1dbaa0' with address 'event-hub4/ConsumerGroups/$default/Partitions/8'.
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] calling detached on receiver 'a815f4db-7bd4-4a19-861f-9d68d508dda9' with address 'event-hub4/ConsumerGroups/$default/Partitions/9'.
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] calling detached on receiver 'aecc7ce7-1ddb-4613-b266-a0a75c20a76a' with address 'event-hub4/ConsumerGroups/$default/Partitions/10'.
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] calling detached on receiver '05a1684b-0942-4942-8aba-b26b0a06efd9' with address 'event-hub4/ConsumerGroups/$default/Partitions/11'.
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] calling detached on receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with address 'event-hub4/ConsumerGroups/$default/Partitions/6'.
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] calling detached on receiver 'a815f4db-7bd4-4a19-861f-9d68d508dda9' with address 'event-hub4/ConsumerGroups/$default/Partitions/9'.
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] calling detached on receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with address 'event-hub4/ConsumerGroups/$default/Partitions/6'.
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] calling detached on receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with address 'event-hub4/ConsumerGroups/$default/Partitions/6'.
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] calling detached on receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with address 'event-hub4/ConsumerGroups/$default/Partitions/6'.
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] calling detached on receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with address 'event-hub4/ConsumerGroups/$default/Partitions/6'.
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] calling detached on receiver '6c9959e4-0976-4197-9e7f-64ceda1dc35d' with address 'event-hub4/ConsumerGroups/$default/Partitions/7'.
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] calling detached on receiver 'ada48e56-235d-4a03-bf2b-c9172b1dbaa0' with address 'event-hub4/ConsumerGroups/$default/Partitions/8'.
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] calling detached on receiver 'aecc7ce7-1ddb-4613-b266-a0a75c20a76a' with address 'event-hub4/ConsumerGroups/$default/Partitions/10'.
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] calling detached on receiver '05a1684b-0942-4942-8aba-b26b0a06efd9' with address 'event-hub4/ConsumerGroups/$default/Partitions/11'.
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The receiver is open ? -> false
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.681Z rhea-promise:error [connection-4] The session is open ? -> false
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] Something is busted. State of Receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with address 'event-hub4/ConsumerGroups/$default/Partitions/6' is: { wasCloseInitiated: true,
  receiverError: undefined,
  _receiver: 
   Receiver {
     domain: null,
     _events: 
      { message: [Function],
        receiver_error: [Function],
        receiver_close: [Function] },
     _eventsCount: 3,
     _maxListeners: undefined,
     actionInitiated: 0,
     type: 'receiver',
     _session: 
      Session {
        domain: null,
        _events: [Object],
        _eventsCount: 2,
        _maxListeners: undefined,
        actionInitiated: 0,
        _connection: [Object],
        _session: [Object] },
     _link: 
      Receiver {
        session: [Object],
        connection: [Object],
        name: 'd6ca97e3-a73a-431b-8c42-13851f2b8ca7',
        options: [Object],
        state: [Object],
        issue_flow: false,
        local: [Object],
        remote: [Object],
        delivery_count: 0,
        credit: 1000,
        observers: [Object],
        drain: false,
        _events: [Object],
        _eventsCount: 7 },
     linkOptions: 
      { name: 'd6ca97e3-a73a-431b-8c42-13851f2b8ca7',
        autoaccept: true,
        source: [Object],
        credit_window: 1000,
        onMessage: [Function],
        onError: [Function],
        onClose: [Function],
        onSessionError: [Function],
        onSessionClose: [Function] } } }
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] Something is busted. State of Receiver '6c9959e4-0976-4197-9e7f-64ceda1dc35d' with address 'event-hub4/ConsumerGroups/$default/Partitions/7' is: { wasCloseInitiated: true,
  receiverError: undefined,
  _receiver: 
   Receiver {
     domain: null,
     _events: 
      { message: [Function],
        receiver_error: [Function],
        receiver_close: [Function] },
     _eventsCount: 3,
     _maxListeners: undefined,
     actionInitiated: 0,
     type: 'receiver',
     _session: 
      Session {
        domain: null,
        _events: [Object],
        _eventsCount: 2,
        _maxListeners: undefined,
        actionInitiated: 0,
        _connection: [Object],
        _session: [Object] },
     _link: 
      Receiver {
        session: [Object],
        connection: [Object],
        name: 'a88ecb69-84c9-4987-b96c-a219cf19d74a',
        options: [Object],
        state: [Object],
        issue_flow: false,
        local: [Object],
        remote: [Object],
        delivery_count: 0,
        credit: 1000,
        observers: [Object],
        drain: false,
        _events: [Object],
        _eventsCount: 7 },
     linkOptions: 
      { name: 'a88ecb69-84c9-4987-b96c-a219cf19d74a',
        autoaccept: true,
        source: [Object],
        credit_window: 1000,
        onMessage: [Function],
        onError: [Function],
        onClose: [Function],
        onSessionError: [Function],
        onSessionClose: [Function] } } }
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] Something is busted. State of Receiver 'ada48e56-235d-4a03-bf2b-c9172b1dbaa0' with address 'event-hub4/ConsumerGroups/$default/Partitions/8' is: { wasCloseInitiated: true,
  receiverError: undefined,
  _receiver: 
   Receiver {
     domain: null,
     _events: 
      { message: [Function],
        receiver_error: [Function],
        receiver_close: [Function] },
     _eventsCount: 3,
     _maxListeners: undefined,
     actionInitiated: 0,
     type: 'receiver',
     _session: 
      Session {
        domain: null,
        _events: [Object],
        _eventsCount: 2,
        _maxListeners: undefined,
        actionInitiated: 0,
        _connection: [Object],
        _session: [Object] },
     _link: 
      Receiver {
        session: [Object],
        connection: [Object],
        name: '2fadec42-2806-454d-8584-7366278cf2d6',
        options: [Object],
        state: [Object],
        issue_flow: false,
        local: [Object],
        remote: [Object],
        delivery_count: 0,
        credit: 1000,
        observers: [Object],
        drain: false,
        _events: [Object],
        _eventsCount: 7 },
     linkOptions: 
      { name: '2fadec42-2806-454d-8584-7366278cf2d6',
        autoaccept: true,
        source: [Object],
        credit_window: 1000,
        onMessage: [Function],
        onError: [Function],
        onClose: [Function],
        onSessionError: [Function],
        onSessionClose: [Function] } } }
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] Something is busted. State of Receiver 'a815f4db-7bd4-4a19-861f-9d68d508dda9' with address 'event-hub4/ConsumerGroups/$default/Partitions/9' is: { wasCloseInitiated: true,
  receiverError: undefined,
  _receiver: 
   Receiver {
     domain: null,
     _events: 
      { message: [Function],
        receiver_error: [Function],
        receiver_close: [Function] },
     _eventsCount: 3,
     _maxListeners: undefined,
     actionInitiated: 0,
     type: 'receiver',
     _session: 
      Session {
        domain: null,
        _events: [Object],
        _eventsCount: 2,
        _maxListeners: undefined,
        actionInitiated: 0,
        _connection: [Object],
        _session: [Object] },
     _link: 
      Receiver {
        session: [Object],
        connection: [Object],
        name: 'a815f4db-7bd4-4a19-861f-9d68d508dda9',
        options: [Object],
        state: [Object],
        issue_flow: false,
        local: [Object],
        remote: [Object],
        delivery_count: 0,
        credit: 1000,
        observers: [Object],
        drain: false,
        _events: [Object],
        _eventsCount: 7 },
     linkOptions: 
      { name: 'a815f4db-7bd4-4a19-861f-9d68d508dda9',
        autoaccept: true,
        source: [Object],
        credit_window: 1000,
        onMessage: [Function],
        onError: [Function],
        onClose: [Function],
        onSessionError: [Function],
        onSessionClose: [Function] } } }
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] Something is busted. State of Receiver 'aecc7ce7-1ddb-4613-b266-a0a75c20a76a' with address 'event-hub4/ConsumerGroups/$default/Partitions/10' is: { wasCloseInitiated: true,
  receiverError: undefined,
  _receiver: 
   Receiver {
     domain: null,
     _events: 
      { message: [Function],
        receiver_error: [Function],
        receiver_close: [Function] },
     _eventsCount: 3,
     _maxListeners: undefined,
     actionInitiated: 0,
     type: 'receiver',
     _session: 
      Session {
        domain: null,
        _events: [Object],
        _eventsCount: 2,
        _maxListeners: undefined,
        actionInitiated: 0,
        _connection: [Object],
        _session: [Object] },
     _link: 
      Receiver {
        session: [Object],
        connection: [Object],
        name: 'ee445d8f-4bb5-423b-a5be-c80cc805450a',
        options: [Object],
        state: [Object],
        issue_flow: false,
        local: [Object],
        remote: [Object],
        delivery_count: 0,
        credit: 1000,
        observers: [Object],
        drain: false,
        _events: [Object],
        _eventsCount: 7 },
     linkOptions: 
      { name: 'ee445d8f-4bb5-423b-a5be-c80cc805450a',
        autoaccept: true,
        source: [Object],
        credit_window: 1000,
        onMessage: [Function],
        onError: [Function],
        onClose: [Function],
        onSessionError: [Function],
        onSessionClose: [Function] } } }
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] Something is busted. State of Receiver '05a1684b-0942-4942-8aba-b26b0a06efd9' with address 'event-hub4/ConsumerGroups/$default/Partitions/11' is: { wasCloseInitiated: true,
  receiverError: undefined,
  _receiver: 
   Receiver {
     domain: null,
     _events: 
      { message: [Function],
        receiver_error: [Function],
        receiver_close: [Function] },
     _eventsCount: 3,
     _maxListeners: undefined,
     actionInitiated: 0,
     type: 'receiver',
     _session: 
      Session {
        domain: null,
        _events: [Object],
        _eventsCount: 2,
        _maxListeners: undefined,
        actionInitiated: 0,
        _connection: [Object],
        _session: [Object] },
     _link: 
      Receiver {
        session: [Object],
        connection: [Object],
        name: '356c76a8-070a-47a0-844d-81a689ba793b',
        options: [Object],
        state: [Object],
        issue_flow: false,
        local: [Object],
        remote: [Object],
        delivery_count: 0,
        credit: 1000,
        observers: [Object],
        drain: false,
        _events: [Object],
        _eventsCount: 7 },
     linkOptions: 
      { name: '356c76a8-070a-47a0-844d-81a689ba793b',
        autoaccept: true,
        source: [Object],
        credit_window: 1000,
        onMessage: [Function],
        onError: [Function],
        onClose: [Function],
        onSessionError: [Function],
        onSessionClose: [Function] } } }
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] Something is busted. State of Receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with address 'event-hub4/ConsumerGroups/$default/Partitions/6' is: { wasCloseInitiated: true,
  receiverError: undefined,
  _receiver: 
   Receiver {
     domain: null,
     _events: 
      { message: [Function],
        receiver_error: [Function],
        receiver_close: [Function] },
     _eventsCount: 3,
     _maxListeners: undefined,
     actionInitiated: 0,
     type: 'receiver',
     _session: 
      Session {
        domain: null,
        _events: [Object],
        _eventsCount: 2,
        _maxListeners: undefined,
        actionInitiated: 0,
        _connection: [Object],
        _session: [Object] },
     _link: 
      Receiver {
        session: [Object],
        connection: [Object],
        name: 'd6ca97e3-a73a-431b-8c42-13851f2b8ca7',
        options: [Object],
        state: [Object],
        issue_flow: false,
        local: [Object],
        remote: [Object],
        delivery_count: 0,
        credit: 1000,
        observers: [Object],
        drain: false,
        _events: [Object],
        _eventsCount: 7 },
     linkOptions: 
      { name: 'd6ca97e3-a73a-431b-8c42-13851f2b8ca7',
        autoaccept: true,
        source: [Object],
        credit_window: 1000,
        onMessage: [Function],
        onError: [Function],
        onClose: [Function],
        onSessionError: [Function],
        onSessionClose: [Function] } } }
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] Something is busted. State of Receiver 'a815f4db-7bd4-4a19-861f-9d68d508dda9' with address 'event-hub4/ConsumerGroups/$default/Partitions/9' is: { wasCloseInitiated: true,
  receiverError: undefined,
  _receiver: 
   Receiver {
     domain: null,
     _events: 
      { message: [Function],
        receiver_error: [Function],
        receiver_close: [Function] },
     _eventsCount: 3,
     _maxListeners: undefined,
     actionInitiated: 0,
     type: 'receiver',
     _session: 
      Session {
        domain: null,
        _events: [Object],
        _eventsCount: 2,
        _maxListeners: undefined,
        actionInitiated: 0,
        _connection: [Object],
        _session: [Object] },
     _link: 
      Receiver {
        session: [Object],
        connection: [Object],
        name: 'a815f4db-7bd4-4a19-861f-9d68d508dda9',
        options: [Object],
        state: [Object],
        issue_flow: false,
        local: [Object],
        remote: [Object],
        delivery_count: 0,
        credit: 1000,
        observers: [Object],
        drain: false,
        _events: [Object],
        _eventsCount: 7 },
     linkOptions: 
      { name: 'a815f4db-7bd4-4a19-861f-9d68d508dda9',
        autoaccept: true,
        source: [Object],
        credit_window: 1000,
        onMessage: [Function],
        onError: [Function],
        onClose: [Function],
        onSessionError: [Function],
        onSessionClose: [Function] } } }
2019-02-01T14:26:58.681Z azure:event-hubs:error [connection-4] Something is busted. State of Receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with address 'event-hub4/ConsumerGroups/$default/Partitions/6' is: { wasCloseInitiated: true,
  receiverError: undefined,
  _receiver: 
   Receiver {
     domain: null,
     _events: 
      { message: [Function],
        receiver_error: [Function],
        receiver_close: [Function] },
     _eventsCount: 3,
     _maxListeners: undefined,
     actionInitiated: 0,
     type: 'receiver',
     _session: 
      Session {
        domain: null,
        _events: [Object],
        _eventsCount: 2,
        _maxListeners: undefined,
        actionInitiated: 0,
        _connection: [Object],
        _session: [Object] },
     _link: 
      Receiver {
        session: [Object],
        connection: [Object],
        name: 'd6ca97e3-a73a-431b-8c42-13851f2b8ca7',
        options: [Object],
        state: [Object],
        issue_flow: false,
        local: [Object],
        remote: [Object],
        delivery_count: 0,
        credit: 1000,
        observers: [Object],
        drain: false,
        _events: [Object],
        _eventsCount: 7 },
     linkOptions: 
      { name: 'd6ca97e3-a73a-431b-8c42-13851f2b8ca7',
        autoaccept: true,
        source: [Object],
        credit_window: 1000,
        onMessage: [Function],
        onError: [Function],
        onClose: [Function],
        onSessionError: [Function],
        onSessionClose: [Function] } } }
2019-02-01T14:26:58.696Z azure:event-hubs:error [connection-4] Something is busted. State of Receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with address 'event-hub4/ConsumerGroups/$default/Partitions/6' is: { wasCloseInitiated: true,
  receiverError: undefined,
  _receiver: 
   Receiver {
     domain: null,
     _events: 
      { message: [Function],
        receiver_error: [Function],
        receiver_close: [Function] },
     _eventsCount: 3,
     _maxListeners: undefined,
     actionInitiated: 0,
     type: 'receiver',
     _session: 
      Session {
        domain: null,
        _events: [Object],
        _eventsCount: 2,
        _maxListeners: undefined,
        actionInitiated: 0,
        _connection: [Object],
        _session: [Object] },
     _link: 
      Receiver {
        session: [Object],
        connection: [Object],
        name: 'd6ca97e3-a73a-431b-8c42-13851f2b8ca7',
        options: [Object],
        state: [Object],
        issue_flow: false,
        local: [Object],
        remote: [Object],
        delivery_count: 0,
        credit: 1000,
        observers: [Object],
        drain: false,
        _events: [Object],
        _eventsCount: 7 },
     linkOptions: 
      { name: 'd6ca97e3-a73a-431b-8c42-13851f2b8ca7',
        autoaccept: true,
        source: [Object],
        credit_window: 1000,
        onMessage: [Function],
        onError: [Function],
        onClose: [Function],
        onSessionError: [Function],
        onSessionClose: [Function] } } }
2019-02-01T14:26:58.696Z azure:event-hubs:error [connection-4] Something is busted. State of Receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with address 'event-hub4/ConsumerGroups/$default/Partitions/6' is: { wasCloseInitiated: true,
  receiverError: undefined,
  _receiver: 
   Receiver {
     domain: null,
     _events: 
      { message: [Function],
        receiver_error: [Function],
        receiver_close: [Function] },
     _eventsCount: 3,
     _maxListeners: undefined,
     actionInitiated: 0,
     type: 'receiver',
     _session: 
      Session {
        domain: null,
        _events: [Object],
        _eventsCount: 2,
        _maxListeners: undefined,
        actionInitiated: 0,
        _connection: [Object],
        _session: [Object] },
     _link: 
      Receiver {
        session: [Object],
        connection: [Object],
        name: 'd6ca97e3-a73a-431b-8c42-13851f2b8ca7',
        options: [Object],
        state: [Object],
        issue_flow: false,
        local: [Object],
        remote: [Object],
        delivery_count: 0,
        credit: 1000,
        observers: [Object],
        drain: false,
        _events: [Object],
        _eventsCount: 7 },
     linkOptions: 
      { name: 'd6ca97e3-a73a-431b-8c42-13851f2b8ca7',
        autoaccept: true,
        source: [Object],
        credit_window: 1000,
        onMessage: [Function],
        onError: [Function],
        onClose: [Function],
        onSessionError: [Function],
        onSessionClose: [Function] } } }
2019-02-01T14:26:58.696Z azure:event-hubs:error [connection-4] Something is busted. State of Receiver '866101fa-3376-47cd-92a6-b3a6bbbdc06d' with address 'event-hub4/ConsumerGroups/$default/Partitions/6' is: { wasCloseInitiated: true,
  receiverError: undefined,
  _receiver: 
   Receiver {
     domain: null,
     _events: 
      { message: [Function],
        receiver_error: [Function],
        receiver_close: [Function] },
     _eventsCount: 3,
     _maxListeners: undefined,
     actionInitiated: 0,
     type: 'receiver',
     _session: 
      Session {
        domain: null,
        _events: [Object],
        _eventsCount: 2,
        _maxListeners: undefined,
        actionInitiated: 0,
        _connection: [Object],
        _session: [Object] },
     _link: 
      Receiver {
        session: [Object],
        connection: [Object],
        name: 'd6ca97e3-a73a-431b-8c42-13851f2b8ca7',
        options: [Object],
        state: [Object],
        issue_flow: false,
        local: [Object],
        remote: [Object],
        delivery_count: 0,
        credit: 1000,
        observers: [Object],
        drain: false,
        _events: [Object],
        _eventsCount: 7 },
     linkOptions: 
      { name: 'd6ca97e3-a73a-431b-8c42-13851f2b8ca7',
        autoaccept: true,
        source: [Object],
        credit_window: 1000,
        onMessage: [Function],
        onError: [Function],
        onClose: [Function],
        onSessionError: [Function],
        onSessionClose: [Function] } } }
2019-02-01T14:26:58.696Z azure:event-hubs:error [connection-4] Something is busted. State of Receiver '6c9959e4-0976-4197-9e7f-64ceda1dc35d' with address 'event-hub4/ConsumerGroups/$default/Partitions/7' is: { wasCloseInitiated: true,
  receiverError: undefined,
  _receiver: 
   Receiver {
     domain: null,
     _events: 
      { message: [Function],
        receiver_error: [Function],
        receiver_close: [Function] },
     _eventsCount: 3,
     _maxListeners: undefined,
     actionInitiated: 0,
     type: 'receiver',
     _session: 
      Session {
        domain: null,
        _events: [Object],
        _eventsCount: 2,
        _maxListeners: undefined,
        actionInitiated: 0,
        _connection: [Object],
        _session: [Object] },
     _link: 
      Receiver {
        session: [Object],
        connection: [Object],
        name: 'a88ecb69-84c9-4987-b96c-a219cf19d74a',
        options: [Object],
        state: [Object],
        issue_flow: false,
        local: [Object],
        remote: [Object],
        delivery_count: 0,
        credit: 1000,
        observers: [Object],
        drain: false,
        _events: [Object],
        _eventsCount: 7 },
     linkOptions: 
      { name: 'a88ecb69-84c9-4987-b96c-a219cf19d74a',
        autoaccept: true,
        source: [Object],
        credit_window: 1000,
        onMessage: [Function],
        onError: [Function],
        onClose: [Function],
        onSessionError: [Function],
        onSessionClose: [Function] } } }
2019-02-01T14:26:58.696Z azure:event-hubs:error [connection-4] Something is busted. State of Receiver 'ada48e56-235d-4a03-bf2b-c9172b1dbaa0' with address 'event-hub4/ConsumerGroups/$default/Partitions/8' is: { wasCloseInitiated: true,
  receiverError: undefined,
  _receiver: 
   Receiver {
     domain: null,
     _events: 
      { message: [Function],
        receiver_error: [Function],
        receiver_close: [Function] },
     _eventsCount: 3,
     _maxListeners: undefined,
     actionInitiated: 0,
     type: 'receiver',
     _session: 
      Session {
        domain: null,
        _events: [Object],
        _eventsCount: 2,
        _maxListeners: undefined,
        actionInitiated: 0,
        _connection: [Object],
        _session: [Object] },
     _link: 
      Receiver {
        session: [Object],
        connection: [Object],
        name: '2fadec42-2806-454d-8584-7366278cf2d6',
        options: [Object],
        state: [Object],
        issue_flow: false,
        local: [Object],
        remote: [Object],
        delivery_count: 0,
        credit: 1000,
        observers: [Object],
        drain: false,
        _events: [Object],
        _eventsCount: 7 },
     linkOptions: 
      { name: '2fadec42-2806-454d-8584-7366278cf2d6',
        autoaccept: true,
        source: [Object],
        credit_window: 1000,
        onMessage: [Function],
        onError: [Function],
        onClose: [Function],
        onSessionError: [Function],
        onSessionClose: [Function] } } }
2019-02-01T14:26:58.696Z azure:event-hubs:error [connection-4] Something is busted. State of Receiver 'aecc7ce7-1ddb-4613-b266-a0a75c20a76a' with address 'event-hub4/ConsumerGroups/$default/Partitions/10' is: { wasCloseInitiated: true,
  receiverError: undefined,
  _receiver: 
   Receiver {
     domain: null,
     _events: 
      { message: [Function],
        receiver_error: [Function],
        receiver_close: [Function] },
     _eventsCount: 3,
     _maxListeners: undefined,
     actionInitiated: 0,
     type: 'receiver',
     _session: 
      Session {
        domain: null,
        _events: [Object],
        _eventsCount: 2,
        _maxListeners: undefined,
        actionInitiated: 0,
        _connection: [Object],
        _session: [Object] },
     _link: 
      Receiver {
        session: [Object],
        connection: [Object],
        name: 'ee445d8f-4bb5-423b-a5be-c80cc805450a',
        options: [Object],
        state: [Object],
        issue_flow: false,
        local: [Object],
        remote: [Object],
        delivery_count: 0,
        credit: 1000,
        observers: [Object],
        drain: false,
        _events: [Object],
        _eventsCount: 7 },
     linkOptions: 
      { name: 'ee445d8f-4bb5-423b-a5be-c80cc805450a',
        autoaccept: true,
        source: [Object],
        credit_window: 1000,
        onMessage: [Function],
        onError: [Function],
        onClose: [Function],
        onSessionError: [Function],
        onSessionClose: [Function] } } }
2019-02-01T14:26:58.696Z azure:event-hubs:error [connection-4] Something is busted. State of Receiver '05a1684b-0942-4942-8aba-b26b0a06efd9' with address 'event-hub4/ConsumerGroups/$default/Partitions/11' is: { wasCloseInitiated: true,
  receiverError: undefined,
  _receiver: 
   Receiver {
     domain: null,
     _events: 
      { message: [Function],
        receiver_error: [Function],
        receiver_close: [Function] },
     _eventsCount: 3,
     _maxListeners: undefined,
     actionInitiated: 0,
     type: 'receiver',
     _session: 
      Session {
        domain: null,
        _events: [Object],
        _eventsCount: 2,
        _maxListeners: undefined,
        actionInitiated: 0,
        _connection: [Object],
        _session: [Object] },
     _link: 
      Receiver {
        session: [Object],
        connection: [Object],
        name: '356c76a8-070a-47a0-844d-81a689ba793b',
        options: [Object],
        state: [Object],
        issue_flow: false,
        local: [Object],
        remote: [Object],
        delivery_count: 0,
        credit: 1000,
        observers: [Object],
        drain: false,
        _events: [Object],
        _eventsCount: 7 },
     linkOptions: 
      { name: '356c76a8-070a-47a0-844d-81a689ba793b',
        autoaccept: true,
        source: [Object],
        credit_window: 1000,
        onMessage: [Function],
        onError: [Function],
        onClose: [Function],
        onSessionError: [Function],
        onSessionClose: [Function] } } }

ramya-rao-a · 2019-02-15T04:01:37Z

Thanks @MatejSkrbis, that gives us some leads. We will get back to you soon

ramya-rao-a · 2019-03-07T02:46:55Z

Thanks a lot for your patience @MatejSkrbis, we were able to piece together the below summary

Something is busted
- At around 14:26, the connection had a problem, due to which all the receivers were asked to reconnect. At this point we see the Something is busted log indicating that the sdk initiated a close() call on the receiver and reconnecting a receiver that was explicitly closed by the sdk doesnt sound right
- We depend on the is_itself_closed() function in rhea to indicate for whether the sdk closed the receiver explicitly or not. This was wrongly giving true. We were able to chase down the root cause in rhea which is now fixed. See the discussion in receiver.is_closed() returns true when ECONNRESET error happens amqp/rhea#170 (comment) for more details
A link to connection '....' $cbs node has already been opened. and UnauthorizedAccess
- At 14:47, all receivers get the OperationTimeoutError and InternalServerError when they are being re-created.
- The server side is not aware of connection problems on the client side, it continue to hold reference to the current $cbs node. When client subsequently creates new recievers, and therefore a new cbssession for authentication, the server side gives this error as it hasnt let go of the previous $cbs node.
- This is usually followed by the server breaking the current connection, clearing its references, and the client retrying to create the connection which eventually succeeds
- When this is happening, the receiver of the initial connection that had broken is in a closed state, but still listening to events. The server rightly sends the UnauthorizedAccess error which you then see in the logs. We are working on a fix to remove the event listeners on receivers in the closed state, and so you shouldnt get the UnauthorizedAccess error after that.
- We are still looking into why the server side sends the UnauthorizedAccess error to this receiver even though it is closed.

In conclusion, for the first issue, you will need the updated version of rhea. Since the fix was done in a patch version, if you re-deploy your application (or run npm install [email protected] in your local machine), you should be able to get the fix.

Regarding the second issue, we are working on a fix and plan to ship an update to @azure/event-hubs library next week.

ramya-rao-a · 2019-03-27T22:03:18Z

@MatejSkrbis Thanks for your patience.

We have just released a new version 2.0.0 for the Event Hubs library which includes the fix for the 2 errors being discussed in this issue.

InvalidOperationError: A link to connection '.....' $cbs node has already been opened.
UnauthorizedError: Unauthorized access. 'Listen' claim(s) are required to perform this operation.

For details on what the underlying problem was, please see the changelog.

Please keep in mind that there is a major version update in this release. This is because of a few breaking changes for which you may have to react to and make some changes in your code. Please see the changelog for the list of breaking changes and bug fixes.

ramya-rao-a mentioned this issue Feb 1, 2019

Event hub client - Unauthorized access after ECONNRESET #174

Closed

AlexGhiondea added Client Issues that refer to the client sdk Event Hubs labels Feb 9, 2019

ramya-rao-a changed the title ~~Event hub client - Unauthorized access due to InvalidOperationError when renewing token~~ Event hub client - Unauthorized access due to "InvalidOperationError: $cbs node has already been opened" when renewing token Feb 11, 2019

dan-v-elevate mentioned this issue Feb 14, 2019

Cannot read property 'address' of undefined / Detach already received / transfer after detach #205

Closed

ramya-rao-a closed this as completed Mar 27, 2019

ramya-rao-a mentioned this issue Jul 11, 2019

[EPH] Uncaught error thrown on disconnect Azure/azure-sdk-for-js#4136

Closed

2 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Event hub client - Unauthorized access due to "InvalidOperationError: $cbs node has already been opened" when renewing token #186

Event hub client - Unauthorized access due to "InvalidOperationError: $cbs node has already been opened" when renewing token #186

ramya-rao-a commented Feb 1, 2019

ramya-rao-a commented Feb 1, 2019 •

edited

Loading

MatejSkrbis commented Feb 4, 2019 •

edited by ramya-rao-a

Loading

MatejSkrbis commented Feb 7, 2019

ramya-rao-a commented Feb 9, 2019 •

edited

Loading

ramya-rao-a commented Feb 11, 2019

MatejSkrbis commented Feb 13, 2019 •

edited by ramya-rao-a

Loading

MatejSkrbis commented Feb 13, 2019 •

edited by ramya-rao-a

Loading

ramya-rao-a commented Feb 15, 2019

ramya-rao-a commented Mar 7, 2019

ramya-rao-a commented Mar 27, 2019 •

edited by amarzavery

Loading

Event hub client - Unauthorized access due to "InvalidOperationError: $cbs node has already been opened" when renewing token #186

Event hub client - Unauthorized access due to "InvalidOperationError: $cbs node has already been opened" when renewing token #186

Comments

ramya-rao-a commented Feb 1, 2019

ramya-rao-a commented Feb 1, 2019 • edited Loading

MatejSkrbis commented Feb 4, 2019 • edited by ramya-rao-a Loading

MatejSkrbis commented Feb 7, 2019

ramya-rao-a commented Feb 9, 2019 • edited Loading

ramya-rao-a commented Feb 11, 2019

MatejSkrbis commented Feb 13, 2019 • edited by ramya-rao-a Loading

MatejSkrbis commented Feb 13, 2019 • edited by ramya-rao-a Loading

ramya-rao-a commented Feb 15, 2019

ramya-rao-a commented Mar 7, 2019

ramya-rao-a commented Mar 27, 2019 • edited by amarzavery Loading

ramya-rao-a commented Feb 1, 2019 •

edited

Loading

MatejSkrbis commented Feb 4, 2019 •

edited by ramya-rao-a

Loading

ramya-rao-a commented Feb 9, 2019 •

edited

Loading

MatejSkrbis commented Feb 13, 2019 •

edited by ramya-rao-a

Loading

MatejSkrbis commented Feb 13, 2019 •

edited by ramya-rao-a

Loading

ramya-rao-a commented Mar 27, 2019 •

edited by amarzavery

Loading