pt-query-digest --type tcpdump memory usage keeps increasing

Bug #1029178 reported by Fernando Ipar on 2012-07-25
This bug affects 3 people
Affects Status Importance Assigned to Milestone
Percona Toolkit
Daniel Nichter

Bug Description

I'm streaming tcpdump captures to another host to get a list of queries for later review like so:

tcpdump -i eth2 -Z <username> -s 65535 -x -n -q -tttt 'port 3306 and tcp[0:2] & 15 == 10 and tcp[2:4] & 15 == 10 ' | ssh <username>@<remote-server> 'cat - | /usr/local/bin/pt-query-digest --no-report --type tcpdump --print 2>/dev/null | gzip -1 > /home/<username>//query-log.gz'

pt-query-digest memory use grows steadily until it crashes or makes the server unusable.

I can reproduce this easily by doing a short tcpdump capture and then running these commands:

while :; do cat tcpdump.log ; done | ./pt-query-digest --no-report --type tcpdump --print

If I monitor memory usage by pt-query-digest while this runs, it just keeps growing.

If I do a similar short slow log capture and run the same command but with this capture instead:

while :; do cat slow.log ; done | ./pt-query-digest --no-report --print 2

Memory use remains constant.

Related branches

Merged into lp:percona-toolkit/2.1 at revision 368
Daniel Nichter: Approve on 2012-08-24
Changed in percona-toolkit:
status: New → In Progress
assignee: nobody → Daniel Nichter (daniel-nichter)
tags: added: memory-usage pt-query-digest
Daniel Nichter (daniel-nichter) wrote :

I can reproduce this, and I'm pretty sure it's related to MySQLProtocolParser's session tracking. Unlike slowlogs which have no sessions, tcpdump logs have sessions which span the lifetime of a client connection, e.g. from handshake to COM_QUIT. That's the only thing that's saved, so that's why I suspect it's causing increasing memory usage. It's been awhile since I've worked with MySQLProtocolParser so I'll have to study the code a bit to remind myself how and why it handles sessions and, relatedly, when it deletes sessions.

summary: - pt-query-digest memory increases steadily when reading from a stream
- with --type tcpdump, --no-report and --print
+ pt-query-digest --type tcpdump memory usage keeps increasing
Daniel Nichter (daniel-nichter) wrote :

I cannot reproduce this anywhere except on my Mac's shell and Perl. I tried Perl 5.12 on a Ubuntu 11 vbox, and Perl 5.8 on a CentOS 5.6 vbox: no memory increase. Yet both Fernando and I can reproduce this on our Macs, so there must be an OS or Perl issue, but I can't isolate it yet. After further code review, MySQLProtocolParser is throwing away temporarily saved stuff as expected. Even on my Mac, the MySQLProtocolParser object's memory usage hold steady around 110k (so does the EventAggregator object's memory), so the memory problem must be elsewhere.

Changed in percona-toolkit:
importance: Undecided → Medium
milestone: none → 2.1.4
Changed in percona-toolkit:
status: In Progress → Fix Committed
Brian Fraser (fraserbn) on 2012-09-26
Changed in percona-toolkit:
status: Fix Committed → Fix Released
Chris Picton (p5lbb) wrote :

I am using percona-toolkit-2.2.6-1 on Centos 5 x86_64 - perl-5.8.8-32.el5_5.2

My command is '/usr/sbin/tcpdump -i lo -s0 -x -nn -q -tttt tcp port 3306 | /usr/bin/pt-query-digest --type=tcpdump --output slowlog --no-report'

Getting a process list every 10 seconds shows:

root 18706 74.5 0.2 158780 27252 pts/1 R+ 12:12 0:06 perl /usr/bin/pt-query-digest --type=tcpdump --output slowlog --no-report
root 18706 73.7 0.2 160352 28824 pts/1 R+ 12:12 0:14 perl /usr/bin/pt-query-digest --type=tcpdump --output slowlog --no-report
root 18706 72.2 0.2 162572 31016 pts/1 R+ 12:12 0:20 perl /usr/bin/pt-query-digest --type=tcpdump --output slowlog --no-report
root 18706 70.6 0.2 163460 31932 pts/1 S+ 12:12 0:27 perl /usr/bin/pt-query-digest --type=tcpdump --output slowlog --no-report
root 18706 72.2 0.2 165100 33572 pts/1 R+ 12:12 0:35 perl /usr/bin/pt-query-digest --type=tcpdump --output slowlog --no-report
root 18706 71.0 0.2 166356 34820 pts/1 S+ 12:12 0:41 perl /usr/bin/pt-query-digest --type=tcpdump --output slowlog --no-report
root 18706 71.9 0.3 168468 36940 pts/1 R+ 12:12 0:49 perl /usr/bin/pt-query-digest --type=tcpdump --output slowlog --no-report
root 18706 71.5 0.3 169652 38124 pts/1 R+ 12:12 0:57 perl /usr/bin/pt-query-digest --type=tcpdump --output slowlog --no-report
root 18706 72.2 0.3 171260 39732 pts/1 R+ 12:12 1:05 perl /usr/bin/pt-query-digest --type=tcpdump --output slowlog --no-report
root 18706 72.8 0.3 172996 41464 pts/1 R+ 12:12 1:12 perl /usr/bin/pt-query-digest --type=tcpdump --output slowlog --no-report

This continues until server runs out of memory

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers