Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Cannot send messages, connection error after some period of time. Does not get reestablished. #5944

Closed
1 of 6 tasks
Evertvdw opened this issue Oct 30, 2019 · 15 comments
Closed
1 of 6 tasks
Assignees
Labels
Client This issue points to a problem in the data-plane of the library. customer-reported Issues that are reported by GitHub users external to the Azure organization. Event Hubs Service Attention Workflow: This issue is responsible by Azure service team.

Comments

@Evertvdw
Copy link

  • Package Name: @azure/event-hubs
  • Package Version: 2.1.1
  • Operating system: Linux container
  • nodejs
    • version: 10 (node:10) docker container
  • browser
    • name/version:
  • typescript
    • version:
  • Is the bug related to documentation in

Describe the bug
I'm having trouble sending stuff to an event-hub. At first it worked fine but since yesterday I only get errors on nothing gets through. Restarting the container does not help. The issue looks a lot like #5282 but it's not exactly the same. Does anyone know what is going on here?

To Reproduce
I think somewhere the connection was lost between client and server, but I'm not sure.

Logs
Sample of the logging, the logs preceeded by INFO: are my personal logs, rest comes from the DEBUG mode.

2019-10-30 16:12:45.000 | tsi-molding_dev
-- | --
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:45.720Z azure:amqp-common:retry [connection-1] Retry for 'senderLink', attempt number: 38
2019-10-30 16:12:45.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:45.720Z azure:event-hubs:error [connection-1] Sender '191642d8-5063-4041-9782-7db58fb7c716' with address 'molding' is open? -> undefined
2019-10-30 16:12:45.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:45.720Z azure:event-hubs:error [connection-1] The sender '191642d8-5063-4041-9782-7db58fb7c716' with address 'molding' is not open and is not currently establishing itself. Hence let's try to connect.
2019-10-30 16:12:45.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:45.720Z azure:amqp-common:cbs The CBS client is trying to establish an AMQP connection.
2019-10-30 16:12:45.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:45.720Z azure:event-hubs:linkEntity [connection-1] Acquiring cbs lock: 'negotiateCbs-6649617e-41f6-b54c-bbbf-3fed0a1daef5' for creating the cbs session while creating the EventHubSender: '191642d8-5063-4041-9782-7db58fb7c716' with address: 'molding'.
2019-10-30 16:12:45.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:45.721Z rhea-promise:connection [connection-1] Trying to create a new amqp connection.
2019-10-30 16:12:45.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated
2019-10-30 16:12:45.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: INFO: Sending message to azure
2019-10-30 16:12:45.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:45.772Z azure:event-hubs:error [connection-1] Sender '191642d8-5063-4041-9782-7db58fb7c716' with address 'molding' is open? -> undefined
2019-10-30 16:12:45.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:45.772Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection.
2019-10-30 16:12:41.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated
2019-10-30 16:12:41.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: INFO: Sending message to azure
2019-10-30 16:12:41.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:41.741Z azure:event-hubs:error [connection-1] Sender '191642d8-5063-4041-9782-7db58fb7c716' with address 'molding' is open? -> undefined
2019-10-30 16:12:41.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:41.744Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection.
2019-10-30 16:12:37.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated
2019-10-30 16:12:37.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: INFO: Sending message to azure
2019-10-30 16:12:37.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:37.616Z azure:event-hubs:error [connection-1] Sender '191642d8-5063-4041-9782-7db58fb7c716' with address 'molding' is open? -> undefined
2019-10-30 16:12:37.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:37.616Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection.
2019-10-30 16:12:32.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: INFO: ccf-shot-translated, updating database nl59wg01180510ccf-shot-translated
2019-10-30 16:12:32.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: INFO: Sending message to azure
2019-10-30 16:12:32.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:32.384Z azure:event-hubs:error [connection-1] Sender '191642d8-5063-4041-9782-7db58fb7c716' with address 'molding' is open? -> undefined
2019-10-30 16:12:32.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:32.384Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection.
2019-10-30 16:12:32.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated
2019-10-30 16:12:32.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: INFO: Sending message to azure
2019-10-30 16:12:32.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:32.632Z azure:event-hubs:error [connection-1] Sender '191642d8-5063-4041-9782-7db58fb7c716' with address 'molding' is open? -> undefined
2019-10-30 16:12:32.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:32.632Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection.
2019-10-30 16:12:31.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:31.019Z azure:event-hubs:error [connection-1] calling detached on sender '191642d8-5063-4041-9782-7db58fb7c716' with address 'molding'.
2019-10-30 16:12:31.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:31.022Z azure:event-hubs:error [connection-1] close() method of Sender '191642d8-5063-4041-9782-7db58fb7c716' with address 'molding' was not called. There was an accompanying error an it is retryable. This is a candidate for re-establishing the sender link.
2019-10-30 16:12:30.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:30.717Z rhea-promise:connection [connection-1] connection got event: 'disconnected'. Re-emitting the translated context.
2019-10-30 16:12:30.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:30.717Z rhea-promise:translate [connection-1] Translating the context for event: 'disconnected'.
2019-10-30 16:12:30.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: 2019-10-30T15:12:30.717Z rhea:events [connection-1] Connection got event: disconnected
2019-10-30 16:12:30.000 | tsi-molding_dev
tsi-molding_dev 7eaf7037aa8b[1]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1083:14)

Additional context
Add any other context about the problem here.

@loarabia loarabia added Client This issue points to a problem in the data-plane of the library. customer-reported Issues that are reported by GitHub users external to the Azure organization. Event Hubs Service Attention Workflow: This issue is responsible by Azure service team. labels Oct 30, 2019
@jfggdl
Copy link

jfggdl commented Oct 30, 2019

@Evertvdw , thank you for creating this issue. We are investing this issue and will be back to you with our findings.

@ramya-rao-a
Copy link
Contributor

@Evertvdw Can you provide more logs? After removing the lines with | tsi-molding_dev there is very little for us to work with.
You can keep the INFO ones as they show us when an attempt to send a message is made, but if you can remove the | tsi-molding_dev lines and share more logs, we would appreciate it.

@ramya-rao-a
Copy link
Contributor

Also, if you can log a support ticket, we can also carry out investigations on the service side. Please consider doing that and sharing the ticket number here.

@Evertvdw
Copy link
Author

@Evertvdw Can you provide more logs? After removing the lines with | tsi-molding_dev there is very little for us to work with.
You can keep the INFO ones as they show us when an attempt to send a message is made, but if you can remove the | tsi-molding_dev lines and share more logs, we would appreciate it.

I'm not sure I understand. tsi-molding_dev is the container name and since I get these logs from Greylog this name is gonna be on every line. I don't have a method yet for getting the raw logs, but I'm working on that. As soon as I can get that I will share more logs.

Regarding the support ticket, I will do that, thanks for the suggestion!

@Evertvdw
Copy link
Author

Evertvdw commented Oct 31, 2019

More logs (cleaner):
Lines start with INFO or ERROR are my entries. ERROR lines come from a catch block around the await send() command but do not contain the error message as that flooded the logs.

INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:54:18.245Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:54:18.245Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
2019-10-31T06:54:18.251Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at Generator.next (<anonymous>)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at new Promise (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5911"
INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:54:20.270Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:54:20.270Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:54:20.274Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at Generator.next (<anonymous>)"
    at new Promise (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at Generator.next (<anonymous>)"
ERROR: something went wrong with sending message to azure 5912"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
2019-10-31T06:54:17.752Z azure:amqp-common:retry [connection-1] Retry for 'senderLink', attempt number: 92"
2019-10-31T06:54:17.753Z rhea-promise:connection [connection-1] Trying to create a new amqp connection."
2019-10-31T06:54:17.752Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:54:17.753Z azure:event-hubs:error [connection-1] The sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is not open and is not currently establishing itself. Hence let's try to connect."
2019-10-31T06:54:17.753Z azure:event-hubs:linkEntity [connection-1] Acquiring cbs lock: 'negotiateCbs-6649617e-41f6-b54c-bbbf-3fed0a1daef5' for creating the cbs session while creating the EventHubSender: '5355170e-ea3e-4918-a122-6a6687db6ea7' with address: 'molding'."
2019-10-31T06:54:17.753Z azure:amqp-common:cbs The CBS client is trying to establish an AMQP connection."
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:54:27.861Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:54:27.864Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
2019-10-31T06:54:27.867Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at new Promise (<anonymous>)"
    at Generator.next (<anonymous>)"
    at Generator.next (<anonymous>)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
ERROR: something went wrong with sending message to azure 5913"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
INFO: ccf-shot-translated, updating database nl59wg01180510ccf-shot-translated"
2019-10-31T06:55:37.954Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:55:37.954Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
INFO: Sending message to azure"
2019-10-31T06:55:37.960Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at Generator.next (<anonymous>)"
    at new Promise (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
ERROR: something went wrong with sending message to azure 5932"
INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:55:33.573Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:55:33.573Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at new Promise (<anonymous>)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Generator.next (<anonymous>)"
2019-10-31T06:55:33.580Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5931"
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:55:32.651Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:55:32.651Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
2019-10-31T06:55:32.652Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at new Promise (<anonymous>)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at Generator.next (<anonymous>)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5930"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
INFO: ccf-shot-translated, updating database nl59wg01180510ccf-shot-translated"
2019-10-31T06:57:03.954Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
INFO: Sending message to azure"
2019-10-31T06:57:03.954Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at new Promise (<anonymous>)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
2019-10-31T06:57:03.961Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at Generator.next (<anonymous>)"
ERROR: something went wrong with sending message to azure 5954"
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
2019-10-31T06:57:04.574Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:57:04.574Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
INFO: Sending message to azure"
    at Generator.next (<anonymous>)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at new Promise (<anonymous>)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
2019-10-31T06:57:04.580Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5955"
INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated"
2019-10-31T06:57:04.608Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:57:04.608Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
INFO: Sending message to azure"
2019-10-31T06:57:04.614Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at new Promise (<anonymous>)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at Generator.next (<anonymous>)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
ERROR: something went wrong with sending message to azure 5956"
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:57:13.680Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:57:13.680Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:57:13.681Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at new Promise (<anonymous>)"
    at Generator.next (<anonymous>)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at Generator.next (<anonymous>)"
ERROR: something went wrong with sending message to azure 5957"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
INFO: Sending message to azure"
INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated"
2019-10-31T06:57:13.684Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:57:13.683Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:57:13.684Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at Generator.next (<anonymous>)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5958"
    at new Promise (<anonymous>)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
2019-10-31T06:53:50.942Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
INFO: Sending message to azure"
2019-10-31T06:53:50.942Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:53:50.949Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at new Promise (<anonymous>)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5904"
INFO: ccf-shot-translated, updating database nl59wg01180510ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:53:49.958Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:53:49.958Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at Generator.next (<anonymous>)"
    at new Promise (<anonymous>)"
2019-10-31T06:53:49.959Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at Generator.next (<anonymous>)"
ERROR: something went wrong with sending message to azure 5903"
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:55:22.988Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:55:22.988Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:55:22.988Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at new Promise (<anonymous>)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5928"
    at Generator.next (<anonymous>)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
INFO: Sending message to azure"
2019-10-31T06:55:24.004Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:55:24.005Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at new Promise (<anonymous>)"
    at Generator.next (<anonymous>)"
2019-10-31T06:55:24.011Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5929"
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:55:13.888Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:55:13.888Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:55:13.895Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at Generator.next (<anonymous>)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at new Promise (<anonymous>)"
    at Generator.next (<anonymous>)"
ERROR: something went wrong with sending message to azure 5925"
INFO: ccf-shot-translated, updating database nl59wg01180510ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:55:15.956Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:55:15.956Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:55:15.956Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at Generator.next (<anonymous>)"
    at new Promise (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Generator.next (<anonymous>)"
ERROR: something went wrong with sending message to azure 5927"
INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated"
2019-10-31T06:55:14.892Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
INFO: Sending message to azure"
2019-10-31T06:55:14.892Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:55:14.899Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at new Promise (<anonymous>)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at Generator.next (<anonymous>)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5926"
INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:56:18.586Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:56:18.586Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:56:18.586Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at new Promise (<anonymous>)"
    at Generator.next (<anonymous>)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at Generator.next (<anonymous>)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5942"
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:56:18.614Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
2019-10-31T06:56:18.614Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
    at new Promise (<anonymous>)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
2019-10-31T06:56:18.614Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
ERROR: something went wrong with sending message to azure 5943"
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:56:27.691Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:56:27.691Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:56:27.692Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at new Promise (<anonymous>)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at Generator.next (<anonymous>)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
ERROR: something went wrong with sending message to azure 5945"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:56:27.718Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:56:27.718Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:56:27.719Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at new Promise (<anonymous>)"
    at Generator.next (<anonymous>)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at Generator.next (<anonymous>)"
ERROR: something went wrong with sending message to azure 5946"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
2019-10-31T06:56:28.157Z rhea-promise:connection [connection-1] connection got event: 'disconnected'. Re-emitting the translated context."
2019-10-31T06:56:28.157Z rhea:events [connection-1] Connection got event: disconnected"
2019-10-31T06:56:28.157Z rhea-promise:translate [connection-1] Translating the context for event: 'disconnected'."
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1083:14)"
  errno: 'ETIMEDOUT',"
  address: '13.69.64.0',"
2019-10-31T06:56:28.157Z azure:event-hubs:error [connection-1] Error (context.error) occurred on the amqp connection: { Error: connect ETIMEDOUT 13.69.64.0:5671"
  port: 5671 }"
  syscall: 'connect',"
  code: 'ETIMEDOUT',"
2019-10-31T06:56:28.158Z rhea-promise:error [connection-1] Error occurred while establishing amqp connection: { Error: connect ETIMEDOUT 13.69.64.0:5671"
  errno: 'ETIMEDOUT',"
  address: '13.69.64.0',"
  port: 5671 }"
  syscall: 'connect',"
  code: 'ETIMEDOUT',"
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1083:14)"
2019-10-31T06:56:28.159Z azure:amqp-common:error [connection-1] An error occured while establishing the cbs links: { Error: connect ETIMEDOUT 13.69.64.0:5671"
  translated: true,"
2019-10-31T06:56:28.159Z azure:event-hubs:error [connection-1] state: { wasConnectionCloseCalled: false,"
  numSenders: 1,"
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1083:14)"
  name: 'ServiceUnavailableError',"
  retryable: true }"
  numReceivers: 0 }"
2019-10-31T06:56:28.159Z azure:event-hubs:error [connection-1] connection.close() was not called from the sdk and there were some sender or receiver links or both. We should reconnect."
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1083:14)"
  retryable: true }"
  translated: true,"
