Timing Logging Enrichment

[vicilliar]

• What kind of change does this PR introduce? (Bug fix, feature, docs update, ...)
  Observability feature.

• What is the current behavior? (You can also link to an open issue here)
  Timing logs are not output at every step of Marqo add_documents and search. They are only returned to the client via processingTimeMS.

• What is the new behavior (if this is a feature change)?
  Breaks down and adds explicit timing logs to relevant parts of the Marqo process. Replaces existing timing devices with timeit.default_timer, due to it being faster to instantiate than datetime.datetime.

The following parts now have explicit timing logs (by batch):

1. add_documents - pre-processing (total time)
2. add_documents - pre-processing (vectorisation time). Individual vectorisation time is sent as logger.debug
3. add_documents - HTTP roundtrip (Marqo <-> Marqo-os)
4. add_documents - Indexing time (from Marqo-os result)
5. search - pre-processing (total time)
6. search - HTTP roundtrip (Marqo <-> Marqo-os)
7. search - post-processing (total time)
8. search - reranking

• Does this PR introduce a breaking change? (What changes might users need to make in their application due to this PR?)
  No.

• Have unit tests been run against this PR? (Has there also been any additional testing?)
  Yes.

• Related Python client changes (link commit/PR here)

• Related documentation changes (link commit/PR here)

• Other information:

• Please check if the PR fulfills these requirements

• The commit message follows our guidelines
• Tests for the changes have been added (for bug fixes/features)
• Docs have been added / updated (for bug fixes / features)

[pandu-k]

left comment