centreon / centreon-broker

A full-featured monitoring event broker, compatible with MySQL, RRDtool, Graphite and more
Apache License 2.0
37 stars 15 forks source link

Broker Error Log: feeder: error occured while processing client #131

Open itsul opened 6 years ago

itsul commented 6 years ago

Hi,

one of our customer has sometimes problems with a outside poller connection. Sometimes the status icon from the display counter is in a red/error state. While the problem was present the vpn was working fine and a test telnet connection to bbdo port 5669 was successfully. Only the broker itself was disconnected. We investigated much time in troubleshooting and increased the log. The monitoring system is the only system with problems, other applications are working well via VPN include important applications like SAP ( user will report immediately if an error occured).

Display Poller Broker Logsettings: grafik

Centreon Versions: centreon-broker-cbmod-3.0.8-1.el6.x86_64 centreon-broker-storage-3.0.8-1.el6.x86_64 centreon-syslog-frontend-1.5.4-1.el6.noarch centreon-engine-1.7.2-3.el6.x86_64 centreon-connector-1.1.2-1.el6.x86_64 centreon-common-2.8.12-7.el6.noarch centreon-bam-server-3.5.5-1.el6.noarch centreon-bi-server-3.1.5-1.el6.noarch centreon-broker-3.0.8-1.el6.x86_64 centreon-connector-ssh-1.1.2-1.el6.x86_64 centreon-perl-libs-2.8.12-7.el6.noarch centreon-poller-centreon-engine-2.8.12-7.el6.noarch centreon-pp-manager-2.2.0-4.el6.noarch centreon-2.8.12-7.el6.noarch centreon-engine-daemon-1.7.2-3.el6.x86_64 centreon-connector-perl-1.1.2-1.el6.x86_64 centreon-release-3.4-4.el6.noarch centreon-base-config-centreon-engine-2.8.12-7.el6.noarch centreon-syslog-server-1.2.5-6.el6.noarch centreon-engine-extcommands-1.7.2-3.el6.x86_64 centreon-broker-cbd-3.0.8-1.el6.x86_64 centreon-clib-1.4.2-1.el6.x86_64 centreon-broker-core-3.0.8-1.el6.x86_64 centreon-trap-2.8.12-7.el6.noarch centreon-web-2.8.12-7.el6.noarch centreon-license-manager-1.0.1-3.el6.noarch

OS: CentOS 6.9

Additional environment details :Hardware maschine with a central and a display poller. Display poller is located in the US and connected via MPLS from Telekom.

