Access Denied after database restart (but granted after login via CLI)

[pvillaverde]

Hey there!

I've found what it seems to be a strange bug in the authentication with the database. Whenever the database server is restarted, I am getting an access denied error like this one:

error: Uncaught (in promise) Error: Access denied for user 'my_username'@'127.0.0.1' (using password: YES)
    at Packet.asError (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/packets/packet.js:728:17)
    at ClientHandshake.execute (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/commands/command.js:29:26)
    at Connection.handlePacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:481:34)
    at PacketParser.onPacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:97:12)
    at PacketParser.executeStart (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/packet_parser.js:75:16)
    at Socket.<anonymous> (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:104:25)
    at Socket.emit (ext:deno_node/_stream.mjs:1851:9)
    at addChunk (ext:deno_node/_stream.mjs:2873:16)
    at readableAddChunk (ext:deno_node/_stream.mjs:2852:13)
    at Socket.Readable.push (ext:deno_node/_stream.mjs:2791:14)

The user has the permissions to login from anywhere ('%') and is using the new caching_sha2_password, as I was tired of the deprecation warnings logs in the database about the mysql_native_password plugin.

My workarround at this moment is the most weird part. If I login to the database with the same credentials using the mysql CLI, I got not error at all, and afterwards the application can also login without getting any more errors until the next database restart.

I've been researching a lot in the last day about this issue but can't find any answer or permanent solution. Anyone else has run into the same issue and can give me some guidance? If you need more information let me know.

Other information

MySQL Version: 8.0.36
Mysql2 version: 3.9.7

[sidorares]

Can you check what is the auth sequence initially ( when it fails ) and after ?

mysql2 currently always connects mysql_native_password initially and then follows AUTH_SWITCH_REQUEST exchange ( see more details here #2143 )

node-mysql2/lib/auth_plugins/caching_sha2_password.js

Lines 56 to 95 in 0edda85

	case STATE_INITIAL:
	scramble = data.slice(0, 20);
	state = STATE_TOKEN_SENT;
	return calculateToken(password, scramble);
	case STATE_TOKEN_SENT:
	if (FAST_AUTH_SUCCESS_PACKET.equals(data)) {
	state = STATE_FINAL;
	return null;
	}
	if (PERFORM_FULL_AUTHENTICATION_PACKET.equals(data)) {
	const isSecureConnection =
	typeof pluginOptions.overrideIsSecure === 'undefined'
	? connection.config.ssl || connection.config.socketPath
	: pluginOptions.overrideIsSecure;
	if (isSecureConnection) {
	state = STATE_FINAL;
	return Buffer.from(`${password}\0`, 'utf8');
	}
	// if client provides key we can save one extra roundrip on first connection
	if (pluginOptions.serverPublicKey) {
	return authWithKey(pluginOptions.serverPublicKey);
	}
	state = STATE_WAIT_SERVER_KEY;
	return REQUEST_SERVER_KEY_PACKET;
	}
	throw new Error(
	`Invalid AuthMoreData packet received by ${PLUGIN_NAME} plugin in STATE_TOKEN_SENT state.`
	);
	case STATE_WAIT_SERVER_KEY:
	if (pluginOptions.onServerPublicKey) {
	pluginOptions.onServerPublicKey(data);
	}
	return authWithKey(data);
	case STATE_FINAL:
	throw new Error(
	`Unexpected data in AuthMoreData packet received by ${PLUGIN_NAME} plugin in STATE_FINAL state.`

caching_sha2_password documentation - https://dev.mysql.com/doc/refman/8.0/en/caching-sha2-pluggable-authentication.html

Note that for "insecure" ( e.i no tls ) connections it might default to "non fast flow". You can change that by specifying pluginOptions.serverPublicKey and/or pluginOptions.overrideIsSecure. Example of setting options: https://github.com/sidorares/node-mysql2/blob/0edda852d767da673b74c8e0e9a816f5a14dcdf7/lib/auth_plugins/caching_sha2_password.md

[pvillaverde]

I've tried specifying the pluginOptions but I got the same result. Here is the code I'm using to connect:

import mysql from "npm:mysql2";
import dbConfig from "../config/db.config.ts";
import logger from "../services/logger.service.ts";

const connection = mysql.createConnection({
   host: dbConfig.DB_HOST,
   user: dbConfig.DB_USER,
   password: dbConfig.DB_PASS,
   database: dbConfig.DB_NAME,
   authPlugins: {
      caching_sha2_password: mysql.authPlugins.caching_sha2_password({
         onServerPublicKey: function (key) {
            console.log(key);
         },
         serverPublicKey: `-----BEGIN PUBLIC KEY-----
REDACTED
REDACTED
REDACTED
REDACTED
REDACTED
REDACTED
REDACTED
-----END PUBLIC KEY-----`,
         overrideIsSecure: true //
      })
   },
   debug: true
});
connection.connect(err => {
   if (err) {
      logger.fatal(err)
      Deno.exit(1);
   }
})
export default connection

By the way I noticed a typo in the typescript definition here ( jonServerPublicKey)

node-mysql2/typings/mysql/lib/Auth.d.ts

Line 17 in 52d8c50

jonServerPublicKey?: (data: Buffer) => void;

I'm not sure how to check the auth sequence, I've added the debug flag and this is what I get when database has just started:

raw: 0a382e302e3336003b0600001106702d1923404400ffff210200ffdf1500000000000000000000684839020a13166b655119290063616368696e675f736861325f70617373776f726400
Trace
    at Connection.handlePacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:433:17)
    at PacketParser.onPacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:97:12)
    at PacketParser.executeStart (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/packet_parser.js:75:16)
    at Socket.<anonymous> (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:104:25)
    at Socket.emit (ext:deno_node/_stream.mjs:1851:9)
    at addChunk (ext:deno_node/_stream.mjs:2873:16)
    at readableAddChunk (ext:deno_node/_stream.mjs:2852:13)
    at Socket.Readable.push (ext:deno_node/_stream.mjs:2791:14)
    at TCP.onStreamRead [as onread] (ext:deno_node/internal/stream_base_commons.ts:152:23)
    at TCP.#read (ext:deno_node/internal_binding/stream_wrap.ts:166:12)
