Error when running pgs-badger on a pcap file

[sshnerson-aurea]

Hi!

I'm trying to analyze tcpdump collected PostgresSQL pcap file but when I run pgs-badger it gives me some weird output - it contains errors, warning, and normal output but only for the first packet:

# /usr/local/bin/pgs-badger --read test.pcap
Use of uninitialized value in hash element at /usr/local/bin/pgs-badger line 184.
Use of uninitialized value $dbname in hash element at /usr/local/bin/pgs-badger line 188.
Use of uninitialized value in hash element at /usr/local/bin/pgs-badger line 184.
Use of uninitialized value in hash element at /usr/local/bin/pgs-badger line 184.
Use of uninitialized value in hash element at /usr/local/bin/pgs-badger line 184.
Undefined subroutine &main::start_activity called at /usr/local/bin/pgs-badger line 427.
curr: 0.000283002853393555 / min: inf / avg: 0
curr: 0 / min: inf / avg: 0
Use of uninitialized value $dbname in hash element at /usr/local/bin/pgs-badger line 330.

===== Overall stats =====

First message:                  Wed Mar 17 21:19:57 2021
Last message:                   Wed Mar 17 21:19:57 2021
Number of cancel requests:      0
Number of sessions/connections: 1/1
Number of disconnections:       0
Cumulated sessions time:        0.000283 s
Cumulated busy time:            0.000000 s
Total busy ratio:               0.000000 %
Total number of rows:           0

==== Notices & Errors ====

Total notices:                0
Min/Max notices per sessions: 0/0
Total errors:                 0
Min/Max errors per sessions:  0/0

=== Most frequent notices ===

None

=== Most frequent errors ===

None

==== Sessions ====

Min/Avg/Max authentication time (s): inf / 0.000000 / 0.000000
Min/Avg/Max busy ratio (%):          0.000000 / 0.000000 / 0.000000
Min/Avg/Max busy time (s):           0.000000 / 0.000000 / 0.000000
Min/Avg/Max sessions time (s):       0.000283 / 0.000283 / 0.000283
Min/Avg/Max number of queries:       0 / 0.00 / 0
Min/Avg/Max number of fields:        -1 / 0 / 0
Min/Avg/Max number of rows:          0 / 0.00 / 0

===== Databases =====

====  ====

=== Global stats for '' ===

# sessions/connections: 1/0
Total sessions time:    0.000283 s
Total busy time:        0.000000 s
Total busy ratio:       0.000000 %
Number of queries:      0
Number of rows:         0
Number of notices:      0
Number of errors:       0

=== Sessions stats for '' (Min/Avg/Max) ===

Busy ratio (%):     0.000000 / 0.000000 / 0.000000
Busy time (s):      0.000000 / 0.000000 / 0.000000
Sessions time (s):  0.000283 / 0.000283 / 0.000283
Number of queries:  0 / 0.00 / 0
Number of rows:     0 / 0.00 / 0
Min/Max notices:    0/0
Min/Max errors:     0/0

===== Queries =====

==== Queries by type ====

Rank            Type         Count      Percentage
   1          COMMIT             1          100.00
   2          VACUUM             0            0.00
   3         PREPARE             0            0.00
   4        ROLLBACK             0            0.00
   5          others             0            0.00
   6            COPY             0            0.00
   7            BIND             0            0.00
   8           BEGIN             0            0.00
   9          INSERT             0            0.00
  10        TRUNCATE             0            0.00
  11            MOVE             0            0.00
  12          DELETE             0            0.00
  13           FETCH             0            0.00
  14          UPDATE             0            0.00
  15           CLOSE             0            0.00
  16         DECLARE             0            0.00
  17       DEALOCATE             0            0.00
  18          SELECT             0            0.00

Total queries: 1

==== Prepared Statements ====

=== Top slowest queries ===

Rank    Duration(s)     Rows
Query
Use of uninitialized value in printf at /usr/local/bin/pgs-badger line 1138.
   1        -1.00000    0               SHOW TRANSACTION ISOLATION LEVEL

=== Queries that took up the most time ===

Rank    total Duration(s)       times executed  Av. duration (s)        Rows min/avg/max        Query
   1               0.00000                   0            0.00000       inf/0/0                 SHOW TRANSACTION ISOLATION LEVEL

=== Most frequent queries ===

Rank    times executed  total Duration(s)       Av. duration (s)        Rows min/avg/max        Query
   1                 0             0.00000                0.00000       inf/0/0                 SHOW TRANSACTION ISOLATION LEVEL

==== Simple Queries ====

=== Top slowest queries ===

None

=== Queries that took up the most time ===

None

=== Most frequent queries ===

None
Use of uninitialized value in subroutine entry at /usr/local/share/perl5/pgShark.pm line 321 during global destruction.

# perl --version

This is perl 5, version 16, subversion 3 (v5.16.3) built for x86_64-linux-thread-multi

# yum info perl-Net-Pcap
Installed Packages
Name        : perl-Net-Pcap
Arch        : x86_64
Version     : 0.17
Release     : 7.el7

Any idea what I could be doing wrong?

[ioguix]

Hello,

I suppose this isn't you doing something wrong.

How pgs-debug is working with the same pcap? Does it have troubles as well?

Is it possible for you to attach a small part of your pcap?

I suspect pgs-badger is parsing packets with no clue about the session, which is created during the first packet of the pgsql session.

[sshnerson-aurea]

Hi!

Thanks for your reply!

pgs-debug is working fine and showing me details of the queries.

I'll send you a sample pcap file by email.

[ioguix]

OK, so I suppose pgs-badger is buggy and doesn't pay attention to acquire the whole session before computing stats.

To be honest, I don't remember what is the status and quality of the pgs-badger code.

But the pcap is still welcome if I can add some quick fixes on top of it.