Skip to content

feat(logging): default to info-level logging #207

Open
EddieHouston wants to merge 1 commit intoBlockstream:new-indexfrom
EddieHouston:startup-logging
Open

feat(logging): default to info-level logging #207
EddieHouston wants to merge 1 commit intoBlockstream:new-indexfrom
EddieHouston:startup-logging

Conversation

@EddieHouston
Copy link
Copy Markdown
Collaborator

@EddieHouston EddieHouston commented Apr 14, 2026

Summary

  • Electrs has been seen dying silently in environments running with no
    -v flag (error-only logging), making it impossible to diagnose where
    they got stuck.
  • Base log level is now info by default. -v selects debug, -vv
    selects trace.
  • Adds info! milestone logs at each startup phase: daemon connection,
    DB open, initial sync start/complete, mempool load, startup complete.
  • Promotes key debug! logs in schema.rs and db.rs to info! so
    block/header counts and DB open are visible at the default level.
  • Demotes noisy per-request and per-peer logs to debug! so the default
    output stays readable once startup completes.
  • Updates README, doc/usage.md, and contrib/electrs.service to drop
    the now-unnecessary -vvvv flag.

Test plan

  • Run electrs with no -v flag — startup milestones are logged and
    output stays quiet during steady-state operation.
  • Run electrs with -v / -vv — per-request and peer logs return
    as expected.
  • Kill electrs mid-startup — last log line indicates which phase it
    was in.

DeviaVir
DeviaVir previously approved these changes Apr 14, 2026
Comment thread src/.DS_Store Outdated
DeviaVir
DeviaVir previously approved these changes Apr 14, 2026
@EddieHouston EddieHouston self-assigned this Apr 14, 2026
Comment thread src/bin/electrs.rs
Comment thread src/bin/electrs.rs Outdated
@philippem
Copy link
Copy Markdown
Collaborator

philippem commented Apr 14, 2026

let's wait until we see

2026-04-14T11:28:46.020-07:00 - INFO Electrum RPC server running on 0.0.0.0:50001
2026-04-14T11:28:46.021-07:00 - INFO REST server running on 0.0.0.0:3001

before we revert verbosity. it's only at this point that electrs is ready

  • print the previous and after levels
  • the "Config" print message at startup should show the actual requested log level, not the overridden one:
$ ./run-release.sh
Config { log: StdErrLog { verbosity: Info, quiet: false, show_level: true, timestamp: Millisecond, modules: [], writer: "stderr", color_choice: Never, show_module_names: false }, network_type: Bitcoin, db_path: "/mnt/quattro/electrs/bitcoin-mainnet/mainnet", daemon_dir: "/home/phil/.bitcoin", blocks_dir: "/home/phil/.bitcoin/blocks", daemon_rpc_addr: 0.0.0.0:8332, daemon_parallelism: 8, cookie: Some("rpcuser:rpcpassword"), electrum_rpc_addr: 0.0.0.0:50001, http_addr: 0.0.0.0:3001, http_socket_file: None, monitoring_addr: 0.0.0.0:4224, jsonrpc_import: true, light_mode: false, address_search: false, index_unspendables: false, cors: Some("*"), precache_scripts: None, utxos_limit: 500, electrum_txs_limit: 500, electrum_banner: "Welcome to electrs-esplora 0.4.1", rpc_logging: RpcLogging { enabled: false, hide_params: false, anonymize_ip: false }, zmq_addr: None, log_verbosity: 1, db_block_cache_mb: 8192, db_parallelism: 20, db_write_buffer_size_mb: 256, initial_sync_batch_size: 100, db_cache_index_filter_blocks: false }

this is what it should show:

$ ./run-release.sh
Config { log: StdErrLog { verbosity: Error, quiet: false, show_level: true, timestamp: Millisecond, modules: [], writer: "stderr", color_choice: Auto, show_module_names: false }, network_type: Bitcoin, db_path: "/mnt/quattro/electrs/bitcoin-mainnet/mainnet", daemon_dir: "/home/phil/.bitcoin", blocks_dir: "/home/phil/.bitcoin/blocks", daemon_rpc_addr: 0.0.0.0:8332, daemon_parallelism: 8, cookie: Some("rpcuser:rpcpassword"), electrum_rpc_addr: 0.0.0.0:50001, http_addr: 0.0.0.0:3001, http_socket_file: None, monitoring_addr: 0.0.0.0:4224, jsonrpc_import: true, light_mode: false, address_search: false, index_unspendables: false, cors: Some("*"), precache_scripts: None, utxos_limit: 500, electrum_txs_limit: 500, electrum_banner: "Welcome to electrs-esplora 0.4.1", rpc_logging: RpcLogging { enabled: false, hide_params: false, anonymize_ip: false }, zmq_addr: None, db_block_cache_mb: 8192, db_parallelism: 20, db_write_buffer_size_mb: 256, initial_sync_batch_size: 100, db_cache_index_filter_blocks: false }
  • another way to implement this would be to add a second option for startup logging. that would simplify the set/revert mechanics