0 undefined ==> ClientHandshake#unknown name(0,,78)
Server hello packet: capability flags:3758096383=(long password, found rows, long flag, connect with db, no schema, compress, odbc, local files, ignore space, protocol 41, interactive, ssl, ignore sigpipe, transactions, reserved, secure connection, multi statements, multi results, ps multi results, plugin auth, connect attrs, plugin auth lenenc client data, can handle expired passwords, session track, deprecate eof, ssl verify server cert, remember options, multi factor authentication)
Sending handshake packet: flags:280687567=(long password, found rows, long flag, connect with db, odbc, local files, ignore space, protocol 41, ignore sigpipe, transactions, reserved, secure connection, multi results, plugin auth, connect attrs, plugin auth lenenc client data, session track, multi factor authentication)
0 1595 <== ClientHandshake#unknown name(1,,176)
0 1595 <== ac000001cff3ba1000000000e000000000000000000000000000000000000000000000006b69726665645f6f627261646f69726f6469786974616c0014d540d4d51e54f8837af9c549b55c2eec1e2b89dd6b69726665645f6f627261646f69726f6469786974616c006d7973716c5f6e61746976655f70617373776f726400300c5f636c69656e745f6e616d650c4e6f64652d4d7953514c2d320f5f636c69656e745f76657273696f6e05332e392e37
 raw: fe63616368696e675f736861325f70617373776f7264001106702d19234044684839020a13166b6551192900
Trace
    at Connection.handlePacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:433:17)
    at PacketParser.onPacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:97:12)
    at PacketParser.executeStart (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/packet_parser.js:75:16)
    at Socket.<anonymous> (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:104:25)
    at Socket.emit (ext:deno_node/_stream.mjs:1851:9)
    at addChunk (ext:deno_node/_stream.mjs:2873:16)
    at readableAddChunk (ext:deno_node/_stream.mjs:2852:13)
    at Socket.Readable.push (ext:deno_node/_stream.mjs:2791:14)
    at TCP.onStreamRead [as onread] (ext:deno_node/internal/stream_base_commons.ts:152:23)
    at TCP.#read (ext:deno_node/internal_binding/stream_wrap.ts:166:12)
0 1595 ==> ClientHandshake#unknown name(2,,48)
0 1595 <== ClientHandshake#unknown name(3,,36)
0 1595 <== 20000003bcd7c7329b64a2a004916561a44eada874908af421f649e20e0174d4e63f4ffb
 raw: 0104
Trace
    at Connection.handlePacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:433:17)
    at PacketParser.onPacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:97:12)
    at PacketParser.executeStart (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/packet_parser.js:75:16)
    at Socket.<anonymous> (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:104:25)
    at Socket.emit (ext:deno_node/_stream.mjs:1851:9)
    at addChunk (ext:deno_node/_stream.mjs:2873:16)
    at readableAddChunk (ext:deno_node/_stream.mjs:2852:13)
    at Socket.Readable.push (ext:deno_node/_stream.mjs:2791:14)
    at TCP.onStreamRead [as onread] (ext:deno_node/internal/stream_base_commons.ts:152:23)
    at TCP.#read (ext:deno_node/internal_binding/stream_wrap.ts:166:12)
0 1595 ==> ClientHandshake#unknown name(4,,6)
0 1595 <== ClientHandshake#unknown name(5,,23)
0 1595 <== 130000053556504e436650794a4b344c6f663372417100
 raw: ff15042332383030304163636573732064656e69656420666f72207573657220276b69726665645f6f627261646f69726f6469786974616c2740273132372e302e302e312720287573696e672070617373776f72643a2059455329
