I would grateful for any hints about what could be causing this, or how to debug it :
This is from frappe-bench/logs/web.error.log :
[2020-02-11 21:42:15 -0500] [31871] [CRITICAL] WORKER TIMEOUT (pid:31894)
[2020-02-11 21:42:15 -0500] [31894] [ERROR] Error handling request /api/method/frappe.desk.page.setup_wizard.setup_wizard.setup_complete
Traceback (most recent call last):
File "/home/erpnext/frappe-bench/apps/frappe/frappe/app.py", line 60, in application
response = frappe.api.handle()
File "/home/erpnext/frappe-bench/apps/frappe/frappe/api.py", line 55, in handle
return frappe.handler.handle()
File "/home/erpnext/frappe-bench/apps/frappe/frappe/handler.py", line 22, in handle
data = execute_cmd(cmd)
File "/home/erpnext/frappe-bench/apps/frappe/frappe/handler.py", line 61, in execute_cmd
return frappe.call(method, **frappe.form_dict)
File "/home/erpnext/frappe-bench/apps/frappe/frappe/__init__.py", line 1042, in call
return fn(*args, **newargs)
File "/home/erpnext/frappe-bench/apps/frappe/frappe/desk/page/setup_wizard/setup_wizard.py", line 71, in setup_complete
task.get('fn')(task.get('args'))
File "/home/erpnext/frappe-bench/apps/erpnext/erpnext/setup/setup_wizard/setup_wizard.py", line 101, in setup_defaults
fixtures.install_defaults(frappe._dict(args))
File "/home/erpnext/frappe-bench/apps/erpnext/erpnext/setup/setup_wizard/operations/install_fixtures.py", line 442, in install_defaults
global_defaults.save()
File "/home/erpnext/frappe-bench/apps/frappe/frappe/model/document.py", line 272, in save
return self._save(*args, **kwargs)
File "/home/erpnext/frappe-bench/apps/frappe/frappe/model/document.py", line 325, in _save
self.run_post_save_methods()
File "/home/erpnext/frappe-bench/apps/frappe/frappe/model/document.py", line 919, in run_post_save_methods
self.run_method("on_update")
File "/home/erpnext/frappe-bench/apps/frappe/frappe/model/document.py", line 787, in run_method
out = Document.hook(fn)(self, *args, **kwargs)
File "/home/erpnext/frappe-bench/apps/frappe/frappe/model/document.py", line 1058, in composer
return composed(self, method, *args, **kwargs)
File "/home/erpnext/frappe-bench/apps/frappe/frappe/model/document.py", line 1041, in runner
add_to_return_value(self, fn(self, *args, **kwargs))
File "/home/erpnext/frappe-bench/apps/frappe/frappe/model/document.py", line 781, in <lambda>
fn = lambda self, *args, **kwargs: getattr(self, method)(*args, **kwargs)
File "/home/erpnext/frappe-bench/apps/erpnext/erpnext/setup/doctype/global_defaults/global_defaults.py", line 47, in on_update
self.toggle_rounded_total()
File "/home/erpnext/frappe-bench/apps/erpnext/erpnext/setup/doctype/global_defaults/global_defaults.py", line 66, in toggle_rounded_total
make_property_setter(doctype, "rounded_total", "print_hide", self.disable_rounded_total, "Check")
File "/home/erpnext/frappe-bench/apps/frappe/frappe/custom/doctype/property_setter/property_setter.py", line 90, in make_property_setter
property_setter.insert()
File "/home/erpnext/frappe-bench/apps/frappe/frappe/model/document.py", line 259, in insert
self.run_post_save_methods()
File "/home/erpnext/frappe-bench/apps/frappe/frappe/model/document.py", line 919, in run_post_save_methods
self.run_method("on_update")
File "/home/erpnext/frappe-bench/apps/frappe/frappe/model/document.py", line 787, in run_method
out = Document.hook(fn)(self, *args, **kwargs)
File "/home/erpnext/frappe-bench/apps/frappe/frappe/model/document.py", line 1058, in composer
return composed(self, method, *args, **kwargs)
File "/home/erpnext/frappe-bench/apps/frappe/frappe/model/document.py", line 1041, in runner
add_to_return_value(self, fn(self, *args, **kwargs))
File "/home/erpnext/frappe-bench/apps/frappe/frappe/model/document.py", line 781, in <lambda>
fn = lambda self, *args, **kwargs: getattr(self, method)(*args, **kwargs)
File "/home/erpnext/frappe-bench/apps/frappe/frappe/custom/doctype/property_setter/property_setter.py", line 74, in on_update
validate_fields_for_doctype(self.doc_type)
File "/home/erpnext/frappe-bench/apps/frappe/frappe/core/doctype/doctype/doctype.py", line 667, in validate_fields_for_doctype
doc = frappe.get_doc("DocType", doctype)
File "/home/erpnext/frappe-bench/apps/frappe/frappe/__init__.py", line 740, in get_doc
doc = frappe.model.document.get_doc(*args, **kwargs)
File "/home/erpnext/frappe-bench/apps/frappe/frappe/model/document.py", line 70, in get_doc
return controller(*args, **kwargs)
File "/home/erpnext/frappe-bench/apps/frappe/frappe/model/document.py", line 105, in __init__
self.load_from_db()
File "/home/erpnext/frappe-bench/apps/frappe/frappe/model/document.py", line 161, in load_from_db
"*", as_dict=True, order_by="idx asc")
File "/home/erpnext/frappe-bench/apps/frappe/frappe/database/database.py", line 445, in get_values
out = self._get_values_from_table(fields, filters, doctype, as_dict, debug, order_by, update)
File "/home/erpnext/frappe-bench/apps/frappe/frappe/database/database.py", line 592, in _get_values_from_table
as_dict=as_dict, debug=debug, update=update)
File "/home/erpnext/frappe-bench/apps/frappe/frappe/database/database.py", line 156, in sql
self._cursor.execute(query, values)
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/pymysql/cursors.py", line 170, in execute
result = self._query(query)
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/pymysql/cursors.py", line 328, in _query
conn.query(q)
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/pymysql/connections.py", line 517, in query
self._affected_rows = self._read_query_result(unbuffered=unbuffered)
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/pymysql/connections.py", line 732, in _read_query_result
result.read()
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/pymysql/connections.py", line 1082, in read
self._read_result_packet(first_packet)
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/pymysql/connections.py", line 1152, in _read_result_packet
self._read_rowdata_packet()
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/pymysql/connections.py", line 1190, in _read_rowdata_packet
rows.append(self._read_row_from_packet(packet))
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/pymysql/connections.py", line 1199, in _read_row_from_packet
data = packet.read_length_coded_string()
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/pymysql/protocol.py", line 175, in read_length_coded_string
length = self.read_length_encoded_integer()
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/pymysql/protocol.py", line 156, in read_length_encoded_integer
c = self.read_uint8()
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/pymysql/protocol.py", line 119, in read_uint8
self._position += 1
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/gunicorn/workers/base.py", line 201, in handle_abort
sys.exit(1)
SystemExit: 1
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/gunicorn/workers/sync.py", line 134, in handle
self.handle_request(listener, req, client, addr)
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/gunicorn/workers/sync.py", line 175, in handle_request
respiter = self.wsgi(environ, resp.start_response)
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/werkzeug/local.py", line 231, in application
return ClosingIterator(app(environ, start_response), self.cleanup)
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/werkzeug/wrappers/base_request.py", line 237, in application
resp = f(*args[:-2] + (request,))
File "/home/erpnext/frappe-bench/apps/frappe/frappe/app.py", line 88, in application
frappe.db.rollback()
File "/home/erpnext/frappe-bench/apps/frappe/frappe/database/database.py", line 753, in rollback
self.sql("rollback")
File "/home/erpnext/frappe-bench/apps/frappe/frappe/database/database.py", line 171, in sql
self._cursor.execute(query)
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/pymysql/cursors.py", line 170, in execute
result = self._query(query)
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/pymysql/cursors.py", line 328, in _query
conn.query(q)
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/pymysql/connections.py", line 517, in query
self._affected_rows = self._read_query_result(unbuffered=unbuffered)
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/pymysql/connections.py", line 732, in _read_query_result
result.read()
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/pymysql/connections.py", line 1075, in read
first_packet = self.connection._read_packet()
File "/home/erpnext/frappe-bench/env/lib/python3.6/site-packages/pymysql/connections.py", line 671, in _read_packet
% (packet_number, self._next_seq_id))
pymysql.err.InternalError: Packet sequence number wrong - got 186 expected 1
[2020-02-11 21:42:15 -0500] [31894] [INFO] Worker exiting (pid: 31894)
[2020-02-11 21:42:15 -0500] [31967] [INFO] Booting worker with pid: 31967
It occurs during the set up wizard when it gets to “setting default values”.
Running on Ubuntu 18.04
me@mine:~/frappe-bench$ bench version
erpnext 12.4.3
frappe 12.2.1
me@mine:~/frappe-bench$
Update 2020/02/12 08:50 EST
I took a full database backup before running the wizard and a second backup after.
Comparing the two I found that tabSingles contains all the data points entered in the wizard.
In short, this is clearly a bug in the way the setup wizard is writing the “rounded_total” setting, not something to do with MariaDb installation.
I searched the backup text and found two instances of the word rounded :
('HR Settings','disable_rounded_total','0')
('Global Defaults','disable_rounded_total','0')
I surmise that toggle_rounded_total in global_defaults.py is not finding a required dependency in the database,
Update 2020/02/12 09:30 EST
The domain settings I chose were :
- Manufacturing
- Distribution
- Retail
- Services
I tried again with only Retail and then again with only Manufacturing but that’s not going to be a work around.
What I did see is that “rounded_total” isn’t always the setting that causes the crash :
I saw …
make_property_setter(doctype, "in_words", "hidden", self.disable_in_words, "Check")
…
make_property_setter(doctype, "base_rounded_total", "hidden", self.disable_rounded_total, "Check")
… are also involved.
Update 2020/02/12 14:00 EST
Still trying to crack this.
I pulled v12.4.2, decompressed it into frappe-bench/apps and ran bench migrate.
bench version shows 12.4.2, but the error persists.
Update 2020/02/14 09:30 EST
NONE OF MY UPDATES ABOVE ARE RELEVANT!
THE REAL PROBLEM IS IN THE FIRST LINE…
[CRITICAL] WORKER TIMEOUT (pid:31894)
