erpnext icon indicating copy to clipboard operation
erpnext copied to clipboard

Deadlock on submitting Sales Invoice

Open meaziz opened this issue 9 months ago • 1 comments

Information about bug

When submitting Sales invoice From a scheduled job Deadlock on the stock ledger entry timeout

Module

stock

Version

Frappe Framework: v15.22.0 (version-15) ERPNext: v15.20.3 (version-15)

Installation method

None

Relevant log output / Stack trace / Full Error Message.

Traceback (most recent call last):
  File "apps/frappe/frappe/database/database.py", line 234, in sql
    self._cursor.execute(query, values)
  File "env/lib/python3.11/site-packages/pymysql/cursors.py", line 153, in execute
    result = self._query(query)
             ^^^^^^^^^^^^^^^^^^
  File "env/lib/python3.11/site-packages/pymysql/cursors.py", line 322, in _query
    conn.query(q)
  File "env/lib/python3.11/site-packages/pymysql/connections.py", line 558, in query
    self._affected_rows = self._read_query_result(unbuffered=unbuffered)
                          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "env/lib/python3.11/site-packages/pymysql/connections.py", line 822, in _read_query_result
    result.read()
  File "env/lib/python3.11/site-packages/pymysql/connections.py", line 1200, in read
    first_packet = self.connection._read_packet()
                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "env/lib/python3.11/site-packages/pymysql/connections.py", line 772, in _read_packet
    packet.raise_for_error()
  File "env/lib/python3.11/site-packages/pymysql/protocol.py", line 221, in raise_for_error
    err.raise_mysql_exception(self._data)
  File "env/lib/python3.11/site-packages/pymysql/err.py", line 143, in raise_mysql_exception
    raise errorclass(errno, errval)
pymysql.err.OperationalError: (1205, 'Lock wait timeout exceeded; try restarting transaction')

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "apps/erpnext_snitch/erpnext_snitch/erpnext_snitch/doctype/snitch_log/snitch_log.py", line 186, in insert_doc
    set_insert(update, self._producer, self.producer)
  File "apps/event_streaming/event_streaming/event_streaming/doctype/event_producer/event_producer.py", line 313, in set_insert
    doc.insert(set_name=update.docname, set_child_names=False)
  File "apps/frappe/frappe/model/document.py", line 315, in insert
    self.run_post_save_methods()
  File "apps/frappe/frappe/model/document.py", line 1131, in run_post_save_methods
    self.run_method("on_submit")
  File "apps/frappe/frappe/model/document.py", line 962, in run_method
    out = Document.hook(fn)(self, *args, **kwargs)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "apps/frappe/frappe/model/document.py", line 1322, in composer
    return composed(self, method, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "apps/frappe/frappe/model/document.py", line 1304, in runner
    add_to_return_value(self, fn(self, *args, **kwargs))
                              ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "apps/frappe/frappe/model/document.py", line 959, in fn
    return method_object(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "apps/erpnext/erpnext/accounts/doctype/sales_invoice/sales_invoice.py", line 455, in on_submit
    self.update_stock_ledger()
  File "apps/erpnext/erpnext/controllers/selling_controller.py", line 538, in update_stock_ledger
    self.make_sl_entries(sl_entries)
  File "apps/erpnext/erpnext/controllers/stock_controller.py", line 749, in make_sl_entries
    make_sl_entries(sl_entries, allow_negative_stock, via_landed_cost_voucher)
  File "apps/erpnext/erpnext/stock/stock_ledger.py", line 95, in make_sl_entries
    sle_doc = make_entry(sle, allow_negative_stock, via_landed_cost_voucher)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "apps/erpnext/erpnext/stock/stock_ledger.py", line 223, in make_entry
    sle.submit()
  File "apps/frappe/frappe/utils/typing_validations.py", line 31, in wrapper
    return func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^
  File "apps/frappe/frappe/model/document.py", line 1048, in submit
    return self._submit()
           ^^^^^^^^^^^^^^
  File "apps/frappe/frappe/model/document.py", line 1031, in _submit
    return self.save()
           ^^^^^^^^^^^
  File "apps/frappe/frappe/model/document.py", line 337, in save
    return self._save(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "apps/frappe/frappe/model/document.py", line 359, in _save
    return self.insert()
           ^^^^^^^^^^^^^
  File "apps/frappe/frappe/model/document.py", line 315, in insert
    self.run_post_save_methods()
  File "apps/frappe/frappe/model/document.py", line 1131, in run_post_save_methods
    self.run_method("on_submit")
  File "apps/frappe/frappe/model/document.py", line 962, in run_method
    out = Document.hook(fn)(self, *args, **kwargs)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "apps/frappe/frappe/model/document.py", line 1322, in composer
    return composed(self, method, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "apps/frappe/frappe/model/document.py", line 1304, in runner
    add_to_return_value(self, fn(self, *args, **kwargs))
                              ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "apps/frappe/frappe/model/document.py", line 959, in fn
    return method_object(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "apps/erpnext/erpnext/stock/doctype/stock_ledger_entry/stock_ledger_entry.py", line 172, in on_submit
    self.set_posting_datetime()
  File "apps/erpnext/erpnext/stock/doctype/stock_ledger_entry/stock_ledger_entry.py", line 100, in set_posting_datetime
    self.db_set("posting_datetime", self.posting_datetime)
  File "apps/frappe/frappe/model/document.py", line 1226, in db_set
    frappe.db.set_value(
  File "apps/frappe/frappe/database/database.py", line 994, in set_value
    query.run(debug=debug)
  File "apps/frappe/frappe/query_builder/utils.py", line 87, in execute_query
    result = frappe.db.sql(query, params, *args, **kwargs)  # nosemgrep
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "apps/frappe/frappe/database/database.py", line 243, in sql
    raise frappe.QueryTimeoutError(e) from e
frappe.exceptions.QueryTimeoutError: (1205, 'Lock wait timeout exceeded; try restarting transaction')

meaziz avatar May 12 '24 10:05 meaziz

https://github.com/frappe/erpnext/blob/3fa8706f57509720c490d50af111d6125dda8267/erpnext/stock/doctype/stock_ledger_entry/stock_ledger_entry.py#L100

Why is it using db_set to set the posting date time instead of changing the value normally.

meaziz avatar May 12 '24 10:05 meaziz

:tada: This issue has been resolved in version 15.25.0 :tada:

The release is available on GitHub release

Your semantic-release bot :package::rocket:

frappe-pr-bot avatar May 22 '24 08:05 frappe-pr-bot