From 8ae95af035b04223384ac1c087887c9aed2c4bca Mon Sep 17 00:00:00 2001 From: tangwang Date: Tue, 24 Mar 2026 09:05:47 +0800 Subject: [PATCH] 1. Stage Timings: 为每个阶段耗时补充起止时间戳。 2， 漏了一些重要的stage，比如「款式意图 SKU 预筛选（StyleSkuSelector.prepare_hits）」，补上这个stage --- context/request_context.py | 27 +++++++++++++++++++++++++-- docs/TODO-prompts.md | 39 +++++++++++++++++++++++++++++++++++++++ frontend/static/js/app.js | 8 +++++++- search/searcher.py | 41 ++++++++++++++++++++++++++++------------- 4 files changed, 99 insertions(+), 16 deletions(-) create mode 100644 docs/TODO-prompts.md diff --git a/context/request_context.py b/context/request_context.py index ead99e7..22d6875 100644 --- a/context/request_context.py +++ b/context/request_context.py @@ -27,6 +27,8 @@ class RequestContextStage(Enum): ELASTICSEARCH_PAGE_FILL = "elasticsearch_page_fill" RESULT_PROCESSING = "result_processing" RERANKING = "reranking" + # 款式意图 SKU 预筛选（StyleSkuSelector.prepare_hits） + STYLE_SKU_PREPARE_HITS = "style_sku_prepare_hits" @dataclass @@ -48,6 +50,8 @@ class PerformanceMetrics: """性能指标""" stage_timings: Dict[str, float] = field(default_factory=dict) stage_start_times: Dict[str, float] = field(default_factory=dict) + # 各阶段起止时间（Unix 毫秒，与 time.time() 一致） + stage_time_bounds_ms: Dict[str, Dict[str, float]] = field(default_factory=dict) total_duration: float = 0.0 extra_metrics: Dict[str, Any] = field(default_factory=dict) @@ -141,8 +145,13 @@ class RequestContext: return 0.0 start_time = self.performance_metrics.stage_start_times[stage.value] - duration_ms = (time.time() - start_time) * 1000 + end_time = time.time() + duration_ms = (end_time - start_time) * 1000 self.performance_metrics.stage_timings[stage.value] = duration_ms + self.performance_metrics.stage_time_bounds_ms[stage.value] = { + "start_unix_ms": round(start_time * 1000, 3), + "end_unix_ms": round(end_time * 1000, 3), + } self.logger.debug( f"End stage | {stage.value} | duration: {duration_ms:.2f}ms", @@ -280,6 +289,12 @@ class RequestContext: 'stage_timings_ms': { k: round(v, 2) for k, v in self.performance_metrics.stage_timings.items() }, + 'stage_time_bounds_ms': { + stage: { + kk: round(vv, 3) for kk, vv in bounds.items() + } + for stage, bounds in self.performance_metrics.stage_time_bounds_ms.items() + }, 'stage_percentages': self.calculate_stage_percentages() }, 'results': { @@ -307,9 +322,17 @@ class RequestContext: # 添加各阶段耗时 if summary['performance']['stage_timings_ms']: msg_parts.append("Stage durations:") + bounds_map = summary['performance'].get('stage_time_bounds_ms') or {} for stage, duration in summary['performance']['stage_timings_ms'].items(): percentage = summary['performance']['stage_percentages'].get(stage, 0) - msg_parts.append(f" - {stage}: {duration:.2f}ms ({percentage}%)") + b = bounds_map.get(stage) or {} + if b.get('start_unix_ms') is not None and b.get('end_unix_ms') is not None: + msg_parts.append( + f" - {stage}: {duration:.2f}ms ({percentage}%) " + f"[{b['start_unix_ms']:.3f} -> {b['end_unix_ms']:.3f} ms]" + ) + else: + msg_parts.append(f" - {stage}: {duration:.2f}ms ({percentage}%)") # 添加查询信息 if summary['query_analysis']['original_query']: diff --git a/docs/TODO-prompts.md b/docs/TODO-prompts.md new file mode 100644 index 0000000..3cdfe44 --- /dev/null +++ b/docs/TODO-prompts.md @@ -0,0 +1,39 @@ + +1. debug信息展示方面 +在这次重构过程中，你基本上了解了从query析到 ES 搜索，再到重排的全流程。 +在这些环节中，有哪些重要的信息对搜索结果产生较大影响，先回顾，适当的完善、优化日志。 +debug_info也给前端更充分的调试信息，包括，丰富每条结果的ranking debug。目前只有这些 +Ranking Debug +spu_id +ES score +ES normalized +ES norm (rerank input): +Rerank score +Fused score +title.en +title.zh + +还不够，需要详细思考，设计一个更加完整的展示的体系 +比如： +position（重排前的，重排后最终的） +ES打分，从ES检索原始打分、相关的因子（minmax归一化的因子。到底用了哪些因子，你自己关注下，用到的要体现出来，让人知道从原始打分怎么得到的ES norm (rerank input)）。另外ES normalized，ES norm，要梳理清楚，如果代码不清晰则改代码，展示不清晰则要梳理展示。 +Rerank这一块，除了rerank_score，输入的信息比如输入的doc模板，被选中的sku及其用于辅助reranker相关性的、加到title后面的后缀 +融合公式这一块，除了fused_score，还要包含rerank_factor, text_factor, knn_factor等因子，以及text_score, knn_score, text_source_score, text_translation_score, … 等变量，要清晰的展示。 +证据 matched_queries + + +耗时记录方面： +1. Stage Timings: 为每个阶段耗时补充起止时间戳。 +2， 我看到total_search大幅度大于上面各个Stage 的总和，可能漏了一些重要的stage，比如「款式意图 SKU 预筛选（StyleSkuSelector.prepare_hits）」，补上这个stage + +但是也要注意，不要影响不带debug_info的请求的性能。 + + +2. 日志方面也需要完善 +从 query 到 ES 再到重排，对结果影响大的信息，语种检测 + index_languages，Query 向量，ES查询的构建过程中所使用的关键的变量、关键的中间结果，rerank相关信息（intput/window，query/doc 模板，融合公式的详细信息和关键的因子、输入原始值以及中间变量、到最终的融合公式的因子，Page fill，sku_filter_dimension等 + + +3. 测试用例方面 +子串匹配（Direct 阶段）是否可能产生误判 — 与尺码/短词强相关 +_is_direct_match 使用 normalized_value in query_text（见 sku_intent_selector.py）。 +词表里 l、m、s、xl，会在常见英文 query 里产生字符级子串命中，例如"l" 是否会匹配 "large …" 里的 l，注意要用分词匹配，检查分词匹配逻辑是否容易产生badcase。 diff --git a/frontend/static/js/app.js b/frontend/static/js/app.js index 82b9857..dee88e8 100644 --- a/frontend/static/js/app.js +++ b/frontend/static/js/app.js @@ -927,8 +927,14 @@ function displayDebugInfo(data) { // Stage Timings if (debugInfo.stage_timings) { html += '
Stage Timings:'; + const bounds = debugInfo.stage_time_bounds_ms || {}; for (const [stage, duration] of Object.entries(debugInfo.stage_timings)) { - html += `
${stage}: ${duration.toFixed(2)}ms
`; + const b = bounds[stage]; + if (b && b.start_unix_ms != null && b.end_unix_ms != null) { + html += `
${stage}: ${Number(duration).toFixed(2)}ms (start ${b.start_unix_ms} → end ${b.end_unix_ms} unix ms)
`; + } else { + html += `
${stage}: ${Number(duration).toFixed(2)}ms
`; + } } html += '
'; } diff --git a/search/searcher.py b/search/searcher.py index ba875f9..450c63d 100644 --- a/search/searcher.py +++ b/search/searcher.py @@ -256,13 +256,19 @@ class Searcher: parsed_query: ParsedQuery, context: Optional[RequestContext] = None, ) -> Dict[str, SkuSelectionDecision]: - decisions = self.style_sku_selector.prepare_hits(es_hits, parsed_query) - if decisions and context is not None: - context.store_intermediate_result( - "style_intent_sku_decisions", - {doc_id: decision.to_dict() for doc_id, decision in decisions.items()}, - ) - return decisions + if context is not None: + context.start_stage(RequestContextStage.STYLE_SKU_PREPARE_HITS) + try: + decisions = self.style_sku_selector.prepare_hits(es_hits, parsed_query) + if decisions and context is not None: + context.store_intermediate_result( + "style_intent_sku_decisions", + {doc_id: decision.to_dict() for doc_id, decision in decisions.items()}, + ) + return decisions + finally: + if context is not None: + context.end_stage(RequestContextStage.STYLE_SKU_PREPARE_HITS) def search( self, @@ -667,6 +673,15 @@ class Searcher: extra={'reqid': context.reqid, 'uid': context.uid} ) + # 非重排窗口：款式意图在 result_processing 之前执行，便于单独计时且与 ES 召回阶段衔接 + if self._has_style_intent(parsed_query) and not in_rerank_window: + es_hits_pre = es_response.get("hits", {}).get("hits") or [] + style_intent_decisions = self._apply_style_intent_to_hits( + es_hits_pre, + parsed_query, + context=context, + ) + # Step 5: Result processing context.start_stage(RequestContextStage.RESULT_PROCESSING) try: @@ -701,12 +716,6 @@ class Searcher: es_hits, style_intent_decisions, ) - elif not in_rerank_window: - style_intent_decisions = self._apply_style_intent_to_hits( - es_hits, - parsed_query, - context=context, - ) # Format results using ResultFormatter formatted_results = ResultFormatter.format_search_results( @@ -832,6 +841,12 @@ class Searcher: "stage_timings": { k: round(v, 2) for k, v in context.performance_metrics.stage_timings.items() }, + "stage_time_bounds_ms": { + stage: { + kk: round(vv, 3) for kk, vv in bounds.items() + } + for stage, bounds in context.performance_metrics.stage_time_bounds_ms.items() + }, "search_params": context.metadata.get('search_params', {}) } if per_result_debug: -- libgit2 0.21.2