Improve diagnosability of internal errors with more network packet information

Author: sharadraju

doc/src/release_notes.rst

@@ -17,6 +17,8 @@ Common Changes
 Thin Mode Changes
 +++++++++++++++++
 
+#)  Add packet number and position in packet for some internal errors for improved diagnosability.
+
 #)  Fixed bug that throws the NJS-111 internal error, on the second
     select SQL issued after first select SQL is done on an empty
     table involving LOB types.

lib/errors.js

@@ -328,7 +328,7 @@ messages.set(ERR_MISSING_CREDENTIALS,                   // NJS-101
 messages.set(ERR_UNEXPECTED_END_OF_DATA,                // NJS-102
   'unexpected end of data: want %d bytes but only %d bytes are available');
 messages.set(ERR_UNEXPECTED_MESSAGE_TYPE,               // NJS-103
-  'unexpected message type %d received');
+  'unexpected message type %d received at position %d of packet %d');
 messages.set(ERR_POOL_HAS_BUSY_CONNECTIONS,             // NJS-104
   'connection pool cannot be closed because connections are busy');
 messages.set(ERR_NAN_VALUE,                             // NJS-105
@@ -344,9 +344,9 @@ messages.set(ERR_INVALID_TYPE_NUM,                      // NJS-109
 messages.set(ERR_INVALID_ORACLE_TYPE_NUM,               // NJS-110
   'invalid Oracle type number %d [csfrm: %d]');
 messages.set(ERR_UNEXPECTED_NEGATIVE_INTEGER,           // NJS-111
-  'internal error: read a negative integer when expecting a positive integer');
+  'internal error: read a negative integer when expecting a positive integer at position %d of packet %d');
 messages.set(ERR_INTEGER_TOO_LARGE,                     // NJS-112
-  'internal error: read integer of length %d when expecting integer of no more than length %d');
+  'internal error: read integer of length %d when expecting integer of no more than length %d at position %d of packet %d');
 messages.set(ERR_UNEXPECTED_DATA,                       // NJS-113
   'unexpected data received: %s');
 messages.set(ERR_OSON_FIELD_NAME_LIMITATION,            // NJS-114

lib/thin/protocol/buffer.js

@@ -92,13 +92,13 @@ class BaseBuffer {
       return 0;
     } else if (size & 0x80) {
       if (!signed) {
-        errors.throwErr(errors.ERR_UNEXPECTED_NEGATIVE_INTEGER);
+        errors.throwErr(errors.ERR_UNEXPECTED_NEGATIVE_INTEGER, this.pos, this.packetNum);
       }
       isNegative = true;
       size = size & 0x7f;
     }
     if (size > maxSize) {
-      errors.throwErr(errors.ERR_INTEGER_TOO_LARGE, size, maxSize);
+      errors.throwErr(errors.ERR_INTEGER_TOO_LARGE, size, maxSize, this.pos, this.packetNum);
     }
     if (skip) {
       this.skipBytes(size);

lib/thin/protocol/messages/base.js

@@ -215,7 +215,7 @@ class Message {
     } else if (messageType === constants.TNS_MSG_TYPE_SERVER_SIDE_PIGGYBACK) {
       this.processServerSidePiggyBack(buf);
     } else {
-      errors.throwErr(errors.ERR_UNEXPECTED_MESSAGE_TYPE, messageType);
+      errors.throwErr(errors.ERR_UNEXPECTED_MESSAGE_TYPE, messageType, buf.pos, buf.packetNum);
     }
   }
 

lib/thin/protocol/packet.js

@@ -254,46 +254,48 @@ class ReadPacket extends BaseBuffer {
    * Receives a packet from the adapter.
    */
   receivePacket() {
-    if (this.savedBufferPos === this.savedBuffers.length) {
+    if (this.savedPacketPos === this.savedPackets.length) {
       const packet = this.nsi.syncRecvPacket();
       if (!packet || this.nsi.isBreak)
         throw new utils.OutOfPacketsError();
-      this.savedBuffers.push(packet.buf);
+      this.savedPackets.push(packet);
     }
-    this.startPacket(this.savedBuffers[this.savedBufferPos++]);
+    this.startPacket(this.savedPackets[this.savedPacketPos++]);
   }
 
   restorePoint() {
-    this.savedBufferPos = 0;
-    this.startPacket(this.savedBuffers[this.savedBufferPos++]);
+    this.savedPacketPos = 0;
+    this.startPacket(this.savedPackets[this.savedPacketPos++]);
     this.pos = this.savedPos;
   }
 
   savePoint() {
-    if (this.savedBuffers) {
-      this.savedBuffers = this.savedBuffers.splice(this.savedBufferPos - 1);
+    if (this.savedPackets) {
+      this.savedPackets = this.savedPackets.splice(this.savedPacketPos - 1);
     } else {
-      this.savedBuffers = [this.buf];
+      this.savedPackets = [this.packet];
     }
-    this.savedBufferPos = 1;
+    this.savedPacketPos = 1;
     this.savedPos = this.pos;
   }
 
-  startPacket(buf) {
-    this.buf = buf;
+  startPacket(packet) {
+    this.packet = packet;
+    this.buf = packet.buf;
     this.pos = 10;                      // skip packet heaader and data flags
-    this.size = buf.length;
+    this.size = packet.buf.length;
+    this.packetNum = packet.num;
   }
 
   async waitForPackets() {
     const packet = await this.nsi.recvPacket();
-    if (!this.savedBuffers) {
-      this.savedBuffers = [packet.buf];
-      this.savedBufferPos = 0;
+    if (!this.savedPackets) {
+      this.savedPackets = [packet];
+      this.savedPacketPos = 0;
     } else {
-      this.savedBuffers.push(packet.buf);
+      this.savedPackets.push(packet);
     }
-    this.startPacket(this.savedBuffers[this.savedBufferPos++]);
+    this.startPacket(this.savedPackets[this.savedPacketPos++]);
   }
 
   /**

lib/thin/sqlnet/ntTcp.js

@@ -47,6 +47,8 @@ const TCPCHA = 1 << 1 |    /* ASYNC support */
   1 << 9 |    /* Full Duplex support */
   1 << 12;    /* SIGPIPE Support */
 
+let streamNum = 1;
+
 /**
  * Network Transport TCP/TCPS adapter
  * @param {Address} address Destination Address
@@ -63,6 +65,8 @@ class NTTCP {
     this.numPacketsSinceLastWait = 0;
     this.secure = false;
     this.largeSDU = false;
+    this.streamNum = streamNum++;
+    this.packetNum = 1;
   }
 
   /**
@@ -319,7 +323,7 @@ class NTTCP {
   send(buf) {
     this.checkErr();
     if (process.env.NODE_ORACLEDB_DEBUG_PACKETS)
-      this.printPacket("Sending packet", buf);
+      this.printPacket(`Sending packet ${this.packetNum} on stream ${this.streamNum}`, buf);
     const result = this.stream.write(buf, (err) => {
       if (err) {
         this.savedErr = err;
@@ -331,6 +335,7 @@ class NTTCP {
       this.needsDrain = true;
     }
     this.numPacketsSinceLastWait++;
+    this.packetNum++;
   }
 
   /**
@@ -394,15 +399,16 @@ class NTTCP {
         const packet = {
           buf: tempBuf.subarray(0, len),
           type: tempBuf[4],
-          flags: tempBuf[5]
+          flags: tempBuf[5],
+          num : this.packetNum++
         };
         this.packets.push(packet);
         if (this.readWaiter) {
           this.readWaiter();
           this.readWaiter = null;
         }
         if (process.env.NODE_ORACLEDB_DEBUG_PACKETS)
-          this.printPacket("Receiving packet", packet.buf);
+          this.printPacket(`Receiving packet ${packet.num} on stream ${this.streamNum}`, packet.buf);
 
         // if the packet consumed all of the bytes (most common scenario), then
         // simply clear the temporary buffer; otherwise, retain whatever bytes