2019-10-31T06:56:28.160Z azure:event-hubs:error [connection-1] An error occurred while creating the sender 5355170e-ea3e-4918-a122-6a6687db6ea7 { Error: connect ETIMEDOUT 13.69.64.0:5671"
2019-10-31T06:56:28.160Z azure:amqp-common:error [connection-1] Error occured for 'senderLink' in attempt number 94: { Error: connect ETIMEDOUT 13.69.64.0:5671"
  name: 'ServiceUnavailableError',"
  name: 'ServiceUnavailableError',"
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1083:14)"
  translated: true,"
  retryable: true }"
2019-10-31T06:56:28.160Z azure:amqp-common:error [connection-1] Sleeping for 15 seconds for 'senderLink'."
2019-10-31T06:56:28.459Z azure:event-hubs:error [connection-1] calling detached on sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding'."
2019-10-31T06:56:28.462Z azure:event-hubs:error [connection-1] close() method of Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' was not called. There was an accompanying error an it is retryable. This is a candidate for re-establishing the sender link."
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1470:50)"
    at Generator.next (<anonymous>)"
2019-10-31T06:56:28.468Z azure:event-hubs:error [connection-1] An error occurred while processing detached() of Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding': Error: Too much pending tasks"
    at fulfilled (/home/node/app/node_modules/tslib/tslib.js:107:62)"
INFO: Sending message to azure"
2019-10-31T06:56:19.959Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
INFO: ccf-shot-translated, updating database nl59wg01180510ccf-shot-translated"
2019-10-31T06:56:19.959Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:56:19.966Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at new Promise (<anonymous>)"
    at Generator.next (<anonymous>)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5944"
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:55:04.773Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:55:04.773Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
    at Generator.next (<anonymous>)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
2019-10-31T06:55:04.774Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at new Promise (<anonymous>)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at Generator.next (<anonymous>)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
ERROR: something went wrong with sending message to azure 5923"
INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:55:05.795Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:55:05.795Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at new Promise (<anonymous>)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at Generator.next (<anonymous>)"
2019-10-31T06:55:05.801Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at Generator.next (<anonymous>)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
ERROR: something went wrong with sending message to azure 5924"
2019-10-31T06:55:06.909Z azure:event-hubs:error [connection-1] The sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is not open and is not currently establishing itself. Hence let's try to connect."
2019-10-31T06:55:06.909Z azure:event-hubs:linkEntity [connection-1] Acquiring cbs lock: 'negotiateCbs-6649617e-41f6-b54c-bbbf-3fed0a1daef5' for creating the cbs session while creating the EventHubSender: '5355170e-ea3e-4918-a122-6a6687db6ea7' with address: 'molding'."
2019-10-31T06:55:06.909Z azure:amqp-common:cbs The CBS client is trying to establish an AMQP connection."
2019-10-31T06:55:06.908Z azure:amqp-common:retry [connection-1] Retry for 'senderLink', attempt number: 93"
2019-10-31T06:55:06.909Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:55:06.909Z rhea-promise:connection [connection-1] Trying to create a new amqp connection."
INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:56:55.488Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:56:55.488Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at new Promise (<anonymous>)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at Generator.next (<anonymous>)"
2019-10-31T06:56:55.488Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at Generator.next (<anonymous>)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
ERROR: something went wrong with sending message to azure 5952"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:56:55.491Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:56:55.491Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at new Promise (<anonymous>)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Generator.next (<anonymous>)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
2019-10-31T06:56:55.492Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at Generator.next (<anonymous>)"
ERROR: something went wrong with sending message to azure 5953"
INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:54:38.461Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:54:38.464Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
2019-10-31T06:54:38.468Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at Generator.next (<anonymous>)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Generator.next (<anonymous>)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at new Promise (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5917"
INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:54:29.369Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:54:29.372Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at Generator.next (<anonymous>)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at new Promise (<anonymous>)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5914"
2019-10-31T06:54:29.376Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
INFO: ccf-shot-translated, updating database nl59wg01180510ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:54:33.955Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at Generator.next (<anonymous>)"
2019-10-31T06:54:33.955Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at new Promise (<anonymous>)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
2019-10-31T06:54:33.955Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at Generator.next (<anonymous>)"
ERROR: something went wrong with sending message to azure 5915"
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:54:36.945Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:54:36.948Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:54:36.952Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at Generator.next (<anonymous>)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5916"
    at new Promise (<anonymous>)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
INFO: ccf-shot-translated, updating database nl59wg01180510ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:56:41.954Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:56:41.954Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:56:41.954Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at Generator.next (<anonymous>)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at new Promise (<anonymous>)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at Generator.next (<anonymous>)"
ERROR: something went wrong with sending message to azure 5949"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
2019-10-31T06:56:43.161Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:56:43.161Z azure:amqp-common:retry [connection-1] Retry for 'senderLink', attempt number: 95"
2019-10-31T06:56:43.161Z azure:event-hubs:error [connection-1] The sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is not open and is not currently establishing itself. Hence let's try to connect."
2019-10-31T06:56:43.161Z azure:event-hubs:linkEntity [connection-1] Acquiring cbs lock: 'negotiateCbs-6649617e-41f6-b54c-bbbf-3fed0a1daef5' for creating the cbs session while creating the EventHubSender: '5355170e-ea3e-4918-a122-6a6687db6ea7' with address: 'molding'."
2019-10-31T06:56:43.161Z azure:amqp-common:cbs The CBS client is trying to establish an AMQP connection."
2019-10-31T06:56:43.161Z rhea-promise:connection [connection-1] Trying to create a new amqp connection."
INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:56:36.750Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:56:36.750Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
    at Generator.next (<anonymous>)"
2019-10-31T06:56:36.751Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at new Promise (<anonymous>)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5947"
    at Generator.next (<anonymous>)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:56:36.777Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:56:36.777Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:56:36.778Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at Generator.next (<anonymous>)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at new Promise (<anonymous>)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at Generator.next (<anonymous>)"
ERROR: something went wrong with sending message to azure 5948"
INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:56:46.373Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:56:46.373Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
2019-10-31T06:56:46.373Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
INFO: Sending message to azure"
    at Generator.next (<anonymous>)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at Generator.next (<anonymous>)"
    at new Promise (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
2019-10-31T06:56:46.374Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
ERROR: something went wrong with sending message to azure 5950"
2019-10-31T06:56:46.374Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:56:46.374Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at Generator.next (<anonymous>)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at new Promise (<anonymous>)"
ERROR: something went wrong with sending message to azure 5951"
INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:54:47.562Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
2019-10-31T06:54:47.562Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at new Promise (<anonymous>)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
2019-10-31T06:54:47.562Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
ERROR: something went wrong with sending message to azure 5919"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at Generator.next (<anonymous>)"
INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:54:56.692Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:54:56.692Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:54:56.699Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at Generator.next (<anonymous>)"
    at new Promise (<anonymous>)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5922"
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:54:55.730Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:54:55.730Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
2019-10-31T06:54:55.736Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at new Promise (<anonymous>)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at Generator.next (<anonymous>)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
ERROR: something went wrong with sending message to azure 5921"
2019-10-31T06:54:51.901Z rhea:events [connection-1] Connection got event: disconnected"
2019-10-31T06:54:51.903Z rhea-promise:connection [connection-1] connection got event: 'disconnected'. Re-emitting the translated context."
2019-10-31T06:54:51.906Z rhea-promise:translate [connection-1] Translating the context for event: 'disconnected'."
  errno: 'ETIMEDOUT',"
2019-10-31T06:54:51.908Z azure:event-hubs:error [connection-1] Error (context.error) occurred on the amqp connection: { Error: connect ETIMEDOUT 13.69.64.0:5671"
  address: '13.69.64.0',"
  code: 'ETIMEDOUT',"
  port: 5671 }"
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1083:14)"
2019-10-31T06:54:51.909Z rhea-promise:error [connection-1] Error occurred while establishing amqp connection: { Error: connect ETIMEDOUT 13.69.64.0:5671"
  syscall: 'connect',"
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1083:14)"
  syscall: 'connect',"
  address: '13.69.64.0',"
  code: 'ETIMEDOUT',"
2019-10-31T06:54:51.909Z azure:amqp-common:error [connection-1] An error occured while establishing the cbs links: { Error: connect ETIMEDOUT 13.69.64.0:5671"
  port: 5671 }"
  errno: 'ETIMEDOUT',"
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1083:14)"
  name: 'ServiceUnavailableError',"
  retryable: true }"
  numReceivers: 0 }"
  numSenders: 1,"
  translated: true,"
