Stuck after queue locked

Question

Stuck after queue locked

Closed this issue 3 years ago · 2 comments

Two examples from today:

LMG source

Apr 29 23:04:12 energy lmgd[65923]: [2021-04-29 23:04:12.646838037 CEST][FATAL]: LMG failed to send values within the last 10 seconds. Assuming the connection died.
Apr 29 23:04:12 energy lmgd[65923]: [2021-04-29 23:04:12.647154012 CEST][ INFO]: Stop recording
Apr 29 23:04:12 energy lmgd[65923]: [2021-04-29 23:04:12.647255302 CEST][DEBUG]: Sending command: :INIT:CONT OFF;*opc?
Apr 29 23:04:12 energy lmgd[65923]: [2021-04-29 23:04:12.647372557 CEST][DEBUG]: Sending command: *rst
Apr 29 23:04:12 energy lmgd[65923]: [2021-04-29 23:04:12.647476132 CEST][DEBUG]: Sending command: gtl
Apr 29 23:04:12 energy lmgd[65923]: [2021-04-29 23:04:12.667086899 CEST][FATAL]: Connection to LMG timed out
Apr 29 23:04:12 energy systemd[1]: metricq-source-lmg-450A.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Apr 29 23:04:12 energy systemd[1]: metricq-source-lmg-450A.service: Failed with result 'exit-code'.
Apr 29 23:04:22 energy systemd[1]: metricq-source-lmg-450A.service: Scheduled restart job, restart counter is at 3.
Apr 29 23:04:22 energy systemd[1]: Stopped MetricQ lmgd 450A.
Apr 29 23:04:22 energy systemd[1]: Started MetricQ lmgd 450A.
Apr 29 23:04:22 energy lmgd[85975]: [2021-04-29 23:04:22.758103170 CEST][DEBUG]: Called lmgd::Source::Source()
Apr 29 23:04:22 energy lmgd[85975]: [2021-04-29 23:04:22.764221626 CEST][metricq][ INFO]: connecting to management server: amqps://XXX:XXX@rabbitmq.metricq.zih.tu-dresden.de/
Apr 29 23:04:22 energy lmgd[85975]: [2021-04-29 23:04:22.765341699 CEST][metricq][DEBUG]: Using SSL-secured connection.
Apr 29 23:04:22 energy lmgd[85975]: [2021-04-29 23:04:22.767096725 CEST][metricq][DEBUG]: resolved rabbitmq.metricq.zih.tu-dresden.de to 141.76.39.250:5671
Apr 29 23:04:22 energy lmgd[85975]: [2021-04-29 23:04:22.767193267 CEST][metricq][DEBUG]: resolved rabbitmq.metricq.zih.tu-dresden.de to 141.76.19.184:5671
Apr 29 23:04:22 energy lmgd[85975]: [2021-04-29 23:04:22.767278470 CEST][metricq][DEBUG]: resolved rabbitmq.metricq.zih.tu-dresden.de to 141.76.19.152:5671
Apr 29 23:04:22 energy lmgd[85975]: [2021-04-29 23:04:22.768003296 CEST][metricq][DEBUG]: Established connection to rabbitmq.metricq.zih.tu-dresden.de at 141.76.39.250:5671
Apr 29 23:04:22 energy lmgd[85975]: [2021-04-29 23:04:22.780502482 CEST][metricq][DEBUG]: SSL handshake was successful.
Apr 29 23:04:22 energy lmgd[85975]: [2021-04-29 23:04:22.825759779 CEST][metricq][DEBUG]: Negotiated heartbeat interval to 60 seconds
Apr 29 23:04:22 energy lmgd[85975]: [2021-04-29 23:04:22.871956147 CEST][metricq][DEBUG]: ConnectionHandler::onReady
Apr 29 23:04:22 energy lmgd[85975]: [2021-04-29 23:04:22.873265634 CEST][metricq][DEBUG]: management channel ready
Apr 29 23:04:22 energy lmgd[85975]: [2021-04-29 23:04:22.878339587 CEST][metricq][ERROR]: management channel error: RESOURCE_LOCKED - cannot obtain exclusive access to locked queue 'source-elab-lmg450A-rpc' in vhost '/'. It could be originally declared on another connection or the>
Apr 30 09:12:36 energy lmgd[85975]: [2021-04-30 09:12:36.569814237 CEST][ INFO]: Caught signal 15. Shutdown.

