erpnext icon indicating copy to clipboard operation
erpnext copied to clipboard

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

Open rohitwaghchaure opened this issue 1 year ago • 2 comments

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 https://github.com/frappe/erpnext/issues/38364

rohitwaghchaure avatar Feb 07 '24 16:02 rohitwaghchaure

@rohitwaghchaure why closed? TZ issues?

Those should be fixable. I can help if required.

ankush avatar Feb 09 '24 17:02 ankush

@ankush Will reopen after fixing TZ issues and test cases

rohitwaghchaure avatar Feb 10 '24 15:02 rohitwaghchaure