Fix corrupted config error by CyrilleB79 · Pull Request #15691 · nvaccess/nvda

CyrilleB79 · 2023-10-26T15:02:24Z

Link to issue number:

Summary of the issue:

Critical error when starting NVDA with a corrupted config file.

During config initialization, an error is logged. To check if it should play an error sound, NVDA imports nvwave, which in turn imports nvdaHelper, which imports versionInfo, where "_" is not yet defined since translations are not initialized.

Description of user facing changes

If the configuration file is corrupted, NVDA will not fail starting anymore, but will reinitialize the configuration to default as it did in NVDA 2023.1 and before.

Description of development approach

First I have used buildVersion module in nvdaHelper instead of versionInfo since the latter contains localized information that we do not use. But it was not enough since "_" (underscore is still missing when importing eventHandler or api
Thus, I have implemented an extension point notified when an error is logged and with a handler responsible of playing the error sound. This handler is registered when nvwave audio is iinitialized. More details in Fix corrupted config error #15691 (review).

Also, when investigating the issue and working on this PR, I have fixed the following minor issues:

Removed two lines log.debugWarning("", exc_info=True), and used the exc_info in the log.warning just above. Indeed, during config initialization, log level is not yet known and thus the exc_info information is not known during startup if needed.
Do not provide a write function when loading the config if the config file name is None since it just generates an erronous warning indicating that I am using a read only file system.

Additional questions and notes

Should I implement a system test to avoid such issues in the future?
@lukaszgo1, since you have worked on import order in the past, your review would be appreciated if possible.
I have not checked, but it has probably been introduced with Support for audio output using WASAPI #14697 or other WASAPI PRs. Cc @jcsteh

Testing strategy:

Tested STR of #15690.

Known issues with pull request:

Code Review Checklist:

Documentation:
- Change log entry
- User Documentation
- Developer / Technical Documentation
- Context sensitive help for GUI changes
Testing:
- Unit tests
- System (end to end) tests
- Manual testing
UX of all users considered:
- Speech
- Braille
- Low Vision
- Different web browsers
- Localization in other languages / culture than English
API is compatible with existing add-ons.
Security precautions taken.

lukaszgo1

While what has been implemented here certainly fixes the issue at hand, I have a feeling that the underlying problem still remains. This is by no means a criticism, (we always solved circular imports using lazy importing), but my personal opinion is that whenever possible code should be restructured to avoid these. In this particular case NVDAHelper clearly requires importing way too much, (most of its uses only requires localLib) and should be split, however this is out of scope for this PR, and should be done in a dedicated one. the following would improve this particular situation without reorganizing too much code:
Currently logHandler requires nvwave to play sounds, yet it can only do so when nvwave is initialized. Rather than importing it lazily in the logHandler I'd defer the decision if the sound can be played, and the actual act of playing it to nvwave, by adding an extension point to the logHandler (something like onErrorLogged). When initializing nvwave it should register a function with this extension point, and in it check if nvwave is not in error, if it is not just play the error sound.
There are two points worth keeping in mint with this design:

extensionPoints imports logHandler, so we are trading one circular import for another. Having said that we would have only one lazy import as opposed to around 10 in nvwave, and several more in logHandler, so I'd say this is a right move. To make this work the extension point in logHandler has to be retrieved with a module level getter function where extensionPoints would be lazily imported (I'd suggest using functools.lru_cache with a cache size set to 1 to create it first time it is needed, and then return cached instance)
nvwave should be terminated in core, to make sure the function responsible for playing error sounds is not registered multiple times

In addition having system test for this issue would probably be helpful.

CyrilleB79 · 2023-10-27T10:45:26Z

@lukaszgo1 thanks for the review and the design suggestion. @seanbudd I would like to hear your opinion on this design before implementing it; thus, I'll put this PR as ready for review, but I am totally open to the design change suggested by @lukaszgo1 if it goes in the sense of code simplification.

I have some remaining questions regarding this design:

Do you suggest to remove the check on nvwave.isInError from shouldPlayErrorSound and to put it in the new handler registered to the new extensions point?
The pattern with __getattr__ at module level to import lazily the extension point point is not common in NVDA's code. Does it not make the code more complex? It also prevents the discoverability of this extension point.
Also, I have not understood the goal for caching extensionPoints; can you help me clarify

lukaszgo1 · 2023-10-27T10:55:27Z

Do you suggest to remove the check on nvwave.isInError from shouldPlayErrorSound and to put it in the new handler registered to the new extensions point?

Yes - the fact that nvwave is in error is its internal details, and in general the responsibility for playing error sound or not is entirely in the module which has the functionality to play it

The pattern with __getattr__ at module level to import lazily the extension point point is not common in NVDA's code. Does it not make the code more complex? It also prevents the discoverability of this extension point.

I'm sorry - I haven't made myself clear enough here. What I proposed was not a __getattr__, but a normal function (something like getOnErrorLogged) in the logHandler. This function lazily imports extensionPoints, creates the onErrorLogged action, and returns it

Also, I have not understood the goal for caching extensionPoints; can you help me clarify

