On 6th of june the sql-backup job failed to run two times because the database wasn't around at the time (or was gone after the client connected)
- Document what happened
- (Optional) Fix it if possible
Description
Description
Related Objects
Related Objects
- Mentioned In
- T310597: Production warning: Aborted connection 38950 to db: 'mwdb_wbstack_X' user: 'mwu_X' host: '10.108.4.7' (Got an error reading communication packets)
- Mentioned Here
- T310588: Increase Backup Scratch Disk Size
T310121: Production warning: [RedisBagOStuff] Rejected set() for X due to snapshot lag (late regeneration).
Event Timeline
Comment Actions
So it seems the secondary mariadb instance has been logging warnings on aborted connections / clients since pretty much forever.
These rows look like this
Aborted connection 762576 to db: 'mwdb_wbstack_X' user: 'mwu_X' host: '10.X.0.X' (Got an error reading communication packets)
Comment Actions
Looking in the database the global stats show a fairly big number
MariaDB [(none)]> SHOW GLOBAL STATUS; +--------------------------------------------------------+--------------------------------------------------+ | Variable_name | Value | +--------------------------------------------------------+--------------------------------------------------+ | Aborted_clients | 2480 | | Aborted_connects | 5 |
Comment Actions
Ok, so describing the pod it was actually OOM killed just after the backups started
Containers:
mariadb:
Port: 3306/TCP
Host Port: 0/TCP
State: Running
Started: Mon, 06 Jun 2022 02:02:26 +0200
Last State: Terminated
Reason: OOMKilled
Exit Code: 137
Started: Thu, 26 May 2022 13:50:15 +0200
Finished: Mon, 06 Jun 2022 02:02:26 +0200
Ready: True
Restart Count: 1
Limits:
cpu: 750m
memory: 900Mi
Requests:
cpu: 100m
memory: 660MiComment Actions
Increasing the resources/limits on production https://github.com/wmde/wbaas-deploy/pull/390
But still this doesn't really explain why the connections are getting aborted / dropped.
Comment Actions
So the above patch was deployed yesterday and it seems that the backup was successfully taken without tipping anything over.
However looking at the charts of memory usage I'm a bit surprised by the impact of mydumper running against the secondary, I wonder if it's just caches that gets created once the dumper runs?
Comment Actions
I'm not able to understand why yet but the spammy warnings from the api-web pod about redis seems to have stopped after the secondary was restarted and got more resources.
[warning] [RedisBagOStuff] Rejected set() for mwdb_wbstack_X-mwt_X_:external-link-list:0 due to snapshot lag (late regeneration).
In this link we're using a relative last 7 days error and at around 17.10 on the 7th we did the deploy which made the api-web pod drop some connections but no other errors seems to trickle in after that.
https://cloudlogging.app.goo.gl/twk7JZtHVNk6G2wQA
MariaDB [(none)]> SHOW GLOBAL STATUS; +--------------------------------------------------------+--------------------------------------------------+ | Variable_name | Value | +--------------------------------------------------------+--------------------------------------------------+ | Aborted_clients | 2482 | | Aborted_connects | 5 |
Aborted connections / clients have only increased by 2 since the first query and deploy, but nothing afterwards..
Comment Actions
Created T310121: Production warning: [RedisBagOStuff] Rejected set() for X due to snapshot lag (late regeneration). to track the redis errors separately.
Comment Actions
So the above patch was deployed yesterday and it seems that the backup was successfully taken without tipping anything over.
However looking at the charts of memory usage I'm a bit surprised by the impact of mydumper running against the secondary, I wonder if it's just caches that gets created once the dumper runs?
Putting this in stalled, lets see how the resource usage develops.
Comment Actions
Memory usage keeps going up.
As of yesterday we started seeing dropped connections again.
Info 2022-06-08T03:22:07.749012469Z 2022-06-08 3:22:07 38950 [Warning] Aborted connection 38950 to db: 'mwdb_wbstack_X' user: 'mwu_X' host: '10.108.4.7' (Got an error reading communication packets) Info 2022-06-08T06:55:36.845314298Z 2022-06-08 6:55:36 60838 [Warning] Aborted connection 60838 to db: 'mwdb_wbstack_X' user: 'mwu_X' host: '10.108.4.7' (Got an error reading communication packets) Info 2022-06-09T00:40:57.745434984Z 2022-06-09 0:40:57 135566 [Warning] Aborted connection 135566 to db: 'mwdb_wbstack_X' user: 'mwu_X' host: '10.108.4.7' (Got an error reading communication packets) Info 2022-06-09T04:52:29.045789708Z 2022-06-09 4:52:29 149679 [Warning] Aborted connection 149679 to db: 'mwdb_wbstack_X' user: 'mwu_X' host: '10.108.4.7' (Got an error reading communication packets) Info 2022-06-09T04:53:44.146336267Z 2022-06-09 4:53:44 149794 [Warning] Aborted connection 149794 to db: 'mwdb_wbstack_X' user: 'mwu_X' host: '10.108.4.7' (Got an error reading communication packets) Info 2022-06-09T04:54:59.344388547Z 2022-06-09 4:54:59 149922 [Warning] Aborted connection 149922 to db: 'mwdb_wbstack_X' user: 'mwu_X' host: '10.108.4.7' (Got an error reading communication packets) Info 2022-06-09T05:04:19.444422837Z 2022-06-09 5:04:19 151065 [Warning] Aborted connection 151065 to db: 'mwdb_wbstack_X' user: 'mwu_X' host: '10.108.4.7' (Got an error reading communication packets) Info 2022-06-09T05:04:55.345402704Z 2022-06-09 5:04:55 151148 [Warning] Aborted connection 151148 to db: 'mwdb_wbstack_X' user: 'mwu_X' host: '10.108.4.7' (Got an error reading communication packets) Info 2022-06-09T05:05:15.444216687Z 2022-06-09 5:05:15 151191 [Warning] Aborted connection 151191 to db: 'mwdb_wbstack_X' user: 'mwu_X' host: '10.108.4.7' (Got an error reading communication packets) Info 2022-06-09T05:05:28.344438418Z 2022-06-09 5:05:28 151214 [Warning] Aborted connection 151214 to db: 'mwdb_wbstack_X' user: 'mwu_X' host: '10.108.4.7' (Got an error reading communication packets)
This comment was removed by • toan.
Comment Actions
So, to wrap the original problem up.
Memory usage seems to have plateaued for now which is good.
Backups are no longer falling over but we've identified the need to increase scratch disk space for them with all the new data T310588: Increase Backup Scratch Disk Size
Will write another ticket to track the aborted connections as this seems unrelated to the original problem.
Comment Actions
Moving to done, secondary sql pod got more memory and is no longer getting OOMkilled.