2019-10-31T06:54:51.909Z azure:event-hubs:error [connection-1] connection.close() was not called from the sdk and there were some sender or receiver links or both. We should reconnect."
2019-10-31T06:54:51.909Z azure:event-hubs:error [connection-1] An error occurred while creating the sender 5355170e-ea3e-4918-a122-6a6687db6ea7 { Error: connect ETIMEDOUT 13.69.64.0:5671"
2019-10-31T06:54:51.909Z azure:event-hubs:error [connection-1] state: { wasConnectionCloseCalled: false,"
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1083:14)"
  retryable: true }"
  translated: true,"
  name: 'ServiceUnavailableError',"
  name: 'ServiceUnavailableError',"
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1083:14)"
  translated: true,"
  retryable: true }"
2019-10-31T06:54:51.909Z azure:amqp-common:error [connection-1] Error occured for 'senderLink' in attempt number 92: { Error: connect ETIMEDOUT 13.69.64.0:5671"
2019-10-31T06:54:51.909Z azure:amqp-common:error [connection-1] Sleeping for 15 seconds for 'senderLink'."
2019-10-31T06:54:52.208Z azure:event-hubs:error [connection-1] calling detached on sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding'."
2019-10-31T06:54:52.208Z azure:event-hubs:error [connection-1] close() method of Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' was not called. There was an accompanying error an it is retryable. This is a candidate for re-establishing the sender link."
2019-10-31T06:54:52.218Z azure:event-hubs:error [connection-1] An error occurred while processing detached() of Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding': Error: Too much pending tasks"
    at Generator.next (<anonymous>)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1470:50)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at fulfilled (/home/node/app/node_modules/tslib/tslib.js:107:62)"
INFO: ccf-shot-translated, updating database nl59wg01180510ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:54:53.954Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:54:53.955Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:54:53.955Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at new Promise (<anonymous>)"
    at Generator.next (<anonymous>)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5920"
INFO: Sending message to azure"
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
2019-10-31T06:54:46.045Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:54:46.045Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
2019-10-31T06:54:46.045Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at Generator.next (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at new Promise (<anonymous>)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5918"
    at Generator.next (<anonymous>)"
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:56:08.998Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
2019-10-31T06:56:08.998Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at new Promise (<anonymous>)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
2019-10-31T06:56:08.999Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at Generator.next (<anonymous>)"
    at Generator.next (<anonymous>)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
ERROR: something went wrong with sending message to azure 5940"
2019-10-31T06:56:09.506Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
INFO: Sending message to azure"
INFO: ccf-shot-translated, updating database nl59ccfby191ccf-shot-translated"
2019-10-31T06:56:09.506Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
    at new Promise (<anonymous>)"
    at Generator.next (<anonymous>)"
    at EventHubSender.send (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1524:24)"
2019-10-31T06:56:09.512Z azure:event-hubs:error An error occurred while sending the message Error: Too much pending tasks"
    at Object.__awaiter (/home/node/app/node_modules/tslib/tslib.js:106:16)"
    at Generator.next (<anonymous>)"
    at EventHubClient.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:2165:27)"
    at /home/node/app/node_modules/tslib/tslib.js:110:75"
ERROR: something went wrong with sending message to azure 5941"
INFO: ccf-shot-translated, updating database nl59ccfby201ccf-shot-translated"
INFO: Sending message to azure"
2019-10-31T06:54:00.046Z azure:event-hubs:sender Acquiring lock sender-031b353a-8dfb-4154-b587-3c2bb2c8da99 for initializing the session, sender and possibly the connection."
2019-10-31T06:54:00.046Z azure:event-hubs:error [connection-1] Sender '5355170e-ea3e-4918-a122-6a6687db6ea7' with address 'molding' is open? -> undefined"
    at EventHubSender.<anonymous> (/home/node/app/node_modules/@azure/event-hubs/dist/index.js:1534:50)"
    at AsyncLock.acquire (/home/node/app/node_modules/async-lock/lib/index.js:148:15)"

@Evertvdw
Copy link
Author

@ramya-rao-a The ticket ID for the azure support is: 119103122000087

@ramya-rao-a
Copy link
Contributor

Thanks for the logs @Evertvdw and our apologies for not responding sooner.

Can you share a code snippet showing how you are sending the messages?
From the logs, the error Too much pending tasks is the one that is appearing consistently for every send attempt.
Having a look at exactly how you are using the send methods will help us determine the root cause better.

@ramya-rao-a
Copy link
Contributor

@chradek, Some observations about the sequence of events to aid in investigation while we wait for a response from @Evertvdw

  • A send request is made
  • We observe that there is no sender link available, so we take a lock to create one
  • Its this attempt of getting a lock that is failing from inside the async-lock package which was created with maxPending requests to be at 10000
  • The failure is not being retried at the moment. This part is something that we can definitely fix by retrying. The delay between retries should help in easing off of the high requests
  • Back to step 1 of a send request being made

@ramya-rao-a
Copy link
Contributor

@chradek There are some ETIMEDOUT related errors in the logs above that we should investigate, but apart from that what I described above was also captured in #3376

@Evertvdw
Copy link
Author

Evertvdw commented Nov 7, 2019

@ramya-rao-a Yes I can, maybe there is something wrong with the approach I take:

      const sendMessageAzure = async (message, hub) => {
        try {
          console.log('INFO: Sending message to azure')
          await hubs[hub].send(message)
          console.log('INFO: Message send to azure')
        } catch (error) {
          errorCounter++
          console.error('ERROR: something went wrong with sending message to azure', errorCounter)
        }
      }

I listen to a Kafka topic and on every message I receive there this function is called. So especially on the initial connection a lot of data can come through and this function is called a lot of times. I'm currently not waiting for the function to finish before it can be called again, is that what causes the issue?