Apr 30 03:16:03 igel metricq-combinator[764]: [2021-04-30 03:16:03.761335446 CEST][metricq][ERROR]: [Data connection] read failed: stream truncated
Apr 30 03:16:03 igel metricq-combinator[764]: [2021-04-30 03:16:03.761543204 CEST][metricq][ERROR]: data channel error: stream truncated
Apr 30 03:16:03 igel metricq-combinator[764]: [2021-04-30 03:16:03.761587260 CEST][metricq][DEBUG]: [Data connection] ConnectionHandler::onError: read failed
Apr 30 03:16:04 igel metricq-combinator[764]: [2021-04-30 03:16:04.463928345 CEST][metricq][ INFO]: sink data queue consume finalize
Apr 30 03:16:04 igel metricq-combinator[764]: [2021-04-30 03:16:04.472657619 CEST][ERROR]: Unhandled exception: ConnectionHandler::onError: read failed
Apr 30 03:16:04 igel systemd[1]: metricq-combinator-lzr.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Apr 30 03:16:04 igel systemd[1]: metricq-combinator-lzr.service: Unit entered failed state.
Apr 30 03:16:04 igel systemd[1]: metricq-combinator-lzr.service: Failed with result 'exit-code'.
Apr 30 03:16:14 igel systemd[1]: metricq-combinator-lzr.service: Service hold-off time over, scheduling restart.
Apr 30 03:16:14 igel systemd[1]: Stopped MetricQ combinator for LZR.
Apr 30 03:16:14 igel systemd[1]: Started MetricQ combinator for LZR.
Apr 30 03:16:14 igel metricq-combinator[103810]: [2021-04-30 03:16:14.678610550 CEST][metricq][ INFO]: connecting to management server: amqps://XXX:XXX@rabbitmq.metricq.zih.tu-dresden.de/
Apr 30 03:16:14 igel metricq-combinator[103810]: [2021-04-30 03:16:14.689634786 CEST][metricq][DEBUG]: [Mgmt connection] Using SSL-secured connection.
Apr 30 03:16:14 igel metricq-combinator[103810]: [2021-04-30 03:16:14.689766193 CEST][ INFO]: MetricQ version metricq-cpp/1.0.0-17-g7eda32e-dirty
Apr 30 03:16:14 igel metricq-combinator[103810]: [2021-04-30 03:16:14.689786399 CEST][ INFO]: starting main loop...
Apr 30 03:16:14 igel metricq-combinator[103810]: [2021-04-30 03:16:14.690848861 CEST][metricq][DEBUG]: [Mgmt connection] resolved rabbitmq.metricq.zih.tu-dresden.de to 141.76.19.184:5671
Apr 30 03:16:14 igel metricq-combinator[103810]: [2021-04-30 03:16:14.690874721 CEST][metricq][DEBUG]: [Mgmt connection] resolved rabbitmq.metricq.zih.tu-dresden.de to 141.76.19.152:5671
Apr 30 03:16:14 igel metricq-combinator[103810]: [2021-04-30 03:16:14.690887393 CEST][metricq][DEBUG]: [Mgmt connection] resolved rabbitmq.metricq.zih.tu-dresden.de to 141.76.39.250:5671
Apr 30 03:16:14 igel metricq-combinator[103810]: [2021-04-30 03:16:14.694996120 CEST][metricq][DEBUG]: [Mgmt connection] Established connection to rabbitmq.metricq.zih.tu-dresden.de at 141.76.19.184:5671
Apr 30 03:16:14 igel metricq-combinator[103810]: [2021-04-30 03:16:14.706643287 CEST][metricq][DEBUG]: [Mgmt connection] SSL handshake was successful.
Apr 30 03:16:14 igel metricq-combinator[103810]: [2021-04-30 03:16:14.709021194 CEST][metricq][DEBUG]: [Mgmt connection] Negotiated heartbeat interval to 60 seconds
Apr 30 03:16:14 igel metricq-combinator[103810]: [2021-04-30 03:16:14.756681112 CEST][metricq][DEBUG]: [Mgmt connection] ConnectionHandler::onReady
Apr 30 03:16:14 igel metricq-combinator[103810]: [2021-04-30 03:16:14.757812418 CEST][metricq][DEBUG]: management channel ready
Apr 30 03:16:14 igel metricq-combinator[103810]: [2021-04-30 03:16:14.758737011 CEST][metricq][ERROR]: management channel error: RESOURCE_LOCKED - cannot obtain exclusive access to locked queue 'transformer-lzr-combinator-rpc' in vhost '/'. It could be originally declared on anothe
Apr 30 08:59:00 igel systemd[1]: Stopping MetricQ combinator for LZR...

Answer 1 · 2021-05-31T12:25:12.000Z

After trying to fix this in metricq-combinator, it seems like this has already been fixed with 2164b07 and b5ce1d8.

We should check that all clients have an up-to-date metricq dependency.

Answer 2 · 2021-06-01T12:22:18.000Z

Closing this for now as this has been resolved (as per the above comment).