Page MenuHomePhabricator

es2027 database unhealthy
Closed, ResolvedPublic

Description

it was down for hours, now it is giving fatal errors on start:

Times are CEST:

[23:45:38] <icinga-wm> PROBLEM - mysqld processes on es2027 is CRITICAL: PROCS CRITICAL: 0 processes with command name mysqld https://wikitech.wikimedia.org/wiki/MariaDB/troubleshooting
[23:46:02] <icinga-wm> PROBLEM - MariaDB read only es3 on es2027 is CRITICAL: Could not connect to localhost:3306 https://wikitech.wikimedia.org/wiki/MariaDB
[07:16:37] <icinga-wm> RECOVERY - mysqld processes on es2027 is OK: PROCS OK: 1 process with command name mysqld https://wikitech.wikimedia.org/wiki/MariaDB/troubleshooting
[07:16:43] <icinga-wm> RECOVERY - MariaDB read only es3 on es2027 is OK: Version 10.11.13-MariaDB-log, Uptime 7s, read_only: True, event_scheduler: True, 4.15 QPS, connection latency: 0.028914s https://wikitech.wikimedia.org/wiki/MariaDB

Times are UTC:

Sep 18 05:16:31 es2027 mysqld[91495]: 2025-09-18  5:16:31 0 [ERROR] mysqld: File './es2027-relay-bin.000001' not found (Errcode: 2 "No such file or directory")
Sep 18 05:16:31 es2027 mysqld[91495]: 2025-09-18  5:16:31 0 [ERROR] Failed to open log (file './es2027-relay-bin.000001', errno 2)
Sep 18 05:16:31 es2027 mysqld[91495]: 2025-09-18  5:16:31 0 [ERROR] Failed to open the relay log './es2027-relay-bin.000001' (relay_log_pos 4)
Sep 18 05:16:31 es2027 mysqld[91495]: 2025-09-18  5:16:31 0 [ERROR] Could not open log file
Sep 18 05:16:31 es2027 mysqld[91495]: 2025-09-18  5:16:31 0 [ERROR] Failed to initialize the master info structure

(repeated several times)

Event Timeline

jcrespo triaged this task as Unbreak Now! priority.Sep 18 2025, 6:21 AM
jcrespo added subscribers: FCeratto-WMF, Ladsgroup.

This is the virtual master for es3. Switching it over to es2029 for depool (it is a read only section: es3 on codfw).

There are several hosts with query killer errors @Ladsgroup, spitting lots of errors logs. Maybe it is normal, but something to check (happening on both es2027 and es2029):