Broker log from display poller with a human readable dateformat: [Thu Sep 28 06:23:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13866': TCP peer '1.2.3.4:37084' is disconnected [Thu Sep 28 06:28:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13867': TCP peer '1.2.3.4:38130' is disconnected [Thu Sep 28 06:33:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13868': TCP peer '1.2.3.4:39174' is disconnected [Thu Sep 28 06:38:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13869': TCP peer '1.2.3.4:40220' is disconnected [Thu Sep 28 06:43:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13870': TCP peer '1.2.3.4:41272' is disconnected [Thu Sep 28 06:48:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13871': TCP peer '1.2.3.4:42326' is disconnected [Thu Sep 28 06:53:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13872': TCP peer '1.2.3.4:43376' is disconnected [Thu Sep 28 06:58:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13873': TCP peer '1.2.3.4:44426' is disconnected [Thu Sep 28 07:03:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13874': TCP peer '1.2.3.4:45478' is disconnected [Thu Sep 28 07:08:10 2017] error: feeder: error occured while processing client 'central-broker-master-input-13875': TCP peer '1.2.3.4:46524' is disconnected [Thu Sep 28 07:13:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13876': TCP peer '1.2.3.4:47568' is disconnected [Thu Sep 28 07:18:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13877': TCP peer '1.2.3.4:48616' is disconnected [Thu Sep 28 07:23:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13878': TCP peer '1.2.3.4:49668' is disconnected [Thu Sep 28 07:28:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13879': TCP peer '1.2.3.4:50714' is disconnected [Thu Sep 28 07:33:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13880': TCP peer '1.2.3.4:51766' is disconnected [Thu Sep 28 07:38:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13881': TCP peer '1.2.3.4:52812' is disconnected [Thu Sep 28 07:43:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13882': TCP peer '1.2.3.4:53864' is disconnected [Thu Sep 28 07:48:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13883': TCP peer '1.2.3.4:54916' is disconnected [Thu Sep 28 07:53:09 2017] error: feeder: error occured while processing client 'central-broker-master-input-13884': TCP peer '1.2.3.4:55966' is disconnected

The log reports every few minutes problems with the connection but the status of the display counter is ok. The problem is rare and sporadic, log is constant.

grafik

Regards

bouda1 commented 6 years ago

Hi,

During a such situation, did you try to keep telnet running long enough ? Is it not interrupted after several minutes ?

Another question, on your poller output you can configure the retry interval to reduce the time between too connections. Did you try to change it with a small value, 5 seconds or so ?

Regards.

itsul commented 6 years ago

Hi,

the last time we changed the value to 60. Since this moment, there are only 2 log entries since today night. Much better than before. Now we changed the value to 5 as you suggested.

Let`s wait a couple of days, what happen in the logs.

Regards

itsul commented 6 years ago

Unfortunately the log will be filled every few seconds: [Fri Oct 20 12:48:20 2017] error: feeder: error occured while processing client 'central-broker-master-input-4694': TCP peer '10.1.1.1:53796' is disconnected [Fri Oct 20 12:53:19 2017] error: feeder: error occured while processing client 'central-broker-master-input-4695': TCP peer '10.1.1.1:54894' is disconnected [Fri Oct 20 12:58:19 2017] error: feeder: error occured while processing client 'central-broker-master-input-4696': TCP peer '10.1.1.1:55998' is disconnected [Fri Oct 20 13:03:19 2017] error: feeder: error occured while processing client 'central-broker-master-input-4697': TCP peer '10.1.1.1:57098' is disconnected [Fri Oct 20 13:08:19 2017] error: feeder: error occured while processing client 'central-broker-master-input-4698': TCP peer '10.1.1.1:58194' is disconnected [Fri Oct 20 13:13:19 2017] error: feeder: error occured while processing client 'central-broker-master-input-4699': TCP peer '10.1.1.1:59290' is disconnected [Fri Oct 20 13:18:19 2017] error: feeder: error occured while processing client 'central-broker-master-input-4700': TCP peer '10.1.1.1:60386' is disconnected [Fri Oct 20 13:23:19 2017] error: feeder: error occured while processing client 'central-broker-master-input-4701': TCP peer '10.1.1.1:33250' is disconnected [Fri Oct 20 13:28:19 2017] error: feeder: error occured while processing client 'central-broker-master-input-4702': TCP peer '10.1.1.1:34356' is disconnected [Fri Oct 20 13:33:20 2017] error: feeder: error occured while processing client 'central-broker-master-input-4703': TCP peer '10.1.1.1:35458' is disconnected [Fri Oct 20 13:38:21 2017] error: feeder: error occured while processing client 'central-broker-master-input-4704': TCP peer '10.1.1.1:36564' is disconnected [Fri Oct 20 13:43:21 2017] error: feeder: error occured while processing client 'central-broker-master-input-4705': TCP peer '10.1.1.1:37662' is disconnected [Fri Oct 20 13:48:21 2017] error: feeder: error occured while processing client 'central-broker-master-input-4706': TCP peer '10.1.1.1:38758' is disconnected [Fri Oct 20 13:53:21 2017] error: feeder: error occured while processing client 'central-broker-master-input-4707': TCP peer '10.1.1.1:39852' is disconnected [Fri Oct 20 13:58:22 2017] error: feeder: error occured while processing client 'central-broker-master-input-4708': TCP peer '10.1.1.1:40950' is disconnected [Fri Oct 20 14:03:21 2017] error: feeder: error occured while processing client 'central-broker-master-input-4709': TCP peer '10.1.1.1:42050' is disconnected [Fri Oct 20 14:08:21 2017] error: feeder: error occured while processing client 'central-broker-master-input-4710': TCP peer '10.1.1.1:43150' is disconnected [Fri Oct 20 14:13:21 2017] error: feeder: error occured while processing client 'central-broker-master-input-4711': TCP peer '10.1.1.1:44244' is disconnected [Fri Oct 20 14:18:21 2017] error: feeder: error occured while processing client 'central-broker-master-input-4712': TCP peer '10.1.1.1:45344' is disconnected [Fri Oct 20 14:23:21 2017] error: feeder: error occured while processing client 'central-broker-master-input-4713': TCP peer '10.1.1.1:46438' is disconnected [Fri Oct 20 14:28:21 2017] error: feeder: error occured while processing client 'central-broker-master-input-4714': TCP peer '10.1.1.1:47534' is disconnected [Fri Oct 20 14:33:22 2017] error: feeder: error occured while processing client 'central-broker-master-input-4715': TCP peer '10.1.1.1:48630' is disconnected

alvaro-octal commented 6 years ago

It seems to be similar, my poller shows as not running and none of its host appear at the monitoring tab:

OS: CentOS 7.4 (AArch64) centreon-engine: 1.8.1 centreon-broker: 3.0.12

Every time I restart the poller's cbd it shows this at central cbd: /var/log/centreon-broker/central-broker-master.log (note that poller has id 2 not 1)

[1514117240] info:    storage: committing transaction
[1514117240] info:    SQL: committing transaction
[1514117240] info:    SQL: processing poller status event (id: 1, last alive: 1514117240)
[1514117240] info:    SQL: committing transaction
[1514117240] info:    storage: committing transaction
[1514117241] info:    storage: committing transaction
[1514117241] info:    SQL: committing transaction
[1514117241] info:    SQL: processing poller status event (id: 1, last alive: 1514117241)
[1514117241] info:    SQL: committing transaction
[1514117241] info:    storage: committing transaction
[1514117241] error:   feeder: error occured while processing client 'central-broker-master-input-15': TCP peer '1.2.3.4:37692' is disconnected
[1514117241] info:    feeder: thread of client 'central-broker-master-input-15' will exit
[1514117242] info:    storage: committing transaction
[1514117242] info:    SQL: committing transaction
[1514117243] info:    storage: committing transaction
[1514117243] info:    SQL: committing transaction
[1514117244] info:    storage: committing transaction
[1514117244] info:    SQL: committing transaction
[1514117244] info:    TCP: new client connected
[1514117244] info:    file: opening new file '/var/lib/centreon-broker//central-broker-master.queue.central-broker-master-input-16'
[1514117244] info:    file: end of file '/var/lib/centreon-broker//central-broker-master.queue.central-broker-master-input-16' reached, erasing file
[1514117244] info:    multiplexing: 'central-broker-master-input-16' start with 0 in queue and the queue file is disable
[1514117244] info:    feeder: thread of client 'central-broker-master-input-16' is starting
[1514117244] info:    BBDO: peer is using protocol version 2.0.0, we're using version 2.0.0
[1514117244] info:    BBDO: we have extensions 'compression' and peer has ''
[1514117244] info:    SQL: committing transaction
[1514117244] info:    storage: committing transaction
lpinsivy commented 6 years ago

Hi,

For your Centreon Broker output on distant poller:

Regards,

itsul commented 6 years ago

Hi,

find the requested information below:

image

image

Regards

bouda1 commented 6 years ago

The error tag is too much in those logs. The connection is lost, broker or cbd see that, the connection is established again and data are sent. Maybe we could just write a medium log information and an error could arise when the new connection fails.