Page MenuHomePhabricator
Create Task
Maniphest T295952

db1131 alerting due to network hiccup
Closed, ResolvedPublic
Actions

Description

We just had a page on db1131 to the SRE:

Notification Type: PROBLEM
Host: db1131
State: DOWN
Address: 10.64.32.6
Info: PING CRITICAL - Packet loss = 100%

Date/Time: Thu Nov 18 03:23:50 UTC 2021

It seems it was a network hiccup:

image.png (995×1 px, 72 KB)

image.png (788×879 px, 79 KB)

Open questions:

  • Investigate the source root of the network hiccup
  • Maybe we need to revisit the alerting for hosts if they start to send false alerts often.

Details

Related Changes in Gerrit:
SubjectRepoBranchLines +/-
db1131: Enable notificationsoperations/puppetproduction+0 -1
mediawiki: Disable notification for db1131operations/puppetproduction+1 -0
Customize query in gerrit

Related Objects

Event Timeline

Ladsgroup created this task.Nov 18 2021, 3:38 AM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptNov 18 2021, 3:38 AM
RLazarus added a project: SRE.Nov 18 2021, 3:39 AM
Ladsgroup added a comment.Nov 18 2021, 3:47 AM

daemon logs during the hiccup:

Nov 18 03:23:15 db1131 systemd[1]: Created slice User Slice of UID 112.
Nov 18 03:23:15 db1131 systemd[1]: Starting User Runtime Directory /run/user/112...
Nov 18 03:23:15 db1131 systemd[1]: Started User Runtime Directory /run/user/112.
Nov 18 03:23:15 db1131 systemd[1]: Starting User Manager for UID 112...
Nov 18 03:23:16 db1131 systemd[14576]: gpgconf: running /usr/bin/gpg-agent failed (exitcode=2): General error
Nov 18 03:23:16 db1131 systemd[14576]: gpgconf: fatal error (exit status 1)
Nov 18 03:23:16 db1131 systemd[14576]: Reached target Timers.
Nov 18 03:23:16 db1131 systemd[14576]: Reached target Paths.
Nov 18 03:23:16 db1131 systemd[14576]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Nov 18 03:23:16 db1131 systemd[14576]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Nov 18 03:23:16 db1131 systemd[14576]: Listening on GnuPG network certificate management daemon.
Nov 18 03:23:16 db1131 systemd[14576]: Listening on GnuPG cryptographic agent and passphrase cache.
Nov 18 03:23:16 db1131 systemd[14576]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Nov 18 03:23:16 db1131 systemd[14576]: Reached target Sockets.
Nov 18 03:23:16 db1131 systemd[14576]: Reached target Basic System.
Nov 18 03:23:16 db1131 systemd[14576]: Reached target Default.
Nov 18 03:23:16 db1131 systemd[14576]: Startup finished in 46ms.
Nov 18 03:23:16 db1131 systemd[1]: Started User Manager for UID 112.
Nov 18 03:23:16 db1131 systemd[1]: Started Session 49565 of user debmonitor.
Nov 18 03:24:00 db1131 systemd[1]: Started Regular job to collect puppet agent stats.
Nov 18 03:24:00 db1131 systemd[1]: prometheus_puppet_agent_stats.service: Succeeded.
Nov 18 03:25:01 db1131 systemd[1]: Started Regular job to collect puppet agent stats.
Nov 18 03:25:01 db1131 systemd[1]: prometheus_puppet_agent_stats.service: Succeeded.
Nov 18 03:25:09 db1131 systemd[1]: Started Update NIC firmware stats exported by node_exporter.
Nov 18 03:25:09 db1131 systemd[1]: prometheus-nic-firmware-textfile.service: Succeeded.
Nov 18 03:25:29 db1131 systemd[1]: session-49565.scope: Succeeded.

gpg-agent fatal'ed during the hiccup, can be the cause or a symptom

Ladsgroup added a comment.Nov 18 2021, 3:51 AM

Oh the syslog is juicy:

