perf: new column Posting Datetime in SLE to optimize stock ledger related queries #39800

rohitwaghchaure · 2024-02-07T16:27:52Z

Before Changes

577.667 Seconds (9.62 mins)

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    248/1    0.011    0.000  577.667  577.667 {built-in method builtins.exec}
        1    0.003    0.003  577.662  577.662 <string>:1(<module>)
        1    0.001    0.001  577.659  577.659 stock_entry.py:166(submit)
     54/1    0.008    0.000  577.636  577.636 document.py:985(_submit)
     55/1    0.001    0.000  577.636  577.636 document.py:307(save)
     55/1    0.002    0.000  577.636  577.636 document.py:311(_save)
   550/15    0.013    0.000  576.870   38.458 document.py:907(run_method)
   550/15    0.007    0.000  576.819   38.455 document.py:1271(composer)
   550/15    0.022    0.000  576.801   38.453 document.py:1262(runner)
   550/15    0.002    0.000  576.790   38.453 document.py:910(fn)
     4016    0.052    0.000  570.633    0.142 database.py:147(sql)
     4016    0.013    0.000  570.266    0.142 cursors.py:138(execute)
     4016    0.017    0.000  569.922    0.142 cursors.py:322(_query)
     4016    0.020    0.000  569.886    0.142 connections.py:543(query)
     4016    0.013    0.000  569.651    0.142 connections.py:767(_read_query_result)
     4016    0.028    0.000  569.631    0.142 connections.py:1155(read)
    31658    0.191    0.000  568.710    0.018 connections.py:687(_read_packet)
    63316    0.089    0.000  567.997    0.009 connections.py:732(_read_bytes)
     5279  567.884    0.108  567.884    0.108 {method 'recv_into' of '_socket.socket' objects}
    63567    0.085    0.000  567.875    0.009 {method 'read' of '_io.BufferedReader' objects}
     4118    0.026    0.000  567.791    0.138 socket.py:691(readinto)
     56/1    0.005    0.000  528.317  528.317 document.py:1083(run_post_save_methods)
        1    0.035    0.035  528.121  528.121 stock_entry.py:201(on_submit)
        1    0.008    0.008  510.838  510.838 stock_entry.py:1201(update_stock_ledger)
        1    0.001    0.001  510.629  510.629 stock_controller.py:508(make_sl_entries)
        1    0.019    0.019  510.628  510.628 stock_ledger.py:34(make_sl_entries)
       50    0.005    0.000  508.122   10.162 stock_ledger.py:96(repost_current_voucher)
       50    0.006    0.000  378.962    7.579 stock_ledger.py:366(__init__)
       50    0.019    0.000  372.795    7.456 stock_ledger.py:405(initialize_previous_data)
       50    0.005    0.000  372.764    7.455 stock_ledger.py:1177(get_previous_sle_of_current_voucher)
      852    0.007    0.000  129.998    0.153 utils.py:84(execute_query)
       50    0.004    0.000  129.155    2.583 stock_ledger.py:1458(update_qty_in_future_sle)
       50    0.005    0.000   66.291    1.326 stock_ledger.py:1524(get_next_stock_reco)
       50    0.003    0.000   62.684    1.254 stock_ledger.py:1583(validate_negative_qty_in_future_sle)
       50    0.005    0.000   62.677    1.254 stock_ledger.py:1639(get_future_sle_with_negative_qty)
       56    0.001    0.000   49.188    0.878 document.py:1035(run_before_save_methods)
        1    0.000    0.000   48.667   48.667 stock_entry.py:113(validate)
        1    0.000    0.000   48.437   48.437 stock_entry.py:720(calculate_rate_and_amount)
        1    0.000    0.000   48.432   48.432 stock_entry.py:728(set_basic_rate)
        1    0.001    0.001   48.432   48.432 stock_entry.py:787(set_rate_for_outgoing_items)
       50    0.001    0.000   48.424    0.968 utils.py:261(get_incoming_rate)
       50    0.000    0.000   48.312    0.966 stock_ledger.py:1218(get_previous_sle)
       50    0.001    0.000   48.312    0.966 stock_ledger.py:1239(get_stock_ledger_entries)
        1    0.000    0.000   15.432   15.432 stock_entry.py:329(update_cost_in_project)
       50    0.018    0.000    6.026    0.121 stock_ledger.py:441(build)
       50    0.006    0.000    5.624    0.112 stock_ledger.py:465(process_sle_against_current_timestamp)
     1275    0.086    0.000    4.924    0.004 stock_ledger.py:558(process_sle)
