vespa icon indicating copy to clipboard operation
vespa copied to clipboard

Increase tracing transparency

Open thomasht86 opened this issue 7 months ago • 0 comments

Is your feature request related to a problem? Please describe.

Given a rank-profile with several phases, including an ONNX-inference with a crossencoder, for global phase-reranking. I want to be able to analyze time spent on

  1. The whole global-phase
  2. Individual parts of the global-phase ranking.

When analyzing query trace with

"trace.level": 4,
"trace.timestamps": "true",

I can see the following jump in timestamps in the trace:

 {
    "timestamp": 10,
    "message": "content.num0 dispatch response: Result (10 of total 1024 hits)"
  },
  {
    "timestamp": 3255,
    "message": "Return searcher 'com.yahoo.prelude.cluster.ClusterSearcher in content'"
  },

Apparently, this step include the whole global-phase. That does not seem very obvious.

Describe the solution you'd like

It would be very nice to at least have a more descriptive message. Even better if it were possible to get more granulated traces for different steps in rank-profile, that were linked to the expressions in the rank-profile, to be able to investigate performance more easily.

thomasht86 avatar Jul 04 '24 10:07 thomasht86