Performance on simple query Flight GRPC vs Influxdb3 CLI

[jules-ch]

I'm getting different performance between the same SQL request on InfluxDB3 between a CLI call that I believe hit the HTTP v3 POST API and calling with a Flight GRPC Client.
I uploaded a simple 1MB+ of data and calls this simple request.

SELECT lat as latitude,lon as longitude,battery,time,altitude
FROM telemetry
ORDER BY time DESC
LIMIT 1

Performance difference is around 10x between the 2 path that I find odd.

Here are the logs:
CLI call
influxdb3 query --dbname location "SELECT lat as latitude,lon as longitude,battery,time,altitude FROM telemetry ORDER BY time DESC LIMIT 1"

2024-09-21T14:57:49.191823Z  INFO influxdb3::commands::serve: InfluxDB3 Edge server starting git_hash=v2.5.0-14110-gc1a5e1b5fdd3b89960fe8ceca4d0124bd5ad09fe version=0.1.0 uuid=c0d47268-b176-4d21-9209-237d12e4f9f5 num_cpus=8 build_malloc_conf=
2024-09-21T14:57:49.191966Z  INFO clap_blocks::object_store: Object Store db_dir="./data" object_store_type="Directory"
2024-09-21T14:57:49.192034Z  INFO influxdb3::commands::serve: Creating shared query executor num_threads=8
2024-09-21T14:57:49.195487Z  INFO influxdb3::commands::serve: Catalog initialized with instance_id="56a28715-7d87-4108-a292-5fdebacc4f8b"
2024-09-21T14:57:52.304846Z  INFO influxdb3_server::http: handling query_sql database=location query_str=SELECT lat as latitude,lon as longitude,battery,time,altitude
        FROM telemetry
        ORDER BY time DESC
        LIMIT 1 format=Pretty
2024-09-21T14:57:52.304911Z  INFO influxdb3_server::query_executor: QueryExecutorImpl as QueryExecutor::query database=location query=SELECT lat as latitude,lon as longitude,battery,time,altitude
        FROM telemetry
        ORDER BY time DESC
        LIMIT 1 params=None kind=Sql
2024-09-21T14:57:52.322450Z  WARN iox_query::physical_optimizer::dedup::split: cannot split dedup operation, fanout too wide n_split=654 max_dedup_split=100
2024-09-21T14:57:52.327571Z  INFO iox_query::query_log: query when="received" id=26542f95-347c-48f5-919b-bedb639d919c namespace_id=0 namespace_name="influxdb3 edge" query_type="sql" query_text=SELECT lat as latitude,lon as longitude,battery,time,altitude
        FROM telemetry
        ORDER BY time DESC
        LIMIT 1 query_params=Params { } issue_time=2024-09-21T14:57:52.327567194+00:00 ingester_metrics=None success=false running=true cancelled=false
2024-09-21T14:57:52.327635Z  INFO iox_query::query_log: query when="planned" id=26542f95-347c-48f5-919b-bedb639d919c namespace_id=0 namespace_name="influxdb3 edge" query_type="sql" query_text=SELECT lat as latitude,lon as longitude,battery,time,altitude
        FROM telemetry
        ORDER BY time DESC
        LIMIT 1 query_params=Params { } issue_time=2024-09-21T14:57:52.327567194+00:00 partitions=0 parquet_files=0 deduplicated_partitions=0 deduplicated_parquet_files=0 plan_duration_secs=6.5131e-5 ingester_metrics=None success=false running=true cancelled=false
2024-09-21T14:57:52.327669Z  INFO iox_query::query_log: query when="permit" id=26542f95-347c-48f5-919b-bedb639d919c namespace_id=0 namespace_name="influxdb3 edge" query_type="sql" query_text=SELECT lat as latitude,lon as longitude,battery,time,altitude
        FROM telemetry
        ORDER BY time DESC
        LIMIT 1 query_params=Params { } issue_time=2024-09-21T14:57:52.327567194+00:00 partitions=0 parquet_files=0 deduplicated_partitions=0 deduplicated_parquet_files=0 plan_duration_secs=6.5131e-5 permit_duration_secs=3.5735e-5 ingester_metrics=None success=false running=true cancelled=false
2024-09-21T14:57:52.342779Z  INFO iox_query::query_log: query when="success" id=26542f95-347c-48f5-919b-bedb639d919c namespace_id=0 namespace_name="influxdb3 edge" query_type="sql" query_text=SELECT lat as latitude,lon as longitude,battery,time,altitude
        FROM telemetry
        ORDER BY time DESC
        LIMIT 1 query_params=Params { } issue_time=2024-09-21T14:57:52.327567194+00:00 partitions=0 parquet_files=0 deduplicated_partitions=0 deduplicated_parquet_files=0 plan_duration_secs=6.5131e-5 permit_duration_secs=3.5735e-5 execute_duration_secs=0.014500581 end2end_duration_secs=0.015198724 compute_duration_secs=0.001106772 max_memory=775654 ingester_metrics=IngesterMetrics { latency_to_plan = 0ns, latency_to_full_data = 0ns, response_rows = 0, partition_count = 0, response_size = 0 } success=true running=false cancelled=false

Here E2E duration is 15 ms

With Flight GRPC:

2024-09-21T14:59:13.756089Z  INFO influxdb3::commands::serve: InfluxDB3 Edge server starting git_hash=v2.5.0-14110-gc1a5e1b5fdd3b89960fe8ceca4d0124bd5ad09fe version=0.1.0 uuid=afb99682-987c-499d-ad7b-54381a3bc6f1 num_cpus=8 build_malloc_conf=
2024-09-21T14:59:13.756231Z  INFO clap_blocks::object_store: Object Store db_dir="./data" object_store_type="Directory"
2024-09-21T14:59:13.756302Z  INFO influxdb3::commands::serve: Creating shared query executor num_threads=8
2024-09-21T14:59:13.759713Z  INFO influxdb3::commands::serve: Catalog initialized with instance_id="56a28715-7d87-4108-a292-5fdebacc4f8b"
2024-09-21T14:59:20.636467Z  INFO iox_query::query_log: query when="received" id=2c89ecc7-5122-46ca-b64c-c879c5f2acbb namespace_id=0 namespace_name="influxdb3 edge" query_type="sql" query_text=SELECT lat as latitude,lon as longitude,battery,time,altitude
FROM telemetry
ORDER BY time DESC
LIMIT 1
 query_params=Params { } issue_time=2024-09-21T14:59:20.636449513+00:00 ingester_metrics=None success=false running=true cancelled=false
2024-09-21T14:59:20.636536Z  INFO service_grpc_flight: DoGet request namespace_name=location query=SELECT lat as latitude,lon as longitude,battery,time,altitude
FROM telemetry
ORDER BY time DESC
LIMIT 1
 trace="" variant="sql"
2024-09-21T14:59:20.654390Z  WARN iox_query::physical_optimizer::dedup::split: cannot split dedup operation, fanout too wide n_split=654 max_dedup_split=100
2024-09-21T14:59:20.660219Z  INFO iox_query::query_log: query when="planned" id=2c89ecc7-5122-46ca-b64c-c879c5f2acbb namespace_id=0 namespace_name="influxdb3 edge" query_type="sql" query_text=SELECT lat as latitude,lon as longitude,battery,time,altitude
FROM telemetry
ORDER BY time DESC
LIMIT 1
 query_params=Params { } issue_time=2024-09-21T14:59:20.636449513+00:00 partitions=0 parquet_files=0 deduplicated_partitions=0 deduplicated_parquet_files=0 plan_duration_secs=0.023759684 ingester_metrics=None success=false running=true cancelled=false
2024-09-21T14:59:20.672398Z  INFO iox_query::query_log: query when="permit" id=2c89ecc7-5122-46ca-b64c-c879c5f2acbb namespace_id=0 namespace_name="influxdb3 edge" query_type="sql" query_text=SELECT lat as latitude,lon as longitude,battery,time,altitude
FROM telemetry
ORDER BY time DESC
LIMIT 1
 query_params=Params { } issue_time=2024-09-21T14:59:20.636449513+00:00 partitions=0 parquet_files=0 deduplicated_partitions=0 deduplicated_parquet_files=0 plan_duration_secs=0.023759684 permit_duration_secs=0.012182856 ingester_metrics=None success=false running=true cancelled=false
2024-09-21T14:59:20.725074Z  INFO iox_query::query_log: query when="success" id=2c89ecc7-5122-46ca-b64c-c879c5f2acbb namespace_id=0 namespace_name="influxdb3 edge" query_type="sql" query_text=SELECT lat as latitude,lon as longitude,battery,time,altitude
FROM telemetry
ORDER BY time DESC
LIMIT 1
 query_params=Params { } issue_time=2024-09-21T14:59:20.636449513+00:00 partitions=0 parquet_files=0 deduplicated_partitions=0 deduplicated_parquet_files=0 plan_duration_secs=0.023759684 permit_duration_secs=0.012182856 execute_duration_secs=0.05203239 end2end_duration_secs=0.088612802 compute_duration_secs=0.046252025 max_memory=10719848 ingester_metrics=IngesterMetrics { latency_to_plan = 0ns, latency_to_full_data = 0ns, response_rows = 0, partition_count = 0, response_size = 0 } success=true running=false cancelled=false

E2E duration goes up to 88 ms which is almost 6x

Anybody got a hint on where this performance hit comes from ?

[mgattozzi]

Hey @jules-ch, just so you're aware, InfluxDB 3.0 open source is still currently under active development and so perf hits like this should be expected while we work on ironing out the kinks/add features.

The CLI is using the http endpoint not the GRPC endpoint, but they both go to the same port where we have a service to figure out how to handle the incoming query (e.g. is this an http or a GRPC request). It should be using the same code underneath to run a query. This would be my first guess, but I haven't done any profiling to figure out if that's actually the problem.

[jules-ch]

@mgattozzi Thanks for getting back to me. Yeah I understand that you're still working actively on it. I just found it was odd since under the hood the same machinery is used to plan and execute the query, and hope that you might have an answer for it.
Also I assumed GRPC to get better perf than the HTTP REST API, the perf hit was quite significant for such a simple query.

[mgattozzi]

Hey @jules-ch just want to follow up with this since my coworkers had fixed it. We had an issue open for this here -> #25466

Turns out Nagle's algorithm strikes yet again. We set TCP_NODELAY to true on the server and that should fix the issues you were seeing.

[jules-ch]

I'm still experiencing the perf hit on the latest commit:
influxdb3 --version
influxdb3 0.1.0, revision v2.5.0-14147-g0e814f5d52509dafd382522f8c9dc846967e6f2b

CLI:
14ms

2024-10-28T17:10:07.929821Z  INFO iox_query::query_log: query when="success" id=92b506b4-fa8f-4359-8075-4b8ad2f744fc namespace_id=0 namespace_name="influxdb3 edge" query_type="sql" query_text=SELECT lat as latitude,lon as longitude,battery,time,altitude FROM telemetry ORDER BY time DESC LIMIT 1 query_params=Params { } issue_time=2024-10-28T17:10:07.915173299+00:00 partitions=0 parquet_files=0 deduplicated_partitions=0 deduplicated_parquet_files=0 plan_duration_secs=2.7132e-5 permit_duration_secs=1.3206e-5 execute_duration_secs=0.013937585 end2end_duration_secs=0.014639328 compute_duration_secs=0.001193133 max_memory=875393 ingester_metrics=IngesterMetrics { latency_to_plan = 0ns, latency_to_full_data = 0ns, response_rows = 0, partition_count = 0, response_size = 0 } success=true running=false cancelled=false

GRPC Client:

110ms

2024-10-28T17:11:23.527252Z  INFO iox_query::query_log: query when="success" id=aae1b4be-309b-46be-9c0d-b2a3e239a066 namespace_id=0 namespace_name="influxdb3 edge" query_type="sql" query_text=-- sql
SELECT
  lat AS latitude,
  lon AS longitude,
  battery,
  time,
  altitude
FROM telemetry
ORDER BY time DESC
LIMIT 1
 query_params=Params { } issue_time=2024-10-28T17:11:23.417186866+00:00 partitions=0 parquet_files=0 deduplicated_partitions=0 deduplicated_parquet_files=0 plan_duration_secs=0.022794678 permit_duration_secs=0.013986618 execute_duration_secs=0.07269745 end2end_duration_secs=0.110057621 compute_duration_secs=0.062325132 max_memory=15534625 ingester_metrics=IngesterMetrics { latency_to_plan = 0ns, latency_to_full_data = 0ns, response_rows = 0, partition_count = 0, response_size = 0 } success=true running=false cancelled=false