Skip to content

Commit

Permalink
Browse files Browse the repository at this point in the history
[misc] add debug option logPackets permitting to log last packets to …
…error
  • Loading branch information
rusher committed Nov 6, 2018
1 parent f2c0687 commit 65c1ad2
Show file tree
Hide file tree
Showing 8 changed files with 130 additions and 35 deletions.
1 change: 1 addition & 0 deletions appveyor.yml
Expand Up @@ -9,6 +9,7 @@ environment:
CMAKE_PARAM: 'Visual Studio 15 2017 Win64'
MUST_USE_TCPIP: 1
TEST_HOST: mariadb.example.com
TEST_LOG_PACKETS: true
matrix:

- DB: '10.2.16'
Expand Down
3 changes: 2 additions & 1 deletion lib/config/connection-options.js
Expand Up @@ -30,6 +30,7 @@ class ConnectionOptions {
this.collation = Collations.fromIndex(opts.charsetNumber) || Collations.fromIndex(224); //UTF8MB4_UNICODE_CI;
}
this.compress = opts.compress || false;
this.logPackets = opts.logPackets || false;
this.connectAttributes = opts.connectAttributes || false;
this.connectTimeout = opts.connectTimeout === undefined ? 10000 : opts.connectTimeout;
this.socketTimeout = opts.socketTimeout === undefined ? 0 : opts.socketTimeout;
Expand Down Expand Up @@ -103,7 +104,7 @@ class ConnectionOptions {
*/
static parseOptionDataType(opts) {
if (opts.bigNumberStrings) opts.bigNumberStrings = opts.bigNumberStrings == "true";
if (opts.bigNumberStrings) opts.bigNumberStrings = opts.bigNumberStrings == "true";
if (opts.logPackets) opts.logPackets = opts.logPackets == "true";
if (opts.charset && !isNaN(Number.parseInt(opts.charset)))
opts.charset = Number.parseInt(opts.charset);
if (opts.compress) opts.compress = opts.compress == "true";
Expand Down
9 changes: 9 additions & 0 deletions lib/connection.js
Expand Up @@ -888,6 +888,10 @@ function Connection(options) {
*/
const _socketTimeoutReached = function() {
const err = Errors.createError("socket timeout", true, info, "08S01", Errors.ER_SOCKET_TIMEOUT);
const packetMsgs = info.getLastPackets();
if (packetMsgs !== "") {
err.message = err.message + "\nlast received packets:\n" + packetMsgs;
}
_fatalError(err, true);
};

Expand Down Expand Up @@ -980,6 +984,11 @@ function Connection(options) {
this.sqlState = "HY000";
}

const packetMsgs = info.getLastPackets();
if (packetMsgs !== "") {
err.message += "\nlast received packets:\n" + packetMsgs;
}

switch (_status) {
case Status.CONNECTING:
case Status.AUTHENTICATING:
Expand Down
48 changes: 35 additions & 13 deletions lib/io/packet-input-stream.js
Expand Up @@ -27,19 +27,41 @@ class PacketInputStream {

receivePacket(packet) {
let cmd = this.currentCmd();
if (this.opts.debug && !this.opts.debugCompress && packet) {
console.log(
"<== conn:%d %s (%d,%d)\n%s",
this.info.threadId ? this.info.threadId : -1,
cmd
? cmd.onPacketReceive
? cmd.constructor.name + "." + cmd.onPacketReceive.name
: cmd.constructor.name
: "no command",
packet.pos,
packet.end,
Utils.log(this.opts, packet.buf, packet.pos, packet.end, this.header)
);

if (packet && (this.opts.logPackets || (this.opts.debug && !this.opts.debugCompress))) {
const packetStr = Utils.log(this.opts, packet.buf, packet.pos, packet.end, this.header);
if (this.opts.logPackets) {
this.info.addPacket(
"<== conn:" +
(this.info.threadId ? this.info.threadId : -1) +
" " +
(cmd
? cmd.onPacketReceive
? cmd.constructor.name + "." + cmd.onPacketReceive.name
: cmd.constructor.name
: "no command") +
" (" +
packet.pos +
"," +
packet.end +
"))\n" +
packetStr
);
}
if (this.opts.debug && !this.opts.debugCompress) {
console.log(
"<== conn:%d %s (%d,%d)\n%s",
this.info.threadId ? this.info.threadId : -1,
cmd
? cmd.onPacketReceive
? cmd.constructor.name + "." + cmd.onPacketReceive.name
: cmd.constructor.name
: "no command",
packet.pos,
packet.end,
packetStr
);
}
}

if (!cmd) {
Expand Down
75 changes: 54 additions & 21 deletions lib/io/packet-output-stream.js
Expand Up @@ -442,18 +442,36 @@ class PacketOutputStream {

this.stream.writeBuf(this.buf.slice(0, this.pos), this.cmd);

if (this.opts.debug && !this.opts.debugCompress) {
console.log(
"==> conn:%d %s\n%s",
this.info.threadId ? this.info.threadId : -1,
(this.cmd.onPacketReceive
? this.cmd.constructor.name + "." + this.cmd.onPacketReceive.name
: this.cmd.constructor.name) +
"(0," +
this.pos +
")",
Utils.log(this.opts, this.buf, 0, this.pos)
);
if (this.opts.logPackets || (this.opts.debug && !this.opts.debugCompress)) {
const packet = Utils.log(this.opts, this.buf, 0, this.pos);
if (this.opts.logPackets) {
this.info.addPacket(
"==> conn:" +
(this.info.threadId ? this.info.threadId : -1) +
" " +
(this.cmd.onPacketReceive
? this.cmd.constructor.name + "." + this.cmd.onPacketReceive.name
: this.cmd.constructor.name) +
"(0," +
this.pos +
")\n" +
packet
);
}

if (this.opts.debug && !this.opts.debugCompress) {
console.log(
"==> conn:%d %s\n%s",
this.info.threadId ? this.info.threadId : -1,
(this.cmd.onPacketReceive
? this.cmd.constructor.name + "." + this.cmd.onPacketReceive.name
: this.cmd.constructor.name) +
"(0," +
this.pos +
")",
Utils.log(this.opts, this.buf, 0, this.pos)
);
}
}

if (commandEnd) {
Expand All @@ -473,15 +491,30 @@ class PacketOutputStream {
writeEmptyPacket() {
const emptyBuf = Buffer.from([0x00, 0x00, 0x00, ++this.cmd.sequenceNo]);

if (this.opts.debug && !this.opts.debugCompress) {
console.log(
"==> conn:%d %s\n%s",
this.info.threadId ? this.info.threadId : -1,
(this.cmd.onPacketReceive
? this.cmd.constructor.name + "." + this.cmd.onPacketReceive.name
: this.cmd.constructor.name) + "(0,4)",
Utils.log(this.opts, emptyBuf, 0, 4)
);
if (this.opts.logPackets || (this.opts.debug && !this.opts.debugCompress)) {
const packet = Utils.log(this.opts, emptyBuf, 0, 4);
if (this.opts.logPackets) {
this.info.addPacket(
"==> conn:" +
(this.info.threadId ? this.info.threadId : -1) +
" " +
(this.cmd.onPacketReceive
? this.cmd.constructor.name + "." + this.cmd.onPacketReceive.name
: this.cmd.constructor.name) +
"(0,4)\n" +
packet
);
}
if (this.opts.debug && !this.opts.debugCompress) {
console.log(
"==> conn:%d %s\n%s",
this.info.threadId ? this.info.threadId : -1,
(this.cmd.onPacketReceive
? this.cmd.constructor.name + "." + this.cmd.onPacketReceive.name
: this.cmd.constructor.name) + "(0,4)",
packet
);
}
}

this.stream.writeBuf(emptyBuf, this.cmd);
Expand Down
12 changes: 12 additions & 0 deletions lib/io/packet.js
Expand Up @@ -491,6 +491,18 @@ class Packet {
let msg = this.buf.toString("utf8", this.pos, this.end);
if (sql) msg += "\n" + sql;
let fatal = sqlState.startsWith("08") || sqlState === "70100";
if (fatal) {
const packetMsgs = info.getLastPackets();
if (packetMsgs !== "")
return Errors.createError(
msg + "\nlast received packets:\n" + packetMsgs,
fatal,
info,
sqlState,
errorCode,
stack
);
}
return Errors.createError(msg, fatal, info, sqlState, errorCode, stack);
}
}
Expand Down
16 changes: 16 additions & 0 deletions lib/misc/connection-information.js
@@ -1,10 +1,26 @@
"use strict";
const Queue = require("denque");

class ConnectionInformation {
constructor() {
this.threadId = -1;
this.status = null;
this.serverVersion = null;
this.lastPackets = new Queue();
}

addPacket(msg) {
this.lastPackets.push(msg);
while (this.lastPackets.size() > 16) this.lastPackets.shift();
}

getLastPackets() {
let output = "";
let packet;
while ((packet = this.lastPackets.shift())) {
output += "\n" + packet;
}
return output;
}

hasMinVersion(major, minor, patch) {
Expand Down
1 change: 1 addition & 0 deletions test/conf.js
Expand Up @@ -15,5 +15,6 @@ if (process.env.TEST_DB) baseConfig["database"] = process.env.TEST_DB;
if (process.env.TEST_PORT) baseConfig["port"] = parseInt(process.env.TEST_PORT, 10);
if (process.env.TEST_SOCKET_PATH) baseConfig["socketPath"] = process.env.TEST_SOCKET_PATH;
if (process.env.TEST_DEBUG_LEN) baseConfig["debugLen"] = process.env.TEST_DEBUG_LEN;
if (process.env.TEST_LOG_PACKETS) baseConfig["logPackets"] = true;

module.exports.baseConfig = baseConfig;

0 comments on commit 65c1ad2

Please sign in to comment.