Thread: What happens on a commit?

What happens on a commit?

From
"Chris Hoover"
Date:
I am trying to diagnose a slowness issue in some of my databases.  I think the issue is due to a hardware/network upgrade over the weekend, but like all dba's, I have to prove it.

Right now, I have almost all commits being issues taking between 1 and 5 seconds to complete.  The can take as long as 20 seconds.  What exactly happens when a commit is issues to PostgreSQL?

Is there a way to trace what is going on internally?  I do have a large process that I can start that will run many transactions during a single session.

Anyway, any help would be appreciated.

Thanks,

Chris

PG 8.1.3
RH 4.0 AS

Re: What happens on a commit?

From
"Chris Hoover"
Date:
I found an e-mail showing how to strace and here is what I have found.  Does it help/mean anything to those who can decode this?

We are installing PostgreSQL from the official rpms.

Chris

 time strace -c -p 2690
Process 2690 attached - interrupt to quit
Process 2690 detached
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 42.80   13.003288          251     51790           recv
 17.47    5.306686          30    175916           send
 16.23    4.930150          14    342118           stat64
 10.26    3.117593          18    174533           write
  8.22    2.497767           9    292070           gettimeofday
  2.63    0.798323         462      1727           fdatasync
  1.83    0.554745           6     92179           _llseek
  0.46    0.138782          11     12896           brk
  0.09    0.026920          19      1433           semop
  0.02    0.006847           4      1734           time
  0.00    0.000494          16        31           read
  0.00    0.000253          23        11           open
  0.00    0.000088           7        12           close
  0.00    0.000013          13         1           kill
  0.00    0.000010          10         1           sigreturn
  0.00    0.000001           1         1           fsync
------ ----------- ----------- --------- --------- ----------------
100.00   30.381960               1146453           total

real    27m21.090s
user    0m5.379s
sys     0m23.073s

Re: What happens on a commit?

From
Alvaro Herrera
Date:
Chris Hoover escribió:
> I found an e-mail showing how to strace and here is what I have found.  Does
> it help/mean anything to those who can decode this?
>
> We are installing PostgreSQL from the official rpms.
>
> Chris
>
> time strace -c -p 2690
> Process 2690 attached - interrupt to quit
> Process 2690 detached
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
> 42.80   13.003288         251     51790           recv
> 17.47    5.306686          30    175916           send

This means that 60% of the time spent by system calls is due to network
operations.  But they account to 18.3 seconds, whereas this

> real    27m21.090s
> user    0m5.379s
> sys     0m23.073s

says that the total time spent is 27:21.  So you have to explain the
remaining 27:03 which are elsewhere.

--
Alvaro Herrera                                http://www.CommandPrompt.com/
The PostgreSQL Company - Command Prompt, Inc.

Re: What happens on a commit?

From
"Chris Hoover"
Date:
Ok, we are looking more into this.  In the mean time, can someone please explain to me (or point me to the correct documentation) what happens in PostgreSQL when a commit is issued.  What exactly does the database do?

Thanks,

Chris

On 5/22/07, Alvaro Herrera <alvherre@commandprompt.com> wrote:
Chris Hoover escribió:
> I found an e-mail showing how to strace and here is what I have found.  Does
> it help/mean anything to those who can decode this?
>
> We are installing PostgreSQL from the official rpms.
>
> Chris
>
> time strace -c -p 2690
> Process 2690 attached - interrupt to quit
> Process 2690 detached
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
> 42.80   13.003288         251     51790           recv
> 17.47    5.306686          30    175916           send

This means that 60% of the time spent by system calls is due to network
operations.  But they account to 18.3 seconds, whereas this

> real    27m21.090s
> user    0m5.379s
> sys     0m23.073s

says that the total time spent is 27:21.  So you have to explain the
remaining 27:03 which are elsewhere.

--
Alvaro Herrera                                http://www.CommandPrompt.com/
The PostgreSQL Company - Command Prompt, Inc.

Re: What happens on a commit?

From
Alvaro Herrera
Date:
Chris Hoover escribió:
> Ok, we are looking more into this.  In the mean time, can someone please
> explain to me (or point me to the correct documentation) what happens in
> PostgreSQL when a commit is issued.  What exactly does the database do?

It writes a commit WAL record and flushes (fsync) the WAL up to that
point.  This is the more important bit.  Also, async notifies are sent
(those you started with NOTIFY), and files corresponding to some
commands are deleted (e.g. TRUNCATE, CLUSTER, REINDEX).  Temp tables
with ON COMMIT setting may be operated upon.

It entirely depends on what the transaction did.

--
Alvaro Herrera                                http://www.CommandPrompt.com/
The PostgreSQL Company - Command Prompt, Inc.