Solved Cannot clone WordPress app, get error: "Addons Error: Error restoring mysql: read ECONNRESET"

[d19dotca]

I'm trying to clone one of my live WordPress sites to a staging domain so I can make some changes there, and this is the first time I've had this issue before but have now seen it repeatedly when trying to clone this app today:

Here are the relevant logs:

Nov 10 16:44:01 box:backups downloadApp: time: 16.465
Nov 10 16:44:01 box:addons www.staging.<domain>.<tld> restoreAddons
Nov 10 16:44:01 box:addons www.staging.<domain>.<tld> restoreAddons: restoring ["mysql","ldap","localstorage","sendmail","scheduler","redis"]
Nov 10 16:44:01 box:addons www.staging.<domain>.<tld> restoreMySql
Nov 10 16:44:04 box:apptask www.staging.<domain>.<tld> error installing app: BoxError: Error restoring mysql: read ECONNRESET
Nov 10 16:44:04 box:apptask www.staging.<domain>.<tld> updating app with values: {"installationState":"error","error":{"message":"Error restoring mysql: read ECONNRESET","reason":"Addons Error","taskId":"6872","installationState":"pending_clone"}}
Nov 10 16:44:07 box:taskworker Task took 46.77 seconds
Nov 10 16:44:07 box:tasks setCompleted - 6872: {"result":null,"error":{"stack":"BoxError: Error restoring mysql: read ECONNRESET\n at Request._callback (/home/yellowtent/box/src/addons.js:1375:40)\n at self.callback (/home/yellowtent/box/node_modules/request/request.js:185:22)\n at Request.emit (events.js:203:15)\n at Request.onRequestError (/home/yellowtent/box/node_modules/request/request.js:877:8)\n at ClientRequest.emit (events.js:198:13)\n at TLSSocket.socketErrorListener (_http_client.js:392:9)\n at TLSSocket.emit (events.js:198:13)\n at emitErrorNT (internal/streams/destroy.js:91:8)\n at emitErrorAndCloseNT (internal/streams/destroy.js:59:3)\n at process._tickCallback (internal/process/next_tick.js:63:19)","name":"BoxError","reason":"Addons Error","details":{},"message":"Error restoring mysql: read ECONNRESET"}}
Nov 10 16:44:07 box:tasks 6872: {"percent":100,"result":null,"error":{"stack":"BoxError: Error restoring mysql: read ECONNRESET\n at Request._callback (/home/yellowtent/box/src/addons.js:1375:40)\n at self.callback (/home/yellowtent/box/node_modules/request/request.js:185:22)\n at Request.emit (events.js:203:15)\n at Request.onRequestError (/home/yellowtent/box/node_modules/request/request.js:877:8)\n at ClientRequest.emit (events.js:198:13)\n at TLSSocket.socketErrorListener (_http_client.js:392:9)\n at TLSSocket.emit (events.js:198:13)\n at emitErrorNT (internal/streams/destroy.js:91:8)\n at emitErrorAndCloseNT (internal/streams/destroy.js:59:3)\n at process._tickCallback (internal/process/next_tick.js:63:19)","name":"BoxError","reason":"Addons Error","details":{},"message":"Error restoring mysql: read ECONNRESET"}}
Nov 10 16:43:29 Generating SSL certificate

Naturally, I hit "Retry clone", and it "succeeds" according to Cloudron, but it's not actually correct. What's absolutely bizarre is at this point it's just as if I had deployed a fresh WordPress instance, there's no pages, no users, no posts, nothing... just the absolute defaults. It's as if it says it succeeds on the second try even though it never actually seemed to copy any of the database data itself.

This is reproducible on this one WordPress instance. I spot-checked a few others and don't seem to have this issue, so it seems specific somehow to this instance. Unclear what's different as I have another site nearly identical to it that doesn't have this issue (same medical clinic website, just a different physical location, otherwise nearly identical content and configuration).

[girish]

@d19dotca This is most likely because mysql is running out of memory. Can you maybe try to give it more memory in Services -> mysql ?