Trace
    at Connection.handlePacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:433:17)
    at PacketParser.onPacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:97:12)
    at PacketParser.executeStart (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/packet_parser.js:75:16)
    at Socket.<anonymous> (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:104:25)
    at Socket.emit (ext:deno_node/_stream.mjs:1851:9)
    at addChunk (ext:deno_node/_stream.mjs:2873:16)
    at readableAddChunk (ext:deno_node/_stream.mjs:2852:13)
    at Socket.Readable.push (ext:deno_node/_stream.mjs:2791:14)
    at TCP.onStreamRead [as onread] (ext:deno_node/internal/stream_base_commons.ts:152:23)
    at TCP.#read (ext:deno_node/internal_binding/stream_wrap.ts:166:12)
0 1595 ==> ClientHandshake#unknown name(6,Error,95)
2024-05-19 07:32:35.383 FATAL   /src/database/index.ts:32
 Error  Access denied for user 'my_username'@'127.0.0.1' (using password: YES), ER_ACCESS_DENIED_ERROR, 1045, 28000, Access denied for user 'my_username'@'127.0.0.1' (using password: YES), , [object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object]
error stack:
  • packet.js   Packet.asError
        /home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/packets/packet.js:728
  • command.js  ClientHandshake.execute
        /home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/commands/command.js:29
  • connection.js       Connection.handlePacket
        /home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:481
  • connection.js       PacketParser.onPacket
        /home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:97
  • packet_parser.js    PacketParser.executeStart
        /home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/packet_parser.js:75
  • connection.js       Socket.<anonymous>
        /home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:104
  • _stream.mjs Socket.emit
        deno_node/_stream.mjs:1851
  • _stream.mjs addChunk
        deno_node/_stream.mjs:2873
  • _stream.mjs readableAddChunk
        deno_node/_stream.mjs:2852
  • _stream.mjs Socket.Readable.push
        deno_node/_stream.mjs:2791

Then I Login through the CLI with the same credencials, this is the trace

 raw: 0a382e302e333600dc060000755c264e0f11480900ffff210200ffdf150000000000000000000045746b1f51200112780b116f0063616368696e675f736861325f70617373776f726400
Trace
    at Connection.handlePacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:433:17)
    at PacketParser.onPacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:97:12)
    at PacketParser.executeStart (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/packet_parser.js:75:16)
    at Socket.<anonymous> (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:104:25)
    at Socket.emit (ext:deno_node/_stream.mjs:1851:9)
    at addChunk (ext:deno_node/_stream.mjs:2873:16)
    at readableAddChunk (ext:deno_node/_stream.mjs:2852:13)
    at Socket.Readable.push (ext:deno_node/_stream.mjs:2791:14)
    at TCP.onStreamRead [as onread] (ext:deno_node/internal/stream_base_commons.ts:152:23)
    at TCP.#read (ext:deno_node/internal_binding/stream_wrap.ts:166:12)
0 undefined ==> ClientHandshake#unknown name(0,,78)
Server hello packet: capability flags:3758096383=(long password, found rows, long flag, connect with db, no schema, compress, odbc, local files, ignore space, protocol 41, interactive, ssl, ignore sigpipe, transactions, reserved, secure connection, multi statements, multi results, ps multi results, plugin auth, connect attrs, plugin auth lenenc client data, can handle expired passwords, session track, deprecate eof, ssl verify server cert, remember options, multi factor authentication)
Sending handshake packet: flags:280687567=(long password, found rows, long flag, connect with db, odbc, local files, ignore space, protocol 41, ignore sigpipe, transactions, reserved, secure connection, multi results, plugin auth, connect attrs, plugin auth lenenc client data, session track, multi factor authentication)
0 1756 <== ClientHandshake#unknown name(1,,176)
0 1756 <== ac000001cff3ba1000000000e000000000000000000000000000000000000000000000006b69726665645f6f627261646f69726f6469786974616c0014ef8d8a62ca672818e9d8c8ef44f0052b3de914c96b69726665645f6f627261646f69726f6469786974616c006d7973716c5f6e61746976655f70617373776f726400300c5f636c69656e745f6e616d650c4e6f64652d4d7953514c2d320f5f636c69656e745f76657273696f6e05332e392e37
 raw: fe63616368696e675f736861325f70617373776f726400755c264e0f11480945746b1f51200112780b116f00
Trace
    at Connection.handlePacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:433:17)
    at PacketParser.onPacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:97:12)
    at PacketParser.executeStart (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/packet_parser.js:75:16)
    at Socket.<anonymous> (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:104:25)
    at Socket.emit (ext:deno_node/_stream.mjs:1851:9)
    at addChunk (ext:deno_node/_stream.mjs:2873:16)
    at readableAddChunk (ext:deno_node/_stream.mjs:2852:13)
    at Socket.Readable.push (ext:deno_node/_stream.mjs:2791:14)
    at TCP.onStreamRead [as onread] (ext:deno_node/internal/stream_base_commons.ts:152:23)
    at TCP.#read (ext:deno_node/internal_binding/stream_wrap.ts:166:12)
0 1756 ==> ClientHandshake#unknown name(2,,48)
0 1756 <== ClientHandshake#unknown name(3,,36)
0 1756 <== 200000030e435d2bc5b634bad3d44192108f8204175a53a2c6afc5a1c0db273b35158ade
 raw: 010323000005
