Edgewall Software
Modify

Opened 13 years ago

Closed 11 years ago

Last modified 5 years ago

#4987 closed defect (fixed)

don't keep open pgsql transaction when trac is idle

Reported by: Radim Kolar Owned by: Jonas Borgström
Priority: high Milestone: 0.11.3
Component: general Version:
Severity: major Keywords: postgresql, needinfo
Cc: Branch:
Release Notes:
API Changes:

Description

When trac is idle, postgresql database connection is in midle of transaction status

53878 ?? Is 0:01.46 postgres: trac trac [local] idle in transaction

If trac with low user activity is running on server, this behaviour has nasty system-wide effects.

  1. You can't VACUUM DB. You can but no rows are cleaned
  2. You can't replicate DB

until transaction is closed. On lowly loaded Trac, it can take days, so it harms other db users. Close transaction while idle please.

Attachments (1)

postgres_backend.py-idle_in_transaction.diff (672 bytes ) - added by guillaume.smet@… 11 years ago.

Download all attachments as: .zip

Change History (20)

comment:1 by Christian Boos, 13 years ago

Keywords: postgresql added
Milestone: 0.10.5

Also reported by someone else on the user list: googlegroups:trac-users:f73a346b6797578e

I think this might be related to concurrent sync attempts (#4586) failing and left without doing the appropriate rollback.

comment:2 by Christian Boos, 13 years ago

Milestone: 0.10.50.10.4

Forgot to say: if this is indeed the case, then the current 0.10.4dev (r5153) should already fix this.

comment:3 by Christian Boos, 13 years ago

Keywords: needinfo added
Milestone: 0.10.40.10.5

comment:4 by Sonic, 13 years ago

Trac is definitively holding on to connections for too long. I get the same problem with Trac 0.10.4 on PosgreSQL 8.2.4. With 3 Trac environments, each as a separate schema in one database, the process list displays a lot of posgresql positions hanging as idle in transaction.

What kind of info can I provide to help solve it?

comment:5 by Christian Boos, 13 years ago

Keywords: verify added; needinfo removed

comment:6 by kent@…, 12 years ago

Hi. I use Trac 0.9.3+PostgreSQL

I try to understand why my Trac server became too slow. I found a lot of established connections even when nobody use Trac. Command ps -aef give such output:

postgres  9709     1  0 Jan09 ?        00:00:01 /usr/bin/postmaster -D /home/postgresql/data
postgres  9782  9709  0 Jan09 ?        00:00:00 postgres: writer process
postgres  9783  9709  0 Jan09 ?        00:00:00 postgres: stats buffer process
postgres  9957  9709  0 12:02 ?        00:00:00 postgres: tracadmin kent 127.0.0.1(34090) idle
postgres 10113  9709  0 12:39 ?        00:00:00 postgres: tracadmin svninfo 127.0.0.1(32960) idle
postgres 10123  9709  0 12:39 ?        00:00:00 postgres: tracadmin svninfo 127.0.0.1(32961) idle
postgres 10378  9709  0 13:44 ?        00:00:00 postgres: tracadmin l-process-draft 127.0.0.1(44468) idle
postgres 10395  9709  0 13:45 ?        00:00:00 postgres: tracadmin lirxca_0_6_4 127.0.0.1(44469) idle
postgres 10404  9709  0 13:45 ?        00:00:00 postgres: tracadmin lirxca_0_6_4 127.0.0.1(44470) idle
postgres 10493  9709  0 13:51 ?        00:00:00 postgres: tracadmin lirvpn 127.0.0.1(33534) idle
postgres 10531  9709  0 13:52 ?        00:00:00 postgres: tracadmin lirvpn 127.0.0.1(33535) idle
postgres 10536  9709  0 13:52 ?        00:00:00 postgres: tracadmin lirvpn 127.0.0.1(33536) idle
postgres 10557  9709  0 13:52 ?        00:00:00 postgres: tracadmin lirvpn 127.0.0.1(33537) idle
postgres 10565  9709  0 13:52 ?        00:00:00 postgres: tracadmin lirvpn 127.0.0.1(33538) idle
postgres 10593  9709  0 14:00 ?        00:00:00 postgres: tracadmin lirvpn 127.0.0.1(53450) idle
postgres 10621  9709  0 14:00 ?        00:00:00 postgres: tracadmin lirvpn 127.0.0.1(53452) idle
postgres 10657  9709  0 14:06 ?        00:00:00 postgres: tracadmin l-process-draft 127.0.0.1(34525) idle
postgres 10676  9709  0 14:07 ?        00:00:00 postgres: tracadmin lirvpn 127.0.0.1(34526) idle
postgres 10687  9709  0 14:07 ?        00:00:00 postgres: tracadmin lirvpn 127.0.0.1(34527) idle

Is it the same trouble as described in this ticket?

P.S.: sorry for my English.

comment:7 by danimo, 12 years ago

I can still confirm this with a recent version of trac 0.11. This is really nasty, as one runs out of postgres connections very quickly.

comment:8 by Christian Boos, 12 years ago

Milestone: 0.10.50.11.1

comment:9 by Jennifer Drummond <jenn@…>, 11 years ago

I had r7190 recommended to me as a patch that might help, but unfortunately it's from farther up on trunk and doesn't apply cleanly against 0.11. Anyone feel like tweaking it for backwards compatibility?

comment:10 by Christian Boos, 11 years ago

Keywords: needinfo added; verify removed
Milestone: 0.11.20.11.1

That changeset has been ported to branches/0.11-stable, simply upgrade to latest stable from svn (TracDownload#Tracstable).

It will be very appreciated if you report back whether the problem got fixed or not after the upgrade, so that we could eventually close this ticket.

comment:11 by Christian Boos, 11 years ago

Jonas, I see that t.e.o is running using r7316, how is this doing w.r.t to this issue? Do you think we can close it now?

comment:12 by Jonas Borgström, 11 years ago

Resolution: fixed
Status: newclosed

Yes I think we can close this for now. I've not seen this on t.e.o for a while now and the new pool should be better at closing unused connections.

comment:13 by guillaume.smet@…, 11 years ago

Resolution: fixed
Status: closedreopened

Hi,

If it's supposed to be fixed in Trac 0.11.2.1 (and it seems to be from what I read above), the problem is not fixed: \_ postgres: trac trac 000.000.000.000(53423) idle in transaction (and we have a lot of other PostgreSQL backends in this state).

It causes a few annoying bugs: sometimes, you update data in Trac and data are not consistent when you browse Trac as you connect to different backends which have different snapshots. Typically, I created new milestones and components and sometimes they appeared in the New ticket form, sometimes not.

I'm not sure that the problem is related to the transaction pool but there are definitely transaction leaks going on.

I don't know the trac code at all so please forgive me if I made obvious mistake:

  • I see a lot of commit() and very few rollback() on errors, it's a bit surprising;
  • when you set the search path in the backend, you rollback on error but you don't commit on success. If you rollback on error, I suppose a transaction is open and so it should be commited on success.

I attached a patch for the latter problem. It seems to fix the problem here. I'll check the status of our connections in a couple of days.

Any comment?

Trac 0.11.2.1 PostgreSQL 8.3.6 CentOS 5

— Guillaume

by guillaume.smet@…, 11 years ago

comment:14 by Jonas Borgström, 11 years ago

Milestone: 0.11.10.11.3

This only applies to environments where a database schema is specified:

Yes, I think you're on to something. by setting search_path in rollback() we also start a new transaction. This isn't such a good idea since this connection is probably going back into the pool and not being used for a while. A commit closes the transaction again (probably without much overhead) and avoids the problem with idle connection.

On the other hand I don't think we'll need to add a cnx.commit() to the constructor since this time we know that the connection will be used right away.

I'll commit the rollback() change to 0.11-stable so that this change makes it into the upcoming 0.11.3 release.

Thanks!

comment:15 by Jonas Borgström, 11 years ago

Resolution: fixed
Status: reopenedclosed

Fixed in [7866] and [7867].

comment:16 by guillaume.smet@…, 11 years ago

Resolution: fixed
Status: closedreopened

Hi Jonas,

Why don't you need to commit the transaction in the constructor? The set search_path is a commitable operation by itself. I don't think it's necessary to let the transaction open more longer than it should be: there's no point in it and moreover you want to commit it.

Suppose the following case (I don't know if it happens in Trac but it's a real use case):

  • You get the connection, you set the search_path but you don't commit
  • You execute a set of queries and for one reason, you have to rollback
  • Then your search_path is rollbacked too and other queries are executed on whatever the default search_path is (the set search_path is a rollbackable operation too).

Even if this case doesn't happen in Trac for whatever reason, there's no reason to take that risk IMHO as there's really no gain in not committing the set search_path right after it's done (the overhead is really negligible).

By the way, the schema thing of Trac is really a great usage of PostgreSQL schemas. Thanks for that.

I don't know if you'll see this comment if I don't reopen the ticket so I reopen it. Sorry if it's not what I should have done.

— Guillaume

comment:17 by Jonas Borgström, 11 years ago

Resolution: fixed
Status: reopenedclosed

Yes, I just realized that when I took my shower this morning :) This way is slight more efficient and does not require us to override the rollback method.

On the other hand I don't see how the case you describe could happen with the current code since it always re-sets the search_path directly after a rollback(). But it doesn't matter anyway since setting it once in the constructor is more efficient anyway.

This should be fixed in [7868] and [7869], thanks again!

comment:18 by guillaume.smet@…, 11 years ago

Yeah, it's better like that.

Thanks for fixing it in 0.11, I must admit I had a hard time when my milestones changed every time I refreshed the page.

— Guillaume

comment:19 by Ryan J Ollos, 5 years ago

Keywords: postgresql needinfo → postgresql, needinfo

Modify Ticket

Change Properties
Set your email in Preferences
Action
as closed The owner will remain Jonas Borgström.
The resolution will be deleted. Next status will be 'reopened'.
to as closed The owner will be changed from Jonas Borgström to the specified user.

Add Comment


E-mail address and name can be saved in the Preferences .
 
Note: See TracTickets for help on using tickets.