search

nvaccess / nvda

NVDA, the free and open source Screen Reader for Microsoft Windows
Other
2.08k stars 626 forks source link

Portable copy of nvdas new run portable copy checkbox, function does not work reliably #7681

Closed Brian1Gaff closed 4 years ago

Brian1Gaff commented 6 years ago

Steps to reproduce:

1 update a portable version when prompted. In my case this launches firefox. 2Run the snapshot, I've been using Next branch 3 allow it to run, set the folder to the folder already containing the copy you wish to update 4 Remember to tick the start after the update The update goes OK, but when nvda tries to start the new copy. Nvda gets stuck showing an error from winndows which points to the nvda.exe.log file in the currently updated folder.>

Expected behavior:

It should close the running temp copy cleanly then boot in the copy just updated. NOTE: If you are running narrator, you can usually dismiss this error screen, but then you have to run the portable copy manually and this works for me as long as the temp copy has finally stopped. A look at the logs shows that in the%temp% folder when the system is stuck, only the nvda.log is present, ie the old log is not. The log of the temp version shows it has not in fact exited correctly usually stopping part way through or at the very time the update was autorun. Suspect log still locked and new copy cannot start. Probably the code to restart is not calling the correct routine to end the temp copy first or not waiting for it to exit. >

System configuration:

NVDA version: Any snapshot containing the new start portable copy after update checkbox. Using Windows 7 pro 64. Main drive for system is an ssd so very fast.

However wherever the temp copy is, on a ram drive or on the main drive the same issue occurs most of the time. I do not tick this box now and use a batch file to restart the new copy instead as this does things reliably.

Other questions:

Does the issue still occur after restarting your PC? Not applicable in this case Obviously older copies did not have this feature so its not applicable nvda.exe.log

LeonarddeR commented 6 years ago

This code is identical to the restart code used for restarting an installed version after an update. Could you try updating a portable copy by running the copy that initiates the update with add-ons disabled?

Brian1Gaff commented 6 years ago

Already did this, and its hit and miss, however strangely this also seemed to make the install restart also flakey.

This morning, and both booted up again OK. As I say its very peculiar. You saw the log file, so it may well be something not being released by windows 7. Brian

