Percona Toolkit moved to https://jira.percona.com/projects/PT

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

Bug #1029178 reported by Fernando Ipar
16
This bug affects 3 people
Affects Status Importance Assigned to Milestone
Percona Toolkit moved to https://jira.percona.com/projects/PT
Fix Released
Medium
Daniel Nichter
Percona Toolkit moved to https://jira.percona.com/projects/PT 2.1.4

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

lp:~percona-toolkit-dev/percona-toolkit/pqd-mem-bug-1029178
Daniel Nichter: Approve
Diff: 13 lines (+3/-0)
1 file modified
bin/pt-query-digest (+3/-0)
Daniel Nichter (daniel-nichter)
Changed in percona-toolkit:
status: New → In Progress
assignee: nobody → Daniel Nichter (daniel-nichter)
tags: added: memory-usage pt-query-digest
Revision history for this message
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.

Daniel Nichter (daniel-nichter)
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
Revision history for this message
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.

Daniel Nichter (daniel-nichter)
Changed in percona-toolkit:
importance: Undecided → Medium
milestone: none → 2.1.4
Daniel Nichter (daniel-nichter)
Changed in percona-toolkit:
status: In Progress → Fix Committed
Brian Fraser (fraserbn)
Changed in percona-toolkit:
status: Fix Committed → Fix Released
Revision history for this message
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

Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PT-558

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

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.