1522815 - write_graphite plugin: send to graphite1.private.mdc2.mozilla.com:2003 (tcp) failed with status -1 (Broken pipe)

Status: RESOLVED WONTFIX

(Infrastructure & Operations :: RelOps: General, task)

Description

[Attila Craciun [:arny]]

I see this on all Linux MS, should we worry?

Jan 25 04:37:09 t-linux64-ms-402.test.releng.mdc2.mozilla.com collectd: write_graphite plugin: send to graphite1.private.mdc2.mozilla.com:2003 (tcp) failed with status -1 (Broken pipe)
Jan 25 04:37:09 t-linux64-ms-402.test.releng.mdc2.mozilla.com collectd: Filter subsystem: Built-in target `write': Dispatching value to the `write_graphite/graphite1.private.mdc2.mozilla.com' plugin failed with status -1.
Jan 25 04:37:09 t-linux64-ms-402.test.releng.mdc2.mozilla.com collectd: Available write targets: ['write_graphite/graphite1.private.mdc2.mozilla.com']
Jan 25 04:37:10 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:37:10 Disk available: 198706466816 bytes
Jan 25 04:37:35 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:37:35 Disk available: 198706466816 bytes
Jan 25 04:37:40 t-linux64-ms-402.test.releng.mdc2.mozilla.com collectd: Filter subsystem: Built-in target `write': Plugin `write_graphite/graphite1.private.mdc2.mozilla.com' is back to normal operation. `write' succeeded.
Jan 25 04:37:56 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:37:56 No task claimed. Idle for 17m41.899855883s (will exit if no task claimed in 95h42m18.100144117s). 1 more tasks to run before exiting.
Jan 25 04:38:01 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:38:01 Disk available: 198706466816 bytes
Jan 25 04:38:26 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:38:26 Disk available: 198706466816 bytes
Jan 25 04:38:51 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:38:51 Disk available: 198706466816 bytes
Jan 25 04:39:12 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:39:12 No task claimed. Idle for 18m57.951123031s (will exit if no task claimed in 95h41m2.048876969s). 1 more tasks to run before exiting.
Jan 25 04:39:17 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:39:17 Disk available: 198706466816 bytes
Jan 25 04:39:42 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:39:42 Disk available: 198706466816 bytes
Jan 25 04:40:07 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:40:07 Disk available: 198706466816 bytes
Jan 25 04:40:28 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:40:28 No task claimed. Idle for 20m13.900358052s (will exit if no task claimed in 95h39m46.099641948s). 1 more tasks to run before exiting.
Jan 25 04:40:33 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:40:33 Disk available: 198706466816 bytes
Jan 25 04:40:58 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:40:58 Disk available: 198706466816 bytes
Jan 25 04:41:24 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:41:23 Disk available: 198706466816 bytes
Jan 25 04:41:44 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:41:44 No task claimed. Idle for 21m29.961373075s (will exit if no task claimed in 95h38m30.038626925s). 1 more tasks to run before exiting.
Jan 25 04:41:49 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:41:49 Disk available: 198706466816 bytes
Jan 25 04:42:09 t-linux64-ms-402.test.releng.mdc2.mozilla.com collectd: write_graphite plugin: send to graphite1.private.mdc2.mozilla.com:2003 (tcp) failed with status -1 (Broken pipe)
Jan 25 04:42:09 t-linux64-ms-402.test.releng.mdc2.mozilla.com collectd: Filter subsystem: Built-in target `write': Dispatching value to the `write_graphite/graphite1.private.mdc2.mozilla.com' plugin failed with status -1.
Jan 25 04:42:09 t-linux64-ms-402.test.releng.mdc2.mozilla.com collectd: Available write targets: ['write_graphite/graphite1.private.mdc2.mozilla.com']
Jan 25 04:42:10 t-linux64-ms-402.test.releng.mdc2.mozilla.com collectd: Filter subsystem: Built-in target `write': Plugin `write_graphite/graphite1.private.mdc2.mozilla.com' is back to normal operation. `write' succeeded.
Jan 25 04:42:14 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:42:14 Disk available: 198706462720 bytes
Jan 25 04:42:39 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:42:39 Disk available: 198706462720 bytes
Jan 25 04:43:00 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:43:00 No task claimed. Idle for 22m45.891059062s (will exit if no task claimed in 95h37m14.108940938s). 1 more tasks to run before exiting.
Jan 25 04:43:05 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:43:05 Disk available: 198706462720 bytes
Jan 25 04:43:30 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:43:30 Disk available: 198706462720 bytes
Jan 25 04:43:55 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:43:55 Disk available: 198706462720 bytes
Jan 25 04:44:16 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:44:16 No task claimed. Idle for 24m1.857610374s (will exit if no task claimed in 95h35m58.142389626s). 1 more tasks to run before exiting.
Jan 25 04:44:21 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:44:21 Disk available: 198706462720 bytes
Jan 25 04:44:46 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:44:46 Disk available: 198706462720 bytes
Jan 25 04:45:12 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:45:12 Disk available: 198706462720 bytes
Jan 25 04:45:32 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:45:32 No task claimed. Idle for 25m18.132290213s (will exit if no task claimed in 95h34m41.867709787s). 1 more tasks to run before exiting.
Jan 25 04:45:37 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:45:37 Disk available: 198706462720 bytes
Jan 25 04:46:02 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:46:02 Disk available: 198706462720 bytes
Jan 25 04:46:28 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:46:28 Disk available: 198706462720 bytes
Jan 25 04:46:43 t-linux64-ms-402.test.releng.mdc2.mozilla.com kernel: [ 1779.869830] usb 1-1: USB disconnect, device number 2
Jan 25 04:46:43 t-linux64-ms-402.test.releng.mdc2.mozilla.com acpid: input device has been disconnected, fd 5
Jan 25 04:46:44 t-linux64-ms-402.test.releng.mdc2.mozilla.com dbus: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service'
Jan 25 04:46:44 t-linux64-ms-402.test.releng.mdc2.mozilla.com dbus: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.Avahi.service': Unit dbus-org.freedesktop.Avahi.service not found.
Jan 25 04:46:46 t-linux64-ms-402.test.releng.mdc2.mozilla.com dbus: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service'
Jan 25 04:46:46 t-linux64-ms-402.test.releng.mdc2.mozilla.com dbus: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.Avahi.service': Unit dbus-org.freedesktop.Avahi.service not found.
Jan 25 04:46:48 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:46:48 No task claimed. Idle for 26m34.073218969s (will exit if no task claimed in 95h33m25.926781031s). 1 more tasks to run before exiting.
Jan 25 04:46:53 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:46:53 Disk available: 198706458624 bytes
Jan 25 04:47:09 t-linux64-ms-402.test.releng.mdc2.mozilla.com collectd: write_graphite plugin: send to graphite1.private.mdc2.mozilla.com:2003 (tcp) failed with status -1 (Broken pipe)
Jan 25 04:47:09 t-linux64-ms-402.test.releng.mdc2.mozilla.com collectd: Filter subsystem: Built-in target `write': Dispatching value to the `write_graphite/graphite1.private.mdc2.mozilla.com' plugin failed with status -1.
Jan 25 04:47:09 t-linux64-ms-402.test.releng.mdc2.mozilla.com collectd: Available write targets: ['write_graphite/graphite1.private.mdc2.mozilla.com']
Jan 25 04:47:12 t-linux64-ms-402.test.releng.mdc2.mozilla.com collectd: Filter subsystem: Built-in target `write': Plugin `write_graphite/graphite1.private.mdc2.mozilla.com' is back to normal operation. `write' succeeded.
Jan 25 04:47:18 t-linux64-ms-402.test.releng.mdc2.mozilla.com generic-worker: 2019/01/25 04:47:18 Disk available: 198706458624 bytes