Nov 18 03:22:06 db1131 kernel: [15945840.380917] tg3 0000:04:00.0 eno1: Link is down
Nov 18 03:23:05 db1131 mysqld[3170]: 2021-11-18  3:23:05 2602606439 [ERROR] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] Unknown thread id: 2602605928
Nov 18 03:23:05 db1131 mysqld[3170]: 2021-11-18  3:23:05 2602606439 [Note] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] At line 32 in ops.wmf_slave_wikiuser_sleep
Nov 18 03:23:05 db1131 mysqld[3170]: 2021-11-18  3:23:05 2602606439 [Note] Event Scheduler: [root@localhost].[ops.wmf_slave_wikiuser_sleep] event execution failed.
Nov 18 03:23:08 db1131 systemd[1]: Started Regular job to collect puppet agent stats.
Nov 18 03:23:08 db1131 systemd[1]: prometheus_puppet_agent_stats.service: Succeeded.
Nov 18 03:23:11 db1131 mysqld[3170]: 2021-11-18  3:23:11 1395380077 [ERROR] Slave I/O: error reconnecting to master 'repl@db1173.eqiad.wmnet:3306' - retry-time: 60  maximum-retries: 86400  message: Unknown MySQL server host 'db1173.eqiad.wmnet' (-3), Internal MariaDB error code: 2005
Nov 18 03:23:15 db1131 systemd[1]: Created slice User Slice of UID 112.
Nov 18 03:23:15 db1131 systemd[1]: Starting User Runtime Directory /run/user/112...
Nov 18 03:23:15 db1131 systemd[1]: Started User Runtime Directory /run/user/112.
Nov 18 03:23:15 db1131 systemd[1]: Starting User Manager for UID 112...
Nov 18 03:23:16 db1131 systemd[14576]: gpgconf: running /usr/bin/gpg-agent failed (exitcode=2): General error
Nov 18 03:23:16 db1131 systemd[14576]: gpgconf: fatal error (exit status 1)
Nov 18 03:23:16 db1131 systemd[14576]: Reached target Timers.
Nov 18 03:23:16 db1131 systemd[14576]: Reached target Paths.
Nov 18 03:23:16 db1131 systemd[14576]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
Nov 18 03:23:16 db1131 systemd[14576]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Nov 18 03:23:16 db1131 systemd[14576]: Listening on GnuPG network certificate management daemon.
Nov 18 03:23:16 db1131 systemd[14576]: Listening on GnuPG cryptographic agent and passphrase cache.
Nov 18 03:23:16 db1131 systemd[14576]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Nov 18 03:23:16 db1131 systemd[14576]: Reached target Sockets.
Nov 18 03:23:16 db1131 systemd[14576]: Reached target Basic System.
Nov 18 03:23:16 db1131 systemd[14576]: Reached target Default.
Nov 18 03:23:16 db1131 systemd[14576]: Startup finished in 46ms.
Nov 18 03:23:16 db1131 systemd[1]: Started User Manager for UID 112.
Nov 18 03:23:16 db1131 systemd[1]: Started Session 49565 of user debmonitor.
Nov 18 03:23:16 db1131 puppet-agent-cronjob: su: warning: cannot change directory to /nonexistent: No such file or directory
Nov 18 03:23:16 db1131 puppet-agent-cronjob: INFO:debmonitor:Found 552 installed binary packages
Nov 18 03:23:16 db1131 puppet-agent-cronjob: INFO:debmonitor:Found 9 upgradable binary packages (including new dependencies)
Nov 18 03:23:22 db1131 puppet-agent-cronjob: WARNING:urllib3.connectionpool:Retrying (Retry(total=2, connect=None, read=None, redirect=None, status=None)) after connection broken by 'NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x7fc272b066d8>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution')': /hosts/db1131.eqiad.wmnet/update
Nov 18 03:23:58 db1131 kernel: [15945952.439595] tg3 0000:04:00.0 eno1: Link is up at 1000 Mbps, full duplex
Nov 18 03:23:58 db1131 kernel: [15945952.439610] tg3 0000:04:00.0 eno1: Flow control is off for TX and off for RX
Nov 18 03:23:58 db1131 kernel: [15945952.439613] tg3 0000:04:00.0 eno1: EEE is disabled
Nov 18 03:24:00 db1131 systemd[1]: Started Regular job to collect puppet agent stats.
Nov 18 03:24:00 db1131 systemd[1]: prometheus_puppet_agent_stats.service: Succeeded.
Nov 18 03:24:02 db1131 kernel: [15945956.681518] tg3 0000:04:00.0 eno1: Link is down
Nov 18 03:24:09 db1131 kernel: [15945963.733365] tg3 0000:04:00.0 eno1: Link is up at 1000 Mbps, full duplex
Nov 18 03:24:09 db1131 kernel: [15945963.733377] tg3 0000:04:00.0 eno1: Flow control is off for TX and off for RX
Nov 18 03:24:09 db1131 kernel: [15945963.733381] tg3 0000:04:00.0 eno1: EEE is disabled
Nov 18 03:24:15 db1131 kernel: [15945969.461256] tg3 0000:04:00.0 eno1: Link is down
Nov 18 03:24:22 db1131 kernel: [15945977.010944] tg3 0000:04:00.0 eno1: Link is up at 1000 Mbps, full duplex
Nov 18 03:24:22 db1131 kernel: [15945977.010957] tg3 0000:04:00.0 eno1: Flow control is off for TX and off for RX
Nov 18 03:24:22 db1131 kernel: [15945977.010960] tg3 0000:04:00.0 eno1: EEE is disabled
Nov 18 03:24:24 db1131 kernel: [15945978.872003] tg3 0000:04:00.0 eno1: Link is down
Nov 18 03:24:28 db1131 kernel: [15945982.415605] tg3 0000:04:00.0 eno1: Link is up at 1000 Mbps, full duplex
Nov 18 03:24:28 db1131 kernel: [15945982.415618] tg3 0000:04:00.0 eno1: Flow control is off for TX and off for RX
Nov 18 03:24:28 db1131 kernel: [15945982.415621] tg3 0000:04:00.0 eno1: EEE is disabled
Nov 18 03:25:01 db1131 CRON[14784]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)