@shesek
Copy link
Copy Markdown
Collaborator

shesek commented Apr 14, 2026

I would consider a different approach: make level 2 logging (error+warn+info) the default and the minimum, such that a single -v enables debug-level logging and -vv enables trace (i.e. log.verbosity(2 + m.occurrences_of("verbosity"))). Then promote important log messages to be info-level (this PR already promotes some messages, but possibly too many. I think some should remain debug).

I don't think it's really ever desirable to hide error/warn/info messages, and it's typical for CLI programs to output these by default without requiring -v, so that behavior makes more sense to me. And it's also simpler than the revert mechanism introduced here.

Changing the meaning of -v does break backwards compatibility, but I think it's something we could live with. The (probably?) most typical setting, -vvvv, will still work the same. If we want to continue supporting logging level < 2, we could introduce a separate -q/--quiet parameter which is the more typical way to handle this, but I don't think that's really necessary.

@EddieHouston
Copy link
Copy Markdown
Collaborator Author

I would consider a different approach: make level 2 logging (error+warn+info) the default and the minimum, such that a single -v enables debug-level logging and -vv enables trace (i.e. log.verbosity(2 + m.occurrences_of("verbosity"))). Then promote important log messages to be info-level (this PR already promotes some messages, but possibly too many. I think some should remain debug).

I don't think it's really ever desirable to hide error/warn/info messages, and it's typical for CLI programs to output these by default without requiring -v, so that behavior makes more sense to me. And it's also simpler than the revert mechanism introduced here.

Changing the meaning of -v does break backwards compatibility, but I think it's something we could live with. The (probably?) most typical setting, -vvvv, will still work the same. If we want to continue supporting logging level < 2, we could introduce a separate -q/--quiet parameter which is the more typical way to handle this, but I don't think that's really necessary.

Good simplification. This does remove the need to override log levels. I can see demoting the mempool message changed in this PR back to debug. I could also see some other info logs we can demote to debug as well:

File Line Message Why
src/rest.rs 688 handle {:?} {:?} Every HTTP request — biggest noise source
src/electrum/server.rs 873 connected peer Every peer connection
src/electrum/server.rs 887 disconnected peer Every peer disconnection
src/daemon.rs 792 downloaded N/M block headers Chatty during initial sync (bracket messages stay info)
src/electrum/discovery.rs 591 Full server list JSON dump Large payload, periodic

If we later find that there is a need to implement the -q/--quiet option (depending on memory growth with 2 as the default)... we can then look at if an override on startup is necessary when that is set.

@EddieHouston EddieHouston force-pushed the startup-logging branch 3 times, most recently from be6a6d8 to 064b113 Compare April 16, 2026 07:16
@shesek
Copy link
Copy Markdown
Collaborator

shesek commented Apr 16, 2026

Looks great 👍

I could also see some other info logs we can demote to debug as well: ...

Agreed that these make sense to demote too.

Maybe squash the two commits and remove the "This replaces the previous approach" part? And also rename the PR.

  Electrs has been observed starting, running for a few minutes, then
  dying silently in environments with no verbosity flags set. With the
  previous default (error-only), there was zero diagnostic output.

  Base verbosity is now info (error+warn+info) without any flags. Each
  -v flag adds one level: -v=debug, -vv=trace.

  Adds explicit info! milestone logs at each startup phase in
  src/bin/electrs.rs: daemon connection, DB open, initial sync
  start/complete, mempool load, startup complete. Promotes messages in
  schema.rs (block/header counts, tip) and db.rs (opening DB) to info
  so they fire on startup.

  Demotes noisy messages to debug: per-request HTTP logging, peer
  connect/disconnect, header download progress, and the discovery
  server-list dump.

  Drops the now-unnecessary -vvvv flag from README, doc/usage.md, and
  contrib/electrs.service.
@EddieHouston EddieHouston changed the title feat(logging): always-on startup logging feat(logging): default to info-level logging Apr 17, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants