Test Failing randomly

[pulphix]

Question

Hi team,

I’ve noticed that some of the documentation tests are failing intermittently. For example, yesterday several tests failed and caused the PR checks to fail, but when I re-ran the tests today without making any code changes, everything passed.

Do you have any idea what could be causing this kind of non-deterministic behavior in the doc tests?

Thanks!

Additional Context

No response

[DouweM]

@pulphix Thanks for filing the issue, I should've done so myself when I started noticing this flaky test 😅

The problem is with this example in the docs:

pydantic-ai/docs/evals.md

Lines 491 to 592 in 8e652f0

	```python {title="opentelemetry_example.py"}
	import asyncio
	from typing import Any
	import logfire
	from pydantic_evals import Case, Dataset
	from pydantic_evals.evaluators import Evaluator
	from pydantic_evals.evaluators.context import EvaluatorContext
	from pydantic_evals.otel.span_tree import SpanQuery
	logfire.configure( # ensure that an OpenTelemetry tracer is configured
	send_to_logfire='if-token-present'
	)
	class SpanTracingEvaluator(Evaluator[str, str]):
	"""Evaluator that analyzes the span tree generated during function execution."""
	def evaluate(self, ctx: EvaluatorContext[str, str]) -> dict[str, Any]:
	# Get the span tree from the context
	span_tree = ctx.span_tree
	if span_tree is None:
	return {'has_spans': False, 'performance_score': 0.0}
	# Find all spans with "processing" in the name
	processing_spans = span_tree.find(lambda node: 'processing' in node.name)
	# Calculate total processing time
	total_processing_time = sum(
	(span.duration.total_seconds() for span in processing_spans), 0.0
	)
	# Check for error spans
	error_query: SpanQuery = {'name_contains': 'error'}
	has_errors = span_tree.any(error_query)
	# Calculate a performance score (lower is better)
	performance_score = 1.0 if total_processing_time < 1.0 else 0.5
	return {
	'has_spans': True,
	'has_errors': has_errors,
	'performance_score': 0 if has_errors else performance_score,
	}
	async def process_text(text: str) -> str:
	"""Function that processes text with OpenTelemetry instrumentation."""
	with logfire.span('process_text'):
	# Simulate initial processing
	with logfire.span('text_processing'):
	await asyncio.sleep(0.1)
	processed = text.strip().lower()
	# Simulate additional processing
	with logfire.span('additional_processing'):
	if 'error' in processed:
	with logfire.span('error_handling'):
	logfire.error(f'Error detected in text: {text}')
	return f'Error processing: {text}'
	await asyncio.sleep(0.2)
	processed = processed.replace(' ', '_')
	return f'Processed: {processed}'
	# Create test cases
	dataset = Dataset(
	cases=[
	Case(
	name='normal_text',
	inputs='Hello World',
	expected_output='Processed: hello_world',
	),
	Case(
	name='text_with_error',
	inputs='Contains error marker',
	expected_output='Error processing: Contains error marker',
	),
	],
	evaluators=[SpanTracingEvaluator()],
	)
	# Run evaluation - spans are automatically captured since logfire is configured
	report = dataset.evaluate_sync(process_text)
	# Print the report
	report.print(include_input=True, include_output=True, include_durations=False) # (1)!
	"""
	Evaluation Summary: process_text
	┏━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━┓
	┃ Case ID ┃ Inputs ┃ Outputs ┃ Scores ┃ Assertions ┃
	┡━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━┩
	│ normal_text │ Hello World │ Processed: hello_world │ performance_score: 1.00 │ ✔✗ │
	├─────────────────┼───────────────────────┼─────────────────────────────────────────┼──────────────────────────┼────────────┤
	│ text_with_error │ Contains error marker │ Error processing: Contains error marker │ performance_score: 0 │ ✔✔ │
	├─────────────────┼───────────────────────┼─────────────────────────────────────────┼──────────────────────────┼────────────┤
	│ Averages │ │ │ performance_score: 0.500 │ 75.0% ✔ │
	└─────────────────┴───────────────────────┴─────────────────────────────────────────┴──────────────────────────┴────────────┘
	"""
	```

Because the output depends on timing, the test_docs_examples test will sometimes fail when the output comes out differently:

--- before
  +++ after
  @@ -582,505 +582,505 @@
   """
                                                 Evaluation Summary: process_text
   ┏━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━━━━━━━━━━━━━━━┳━━━━━━━━━━━━┓
   ┃ Case ID         ┃ Inputs                ┃ Outputs                                 ┃ Scores                   ┃ Assertions ┃
   ┡━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━━━━━━━━━━━━━━━╇━━━━━━━━━━━━┩
  -│ normal_text     │ Hello World           │ Processed: hello_world                  │ performance_score: 1.00  │ ✔✗         │
  +│ normal_text     │ Hello World           │ Processed: hello_world                  │ performance_score: 0.500 │ ✔✗         │
   ├─────────────────┼───────────────────────┼─────────────────────────────────────────┼──────────────────────────┼────────────┤
   │ text_with_error │ Contains error marker │ Error processing: Contains error marker │ performance_score: 0     │ ✔✔         │
   ├─────────────────┼───────────────────────┼─────────────────────────────────────────┼──────────────────────────┼────────────┤
  -│ Averages        │                       │                                         │ performance_score: 0.500 │ 75.0% ✔    │
  +│ Averages        │                       │                                         │ performance_score: 0.250 │ 75.0% ✔    │
   └─────────────────┴───────────────────────┴─────────────────────────────────────────┴──────────────────────────┴────────────┘
   """

I already tweaked the timing requirement once before in #1938, but I'm guessing it's fine to do it again -- it's just an example anyway.