[DDW-1088] Fix no progress shown on loading screen on Windows #2967

marcin-mazurek · 2022-04-21T21:45:14Z

This PR fixes the issue with no progress shown on the loading screen on Windows.

Screenshots

Testing Checklist

Slack QA thread
Test

Review Checklist

Basics

Code Quality

Important parts of the code are properly commented and documented
Code is properly typed with typescript types
React components are split-up enough to avoid unnecessary re-renderings
Any code that only works in main process is neatly separated from components

Testing

New feature/change is covered by acceptance tests
New feature/change is manually tested and approved by QA team
All existing acceptance tests are still up-to-date
New feature/change is covered by Daedalus Testing scenario
All existing Daedalus Testing scenarios are still up-to-date

After Review

Update Slack QA thread by marking it with a green checkmark

lucas-barros · 2022-04-22T14:14:59Z

@marcin-mazurek I think the MaxListenersExceededWarning might be due to the polling aspect of watchFile. It is batching many progress lines from the file and sending a lot of events at once which will set many listeners at once, I belive. I added a commit to debounce the send event, which will limit the amount of IPC listeners. Let me know what you think.

…ce usage

…w messages on actual change

marcin-mazurek · 2022-04-22T16:46:11Z

source/main/utils/handleCheckBlockReplayProgress.ts

