Bug 765998

Summary: reference leak in _mogrify when dict value is referenced more than once
Product: Red Hat Enterprise Linux 6 Reporter: Trevor McKay <tmckay>
Component: python-psycopg2Assignee: Tom Lane <tgl>
Status: CLOSED ERRATA QA Contact: qe-baseos-daemons
Severity: urgent Docs Contact:
Priority: urgent    
Version: 6.0CC: azelinka, hhorak, iboverma, jneedle, jscotka, matt, msvoboda, psklenar, sgraf, syeghiay
Target Milestone: rcKeywords: Rebase, ZStream
Target Release: 6.2   
Hardware: Unspecified   
OS: Unspecified   
See Also: https://bugzilla.redhat.com/show_bug.cgi?id=759200
Whiteboard:
Fixed In Version: Doc Type: Rebase: Bug Fixes and Enhancements
Doc Text:
The python-psycopg2 package has been upgraded to upstream version 2.0.14, which provides a number of bug fixes and enhancements over the previous version, including the fix for a memory leak in cursor handling. This update also ensures better compatibility with the PostgreSQL object-relational database management system version 8.4.
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-02-21 03:41:39 EST Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Bug Depends On:    
Bug Blocks: 435010, 787164    
Attachments:
Description Flags
Python script that shows invalid reference counts from cursor.mogrify
none
patch for cursor_type.c in python-psycopg2-2.4.2 none

Description Trevor McKay 2011-12-09 15:28:15 EST
Description of problem:

It appears that cursor.mogrify(str, vals) will leak a reference to a value if that value is referred to more than once in the format string.  For example:

cursor.mogrify("%(a)s %(a)s", {"a": "foo"})

will incorrectly increment the reference count for the string "foo".

Version-Release number of selected component (if applicable):

Verified leak exists in python-psycopg2-2.0.13, python-psycopg2-2.0.14, and python-pscyopg2-2.4.2 (as well as newest from the psycopg repo)

How reproducible:

100%

Steps to Reproduce:
1.  Use the attached test script.  Script needs to be modified to set the database dsn for your local Postgres database

  
Actual results:

reference counts for dictionary values will increase when those values are referenced multiple times in the same format string

Expected results:

references counts should stay constant

Additional info:

Also attached is a proposed patch to fix this.  Apply the patch and rerun the test to see correct reference counts.
Comment 1 Trevor McKay 2011-12-09 15:32:26 EST
Here is an external tracker for the psycopg2 ticket, lighthouse does not show up in our external trackers pulldown.

http://psycopg.lighthouseapp.com/projects/62710/tickets/81-_mogrify-leaks-reference-when-same-dict-value-referenced-multiple-times-with
Comment 3 Trevor McKay 2011-12-09 15:33:31 EST
Created attachment 544686 [details]
Python script that shows invalid reference counts from cursor.mogrify
Comment 4 Trevor McKay 2011-12-09 15:57:23 EST
Created attachment 544696 [details]
patch for cursor_type.c in python-psycopg2-2.4.2

Note,

  It appears that this issue was discovered at some point and the equivalent patch is applied at least in version 2.3.2.  However, the patch is not in the 2.4 tree.  Not sure of the history here....
Comment 5 Trevor McKay 2011-12-12 10:37:51 EST
Disregard note on comment 4.  There is no fix in 2.3.2  The code in the routine changed and I misread the decref on another temporary object as the fix.

Note also, the patch here is a patch for 2.4.2.  Earlier versions need the same logical fix, but that patch file probably won't work.