It seems the network interface went down.

Ladsgroup added a comment.Nov 18 2021, 4:12 AM

It's on C8, the access switch didn't log any errors in that port: https://librenms.wikimedia.org/device/device=162/tab=port/port=14869/

Ladsgroup added a comment.Nov 18 2021, 4:24 AM

It actually flapped several times (from kern.log):

Nov 18 01:35:21 db1131 kernel: [15939435.175199] tg3 0000:04:00.0 eno1: Link is down
Nov 18 01:35:40 db1131 kernel: [15939454.725701] tg3 0000:04:00.0 eno1: Link is up at 1000 Mbps, full duplex
Nov 18 01:35:40 db1131 kernel: [15939454.725711] tg3 0000:04:00.0 eno1: Flow control is off for TX and off for RX
Nov 18 01:35:40 db1131 kernel: [15939454.725713] tg3 0000:04:00.0 eno1: EEE is disabled

Nov 18 01:35:41 db1131 kernel: [15939455.149812] tg3 0000:04:00.0 eno1: Link is down
Nov 18 01:35:44 db1131 kernel: [15939458.756397] tg3 0000:04:00.0 eno1: Link is up at 1000 Mbps, full duplex
Nov 18 01:35:44 db1131 kernel: [15939458.756410] tg3 0000:04:00.0 eno1: Flow control is off for TX and off for RX
Nov 18 01:35:44 db1131 kernel: [15939458.756414] tg3 0000:04:00.0 eno1: EEE is disabled

Nov 18 02:58:30 db1131 kernel: [15944424.039480] tg3 0000:04:00.0 eno1: Link is down
Nov 18 02:58:33 db1131 kernel: [15944427.484025] tg3 0000:04:00.0 eno1: Link is up at 1000 Mbps, full duplex
Nov 18 02:58:33 db1131 kernel: [15944427.484041] tg3 0000:04:00.0 eno1: Flow control is off for TX and off for RX
Nov 18 02:58:33 db1131 kernel: [15944427.484044] tg3 0000:04:00.0 eno1: EEE is disabled