Jul 01 18:08:35 es2029 mysqld[1330]: 2025-07-01 18:08:35 30911478 [ERROR] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] Unknown thread id: 30909430
Jul 01 18:08:35 es2029 mysqld[1330]: 2025-07-01 18:08:35 30911478 [Note] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] At line 32 in ops.wmf_slave_wikiuser_sleep
Jul 01 18:08:35 es2029 mysqld[1330]: 2025-07-01 18:08:35 30911478 [Note] Event Scheduler: [root@localhost].[ops.wmf_slave_wikiuser_sleep] event execution failed.
Jul 02 12:53:05 es2029 mysqld[1330]: 2025-07-02 12:53:05 33818553 [ERROR] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] Unknown thread id: 33814405
Jul 02 12:53:05 es2029 mysqld[1330]: 2025-07-02 12:53:05 33818553 [Note] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] At line 32 in ops.wmf_slave_wikiuser_sleep
Jul 02 12:53:05 es2029 mysqld[1330]: 2025-07-02 12:53:05 33818553 [Note] Event Scheduler: [root@localhost].[ops.wmf_slave_wikiuser_sleep] event execution failed.
Jul 02 22:52:05 es2029 mysqld[1330]: 2025-07-02 22:52:05 34707877 [ERROR] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] Unknown thread id: 34706595
Jul 02 22:52:05 es2029 mysqld[1330]: 2025-07-02 22:52:05 34707877 [Note] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] At line 32 in ops.wmf_slave_wikiuser_sleep
Jul 02 22:52:05 es2029 mysqld[1330]: 2025-07-02 22:52:05 34707877 [Note] Event Scheduler: [root@localhost].[ops.wmf_slave_wikiuser_sleep] event execution failed.
Jul 04 19:21:35 es2029 mysqld[1330]: 2025-07-04 19:21:35 38854778 [ERROR] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] Unknown thread id: 38853814
Jul 04 19:21:35 es2029 mysqld[1330]: 2025-07-04 19:21:35 38854778 [Note] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] At line 32 in ops.wmf_slave_wikiuser_sleep
Jul 04 19:21:35 es2029 mysqld[1330]: 2025-07-04 19:21:35 38854778 [Note] Event Scheduler: [root@localhost].[ops.wmf_slave_wikiuser_sleep] event execution failed.
Jul 05 13:33:35 es2029 mysqld[1330]: 2025-07-05 13:33:35 40033909 [ERROR] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] Unknown thread id: 40030123
Jul 05 13:33:35 es2029 mysqld[1330]: 2025-07-05 13:33:35 40033909 [Note] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] At line 32 in ops.wmf_slave_wikiuser_sleep
Jul 05 13:33:35 es2029 mysqld[1330]: 2025-07-05 13:33:35 40033909 [Note] Event Scheduler: [root@localhost].[ops.wmf_slave_wikiuser_sleep] event execution failed.
Jul 08 09:05:35 es2029 mysqld[1330]: 2025-07-08  9:05:35 45034913 [ERROR] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] Unknown thread id: 45033387
Jul 08 09:05:35 es2029 mysqld[1330]: 2025-07-08  9:05:35 45034913 [Note] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] At line 32 in ops.wmf_slave_wikiuser_sleep
Jul 08 09:05:35 es2029 mysqld[1330]: 2025-07-08  9:05:35 45034913 [Note] Event Scheduler: [root@localhost].[ops.wmf_slave_wikiuser_sleep] event execution failed.
Jul 09 00:09:05 es2029 mysqld[1330]: 2025-07-09  0:09:05 45973392 [ERROR] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] Unknown thread id: 45970896
Jul 09 00:09:05 es2029 mysqld[1330]: 2025-07-09  0:09:05 45973392 [Note] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] At line 32 in ops.wmf_slave_wikiuser_sleep
Jul 09 00:09:05 es2029 mysqld[1330]: 2025-07-09  0:09:05 45973392 [Note] Event Scheduler: [root@localhost].[ops.wmf_slave_wikiuser_sleep] event execution failed.
Jul 09 15:56:05 es2029 mysqld[1330]: 2025-07-09 15:56:05 47238572 [ERROR] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] Unknown thread id: 47236875
Jul 09 15:56:05 es2029 mysqld[1330]: 2025-07-09 15:56:05 47238572 [Note] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] At line 32 in ops.wmf_slave_wikiuser_sleep
Jul 09 15:56:05 es2029 mysqld[1330]: 2025-07-09 15:56:05 47238572 [Note] Event Scheduler: [root@localhost].[ops.wmf_slave_wikiuser_sleep] event execution failed.
Jul 11 05:16:05 es2029 mysqld[1330]: 2025-07-11  5:16:05 50546984 [ERROR] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] Unknown thread id: 50544823
Jul 11 05:16:05 es2029 mysqld[1330]: 2025-07-11  5:16:05 50546984 [Note] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] At line 32 in ops.wmf_slave_wikiuser_sleep
Jul 11 05:16:05 es2029 mysqld[1330]: 2025-07-11  5:16:05 50546984 [Note] Event Scheduler: [root@localhost].[ops.wmf_slave_wikiuser_sleep] event execution failed.
Jul 11 20:25:35 es2029 mysqld[1330]: 2025-07-11 20:25:35 51824097 [ERROR] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] Unknown thread id: 51822565
Jul 11 20:25:35 es2029 mysqld[1330]: 2025-07-11 20:25:35 51824097 [Note] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] At line 32 in ops.wmf_slave_wikiuser_sleep
Jul 11 20:25:35 es2029 mysqld[1330]: 2025-07-11 20:25:35 51824097 [Note] Event Scheduler: [root@localhost].[ops.wmf_slave_wikiuser_sleep] event execution failed.
Jul 12 10:30:35 es2029 mysqld[1330]: 2025-07-12 10:30:35 53058042 [ERROR] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] Unknown thread id: 53055775
Jul 12 10:30:35 es2029 mysqld[1330]: 2025-07-12 10:30:35 53058042 [Note] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] At line 32 in ops.wmf_slave_wikiuser_sleep
Jul 12 10:30:35 es2029 mysqld[1330]: 2025-07-12 10:30:35 53058042 [Note] Event Scheduler: [root@localhost].[ops.wmf_slave_wikiuser_sleep] event execution failed.
Jul 12 15:08:05 es2029 mysqld[1330]: 2025-07-12 15:08:05 53485362 [ERROR] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] Unknown thread id: 53483771
Jul 12 15:08:05 es2029 mysqld[1330]: 2025-07-12 15:08:05 53485362 [Note] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] At line 32 in ops.wmf_slave_wikiuser_sleep
Jul 12 15:08:05 es2029 mysqld[1330]: 2025-07-12 15:08:05 53485362 [Note] Event Scheduler: [root@localhost].[ops.wmf_slave_wikiuser_sleep] event execution failed.
Jul 13 22:34:35 es2029 mysqld[1330]: 2025-07-13 22:34:35 55709207 [ERROR] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] Unknown thread id: 55707921
Jul 13 22:34:35 es2029 mysqld[1330]: 2025-07-13 22:34:35 55709207 [Note] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] At line 32 in ops.wmf_slave_wikiuser_sleep