(In reply to comment #4)
> Created attachment 544696 [details]
> patch for cursor_type.c
> 
> Note,
> 
>   It appears that this issue was discovered at some point and the equivalent
> patch is applied at least in version 2.3.2.  However, the patch is not in the
> 2.4 tree.  Not sure of the history here....
Comment 10 Matthew Farrellee 2012-01-24 12:06:21 EST
With ~400 slots running ~5 second jobs (small configuration)...

15:24 23 Jan - 3535 cumin     18   0  379m  41m 4360 S 44.4  0.1   0:24.81 cumin-data
11:39 24 Jan - 3535 cumin     18   0 1379m 1.0g 4360 S 27.4  2.2 443:58.75 cumin-data

...we're seeing about ~50MB/hour leakage.

The leak is expected to scale in the number of slots and number of jobs run (slot updates, such as state transition).
Comment 12 Matthew Farrellee 2012-01-24 12:13:49 EST
(In reply to comment #10)
> With ~400 slots running ~5 second jobs (small configuration)...
> 
> 15:24 23 Jan - 3535 cumin     18   0  379m  41m 4360 S 44.4  0.1   0:24.81
> cumin-data
> 11:39 24 Jan - 3535 cumin     18   0 1379m 1.0g 4360 S 27.4  2.2 443:58.75
> cumin-data
> 
> ...we're seeing about ~50MB/hour leakage.
> 
> The leak is expected to scale in the number of slots and number of jobs run
> (slot updates, such as state transition).

Additionally, the patched version had been running prior to these measurements for an extended period of time (unknown exactly how long) and had accumulated ~440MB virt & ~40MB res over 2115 CPU hours.
Comment 16 Stanislav Graf 2012-02-03 03:41:04 EST
MRG REPRODUCE:

RHEL6 i386
cumin-0.1.5192-1.el6.noarch
python-psycopg2-2.0.13-2.el6_1.1.i686

RHEL6 x86_64
cumin-0.1.5192-1.el6.noarch
python-psycopg2-2.0.13-2.el6_1.1.x86_64

# python psycopg_leak.py 
sql is %(a)s %(b)s
vals {'a': 'unique string', 'b': 'some other string'}
reference count for vals[a] = 6
reference count for vals[b] = 6
after call to cursor.mogrify(sql, vals)...
reference count for vals[a] = 6
reference count for vals[b] = 6

sql is %(a)s %(a)s
vals {'a': 'unique string', 'b': 'some other string'}
reference count for vals[a] = 6
reference count for vals[b] = 6
after call to cursor.mogrify(sql, vals)...
reference count for vals[a] = 7
reference count for vals[b] = 6

sql is %(b)s %(b)s
vals {'a': 'unique string', 'b': 'some other string'}
reference count for vals[a] = 7
reference count for vals[b] = 6
after call to cursor.mogrify(sql, vals)...
reference count for vals[a] = 7
reference count for vals[b] = 7

sql is %(b)s %(b)s %(b)s
vals {'a': 'unique string', 'b': 'some other string'}
reference count for vals[a] = 7
reference count for vals[b] = 7
after call to cursor.mogrify(sql, vals)...
reference count for vals[a] = 7
reference count for vals[b] = 9

MRG VERIFY:

RHEL6 i386
# rpm -Uvh .../python-psycopg2-2.0.14-1.el6.i686.rpm
# reboot
cumin-0.1.5192-1.el6.noarch
python-psycopg2-2.0.14-1.el6.i686

RHEL6 x86_64
# rpm -Uvh .../python-psycopg2-2.0.14-1.el6.x86_64.rpm
# reboot
cumin-0.1.5192-1.el6.noarch
python-psycopg2-2.0.14-1.el6.x86_64

# python psycopg_leak.py 
sql is %(a)s %(b)s
vals {'a': 'unique string', 'b': 'some other string'}
reference count for vals[a] = 6
reference count for vals[b] = 6
after call to cursor.mogrify(sql, vals)...
reference count for vals[a] = 6
reference count for vals[b] = 6

sql is %(a)s %(a)s
vals {'a': 'unique string', 'b': 'some other string'}
reference count for vals[a] = 6
reference count for vals[b] = 6
after call to cursor.mogrify(sql, vals)...
reference count for vals[a] = 6
reference count for vals[b] = 6

sql is %(b)s %(b)s
vals {'a': 'unique string', 'b': 'some other string'}
reference count for vals[a] = 6
reference count for vals[b] = 6
after call to cursor.mogrify(sql, vals)...
reference count for vals[a] = 6
reference count for vals[b] = 6

sql is %(b)s %(b)s %(b)s
vals {'a': 'unique string', 'b': 'some other string'}
reference count for vals[a] = 6
reference count for vals[b] = 6
after call to cursor.mogrify(sql, vals)...
reference count for vals[a] = 6
reference count for vals[b] = 6

psycopg_leak.py - OK, references counts stay constant
work with cumin - OK
no errors in cumin web.log - OK

MRG OK
Comment 18 Miroslav Svoboda 2012-02-21 08:03:40 EST
    Technical note added. If any revisions are required, please edit the "Technical Notes" field
    accordingly. All revisions will be proofread by the Engineering Content Services team.
    
    New Contents:
The python-psycopg2 package has been upgraded to upstream version 2.0.14, which provides a number of bug fixes and enhancements over the previous version, including the fix for a memory leak in cursor handling. This update also ensures better compatibility with the PostgreSQL object-relational database management system version 8.4.
Comment 24 errata-xmlrpc 2013-02-21 03:41:39 EST
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHBA-2013-0327.html