concurrent users over xmlrpc

Bug #1013223 reported by Marcos Mendez
42
This bug affects 9 people
Affects Status Importance Assigned to Milestone
Odoo Server (MOVED TO GITHUB)
New
Undecided
Unassigned

Bug Description

Setup:

1 x ubuntu 12.04 LTS server (all updates applied)
python 2.7.3
postgresql 9.1
openerp 6.1

We wanted to run some load tests based on the simple create_partner.py example that everyone uses. When we put 100 concurrent users, logging in and creating 100 partners (one at a time) using JMeter we get some errors:

2012-06-12 19:51:42,843 2210 DEBUG ? openerp.sql_db: ConnectionPool(used=0/count=64/max=64) Put connection to 'host=localhost port=5432 user=openerp password=xxxxxxx dbname=openerp' in pool
2012-06-12 19:51:42,843 2210 ERROR ? openerp.osv.osv: Uncaught exception
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 121, in wrapper
    return f(self, dbname, *args, **kwargs)
  File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 176, in execute
    res = self.execute_cr(cr, uid, obj, method, *args, **kw)
  File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 164, in execute_cr
    return getattr(object, method)(cr, uid, *args, **kw)
  File "/usr/lib/pymodules/python2.7/openerp/osv/orm.py", line 4154, in create
    cr.execute('insert into "'+self._table+'" (id'+upd0+") values ("+str(id_new)+upd1+')', tuple(upd2))
  File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 152, in wrapper
    return f(self, *args, **kwargs)
  File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 212, in execute
    res = self._obj.execute(query, params)
TransactionRollbackError: could not serialize access due to concurrent update
CONTEXT: SQL statement "SELECT 1 FROM ONLY "public"."res_users" x WHERE "id" OPERATOR(pg_catalog.=) $1 FOR SHARE OF x"
2012-06-12 19:51:42,844 2210 ERROR ? openerp.netsvc: could not serialize access due to concurrent update

After seeing this error I decided to update the db_maxconn property to 1000, to ensure you have enough connections for the test. But I still see errors like the one below:

2012-06-12 19:57:14,811 6327 DEBUG ? openerp.sql_db: ConnectionPool(used=19/count=85/max=1000) Put connection to 'host=localhost port=5432 user=openerp password=xxxxxxx dbname=openerp' in pool
2012-06-12 19:57:14,811 6327 ERROR ? openerp.netsvc: Object Error
Object res.partner doesn't exist

2012-06-12 20:20:26,636 15119 ERROR ? openerp.sql_db: bad query: SELECT id from res_users
                          WHERE login='admin' AND password='admin'
                                AND active FOR UPDATE NOWAIT
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 212, in execute
    res = self._obj.execute(query, params)
OperationalError: could not obtain lock on row in relation "res_users"

2012-06-12 20:20:26,745 15119 ERROR ? openerp.sql_db: bad query: insert into "res_partner" (id,"customer","lang","name","color","employee","company_id","supplier","active",create_uid,create_date) values (43536,'True','en_US','Partner - 1 ',0,'False',1,'False','True',1,(now() at time zone 'UTC'))
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 212, in execute
    res = self._obj.execute(query, params)
TransactionRollbackError: could not serialize access due to concurrent update

2012-06-12 20:20:26,779 15119 ERROR ? openerp.sql_db: bad query: insert into "res_partner" (id,"customer","lang","name","color","employee","company_id","supplier","active",create_uid,create_date) values (43537,'True','en_US','Partner - 1 ',0,'False',1,'False','True',1,(now() at time zone 'UTC'))
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 212, in execute
    res = self._obj.execute(query, params)
TransactionRollbackError: could not serialize access due to concurrent update

Please find attached the JMeter file you can use to launch the test. You will need to change the IP addresses, admin account/password and database probably.

The test environment consists of one box with Ubuntu 12 LTS Server with Postgres 9.1 and OpenERP 6.1 (CRM + Employee Directory modules + demo data).
 /usr/bin/openerp-server --db_user=openerp --db_password=openerp --db_host=localhost --db_port=5432 --no-database-list --log-sq --db_maxconn=1000