Anyways, due to some mysterious circumstances after ~3 days of malfunction there is data coming through again now. I did not restart the docker container, so it somehow fixed itself. I will also post some logs of the current state of operation, maybe that helps.

@Evertvdw
Copy link
Author

Evertvdw commented Nov 7, 2019

Here is an image of the TSI environment, where you can see that somewhere on 29-10 the data stopped coming in, and started steadily again at around 2-11.
image

@Evertvdw
Copy link
Author

Evertvdw commented Nov 7, 2019

INFO: ccf-shot-translated, updating database nl59wg01260510ccf-shot-translated
INFO: Sending message to azure
2019-11-07T10:51:01.524Z azure:event-hubs:error [connection-1] Sender '14cf9497-38ef-4970-a784-2f150a202935' with address 'molding' is open? -> true
2019-11-07T10:51:01.524Z azure:amqp-common:datatransformer [encode] The given message body that needs to be encoded is:  { id: 'nl59wg01260510ccf-shot-translated',
  timestamp: '2019-11-07T10:51:08.019+00:00',
  series:
   [ { 'Shot counter': 16069,
       'Shot counter bad': 16069,
       'Part counter': 13312720,
       'Part counter bad': 10277500,
       'Reject reason': 0,
       'Number of cavities': 8,
       'Cycle time set value': 0,
       'Cycle time last value': 22.8,
       'Cooling time': 8.01,
       'Hold pressure peak 1': 74,
       'Hold pressure peak 2': 52.3,
       'Injection pressure peak 1': 133.9,
       'Injection pressure peak 2': 51.6,
       'Back pressure peak 1': 26.3,
       'Back pressure peak 2': 8.2,
       'Material consumption 1': 191,
       'Material consumption 2': 0,
       'Screw position 1': 37.2,
       'Screw position 2': 26.8,
       'Flow number 1': 1599,
       'Flow number 2': 597.4,
       'Injection time 1': 0.81,
       'Injection time 2': 0.55,
       'Plasticizing time 1': 3.06,
       'Plasticizing time 2': 2.86,
       'Switchover pressure 1': 1462.3,
       'Switchover pressure 2': 925.7,
       'Melt cushion 1': 5.44,
       'Melt cushion 2': 5.12,
       'Injection pressure peak value': 133.9,
       'Plasticizing position end - corrected': 58.5,
       'Clamp force': 2218.8,
       'Mold protection time actual value': 1.03,
       'Oil temperature': 37,
       'Temperature zone 1': 284.9,
       'Temperature zone 2': 290,
       'Temperature zone 3': 289.8,
       'Temperature zone 4': 280,
       'Temperature zone 5': 264.9,
       'Temperature zone 6': 3276.7,
       'Temperature zone 7': 50.2,
       'Temperature zone 8': 300.3,
       'Temperature zone 9': 295.5,
       'Temperature zone 10': 295.3,
       'Temperature zone 11': 290.4,
       'Temperature zone 12': 295.4,
       'Temperature zone 13': 295.5,
       'Temperature zone 14': 290.5,
       'Temperature zone 15': 295.2,
       'Temperature zone 16': 220.4,
       'Set temperature zone 1': 285,
       'Set temperature zone 2': 290,
       'Set temperature zone 3': 285,
       'Set temperature zone 4': 280,
       'Set temperature zone 5': 265,
       'Set temperature zone 6': 0,
       'Set temperature zone 7': 50,
       'Set temperature zone 8': 280,
       'Set temperature zone 9': 272,
       'Set temperature zone 10': 285,
       'Set temperature zone 11': 285,
       'Set temperature zone 12': 285,
       'Set temperature zone 13': 283,
       'Set temperature zone 14': 280,
       'Set temperature zone 15': 282,
       'Set temperature zone 16': 228,
       'Heating energy actual value last cycle': 0.02351489,
       'Heating energy consumption': 62481.4,
       'Motor energy actual value last cycle': 0.01947028,
       'Motor energy consumption': 44142.2,
       'Total energy actual value last cycle': 0.04298517,
       'Total energy consumption': 106623.6 } ] }
2019-11-07T10:51:01.590Z azure:amqp-common:datatransformer [encode] The encoded message body is: Section {
  typecode: 117,
  content:
   <Buffer 7b 22 69 64 22 3a 22 6e 6c 35 39 77 67 30 31 32 36 30 35 31 30 63 63 66 2d 73 68 6f 74 2d 74 72 61 6e 73 6c 61 74 65 64 22 2c 22 74 69 6d 65 73 74 61 ... 2121 more bytes>,
  multiple: undefined }.
