You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@geode.apache.org by GitBox <gi...@apache.org> on 2021/07/01 15:38:14 UTC

[GitHub] [geode-native] pdxcodemonkey opened a new pull request #828: Performance improvements for gnmsg script

pdxcodemonkey opened a new pull request #828:
URL: https://github.com/apache/geode-native/pull/828


   - Compiling regex every time we check a line for matches is silly, made
     the regexes member variables of the decoder classes and only compile
     them once.
   - Short-circuited regex checking by doing a "sanity check" using a
     substring search for each line before using regex.  Substring search
     is much, much cheaper than re.search().
   
   Performance comparison follows.  I ran gnmsg on two log files, one "normal" and one that was extremely slow to scan.
   
   Results for the normal file: 7.434 seconds dropped to 0.786 seconds (9.4x faster), relevant function calls shown below:
   
   ```
   Before:
   
            2258846 function calls (2219404 primitive calls) in 7.434 seconds
   
      Ordered by: standard name
   
      ncalls  tottime  percall  cumtime  percall filename:lineno(function)
       22117    0.009    0.000    0.216    0.000 client_message_decoder.py:111(get_send_trace_parts)
       21692    0.011    0.000    5.487    0.000 client_message_decoder.py:125(get_add_security_trace_parts)
           1    0.000    0.000    0.037    0.037 client_message_decoder.py:16(<module>)
         425    0.001    0.000    0.001    0.000 client_message_decoder.py:171(parse_request_fields_base)
         425    0.000    0.000    0.002    0.000 client_message_decoder.py:187(parse_request_fields)
       22117    0.019    0.000    5.733    0.000 client_message_decoder.py:194(process_line)
           1    0.000    0.000    0.000    0.000 client_message_decoder.py:28(ClientMessageDecoder)
           1    0.000    0.000    0.000    0.000 client_message_decoder.py:29(__init__)
          36    0.000    0.000    0.001    0.000 client_message_decoder.py:80(get_send_trace_parts_v911)
       22117    0.013    0.000    0.207    0.000 client_message_decoder.py:96(get_send_trace_parts_base)
   
           2    0.000    0.000    0.000    0.000 re.py:188(match)
      277427    0.054    0.000    0.186    0.000 re.py:250(compile)
           1    0.000    0.000    0.000    0.000 re.py:270(escape)
      277429    0.081    0.000    0.132    0.000 re.py:289(_compile)
   
       21692    0.014    0.000    0.321    0.000 server_message_decoder.py:106(get_receive_trace_header_base)
          42    0.000    0.000    0.001    0.000 server_message_decoder.py:113(get_receive_trace_header_v911)
       21338    0.010    0.000    0.040    0.000 server_message_decoder.py:132(get_receive_trace_body_parts)
       21692    0.008    0.000    0.330    0.000 server_message_decoder.py:150(get_receive_trace_parts)
       20984    0.009    0.000    0.125    0.000 server_message_decoder.py:164(get_add_security_trace_parts)
           1    0.000    0.000    0.004    0.004 server_message_decoder.py:17(<module>)
       20984    0.018    0.000    0.252    0.000 server_message_decoder.py:180(get_response_header)
       20931    0.017    0.000    0.244    0.000 server_message_decoder.py:214(get_chunk_header)
       20931    0.017    0.000    0.248    0.000 server_message_decoder.py:251(get_chunk_bytes)
         354    0.001    0.000    0.001    0.000 server_message_decoder.py:294(parse_response_fields_base)
           1    0.000    0.000    0.000    0.000 server_message_decoder.py:32(ServerMessageDecoder)
         354    0.000    0.000    0.001    0.000 server_message_decoder.py:327(parse_response_fields)
           1    0.000    0.000    0.000    0.000 server_message_decoder.py:33(__init__)
       22117    0.050    0.000    1.436    0.000 server_message_decoder.py:331(process_line)
       22117    0.010    0.000    0.139    0.000 server_message_decoder.py:53(associate_connection_to_tid)
       21692    0.010    0.000    0.133    0.000 server_message_decoder.py:67(get_receive_trace_header_with_pointer)
       21692    0.011    0.000    0.175    0.000 server_message_decoder.py:87(get_receive_trace_header_without_pointer)
   
   After:
   
            1052014 function calls (1012572 primitive calls) in 0.786 seconds
   
      Ordered by: standard name
   
      ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        6234    0.004    0.000    0.100    0.000 client_message_decoder.py:105(get_send_trace_parts_base)
        6234    0.002    0.000    0.102    0.000 client_message_decoder.py:117(get_send_trace_parts)
        5809    0.001    0.000    0.001    0.000 client_message_decoder.py:131(get_add_security_trace_parts)
           1    0.000    0.000    0.041    0.041 client_message_decoder.py:16(<module>)
         425    0.001    0.000    0.001    0.000 client_message_decoder.py:176(parse_request_fields_base)
         425    0.000    0.000    0.002    0.000 client_message_decoder.py:192(parse_request_fields)
       22117    0.007    0.000    0.007    0.000 client_message_decoder.py:199(is_candidate_line)
       22117    0.012    0.000    0.133    0.000 client_message_decoder.py:202(process_line)
           1    0.000    0.000    0.000    0.000 client_message_decoder.py:28(ClientMessageDecoder)
           1    0.000    0.000    0.002    0.002 client_message_decoder.py:29(__init__)
           2    0.000    0.000    0.000    0.000 client_message_decoder.py:92(get_send_trace_parts_v911)
   
           2    0.000    0.000    0.000    0.000 re.py:188(match)
          40    0.000    0.000    0.014    0.000 re.py:250(compile)
           1    0.000    0.000    0.000    0.000 re.py:270(escape)
          42    0.000    0.000    0.014    0.000 re.py:289(_compile)
   
        6234    0.002    0.000    0.040    0.000 server_message_decoder.py:100(associate_connection_to_tid)
        5809    0.002    0.000    0.033    0.000 server_message_decoder.py:111(get_receive_trace_header_with_pointer)
        5809    0.003    0.000    0.076    0.000 server_message_decoder.py:128(get_receive_trace_header_without_pointer)
        5809    0.004    0.000    0.113    0.000 server_message_decoder.py:144(get_receive_trace_header_base)
           7    0.000    0.000    0.000    0.000 server_message_decoder.py:151(get_receive_trace_header_v911)
        5455    0.003    0.000    0.008    0.000 server_message_decoder.py:167(get_receive_trace_body_parts)
           1    0.000    0.000    0.003    0.003 server_message_decoder.py:17(<module>)
        5809    0.002    0.000    0.115    0.000 server_message_decoder.py:182(get_receive_trace_parts)
        5101    0.001    0.000    0.027    0.000 server_message_decoder.py:196(get_add_security_trace_parts)
        5101    0.002    0.000    0.060    0.000 server_message_decoder.py:209(get_response_header)
        5048    0.002    0.000    0.052    0.000 server_message_decoder.py:237(get_chunk_header)
        5048    0.002    0.000    0.058    0.000 server_message_decoder.py:268(get_chunk_bytes)
         354    0.001    0.000    0.001    0.000 server_message_decoder.py:305(parse_response_fields_base)
           1    0.000    0.000    0.000    0.000 server_message_decoder.py:32(ServerMessageDecoder)
           1    0.000    0.000    0.008    0.008 server_message_decoder.py:33(__init__)
         354    0.000    0.000    0.001    0.000 server_message_decoder.py:338(parse_response_fields)
       22117    0.006    0.000    0.006    0.000 server_message_decoder.py:342(is_candidate_line)
       22117    0.019    0.000    0.393    0.000 server_message_decoder.py:345(process_line)
   ```
   
   Results for the slow file:  128.853 seconds dropped to 1.182 seconds (109x faster!!!), relevant function calls shown below:
   
   ```
   Before:
   
            3095155 function calls (3030151 primitive calls) in 128.853 seconds
   
      Ordered by: standard name
   
      ncalls  tottime  percall  cumtime  percall filename:lineno(function)
       29964    0.013    0.000    0.329    0.000 client_message_decoder.py:111(get_send_trace_parts)
       29425    0.015    0.000  125.991    0.004 client_message_decoder.py:125(get_add_security_trace_parts)
           1    0.000    0.000    0.036    0.036 client_message_decoder.py:16(<module>)
         539    0.002    0.000    0.002    0.000 client_message_decoder.py:171(parse_request_fields_base)
         539    0.000    0.000    0.003    0.000 client_message_decoder.py:187(parse_request_fields)
         328    0.000    0.000    0.000    0.000 client_message_decoder.py:191(request_requires_security_footer)
       29964    0.025    0.000  126.364    0.004 client_message_decoder.py:194(process_line)
           1    0.000    0.000    0.000    0.000 client_message_decoder.py:28(ClientMessageDecoder)
           1    0.000    0.000    0.000    0.000 client_message_decoder.py:29(__init__)
          74    0.000    0.000    0.001    0.000 client_message_decoder.py:80(get_send_trace_parts_v911)
       29964    0.018    0.000    0.316    0.000 client_message_decoder.py:96(get_send_trace_parts_base)
   
           2    0.000    0.000    0.000    0.000 re.py:188(match)
      375623    0.075    0.000    0.248    0.000 re.py:250(compile)
           1    0.000    0.000    0.000    0.000 re.py:270(escape)
      375625    0.109    0.000    0.172    0.000 re.py:289(_compile)
   
       29425    0.020    0.000    0.514    0.000 server_message_decoder.py:106(get_receive_trace_header_base)
          21    0.000    0.000    0.001    0.000 server_message_decoder.py:113(get_receive_trace_header_v911)
       28885    0.015    0.000    0.060    0.000 server_message_decoder.py:132(get_receive_trace_body_parts)
       29425    0.012    0.000    0.526    0.000 server_message_decoder.py:150(get_receive_trace_parts)
       28345    0.013    0.000    0.182    0.000 server_message_decoder.py:164(get_add_security_trace_parts)
           1    0.000    0.000    0.001    0.001 server_message_decoder.py:17(<module>)
       28345    0.024    0.000    0.358    0.000 server_message_decoder.py:180(get_response_header)
       28345    0.024    0.000    0.358    0.000 server_message_decoder.py:214(get_chunk_header)
       28345    0.024    0.000    0.350    0.000 server_message_decoder.py:251(get_chunk_bytes)
         540    0.002    0.000    0.002    0.000 server_message_decoder.py:294(parse_response_fields_base)
           1    0.000    0.000    0.000    0.000 server_message_decoder.py:32(ServerMessageDecoder)
         540    0.000    0.000    0.002    0.000 server_message_decoder.py:327(parse_response_fields)
           1    0.000    0.000    0.000    0.000 server_message_decoder.py:33(__init__)
       29964    0.070    0.000    2.153    0.000 server_message_decoder.py:331(process_line)
       29964    0.016    0.000    0.211    0.000 server_message_decoder.py:53(associate_connection_to_tid)
       29425    0.014    0.000    0.212    0.000 server_message_decoder.py:67(get_receive_trace_header_with_pointer)
       29425    0.016    0.000    0.281    0.000 server_message_decoder.py:87(get_receive_trace_header_without_pointer)
   
   After:
   
            1472594 function calls (1407590 primitive calls) in 1.182 seconds
   
      Ordered by: standard name
   
      ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        8891    0.004    0.000    0.153    0.000 client_message_decoder.py:105(get_send_trace_parts_base)
        8891    0.003    0.000    0.156    0.000 client_message_decoder.py:117(get_send_trace_parts)
        8352    0.002    0.000    0.039    0.000 client_message_decoder.py:131(get_add_security_trace_parts)
           1    0.000    0.000    0.036    0.036 client_message_decoder.py:16(<module>)
         539    0.002    0.000    0.002    0.000 client_message_decoder.py:176(parse_request_fields_base)
         539    0.000    0.000    0.002    0.000 client_message_decoder.py:192(parse_request_fields)
         328    0.000    0.000    0.000    0.000 client_message_decoder.py:196(request_requires_security_footer)
       29964    0.010    0.000    0.010    0.000 client_message_decoder.py:199(is_candidate_line)
       29964    0.016    0.000    0.237    0.000 client_message_decoder.py:202(process_line)
           1    0.000    0.000    0.000    0.000 client_message_decoder.py:28(ClientMessageDecoder)
           1    0.000    0.000    0.002    0.002 client_message_decoder.py:29(__init__)
          18    0.000    0.000    0.000    0.000 client_message_decoder.py:92(get_send_trace_parts_v911)
   
           2    0.000    0.000    0.000    0.000 re.py:188(match)
          40    0.000    0.000    0.014    0.000 re.py:250(compile)
           1    0.000    0.000    0.000    0.000 re.py:270(escape)
          42    0.000    0.000    0.015    0.000 re.py:289(_compile)
   
        8891    0.004    0.000    0.071    0.000 server_message_decoder.py:100(associate_connection_to_tid)
        8352    0.002    0.000    0.069    0.000 server_message_decoder.py:111(get_receive_trace_header_with_pointer)
        8352    0.004    0.000    0.134    0.000 server_message_decoder.py:128(get_receive_trace_header_without_pointer)
        8352    0.005    0.000    0.208    0.000 server_message_decoder.py:144(get_receive_trace_header_base)
           4    0.000    0.000    0.000    0.000 server_message_decoder.py:151(get_receive_trace_header_v911)
        7812    0.003    0.000    0.013    0.000 server_message_decoder.py:167(get_receive_trace_body_parts)
           1    0.000    0.000    0.001    0.001 server_message_decoder.py:17(<module>)
        8352    0.003    0.000    0.212    0.000 server_message_decoder.py:182(get_receive_trace_parts)
        7272    0.002    0.000    0.041    0.000 server_message_decoder.py:196(get_add_security_trace_parts)
        7272    0.003    0.000    0.082    0.000 server_message_decoder.py:209(get_response_header)
        7272    0.003    0.000    0.081    0.000 server_message_decoder.py:237(get_chunk_header)
        7272    0.003    0.000    0.079    0.000 server_message_decoder.py:268(get_chunk_bytes)
         540    0.002    0.000    0.002    0.000 server_message_decoder.py:305(parse_response_fields_base)
           1    0.000    0.000    0.000    0.000 server_message_decoder.py:32(ServerMessageDecoder)
           1    0.000    0.000    0.009    0.009 server_message_decoder.py:33(__init__)
         540    0.000    0.000    0.002    0.000 server_message_decoder.py:338(parse_response_fields)
       29964    0.008    0.000    0.008    0.000 server_message_decoder.py:342(is_candidate_line)
       29964    0.027    0.000    0.649    0.000 server_message_decoder.py:345(process_line)
   ```
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@geode.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [geode-native] pdxcodemonkey merged pull request #828: Performance improvements for gnmsg script

Posted by GitBox <gi...@apache.org>.
pdxcodemonkey merged pull request #828:
URL: https://github.com/apache/geode-native/pull/828


   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@geode.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org