Same test with gunicorn sync (no gevent). Please find attached the gunicorn configuration. Please look at this well. There could be concurrency issues with some of the underlying SQL statements.

2012-06-12 17:17:33,826 1368 ERROR openerp openerp.sql_db: bad query: insert into "res_partner" (id,"customer","lang","name","color","employee","company_id","supplier","active",create_uid,create_date) values (44646,'True','en_US','Partner - 1 ',0,'False',1,'False','True',1,(now() at time zone 'UTC'))
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 212, in execute
    res = self._obj.execute(query, params)
TransactionRollbackError: could not serialize access due to concurrent update
CONTEXT: SQL statement "SELECT 1 FROM ONLY "public"."res_users" x WHERE "id" OPERATOR(pg_catalog.=) $1 FOR SHARE OF x"

2012-06-12 17:17:33,827 1368 ERROR openerp openerp.osv.osv: Uncaught exception
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 121, in wrapper
    return f(self, dbname, *args, **kwargs)
  File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 176, in execute
    res = self.execute_cr(cr, uid, obj, method, *args, **kw)
  File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 164, in execute_cr
    return getattr(object, method)(cr, uid, *args, **kw)
  File "/usr/lib/pymodules/python2.7/openerp/osv/orm.py", line 4154, in create
    cr.execute('insert into "'+self._table+'" (id'+upd0+") values ("+str(id_new)+upd1+')', tuple(upd2))
  File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 152, in wrapper
    return f(self, *args, **kwargs)
  File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 212, in execute
    res = self._obj.execute(query, params)
TransactionRollbackError: could not serialize access due to concurrent update
CONTEXT: SQL statement "SELECT 1 FROM ONLY "public"."res_users" x WHERE "id" OPERATOR(pg_catalog.=) $1 FOR SHARE OF x"

2012-06-12 17:17:33,831 1368 ERROR openerp openerp.netsvc: could not serialize access due to concurrent update
CONTEXT: SQL statement "SELECT 1 FROM ONLY "public"."res_users" x WHERE "id" OPERATOR(pg_catalog.=) $1 FOR SHARE OF x"

2012-06-12 17:17:33,843 1369 ERROR openerp openerp.sql_db: bad query: insert into "res_partner" (id,"customer","lang","name","color","employee","company_id","supplier","active",create_uid,create_date) values (44647,'True','en_US','Partner - 1 ',0,'False',1,'False','True',1,(now() at time zone 'UTC'))
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 212, in execute
    res = self._obj.execute(query, params)
TransactionRollbackError: could not serialize access due to concurrent update
CONTEXT: SQL statement "SELECT 1 FROM ONLY "public"."res_users" x WHERE "id" OPERATOR(pg_catalog.=) $1 FOR SHARE OF x"

2012-06-12 17:17:33,847 1369 ERROR openerp openerp.osv.osv: Uncaught exception
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 121, in wrapper
    return f(self, dbname, *args, **kwargs)
  File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 176, in execute
    res = self.execute_cr(cr, uid, obj, method, *args, **kw)
  File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 164, in execute_cr
    return getattr(object, method)(cr, uid, *args, **kw)
  File "/usr/lib/pymodules/python2.7/openerp/osv/orm.py", line 4154, in create
    cr.execute('insert into "'+self._table+'" (id'+upd0+") values ("+str(id_new)+upd1+')', tuple(upd2))
  File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 152, in wrapper
    return f(self, *args, **kwargs)
  File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 212, in execute
    res = self._obj.execute(query, params)
TransactionRollbackError: could not serialize access due to concurrent u2012-06-12 17:17:33,845 1371 ERROR openerp openerp.sql_db: bad query: insert into "res_partner" (id,"customer","lang","name","color","employee","company_id","supplier","active",create_uid,create_date) values (44648,'True','en_US','Partner - 1 ',0,'False',1,'False','True',1,(now() at time zone 'UTC'))
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 212, in execute
    res = self._obj.execute(query, params)
TransactionRollbackError: could not serialize access due to concurrent update
CONTEXT: SQL statement "SELECT 1 FROM ONLY "public"."res_users" x WHERE "id" OPERATOR(pg_catalog.=) $1 FOR SHARE OF x"