1413/1397    0.007    0.000    3.812    0.003 __init__.py:1921(get_all)
1413/1397    0.026    0.000    3.806    0.003 __init__.py:1895(get_list)
1413/1397    0.039    0.000    3.763    0.003 db_query.py:82(execute)
1413/1397    0.022    0.000    3.528    0.003 db_query.py:212(build_and_run)
     1325    0.020    0.000    3.082    0.002 inventory_dimension.py:334(get_inventory_dimensions)
1413/1397    0.041    0.000    2.439    0.002 db_query.py:247(prepare_args)
1413/1397    0.009    0.000    2.203    0.002 db_query.py:570(build_conditions)
2826/2794    0.012    0.000    2.193    0.001 db_query.py:582(build_filter_conditions)
1554/1526    0.066    0.000    2.181    0.001 db_query.py:700(prepare_filter_condition)
     2065    0.010    0.000    1.798    0.001 database.py:538(get_values)
       54    0.012    0.000    1.729    0.032 document.py:220(insert)
     2483    0.010    0.000    1.630    0.001 connections.py:1237(_read_result_packet)
1554/1526    0.066    0.000    1.594    0.001 data.py:1775(get_filter)
      528    0.004    0.000    1.554    0.003 database.py:806(_get_values_from_table)
       53    0.001    0.000    1.526    0.029 document.py:1007(submit)
     2914    0.043    0.000    1.511    0.001 __init__.py:45(format)
     2015    0.006    0.000    1.486    0.001 database.py:468(get_value)
28752/17321    0.036    0.000    1.451    0.000 {method 'join' of 'str' objects}
     1327    0.027    0.000    1.441    0.001 base_document.py:554(db_update)
     5828    0.035    0.000    1.361    0.000 filter_stack.py:25(run)
       50    0.001    0.000    1.302    0.026 stock_ledger.py:197(make_entry)
     1554    0.049    0.000    1.091    0.001 data.py:1883(sanitize_column)
        1    0.003    0.003    1.015    1.015 stock_controller.py:55(make_gl_entries)
     1444    0.013    0.000    0.985    0.001 __init__.py:1187(get_doc)
     1444    0.033    0.000    0.965    0.001 document.py:26(get_doc)
1830/1489    0.022    0.000    0.959    0.001 document.py:83(__init__)

After Changes
11.514 Seconds (0.19 mins)

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    248/1    0.001    0.000   11.514   11.514 {built-in method builtins.exec}
        1    0.000    0.000   11.514   11.514 <string>:1(<module>)
        1    0.000    0.000   11.514   11.514 stock_entry.py:167(submit)
     54/1    0.000    0.000   11.482   11.482 document.py:985(_submit)
     55/1    0.000    0.000   11.482   11.482 document.py:307(save)
     55/1    0.000    0.000   11.482   11.482 document.py:311(_save)
   650/15    0.004    0.000   10.854    0.724 document.py:907(run_method)
   650/15    0.004    0.000   10.795    0.720 document.py:1271(composer)
   650/15    0.002    0.000   10.773    0.718 document.py:1262(runner)
   650/15    0.001    0.000   10.760    0.717 document.py:910(fn)
     56/1    0.001    0.000    9.683    9.683 document.py:1083(run_post_save_methods)
        1    0.000    0.000    9.622    9.622 stock_entry.py:202(on_submit)
     4191    0.033    0.000    7.895    0.002 database.py:147(sql)
     4191    0.007    0.000    7.675    0.002 cursors.py:138(execute)
     4191    0.009    0.000    7.458    0.002 cursors.py:322(_query)
     4191    0.012    0.000    7.440    0.002 connections.py:543(query)
     4191    0.011    0.000    7.297    0.002 connections.py:767(_read_query_result)
     4191    0.011    0.000    7.279    0.002 connections.py:1155(read)
    37571    0.107    0.000    6.646    0.000 connections.py:687(_read_packet)
    75142    0.075    0.000    6.088    0.000 connections.py:732(_read_bytes)
    75393    0.039    0.000    5.979    0.000 {method 'read' of '_io.BufferedReader' objects}
     5943    5.956    0.001    5.956    0.001 {method 'recv_into' of '_socket.socket' objects}
     4296    0.009    0.000    5.940    0.001 socket.py:691(readinto)
        1    0.000    0.000    5.566    5.566 stock_entry.py:1202(update_stock_ledger)
        1    0.000    0.000    5.439    5.439 stock_controller.py:508(make_sl_entries)
        1    0.001    0.001    5.439    5.439 stock_ledger.py:47(make_sl_entries)
       50    0.001    0.000    3.849    0.077 stock_ledger.py:109(repost_current_voucher)
       50    0.001    0.000    3.588    0.072 stock_ledger.py:379(__init__)
        1    0.000    0.000    3.369    3.369 stock_entry.py:330(update_cost_in_project)
       50    0.001    0.000    3.336    0.067 stock_ledger.py:454(build)
       50    0.001    0.000    3.145    0.063 stock_ledger.py:478(process_sle_against_current_timestamp)
     1275    0.036    0.000    2.759    0.002 stock_ledger.py:572(process_sle)
1422/1410    0.003    0.000    2.037    0.001 __init__.py:1921(get_all)
1422/1410    0.009    0.000    2.034    0.001 __init__.py:1895(get_list)
1422/1410    0.016    0.000    2.015    0.001 db_query.py:82(execute)
1422/1410    0.014    0.000    1.878    0.001 db_query.py:212(build_and_run)
     1325    0.008    0.000    1.683    0.001 inventory_dimension.py:334(get_inventory_dimensions)
     2182    0.006    0.000    1.569    0.001 database.py:538(get_values)
       56    0.000    0.000    1.428    0.026 document.py:1035(run_before_save_methods)
     2113    0.004    0.000    1.347    0.001 database.py:468(get_value)
      595    0.003    0.000    1.320    0.002 database.py:806(_get_values_from_table)
     2608    0.006    0.000    1.237    0.000 connections.py:1237(_read_result_packet)
1422/1410    0.028    0.000    1.189    0.001 db_query.py:247(prepare_args)
      968    0.006    0.000    1.157    0.001 utils.py:84(execute_query)
        1    0.000    0.000    1.136    1.136 stock_entry.py:113(validate)
1422/1410    0.004    0.000    1.035    0.001 db_query.py:570(build_conditions)
2844/2820    0.005    0.000    1.031    0.000 db_query.py:582(build_filter_conditions)
1569/1548    0.040    0.000    1.026    0.001 db_query.py:700(prepare_filter_condition)
29063/17388    0.027    0.000    0.945    0.000 {method 'join' of 'str' objects}
     2992    0.011    0.000    0.945    0.000 __init__.py:45(format)
       54    0.002    0.000    0.937    0.017 document.py:220(insert)
     1327    0.014    0.000    0.898    0.001 base_document.py:554(db_update)
     5984    0.016    0.000    0.883    0.000 filter_stack.py:25(run)
       53    0.000    0.000    0.827    0.016 document.py:1007(submit)
1938/1568    0.009    0.000    0.749    0.000 document.py:83(__init__)
1569/1548    0.031    0.000    0.732    0.000 data.py:1775(get_filter)
     2608    0.071    0.000    0.729    0.000 connections.py:1302(_get_descriptions)
      856    0.004    0.000    0.717    0.001 utils.py:58(get_query)
      856    0.010    0.000    0.713    0.001 query.py:34(get_query)
       50    0.000    0.000    0.702    0.014 stock_ledger.py:210(make_entry)
      100    0.000    0.000    0.688    0.007 stock_ledger.py:1234(get_previous_sle)
      100    0.001    0.000    0.688    0.007 stock_ledger.py:1255(get_stock_ledger_entries)
     1491    0.005    0.000    0.681    0.000 __init__.py:1187(get_doc)
     1491    0.014    0.000    0.663    0.000 document.py:26(get_doc)
      165    0.002    0.000    0.626    0.004 document.py:130(load_from_db)
     2992    0.037    0.000    0.593    0.000 grouping.py:397(group)
     1569    0.015    0.000    0.546    0.000 data.py:1883(sanitize_column)
      704    0.004    0.000    0.518    0.001 query.py:99(apply_fields)
      102    0.000    0.000    0.512    0.005 stock_controller.py:913(future_sle_exists)
     2608    0.011    0.000    0.498    0.000 connections.py:1270(_read_rowdata_packet)
      704    0.004    0.000    0.465    0.001 query.py:302(parse_fields)
        1    0.001    0.001    0.452    0.452 stock_entry.py:667(set_actual_qty)
      704    0.001    0.000    0.441    0.001 query.py:272(sanitize_fields)