2019-11-07T10:51:01.590Z azure:amqp-common:retry [connection-1] Retry for 'sendMessage', attempt number: 1
2019-11-07T10:51:01.599Z azure:event-hubs:sender [connection-1] Sender '14cf9497-38ef-4970-a784-2f150a202935', credit: 290 available: 2048
2019-11-07T10:51:01.602Z azure:event-hubs:sender [connection-1] Sender '14cf9497-38ef-4970-a784-2f150a202935', sending message with id '<not specified>'.
2019-11-07T10:51:01.605Z rhea:message Encoding section 1 of 5: Typed { type: TypeDesc { name: 'List0', typecode: 69, width: 0, category: 1, create: { [Function] typecode: 69 } }, value: [], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value:
112 } }
2019-11-07T10:51:01.612Z rhea:message Encoding section 2 of 5: Typed { type: TypeDesc { name: 'Map32', typecode: 209, width: 4, category: 3, create: { [Function] typecode: 209 } }, value: [], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value
: 113 } }
2019-11-07T10:51:01.619Z rhea:message Encoding section 3 of 5: Typed { type: TypeDesc { name: 'Map32', typecode: 209, width: 4, category: 3, create: { [Function] typecode: 209 } }, value: [], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value
: 114 } }
2019-11-07T10:51:01.626Z rhea:message Encoding section 4 of 5: Typed { type: TypeDesc { name: 'List0', typecode: 69, width: 0, category: 1, create: { [Function] typecode: 69 } }, value: [], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value:
115 } }
2019-11-07T10:51:01.633Z rhea:message Encoding section 5 of 5: Typed { type: TypeDesc { name: 'Vbin32', typecode: 176, width: 4, category: 2, create: { [Function] typecode: 176 } }, value: <Buffer 7b 22 69 64 22 3a 22 6e 6c 35 39 77 67 30 31 32 36 30 35 31 30 63 63 66 2d 73 68 6f 74 2d 74 72 61 6e 73 6c 61 74 65 64 22 2c 22 74 69 6d 65 73 74 61 ... 2121 more by
tes>, descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 117 } }
2019-11-07T10:51:01.642Z rhea:message encoded 2211 bytes
2019-11-07T10:51:01.644Z azure:event-hubs:sender [connection-1] Sender '14cf9497-38ef-4970-a784-2f150a202935', sent message with delivery id: 310 and tag: 310
2019-11-07T10:51:01.647Z rhea:frames [connection-1]:1 -> transfer#14 {"delivery_id":310,"delivery_tag":{"type":"Buffer","data":[51,49,48]}} <Buffer 00 53 70 45 00 53 71 d1 00 00 00 04 00 00 00 00 00 53 72 d1 00 00 00 04 00 00 00 00 00 53 73 45 00 53 75 b0 00 00 08 7b 7b 22 69 64 22 3a 22 6e 6c 35 ... 2161 more bytes>
2019-11-07T10:51:01.647Z rhea:raw [connection-1] SENT: 2245 000008c502000001005314d00000001200000006437000000136a00333313043424200537045005371d10000000400000000005372d1000000040000000000537345005375b00000087b7b226964223a226e6c3539776730313236303531306363662d73686f742d7472616e736c61746564222c2274696d657374616d70223a22323031392d31312d30375431303a35313a30382e30313
92b30303a3030222c22736572696573223a5b7b2253686f7420636f756e746572223a31363036392c2253686f7420636f756e74657220626164223a31363036392c225061727420636f756e746572223a31333331323732302c225061727420636f756e74657220626164223a31303237373530302c2252656a65637420726561736f6e223a302c224e756d626572206f66206361766974696573223a382c224379636c652074696d65207365742076616c7565223a
302c224379636c652074696d65206c6173742076616c7565223a32322e382c22436f6f6c696e672074696d65223a382e30312c22486f6c64207072657373757265207065616b2031223a37342c22486f6c64207072657373757265207065616b2032223a35322e332c22496e6a656374696f6e207072657373757265207065616b2031223a3133332e392c22496e6a656374696f6e207072657373757265207065616b2032223a35312e362c224261636b207072657
373757265207065616b2031223a32362e332c224261636b207072657373757265207065616b2032223a382e322c224d6174657269616c20636f6e73756d7074696f6e2031223a3139312c224d6174657269616c20636f6e73756d7074696f6e2032223a302c22536372657720706f736974696f6e2031223a33372e322c22536372657720706f736974696f6e2032223a32362e382c22466c6f77206e756d6265722031223a313539392c22466c6f77206e756d6265
722032223a3539372e342c22496e6a656374696f6e2074696d652031223a302e38312c22496e6a656374696f6e2074696d652032223a302e35352c22506c6173746963697a696e672074696d652031223a332e30362c22506c6173746963697a696e672074696d652032223a322e38362c225377697463686f7665722070726573737572652031223a313436322e332c225377697463686f7665722070726573737572652032223a3932352e372c224d656c7420637
57368696f6e2031223a352e34342c224d656c742063757368696f6e2032223a352e31322c22496e6a656374696f6e207072657373757265207065616b2076616c7565223a3133332e392c22506c6173746963697a696e6720706f736974696f6e20656e64202d20636f72726563746564223a35382e352c22436c616d7020666f726365223a323231382e382c224d6f6c642070726f74656374696f6e2074696d652061637475616c2076616c7565223a312e30332c
224f696c2074656d7065726174757265223a33372c2254656d7065726174757265207a6f6e652031223a3238342e392c2254656d7065726174757265207a6f6e652032223a3239302c2254656d7065726174757265207a6f6e652033223a3238392e382c2254656d7065726174757265207a6f6e652034223a3238302c2254656d7065726174757265207a6f6e652035223a3236342e392c2254656d7065726174757265207a6f6e652036223a333237362e372c225
4656d7065726174757265207a6f6e652037223a35302e322c2254656d7065726174757265207a6f6e652038223a3330302e332c2254656d7065726174757265207a6f6e652039223a3239352e352c2254656d7065726174757265207a6f6e65203130223a3239352e332c2254656d7065726174757265207a6f6e65203131223a3239302e342c2254656d7065726174757265207a6f6e65203132223a3239352e342c2254656d7065726174757265207a6f6e652031
33223a3239352e352c2254656d7065726174757265207a6f6e65203134223a3239302e352c2254656d7065726174757265207a6f6e65203135223a3239352e322c2254656d7065726174757265207a6f6e65203136223a3232302e342c225365742074656d7065726174757265207a6f6e652031223a3238352c225365742074656d7065726174757265207a6f6e652032223a3239302c225365742074656d7065726174757265207a6f6e652033223a3238352c225
365742074656d7065726174757265207a6f6e652034223a3238302c225365742074656d7065726174757265207a6f6e652035223a3236352c225365742074656d7065726174757265207a6f6e652036223a302c225365742074656d7065726174757265207a6f6e652037223a35302c225365742074656d7065726174757265207a6f6e652038223a3238302c225365742074656d7065726174757265207a6f6e652039223a3237322c225365742074656d70657261
74757265207a6f6e65203130223a3238352c225365742074656d7065726174757265207a6f6e65203131223a3238352c225365742074656d7065726174757265207a6f6e65203132223a3238352c225365742074656d7065726174757265207a6f6e65203133223a3238332c225365742074656d7065726174757265207a6f6e65203134223a3238302c225365742074656d7065726174757265207a6f6e65203135223a3238322c225365742074656d70657261747
57265207a6f6e65203136223a3232382c2248656174696e6720656e657267792061637475616c2076616c7565206c617374206379636c65223a302e30323335313438392c2248656174696e6720656e6572677920636f6e73756d7074696f6e223a36323438312e342c224d6f746f7220656e657267792061637475616c2076616c7565206c617374206379636c65223a302e30313934373032382c224d6f746f7220656e6572677920636f6e73756d7074696f6e22
3a34343134322e322c22546f74616c20656e657267792061637475616c2076616c7565206c617374206379636c65223a302e30343239383531372c22546f74616c20656e6572677920636f6e73756d7074696f6e223a3130363632332e367d5d7d
2019-11-07T10:51:01.734Z rhea:io [connection-1] read 27 bytes
2019-11-07T10:51:01.734Z rhea:io [connection-1] got frame of size 27
2019-11-07T10:51:01.736Z rhea:raw [connection-1] RECV: 27 0000001b02000001005315c00e0641700000013640410053244540
2019-11-07T10:51:01.739Z rhea:frames [connection-1]:1 <- disposition#15 {"role":true,"first":310,"settled":true,"state":[]}
2019-11-07T10:51:01.739Z rhea:events [connection-1] Received disposition for outgoing transfers
2019-11-07T10:51:01.743Z rhea:events [connection-1] Link got event: accepted
2019-11-07T10:51:01.743Z rhea-promise:sender [connection-1] sender got event: 'accepted'. Re-emitting the translated context.
2019-11-07T10:51:01.745Z rhea-promise:translate [connection-1] Translating the context for event: 'accepted'.
2019-11-07T10:51:01.748Z azure:event-hubs:sender [connection-1] Sender '14cf9497-38ef-4970-a784-2f150a202935', got event accepted.
2019-11-07T10:51:01.748Z rhea:events [connection-1] Link got event: settled
2019-11-07T10:51:01.754Z rhea-promise:sender [connection-1] sender got event: 'settled'. Re-emitting the translated context.
2019-11-07T10:51:01.754Z rhea-promise:translate [connection-1] Translating the context for event: 'settled'.
2019-11-07T10:51:01.758Z azure:amqp-common:retry [connection-1] Success for 'sendMessage', after attempt number: 1.
INFO: Message send to azure
INFO: ccf-shot-translated, updating database nl59wg01180510ccf-shot-translated
INFO: Sending message to azure
2019-11-07T10:51:02.186Z azure:event-hubs:error [connection-1] Sender '14cf9497-38ef-4970-a784-2f150a202935' with address 'molding' is open? -> true
2019-11-07T10:51:02.187Z azure:amqp-common:datatransformer [encode] The given message body that needs to be encoded is:  { id: 'nl59wg01180510ccf-shot-translated',
  timestamp: '2019-11-07T10:51:08.641+00:00',
  series:
   [ { 'Shot counter': 436302,
       'Shot counter bad': 11158,
       'Reject reason': 0,
       'Number of cavities': 4,
       'Cycle time set value': 0,
       'Cycle time last value': 22,
       'Cooling time': 6.64,
       'Hold pressure peak 1': 49.2,
       'Injection pressure peak 1': 90.7,
       'Back pressure peak 1': 2.4,
       'Material consumption 1': 191,
       'Screw position 1': 75.4,
       'Flow number 1': 887.3,
       'Injection time 1': 0.89,
       'Plasticizing time 1': 5.19,
       'Switchover pressure 1': 752.2,
       'Melt cushion 1': 3.54,
       'Injection pressure peak value': 90.7,
       'Plasticizing position end - corrected': 70.8,
       'Clamp force': 1800.8,
       'Mold protection time actual value': 0.53,
       'Oil temperature': 38.8,
       'Temperature zone 1': 270.3,
       'Temperature zone 2': 270.3,
       'Temperature zone 3': 270.1,
       'Temperature zone 4': 270,
       'Temperature zone 5': 264.9,
       'Temperature zone 6': 3276.7,
       'Temperature zone 7': 49,
       'Temperature zone 8': 268.3,
       'Temperature zone 9': 275.3,
       'Temperature zone 10': 272.3,
       'Temperature zone 11': 269.9,
       'Temperature zone 12': 269.9,
       'Temperature zone 13': 269.9,
       'Temperature zone 14': 3276.7,
       'Temperature zone 15': 3276.7,
       'Temperature zone 16': 3276.7,
       'Set temperature zone 1': 270,
       'Set temperature zone 2': 270,
       'Set temperature zone 3': 270,
       'Set temperature zone 4': 270,
       'Set temperature zone 5': 265,
       'Set temperature zone 6': 0,
       'Set temperature zone 7': 50,
       'Set temperature zone 8': 268,
       'Set temperature zone 9': 275,
       'Set temperature zone 10': 272,
       'Set temperature zone 11': 270,
       'Set temperature zone 12': 270,
       'Set temperature zone 13': 270,
       'Set temperature zone 14': 0,
       'Set temperature zone 15': 0,
       'Set temperature zone 16': 0,
       'Heating energy actual value last cycle': 0.01670213,
       'Heating energy consumption': 60436.8,
       'Motor energy actual value last cycle': 0.02045314,
       'Motor energy consumption': 84731.9,
       'Total energy actual value last cycle': 0.03715529,
       'Total energy consumption': 145168.6 } ] }
