8000 Improving logging, trace to see network bytes, debug to see prepared … · mauricio/postgresql-async@40b06b5 · GitHub
[go: up one dir, main page]
Skip to content
This repository was archived by the owner on Dec 3, 2019. It is now read-only.

Commit 40b06b5

Browse files
mauriciomauricio
committed
Improving logging, trace to see network bytes, debug to see prepared statements opening and execute outputs - fixes #77 
1 parent 6fb7e71 commit 40b06b5

File tree

5 files changed

+53
-12
lines changed

5 files changed

+53
-12
lines changed

‎postgresql-async/src/main/scala/com/github/mauricio/async/db/postgresql/codec/MessageDecoder.scala

Lines changed: 13 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,7 @@ package com.github.mauricio.async.db.postgresql.codec
1919
import com.github.mauricio.async.db.postgresql.exceptions.{MessageTooLongException}
2020
import com.github.mauricio.async.db.postgresql.messages.backend.ServerMessage
2121
import com.github.mauricio.async.db.postgresql.parsers.{AuthenticationStartupParser, MessageParsersRegistry}
22-
import com.github.mauricio.async.db.util.Log
22+
import com.github.mauricio.async.db.util.{BufferDumper, Log}
2323
import java.nio.charset.Charset
2424
import com.github.mauricio.async.db.exceptions.NegativeMessageSizeException
2525
import io.netty.handler.codec.ByteToMessageDecoder
@@ -33,6 +33,8 @@ object MessageDecoder {
3333

3434
class MessageDecoder(charset: Charset, maximumMessageSize : Int = MessageDecoder.DefaultMaximumSize) extends ByteToMessageDecoder {
3535

36+
import MessageDecoder.log
37+
3638
private val parser = new MessageParsersRegistry(charset)
3739

3840
override def decode(ctx: ChannelHandlerContext, b: ByteBuf, out: java.util.List[Object]): Unit = {
@@ -54,17 +56,22 @@ class MessageDecoder(charset: Charset, maximumMessageSize : Int = MessageDecoder
5456
}
5557

5658
if (b.readableBytes() >= length) {
57-
code match {
59+
60+
if ( log.isTraceEnabled ) {
61+
log.trace(s"Received buffer ${code}\n${BufferDumper.dumpAsHex(b)}")
62+
}
63+
64+
val result = code match {
5865
case ServerMessage.Authentication => {
59-
val msg = AuthenticationStartupParser.parseMessage(b)
60-
out.add(msg)
66+
AuthenticationStartupParser.parseMessage(b)
6167
}
6268
case _ => {
63-
val msg = parser.parse(code, b.readSlice(length))
64-
out.add(msg)
69+
parser.parse(code, b.readSlice(length))
6570
}
6671
}
6772

73+
out.add(result)
74+
6875
} else {
6976
b.resetReaderIndex()
7077
return

‎postgresql-async/src/main/scala/com/github/mauricio/async/db/postgresql/codec/MessageEncoder.scala

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -33,6 +33,8 @@ object MessageEncoder {
3333

3434
class MessageEncoder(charset: Charset, encoderRegistry: ColumnEncoderRegistry) extends MessageToMessageEncoder[Object] {
3535

36+
import MessageEncoder.log
37+
3638
private val executeEncoder = new ExecutePreparedStatementEncoder(charset, encoderRegistry)
3739
private val openEncoder = new PreparedStatementOpeningEncoder(charset, encoderRegistry)
3840
private val startupEncoder = new StartupMessageEncoder(charset)
@@ -54,13 +56,16 @@ class MessageEncoder(charset: Charset, encoderRegistry: ColumnEncoderRegistry) e
5456
}
5557

5658
encoder.encode(message)
57-
5859
}
5960
case _ => {
6061
throw new IllegalArgumentException("Can not encode message %s".format(msg))
6162
}
6263
}
6364

65+
if (log.isTraceEnabled) {
66+
log.trace(s"Message being sent ${msg.getClass.getName}\n${BufferDumper.dumpAsHex(buffer)}")
67+
}
68+
6469
out.add(buffer)
6570
}
6671

‎postgresql-async/src/main/scala/com/github/mauricio/async/db/postgresql/encoders/ExecutePreparedStatementEncoder.scala

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -33,10 +33,9 @@ class ExecutePreparedStatementEncoder(
3333
def encode(message: ClientMessage): ByteBuf = {
3434

3535
val m = message.asInstanceOf[PreparedStatementExecuteMessage]
36-
3736
val statementIdBytes = m.statementId.toString.getBytes(charset)
3837

39-
writeExecutePortal( statementIdBytes, m.values, encoder, charset )
38+
writeExecutePortal( statementIdBytes, m.query, m.values, encoder, charset )
4039
}
4140

4241
}

‎postgresql-async/src/main/scala/com/github/mauricio/async/db/postgresql/encoders/PreparedStatementEncoderHelper.scala

Lines changed: 23 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ import com.github.mauricio.async.db.util.{Log, ByteBufferUtils}
2121
import com.github.mauricio.async.db.column.ColumnEncoderRegistry
2222
import java.nio.charset.Charset
2323
import io.netty.buffer.{Unpooled, ByteBuf}
24+
import scala.collection.mutable.ArrayBuffer
2425

2526
object PreparedStatementEncoderHelper {
2627
final val log = Log.get[PreparedStatementEncoderHelper]
@@ -32,6 +33,7 @@ trait PreparedStatementEncoderHelper {
3233

3334
def writeExecutePortal(
3435
A36C statementIdBytes: Array[Byte],
36+
query : String,
3537
values: Seq[Any],
3638
encoder: ColumnEncoderRegistry,
3739
charset: Charset,
@@ -52,16 +54,36 @@ trait PreparedStatementEncoderHelper {
5254

5355
bindBuffer.writeShort(values.length)
5456

57+
val decodedValues = if ( log.isDebugEnabled ) {
58+
new ArrayBuffer[String](values.size)
59+
} else {
60+
null
61+
}
62+
5563
for (value <- values) {
5664
if (value == null || value == None) {
5765
bindBuffer.writeInt(-1)
66+
67+
if (log.isDebugEnabled) {
68+
decodedValues += null
69+
}
5870
} else {
59-
val content = encoder.encode(value).getBytes(charset)
71+
val encodedValue = encoder.encode(value)
72+
73+
if ( log.isDebugEnabled ) {
74+
decodedValues += encodedValue
75+
}
76+
77+
val content = encodedValue.getBytes(charset)
6078
bindBuffer.writeInt(content.length)
6179
bindBuffer.writeBytes( content )
6280
}
6381
}
6482

83+
if (log.isDebugEnabled) {
84+
log.debug(s"Executing query - statement id (${statementIdBytes.mkString("-")}) - statement ($query) - encoded values (${decodedValues.mkString(", ")}) - original values (${values.mkString(", ")})")
85+
}
86+
6587
bindBuffer.writeShort(0)
6688

6789
ByteBufferUtils.writeLength(bindBuffer)

‎postgresql-async/src/main/scala/com/github/mauricio/async/db/postgresql/encoders/PreparedStatementOpeningEncoder.scala

Lines changed: 10 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -23,12 +23,16 @@ import com.github.mauricio.async.db.util.{Log, ByteBufferUtils}
2323
import java.nio.charset.Charset
2424
import io.netty.buffer.{Unpooled, ByteBuf}
2525

26+
object PreparedStatementOpeningEncoder {
27+
val log = Log.get[PreparedStatementOpeningEncoder]
28+
}
29+
2630
class PreparedStatementOpeningEncoder(charset: Charset, encoder : ColumnEncoderRegistry)
2731
extends Encoder
2832
with PreparedStatementEncoderHelper
2933
{
3034

31-
private val log = Log.get[PreparedStatementOpeningEncoder]
35+
import PreparedStatementOpeningEncoder.log
3236

3337
override def encode(message: ClientMessage): ByteBuf = {
3438

@@ -49,13 +53,17 @@ class PreparedStatementOpeningEncoder(charset: Charset, encoder : ColumnEncoderR
4953

5054
parseBuffer.writeShort(columnCount)
5155

56+
if ( log.isDebugEnabled ) {
57+
log.debug(s"Opening query (${m.query}) - statement id (${statementIdBytes.mkString("-")}) - selected types (${m.valueTypes.mkString(", ")}) - values (${m.values.mkString(", ")})")
58+
}
59+
5260
for (kind <- m.valueTypes) {
5361
parseBuffer.writeInt(kind)
5462
}
5563

5664
ByteBufferUtils.writeLength(parseBuffer)
5765

58-
val executeBuffer = writeExecutePortal(statementIdBytes, m.values, encoder, charset, true)
66+
val executeBuffer = writeExecutePortal(statementIdBytes, m.query, m.values, encoder, charset, true)
5967

6068
Unpooled.wrappedBuffer(parseBuffer, executeBuffer)
6169
}

0 commit comments

Comments
 (0)
0