[d19dotca]

@girish Sure, I can try.

Quick question though if that's the root cause... why does this only impact this one app? I can successfully clone from other WordPress instances without problem, it's only this one. And it's database I suspect isn't that much larger than any others, especially it's "sister site" which is basically a replica of it.

I'll try though now and see what the outcome is.

Update: MySQL seems to be okay for the most part, should have plenty left:

[d19dotca]

@girish Okay I increased memory from 4 GB to 5.75 GB, and still the same behaviour. I don't think it's a memory issue at this point, MySQL has plenty of it.

[girish]

@d19dotca Do you see a crash in the mysql service logs?

[d19dotca]

@girish Interestingly enough I don't see a crash but I see duplicate keys apparently (and this is from a custom plugin from a payment provider my client was wanting to integrate with "Motion Pay").

Here is what I see in the logs:

Nov 10 16:59:22 Stderr from db import: ERROR 1022 (23000) at line 1283: Can't write; duplicate key in table 'wp_wc_motionpay_loginfo'
Nov 10 16:59:22
Nov 10 16:59:22 events.js:287
Nov 10 16:59:22 throw er; // Unhandled 'error' event
Nov 10 16:59:22 ^
Nov 10 16:59:22
Nov 10 16:59:22 Error: write EPIPE
Nov 10 16:59:22 at WriteWrap.onWriteComplete [as oncomplete] (internal/stream_base_commons.js:92:16)
Nov 10 16:59:22 Emitted 'error' event on Socket instance at:
Nov 10 16:59:22 at errorOrDestroy (internal/streams/destroy.js:108:12)
Nov 10 16:59:22 at Socket.onerror (_stream_readable.js:729:7)
Nov 10 16:59:22 at Socket.emit (events.js:310:20)
Nov 10 16:59:22 at errorOrDestroy (internal/streams/destroy.js:108:12)
Nov 10 16:59:22 at onwriteError (_stream_writable.js:463:5)
Nov 10 16:59:22 at onwrite (_stream_writable.js:484:5)
Nov 10 16:59:22 at internal/streams/destroy.js:50:7
Nov 10 16:59:22 at Socket._destroy (net.js:677:5)
Nov 10 16:59:22 at Socket.destroy (internal/streams/destroy.js:38:8)
Nov 10 16:59:22 at WriteWrap.onWriteComplete [as oncomplete] (internal/stream_base_commons.js:93:12) {
Nov 10 16:59:22 errno: 'EPIPE',
Nov 10 16:59:22 code: 'EPIPE',
Nov 10 16:59:22 syscall: 'write'
Nov 10 16:59:22 }
Nov 10 16:59:22 2020-11-11 00:59:22,041 INFO exited: mysql-service (exit status 1; not expected)
Nov 10 16:59:22 2020-11-11 00:59:22,042 INFO reaped unknown pid 1488
Nov 10 16:59:23 2020-11-11 00:59:23,045 INFO spawned: 'mysql-service' with pid 1489
Nov 10 16:59:23 Mysql service endpoint listening on https://:::3000
Nov 10 16:59:24 2020-11-11 00:59:24,360 INFO success: mysql-service entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
Nov 10 17:05:53 [DELETE] /databases/07a886774d4f5d09
Nov 10 17:26:58 [GET] /healthcheck
Nov 10 17:27:46 [GET] /healthcheck
Nov 10 17:28:01 [DELETE] /databases/a262c28a1b3d64fe
Nov 10 17:28:02 [POST] /databases
Nov 10 17:28:18 [POST] /databases/a262c28a1b3d64fe/clear
Nov 10 17:28:18 clear: database a262c28a1b3d64fe
Nov 10 17:28:35 [POST] /databases/a262c28a1b3d64fe/restore
Nov 10 17:28:35 restore: database a262c28a1b3d64fe
Nov 10 17:28:38 Stderr from db import: ERROR
Nov 10 17:28:38 Stderr from db import: 1022 (23000)
Nov 10 17:28:38 Stderr from db import: at line 1283
Nov 10 17:28:38 Stderr from db import: : Can't write; duplicate key in table 'wp_wc_motionpay_loginfo'
Nov 10 17:28:38
Nov 10 17:28:38 events.js:287
Nov 10 17:28:38 throw er; // Unhandled 'error' event
Nov 10 17:28:38 ^
Nov 10 17:28:38
Nov 10 17:28:38 Error: write EPIPE
Nov 10 17:28:38 at WriteWrap.onWriteComplete [as oncomplete] (internal/stream_base_commons.js:92:16)
Nov 10 17:28:38 Emitted 'error' event on Socket instance at:
Nov 10 17:28:38 at errorOrDestroy (internal/streams/destroy.js:108:12)
Nov 10 17:28:38 at Socket.onerror (_stream_readable.js:729:7)
Nov 10 17:28:38 at Socket.emit (events.js:310:20)
Nov 10 17:28:38 at errorOrDestroy (internal/streams/destroy.js:108:12)
Nov 10 17:28:38 at onwriteError (_stream_writable.js:463:5)
Nov 10 17:28:38 at onwrite (_stream_writable.js:484:5)
Nov 10 17:28:38 at internal/streams/destroy.js:50:7
Nov 10 17:28:38 at Socket._destroy (net.js:677:5)
Nov 10 17:28:38 at Socket.destroy (internal/streams/destroy.js:38:8)
Nov 10 17:28:38 at WriteWrap.onWriteComplete [as oncomplete] (internal/stream_base_commons.js:93:12) {
Nov 10 17:28:38 errno: 'EPIPE',
Nov 10 17:28:38 code: 'EPIPE',
Nov 10 17:28:38 syscall: 'write'
Nov 10 17:28:38 }
Nov 10 17:28:38 2020-11-11 01:28:38,912 INFO exited: mysql-service (exit status 1; not expected)
Nov 10 17:28:38 2020-11-11 01:28:38,916 INFO reaped unknown pid 1502
Nov 10 17:28:39 2020-11-11 01:28:39,922 INFO spawned: 'mysql-service' with pid 1503
Nov 10 17:28:40 Mysql service endpoint listening on https://:::3000
Nov 10 17:28:41 2020-11-11 01:28:41,232 INFO success: mysql-service entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
Nov 10 17:28:55 [GET] /healthcheck