Nov 18 03:22:06 db1131 kernel: [15945840.380917] tg3 0000:04:00.0 eno1: Link is down
Nov 18 03:23:58 db1131 kernel: [15945952.439595] tg3 0000:04:00.0 eno1: Link is up at 1000 Mbps, full duplex
Nov 18 03:23:58 db1131 kernel: [15945952.439610] tg3 0000:04:00.0 eno1: Flow control is off for TX and off for RX
Nov 18 03:23:58 db1131 kernel: [15945952.439613] tg3 0000:04:00.0 eno1: EEE is disabled
Nov 18 03:24:02 db1131 kernel: [15945956.681518] tg3 0000:04:00.0 eno1: Link is down
Nov 18 03:24:09 db1131 kernel: [15945963.733365] tg3 0000:04:00.0 eno1: Link is up at 1000 Mbps, full duplex
Nov 18 03:24:09 db1131 kernel: [15945963.733377] tg3 0000:04:00.0 eno1: Flow control is off for TX and off for RX
Nov 18 03:24:09 db1131 kernel: [15945963.733381] tg3 0000:04:00.0 eno1: EEE is disabled

Nov 18 03:24:15 db1131 kernel: [15945969.461256] tg3 0000:04:00.0 eno1: Link is down
Nov 18 03:24:22 db1131 kernel: [15945977.010944] tg3 0000:04:00.0 eno1: Link is up at 1000 Mbps, full duplex
Nov 18 03:24:22 db1131 kernel: [15945977.010957] tg3 0000:04:00.0 eno1: Flow control is off for TX and off for RX
Nov 18 03:24:22 db1131 kernel: [15945977.010960] tg3 0000:04:00.0 eno1: EEE is disabled

Nov 18 03:24:24 db1131 kernel: [15945978.872003] tg3 0000:04:00.0 eno1: Link is down
Nov 18 03:24:28 db1131 kernel: [15945982.415605] tg3 0000:04:00.0 eno1: Link is up at 1000 Mbps, full duplex
Nov 18 03:24:28 db1131 kernel: [15945982.415618] tg3 0000:04:00.0 eno1: Flow control is off for TX and off for RX
Nov 18 03:24:28 db1131 kernel: [15945982.415621] tg3 0000:04:00.0 eno1: EEE is disabled

This is where my (non-existent) network knowledge ends, Can it be NIC having issues and needing replacement? A loose Ethernet cable?

Stashbot added a comment.Nov 18 2021, 5:08 AM