2019-11-07T10:51:02.191Z azure:amqp-common:datatransformer [encode] The encoded message body is: Section {
  typecode: 117,
  content:
   <Buffer 7b 22 69 64 22 3a 22 6e 6c 35 39 77 67 30 31 31 38 30 35 31 30 63 63 66 2d 73 68 6f 74 2d 74 72 61 6e 73 6c 61 74 65 64 22 2c 22 74 69 6d 65 73 74 61 ... 1802 more bytes>,
  multiple: undefined }.
2019-11-07T10:51:02.191Z azure:amqp-common:retry [connection-1] Retry for 'sendMessage', attempt number: 1
2019-11-07T10:51:02.191Z azure:event-hubs:sender [connection-1] Sender '14cf9497-38ef-4970-a784-2f150a202935', credit: 289 available: 2048
2019-11-07T10:51:02.192Z azure:event-hubs:sender [connection-1] Sender '14cf9497-38ef-4970-a784-2f150a202935', sending message with id '<not specified>'.
2019-11-07T10:51:02.192Z rhea:message Encoding section 1 of 5: Typed { type: TypeDesc { name: 'List0', typecode: 69, width: 0, category: 1, create: { [Function] typecode: 69 } }, value: [], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value:
112 } }
2019-11-07T10:51:02.192Z rhea:message Encoding section 2 of 5: Typed { type: TypeDesc { name: 'Map32', typecode: 209, width: 4, category: 3, create: { [Function] typecode: 209 } }, value: [], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value
: 113 } }
2019-11-07T10:51:02.192Z rhea:message Encoding section 3 of 5: Typed { type: TypeDesc { name: 'Map32', typecode: 209, width: 4, category: 3, create: { [Function] typecode: 209 } }, value: [], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value
: 114 } }
2019-11-07T10:51:02.192Z rhea:message Encoding section 4 of 5: Typed { type: TypeDesc { name: 'List0', typecode: 69, width: 0, category: 1, create: { [Function] typecode: 69 } }, value: [], descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value:
115 } }
2019-11-07T10:51:02.192Z rhea:message Encoding section 5 of 5: Typed { type: TypeDesc { name: 'Vbin32', typecode: 176, width: 4, category: 2, create: { [Function] typecode: 176 } }, value: <Buffer 7b 22 69 64 22 3a 22 6e 6c 35 39 77 67 30 31 31 38 30 35 31 30 63 63 66 2d 73 68 6f 74 2d 74 72 61 6e 73 6c 61 74 65 64 22 2c 22 74 69 6d 65 73 74 61 ... 1802 more by
tes>, descriptor: Typed { type: TypeDesc { name: 'SmallUlong', typecode: 83, width: 1, category: 1, read: [Function: read], write: [Function: write], create: [Function] }, value: 117 } }
2019-11-07T10:51:02.192Z rhea:message encoded 1892 bytes
2019-11-07T10:51:02.192Z azure:event-hubs:sender [connection-1] Sender '14cf9497-38ef-4970-a784-2f150a202935', sent message with delivery id: 311 and tag: 311
2019-11-07T10:51:02.193Z rhea:frames [connection-1]:1 -> transfer#14 {"delivery_id":311,"delivery_tag":{"type":"Buffer","data":[51,49,49]}} <Buffer 00 53 70 45 00 53 71 d1 00 00 00 04 00 00 00 00 00 53 72 d1 00 00 00 04 00 00 00 00 00 53 73 45 00 53 75 b0 00 00 07 3c 7b 22 69 64 22 3a 22 6e 6c 35 ... 1842 more bytes>
2019-11-07T10:51:02.193Z rhea:raw [connection-1] SENT: 1926 0000078602000001005314d00000001200000006437000000137a00333313143424200537045005371d10000000400000000005372d1000000040000000000537345005375b00000073c7b226964223a226e6c3539776730313138303531306363662d73686f742d7472616e736c61746564222c2274696d657374616d70223a22323031392d31312d30375431303a35313a30382e36343
12b30303a3030222c22736572696573223a5b7b2253686f7420636f756e746572223a3433363330322c2253686f7420636f756e74657220626164223a31313135382c2252656a65637420726561736f6e223a302c224e756d626572206f66206361766974696573223a342c224379636c652074696d65207365742076616c7565223a302c224379636c652074696d65206c6173742076616c7565223a32322c22436f6f6c696e672074696d65223a362e36342c2248
6f6c64207072657373757265207065616b2031223a34392e322c22496e6a656374696f6e207072657373757265207065616b2031223a39302e372c224261636b207072657373757265207065616b2031223a322e342c224d6174657269616c20636f6e73756d7074696f6e2031223a3139312c22536372657720706f736974696f6e2031223a37352e342c22466c6f77206e756d6265722031223a3838372e332c22496e6a656374696f6e2074696d652031223a302
e38392c22506c6173746963697a696e672074696d652031223a352e31392c225377697463686f7665722070726573737572652031223a3735322e322c224d656c742063757368696f6e2031223a332e35342c22496e6a656374696f6e207072657373757265207065616b2076616c7565223a39302e372c22506c6173746963697a696e6720706f736974696f6e20656e64202d20636f72726563746564223a37302e382c22436c616d7020666f726365223a313830
302e382c224d6f6c642070726f74656374696f6e2074696d652061637475616c2076616c7565223a302e35332c224f696c2074656d7065726174757265223a33382e382c2254656d7065726174757265207a6f6e652031223a3237302e332c2254656d7065726174757265207a6f6e652032223a3237302e332c2254656d7065726174757265207a6f6e652033223a3237302e312c2254656d7065726174757265207a6f6e652034223a3237302c2254656d7065726
174757265207a6f6e652035223a3236342e392c2254656d7065726174757265207a6f6e652036223a333237362e372c2254656d7065726174757265207a6f6e652037223a34392c2254656d7065726174757265207a6f6e652038223a3236382e332c2254656d7065726174757265207a6f6e652039223a3237352e332c2254656d7065726174757265207a6f6e65203130223a3237322e332c2254656d7065726174757265207a6f6e65203131223a3236392e392c
2254656d7065726174757265207a6f6e65203132223a3236392e392c2254656d7065726174757265207a6f6e65203133223a3236392e392c2254656d7065726174757265207a6f6e65203134223a333237362e372c2254656d7065726174757265207a6f6e65203135223a333237362e372c2254656d7065726174757265207a6f6e65203136223a333237362e372c225365742074656d7065726174757265207a6f6e652031223a3237302c225365742074656d706
5726174757265207a6f6e652032223a3237302c225365742074656d7065726174757265207a6f6e652033223a3237302c225365742074656d7065726174757265207a6f6e652034223a3237302c225365742074656d7065726174757265207a6f6e652035223a3236352c225365742074656d7065726174757265207a6f6e652036223a302c225365742074656d7065726174757265207a6f6e652037223a35302c225365742074656d7065726174757265207a6f6e
652038223a3236382c225365742074656d7065726174757265207a6f6e652039223a3237352c225365742074656d7065726174757265207a6f6e65203130223a3237322c225365742074656d7065726174757265207a6f6e65203131223a3237302c225365742074656d7065726174757265207a6f6e65203132223a3237302c225365742074656d7065726174757265207a6f6e65203133223a3237302c225365742074656d7065726174757265207a6f6e6520313
4223a302c225365742074656d7065726174757265207a6f6e65203135223a302c225365742074656d7065726174757265207a6f6e65203136223a302c2248656174696e6720656e657267792061637475616c2076616c7565206c617374206379636c65223a302e30313637303231332c2248656174696e6720656e6572677920636f6e73756d7074696f6e223a36303433362e382c224d6f746f7220656e657267792061637475616c2076616c7565206c61737420
6379636c65223a302e30323034353331342c224d6f746f7220656e6572677920636f6e73756d7074696f6e223a38343733312e392c22546f74616c20656e657267792061637475616c2076616c7565206c617374206379636c65223a302e30333731353532392c22546f74616c20656e6572677920636f6e73756d7074696f6e223a3134353136382e367d5d7d
2019-11-07T10:51:02.379Z rhea:io [connection-1] read 27 bytes
2019-11-07T10:51:02.380Z rhea:io [connection-1] got frame of size 27
2019-11-07T10:51:02.380Z rhea:raw [connection-1] RECV: 27 0000001b02000001005315c00e0641700000013740410053244540
2019-11-07T10:51:02.380Z rhea:frames [connection-1]:1 <- disposition#15 {"role":true,"first":311,"settled":true,"state":[]}
2019-11-07T10:51:02.381Z rhea:events [connection-1] Received disposition for outgoing transfers
2019-11-07T10:51:02.381Z rhea:events [connection-1] Link got event: accepted
2019-11-07T10:51:02.381Z rhea-promise:sender [connection-1] sender got event: 'accepted'. Re-emitting the translated context.
2019-11-07T10:51:02.381Z rhea-promise:translate [connection-1] Translating the context for event: 'accepted'.
2019-11-07T10:51:02.381Z azure:event-hubs:sender [connection-1] Sender '14cf9497-38ef-4970-a784-2f150a202935', got event accepted.
2019-11-07T10:51:02.381Z rhea:events [connection-1] Link got event: settled
2019-11-07T10:51:02.381Z rhea-promise:sender [connection-1] sender got event: 'settled'. Re-emitting the translated context.
2019-11-07T10:51:02.381Z rhea-promise:translate [connection-1] Translating the context for event: 'settled'.
2019-11-07T10:51:02.382Z azure:amqp-common:retry [connection-1] Success for 'sendMessage', after attempt number: 1.
INFO: Message send to azure