-    const percentage = line.match(/Progress:([\s\d.,]+)%/)?.[1];
-    const progressType = getProgressType(line);
-    if (!percentage || !progressType) {
+    const unparsedProgress = line.match(/Progress:([\s\d.,]+)%/)?.[1];


I've decided to make the variable names more concise as the if in line 70 was getting a bit too big to read it easily.

marcin-mazurek · 2022-04-22T16:49:03Z

source/main/utils/handleCheckBlockReplayProgress.ts

+
+    const progress = Math.floor(parseFloat(unparsedProgress));
+
+    if (lastReportedProgressByType[type] !== progress) {


This helps us ensure we're not sending duplicate events via IPC, and mitigates the risk of getting the MaxListenersExceededWarning, which could previously be observed while trying to send multiple (10+) messages at once.

The way fs.fileWatch works is, it pools for file changes every 5 seconds (by default) and invokes given callback for each line - so if there are 100 new lines added in 5 seconds = 100 callback calls = 100 IPC messages.

marcin-mazurek · 2022-04-22T16:53:02Z

source/main/utils/handleCheckBlockReplayProgress.ts

+    // https://github.com/nodejs/node/issues/36888
+    // https://github.com/lucagrulla/node-tail/issues/137
+    // https://nodejs.org/dist/latest-v14.x/docs/api/fs.html#fs_caveats
+    useWatchFile: environment.isWindows,


This is the actual fix for Windows.

marcin-mazurek · 2022-04-22T16:55:53Z

source/renderer/app/components/loading/syncing-connecting/SyncingProgress/SyncingProgress.tsx

          className={makePercentageCellStyles(props[type] === 100)}
        >
-          {Math.floor(props[type])}%
+          {props[type]}%


I moved this to the main process so we can compare against actually displayed values (currently we're getting values as float and then dropping the fractional part in the component itself, which results in unnecessary re-renders)

…ogress-on-win-splash-screen

gabriela-ponce · 2022-04-25T14:19:34Z

@marcin-mazurek The behavior is as expected in most scenarios, but I found some inconsistencies:

In macOS, the first item never shows the actual progress. It's ok for the rest of the items most of the time (sometimes it also fails) and it also looks ok in production.
For Windows, most of the time it's working, but similarly to macOS, the progress is not displayed sometimes for any item. To provide a little more context, this issue in Windows reproduces when I deleted the logs folder to get new logs. After a few tries it would be ok, but as it doesn't reproduce in production, I'm wondering if this can be improved.

miorsufianiohk · 2022-04-25T15:42:25Z

Hi @marcin-mazurek ,

For build 21637, on Linux when starting the first time all 3 items were showing 0%. The percentages never went up. But the transition to main screen happened eventually. However, the subsequent attempts did show percentages going up. When retested with production, the production did show percentages going up the first time I ran Daedalus. (ps: I didn't take any video as some of the issues overlap with what @gabriela-ponce found here)

…ges are lost if the IPC subscription is registered late

marcin-mazurek · 2022-04-26T21:56:10Z

source/main/utils/handleCheckBlockReplayProgress.ts

    }

-    const progress = Math.floor(parseFloat(unparsedProgress));
+    // In rare cases cardano-node does not log 100%, therefore we need to manually mark the previous step as complete.


This mitigates the risk of having a race condition. In rare cases the log entries can be pushed before we set up the file watch mechanism, so this additional logic ensures we mark previous steps as complete when the next steps starts. This also improves UX as currently sometimes cardano-node doesn't report 100% progress.

I believe the initial goal was to have the UI matching 1:1 the logs so the users could report the exactly progress in case they get stuck. @dmitrii-gaico Do you think this new behavior is fine ?

Alternatively we can read past entries from the file. @szymonmaslowski found out that there is a param in tail that allows us to do that.

But to be fair, I believe it just depends how you interpret logs. Eg. you can interpret the following entry:

�[34m[Marcins-:cardano.node.ChainDB:Info:19]�[0m [2022-04-27 12:30:36.94 UTC] Opened lgr db �[34m[Marcins-:cardano.node.ChainDB:Info:19]�[0m [2022-04-27 12:30:36.94 UTC] Started initial chain selection

as "replayed block is completed". It just doesn't match the Progress: x%. But makes the UX much better and shows the truth. The steps are sequential, but previous logic would often result in showing the previous step is stuck at eg. 67% and next step is complete, while that's not true.

Are we 100% the steps are sequential? Often cardano-node would output in a different order depending of the ledger state.

Although I observed this behaviour consistently while testing, I might be wrong. Since this implementation is controversial, I'll reimplement this with the approach @szymonmaslowski suggested - using the fromBeginning param from tail.

marcin-mazurek · 2022-04-26T22:05:04Z

source/main/utils/handleCheckBlockReplayProgress.ts

+
+    if (progressReport[type] !== progress) {
+      progressReport[type] = progress;
+      getBlockSyncProgressChannel.send(progressReport, mainWindow.webContents);


Instead of sending report for a specific type, we will send the whole progress report. This resolves the issue where the IPC channel subscription in the renderer is registered late and messages from the main thread are sent into the void in case sync step is very quick.

Question for people more experienced with IPC: is there any way to send a 'sticky' message (messsage which can be delivered to subscriptions registered after the message was sent)? If so, we could just slightly tweak the previous implementation which sends less data... However, I tried searching for it and couldn't find anything.

I don't know about the electron IPC implementation but the node IPC protocol itself does not support queueing messages. I think sending the entire progressReport object totally makes sense. It is not a concern from the performance perspective.

Agreed sending a snapshot of progressReport , that's smart.

marcin-mazurek · 2022-04-26T22:07:37Z

@gabriela-ponce @miorsufianiohk could you please have one more look when you get the chance? Hopefully I addressed the scenarios you've described.

Unfortunately there will be more dev effort - I found another issue which I think we should solve. Namely, we're not stopping the file watch when the sync is complete. In Mac/Linux implementation uses the performant fs.watch API it should be fine, but on Windows, where we use the less performant fs.watchFile, it may cause some performance issues. I'll be addressing that tomorrow.

szymonmaslowski

Good job!

szymonmaslowski · 2022-04-27T11:24:52Z

source/main/utils/handleCheckBlockReplayProgress.ts

+  tail.on('line', handleNewLogLine);
+};
+
+const waitForLogFileToBeCreatedAndWatchLogFile = ({


Suggested change

const waitForLogFileToBeCreatedAndWatchLogFile = ({

const waitForLogFileToBeCreatedAndWatchIt = ({

szymonmaslowski · 2022-04-27T11:44:45Z

source/main/utils/handleCheckBlockReplayProgress.ts

+
+    if (progressReport[type] !== progress) {
+      progressReport[type] = progress;
+      getBlockSyncProgressChannel.send(progressReport, mainWindow.webContents);


I don't know about the electron IPC implementation but the node IPC protocol itself does not support queueing messages. I think sending the entire progressReport object totally makes sense. It is not a concern from the performance perspective.

dmitrii-gaico · 2022-04-27T12:27:20Z

@marcin-mazurek @szymonmaslowski Hello! Let's keep this PR as a Fix Only and gather all the "suggestions to improve" in a separate card so we can implement those in near future. Thank you in advance!

…ed previous sync steps as complete when 100% was not seen in logs

marcin-mazurek · 2022-04-27T14:52:18Z

@gabriela-ponce @miorsufianiohk @dmitrii-gaico I just pushed another change, which is a result of a discussion we had in the code review. Please use the 21648 build for testing. Sorry for last minute change.

danielmain

Clean and well refactor 💪

Great job @marcin-mazurek !

…reen

marcin-mazurek · 2022-04-28T10:16:49Z

@danielmain kudos to @lucas-barros too as he contributed to this PR!

marcin-mazurek added bug WIP ⏳release-vNext labels Apr 21, 2022

[DDW-1088] Fix no progress shown on splash screen on Windows

761d05a

marcin-mazurek force-pushed the fix/ddw-1088-no-progress-on-win-splash-screen branch from 5ab1201 to 761d05a Compare April 21, 2022 21:49

[DDW-1088] Use debounce

9b48a33

Marcin Mazurek added 3 commits April 22, 2022 17:26

[DDW-1088] Debounce entire fs.watchFile callback to reduce the resour…

f37a79a

…ce usage

[DDW-1088] Keep track of reported progress in memory and only send ne…

9f5a6c4

…w messages on actual change

[DDW-1088] Remove debug statement

02acfd3

marcin-mazurek commented Apr 22, 2022

View reviewed changes

marcin-mazurek self-assigned this Apr 22, 2022

[DDW-1088] Changelog

849b704

marcin-mazurek requested review from lucas-barros, renanvalentin and szymonmaslowski April 22, 2022 17:05

lucas-barros approved these changes Apr 22, 2022

View reviewed changes

Marcin Mazurek added 2 commits April 22, 2022 19:15

[DDW-1088] Update storybook

acbdaad

Merge remote-tracking branch 'origin/develop' into fix/ddw-1088-no-pr…

2e50e37

…ogress-on-win-splash-screen

marcin-mazurek removed the WIP label Apr 25, 2022

[DDW-1088] Trigger build

1c62127

Lucas Araujo and others added 2 commits April 25, 2022 22:23

[DDW-1088] Cover log file not yet created case

276eaa5

[DDW-1088] Fix race condition - send full proress reports so no messa…

4894005

…ges are lost if the IPC subscription is registered late

marcin-mazurek commented Apr 26, 2022

View reviewed changes

dmitrii-gaico self-requested a review April 27, 2022 10:21

szymonmaslowski approved these changes Apr 27, 2022

View reviewed changes

[DDW-1088] Ensure file is read from beginning, remove logic that mark…

2da0a21

…ed previous sync steps as complete when 100% was not seen in logs

[DDW-1088] Address PR feedback

2af70f8

renanvalentin approved these changes Apr 27, 2022

View reviewed changes

gabriela-ponce approved these changes Apr 27, 2022

View reviewed changes

dmitrii-gaico approved these changes Apr 28, 2022

View reviewed changes

danielmain approved these changes Apr 28, 2022

View reviewed changes

Merge branch 'develop' into fix/ddw-1088-no-progress-on-win-splash-sc…

888400b

…reen

danielmain merged commit 97d7693 into develop Apr 28, 2022

danielmain deleted the fix/ddw-1088-no-progress-on-win-splash-screen branch April 28, 2022 08:05

danielmain added release-4.10.0 and removed ⏳release-vNext labels May 16, 2022


		const progress = Math.floor(parseFloat(unparsedProgress));

		if (lastReportedProgressByType[type] !== progress) {

	const waitForLogFileToBeCreatedAndWatchLogFile = ({
	const waitForLogFileToBeCreatedAndWatchIt = ({

[DDW-1088] Fix no progress shown on loading screen on Windows #2967

[DDW-1088] Fix no progress shown on loading screen on Windows #2967

Uh oh!

Conversation

marcin-mazurek commented Apr 21, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Screenshots

Testing Checklist

Review Checklist

Basics

Code Quality

Testing

After Review

Uh oh!

lucas-barros commented Apr 22, 2022

Uh oh!

marcin-mazurek Apr 22, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

marcin-mazurek Apr 22, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

marcin-mazurek Apr 22, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

gabriela-ponce commented Apr 25, 2022

Uh oh!

miorsufianiohk commented Apr 25, 2022

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

marcin-mazurek Apr 27, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

marcin-mazurek Apr 26, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

marcin-mazurek Apr 26, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

marcin-mazurek commented Apr 26, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

szymonmaslowski left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

dmitrii-gaico commented Apr 27, 2022

Uh oh!

marcin-mazurek commented Apr 27, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

danielmain left a comment

Choose a reason for hiding this comment

Uh oh!

marcin-mazurek commented Apr 28, 2022

Uh oh!

Reviewers

Assignees

marcin-mazurek commented Apr 21, 2022 •

edited

Loading

marcin-mazurek Apr 22, 2022 •

edited

Loading

marcin-mazurek Apr 22, 2022 •

edited

Loading

marcin-mazurek Apr 22, 2022 •

edited

Loading

marcin-mazurek Apr 27, 2022 •

edited

Loading

marcin-mazurek Apr 26, 2022 •

edited

Loading

marcin-mazurek Apr 26, 2022 •

edited

Loading

marcin-mazurek commented Apr 26, 2022 •

edited

Loading

marcin-mazurek commented Apr 27, 2022 •

edited

Loading