Mysql: Write error when executing a too big query

[danger89]

When I try to import a too big list of multi line queries (eg. coming from a sql file).

It will crash:

{ Error: write EPIPE
at WriteWrap.afterWrite [as oncomplete] (net.js:835:14) errno: 'EPIPE', code: 'EPIPE', syscall: 'write', fatal: true }

Regards,
Melroy van den Berg

[danger89]

with debug on true.

<ALL MY SQL STATEMENTS...>
COMMIT;

0 71 <== query#start(0,,2899185)
0 71 <== ed3c2c00032d2d204d7953514c205363726970742067656e657261746564206279204d7953514c20576f726b62656e63680a2d2d207672203138206d656920323031382030323a33343a343320434553540a2d2d204d6f64656c3a204e6577204d6f64656c2020202056657273696f6e3a20312e300a2d2d204d7953514c20576f726b62656e636820466f727761726420456e67696e656572696e670a0a53455420404f4c445f554e495155455f434845434b533d4040554e495155455f434845434b532c20554e495155455f434845434b533d303b0a53455420404f4c445f464f524549474e5f4b45595f434845434b533d4040464f524549474e5f4b45595f434845434b532c20464f524549474e5f4b45595f434845434b533d303b0a53455420404f4c445f53514c5f4d4f44453d404053514c5f4d4f44452c2053514c5f4d4f44453d27545241444954494f4e414c2c414c4c4f575f494e56414c49445f4441544553273b0a0a2d2d202d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d0a2d2d20536368656d61206572706a730a2d2d202d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d0a0a2d2d202d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d0a2d2d205461626c65206067726f7570600a2d2d202d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d0a435245415445205441424c45204946204e4f5420455849535453206067726f75706020280a20206067726f75705f69646020494e54204e4f54204e554c4c2c0a20206067726f75705f6e616d6560205641524348415228363029204e4f54204e554c4c2c0a20205052494d415259204b455920286067726f75705f69646029290a454e47494e45203d20496e6e6f44420a434f4d4d454e54203d2027412067656e6572616
.....
2d2d2d0a2d2d20466978204e554c4c206973737565207769746820656d707479206e616d657320286167682c207374757069642043535620696d706f727473290a2d2d202d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d2d0a0a5354415254205452414e53414354494f4e3b0a55504441544520606c6564676572602053455420606c65646765725f6e616d6560203d204e554c4c20574845524520606c65646765725f6e616d6560203d2027273b0a55504441544520606c65646765725f6d75746174696f6e602053455420606c65646765725f6d75746174696f6e5f6e616d6560203d204e554c4c20574845524520606c65646765725f6d75746174696f6e5f6e616d6560203d2027273b0a0a434f4d4d49543b0a
{ Error: write EPIPE
    at WriteWrap.afterWrite [as oncomplete] (net.js:835:14) errno: 'EPIPE', code: 'EPIPE', syscall: 'write', fatal: true }

[dougwilson]

Thanks for the report! We can take a look, can you include the data, script, and module version so we can reproduce the issue?

[danger89]

Sure!

[dougwilson]

Thanks! Also Node.js version you're using may be relevant if you can include that.

[danger89]

Aha.. I switched from mysql2 to mysql (still crashes tho). But could have a lead..

Error: write EPIPE
    at WriteWrap.afterWrite [as oncomplete] (net.js:835:14)
    --------------------
    at Protocol._enqueue (/my_project/node_modules/mysql/lib/protocol/Protocol.js:145:48)
    at Connection.query (/my_project/node_modules/mysql/lib/Connection.js:208:25)
    at my_script:37:16
    at FSReqWrap.readFileAfterClose [as oncomplete] (fs.js:422:3)

[dougwilson]

In case it helps as well, what EPIPE means is documented in Node.js https://nodejs.org/dist/latest-v10.x/docs/api/errors.html#errors_common_system_errors

[dougwilson]

EPIPE (Broken pipe): A write on a pipe, socket, or FIFO for which there is no process to read the data. Commonly encountered at the net and http layers, indicative that the remote side of the stream being written to has been closed.

It seems to indicate that the mysql server closed the connection?

[danger89]

Or is the file closing while it tries to preform the query??
Sorry I didn't provide you all the info yet. But this is the script:
https://gitlab.melroy.org/snippets/15

[dougwilson]

So i removed the config thing since that is not provided and changed it to a local docker image. I then put in some SQL into the file and it ran the SQL fine for me. Maybe it depends on what is in that file?

[danger89]

Please check the snippet again. I uploaded the sql file (DOWNLOAD FILE) :). This problem occurs only when the file is 'too big'.

