systeminit / si

The System Initiative software
https://systeminit.com
Apache License 2.0
1.54k stars 265 forks source link

`sdf` service is not starting in Local Development Setup #4833

Open minev-dev opened 5 hours ago

minev-dev commented 5 hours ago

What happened?

I'm following Local Development Setup.

After I run buck2 run dev:up all services are started except sdf, here are the logs:

Running cmd: buck2 build @//mode/release //bin/sdf:sdf
[2024-10-19T11:25:32.030-07:00] Build ID: ddc4aed8-9a40-446a-b0bc-a54d222437f6
[2024-10-19T11:25:32.031-07:00] File changed: root//
[2024-10-19T11:25:32.031-07:00] File changed: root//app/docs/src/.vitepress/config.ts.timestamp-1729362313385-f9c989742e5e.mjs
[2024-10-19T11:25:32.031-07:00] File changed: root//app/docs/src/.vitepress/cache/deps/_metadata.json
[2024-10-19T11:25:32.031-07:00] 59 additional file change events
[2024-10-19T11:25:39.032-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:25:46.131-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:25:53.131-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:26:00.230-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:26:07.331-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:26:14.430-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:26:21.529-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:26:28.530-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:26:35.629-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:26:42.629-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:26:49.630-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:26:56.729-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:27:03.828-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:27:10.828-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:27:17.929-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:27:25.028-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:27:32.128-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:27:39.228-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:27:46.329-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:27:53.428-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:28:00.428-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:28:07.528-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:28:14.627-07:00] Waiting on root//lib/sdf-server:sdf-server (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc rlib [pic]) [local_execute]
[2024-10-19T11:28:21.727-07:00] Waiting on root//bin/sdf:sdf (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc link [pic]) [local_execute]
[2024-10-19T11:28:28.826-07:00] Waiting on root//bin/sdf:sdf (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc link [pic]) [local_execute]
[2024-10-19T11:28:35.827-07:00] Waiting on root//bin/sdf:sdf (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc link [pic]) [local_execute]
[2024-10-19T11:28:42.827-07:00] Waiting on root//bin/sdf:sdf (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc link [pic]) [local_execute]
[2024-10-19T11:28:49.827-07:00] Waiting on root//bin/sdf:sdf (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc link [pic]) [local_execute]
[2024-10-19T11:28:56.925-07:00] Waiting on root//bin/sdf:sdf (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc link [pic]) [local_execute]
[2024-10-19T11:29:03.926-07:00] Waiting on root//bin/sdf:sdf (prelude-si//platforms:default#89c77ab9b148a055) -- action (rustc link [pic]) [local_execute]
[2024-10-19T11:29:10.402-07:00] Cache hits: 0%
[2024-10-19T11:29:10.402-07:00] Commands: 2 (cached: 0, remote: 0, local: 2)
[2024-10-19T11:29:10.402-07:00] Network: Up: 0B  Down: 0B
BUILD SUCCEEDED
Running cmd: buck2 run @//mode/release //bin/sdf:sdf | tee /tmp/si-logs/sdf
[2024-10-19T11:29:10.713-07:00] Build ID: 79665885-2cb7-4a01-9c14-71c881317946
[2024-10-19T11:29:10.717-07:00] Network: Up: 0B  Down: 0B
BUILD SUCCEEDED
2024-10-19T18:29:11.737089Z  WARN ThreadId(02) sdf_server::config: detected development run jwt_signing_public_key_path="/Users/minev/Documents/workspace/si/buck-out/v2/gen/root/89c77ab9b148a055/config/keys/__prod.jwt_signing_public_key.pem__/prod.jwt_signing_public_key.pem" veritech_encryption_key_path="/Users/minev/Documents/workspace/si/buck-out/v2/gen/root/89c77ab9b148a055/lib/veritech-server/__dev.encryption.key__/dev.encryption.key" symmetric_crypto_service_key="/Users/minev/Documents/workspace/si/buck-out/v2/gen/root/89c77ab9b148a055/lib/dal/__dev.donkey.key__/dev.donkey.key" postgres_cert="/Users/minev/Documents/workspace/si/buck-out/v2/gen/root/89c77ab9b148a055/config/keys/__dev.postgres.root.crt__/dev.postgres.root.crt" pkgs_path="/Users/minev/Documents/workspace/si/buck-out/v2/gen/root/89c77ab9b148a055/pkgs/__pkgs__/pkgs"
2024-10-19T18:29:11.747408Z  INFO ThreadId(05) async_nats: event: connected
2024-10-19T18:29:11.761574Z  INFO ThreadId(05) async_nats: event: connected
2024-10-19T18:29:11.961858Z  INFO ThreadId(02) sdf.init.from_config:sdf.init.initialize_layer_db:layer_db.init.from_config:layer_db.init.from_services: si_layer_cache::disk_cache: starting disk cache cleanup task for /tmp/sdf-cache-cCR8HM/sdf in remove mode
2024-10-19T18:29:11.978052Z  INFO ThreadId(02) sdf.init.from_config:sdf.init.from_services: sdf_server::server: http service bound to tcp socket socket=0.0.0.0:5156
2024-10-19T18:29:11.989133Z  INFO ThreadId(12) tokio_postgres::connection: NOTICE: relation "refinery_schema_history" already exists, skipping    
2024-10-19T18:29:11.997188Z  INFO ThreadId(02) sdf.migrator.run_migrations:sdf.migrator.migrate_layer_db_database: refinery_core::traits: current version: 8    
2024-10-19T18:29:11.997203Z  INFO ThreadId(02) sdf.migrator.run_migrations:sdf.migrator.migrate_layer_db_database: refinery_core::traits::r#async: no migrations to apply    
2024-10-19T18:29:12.000051Z  INFO ThreadId(02) sdf.migrator.run_migrations:sdf.migrator.migrate_dal_database:migrate_all_with_progress: dal: migrating elapsed=0.0008940830011852086
2024-10-19T18:29:12.006746Z  INFO ThreadId(12) tokio_postgres::connection: NOTICE: relation "refinery_schema_history" already exists, skipping    
2024-10-19T18:29:12.012535Z  INFO ThreadId(02) sdf.migrator.run_migrations:sdf.migrator.migrate_dal_database:migrate_all_with_progress:migrate_all:migrate: refinery_core::traits: current version: 3301    
2024-10-19T18:29:12.012549Z  INFO ThreadId(02) sdf.migrator.run_migrations:sdf.migrator.migrate_dal_database:migrate_all_with_progress:migrate_all:migrate: refinery_core::traits::r#async: no migrations to apply    
2024-10-19T18:29:12.014372Z  INFO ThreadId(02) sdf.migrator.run_migrations:sdf.migrator.migrate_dal_database:migrate_all_with_progress: dal: migrating completed elapsed=0.01521566603332758
2024-10-19T18:29:12.022734Z  INFO ThreadId(02) sdf.migrator.run_migrations:sdf.migrator.migrate_builtins_from_module_index: sdf_server::migrations: setup builtin workspace
2024-10-19T18:29:12.055220Z  INFO ThreadId(02) sdf.migrator.run_migrations:sdf.migrator.migrate_builtins_from_module_index: sdf_server::migrations: migrating intrinsic functions
2024-10-19T18:29:12.055645Z  INFO ThreadId(02) sdf.migrator.run_migrations:sdf.migrator.migrate_builtins_from_module_index: dal::builtins::func: importing
2024-10-19T18:29:12.057057Z  INFO ThreadId(02) sdf.migrator.run_migrations:sdf.migrator.migrate_builtins_from_module_index: dal::builtins::func: imported, commiting
2024-10-19T18:29:12.417170Z  INFO ThreadId(02) sdf.migrator.run_migrations:sdf.migrator.migrate_builtins_from_module_index: dal::builtins::func: commit finished
2024-10-19T18:29:13.108755Z  INFO ThreadId(02) sdf.migrator.run_migrations:sdf.migrator.migrate_builtins_from_module_index: sdf_server::migrations: builtins install starting
2024-10-19T18:29:13.108817Z  INFO ThreadId(02) sdf.migrator.run_migrations:sdf.migrator.migrate_builtins_from_module_index: sdf_server::migrations: migrating in progress... elapsed=1.0873557329177856
2024-10-19T18:29:17.039624Z  INFO ThreadId(02) sdf.migrator.run_migrations:sdf.migrator.migrate_builtins_from_module_index: sdf_server::migrations: migrating in progress... elapsed=5.018260955810547
2024-10-19T18:29:22.022592Z  INFO ThreadId(02) sdf.migrator.run_migrations:sdf.migrator.migrate_builtins_from_module_index: sdf_server::migrations: migrating in progress... elapsed=10.001357078552246
2024-10-19T18:29:23.895287Z  WARN ThreadId(03) tokio_dedicated_executor: a `DedicatedExecutor` was dropped without calling `shutdown()`
2024-10-19T18:29:23.895313Z  WARN ThreadId(03) tokio_dedicated_executor: a `DedicatedExecutor` was dropped without waiting for worker termination
Error: 
   0: error while migrating builtins from module index: rebase of batch d0c87e102b92aecfeaa63b7e70d819a41c24310f9c6f524b7763d06d24cf66a5 for change set id 01JAK0MS6V03ZJNKYP5WCWKCFV failed: missing rebase batch d0c87e102b92aecfeaa63b7e70d819a41c24310f9c6f524b7763d06d24cf66a5
   1: rebase of batch d0c87e102b92aecfeaa63b7e70d819a41c24310f9c6f524b7763d06d24cf66a5 for change set id 01JAK0MS6V03ZJNKYP5WCWKCFV failed: missing rebase batch d0c87e102b92aecfeaa63b7e70d819a41c24310f9c6f524b7763d06d24cf66a5

Location:
   <unknown>

Backtrace omitted. Run with RUST_BACKTRACE=1 environment variable to display it.
Run with RUST_BACKTRACE=full to include source snippets.
Server exited with exit code 0
image

How can we reproduce this?

Run 1-5 steps from Local Development Setup on MacOS M1 Pro

Operating system

macOS

Architecture

aarch64 / arm64

What browsers are you seeing the problem on?

Chrome

Code of Conduct

Additional context

No response

stack72 commented 4 hours ago

Hi @minev-dev

Thanks for opening the issue - sorry this is causing a problem for you. Can you set your ulimit 9999 and run "buck2 run dev:down" then "buck2 run dev:up"

I've a feeling that this is a ulimit issue but want to try and check that

Paul