@@ -26,8 +26,11 @@ use oak_scan::ScanRequest;
2626use oak_scan:: ScanScheduler ;
2727use oak_semantic:: library:: Library ;
2828use stdext:: result:: ResultExt ;
29+ use stdext:: spawn;
30+ use tokio:: runtime:: Handle ;
2931use tokio:: sync:: mpsc;
3032use tokio:: sync:: mpsc:: unbounded_channel as tokio_unbounded_channel;
33+ use tokio:: sync:: oneshot;
3134use tokio:: task:: JoinHandle ;
3235use tower_lsp:: jsonrpc;
3336use tower_lsp:: lsp_types;
@@ -157,6 +160,21 @@ pub(crate) struct GlobalState {
157160 events_rx : TokioUnboundedReceiver < Event > ,
158161}
159162
163+ /// Owns the running LSP loops. Dropping it shuts them down.
164+ ///
165+ /// - The auxiliary loop is a runtime task, aborted when `_aux_loop` drops.
166+ /// - The main loop runs on its own thread. Dropping `_main_shutdown_tx` closes
167+ /// the channel the loop selects on, so it breaks, drops the owned
168+ /// `GlobalState`, and the thread exits. We hold the thread's handle but don't
169+ /// join it on drop (it winds down on its own), so dropping never blocks the
170+ /// caller.
171+ #[ derive( Debug ) ]
172+ pub ( crate ) struct LoopHandles {
173+ _main_loop : std:: thread:: JoinHandle < ( ) > ,
174+ _main_shutdown_tx : oneshot:: Sender < ( ) > ,
175+ _aux_loop : tokio:: task:: JoinSet < ( ) > ,
176+ }
177+
160178/// Non-cloneable, per-session state mutated only by exclusive handlers.
161179/// Sits alongside [`WorldState`] (which is cloneable for snapshot
162180/// handlers); state that can't be cloned lives here instead.
@@ -265,37 +283,66 @@ impl GlobalState {
265283 self . events_tx . clone ( )
266284 }
267285
268- /// Start the main and auxiliary loops
286+ /// Start the main and auxiliary loops.
269287 ///
270- /// Returns a `JoinSet` that holds onto all tasks and state owned by the
271- /// event loop. Drop it to cancel everything and shut down the service.
272- pub ( crate ) fn start ( self ) -> tokio:: task:: JoinSet < ( ) > {
273- let mut set = tokio:: task:: JoinSet :: < ( ) > :: new ( ) ;
274-
275- // Spawn latency-sensitive auxiliary loop. Must be first to initialise
276- // global transmission channel.
277- let aux = AuxiliaryState :: new ( self . client . clone ( ) ) ;
278- set. spawn ( async move { aux. start ( ) . await } ) ;
279-
280- // Spawn main loop
281- set. spawn ( async move { self . main_loop ( ) . await } ) ;
288+ /// The returned [`LoopHandles`] owns everything the loops need. Drop it to
289+ /// shut the loops down and release the owned state.
290+ pub ( crate ) fn start ( self ) -> LoopHandles {
291+ let mut aux = tokio:: task:: JoinSet :: < ( ) > :: new ( ) ;
292+
293+ // The auxiliary loop is fully async and never blocks. Must be started
294+ // first to initialise the global transmission channel.
295+ let aux_state = AuxiliaryState :: new ( self . client . clone ( ) ) ;
296+ aux. spawn ( async move { aux_state. start ( ) . await } ) ;
297+
298+ // Since the main loop owns the Salsa DB and writes to it, we run on its
299+ // own thread instead of a Tokio worker. Salsa writes are potentially
300+ // blocking until the writer gains exclusive access. If background tasks
301+ // holding clones of the DB are stuck on the same thread as the main
302+ // loop, the LSP deadlocks. This can be avoided by wrapping writes in
303+ // `block_in_place()` but the safer structure is to have it run on an OS
304+ // thread that we're in control of.
305+ let ( shutdown_tx, shutdown_rx) = oneshot:: channel ( ) ;
306+ let handle = Handle :: current ( ) ;
307+ let main_loop = spawn ! ( "oak-main-loop" , move || {
308+ handle. block_on( self . main_loop( shutdown_rx) ) ;
309+ } ) ;
282310
283- set
311+ LoopHandles {
312+ _main_shutdown_tx : shutdown_tx,
313+ _aux_loop : aux,
314+ _main_loop : main_loop,
315+ }
284316 }
285317
286318 /// Run main loop
287319 ///
288320 /// This takes ownership of all global state and handles one by one LSP
289321 /// requests, notifications, and other internal events.
290- async fn main_loop ( mut self ) {
322+ async fn main_loop ( mut self , mut shutdown_rx : oneshot :: Receiver < ( ) > ) {
291323 loop {
292- let event = self . next_event ( ) . await ;
293- if let Err ( err) = self . handle_event ( event) . await {
294- lsp:: log_error!( "Failure while handling event:\n {err:?}" )
324+ tokio:: select! {
325+ _ = & mut shutdown_rx => {
326+ lsp:: log_info!( "Main loop stopping: handle dropped" ) ;
327+ break ;
328+ } ,
329+ event = self . events_rx. recv( ) => {
330+ let Some ( event) = event else {
331+ lsp:: log_info!( "Main loop stopping: event channel closed" ) ;
332+ break ;
333+ } ;
334+ if let Err ( err) = self . handle_event( event) . await {
335+ lsp:: log_error!( "Failure while handling event:\n {err:?}" )
336+ }
337+ }
295338 }
296339 }
297340 }
298341
342+ /// Pull the next event off the channel. Only the test pump uses this; the
343+ /// running loop selects on the channel directly so it can also watch for
344+ /// shutdown.
345+ #[ cfg( test) ]
299346 async fn next_event ( & mut self ) -> Event {
300347 self . events_rx . recv ( ) . await . unwrap ( )
301348 }
@@ -329,6 +376,10 @@ impl GlobalState {
329376 Event :: Lsp ( msg) => match msg {
330377 LspMessage :: Notification ( notif) => {
331378 lsp:: log_info!( "{notif:#?}" ) ;
379+ lsp:: log_info!(
380+ "Entering notification handler with {n} outstanding Salsa db holds" ,
381+ n = self . world. db. outstanding_holds( )
382+ ) ;
332383
333384 match notif {
334385 LspNotification :: Initialized ( _params) => {
@@ -449,6 +500,8 @@ impl GlobalState {
449500 } ,
450501
451502 Event :: OakScanCompleted ( scan) => {
503+ lsp:: log_info!( "Received `OakScanCompleted`" ) ;
504+
452505 // This scan ran on a background task, but it sends its result
453506 // back here so the write happens on the main loop. Keep it that
454507 // way: Only the main loop should write to the oak DB (not
@@ -475,6 +528,12 @@ impl GlobalState {
475528 scan,
476529 & editor_owned,
477530 ) ;
531+ lsp:: log_info!(
532+ "Dispatching {n} followup scan requests with {n_holds} outstanding Salsa db holds" ,
533+ n = followups. len( ) ,
534+ n_holds = self . world. db. outstanding_holds( ) ,
535+ ) ;
536+
478537 dispatch_scan_requests ( & self . events_tx , followups) ;
479538
480539 // Warm the workspace index once the scan settles. Editor
@@ -486,13 +545,15 @@ impl GlobalState {
486545 }
487546 } ,
488547 }
548+ lsp:: log_info!( "Finished handling event in {}ms" , loop_tick. elapsed( ) . as_millis( ) ) ;
489549
490- // TODO Make this threshold configurable by the client
550+ // TODO: Make this threshold configurable by the client
491551 if loop_tick. elapsed ( ) > std:: time:: Duration :: from_millis ( 50 ) {
492- lsp:: log_info!( "Handler took {}ms" , loop_tick . elapsed ( ) . as_millis ( ) ) ;
552+ lsp:: log_info!( "Handler took more than 50ms" ) ;
493553 }
494554
495555 if salsa:: plumbing:: current_revision ( & self . world . db ) != old_revision {
556+ lsp:: log_info!( "World state revision advanced" ) ;
496557 diagnostics_refresh_all ( & self . world ) ;
497558 }
498559
@@ -937,11 +998,10 @@ async fn process_diagnostics_queue(mut rx: mpsc::UnboundedReceiver<RefreshDiagno
937998 }
938999 process_diagnostics_batch ( batch) ;
9391000 }
1001+ lsp:: log_warn!( "process_diagnostics_queue: channel closed, task exiting" ) ;
9401002}
9411003
9421004fn process_diagnostics_batch ( batch : Vec < RefreshDiagnosticsTask > ) {
943- tracing:: trace!( "Processing {n} diagnostic tasks" , n = batch. len( ) ) ;
944-
9451005 // Deduplicate tasks by keeping only the last one for each URI. We use a
9461006 // `HashMap` so only the last insertion is retained. This is effectively a
9471007 // way of cancelling diagnostics tasks for outdated documents.
@@ -950,6 +1010,9 @@ fn process_diagnostics_batch(batch: Vec<RefreshDiagnosticsTask>) {
9501010 . map ( |task| ( task. file . wire_url ( ) . clone ( ) , task) )
9511011 . collect ( ) ;
9521012
1013+ tracing:: trace!( "Processing {n} diagnostic tasks" , n = batch. len( ) ) ;
1014+ lsp:: log_info!( "Processing {n} diagnostic tasks" , n = batch. len( ) ) ;
1015+
9531016 // Each file is its own blocking task. `spawn_blocking()` catches salsa
9541017 // cancellation, so a pass cancelled by a concurrent edit just produces no
9551018 // event. The publish happens via the returned [`AuxiliaryEvent`].
@@ -979,8 +1042,16 @@ fn refresh_diagnostics(task: RefreshDiagnosticsTask) -> RefreshDiagnosticsResult
9791042 . components ( )
9801043 . any ( |c| c. as_os_str ( ) == "testthat" ) ;
9811044
1045+ let now = std:: time:: Instant :: now ( ) ;
1046+ lsp:: log_info!( "Generating diagnostics for file: {uri}" ) ;
1047+
9821048 let diagnostics = generate_diagnostics ( file. file ( ) , state, testthat) ;
9831049
1050+ lsp:: log_info!(
1051+ "Finished diagnostics for file: {uri} in {:.0?}" ,
1052+ now. elapsed( )
1053+ ) ;
1054+
9841055 RefreshDiagnosticsResult {
9851056 uri,
9861057 diagnostics,
@@ -1027,7 +1098,10 @@ pub(crate) fn diagnostics_refresh_all(state: &WorldState) {
10271098/// passes spawned by that same write force the same memos and finish the job.
10281099fn warm_workspace_index ( db : OakDatabase ) {
10291100 spawn_blocking ( move || {
1101+ let now = std:: time:: Instant :: now ( ) ;
1102+ lsp:: log_info!( "Starting workspace index warmup" ) ;
10301103 indexer:: warm ( & db) ;
1104+ lsp:: log_info!( "Finished workspace index warmup ({:.0?})" , now. elapsed( ) ) ;
10311105 Ok ( None )
10321106 } )
10331107}
0 commit comments