Mentioned in SAL (#wikimedia-operations) [2021-11-18T05:08:03Z] <ladsgroup@cumin1001> dbctl commit (dc=all): 'Depooling db1131 due to network issues (T295952)', diff saved to https://phabricator.wikimedia.org/P17758 and previous config saved to /var/cache/conftool/dbconfig/20211118-050802-ladsgroup.json

Ladsgroup added a project: ops-eqiad.Nov 18 2021, 5:09 AM

Hi, ops-eqiad. It is possible to check Ethernet cable of db1131 (C8)? Thanks!

gerritbot added a comment.Nov 18 2021, 5:13 AM

Change 739698 had a related patch set uploaded (by Ladsgroup; author: Amir Sarabadani):

[operations/puppet@production] mediawiki: Disable notification for db1131

https://gerrit.wikimedia.org/r/739698

gerritbot added a project: Patch-For-Review.Nov 18 2021, 5:13 AM
gerritbot added a comment.Nov 18 2021, 5:15 AM

Change 739698 merged by Ladsgroup:

[operations/puppet@production] mediawiki: Disable notification for db1131

https://gerrit.wikimedia.org/r/739698

Marostegui triaged this task as High priority.Nov 18 2021, 5:19 AM
Marostegui moved this task from Triage to In progress on the DBA board.
Marostegui added subscribers: • Cmjohnson, Jclark-ctr, wiki_willy.

Raising this to high as this is the candidate master for s6.

Maintenance_bot removed a project: Patch-For-Review.Nov 18 2021, 6:10 AM
Marostegui added a comment.Nov 18 2021, 1:25 PM

@Cmjohnson @Jclark-ctr can you double check if the cable is loose?

wiki_willy assigned this task to • Cmjohnson.Nov 18 2021, 4:00 PM
wiki_willy added a comment.Nov 18 2021, 4:07 PM

Hopefully it's just a loose cable. If not, just a FYI - the out of warranty date is listed as November 13, so we may or may not be able to RMA parts with Dell for it. Thanks, Willy

In T295952#7513586, @Marostegui wrote:

@Cmjohnson @Jclark-ctr can you double check if the cable is loose?

• Cmjohnson added a comment.Nov 18 2021, 6:07 PM

@Marostegui the cable has been replaced, I am able to ssh into the server now. Please take a look

Marostegui added a comment.Nov 18 2021, 6:11 PM

Thanks @Cmjohnson - I can access the host too. Before it was also accesible but we saw the network flapping a few times. I am going to leave the host depooled for the weekend and if the network hasn't flapped during Friday and the weekend I will start repooling it.
Thank you!

Jclark-ctr added a comment.Nov 18 2021, 7:16 PM

@Marostegui when i switched out cable earlier had left my laptop in another building i relayed information to chris. The connection activity led on nic was flashing abnormally after replacing cable it was more consistant with how it would usually flash. It did have connection prior to me changing cable also.

Marostegui added a comment.Nov 18 2021, 7:19 PM

Oh sweet - thanks for the information John. So maybe it was indeed a bad cable. I will check on Monday if we had some other flapping since the cable change, and if all goes well I will repool and close this task.

Thanks for being so fast!!

Marostegui lowered the priority of this task from High to Medium.Nov 18 2021, 7:48 PM
Marostegui added a comment.Nov 22 2021, 6:22 AM

No more network flaps, so going to start repooling.

gerritbot added a comment.Nov 22 2021, 6:22 AM

Change 740384 had a related patch set uploaded (by Marostegui; author: Marostegui):

[operations/puppet@production] db1131: Enable notifications

https://gerrit.wikimedia.org/r/740384

gerritbot added a project: Patch-For-Review.Nov 22 2021, 6:22 AM

Change 740384 merged by Marostegui:

[operations/puppet@production] db1131: Enable notifications

https://gerrit.wikimedia.org/r/740384

Maintenance_bot removed a project: Patch-For-Review.Nov 22 2021, 7:10 AM
Marostegui closed this task as Resolved.Nov 22 2021, 8:25 AM

Host repooled - thanks DCOps for the fast response!

• Kormat added a comment.Nov 24 2021, 11:21 AM

Maybe we need to revisit the alerting for hosts if they start to send false alerts often.

@Ladsgroup: I'm not following, why would a networking problem be a 'false' alert?

Ladsgroup added a comment.Nov 24 2021, 12:59 PM
In T295952#7526103, @Kormat wrote:

Maybe we need to revisit the alerting for hosts if they start to send false alerts often.

@Ladsgroup: I'm not following, why would a networking problem be a 'false' alert?

Sorry for misunderstanding. I created the ticket right after the alert when we were not sure what is the root cause and a couple of days after we introduced these alerts, so my thinking was that if it alerts too often, wouldn't have a user impact (and it's self-healing), we should drop it. I have had a lot of flapping alerts that made me numb to alerts and that's not good.

Content licensed under Creative Commons Attribution-ShareAlike (CC BY-SA) 4.0 unless otherwise noted; code licensed under GNU General Public License (GPL) 2.0 or later and other open source licenses. By using this site, you agree to the Terms of Use, Privacy Policy, and Code of Conduct. · Wikimedia Foundation · Privacy Policy · Code of Conduct · Terms of Use · Disclaimer · CC-BY-SA · GPL · Credits