bglists@blueyonder.co.uk Sent via blueyonder. Please address personal email to:- briang1@blueyonder.co.uk, putting 'Brian Gaff' in the display name field. ----- Original Message ----- From: "Leonard de Ruijter" notifications@github.com To: "nvaccess/nvda" nvda@noreply.github.com Cc: "Brian Gaff" bglists@blueyonder.co.uk; "Author" author@noreply.github.com Sent: Tuesday, October 24, 2017 6:27 AM Subject: Re: [nvaccess/nvda] Portable copy of nvdas new run portable copy checkbox, function does not work reliably (#7681)

This code is identical to the restart code used for restarting an installed version after an update. Could you try updating a portable copy by running the copy that initiates the update with add-ons disabled?

-- You are receiving this because you authored the thread. Reply to this email directly or view it on GitHub: https://github.com/nvaccess/nvda/issues/7681#issuecomment-338877969

Brian1Gaff commented 6 years ago

In addition to my last here are the logs good and bad. Sadly no indication other than a truncated log.

OK so even if it does reboot successfully its awfully close to failing.

IO - tones.beep (13:59:17.760): Beep at pitch 1760, for 40 ms, left volume 50, right volume 50 IO - speech.speak (13:59:17.841): Speaking [LangChangeCommand ('en_GB'), u'Success dialog Successfully created a portable copy of NVDA at C:\nvda extra'] IO - speech.speak (13:59:17.855): Speaking [LangChangeCommand ('en_GB'), u'OK button'] IO - inputCore.InputManager.executeGesture (13:59:19.966): Input: kb(desktop):enter DEBUGWARNING - NVDAObjects.IAccessible.IAccessible._get_IAccessibleRole (13:59:20.045): accRole failed: (-2147024809, 'The parameter is incorrect.', (None, None, None, 0, None)) IO - speech.speak (13:59:20.085): Speaking [LangChangeCommand ('en_GB'), u'Creating Portable Copy dialog Please wait while a portable copy of NVDA is created.'] IO - speech.speak (13:59:20.089): Speaking [LangChangeCommand ('en_GB'), u'Creating Portable Copy'] DEBUGWARNING - NVDAObjects.IAccessible.IAccessible._get_IAccessibleRole (13:59:20.180): accRole failed: (-2147024809, 'The parameter is incorrect.', (None, None, None, 0, None)) IO - speech.speak (13:59:20.201): Speaking [LangChangeCommand ('en_GB'), u'C:\Users\Brian\Downloads'] IO - speech.speak (13:59:20.204): Speaking [LangChangeCommand ('en_GB'), u'Items View list'] IO - speech.speak (13:59:20.223): Speaking [LangChangeCommand ('en_GB'), u'nvda_snapshot_next-14543,3609539b.exe 64 of 81']

That is where the written log stopped. it really should contain the complete details of the shut down of nvda. Luckily this got away with it, as although it did not play the descending tones and it wrote a problem log about the log file itself.

Traceback (most recent call last): File "nvda.pyw", line 183, in File "logHandler.pyc", line 336, in initialize File "logHandler.pyc", line 213, in init IOError: [Errno 22] invalid mode ('wt') or filename: 'C:\Users\Brian\AppData\Local\Temp\nvda.log'

it did reboot but what state it did this is anybody's guess. With no add ons this offten occurs in an installed copy as well, so maybe there has always been this issue, and for some reason its only just showing up. How hard would it be to delay the start of the reboot of the new version? I of course achieve it as I use a batch file, which is external to nvdas running code.

@echo off start /w nvda.exe -q start nvda.exe exit Which according to batch should wait for the process to end before doing the reboot of nvda and its not ever failed me to reboot the copy I'm calling.

IO - inputCore.InputManager.executeGesture (14:15:08.551): Input: kb(desktop):control+alt+x IO - speech.speak (14:15:08.634): Speaking [LangChangeCommand ('en_GB'), u'Taskbar'] IO - speech.speak (14:15:08.668): Speaking [LangChangeCommand ('en_GB'), u'nvda portable terminal'] IO - speech.speak (14:15:08.670): Speaking [LangChangeCommand ('en_GB'), u'80 space', u'blank'] INFO - core.main (14:15:08.681): Exiting DEBUG - core._terminate (14:15:08.681): Terminating updateCheck DEBUG - core._terminate (14:15:08.681): Terminating watchdog DEBUG - core._terminate (14:15:08.681): Terminating global plugin handler DEBUG - external:globalPlugins.focusHighlight.GlobalPlugin.terminate (14:15:09.183): focusHighlight terminated DEBUG - core._terminate (14:15:09.183): Terminating gui DEBUG - fileUtils.FaultTolerantFile (14:15:09.196): C:\nvda extra\userConfig\nvda.inighe0dz.tmp INFO - config.ConfigManager.save (14:15:09.211): Base configuration saved DEBUG - core.main (14:15:09.211): calling lose focus on object with focus DEBUG - core._terminate (14:15:09.213): Terminating treeInterceptorHandler DEBUG - core._terminate (14:15:09.213): Terminating IAccessible support DEBUG - core._terminate (14:15:09.214): Terminating UIA support DEBUGWARNING - _UIAHandler.UIAHandler.terminate (14:15:09.414): Timeout or error while waiting for UIAHandler MTA thread DEBUG - core._terminate (14:15:09.414): Terminating winConsole support DEBUG - core._terminate (14:15:09.414): Terminating Java Access Bridge support DEBUG - core._terminate (14:15:09.414): Terminating app module handler DEBUG - core._terminate (14:15:09.414): Terminating NVDAHelper DEBUG - core._terminate (14:15:09.421): Terminating touchHandler DEBUG - core._terminate (14:15:09.421): Terminating keyboard handler DEBUG - core._terminate (14:15:09.421): Terminating mouseHandler DEBUG - core._terminate (14:15:09.423): Terminating inputCore DEBUG - core._terminate (14:15:09.423): Terminating brailleInput DEBUG - core._terminate (14:15:09.423): Terminating braille DEBUG - core._terminate (14:15:09.423): Terminating speech DEBUG - core._terminate (14:15:09.423): Terminating addonHandler DEBUG - core.main (14:15:10.474): core done INFO - main (14:15:10.494): NVDA exit

Have a look yourself and see how often the old log actually looks like this.

I have just had the non start again, but this time although cancelling the error panel and restarting nvda manually, Explorer was completely messed up. I could not get anything to work via nvda but task manager so I shut down explorer and restarted it and it ended up in myBrian folder area, which when I closed took me back to the desktop. So obviously this can cause issues with running software if it falls over at a critical point where its unhookin itself.

Also you presumably do not get a save of the parameters either in the failed cases which might cause other problems I suppose.

Just to prove it does sometimes operate correctly, here is the end of the log from a good restart. IO - speech.speak (14:47:25.657): Speaking [LangChangeCommand ('en_GB'), u'Success dialog Successfully created a portable copy of NVDA at C:\nvda extra'] IO - speech.speak (14:47:25.667): Speaking [LangChangeCommand ('en_GB'), u'OK button'] IO - inputCore.InputManager.executeGesture (14:47:26.575): Input: kb(desktop):space IO - speech._speakSpellingGen (14:47:26.588): Speaking character u'space' DEBUG - queueHandler.registerGeneratorObject (14:47:26.588): Adding generator 11 IO - speech.speak (14:47:26.588): Speaking [LangChangeCommand ('en_GB'), u'pressed'] DEBUG - queueHandler.pumpAll (14:47:26.598): generator 11 finished DEBUGWARNING - NVDAObjects.IAccessible.IAccessible._get_IAccessibleRole (14:47:26.756): accRole failed: (-2147024809, 'The parameter is incorrect.', (None, None, None, 0, None)) IO - speech.speak (14:47:26.773): Speaking [LangChangeCommand ('en_GB'), u'dialog'] IO - speech.speak (14:47:26.776): Speaking [LangChangeCommand ('en_GB'), u'pane'] DEBUGWARNING - NVDAObjects.IAccessible.IAccessible._get_IAccessibleRole (14:47:26.786): accRole failed: (-2147024809, 'The parameter is incorrect.', (None, None, None, 0, None)) IO - speech.speak (14:47:26.811): Speaking [LangChangeCommand ('en_GB'), u'C:\Users\Brian\AppData\Local\Temp'] IO - speech.speak (14:47:26.835): Speaking [LangChangeCommand ('en_GB'), u'Items View list'] IO - speech.speak (14:47:26.851): Speaking [LangChangeCommand ('en_GB'), u'FXSAPIDebugLogFile.txt row 17 column 1 17 of 20'] INFO - core.main (14:47:26.869): Exiting DEBUG - core._terminate (14:47:26.869): Terminating updateCheck DEBUG - core._terminate (14:47:26.869): Terminating watchdog DEBUG - core._terminate (14:47:26.869): Terminating global plugin handler DEBUG - external:globalPlugins.focusHighlight.GlobalPlugin.terminate (14:47:27.371): focusHighlight terminated DEBUG - core._terminate (14:47:27.371): Terminating gui DEBUG - fileUtils.FaultTolerantFile (14:47:27.377): C:\Users\Brian\AppData\Roaming\nvda\nvda.inihrel3l.tmp INFO - config.ConfigManager.save (14:47:27.392): Base configuration saved DEBUG - core._terminate (14:47:27.394): Terminating treeInterceptorHandler DEBUG - core._terminate (14:47:27.394): Terminating IAccessible support DEBUG - core._terminate (14:47:27.394): Terminating UIA support DEBUGWARNING - _UIAHandler.UIAHandler.terminate (14:47:27.595): Timeout or error while waiting for UIAHandler MTA thread DEBUG - core._terminate (14:47:27.595): Terminating winConsole support DEBUG - core._terminate (14:47:27.595): Terminating Java Access Bridge support DEBUG - core._terminate (14:47:27.595): Terminating app module handler DEBUG - core._terminate (14:47:27.595): Terminating NVDAHelper DEBUG - core._terminate (14:47:27.596): Terminating touchHandler DEBUG - core._terminate (14:47:27.596): Terminating keyboard handler DEBUG - core._terminate (14:47:27.596): Terminating mouseHandler DEBUG - core._terminate (14:47:27.598): Terminating inputCore DEBUG - core._terminate (14:47:27.598): Terminating brailleInput DEBUG - core._terminate (14:47:27.598): Terminating braille DEBUG - core._terminate (14:47:27.598): Terminating speech DEBUG - core._terminate (14:47:27.598): Terminating addonHandler DEBUG - core.main (14:47:28.645): core done INFO - main (14:47:28.664): NVDA exit

So it looks like its a timing thing to me, its just either slow to exit or too fast rebooting or a bit of both resulting in unpredicctable results.

Brian

bglists@blueyonder.co.uk Sent via blueyonder. Please address personal email to:- briang1@blueyonder.co.uk, putting 'Brian Gaff' in the display name field. ----- Original Message ----- From: "Leonard de Ruijter" notifications@github.com To: "nvaccess/nvda" nvda@noreply.github.com Cc: "Brian Gaff" bglists@blueyonder.co.uk; "Author" author@noreply.github.com Sent: Tuesday, October 24, 2017 6:27 AM Subject: Re: [nvaccess/nvda] Portable copy of nvdas new run portable copy checkbox, function does not work reliably (#7681)

This code is identical to the restart code used for restarting an installed version after an update. Could you try updating a portable copy by running the copy that initiates the update with add-ons disabled?

-- You are receiving this because you authored the thread. Reply to this email directly or view it on GitHub: https://github.com/nvaccess/nvda/issues/7681#issuecomment-338877969

Brian1Gaff commented 6 years ago

Hi this mornings update to next just would not auto run on an update to an installed copy till I did a windows restart. However it was able to be run from my batch file and showed the correct snapshot number had been installed. Once again the log error was written in the nvda folder that day. Interestingly, I observed that if the update takes a bit longer, ie due to the new code trying to, and not succeeding removal of folders, it is far more likely to fail to restart.

I did wonder whether windows is kind of getting choked up with locked file requests and simply fails to do what it should in a timely manner. Trouble is that last night when I did multiple stress installs, I ended up with a situation where the hooks into the system failed on every nvda run with an error impacting mainly as failure to echo keys and other oddities till windows was rebooted.

Hope this might help. I think we have done the problem to death via logs as really they tell us nothing other than its not working!

Brian

bglists@blueyonder.co.uk Sent via blueyonder. Please address personal email to:- briang1@blueyonder.co.uk, putting 'Brian Gaff' in the display name field.

ehollig commented 6 years ago

@Brian1Gaff, is this still an issue or still relevant to you? I just updated a portable version of NVDA and told it to download and install and it finished without errors.

LeonarddeR commented 5 years ago

@Brian1Gaff : can you still reproduce this?

Brian1Gaff commented 5 years ago

Now and again, yes. It is as far as I can see a problem where windows keeps the log file locked as nvda tries to restart, and hence it cannot continue and writes that fragment to the, what I call emergency log in the nvda folder.

It can happen on installed copies as well, and even with no add ons, but it seems totally random. I think that windows gets kind of blocked up with all the requests to delete and rename things and has not actually caught up when nvda restarts. The way to get back is as follows. Wait for about ten seconds, then hit ESC. Then hit the shortcut to run the version you updated. It then runs as it should do.

I am using Windows 7, and an SSD main drive on a 4 core machine with 8gig of ram, but have noticed that there are significant pauses, for example when clearing out the recycle bin or doing some other updates that need files to be removed.

However most other software does not give that windows error screen, so they must somehow be waiting for the system to be ready. Oh and now it occurs when add ons update as well sometimes, but its more rare. Would you think any software on the machine might be making this worse? I have tried turning off anti virus stuff, about the only other thing running is unchecky, but never seen any issues from that before.

Brian

bglists@blueyonder.co.uk Sent via blueyonder. Please address personal E-mail to:- briang1@blueyonder.co.uk, putting 'Brian Gaff' in the display name field.

Brian1Gaff commented 5 years ago

PS the last time it happened on an alpha snap was 6th Feb and on the installed version on add on restart on the 2nd Feb both this year obviously.

Brian

bglists@blueyonder.co.uk Sent via blueyonder. Please address personal E-mail to:- briang1@blueyonder.co.uk, putting 'Brian Gaff' in the display name field.

Adriani90 commented 4 years ago

@Brian1Gaff could you please give an update on this with NVDA 2019.3 Beta 1? Do you still see this issue?

Adriani90 commented 4 years ago

@Brian1Gaff if you still have this issue, have you checked how much space you have on your hard drive? This could occur when NVDA cannot write its log if there is no spache on the hard drive. Could you try to disable the log level completely and see if this issue still occurs? You can disable the logging in the genneral settings, it's the last option in the combo box I think.

Adriani90 commented 4 years ago

No updates from the initial author since more than one year. Closing as abandoned. Please comment with updates on this and we can reopen.