It is not extensionPoints which should be cached - rather the created instance of onErrorLogged action should be created only once, and then just returned from the function in subsequent calls.

CyrilleB79 · 2023-10-29T23:12:46Z

Thanks @lukaszgo1 for all these indications.

nvwave should be terminated in core, to make sure the function responsible for playing error sounds is not registered multiple times

How can it be?

Do you suggest to remove the check on nvwave.isInError from shouldPlayErrorSound and to put it in the new handler registered to the new extensions point?

Yes - the fact that nvwave is in error is its internal details, and in general the responsibility for playing error sound or not is entirely in the module which has the functionality to play it

So it seems that shouldPlayErrorSound should also go to nvwave.py to be logical. This is an API breaking change unfortunately.
Do you agree with this.

lukaszgo1 · 2023-10-30T11:47:32Z

nvwave should be terminated in core, to make sure the function responsible for playing error sounds is not registered multiple times

How can it be?

In the same way as most of our existing modules i.e. at the bottom of core.main it should be passed to the _terminate function. You would have to add nvwave.terminate to make this work.

Do you suggest to remove the check on nvwave.isInError from shouldPlayErrorSound and to put it in the new handler registered to the new extensions point?

Yes - the fact that nvwave is in error is its internal details, and in general the responsibility for playing error sound or not is entirely in the module which has the functionality to play it

So it seems that shouldPlayErrorSound should also go to nvwave.py to be logical. This is an API breaking change unfortunately. Do you agree with this.

I haven't considered this before, but I believe shouldPlayErrorSound can remain in logHandler, but without checking of nvwave being in error or not. My thinking is that shouldPlayErrorSound is responsible for checking if user requested error sounds to be played, and the code in nvwave checks if it technically can be played or not.

CyrilleB79 · 2023-11-01T23:29:19Z

nvwave should be terminated in core, to make sure the function responsible for playing error sounds is not registered multiple times

How can it be?

In the same way as most of our existing modules i.e. at the bottom of core.main it should be passed to the _terminate function. You would have to add nvwave.terminate to make this work.

Sorry, I meant:
How can the function responsible for playing error sound be registered multiple times in case I do not create a terminate function to unregister it?

Do you suggest to remove the check on nvwave.isInError from shouldPlayErrorSound and to put it in the new handler registered to the new extensions point?

Yes - the fact that nvwave is in error is its internal details, and in general the responsibility for playing error sound or not is entirely in the module which has the functionality to play it

So it seems that shouldPlayErrorSound should also go to nvwave.py to be logical. This is an API breaking change unfortunately. Do you agree with this.

I haven't considered this before, but I believe shouldPlayErrorSound can remain in logHandler, but without checking of nvwave being in error or not. My thinking is that shouldPlayErrorSound is responsible for checking if user requested error sounds to be played, and the code in nvwave checks if it technically can be played or not.

This makes sense. Maybe I will have to find more adapted names than _onErrorLogged / _getOnErrorLogged...

AppVeyorBot · 2023-11-02T00:00:23Z

PASS: Translation comments check.
PASS: Unit tests.
PASS: Lint check.
FAIL: System tests (tags: installer NVDA). See test results for more information.
Build (for testing PR): https://ci.appveyor.com/api/buildjobs/q5nk81e2r09ud3u3/artifacts/output/nvda_snapshot_pr15691-29822,b75a4236.exe
CI timing (mins):
INIT 0.0,
INSTALL_START 0.9,
INSTALL_END 0.9,
BUILD_START 0.0,
BUILD_END 24.6,
TESTSETUP_START 0.0,
TESTSETUP_END 0.3,
TEST_START 0.0,
TEST_END 19.1,
FINISH_END 0.1

See test results for failed build of commit b75a423672

lukaszgo1 · 2023-11-05T14:08:56Z

Sorry, I meant: How can the function responsible for playing error sound be registered multiple times in case I do not create a terminate function to unregister it?

I assumed, without looking at the code :-( that nvwave is initialized again in core.resetConfiguration, but it isn't. You can ignore this part i.e. there is no need to terminate it in that case.

lukaszgo1

Please update the initial comment, to describe the new approach.
Also I take back my suggestion about system tests. I haven't realized that they rely on scratchpad being enabled, and that cannot be done when the provided config is not valid. It should be possible to convert them into an add-on, and set the necessary config from it, rather than just providing the preset config file, but that is certainly something for another day.

CyrilleB79 · 2023-11-08T12:27:21Z

-				nvwave.playWaveFile(os.path.join(globalVars.appDir, "waves", "error.wav"))
-			except:
-				pass
+			getOnErrorSoundRequested().notify()


I would have preferred a more global "pre_errorLogged" extension point, which could be more useful for add-on authors (including myself with NVDA Dev & Test Toolbox). But I am not able to define one cleanly without reintroducing more lazy imports.

@XLTechie, @lukaszgo1 any opinion on this?

That is probably something for a separate issue / PR, but if there is a need to have more extension points in the logHandler then the circular import between it and extensionPoints has to be fixed. My first thought would be to expose an additional way to import logHandler.log (perhaps from globalVars).

seanbudd · 2023-11-08T22:30:16Z

-		log.warning("Error saving configuration; probably read only file system")
-		log.debugWarning("", exc_info=True)
-		pass
+	except PermissionError:


are we certain no other exceptions are thrown here? wouldn't it be safer to continue to catch other exceptions and log at exception level

Actually, other exceptions are thrown here and it was erroneous to catch all here to issue a so specific error message related to read only file system.

For an example of other exception thrown here, in NVDA 2023.3, press 3 times NVDA+control+R to restore default settings. You will get the following inappropriate warning message in the log:

WARNING - config.profileUpgrader.upgrade (09:35:01.738) - MainThread (15004): Error saving configuration; probably read only file system

Thus I have narrowed the error filtering to PermissionError as it is already done in source/config/__init__.py for the same logged message.

If there are other exceptions that were previously catched by the filtering on Exception, they should be reported and fixed, not filtered out with a single warning.

) Fix-up of #15691. Summary of the issue: In #15691, a new extension point has been created. Unfortunately I have forgotten to document it. Description of user facing changes Document this extension point in the dev guide as well as in the change log.

