node-mysql2 の timeout オプションでタイムアウトした次のクエリが前回のタイムアウトしたクエリの終了を待つ

node-mysql2 を弄っていたところ次のようなコードで、1番目のクエリが1ミリ秒でタイムアウトした後、2番目のクエリが1番目のクエリの sleep(10) を待ってから実行される=10秒かかる、という現象がありました。

(async () => {
    const pool = mysql.createPool({ host: "127.0.0.1", port: 3306, user: "user", password: "pass" });

    {
        const conn = await pool.getConnection();
        try {
            // 1ミリ秒でタイムアウト
            const sql = `select sleep(10)`;
            await conn.query({ sql, timeout: 1 });
        } catch (err) {
            console.error(err);
        } finally {
            conn.release();
        }
    }

    {
        const conn = await pool.getConnection();
        try {
            // 10秒待たされる
            const sql = `select 1`;
            const res = await conn.query({ sql });
            console.log(res);
        } catch (err) {
            console.error(err);
        } finally {
            conn.release();
        }
    }

    await pool.end();
})();

これは node-mysql2 のバグ・・というわけでも無いです。この timeout はあくまでもクライアント側で制御しているタイムアウトなので、1番目のクエリがタイムアウトしても MySQL 的にはまだまだクエリ実行中です。そして2番目のクエリのためにプールから取り出された接続が1番目の接続と同じになると、同じ接続上では前回のクエリが終わるまで次のクエリは実行できないので、単なる select 1 が10秒待たされることになります。

クライアント側でタイムアウトしたとき、何かしらの方法でクエリを中断できればいいのですが、MySQL では実行中のクエリを中断する正当な方法は無く、別の接続を使って接続を KILL するぐらいしかありません。

        const conn = await pool.getConnection();
        try {
            const sql = `select sleep(10)`;
            await conn.query({ sql, timeout: 1 });
        } catch (err) {
            console.error(err);
            if (err instanceof Error && "code" in err && err.code === "PROTOCOL_SEQUENCE_TIMEOUT") {
                const conn2 = await pool.getConnection();
                try {
                    // 別の接続を使って KILL する
                    await conn2.query(`KILL ?`, [conn.threadId]);
                } finally {
                    conn2.release();
                    // 切断された接続はプールから削除されるものの、
                    // 非同期なので次のクエリが先に実行される可能性があるため、
                    // release 前に destroy してプールから削除しておく
                    conn.destroy();
                }
            }
        } finally {
            conn.release();
        }

あるいは KILL までしなくても conn.destroy だけで良いかも。これは正しい手続きを行わずに TCP ぶつ切りにするためサーバ側で Aborted connection とかになりますが、プールからも削除されるし接続も切れる・・と思ったのですが、完全に閉じているわけではなくソケットの送信側をシャットダウンしているだけでした、

のでサーバ側で Aborted connection となって切断されるまでは生きたままなので、node のプロセスの終了時に待ち時間が発生してしまうことがあるようです。

さいごに

10年以上前にC言語で MySQL に接続していたときにも同じことに悩まされたような・・MySQL はクエリを多重化できないし(クエリの結果をフェッチしきるまで次のクエリが実行できない)、実行中のクエリを止める手段も無いし(別接続を使って KILL とかかなりの荒業だと思う)、切断しようにもクエリの終了が待たされるし(mysql_close もクエリ実行中は待たされる)、どうしたものか。

長いこと PHP ばかり使っていてあまり気にしていませんでしたが、PDO で mysqlnd.net_read_timeout とかでタイムアウトしたときは TCP ぶつ切りになります。なのでそれ以後に同じ PDO インスタンスを使うとすべてエラーになります。まあそうするしかないですね。

余談ですが node-mysql2 はプールから接続を取り出すときに LIFO で取り出します。つまり最後にプールに戻った接続が最初に取り出されるので、前述のようなケースでプールに複数の接続があったとしても1番目と2番目で同じ接続が使われやすい、という問題もあるかも。