Additional logging for the path from Search Results to LLM Context (#4387)

* added logging

* nit

* nit

backend/onyx/chat/prune_and_merge.py

@@ -153,6 +153,8 @@ def _apply_pruning(
     # remove docs that are explicitly marked as not for QA
     sections = _remove_sections_to_ignore(sections=sections)
 
+    section_idx_token_count: dict[int, int] = {}
+
     final_section_ind = None
     total_tokens = 0
     for ind, section in enumerate(sections):
@@ -202,10 +204,20 @@ def _apply_pruning(
             section_token_count = DOC_EMBEDDING_CONTEXT_SIZE
 
         total_tokens += section_token_count
+        section_idx_token_count[ind] = section_token_count
+
         if total_tokens > token_limit:
             final_section_ind = ind
             break
 
+    try:
+        logger.debug(f"Number of documents after pruning: {ind + 1}")
+        logger.debug("Number of tokens per document (pruned):")
+        for x, y in section_idx_token_count.items():
+            logger.debug(f"{x + 1}: {y}")
+    except Exception as e:
+        logger.error(f"Error logging prune statistics: {e}")
+
     if final_section_ind is not None:
         if is_manually_selected_docs or use_sections:
             if final_section_ind != len(sections) - 1:
@@ -362,6 +374,26 @@ def _merge_sections(sections: list[InferenceSection]) -> list[InferenceSection]:
         reverse=True,
     )
 
+    try:
+        num_original_sections = len(sections)
+        num_original_document_ids = len(
+            set([section.center_chunk.document_id for section in sections])
+        )
+        num_merged_sections = len(new_sections)
+        num_merged_document_ids = len(
+            set([section.center_chunk.document_id for section in new_sections])
+        )
+        logger.debug(
+            f"Merged {num_original_sections} sections from {num_original_document_ids} documents "
+            f"into {num_merged_sections} new sections in {num_merged_document_ids} documents"
+        )
+
+        logger.debug("Number of chunks per document (new ranking):")
+        for x, y in enumerate(new_sections):
+            logger.debug(f"{x + 1}: {len(y.chunks)}")
+    except Exception as e:
+        logger.error(f"Error logging merge statistics: {e}")
+
     return new_sections
 
 

backend/onyx/document_index/vespa/chunk_retrieval.py

@@ -350,6 +350,19 @@ def query_vespa(
     filtered_hits = [hit for hit in hits if hit["fields"].get(CONTENT) is not None]
 
     inference_chunks = [_vespa_hit_to_inference_chunk(hit) for hit in filtered_hits]
+
+    try:
+        num_retrieved_inference_chunks = len(inference_chunks)
+        num_retrieved_document_ids = len(
+            set([chunk.document_id for chunk in inference_chunks])
+        )
+        logger.debug(
+            f"Retrieved {num_retrieved_inference_chunks} inference chunks for {num_retrieved_document_ids} documents"
+        )
+    except Exception as e:
+        # Debug logging only, should not fail the retrieval
+        logger.error(f"Error logging retrieval statistics: {e}")
+
     # Good Debugging Spot
     return inference_chunks