Skip to content

Getting a slow response from sync-service after 20s (in development) #4179

@iduuck

Description

@iduuck

Versions

  • Client: v1.5.13
  • Electric: v1.5.1 (Sync Service)
  • Tanstack DB

Bug description
I am experiencing an performance issue with my sync-service (running locally on docker-compose).

  • For URL's like /v1/shape?offset=-1&where=workspace_id+%3D+%27[ID]%27&orderBy=updated_at+desc&table=projects I am seeing a response time of 62µs
  • When adding handles, I am seeing a response time of always ~20000ms (i.e. /v1/shape?cursor=48797060&expired_handle=39099373-1777227296437870&handle=39099373-1777227567391493&live=true&log=full&offset=0_inf&where=workspace_id+%3D+%27[ID]M%27&orderBy=updated_at+desc&table=projects)

The biggest problem here is, that my app is always delayed by 20s, when working on development, which is also hindering my development workflow/DX

Expected behavior
I would expect to have the sync happen immediately, because the sync service would ideally cache everything locally, and then return it to me based on the file
system.

Note

Again, this is only happening locally on my docker container, on the web, this is near instant.


Logs without handles:

05:26:00.785 pid=<0.5609.0> request_id=GKofbh9tNsyOEGMAAFxB [debug] GET /v1/health

05:26:00.785 pid=<0.5609.0> request_id=GKofbh9tNsyOEGMAAFxB [debug] Sent 200 in 129µs

05:26:04.261 pid=<0.5611.0> request_id=GKofbu6fuEoABn8AAD2D [debug] GET /v1/shape

05:26:04.262 pid=<0.5611.0> request_id=GKofbu6fuEoABn8AAD2D [debug] Query String: offset=-1&where=workspace_id+%3D+%27[ID]%27&orderBy=updated_at+desc&table=projects

05:26:04.263 pid=<0.5611.0> request_id=GKofbu6fuEoABn8AAD2D [debug] Table {"public", "projects"} found with 17 columns. 
Column info: [%{name: "id", type: "text", formatted_type: "text", type_id: {25, -1}, type_mod: -1, pk_position: 0, array_type: nil, type_kind: :base, relation_id: 16793, array_dimensions: 0, not_null: true, is_generated: false}, %{name: "workspace_id", type: "text", formatted_type: "text", type_id: {25, -1}, type_mod: -1, pk_position: nil, array_type: nil, type_kind: :base, relation_id: 16793, array_dimensions: 0, not_null: true, is_generated: false}, %{name: "contact_id", type: "text", formatted_type: "text", type_id: {25, -1}, type_mod: -1, pk_position: nil, array_type: nil, type_kind: :base, relation_id: 16793, array_dimensions: 0, not_null: true, is_generated: false}, %{name: "building_id", type: "text", formatted_type: "text", type_id: {25, -1}, type_mod: -1, pk_position: nil, array_type: nil, type_kind: :base, relation_id: 16793, array_dimensions: 0, not_null: true, is_generated: false}, %{name: "title", type: "text", formatted_type: "text", type_id: {25, -1}, type_mod: -1, pk_position: nil, array_type: nil, type_kind: :base, relation_id: 16793, array_dimensions: 0, not_null: true, is_generated: false}, %{name: "type", type: "text", formatted_type: "text", type_id: {25, -1}, type_mod: -1, pk_position: nil, array_type: nil, type_kind: :base, relation_id: 16793, array_dimensions: 0, not_null: true, is_generated: false}, %{name: "status", type: "text", formatted_type: "text", type_id: {25, -1}, type_mod: -1, pk_position: nil, array_type: nil, ...}, ...]

05:26:04.273 pid=<0.5611.0> request_id=GKofbu6fuEoABn8AAD2D [debug] Sent 304 in 11ms

Logs with handles:

05:26:20.610 pid=<0.5611.0> request_id=GKofcr0V1-MABn8AAElC [debug] GET /v1/shape

05:26:20.610 pid=<0.5611.0> request_id=GKofcr0V1-MABn8AAElC [debug] Query String: cursor=48797060&expired_handle=39099373-1777227296437870&handle=39099373-1777227567391493&live=true&log=full&offset=0_inf&where=workspace_id+%3D+%27U[ID]%27&orderBy=updated_at+desc&table=projects

05:26:20.611 pid=<0.5611.0> request_id=GKofcr0V1-MABn8AAElC [debug] Table {"public", "projects"} found with 17 columns. 
Column info: [%{name: "id", type: "text", formatted_type: "text", type_id: {25, -1}, type_mod: -1, pk_position: 0, array_type: nil, type_kind: :base, relation_id: 16793, array_dimensions: 0, not_null: true, is_generated: false}, %{name: "workspace_id", type: "text", formatted_type: "text", type_id: {25, -1}, type_mod: -1, pk_position: nil, array_type: nil, type_kind: :base, relation_id: 16793, array_dimensions: 0, not_null: true, is_generated: false}, %{name: "contact_id", type: "text", formatted_type: "text", type_id: {25, -1}, type_mod: -1, pk_position: nil, array_type: nil, type_kind: :base, relation_id: 16793, array_dimensions: 0, not_null: true, is_generated: false}, %{name: "building_id", type: "text", formatted_type: "text", type_id: {25, -1}, type_mod: -1, pk_position: nil, array_type: nil, type_kind: :base, relation_id: 16793, array_dimensions: 0, not_null: true, is_generated: false}, %{name: "title", type: "text", formatted_type: "text", type_id: {25, -1}, type_mod: -1, pk_position: nil, array_type: nil, type_kind: :base, relation_id: 16793, array_dimensions: 0, not_null: true, is_generated: false}, %{name: "type", type: "text", formatted_type: "text", type_id: {25, -1}, type_mod: -1, pk_position: nil, array_type: nil, type_kind: :base, relation_id: 16793, array_dimensions: 0, not_null: true, is_generated: false}, %{name: "status", type: "text", formatted_type: "text", type_id: {25, -1}, type_mod: -1, pk_position: nil, array_type: nil, ...}, ...]

05:26:20.613 pid=<0.5611.0> request_id=GKofcr0V1-MABn8AAElC [debug] Client #PID<0.5611.0> is registered for changes to 39099373-1777227567391493

05:26:20.613 pid=<0.5611.0> request_id=GKofcr0V1-MABn8AAElC [debug] Client #PID<0.5611.0> is checking for any changes to 39099373-1777227567391493 since start of request

05:26:20.613 pid=<0.5611.0> request_id=GKofcr0V1-MABn8AAElC [debug] Client #PID<0.5611.0> is waiting for changes to 39099373-1777227567391493

05:26:28.969 pid=<0.5337.0> [debug] Primary Keepalive: wal_end=34568176 (0/20F77F0) reply=1

05:26:28.969 pid=<0.5337.0> [debug] Standby status update: received_wal=0/20F77F9, flushed_wal=0/20F77F9

05:26:30.826 pid=<0.5617.0> request_id=GKofdR4Df8EvXnQAAEoC [debug] GET /v1/health

05:26:30.826 pid=<0.5617.0> request_id=GKofdR4Df8EvXnQAAEoC [debug] Sent 200 in 60µs

05:26:40.615 pid=<0.5611.0> request_id=GKofcr0V1-MABn8AAElC [debug] Sent 200 in 20004ms

05:26:40.642 pid=<0.5611.0> request_id=GKofd2cdQ2AABn8AAEpC [debug] GET /.well-known/appspecific/com.chrome.devtools.json

05:26:40.643 pid=<0.5611.0> request_id=GKofd2cdQ2AABn8AAEpC [debug] Sent 404 in 350µs

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions