Thread: Concurrency issue under very heay loads

Concurrency issue under very heay loads

From

"Raji Sridar (raji)"

Date:

16 July 2009, 05:09:48

Hi,

We use a typical counter within a transaction to generate order sequence number and update the next sequence number. This is a simple next counter - nothing fancy about it. When multiple clients are concurrently accessing this table and updating it, under extermely heavy loads in the system (stress testing), we find that the same order number is being generated for multiple clients. Could this be a bug? Is there a workaround? Please let me know.

Thanks

Raji

Re: [PERFORM] Concurrency issue under very heay loads

From

"ramasubramanian"

Date:

16 July 2009, 05:26:42

Hi,

Are you using automatic sequence increment in table?

----- Original Message -----
From: Raji Sridar (raji)
To: pgsql-general@postgresql.org ; pgsql-performance@postgresql.org
Sent: Thursday, July 16, 2009 10:29 AM
Subject: [PERFORM] Concurrency issue under very heay loads

Hi,

We use a typical counter within a transaction to generate order sequence number and update the next sequence number. This is a simple next counter - nothing fancy about it. When multiple clients are concurrently accessing this table and updating it, under extermely heavy loads in the system (stress testing), we find that the same order number is being generated for multiple clients. Could this be a bug? Is there a workaround? Please let me know.

Thanks
Raji

Re: Concurrency issue under very heay loads

From

Greenhorn

Date:

16 July 2009, 05:31:07

2009/7/16 Raji Sridar (raji) <raji@cisco.com>:
> Hi,
>
> We use a typical counter within a transaction to generate order sequence
> number and update the next sequence number. This is a simple next counter -
> nothing fancy about it.  When multiple clients are concurrently accessing
> this table and updating it, under extermely heavy loads in the system
> (stress testing), we find that the same order number is being generated for
> multiple clients. Could this be a bug? Is there a workaround? Please let me
> know.
>
> Thanks
> Raji

You'll not have this problem if you use serial type.

Re: Concurrency issue under very heay loads

From

John R Pierce

Date:

16 July 2009, 05:35:53

Raji Sridar (raji) wrote:
> Hi,
>
> We use a typical counter within a transaction to generate order
> sequence number and update the next sequence number. This is a simple
> next counter - nothing fancy about it.  When multiple clients are
> concurrently accessing this table and updating it, under extermely
> heavy loads in the system (stress testing), we find that the same
> order number is being generated for multiple clients. Could this be a
> bug? Is there a workaround? Please let me know.

without seeing your code, its hard to say where this bug is, in your
counter implementation, or in postgres.  you also don't say what version
of postgres you're using, or even what OS you're running under...

sounds like you should be using a SERIAL (which is implemented as an
INTEGER or BIGINT field with an associated SEQUENCE), as these DO work
just fine under heavy concurrency without any gotchas.

Re: [PERFORM] Concurrency issue under very heay loads

From

Scott Marlowe

Date:

16 July 2009, 06:11:46

On Wed, Jul 15, 2009 at 10:59 PM, Raji Sridar (raji)<raji@cisco.com> wrote:
> Hi,
>
> We use a typical counter within a transaction to generate order sequence
> number and update the next sequence number. This is a simple next counter -
> nothing fancy about it.  When multiple clients are concurrently accessing
> this table and updating it, under extermely heavy loads in the system
> (stress testing), we find that the same order number is being generated for
> multiple clients. Could this be a bug? Is there a workaround? Please let me
> know.

