action #40652
closedAMQP on openqa.opensuse.org disfunctional
0%
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
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
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
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
Updated by coolo over 6 years ago
https://github.com/os-autoinst/openQA/pull/1786 works around the issue
Updated by coolo over 6 years ago
- Status changed from New to Resolved
- Target version set to Done
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