More details:

• Node v10.1.0
• Mysql v2.15.0
• Mysql2 v1.5.3

[danger89]

I do have a "smaller" version from the original file (download smaller file). Which do execute fine.

[danger89]

I really have the feeling I'm incorrect using fs.readFile for some reason..

[dougwilson]

So I tried to run your stuff and it ran without any issue. The error seems to indicate an issue with your MySQL server from the Node.js docs and your error happens with both mysql and mysql2. Are you sure there is an issue with the client? Here is what I ran if you can spot maybe where I did something different from you:

out.log

[danger89]

Ok so maybe it's a time-out of my mariadb server.. :S. I think you are right about the fact the connection seems to be disconnected while in the readFile callback..

EDIT: Currently banging my head against the wall.. :face_with_head_bandage:

[dougwilson]

I notice you keep editing your comments -- I am reading your comments that come in over email, and Github doesn't send any emails when you edit a comment, so if you're editing a comment, just assume that I may not see it if it's something important and instead make a new comment.

[danger89]

Yea sorry about that. Not really important data still. I think... Atleast you see my database server version.

./bin/prepare_test 
<-- HandshakeInitializationPacket
HandshakeInitializationPacket {
  protocolVersion: 10,
  serverVersion: '5.5.5-10.0.34-MariaDB-0ubuntu0.16.04.1',
  threadId: 103,
  scrambleBuff1: <Buffer 2f 66 34 6e 4f 21 52 5e>,
  filler1: <Buffer 00>,
  serverCapabilities1: 63487,
  serverLanguage: 8,
  serverStatus: 2,
  serverCapabilities2: 41023,
  scrambleLength: 21,
  filler2: <Buffer 00 00 00 00 00 00 00 00 00 00>,
  scrambleBuff2: <Buffer 5e 3f 5e 3e 57 7a 22 36 29 69 59 61>,
  filler3: <Buffer 00>,
  pluginData: 'mysql_native_password',
  protocol41: true }

--> ClientAuthenticationPacket
ClientAuthenticationPacket {
  clientFlags: 521167,
  maxPacketSize: 0,
  charsetNumber: 33,
  filler: undefined,
  user: 'erpjs',
  scrambleBuff: <Buffer 0f b3 c1 16 53 10 4e 60 3e f4 3a 51 3d aa 39 ad 29 ed a3 16>,
  database: 'test_erpjs',
  protocol41: true }

<-- OkPacket
OkPacket {
  fieldCount: 0,
  affectedRows: 0,
  insertId: 0,
  serverStatus: 2,
  warningCount: 0,
  message: '',
  protocol41: true,
  changedRows: 0 }

--> ComQueryPacket
ComQueryPacket {
  command: 3,
  sql: '<FULL_SQL_CONTENT>'
}

(node:15469) [DEP0096] DeprecationWarning: timers.unenroll() is deprecated. Please use clearTimeout instead.
/mnt/c910940f-f82f-47a8-8a73-b93a7a23a069/Projects/erp-backend/bin/prepare_test:40
        throw err;
        ^

Error: write EPIPE
    at WriteWrap.afterWrite [as oncomplete] (net.js:835:14)
    --------------------
    at Protocol._enqueue (/mnt/c910940f-f82f-47a8-8a73-b93a7a23a069/Projects/erp-backend/node_modules/mysql/lib/protocol/Protocol.js:145:48)
    at Connection.query (/mnt/c910940f-f82f-47a8-8a73-b93a7a23a069/Projects/erp-backend/node_modules/mysql/lib/Connection.js:208:25)
    at /mnt/c910940f-f82f-47a8-8a73-b93a7a23a069/Projects/erp-backend/bin/prepare_test:38:16
    at FSReqWrap.readFileAfterClose [as oncomplete] (fs.js:422:3)

[danger89]

My Nodejs docker image doesn't have mysql-client installed, so I though let's use your mysql client to do the imports.

Well, using my mysql CLI command:
mysql Ver 15.1 Distrib 10.0.34-MariaDB, for debian-linux-gnu (x86_64) using readline 5.2

The import DOES work without any problems:
mysql -u erpjs -p test_erpjs < database.sql

I have the feeling the database server/client (still not sure), can't handle this big amount of multi line query in a single query.

[danger89]

I will play with the max_statement_time....

[dougwilson]

So MariaDB 5.5.5 is so old there is no official Docker image for it. I tried the latest 5.5 and didn't have an issue, at least. Log attached.

m.log

[danger89]

Uhm..I don't know how to read this output (5.5.5-10.0.34).