Seems strange to me though that this would be caused by any kind of duplicate key in the table, if it's not a duplicate key setting it off in the live instance then why would it appear in the clone? Strange.

[girish]

@d19dotca That's indeed strange. Does this happen even if you create a new backup and try to clone from that? I cannot think of a case where a table has duplicate keys in the current database but fails only on re-import! Very intriguing.

[d19dotca]

@girish Just tried, same issue if I take a fresh backup and clone from that new backup. It's so weird.

[girish]

@d19dotca There will be a mysqldump file in the backup. Can you check if it has duplicate keys for the table wp_wc_motionpay_loginfo ?

[d19dotca]

@girish Okay I talked to the developer of the MotionPay plugin, and he says that the table is just a log table and isn't critical, so suggested I just drop the table which I've now done and backed up and cloned successfully - so it's working now.

Still very strange, I suspect I may need to drop that table every time I go to clone that site, which is going to be an annoyance but not a biggie. So I guess this isn't really an issue anymore, and I suppose isn't a Cloudron issue but was a MySQL one specifically caused by the MotionPay plugin and how it creates it's data.

Still weird it was even ever allowed to create duplicate keys though in the first place, it's all kind of weird to me, I don't quite understand how it happened in the first place, but at least I know what to do in the future now if it happens again.

[girish]

@d19dotca said in Cannot clone WordPress app, get error: "Addons Error: Error restoring mysql: read ECONNRESET":

Still weird it was even ever allowed to create duplicate keys though in the first place

I am as puzzled as you are I don't understand how one can create a table with duplicate keys which somehow ended up in the dump and thus cannot be restored.

[girish]

I will mark this as solved for now but I suspect this will come back some day.