11118/10886    0.015    0.000    0.439    0.000 __init__.py:1228(get_meta)
     1423    0.004    0.000    0.438    0.000 query.py:273(_sanitize_field)

Fixed #38364

erpnext/patches/v14_0/update_posting_datetime.py

erpnext/stock/doctype/stock_ledger_entry/stock_ledger_entry.py

ankush · 2024-02-09T17:37:57Z

@rohitwaghchaure why closed? TZ issues?

Those should be fixable. I can help if required.

rohitwaghchaure · 2024-02-10T15:07:11Z

@ankush Will reopen after fixing TZ issues and test cases

…ated queries

erpnext/patches/v14_0/update_posting_datetime_and_dropped_indexes.py

erpnext/patches.txt

ankush · 2024-02-15T04:39:54Z

erpnext/stock/stock_ledger.py

 			from
 				`tabStock Ledger Entry`
 			where
 				item_code = %(item_code)s
 				and warehouse = %(warehouse)s
 				and is_cancelled = 0
 				and (
-					posting_date = %(posting_date)s and
-					time_format(posting_time, %(time_format)s) = time_format(%(posting_time)s, %(time_format)s)
+					posting_datetime = %(posting_datetime)s


This isn't same as before. The previous code was stripping ~~milliseconds~~ microseconds. We can convert this into two different conditions

posting_datetime >= time.replace(microseconds=0) AND posting_date < time.replace(microseconds=0) + timedelta(seconds=1)

I have already tried this but the test case test_timestamp_clash is breaking because of this

ankush · 2024-02-15T04:40:46Z

erpnext/stock/stock_ledger.py

+
+	if operator == "<=":
+		# Add 1 second to handle millisecond for less than and equal to condition
+		args["posting_datetime"] = add_to_date(args["posting_datetime"], seconds=1)


This will not work as args is a dictionary you'll end up overriding the previous conditions?

Or is this supposed to work because of order by and limit?

Yes it's working because of order by and limit, but maybe need to think of ms case.

…ated queries (backport #39800) (#40004) * perf: new column posting datetime in SLE to optimize stock ledger related queries (cherry picked from commit d80ca52) # Conflicts: # erpnext/stock/doctype/purchase_receipt/test_purchase_receipt.py * test: test cases to test clash timestamp entries (cherry picked from commit f04676a) * chore: remove microsecond from posting_datetime (cherry picked from commit a73ba2c) * chore: fix conflicts --------- Co-authored-by: Rohit Waghchaure <rohitw1991@gmail.com>

# [15.15.0](v15.14.7...v15.15.0) (2024-02-28) ### Bug Fixes * add flags for repost to ensure correct accounting from India Compliance App ([7d14ecf](7d14ecf)) * amount label according to party type ([d541ba3](d541ba3)) * Cannot read properties of undefined (backport [#40081](#40081)) ([#40083](#40083)) ([53d943e](53d943e)) * capacity planning issue in the job card (backport [#40092](#40092)) ([#40101](#40101)) ([27703b5](27703b5)) * change label name ([824df72](824df72)) * check for pricing rules on item ([32d9642](32d9642)) * check_credit_limit on_update_after_submit of Sales Order ([83d7111](83d7111)) * communication_date in party dashboards (backport [#40005](#40005)) ([#40021](#40021)) ([4269ef8](4269ef8)) * Completed Work Orders report not working ([ca03e9c](ca03e9c)) * Cr/Dr notes with POS Payments ([2e07b03](2e07b03)) * currency symbol in landed cost voucher and material request (backport [#40138](#40138)) ([#40141](#40141)) ([57bb031](57bb031)) * Data too long for column 'serial_no' at row 1 (backport [#40098](#40098)) ([#40139](#40139)) ([9d19ec4](9d19ec4)) * default taxable value for item not found in item list ([7e43f6b](7e43f6b)) * delete PLE containing invoice in against ([190bd45](190bd45)) * do not make MR against raw materials of available sub assemblies (backport [#40085](#40085)) ([#40087](#40087)) ([cf5fa21](cf5fa21)) * Fiscal Year exception on demo data setup ([56ee843](56ee843)) * incorrect item name in MR (backport [#40018](#40018)) ([#40024](#40024)) ([9f8f3db](9f8f3db)) * Issues regarding asset cancellation and deletion ([8eb2f67](8eb2f67)) * negative stock error while making stock reconciliation (backport [#40016](#40016)) ([#40026](#40026)) ([c964c45](c964c45)) * on unreconciliation, update advance paid ([4d1f56c](4d1f56c)) * only check for delinked PLEs ([a75a69a](a75a69a)) * only consider contributed qty towards achieved targets ([194f46b](194f46b)) * parent warehouse checks in the production plan for sub-assemblies (backport [#40150](#40150)) ([#40157](#40157)) ([4784117](4784117)) * remove cancelled payment entry from Payment Period Based On Invoice Date ([72da308](72da308)) * remove cancelled payment entry from PPBOID report ([0be5203](0be5203)) * remove config for default bank account in test ([36b442a](36b442a)) * remove microsecond from posting datetime (backport [#40017](#40017)) ([#40022](#40022)) ([eaa3849](eaa3849)) * removed unwanted patch ([ee2d108](ee2d108)) * resolved conflict ([6928674](6928674)) * resolved conflict ([a0c0ab7](a0c0ab7)) * skip max discount validation for rate adjustment ([3b96aae](3b96aae)) * skip SO & DN validation for debit note ([cd42089](cd42089)) * Supplier users not able to see RFQ on the Portal (backport [#40161](#40161)) ([#40165](#40165)) ([6a63a6c](6a63a6c)) * timesheet per billed state edge case (backport [#40010](#40010)) ([#40029](#40029)) ([a543bf4](a543bf4)) * translatable columns in Sales Pipeline Analytics report ([1c5a7e2](1c5a7e2)) * type error for missing frm obj ([6b5e1cf](6b5e1cf)) * unique gl account for plaid bank accounts ([65853da](65853da)) * use correct variable name on hotfix branches ([0694fd1](0694fd1)) * use frm instead of cur_frm ([341f903](341f903)) * use serial batch fields for packed items (backport [#40140](#40140)) ([#40142](#40142)) ([1860399](1860399)) ### Features * show contributed qty in transaction summary ([38abfdb](38abfdb)) * update billed amount in PO and PR ([e7e8149](e7e8149)) ### Performance Improvements * new column Posting Datetime in SLE to optimize stock ledger related queries (backport [#39800](#39800)) ([#40004](#40004)) ([b9181e8](b9181e8))

rohitwaghchaure requested review from deepeshgarg007 and s-aga-r as code owners February 7, 2024 16:27

rohitwaghchaure marked this pull request as draft February 7, 2024 16:27

github-actions bot added needs-tests This PR needs automated unit-tests. stock labels Feb 7, 2024

rohitwaghchaure force-pushed the persistent-indexing branch 3 times, most recently from af442b7 to 244a385 Compare February 7, 2024 16:56

ankush reviewed Feb 7, 2024

View reviewed changes

erpnext/patches/v14_0/update_posting_datetime.py Outdated Show resolved Hide resolved

ankush reviewed Feb 7, 2024

View reviewed changes

erpnext/patches/v14_0/update_posting_datetime.py Outdated Show resolved Hide resolved

rohitwaghchaure force-pushed the persistent-indexing branch 11 times, most recently from 3b9485f to b58cc8c Compare February 9, 2024 05:54

ankush reviewed Feb 9, 2024

View reviewed changes

erpnext/stock/doctype/stock_ledger_entry/stock_ledger_entry.py Outdated Show resolved Hide resolved

rohitwaghchaure closed this Feb 9, 2024

rohitwaghchaure reopened this Feb 12, 2024

rohitwaghchaure force-pushed the persistent-indexing branch from b58cc8c to c5684a3 Compare February 12, 2024 14:50

github-actions bot added accounts and removed needs-tests This PR needs automated unit-tests. labels Feb 12, 2024

rohitwaghchaure force-pushed the persistent-indexing branch from c5684a3 to 7bed8a6 Compare February 12, 2024 14:51

rohitwaghchaure force-pushed the persistent-indexing branch 3 times, most recently from 4d00d73 to d700603 Compare February 13, 2024 06:11

perf: new column posting datetime in SLE to optimize stock ledger rel…

d80ca52

…ated queries

rohitwaghchaure force-pushed the persistent-indexing branch from d700603 to d80ca52 Compare February 13, 2024 06:12

rohitwaghchaure marked this pull request as ready for review February 13, 2024 06:26

rohitwaghchaure requested a review from ruthra-kumar as a code owner February 13, 2024 06:26

ankush reviewed Feb 15, 2024

View reviewed changes

erpnext/patches/v14_0/update_posting_datetime_and_dropped_indexes.py Show resolved Hide resolved

ankush reviewed Feb 15, 2024

View reviewed changes

erpnext/patches.txt Outdated Show resolved Hide resolved

ankush reviewed Feb 15, 2024

View reviewed changes

rohitwaghchaure force-pushed the persistent-indexing branch from 3e89fe2 to 05e3cb4 Compare February 17, 2024 09:30

test: test cases to test clash timestamp entries

f04676a

rohitwaghchaure force-pushed the persistent-indexing branch from 05e3cb4 to f04676a Compare February 17, 2024 09:31

rohitwaghchaure added 2 commits February 21, 2024 11:02

Merge branch 'develop' into persistent-indexing

f37f7ca

chore: remove microsecond from posting_datetime

a73ba2c

rohitwaghchaure force-pushed the persistent-indexing branch from 314b127 to a73ba2c Compare February 21, 2024 12:44

rohitwaghchaure merged commit 4c061d6 into frappe:develop Feb 21, 2024
12 of 13 checks passed

rohitwaghchaure added the backport version-15-hotfix label Feb 21, 2024

mergify bot mentioned this pull request Feb 21, 2024

perf: new column Posting Datetime in SLE to optimize stock ledger related queries (backport #39800) #40004

Merged

rohitwaghchaure added the backport version-14-hotfix backport to version 14 label Feb 22, 2024

mergify bot mentioned this pull request Feb 22, 2024

perf: new column Posting Datetime in SLE to optimize stock ledger related queries (backport #39800) #40036

Merged

github-actions bot locked as resolved and limited conversation to collaborators Mar 8, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

perf: new column Posting Datetime in SLE to optimize stock ledger related queries #39800

perf: new column Posting Datetime in SLE to optimize stock ledger related queries #39800

rohitwaghchaure commented Feb 7, 2024 •

edited

Loading

ankush commented Feb 9, 2024

rohitwaghchaure commented Feb 10, 2024

ankush Feb 15, 2024 •

edited

Loading

rohitwaghchaure Feb 15, 2024

ankush Feb 15, 2024 •

edited

Loading

rohitwaghchaure Feb 15, 2024

perf: new column Posting Datetime in SLE to optimize stock ledger related queries #39800

perf: new column Posting Datetime in SLE to optimize stock ledger related queries #39800

Conversation

rohitwaghchaure commented Feb 7, 2024 • edited Loading

ankush commented Feb 9, 2024

rohitwaghchaure commented Feb 10, 2024

ankush Feb 15, 2024 • edited Loading

Choose a reason for hiding this comment

rohitwaghchaure Feb 15, 2024

Choose a reason for hiding this comment

ankush Feb 15, 2024 • edited Loading

Choose a reason for hiding this comment

rohitwaghchaure Feb 15, 2024

Choose a reason for hiding this comment

rohitwaghchaure commented Feb 7, 2024 •

edited

Loading

ankush Feb 15, 2024 •

edited

Loading

ankush Feb 15, 2024 •

edited

Loading