Ark: LSP crash while looking for completions or creating new document context

[lionel-]

Here is the state of my positron window when the crash happened. I was typing in the console IIRC:

Complete logs:

• crash.log
• crash-lsp.log

Relevant part of the log (why is the leading json truncated like this?):

[R]         contents: [
[R]             "plo",
[R]         ],
[R]         ast: {Tree {Node program (0, 0) - (0, 3)}},
[R]     },
[R]     node: {Node identifier (0, 0) - (0, 3)},
[R]     point: Point {
[R]         row: 0,
[R]         column: 3,
[R]     },
[R]     trigger: None,
[R] }
[R] 2024-04-08T11:36:43.272029000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-lsp' (ThreadId(22)) is requesting a task.
[R] 2024-04-08T11:36:43.272119000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-08T11:36:43.272176000Z [ark-unknown] INFO crates/ark/src/lsp/completions/provide.rs:22: provide_completions()
[R] 2024-04-08T11:36:43.272206000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique.rs:31: completions_from_unique_sources()
[R] 2024-04-08T11:36:43.272252000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/comment.rs:28: completions_from_comment()
[R] 2024-04-08T11:36:43.272281000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/string.rs:16: completions_from_string()
[R] 2024-04-08T11:36:43.272306000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/namespace.rs:36: completions_from_namespace()
[R] 2024-04-08T11:36:43.272335000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/custom.rs:35: completions_from_custom_source()
[R] 2024-04-08T11:36:43.272362000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/extractor.rs:48: completions_from_extractor()
[R] 2024-04-08T11:36:43.272386000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/extractor.rs:48: completions_from_extractor()
[R] 2024-04-08T11:36:43.272410000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite.rs:43: completions_from_composite_sources()
[R] 2024-04-08T11:36:43.272433000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/pipe.rs:59: find_pipe_root()
[R] 2024-04-08T11:36:43.272465000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/call.rs:33: completions_from_call()
[R] 2024-04-08T11:36:43.272492000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/subset.rs:27: completions_from_subset()
[R] 2024-04-08T11:36:43.272567000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/keyword.rs:12: completions_from_keywords()
[R] 2024-04-08T11:36:43.272608000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/snippets.rs:42: completions_from_snippets()
[R] 2024-04-08T11:36:43.273950000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/search_path.rs:31: completions_from_search_path()
[R] 2024-04-08T11:36:43.921781000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/workspace.rs:29: completions_from_workspace()
[R] 2024-04-08T11:36:43.924301000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-lsp' (ThreadId(22)) was unblocked after waiting for 652 milliseconds.
[R] 2024-04-08T11:36:43.978311000Z [ark-unknown] ERROR crates/ark/src/main.rs:461: Panic! In file 'crates/ark/src/lsp/document_context.rs' at line 28: called `Option::unwrap()` on a `None` value
[R] 2024-04-08T11:36:44.281187000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'stream' message via IOPub socket
[R] 2024-04-08T11:36:44.366263000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'stream' message via IOPub socket
[R] 2024-04-08T11:36:44.529633000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'stream' message via IOPub socket
[R] *** Log ended at Mon Apr  8 13:36:44 CEST 2024
[R] Process exit code 134
[R] 
[Positron] R kernel status changed: idle => exited
[Positron] No socket shell found.

Unfortunately the backtrace is missing from the logs for some reason. The crash happens here, we might want to replace the unwrap() with some logging:

https://github.com/posit-dev/amalthea/blob/ce635139ac93f22a12316710e640d601c80981cd/crates/ark/src/lsp/document_context.rs#L28

Slack threads:

• https://positpbc.slack.com/archives/C04FPQK3H9C/p1710960957178119
• https://positpbc.slack.com/archives/C05M2EZCPGR/p1712330668006389

[DavisVaughan]

Caught one while typing in the console in a pretty fresh Positron session. Here's everything in my Console that popped up as I was typing View(flights)