But I'm pretty use I'm using 10.0.34 actually... Also if I look in my package manager.

Servertype: MariaDB
Serverversie: 10.0.34-MariaDB-0ubuntu0.16.04.1 - Ubuntu 16.04
Protocolversie: 10 

[dougwilson]

Yea, I just noticed that. Ran again against 10.0.34 without issue. Log attached.

m10.log

[danger89]

10.0.34 doesn't have max_statement_time, so uh I'm really out of ideas now.

[dougwilson]

Would it be possible for you to install Wireshark on the machine you're running the Node.js client on (https://www.wireshark.org/) and get a capture of the packets between the client and MySQL server when this happens?

[danger89]

Sure I had wireshark already installed :smile:

Download playback file.

[danger89]

max_allowed_packet?

[danger89]

There we go.... https://stackoverflow.com/questions/93128/mysql-error-1153-got-a-packet-bigger-than-max-allowed-packet-bytes#104176

The baby is out.. xD

[dougwilson]

So there is two issues here I see from the capture.

(1) You're actually getting the error Got a packet bigger than 'max_allowed_packet' bytes
(2) The module continues to write more packets and the server hangs up on it, which causes the EPIPE error

[danger89]

Yes, exactly.. but why don't I get this max allowed packet issues during a normal command line (CLI) mysql command...?

[dougwilson]

I don't know all the details on how that is working to really know off-hand. Perhaps if you can do a packet capture of the mysql command running the file it may reveal why?

[danger89]

Yea let's try that as well! Good idea. I checked the config file in Linux Mint (/etc/mysql/mariadb.conf.d/50-server.cnf). And I see:
max_allowed_packet = 16M

[danger89]

Perhaps if you can do a packet capture of the mysql command running the file it may reveal why?

UH.. I don't see network traffic :) so that is why! mysql is using a socket connection of course!

[dougwilson]

Ah. You can use the socketPath option with this module to use a socket connection instead of a TCP connection if that works better for your use-case anyway (it's more efficient for localhost).

[danger89]

@dougwilson Maybe not ideal, I would like to have a general solution on all platforms, my computer as well as docker. Nevertheless I tried your option.... Which is quite _INTERESTING_...

Still got an error, but this time it's very clear!

./bin/prepare_test 
(node:19104) [DEP0096] DeprecationWarning: timers.unenroll() is deprecated. Please use clearTimeout instead.
/mnt/c910940f-f82f-47a8-8a73-b93a7a23a069/Projects/erp-backend/node_modules/mysql/lib/protocol/Parser.js:80
        throw err; // Rethrow non-MySQL errors
        ^

Error: ER_NET_PACKET_TOO_LARGE: Got a packet bigger than 'max_allowed_packet' bytes
    at Query.Sequence._packetToError (/mnt/c910940f-f82f-47a8-8a73-b93a7a23a069/Projects/erp-backend/node_modules/mysql/lib/protocol/sequences/Sequence.js:52:14)
    at Query.ErrorPacket (/mnt/c910940f-f82f-47a8-8a73-b93a7a23a069/Projects/erp-backend/node_modules/mysql/lib/protocol/sequences/Query.js:77:18)
    at Protocol._parsePacket (/mnt/c910940f-f82f-47a8-8a73-b93a7a23a069/Projects/erp-backend/node_modules/mysql/lib/protocol/Protocol.js:279:23)
    at Parser.write (/mnt/c910940f-f82f-47a8-8a73-b93a7a23a069/Projects/erp-backend/node_modules/mysql/lib/protocol/Parser.js:76:12)
    at Protocol.write (/mnt/c910940f-f82f-47a8-8a73-b93a7a23a069/Projects/erp-backend/node_modules/mysql/lib/protocol/Protocol.js:39:16)
    at Socket.<anonymous> (/mnt/c910940f-f82f-47a8-8a73-b93a7a23a069/Projects/erp-backend/node_modules/mysql/lib/Connection.js:103:28)
    at Socket.emit (events.js:182:13)
    at addChunk (_stream_readable.js:277:12)
    at readableAddChunk (_stream_readable.js:262:11)
    at Socket.Readable.push (_stream_readable.js:217:10)
    --------------------
    at Protocol._enqueue (/mnt/c910940f-f82f-47a8-8a73-b93a7a23a069/Projects/erp-backend/node_modules/mysql/lib/protocol/Protocol.js:145:48)
    at Connection.query (/mnt/c910940f-f82f-47a8-8a73-b93a7a23a069/Projects/erp-backend/node_modules/mysql/lib/Connection.js:208:25)
    at /mnt/c910940f-f82f-47a8-8a73-b93a7a23a069/Projects/erp-backend/bin/prepare_test:38:16
    at FSReqWrap.readFileAfterClose [as oncomplete] (fs.js:422:3)

Meaning there is still a difference apparently in using your NodeJS mysql client or the mysql client CLI command.

[danger89]

Ps. I tried to increase this to 64M still without luck :confused: max_allowed_packet = 64M.

[dougwilson]

Very strange. I'm trying to dig in, but it's quite difficult right now without being able to reproduce locally as I can't tell if what I'm trying works any differently or not.

[danger89]

yes, it's frustrating that you can't reproduce my problem. Currently using Linux Mint 18.3 64bit Cinnamon with MariaDB server 10.0.34. Maybe run a VM?

[dougwilson]

Yea, I'll look into doing that. If you run though my steps, does it reproduce for you? I would hate to throw a random VM together only for it not to work. I'm wondering if (1) does running my commands on your machine repro or not and then (2) are there any specific command you can provide like mine I can just steps through to get a reproduction on my end? I'm about to head off for the night and it's the weekend here so I'll see how much time I have, but certainly not having my work machine won't have somewhere to run a VM on until the week starts again :+1:

[danger89]

I do use deb https://deb.nodesource.com/node_10.x xenial main as extra deb source for getting Node v10.1.0.

package.json

package-lock.json

[danger89]

Hehe, I see. it's also 3 o clock for me at midnight. I also go to bed, thanks for your help so far! :+1:

I will try to reproduce your docker commands anytime soon, to see if that is just working fine...

[sqlbot]

@danger89 MySQL and MariaDB both have two values both called max_allowed_packet -- one on the server and one for the CLI. Ensure that the one you are changing is in a config section tagged [mysqld]. In any other section, the server will not see it. If defined more than once in the correct section of the config file(s), the result may be unexpected.

SELECT @@max_allowed_packet; on the server to ensure that your config change has actually taken effect.

[danger89]

@sqlbot Thanks. I indeed added it to the [mysqld] section, in fact it was already part of the /etc/mysql/mariadb.conf.d/50-server.cnf file. In the config file this max_allowed_packet was set on 16MB, I try to change it to 32MB and even 64MB.

But in all cases my MariaDB server says:

+----------------------+
| @@max_allowed_packet |
+----------------------+
|              1048576 |

Which is still only 1MB!

Also interesting to note is that I'm using the current Linux Mint 18.3 version of MariaDB --> v10.0.34.
The max_allowed_packet default values do differ a lot between the versions.

Default Value:

16777216 (16M) >= MariaDB 10.2.4
4194304 (4M) >= MariaDB 10.1.7
1048576 (1MB) <= MariaDB 10.1.6

EDIT: The MySQL Docker does use 16MB by default (which is not the default version officially provided by MariaDB):

docker exec mysql mysql -e 'select version()'
version()
10.0.34-MariaDB-1~jessie

docker exec mysql mysql -e 'SELECT @@max_allowed_packet'
@@max_allowed_packet
16777216 --> 16MB

[sqlbot]

@danger89 at the risk of asking the obvious, are you restarting the service after changing the configuration?

[danger89]

@sqlbot Yes I did restart my service ;)...

But the solution is that for some reason Linux Mint (Ubuntu, which is again based on Debian) is not creating /etc/mysql/my.cnf config file used by MariaDB from v10.0.13 and up.

Although I have a folder with cnf files in /etc/mysql/mariadb.conf.d/ these are basically ignored. :confused:

After creating a manually a my.cnf file in the root of /etc/mysql directory. Increasing again the max_allowed_packet, it works!

+----------------------+
| @@max_allowed_packet |
+----------------------+
| 67108864 |
+----------------------+

I don't see my.cnf being part of the mariadb-server-10.0 package:

...
/etc/mysql
/etc/mysql/debian-start
/etc/mysql/mariadb.conf.d
/etc/mysql/mariadb.conf.d/50-mysqld_safe.cnf
/etc/mysql/mariadb.conf.d/50-server.cnf
....

It could be me, but I think it's a MariaDB 'flaw', since they don't provide any relevant my.cnf file by default. Causing the MariaDB default value in my case max_allowed_packet of 1MB by default.

Ps. I think the mysql CLI handle the sql file in a different way (eg. smaller multiple SQL query, instead of 1 big one..).

[dougwilson]

I'm going to re-open this for the time being, as I had to back out the commit from master for the time being as it revealed a MariaDB protocol difference so failed CI. I will adjust the fix and when it's back on master will re-close this 👍