@chradek
Copy link
Contributor

chradek commented Nov 7, 2019

@Evertvdw
Thanks for providing a sample of how you're sending events. It seems likely that you're seeing the Too much pending tasks error due to sending a large (> 10000) number of events right away.

This is because behind the scenes, the first time you call send or sendBatch, the SDK will create what's called a link to the service. To prevent extra links from being created, we acquire a lock on the link initialization and once that's complete subsequent calls will skip link initialization. The error message in the logs is coming from the locking mechanism since there are more than 10,000 send invocations attempting to acquire the lock.

There are a couple things you can do in your code to work around this.

One method that will be good overall for performance would be to batch your events so you make fewer send calls to the service. This will also reduce the number of link initializations that are attempted when you start sending events.
The sendBatch method takes in an array of events. You can batch events over a period of time, number of events, or a combination of the two. One thing to keep in mind while creating your batch is that there is a maximum event size based on your event hubs tier (256 KB for basic, 1 MB for standard), so you'll want to be careful that the accumulated size of the events in your batch doesn't exceed this limit.

Another thing you could do is make 1 send/sendBatch call to create the link, then allow subsequent send/sendBatch calls to occur in parallel. Doing this combined with the method above should give you the best results.

As you were hinting, waiting for a send to complete before receiving another event to send should also alleviate the problem, though may also have lower throughput than the above options.

@Evertvdw
Copy link
Author

Thank you for the explanation, will close this issue.

@ghost
Copy link

ghost commented Nov 18, 2019

Thanks for working with Microsoft on GitHub! Tell us how you feel about your experience using the reactions on this comment.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Client This issue points to a problem in the data-plane of the library. customer-reported Issues that are reported by GitHub users external to the Azure organization. Event Hubs Service Attention Workflow: This issue is responsible by Azure service team.
Projects
None yet
Development

No branches or pull requests

6 participants