As others have said, a serial is a good idea, HOWEVER, if you can't
have gaps in sequences, or each customer needs their own sequence,
then you get to lock the rows / table / etc that you're mucking with
to make sure you don't issue the same id number twice.  It's easy to
test your code by hand by running pieces of it in two different psql
sessions in such a way as to induce the race condition (or not if
you've got it right).

Re: [PERFORM] Concurrency issue under very heay loads

From

"Albe Laurenz"

Date:

16 July 2009, 09:17:57

Raji Sridar wrote:
> We use a typical counter within a transaction to generate
> order sequence number and update the next sequence number.
> This is a simple next counter - nothing fancy about it.  When
> multiple clients are concurrently accessing this table and
> updating it, under extermely heavy loads in the system
> (stress testing), we find that the same order number is being
> generated for multiple clients. Could this be a bug? Is there
> a workaround? Please let me know.

Please show us your code!

Yours,
Laurenz Albe

Re: [PERFORM] Concurrency issue under very heay loads

From

Allan Kamau

Date:

16 July 2009, 09:44:24

May be a simple way would be to use a "SEQUENCE" database object. And
call nextval('your_sequence') to obtain the next unique value (of type
bigint).
According to PG docs
"http://www.postgresql.org/docs/8.4/interactive/functions-sequence.html",
the sequence object has functions that "provide simple, multiuser-safe
methods for obtaining successive sequence values from sequence
objects. "

You may either provide this function as a default to the field in
which you'd like the unique values to go to.
OR
If you'd like to make use of this value before data is inserted to the
table simply call SELECT nextval('your_sequence') to obtain the next
unique bigint value which you may insert into the appropriate field in
your table and still the the value for later use maybe to populate a
child table.

Allan.

On Thu, Jul 16, 2009 at 11:15 AM, Albe Laurenz<laurenz.albe@wien.gv.at> wrote:
> Raji Sridar wrote:
>> We use a typical counter within a transaction to generate
>> order sequence number and update the next sequence number.
>> This is a simple next counter - nothing fancy about it.  When
>> multiple clients are concurrently accessing this table and
>> updating it, under extermely heavy loads in the system
>> (stress testing), we find that the same order number is being
>> generated for multiple clients. Could this be a bug? Is there
>> a workaround? Please let me know.
>
> Please show us your code!
>
> Yours,
> Laurenz Albe
>
> --
> Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
> To make changes to your subscription:
> http://www.postgresql.org/mailpref/pgsql-general
>

Re: Concurrency issue under very heay loads

From

Bill Moran

Date:

16 July 2009, 11:24:26

"Raji Sridar (raji)" <raji@cisco.com> wrote:
>
> We use a typical counter within a transaction to generate order sequence number and update the next sequence number.
Thisis a simple next counter - nothing fancy about it.  When multiple clients are concurrently accessing this table and
updatingit, under extermely heavy loads in the system (stress testing), we find that the same order number is being
generatedfor multiple clients. Could this be a bug? Is there a workaround? Please let me know. 

As others have said: using a sequence/serial is best, as long as you can
deal with gaps in the generated numbers.  (note that in actual practice,
the number of gaps is usually very small.)

Without seeing the code, here's my guess as to what's wrong:
You take out a write lock on the table, then acquire the next number, then
release the lock, _then_ insert the new row.  Doing this allows a race
condition between number generation and insertion which could allow
duplicates.

Am I right?  Did I guess it?

If so, you need to take out the lock on the table and hold that lock until
you've inserted the new row.

If none of these answers help, you're going to have to show us your code,
or at least a pared down version that exhibits the problem.

[I'm stripping off the performance list, as this doesn't seem like a
performance question.]

--
Bill Moran
http://www.potentialtech.com

Re: Concurrency issue under very heay loads

From

Greg Smith

Date:

16 July 2009, 21:03:34

On Wed, 15 Jul 2009, Raji Sridar (raji) wrote:

> When multiple clients are concurrently accessing this table and updating
> it, under extermely heavy loads in the system (stress testing), we find
> that the same order number is being generated for multiple clients.

The only clean way to generate sequence numbers without needing to worry
about duplicates is using nextval:
http://www.postgresql.org/docs/current/static/functions-sequence.html

If you're trying to duplicate that logic in your own code, there's
probably a subtle race condition in your implementation that is causing
the bug.

If you had two calls to nextval from different clients get the same value
returned, that might be a PostgreSQL bug.  Given how much that code gets
tested, the more likely case is that there's something to tweak in your
application instead.  I would advise starting with the presumption it's an
issue in your app rather than on the server side of things.

P.S. Posting the same question to two lists here is frowned upon;
pgsql-general is the right one for a question like this.

--
* Greg Smith gsmith@gregsmith.com http://www.gregsmith.com Baltimore, MD

Re: Concurrency issue under very heay loads

From

Craig Ringer

Date:

17 July 2009, 14:36:38

On Wed, 2009-07-15 at 22:34 -0700, John R Pierce wrote:

> sounds like you should be using a SERIAL (which is implemented as an
> INTEGER or BIGINT field with an associated SEQUENCE), as these DO work
> just fine under heavy concurrency without any gotchas.

There is one gotcha, though we're all so used to it (and/or never
would've thought to care about it) as to forget it:

  With a SEQUENCE, as produced by the SERIAL pseudo-type, values
  may be skipped if a transaction rolls back. That includes automatic
  rollback on error or disconnect, not just explicit ROLLBACK of course.

If you're using sequences to generate synthetic keys that's exactly what
you want; you don't care about gaps and you want it fast and
concurrency-friendly.

If your application can't cope with gaps in the sequence then either (a)
fix it so it can, or (b) search this mailing list for gapless sequence
implementations and use one of them. Beware the nasty performance
implications.

--
Craig Ringer

Re: [PERFORM] Concurrency issue under very heay loads

From

Craig Ringer

Date:

17 July 2009, 14:38:04

On Thu, 2009-07-16 at 00:11 -0600, Scott Marlowe wrote:

> As others have said, a serial is a good idea, HOWEVER, if you can't
> have gaps in sequences, or each customer needs their own sequence,
> then you get to lock the rows / table / etc that you're mucking with
> to make sure you don't issue the same id number twice.

These days can't you just UPDATE ... RETURNING the sequence source
table? Or is there some concurrency issue there I'm not seeing? Other
than the awful impact on concurrent insert performance of course, but
you're stuck with that using any gapless sequence.

--
Craig Ringer

Re: Concurrency issue under very heay loads

From

"Raji Sridar (raji)"

Date:

17 July 2009, 16:48:37

Thanks for everyone's inputs and here is an update on the issue:
The problem source is that autocommit is not getting unset.
The code does the following ( and source code or copyright does not
belong to Cisco):
. unsets autocommit
. starts transaction
. SQL for select for update....
. SQL for update next sequence number
. Commits transaction
The problem is in unsetting auto commit. Since this runs inside an Jboss
app server/EJB environment, this becomes a no-op and hence the ACIDity
across the select for update and update. We are using postgres 8.2.12 on
Windows with JDBC driver 8.2-506.
Thanks
Raji
-----Original Message-----
From: Greg Smith [mailto:gsmith@gregsmith.com]
Sent: Thursday, July 16, 2009 2:03 PM
To: Raji Sridar (raji)
Cc: pgsql-general@postgresql.org
Subject: Re: [GENERAL] Concurrency issue under very heay loads

On Wed, 15 Jul 2009, Raji Sridar (raji) wrote:

> When multiple clients are concurrently accessing this table and
> updating it, under extermely heavy loads in the system (stress
> testing), we find that the same order number is being generated for
multiple clients.

The only clean way to generate sequence numbers without needing to worry
about duplicates is using nextval:
http://www.postgresql.org/docs/current/static/functions-sequence.html

If you're trying to duplicate that logic in your own code, there's
probably a subtle race condition in your implementation that is causing
the bug.

If you had two calls to nextval from different clients get the same
value returned, that might be a PostgreSQL bug.  Given how much that
code gets tested, the more likely case is that there's something to
tweak in your application instead.  I would advise starting with the
presumption it's an issue in your app rather than on the server side of
things.

P.S. Posting the same question to two lists here is frowned upon;
pgsql-general is the right one for a question like this.

--
* Greg Smith gsmith@gregsmith.com http://www.gregsmith.com Baltimore, MD

Re: [PERFORM] Concurrency issue under very heay loads

From

"Haszlakiewicz, Eric"

Date:

17 July 2009, 19:13:41

>-----Original Message-----
>From: pgsql-performance-owner@postgresql.org
>
>We use a typical counter within a transaction to generate
>order sequence number and update the next sequence number.
>This is a simple next counter - nothing fancy about it.  When
>multiple clients are concurrently accessing this table and
>updating it, under extermely heavy loads in the system (stress
>testing), we find that the same order number is being
>generated for multiple clients. Could this be a bug? Is there
>a workaround? Please let me know.

Are you using "for update" in your select statements?   Are you setting
an appropriate transaction isolation level?

A better way to do this is with a sequence instead.  This is guaranteed
to give you a unique value:
select nextval('address_serial_num_seq');

eric

Help needed for reading postgres log : RE: Concurrency issue under very heay loads

From

"Raji Sridar (raji)"

Date:

20 July 2009, 22:38:14

I would like some help in reading the postgres logs.
Here is a snippet of the log.
Auto commit seems to be set to false.
But still the logs shows "CommitTransactionCommand" in debug mode.
The same order number is given for multiple clients.
Please see "CommitTransactionCommand" below for both "select ...for
update" and "update..." SQLs and let me know if I am reading correctly
that auto commit is actually effective.
Thanks
Raji
-----
2009-07-17 14:10:59 4736 970134 DEBUG:  parse <unnamed>: SELECT
nextEntityID FROM tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 STATEMENT:  SELECT nextEntityID FROM
tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 DEBUG:  StartTransactionCommand
2009-07-17 14:10:59 4736 970134 STATEMENT:  SELECT nextEntityID FROM
tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 DEBUG:  parse tree:
2009-07-17 14:10:59 4736 970134 DETAIL:     {QUERY
    :commandType 1
    :querySource 0
    :canSetTag true
    :utilityStmt <>
    :resultRelation 0
    :into <>
    :intoOptions <>
    :intoOnCommit 0
    :intoTableSpaceName <>
    :hasAggs false
    :hasSubLinks false
    :rtable (
       {RTE
       :alias <>
       :eref
          {ALIAS
          :aliasname tableentityid
          :colnames ("entitytype" "nextentityid")
          }
       :rtekind 0
       :relid 16420
       :inh true
       :inFromCl true
       :requiredPerms 6
       :checkAsUser 0
       }
    )
    :jointree
       {FROMEXPR
       :fromlist (
          {RANGETBLREF
          :rtindex 1
          }
       )
       :quals
          {OPEXPR
          :opno 98
          :opfuncid 0
          :opresulttype 16
          :opretset false
          :args (
             {RELABELTYPE
             :arg
                {VAR
                :varno 1
                :varattno 1
                :vartype 1043
                :vartypmod 68
                :varlevelsup 0
                :varnoold 1
                :varoattno 1
                }
             :resulttype 25
             :resulttypmod -1
             :relabelformat 2
             }
             {RELABELTYPE
             :arg
                {PARAM
                :paramkind 0
                :paramid 1
                :paramtype 1043
                }
             :resulttype 25
             :resulttypmod -1
             :relabelformat 2
             }
          )
          }
       }
    :targetList (
       {TARGETENTRY
       :expr
          {VAR
          :varno 1
          :varattno 2
          :vartype 1043
          :vartypmod 132
          :varlevelsup 0
          :varnoold 1
          :varoattno 2
          }
       :resno 1
       :resname nextentityid
       :ressortgroupref 0
       :resorigtbl 16420
       :resorigcol 2
       :resjunk false
       }
    )
    :returningList <>
    :groupClause <>
    :havingQual <>
    :distinctClause <>
    :sortClause <>
    :limitOffset <>
    :limitCount <>
    :rowMarks (
       {ROWMARKCLAUSE
       :rti 1
       :forUpdate true
       :noWait false
       }
    )
    :setOperations <>
    :resultRelations <>
    :returningLists <>
    }

2009-07-17 14:10:59 4736 970134 STATEMENT:  SELECT nextEntityID FROM
tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 DEBUG:  rewritten parse tree:
2009-07-17 14:10:59 4736 970134 DETAIL:  (
    {QUERY
    :commandType 1
    :querySource 0
    :canSetTag true
    :utilityStmt <>
    :resultRelation 0
    :into <>
    :intoOptions <>
    :intoOnCommit 0
    :intoTableSpaceName <>
    :hasAggs false
    :hasSubLinks false
    :rtable (
       {RTE
       :alias <>
       :eref
          {ALIAS
          :aliasname tableentityid
          :colnames ("entitytype" "nextentityid")
          }
       :rtekind 0
       :relid 16420
       :inh true
       :inFromCl true
       :requiredPerms 6
       :checkAsUser 0
       }
    )
    :jointree
       {FROMEXPR
       :fromlist (
          {RANGETBLREF
          :rtindex 1
          }
       )
       :quals
          {OPEXPR
          :opno 98
          :opfuncid 0
          :opresulttype 16
          :opretset false
          :args (
             {RELABELTYPE
             :arg
                {VAR
                :varno 1
                :varattno 1
                :vartype 1043
                :vartypmod 68
                :varlevelsup 0
                :varnoold 1
                :varoattno 1
                }
             :resulttype 25
             :resulttypmod -1
             :relabelformat 2
             }
             {RELABELTYPE
             :arg
                {PARAM
                :paramkind 0
                :paramid 1
                :paramtype 1043
                }
             :resulttype 25
             :resulttypmod -1
             :relabelformat 2
             }
          )
          }
       }
    :targetList (
       {TARGETENTRY
       :expr
          {VAR
          :varno 1
          :varattno 2
          :vartype 1043
          :vartypmod 132
          :varlevelsup 0
          :varnoold 1
          :varoattno 2
          }
       :resno 1
       :resname nextentityid
       :ressortgroupref 0
       :resorigtbl 16420
       :resorigcol 2
       :resjunk false
       }
    )
    :returningList <>
    :groupClause <>
    :havingQual <>
    :distinctClause <>
    :sortClause <>
    :limitOffset <>
    :limitCount <>
    :rowMarks (
       {ROWMARKCLAUSE
       :rti 1
       :forUpdate true
       :noWait false
       }
    )
    :setOperations <>
    :resultRelations <>
    :returningLists <>
    }
 )

2009-07-17 14:10:59 4736 970134 STATEMENT:  SELECT nextEntityID FROM
tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 LOG:  duration: 0.000 ms
2009-07-17 14:10:59 4736 970134 STATEMENT:  SELECT nextEntityID FROM
tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 DEBUG:  bind <unnamed> to <unnamed>
2009-07-17 14:10:59 4736 970134 DEBUG:  plan:
2009-07-17 14:10:59 4736 970134 DETAIL:     {SEQSCAN
    :startup_cost 0.00
    :total_cost 4.05
    :plan_rows 1
    :plan_width 12
    :targetlist (
       {TARGETENTRY
       :expr
          {VAR
          :varno 1
          :varattno 2
          :vartype 1043
          :vartypmod 132
          :varlevelsup 0
          :varnoold 1
          :varoattno 2
          }
       :resno 1
       :resname nextentityid
       :ressortgroupref 0
       :resorigtbl 16420
       :resorigcol 2
       :resjunk false
       }
       {TARGETENTRY
       :expr
          {VAR
          :varno 1
          :varattno -1
          :vartype 27
          :vartypmod -1
          :varlevelsup 0
          :varnoold 1
          :varoattno -1
          }
       :resno 2
       :resname ctid1
       :ressortgroupref 0
       :resorigtbl 0
       :resorigcol 0
       :resjunk true
       }
    )
    :qual (
       {OPEXPR
       :opno 98
       :opfuncid 67
       :opresulttype 16
       :opretset false
       :args (
          {RELABELTYPE
          :arg
             {VAR
             :varno 1
             :varattno 1
             :vartype 1043
             :vartypmod 68
             :varlevelsup 0
             :varnoold 1
             :varoattno 1
             }
          :resulttype 25
          :resulttypmod -1
          :relabelformat 0
          }
          {CONST
          :consttype 25
          :constlen -1
          :constbyval false
          :constisnull false
          :constvalue 10 [ 10 0 0 0 119 105 122 97 114 100 ]
          }
       )
       }
    )
    :lefttree <>
    :righttree <>
    :initPlan <>
    :extParam (b)
    :allParam (b)
    :nParamExec 0
    :scanrelid 1
    }

2009-07-17 14:10:59 4736 970134 STATEMENT:  SELECT nextEntityID FROM
tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 LOG:  duration: 0.000 ms
2009-07-17 14:10:59 4736 970134 STATEMENT:  SELECT nextEntityID FROM
tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 LOG:  duration: 0.000 ms
2009-07-17 14:10:59 4736 970134 STATEMENT:  SELECT nextEntityID FROM
tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 DEBUG:  CommitTransactionCommand
2009-07-17 14:10:59 4736 970134 DEBUG:  parse <unnamed>: UPDATE
tableEntityID SET nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 DEBUG:  StartTransactionCommand
2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 DEBUG:  parse tree:
2009-07-17 14:10:59 4736 970134 DETAIL:     {QUERY
    :commandType 2
    :querySource 0
    :canSetTag true
    :utilityStmt <>
    :resultRelation 1
    :into <>
    :intoOptions <>
    :intoOnCommit 0
    :intoTableSpaceName <>
    :hasAggs false
    :hasSubLinks false
    :rtable (
       {RTE
       :alias <>
       :eref
          {ALIAS
          :aliasname tableentityid
          :colnames ("entitytype" "nextentityid")
          }
       :rtekind 0
       :relid 16420
       :inh true
       :inFromCl false
       :requiredPerms 6
       :checkAsUser 0
       }
    )
    :jointree
       {FROMEXPR
       :fromlist (
          {RANGETBLREF
          :rtindex 1
          }
       )
       :quals
          {OPEXPR
          :opno 98
          :opfuncid 0
          :opresulttype 16
          :opretset false
          :args (
             {RELABELTYPE
             :arg
                {VAR
                :varno 1
                :varattno 1
                :vartype 1043
                :vartypmod 68
                :varlevelsup 0
                :varnoold 1
                :varoattno 1
                }
             :resulttype 25
             :resulttypmod -1
             :relabelformat 2
             }
             {RELABELTYPE
             :arg
                {PARAM
                :paramkind 0
                :paramid 2
                :paramtype 1043
                }
             :resulttype 25
             :resulttypmod -1
             :relabelformat 2
             }
          )
          }
       }
    :targetList (
       {TARGETENTRY
       :expr
          {FUNCEXPR
          :funcid 669
          :funcresulttype 1043
          :funcretset false
          :funcformat 2
          :args (
             {FUNCEXPR
             :funcid 112
             :funcresulttype 1043
             :funcretset false
             :funcformat 2
             :args (
                {PARAM
                :paramkind 0
                :paramid 1
                :paramtype 23
                }
             )
             }
             {CONST
             :consttype 23
             :constlen 4
             :constbyval true
             :constisnull false
             :constvalue 4 [ -124 0 0 0 ]
             }
             {CONST
             :consttype 16
             :constlen 1
             :constbyval true
             :constisnull false
             :constvalue 1 [ 0 0 0 0 ]
             }
          )
          }
       :resno 2
       :resname nextentityid
       :ressortgroupref 0
       :resorigtbl 0
       :resorigcol 0
       :resjunk false
       }
    )
    :returningList <>
    :groupClause <>
    :havingQual <>
    :distinctClause <>
    :sortClause <>
    :limitOffset <>
    :limitCount <>
    :rowMarks <>
    :setOperations <>
    :resultRelations <>
    :returningLists <>
    }

2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 DEBUG:  rewritten parse tree:
2009-07-17 14:10:59 4736 970134 DETAIL:  (
    {QUERY
    :commandType 2
    :querySource 0
    :canSetTag true
    :utilityStmt <>
    :resultRelation 1
    :into <>
    :intoOptions <>
    :intoOnCommit 0
    :intoTableSpaceName <>
    :hasAggs false
    :hasSubLinks false
    :rtable (
       {RTE
       :alias <>
       :eref
          {ALIAS
          :aliasname tableentityid
          :colnames ("entitytype" "nextentityid")
          }
       :rtekind 0
       :relid 16420
       :inh true
       :inFromCl false
       :requiredPerms 6
       :checkAsUser 0
       }
    )
    :jointree
       {FROMEXPR
       :fromlist (
          {RANGETBLREF
          :rtindex 1
          }
       )
       :quals
          {OPEXPR
          :opno 98
          :opfuncid 0
          :opresulttype 16
          :opretset false
          :args (
             {RELABELTYPE
             :arg
                {VAR
                :varno 1
                :varattno 1
                :vartype 1043
                :vartypmod 68
                :varlevelsup 0
                :varnoold 1
                :varoattno 1
                }
             :resulttype 25
             :resulttypmod -1
             :relabelformat 2
             }
             {RELABELTYPE
             :arg
                {PARAM
                :paramkind 0
                :paramid 2
                :paramtype 1043
                }
             :resulttype 25
             :resulttypmod -1
             :relabelformat 2
             }
          )
          }
       }
    :targetList (
       {TARGETENTRY
       :expr
          {FUNCEXPR
          :funcid 669
          :funcresulttype 1043
          :funcretset false
          :funcformat 2
          :args (
             {FUNCEXPR
             :funcid 112
             :funcresulttype 1043
             :funcretset false
             :funcformat 2
             :args (
                {PARAM
                :paramkind 0
                :paramid 1
                :paramtype 23
                }
             )
             }
             {CONST
             :consttype 23
             :constlen 4
             :constbyval true
             :constisnull false
             :constvalue 4 [ -124 0 0 0 ]
             }
             {CONST
             :consttype 16
             :constlen 1
             :constbyval true
             :constisnull false
             :constvalue 1 [ 0 0 0 0 ]
             }
          )
          }
       :resno 2
       :resname nextentityid
       :ressortgroupref 0
       :resorigtbl 0
       :resorigcol 0
       :resjunk false
       }
    )
    :returningList <>
    :groupClause <>
    :havingQual <>
    :distinctClause <>
    :sortClause <>
    :limitOffset <>
    :limitCount <>
    :rowMarks <>
    :setOperations <>
    :resultRelations <>
    :returningLists <>
    }
 )

2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 LOG:  duration: 0.000 ms
2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 DEBUG:  bind <unnamed> to <unnamed>
2009-07-17 14:10:59 4736 970134 DEBUG:  plan:
2009-07-17 14:10:59 4736 970134 DETAIL:     {SEQSCAN
    :startup_cost 0.00
    :total_cost 4.05
    :plan_rows 1
    :plan_width 17
    :targetlist (
       {TARGETENTRY
       :expr
          {VAR
          :varno 1
          :varattno 1
          :vartype 1043
          :vartypmod 68
          :varlevelsup 0
          :varnoold 1
          :varoattno 1
          }
       :resno 1
       :resname entitytype
       :ressortgroupref 0
       :resorigtbl 0
       :resorigcol 0
       :resjunk false
       }
       {TARGETENTRY
       :expr
          {CONST
          :consttype 1043
          :constlen -1
          :constbyval false
          :constisnull false
          :constvalue 7 [ 7 0 0 0 51 48 53 ]
          }
       :resno 2
       :resname nextentityid
       :ressortgroupref 0
       :resorigtbl 0
       :resorigcol 0
       :resjunk false
       }
       {TARGETENTRY
       :expr
          {VAR
          :varno 1
          :varattno -1
          :vartype 27
          :vartypmod -1
          :varlevelsup 0
          :varnoold 1
          :varoattno -1
          }
       :resno 3
       :resname ctid
       :ressortgroupref 0
       :resorigtbl 0
       :resorigcol 0
       :resjunk true
       }
    )
    :qual (
       {OPEXPR
       :opno 98
       :opfuncid 67
       :opresulttype 16
       :opretset false
       :args (
          {RELABELTYPE
          :arg
             {VAR
             :varno 1
             :varattno 1
             :vartype 1043
             :vartypmod 68
             :varlevelsup 0
             :varnoold 1
             :varoattno 1
             }
          :resulttype 25
          :resulttypmod -1
          :relabelformat 0
          }
          {CONST
          :consttype 25
          :constlen -1
          :constbyval false
          :constisnull false
          :constvalue 10 [ 10 0 0 0 119 105 122 97 114 100 ]
          }
       )
       }
    )
    :lefttree <>
    :righttree <>
    :initPlan <>
    :extParam (b)
    :allParam (b)
    :nParamExec 0
    :scanrelid 1
    }

2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 LOG:  duration: 0.000 ms
2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 DEBUG:  ProcessQuery
2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 LOG:  duration: 0.000 ms
2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 DEBUG:  CommitTransactionCommand

-----Original Message-----
From: Raji Sridar (raji)
Sent: Friday, July 17, 2009 9:48 AM
To: 'Greg Smith'
Cc: pgsql-general@postgresql.org
Subject: RE: [GENERAL] Concurrency issue under very heay loads

Thanks for everyone's inputs and here is an update on the issue:
The problem source is that autocommit is not getting unset.
The code does the following ( and source code or copyright does not
belong to Cisco):
. unsets autocommit
. starts transaction
. SQL for select for update....
. SQL for update next sequence number
. Commits transaction
The problem is in unsetting auto commit. Since this runs inside an Jboss
app server/EJB environment, this becomes a no-op and hence the ACIDity
across the select for update and update. We are using postgres 8.2.12 on
Windows with JDBC driver 8.2-506.
Thanks
Raji
-----Original Message-----
From: Greg Smith [mailto:gsmith@gregsmith.com]
Sent: Thursday, July 16, 2009 2:03 PM
To: Raji Sridar (raji)
Cc: pgsql-general@postgresql.org
Subject: Re: [GENERAL] Concurrency issue under very heay loads

On Wed, 15 Jul 2009, Raji Sridar (raji) wrote:

> When multiple clients are concurrently accessing this table and
> updating it, under extermely heavy loads in the system (stress
> testing), we find that the same order number is being generated for
multiple clients.

The only clean way to generate sequence numbers without needing to worry
about duplicates is using nextval:
http://www.postgresql.org/docs/current/static/functions-sequence.html

If you're trying to duplicate that logic in your own code, there's
probably a subtle race condition in your implementation that is causing
the bug.

If you had two calls to nextval from different clients get the same
value returned, that might be a PostgreSQL bug.  Given how much that
code gets tested, the more likely case is that there's something to
tweak in your application instead.  I would advise starting with the
presumption it's an issue in your app rather than on the server side of
things.

P.S. Posting the same question to two lists here is frowned upon;
pgsql-general is the right one for a question like this.

--
* Greg Smith gsmith@gregsmith.com http://www.gregsmith.com Baltimore, MD

Re: Concurrency issue under very heay loads

From

"Raji Sridar (raji)"

Date:

20 July 2009, 22:50:16

Here is a snippet of the postgres log.
Auto commit seems to be set to false.
But still the logs shows "CommitTransactionCommand" in debug mode.
The same order number is given for multiple clients.
Please see "CommitTransactionCommand" below for both "select ...for
update" and "update..." SQLs and let me know if I am reading correctly
that auto commit is actually effective.

Thanks
Raji
-----
2009-07-17 14:10:59 4736 970134 DEBUG:  parse <unnamed>: SELECT
nextEntityID FROM tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 STATEMENT:  SELECT nextEntityID FROM
tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 DEBUG:  StartTransactionCommand
2009-07-17 14:10:59 4736 970134 STATEMENT:  SELECT nextEntityID FROM
tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 DEBUG:  parse tree:
2009-07-17 14:10:59 4736 970134 DETAIL:     {QUERY
    :commandType 1
    :querySource 0
    :canSetTag true
    :utilityStmt <>
    :resultRelation 0
    :into <>
    :intoOptions <>
    :intoOnCommit 0
    :intoTableSpaceName <>
    :hasAggs false
    :hasSubLinks false
    :rtable (
       {RTE
       :alias <>
       :eref
          {ALIAS
          :aliasname tableentityid
          :colnames ("entitytype" "nextentityid")
          }
       :rtekind 0
       :relid 16420
       :inh true
       :inFromCl true
       :requiredPerms 6
       :checkAsUser 0
       }
    )
    :jointree
       {FROMEXPR
       :fromlist (
          {RANGETBLREF
          :rtindex 1
          }
       )
       :quals
          {OPEXPR
          :opno 98
          :opfuncid 0
          :opresulttype 16
          :opretset false
          :args (
             {RELABELTYPE
             :arg
                {VAR
                :varno 1
                :varattno 1
                :vartype 1043
                :vartypmod 68
                :varlevelsup 0
                :varnoold 1
                :varoattno 1
                }
             :resulttype 25
             :resulttypmod -1
             :relabelformat 2
             }
             {RELABELTYPE
             :arg
                {PARAM
                :paramkind 0
                :paramid 1
                :paramtype 1043
                }
             :resulttype 25
             :resulttypmod -1
             :relabelformat 2
             }
          )
          }
       }
    :targetList (
       {TARGETENTRY
       :expr
          {VAR
          :varno 1
          :varattno 2
          :vartype 1043
          :vartypmod 132
          :varlevelsup 0
          :varnoold 1
          :varoattno 2
          }
       :resno 1
       :resname nextentityid
       :ressortgroupref 0
       :resorigtbl 16420
       :resorigcol 2
       :resjunk false
       }
    )
    :returningList <>
    :groupClause <>
    :havingQual <>
    :distinctClause <>
    :sortClause <>
    :limitOffset <>
    :limitCount <>
    :rowMarks (
       {ROWMARKCLAUSE
       :rti 1
       :forUpdate true
       :noWait false
       }
    )
    :setOperations <>
    :resultRelations <>
    :returningLists <>
    }

2009-07-17 14:10:59 4736 970134 STATEMENT:  SELECT nextEntityID FROM
tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 DEBUG:  rewritten parse tree:
2009-07-17 14:10:59 4736 970134 DETAIL:  (
    {QUERY
    :commandType 1
    :querySource 0
    :canSetTag true
    :utilityStmt <>
    :resultRelation 0
    :into <>
    :intoOptions <>
    :intoOnCommit 0
    :intoTableSpaceName <>
    :hasAggs false
    :hasSubLinks false
    :rtable (
       {RTE
       :alias <>
       :eref
          {ALIAS
          :aliasname tableentityid
          :colnames ("entitytype" "nextentityid")
          }
       :rtekind 0
       :relid 16420
       :inh true
       :inFromCl true
       :requiredPerms 6
       :checkAsUser 0
       }
    )
    :jointree
       {FROMEXPR
       :fromlist (
          {RANGETBLREF
          :rtindex 1
          }
       )
       :quals
          {OPEXPR
          :opno 98
          :opfuncid 0
          :opresulttype 16
          :opretset false
          :args (
             {RELABELTYPE
             :arg
                {VAR
                :varno 1
                :varattno 1
                :vartype 1043
                :vartypmod 68
                :varlevelsup 0
                :varnoold 1
                :varoattno 1
                }
             :resulttype 25
             :resulttypmod -1
             :relabelformat 2
             }
             {RELABELTYPE
             :arg
                {PARAM
                :paramkind 0
                :paramid 1
                :paramtype 1043
                }
             :resulttype 25
             :resulttypmod -1
             :relabelformat 2
             }
          )
          }
       }
    :targetList (
       {TARGETENTRY
       :expr
          {VAR
          :varno 1
          :varattno 2
          :vartype 1043
          :vartypmod 132
          :varlevelsup 0
          :varnoold 1
          :varoattno 2
          }
       :resno 1
       :resname nextentityid
       :ressortgroupref 0
       :resorigtbl 16420
       :resorigcol 2
       :resjunk false
       }
    )
    :returningList <>
    :groupClause <>
    :havingQual <>
    :distinctClause <>
    :sortClause <>
    :limitOffset <>
    :limitCount <>
    :rowMarks (
       {ROWMARKCLAUSE
       :rti 1
       :forUpdate true
       :noWait false
       }
    )
    :setOperations <>
    :resultRelations <>
    :returningLists <>
    }
 )

2009-07-17 14:10:59 4736 970134 STATEMENT:  SELECT nextEntityID FROM
tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 LOG:  duration: 0.000 ms
2009-07-17 14:10:59 4736 970134 STATEMENT:  SELECT nextEntityID FROM
tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 DEBUG:  bind <unnamed> to <unnamed>
2009-07-17 14:10:59 4736 970134 DEBUG:  plan:
2009-07-17 14:10:59 4736 970134 DETAIL:     {SEQSCAN
    :startup_cost 0.00
    :total_cost 4.05
    :plan_rows 1
    :plan_width 12
    :targetlist (
       {TARGETENTRY
       :expr
          {VAR
          :varno 1
          :varattno 2
          :vartype 1043
          :vartypmod 132
          :varlevelsup 0
          :varnoold 1
          :varoattno 2
          }
       :resno 1
       :resname nextentityid
       :ressortgroupref 0
       :resorigtbl 16420
       :resorigcol 2
       :resjunk false
       }
       {TARGETENTRY
       :expr
          {VAR
          :varno 1
          :varattno -1
          :vartype 27
          :vartypmod -1
          :varlevelsup 0
          :varnoold 1
          :varoattno -1
          }
       :resno 2
       :resname ctid1
       :ressortgroupref 0
       :resorigtbl 0
       :resorigcol 0
       :resjunk true
       }
    )
    :qual (
       {OPEXPR
       :opno 98
       :opfuncid 67
       :opresulttype 16
       :opretset false
       :args (
          {RELABELTYPE
          :arg
             {VAR
             :varno 1
             :varattno 1
             :vartype 1043
             :vartypmod 68
             :varlevelsup 0
             :varnoold 1
             :varoattno 1
             }
          :resulttype 25
          :resulttypmod -1
          :relabelformat 0
          }
          {CONST
          :consttype 25
          :constlen -1
          :constbyval false
          :constisnull false
          :constvalue 10 [ 10 0 0 0 119 105 122 97 114 100 ]
          }
       )
       }
    )
    :lefttree <>
    :righttree <>
    :initPlan <>
    :extParam (b)
    :allParam (b)
    :nParamExec 0
    :scanrelid 1
    }

2009-07-17 14:10:59 4736 970134 STATEMENT:  SELECT nextEntityID FROM
tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 LOG:  duration: 0.000 ms
2009-07-17 14:10:59 4736 970134 STATEMENT:  SELECT nextEntityID FROM
tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 LOG:  duration: 0.000 ms
2009-07-17 14:10:59 4736 970134 STATEMENT:  SELECT nextEntityID FROM
tableEntityID WHERE entityType = $1 FOR UPDATE
2009-07-17 14:10:59 4736 970134 DEBUG:  CommitTransactionCommand
2009-07-17 14:10:59 4736 970134 DEBUG:  parse <unnamed>: UPDATE
tableEntityID SET nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 DEBUG:  StartTransactionCommand
2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 DEBUG:  parse tree:
2009-07-17 14:10:59 4736 970134 DETAIL:     {QUERY
    :commandType 2
    :querySource 0
    :canSetTag true
    :utilityStmt <>
    :resultRelation 1
    :into <>
    :intoOptions <>
    :intoOnCommit 0
    :intoTableSpaceName <>
    :hasAggs false
    :hasSubLinks false
    :rtable (
       {RTE
       :alias <>
       :eref
          {ALIAS
          :aliasname tableentityid
          :colnames ("entitytype" "nextentityid")
          }
       :rtekind 0
       :relid 16420
       :inh true
       :inFromCl false
       :requiredPerms 6
       :checkAsUser 0
       }
    )
    :jointree
       {FROMEXPR
       :fromlist (
          {RANGETBLREF
          :rtindex 1
          }
       )
       :quals
          {OPEXPR
          :opno 98
          :opfuncid 0
          :opresulttype 16
          :opretset false
          :args (
             {RELABELTYPE
             :arg
                {VAR
                :varno 1
                :varattno 1
                :vartype 1043
                :vartypmod 68
                :varlevelsup 0
                :varnoold 1
                :varoattno 1
                }
             :resulttype 25
             :resulttypmod -1
             :relabelformat 2
             }
             {RELABELTYPE
             :arg
                {PARAM
                :paramkind 0
                :paramid 2
                :paramtype 1043
                }
             :resulttype 25
             :resulttypmod -1
             :relabelformat 2
             }
          )
          }
       }
    :targetList (
       {TARGETENTRY
       :expr
          {FUNCEXPR
          :funcid 669
          :funcresulttype 1043
          :funcretset false
          :funcformat 2
          :args (
             {FUNCEXPR
             :funcid 112
             :funcresulttype 1043
             :funcretset false
             :funcformat 2
             :args (
                {PARAM
                :paramkind 0
                :paramid 1
                :paramtype 23
                }
             )
             }
             {CONST
             :consttype 23
             :constlen 4
             :constbyval true
             :constisnull false
             :constvalue 4 [ -124 0 0 0 ]
             }
             {CONST
             :consttype 16
             :constlen 1
             :constbyval true
             :constisnull false
             :constvalue 1 [ 0 0 0 0 ]
             }
          )
          }
       :resno 2
       :resname nextentityid
       :ressortgroupref 0
       :resorigtbl 0
       :resorigcol 0
       :resjunk false
       }
    )
    :returningList <>
    :groupClause <>
    :havingQual <>
    :distinctClause <>
    :sortClause <>
    :limitOffset <>
    :limitCount <>
    :rowMarks <>
    :setOperations <>
    :resultRelations <>
    :returningLists <>
    }

2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 DEBUG:  rewritten parse tree:
2009-07-17 14:10:59 4736 970134 DETAIL:  (
    {QUERY
    :commandType 2
    :querySource 0
    :canSetTag true
    :utilityStmt <>
    :resultRelation 1
    :into <>
    :intoOptions <>
    :intoOnCommit 0
    :intoTableSpaceName <>
    :hasAggs false
    :hasSubLinks false
    :rtable (
       {RTE
       :alias <>
       :eref
          {ALIAS
          :aliasname tableentityid
          :colnames ("entitytype" "nextentityid")
          }
       :rtekind 0
       :relid 16420
       :inh true
       :inFromCl false
       :requiredPerms 6
       :checkAsUser 0
       }
    )
    :jointree
       {FROMEXPR
       :fromlist (
          {RANGETBLREF
          :rtindex 1
          }
       )
       :quals
          {OPEXPR
          :opno 98
          :opfuncid 0
          :opresulttype 16
          :opretset false
          :args (
             {RELABELTYPE
             :arg
                {VAR
                :varno 1
                :varattno 1
                :vartype 1043
                :vartypmod 68
                :varlevelsup 0
                :varnoold 1
                :varoattno 1
                }
             :resulttype 25
             :resulttypmod -1
             :relabelformat 2
             }
             {RELABELTYPE
             :arg
                {PARAM
                :paramkind 0
                :paramid 2
                :paramtype 1043
                }
             :resulttype 25
             :resulttypmod -1
             :relabelformat 2
             }
          )
          }
       }
    :targetList (
       {TARGETENTRY
       :expr
          {FUNCEXPR
          :funcid 669
          :funcresulttype 1043
          :funcretset false
          :funcformat 2
          :args (
             {FUNCEXPR
             :funcid 112
             :funcresulttype 1043
             :funcretset false
             :funcformat 2
             :args (
                {PARAM
                :paramkind 0
                :paramid 1
                :paramtype 23
                }
             )
             }
             {CONST
             :consttype 23
             :constlen 4
             :constbyval true
             :constisnull false
             :constvalue 4 [ -124 0 0 0 ]
             }
             {CONST
             :consttype 16
             :constlen 1
             :constbyval true
             :constisnull false
             :constvalue 1 [ 0 0 0 0 ]
             }
          )
          }
       :resno 2
       :resname nextentityid
       :ressortgroupref 0
       :resorigtbl 0
       :resorigcol 0
       :resjunk false
       }
    )
    :returningList <>
    :groupClause <>
    :havingQual <>
    :distinctClause <>
    :sortClause <>
    :limitOffset <>
    :limitCount <>
    :rowMarks <>
    :setOperations <>
    :resultRelations <>
    :returningLists <>
    }
 )

2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 LOG:  duration: 0.000 ms
2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 DEBUG:  bind <unnamed> to <unnamed>
2009-07-17 14:10:59 4736 970134 DEBUG:  plan:
2009-07-17 14:10:59 4736 970134 DETAIL:     {SEQSCAN
    :startup_cost 0.00
    :total_cost 4.05
    :plan_rows 1
    :plan_width 17
    :targetlist (
       {TARGETENTRY
       :expr
          {VAR
          :varno 1
          :varattno 1
          :vartype 1043
          :vartypmod 68
          :varlevelsup 0
          :varnoold 1
          :varoattno 1
          }
       :resno 1
       :resname entitytype
       :ressortgroupref 0
       :resorigtbl 0
       :resorigcol 0
       :resjunk false
       }
       {TARGETENTRY
       :expr
          {CONST
          :consttype 1043
          :constlen -1
          :constbyval false
          :constisnull false
          :constvalue 7 [ 7 0 0 0 51 48 53 ]
          }
       :resno 2
       :resname nextentityid
       :ressortgroupref 0
       :resorigtbl 0
       :resorigcol 0
       :resjunk false
       }
       {TARGETENTRY
       :expr
          {VAR
          :varno 1
          :varattno -1
          :vartype 27
          :vartypmod -1
          :varlevelsup 0
          :varnoold 1
          :varoattno -1
          }
       :resno 3
       :resname ctid
       :ressortgroupref 0
       :resorigtbl 0
       :resorigcol 0
       :resjunk true
       }
    )
    :qual (
       {OPEXPR
       :opno 98
       :opfuncid 67
       :opresulttype 16
       :opretset false
       :args (
          {RELABELTYPE
          :arg
             {VAR
             :varno 1
             :varattno 1
             :vartype 1043
             :vartypmod 68
             :varlevelsup 0
             :varnoold 1
             :varoattno 1
             }
          :resulttype 25
          :resulttypmod -1
          :relabelformat 0
          }
          {CONST
          :consttype 25
          :constlen -1
          :constbyval false
          :constisnull false
          :constvalue 10 [ 10 0 0 0 119 105 122 97 114 100 ]
          }
       )
       }
    )
    :lefttree <>
    :righttree <>
    :initPlan <>
    :extParam (b)
    :allParam (b)
    :nParamExec 0
    :scanrelid 1
    }

2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 LOG:  duration: 0.000 ms
2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 DEBUG:  ProcessQuery
2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 LOG:  duration: 0.000 ms
2009-07-17 14:10:59 4736 970134 STATEMENT:  UPDATE tableEntityID SET
nextEntityID = $1 WHERE entityType = $2
2009-07-17 14:10:59 4736 970134 DEBUG:  CommitTransactionCommand

-----Original Message-----
From: Raji Sridar (raji)
Sent: Friday, July 17, 2009 9:48 AM
To: 'Greg Smith'
Cc: pgsql-general@postgresql.org
Subject: RE: [GENERAL] Concurrency issue under very heay loads

Thanks for everyone's inputs and here is an update on the issue:
The problem source is that autocommit is not getting unset.
The code does the following ( and source code or copyright does not
belong to Cisco):
. unsets autocommit
. starts transaction
. SQL for select for update....
. SQL for update next sequence number
. Commits transaction
The problem is in unsetting auto commit. Since this runs inside an Jboss
app server/EJB environment, this becomes a no-op and hence the ACIDity
across the select for update and update. We are using postgres 8.2.12 on
Windows with JDBC driver 8.2-506.
Thanks
Raji
-----Original Message-----
From: Greg Smith [mailto:gsmith@gregsmith.com]
Sent: Thursday, July 16, 2009 2:03 PM
To: Raji Sridar (raji)
Cc: pgsql-general@postgresql.org
Subject: Re: [GENERAL] Concurrency issue under very heay loads

On Wed, 15 Jul 2009, Raji Sridar (raji) wrote:

> When multiple clients are concurrently accessing this table and
> updating it, under extermely heavy loads in the system (stress
> testing), we find that the same order number is being generated for
multiple clients.

The only clean way to generate sequence numbers without needing to worry
about duplicates is using nextval:
http://www.postgresql.org/docs/current/static/functions-sequence.html

If you're trying to duplicate that logic in your own code, there's
probably a subtle race condition in your implementation that is causing
the bug.

If you had two calls to nextval from different clients get the same
value returned, that might be a PostgreSQL bug.  Given how much that
code gets tested, the more likely case is that there's something to
tweak in your application instead.  I would advise starting with the
presumption it's an issue in your app rather than on the server side of
things.

P.S. Posting the same question to two lists here is frowned upon;
pgsql-general is the right one for a question like this.

--
* Greg Smith gsmith@gregsmith.com http://www.gregsmith.com Baltimore, MD

Re: Help needed for reading postgres log : RE: Concurrency issue under very heay loads

From

Alvaro Herrera

Date:

21 July 2009, 01:00:41

Raji Sridar (raji) wrote:
> I would like some help in reading the postgres logs.
> Here is a snippet of the log.
> Auto commit seems to be set to false.
> But still the logs shows "CommitTransactionCommand" in debug mode.
> The same order number is given for multiple clients.
> Please see "CommitTransactionCommand" below for both "select ...for
> update" and "update..." SQLs and let me know if I am reading correctly
> that auto commit is actually effective.

CommitTransactionCommand is an internal function that has nothing to do
with a SQL-level COMMIT.  If there were a true transaction commit you'd
see a debug entry saying "CommitTransaction".

You seem to be barking up the wrong tree here.

--
Alvaro Herrera                                http://www.CommandPrompt.com/
PostgreSQL Replication, Consulting, Custom Development, 24x7 support