[FSDB] took ~300 secs to load a signal with 20 millions VC

[heyfey]

linux perf report for fsdb_worker.js process:

Samples: 191K of event 'cpu-clock:uhpppH', Event count (approx.): 47872500000
  Children      Self  Command  Shared Object             Symbol
+   91.86%     0.00%  node     [unknown]                 [.] 0x5541f689495641d7
+   91.86%     0.00%  node     libc-2.28.so              [.] __libc_start_main
+   91.86%     0.00%  node     node                      [.] node::Start
+   91.86%     0.00%  node     node                      [.] node::NodeMainInstance::Run
+   91.86%     0.00%  node     node                      [.] node::NodeMainInstance::Run
+   91.86%     0.00%  node     node                      [.] node::SpinEventLoopInternal
+   91.86%     0.00%  node     node                      [.] uv_run
+   91.83%     0.00%  node     node                      [.] uv__io_poll
+   91.80%     0.00%  node     node                      [.] uv__stream_io
+   91.80%     0.00%  node     node                      [.] uv__read
+   91.80%     0.00%  node     node                      [.] node::LibuvStreamWrap::ReadStart()::{lambda(uv_stream_s*, long, uv_buf_t const*)#2}::_FUN
+   91.80%     0.00%  node     node                      [.] node::LibuvStreamWrap::OnUvRead
+   91.80%     0.00%  node     node                      [.] node::EmitToJSStreamListener::OnStreamRead
+   91.80%     0.00%  node     node                      [.] node::StreamBase::CallJSOnreadMethod
+   91.80%     0.00%  node     node                      [.] node::AsyncWrap::MakeCallback
+   91.80%     0.00%  node     node                      [.] node::InternalMakeCallback
+   91.80%     0.00%  node     node                      [.] node::InternalCallbackScope::Close
+   91.80%     0.00%  node     node                      [.] v8::Function::Call
+   91.80%     0.00%  node     node                      [.] v8::internal::Execution::Call
+   91.80%     0.00%  node     node                      [.] v8::internal::(anonymous namespace)::Invoke
+   91.80%     0.00%  node     node                      [.] Builtins_JSEntry
+   91.80%     0.00%  node     node                      [.] Builtins_JSEntryTrampoline
+   91.79%     0.00%  node     node                      [.] Builtins_InterpreterEntryTrampoline
+   91.79%     0.00%  node     [JIT] tid 724292          [.] 0x00007fffd000bb4c
+   91.76%     0.00%  node     node                      [.] Builtins_CEntry_Return1_ArgvOnStack_BuiltinExit
+   77.78%     0.00%  node     node                      [.] v8::internal::Builtin_HandleApiCall
+   77.78%     0.00%  node     node                      [.] v8::internal::(anonymous namespace)::HandleApiCallHelper<false>
+   77.78%     0.00%  node     node                      [.] v8::internal::FunctionCallbackArguments::Call
+   77.53%     0.00%  node     [JIT] tid 724292          [.] 0x00007fffd000cc3c
+   77.53%     0.00%  node     node                      [.] v8impl::(anonymous namespace)::FunctionCallbackWrapper::Invoke
+   77.52%     0.00%  node     fsdb_reader.node          [.] Napi::details::CallbackData<Napi::Object (*)(Napi::CallbackInfo const&), Napi::Object>::Wrapper
+   75.27%     0.69%  node     fsdb_reader.node          [.] getValueChanges
+   63.67%     0.00%  node     node                      [.] v8::internal::Heap::CollectGarbage
+   63.66%     0.00%  node     node                      [.] v8::internal::Heap::PerformGarbageCollection
+   63.61%     0.00%  node     node                      [.] v8::internal::HeapAllocator::AllocateRawWithRetryOrFailSlowPath
+   63.61%     0.00%  node     node                      [.] v8::internal::HeapAllocator::AllocateRawWithLightRetrySlowPath
+   63.39%     0.00%  node     node                      [.] v8::internal::Heap::Scavenge
+   63.35%     1.05%  node     node                      [.] v8::internal::ScavengerCollector::CollectGarbage
+   60.51%     0.00%  node     node                      [.] v8::internal::Heap::IterateRoots
+   59.87%     0.08%  node     node                      [.] napi_create_array_with_length
+   59.80%     0.17%  node     node                      [.] v8::Array::New
+   59.62%     0.21%  node     node                      [.] v8::internal::Factory::NewJSArray
+   36.19%     0.25%  node     node                      [.] v8::internal::Factory::AllocateRaw
+   32.06%    32.06%  node     node                      [.] v8::internal::ClearStaleLeftTrimmedHandlesVisitor::VisitRootPointers
+   30.80%     0.10%  node     node                      [.] v8::internal::Factory::NewJSArrayWithUnverifiedElements
+   30.03%     0.20%  node     node                      [.] v8::internal::Factory::AllocateRawWithAllocationSite
+   28.38%     0.22%  node     node                      [.] v8::internal::HandleScopeImplementer::IterateThis
+   28.36%     0.44%  node     node                      [.] v8::internal::FactoryBase<v8::internal::Factory>::NewFixedArrayWithFiller
+   28.34%     0.03%  node     node                      [.] v8::internal::Factory::NewJSArrayStorage
+   28.14%    25.94%  node     node                      [.] v8::internal::RootScavengeVisitor::VisitRootPointers
+   27.90%     0.06%  node     node                      [.] v8::internal::FactoryBase<v8::internal::Factory>::AllocateRawArray
+   14.23%     0.00%  node     [JIT] tid 724292          [.] 0x00007fffd000ccfe
+   14.23%     0.00%  node     [JIT] tid 724292          [.] 0x00007fffd00092dd
+   14.23%     0.00%  node     [JIT] tid 724292          [.] 0x00007fffd000af6e
+   13.98%     0.50%  node     node                      [.] v8::internal::JsonStringifier::Serialize_<false>
+   13.98%     0.00%  node     [JIT] tid 724292          [.] 0x00007fffd000852d
+   13.98%     0.00%  node     node                      [.] v8::internal::Builtin_JsonStringify
+   13.98%     0.00%  node     node                      [.] v8::internal::JsonStringify
+   13.98%     0.00%  node     node                      [.] v8::internal::JsonStringifier::Serialize_<true>
+   13.98%     0.37%  node     node                      [.] v8::internal::JsonStringifier::SerializeArrayLikeSlow
+    9.32%     0.34%  node     node                      [.] napi_set_element
+    8.34%     0.00%  node     node                      [.] v8::internal::IncrementalStringBuilder::Extend
+    8.34%     0.01%  node     node                      [.] v8::internal::FactoryBase<v8::internal::Factory>::NewRawOneByteString
+    8.33%     0.00%  node     node                      [.] v8::internal::FactoryBase<v8::internal::Factory>::AllocateRawWithImmortalMap
+    8.26%     0.27%  node     node                      [.] v8::internal::JsonStringifier::SerializeSmi
+    8.10%     1.06%  node     node                      [.] v8::Object::Set
+    5.47%     0.00%  node     node                      [.] v8::internal::ScavengerCollector::JobTask::ProcessItems
+    4.81%     0.96%  node     node                      [.] v8::internal::Scavenger::Process
+    4.74%     0.00%  node     libpthread-2.28.so        [.] start_thread
+    4.74%     0.00%  node     node                      [.] node::(anonymous namespace)::PlatformWorkerThread
+    4.74%     0.00%  node     node                      [.] v8::platform::DefaultJobWorker::Run
+    4.54%     3.90%  node     node                      [.] v8::internal::Scavenger::ScavengeObject<v8::internal::FullHeapObjectSlot>
+    3.63%     0.00%  node     node                      [.] v8::internal::ScavengerCollector::JobTask::Run
+    3.00%     0.56%  node     node                      [.] v8::internal::Object::AddDataProperty
+    2.99%     1.16%  node     node                      [.] v8::internal::LookupIterator::Start<true>
+    2.63%     0.72%  node     fsdb_reader.node          [.] Napi::String::Utf8Value[abi:cxx11]

[Lramseyer]

The bottleneck is vscode.postMessage(), where it sends the value change data to the webview. This was somewhat mitigated by chunking the value change data, but it looks like I should implement compression. The wellen library supports it, but I will need to support it on the webview side.

[heyfey]

There's also huge room for improvement in fsdb worker. I can work on it after the fsdb branch is merged. @Lramseyer please assign to me.

[Lramseyer]

OK, I implemented LZ4 compression on the WASM side of signal loading. I notice a speed up for signals with a lot of value changes. I am going to work on the data structuring a little more, and write up some documentation so that you can use it.

I also haven't forgotten about your PR. I will merge it soon!

[heyfey]

Great! Please let me know if you have any questions about the PR

I have two questions:

1. Is the PR easy to merge? Or should I make a new one based on the latest commit
2. Can the LZ4 compression somehow apply to FSDB flow?

[Lramseyer]

I am still working on LZ4 compression of value change data. Essentially, I needed a way to encode the value change data (in a way that was not JSON, and would compress better) compress it, and then decode it in the webview. The challenge was finding a compression library and a decompression library in both rust and typescript. Next, I profiled it with real waveforms, and I saw a noticeable speed up for waveforms with more than a few hundred value changes.

The next steps are the following:

• Better chunking so that I don't have to allocate a ton of memory when loading the value change data
• Supporting reals and strings
• documenting it so that you can use it in the FSDB component

I will probably change up the data structures a little bit, so I wouldn't rush to implement this on your end just yet.