All Syst

Comment 1

[:dhouse]

The collectd service appears to be active during this time. Maybe the tcp connection is being dropped and then resumed on the receiver. It appears to happen every 5 minutes; And we have collectd configured to query at 5 minute intervals.

[root@t-linux64-ms-395 ~]# systemctl status collectd
● collectd.service - Statistics collection and monitoring daemon
   Loaded: loaded (/lib/systemd/system/collectd.service; enabled; vendor preset: enabled)
   Active: active (running) since Tue 2019-02-05 00:44:50 PST; 19h ago
     Docs: man:collectd(1)
           man:collectd.conf(5)
           https://collectd.org
 Main PID: 1303 (collectd)
   CGroup: /system.slice/collectd.service
           └─1303 /usr/sbin/collectd

Feb 05 20:04:50 t-linux64-ms-395 collectd[1303]: Available write targets: ['write_graphite/graphite1.private.mdc2.mozilla.com']
Feb 05 20:04:50 t-linux64-ms-395 collectd[1303]: Filter subsystem: Built-in target `write': Plugin `write_graphite/graphite1.private.mdc2.mozilla.com' is back to normal operation. `write' succeeded.
Feb 05 20:09:50 t-linux64-ms-395 collectd[1303]: write_graphite plugin: send to graphite1.private.mdc2.mozilla.com:2003 (tcp) failed with status -1 (Broken pipe)
Feb 05 20:09:50 t-linux64-ms-395 collectd[1303]: Filter subsystem: Built-in target `write': Dispatching value to the `write_graphite/graphite1.private.mdc2.mozilla.com' plugin failed with status -1.
Feb 05 20:09:50 t-linux64-ms-395 collectd[1303]: Available write targets: ['write_graphite/graphite1.private.mdc2.mozilla.com']
Feb 05 20:09:50 t-linux64-ms-395 collectd[1303]: Filter subsystem: Built-in target `write': Plugin `write_graphite/graphite1.private.mdc2.mozilla.com' is back to normal operation. `write' succeeded.
Feb 05 20:14:50 t-linux64-ms-395 collectd[1303]: write_graphite plugin: send to graphite1.private.mdc2.mozilla.com:2003 (tcp) failed with status -1 (Broken pipe)
Feb 05 20:14:50 t-linux64-ms-395 collectd[1303]: Filter subsystem: Built-in target `write': Dispatching value to the `write_graphite/graphite1.private.mdc2.mozilla.com' plugin failed with status -1.
Feb 05 20:14:50 t-linux64-ms-395 collectd[1303]: Available write targets: ['write_graphite/graphite1.private.mdc2.mozilla.com']
Feb 05 20:14:50 t-linux64-ms-395 collectd[1303]: Filter subsystem: Built-in target `write': Plugin `write_graphite/graphite1.private.mdc2.mozilla.com' is back to normal operation. `write' succeeded.

LoadPlugin "write_graphite"

<Plugin "write_graphite">
    <Node "graphite1.private.mdc2.mozilla.com">
        Host "graphite1.private.mdc2.mozilla.com"
        Port "2003"
        Prefix "hosts."
        StoreRates true
        AlwaysAppendDS false
        EscapeCharacter "_"
        SeparateInstances true
    </Node>
</Plugin>
/etc/collectd/collectd.d/write_graphite.conf (END)

Comment 2

[:dhouse]

https://github.com/collectd/collectd/blob/collectd-5.5/src/write_graphite.c

Looking at the write_graphite plugin info on collectd wiki:
"It keeps the TCP connection to Carbon open in order to minimize the connection handshake overhead. " (https://collectd.org/wiki/index.php/Plugin:Write_Graphite)

In newer versions, there is a config option to set the reconnect interval, but there is no way to configure a disconnect or stop reconnecting.

We could switch to udp, or we could turn off the logging. Or we could remove collectd from the workers.

Comment 3

[:dhouse]

I added a filter to drop these failures from the papertrail logs.

We're planning to remove collectd and it is not being used currently. So we don't need to be concerned about the connection drops right now.