2012-06-12 17:17:33,853 1371 ERROR openerp openerp.osv.osv: Uncaught exception
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 121, in wrapper
    return f(self, dbname, *args, **kwargs)
  File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 176, in execute
    res = self.execute_cr(cr, uid, obj, method, *args, **kw)
  File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 164, in execute_cr
    return getattr(object, method)(cr, uid, *args, **kw)
  File "/usr/lib/pymodules/python2.7/openerp/osv/orm.py", line 4154, in create
    cr.execute('insert into "'+self._table+'" (id'+upd0+") values ("+str(id_new)+upd1+')', tuple(upd2))
  File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 152, in wrapper
    return f(self, *args, **kwargs)
  File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 212, in execute
    res = self._obj.execute(query, params)
TransactionRollbackError: could not serialize access due to concurrent update
CONTEXT: SQL statement "SELECT 1 FROM ONLY "public"."res_users" x WHERE "id" OPERATOR(pg_catalog.=) $1 FOR SHARE OF x"

2012-06-12 17:17:33,854 1369 ERROR openerp openerp.netsvc: could not serialize access due to concurrent update
CONTEXT: SQL statement "SELECT 1 FROM ONLY "public"."res_users" x WHERE "id" OPERATOR(pg_catalog.=) $1 FOR SHARE OF x"

pdate
CONTEXT: SQL statement "SELECT 1 FROM ONLY "public"."res_users" x WHERE "id" OPERATOR(pg_catalog.=) $1 FOR SHARE OF x"

2012-06-12 17:17:33,855 1371 ERROR openerp openerp.netsvc: could not serialize access due to concurrent update
CONTEXT: SQL statement "SELECT 1 FROM ONLY "public"."res_users" x WHERE "id" OPERATOR(pg_catalog.=) $1 FOR SHARE OF x"

2012-06-12 17:17:33,895 1370 ERROR openerp openerp.sql_db: bad query: SELECT id from res_users
                          WHERE login='admin' AND password='admin'
                                AND active FOR UPDATE NOWAIT
Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 212, in execute
    res = self._obj.execute(query, params)
OperationalError: could not obtain lock on row in relation "res_users"

Revision history for this message
Marcos Mendez (marcos-hr7) wrote :
Revision history for this message
Marcos Mendez (marcos-hr7) wrote :

my original test was of 100 users (threads) and 100 partners, one at a time. however, this can be brought down to 6 users (threads) and 1 partner. no loops needed. so 6 people creating 1 partner at the same time.

Revision history for this message
Marcos Mendez (marcos-hr7) wrote :

I don't believe this is a duplicate bug. the res_users lock error, is ignored for the most part, even though it is logged. if you look at res_users.py, there is a workaround for the login portion there.

the problem is that the correct number of partners is not created. for example use the JMeter test and run 10 users (threads) with one look - 10 users creating 1 partner all at the same time. In my test environment only 8 partners are created.

An example error is :

<?xml version='1.0'?>
<methodResponse>
<fault>
<value><struct>
<member>
<name>faultCode</name>
<value><string>could not serialize access due to concurrent update
CONTEXT: SQL statement "SELECT 1 FROM ONLY "public"."res_users" x WHERE "id" OPERATOR(pg_catalog.=) $1 FOR SHARE OF x"
</string></value>
</member>
<member>
<name>faultString</name>
<value><string>Traceback (most recent call last):
  File "/usr/lib/pymodules/python2.7/openerp/wsgi/core.py", line 79, in xmlrpc_return
    result = openerp.netsvc.dispatch_rpc(service, method, params)
  File "/usr/lib/pymodules/python2.7/openerp/netsvc.py", line 360, in dispatch_rpc
    result = ExportService.getService(service_name).dispatch(method, params)
  File "/usr/lib/pymodules/python2.7/openerp/service/web_services.py", line 572, in dispatch
    res = fn(db, uid, *params)
  File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 121, in wrapper
    return f(self, dbname, *args, **kwargs)
  File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 176, in execute
    res = self.execute_cr(cr, uid, obj, method, *args, **kw)
  File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 164, in execute_cr
    return getattr(object, method)(cr, uid, *args, **kw)
  File "/usr/lib/pymodules/python2.7/openerp/osv/orm.py", line 4154, in create
    cr.execute('insert into "'+self._table+'" (id'+upd0+") values ("+str(id_new)+upd1+')', tuple(upd2))
  File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 152, in wrapper
    return f(self, *args, **kwargs)
  File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 212, in execute
    res = self._obj.execute(query, params)