Mentioned in SAL (#wikimedia-operations) [2025-09-18T06:34:37Z] <jynus@cumin1003> dbctl commit (dc=all): 'Depool es2027 T404940', diff saved to https://phabricator.wikimedia.org/P83420 and previous config saved to /var/cache/conftool/dbconfig/20250918-063436-jynus.json

I have depooled the host until it can be made healthy again:

root@cumin1003:~$ dbctl config commit -m "Depool es2027 T404940"
codfw/externalLoads/es3 live                                                              codfw/externalLoads/es3 generated                                                        
[                                                                                         [                                                                                        
    {                                                                                         {                                                                                    
        "es2027": 100                                                                             "es2029": 100                                                                    
    },                                                                                        },                                                                                   
    {                                                                                         {                                                                                    
        "es2029": 100,                                                                                                                                                             
        "es2034": 100                                                                             "es2034": 100                                                                    
    }                                                                                         }                                                                                    
]                                                                                         ]                                                                                        

Enter y or yes to confirm: y
Previous configuration saved. To restore it run: dbctl config restore /var/cache/conftool/dbconfig/20250918-063436-jynus.json
WARNING:conftool.announce:dbctl commit (dc=all): 'Depool es2027 T404940', diff saved to https://phabricator.wikimedia.org/P83420 and previous config saved to /var/cache/conftool/dbconfig/20250918-063436-jynus.json
✔
jcrespo lowered the priority of this task from Unbreak Now! to High.Sep 18 2025, 6:44 AM

The cloning process took approx 16 hours, see https://grafana.wikimedia.org/d/000000273/mysql?orgId=1&refresh=1m&var-job=%24__all&var-server=es2027&var-port=9104&from=2025-09-17T13%3A10%3A30.691Z&to=2025-09-18T07%3A05%3A26.466Z&timezone=utc

There are some red herrings and spurious alerts, to prevent similar issues from reoccurring I would suggest:

  • Consider disabling the relay subsystem where not used to prevent the error messages
  • Fix the Sep 11 08:53:45 es2027 nrpe2nodexp-ferm_active[1949308]: PermissionError: [Errno 13] Permission denied: '/var/lib/prometheus/node.d' issue (tracked in T403617)
  • Fix the rsyslogd[2465516]: omfwd: TCPSendBuf error -1, destruct TCP Connection to centrallog2002.codfw.wmnet:6514 errors (seen across multiple hosts)
  • Fix the [ERROR] Event Scheduler: [root@localhost][ops.wmf_slave_wikiuser_sleep] Unknown thread id: ... errors (seen across multiple hosts)
  • Update the cloning cookbook to wait for user input before pooling back the source host so that it can be done during working hours
  • Extend the silencing time in the cloning cookbook to a long time (days) as it will remove the downtime by itself when ready

Please first depool the source before doing the cloning.

Ladsgroup moved this task from Triage to Done on the DBA board.