From 7aeef3de312a8dd3bbd237b2f1de19d09bc4f6e9 Mon Sep 17 00:00:00 2001
From: Tudor Golubenco <tudor@packetbeat.com>
Date: Fri, 12 Jun 2015 19:26:11 +0200
Subject: [PATCH] Correctly ignore command types we don't understand.

We used to glue packets together waiting for one that we understand,
but one side effect was that we pick the wrong start time for the
transaction. This fixes #160.
---
 protos/pgsql/pgsql.go     |   8 +++++++-
 tests/pcaps/pgsql_rt.pcap | Bin 0 -> 3012 bytes
 tests/test_0009_pgsql.py  |  16 ++++++++++++++++
 3 files changed, 23 insertions(+), 1 deletion(-)
 create mode 100644 tests/pcaps/pgsql_rt.pcap

diff --git a/protos/pgsql/pgsql.go b/protos/pgsql/pgsql.go
index d07e30b76a4..05f7b32484a 100644
--- a/protos/pgsql/pgsql.go
+++ b/protos/pgsql/pgsql.go
@@ -430,7 +430,7 @@ func (pgsql *Pgsql) pgsqlMessageParser(s *PgsqlStream) (bool, bool) {
 						m.end = s.parseOffset
 						m.Query = string(s.data[m.start+5 : m.end-1]) //without string termination
 						m.toExport = true
-						logp.Debug("pgsqldetailed", "Simple Query", "%s", m.Query)
+						logp.Debug("pgsqldetailed", "Simple Query: %s", m.Query)
 						return true, true
 					} else {
 						// wait for more
@@ -542,6 +542,11 @@ func (pgsql *Pgsql) pgsqlMessageParser(s *PgsqlStream) (bool, bool) {
 					if len(s.data[s.parseOffset:]) >= length+1 {
 						s.parseOffset += 1 //type
 						s.parseOffset += length
+						m.end = s.parseOffset
+
+						// ok and complete, but ignore
+						m.toExport = false
+						return true, true
 					} else {
 						// wait for more
 						logp.Debug("pgsqldetailed", "Wait for more data 6")
@@ -675,6 +680,7 @@ func (pgsql *Pgsql) Parse(pkt *protos.Packet, tcptuple *common.TcpTuple,
 		}
 
 		ok, complete := pgsql.pgsqlMessageParser(priv.Data[dir])
+		//logp.Debug("pgsqldetailed", "MessageParser returned ok=%v complete=%v", ok, complete)
 		if !ok {
 			// drop this tcp stream. Will retry parsing with the next
 			// segment in it
diff --git a/tests/pcaps/pgsql_rt.pcap b/tests/pcaps/pgsql_rt.pcap
new file mode 100644
index 0000000000000000000000000000000000000000..764f399252c93e3cc667915f29dbccf48be5144c
GIT binary patch
literal 3012
zcmb`JOH3PA6o!u<z+l|giA)XcqNu1*C=m%5J9eRpQJ@vcK-2=25(znjJ<yT-VrHN<
ziWIl$3#mv|B`>;5mq=Z8RbW{)fYfZNs+B6GC{kBlB$h!?Cl&OZJ2Q?45B8>(t{?Y$
zzVqMz+&O1{{qg&6?cfCCb#w$Uk3T$ec50`;33&WY1Hj>gM)n2YI2ZvKEZ&Jgr147d
zHh_&r9$G`5n~e(n>#jZ5c6b56?u@vdcFyI_?iFa>=5RQO{iqHbfY^iU2D>$shx~8T
z9P-t>r*m+eO?-p>53+|b77YvC{l!n1?l%p#u3JTZbI#*&9G*p;Hcc~eN$>B$I$nIr
znEjT_He{j~l}r@IIe&TaJhA^mb}hZDC1QWQWw3QGn$e3}s28mCeiv$@9I;{HL16U>
zW8Sl5wjs02taqG*dIxF?Eq=yK7%-r^vA57z*Ga~PFEzneD3peU&|L9zVvattWRkI}
zStvqyZ~!bQq6`^jJ^^t-6=noQ)P4z>OhSqYs+3MeQ$kXojU^;8rAEb6EFG6pb1*ge
zR!F-Eu1__=I|!v=p>JsQDKm1-(5ENIg~{2<k&%J2z9Jo_cah@8(a=!(<7YCp`Mo-(
ze!)x)8v%4vx6o8y?v%$~k$nnKB<9nbwVA8`GSNR7OkK1OMQ<as@<f%H&kMDg#bu^5
zWH5D|+o-b*lV7FtH0o?Q!_}-X{B2?u-Y7F|t)Zpu^)D$E)fHxcm*%Mo5WBq&8>%ae
zjq7^w1M*j@E6o0`JG;MYuwO%Vtvi;_G2KJQbgv+P&3q$hT+$n<qnH1PF`xOXd7&{)
z6-HyC6|BM#`|Ub<yRQ)Y)Q5&%JP+i>8hVj8SD0sdANQ~>aAJk&zRH-3mP}KH(U{{T
z)N#I!u^%%NE*a3gW<nmtuAgM=9c0$3Fg$BxkBgQ}Q-vuT`@dBf+Ven=t65>Xd1j<!
z=+l$4j>&mwt}y$1bV$n;M!ElhqX5eoAc@C;hD8aR=2<^1c#QzMsSnZAO$=Z^#M-Cz
zE*4-fgOsz$cp!E$<`?6knXn)P#CUwhAD{L2#e%_$v;O|xaCjEj(UUk>wgDT}!EM>@
zG1{Hyf)QNb-R9EvhKqK0gsS!62e`XE+8syxn85Lpbv37@cFU4ZE52bt6(`heLWI$Y
zYv($~hOaYNyOdJJIZ=*c!w^*|DJqaov6YucaYbGf653Unw4%<*xJ)#!q(qg4j3~2)
zqhHXD&1Vrw=6=Ey>npgbU<-n9Pj63efRSENM1|&}!h-sKT9%erlhV2tUD~OrLMkrE
z@n|fanoY||Y*bN2mGPsj)HjK`Z=_QqB+@Y<LA!vfcrA9E_A?(eoqKWve>99zVm3>4
zZZ-BqQy4T7qn(Nk7uU7pHrIp$8z$z!i_GAJ3#Kswjp}5>7|$LM3a?r+sU{2=$u6}J
zlbUXuA|}L`+VOhFtej4EsG_0{00q1Ew+mMB4>T--ebYV8?wc2kVA{#rapTGAWcSTV
zIhfa-EwxM{r3dT+encFAM;3hGJi-^ij5cSloTK{h0h+S)(pz7}L?2D~FXQ`j6C?b{
i<;jjd(3~gXf1>c3-Ge>y9PfG?o#_0$+4&L)_x=aXv7EmE

literal 0
HcmV?d00001

diff --git a/tests/test_0009_pgsql.py b/tests/test_0009_pgsql.py
index 7aeb65db29f..9bbb6e0a1ef 100644
--- a/tests/test_0009_pgsql.py
+++ b/tests/test_0009_pgsql.py
@@ -46,3 +46,19 @@ def test_insert_error(self):
         assert o["status"] == "Error"
         assert o["pgsql.error_code"] == "23505"
         assert o["pgsql.iserror"] is True
+
+    def test_login_rt(self):
+        """
+        Response time for a query happing shortly after a command type we don't
+        understand shouldn't have it's rt affected. Regression test for #
+        """
+        self.render_config_template(
+            pgsql_ports=[5432]
+        )
+        self.run_packetbeat(pcap="pgsql_rt.pcap")
+
+        objs = self.read_output()
+        assert len(objs) == 1
+        o = objs[0]
+        assert o["method"] == "SELECT"
+        assert o["responsetime"] == 38