TransactionRollbackError: could not serialize access due to concurrent update
CONTEXT: SQL statement "SELECT 1 FROM ONLY "public"."res_users" x WHERE "id" OPERATOR(pg_catalog.=) $1 FOR SHARE OF x"

</string></value>
</member>
</struct></value>
</fault>
</methodResponse>

Revision history for this message
Marcos Mendez (marcos-hr7) wrote : Re: [Bug 1013223] Re: concurrent users over xmlrpc
Download full text (11.9 KiB)

Great. Any way to push this to higher priority than low? This is a serious issue for us.

On Jun 18, 2012, at 9:03 AM, Amit Parik (OpenERP) wrote:

> *** This bug is a duplicate of bug 992525 ***
> https://bugs.launchpad.net/bugs/992525
>
> ** This bug is no longer a duplicate of bug 949907
> could not obtain lock on row in relation "res_users"
>
> ** This bug has been marked a duplicate of bug 992525
> TransactionRollbackError due to concurrent update could be better handled
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1013223
>
> Title:
> concurrent users over xmlrpc
>
> Status in OpenERP Server:
> New
>
> Bug description:
> Setup:
>
> 1 x ubuntu 12.04 LTS server (all updates applied)
> python 2.7.3
> postgresql 9.1
> openerp 6.1
>
> We wanted to run some load tests based on the simple create_partner.py
> example that everyone uses. When we put 100 concurrent users, logging
> in and creating 100 partners (one at a time) using JMeter we get some
> errors:
>
> 2012-06-12 19:51:42,843 2210 DEBUG ? openerp.sql_db: ConnectionPool(used=0/count=64/max=64) Put connection to 'host=localhost port=5432 user=openerp password=xxxxxxx dbname=openerp' in pool
> 2012-06-12 19:51:42,843 2210 ERROR ? openerp.osv.osv: Uncaught exception
> Traceback (most recent call last):
> File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 121, in wrapper
> return f(self, dbname, *args, **kwargs)
> File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 176, in execute
> res = self.execute_cr(cr, uid, obj, method, *args, **kw)
> File "/usr/lib/pymodules/python2.7/openerp/osv/osv.py", line 164, in execute_cr
> return getattr(object, method)(cr, uid, *args, **kw)
> File "/usr/lib/pymodules/python2.7/openerp/osv/orm.py", line 4154, in create
> cr.execute('insert into "'+self._table+'" (id'+upd0+") values ("+str(id_new)+upd1+')', tuple(upd2))
> File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 152, in wrapper
> return f(self, *args, **kwargs)
> File "/usr/lib/pymodules/python2.7/openerp/sql_db.py", line 212, in execute
> res = self._obj.execute(query, params)
> TransactionRollbackError: could not serialize access due to concurrent update
> CONTEXT: SQL statement "SELECT 1 FROM ONLY "public"."res_users" x WHERE "id" OPERATOR(pg_catalog.=) $1 FOR SHARE OF x"
> 2012-06-12 19:51:42,844 2210 ERROR ? openerp.netsvc: could not serialize access due to concurrent update
>
> After seeing this error I decided to update the db_maxconn property to
> 1000, to ensure you have enough connections for the test. But I still
> see errors like the one below:
>
> 2012-06-12 19:57:14,811 6327 DEBUG ? openerp.sql_db: ConnectionPool(used=19/count=85/max=1000) Put connection to 'host=localhost port=5432 user=openerp password=xxxxxxx dbname=openerp' in pool
> 2012-06-12 19:57:14,811 6327 ERROR ? openerp.netsvc: Object Error
> Object res.partner doesn't exist
>
> 2012-06-12 20:20:26,636 15119 ERROR ? openerp.sql_db: bad query: SELECT id from res_users
> WHERE login='admin' AND passwo...

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

Other bug subscribers

Remote bug watches

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