Skip to content

Fixed a bug causing wrong deprecation warnings or errors. #14806

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Merged
merged 5 commits into from
Apr 18, 2023
Merged

Fixed a bug causing wrong deprecation warnings or errors. #14806

merged 5 commits into from
Apr 18, 2023

Conversation

CyrilleB79
Copy link
Collaborator

@CyrilleB79 CyrilleB79 commented Apr 7, 2023 •
edited
Loading

Link to issue number:

None
Fix-up of #14350.

Summary of the issue:

Running NVDA 2023.1 (and older), with add-ons and/or scratchpad enabled:

I get the following deprecation warnings:

  • When opening start menu: 
    WARNING - appModuleHandler._warnDeprecatedAliasAppModule (15:49:46.531) - MainThread (19688):
Importing appModules.searchapp is deprecated, instead import appModules.searchui.
  • When switching to Notepad++: 
    WARNING - appModuleHandler._warnDeprecatedAliasAppModule (15:50:26.621) - MainThread (19688):
Importing appModules.notepad++ is deprecated, instead import appModules.notepadPlusPlus.

And if I force errors on deprecated code by modifying NVDAState._allowDeprecatedAPI to return False, I get errors instead.

This is not expected since these warnings/errors come from NVDA's core code which should not (and actually does not) contain deprecated code.

Description of user facing changes

No more wrong deprecation warnings/errors due to NVDA's core appModules when opening start menu or switching to Notepad++

Description of development approach

appModules.__path__ contains the paths where NVDA has to search appModules. It contains first the folder in the scratchpad, then the folders in add-on containing appModules and finally the core appModule folder. Thus we need to look at the last element of appModules.__path__, not the first as it was done.

Testing strategy:

  • Test with add-ons and scratchpad that no deprecation warning nor error appear anymore.
  • Tested that the following call in the console still causes the warning to be logged (upon first call):
    from appModules import searchapp

Note: This was probably missed during #13366 test, maybe because it was tested without add-on nor scratchpad.

Known issues with pull request:

Change log entries:

Bug fixes (or Changes for developers? Where should bugfixes impacting only dev be listed?)

