winston6071
commented
7 years ago 2017-05-09 08:27:54,740 23695 WARNING care openerp.addons.website_sale_donate.controllers.main: website_sale_donate: opc_payment(): call super payment() HINT: payment() is derived in website_delivery and calls _check_carrier_quotation()
2017-05-09 08:27:54,743 23695 WARNING care openerp.addons.website_sale_donate.models.website_sale_donate: website_sale_donate: _check_carrier_quotation(): call super website_sale_delivery _check_carrier_quotation() HINT: force_carrier_id = None, order = sale.order(38155,)
2017-05-09 08:27:54,773 23695 WARNING care openerp.addons.website_sale_donate.models.website_sale_donate: website_sale_donate: _check_carrier_quotation(): AFTER call of super website_sale_delivery _check_carrier_quotation(): carrier_id: True
2017-05-09 08:27:54,827 23695 WARNING care openerp.addons.website_sale_donate.controllers.main: website_sale_donate: opc_payment(): call super payment() HINT: payment() is derived in website_delivery and calls _check_carrier_quotation()
2017-05-09 08:27:54,829 23695 WARNING care openerp.addons.website_sale_donate.models.website_sale_donate: website_sale_donate: _check_carrier_quotation(): call super website_sale_delivery _check_carrier_quotation() HINT: force_carrier_id = None, order = sale.order(38155,)
2017-05-09 08:27:55,548 23695 ERROR care openerp.sql_db: bad query: UPDATE "sale_order" SET "carrier_id"=NULL,"write_uid"=1,"write_date"=(now() at time zone 'UTC') WHERE id IN (38155)
Traceback (most recent call last):
File "/opt/online/online_o8r57/odoo/openerp/sql_db.py", line 234, in execute
res = self._obj.execute(query, params)
TransactionRollbackError: could not serialize access due to concurrent update
2017-05-09 08:27:55,549 23695 INFO care openerp.service.model: SERIALIZATION_FAILURE, retry 1/5 in 0.6662 sec...
2017-05-09 08:27:55,549 23695 INFO care werkzeug: 192.168.37.113 - - [09/May/2017 08:27:55] "GET /shop/product/kindern-helfen-12?category=2&aswidget=true%3E HTTP/1.0" 200 -
2017-05-09 08:27:56,322 23695 WARNING care openerp.addons.website_sale_donate.controllers.main: website_sale_donate: opc_payment(): call super payment() HINT: payment() is derived in website_delivery and calls _check_carrier_quotation()
2017-05-09 08:27:56,323 23695 WARNING care openerp.addons.website_sale_donate.models.website_sale_donate: website_sale_donate: _check_carrier_quotation(): call super website_sale_delivery _check_carrier_quotation() HINT: force_carrier_id = None, order = sale.order(38155,)
2017-05-09 08:27:56,336 23695 WARNING care openerp.addons.website_sale_donate.models.website_sale_donate: website_sale_donate: _check_carrier_quotation(): AFTER call of super website_sale_delivery _check_carrier_quotation(): carrier_id: True
2017-05-09 08:27:57,111 23695 INFO care werkzeug: 192.168.37.113 - - [09/May/2017 08:27:57] "GET /shop/product/kindern-helfen-12?category=2&aswidget=true%3E& HTTP/1.0" 200 -
2017-05-09 08:28:08,981 23695 INFO care werkzeug: 192.168.37.113 - - [09/May/2017 08:28:08] "POST /longpolling/poll HTTP/1.0" 200 -
2017-05-09 08:28:11,304 23695 INFO care werkzeug: 192.168.37.113 - - [09/May/2017 08:28:11] "POST /calendar/notify HTTP/1.0" 200 -
2017-05-09 08:28:17,630 23695 INFO care werkzeug: 192.168.37.113 - - [09/May/2017 08:28:17] "POST /longpolling/poll HTTP/1.0" 200 -
--
2017-05-09 08:54:27,138 23695 WARNING care openerp.addons.website_sale_donate.controllers.main: website_sale_donate: opc_payment(): call super payment() HINT: payment() is derived in website_delivery and calls _check_carrier_quotation()
2017-05-09 08:54:27,139 23695 WARNING care openerp.addons.website_sale_donate.models.website_sale_donate: website_sale_donate: _check_carrier_quotation(): call super website_sale_delivery _check_carrier_quotation() HINT: force_carrier_id = None, order = sale.order(38155,)
2017-05-09 08:54:27,169 23695 WARNING care openerp.addons.website_sale_donate.models.website_sale_donate: website_sale_donate: _check_carrier_quotation(): AFTER call of super website_sale_delivery _check_carrier_quotation(): carrier_id: True
2017-05-09 08:54:27,204 23695 WARNING care openerp.addons.website_sale_donate.controllers.main: website_sale_donate: opc_payment(): call super payment() HINT: payment() is derived in website_delivery and calls _check_carrier_quotation()
2017-05-09 08:54:27,205 23695 WARNING care openerp.addons.website_sale_donate.models.website_sale_donate: website_sale_donate: _check_carrier_quotation(): call super website_sale_delivery _check_carrier_quotation() HINT: force_carrier_id = None, order = sale.order(38155,)
2017-05-09 08:54:27,563 23695 INFO care werkzeug: 192.168.37.113 - - [09/May/2017 08:54:27] "POST /calendar/notify HTTP/1.0" 200 -
2017-05-09 08:54:27,933 23695 ERROR care openerp.sql_db: bad query: UPDATE "sale_order" SET "carrier_id"=NULL,"write_uid"=1,"write_date"=(now() at time zone 'UTC') WHERE id IN (38155)
Traceback (most recent call last):
File "/opt/online/online_o8r57/odoo/openerp/sql_db.py", line 234, in execute
res = self._obj.execute(query, params)
TransactionRollbackError: could not serialize access due to concurrent update
2017-05-09 08:54:27,933 23695 INFO care openerp.service.model: SERIALIZATION_FAILURE, retry 1/5 in 0.9913 sec...
2017-05-09 08:54:27,934 23695 INFO care werkzeug: 192.168.37.113 - - [09/May/2017 08:54:27] "GET /shop/category/schenkenmitsinn-7?aswidget=true HTTP/1.0" 200 -
2017-05-09 08:54:28,649 23695 INFO care werkzeug: 192.168.37.113 - - [09/May/2017 08:54:28] "POST /longpolling/poll HTTP/1.0" 200 -
2017-05-09 08:54:28,987 23695 WARNING care openerp.addons.website_sale_donate.controllers.main: website_sale_donate: opc_payment(): call super payment() HINT: payment() is derived in website_delivery and calls _check_carrier_quotation()
2017-05-09 08:54:28,988 23695 WARNING care openerp.addons.website_sale_donate.models.website_sale_donate: website_sale_donate: _check_carrier_quotation(): call super website_sale_delivery _check_carrier_quotation() HINT: force_carrier_id = None, order = sale.order(38155,)
2017-05-09 08:54:28,999 23695 WARNING care openerp.addons.website_sale_donate.models.website_sale_donate: website_sale_donate: _check_carrier_quotation(): AFTER call of super website_sale_delivery _check_carrier_quotation(): carrier_id: True
2017-05-09 08:54:29,723 23695 INFO care werkzeug: 192.168.37.113 - - [09/May/2017 08:54:29] "GET /shop/category/schenkenmitsinn-7?aswidget=true& HTTP/1.0" 200 -
2017-05-09 08:54:29,776 23695 INFO care werkzeug: 192.168.37.113 - - [09/May/2017 08:54:29] "GET /web/css/web.assets_common/2a0d936 HTTP/1.0" 200 -
2017-05-09 08:54:29,816 23695 INFO care werkzeug: 192.168.37.113 - - [09/May/2017 08:54:29] "GET /web/css/website.assets_frontend/1599457 HTTP/1.0" 200 -
michaelkarrer81
Fehlerbeschreibung
In einigen Fällen kommt es bei Webspenden zu Datenverlusten da es zu einem Rollback der Transaktion beim Schreiben einer Sales Order kommt.
Fehlerursache
Es scheint als würde manchmal innerhalb der Transaktion bei der die Daten des Spenders geschrieben werden sollten ein weiterer Schreibvorgang in der selben Transaktion ausgelöst der versucht
"carrier_id"=NULLzu schreiben.Dies geschieht meist bei One-Page-Checkout Seiten wenn der Button "Jetzt Spenden" gedrückt wird.
Reproduktion des Fehlers
Bisher ist keine wiederholbare Reproduktion des Fehlers gelungen da er nur sporadisch auftritt.
Im Log scheint der Hergang folgendermaßen zu sein:
Zusätzlich Informationen
Quelle der Fehlermeldung
SO36497mit der ID 36333Info von Joe
Elisabeth Reiter hat am 18.04.2017 eine Spende gemacht SO36497 --> SO_ID --> 36333 --> siehe log vom 18-04 --> aus meiner Sicht NICHT sauber abgeschlossen da ich auch keine Transaction am 18.04. habe am Fr. dem 05.05.2017 wurde wieder von Elisabeth Reiter eine Spende gemacht, diese Spende ist offensichtlich nicht mit dem Datum 05.05.2017 unter Aufträge eingeschrieben.... aber es konnte verifiziert werden das diese Spenden vom 05.05.2017 beim Datensatz vom 18.04.2017 weiter verarbeitet wurde.....hierzu gab es dann auch am 05.05.2017 einen Transaction ID
Gleichzeitig aufgefallen im LOG unten ein Transactionrollback am 18.04.2017 und das definitiv aufgrund der SalesOrder ID --> nachvollziehbar ist das es die selbe Sales Order ist wie die am 05.05.2017 siehe log vom 05.05.02017 und SaleOrder_ID
Weitere Checks es gibt eine Elisabeth Reiter die einen FS TOKEN hat ... die verwendete Person bei der Spende am 05.05.2017 in der Sales Order ist aber NICHT die Elisabeth Reiter Person mit dem FS Token.
Checks im Syncer zeigen das am 18.04. ein Insert und Updates passiert sind. aber auch keine Transaction dazu am 05.05.2017 wurde aber diese gleiche Order_id 36333 im syncer wieder geinserted und geupdated ...
Es scheint als würde auf der FSOnline Seite eine alte Order ID nochmals verwendet worden sein. selbes Verhalten konnte mit der Order_ID 37891 Sales Order SO38056 festgestellt werden... am Fr. Vorige Woche testspende mit Georg Duit Sales Order heute erneut erst abgeschlossen siehe Log vom 05.05.2017:07:01care.log.1 und am 08.05.2017 care.log --> abgeschlossene Sales Order mit Danke Seite usw....
----- Weitere Analyse notwendig