Performance/testing

[AlexanderMann]

Motivation

Performance testing is something which we haven't really done for any of the targets as of yet. This PR adds in some harness work to allow for doing fairly detailed performance testing, by generating statistics based on:

• MillisLoggingCursor Output
• Singer Timer Metrics Output
• cProfile Stats

Each form of output produces a different level of information:

• MillisLoggingCursor produces files suffixed remote.csv and includes detailed statistics showing what queries are taking the longest
• Singer Timer Metrics are implemented by the underlying SQLInterface class and can offer insights into what sections/actions the code is taking the longest on
• cProfile stats are able to show us in greater depth what specific functions/lines are consuming our time and can often lead to little tweaks which result in speed gains

All of this was used to make up the PRs #12 #13. Both were made apparent by the remote queries data (plus some massaging in Sheets).

Future Think

Eventually it would be nice to turn this into a more useful target agnostic profiler so that we can try out our own targets, but also those of others to better understand hard numbers/tradeoffs/benefits etc.

The things standing in our way are:

• generative data: Presently we're relying upon our CatStream generation to fuel the records to be persisted...ideally we would be able to use a tap/echo some data into a target
• this suite would need to probably become a library so that the cProfileing would still produce useful output
• remote cleanup: since we are implementing a Snowflake performance test here, and have control of the code, we are able to clear out the remote db before and after our testing

Example Output

Remote and Code: https://docs.google.com/spreadsheets/d/1jRU5QooSoLuXHefYS22lZuBzByRkezA3tye9ztE8E34/edit?usp=sharing

cProfile

Thu Aug 29 20:24:26 2019    /code/performance/2019_08_29_20_23_24/978e3370-6fc0-4644-b911-3bdf6dda739e.prof
Thu Aug 29 20:25:21 2019    /code/performance/2019_08_29_20_23_24/3ff718ff-c948-4128-9bfb-4ff1722326ef.prof
Thu Aug 29 20:26:17 2019    /code/performance/2019_08_29_20_23_24/af53e05b-f58d-4082-a632-015d23270350.prof

         1875472 function calls (1826211 primitive calls) in 161.966 seconds

   Ordered by: cumulative time
   List reduced from 2499 to 2000 due to restriction <2000>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        3    0.001    0.000  162.068   54.023 /code/target_snowflake/__init__.py:20(main)
        3    0.001    0.000  149.714   49.905 /code/venv--target-snowflake/lib/python3.7/site-packages/target_postgres/target_tools.py:32(stream_to_target)
        3    0.000    0.000  149.256   49.752 /code/venv--target-snowflake/lib/python3.7/site-packages/target_postgres/stream_tracker.py:45(flush_streams)
        3    0.001    0.000  149.256   49.752 /code/target_snowflake/snowflake.py:85(write_batch)
      288    0.032    0.000  147.790    0.513 /code/target_snowflake/connection.py:16(execute)
      288    0.067    0.000  147.369    0.512 /code/venv--target-snowflake/lib/python3.7/site-packages/snowflake/connector/cursor.py:414(execute)
      300    0.035    0.000  144.548    0.482 /code/venv--target-snowflake/lib/python3.7/site-packages/snowflake/connector/network.py:503(_post_request)
      300    0.026    0.000  144.485    0.482 /code/venv--target-snowflake/lib/python3.7/site-packages/snowflake/connector/network.py:562(fetch)
        3    0.002    0.001  144.310   48.103 /code/venv--target-snowflake/lib/python3.7/site-packages/target_postgres/sql_base.py:773(write_batch_helper)
      300    0.030    0.000  144.292    0.481 /code/venv--target-snowflake/lib/python3.7/site-packages/snowflake/connector/network.py:619(_request_exec_wrapper)
      300    0.054    0.000  143.798    0.479 /code/venv--target-snowflake/lib/python3.7/site-packages/snowflake/connector/network.py:752(_request_exec)
      300    0.032    0.000  143.260    0.478 /code/venv--target-snowflake/lib/python3.7/site-packages/botocore/vendored/requests/sessions.py:386(request)
      300    0.057    0.000  135.029    0.450 /code/venv--target-snowflake/lib/python3.7/site-packages/botocore/vendored/requests/sessions.py:539(send)
      294    0.021    0.000  134.160    0.456 /code/venv--target-snowflake/lib/python3.7/site-packages/snowflake/connector/network.py:272(request)
      300    0.034    0.000  134.124    0.447 /code/venv--target-snowflake/lib/python3.7/site-packages/botocore/vendored/requests/adapters.py:323(send)
      288    0.056    0.000  133.879    0.465 /code/venv--target-snowflake/lib/python3.7/site-packages/snowflake/connector/cursor.py:291(_execute_helper)
      288    0.028    0.000  133.399    0.463 /code/venv--target-snowflake/lib/python3.7/site-packages/snowflake/connector/connection.py:814(cmd_query)
      300    0.034    0.000  132.590    0.442 /code/venv--target-snowflake/lib/python3.7/site-packages/botocore/vendored/requests/packages/urllib3/connectionpool.py:421(urlopen)
      300    0.051    0.000  131.778    0.439 /code/venv--target-snowflake/lib/python3.7/site-packages/botocore/vendored/requests/packages/urllib3/connectionpool.py:317(_make_request)
      306    0.012    0.000  122.096    0.399 /usr/local/lib/python3.7/http/client.py:1277(getresponse)
      306    0.041    0.000  122.045    0.399 /usr/local/lib/python3.7/http/client.py:289(begin)
     3369    0.054    0.000  119.701    0.036 {method 'readline' of '_io.BufferedReader' objects}
      306    0.024    0.000  119.691    0.391 /usr/local/lib/python3.7/http/client.py:256(_read_status)
      314    0.017    0.000  119.647    0.381 /usr/local/lib/python3.7/socket.py:575(readinto)

Suggested Musical Pairing

Wind.