Trace
    at Connection.handlePacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:433:17)
    at PacketParser.onPacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:97:12)
    at PacketParser.executeStart (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/packet_parser.js:75:16)
    at Socket.<anonymous> (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:104:25)
    at Socket.emit (ext:deno_node/_stream.mjs:1851:9)
    at addChunk (ext:deno_node/_stream.mjs:2873:16)
    at readableAddChunk (ext:deno_node/_stream.mjs:2852:13)
    at Socket.Readable.push (ext:deno_node/_stream.mjs:2791:14)
    at TCP.onStreamRead [as onread] (ext:deno_node/internal/stream_base_commons.ts:152:23)
    at TCP.#read (ext:deno_node/internal_binding/stream_wrap.ts:166:12)
0 1756 ==> ClientHandshake#unknown name(4,,6)
 raw: 00000002400000001a0118176b69726665645f6f627261646f69726f6469786974616c
Trace
    at Connection.handlePacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:433:17)
    at PacketParser.onPacket (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:97:12)
    at PacketParser.executeStart (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/packet_parser.js:75:16)
    at Socket.<anonymous> (file:///home/my_username/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:104:25)
    at Socket.emit (ext:deno_node/_stream.mjs:1851:9)
    at addChunk (ext:deno_node/_stream.mjs:2873:16)
    at readableAddChunk (ext:deno_node/_stream.mjs:2852:13)
    at Socket.Readable.push (ext:deno_node/_stream.mjs:2791:14)
    at TCP.onStreamRead [as onread] (ext:deno_node/internal/stream_base_commons.ts:152:23)
    at TCP.#read (ext:deno_node/internal_binding/stream_wrap.ts:166:12)
0 1756 ==> ClientHandshake#unknown name(5,maybeOK,39)

[sidorares]

unfortunately logs are not super helpful, the whole "auth switch" is part of ClientHandshake command in both examples.

Could you add console.log('caching_sha2_password state: ', state); above this line

node-mysql2/lib/auth_plugins/caching_sha2_password.js

Line 56 in 0edda85

case STATE_INITIAL:

and run again 2 scenarios?

[pvillaverde]

First iteration (access denied):

Handling connection for 3306
caching_sha2_password state:  0
caching_sha2_password state:  1
2024-05-19 11:54:13.374 FATAL   /src/database/index.ts:31
 Error  Access denied for user 'my_username'@'127.0.0.1' (using password: YES), ER_ACCESS_DENIED_ERROR, 1045, 28000, Access denied for user 'my_username'@'127.0.0.1' (using password: YES), , [object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object]
error stack:

Same logs after loggin in through CLI and no access denied:

Handling connection for 3306
caching_sha2_password state:  0
caching_sha2_password state:  1

[sidorares]

can you also add console.log(data)? Perhaps in one case it finishes with FAST_AUTH_SUCCESS_PACKET and in the second with PERFORM_FULL_AUTHENTICATION_PACKET

[pvillaverde]

It's seems you are right!

Access denied gaves me 04 (PERFORM_FULL_AUTHENTICATION_PACKET):

caching_sha2_password state:  0
caching_sha2_password data:  <Buffer 28 1e 47 74 43 0a 6d 3c 46 2e 4b 72 69 0e 0a 5a 3b 52 2b 20 00>
caching_sha2_password state:  1
caching_sha2_password data:  <Buffer 04>

Then it gaves 03 (FAST_AUTH_SUCCESS_PACKET):

caching_sha2_password state:  0
caching_sha2_password data:  <Buffer 73 7b 0d 4d 27 5c 17 54 39 42 6a 74 0e 0b 4e 7e 3c 36 05 67 00>
caching_sha2_password state:  1
caching_sha2_password data:  <Buffer 03>

[sidorares]

ok, that explains the difference. The next step is to decide who is wrong - mysql2 logic for PERFORM_FULL_AUTHENTICATION_PACKET or something on your side

Can you try just setting overrideIsSecure: true and log the states?

[pvillaverde]

That was with the overrideIsSecure. I've made it a couple of times more. First with this code:

import mysql from "npm:mysql2";
import dbConfig from "../config/db.config.ts";
import logger from "../services/logger.service.ts";

const connection = mysql.createConnection({
   host: dbConfig.DB_HOST,
   user: dbConfig.DB_USER,
   password: dbConfig.DB_PASS,
   database: dbConfig.DB_NAME,
});
connection.connect(err => {
   if (err) {
      logger.fatal(err)
      Deno.exit(1);
   }
})
export default connection

I got

Handling connection for 3306
caching_sha2_password state:  0
caching_sha2_password data:  <Buffer 15 3c 4a 66 6f 68 03 7d 1a 77 28 78 25 30 19 5e 1a 15 40 01 00>
caching_sha2_password state:  1
caching_sha2_password data:  <Buffer 04>
caching_sha2_password state:  2
caching_sha2_password data:  <Buffer 2d 2d 2d 2d 2d 42 45 47 49 4e 20 50 55 42 4c 49 43 20 4b 45 59 2d 2d 2d 2d 2d 0a 4d 49 49 42 49 6a 41 4e 42 67 6b 71 68 6b 69 47 39 77 30 42 41 51 45 ... >
2024-05-20 13:42:21.227 FATAL   /src/database/index.ts:13
 Error  Access denied for user 

Then with the the overrideIsSecure:

import mysql from "npm:mysql2";
import dbConfig from "../config/db.config.ts";
import logger from "../services/logger.service.ts";

const connection = mysql.createConnection({
   host: dbConfig.DB_HOST,
   user: dbConfig.DB_USER,
   password: dbConfig.DB_PASS,
   database: dbConfig.DB_NAME,
   authPlugins: {
      caching_sha2_password: mysql.authPlugins.caching_sha2_password({
         onServerPublicKey: function (key) {
            console.log(key);
         },
         serverPublicKey: `-----BEGIN PUBLIC KEY-----
REDACTED
REDACTED
REDACTED
REDACTED
REDACTED
REDACTED
REDACTED
-----END PUBLIC KEY-----`,
         overrideIsSecure: true //
      })
   },
   debug: true
});
connection.connect(err => {
   if (err) {
      logger.fatal(err)
      Deno.exit(1);
   }
})
export default connection

And this is the output

Handling connection for 3306
caching_sha2_password state:  0
caching_sha2_password data:  <Buffer 73 79 5c 07 4a 7a 49 1d 6f 25 68 70 0b 61 2c 17 46 3d 6d 0e 00>
caching_sha2_password state:  1
caching_sha2_password data:  <Buffer 04>
2024-05-20 13:42:06.848 FATAL   /src/database/index.ts:31
 Error  Access denied for user 

After the manual login both answers are similar:

caching_sha2_password state:  0
caching_sha2_password data:  <Buffer 33 41 5f 6c 12 36 7e 5f 25 79 7b 66 6c 6b 02 7c 6d 16 41 27 00>
caching_sha2_password state:  1
caching_sha2_password data:  <Buffer 03>

Handling connection for 3306
caching_sha2_password state:  0
caching_sha2_password data:  <Buffer 01 04 7e 4a 32 30 0e 0d 7d 05 21 5b 39 15 4e 01 3a 41 27 42 00>
caching_sha2_password state:  1
caching_sha2_password data:  <Buffer 03>

[sidorares]

Can we double check the server public key you use is correct? If you use TLS ( or have overrideIsSecure: true) and do not supply the key then next state transition is (STATE_TOKEN_SENT, PERFORM_FULL_AUTHENTICATION_PACKET) -> STATE_WAIT_SERVER_KEY and the server should respond with a key ( available to you via onServerPublicKey plugin option )

[pvillaverde]

I don't have TLS, but when using 'overrideIsSecure: false' and just restarted the server I get the access denied and the server public key, but afterwards It's receives directly the FAST_AUTH_SUCCESS_PACKET:

import mysql from "npm:mysql2";
import dbConfig from "../config/db.config.ts";
import logger from "../services/logger.service.ts";

const connection = mysql.createConnection({
   host: dbConfig.DB_HOST,
   user: dbConfig.DB_USER,
   password: dbConfig.DB_PASS,
   database: dbConfig.DB_NAME,
   authPlugins: {
      caching_sha2_password: mysql.authPlugins.caching_sha2_password({
         onServerPublicKey: function (data) {
            console.log("onServerPublicKey", data);
            console.log("onServerPublicKey", data.toString());
         },
         overrideIsSecure: false //
      })
   },
   debug: false
});
connection.connect(err => {
   if (err) {
      logger.fatal(err)
      Deno.exit(1);
   } else {
      logger.info("Connected to the database!")
      Deno.exit(0)
   }
})
export default connection

Task dev deno run --allow-sys --allow-read --allow-env --allow-net --watch src/dev/mysql.ts
Watcher Process started.
Handling connection for 3306
caching_sha2_password state:  0
caching_sha2_password data:  <Buffer 07 4a 12 25 33 6a 7b 63 2b 34 47 54 79 77 48 2a 21 72 50 7d 00>
caching_sha2_password state:  1
caching_sha2_password data:  <Buffer 04>
caching_sha2_password state:  2
caching_sha2_password data:  <Buffer 2d 2d 2d 2d 2d 42 45 47 49 4e 20 50 55 42 4c 49 43 20 4b 45 59 2d 2d 2d 2d 2d 0a 4d 49 49 42 49 6a 41 4e 42 67 6b 71 68 6b 69 47 39 77 30 42 41 51 45 ... >
onServerPublicKey <Buffer 2d 2d 2d 2d 2d 42 45 47 49 4e 20 50 55 42 4c 49 43 20 4b 45 59 2d 2d 2d 2d 2d 0a 4d 49 49 42 49 6a 41 4e 42 67 6b 71 68 6b 69 47 39 77 30 42 41 51 45 ... >
onServerPublicKey -----BEGIN PUBLIC KEY-----
MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAwG8mf0lCrujOuewcK9M0
OFis3FP84P+4ZDqWdZCXxr5Epa5zk9Nx7HagKzh6jFp2Qs/NMmVEF3WbfVG/zAkE
r6n876Z3kiG886H25DjTB8/u0QTZmAu29tOG7tZHKxK0ixjfvK1tnKsWdE0Jn7Pz
Bqm+oWPSDyqUUCObAdqqkyNHjpggroTqhYi5bz61K0Sxq57gLnnchIaTGz8VMsRm
1h30/cNRh0MNqMhpk9d+1mNixYEZBOmXmbZBMOV94TzkmutebPP73ixwLtxs+Q4O
FgJhYrARirfZZjBxXCgwY5ck6UIIgyqIVk7+/kvocT/0Df4UlLimQb+jg4qw5Pnk
2wIDAQAB
-----END PUBLIC KEY-----

2024-05-21 09:23:06.292 FATAL   /src/dev/mysql.ts:23
 Error  Access denied for user

Same code after login through CLI:

Watcher Process started.
Handling connection for 3306
caching_sha2_password state:  0
caching_sha2_password data:  <Buffer 11 60 01 78 27 77 58 31 44 04 3c 3e 3c 78 11 1c 19 71 4c 57 00>
caching_sha2_password state:  1
caching_sha2_password data:  <Buffer 03>
2024-05-21 09:25:43.051 INFO    /src/dev/mysql.ts:26    Connected to the database!

[sidorares]

I just checked with docker started server ( docker run -it -p 3306:3306 -e MYSQL_ROOT_PASSWORD=test -d mysql:8 ) and a local script and it connects no issues. Also tried to run with deno, same result
First run - state 0 + scarmble, state 1 + PERFORM_FULL_AUTHENTICATION_PACKET, state 2 + public key, OK
Next runs - state 0 + scarmble, state 1 + FAST_AUTH_SUCCESS_PACKET, OK

public key seems to be similar - to yours

Algo RSA
Format X.509
 ASN1 Dump
RSA Public Key [41:fc:07:b0:e5:6f:a7:09:03:38:f6:77:e1:fc:de:0a:b8:22:f0:51]
...

[pvillaverde]

Interesting... I created the docker the same way and I still got access denied, showing you the full test:

[pvillaverde@Fedellux radio_dixital]$ docker run -it -p 3306:3306 -e MYSQL_ROOT_PASSWORD=test -d mysql:8
Unable to find image 'mysql:8' locally
8: Pulling from library/mysql
fcbdc4090331: Pull complete 
95eb5073c36f: Pull complete 
5e5ba0e6412a: Pull complete 
ee4654eb29b7: Pull complete 
1d2218160b86: Pull complete 
bbe712936412: Pull complete 
4a6efa152609: Pull complete 
0f7c3b67bb2b: Pull complete 
7ccd17e83c8a: Pull complete 
04bf2c116556: Pull complete 
Digest: sha256:4a4e5e2a19aab7a67870588952e8f401e17a330466ecfc55c9acf51196da5bd0
Status: Downloaded newer image for mysql:8
5652372d5652219375caf3625200e574e3f57697f39fd8c7517384b8b115bef6
[pvillaverde@Fedellux radio_dixital]$ mysql -u root -ptest -h 127.0.0.1
mysql: Deprecated program name. It will be removed in a future release, use '/usr/bin/mariadb' instead
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MySQL connection id is 9
Server version: 8.4.0 MySQL Community Server - GPL

Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MySQL [(none)]> SELECT user,host,plugin from mysql.user;
+------------------+-----------+-----------------------+
| user             | host      | plugin                |
+------------------+-----------+-----------------------+
| root             | %         | caching_sha2_password |
| mysql.infoschema | localhost | caching_sha2_password |
| mysql.session    | localhost | caching_sha2_password |
| mysql.sys        | localhost | caching_sha2_password |
| root             | localhost | caching_sha2_password |
+------------------+-----------+-----------------------+
5 rows in set (0,001 sec)

MySQL [(none)]> exit
Bye
[pvillaverde@Fedellux radio_dixital]$ docker ps -a
CONTAINER ID   IMAGE                                     COMMAND                  CREATED         STATUS                  PORTS                                                  NAMES
5652372d5652   mysql:8                                   "docker-entrypoint.s…"   6 minutes ago   Up 6 minutes            0.0.0.0:3306->3306/tcp, :::3306->3306/tcp, 33060/tcp   pedantic_elion
[pvillaverde@Fedellux radio_dixital]$ docker restart pedantic_elion
pedantic_elion
[pvillaverde@Fedellux radio_dixital]$ deno task dev
Task dev deno run --allow-sys --allow-read --allow-env --allow-net --watch src/dev/mysql.ts
Watcher Process started.
caching_sha2_password state:  0
caching_sha2_password data:  <Buffer 6d 60 54 78 45 02 5f 04 47 07 62 75 68 74 52 0d 0b 66 68 5d 00>
caching_sha2_password state:  1
caching_sha2_password data:  <Buffer 04>
caching_sha2_password state:  2
caching_sha2_password data:  <Buffer 2d 2d 2d 2d 2d 42 45 47 49 4e 20 50 55 42 4c 49 43 20 4b 45 59 2d 2d 2d 2d 2d 0a 4d 49 49 42 49 6a 41 4e 42 67 6b 71 68 6b 69 47 39 77 30 42 41 51 45 ... >
onServerPublicKey <Buffer 2d 2d 2d 2d 2d 42 45 47 49 4e 20 50 55 42 4c 49 43 20 4b 45 59 2d 2d 2d 2d 2d 0a 4d 49 49 42 49 6a 41 4e 42 67 6b 71 68 6b 69 47 39 77 30 42 41 51 45 ... >
onServerPublicKey -----BEGIN PUBLIC KEY-----
MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEArLrJ9qT3mOeF0Ji1Pp1f
c65WuxUcaN1dcqBqpfOYtWuvlzBX8uNYMtKW/KEP7a/yzHNwRL+J8DFl6jdq6/e3
78KikH33gKQe0VJme2FiABmq9HdXLVr/VNN9gJvGQRcFvBCchr7AOwEP8O9TVh98
NuUrqSZv1BUSvjUuWm74WKTGcjsc4SYSjorg2IWOJKMaaWVlqyEXTAqSpNdu9PIs
AZAN264bLmWjNRqVC2mAnlalB4Z1hd3e9oRrBHl2FM3vIMnAjSpsPAIDYCy6bsBH
TYxmiVRtaDzChaSRXClL7NxE6XrRUBRPlJI6MDcQ6z4wxsH6NIOWAgV46OYdEbyL
ywIDAQAB
-----END PUBLIC KEY-----

2024-05-23 18:08:30.040 FATAL   /src/dev/mysql.ts:23
 Error  Access denied for user 'root'@'172.17.0.1' (using password: YES), ER_ACCESS_DENIED_ERROR, 1045, 28000, Access denied for user 'root'@'172.17.0.1' (using password: YES), , [object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object],[object Object]
error stack:
  • packet.js   Packet.asError
        /home/pvillaverde/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/packets/packet.js:728
  • command.js  ClientHandshake.execute
        /home/pvillaverde/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/commands/command.js:29
  • connection.js       Connection.handlePacket
        /home/pvillaverde/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:481
  • connection.js       PacketParser.onPacket
        /home/pvillaverde/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:97
  • packet_parser.js    PacketParser.executeStart
        /home/pvillaverde/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/packet_parser.js:75
  • connection.js       Socket.<anonymous>
        /home/pvillaverde/.cache/deno/npm/registry.npmjs.org/mysql2/3.9.7/lib/connection.js:104
  • _stream.mjs Socket.emit
        deno_node/_stream.mjs:1851
  • _stream.mjs addChunk
        deno_node/_stream.mjs:2873
  • _stream.mjs readableAddChunk
        deno_node/_stream.mjs:2852
  • _stream.mjs Socket.Readable.push
        deno_node/_stream.mjs:2791
[pvillaverde@Fedellux radio_dixital]$ mysql -u root -ptest -h 127.0.0.1
mysql: Deprecated program name. It will be removed in a future release, use '/usr/bin/mariadb' instead
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MySQL connection id is 12
Server version: 8.4.0 MySQL Community Server - GPL

Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MySQL [(none)]> SHOW DATABASES;
+--------------------+
| Database           |
+--------------------+
| information_schema |
| mysql              |
| performance_schema |
| sys                |
+--------------------+
4 rows in set (0,016 sec)

MySQL [(none)]> ^C
MySQL [(none)]> exit
Bye
[pvillaverde@Fedellux radio_dixital]$ deno task dev
Task dev deno run --allow-sys --allow-read --allow-env --allow-net --watch src/dev/mysql.ts
Watcher Process started.
caching_sha2_password state:  0
caching_sha2_password data:  <Buffer 6c 7e 2f 01 7b 41 68 25 17 35 35 7f 22 1f 02 32 67 65 4c 09 00>
caching_sha2_password state:  1
caching_sha2_password data:  <Buffer 03>
2024-05-23 18:10:22.846 INFO    /src/dev/mysql.ts:26    Connected to the database!

The code I used:

export default {
 DB_HOST: "localhost",
 DB_USER: "root",
 DB_PASS: "test",
 DB_NAME: "mysql",
};

import mysql from "npm:mysql2";
import dbConfig from "../config/db.config.ts";
import logger from "../services/logger.service.ts";

const connection = mysql.createConnection({
 host: dbConfig.DB_HOST,
 user: dbConfig.DB_USER,
 password: dbConfig.DB_PASS,
 database: dbConfig.DB_NAME,
 authPlugins: {
    caching_sha2_password: mysql.authPlugins.caching_sha2_password({
       onServerPublicKey: function (data) {
          console.log("onServerPublicKey", data);
          console.log("onServerPublicKey", data.toString());
       },
       overrideIsSecure: false //
    })
 },
 debug: false
});
connection.connect(err => {
 if (err) {
    logger.fatal(err)
    Deno.exit(1);
 } else {
    logger.info("Connected to the database!")
    Deno.exit(0)
 }
})
export default connection

Just in case we missed something else out with the versions. I'm using Deno and these versions:

deno 1.43.2 (release, x86_64-unknown-linux-gnu)
v8 12.4.254.12
typescript 5.4.5
---
mysql2@3.9.7

Aaaand, it might be related to Deno(?). I've rewrote the code for NodeJS, installed the library and now I get what you get:

import mysql from 'mysql2';
const dbConfig = {
   DB_HOST: "localhost",
   DB_USER: "root",
   DB_PASS: "test",
   DB_NAME: "mysql",
};

const connection = mysql.createConnection({
   host: dbConfig.DB_HOST,
   user: dbConfig.DB_USER,
   password: dbConfig.DB_PASS,
   database: dbConfig.DB_NAME,
   authPlugins: {
      caching_sha2_password: mysql.authPlugins.caching_sha2_password({
         onServerPublicKey: function (data) {
            console.log("onServerPublicKey", data);
            console.log("onServerPublicKey", data.toString());
         },
         overrideIsSecure: false
      })
   },
   debug: false
});

connection.connect(err => {
   if (err) {
      console.error(err);
      process.exit(1);
   } else {
      console.info("Connected to the database!");
      process.exit(0);
   }
});

export default connection;

[pvillaverde@Fedellux dev]$ docker restart pedantic_elion
pedantic_elion
[pvillaverde@Fedellux dev]$ node mysql.mjs 
caching_sha2_password state:  0
caching_sha2_password data:  <Buffer 4d 01 3f 50 42 20 75 7f 4f 60 6e 0a 28 30 68 6c 6b 14 21 7b 00>
caching_sha2_password state:  1
caching_sha2_password data:  <Buffer 04>
caching_sha2_password state:  2
caching_sha2_password data:  <Buffer 2d 2d 2d 2d 2d 42 45 47 49 4e 20 50 55 42 4c 49 43 20 4b 45 59 2d 2d 2d 2d 2d 0a 4d 49 49 42 49 6a 41 4e 42 67 6b 71 68 6b 69 47 39 77 30 42 41 51 45 ... 401 more bytes>
onServerPublicKey <Buffer 2d 2d 2d 2d 2d 42 45 47 49 4e 20 50 55 42 4c 49 43 20 4b 45 59 2d 2d 2d 2d 2d 0a 4d 49 49 42 49 6a 41 4e 42 67 6b 71 68 6b 69 47 39 77 30 42 41 51 45 ... 401 more bytes>
onServerPublicKey -----BEGIN PUBLIC KEY-----
MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEArLrJ9qT3mOeF0Ji1Pp1f
c65WuxUcaN1dcqBqpfOYtWuvlzBX8uNYMtKW/KEP7a/yzHNwRL+J8DFl6jdq6/e3
78KikH33gKQe0VJme2FiABmq9HdXLVr/VNN9gJvGQRcFvBCchr7AOwEP8O9TVh98
NuUrqSZv1BUSvjUuWm74WKTGcjsc4SYSjorg2IWOJKMaaWVlqyEXTAqSpNdu9PIs
AZAN264bLmWjNRqVC2mAnlalB4Z1hd3e9oRrBHl2FM3vIMnAjSpsPAIDYCy6bsBH
TYxmiVRtaDzChaSRXClL7NxE6XrRUBRPlJI6MDcQ6z4wxsH6NIOWAgV46OYdEbyL
ywIDAQAB
-----END PUBLIC KEY-----

Connected to the database!
[pvillaverde@Fedellux dev]$ node mysql.mjs 
caching_sha2_password state:  0
caching_sha2_password data:  <Buffer 4e 7a 2f 61 0d 06 74 62 1d 58 57 1e 79 4f 5e 55 6c 40 03 45 00>
caching_sha2_password state:  1
caching_sha2_password data:  <Buffer 03>
Connected to the database!

Strange... the code from the library is exactly the same so... the problem is elsewhere, but I have no clue where it might be... and why it only fails the first time...

[sidorares]

Strange... the code from the library is exactly the same so... the problem is elsewhere, but I have no clue where it might be... and why it only fails the first time...

It fails the first time because failure path is somewhere in cert + encryprion. The server remembers client somehow and chooses "fast auth" sequence

I tried with very old deno version - maybe you are right and it's something on deno side, maybe crypto implementation or something else. I'll try with 1.43.2

[sidorares]

@pvillaverde I can replicate the issue with deno v1.43.2 and I'll try do debug what's happening

Could you try to use deno v1.29.4 - this is the version that worked with no issues for me

[sidorares]

I think I found the culprit: crypto.publicEncrypt() returns Uint8Array in v1.43.2 and Buffer in v1.29.4 or node