i trying run our test suite using django-nose multiple processors cutdown on runtime. tests pass 1 processor, using multiple processors produces databaseerror: server closed connection unexpectedly
i found 2 tests when run multiple processors fail 90% of time. userfactory working accounts_user , customerfactory working accounts_customer. note in passing log final update accounts_customer completed before transaction closed. in failing log update accounts_customer never happens, since transaction has closed resulting in databaseerror: server closed connection unexpectedly
i'm trying decide causing problem. think problem how django or postgres handling transacations, of below.
- django 1.7
- python 2.7
- django-nose
- factory_boy
- postgres
passing postgres log:
145 (pid: 44072, tid: 0, host: ::1(58134)) log: statement: select * "accounts_customer" inner join "accounts_user" on ( "accounts_customer"."user_ptr_id" = "accounts_user"."id" ) "accounts_user"."email" = 'testjkqs.useruksx@example.com' limit 21 146 (pid: 44072, tid: 0, host: ::1(58134)) log: duration: 1.927 ms 147 (pid: 44072, tid: 0, host: ::1(58134)) log: statement: savepoint "s140735112696576_x1" 148 (pid: 44072, tid: 0, host: ::1(58134)) log: duration: 0.041 ms 149 (pid: 44072, tid: 0, host: ::1(58134)) log: statement: select (1) "a" "accounts_customer" "accounts_customer"."account_number" = '87611264' limit 1 150 (pid: 44072, tid: 0, host: ::1(58134)) log: duration: 0.187 ms 151 (pid: 44072, tid: 0, host: ::1(58134)) log: statement: insert "accounts_user" ("password", "last_login", "email", "phone", "first_name", "last_name") values ('', '2015-07-13 17:49:25.779534+00:00', 'testjkqs.useruksx@example.com', '', 'testjkqs', 'useruksx') returning "accounts_user"."id" 152 (pid: 44072, tid: 394680, host: ::1(58134)) log: duration: 0.382 ms 153 (pid: 44072, tid: 394680, host: ::1(58134)) log: statement: insert "accounts_customer" ("user_ptr_id", "advisor_id") values (1, null) 154 (pid: 44072, tid: 394680, host: ::1(58134)) log: duration: 0.199 ms 155 (pid: 44072, tid: 394680, host: ::1(58134)) log: statement: release savepoint "s140735112696576_x1" 156 (pid: 44072, tid: 394680, host: ::1(58134)) log: duration: 0.022 ms 157 (pid: 44072, tid: 394680, host: ::1(58134)) log: statement: update "accounts_user" set "password" = 'md5$lnepsrk4upi8$400710819735936b83344e0c47836251', "last_login" = '2015-07-13 17:49:25.779534+00:00', "is_superuser" = true, "email" = 'testjkqs.useruksx@example.com', "first_name" = 'testjkqs', "last_name" = 'useruksx' "accounts_user"."id" = 1 158 (pid: 44072, tid: 394680, host: ::1(58134)) log: duration: 0.363 ms ****159 (pid: 44072, tid: 394680, host: ::1(58134)) log: statement: update "accounts_customer" set "advisor_id" = null "accounts_customer"."user_ptr_id" = 1 160 (pid: 44072, tid: 394680, host: ::1(58134)) log: duration: 0.274 ms 161 (pid: 44072, tid: 0, host: ::1(58134)) log: disconnection: session time: 0:00:00.156 user=rex database=test_db host=::1 port=58134 1 (pid: 44080, tid: 0, host: ) log: connection received: host=::1 port=58135 failing postgres log:
143 (pid: 43828, tid: 0, host: ::1(58068)) log: statement: begin 145 (pid: 43828, tid: 0, host: ::1(58068)) log: statement: select * "accounts_customer" inner join "accounts_user" on ( "accounts_customer"."user_ptr_id" = "accounts_user"."id" ) "accounts_user"."email" = 'testhtij.userrxki@example.com' limit 21 146 (pid: 43828, tid: 0, host: ::1(58068)) log: duration: 1.368 ms 147 (pid: 43828, tid: 0, host: ::1(58068)) log: statement: savepoint "s140735112696576_x1" 149 (pid: 43828, tid: 0, host: ::1(58068)) log: statement: select (1) "a" "accounts_customer" "accounts_customer"."account_number" = '71017283' limit 1 150 (pid: 43828, tid: 0, host: ::1(58068)) log: duration: 0.198 ms 151 (pid: 43828, tid: 0, host: ::1(58068)) log: statement: insert "accounts_user" ("password", "last_login", "email", "phone", "first_name", "last_name",) values ('', '2015-07-13 17:48:01.528782+00:00', 'testhtij.userrxki@example.com', '', 'testhtij', 'userrxki', ) returning "accounts_user"."id" 152 (pid: 43828, tid: 394672, host: ::1(58068)) log: duration: 0.351 ms 153 (pid: 43828, tid: 394672, host: ::1(58068)) log: statement: insert "accounts_customer" ("user_ptr_id", "advisor_id") values (1, null) 154 (pid: 43828, tid: 394672, host: ::1(58068)) log: duration: 0.176 ms 155 (pid: 43828, tid: 394672, host: ::1(58068)) log: statement: release savepoint "s140735112696576_x1" 156 (pid: 43828, tid: 394672, host: ::1(58068)) log: duration: 0.033 ms 157 (pid: 43828, tid: 394672, host: ::1(58068)) log: statement: update "accounts_user" set "password" = 'md5$xn2n3dogjjhs$388f6cf97aa7ddba7c317108a7d4d511', "last_login" = '2015-07-13 17:48:01.528782+00:00', "email" = 'testhtij.userrxki@example.com', "first_name" = 'testhtij', "last_name" = 'userrxki' "accounts_user"."id" = 1 158 (pid: 43828, tid: 394672, host: ::1(58068)) log: duration: 0.291 ms 159 (pid: 43828, tid: 0, host: ::1(58068)) log: disconnection: session time: 0:00:00.142 user=rex database=test_db host=::1 port=58068 1 (pid: 43833, tid: 0, host: ) log: connection received: host=::1 port=58069 stack-trace:
====================================================================== error: test_my_test (website.apps.myapp.tests.test_file.mytestclass) ---------------------------------------------------------------------- traceback (most recent call last): file ".../tests/test_file.py", line 33, in test_my_test customer1 = accounts_factories.customerfactory() file "/users/user/pkgs/myproject/lib/python2.7/site-packages/factory/base.py", line 81, in __call__ return cls.create(**kwargs) file "/users/user/pkgs/myproject/lib/python2.7/site-packages/factory/base.py", line 559, in create return cls._generate(true, attrs) file "/users/user/pkgs/myproject/lib/python2.7/site-packages/factory/base.py", line 492, in _generate cls._after_postgeneration(obj, create, results) file "/users/user/pkgs/myproject/lib/python2.7/site-packages/factory/django.py", line 156, in _after_postgeneration obj.save() file "/users/user/pkgs/myproject/myproject/website/apps/accounts/models.py", line 198, in save return super(customer, self).save(*args, **kwargs) file "/users/user/pkgs/myproject/lib/python2.7/site-packages/django/db/models/base.py", line 589, in save force_update=force_update, update_fields=update_fields) file "/users/user/pkgs/myproject/lib/python2.7/site-packages/django/db/models/base.py", line 617, in save_base updated = self._save_table(raw, cls, force_insert, force_update, using, update_fields) file "/users/user/pkgs/myproject/lib/python2.7/site-packages/django/db/models/base.py", line 679, in _save_table forced_update) file "/users/user/pkgs/myproject/lib/python2.7/site-packages/django/db/models/base.py", line 723, in _do_update return filtered._update(values) > 0 file "/users/user/pkgs/myproject/lib/python2.7/site-packages/django/db/models/query.py", line 600, in _update return query.get_compiler(self.db).execute_sql(cursor) file "/users/user/pkgs/myproject/lib/python2.7/site-packages/django/db/models/sql/compiler.py", line 1005, in execute_sql cursor = super(sqlupdatecompiler, self).execute_sql(result_type) file "/users/user/pkgs/myproject/lib/python2.7/site-packages/django/db/models/sql/compiler.py", line 787, in execute_sql cursor.execute(sql, params) file "/users/user/pkgs/myproject/lib/python2.7/site-packages/django/db/backends/utils.py", line 65, in execute return self.cursor.execute(sql, params) file "/users/user/pkgs/myproject/lib/python2.7/site-packages/django/db/utils.py", line 94, in __exit__ six.reraise(dj_exc_type, dj_exc_value, traceback) file "/users/user/pkgs/myproject/lib/python2.7/site-packages/django/db/backends/utils.py", line 65, in execute return self.cursor.execute(sql, params) databaseerror: server closed connection unexpectedly means server terminated abnormally before or while processing request. -------------------- >> begin captured logging << -------------------- factory.generate: debug: basefactory: preparing accounts.factories.customerfactory(extra={}) factory.generate: debug: <class 'accounts.factories.customerfactory'>: setting next sequence (0) factory.containers: debug: lazystub: computing values accounts.factories.customerfactory(first_name=<ordereddeclarationwrapper <factory.fuzzy.fuzzytext object @ 0x10bf1b350>>, last_name=<ordereddeclarationwrapper <factory.fuzzy.fuzzytext object @ 0x10bf1b390>>, email=<ordereddeclarationwrapper <factory.declarations.lazyattribute object @ 0x10bf1b3d0>>) factory.generate: debug: lazyattribute: evaluating <function <lambda> @ 0x10bf1d500> on <lazystub accounts.factories.customerfactory> factory.containers: debug: lazystub: computed values, got accounts.factories.customerfactory(first_name=u'testhtij', last_name=u'userrxki', email='testhtij.userrxki@example.com') factory.generate: debug: basefactory: generating accounts.factories.customerfactory(first_name=u'testhtij', last_name=u'userrxki', email='testhtij.userrxki@example.com') factory.generate: debug: postgenerationmethodcall: calling <customer: testhtij.userrxki@example.com>.set_password('secret') --------------------- >> end captured logging << ---------------------
running django-nose on multiple processors doesn't work databases, or more exact, django transactions / database connectors.
try using package split tests: nose-picker. check last section of tutorial on improving django test performance.
also, python 3.4 includes improved version of sqlite3 supposed better @ handling concurrency. ymmv.
Comments
Post a Comment