t

gistfile1.txt

{
trace: {
children: [
{
message: "Using query profile 'default' of type 'root'"
},
{
children: [
{
timestamp: 0,
message: "Invoke searcher 'ai.vespa.example.cord19.searcher.RelatedArticlesByNNSearcher in default'"
},
{
timestamp: 0,
message: "Invoke searcher 'ai.vespa.example.cord19.searcher.BoldingSearcher in default'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.querytransform.WeakAndReplacementSearcher in vespa'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.prelude.statistics.StatisticsSearcher in native'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.prelude.querytransform.PhrasingSearcher in vespa'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.prelude.searcher.FieldCollapsingSearcher in vespa'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.yql.MinimalQueryInserter in vespa'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.yql.FieldFilter in vespa'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.prelude.searcher.JuniperSearcher in vespa'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.prelude.searcher.PosSearcher in vespa'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.prelude.semantics.SemanticSearcher in vespa'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.grouping.GroupingQueryParser in vespa'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.prelude.searcher.BlendingSearcher in vespa'"
},
{
timestamp: 0,
message: "Invoke searcher 'federation in native'"
},
{
timestamp: 0,
children: [
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.querytransform.NGramSearcher in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.querytransform.DefaultPositionSearcher in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.prelude.querytransform.CJKSearcher in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.prelude.querytransform.LiteralBoostSearcher in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.querytransform.RangeQueryOptimizer in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.querytransform.SortingDegrader in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.searchers.QueryValidator in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.grouping.GroupingValidator in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.querytransform.WandSearcher in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.prelude.querytransform.RecallSearcher in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.prelude.querytransform.StemmingSearcher in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.prelude.querytransform.NormalizingSearcher in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.querytransform.VespaLowercasingSearcher in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.prelude.searcher.ValidateSortingSearcher in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.querytransform.BooleanSearcher in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.prelude.searcher.ValidatePredicateSearcher in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.searchers.ValidateNearestNeighborSearcher in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.grouping.vespa.GroupingExecutor in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.searchers.ValidateMatchPhaseSearcher in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.yql.FieldFiller in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.searchers.InputCheckingSearcher in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.search.searchers.ContainerLatencySearcher in content'"
},
{
timestamp: 0,
message: "Invoke searcher 'com.yahoo.prelude.cluster.ClusterSearcher in content'"
},
{
timestamp: 0,
message: "sc0.num0 search to dispatch: query=[sar] timeout=2000ms offset=0 hits=1 groupingSessionCache=true sessionId=12738b6c-05e4-40f2-8266-64450d3191c3.1639337086354.1230.default grouping=0 : restrict=[doc]"
},
{
timestamp: 3,
message: [
{
start_time: "2021-12-12 19:24:46.355 UTC",
traces: [
{
timestamp_ms: 0.072778,
event: "MTF: Start"
},
{
timestamp_ms: 0.075551,
event: "MTF: Build query"
},
{
timestamp_ms: 0.085775,
event: "MTF: reserve handles"
},
{
timestamp_ms: 0.140031,
event: "MTF: Fetch Postings"
},
{
timestamp_ms: 0.146283,
event: "MTF: Handle Global Filters"
},
{
timestamp_ms: 0.147213,
event: "MTF: prepareSharedState"
},
{
timestamp_ms: 0.168085,
event: "MTF: Complete"
},
{
timestamp_ms: 2.121468,
tag: "match_threads",
threads: [
{
traces: [
{
timestamp_ms: 0.195574,
event: "Start MatchThread::run"
},
{
timestamp_ms: 0.234326,
event: "Start match and first phase rank"
},
{
timestamp_ms: 1.88497,
event: "Create result set"
},
{
timestamp_ms: 1.896233,
event: "Wait for result processing token"
},
{
timestamp_ms: 1.897113,
event: "Start result processing"
},
{
timestamp_ms: 1.926601,
event: "Start thread merge"
},
{
timestamp_ms: 2.114767,
event: "MatchThread::run Done"
}
]
},
{
traces: [
{
timestamp_ms: 0.204872,
event: "Start MatchThread::run"
},
{
timestamp_ms: 0.24116,
event: "Start match and first phase rank"
},
{
timestamp_ms: 2.040378,
event: "Create result set"
},
{
timestamp_ms: 2.055108,
event: "Wait for result processing token"
},
{
timestamp_ms: 2.056231,
event: "Start result processing"
},
{
timestamp_ms: 2.077611,
event: "Start thread merge"
},
{
timestamp_ms: 2.10184,
event: "MatchThread::run Done"
}
]
},
{
traces: [
{
timestamp_ms: 0.196398,
event: "Start MatchThread::run"
},
{
timestamp_ms: 0.234476,
event: "Start match and first phase rank"
},
{
timestamp_ms: 2.006179,
event: "Create result set"
},
{
timestamp_ms: 2.012182,
event: "Wait for result processing token"
},
{
timestamp_ms: 2.012594,
event: "Start result processing"
},
{
timestamp_ms: 2.045133,
event: "Start thread merge"
},
{
timestamp_ms: 2.106355,
event: "MatchThread::run Done"
}
]
},
{
traces: [
{
timestamp_ms: 0.199302,
event: "Start MatchThread::run"
},
{
timestamp_ms: 0.241162,
event: "Start match and first phase rank"
},
{
timestamp_ms: 2.039604,
event: "Create result set"
},
{
timestamp_ms: 2.055064,
event: "Wait for result processing token"
},
{
timestamp_ms: 2.055929,
event: "Start result processing"
},
{
timestamp_ms: 2.078528,
event: "Start thread merge"
},
{
timestamp_ms: 2.095299,
event: "MatchThread::run Done"
}
]
}
]
}
],
distribution-key: 46,
duration_ms: 2.163072
}
]
},
{
timestamp: 3,
message: [
{
start_time: "2021-12-12 19:24:46.355 UTC",
traces: [
{
timestamp_ms: 0.081276,
event: "MTF: Start"
},
{
timestamp_ms: 0.084042,
event: "MTF: Build query"
},
{
timestamp_ms: 0.09348,
event: "MTF: reserve handles"
},
{
timestamp_ms: 0.141396,
event: "MTF: Fetch Postings"
},
{
timestamp_ms: 0.146737,
event: "MTF: Handle Global Filters"
},
{
timestamp_ms: 0.147581,
event: "MTF: prepareSharedState"
},
{
timestamp_ms: 0.168811,
event: "MTF: Complete"
},
{
timestamp_ms: 2.172765,
tag: "match_threads",
threads: [
{
traces: [
{
timestamp_ms: 0.197482,
event: "Start MatchThread::run"
},
{
timestamp_ms: 0.229815,
event: "Start match and first phase rank"
},
{
timestamp_ms: 2.029405,
event: "Create result set"
},
{
timestamp_ms: 2.037606,
event: "Wait for result processing token"
},
{
timestamp_ms: 2.038447,
event: "Start result processing"
},
{
timestamp_ms: 2.074002,
event: "Start thread merge"
},
{
timestamp_ms: 2.161606,
event: "MatchThread::run Done"
}
]
},
{
traces: [
{
timestamp_ms: 0.207269,
event: "Start MatchThread::run"
},
{
timestamp_ms: 0.246124,
event: "Start match and first phase rank"
},
{
timestamp_ms: 2.055187,
event: "Create result set"
},
{
timestamp_ms: 2.061774,
event: "Wait for result processing token"
},
{
timestamp_ms: 2.062392,
event: "Start result processing"
},
{
timestamp_ms: 2.104884,
event: "Start thread merge"
},
{
timestamp_ms: 2.135089,
event: "MatchThread::run Done"
}
]
},
{
traces: [
{
timestamp_ms: 0.207271,
event: "Start MatchThread::run"
},
{
timestamp_ms: 0.246121,
event: "Start match and first phase rank"
},
{
timestamp_ms: 2.026738,
event: "Create result set"
},
{
timestamp_ms: 2.037124,
event: "Wait for result processing token"
},
{
timestamp_ms: 2.03807,
event: "Start result processing"
},
{
timestamp_ms: 2.07909,
event: "Start thread merge"
},
{
timestamp_ms: 2.153638,
event: "MatchThread::run Done"
}
]
},
{
traces: [
{
timestamp_ms: 0.192892,
event: "Start MatchThread::run"
},
{
timestamp_ms: 0.229594,
event: "Start match and first phase rank"
},
{
timestamp_ms: 1.987269,
event: "Create result set"
},
{
timestamp_ms: 1.999526,
event: "Wait for result processing token"
},
{
timestamp_ms: 2.000398,
event: "Start result processing"
},
{
timestamp_ms: 2.042928,
event: "Start thread merge"
},
{
timestamp_ms: 2.151182,
event: "MatchThread::run Done"
}
]
}
]
}
],
distribution-key: 45,
duration_ms: 2.213782
}
]
},
{
timestamp: 3,
message: [
{
start_time: "2021-12-12 19:24:46.355 UTC",
traces: [
{
timestamp_ms: 0.083891,
event: "MTF: Start"
},
{
timestamp_ms: 0.086273,
event: "MTF: Build query"
},
{
timestamp_ms: 0.097231,
event: "MTF: reserve handles"
},
{
timestamp_ms: 0.150847,
event: "MTF: Fetch Postings"
},
{
timestamp_ms: 0.15762,
event: "MTF: Handle Global Filters"
},
{
timestamp_ms: 0.158596,
event: "MTF: prepareSharedState"
},
{
timestamp_ms: 0.18054,
event: "MTF: Complete"
},
{
timestamp_ms: 2.233185,
tag: "match_threads",
threads: [
{
traces: [
{
timestamp_ms: 0.208959,
event: "Start MatchThread::run"
},
{
timestamp_ms: 0.248086,
event: "Start match and first phase rank"
},
{
timestamp_ms: 1.609921,
event: "Create result set"
},
{
timestamp_ms: 1.617821,
event: "Wait for result processing token"
},
{
timestamp_ms: 1.618672,
event: "Start result processing"
},
{
timestamp_ms: 1.646528,
event: "Start thread merge"
},
{
timestamp_ms: 2.211051,
event: "MatchThread::run Done"
}
]
},
{
traces: [
{
timestamp_ms: 0.217276,
event: "Start MatchThread::run"
},
{
timestamp_ms: 0.263453,
event: "Start match and first phase rank"
},
{
timestamp_ms: 1.434901,
event: "Create result set"
},
{
timestamp_ms: 1.443783,
event: "Wait for result processing token"
},
{
timestamp_ms: 1.444782,
event: "Start result processing"
},
{
timestamp_ms: 1.471782,
event: "Start thread merge"
},
{
timestamp_ms: 2.217369,
event: "MatchThread::run Done"
}
]
},
{
traces: [
{
timestamp_ms: 0.2104,
event: "Start MatchThread::run"
},
{
timestamp_ms: 0.247898,
event: "Start match and first phase rank"
},
{
timestamp_ms: 2.010909,
event: "Create result set"
},
{
timestamp_ms: 2.019574,
event: "Wait for result processing token"
},
{
timestamp_ms: 2.020006,
event: "Start result processing"
},
{
timestamp_ms: 2.053102,
event: "Start thread merge"
},
{
timestamp_ms: 2.212432,
event: "MatchThread::run Done"
}
]
},
{
traces: [
{
timestamp_ms: 0.210283,
event: "Start MatchThread::run"
},
{
timestamp_ms: 0.263376,
event: "Start match and first phase rank"
},
{
timestamp_ms: 2.142801,
event: "Create result set"
},
{
timestamp_ms: 2.154619,
event: "Wait for result processing token"
},
{
timestamp_ms: 2.155076,
event: "Start result processing"
},
{
timestamp_ms: 2.191224,
event: "Start thread merge"
},
{
timestamp_ms: 2.203591,
event: "MatchThread::run Done"
}
]
}
]
}
],
distribution-key: 44,
duration_ms: 2.271534
}
]
},
{
timestamp: 4,
message: [
{
start_time: "2021-12-12 19:24:46.355 UTC",
traces: [
{
timestamp_ms: 0.077205,
event: "MTF: Start"
},
{
timestamp_ms: 0.079458,
event: "MTF: Build query"
},
{
timestamp_ms: 0.089347,
event: "MTF: reserve handles"
},
{
timestamp_ms: 0.138103,
event: "MTF: Fetch Postings"
},
{
timestamp_ms: 0.144157,
event: "MTF: Handle Global Filters"
},
{
timestamp_ms: 0.145528,
event: "MTF: prepareSharedState"
},
{
timestamp_ms: 0.166704,
event: "MTF: Complete"
},
{
timestamp_ms: 2.507614,
tag: "match_threads",
threads: [
{
traces: [
{
timestamp_ms: 0.197764,
event: "Start MatchThread::run"
},
{
timestamp_ms: 0.234288,
event: "Start match and first phase rank"
},
{
timestamp_ms: 1.312087,
event: "Create result set"
},
{
timestamp_ms: 1.320199,
event: "Wait for result processing token"
},
{
timestamp_ms: 1.321106,
event: "Start result processing"
},
{
timestamp_ms: 1.341892,
event: "Start thread merge"
},
{
timestamp_ms: 2.500196,
event: "MatchThread::run Done"
}
]
},
{
traces: [
{
timestamp_ms: 0.205564,
event: "Start MatchThread::run"
},
{
timestamp_ms: 0.236464,
event: "Start match and first phase rank"
},
{
timestamp_ms: 2.166852,
event: "Create result set"
},
{
timestamp_ms: 2.17805,
event: "Wait for result processing token"
},
{
timestamp_ms: 2.179047,
event: "Start result processing"
},
{
timestamp_ms: 2.216818,
event: "Start thread merge"
},
{
timestamp_ms: 2.49014,
event: "MatchThread::run Done"
}
]
},
{
traces: [
{
timestamp_ms: 0.200183,
event: "Start MatchThread::run"
},
{
timestamp_ms: 0.23419,
event: "Start match and first phase rank"
},
{
timestamp_ms: 1.502022,
event: "Create result set"
},
{
timestamp_ms: 1.50825,
event: "Wait for result processing token"
},
{
timestamp_ms: 1.508787,
event: "Start result processing"
},
{
timestamp_ms: 1.545705,
event: "Start thread merge"
},
{
timestamp_ms: 2.493453,
event: "MatchThread::run Done"
}
]
},
{
traces: [
{
timestamp_ms: 0.196024,
event: "Start MatchThread::run"
},
{
timestamp_ms: 0.236574,
event: "Start match and first phase rank"
},
{
timestamp_ms: 2.435794,
event: "Create result set"
},
{
timestamp_ms: 2.448038,
event: "Wait for result processing token"
},
{
timestamp_ms: 2.448369,
event: "Start result processing"
},
{
timestamp_ms: 2.474146,
event: "Start thread merge"
},
{
timestamp_ms: 2.487214,
event: "MatchThread::run Done"
}
]
}
]
}
],
distribution-key: 47,
duration_ms: 2.557569
}
]
},
{
timestamp: 4,
message: "sc0.num0 dispatch response: Result (1 of total 52097 hits)"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.prelude.cluster.ClusterSearcher in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.searchers.ContainerLatencySearcher in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.searchers.InputCheckingSearcher in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.yql.FieldFiller in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.searchers.ValidateMatchPhaseSearcher in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.grouping.vespa.GroupingExecutor in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.searchers.ValidateNearestNeighborSearcher in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.prelude.searcher.ValidatePredicateSearcher in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.querytransform.BooleanSearcher in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.prelude.searcher.ValidateSortingSearcher in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.querytransform.VespaLowercasingSearcher in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.prelude.querytransform.NormalizingSearcher in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.prelude.querytransform.StemmingSearcher in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.prelude.querytransform.RecallSearcher in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.querytransform.WandSearcher in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.grouping.GroupingValidator in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.searchers.QueryValidator in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.querytransform.SortingDegrader in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.querytransform.RangeQueryOptimizer in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.prelude.querytransform.LiteralBoostSearcher in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.prelude.querytransform.CJKSearcher in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.querytransform.DefaultPositionSearcher in content'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.querytransform.NGramSearcher in content'"
},
{
timestamp: 4,
message: "sc0.num0 fill to dispatch: query=[sar] timeout=2000ms offset=0 hits=1 groupingSessionCache=true sessionId=12738b6c-05e4-40f2-8266-64450d3191c3.1639337086354.1230.default grouping=0 : restrict=[doc] summary='full'"
}
]
},
{
timestamp: 4,
message: "Return searcher 'federation in native'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.prelude.searcher.BlendingSearcher in vespa'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.grouping.GroupingQueryParser in vespa'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.prelude.semantics.SemanticSearcher in vespa'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.prelude.searcher.PosSearcher in vespa'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.prelude.searcher.JuniperSearcher in vespa'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.yql.FieldFilter in vespa'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.yql.MinimalQueryInserter in vespa'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.prelude.searcher.FieldCollapsingSearcher in vespa'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.prelude.querytransform.PhrasingSearcher in vespa'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.prelude.statistics.StatisticsSearcher in native'"
},
{
timestamp: 4,
message: "Return searcher 'com.yahoo.search.querytransform.WeakAndReplacementSearcher in vespa'"
},
{
timestamp: 4,
message: "Return searcher 'ai.vespa.example.cord19.searcher.BoldingSearcher in default'"
},
{
timestamp: 4,
message: "Return searcher 'ai.vespa.example.cord19.searcher.RelatedArticlesByNNSearcher in default'"
},
{
timestamp: 4
}
]
}
]
},
timing: {
querytime: 0.004,
summaryfetchtime: 0,
searchtime: 0.005
},