Project

General

Profile

Actions

action #40652

closed

AMQP on openqa.opensuse.org disfunctional

Added by coolo over 6 years ago. Updated over 6 years ago.

Status:
Resolved
Priority:
Normal
Assignee:
-
Category:
Regressions/Crashes
Target version:
Start date:
2018-09-06
Due date:
% Done:

0%

Estimated time:

Description

We had this before and I disabled the plugin there back then. dheidler wanted to see the problem,
so I reenabled it (rather recently) and now it's broken again.

Problem is: we need these events for staging workflow really soon now, so this needs fixing

[2018-08-10T03:58:04.0601 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:04.0602 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:04.0715 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:04.0716 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:04.0739 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:04.0739 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:04.0861 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:04.0861 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:04.0894 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:04.0894 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:05.0013 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:05.0013 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:05.0043 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:05.0044 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:05.0155 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:05.0155 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:05.0210 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:05.0210 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:05.0301 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:05.0305 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:05.0348 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:05.0349 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:05.0462 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:05.0463 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:05.0483 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:05.0483 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:05.0625 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:05.0625 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:05.0643 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:05.0643 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:05.0785 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:05.0786 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:05.0813 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:05.0814 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:05.0934 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:05.0935 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:06.0086 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:06.0086 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:06.0169 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:06.0170 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:06.0225 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:06.0225 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:06.0332 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:06.0334 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:06.0389 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:06.0390 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:06.0474 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:06.0475 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:06.0557 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:06.0558 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:06.0631 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:06.0631 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:06.0711 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:06.0712 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:06.0844 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:06.0844 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:06.0874 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:06.0876 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:07.0007 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:07.0007 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:07.0019 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:07.0019 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:07.0146 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:07.0146 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:07.0170 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:07.0171 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:07.0297 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:07.0298 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:07.0303 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:07.0304 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:07.0471 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:07.0472 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:07.0474 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:07.0474 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:07.0634 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:07.0634 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:07.0639 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:07.0640 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:07.0799 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:07.0800 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:07.0821 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:07.0822 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:07.0937 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:07.0937 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:07.0979 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:07.0980 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:08.0075 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:08.0075 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:08.0140 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:08.0140 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:08.0234 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:08.0234 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:08.0323 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:08.0323 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:08.0401 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:08.0402 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:08.0459 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:08.0460 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:08.0554 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:08.0554 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:08.0619 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:08.0620 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:08.0695 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:08.0695 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:08.0732 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:08.0732 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:08.0826 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:08.0827 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:08.0850 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:08.0850 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:08.0900 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:08.0900 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:09.0006 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:09.0010 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:09.0018 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:09.0018 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:09.0068 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:09.0068 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:09.0186 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:09.0187 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:09.0202 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:09.0203 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:09.0233 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:09.0234 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:09.0336 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:09.0336 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:09.0345 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:09.0345 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:09.0420 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:09.0420 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:09.0483 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:09.0484 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:09.0504 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:09.0505 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:09.0575 UTC] [warn] AMQP connection closed
[2018-08-10T03:58:09.0575 UTC] [info] AMQP reconnecting in 5 seconds
[2018-08-10T03:58:09.0667 UTC] [warn] AMQP connection closed

Related issues 1 (0 open1 closed)

Related to openQA Project (public) - action #52961: error messages from RabbitMQ "(in cleanup) Can't call method "_handle" on an undefined value" and moreResolvedokurz2019-06-12

Actions
Actions #1

Updated by coolo over 6 years ago

  • Priority changed from High to Urgent
  • Target version set to Current Sprint
  • Difficulty set to medium

this looks the same on osd

Actions #2

Updated by coolo over 6 years ago

Marius and me instrumented the code a little and we found out what the problem is: artefact chunk uploads.

create_artefact creates a subprocess for every chunk - and as such forks a lot of small processes. Each of these processes gets a AMQP disconnect
as the stream is destroyed in the child. As such: subprocess considered harmful

[2018-09-11T19:51:57.0287 CEST] [info] Forking 27114
[2018-09-11T19:51:57.0345 CEST] [warn] AMQP connection closed due disconnect (pid 27115)
[2018-09-11T19:51:57.0348 CEST] [warn] longmess at /usr/lib/perl5/vendor_perl/5.18.2/Mojo/EventEmitter.pm line 15.
        Mojo::EventEmitter::emit('Mojo::RabbitMQ::Client=HASH(0x9003310)', 'disconnect') called at /usr/lib/perl5/vendor_perl/5.18.2/Mojo/RabbitMQ/Client.pm line 269
        Mojo::RabbitMQ::Client::_handle('Mojo::RabbitMQ::Client=HASH(0x9003310)', 'c86647e614a7a94b6156bc1d8a0dca69', 1) called at /usr/lib/perl5/vendor_perl/5.18.2/Mojo/RabbitMQ/Client.pm line 384
        Mojo::RabbitMQ::Client::__ANON__('Mojo::IOLoop::Stream=HASH(0x91c74d8)') called at /usr/lib/perl5/vendor_perl/5.18.2/Mojo/EventEmitter.pm line 15
        Mojo::EventEmitter::emit('Mojo::IOLoop::Stream=HASH(0x91c74d8)', 'close') called at /usr/lib/perl5/vendor_perl/5.18.2/Mojo/IOLoop/Stream.pm line 21
        Mojo::IOLoop::Stream::close('Mojo::IOLoop::Stream=HASH(0x91c74d8)') called at /usr/lib/perl5/vendor_perl/5.18.2/Mojo/IOLoop/Stream.pm line 11
        Mojo::IOLoop::Stream::DESTROY('Mojo::IOLoop::Stream=HASH(0x91c74d8)') called at /usr/lib/perl5/vendor_perl/5.18.2/Mojo/IOLoop.pm line 101
        eval {...} called at /usr/lib/perl5/vendor_perl/5.18.2/Mojo/IOLoop.pm line 101
        Mojo::IOLoop::reset('Mojo::IOLoop=HASH(0x1c42928)') called at /usr/lib/perl5/vendor_perl/5.18.2/Mojo/IOLoop/Subprocess.pm line 38
        Mojo::IOLoop::Subprocess::_start('Mojo::IOLoop::Subprocess=HASH(0x9e26b40)', 'CODE(0x99807c0)', 'CODE(0x9946488)') called at /usr/lib/perl5/vendor_perl/5.18.2/Mojo/IOLoop/Subprocess.pm line 18
        Mojo::IOLoop::Subprocess::__ANON__('Mojo::IOLoop=HASH(0x1c42928)') called at /usr/lib/perl5/vendor_perl/5.18.2/Mojo/IOLoop.pm line 81
Actions #3

Updated by coolo over 6 years ago

  • Priority changed from Urgent to Normal
  • Target version deleted (Current Sprint)

We found out that this disconnect is just noisy in the logs due to subprocess - but it doesn't look like we loose AMQP messages.
As such I lower the priority

Actions #4

Updated by coolo over 6 years ago

Actions #5

Updated by coolo over 6 years ago

  • Status changed from New to Resolved
  • Target version set to Done
Actions #6

Updated by okurz over 5 years ago

  • Related to action #52961: error messages from RabbitMQ "(in cleanup) Can't call method "_handle" on an undefined value" and more added
Actions

Also available in: Atom PDF