If I had to guess, maybe the signature_help() request is being fired on a new state of the document (according to the frontend the document probably looks like View() before the did_change() request has come through and updated the internal Rope to the same new state? Specifically, an example would look like:

Say the document is at View and I type the (

• On the frontend side, it processes (, thinks the state is now View(, and sends off did_change() to the LSP backend so we can sync up
• At roughly the same time, the frontend does a signature_help() request where the user's cursor is, i.e. at View(<>, i.e. (0, 5), and sends that to the LSP backend

But the signature_help() seems to have arrived before did_change(), so on our end our Rope only says View, not View(, but we got a request for position (0, 5), which doesn't exist yet, so we are unable to find a "closest node" to that point.

---

Note to self - I thought it was impossible for find_closest_node_to_point() to ever return None because it would always return the program node as a fallback case, but the point we are requesting here is TOTALLY OUTSIDE the document, even the overarching program node! So that's the real case we are looking out for.

> library(nycflights13)
thread 'ark-lsp' panicked at crates/ark/src/lsp/document_context.rs:32:13:
Failed to find closest node to point: (0, 5) with contents 'View'
stack backtrace:
   0: rust_begin_unwind
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/panicking.rs:645:5
   1: core::panicking::panic_fmt
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/panicking.rs:72:14
   2: ark::lsp::document_context::DocumentContext::new
             at /Users/davis/files/programming/positron/amalthea/crates/ark/src/lsp/document_context.rs:32:13
   3: <ark::lsp::backend::Backend as tower_lsp::LanguageServer>::signature_help::{{closure}}
             at /Users/davis/files/programming/positron/amalthea/crates/ark/src/lsp/backend.rs:420:23
   4: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/future/future.rs:125:9
   5: tower_lsp::generated::register_lsp_methods::signature_help::{{closure}}
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tower-lsp-0.19.0/src/lib.rs:112:1
   6: tower_lsp::jsonrpc::router::Router<S,E>::method::{{closure}}::{{closure}}::{{closure}}
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tower-lsp-0.19.0/src/jsonrpc/router.rs:58:64
   7: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/future/future.rs:125:9
   8: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/future/future/map.rs:55:37
   9: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/lib.rs:91:13
  10: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/future/future.rs:125:9
  11: <futures_util::abortable::Abortable<Fut> as core::future::future::Future>::poll::{{closure}}
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/abortable.rs:170:37
  12: futures_util::abortable::Abortable<T>::try_poll
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/abortable.rs:144:33
  13: <futures_util::abortable::Abortable<Fut> as core::future::future::Future>::poll
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/abortable.rs:170:9
  14: tower_lsp::service::pending::Pending::execute::{{closure}}
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tower-lsp-0.19.0/src/service/pending.rs:42:48
  15: <futures_util::future::either::Either<A,B> as core::future::future::Future>::poll
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/future/either.rs:109:32
  16: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/future/future.rs:125:9
  17: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/future/future.rs:125:9
  18: <tower_lsp::service::LspService<S> as tower_service::Service<tower_lsp::jsonrpc::Request>>::call::{{closure}}
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tower-lsp-0.19.0/src/service.rs:124:32
  19: <core::pin::Pin<P> as core::future::future::Future>::poll
             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/future/future.rs:125:9
  20: <F as futures_core::future::TryFuture>::try_poll
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-core-0.3.28/src/future.rs:82:9
  21: <futures_util::future::try_future::into_future::IntoFuture<Fut> as core::future::future::Future>::poll
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/future/try_future/into_future.rs:34:9
  22: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/future/future/map.rs:55:37
  23: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/lib.rs:91:13
  24: <futures_util::future::try_future::UnwrapOrElse<Fut,F> as core::future::future::Future>::poll
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/lib.rs:91:13
  25: <futures_util::stream::futures_unordered::FuturesUnordered<Fut> as futures_core::stream::Stream>::poll_next
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/stream/futures_unordered/mod.rs:518:17
  26: futures_util::stream::stream::StreamExt::poll_next_unpin
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/stream/stream/mod.rs:1632:9
  27: <futures_util::stream::stream::buffer_unordered::BufferUnordered<St> as futures_core::stream::Stream>::poll_next
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/stream/stream/buffer_unordered.rs:75:15
  28: <futures_util::stream::stream::filter_map::FilterMap<St,Fut,F> as futures_core::stream::Stream>::poll_next
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/stream/stream/filter_map.rs:79:47
  29: <futures_util::stream::stream::map::Map<St,F> as futures_core::stream::Stream>::poll_next
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/stream/stream/map.rs:58:26
  30: <futures_util::stream::stream::fuse::Fuse<S> as futures_core::stream::Stream>::poll_next
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/stream/stream/fuse.rs:53:27
  31: <futures_util::stream::stream::forward::Forward<St,Si,Item> as core::future::future::Future>::poll
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/stream/stream/forward.rs:59:19
  32: <futures_util::stream::stream::Forward<St,Si> as core::future::future::Future>::poll
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/lib.rs:91:13
  33: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/future/future/map.rs:55:37
  34: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/lib.rs:91:13
  35: <futures_util::future::maybe_done::MaybeDone<Fut> as core::future::future::Future>::poll
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/future/maybe_done.rs:95:38
  36: tower_lsp::transport::Server<I,O,L>::serve::{{closure}}::{{closure}}
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/async_await/join_mod.rs:95:13
  37: <futures_util::future::poll_fn::PollFn<F> as core::future::future::Future>::poll
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/future/poll_fn.rs:56:9
  38: tower_lsp::transport::Server<I,O,L>::serve::{{closure}}
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tower-lsp-0.19.0/src/transport.rs:163:9
  39: ark::lsp::backend::start_lsp::{{closure}}
             at /Users/davis/files/programming/positron/amalthea/crates/ark/src/lsp/backend.rs:570:31
  40: tokio::runtime::park::CachedParkThread::block_on::{{closure}}
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.28.1/src/runtime/park.rs:283:63
  41: tokio::runtime::coop::with_budget
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.28.1/src/runtime/coop.rs:107:5
  42: tokio::runtime::coop::budget
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.28.1/src/runtime/coop.rs:73:5
  43: tokio::runtime::park::CachedParkThread::block_on
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.28.1/src/runtime/park.rs:283:31
  44: tokio::runtime::context::BlockingRegionGuard::block_on
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.28.1/src/runtime/context.rs:315:13
  45: tokio::runtime::scheduler::multi_thread::MultiThread::block_on
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.28.1/src/runtime/scheduler/multi_thread/mod.rs:66:9
  46: tokio::runtime::runtime::Runtime::block_on
             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.28.1/src/runtime/runtime.rs:304:45
  47: ark::lsp::backend::start_lsp
             at /Users/davis/files/programming/positron/amalthea/crates/ark/src/lsp/backend.rs:511:5
  48: <ark::lsp::handler::Lsp as amalthea::language::server_handler::ServerHandler>::start::{{closure}}
             at /Users/davis/files/programming/positron/amalthea/crates/ark/src/lsp/handler.rs:60:13

Full Console output below. Nothing useful in LSP output.

2024-04-24 10:40:24.697 [info] [Positron] Connecting to R 4.3.1 kernel (pid 84913)
2024-04-24 10:40:24.697 [info] [Positron] Streaming log file: /var/folders/by/4wf2qrmn4_j93s5k5k5fzrx00000gp/T/kernel-u0l5Sf/kernel.log
2024-04-24 10:40:24.697 [info] [Positron] Connecting to kernel sockets defined in /var/folders/by/4wf2qrmn4_j93s5k5k5fzrx00000gp/T/kernel-u0l5Sf/connection.json...
2024-04-24 10:40:24.697 [info] [Positron] Control socket created (count = 1)
2024-04-24 10:40:24.697 [info] [Positron] Shell socket created (count = 2)
2024-04-24 10:40:24.697 [info] [Positron] Stdin socket created (count = 3)
2024-04-24 10:40:24.697 [info] [Positron] I/O socket created (count = 4)
2024-04-24 10:40:24.697 [info] [Positron] Heartbeat socket created (count = 5)
2024-04-24 10:40:24.697 [info] [Positron] Control socket connecting to tcp://127.0.0.1:49821...
2024-04-24 10:40:24.697 [info] [Positron] Shell socket connecting to tcp://127.0.0.1:48139...
2024-04-24 10:40:24.697 [info] [Positron] Stdin socket connecting to tcp://127.0.0.1:54889...
2024-04-24 10:40:24.697 [info] [Positron] I/O socket connecting to tcp://127.0.0.1:42448...
2024-04-24 10:40:24.697 [info] [Positron] Heartbeat socket connecting to tcp://127.0.0.1:51472...
[Positron] Shell socket connected to tcp://127.0.0.1:48139
[Positron] I/O socket connected to tcp://127.0.0.1:42448
[Positron] Control socket connected to tcp://127.0.0.1:49821
[Positron] Stdin socket connected to tcp://127.0.0.1:54889
[Positron] Heartbeat socket connected to tcp://127.0.0.1:51472
[Positron] Establishing socket listeners...
[Positron] Received initial heartbeat: heartbeat
[Positron] SEND kernel_info_request to Shell: {"buffers":[],"content":{},"header":{"msg_id":"98934144-4ae8-46c9-a6c7-286c48278191","msg_type":"kernel_info_request","version":"5.0","date":"2024-04-24T14:40:25.298Z","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] Starting heartbeat check at 30 second intervals...
[Positron] SEND heartbeat with timeout of 30 seconds
[Positron] SEND kernel_info_request: OK
[Positron] R kernel status changed: starting => ready
[Positron] SEND kernel_info_request to Shell: {"buffers":[],"content":{},"header":{"msg_id":"99d422d3-c835-4ab7-a0bb-4b66b4c84b1b","msg_type":"kernel_info_request","version":"5.0","date":"2024-04-24T14:40:25.410Z","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND kernel_info_request: OK
[Positron] Starting Positron LSP server on port 46335
[Positron] Starting LSP server positron-lsp-r-0-441e47c3 for 127.0.0.1:46335
[Positron] Creating 'positron.lsp' client for R
[Positron] SEND comm_open to Shell: {"buffers":[],"content":{"target_name":"positron.lsp","comm_id":"positron-lsp-r-0-441e47c3","data":{"client_address":"127.0.0.1:46335"}},"header":{"msg_id":"0224c99c-5d5e-4751-948c-642a62673995","msg_type":"comm_open","version":"5.0","date":"2024-04-24T14:40:25.411Z","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND comm_open: OK
[Positron] RECV kernel_info_reply from shell: {"header":{"msg_id":"9f160197-38ec-4808-a166-9ed163aa179c","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.410999+00:00","msg_type":"kernel_info_reply","version":"5.3"},"parent_header":{"msg_id":"99d422d3-c835-4ab7-a0bb-4b66b4c84b1b","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.410Z","msg_type":"kernel_info_request","version":"5.0"},"metadata":{},"content":{"status":"ok","protocol_version":"5.3","language_info":{"name":"R","version":"R version 4.3.1 (2023-06-16)","mimetype":"text/r","file_extension":".R","pygments_lexer":"","codemirror_mode":"","nbconvert_exporter":"","positron":{"input_prompt":"> ","continuation_prompt":"+ "}},"banner":"","debugger":false,"help_links":[]},"buffers":[]}
[Positron] Starting DAP server positron-dap-r-1-9ddcacbe for 127.0.0.1:63441
[Positron] Creating 'positron.dap' client for R
[Positron] SEND comm_open to Shell: {"buffers":[],"content":{"target_name":"positron.dap","comm_id":"positron-dap-r-1-9ddcacbe","data":{"client_address":"127.0.0.1:63441"}},"header":{"msg_id":"10e51d14-a82e-4131-959a-bc149196098a","msg_type":"comm_open","version":"5.0","date":"2024-04-24T14:40:25.412Z","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND comm_open: OK
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"dddce203-32a2-4e7c-bcd2-28b5657c4003","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.409141+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"98934144-4ae8-46c9-a6c7-286c48278191","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.298Z","msg_type":"kernel_info_request","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] R kernel status changed: ready => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"fce99db0-bd5d-4d0e-aae4-0f29e913f133","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.411020+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"99d422d3-c835-4ab7-a0bb-4b66b4c84b1b","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.410Z","msg_type":"kernel_info_request","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"7de66121-9a0a-48ac-b14b-b8c2a741e37d","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.411257+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"99d422d3-c835-4ab7-a0bb-4b66b4c84b1b","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.410Z","msg_type":"kernel_info_request","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"b2b76791-659f-40d2-b19b-fc78f55553c0","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.411774+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"0224c99c-5d5e-4751-948c-642a62673995","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.411Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"bcc6fa06-cf6c-4a00-b1ec-a61f45953b38","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.412561+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"0224c99c-5d5e-4751-948c-642a62673995","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.411Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] RECV comm_msg/LSP/server_started from iopub: {"header":{"msg_id":"7e424cf5-fc0d-4f66-8c79-516e8a085874","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.412677+00:00","msg_type":"comm_msg","version":"5.3"},"parent_header":null,"metadata":{},"content":{"comm_id":"positron-lsp-r-0-441e47c3","data":{"msg_type":"server_started","content":{}}},"buffers":[]}
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"c885f7a5-0b24-47c2-ac4f-940ce2eaa438","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.412773+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"10e51d14-a82e-4131-959a-bc149196098a","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.412Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] Creating 'positron.variables' client for R
[Positron] SEND comm_open to Shell: {"buffers":[],"content":{"target_name":"positron.variables","comm_id":"positron-variables-r-0-5ec14857","data":{}},"header":{"msg_id":"3d1daae2-9c3d-4ba8-a4ed-385a37297346","msg_type":"comm_open","version":"5.0","date":"2024-04-24T14:40:25.418Z","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND comm_open: OK
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"cf086da0-162c-438a-b689-bfbb49b17ccc","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.413298+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"10e51d14-a82e-4131-959a-bc149196098a","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.412Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] RECV comm_msg/DAP/server_started from iopub: {"header":{"msg_id":"4a347c82-1db4-4f45-a5f4-2e5604e2f117","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.413447+00:00","msg_type":"comm_msg","version":"5.3"},"parent_header":null,"metadata":{},"content":{"comm_id":"positron-dap-r-1-9ddcacbe","data":{"msg_type":"server_started","content":{}}},"buffers":[]}
[Positron] Unknown DAP command: server_started
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"d0fadc1a-1033-4d90-9af3-c73477365734","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.419027+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"3d1daae2-9c3d-4ba8-a4ed-385a37297346","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.418Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] Creating 'positron.ui' client for R
[Positron] SEND comm_open to Shell: {"buffers":[],"content":{"target_name":"positron.ui","comm_id":"positron-ui-r-1-e3eb9a4f","data":{}},"header":{"msg_id":"d40ca7a3-eaa9-4123-a0e5-396cb5ebe158","msg_type":"comm_open","version":"5.0","date":"2024-04-24T14:40:25.420Z","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND comm_open: OK
[Positron] Creating 'positron.help' client for R
[Positron] SEND comm_open to Shell: {"buffers":[],"content":{"target_name":"positron.help","comm_id":"positron-help-r-2-591b88dc","data":{}},"header":{"msg_id":"5ae1674e-a2f2-411f-acbf-c114af794f3e","msg_type":"comm_open","version":"5.0","date":"2024-04-24T14:40:25.420Z","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND comm_open: OK
[Positron] SEND comm_info_request to Shell: {"buffers":[],"content":{"target_name":"positron.plot"},"header":{"msg_id":"c25f666d-ddb0-46a7-a1b2-85d56c79ea60","msg_type":"comm_info_request","version":"5.0","date":"2024-04-24T14:40:25.421Z","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND comm_info_request: OK
[Positron] SEND comm_info_request to Shell: {"buffers":[],"content":{"target_name":"jupyter.widget"},"header":{"msg_id":"45d8bd9e-69b1-42b6-a456-fa10dcd240a0","msg_type":"comm_info_request","version":"5.0","date":"2024-04-24T14:40:25.421Z","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND comm_info_request: OK
[Positron] SEND comm_msg to Shell: {"buffers":[],"content":{"comm_id":"positron-ui-r-1-e3eb9a4f","data":{"jsonrpc":"2.0","method":"call_method","params":{"method":"setConsoleWidth","params":[80]}}},"header":{"msg_id":"c82a1ade-d793-467e-965e-fae03306bca9","msg_type":"comm_msg","version":"5.0","date":"2024-04-24T14:40:25.422Z","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] Set initial console width to 80
[Positron] SEND comm_msg: OK
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"229868b9-f92c-4714-bdce-f36bbfe467c8","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.419655+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"3d1daae2-9c3d-4ba8-a4ed-385a37297346","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.418Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] RECV comm_msg/positron-variables-r-0-5ec14857/undefined from iopub: {"header":{"msg_id":"01677894-6a6b-4b75-84bd-5368a3e05502","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.420686+00:00","msg_type":"comm_msg","version":"5.3"},"parent_header":null,"metadata":{},"content":{"comm_id":"positron-variables-r-0-5ec14857","data":{"method":"refresh","params":{"variables":[],"length":0,"version":1}}},"buffers":[]}
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"23ece30c-39af-4abf-9a9e-bba7332184b5","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.421070+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"d40ca7a3-eaa9-4123-a0e5-396cb5ebe158","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.420Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"fe3b075f-b23e-4dd3-91fa-e2252f2efc5c","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.421219+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"d40ca7a3-eaa9-4123-a0e5-396cb5ebe158","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.420Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] RECV comm_msg/positron-ui-r-1-e3eb9a4f/undefined from iopub: {"header":{"msg_id":"e894b690-f35c-4de0-b410-41abca07dc49","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.421496+00:00","msg_type":"comm_msg","version":"5.3"},"parent_header":null,"metadata":{},"content":{"comm_id":"positron-ui-r-1-e3eb9a4f","data":{"method":"working_directory","params":{"directory":"~/files/programming/tree-sitter-r"}}},"buffers":[]}
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"a82325e2-c02d-4d37-98aa-1af728060ae0","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.421890+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"5ae1674e-a2f2-411f-acbf-c114af794f3e","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.420Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] RECV comm_msg/positron-ui-r-1-e3eb9a4f/undefined from iopub: {"header":{"msg_id":"b2fbc162-6dc6-499d-841a-6e1b1853b981","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.421981+00:00","msg_type":"comm_msg","version":"5.3"},"parent_header":null,"metadata":{},"content":{"comm_id":"positron-ui-r-1-e3eb9a4f","data":{"method":"busy","params":{"busy":false}}},"buffers":[]}
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"ecb766a6-2d8c-4216-b09f-5934c0b8c688","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.431722+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"5ae1674e-a2f2-411f-acbf-c114af794f3e","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.420Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"479b1c39-dc1c-40eb-b2df-c5c261e34731","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.431992+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"c25f666d-ddb0-46a7-a1b2-85d56c79ea60","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.421Z","msg_type":"comm_info_request","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"6e9e9ec3-f752-4f50-8814-528a850b5644","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.432198+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"c25f666d-ddb0-46a7-a1b2-85d56c79ea60","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.421Z","msg_type":"comm_info_request","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"62eabe62-89fb-48df-93e6-d309c818c6f1","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.432492+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"45d8bd9e-69b1-42b6-a456-fa10dcd240a0","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.421Z","msg_type":"comm_info_request","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"2dc565dd-2a36-4849-a2f1-408efca7b541","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.432801+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"45d8bd9e-69b1-42b6-a456-fa10dcd240a0","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.421Z","msg_type":"comm_info_request","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"e938da11-a229-4097-9cec-9b46b20c0078","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.432995+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"c82a1ade-d793-467e-965e-fae03306bca9","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.422Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] R kernel status changed: busy => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"dffad589-6362-45a5-b62a-0af8be46b9fd","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.433230+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"c82a1ade-d793-467e-965e-fae03306bca9","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.422Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"753efb53-b435-4f9a-868c-c442b7f29bc5","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.433433+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"c82a1ade-d793-467e-965e-fae03306bca9","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.422Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"147daaf6-8d9b-465a-9762-a220f30bb9a6","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.433599+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"c82a1ade-d793-467e-965e-fae03306bca9","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.422Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] RECV comm_msg/positron-ui-r-1-e3eb9a4f/undefined from iopub: {"header":{"msg_id":"151ae988-760a-4c9e-9e0b-a5c43f0e4190","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.433769+00:00","msg_type":"comm_msg","version":"5.3"},"parent_header":{"msg_id":"c82a1ade-d793-467e-965e-fae03306bca9","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.422Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"comm_id":"positron-ui-r-1-e3eb9a4f","data":{"method":"CallMethodReply","result":80}},"buffers":[]}
[Positron] RECV comm_info_reply from shell: {"header":{"msg_id":"07e8d188-44e8-4d7d-b0e8-77fca2ce9594","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.431898+00:00","msg_type":"comm_info_reply","version":"5.3"},"parent_header":{"msg_id":"c25f666d-ddb0-46a7-a1b2-85d56c79ea60","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.421Z","msg_type":"comm_info_request","version":"5.0"},"metadata":{},"content":{"status":"ok","comms":{}},"buffers":[]}
[Positron] RECV comm_info_reply from shell: {"header":{"msg_id":"49364d17-7030-4dc5-ae2b-01e09f7ac642","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:25.432507+00:00","msg_type":"comm_info_reply","version":"5.3"},"parent_header":{"msg_id":"45d8bd9e-69b1-42b6-a456-fa10dcd240a0","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:25.421Z","msg_type":"comm_info_request","version":"5.0"},"metadata":{},"content":{"status":"ok","comms":{}},"buffers":[]}
[R] *** Log started at Wed Apr 24 10:40:24 EDT 2024
[R] *** Command line:
[R] /Users/davis/files/programming/positron/amalthea/target/debug/ark --connection_file /var/folders/by/4wf2qrmn4_j93s5k5k5fzrx00000gp/T/kernel-u0l5Sf/connection.json --log /var/folders/by/4wf2qrmn4_j93s5k5k5fzrx00000gp/T/kernel-u0l5Sf/kernel.log --startup-file /Users/davis/files/programming/positron/positron/extensions/positron-r/resources/scripts/startup.R --session-mode console -- --interactive --no-restore-data --quiet
[R] 2024-04-24T14:40:25.166649000Z [ark-unknown] INFO crates/ark/src/main.rs:217: Loaded connection information from frontend in /var/folders/by/4wf2qrmn4_j93s5k5k5fzrx00000gp/T/kernel-u0l5Sf/connection.json
[R] 2024-04-24T14:40:25.169876000Z [ark-unknown] DEBUG crates/ark/src/main.rs:221: Connection data: ConnectionFile { control_port: 49821, shell_port: 48139, stdin_port: 54889, iopub_port: 42448, hb_port: 51472, transport: "tcp", signature_scheme: "hmac-sha256", ip: "127.0.0.1", key: "4807e126ef0f8f673d60f90d3c4b05b6" }
[R] 2024-04-24T14:40:25.172747000Z [ark-unknown] TRACE crates/amalthea/src/socket/socket.rs:45: Binding to ZeroMQ 'Shell' socket at tcp://127.0.0.1:48139
[R] 2024-04-24T14:40:25.173591000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:25.173826000Z [ark-unknown] TRACE crates/amalthea/src/socket/socket.rs:45: Binding to ZeroMQ 'IOPub' socket at tcp://127.0.0.1:42448
[R] 2024-04-24T14:40:25.174205000Z [ark-unknown] TRACE crates/amalthea/src/socket/socket.rs:45: Binding to ZeroMQ 'Heartbeat' socket at tcp://127.0.0.1:51472
[R] 2024-04-24T14:40:25.174307000Z [ark-unknown] TRACE crates/amalthea/src/socket/iopub.rs:304: Entering kernel state: Starting
[R] 2024-04-24T14:40:25.174846000Z [ark-unknown] TRACE crates/amalthea/src/socket/socket.rs:45: Binding to ZeroMQ 'Stdin' socket at tcp://127.0.0.1:54889
[R] 2024-04-24T14:40:25.174897000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:28: Listening for heartbeats
[R] 2024-04-24T14:40:25.175104000Z [ark-unknown] TRACE crates/amalthea/src/socket/socket.rs:45: Binding to ZeroMQ 'Control' socket at tcp://127.0.0.1:49821
[R] 2024-04-24T14:40:25.175229000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'status/starting' message via IOPub socket
[R] 2024-04-24T14:40:25.175274000Z [ark-unknown] TRACE crates/amalthea/src/socket/socket.rs:91: Binding to ZeroMQ 'OutboundNotifierTx' socket at inproc://outbound_notif
[R] 2024-04-24T14:40:25.175337000Z [ark-unknown] TRACE crates/amalthea/src/socket/socket.rs:96: Connecting to ZeroMQ 'OutboundNotifierRx' socket at inproc://outbound_notif
[R] 2024-04-24T14:40:25.175565000Z [ark-unknown] TRACE crates/amalthea/src/socket/control.rs:58: Waiting for control messages
[R] 2024-04-24T14:40:25.183520000Z [ark-unknown] INFO crates/harp/src/sys/unix/library.rs:107: Setting 'DYLD_FALLBACK_LIBRARY_PATH' env var to '/Library/Frameworks/R.framework/Versions/4.3-arm64/Resources/lib:/Library/Java/JavaVirtualMachines/jdk-11.0.18+10/Contents/Home/lib/server'.
[R] 2024-04-24T14:40:25.187543000Z [ark-unknown] INFO crates/harp/src/library.rs:30: Successfully opened R shared library at '/Library/Frameworks/R.framework/Versions/4.3-arm64/Resources/lib/libR.dylib'.
[R] 2024-04-24T14:40:25.188837000Z [ark-unknown] TRACE crates/ark/src/sys/unix/interface.rs:56: R_HOME: "/Library/Frameworks/R.framework/Versions/4.3-arm64/Resources"
[R] 2024-04-24T14:40:25.297543000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:41: Heartbeat message: [104, 101, 97, 114, 116, 98, 101, 97, 116]
[R] 2024-04-24T14:40:25.297637000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:50: Heartbeat message replied
[R] 2024-04-24T14:40:25.297660000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:28: Listening for heartbeats
[R] 2024-04-24T14:40:25.299086000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:41: Heartbeat message: [104, 101, 97, 114, 116, 98, 101, 97, 116]
[R] 2024-04-24T14:40:25.299118000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:50: Heartbeat message replied
[R] 2024-04-24T14:40:25.299134000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:28: Listening for heartbeats
[R] 2024-04-24T14:40:25.299334000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:261: Received shell information request: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "98934144-4ae8-46c9-a6c7-286c48278191", session: "75b352bae874ffc75a1beb092c6d973b", username: "davis", date: "2024-04-24T14:40:25.298Z", msg_type: "kernel_info_request", version: "5.0" }, parent_header: None, content: KernelInfoRequest }
[R] 2024-04-24T14:40:25.299432000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'kernel_info_request') via IOPub socket
[R] 2024-04-24T14:40:25.299556000Z [ark-unknown] TRACE crates/ark/src/shell.rs:147: Got kernel info request; waiting for R to complete initialization
[R] 2024-04-24T14:40:25.371236000Z [ark-unknown] TRACE crates/ark/src/modules.rs:125: Loading R modules from sources via cargo manifest
[R] 2024-04-24T14:40:25.371302000Z [ark-unknown] INFO crates/ark/src/modules.rs:258: Loading modules from directory: /Users/davis/files/programming/positron/amalthea/crates/ark/src/modules/positron
[R] 2024-04-24T14:40:25.402339000Z [ark-unknown] INFO crates/ark/src/modules.rs:258: Loading modules from directory: /Users/davis/files/programming/positron/amalthea/crates/ark/src/modules/rstudio
[R] 2024-04-24T14:40:25.406414000Z [ark-unknown] INFO crates/ark/src/modules.rs:137: Watching R modules from sources via cargo manifest
[R] 2024-04-24T14:40:25.406738000Z [ark-unknown] INFO crates/ark/src/errors.rs:54: Initializing global error handler
[R] 2024-04-24T14:40:25.408510000Z [ark-unknown] INFO crates/ark/src/kernel.rs:132: Sending UI message to frontend: Event(Busy(BusyParams { busy: false }))
[R] 2024-04-24T14:40:25.408559000Z [ark-unknown] INFO crates/ark/src/kernel.rs:135: Discarding message Event(Busy(BusyParams { busy: false })); no frontend UI comm connected
[R] 2024-04-24T14:40:25.408618000Z [ark-unknown] TRACE crates/ark/src/interface.rs:743: prompt_info(): n_frame = '0'
[R] 2024-04-24T14:40:25.408657000Z [ark-unknown] DEBUG crates/ark/src/interface.rs:507: R prompt: > 
[R] 2024-04-24T14:40:25.408671000Z [ark-unknown] DEBUG crates/ark/src/interface.rs:448: Sending kernel info: R version 4.3.1 (2023-06-16)
[R] 2024-04-24T14:40:25.408855000Z [ark-unknown] TRACE crates/ark/src/interface.rs:512: Got initial R prompt '> ', ready for execution requests
[R] 2024-04-24T14:40:25.408905000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'kernel_info_reply' message (reply to 'kernel_info_request') via Shell socket
[R] 2024-04-24T14:40:25.409125000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:25.409153000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'kernel_info_request') via IOPub socket
[R] 2024-04-24T14:40:25.410941000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:261: Received shell information request: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "99d422d3-c835-4ab7-a0bb-4b66b4c84b1b", session: "75b352bae874ffc75a1beb092c6d973b", username: "davis", date: "2024-04-24T14:40:25.410Z", msg_type: "kernel_info_request", version: "5.0" }, parent_header: None, content: KernelInfoRequest }
[R] 2024-04-24T14:40:25.410979000Z [ark-unknown] TRACE crates/ark/src/shell.rs:150: R already started, using existing kernel information
[R] 2024-04-24T14:40:25.411029000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'kernel_info_reply' message (reply to 'kernel_info_request') via Shell socket
[R] 2024-04-24T14:40:25.411064000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'kernel_info_request') via IOPub socket
[R] 2024-04-24T14:40:25.411267000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:25.411374000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'kernel_info_request') via IOPub socket
[R] 2024-04-24T14:40:25.411677000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:312: Received request to open comm: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "0224c99c-5d5e-4751-948c-642a62673995", session: "75b352bae874ffc75a1beb092c6d973b", username: "davis", date: "2024-04-24T14:40:25.411Z", msg_type: "comm_open", version: "5.0" }, parent_header: None, content: CommOpen { comm_id: "positron-lsp-r-0-441e47c3", target_name: "positron.lsp", data: Object {"client_address": String("127.0.0.1:46335")} } }
[R] 2024-04-24T14:40:25.411803000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:25.411975000Z [ark-unknown] INFO crates/amalthea/src/comm/comm_manager.rs:135: Comm channel opened; there are now 1 open comms
[R] 2024-04-24T14:40:25.412158000Z [ark-unknown] TRACE crates/ark/src/lsp/backend.rs:517: Connecting to LSP at '127.0.0.1:46335'
[R] 2024-04-24T14:40:25.412546000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:25.412572000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:25.412694000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'comm_msg/LSP/unknown' message via IOPub socket
[R] 2024-04-24T14:40:25.412724000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:312: Received request to open comm: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "10e51d14-a82e-4131-959a-bc149196098a", session: "75b352bae874ffc75a1beb092c6d973b", username: "davis", date: "2024-04-24T14:40:25.412Z", msg_type: "comm_open", version: "5.0" }, parent_header: None, content: CommOpen { comm_id: "positron-dap-r-1-9ddcacbe", target_name: "positron.dap", data: Object {"client_address": String("127.0.0.1:63441")} } }
[R] 2024-04-24T14:40:25.412768000Z [ark-unknown] INFO crates/ark/src/dap/dap.rs:259: DAP: Spawning thread
[R] 2024-04-24T14:40:25.412792000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:25.412887000Z [ark-unknown] INFO crates/amalthea/src/comm/comm_manager.rs:135: Comm channel opened; there are now 2 open comms
[R] 2024-04-24T14:40:25.412928000Z [ark-unknown] TRACE crates/ark/src/dap/dap_server.rs:53: DAP: Thread starting at address 127.0.0.1:63441.
[R] 2024-04-24T14:40:25.413252000Z [ark-unknown] TRACE crates/ark/src/dap/dap_server.rs:62: DAP: Waiting for client
[R] 2024-04-24T14:40:25.413275000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:25.413363000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:25.413467000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'comm_msg/DAP/unknown' message via IOPub socket
[R] 2024-04-24T14:40:25.418941000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:312: Received request to open comm: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "3d1daae2-9c3d-4ba8-a4ed-385a37297346", session: "75b352bae874ffc75a1beb092c6d973b", username: "davis", date: "2024-04-24T14:40:25.418Z", msg_type: "comm_open", version: "5.0" }, parent_header: None, content: CommOpen { comm_id: "positron-variables-r-0-5ec14857", target_name: "positron.variables", data: Object {} } }
[R] 2024-04-24T14:40:25.419028000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-shell' (ThreadId(17)) is requesting a task.
[R] 2024-04-24T14:40:25.419111000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:25.419214000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:25.419539000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-shell' (ThreadId(17)) was unblocked after waiting for 0 milliseconds.
[R] 2024-04-24T14:40:25.419581000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-variables' (ThreadId(28)) is requesting a task.
[R] 2024-04-24T14:40:25.419843000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:25.419869000Z [ark-unknown] INFO crates/amalthea/src/comm/comm_manager.rs:135: Comm channel opened; there are now 3 open comms
[R] 2024-04-24T14:40:25.419899000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:25.419925000Z [ark-unknown] TRACE crates/ark/src/lsp/backend.rs:526: Connected to LSP at '127.0.0.1:46335'
[R] 2024-04-24T14:40:25.420006000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:25.420258000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-variables' (ThreadId(28)) was unblocked after waiting for 0 milliseconds.
[R] 2024-04-24T14:40:25.420665000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-lsp' (ThreadId(26)) is requesting a task.
[R] 2024-04-24T14:40:25.420751000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'comm_msg/variables/refresh' message via IOPub socket
[R] 2024-04-24T14:40:25.420786000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:25.420870000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-lsp' (ThreadId(26)) was unblocked after waiting for 0 milliseconds.
[R] 2024-04-24T14:40:25.420971000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:312: Received request to open comm: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "d40ca7a3-eaa9-4123-a0e5-396cb5ebe158", session: "75b352bae874ffc75a1beb092c6d973b", username: "davis", date: "2024-04-24T14:40:25.420Z", msg_type: "comm_open", version: "5.0" }, parent_header: None, content: CommOpen { comm_id: "positron-ui-r-1-e3eb9a4f", target_name: "positron.ui", data: Object {} } }
[R] 2024-04-24T14:40:25.421079000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:25.421156000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:25.421219000Z [ark-unknown] INFO crates/amalthea/src/comm/comm_manager.rs:135: Comm channel opened; there are now 4 open comms
[R] 2024-04-24T14:40:25.421297000Z [ark-unknown] INFO crates/ark/src/kernel.rs:132: Sending UI message to frontend: Event(WorkingDirectory(WorkingDirectoryParams { directory: "~/files/programming/tree-sitter-r" }))
[R] 2024-04-24T14:40:25.421339000Z [ark-unknown] INFO crates/ark/src/r_task.rs:161: Thread 'ark-shell-thread' (ThreadId(15)) is requesting an async task.
[R] 2024-04-24T14:40:25.421360000Z [ark-unknown] INFO crates/ark/src/r_task.rs:173: Thread 'ark-shell-thread' (ThreadId(15)) has sent the async task.
[R] 2024-04-24T14:40:25.421377000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:25.421496000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:25.421528000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:312: Received request to open comm: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "5ae1674e-a2f2-411f-acbf-c114af794f3e", session: "75b352bae874ffc75a1beb092c6d973b", username: "davis", date: "2024-04-24T14:40:25.420Z", msg_type: "comm_open", version: "5.0" }, parent_header: None, content: CommOpen { comm_id: "positron-help-r-2-591b88dc", target_name: "positron.help", data: Object {} } }
[R] 2024-04-24T14:40:25.421738000Z [ark-unknown] INFO crates/ark/src/kernel.rs:132: Sending UI message to frontend: Event(Busy(BusyParams { busy: false }))
[R] 2024-04-24T14:40:25.421763000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-shell' (ThreadId(17)) is requesting a task.
[R] 2024-04-24T14:40:25.421788000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'comm_msg/positron-ui-r-1-e3eb9a4f/working_directory' message via IOPub socket
[R] 2024-04-24T14:40:25.421835000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:25.421901000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:25.422001000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'comm_msg/positron-ui-r-1-e3eb9a4f/busy' message via IOPub socket
[R] 2024-04-24T14:40:25.429932000Z [ark-unknown] INFO crates/ark/src/lsp/indexer.rs:115: Indexing started.
[R] 2024-04-24T14:40:25.431350000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-shell' (ThreadId(17)) was unblocked after waiting for 9 milliseconds.
[R] 2024-04-24T14:40:25.431456000Z [ark-unknown] TRACE crates/ark/src/help/r_help.rs:75: Help comm positron-help-r-2-591b88dc started; started help server on port 16542
[R] 2024-04-24T14:40:25.431500000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-shell' (ThreadId(17)) is requesting a task.
[R] 2024-04-24T14:40:25.431555000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:25.431629000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-shell' (ThreadId(17)) was unblocked after waiting for 0 milliseconds.
[R] 2024-04-24T14:40:25.431671000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:25.431760000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:25.431855000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:287: Received request for open comms: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "c25f666d-ddb0-46a7-a1b2-85d56c79ea60", session: "75b352bae874ffc75a1beb092c6d973b", username: "davis", date: "2024-04-24T14:40:25.421Z", msg_type: "comm_info_request", version: "5.0" }, parent_header: None, content: CommInfoRequest { target_name: "positron.plot" } }
[R] 2024-04-24T14:40:25.431911000Z [ark-unknown] INFO crates/amalthea/src/comm/comm_manager.rs:135: Comm channel opened; there are now 5 open comms
[R] 2024-04-24T14:40:25.431985000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'comm_info_reply' message (reply to 'comm_info_request') via Shell socket
[R] 2024-04-24T14:40:25.432023000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_info_request') via IOPub socket
[R] 2024-04-24T14:40:25.432145000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:25.432246000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_info_request') via IOPub socket
[R] 2024-04-24T14:40:25.432467000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:287: Received request for open comms: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "45d8bd9e-69b1-42b6-a456-fa10dcd240a0", session: "75b352bae874ffc75a1beb092c6d973b", username: "davis", date: "2024-04-24T14:40:25.421Z", msg_type: "comm_info_request", version: "5.0" }, parent_header: None, content: CommInfoRequest { target_name: "jupyter.widget" } }
[R] 2024-04-24T14:40:25.432504000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_info_request') via IOPub socket
[R] 2024-04-24T14:40:25.432540000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'comm_info_reply' message (reply to 'comm_info_request') via Shell socket
[R] 2024-04-24T14:40:25.432766000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:25.432809000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_info_request') via IOPub socket
[R] 2024-04-24T14:40:25.432981000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:339: Received request to send a message on a comm: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "c82a1ade-d793-467e-965e-fae03306bca9", session: "75b352bae874ffc75a1beb092c6d973b", username: "davis", date: "2024-04-24T14:40:25.422Z", msg_type: "comm_msg", version: "5.0" }, parent_header: None, content: CommWireMsg { comm_id: "positron-ui-r-1-e3eb9a4f", data: Object {"jsonrpc": String("2.0"), "method": String("call_method"), "params": Object {"method": String("setConsoleWidth"), "params": Array [Number(80)]}} } }
[R] 2024-04-24T14:40:25.433013000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:25.433068000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:25.433097000Z [ark-unknown] TRACE crates/amalthea/src/comm/comm_manager.rs:157: Comm manager: Sending message to comm 'positron.ui'
[R] 2024-04-24T14:40:25.433246000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:25.433315000Z [ark-unknown] TRACE crates/ark/src/ui/ui.rs:145: Handling 'setConsoleWidth' frontend RPC method
[R] 2024-04-24T14:40:25.433368000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-comm-ui' (ThreadId(29)) is requesting a task.
[R] 2024-04-24T14:40:25.433448000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:25.433488000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:25.433573000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-comm-ui' (ThreadId(29)) was unblocked after waiting for 0 milliseconds.
[R] 2024-04-24T14:40:25.433592000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-comm-ui' (ThreadId(29)) is requesting a task.
[R] 2024-04-24T14:40:25.433611000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:25.433642000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:25.433709000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-comm-ui' (ThreadId(29)) was unblocked after waiting for 0 milliseconds.
[R] 2024-04-24T14:40:25.433805000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'comm_msg/positron-ui-r-1-e3eb9a4f/CallMethodReply' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:25.494228000Z [ark-unknown] INFO crates/ark/src/lsp/indexer.rs:131: Indexing finished after 64.296ms.
[Positron] SEND comm_msg to Shell: {"buffers":[],"content":{"comm_id":"positron-ui-r-1-e3eb9a4f","data":{"jsonrpc":"2.0","method":"call_method","params":{"method":"setConsoleWidth","params":[91]}}},"header":{"msg_id":"c83281d1-31a5-4a95-af44-f2863d6226b0","msg_type":"comm_msg","version":"5.0","date":"2024-04-24T14:40:44.963Z","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND comm_msg: OK
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"939600ac-3d05-4c89-8f7a-823cba0bb697","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:44.964312+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"c83281d1-31a5-4a95-af44-f2863d6226b0","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:44.963Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] R kernel status changed: busy => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"82651dc9-07d4-43ba-8461-b910461a5fe4","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:44.964501+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"c83281d1-31a5-4a95-af44-f2863d6226b0","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:44.963Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"c3865a3c-1cda-44c2-9ed1-5e4eb4967ef6","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:44.964576+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"c83281d1-31a5-4a95-af44-f2863d6226b0","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:44.963Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"1a626d94-2e58-4c83-8c76-b75c788769df","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:44.964649+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"c83281d1-31a5-4a95-af44-f2863d6226b0","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:44.963Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] RECV comm_msg/positron-ui-r-1-e3eb9a4f/undefined from iopub: {"header":{"msg_id":"fe014f90-63cc-4266-b9b5-6af232efd236","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:44.964931+00:00","msg_type":"comm_msg","version":"5.3"},"parent_header":{"msg_id":"c83281d1-31a5-4a95-af44-f2863d6226b0","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:44.963Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"comm_id":"positron-ui-r-1-e3eb9a4f","data":{"method":"CallMethodReply","result":80}},"buffers":[]}
[Positron] Set console width from 80 to 91
[Positron] SEND comm_msg to Shell: {"buffers":[],"content":{"comm_id":"positron-ui-r-1-e3eb9a4f","data":{"jsonrpc":"2.0","method":"call_method","params":{"method":"setConsoleWidth","params":[89]}}},"header":{"msg_id":"bc08dd1c-d141-4552-b428-a17fdad9b868","msg_type":"comm_msg","version":"5.0","date":"2024-04-24T14:40:46.160Z","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND comm_msg: OK
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"0073d931-5ddd-47d0-a5c0-9319f1334f13","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:46.160592+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"bc08dd1c-d141-4552-b428-a17fdad9b868","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:46.160Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] R kernel status changed: busy => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"e8ca3af0-4c46-454f-b4b9-1ab866d8a41a","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:46.160757+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"bc08dd1c-d141-4552-b428-a17fdad9b868","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:46.160Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"b39863c9-2697-4ff6-befa-7bf1f28a1cc6","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:46.160912+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"bc08dd1c-d141-4552-b428-a17fdad9b868","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:46.160Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"1937859b-efc9-423d-a421-9e507aca21ce","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:46.160981+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"bc08dd1c-d141-4552-b428-a17fdad9b868","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:46.160Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] RECV comm_msg/positron-ui-r-1-e3eb9a4f/undefined from iopub: {"header":{"msg_id":"e3c5bbc0-6365-4cdf-806e-72b3c9c95373","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:46.186180+00:00","msg_type":"comm_msg","version":"5.3"},"parent_header":{"msg_id":"bc08dd1c-d141-4552-b428-a17fdad9b868","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:46.160Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"comm_id":"positron-ui-r-1-e3eb9a4f","data":{"method":"CallMethodReply","result":91}},"buffers":[]}
[Positron] Set console width from 91 to 89
[Positron] SEND is_complete_request to Shell: {"buffers":[],"content":{"code":"library(nycflights13)"},"header":{"msg_id":"9b876888-757c-40fc-885e-d6bf8894b6ff","msg_type":"is_complete_request","version":"5.0","date":"2024-04-24T14:40:47.766Z","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND is_complete_request: OK
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"1480495c-7d06-473a-8aa4-d6133f40d9d2","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:47.767217+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"9b876888-757c-40fc-885e-d6bf8894b6ff","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:47.766Z","msg_type":"is_complete_request","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] RECV is_complete_reply from shell: {"header":{"msg_id":"421689d8-d0c7-4c21-8956-16445de75a76","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:47.824851+00:00","msg_type":"is_complete_reply","version":"5.3"},"parent_header":{"msg_id":"9b876888-757c-40fc-885e-d6bf8894b6ff","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:47.766Z","msg_type":"is_complete_request","version":"5.0"},"metadata":{},"content":{"status":"complete","indent":""},"buffers":[]}
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"50ddb733-0bcd-43dd-b46d-90abd8981bb3","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:47.825078+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"9b876888-757c-40fc-885e-d6bf8894b6ff","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:47.766Z","msg_type":"is_complete_request","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] Sending code to R: library(nycflights13)
[Positron] SEND execute_request to Shell: {"buffers":[],"content":{"code":"library(nycflights13)","allow_stdin":true,"silent":false,"store_history":true,"user_expressions":{},"stop_on_error":false},"header":{"msg_id":"fragment-63b439b5-d220-45a8-9797-ce0616b86b04","msg_type":"execute_request","version":"5.0","date":"2024-04-24T14:40:47.830Z","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND execute_request: OK
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"c3dc4fb4-0c3c-4059-a7da-a804a7375ff8","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:47.830500+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"fragment-63b439b5-d220-45a8-9797-ce0616b86b04","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:47.830Z","msg_type":"execute_request","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] RECV execute_input from iopub: {"header":{"msg_id":"eab1ddad-0cbe-48c3-8788-c97d4eb765fc","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:47.830666+00:00","msg_type":"execute_input","version":"5.3"},"parent_header":{"msg_id":"fragment-63b439b5-d220-45a8-9797-ce0616b86b04","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:47.830Z","msg_type":"execute_request","version":"5.0"},"metadata":{},"content":{"code":"library(nycflights13)","execution_count":1},"buffers":[]}
[Positron] RECV comm_msg/positron-ui-r-1-e3eb9a4f/undefined from iopub: {"header":{"msg_id":"0e5dae91-2e7f-4bb7-ba57-cd530bf4edcd","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:47.830757+00:00","msg_type":"comm_msg","version":"5.3"},"parent_header":null,"metadata":{},"content":{"comm_id":"positron-ui-r-1-e3eb9a4f","data":{"method":"busy","params":{"busy":true}}},"buffers":[]}
[Positron] RECV comm_msg/positron-ui-r-1-e3eb9a4f/undefined from iopub: {"header":{"msg_id":"1c5e3753-9b51-468c-b8af-d1504010f6cf","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:48.014647+00:00","msg_type":"comm_msg","version":"5.3"},"parent_header":null,"metadata":{},"content":{"comm_id":"positron-ui-r-1-e3eb9a4f","data":{"method":"busy","params":{"busy":false}}},"buffers":[]}
[Positron] RECV comm_msg/positron-ui-r-1-e3eb9a4f/undefined from iopub: {"header":{"msg_id":"c7e01bdc-333a-4d63-83e0-6d862da8d568","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:48.014817+00:00","msg_type":"comm_msg","version":"5.3"},"parent_header":null,"metadata":{},"content":{"comm_id":"positron-ui-r-1-e3eb9a4f","data":{"method":"prompt_state","params":{"input_prompt":"> ","continuation_prompt":"+ "}}},"buffers":[]}
[Positron] RECV execute_result from iopub: {"header":{"msg_id":"b6f221aa-ea47-4316-9f34-7ccd8af69d88","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:48.015030+00:00","msg_type":"execute_result","version":"5.3"},"parent_header":{"msg_id":"fragment-63b439b5-d220-45a8-9797-ce0616b86b04","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:47.830Z","msg_type":"execute_request","version":"5.0"},"metadata":{},"content":{"data":{"text/plain":""},"execution_count":1,"metadata":{}},"buffers":[]}
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"3750a51b-3e6d-454b-accd-7ee4f20838a4","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:48.015312+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"fragment-63b439b5-d220-45a8-9797-ce0616b86b04","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:47.830Z","msg_type":"execute_request","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] RECV execute_reply from shell: {"header":{"msg_id":"f9e85e70-2475-4d3c-8afd-d18e773f6b5d","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:48.015196+00:00","msg_type":"execute_reply","version":"5.3"},"parent_header":{"msg_id":"fragment-63b439b5-d220-45a8-9797-ce0616b86b04","session":"75b352bae874ffc75a1beb092c6d973b","username":"davis","date":"2024-04-24T14:40:47.830Z","msg_type":"execute_request","version":"5.0"},"metadata":{},"content":{"status":"ok","execution_count":1,"user_expressions":{}},"buffers":[]}
[R] 2024-04-24T14:40:44.964305000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:339: Received request to send a message on a comm: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "c83281d1-31a5-4a95-af44-f2863d6226b0", session: "75b352bae874ffc75a1beb092c6d973b", username: "davis", date: "2024-04-24T14:40:44.963Z", msg_type: "comm_msg", version: "5.0" }, parent_header: None, content: CommWireMsg { comm_id: "positron-ui-r-1-e3eb9a4f", data: Object {"jsonrpc": String("2.0"), "method": String("call_method"), "params": Object {"method": String("setConsoleWidth"), "params": Array [Number(91)]}} } }
[R] 2024-04-24T14:40:44.964385000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:44.964415000Z [ark-unknown] TRACE crates/amalthea/src/comm/comm_manager.rs:157: Comm manager: Sending message to comm 'positron.ui'
[R] 2024-04-24T14:40:44.964467000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:44.964491000Z [ark-unknown] TRACE crates/ark/src/ui/ui.rs:145: Handling 'setConsoleWidth' frontend RPC method
[R] 2024-04-24T14:40:44.964508000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:44.964526000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-comm-ui' (ThreadId(29)) is requesting a task.
[R] 2024-04-24T14:40:44.964582000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:44.964605000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:44.964654000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:44.964704000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-comm-ui' (ThreadId(29)) was unblocked after waiting for 0 milliseconds.
[R] 2024-04-24T14:40:44.964762000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-comm-ui' (ThreadId(29)) is requesting a task.
[R] 2024-04-24T14:40:44.964804000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:44.964878000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-comm-ui' (ThreadId(29)) was unblocked after waiting for 0 milliseconds.
[R] 2024-04-24T14:40:44.964945000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'comm_msg/positron-ui-r-1-e3eb9a4f/CallMethodReply' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:45.477576000Z [ark-unknown] INFO crates/ark/src/lsp/indexer.rs:70: Received signal that indexer was initialized, proceeding with diagnostics.
[R] 2024-04-24T14:40:45.478177000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'tokio-runtime-worker' (ThreadId(10)) is requesting a task.
[R] 2024-04-24T14:40:45.478379000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:45.589030000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'tokio-runtime-worker' (ThreadId(10)) was unblocked after waiting for 110 milliseconds.
[R] 2024-04-24T14:40:45.979325000Z [ark-unknown] INFO crates/ark/src/lsp/backend.rs:342: Completion context: DocumentContext {
[R]     document: Document {
[R]         contents: [
[R]             "lib",
[R]         ],
[R]         ast: {Tree {Node program (0, 0) - (0, 3)}},
[R]     },
[R]     node: {Node identifier (0, 0) - (0, 3)},
[R]     point: Point {
[R]         row: 0,
[R]         column: 3,
[R]     },
[R]     trigger: None,
[R] }
[R] 2024-04-24T14:40:45.979740000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-lsp' (ThreadId(26)) is requesting a task.
[R] 2024-04-24T14:40:45.979860000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:45.979985000Z [ark-unknown] INFO crates/ark/src/lsp/completions/provide.rs:22: provide_completions()
[R] 2024-04-24T14:40:45.980020000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique.rs:31: completions_from_unique_sources()
[R] 2024-04-24T14:40:45.980079000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/comment.rs:28: completions_from_comment()
[R] 2024-04-24T14:40:45.980100000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/string.rs:16: completions_from_string()
[R] 2024-04-24T14:40:45.980140000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/namespace.rs:36: completions_from_namespace()
[R] 2024-04-24T14:40:45.980162000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/custom.rs:35: completions_from_custom_source()
[R] 2024-04-24T14:40:45.980180000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/extractor.rs:48: completions_from_extractor()
[R] 2024-04-24T14:40:45.980196000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/extractor.rs:48: completions_from_extractor()
[R] 2024-04-24T14:40:45.980212000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite.rs:43: completions_from_composite_sources()
[R] 2024-04-24T14:40:45.980227000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/pipe.rs:59: find_pipe_root()
[R] 2024-04-24T14:40:45.980252000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/call.rs:33: completions_from_call()
[R] 2024-04-24T14:40:45.980270000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/subset.rs:27: completions_from_subset()
[R] 2024-04-24T14:40:45.980288000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/keyword.rs:16: completions_from_keywords()
[R] 2024-04-24T14:40:45.980452000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/snippets.rs:42: completions_from_snippets()
[R] 2024-04-24T14:40:45.981945000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/search_path.rs:31: completions_from_search_path()
[R] 2024-04-24T14:40:46.160581000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:339: Received request to send a message on a comm: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "bc08dd1c-d141-4552-b428-a17fdad9b868", session: "75b352bae874ffc75a1beb092c6d973b", username: "davis", date: "2024-04-24T14:40:46.160Z", msg_type: "comm_msg", version: "5.0" }, parent_header: None, content: CommWireMsg { comm_id: "positron-ui-r-1-e3eb9a4f", data: Object {"jsonrpc": String("2.0"), "method": String("call_method"), "params": Object {"method": String("setConsoleWidth"), "params": Array [Number(89)]}} } }
[R] 2024-04-24T14:40:46.160649000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:46.160678000Z [ark-unknown] TRACE crates/amalthea/src/comm/comm_manager.rs:157: Comm manager: Sending message to comm 'positron.ui'
[R] 2024-04-24T14:40:46.160708000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:46.160769000Z [ark-unknown] TRACE crates/ark/src/ui/ui.rs:145: Handling 'setConsoleWidth' frontend RPC method
[R] 2024-04-24T14:40:46.160810000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-comm-ui' (ThreadId(29)) is requesting a task.
[R] 2024-04-24T14:40:46.160829000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:46.160918000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:46.160986000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:46.183276000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/workspace.rs:29: completions_from_workspace()
[R] 2024-04-24T14:40:46.185904000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-lsp' (ThreadId(26)) was unblocked after waiting for 206 milliseconds.
[R] 2024-04-24T14:40:46.185933000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:46.185992000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-comm-ui' (ThreadId(29)) was unblocked after waiting for 25 milliseconds.
[R] 2024-04-24T14:40:46.186038000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-comm-ui' (ThreadId(29)) is requesting a task.
[R] 2024-04-24T14:40:46.186072000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:46.186126000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-comm-ui' (ThreadId(29)) was unblocked after waiting for 0 milliseconds.
[R] 2024-04-24T14:40:46.186198000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'comm_msg/positron-ui-r-1-e3eb9a4f/CallMethodReply' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:46.270461000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-lsp' (ThreadId(26)) is requesting a task.
[R] 2024-04-24T14:40:46.270532000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:46.329748000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-lsp' (ThreadId(26)) was unblocked after waiting for 59 milliseconds.
[R] 2024-04-24T14:40:46.471432000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-lsp' (ThreadId(26)) is requesting a task.
[R] 2024-04-24T14:40:46.471544000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:46.535328000Z [ark-unknown] INFO crates/ark/src/lsp/signature_help.rs:304: SignatureHelp { signatures: [SignatureInformation { label: "library(package, help, pos, lib.loc, character.only, logical.return, warn.conflicts, quietly, verbose, mask.ok, exclude, include.only, attach.required)", documentation: None, parameters: Some([ParameterInformation { label: LabelOffsets([8, 15]), documentation: None }, ParameterInformation { label: LabelOffsets([17, 21]), documentation: None }, ParameterInformation { label: LabelOffsets([23, 26]), documentation: None }, ParameterInformation { label: LabelOffsets([28, 35]), documentation: None }, ParameterInformation { label: LabelOffsets([37, 51]), documentation: None }, ParameterInformation { label: LabelOffsets([53, 67]), documentation: None }, ParameterInformation { label: LabelOffsets([69, 83]), documentation: None }, ParameterInformation { label: LabelOffsets([85, 92]), documentation: None }, ParameterInformation { label: LabelOffsets([94, 101]), documentation: None }, ParameterInformation { label: LabelOffsets([103, 110]), documentation: None }, ParameterInformation { label: LabelOffsets([112, 119]), documentation: None }, ParameterInformation { label: LabelOffsets([121, 133]), documentation: None }, ParameterInformation { label: LabelOffsets([135, 150]), documentation: None }]), active_parameter: Some(0) }], active_signature: None, active_parameter: Some(0) }
[R] 2024-04-24T14:40:46.535516000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-lsp' (ThreadId(26)) was unblocked after waiting for 64 milliseconds.
[R] 2024-04-24T14:40:46.797806000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-lsp' (ThreadId(26)) is requesting a task.
[R] 2024-04-24T14:40:46.798087000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:46.871055000Z [ark-unknown] INFO crates/ark/src/lsp/signature_help.rs:304: SignatureHelp { signatures: [SignatureInformation { label: "library(package, help, pos, lib.loc, character.only, logical.return, warn.conflicts, quietly, verbose, mask.ok, exclude, include.only, attach.required)", documentation: None, parameters: Some([ParameterInformation { label: LabelOffsets([8, 15]), documentation: None }, ParameterInformation { label: LabelOffsets([17, 21]), documentation: None }, ParameterInformation { label: LabelOffsets([23, 26]), documentation: None }, ParameterInformation { label: LabelOffsets([28, 35]), documentation: None }, ParameterInformation { label: LabelOffsets([37, 51]), documentation: None }, ParameterInformation { label: LabelOffsets([53, 67]), documentation: None }, ParameterInformation { label: LabelOffsets([69, 83]), documentation: None }, ParameterInformation { label: LabelOffsets([85, 92]), documentation: None }, ParameterInformation { label: LabelOffsets([94, 101]), documentation: None }, ParameterInformation { label: LabelOffsets([103, 110]), documentation: None }, ParameterInformation { label: LabelOffsets([112, 119]), documentation: None }, ParameterInformation { label: LabelOffsets([121, 133]), documentation: None }, ParameterInformation { label: LabelOffsets([135, 150]), documentation: None }]), active_parameter: Some(0) }], active_signature: None, active_parameter: Some(0) }
[R] 2024-04-24T14:40:46.871236000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-lsp' (ThreadId(26)) was unblocked after waiting for 73 milliseconds.
[R] 2024-04-24T14:40:47.004022000Z [ark-unknown] INFO crates/ark/src/lsp/backend.rs:342: Completion context: DocumentContext {
[R]     document: Document {
[R]         contents: [
[R]             "library(nyc)",
[R]         ],
[R]         ast: {Tree {Node program (0, 0) - (0, 12)}},
[R]     },
[R]     node: {Node identifier (0, 8) - (0, 11)},
[R]     point: Point {
[R]         row: 0,
[R]         column: 11,
[R]     },
[R]     trigger: None,
[R] }
[R] 2024-04-24T14:40:47.004128000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-lsp' (ThreadId(26)) is requesting a task.
[R] 2024-04-24T14:40:47.004190000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:47.004234000Z [ark-unknown] INFO crates/ark/src/lsp/completions/provide.rs:22: provide_completions()
[R] 2024-04-24T14:40:47.004255000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique.rs:31: completions_from_unique_sources()
[R] 2024-04-24T14:40:47.004277000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/comment.rs:28: completions_from_comment()
[R] 2024-04-24T14:40:47.004294000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/string.rs:16: completions_from_string()
[R] 2024-04-24T14:40:47.004309000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/namespace.rs:36: completions_from_namespace()
[R] 2024-04-24T14:40:47.004327000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/custom.rs:35: completions_from_custom_source()
[R] 2024-04-24T14:40:47.061944000Z [ark-unknown] INFO crates/ark/src/lsp/signature_help.rs:304: SignatureHelp { signatures: [SignatureInformation { label: "library(package, help, pos, lib.loc, character.only, logical.return, warn.conflicts, quietly, verbose, mask.ok, exclude, include.only, attach.required)", documentation: None, parameters: Some([ParameterInformation { label: LabelOffsets([8, 15]), documentation: None }, ParameterInformation { label: LabelOffsets([17, 21]), documentation: None }, ParameterInformation { label: LabelOffsets([23, 26]), documentation: None }, ParameterInformation { label: LabelOffsets([28, 35]), documentation: None }, ParameterInformation { label: LabelOffsets([37, 51]), documentation: None }, ParameterInformation { label: LabelOffsets([53, 67]), documentation: None }, ParameterInformation { label: LabelOffsets([69, 83]), documentation: None }, ParameterInformation { label: LabelOffsets([85, 92]), documentation: None }, ParameterInformation { label: LabelOffsets([94, 101]), documentation: None }, ParameterInformation { label: LabelOffsets([103, 110]), documentation: None }, ParameterInformation { label: LabelOffsets([112, 119]), documentation: None }, ParameterInformation { label: LabelOffsets([121, 133]), documentation: None }, ParameterInformation { label: LabelOffsets([135, 150]), documentation: None }]), active_parameter: Some(0) }], active_signature: None, active_parameter: Some(0) }
[R] 2024-04-24T14:40:47.070516000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-lsp' (ThreadId(26)) was unblocked after waiting for 66 milliseconds.
[R] 2024-04-24T14:40:47.082750000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-lsp' (ThreadId(26)) is requesting a task.
[R] 2024-04-24T14:40:47.082823000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:47.084093000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-lsp' (ThreadId(26)) was unblocked after waiting for 1 milliseconds.
[R] 2024-04-24T14:40:47.114915000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-lsp' (ThreadId(26)) is requesting a task.
[R] 2024-04-24T14:40:47.114975000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:47.162573000Z [ark-unknown] INFO crates/ark/src/lsp/signature_help.rs:304: SignatureHelp { signatures: [SignatureInformation { label: "library(package, help, pos, lib.loc, character.only, logical.return, warn.conflicts, quietly, verbose, mask.ok, exclude, include.only, attach.required)", documentation: None, parameters: Some([ParameterInformation { label: LabelOffsets([8, 15]), documentation: None }, ParameterInformation { label: LabelOffsets([17, 21]), documentation: None }, ParameterInformation { label: LabelOffsets([23, 26]), documentation: None }, ParameterInformation { label: LabelOffsets([28, 35]), documentation: None }, ParameterInformation { label: LabelOffsets([37, 51]), documentation: None }, ParameterInformation { label: LabelOffsets([53, 67]), documentation: None }, ParameterInformation { label: LabelOffsets([69, 83]), documentation: None }, ParameterInformation { label: LabelOffsets([85, 92]), documentation: None }, ParameterInformation { label: LabelOffsets([94, 101]), documentation: None }, ParameterInformation { label: LabelOffsets([103, 110]), documentation: None }, ParameterInformation { label: LabelOffsets([112, 119]), documentation: None }, ParameterInformation { label: LabelOffsets([121, 133]), documentation: None }, ParameterInformation { label: LabelOffsets([135, 150]), documentation: None }]), active_parameter: Some(0) }], active_signature: None, active_parameter: Some(0) }
[R] 2024-04-24T14:40:47.162674000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-lsp' (ThreadId(26)) was unblocked after waiting for 47 milliseconds.
[R] 2024-04-24T14:40:47.525421000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-lsp' (ThreadId(26)) is requesting a task.
[R] 2024-04-24T14:40:47.525804000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:47.596518000Z [ark-unknown] INFO crates/ark/src/lsp/signature_help.rs:304: SignatureHelp { signatures: [SignatureInformation { label: "library(package, help, pos, lib.loc, character.only, logical.return, warn.conflicts, quietly, verbose, mask.ok, exclude, include.only, attach.required)", documentation: None, parameters: Some([ParameterInformation { label: LabelOffsets([8, 15]), documentation: None }, ParameterInformation { label: LabelOffsets([17, 21]), documentation: None }, ParameterInformation { label: LabelOffsets([23, 26]), documentation: None }, ParameterInformation { label: LabelOffsets([28, 35]), documentation: None }, ParameterInformation { label: LabelOffsets([37, 51]), documentation: None }, ParameterInformation { label: LabelOffsets([53, 67]), documentation: None }, ParameterInformation { label: LabelOffsets([69, 83]), documentation: None }, ParameterInformation { label: LabelOffsets([85, 92]), documentation: None }, ParameterInformation { label: LabelOffsets([94, 101]), documentation: None }, ParameterInformation { label: LabelOffsets([103, 110]), documentation: None }, ParameterInformation { label: LabelOffsets([112, 119]), documentation: None }, ParameterInformation { label: LabelOffsets([121, 133]), documentation: None }, ParameterInformation { label: LabelOffsets([135, 150]), documentation: None }]), active_parameter: Some(0) }], active_signature: None, active_parameter: Some(0) }
[R] 2024-04-24T14:40:47.596682000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-lsp' (ThreadId(26)) was unblocked after waiting for 70 milliseconds.
[R] 2024-04-24T14:40:47.756574000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-lsp' (ThreadId(26)) is requesting a task.
[R] 2024-04-24T14:40:47.756738000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:47.767193000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:248: Received request to test code for completeness: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "9b876888-757c-40fc-885e-d6bf8894b6ff", session: "75b352bae874ffc75a1beb092c6d973b", username: "davis", date: "2024-04-24T14:40:47.766Z", msg_type: "is_complete_request", version: "5.0" }, parent_header: None, content: IsCompleteRequest { code: "library(nycflights13)" } }
[R] 2024-04-24T14:40:47.767287000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'is_complete_request') via IOPub socket
[R] 2024-04-24T14:40:47.767342000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-shell' (ThreadId(17)) is requesting a task.
[R] 2024-04-24T14:40:47.824486000Z [ark-unknown] INFO crates/ark/src/lsp/signature_help.rs:304: SignatureHelp { signatures: [SignatureInformation { label: "library(package, help, pos, lib.loc, character.only, logical.return, warn.conflicts, quietly, verbose, mask.ok, exclude, include.only, attach.required)", documentation: None, parameters: Some([ParameterInformation { label: LabelOffsets([8, 15]), documentation: None }, ParameterInformation { label: LabelOffsets([17, 21]), documentation: None }, ParameterInformation { label: LabelOffsets([23, 26]), documentation: None }, ParameterInformation { label: LabelOffsets([28, 35]), documentation: None }, ParameterInformation { label: LabelOffsets([37, 51]), documentation: None }, ParameterInformation { label: LabelOffsets([53, 67]), documentation: None }, ParameterInformation { label: LabelOffsets([69, 83]), documentation: None }, ParameterInformation { label: LabelOffsets([85, 92]), documentation: None }, ParameterInformation { label: LabelOffsets([94, 101]), documentation: None }, ParameterInformation { label: LabelOffsets([103, 110]), documentation: None }, ParameterInformation { label: LabelOffsets([112, 119]), documentation: None }, ParameterInformation { label: LabelOffsets([121, 133]), documentation: None }, ParameterInformation { label: LabelOffsets([135, 150]), documentation: None }]), active_parameter: Some(0) }], active_signature: None, active_parameter: Some(0) }
[R] 2024-04-24T14:40:47.824652000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-lsp' (ThreadId(26)) was unblocked after waiting for 67 milliseconds.
[R] 2024-04-24T14:40:47.824693000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:47.824807000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-shell' (ThreadId(17)) was unblocked after waiting for 57 milliseconds.
[R] 2024-04-24T14:40:47.824869000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'is_complete_reply' message (reply to 'is_complete_request') via Shell socket
[R] 2024-04-24T14:40:47.825017000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:47.825118000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'is_complete_request') via IOPub socket
[R] 2024-04-24T14:40:47.830489000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:230: Received execution request JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "fragment-63b439b5-d220-45a8-9797-ce0616b86b04", session: "75b352bae874ffc75a1beb092c6d973b", username: "davis", date: "2024-04-24T14:40:47.830Z", msg_type: "execute_request", version: "5.0" }, parent_header: None, content: ExecuteRequest { code: "library(nycflights13)", silent: false, store_history: true, user_expressions: Object {}, allow_stdin: true, stop_on_error: false } }
[R] 2024-04-24T14:40:47.830536000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'execute_request') via IOPub socket
[R] 2024-04-24T14:40:47.830574000Z [ark-unknown] TRACE crates/ark/src/shell.rs:220: Code sent to R: library(nycflights13)
[R] 2024-04-24T14:40:47.830616000Z [ark-unknown] INFO crates/ark/src/kernel.rs:132: Sending UI message to frontend: Event(Busy(BusyParams { busy: true }))
[R] 2024-04-24T14:40:47.830675000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'execute_input' message (reply to 'execute_request') via IOPub socket
[R] 2024-04-24T14:40:47.830775000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'comm_msg/positron-ui-r-1-e3eb9a4f/busy' message via IOPub socket
[R] 2024-04-24T14:40:47.955248000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-lsp' (ThreadId(26)) is requesting a task.
[R] 2024-04-24T14:40:47.955324000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:47.955378000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-lsp' (ThreadId(26)) was unblocked after waiting for 0 milliseconds.
[R] 2024-04-24T14:40:48.014506000Z [ark-unknown] INFO crates/ark/src/kernel.rs:132: Sending UI message to frontend: Event(Busy(BusyParams { busy: false }))
[R] 2024-04-24T14:40:48.014585000Z [ark-unknown] TRACE crates/ark/src/interface.rs:743: prompt_info(): n_frame = '0'
[R] 2024-04-24T14:40:48.014611000Z [ark-unknown] DEBUG crates/ark/src/interface.rs:507: R prompt: > 
[R] 2024-04-24T14:40:48.014625000Z [ark-unknown] INFO crates/ark/src/kernel.rs:132: Sending UI message to frontend: Event(PromptState(PromptStateParams { input_prompt: "> ", continuation_prompt: "+ " }))
[R] 2024-04-24T14:40:48.014640000Z [ark-unknown] TRACE crates/ark/src/interface.rs:834: Got R prompt '> ', completing execution
[R] 2024-04-24T14:40:48.014673000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'comm_msg/positron-ui-r-1-e3eb9a4f/busy' message via IOPub socket
[R] 2024-04-24T14:40:48.014834000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'comm_msg/positron-ui-r-1-e3eb9a4f/prompt_state' message via IOPub socket
[R] 2024-04-24T14:40:48.015037000Z [ark-unknown] INFO crates/ark/src/variables/r_variables.rs:116: Got console prompt signal.
[R] 2024-04-24T14:40:48.015054000Z [ark-unknown] INFO crates/ark/src/r_task.rs:161: Thread 'ark-shell' (ThreadId(17)) is requesting an async task.
[R] 2024-04-24T14:40:48.015077000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'execute_result' message (reply to 'execute_request') via IOPub socket
[R] 2024-04-24T14:40:48.015094000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-variables' (ThreadId(28)) is requesting a task.
[R] 2024-04-24T14:40:48.015111000Z [ark-unknown] INFO crates/ark/src/r_task.rs:173: Thread 'ark-shell' (ThreadId(17)) has sent the async task.
[R] 2024-04-24T14:40:48.015127000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:48.015175000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:234: Got execution reply, delivering to frontend: ExecuteReply { status: Ok, execution_count: 1, user_expressions: Object {} }
[R] 2024-04-24T14:40:48.015206000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'execute_reply' message (reply to 'execute_request') via Shell socket
[R] 2024-04-24T14:40:48.015227000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:48.015300000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:48.015321000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-variables' (ThreadId(28)) was unblocked after waiting for 0 milliseconds.
[R] 2024-04-24T14:40:48.015339000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'execute_request') via IOPub socket
[R] 2024-04-24T14:40:49.017675000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'tokio-runtime-worker' (ThreadId(10)) is requesting a task.
[R] 2024-04-24T14:40:49.018181000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:49.045117000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'tokio-runtime-worker' (ThreadId(10)) was unblocked after waiting for 27 milliseconds.
[R] 2024-04-24T14:40:49.643997000Z [ark-unknown] INFO crates/ark/src/lsp/backend.rs:342: Completion context: DocumentContext {
[R]     document: Document {
[R]         contents: [
[R]             "Vie",
[R]         ],
[R]         ast: {Tree {Node program (0, 0) - (0, 3)}},
[R]     },
[R]     node: {Node identifier (0, 0) - (0, 3)},
[R]     point: Point {
[R]         row: 0,
[R]         column: 3,
[R]     },
[R]     trigger: None,
[R] }
[R] 2024-04-24T14:40:49.644157000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-lsp' (ThreadId(26)) is requesting a task.
[R] 2024-04-24T14:40:49.644254000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:49.644340000Z [ark-unknown] INFO crates/ark/src/lsp/completions/provide.rs:22: provide_completions()
[R] 2024-04-24T14:40:49.644369000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique.rs:31: completions_from_unique_sources()
[R] 2024-04-24T14:40:49.644398000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/comment.rs:28: completions_from_comment()
[R] 2024-04-24T14:40:49.644419000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/string.rs:16: completions_from_string()
[R] 2024-04-24T14:40:49.644436000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/namespace.rs:36: completions_from_namespace()
[R] 2024-04-24T14:40:49.644457000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/custom.rs:35: completions_from_custom_source()
[R] 2024-04-24T14:40:49.644476000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/extractor.rs:48: completions_from_extractor()
[R] 2024-04-24T14:40:49.644492000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/unique/extractor.rs:48: completions_from_extractor()
[R] 2024-04-24T14:40:49.644508000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite.rs:43: completions_from_composite_sources()
[R] 2024-04-24T14:40:49.644522000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/pipe.rs:59: find_pipe_root()
[R] 2024-04-24T14:40:49.644538000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/call.rs:33: completions_from_call()
[R] 2024-04-24T14:40:49.644553000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/subset.rs:27: completions_from_subset()
[R] 2024-04-24T14:40:49.644569000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/keyword.rs:16: completions_from_keywords()
[R] 2024-04-24T14:40:49.644691000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/snippets.rs:42: completions_from_snippets()
[R] 2024-04-24T14:40:49.644808000Z [ark-unknown] INFO crates/ark/src/lsp/completions/sources/composite/search_path.rs:31: completions_from_search_path()
[Positron] RECV stream from iopub: {"header":{"msg_id":"6ab456a7-3b72-48f3-bd05-8d72884aeb2f","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:50.828059+00:00","msg_type":"stream","version":"5.3"},"parent_header":null,"metadata":{},"content":{"name":"stderr","text":"thread 'ark-lsp' panicked at crates/ark/src/lsp/document_context.rs:32:13:\nFailed to find closest node to point: (0, 5) with contents 'View'\nstack backtrace:\n   0: rust_begin_unwind\n             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/std/src/panicking.rs:645:5\n   1: core::panicking::panic_fmt\n             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/panicking.rs:72:14\n"},"buffers":[]}
[Positron] RECV stream from iopub: {"header":{"msg_id":"6625df60-9869-4cf9-bc1c-64d41f818548","session":"abf8fccf-fb2f-4a0a-ad26-a9f7fad05453","username":"kernel","date":"2024-04-24T14:40:50.908971+00:00","msg_type":"stream","version":"5.3"},"parent_header":null,"metadata":{},"content":{"name":"stderr","text":"   2: ark::lsp::document_context::DocumentContext::new\n             at /Users/davis/files/programming/positron/amalthea/crates/ark/src/lsp/document_context.rs:32:13\n   3: <ark::lsp::backend::Backend as tower_lsp::LanguageServer>::signature_help::{{closure}}\n             at /Users/davis/files/programming/positron/amalthea/crates/ark/src/lsp/backend.rs:420:23\n   4: <core::pin::Pin<P> as core::future::future::Future>::poll\n             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/future/future.rs:125:9\n   5: tower_lsp::generated::register_lsp_methods::signature_help::{{closure}}\n             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tower-lsp-0.19.0/src/lib.rs:112:1\n   6: tower_lsp::jsonrpc::router::Router<S,E>::method::{{closure}}::{{closure}}::{{closure}}\n             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tower-lsp-0.19.0/src/jsonrpc/router.rs:58:64\n   7: <core::pin::Pin<P> as core::future::future::Future>::poll\n             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/future/future.rs:125:9\n   8: <futures_util::future::future::map::Map<Fut,F> as core::future::future::Future>::poll\n             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/future/future/map.rs:55:37\n   9: <futures_util::future::future::Map<Fut,F> as core::future::future::Future>::poll\n             at /Users/davis/.cargo/registry/src/index.crates.io-6f17d22bba15001f/futures-util-0.3.28/src/lib.rs:91:13\n  10: <core::pin::Pin<P> as core::future::future::Future>::poll\n             at /rustc/82e1608dfa6e0b5569232559e3d385fea5a93112/library/core/src/future/future.rs:125:9\n  11: <futures_util:... (truncated)
[Positron] Stdin socket disconnected from tcp://127.0.0.1:54889
[Positron] Heartbeat socket disconnected from tcp://127.0.0.1:51472
[Positron] Control socket disconnected from tcp://127.0.0.1:49821
[Positron] I/O socket disconnected from tcp://127.0.0.1:42448
[Positron] Shell socket disconnected from tcp://127.0.0.1:48139
[Positron] All 5 sockets disconnected; kernel exited
[R] 2024-04-24T14:40:50.513842000Z [ark-unknown] ERROR crates/ark/src/main.rs:463: Panic! In file 'crates/ark/src/lsp/document_context.rs' at line 32: Failed to find closest node to point: (0, 5) with contents 'View'
[R] 2024-04-24T14:40:50.828088000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'stream' message via IOPub socket
[R] 2024-04-24T14:40:50.909003000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'stream' message via IOPub socket
[R] 
[Positron] R kernel status changed: idle => exited
[Positron] Connecting to R 4.3.1 kernel (pid 85898)
[Positron] Streaming log file: /var/folders/by/4wf2qrmn4_j93s5k5k5fzrx00000gp/T/kernel-42x4CB/kernel.log
[Positron] Connecting to kernel sockets defined in /var/folders/by/4wf2qrmn4_j93s5k5k5fzrx00000gp/T/kernel-42x4CB/connection.json...
[Positron] Control socket created (count = 1)
[Positron] Shell socket created (count = 2)
[Positron] Stdin socket created (count = 3)
[Positron] I/O socket created (count = 4)
[Positron] Heartbeat socket created (count = 5)
[Positron] Control socket connecting to tcp://127.0.0.1:49515...
[Positron] Shell socket connecting to tcp://127.0.0.1:58472...
[Positron] Stdin socket connecting to tcp://127.0.0.1:51374...
[Positron] I/O socket connecting to tcp://127.0.0.1:46719...
[Positron] Heartbeat socket connecting to tcp://127.0.0.1:50243...
[Positron] Shell socket connected to tcp://127.0.0.1:58472
[Positron] I/O socket connected to tcp://127.0.0.1:46719
[Positron] Control socket connected to tcp://127.0.0.1:49515
[Positron] Stdin socket connected to tcp://127.0.0.1:51374
[Positron] Heartbeat socket connected to tcp://127.0.0.1:50243
[Positron] Establishing socket listeners...
[Positron] Received initial heartbeat: heartbeat
[Positron] SEND kernel_info_request to Shell: {"buffers":[],"content":{},"header":{"msg_id":"e0dae73b-284f-45e3-8da2-be018e4f2072","msg_type":"kernel_info_request","version":"5.0","date":"2024-04-24T14:40:51.672Z","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] Starting heartbeat check at 30 second intervals...
[Positron] SEND heartbeat with timeout of 30 seconds
[Positron] SEND kernel_info_request: OK
[Positron] R kernel status changed: starting => ready
[Positron] SEND kernel_info_request to Shell: {"buffers":[],"content":{},"header":{"msg_id":"d3d53d59-944e-4d65-92f6-72808fd037e7","msg_type":"kernel_info_request","version":"5.0","date":"2024-04-24T14:40:51.773Z","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND kernel_info_request: OK
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"1444d42d-d42f-48a7-9af3-285ec9662909","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.773066+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"e0dae73b-284f-45e3-8da2-be018e4f2072","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.672Z","msg_type":"kernel_info_request","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] Starting DAP server positron-dap-r-2-41e391bf for 127.0.0.1:51492
[Positron] Creating 'positron.dap' client for R
[Positron] SEND comm_open to Shell: {"buffers":[],"content":{"target_name":"positron.dap","comm_id":"positron-dap-r-2-41e391bf","data":{"client_address":"127.0.0.1:51492"}},"header":{"msg_id":"bcf0dd40-8a69-44b6-8808-69afd8bbca57","msg_type":"comm_open","version":"5.0","date":"2024-04-24T14:40:51.774Z","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND comm_open: OK
[Positron] RECV kernel_info_reply from shell: {"header":{"msg_id":"a5f91b08-071e-47a1-9f6d-428d81e72de7","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.774319+00:00","msg_type":"kernel_info_reply","version":"5.3"},"parent_header":{"msg_id":"d3d53d59-944e-4d65-92f6-72808fd037e7","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.773Z","msg_type":"kernel_info_request","version":"5.0"},"metadata":{},"content":{"status":"ok","protocol_version":"5.3","language_info":{"name":"R","version":"R version 4.3.1 (2023-06-16)","mimetype":"text/r","file_extension":".R","pygments_lexer":"","codemirror_mode":"","nbconvert_exporter":"","positron":{"input_prompt":"> ","continuation_prompt":"+ "}},"banner":"","debugger":false,"help_links":[]},"buffers":[]}
[Positron] Starting Positron LSP server on port 51178
[Positron] Starting LSP server positron-lsp-r-3-622a8393 for 127.0.0.1:51178
[Positron] Creating 'positron.lsp' client for R
[Positron] SEND comm_open to Shell: {"buffers":[],"content":{"target_name":"positron.lsp","comm_id":"positron-lsp-r-3-622a8393","data":{"client_address":"127.0.0.1:51178"}},"header":{"msg_id":"a4bfc0bb-a513-4a8e-99d8-458f3d6ce02b","msg_type":"comm_open","version":"5.0","date":"2024-04-24T14:40:51.775Z","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND comm_open: OK
[Positron] R kernel status changed: ready => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"454ebcb8-1f05-48a0-8729-0a2da694b38b","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.774268+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"d3d53d59-944e-4d65-92f6-72808fd037e7","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.773Z","msg_type":"kernel_info_request","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"41b123b8-695c-44dd-8a6b-0bff191b683f","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.774526+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"d3d53d59-944e-4d65-92f6-72808fd037e7","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.773Z","msg_type":"kernel_info_request","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"fe9cc20a-79d0-451b-8189-70dc36c6ce3e","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.775162+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"bcf0dd40-8a69-44b6-8808-69afd8bbca57","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.774Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] Creating 'positron.variables' client for R
[Positron] SEND comm_open to Shell: {"buffers":[],"content":{"target_name":"positron.variables","comm_id":"positron-variables-r-3-b7eff62d","data":{}},"header":{"msg_id":"ffc16bba-3b1c-4460-a430-a5a28da5ce9b","msg_type":"comm_open","version":"5.0","date":"2024-04-24T14:40:51.776Z","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND comm_open: OK
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"8b6abc85-1694-42a5-9f14-815cbdd9beca","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.775461+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"bcf0dd40-8a69-44b6-8808-69afd8bbca57","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.774Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] RECV comm_msg/DAP/server_started from iopub: {"header":{"msg_id":"fc37e0e5-be44-4758-ac0a-e965284428a3","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.775660+00:00","msg_type":"comm_msg","version":"5.3"},"parent_header":null,"metadata":{},"content":{"comm_id":"positron-dap-r-2-41e391bf","data":{"msg_type":"server_started","content":{}}},"buffers":[]}
[Positron] Unknown DAP command: server_started
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"059aa449-f454-496a-bbd5-5c25916f82ee","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.775729+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"a4bfc0bb-a513-4a8e-99d8-458f3d6ce02b","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.775Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"857b50e6-e139-404e-a7f4-24d0143a33e7","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.775987+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"a4bfc0bb-a513-4a8e-99d8-458f3d6ce02b","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.775Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] RECV comm_msg/LSP/server_started from iopub: {"header":{"msg_id":"e4da9509-2051-45c6-bd2f-d4e51d688609","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.776056+00:00","msg_type":"comm_msg","version":"5.3"},"parent_header":null,"metadata":{},"content":{"comm_id":"positron-lsp-r-3-622a8393","data":{"msg_type":"server_started","content":{}}},"buffers":[]}
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"795a23a2-c47e-4ef8-8b1c-54e74ad390ac","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.776249+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"ffc16bba-3b1c-4460-a430-a5a28da5ce9b","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.776Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] Creating 'positron.ui' client for R
[Positron] SEND comm_open to Shell: {"buffers":[],"content":{"target_name":"positron.ui","comm_id":"positron-ui-r-4-b55cc19","data":{}},"header":{"msg_id":"cfa14797-d375-497d-9c02-7f48fb215c11","msg_type":"comm_open","version":"5.0","date":"2024-04-24T14:40:51.777Z","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND comm_open: OK
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"e9fc97a1-b353-4c30-86ff-9c22ceee7973","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.776626+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"ffc16bba-3b1c-4460-a430-a5a28da5ce9b","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.776Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] RECV comm_msg/positron-variables-r-3-b7eff62d/undefined from iopub: {"header":{"msg_id":"2f63a5a5-b7c4-473b-9b36-d9e0d2f26c58","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.776760+00:00","msg_type":"comm_msg","version":"5.3"},"parent_header":null,"metadata":{},"content":{"comm_id":"positron-variables-r-3-b7eff62d","data":{"method":"refresh","params":{"variables":[],"length":0,"version":1}}},"buffers":[]}
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"d6743cdb-db57-4c5d-97e2-23eec8ee684c","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.778264+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"cfa14797-d375-497d-9c02-7f48fb215c11","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.777Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] Creating 'positron.help' client for R
[Positron] SEND comm_open to Shell: {"buffers":[],"content":{"target_name":"positron.help","comm_id":"positron-help-r-5-971ca4e5","data":{}},"header":{"msg_id":"698e3587-edbf-4483-b1d9-6f2cc00270ad","msg_type":"comm_open","version":"5.0","date":"2024-04-24T14:40:51.778Z","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND comm_open: OK
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"aba4ded3-139c-4c5a-85d9-893c3bf9deaa","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.778383+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"cfa14797-d375-497d-9c02-7f48fb215c11","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.777Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] RECV comm_msg/positron-ui-r-4-b55cc19/undefined from iopub: {"header":{"msg_id":"336b247f-f1ac-46f6-919e-ec5f34320a44","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.778508+00:00","msg_type":"comm_msg","version":"5.3"},"parent_header":null,"metadata":{},"content":{"comm_id":"positron-ui-r-4-b55cc19","data":{"method":"working_directory","params":{"directory":"~/files/programming/tree-sitter-r"}}},"buffers":[]}
[Positron] RECV comm_msg/positron-ui-r-4-b55cc19/undefined from iopub: {"header":{"msg_id":"dc726000-3ecb-4ce2-b0df-309330bf3f64","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.778623+00:00","msg_type":"comm_msg","version":"5.3"},"parent_header":null,"metadata":{},"content":{"comm_id":"positron-ui-r-4-b55cc19","data":{"method":"busy","params":{"busy":false}}},"buffers":[]}
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"06ca6b4a-949d-4d1c-8757-d92a4b9acd82","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.779110+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"698e3587-edbf-4483-b1d9-6f2cc00270ad","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.778Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] SEND comm_info_request to Shell: {"buffers":[],"content":{"target_name":"positron.plot"},"header":{"msg_id":"6c782cbb-3402-4f33-baff-0a4bed0909f4","msg_type":"comm_info_request","version":"5.0","date":"2024-04-24T14:40:51.781Z","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND comm_info_request: OK
[Positron] SEND comm_info_request to Shell: {"buffers":[],"content":{"target_name":"jupyter.widget"},"header":{"msg_id":"24244763-fbd8-4d6d-9828-08c1d43a9b36","msg_type":"comm_info_request","version":"5.0","date":"2024-04-24T14:40:51.782Z","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] SEND comm_info_request: OK
[Positron] SEND comm_msg to Shell: {"buffers":[],"content":{"comm_id":"positron-ui-r-4-b55cc19","data":{"jsonrpc":"2.0","method":"call_method","params":{"method":"setConsoleWidth","params":[89]}}},"header":{"msg_id":"5ae678ea-2ae5-4518-a5a2-52f116550cc4","msg_type":"comm_msg","version":"5.0","date":"2024-04-24T14:40:51.784Z","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis"},"metadata":{},"parent_header":{}}
[Positron] Set initial console width to 89
[Positron] SEND comm_msg: OK
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"b8f3b9e9-a5c0-4517-aa9b-c7b4b3c01b61","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.788352+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"698e3587-edbf-4483-b1d9-6f2cc00270ad","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.778Z","msg_type":"comm_open","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"3982247f-279d-4fe8-8c9b-e07270e264db","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.788681+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"6c782cbb-3402-4f33-baff-0a4bed0909f4","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.781Z","msg_type":"comm_info_request","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] RECV comm_info_reply from shell: {"header":{"msg_id":"776347d0-6ffe-4083-92fa-69cf23bf182c","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.788628+00:00","msg_type":"comm_info_reply","version":"5.3"},"parent_header":{"msg_id":"6c782cbb-3402-4f33-baff-0a4bed0909f4","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.781Z","msg_type":"comm_info_request","version":"5.0"},"metadata":{},"content":{"status":"ok","comms":{}},"buffers":[]}
[Positron] RECV comm_info_reply from shell: {"header":{"msg_id":"6719da02-382b-48f1-a582-4dd499f2fff7","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.789135+00:00","msg_type":"comm_info_reply","version":"5.3"},"parent_header":{"msg_id":"24244763-fbd8-4d6d-9828-08c1d43a9b36","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.782Z","msg_type":"comm_info_request","version":"5.0"},"metadata":{},"content":{"status":"ok","comms":{}},"buffers":[]}
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"169f7fcb-fa43-4dcb-a0d1-35ebd8e6c10c","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.789110+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"6c782cbb-3402-4f33-baff-0a4bed0909f4","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.781Z","msg_type":"comm_info_request","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"56df35d7-bab1-46b0-b9b4-30845c57d7b6","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.789411+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"24244763-fbd8-4d6d-9828-08c1d43a9b36","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.782Z","msg_type":"comm_info_request","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"14adb603-6cea-494c-a1be-1a93adcde5ed","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.789505+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"24244763-fbd8-4d6d-9828-08c1d43a9b36","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.782Z","msg_type":"comm_info_request","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] R kernel status changed: idle => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"0a140174-99ab-40fd-8211-1bd52a3e5222","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.789575+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"5ae678ea-2ae5-4518-a5a2-52f116550cc4","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.784Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] R kernel status changed: busy => busy
[Positron] RECV status/busy from iopub: {"header":{"msg_id":"ec792bc8-4184-45f7-8e4f-43dba579517c","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.789641+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"5ae678ea-2ae5-4518-a5a2-52f116550cc4","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.784Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"execution_state":"busy"},"buffers":[]}
[Positron] R kernel status changed: busy => idle
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"33ba2395-bfd7-4ef4-9fd9-fd1bedbdf7a4","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.789704+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"5ae678ea-2ae5-4518-a5a2-52f116550cc4","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.784Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] RECV status/idle from iopub: {"header":{"msg_id":"0a52bb77-bab6-4c94-8014-04818385c881","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.789765+00:00","msg_type":"status","version":"5.3"},"parent_header":{"msg_id":"5ae678ea-2ae5-4518-a5a2-52f116550cc4","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.784Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"execution_state":"idle"},"buffers":[]}
[Positron] RECV comm_msg/positron-ui-r-4-b55cc19/undefined from iopub: {"header":{"msg_id":"95e15e85-fd5c-4b9a-b082-23895362946a","session":"be80442b-fe82-475a-ae13-899034cc4e41","username":"kernel","date":"2024-04-24T14:40:51.790402+00:00","msg_type":"comm_msg","version":"5.3"},"parent_header":{"msg_id":"5ae678ea-2ae5-4518-a5a2-52f116550cc4","session":"8114f7705f4f6d05a9d939c651b2c1ec","username":"davis","date":"2024-04-24T14:40:51.784Z","msg_type":"comm_msg","version":"5.0"},"metadata":{},"content":{"comm_id":"positron-ui-r-4-b55cc19","data":{"method":"CallMethodReply","result":80}},"buffers":[]}
[R] *** Log started at Wed Apr 24 10:40:51 EDT 2024
[R] *** Command line:
[R] /Users/davis/files/programming/positron/amalthea/target/debug/ark --connection_file /var/folders/by/4wf2qrmn4_j93s5k5k5fzrx00000gp/T/kernel-42x4CB/connection.json --log /var/folders/by/4wf2qrmn4_j93s5k5k5fzrx00000gp/T/kernel-42x4CB/kernel.log --startup-file /Users/davis/files/programming/positron/positron/extensions/positron-r/resources/scripts/startup.R --session-mode console -- --interactive --no-restore-data --quiet
[R] 2024-04-24T14:40:51.539452000Z [ark-unknown] INFO crates/ark/src/main.rs:217: Loaded connection information from frontend in /var/folders/by/4wf2qrmn4_j93s5k5k5fzrx00000gp/T/kernel-42x4CB/connection.json
[R] 2024-04-24T14:40:51.541620000Z [ark-unknown] DEBUG crates/ark/src/main.rs:221: Connection data: ConnectionFile { control_port: 49515, shell_port: 58472, stdin_port: 51374, iopub_port: 46719, hb_port: 50243, transport: "tcp", signature_scheme: "hmac-sha256", ip: "127.0.0.1", key: "cf4e741f0ee6b93307b3f26674a32856" }
[R] 2024-04-24T14:40:51.542576000Z [ark-unknown] TRACE crates/amalthea/src/socket/socket.rs:45: Binding to ZeroMQ 'Shell' socket at tcp://127.0.0.1:58472
[R] 2024-04-24T14:40:51.543218000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:51.543462000Z [ark-unknown] TRACE crates/amalthea/src/socket/socket.rs:45: Binding to ZeroMQ 'IOPub' socket at tcp://127.0.0.1:46719
[R] 2024-04-24T14:40:51.543581000Z [ark-unknown] TRACE crates/amalthea/src/socket/iopub.rs:304: Entering kernel state: Starting
[R] 2024-04-24T14:40:51.543799000Z [ark-unknown] TRACE crates/amalthea/src/socket/socket.rs:45: Binding to ZeroMQ 'Heartbeat' socket at tcp://127.0.0.1:50243
[R] 2024-04-24T14:40:51.543829000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'status/starting' message via IOPub socket
[R] 2024-04-24T14:40:51.543903000Z [ark-unknown] TRACE crates/amalthea/src/socket/socket.rs:45: Binding to ZeroMQ 'Stdin' socket at tcp://127.0.0.1:51374
[R] 2024-04-24T14:40:51.543937000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:28: Listening for heartbeats
[R] 2024-04-24T14:40:51.544159000Z [ark-unknown] TRACE crates/amalthea/src/socket/socket.rs:45: Binding to ZeroMQ 'Control' socket at tcp://127.0.0.1:49515
[R] 2024-04-24T14:40:51.544268000Z [ark-unknown] TRACE crates/amalthea/src/socket/socket.rs:91: Binding to ZeroMQ 'OutboundNotifierTx' socket at inproc://outbound_notif
[R] 2024-04-24T14:40:51.544327000Z [ark-unknown] TRACE crates/amalthea/src/socket/socket.rs:96: Connecting to ZeroMQ 'OutboundNotifierRx' socket at inproc://outbound_notif
[R] 2024-04-24T14:40:51.544423000Z [ark-unknown] TRACE crates/amalthea/src/socket/control.rs:58: Waiting for control messages
[R] 2024-04-24T14:40:51.557015000Z [ark-unknown] INFO crates/harp/src/sys/unix/library.rs:107: Setting 'DYLD_FALLBACK_LIBRARY_PATH' env var to '/Library/Frameworks/R.framework/Versions/4.3-arm64/Resources/lib:/Library/Java/JavaVirtualMachines/jdk-11.0.18+10/Contents/Home/lib/server'.
[R] 2024-04-24T14:40:51.560870000Z [ark-unknown] INFO crates/harp/src/library.rs:30: Successfully opened R shared library at '/Library/Frameworks/R.framework/Versions/4.3-arm64/Resources/lib/libR.dylib'.
[R] 2024-04-24T14:40:51.561671000Z [ark-unknown] TRACE crates/ark/src/sys/unix/interface.rs:56: R_HOME: "/Library/Frameworks/R.framework/Versions/4.3-arm64/Resources"
[R] 2024-04-24T14:40:51.672550000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:41: Heartbeat message: [104, 101, 97, 114, 116, 98, 101, 97, 116]
[R] 2024-04-24T14:40:51.672632000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:50: Heartbeat message replied
[R] 2024-04-24T14:40:51.672650000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:28: Listening for heartbeats
[R] 2024-04-24T14:40:51.673181000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:261: Received shell information request: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "e0dae73b-284f-45e3-8da2-be018e4f2072", session: "8114f7705f4f6d05a9d939c651b2c1ec", username: "davis", date: "2024-04-24T14:40:51.672Z", msg_type: "kernel_info_request", version: "5.0" }, parent_header: None, content: KernelInfoRequest }
[R] 2024-04-24T14:40:51.673251000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'kernel_info_request') via IOPub socket
[R] 2024-04-24T14:40:51.673275000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:41: Heartbeat message: [104, 101, 97, 114, 116, 98, 101, 97, 116]
[R] 2024-04-24T14:40:51.673293000Z [ark-unknown] TRACE crates/ark/src/shell.rs:147: Got kernel info request; waiting for R to complete initialization
[R] 2024-04-24T14:40:51.673319000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:50: Heartbeat message replied
[R] 2024-04-24T14:40:51.673332000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:28: Listening for heartbeats
[R] 2024-04-24T14:40:51.739264000Z [ark-unknown] TRACE crates/ark/src/modules.rs:125: Loading R modules from sources via cargo manifest
[R] 2024-04-24T14:40:51.739318000Z [ark-unknown] INFO crates/ark/src/modules.rs:258: Loading modules from directory: /Users/davis/files/programming/positron/amalthea/crates/ark/src/modules/positron
[R] 2024-04-24T14:40:51.767401000Z [ark-unknown] INFO crates/ark/src/modules.rs:258: Loading modules from directory: /Users/davis/files/programming/positron/amalthea/crates/ark/src/modules/rstudio
[R] 2024-04-24T14:40:51.771139000Z [ark-unknown] INFO crates/ark/src/modules.rs:137: Watching R modules from sources via cargo manifest
[R] 2024-04-24T14:40:51.771385000Z [ark-unknown] INFO crates/ark/src/errors.rs:54: Initializing global error handler
[R] 2024-04-24T14:40:51.772677000Z [ark-unknown] INFO crates/ark/src/kernel.rs:132: Sending UI message to frontend: Event(Busy(BusyParams { busy: false }))
[R] 2024-04-24T14:40:51.772697000Z [ark-unknown] INFO crates/ark/src/kernel.rs:135: Discarding message Event(Busy(BusyParams { busy: false })); no frontend UI comm connected
[R] 2024-04-24T14:40:51.772722000Z [ark-unknown] TRACE crates/ark/src/interface.rs:743: prompt_info(): n_frame = '0'
[R] 2024-04-24T14:40:51.772753000Z [ark-unknown] DEBUG crates/ark/src/interface.rs:507: R prompt: > 
[R] 2024-04-24T14:40:51.772766000Z [ark-unknown] DEBUG crates/ark/src/interface.rs:448: Sending kernel info: R version 4.3.1 (2023-06-16)
[R] 2024-04-24T14:40:51.772812000Z [ark-unknown] TRACE crates/ark/src/interface.rs:512: Got initial R prompt '> ', ready for execution requests
[R] 2024-04-24T14:40:51.772885000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'kernel_info_reply' message (reply to 'kernel_info_request') via Shell socket
[R] 2024-04-24T14:40:51.773053000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:51.773079000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'kernel_info_request') via IOPub socket
[R] 2024-04-24T14:40:51.774200000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:261: Received shell information request: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "d3d53d59-944e-4d65-92f6-72808fd037e7", session: "8114f7705f4f6d05a9d939c651b2c1ec", username: "davis", date: "2024-04-24T14:40:51.773Z", msg_type: "kernel_info_request", version: "5.0" }, parent_header: None, content: KernelInfoRequest }
[R] 2024-04-24T14:40:51.774224000Z [ark-unknown] TRACE crates/ark/src/shell.rs:150: R already started, using existing kernel information
[R] 2024-04-24T14:40:51.774319000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'kernel_info_request') via IOPub socket
[R] 2024-04-24T14:40:51.774361000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'kernel_info_reply' message (reply to 'kernel_info_request') via Shell socket
[R] 2024-04-24T14:40:51.774506000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:51.774538000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'kernel_info_request') via IOPub socket
[R] 2024-04-24T14:40:51.775119000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:312: Received request to open comm: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "bcf0dd40-8a69-44b6-8808-69afd8bbca57", session: "8114f7705f4f6d05a9d939c651b2c1ec", username: "davis", date: "2024-04-24T14:40:51.774Z", msg_type: "comm_open", version: "5.0" }, parent_header: None, content: CommOpen { comm_id: "positron-dap-r-2-41e391bf", target_name: "positron.dap", data: Object {"client_address": String("127.0.0.1:51492")} } }
[R] 2024-04-24T14:40:51.775166000Z [ark-unknown] INFO crates/ark/src/dap/dap.rs:259: DAP: Spawning thread
[R] 2024-04-24T14:40:51.775185000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:51.775223000Z [ark-unknown] TRACE crates/ark/src/dap/dap_server.rs:53: DAP: Thread starting at address 127.0.0.1:51492.
[R] 2024-04-24T14:40:51.775395000Z [ark-unknown] INFO crates/amalthea/src/comm/comm_manager.rs:135: Comm channel opened; there are now 1 open comms
[R] 2024-04-24T14:40:51.775554000Z [ark-unknown] TRACE crates/ark/src/dap/dap_server.rs:62: DAP: Waiting for client
[R] 2024-04-24T14:40:51.775574000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:51.775592000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:51.775657000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:312: Received request to open comm: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "a4bfc0bb-a513-4a8e-99d8-458f3d6ce02b", session: "8114f7705f4f6d05a9d939c651b2c1ec", username: "davis", date: "2024-04-24T14:40:51.775Z", msg_type: "comm_open", version: "5.0" }, parent_header: None, content: CommOpen { comm_id: "positron-lsp-r-3-622a8393", target_name: "positron.lsp", data: Object {"client_address": String("127.0.0.1:51178")} } }
[R] 2024-04-24T14:40:51.775675000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'comm_msg/DAP/unknown' message via IOPub socket
[R] 2024-04-24T14:40:51.775729000Z [ark-unknown] INFO crates/amalthea/src/comm/comm_manager.rs:135: Comm channel opened; there are now 2 open comms
[R] 2024-04-24T14:40:51.775759000Z [ark-unknown] TRACE crates/ark/src/lsp/backend.rs:517: Connecting to LSP at '127.0.0.1:51178'
[R] 2024-04-24T14:40:51.775917000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:51.775975000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:51.775992000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:51.776071000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'comm_msg/LSP/unknown' message via IOPub socket
[R] 2024-04-24T14:40:51.776218000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:312: Received request to open comm: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "ffc16bba-3b1c-4460-a430-a5a28da5ce9b", session: "8114f7705f4f6d05a9d939c651b2c1ec", username: "davis", date: "2024-04-24T14:40:51.776Z", msg_type: "comm_open", version: "5.0" }, parent_header: None, content: CommOpen { comm_id: "positron-variables-r-3-b7eff62d", target_name: "positron.variables", data: Object {} } }
[R] 2024-04-24T14:40:51.776256000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:51.776276000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-shell' (ThreadId(17)) is requesting a task.
[R] 2024-04-24T14:40:51.776327000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:51.776418000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-variables' (ThreadId(28)) is requesting a task.
[R] 2024-04-24T14:40:51.776585000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-shell' (ThreadId(17)) was unblocked after waiting for 0 milliseconds.
[R] 2024-04-24T14:40:51.776615000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:51.776633000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:51.776655000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:51.776673000Z [ark-unknown] INFO crates/amalthea/src/comm/comm_manager.rs:135: Comm channel opened; there are now 3 open comms
[R] 2024-04-24T14:40:51.776695000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-variables' (ThreadId(28)) was unblocked after waiting for 0 milliseconds.
[R] 2024-04-24T14:40:51.776781000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'comm_msg/variables/refresh' message via IOPub socket
[R] 2024-04-24T14:40:51.778216000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:312: Received request to open comm: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "cfa14797-d375-497d-9c02-7f48fb215c11", session: "8114f7705f4f6d05a9d939c651b2c1ec", username: "davis", date: "2024-04-24T14:40:51.777Z", msg_type: "comm_open", version: "5.0" }, parent_header: None, content: CommOpen { comm_id: "positron-ui-r-4-b55cc19", target_name: "positron.ui", data: Object {} } }
[R] 2024-04-24T14:40:51.778279000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:51.778318000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:51.778343000Z [ark-unknown] INFO crates/amalthea/src/comm/comm_manager.rs:135: Comm channel opened; there are now 4 open comms
[R] 2024-04-24T14:40:51.778392000Z [ark-unknown] INFO crates/ark/src/kernel.rs:132: Sending UI message to frontend: Event(WorkingDirectory(WorkingDirectoryParams { directory: "~/files/programming/tree-sitter-r" }))
[R] 2024-04-24T14:40:51.778426000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:51.778454000Z [ark-unknown] INFO crates/ark/src/r_task.rs:161: Thread 'ark-shell-thread' (ThreadId(15)) is requesting an async task.
[R] 2024-04-24T14:40:51.778477000Z [ark-unknown] INFO crates/ark/src/r_task.rs:173: Thread 'ark-shell-thread' (ThreadId(15)) has sent the async task.
[R] 2024-04-24T14:40:51.778501000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:51.778524000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'comm_msg/positron-ui-r-4-b55cc19/working_directory' message via IOPub socket
[R] 2024-04-24T14:40:51.778542000Z [ark-unknown] TRACE crates/ark/src/lsp/backend.rs:526: Connected to LSP at '127.0.0.1:51178'
[R] 2024-04-24T14:40:51.778573000Z [ark-unknown] INFO crates/ark/src/kernel.rs:132: Sending UI message to frontend: Event(Busy(BusyParams { busy: false }))
[R] 2024-04-24T14:40:51.778642000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:201: Sending 'comm_msg/positron-ui-r-4-b55cc19/busy' message via IOPub socket
[R] 2024-04-24T14:40:51.778669000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-lsp' (ThreadId(27)) is requesting a task.
[R] 2024-04-24T14:40:51.778718000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:51.778755000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-lsp' (ThreadId(27)) was unblocked after waiting for 0 milliseconds.
[R] 2024-04-24T14:40:51.779076000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:312: Received request to open comm: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "698e3587-edbf-4483-b1d9-6f2cc00270ad", session: "8114f7705f4f6d05a9d939c651b2c1ec", username: "davis", date: "2024-04-24T14:40:51.778Z", msg_type: "comm_open", version: "5.0" }, parent_header: None, content: CommOpen { comm_id: "positron-help-r-5-971ca4e5", target_name: "positron.help", data: Object {} } }
[R] 2024-04-24T14:40:51.779106000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-shell' (ThreadId(17)) is requesting a task.
[R] 2024-04-24T14:40:51.779122000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:51.779138000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:51.781787000Z [ark-unknown] INFO crates/ark/src/lsp/indexer.rs:115: Indexing started.
[R] 2024-04-24T14:40:51.787682000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-shell' (ThreadId(17)) was unblocked after waiting for 8 milliseconds.
[R] 2024-04-24T14:40:51.787750000Z [ark-unknown] TRACE crates/ark/src/help/r_help.rs:75: Help comm positron-help-r-5-971ca4e5 started; started help server on port 18799
[R] 2024-04-24T14:40:51.787783000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-shell' (ThreadId(17)) is requesting a task.
[R] 2024-04-24T14:40:51.787906000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:51.788215000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-shell' (ThreadId(17)) was unblocked after waiting for 0 milliseconds.
[R] 2024-04-24T14:40:51.788330000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:51.788383000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_open') via IOPub socket
[R] 2024-04-24T14:40:51.788546000Z [ark-unknown] INFO crates/amalthea/src/comm/comm_manager.rs:135: Comm channel opened; there are now 5 open comms
[R] 2024-04-24T14:40:51.788597000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:287: Received request for open comms: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "6c782cbb-3402-4f33-baff-0a4bed0909f4", session: "8114f7705f4f6d05a9d939c651b2c1ec", username: "davis", date: "2024-04-24T14:40:51.781Z", msg_type: "comm_info_request", version: "5.0" }, parent_header: None, content: CommInfoRequest { target_name: "positron.plot" } }
[R] 2024-04-24T14:40:51.788645000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'comm_info_reply' message (reply to 'comm_info_request') via Shell socket
[R] 2024-04-24T14:40:51.788694000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_info_request') via IOPub socket
[R] 2024-04-24T14:40:51.788999000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:51.789109000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:287: Received request for open comms: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "24244763-fbd8-4d6d-9828-08c1d43a9b36", session: "8114f7705f4f6d05a9d939c651b2c1ec", username: "davis", date: "2024-04-24T14:40:51.782Z", msg_type: "comm_info_request", version: "5.0" }, parent_header: None, content: CommInfoRequest { target_name: "jupyter.widget" } }
[R] 2024-04-24T14:40:51.789144000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'comm_info_reply' message (reply to 'comm_info_request') via Shell socket
[R] 2024-04-24T14:40:51.789186000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_info_request') via IOPub socket
[R] 2024-04-24T14:40:51.789271000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:51.789420000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_info_request') via IOPub socket
[R] 2024-04-24T14:40:51.789467000Z [ark-unknown] DEBUG crates/amalthea/src/socket/shell.rs:339: Received request to send a message on a comm: JupyterMessage { zmq_identities: [[112, 111, 115, 105, 116, 114, 111, 110, 45, 115, 104, 101, 108, 108]], header: JupyterHeader { msg_id: "5ae678ea-2ae5-4518-a5a2-52f116550cc4", session: "8114f7705f4f6d05a9d939c651b2c1ec", username: "davis", date: "2024-04-24T14:40:51.784Z", msg_type: "comm_msg", version: "5.0" }, parent_header: None, content: CommWireMsg { comm_id: "positron-ui-r-4-b55cc19", data: Object {"jsonrpc": String("2.0"), "method": String("call_method"), "params": Object {"method": String("setConsoleWidth"), "params": Array [Number(89)]}} } }
[R] 2024-04-24T14:40:51.789511000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_info_request') via IOPub socket
[R] 2024-04-24T14:40:51.789580000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:51.789646000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/busy' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:51.789709000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:51.789770000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'status/idle' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:51.789837000Z [ark-unknown] TRACE crates/amalthea/src/socket/shell.rs:120: Waiting for shell messages
[R] 2024-04-24T14:40:51.789894000Z [ark-unknown] TRACE crates/amalthea/src/comm/comm_manager.rs:157: Comm manager: Sending message to comm 'positron.ui'
[R] 2024-04-24T14:40:51.790035000Z [ark-unknown] TRACE crates/ark/src/ui/ui.rs:145: Handling 'setConsoleWidth' frontend RPC method
[R] 2024-04-24T14:40:51.790052000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-comm-ui' (ThreadId(29)) is requesting a task.
[R] 2024-04-24T14:40:51.790106000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:51.790179000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-comm-ui' (ThreadId(29)) was unblocked after waiting for 0 milliseconds.
[R] 2024-04-24T14:40:51.790204000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'ark-comm-ui' (ThreadId(29)) is requesting a task.
[R] 2024-04-24T14:40:51.790237000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:51.790305000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'ark-comm-ui' (ThreadId(29)) was unblocked after waiting for 0 milliseconds.
[R] 2024-04-24T14:40:51.790527000Z [ark-unknown] TRACE crates/amalthea/src/wire/wire_message.rs:193: Sending 'comm_msg/positron-ui-r-4-b55cc19/CallMethodReply' message (reply to 'comm_msg') via IOPub socket
[R] 2024-04-24T14:40:51.839892000Z [ark-unknown] INFO crates/ark/src/lsp/indexer.rs:131: Indexing finished after 58.104ms.
[R] 2024-04-24T14:40:52.787024000Z [ark-unknown] INFO crates/ark/src/lsp/indexer.rs:70: Received signal that indexer was initialized, proceeding with diagnostics.
[R] 2024-04-24T14:40:52.787220000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'tokio-runtime-worker' (ThreadId(3)) is requesting a task.
[R] 2024-04-24T14:40:52.787273000Z [ark-unknown] INFO crates/ark/src/r_task.rs:55: Thread 'tokio-runtime-worker' (ThreadId(14)) is requesting a task.
[R] 2024-04-24T14:40:52.787416000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:52.813524000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'tokio-runtime-worker' (ThreadId(3)) was unblocked after waiting for 26 milliseconds.
[R] 2024-04-24T14:40:52.813609000Z [ark-unknown] INFO crates/ark/src/interface.rs:1026: Yielding to task - 0 more task(s) remaining
[R] 2024-04-24T14:40:52.824181000Z [ark-unknown] INFO crates/ark/src/r_task.rs:129: Thread 'tokio-runtime-worker' (ThreadId(14)) was unblocked after waiting for 36 milliseconds.
[Positron] SEND heartbeat with timeout of 30 seconds
[R] 2024-04-24T14:41:21.676053000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:41: Heartbeat message: [104, 101, 97, 114, 116, 98, 101, 97, 116]
[R] 2024-04-24T14:41:21.676425000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:50: Heartbeat message replied
[R] 2024-04-24T14:41:21.676520000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:28: Listening for heartbeats
[Positron] SEND heartbeat with timeout of 30 seconds
[R] 2024-04-24T14:41:51.678252000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:41: Heartbeat message: [104, 101, 97, 114, 116, 98, 101, 97, 116]
[R] 2024-04-24T14:41:51.678525000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:50: Heartbeat message replied
[R] 2024-04-24T14:41:51.678639000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:28: Listening for heartbeats
[Positron] SEND heartbeat with timeout of 30 seconds
[R] 2024-04-24T14:42:21.685565000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:41: Heartbeat message: [104, 101, 97, 114, 116, 98, 101, 97, 116]
[R] 2024-04-24T14:42:21.685805000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:50: Heartbeat message replied
[R] 2024-04-24T14:42:21.685858000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:28: Listening for heartbeats
[Positron] SEND heartbeat with timeout of 30 seconds
[R] 2024-04-24T14:42:51.692930000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:41: Heartbeat message: [104, 101, 97, 114, 116, 98, 101, 97, 116]
[R] 2024-04-24T14:42:51.693053000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:50: Heartbeat message replied
[R] 2024-04-24T14:42:51.693083000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:28: Listening for heartbeats
[Positron] SEND heartbeat with timeout of 30 seconds
[R] 2024-04-24T14:43:21.694667000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:41: Heartbeat message: [104, 101, 97, 114, 116, 98, 101, 97, 116]
[R] 2024-04-24T14:43:21.694792000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:50: Heartbeat message replied
[R] 2024-04-24T14:43:21.694828000Z [ark-unknown] TRACE crates/amalthea/src/socket/heartbeat.rs:28: Listening for heartbeats

[DavisVaughan]

@lionel- and I think this may be heavily related to ebkalderon/tower-lsp#284

i.e. we are guessing that the frontend is actually sending the requests over in sequential order, but tower-lsp has an async request processing framework in place that could result in us finally receiving those requests out of order. This may also explain why sometimes we get did_change() requests out of order, forcing us to maintain a cache of "future" requests we can't apply yet until we get the "missing" ones in between.

It seems to be a pretty big issue, with lots of comments on that thread.

ruff also went as far as implementing their own server rather than using tower-lsp to avoid this potential issue
astral-sh/ruff#10158

[lionel-]

Actually the tower-lsp issue is only affecting response ordering, AFAIU.

The handlers for incoming messages should be called in message order as expected and it's up to us to ensure that the concurrency doesn't mess up handling expectations. I think we can achieve that with an appropriate locking strategy.

Edit: Actually we should also be able to use some locking setup on handler exit to queue responses in the incoming order. This should fix the issue discussed in the linked thread.