NVDA will no longer log inaccurate warnings or errors about deprecated appModules. (#14806)

Code Review Checklist:

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

@AppVeyorBot
Copy link

See test results for failed build of commit a18e67891d

lukaszgo1
lukaszgo1 suggested changes Apr 7, 2023
View reviewed changes
Copy link
Contributor

@lukaszgo1 lukaszgo1 left a comment •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for this PR @CyrilleB79 ! In fact this regressed in #14350 as follows:

  • Before #14350 at the first import of appModuleHandler no additional packages were added to the path of appModules, so first index indeed represented the path of modules bundled in NVDA
  • Now code in scratchpad and in add-ons is added to the path before appModuleHandler is first imported, which means that first item in the path represents either the code in the scratchpad, or the first loaded add-on with appModules.

Given that relying on the order of imports turned out to be fragile I'd suggest to remove _CORE_APP_MODULES_PATH, and just check if the module is a part of NVDA's core using logHandler.isPathExternalToNVDA, which should be way more reliable. What do you think?
As an aside, I'm not sure if logHandler is the best place for isPathExternalToNVDA, but that is an issue for a different discussion perhaps.

@CyrilleB79
Copy link
Collaborator Author

Thanks for this PR @CyrilleB79 ! In fact this regressed in #14350 as follows:

* Before [Streamline importing of addon directories for python packages #14350](https://github.com/nvaccess/nvda/pull/14350) at the first import of `appModuleHandler` no additional packages were added to the path of `appModules`, so first index indeed represented the path of modules bundled in NVDA

* Now code in scratchpad and in add-ons is added to the path _before_ `appModuleHandler` is first imported, which means that first item in the path represents either the code in the scratchpad, or the first loaded add-on with appModules.

Thanks @lukaszgo1 for the thorough investigation and the details. I have updated the initial description to link with the correct PR.

Given that relying on the order of imports turned out to be fragile I'd suggest to remove _CORE_APP_MODULES_PATH, and just check if the module is a part of NVDA's core using logHandler.isPathExternalToNVDA, which should be way more reliable. What do you think? As an aside, I'm not sure if logHandler is the best place for isPathExternalToNVDA, but that is an issue for a different discussion perhaps.

Well, I am not sure that this function is more robust. On my system the log messages emitted by core files are prefixed by "external" when run from source...
I just realize that on my system sys.path[0] is set to 'C:\\Users\\Cyrille\\AppData\\Roaming\\nvda\\addons\\nvdaChatGPT\\globalPlugins\\nvdaChatGPT\\site-packages'. (Cc @mo29cg FYI)
There are various add-ons in the wild playing with sys.path and we can see that sometimes, they forget to restore it. Probably that's the source of this wrong prefix.

On the contrary appModule import order is much less likely to be modified and I do not expect add-ons modifying appModules.__path__.

Of course, a third solution (if any) retrieving the path of appModules folder more directly could still be an improvement.

@CyrilleB79 CyrilleB79 marked this pull request as ready for review April 7, 2023 22:57
@CyrilleB79 CyrilleB79 requested a review from a team as a code owner April 7, 2023 22:57
@CyrilleB79 CyrilleB79 requested a review from seanbudd April 7, 2023 22:57
@XLTechie
Copy link
Collaborator

XLTechie commented Apr 8, 2023 via email

@Brian1Gaff
Copy link

Brian1Gaff commented Apr 8, 2023 via email

@CyrilleB79
Copy link
Collaborator Author

@XLTechie I had the feeling that my wording did not sound very well actually; many thanks for the English wording fix.

@CyrilleB79
Copy link
Collaborator Author

Does this also hold true for add ons that give these messages? By which I mean if I see blah blag command deprecated, use wotsit instead, is that coming from nvda core code even though its generated in a line in an add on, or is this nvda actually saying this won't work in the next version of the compiler? Take a look at Sound schemes add on for some examples in the log. Brian

Unless the add-on imports appModules from NVDA's core, it's unrelated. I do not know nor use Sound schemes add-on but IMO it's very unlikely that this PR changes anything.

@lukaszgo1
Copy link
Contributor

Well, I am not sure that this function is more robust. On my system the log messages emitted by core files are prefixed by "external" when run from source... I just realize that on my system sys.path[0] is set to 'C:\\Users\\Cyrille\\AppData\\Roaming\\nvda\\addons\\nvdaChatGPT\\globalPlugins\\nvdaChatGPT\\site-packages'. (Cc @mo29cg FYI) There are various add-ons in the wild playing with sys.path and we can see that sometimes, they forget to restore it. Probably that's the source of this wrong prefix.

That's pretty unfortunate - I've assumed that even if someone appends to sys.path they would clean up afterwards, but there is very little we can do about this. I'll look into how we can make logHandler.isPathExternalToNVDA more resilient against changes like this.

Of course, a third solution (if any) retrieving the path of appModules folder more directly could still be an improvement.

This can be easily done with os.path.dirname(appModules.__spec__.origin) (this works well for binary copies, but please test the source copy if you'll decide to implement this).

@lukaszgo1 lukaszgo1 mentioned this pull request Apr 8, 2023
Merged
6 tasks
@lukaszgo1
Copy link
Contributor

Well, I am not sure that this function is more robust. On my system the log messages emitted by core files are prefixed by "external" when run from source... I just realize that on my system sys.path[0] is set to 'C:\\Users\\Cyrille\\AppData\\Roaming\\nvda\\addons\\nvdaChatGPT\\globalPlugins\\nvdaChatGPT\\site-packages'. (Cc @mo29cg FYI) There are various add-ons in the wild playing with sys.path and we can see that sometimes, they forget to restore it. Probably that's the source of this wrong prefix.

That's pretty unfortunate - I've assumed that even if someone appends to sys.path they would clean up afterwards, but there is very little we can do about this. I'll look into how we can make logHandler.isPathExternalToNVDA more resilient against changes like this.

This is now implemented in #14812

@seanbudd
Copy link
Member

Labelling this as blocked by #14812 and marking as draft

@seanbudd seanbudd marked this pull request as draft April 11, 2023 04:46
@lukaszgo1
Copy link
Contributor

I'm not sure why this is blocked by #14812 unless the solution for retrieving real path of core app modules, which I've proposed in this comment is considered inappropriate for some reason.

@seanbudd
Copy link
Member

Apologies @lukaszgo1 I misunderstood your comment.
Am I wrong in thinking that this should still be marked as a draft until a safer solution is implemented?

@seanbudd seanbudd removed the blocked label Apr 11, 2023
seanbudd pushed a commit that referenced this pull request Apr 11, 2023
@lukaszgo1
Logging: Fix some edge cases when identifying if the logged messages …
54fe32c 
…comes from external code or not. (#14812)

Discussion in #14806

Summary of the issue:
When logging NVDA tries to determine if the logged message comes from its own code or from an add-on. In some cases it does so incorrectly.

Case 1: Directory prepended to sys.path by an add-on
Some add-ons have to modify sys.path to import additional libraries. NVDA's logHandler relied on the fact that the first entry in path represents the location of NVDA's source code. While add-on developers should really clean-up after themselves i.e. modify path only for as long as necessary to import additional libraries this is not something we can enforce. Initially observed by @CyrilleB79 for an add-on for ChatGPT.

Case 2: Messages logged from add-ons installed in the default config for source copies
By default configuration folder for source copies is placed next to NVDA sources, i.e. in the source folder. When determining if the path belongs to NVDA or not we used to check if the given path starts with NVDA's source folder which was true for the plugins in the user config even though the code was not a part of NVDA.

Description of user facing changes
This should affect only developers who inspect the log.

Description of development approach
When checking if the path is external or not we no longer rely on sys.path - rather the location of the logHandler is used to determine the true location of NVDA's source code. In addition if the path is beneath the current NVDA's config it is always marked as external.
@CyrilleB79
Copy link
Collaborator Author

Thanks @lukaszgo1, I have modified the code with your suggestion for more robustness. Your suggestion gives the path on installed version as well as on a version running from source.

@seanbudd this PR is ready again. I have tested again as described in the initial description.

@CyrilleB79 CyrilleB79 marked this pull request as ready for review April 16, 2023 21:31
@seanbudd seanbudd merged commit fce7535 into nvaccess:master Apr 18, 2023
@nvaccessAuto nvaccessAuto added this to the 2023.2 milestone Apr 18, 2023
@seanbudd
Copy link
Member

Thanks @CyrilleB79

@CyrilleB79 CyrilleB79 deleted the fixDeprecation branch April 18, 2023 07:03
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@lukaszgo1 lukaszgo1 lukaszgo1 requested changes

@seanbudd seanbudd seanbudd approved these changes

Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
2023.2
Development

Successfully merging this pull request may close these issues.
7 participants
@CyrilleB79 @AppVeyorBot @XLTechie @Brian1Gaff @lukaszgo1 @seanbudd @nvaccessAuto