…ccess#16017) Fix-up of nvaccess#15691. Summary of the issue: In nvaccess#15691, a new extension point has been created. Unfortunately I have forgotten to document it. Description of user facing changes Document this extension point in the dev guide as well as in the change log.

Fix of a critical error at startup when there is a corrupted config file

134c8eb

CyrilleB79 force-pushed the fixCorruptedConfigError branch from eeaaab4 to 134c8eb Compare October 26, 2023 15:13

Change log

225a0d5

lukaszgo1 suggested changes Oct 26, 2023

View reviewed changes

Comment thread source/config/profileUpgrader.py Outdated

Small code modification

efdb07f

CyrilleB79 added 2 commits October 29, 2023 23:13

Merge branch 'master' into fixCorruptedConfigError

7a8ee64

Remove lazy imports in nvwave.py

12c7ac9

CyrilleB79 added 2 commits November 2, 2023 00:08

Use extension point

8243bf6

Merge branch 'master' into fixCorruptedConfigError

977480b

CyrilleB79 added 3 commits November 3, 2023 23:17

Merge branch 'master' into fixCorruptedConfigError

98334ab

Unregister extension point handler

5898124

Rename extension point

81d71b8

Merge branch 'master' into fixCorruptedConfigError

37d68f1

CyrilleB79 marked this pull request as ready for review November 8, 2023 12:16

CyrilleB79 requested a review from a team as a code owner November 8, 2023 12:16

CyrilleB79 requested a review from seanbudd November 8, 2023 12:16

lukaszgo1 suggested changes Nov 8, 2023

View reviewed changes

Comment thread source/logHandler.py

CyrilleB79 commented Nov 8, 2023

View reviewed changes

seanbudd reviewed Nov 9, 2023

View reviewed changes

CyrilleB79 added 2 commits November 9, 2023 09:17

Merge branch 'master' into fixCorruptedConfigError

058a11b

Add type hints

4472a99

seanbudd approved these changes Nov 9, 2023

View reviewed changes

lukaszgo1 mentioned this pull request Nov 11, 2023

Fix installer bug where install fails if registry entries exist but NVDA is not installed #15767

Merged

5 tasks

seanbudd merged commit 5709ce6 into nvaccess:master Nov 12, 2023

nvaccessAuto added this to the 2024.1 milestone Nov 12, 2023

CyrilleB79 deleted the fixCorruptedConfigError branch November 13, 2023 14:02

hwf1324 mentioned this pull request Nov 14, 2023

Where possible, invalid keys should be reset to the default, rather than resetting the whole config. #14424

Closed

CyrilleB79 mentioned this pull request Jan 9, 2024

Document logHandler.getOnErrorSoundRequested() extension point #16017

Merged

5 tasks

Uh oh!

Conversation

CyrilleB79 commented Oct 26, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Link to issue number:

Summary of the issue:

Description of user facing changes

Description of development approach

Additional questions and notes

Testing strategy:

Known issues with pull request:

Code Review Checklist:

Uh oh!

lukaszgo1 left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

CyrilleB79 commented Oct 27, 2023

Uh oh!

lukaszgo1 commented Oct 27, 2023

Uh oh!

CyrilleB79 commented Oct 29, 2023

Uh oh!

lukaszgo1 commented Oct 30, 2023

Uh oh!

CyrilleB79 commented Nov 1, 2023

Uh oh!

AppVeyorBot commented Nov 2, 2023

Uh oh!

lukaszgo1 commented Nov 5, 2023

Uh oh!

lukaszgo1 left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

CyrilleB79 Nov 8, 2023

Choose a reason for hiding this comment

Uh oh!

lukaszgo1 Nov 9, 2023

Choose a reason for hiding this comment

Uh oh!

Uh oh!

seanbudd Nov 8, 2023

Choose a reason for hiding this comment

Uh oh!

CyrilleB79 Nov 9, 2023

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

CyrilleB79 commented Oct 26, 2023 •

edited

Loading