from logging import log
from vespa.package import Field, RankProfile, FirstPhaseRanking
%load_ext autoreload
%autoreload 2
import json
import mycode.vap as vap
import mycode.trace as trace# The goal is to have a demo application that has 10M docs
# - numeric field like timestamp in second granularity with fast-search
# - numeric field like timestamp in second granularity witout fast-search
# - numeric field with hour granularity with fast-search
# - numeric field with daily granularity with fast-search
# - single dimension embedding field for the nearestNeighbor search
# - field string type for weakAnd
# Show that a when using a field with high cardinality, the posting list preparation time is astronomical.
# Show that when using rounded timestamp the postling list preparation is tamed.
# Show that when (rounded_timestamp > X) AND (precise_timestamp > X) AND NN, then the query is super slow
# Show that (rounded_timestamp > X) AND (precise_timestamp_with_fast_search > X) just adds the posting list preparation time with no benefit for the queryapp = vap.demo_application_package()from vespa.package import Field
from vespa.package import QueryTypeField, QueryProfileType
app.get_schema("doc").add_fields(
Field(
name="timestamp_second_nofs",
type="int",
indexing="attribute",
# no fast search
),
Field(
name="timestamp_second",
type="int",
indexing="attribute",
attribute=["fast-search"],
),
Field(
name="timestamp_hour",
type="int",
indexing="attribute",
attribute=["fast-search"],
),
Field(
name="timestamp_day",
type="int",
indexing="attribute",
attribute=["fast-search"],
),
Field(
name="embedding",
type="tensor<float>(x[1])",
indexing="attribute"
),
Field(
name="lexical",
type="string",
indexing="index",
index="enable-bm25"
),
)
app.query_profile_type = QueryProfileType(
fields=[
QueryTypeField(
name="ranking.features.query(query_embedding)",
type="tensor<float>(x[1])"
)
]
)
app.get_schema("doc").rank_profiles.pop("fields")RankProfile('fields', '0', 'unranked', None, [Function('id', 'attribute(id)', None)], ['id'], ['id'], None, None, None, None, None, None, None, None, None, None, None)print(app.get_schema("doc").schema_to_text)schema doc {
document doc {
field id type int {
indexing: attribute
attribute {
fast-search
}
}
field timestamp_second_nofs type int {
indexing: attribute
}
field timestamp_second type int {
indexing: attribute
attribute {
fast-search
}
}
field timestamp_hour type int {
indexing: attribute
attribute {
fast-search
}
}
field timestamp_day type int {
indexing: attribute
attribute {
fast-search
}
}
field embedding type tensor<float>(x[1]) {
indexing: attribute
}
field lexical type string {
indexing: index
index: enable-bm25
}
}
}
from vespa.deployment import VespaDocker
# In case running colima on macos run the following
# !sudo ln -sf $HOME/.colima/default/docker.sock /var/run/docker.sock
vespa_docker = VespaDocker(
container_image="vespaengine/vespa:8.672.3",
)
# Start a docker container and deploy the application package
client = vespa_docker.deploy(
application_package=app,
)Waiting for configuration server, 0/60 seconds...
Waiting for configuration server, 5/60 seconds...
Application is up!
Finished deployment.
from vespa.application import Vespa
client = Vespa(url="http://localhost", port=8080)from vespa.package import RankProfile, FirstPhaseRanking
app.get_schema("doc").add_rank_profile(RankProfile(
name="minimal",
first_phase=FirstPhaseRanking(expression="1", keep_rank_count=1),
))
vap.redeploy(vespa_docker, app)Deploy status code: 200
Vespa(http://localhost, 8080)from vespa.io import VespaResponse
import random
import datetime
def simulate_text():
"""
Pics a random number of words from random numbers from 0 to 30000.
Joins them in to a string.
:return:
"""
dictionary_size = 30001
num_words = random.randint(1, 20)
return " ".join(map(lambda n: str(n), random.sample(range(dictionary_size), num_words)))
def simulate_embedding():
"""
Random float number between 0 and 1.
:return:
"""
return [random.uniform(0, 1)]
def shuf_range(start, end):
"""
Generate a bunch of item ids, shuffle them, so that feeding is faster.
:param start:
:param end:
:return:
"""
numbers = list(range(start, end))
random.shuffle(numbers)
return numbers
def get_timestamp():
"""
current timestamp in seconds as integer
:return:
"""
return int(datetime.datetime.now().timestamp())
def round_to_hours(timestamp):
"""
Get first second of the hour
:param timestamp:
:return:
"""
return int(timestamp / 3600) * 3600
def round_to_days(timestamp):
"""
Get first second of the day
:param timestamp:
:return:
"""
return int(timestamp / (3600 * 24)) * (3600 * 24)
def feed_call_back_with_progress(n=100000):
cnt = 0
def callback(response: VespaResponse, document_id: str):
nonlocal cnt
cnt += 1
if (cnt % n) == 0:
print(f"{datetime.datetime.now().isoformat()}: Already fed: {cnt} docs")
if not response.is_successful():
print(f"Error when feeding document {document_id}: {response.get_json()}")
return callback
def interval_first_second(ts, interval_seconds=1):
return (int(ts / interval_seconds) * interval_seconds)
def interval_last_second(ts, interval_seconds=1):
return (int(ts / interval_seconds) * interval_seconds) + interval_seconds
def range_filter(start: int = None, end: int = None, field="timestamp_second", interval_seconds=1):
if (start is not None) and (end is not None):
return f'{field} >= {interval_first_second(start, interval_seconds)} AND {field} <= {interval_last_second(end, interval_seconds)}'
elif (start is not None) and (end is None):
return f'{field} >= {interval_first_second(start, interval_seconds)}'
elif (start is None) and (end is not None):
return f'{field} <= {interval_last_second(end, interval_seconds)}'
else:
return ''ts = get_timestamp()
start = interval_first_second(ts, 3600)
end = interval_last_second(ts, 3600)
print(datetime.datetime.fromtimestamp(ts).isoformat(), datetime.datetime.fromtimestamp(start).isoformat(),
datetime.datetime.fromtimestamp(end).isoformat())
# EXAMPLE ON HOT TO USE rounded range filter
range_filter(get_timestamp(), get_timestamp() + 1, interval_seconds=3600)2026-04-20T17:05:29 2026-04-20T17:00:00 2026-04-20T18:00:00
'timestamp_second >= 1776693600 AND timestamp_second <= 1776697200'amount_of_docs = 10_000_000 # around four months every second
ids = shuf_range(get_timestamp(), get_timestamp() + amount_of_docs)
print("generated doc ids")
vap.feed(
client=client,
docs=(
{
"timestamp_second_nofs": i,
"timestamp_second": i,
"timestamp_hour": round_to_hours(i),
"timestamp_day": round_to_days(i),
"embedding": simulate_embedding(),
"lexical": simulate_text()
} for i in ids),
feed_callback=feed_call_back_with_progress(10000)
)def yql_base(field):
return f"""
select *
from sources *
where
({field} > {get_timestamp()})
"""
def request(field="timestamp_second"):
return {
"yql": yql_base(field),
"query_str": "27110 6334 10140 22335 22040 2716",
"input.query(query_embedding)": [0.5],
"presentation.timing": True,
"hits": 1,
"timeout": "5s",
"ranking.profile": "unranked",
}resp_no_filters = client.query(body=trace.add_trace(request("timestamp_second"))).json
print(trace.get_breakdown(trace.inspect_trace(resp_no_filters)))looking into node doc[0]
┌────────────┬─────────────────────────────────────────────────────────────┐
│ timestamp │ event │
├────────────┼─────────────────────────────────────────────────────────────┤
│ 0.192 ms │ searching for 1 hits at offset 0 │
│ 0.235 ms │ Start query setup │
│ 0.240 ms │ Deserialize and build query tree │
│ 0.250 ms │ Build query execution plan │
│ 0.384 ms │ Optimize query execution plan │
│ 0.413 ms │ Perform dictionary lookups and posting lists initialization │
│ 364.680 ms │ Prepare shared state for multi-threaded rank executors │
│ 364.689 ms │ Complete query setup │
│ │ (query execution happens here, analyzed below) │
│ 986.970 ms │ returning 1 hits from total 6453248 │
└────────────┴─────────────────────────────────────────────────────────────┘
resp_no_filters_no_trace = client.query(body=request("timestamp_second")).json
print(resp_no_filters_no_trace['timing']){'querytime': 0.398, 'searchtime': 0.399, 'summaryfetchtime': 0.0}
# the timing matches: ~364 ms for posting lists, and some time spend in `unranked` ranking profileprint(yql_base("timestamp_second"))
select *
from sources *
where
(timestamp_second > 1776678426)
# the dictionary lookup is 338ms for the second granularityresp_no_filters = client.query(body=request("timestamp_second")).json
resp_no_filters['timing']{'querytime': 0.374, 'searchtime': 0.375, 'summaryfetchtime': 0.0}timestamp_hour = client.query(body=trace.add_trace(request("timestamp_hour"))).json
print(trace.get_breakdown(trace.inspect_trace(timestamp_hour)))looking into node doc[0]
┌────────────┬─────────────────────────────────────────────────────────────┐
│ timestamp │ event │
├────────────┼─────────────────────────────────────────────────────────────┤
│ 0.173 ms │ searching for 1 hits at offset 0 │
│ 0.207 ms │ Start query setup │
│ 0.209 ms │ Deserialize and build query tree │
│ 0.223 ms │ Build query execution plan │
│ 0.465 ms │ Optimize query execution plan │
│ 0.480 ms │ Perform dictionary lookups and posting lists initialization │
│ 36.842 ms │ Prepare shared state for multi-threaded rank executors │
│ 36.851 ms │ Complete query setup │
│ │ (query execution happens here, analyzed below) │
│ 835.919 ms │ returning 1 hits from total 9630948 │
└────────────┴─────────────────────────────────────────────────────────────┘
# hourly, 34 ms. better,# Hourly without tracing
timestamp_hour_no_trace = client.query(body=request("timestamp_hour")).json
print(trace.inspect_trace(timestamp_hour_no_trace))┌─────────┬───────────┐
│ total │ 95.000 ms │
├─────────┼───────────┤
│ query │ 94.000 ms │
│ summary │ 0.000 ms │
│ other │ 1.000 ms │
└─────────┴───────────┘
# Much better, only 95 ms, down from, 0.398 s. 4x improvementtimestamp_day = client.query(body=trace.add_trace(request("timestamp_day"))).json
print(trace.get_breakdown(trace.inspect_trace(timestamp_day)))looking into node doc[0]
┌────────────┬─────────────────────────────────────────────────────────────┐
│ timestamp │ event │
├────────────┼─────────────────────────────────────────────────────────────┤
│ 0.104 ms │ searching for 1 hits at offset 0 │
│ 0.129 ms │ Start query setup │
│ 0.130 ms │ Deserialize and build query tree │
│ 0.151 ms │ Build query execution plan │
│ 0.185 ms │ Optimize query execution plan │
│ 0.193 ms │ Perform dictionary lookups and posting lists initialization │
│ 34.783 ms │ Prepare shared state for multi-threaded rank executors │
│ 34.791 ms │ Complete query setup │
│ │ (query execution happens here, analyzed below) │
│ 986.984 ms │ returning 1 hits from total 9599005 │
└────────────┴─────────────────────────────────────────────────────────────┘
# somewhat faster but very littletimestamp_day_no_trace = client.query(body=request("timestamp_day")).json
print(trace.inspect_trace(timestamp_day_no_trace))┌─────────┬───────────┐
│ total │ 94.000 ms │
├─────────┼───────────┤
│ query │ 94.000 ms │
│ summary │ 0.000 ms │
│ other │ 0.000 ms │
└─────────┴───────────┘
# ~No difference between hourly and dailytimestamp_second_nofs = client.query(body=trace.add_trace(request("timestamp_second_nofs"))).json
print(trace.inspect_trace(timestamp_second_nofs))┌─────────┬─────────────┐
│ total │ 2514.000 ms │
├─────────┼─────────────┤
│ query │ 2509.000 ms │
│ summary │ 3.000 ms │
│ other │ 2.000 ms │
└─────────┴─────────────┘
found 1 search
┌────────┬───────┬───────────────┬───────────────┐
│ search │ nodes │ back-end time │ document type │
├────────┼───────┼───────────────┼───────────────┤
│ 0 │ 1 │ 2490.693 ms │ doc │
└────────┴───────┴───────────────┴───────────────┘
looking into search #0
slowest node was: doc[0]: 2490.693 ms
┌───────────────┬─────────────┐
│ task │ doc[0] │
├───────────────┼─────────────┤
│ global filter │ 0.000 ms │
│ ann setup │ 0.000 ms │
│ matching │ 1845.959 ms │
│ first phase │ 0.000 ms │
│ second phase │ 0.000 ms │
└───────────────┴─────────────┘
looking into node doc[0]
┌─────────────┬─────────────────────────────────────────────────────────────┐
│ timestamp │ event │
├─────────────┼─────────────────────────────────────────────────────────────┤
│ 0.557 ms │ searching for 1 hits at offset 0 │
│ 0.742 ms │ Start query setup │
│ 0.756 ms │ Deserialize and build query tree │
│ 0.853 ms │ Build query execution plan │
│ 1.086 ms │ Optimize query execution plan │
│ 1.171 ms │ Perform dictionary lookups and posting lists initialization │
│ 1.173 ms │ Prepare shared state for multi-threaded rank executors │
│ 1.233 ms │ Complete query setup │
│ │ (query execution happens here, analyzed below) │
│ 2490.683 ms │ returning 1 hits from total 9651290 │
└─────────────┴─────────────────────────────────────────────────────────────┘
found 1 thread
slowest matching and ranking was thread #0: 1845.959 ms
┌──────────────┬─────────────┐
│ task │ thread #0 │
├──────────────┼─────────────┤
│ matching │ 1845.959 ms │
│ first phase │ 0.000 ms │
│ second phase │ 0.000 ms │
└──────────────┴─────────────┘
looking into thread #0
┌─────────────┬──────────────────────────────────┐
│ timestamp │ event │
├─────────────┼──────────────────────────────────┤
│ 1.510 ms │ Start MatchThread::run │
│ 4.974 ms │ Start match and first phase rank │
│ 2490.251 ms │ Create result set │
│ 2490.299 ms │ Wait for result processing token │
│ 2490.346 ms │ Start result processing │
│ 2490.359 ms │ Start thread merge │
│ 2490.359 ms │ MatchThread::run Done │
└─────────────┴──────────────────────────────────┘
match profiling for thread #0 (total time was 1845.959 ms)
┌─────────┬──────────┬──────────┬──────┬────────────────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├─────────┼──────────┼──────────┼──────┼────────────────────────────────────────────────────────────────┤
│ 9651291 │ 1845.959 │ 1114.880 │ S │ And[1] │
│ 9651291 │ 431.204 │ 431.204 │ S │ ├── Attribute{int32,lookup}[2] timestamp_second_nofs:<range> │
│ 9651291 │ 299.875 │ 299.875 │ N │ └── WhiteList[3] │
└─────────┴──────────┴──────────┴──────┴────────────────────────────────────────────────────────────────┘
first phase rank profiling for thread #0 (total time was 0.000 ms)
┌───────┬─────────┬───────────────────────┐
│ count │ self_ms │ component │
├───────┼─────────┼───────────────────────┤
│ 1 │ 0.000 │ rank feature value(0) │
└───────┴─────────┴───────────────────────┘
# no tracing overhead
timestamp_second_nofs_no_trace = client.query(body=request("timestamp_second_nofs")).json
print(trace.inspect_trace(timestamp_second_nofs_no_trace))┌─────────┬───────────┐
│ total │ 73.000 ms │
├─────────┼───────────┤
│ query │ 72.000 ms │
│ summary │ 0.000 ms │
│ other │ 1.000 ms │
└─────────┴───────────┘
# Shocking result: without fast-search the query is even faster: 83 vs 95 ms.print(trace.get_matching_summary(trace.inspect_trace(timestamp_second_nofs)))match profiling for thread #0 (total time was 1702.365 ms)
┌─────────┬──────────┬──────────┬──────┬────────────────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├─────────┼──────────┼──────────┼──────┼────────────────────────────────────────────────────────────────┤
│ 9655613 │ 1702.365 │ 1105.527 │ S │ And[1] │
│ 9655613 │ 300.645 │ 300.645 │ S │ ├── Attribute{int32,lookup}[2] timestamp_second_nofs:<range> │
│ 9655612 │ 296.193 │ 296.193 │ N │ └── WhiteList[3] │
└─────────┴──────────┴──────────┴──────┴────────────────────────────────────────────────────────────────┘
# ^ the overhead of the tracing dominates: instead of 83 ms without tracing, we get 2514 ms# no tracing overhead, just 1 M docs
timestamp_second_nofs_no_trace = client.query(body={
**request("timestamp_second_nofs"),
"yql": f"""
select *
from sources *
where
(timestamp_second_nofs > {get_timestamp() + 8000000} AND timestamp_second_nofs < {get_timestamp() + 9000000})
""",
"ranking.profile": "minimal",
}).json
print(trace.inspect_trace(timestamp_second_nofs_no_trace))┌─────────┬───────────┐
│ total │ 72.000 ms │
├─────────┼───────────┤
│ query │ 71.000 ms │
│ summary │ 0.000 ms │
│ other │ 1.000 ms │
└─────────┴───────────┘
# with just 1M docs to find is is well under 100 ms.# no tracing overhead, just 1 M docs
timestamp_second_nofs_no_trace = client.query(body={
**request("timestamp_second_nofs"),
"yql": f"""
select *
from sources *
where
(timestamp_second_nofs > {get_timestamp() + 8000000} AND timestamp_second_nofs < {get_timestamp() + 9000000})
""",
"ranking.profile": "minimal",
"ranking.matchPhase.attribute": "timestamp_second",
"ranking.matchPhase.totalMaxHits": 10000,
}).json
print(trace.inspect_trace(timestamp_second_nofs_no_trace))┌─────────┬───────────┐
│ total │ 67.000 ms │
├─────────┼───────────┤
│ query │ 67.000 ms │
│ summary │ 0.000 ms │
│ other │ 0.000 ms │
└─────────┴───────────┘
#range_filter(get_timestamp(), get_timestamp() + 1, interval_seconds=3600)field = "timestamp_second_nofs"
interval_seconds = 1
docs_count = 84_000_000
range_query = range_filter(get_timestamp() + 1000000, get_timestamp() + docs_count, field=field,
interval_seconds=interval_seconds)
print(range_query)
print(trace.inspect_trace(client.query(body={
**request(field),
"yql": f"""
select *
from sources *
where
{range_query}
""",
"ranking.profile": "minimal",
}).json))timestamp_second_nofs >= 1777695953 AND timestamp_second_nofs <= 1860695954
┌─────────┬────────────┐
│ total │ 345.000 ms │
├─────────┼────────────┤
│ query │ 337.000 ms │
│ summary │ 2.000 ms │
│ other │ 6.000 ms │
└─────────┴────────────┘
# closed range; second granularity
field = "timestamp_second"
interval_seconds = 1
docs_count = 8_000_000
range_query = range_filter(get_timestamp(), get_timestamp() + docs_count, field=field,
interval_seconds=interval_seconds)
print(range_query)
print(trace.inspect_trace(client.query(body={
**request(field),
"yql": f"""
select *
from sources *
where
{range_query}
""",
"ranking.profile": "minimal",
}).json))timestamp_second >= 1776695918 AND timestamp_second <= 1784695919
┌─────────┬────────────┐
│ total │ 545.000 ms │
├─────────┼────────────┤
│ query │ 544.000 ms │
│ summary │ 0.000 ms │
│ other │ 1.000 ms │
└─────────┴────────────┘
field = "timestamp_hour"
interval_seconds = 3600
docs_count = 8_000_000
range_query = range_filter(get_timestamp(), get_timestamp() + docs_count, field=field,
interval_seconds=interval_seconds)
print(range_query)
print(trace.inspect_trace(client.query(body={
**request(field),
"yql": f"""
select *
from sources *
where
{range_query}
""",
"ranking.profile": "minimal",
}).json))timestamp_hour >= 1776693600 AND timestamp_hour <= 1784696400
┌─────────┬────────────┐
│ total │ 309.000 ms │
├─────────┼────────────┤
│ query │ 307.000 ms │
│ summary │ 1.000 ms │
│ other │ 1.000 ms │
└─────────┴────────────┘
# Inverted condition, even worse
field = "timestamp_hour"
interval_seconds = 3600
docs_count = 8_000_000
range_query = range_filter(get_timestamp(), get_timestamp() + docs_count, field=field,
interval_seconds=interval_seconds)
print(range_query)
print(trace.inspect_trace(client.query(body={
**request(field),
"yql": f"""
select *
from sources *
where
!({field} < {get_timestamp()} OR ({field} > {get_timestamp() + docs_count}))
""",
"ranking.profile": "minimal",
}).json))timestamp_hour >= 1776693600 AND timestamp_hour <= 1784696400
┌─────────┬────────────┐
│ total │ 367.000 ms │
├─────────┼────────────┤
│ query │ 364.000 ms │
│ summary │ 1.000 ms │
│ other │ 2.000 ms │
└─────────┴────────────┘
field = "timestamp_hour"
interval_seconds = 3600
docs_count = 8_000_000
range_query = range_filter(get_timestamp(), get_timestamp() + docs_count, field=field,
interval_seconds=interval_seconds)
range_query_nofs = range_filter(get_timestamp(), get_timestamp() + docs_count, field="timestamp_second_nofs",
interval_seconds=1)
print(range_query, range_query_nofs)
print(trace.inspect_trace(client.query(body={
**request(field),
"yql": f"""
select *
from sources *
where
({range_query})
AND
({range_query_nofs})
""",
"ranking.profile": "minimal",
}).json))timestamp_hour >= 1776693600 AND timestamp_hour <= 1784696400 timestamp_second_nofs >= 1776695968 AND timestamp_second_nofs <= 1784695969
┌─────────┬────────────┐
│ total │ 342.000 ms │
├─────────┼────────────┤
│ query │ 341.000 ms │
│ summary │ 0.000 ms │
│ other │ 1.000 ms │
└─────────┴────────────┘
# with trace
field = "timestamp_hour"
interval_seconds = 3600
docs_count = 8_000_000
range_query = range_filter(get_timestamp(), get_timestamp() + docs_count, field=field,
interval_seconds=interval_seconds)
range_query_nofs = range_filter(get_timestamp(), get_timestamp() + docs_count, field="timestamp_second_nofs",
interval_seconds=1)
print(range_query, range_query_nofs)
print(trace.inspect_trace(client.query(body=trace.add_trace({
**request(field),
"yql": f"""
select *
from sources *
where
({range_query})
AND
({range_query_nofs})
""",
"ranking.profile": "minimal",
})).json))timestamp_hour >= 1776693600 AND timestamp_hour <= 1784696400 timestamp_second_nofs >= 1776695978 AND timestamp_second_nofs <= 1784695979
┌─────────┬─────────────┐
│ total │ 2472.000 ms │
├─────────┼─────────────┤
│ query │ 2471.000 ms │
│ summary │ 0.000 ms │
│ other │ 1.000 ms │
└─────────┴─────────────┘
found 1 search
┌────────┬───────┬───────────────┬───────────────┐
│ search │ nodes │ back-end time │ document type │
├────────┼───────┼───────────────┼───────────────┤
│ 0 │ 1 │ 2468.669 ms │ doc │
└────────┴───────┴───────────────┴───────────────┘
looking into search #0
slowest node was: doc[0]: 2468.669 ms
┌───────────────┬─────────────┐
│ task │ doc[0] │
├───────────────┼─────────────┤
│ global filter │ 0.000 ms │
│ ann setup │ 0.000 ms │
│ matching │ 1558.031 ms │
│ first phase │ 0.001 ms │
│ second phase │ 0.000 ms │
└───────────────┴─────────────┘
looking into node doc[0]
┌─────────────┬─────────────────────────────────────────────────────────────┐
│ timestamp │ event │
├─────────────┼─────────────────────────────────────────────────────────────┤
│ 0.157 ms │ searching for 1 hits at offset 0 │
│ 0.197 ms │ Start query setup │
│ 0.199 ms │ Deserialize and build query tree │
│ 0.212 ms │ Build query execution plan │
│ 0.325 ms │ Optimize query execution plan │
│ 0.335 ms │ Perform dictionary lookups and posting lists initialization │
│ 31.703 ms │ Prepare shared state for multi-threaded rank executors │
│ 31.712 ms │ Complete query setup │
│ │ (query execution happens here, analyzed below) │
│ 2468.665 ms │ returning 1 hits from total 7447309 │
└─────────────┴─────────────────────────────────────────────────────────────┘
found 1 thread
slowest matching and ranking was thread #0: 1558.032 ms
┌──────────────┬─────────────┐
│ task │ thread #0 │
├──────────────┼─────────────┤
│ matching │ 1558.031 ms │
│ first phase │ 0.001 ms │
│ second phase │ 0.000 ms │
└──────────────┴─────────────┘
looking into thread #0
┌─────────────┬──────────────────────────────────┐
│ timestamp │ event │
├─────────────┼──────────────────────────────────┤
│ 31.839 ms │ Start MatchThread::run │
│ 31.946 ms │ Start match and first phase rank │
│ 2468.373 ms │ Create result set │
│ 2468.389 ms │ Wait for result processing token │
│ 2468.426 ms │ Start result processing │
│ 2468.431 ms │ Start thread merge │
│ 2468.431 ms │ MatchThread::run Done │
└─────────────┴──────────────────────────────────┘
match profiling for thread #0 (total time was 1558.031 ms)
┌─────────┬──────────┬──────────┬──────┬────────────────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├─────────┼──────────┼──────────┼──────┼────────────────────────────────────────────────────────────────┤
│ 7447310 │ 1558.031 │ 1081.994 │ S │ And[1] │
│ 7453241 │ 121.848 │ 121.848 │ S │ ├── Attribute{int32,fs}[2] timestamp_hour:<range> │
│ 7453241 │ 232.342 │ 232.342 │ N │ ├── Attribute{int32,lookup}[3] timestamp_second_nofs:<range> │
│ 7453241 │ 121.847 │ 121.847 │ N │ └── WhiteList[4] │
└─────────┴──────────┴──────────┴──────┴────────────────────────────────────────────────────────────────┘
first phase rank profiling for thread #0 (total time was 0.001 ms)
┌───────┬─────────┬─────────────────────┐
│ count │ self_ms │ component │
├───────┼─────────┼─────────────────────┤
│ 1 │ 0.001 │ function firstphase │
└───────┴─────────┴─────────────────────┘
1081.994 + 121.848 + 232.342 + 121.8471558.031# Now let's combine the hourly matching with second level matching _nofs
# AND timestamp_second_nofs > {get_timestamp()}
# AND timestamp_second_nofs < {get_timestamp() + 5000000}
combined = client.query(body={
**trace.add_trace(request("timestamp_second_nofs")),
"yql": f"""
select *
from sources *
where
(timestamp_hour >= {get_timestamp()} )
AND (timestamp_hour <= {get_timestamp() + 1000000})
AND ({{targetHits: 1000, approximate: false}}
nearestNeighbor(embedding, query_embedding))
""",
"ranking.profile": "minimal",
}).json
print(trace.inspect_trace(combined))┌─────────┬────────────┐
│ total │ 159.000 ms │
├─────────┼────────────┤
│ query │ 158.000 ms │
│ summary │ 0.000 ms │
│ other │ 1.000 ms │
└─────────┴────────────┘
found 1 search
┌────────┬───────┬───────────────┬───────────────┐
│ search │ nodes │ back-end time │ document type │
├────────┼───────┼───────────────┼───────────────┤
│ 0 │ 1 │ 155.336 ms │ doc │
└────────┴───────┴───────────────┴───────────────┘
looking into search #0
slowest node was: doc[0]: 155.336 ms
┌───────────────┬────────────┐
│ task │ doc[0] │
├───────────────┼────────────┤
│ global filter │ 0.000 ms │
│ ann setup │ 0.000 ms │
│ matching │ 150.128 ms │
│ first phase │ 0.001 ms │
│ second phase │ 0.000 ms │
└───────────────┴────────────┘
looking into node doc[0]
┌────────────┬─────────────────────────────────────────────────────────────┐
│ timestamp │ event │
├────────────┼─────────────────────────────────────────────────────────────┤
│ 0.097 ms │ searching for 1 hits at offset 0 │
│ 0.150 ms │ Start query setup │
│ 0.152 ms │ Deserialize and build query tree │
│ 0.164 ms │ Build query execution plan │
│ 0.225 ms │ Optimize query execution plan │
│ 0.233 ms │ Perform dictionary lookups and posting lists initialization │
│ 3.964 ms │ Prepare shared state for multi-threaded rank executors │
│ 3.970 ms │ Complete query setup │
│ │ (query execution happens here, analyzed below) │
│ 155.333 ms │ returning 1 hits from total 7907 │
└────────────┴─────────────────────────────────────────────────────────────┘
ann query details (total setup time was 0.000 ms)
┌─────────────────────────┬─────────────────────┐
│ property │ details │
├─────────────────────────┼─────────────────────┤
│ attribute tensor │ tensor<float>(x[1]) │
│ query tensor │ tensor<float>(x[1]) │
│ target hits │ 1000 │
│ explore additional hits │ 0 │
│ algorithm │ exact │
│ global filter │ not calculated │
│ lazy filter │ not constructed │
└─────────────────────────┴─────────────────────┘
found 1 thread
slowest matching and ranking was thread #0: 150.129 ms
┌──────────────┬────────────┐
│ task │ thread #0 │
├──────────────┼────────────┤
│ matching │ 150.128 ms │
│ first phase │ 0.001 ms │
│ second phase │ 0.000 ms │
└──────────────┴────────────┘
looking into thread #0
┌────────────┬──────────────────────────────────┐
│ timestamp │ event │
├────────────┼──────────────────────────────────┤
│ 4.010 ms │ Start MatchThread::run │
│ 4.045 ms │ Start match and first phase rank │
│ 155.201 ms │ Create result set │
│ 155.222 ms │ Wait for result processing token │
│ 155.223 ms │ Start result processing │
│ 155.245 ms │ Start thread merge │
│ 155.245 ms │ MatchThread::run Done │
└────────────┴──────────────────────────────────┘
match profiling for thread #0 (total time was 150.128 ms)
┌─────────┬──────────┬─────────┬──────┬─────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├─────────┼──────────┼─────────┼──────┼─────────────────────────────────────────────────────┤
│ 7908 │ 150.128 │ 72.665 │ S │ And[1] │
│ 1000801 │ 14.899 │ 14.899 │ S │ ├── Attribute{int32,fs}[2] timestamp_hour:<range> │
│ 1000801 │ 14.899 │ 14.898 │ N │ ├── WhiteList[3] │
│ 1000800 │ 47.666 │ 47.666 │ N │ └── NearestNeighbor[4] │
└─────────┴──────────┴─────────┴──────┴─────────────────────────────────────────────────────┘
first phase rank profiling for thread #0 (total time was 0.001 ms)
┌───────┬─────────┬─────────────────────┐
│ count │ self_ms │ component │
├───────┼─────────┼─────────────────────┤
│ 1 │ 0.001 │ function firstphase │
└───────┴─────────┴─────────────────────┘
#Hour
match
profiling
for thread #0 (total time was 187.187 ms)
┌─────────┬──────────┬─────────┬──────┬─────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query
tree │
├─────────┼──────────┼─────────┼──────┼─────────────────────────────────────────────────────┤
│ 7965 │ 187.187 │ 70.540 │ S │ And[1] │
│ 1000801 │ 15.177 │ 15.177 │ S │ ├── Attribute
{int32, fs}[2]
timestamp_hour: < range > │
│ 1000801 │ 15.176 │ 15.176 │ N │ ├── WhiteList[3] │
│ 1000800 │ 86.294 │ 86.294 │ N │ └── NearestNeighbor[4] │
└─────────┴──────────┴─────────┴──────┴─────────────────────────────────────────────────────┘
#day
match
profiling
for thread #0 (total time was 158.239 ms)
┌─────────┬──────────┬─────────┬──────┬────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query
tree │
├─────────┼──────────┼─────────┼──────┼────────────────────────────────────────────────────┤
│ 7967 │ 158.239 │ 75.667 │ S │ And[1] │
│ 1036801 │ 16.031 │ 16.030 │ S │ ├── Attribute
{int32, fs}[2]
timestamp_day: < range > │
│ 1036801 │ 16.030 │ 16.030 │ N │ ├── WhiteList[3] │
│ 1036800 │ 50.512 │ 50.512 │ N │ └── NearestNeighbor[4] │
└─────────┴──────────┴─────────┴──────┴────────────────────────────────────────────────────┘
# second
┌─────────┬──────────┬─────────┬──────┬───────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query
tree │
├─────────┼──────────┼─────────┼──────┼───────────────────────────────────────────────────────┤
│ 7966 │ 159.081 │ 76.350 │ S │ And[1] │
│ 1000002 │ 15.992 │ 15.992 │ S │ ├── Attribute
{int32, fs}[2]
timestamp_second: < range > │
│ 1000002 │ 15.992 │ 15.991 │ N │ ├── WhiteList[3] │
│ 1000001 │ 50.748 │ 50.748 │ N │ └── NearestNeighbor[4] │
└─────────┴──────────┴─────────┴──────┴───────────────────────────────────────────────────────┘
nofs
match
profiling
for thread #0 (total time was 232.227 ms)
┌─────────┬──────────┬─────────┬──────┬────────────────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query
tree │
├─────────┼──────────┼─────────┼──────┼────────────────────────────────────────────────────────────────┤
│ 7966 │ 232.227 │ 109.561 │ S │ And[1] │
│ 1000002 │ 42.270 │ 42.270 │ S │ ├── Attribute
{int32, lookup}[2]
timestamp_second_nofs: < range > │
│ 1000001 │ 30.292 │ 30.292 │ N │ ├── WhiteList[3] │
│ 1000001 │ 50.104 │ 50.104 │ N │ └── NearestNeighbor[4] │
└─────────┴──────────┴─────────┴──────┴────────────────────────────────────────────────────────────────┘ Cell In[143], line 3
┌─────────┬──────────┬─────────┬──────┬─────────────────────────────────────────────────────┐
^
SyntaxError: invalid character '┌' (U+250C)
# Simply match on the second level
### SLOW VERSION no trace
baseline_grouped_filters = f"""
SELECT *
FROM sources *
WHERE
(timestamp_second >= {get_timestamp()})
AND
(timestamp_second <= {get_timestamp() + 3000000})
"""
baseline_grouped_request = {
**request("timestamp_second_nofs"),
"yql": baseline_grouped_filters,
"ranking.profile": "minimal",
"hits": 100,
}
baseline_grouped_response = client.query(body=baseline_grouped_request).json
print(trace.inspect_trace(baseline_grouped_response))┌─────────┬────────────┐
│ total │ 190.000 ms │
├─────────┼────────────┤
│ query │ 189.000 ms │
│ summary │ 0.000 ms │
│ other │ 1.000 ms │
└─────────┴────────────┘
print(baseline_grouped_filters)
SELECT *
FROM sources *
WHERE
(timestamp_second >= 1776717390)
AND
(timestamp_second <= 1779717390)
baseline_grouped_trace = client.query(body=trace.add_trace(baseline_grouped_request)).json
print(trace.get_matching_summary(trace.inspect_trace(baseline_grouped_trace)))match profiling for thread #0 (total time was 162.841 ms)
┌─────────┬──────────┬─────────┬──────┬───────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├─────────┼──────────┼─────────┼──────┼───────────────────────────────────────────────────────┤
│ 3000002 │ 54.280 │ 54.280 │ S │ And[1] │
│ 3000002 │ 54.281 │ 54.281 │ S │ ├── Attribute{int32,fs}[2] timestamp_second:<range> │
│ 3000002 │ 54.280 │ 54.280 │ N │ └── WhiteList[3] │
└─────────┴──────────┴─────────┴──────┴───────────────────────────────────────────────────────┘
### SLOW VERSION no trace
non_grouped_filters = f"""
SELECT *
FROM sources *
WHERE
(
(timestamp_hour >= {get_timestamp()})
AND
(timestamp_second_nofs > {get_timestamp() + 100})
)
AND
(
(timestamp_hour <= {get_timestamp() + 3000000})
AND
(timestamp_second_nofs < {get_timestamp() + 3000000 - 100})
)
"""
non_grouped_request = {
**request("timestamp_second_nofs"),
"yql": non_grouped_filters,
"ranking.profile": "minimal",
"hits": 100,
}
combined = client.query(body=non_grouped_request).json
print(trace.inspect_trace(combined))┌─────────┬────────────┐
│ total │ 165.000 ms │
├─────────┼────────────┤
│ query │ 164.000 ms │
│ summary │ 0.000 ms │
│ other │ 1.000 ms │
└─────────┴────────────┘
print(non_grouped_filters)
SELECT *
FROM sources *
WHERE
(
(timestamp_hour >= 1776715821)
AND
(timestamp_second_nofs > 1776715921)
)
AND
(
(timestamp_hour <= 1779715821)
AND
(timestamp_second_nofs < 1779715721)
)
combined = client.query(body=trace.add_trace(non_grouped_request)).json
print(trace.get_matching_summary(trace.inspect_trace(combined)))match profiling for thread #0 (total time was 736.411 ms)
┌─────────┬──────────┬─────────┬──────┬────────────────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├─────────┼──────────┼─────────┼──────┼────────────────────────────────────────────────────────────────┤
│ 2996922 │ 736.411 │ 481.056 │ S │ And[1] │
│ 2998801 │ 30.284 │ 30.284 │ S │ ├── Attribute{int32,fs}[2] timestamp_hour:<range> │
│ 2998801 │ 30.284 │ 30.283 │ N │ ├── Attribute{int32,fs}[3] timestamp_hour:<range> │
│ 2998800 │ 83.801 │ 83.801 │ N │ ├── Attribute{int32,lookup}[4] timestamp_second_nofs:<range> │
│ 2996921 │ 80.704 │ 80.704 │ N │ ├── Attribute{int32,lookup}[5] timestamp_second_nofs:<range> │
│ 2998801 │ 30.284 │ 30.283 │ N │ └── WhiteList[6] │
└─────────┴──────────┴─────────┴──────┴────────────────────────────────────────────────────────────────┘
### FAST VERSION, no trace
combined = client.query(body={
**request("timestamp_second_nofs"),
"yql": f"""
select *
from sources *
where
(
(timestamp_day >= {get_timestamp()})
AND (timestamp_day <= {get_timestamp() + 3000000})
AND ({{targetHits: 1000, approximate: false}}nearestNeighbor(embedding, query_embedding))
)
""",
"ranking.profile": "minimal",
"hits": 100,
}).json
print(trace.inspect_trace(combined))┌─────────┬───────────┐
│ total │ 57.000 ms │
├─────────┼───────────┤
│ query │ 56.000 ms │
│ summary │ 0.000 ms │
│ other │ 1.000 ms │
└─────────┴───────────┘
### FAST VERSION
combined = client.query(body={
**trace.add_trace(request("timestamp_second_nofs")),
"yql": f"""
select *
from sources *
where
(
(timestamp_day >= {get_timestamp()})
AND (timestamp_day <= {get_timestamp() + 3000000})
AND ({{targetHits: 1000, approximate: false}}nearestNeighbor(embedding, query_embedding))
)
""",
"ranking.profile": "minimal",
"hits": 100,
}).json
print(trace.inspect_trace(combined))┌─────────┬────────────┐
│ total │ 554.000 ms │
├─────────┼────────────┤
│ query │ 552.000 ms │
│ summary │ 1.000 ms │
│ other │ 1.000 ms │
└─────────┴────────────┘
found 1 search
┌────────┬───────┬───────────────┬───────────────┐
│ search │ nodes │ back-end time │ document type │
├────────┼───────┼───────────────┼───────────────┤
│ 0 │ 1 │ 549.691 ms │ doc │
└────────┴───────┴───────────────┴───────────────┘
looking into search #0
slowest node was: doc[0]: 549.691 ms
┌───────────────┬────────────┐
│ task │ doc[0] │
├───────────────┼────────────┤
│ global filter │ 0.000 ms │
│ ann setup │ 0.000 ms │
│ matching │ 535.814 ms │
│ first phase │ 0.001 ms │
│ second phase │ 0.000 ms │
└───────────────┴────────────┘
looking into node doc[0]
┌────────────┬─────────────────────────────────────────────────────────────┐
│ timestamp │ event │
├────────────┼─────────────────────────────────────────────────────────────┤
│ 0.095 ms │ searching for 100 hits at offset 0 │
│ 0.116 ms │ Start query setup │
│ 0.118 ms │ Deserialize and build query tree │
│ 0.131 ms │ Build query execution plan │
│ 0.178 ms │ Optimize query execution plan │
│ 0.187 ms │ Perform dictionary lookups and posting lists initialization │
│ 12.253 ms │ Prepare shared state for multi-threaded rank executors │
│ 12.262 ms │ Complete query setup │
│ │ (query execution happens here, analyzed below) │
│ 549.689 ms │ returning 100 hits from total 8872 │
└────────────┴─────────────────────────────────────────────────────────────┘
ann query details (total setup time was 0.000 ms)
┌─────────────────────────┬─────────────────────┐
│ property │ details │
├─────────────────────────┼─────────────────────┤
│ attribute tensor │ tensor<float>(x[1]) │
│ query tensor │ tensor<float>(x[1]) │
│ target hits │ 1000 │
│ explore additional hits │ 0 │
│ algorithm │ exact │
│ global filter │ not calculated │
│ lazy filter │ not constructed │
└─────────────────────────┴─────────────────────┘
found 1 thread
slowest matching and ranking was thread #0: 535.814 ms
┌──────────────┬────────────┐
│ task │ thread #0 │
├──────────────┼────────────┤
│ matching │ 535.814 ms │
│ first phase │ 0.001 ms │
│ second phase │ 0.000 ms │
└──────────────┴────────────┘
looking into thread #0
┌────────────┬──────────────────────────────────┐
│ timestamp │ event │
├────────────┼──────────────────────────────────┤
│ 12.318 ms │ Start MatchThread::run │
│ 12.358 ms │ Start match and first phase rank │
│ 549.557 ms │ Create result set │
│ 549.583 ms │ Wait for result processing token │
│ 549.584 ms │ Start result processing │
│ 549.616 ms │ Start thread merge │
│ 549.617 ms │ MatchThread::run Done │
└────────────┴──────────────────────────────────┘
match profiling for thread #0 (total time was 535.814 ms)
┌─────────┬──────────┬─────────┬──────┬────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├─────────┼──────────┼─────────┼──────┼────────────────────────────────────────────────────┤
│ 8873 │ 535.814 │ 261.182 │ S │ And[1] │
│ 3024001 │ 53.476 │ 53.476 │ S │ ├── Attribute{int32,fs}[2] timestamp_day:<range> │
│ 3024001 │ 53.476 │ 53.476 │ N │ ├── WhiteList[3] │
│ 3024000 │ 167.679 │ 167.679 │ N │ └── NearestNeighbor[4] │
└─────────┴──────────┴─────────┴──────┴────────────────────────────────────────────────────┘
first phase rank profiling for thread #0 (total time was 0.001 ms)
┌───────┬─────────┬─────────────────────┐
│ count │ self_ms │ component │
├───────┼─────────┼─────────────────────┤
│ 1 │ 0.001 │ function firstphase │
└───────┴─────────┴─────────────────────┘
### CLEVER rewrite: no trace
grouped_filters_yql = f"""
SELECT *
FROM sources *
WHERE
(
(timestamp_hour >= {get_timestamp()})
AND
(timestamp_hour <= {get_timestamp() + 3000000})
)
AND
(
(timestamp_second_nofs > {get_timestamp() + 100})
AND
(timestamp_second_nofs < {get_timestamp() + 3000000 - 100})
)
"""
grouped_filters_request = {
**request("timestamp_second_nofs"),
"yql": grouped_filters_yql,
"ranking.profile": "minimal",
"hits": 100,
}
combined = client.query(body=grouped_filters_request).json
print(trace.inspect_trace(combined))┌─────────┬────────────┐
│ total │ 119.000 ms │
├─────────┼────────────┤
│ query │ 118.000 ms │
│ summary │ 0.000 ms │
│ other │ 1.000 ms │
└─────────┴────────────┘
print(grouped_filters_yql)
SELECT *
FROM sources *
WHERE
(
(timestamp_hour >= 1776716537)
AND
(timestamp_hour <= 1779716537)
)
AND
(
(timestamp_second_nofs > 1776716637)
AND
(timestamp_second_nofs < 1779716437)
)
grouped_request_matching_trace = client.query(body=trace.add_trace(grouped_filters_request)).json
print(trace.get_matching_summary(trace.inspect_trace(grouped_request_matching_trace)))match profiling for thread #0 (total time was 555.878 ms)
┌─────────┬──────────┬─────────┬──────┬────────────────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├─────────┼──────────┼─────────┼──────┼────────────────────────────────────────────────────────────────┤
│ 2997645 │ 555.878 │ 382.018 │ S │ And[1] │
│ 2998801 │ 45.348 │ 45.348 │ S │ ├── Attribute{int32,fs}[2] timestamp_hour:<range> │
│ 2998800 │ 83.165 │ 83.165 │ N │ ├── Attribute{int32,lookup}[3] timestamp_second_nofs:<range> │
│ 2998801 │ 45.348 │ 45.348 │ N │ └── WhiteList[4] │
└─────────┴──────────┴─────────┴──────┴────────────────────────────────────────────────────────────────┘
### CLEVER rewrite
combined = client.query(body={
**trace.add_trace(request),
"yql": f"""
select *
from sources *
where
(
(timestamp_day >= {get_timestamp()} AND timestamp_day <= {get_timestamp() + 3000000})
AND ({{targetHits: 1000, approximate: false}}nearestNeighbor(embedding, query_embedding))
AND ((timestamp_second_nofs > {get_timestamp() + 100}) AND (timestamp_second_nofs < {get_timestamp() + 3000000 - 100}))
)
""",
"ranking.profile": "minimal",
"hits": 100,
}).json
print(trace.inspect_trace(combined))┌─────────┬────────────┐
│ total │ 255.000 ms │
├─────────┼────────────┤
│ query │ 254.000 ms │
│ summary │ 0.000 ms │
│ other │ 1.000 ms │
└─────────┴────────────┘
found 1 search
┌────────┬───────┬───────────────┬───────────────┐
│ search │ nodes │ back-end time │ document type │
├────────┼───────┼───────────────┼───────────────┤
│ 0 │ 1 │ 252.447 ms │ doc │
└────────┴───────┴───────────────┴───────────────┘
looking into search #0
slowest node was: doc[0]: 252.447 ms
┌───────────────┬────────────┐
│ task │ doc[0] │
├───────────────┼────────────┤
│ global filter │ 0.000 ms │
│ ann setup │ 0.000 ms │
│ matching │ 238.798 ms │
│ first phase │ 0.001 ms │
│ second phase │ 0.000 ms │
└───────────────┴────────────┘
looking into node doc[0]
┌────────────┬─────────────────────────────────────────────────────────────┐
│ timestamp │ event │
├────────────┼─────────────────────────────────────────────────────────────┤
│ 0.092 ms │ searching for 100 hits at offset 0 │
│ 0.112 ms │ Start query setup │
│ 0.114 ms │ Deserialize and build query tree │
│ 0.125 ms │ Build query execution plan │
│ 0.169 ms │ Optimize query execution plan │
│ 0.179 ms │ Perform dictionary lookups and posting lists initialization │
│ 12.334 ms │ Prepare shared state for multi-threaded rank executors │
│ 12.341 ms │ Complete query setup │
│ │ (query execution happens here, analyzed below) │
│ 252.444 ms │ returning 100 hits from total 7910 │
└────────────┴─────────────────────────────────────────────────────────────┘
ann query details (total setup time was 0.000 ms)
┌─────────────────────────┬─────────────────────┐
│ property │ details │
├─────────────────────────┼─────────────────────┤
│ attribute tensor │ tensor<float>(x[1]) │
│ query tensor │ tensor<float>(x[1]) │
│ target hits │ 1000 │
│ explore additional hits │ 0 │
│ algorithm │ exact │
│ global filter │ not calculated │
│ lazy filter │ not constructed │
└─────────────────────────┴─────────────────────┘
found 1 thread
slowest matching and ranking was thread #0: 238.799 ms
┌──────────────┬────────────┐
│ task │ thread #0 │
├──────────────┼────────────┤
│ matching │ 238.798 ms │
│ first phase │ 0.001 ms │
│ second phase │ 0.000 ms │
└──────────────┴────────────┘
looking into thread #0
┌────────────┬──────────────────────────────────┐
│ timestamp │ event │
├────────────┼──────────────────────────────────┤
│ 12.392 ms │ Start MatchThread::run │
│ 12.450 ms │ Start match and first phase rank │
│ 252.197 ms │ Create result set │
│ 252.227 ms │ Wait for result processing token │
│ 252.228 ms │ Start result processing │
│ 252.256 ms │ Start thread merge │
│ 252.256 ms │ MatchThread::run Done │
└────────────┴──────────────────────────────────┘
match profiling for thread #0 (total time was 238.798 ms)
┌─────────┬──────────┬─────────┬──────┬────────────────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├─────────┼──────────┼─────────┼──────┼────────────────────────────────────────────────────────────────┤
│ 7911 │ 238.798 │ 122.036 │ S │ And[1] │
│ 1143573 │ 16.421 │ 16.421 │ S │ ├── Attribute{int32,fs}[2] timestamp_day:<range> │
│ 1143573 │ 32.392 │ 32.392 │ N │ ├── Attribute{int32,lookup}[3] timestamp_second_nofs:<range> │
│ 1143573 │ 16.421 │ 16.420 │ N │ ├── WhiteList[4] │
│ 1111552 │ 51.530 │ 51.530 │ N │ └── NearestNeighbor[5] │
└─────────┴──────────┴─────────┴──────┴────────────────────────────────────────────────────────────────┘
first phase rank profiling for thread #0 (total time was 0.001 ms)
┌───────┬─────────┬─────────────────────┐
│ count │ self_ms │ component │
├───────┼─────────┼─────────────────────┤
│ 1 │ 0.001 │ function firstphase │
└───────┴─────────┴─────────────────────┘
## SIMPLY use second level fast search
combined = client.query(body={
**trace.add_trace(request),
"yql": f"""
select *
from sources *
where
(
(timestamp_second >= {get_timestamp()} AND timestamp_second <= {get_timestamp() + 3000000})
AND ({{targetHits: 1000, approximate: false}}nearestNeighbor(embedding, query_embedding))
)
""",
"ranking.profile": "minimal",
"hits": 100,
}).json
print(trace.inspect_trace(combined))┌─────────┬────────────┐
│ total │ 254.000 ms │
├─────────┼────────────┤
│ query │ 252.000 ms │
│ summary │ 1.000 ms │
│ other │ 1.000 ms │
└─────────┴────────────┘
found 1 search
┌────────┬───────┬───────────────┬───────────────┐
│ search │ nodes │ back-end time │ document type │
├────────┼───────┼───────────────┼───────────────┤
│ 0 │ 1 │ 247.180 ms │ doc │
└────────┴───────┴───────────────┴───────────────┘
looking into search #0
slowest node was: doc[0]: 247.180 ms
┌───────────────┬────────────┐
│ task │ doc[0] │
├───────────────┼────────────┤
│ global filter │ 0.000 ms │
│ ann setup │ 0.000 ms │
│ matching │ 105.573 ms │
│ first phase │ 0.008 ms │
│ second phase │ 0.000 ms │
└───────────────┴────────────┘
looking into node doc[0]
┌────────────┬─────────────────────────────────────────────────────────────┐
│ timestamp │ event │
├────────────┼─────────────────────────────────────────────────────────────┤
│ 0.181 ms │ searching for 100 hits at offset 0 │
│ 0.241 ms │ Start query setup │
│ 0.244 ms │ Deserialize and build query tree │
│ 0.266 ms │ Build query execution plan │
│ 1.523 ms │ Optimize query execution plan │
│ 1.556 ms │ Perform dictionary lookups and posting lists initialization │
│ 140.184 ms │ Prepare shared state for multi-threaded rank executors │
│ 140.232 ms │ Complete query setup │
│ │ (query execution happens here, analyzed below) │
│ 247.177 ms │ returning 100 hits from total 7477 │
└────────────┴─────────────────────────────────────────────────────────────┘
ann query details (total setup time was 0.000 ms)
┌─────────────────────────┬─────────────────────┐
│ property │ details │
├─────────────────────────┼─────────────────────┤
│ attribute tensor │ tensor<float>(x[1]) │
│ query tensor │ tensor<float>(x[1]) │
│ target hits │ 1000 │
│ explore additional hits │ 0 │
│ algorithm │ exact │
│ global filter │ not calculated │
│ lazy filter │ not constructed │
└─────────────────────────┴─────────────────────┘
found 1 thread
slowest matching and ranking was thread #0: 105.581 ms
┌──────────────┬────────────┐
│ task │ thread #0 │
├──────────────┼────────────┤
│ matching │ 105.573 ms │
│ first phase │ 0.008 ms │
│ second phase │ 0.000 ms │
└──────────────┴────────────┘
looking into thread #0
┌────────────┬──────────────────────────────────┐
│ timestamp │ event │
├────────────┼──────────────────────────────────┤
│ 140.292 ms │ Start MatchThread::run │
│ 140.381 ms │ Start match and first phase rank │
│ 246.836 ms │ Create result set │
│ 246.905 ms │ Wait for result processing token │
│ 246.907 ms │ Start result processing │
│ 246.940 ms │ Start thread merge │
│ 246.941 ms │ MatchThread::run Done │
└────────────┴──────────────────────────────────┘
match profiling for thread #0 (total time was 105.573 ms)
┌────────┬──────────┬─────────┬──────┬───────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├────────┼──────────┼─────────┼──────┼───────────────────────────────────────────────────────┤
│ 7478 │ 105.573 │ 51.680 │ S │ And[1] │
│ 706991 │ 10.611 │ 10.611 │ S │ ├── Attribute{int32,fs}[2] timestamp_second:<range> │
│ 706991 │ 10.610 │ 10.610 │ N │ ├── WhiteList[3] │
│ 706991 │ 32.672 │ 32.672 │ N │ └── NearestNeighbor[4] │
└────────┴──────────┴─────────┴──────┴───────────────────────────────────────────────────────┘
first phase rank profiling for thread #0 (total time was 0.008 ms)
┌───────┬─────────┬─────────────────────┐
│ count │ self_ms │ component │
├───────┼─────────┼─────────────────────┤
│ 1 │ 0.008 │ function firstphase │
└───────┴─────────┴─────────────────────┘
### LET's do a brutal hack: in the ranking profile we should do a "filter" on precise time range:
### - if the value falls outside range let's set it to low value and the rank profile should filter out such hits
### - It is the first phase after all, the scores calculated should be cheapapp.get_schema("doc").add_rank_profile(
RankProfile(
name="range_filter_hack",
inputs=[
# How to write -infinity and +Infinity
("query(min_range_value)", "double", "-10000000000"),
("query(max_range_value)", "double", "10000000000"),
],
first_phase=FirstPhaseRanking(
expression="if ((query(min_range_value) >= attribute(timestamp_second_nofs) && attribute(timestamp_second_nofs) <= query(max_range_value)), 1, -1)",
rank_score_drop_limit=-1.0,
)
)
)print(app.get_schema("doc").schema_to_text)schema doc {
document doc {
field id type int {
indexing: attribute
attribute {
fast-search
}
}
field timestamp_second_nofs type int {
indexing: attribute
}
field timestamp_second type int {
indexing: attribute
attribute {
fast-search
}
}
field timestamp_hour type int {
indexing: attribute
attribute {
fast-search
}
}
field timestamp_day type int {
indexing: attribute
attribute {
fast-search
}
}
field embedding type tensor<float>(x[1]) {
indexing: attribute
}
field lexical type string {
indexing: index
index: enable-bm25
}
}
rank-profile minimal {
first-phase {
expression {
1
}
keep-rank-count: 1
}
}
rank-profile range_filter_hack {
inputs {
query(min_range_value) double: -10000000000
query(max_range_value) double: 10000000000
}
first-phase {
expression {
if ((query(min_range_value) >= attribute(timestamp_second_nofs) && attribute(timestamp_second_nofs) <= query(max_range_value)), 1, -1)
}
rank-score-drop-limit: -1.0
}
}
}
vap.redeploy(vespa_docker, app)Deploy status code: 200
Vespa(http://localhost, 8080)min_range_value = get_timestamp()
max_range_value = min_range_value + 1 # so there should be two hits
combined = client.query(body={
**request("timestamp_second_nofs"),
"yql": f"""
select *
from sources *
where
(
(timestamp_second >= {min_range_value - 1} AND timestamp_second <= {max_range_value + 1})
)
""",
"ranking.profile": "range_filter_hack", # changing to unranked, makes 4 docs to match
"hits": 100,
"input.query(min_range_value)": min_range_value,
"input.query(max_range_value)": min_range_value,
}).json
combined{'root': {'children': [{'fields': {'documentid': 'id:doc:doc::2072944',
'sddocname': 'doc'},
'id': 'id:doc:doc::2072944',
'relevance': 1.0,
'source': 'test_content'},
{'fields': {'documentid': 'id:doc:doc::2157537', 'sddocname': 'doc'},
'id': 'id:doc:doc::2157537',
'relevance': 1.0,
'source': 'test_content'}],
'coverage': {'coverage': 100,
'documents': 10000000,
'full': True,
'nodes': 1,
'results': 1,
'resultsFull': 1},
'fields': {'totalCount': 2},
'id': 'toplevel',
'relevance': 1.0},
'timing': {'querytime': 0.002,
'searchtime': 0.004,
'summaryfetchtime': 0.001}}### Check if scoring is faster than filter evaluation on non fast-search attributes
min_range_value = get_timestamp()
max_range_value = min_range_value + 1 # so there should be two hits
request_body = {
**request("timestamp_second_nofs"),
"yql": f"""
select *
from sources *
where true
""",
"ranking.profile": "range_filter_hack", # changing to unranked, makes 4 docs to match
"hits": 1,
"input.query(min_range_value)": min_range_value,
"input.query(max_range_value)": min_range_value,
"timeout": "55s",
}
# combined = client.query(body=trace.add_trace(request_body)).json
# print(trace.inspect_trace(combined))
combined = client.query(body=request_body).json
combined{'root': {'children': [{'fields': {'documentid': 'id:doc:doc::38',
'sddocname': 'doc'},
'id': 'id:doc:doc::38',
'relevance': 1.0,
'source': 'test_content'}],
'coverage': {'coverage': 100,
'documents': 10000000,
'full': True,
'nodes': 1,
'results': 1,
'resultsFull': 1},
'fields': {'totalCount': 154131},
'id': 'toplevel',
'relevance': 1.0},
'timing': {'querytime': 0.507, 'searchtime': 0.508, 'summaryfetchtime': 0.0}}### Check if matching is used on that attribute
min_range_value = get_timestamp()
max_range_value = min_range_value + 1 # so there should be two hits
request_body = {
**request("timestamp_second_nofs"),
"yql": f"""
select *
from sources *
where timestamp_second_nofs > 0 AND timestamp_second_nofs < 100000000000
""",
"ranking.profile": "unranked", # changing to unranked, makes 4 docs to match
"hits": 1,
# "input.query(min_range_value)": min_range_value,
# "input.query(max_range_value)": min_range_value,
"timeout": "55s",
}
combined = client.query(body=trace.add_trace(request_body)).json
print(trace.inspect_trace(combined))
# combined = client.query(body=request_body).json
# combined┌─────────┬─────────────┐
│ total │ 2116.000 ms │
├─────────┼─────────────┤
│ query │ 2116.000 ms │
│ summary │ 0.000 ms │
│ other │ 0.000 ms │
└─────────┴─────────────┘
found 1 search
┌────────┬───────┬───────────────┬───────────────┐
│ search │ nodes │ back-end time │ document type │
├────────┼───────┼───────────────┼───────────────┤
│ 0 │ 1 │ 2114.064 ms │ doc │
└────────┴───────┴───────────────┴───────────────┘
looking into search #0
slowest node was: doc[0]: 2114.064 ms
┌───────────────┬─────────────┐
│ task │ doc[0] │
├───────────────┼─────────────┤
│ global filter │ 0.000 ms │
│ ann setup │ 0.000 ms │
│ matching │ 1557.606 ms │
│ first phase │ 0.000 ms │
│ second phase │ 0.000 ms │
└───────────────┴─────────────┘
looking into node doc[0]
┌─────────────┬─────────────────────────────────────────────────────────────┐
│ timestamp │ event │
├─────────────┼─────────────────────────────────────────────────────────────┤
│ 0.072 ms │ searching for 1 hits at offset 0 │
│ 0.093 ms │ Start query setup │
│ 0.094 ms │ Deserialize and build query tree │
│ 0.102 ms │ Build query execution plan │
│ 0.116 ms │ Optimize query execution plan │
│ 0.122 ms │ Perform dictionary lookups and posting lists initialization │
│ 0.123 ms │ Prepare shared state for multi-threaded rank executors │
│ 0.126 ms │ Complete query setup │
│ │ (query execution happens here, analyzed below) │
│ 2114.062 ms │ returning 1 hits from total 10000000 │
└─────────────┴─────────────────────────────────────────────────────────────┘
found 1 thread
slowest matching and ranking was thread #0: 1557.606 ms
┌──────────────┬─────────────┐
│ task │ thread #0 │
├──────────────┼─────────────┤
│ matching │ 1557.606 ms │
│ first phase │ 0.000 ms │
│ second phase │ 0.000 ms │
└──────────────┴─────────────┘
looking into thread #0
┌─────────────┬──────────────────────────────────┐
│ timestamp │ event │
├─────────────┼──────────────────────────────────┤
│ 0.154 ms │ Start MatchThread::run │
│ 0.179 ms │ Start match and first phase rank │
│ 2113.962 ms │ Create result set │
│ 2113.973 ms │ Wait for result processing token │
│ 2114.001 ms │ Start result processing │
│ 2114.005 ms │ Start thread merge │
│ 2114.006 ms │ MatchThread::run Done │
└─────────────┴──────────────────────────────────┘
match profiling for thread #0 (total time was 1557.606 ms)
┌──────────┬──────────┬─────────┬──────┬────────────────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├──────────┼──────────┼─────────┼──────┼────────────────────────────────────────────────────────────────┤
│ 10000001 │ 1557.606 │ 993.287 │ S │ And[1] │
│ 10000001 │ 282.877 │ 282.877 │ S │ ├── Attribute{int32,lookup}[2] timestamp_second_nofs:<range> │
│ 10000000 │ 281.442 │ 281.442 │ N │ └── WhiteList[3] │
└──────────┴──────────┴─────────┴──────┴────────────────────────────────────────────────────────────────┘
first phase rank profiling for thread #0 (total time was 0.000 ms)
┌───────┬─────────┬───────────────────────┐
│ count │ self_ms │ component │
├───────┼─────────┼───────────────────────┤
│ 1 │ 0.000 │ rank feature value(0) │
└───────┴─────────┴───────────────────────┘
yql_base = """
SELECT *
FROM sources *
WHERE
(id
> 1)
AND (
({targetHits: 1000
, approximate: false} nearestNeighbor(embedding
, query_embedding))
OR
({targetHits: 1000
, defaultIndex: "lexical"} userInput(@query_str))
) \
"""
print(yql_base)
SELECT *
FROM sources *
WHERE
(id> 1)
AND (
({targetHits: 1000, approximate: false}nearestNeighbor(embedding, query_embedding))
OR
({targetHits: 1000, defaultIndex: "lexical"}userInput(@query_str))
)
request = {
"yql": yql_base,
"query_str": "27110 6334 10140 22335 22040 2716",
"input.query(query_embedding)": [0.5],
"presentation.timing": True,
"hits": 1,
}
print(json.dumps(client.query(body=request).json, indent=2)){
"root": {
"children": [
{
"fields": {
"documentid": "id:doc:doc::96960",
"sddocname": "doc"
},
"id": "id:doc:doc::96960",
"relevance": 0.24059506636028924,
"source": "test_content"
}
],
"coverage": {
"coverage": 100,
"documents": 100000,
"full": true,
"nodes": 1,
"results": 1,
"resultsFull": 1
},
"fields": {
"totalCount": 5692
},
"id": "toplevel",
"relevance": 1.0
},
"timing": {
"querytime": 0.012,
"searchtime": 0.013000000000000001,
"summaryfetchtime": 0.0
}
}
# Good we've found ~5692 docs# Now let's try with tracing and ask vespa CLI to summarize the traceimport mycode.trace as traceresp_base = client.query(body=trace.add_trace(request)).jsonprint(trace.inspect_trace(resp_base))┌─────────┬───────────┐
│ total │ 96.000 ms │
├─────────┼───────────┤
│ query │ 94.000 ms │
│ summary │ 1.000 ms │
│ other │ 1.000 ms │
└─────────┴───────────┘
found 1 search
┌────────┬───────┬───────────────┬───────────────┐
│ search │ nodes │ back-end time │ document type │
├────────┼───────┼───────────────┼───────────────┤
│ 0 │ 1 │ 89.984 ms │ doc │
└────────┴───────┴───────────────┴───────────────┘
looking into search #0
slowest node was: doc[0]: 89.984 ms
┌───────────────┬───────────┐
│ task │ doc[0] │
├───────────────┼───────────┤
│ global filter │ 0.000 ms │
│ ann setup │ 0.000 ms │
│ matching │ 85.378 ms │
│ first phase │ 2.538 ms │
│ second phase │ 0.000 ms │
└───────────────┴───────────┘
looking into node doc[0]
┌───────────┬─────────────────────────────────────────────────────────────┐
│ timestamp │ event │
├───────────┼─────────────────────────────────────────────────────────────┤
│ 0.103 ms │ searching for 10 hits at offset 0 │
│ 0.131 ms │ Start query setup │
│ 0.133 ms │ Deserialize and build query tree │
│ 0.150 ms │ Build query execution plan │
│ 0.272 ms │ Optimize query execution plan │
│ 0.286 ms │ Perform dictionary lookups and posting lists initialization │
│ 0.697 ms │ Prepare shared state for multi-threaded rank executors │
│ 0.719 ms │ Complete query setup │
│ │ (query execution happens here, analyzed below) │
│ 89.983 ms │ returning 10 hits from total 5692 │
└───────────┴─────────────────────────────────────────────────────────────┘
ann query details (total setup time was 0.000 ms)
┌─────────────────────────┬─────────────────────┐
│ property │ details │
├─────────────────────────┼─────────────────────┤
│ attribute tensor │ tensor<float>(x[1]) │
│ query tensor │ tensor<float>(x[1]) │
│ target hits │ 1000 │
│ explore additional hits │ 0 │
│ algorithm │ exact │
│ global filter │ not calculated │
└─────────────────────────┴─────────────────────┘
found 1 thread
slowest matching and ranking was thread #0: 87.915 ms
┌──────────────┬───────────┐
│ task │ thread #0 │
├──────────────┼───────────┤
│ matching │ 85.378 ms │
│ first phase │ 2.538 ms │
│ second phase │ 0.000 ms │
└──────────────┴───────────┘
looking into thread #0
┌───────────┬──────────────────────────────────┐
│ timestamp │ event │
├───────────┼──────────────────────────────────┤
│ 0.891 ms │ Start MatchThread::run │
│ 0.999 ms │ Start match and first phase rank │
│ 89.783 ms │ Create result set │
│ 89.797 ms │ Wait for result processing token │
│ 89.798 ms │ Start result processing │
│ 89.867 ms │ Start thread merge │
│ 89.868 ms │ MatchThread::run Done │
└───────────┴──────────────────────────────────┘
match profiling for thread #0 (total time was 85.378 ms)
┌────────┬──────────┬─────────┬──────┬────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├────────┼──────────┼─────────┼──────┼────────────────────────────────────────────────┤
│ 5693 │ 85.378 │ 8.391 │ S │ And[1] │
│ 105690 │ 2.628 │ 2.435 │ S │ ├── Attribute{int32,fs}[2] id:<range> │
│ 99998 │ 72.503 │ 11.457 │ N │ ├── Or[3] │
│ 100198 │ 5.669 │ 5.669 │ N │ │ ├── NearestNeighbor[4] │
│ 99998 │ 55.377 │ 32.596 │ N │ │ └── WeakAnd[5] │
│ 99998 │ 3.765 │ 3.752 │ N │ │ ├── SourceBlender[6] │
│ 37 │ 0.013 │ 0.013 │ N │ │ │ └── MemoryTerm[7] lexical:27110 │
│ 99998 │ 3.929 │ 3.915 │ N │ │ ├── SourceBlender[8] │
│ 24 │ 0.013 │ 0.013 │ N │ │ │ └── MemoryTerm[9] lexical:6334 │
│ 99998 │ 3.771 │ 3.747 │ N │ │ ├── SourceBlender[10] │
│ 29 │ 0.024 │ 0.024 │ N │ │ │ └── MemoryTerm[11] lexical:10140 │
│ 99998 │ 3.660 │ 3.637 │ N │ │ ├── SourceBlender[12] │
│ 36 │ 0.023 │ 0.023 │ N │ │ │ └── MemoryTerm[13] lexical:22335 │
│ 99998 │ 3.985 │ 3.952 │ N │ │ ├── SourceBlender[14] │
│ 58 │ 0.034 │ 0.034 │ N │ │ │ └── MemoryTerm[15] lexical:22040 │
│ 99998 │ 3.671 │ 3.658 │ N │ │ └── SourceBlender[16] │
│ 33 │ 0.012 │ 0.012 │ N │ │ └── MemoryTerm[17] lexical:2716 │
│ 99999 │ 2.242 │ 2.049 │ N │ └── WhiteList[18] │
└────────┴──────────┴─────────┴──────┴────────────────────────────────────────────────┘
first phase rank profiling for thread #0 (total time was 2.538 ms)
┌───────┬─────────┬───────────────────────────────────┐
│ count │ self_ms │ component │
├───────┼─────────┼───────────────────────────────────┤
│ 5692 │ 1.003 │ rank feature nativeProximity │
│ 5692 │ 0.829 │ rank feature nativeRank │
│ 5692 │ 0.471 │ rank feature nativeFieldMatch │
│ 5692 │ 0.234 │ rank feature nativeAttributeMatch │
└───────┴─────────┴───────────────────────────────────┘
print(trace.get_matching_summary(trace.inspect_trace(resp_base)))match profiling for thread #0 (total time was 91.847 ms)
┌────────┬──────────┬─────────┬──────┬────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├────────┼──────────┼─────────┼──────┼────────────────────────────────────────────────┤
│ 5693 │ 91.847 │ 9.503 │ S │ And[1] │
│ 105690 │ 2.840 │ 2.628 │ S │ ├── Attribute{int32,fs}[2] id:<range> │
│ 99998 │ 77.513 │ 12.364 │ N │ ├── Or[3] │
│ 100198 │ 6.139 │ 6.139 │ N │ │ ├── NearestNeighbor[4] │
│ 99998 │ 59.010 │ 35.133 │ N │ │ └── WeakAnd[5] │
│ 99998 │ 3.928 │ 3.906 │ N │ │ ├── SourceBlender[6] │
│ 37 │ 0.022 │ 0.022 │ N │ │ │ └── MemoryTerm[7] lexical:27110 │
│ 99998 │ 3.959 │ 3.944 │ N │ │ ├── SourceBlender[8] │
│ 24 │ 0.015 │ 0.015 │ N │ │ │ └── MemoryTerm[9] lexical:6334 │
│ 99998 │ 4.027 │ 4.014 │ N │ │ ├── SourceBlender[10] │
│ 29 │ 0.013 │ 0.013 │ N │ │ │ └── MemoryTerm[11] lexical:10140 │
│ 99998 │ 4.046 │ 4.027 │ N │ │ ├── SourceBlender[12] │
│ 36 │ 0.019 │ 0.019 │ N │ │ │ └── MemoryTerm[13] lexical:22335 │
│ 99998 │ 3.967 │ 3.939 │ N │ │ ├── SourceBlender[14] │
│ 58 │ 0.027 │ 0.027 │ N │ │ │ └── MemoryTerm[15] lexical:22040 │
│ 99998 │ 3.951 │ 3.939 │ N │ │ └── SourceBlender[16] │
│ 33 │ 0.012 │ 0.012 │ N │ │ └── MemoryTerm[17] lexical:2716 │
│ 99999 │ 2.416 │ 2.204 │ N │ └── WhiteList[18] │
└────────┴──────────┴─────────┴──────┴────────────────────────────────────────────────┘
# Above we see that weakAnd evaluated 99998 docs, which means that it can't prune matches.
# Now let's rewrite the queryyql_alt = """
SELECT *
FROM sources *
WHERE
(id
> 1
AND ({targetHits: 1000
, approximate: false}
nearestNeighbor(embedding
, query_embedding))
OR
(id
> 1
AND ({targetHits: 1000
, defaultIndex: "lexical"} userInput(@query_str)))) \
"""
print(yql_alt)
SELECT *
FROM sources *
WHERE
(id> 1 AND ({targetHits: 1000, approximate: false}
nearestNeighbor(embedding, query_embedding))
OR
(id> 1 AND ({targetHits: 1000, defaultIndex: "lexical"}userInput(@query_str))))
client.query(body={
**request,
"yql": yql_alt,
}).json{'root': {'children': [{'fields': {'documentid': 'id:doc:doc::96960',
'sddocname': 'doc'},
'id': 'id:doc:doc::96960',
'relevance': 0.24030457979529288,
'source': 'test_content'}],
'coverage': {'coverage': 100,
'documents': 100000,
'full': True,
'nodes': 1,
'results': 1,
'resultsFull': 1},
'fields': {'totalCount': 5692},
'id': 'toplevel',
'relevance': 1.0},
'timing': {'querytime': 0.007,
'searchtime': 0.009000000000000001,
'summaryfetchtime': 0.0}}resp_alt = client.query(body={
**trace.add_trace(request),
"yql": yql,
}).json
print(trace.inspect_trace(resp_alt))┌─────────┬───────────┐
│ total │ 35.000 ms │
├─────────┼───────────┤
│ query │ 33.000 ms │
│ summary │ 1.000 ms │
│ other │ 1.000 ms │
└─────────┴───────────┘
found 1 search
┌────────┬───────┬───────────────┬───────────────┐
│ search │ nodes │ back-end time │ document type │
├────────┼───────┼───────────────┼───────────────┤
│ 0 │ 1 │ 26.625 ms │ doc │
└────────┴───────┴───────────────┴───────────────┘
looking into search #0
slowest node was: doc[0]: 26.625 ms
┌───────────────┬───────────┐
│ task │ doc[0] │
├───────────────┼───────────┤
│ global filter │ 0.000 ms │
│ ann setup │ 0.000 ms │
│ matching │ 21.827 ms │
│ first phase │ 2.696 ms │
│ second phase │ 0.000 ms │
└───────────────┴───────────┘
looking into node doc[0]
┌───────────┬─────────────────────────────────────────────────────────────┐
│ timestamp │ event │
├───────────┼─────────────────────────────────────────────────────────────┤
│ 0.096 ms │ searching for 1 hits at offset 0 │
│ 0.117 ms │ Start query setup │
│ 0.119 ms │ Deserialize and build query tree │
│ 0.138 ms │ Build query execution plan │
│ 0.236 ms │ Optimize query execution plan │
│ 0.248 ms │ Perform dictionary lookups and posting lists initialization │
│ 0.753 ms │ Prepare shared state for multi-threaded rank executors │
│ 0.780 ms │ Complete query setup │
│ │ (query execution happens here, analyzed below) │
│ 26.623 ms │ returning 1 hits from total 5692 │
└───────────┴─────────────────────────────────────────────────────────────┘
ann query details (total setup time was 0.000 ms)
┌─────────────────────────┬─────────────────────┐
│ property │ details │
├─────────────────────────┼─────────────────────┤
│ attribute tensor │ tensor<float>(x[1]) │
│ query tensor │ tensor<float>(x[1]) │
│ target hits │ 1000 │
│ explore additional hits │ 0 │
│ algorithm │ exact │
│ global filter │ not calculated │
└─────────────────────────┴─────────────────────┘
found 1 thread
slowest matching and ranking was thread #0: 24.523 ms
┌──────────────┬───────────┐
│ task │ thread #0 │
├──────────────┼───────────┤
│ matching │ 21.827 ms │
│ first phase │ 2.696 ms │
│ second phase │ 0.000 ms │
└──────────────┴───────────┘
looking into thread #0
┌───────────┬──────────────────────────────────┐
│ timestamp │ event │
├───────────┼──────────────────────────────────┤
│ 0.844 ms │ Start MatchThread::run │
│ 0.933 ms │ Start match and first phase rank │
│ 26.419 ms │ Create result set │
│ 26.433 ms │ Wait for result processing token │
│ 26.434 ms │ Start result processing │
│ 26.510 ms │ Start thread merge │
│ 26.510 ms │ MatchThread::run Done │
└───────────┴──────────────────────────────────┘
match profiling for thread #0 (total time was 21.827 ms)
┌───────┬──────────┬─────────┬──────┬────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├───────┼──────────┼─────────┼──────┼────────────────────────────────────────────────────┤
│ 5693 │ 21.827 │ 1.129 │ S │ And[1] │
│ 5693 │ 20.494 │ 0.914 │ S │ ├── Or[2] │
│ 5492 │ 19.203 │ 9.370 │ S │ │ ├── And[3] │
│ 99998 │ 3.764 │ 3.764 │ S │ │ │ ├── Attribute{int32,fs}[4] id:<range> │
│ 99998 │ 6.070 │ 6.070 │ N │ │ │ └── NearestNeighbor[5] │
│ 213 │ 0.377 │ 0.059 │ S │ │ └── And[6] │
│ 213 │ 0.249 │ 0.073 │ S │ │ ├── WeakAnd[7] │
│ 38 │ 0.027 │ 0.013 │ S │ │ │ ├── SourceBlender[8] │
│ 37 │ 0.014 │ 0.014 │ S │ │ │ │ └── MemoryTerm[9] lexical:27110 │
│ 25 │ 0.027 │ 0.016 │ S │ │ │ ├── SourceBlender[10] │
│ 24 │ 0.012 │ 0.012 │ S │ │ │ │ └── MemoryTerm[11] lexical:6334 │
│ 30 │ 0.022 │ 0.011 │ S │ │ │ ├── SourceBlender[12] │
│ 29 │ 0.011 │ 0.011 │ S │ │ │ │ └── MemoryTerm[13] lexical:10140 │
│ 37 │ 0.026 │ 0.013 │ S │ │ │ ├── SourceBlender[14] │
│ 36 │ 0.013 │ 0.013 │ S │ │ │ │ └── MemoryTerm[15] lexical:22335 │
│ 59 │ 0.047 │ 0.023 │ S │ │ │ ├── SourceBlender[16] │
│ 58 │ 0.024 │ 0.024 │ S │ │ │ │ └── MemoryTerm[17] lexical:22040 │
│ 34 │ 0.028 │ 0.017 │ S │ │ │ └── SourceBlender[18] │
│ 33 │ 0.011 │ 0.011 │ S │ │ │ └── MemoryTerm[19] lexical:2716 │
│ 212 │ 0.069 │ 0.069 │ N │ │ └── Attribute{int32,fs}[20] id:<range> │
│ 5692 │ 0.204 │ 0.204 │ N │ └── WhiteList[21] │
└───────┴──────────┴─────────┴──────┴────────────────────────────────────────────────────┘
first phase rank profiling for thread #0 (total time was 2.696 ms)
┌───────┬─────────┬───────────────────────────────────┐
│ count │ self_ms │ component │
├───────┼─────────┼───────────────────────────────────┤
│ 5692 │ 1.001 │ rank feature nativeProximity │
│ 5692 │ 0.937 │ rank feature nativeRank │
│ 5692 │ 0.519 │ rank feature nativeFieldMatch │
│ 5692 │ 0.240 │ rank feature nativeAttributeMatch │
└───────┴─────────┴───────────────────────────────────┘
print(trace.get_matching_summary(trace.inspect_trace(resp_alt)))match profiling for thread #0 (total time was 21.827 ms)
┌───────┬──────────┬─────────┬──────┬────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├───────┼──────────┼─────────┼──────┼────────────────────────────────────────────────────┤
│ 5693 │ 21.827 │ 1.129 │ S │ And[1] │
│ 5693 │ 20.494 │ 0.914 │ S │ ├── Or[2] │
│ 5492 │ 19.203 │ 9.370 │ S │ │ ├── And[3] │
│ 99998 │ 3.764 │ 3.764 │ S │ │ │ ├── Attribute{int32,fs}[4] id:<range> │
│ 99998 │ 6.070 │ 6.070 │ N │ │ │ └── NearestNeighbor[5] │
│ 213 │ 0.377 │ 0.059 │ S │ │ └── And[6] │
│ 213 │ 0.249 │ 0.073 │ S │ │ ├── WeakAnd[7] │
│ 38 │ 0.027 │ 0.013 │ S │ │ │ ├── SourceBlender[8] │
│ 37 │ 0.014 │ 0.014 │ S │ │ │ │ └── MemoryTerm[9] lexical:27110 │
│ 25 │ 0.027 │ 0.016 │ S │ │ │ ├── SourceBlender[10] │
│ 24 │ 0.012 │ 0.012 │ S │ │ │ │ └── MemoryTerm[11] lexical:6334 │
│ 30 │ 0.022 │ 0.011 │ S │ │ │ ├── SourceBlender[12] │
│ 29 │ 0.011 │ 0.011 │ S │ │ │ │ └── MemoryTerm[13] lexical:10140 │
│ 37 │ 0.026 │ 0.013 │ S │ │ │ ├── SourceBlender[14] │
│ 36 │ 0.013 │ 0.013 │ S │ │ │ │ └── MemoryTerm[15] lexical:22335 │
│ 59 │ 0.047 │ 0.023 │ S │ │ │ ├── SourceBlender[16] │
│ 58 │ 0.024 │ 0.024 │ S │ │ │ │ └── MemoryTerm[17] lexical:22040 │
│ 34 │ 0.028 │ 0.017 │ S │ │ │ └── SourceBlender[18] │
│ 33 │ 0.011 │ 0.011 │ S │ │ │ └── MemoryTerm[19] lexical:2716 │
│ 212 │ 0.069 │ 0.069 │ N │ │ └── Attribute{int32,fs}[20] id:<range> │
│ 5692 │ 0.204 │ 0.204 │ N │ └── WhiteList[21] │
└───────┴──────────┴─────────┴──────┴────────────────────────────────────────────────────┘
# above we see that weakAnd evaluated only 213 docs
# Which resulted in significantly lower latency: from ~100ms down to ~35ms.print(trace.get_matching_summary(trace.inspect_trace(resp_alt)))match profiling for thread #0 (total time was 21.827 ms)
┌───────┬──────────┬─────────┬──────┬────────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├───────┼──────────┼─────────┼──────┼────────────────────────────────────────────────────┤
│ 5693 │ 21.827 │ 1.129 │ S │ And[1] │
│ 5693 │ 20.494 │ 0.914 │ S │ ├── Or[2] │
│ 5492 │ 19.203 │ 9.370 │ S │ │ ├── And[3] │
│ 99998 │ 3.764 │ 3.764 │ S │ │ │ ├── Attribute{int32,fs}[4] id:<range> │
│ 99998 │ 6.070 │ 6.070 │ N │ │ │ └── NearestNeighbor[5] │
│ 213 │ 0.377 │ 0.059 │ S │ │ └── And[6] │
│ 213 │ 0.249 │ 0.073 │ S │ │ ├── WeakAnd[7] │
│ 38 │ 0.027 │ 0.013 │ S │ │ │ ├── SourceBlender[8] │
│ 37 │ 0.014 │ 0.014 │ S │ │ │ │ └── MemoryTerm[9] lexical:27110 │
│ 25 │ 0.027 │ 0.016 │ S │ │ │ ├── SourceBlender[10] │
│ 24 │ 0.012 │ 0.012 │ S │ │ │ │ └── MemoryTerm[11] lexical:6334 │
│ 30 │ 0.022 │ 0.011 │ S │ │ │ ├── SourceBlender[12] │
│ 29 │ 0.011 │ 0.011 │ S │ │ │ │ └── MemoryTerm[13] lexical:10140 │
│ 37 │ 0.026 │ 0.013 │ S │ │ │ ├── SourceBlender[14] │
│ 36 │ 0.013 │ 0.013 │ S │ │ │ │ └── MemoryTerm[15] lexical:22335 │
│ 59 │ 0.047 │ 0.023 │ S │ │ │ ├── SourceBlender[16] │
│ 58 │ 0.024 │ 0.024 │ S │ │ │ │ └── MemoryTerm[17] lexical:22040 │
│ 34 │ 0.028 │ 0.017 │ S │ │ │ └── SourceBlender[18] │
│ 33 │ 0.011 │ 0.011 │ S │ │ │ └── MemoryTerm[19] lexical:2716 │
│ 212 │ 0.069 │ 0.069 │ N │ │ └── Attribute{int32,fs}[20] id:<range> │
│ 5692 │ 0.204 │ 0.204 │ N │ └── WhiteList[21] │
└───────┴──────────┴─────────┴──────┴────────────────────────────────────────────────────┘
yql_and = """
SELECT *
FROM sources *
WHERE
(id
> 1)
AND (
({targetHits: 1000
, approximate: false} nearestNeighbor(embedding
, query_embedding))
OR
({targetHits: 1000
, defaultIndex: "lexical"
, grammar: "all"} userInput(@query_str))
) \
"""
request = {
"yql": yql_and,
"query_str": "27110 6334 10140 22335 22040 2716",
"input.query(query_embedding)": [0.5],
"presentation.timing": True,
"hits": 1,
}
client.query(body=request).json{'root': {'coverage': {'coverage': 100,
'documents': 10000000,
'full': True,
'nodes': 1,
'results': 1,
'resultsFull': 1},
'fields': {'totalCount': 0},
'id': 'toplevel',
'relevance': 1.0},
'timing': {'querytime': 0.008, 'searchtime': 0.008, 'summaryfetchtime': 0.0}}yql_no_filters = """
select *
from sources *
where (
({targetHits: 1000
, approximate: false} nearestNeighbor(embedding
, query_embedding))
OR
({targetHits: 1000
, defaultIndex: "lexical"} userInput(@query_str))
)
"""
request = {
**trace.add_trace(request),
"yql": yql_no_filters,
"query_str": "27110 6334 10140 22335 22040 2716",
"input.query(query_embedding)": [0.5],
"presentation.timing": True,
"hits": 1,
}
resp_no_filters = client.query(body=request).json
print(trace.get_matching_summary(trace.inspect_trace(resp_no_filters)))match profiling for thread #0 (total time was 93.455 ms)
┌───────┬──────────┬─────────┬──────┬──────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├───────┼──────────┼─────────┼──────┼──────────────────────────────────────────────┤
│ 16012 │ 93.455 │ 3.182 │ S │ And[1] │
│ 16012 │ 89.302 │ 2.875 │ S │ ├── Or[2] │
│ 5746 │ 8.869 │ 2.202 │ S │ │ ├── WeakAnd[3] │
│ 3413 │ 1.638 │ 1.189 │ S │ │ │ ├── SourceBlender[4] │
│ 3412 │ 0.449 │ 0.449 │ S │ │ │ │ ├── DiskTerm[5] lexical:27110 │
│ 0 │ 0.000 │ 0.000 │ S │ │ │ │ └── Empty[6] │
│ 3027 │ 0.940 │ 0.753 │ S │ │ │ ├── SourceBlender[7] │
│ 3026 │ 0.188 │ 0.188 │ S │ │ │ │ ├── DiskTerm[8] lexical:6334 │
│ 0 │ 0.000 │ 0.000 │ S │ │ │ │ └── Empty[9] │
│ 2964 │ 1.033 │ 0.835 │ S │ │ │ ├── SourceBlender[10] │
│ 2963 │ 0.198 │ 0.198 │ S │ │ │ │ ├── DiskTerm[11] lexical:10140 │
│ 0 │ 0.000 │ 0.000 │ S │ │ │ │ └── Empty[12] │
│ 3039 │ 1.086 │ 0.862 │ S │ │ │ ├── SourceBlender[13] │
│ 3038 │ 0.223 │ 0.223 │ S │ │ │ │ ├── DiskTerm[14] lexical:22335 │
│ 0 │ 0.000 │ 0.000 │ S │ │ │ │ └── Empty[15] │
│ 2984 │ 0.958 │ 0.773 │ S │ │ │ ├── SourceBlender[16] │
│ 2983 │ 0.186 │ 0.186 │ S │ │ │ │ ├── DiskTerm[17] lexical:22040 │
│ 0 │ 0.000 │ 0.000 │ S │ │ │ │ └── Empty[18] │
│ 3048 │ 1.012 │ 0.820 │ S │ │ │ └── SourceBlender[19] │
│ 3047 │ 0.191 │ 0.191 │ S │ │ │ ├── DiskTerm[20] lexical:2716 │
│ 0 │ 0.000 │ 0.000 │ S │ │ │ └── Empty[21] │
│ 10285 │ 77.558 │ 77.558 │ S │ │ └── NearestNeighbor[22] │
│ 16011 │ 0.970 │ 0.970 │ N │ └── WhiteList[23] │
└───────┴──────────┴─────────┴──────┴──────────────────────────────────────────────┘
print(trace.get_matching_summary(trace.inspect_trace(resp_no_filters)))match profiling for thread #0 (total time was 4.903 ms)
┌───────┬──────────┬─────────┬──────┬────────────────────────────────────────────────┐
│ seeks │ total_ms │ self_ms │ step │ query tree │
├───────┼──────────┼─────────┼──────┼────────────────────────────────────────────────┤
│ 5691 │ 4.903 │ 1.046 │ S │ And[1] │
│ 5691 │ 3.670 │ 0.942 │ S │ ├── Or[2] │
│ 5491 │ 1.762 │ 1.762 │ S │ │ ├── NearestNeighbor[3] │
│ 213 │ 0.965 │ 0.059 │ S │ │ └── WeakAnd[4] │
│ 38 │ 0.126 │ 0.009 │ S │ │ ├── SourceBlender[5] │
│ 37 │ 0.116 │ 0.116 │ S │ │ │ └── MemoryTerm[6] lexical:27110 │
│ 25 │ 0.121 │ 0.011 │ S │ │ ├── SourceBlender[7] │
│ 24 │ 0.109 │ 0.109 │ S │ │ │ └── MemoryTerm[8] lexical:6334 │
│ 30 │ 0.125 │ 0.015 │ S │ │ ├── SourceBlender[9] │
│ 29 │ 0.109 │ 0.109 │ S │ │ │ └── MemoryTerm[10] lexical:10140 │
│ 37 │ 0.156 │ 0.020 │ S │ │ ├── SourceBlender[11] │
│ 36 │ 0.136 │ 0.136 │ S │ │ │ └── MemoryTerm[12] lexical:22335 │
│ 59 │ 0.233 │ 0.013 │ S │ │ ├── SourceBlender[13] │
│ 58 │ 0.220 │ 0.220 │ S │ │ │ └── MemoryTerm[14] lexical:22040 │
│ 34 │ 0.146 │ 0.012 │ S │ │ └── SourceBlender[15] │
│ 33 │ 0.133 │ 0.133 │ S │ │ └── MemoryTerm[16] lexical:2716 │
│ 5690 │ 0.187 │ 0.187 │ N │ └── WhiteList[17] │
└───────┴──────────┴─────────┴──────┴────────────────────────────────────────────────┘
# Query ENN without a filter
combined = client.query(body={
**request("timestamp_second_nofs"),
"yql": f"""
select *
from sources *
where ({{targetHits: 1000, approximate: false}}
nearestNeighbor(embedding, query_embedding))
""",
"ranking.profile": "minimal",
}).json
print(trace.inspect_trace(combined))┌─────────┬───────────┐
│ total │ 61.000 ms │
├─────────┼───────────┤
│ query │ 61.000 ms │
│ summary │ 0.000 ms │
│ other │ 0.000 ms │
└─────────┴───────────┘
# Filter is on the non `fast-search` field.
combined = client.query(body={
**request("timestamp_second_nofs"),
"yql": f"""
select *
from sources *
where
(timestamp_second_nofs >= {get_timestamp()} )
AND (timestamp_second_nofs <= {get_timestamp() + 3000000})
AND ({{targetHits: 1000, approximate: false}}
nearestNeighbor(embedding, query_embedding))
""",
"ranking.profile": "minimal",
}).json
print(trace.inspect_trace(combined))┌─────────┬───────────┐
│ total │ 81.000 ms │
├─────────┼───────────┤
│ query │ 80.000 ms │
│ summary │ 0.000 ms │
│ other │ 1.000 ms │
└─────────┴───────────┘
# Filter is on the non `fast-search` field.
combined = client.query(body={
**request("timestamp_second_nofs"),
"yql": f"""
select *
from sources *
where
(timestamp_second_nofs >= {get_timestamp()} )
AND (timestamp_second_nofs <= {get_timestamp() + 3000000})
AND ({{targetHits: 1000, approximate: false}}
nearestNeighbor(embedding, query_embedding))
""",
"ranking.profile": "minimal",
}).json
print(trace.inspect_trace(combined))┌─────────┬───────────┐
│ total │ 77.000 ms │
├─────────┼───────────┤
│ query │ 77.000 ms │
│ summary │ 0.000 ms │
│ other │ 0.000 ms │
└─────────┴───────────┘
# Filter on a `fast-search` field with high cardinality
combined = client.query(body={
**request("timestamp_second_nofs"),
"yql": f"""
select *
from sources *
where
(timestamp_second >= {get_timestamp()} )
AND (timestamp_second <= {get_timestamp() + 3000000})
AND ({{targetHits: 1000, approximate: false}}
nearestNeighbor(embedding, query_embedding))
""",
"ranking.profile": "minimal",
}).json
print(trace.inspect_trace(combined))┌─────────┬────────────┐
│ total │ 135.000 ms │
├─────────┼────────────┤
│ query │ 135.000 ms │
│ summary │ 0.000 ms │
│ other │ 0.000 ms │
└─────────┴────────────┘
# Filter on a `fast-search` field with high cardinality
combined = client.query(body={
"yql": f"""
select *
from sources *
where
(timestamp_hour >= {get_timestamp()} )
AND (timestamp_hour <= {get_timestamp() + 3000000})
AND ({{targetHits: 1000, approximate: false}}
nearestNeighbor(embedding, query_embedding))
""",
"ranking.profile": "minimal",
"input.query(query_embedding)": [0.5],
}).json
print(trace.inspect_trace(combined))
# Filter on a `fast-search` field with high cardinality
resp = client.query(body={
"yql": f"""
select *
from sources *
where ({{targetHits: 1000, approximate: false}}
nearestNeighbor(embedding, query_embedding))
limit 0
""",
"query_str": "27110 6334 10140 22335 22040 2716",
"input.query(query_embedding)": [0.5],
"presentation.timing": True,
"ranking.profile": "minimal",
}).json{'root': {'coverage': {'coverage': 100,
'documents': 10000000,
'full': True,
'nodes': 1,
'results': 1,
'resultsFull': 1},
'fields': {'totalCount': 10284},
'id': 'toplevel',
'relevance': 1.0},
'timing': {'querytime': 0.07100000000000001,
'searchtime': 0.07200000000000001,
'summaryfetchtime': 0.0}}import math
for th in [1, 10, 100, 1000, 10000, 100000, 1000000]:
resp = client.query(body={
"yql": f"""
select *
from sources *
where ({{targetHits: {th}, approximate: false}}
nearestNeighbor(embedding, query_embedding))
limit 0
""",
"query_str": "27110 6334 10140 22335 22040 2716",
"input.query(query_embedding)": [0.5],
"presentation.timing": True,
"ranking.profile": "minimal",
}).json
print(f'targetHits={th} totalCount: {resp['root']['fields']['totalCount']} estimate={th * (1 + math.log(10000000/th))}')---------------------------------------------------------------------------
ConnectError Traceback (most recent call last)
File ~/IdeaProjects/notes/.venv/lib/python3.13/site-packages/vespa/application.py:1522, in VespaSync._request_with_retry(self, method, url, json_data, **kwargs)
1520 try:
1521 # Make the request using httpr.Client
-> 1522 response = getattr(self.http_client, method.lower())(url, **kwargs)
1524 if response.status_code == 429 and attempt < self.num_retries_429:
1525 # Exponential backoff for 429 (same formula as CustomHTTPAdapter)
File ~/IdeaProjects/notes/.venv/lib/python3.13/site-packages/httpr/__init__.py:428, in Client.post(self, url, **kwargs)
385 """
386 Make a POST request.
387
(...) 426 ```
427 """
--> 428 return self.request(method="POST", url=url, **kwargs)
File ~/IdeaProjects/notes/.venv/lib/python3.13/site-packages/httpr/__init__.py:300, in Client.request(self, method, url, **kwargs)
298 kwargs["params"] = {k: str(v) for k, v in kwargs["params"].items()}
--> 300 return super().request(method=method, url=url, **kwargs)
ConnectError: error sending request for url (http://localhost:8080/search/)
During handling of the above exception, another exception occurred:
KeyboardInterrupt Traceback (most recent call last)
Cell In[4], line 4
2 import math
3 for th in [1, 10, 100, 1000, 10000, 100000, 1000000]:
----> 4 resp = client.query(body={
5 "yql": f"""
6 select *
7 from sources *
8 where ({{targetHits: {th}, approximate: false}}
9 nearestNeighbor(embedding, query_embedding))
10 limit 0
11 """,
12 "query_str": "27110 6334 10140 22335 22040 2716",
13 "input.query(query_embedding)": [0.5],
14 "presentation.timing": True,
15 "ranking.profile": "minimal",
16 }).json
17 print(f'targetHits={th} totalCount: {resp['root']['fields']['totalCount']} estimate={th * (1 + math.log(10000000/th))}')
File ~/IdeaProjects/notes/.venv/lib/python3.13/site-packages/vespa/application.py:605, in Vespa.query(self, body, groupname, streaming, profile, **kwargs)
603 # Use one connection as this is a single query
604 with VespaSync(self, pool_maxsize=1, pool_connections=1) as sync_app:
--> 605 return sync_app.query(
606 body=body,
607 groupname=groupname,
608 streaming=streaming,
609 profile=profile,
610 **kwargs,
611 )
File ~/IdeaProjects/notes/.venv/lib/python3.13/site-packages/vespa/application.py:1715, in VespaSync.query(self, body, groupname, streaming, profile, **kwargs)
1713 return self._query_streaming(body, **kwargs)
1714 else:
-> 1715 response = self._request_with_retry(
1716 "POST",
1717 self.app.search_end_point,
1718 json_data=body,
1719 params=kwargs,
1720 headers={"Accept": "application/cbor"},
1721 )
1722 raise_for_status(response)
1724 return VespaQueryResponse(
1725 json=response.json(),
1726 status_code=response.status_code,
1727 url=str(response.url),
1728 )
File ~/IdeaProjects/notes/.venv/lib/python3.13/site-packages/vespa/application.py:1536, in VespaSync._request_with_retry(self, method, url, json_data, **kwargs)
1534 if _is_connection_error(e) and attempt < self.num_retries_429:
1535 wait_time = 0.1 * 1.618**attempt + random.uniform(0, 1)
-> 1536 time.sleep(wait_time)
1537 elif _is_connection_error(e):
1538 raise
KeyboardInterrupt: 10 + 10 *math.log(10000000/10)148.15510557964274