msg340547 - (view) |
Author: Lorenz Mende (LorenzMende) * |
Date: 2019-04-19 15:52 |
The test suite fails with the first tests (I assume 1st call of getloadavg of WindowsLoadTracker). Traceback (most recent call last): File "P:\Repos\CPython\cpython\lib\runpy.py", line 192, in _run_module_as_main return _run_code(code, main_globals, None, File "P:\Repos\CPython\cpython\lib\runpy.py", line 85, in _run_code exec(code, run_globals) File "P:\Repos\CPython\cpython\lib\test\__main__.py", line 2, in main() File "P:\Repos\CPython\cpython\lib\test\libregrtest\main.py", line 653, in main Regrtest().main(tests=tests, **kwargs) File "P:\Repos\CPython\cpython\lib\test\libregrtest\main.py", line 586, in main self._main(tests, kwargs) File "P:\Repos\CPython\cpython\lib\test\libregrtest\main.py", line 632, in _main self.run_tests() File "P:\Repos\CPython\cpython\lib\test\libregrtest\main.py", line 515, in run_tests self.run_tests_sequential() File "P:\Repos\CPython\cpython\lib\test\libregrtest\main.py", line 396, in run_tests_sequential self.display_progress(test_index, text) File "P:\Repos\CPython\cpython\lib\test\libregrtest\main.py", line 150, in display_progress load_avg_1min = self.getloadavg() File "P:\Repos\CPython\cpython\lib\test\libregrtest\win_utils.py", line 81, in getloadavg typeperf_output = self.read_output() File "P:\Repos\CPython\cpython\lib\test\libregrtest\win_utils.py", line 78, in read_output return response.decode() UnicodeDecodeError: 'utf-8' codec can't decode byte 0x81 in position 67: invalid start byte ########################################################## The windows 'typeperf "\System\Processor Queue Length" -si 1' command unluckily returns an string with an umlaut which leads to the Decode-Error. This comes up because the for the typeperf is location dependend. (In german the counter would read \System\Prozessor-Warteschlangenlänge) I see two possible solutions to this issue. 1. Raising an exception earlier on creation of WindowsLoadTracker resulting in the same behaviour as if there is no typeperf available (german pythoneers would have a drawback with this) 2. Getting the typeperf counter correctly from registry (HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows NT\CurrentVersion\Perflib\CurrentLanguage, described here https://social.technet.microsoft.com/Forums/de-DE/25bc6907-cf2c-4dc8-8687-974b799ba754/powershell-ausgabesprache-umstellen?forum=powershell_de) environment: Windows 10 x64, 1809, german cpython @e16467af0bfcc9f399df251495ff2d2ad20a1669 commit of assumed root cause of https://bugs.python.org/issue34060 |
|
|
msg340548 - (view) |
Author: Ammar Askar (ammar2) *  |
Date: 2019-04-19 16:26 |
What does `typeperf "\System\Processor Queue Length" -si 1` actually return on your non-English system? Does it just return an error with the counter's name or is the umalet just in the first header line, i.e this one for me: "(PDH-CSV 4.0)","\\MSI\System\Processor Queue Length" If it's the latter then I think the correct fix would be to figure out what encoding typeperf is outputting in and then just decode with that. |
|
|
msg340550 - (view) |
Author: Lorenz Mende (LorenzMende) * |
Date: 2019-04-19 17:11 |
Hi Ammar, you are correct. typeperf returns: P:\Repos\CPython\cpython>typeperf "\System\Prozessor-Warteschlangenlänge" -si 1 "(PDH-CSV 4.0)","\\ZERO\System\Prozessor-Warteschlangenlänge" "04/19/2019 19:09:14.510","0.000000" "04/19/2019 19:09:15.514","0.000000" So even with correct counter name the outpu needs to be decoded correctly. I already got a solution to get the location specific counter name from registry - if it helps I'll commit it. |
|
|
msg340551 - (view) |
Author: Ammar Askar (ammar2) *  |
Date: 2019-04-19 17:13 |
Thank you, could you also share the output if you just give it the English name of the counter? |
|
|
msg340562 - (view) |
Author: Terry J. Reedy (terry.reedy) *  |
Date: 2019-04-20 06:41 |
'crash' mean *nix coredump or Windows equivelent, rather than traceback. |
|
|
msg340575 - (view) |
Author: Steve Dower (steve.dower) *  |
Date: 2019-04-20 14:39 |
It'll probably be mbcs or oem encoding. Certainly not UTF-8 |
|
|
msg340576 - (view) |
Author: Eryk Sun (eryksun) *  |
Date: 2019-04-20 15:09 |
> It'll probably be mbcs or oem encoding. Certainly not UTF-8 Unless the system locale's codepage is set to UTF-8 in Windows 10. I stepped through this in the debugger. When writing to a pipe, typeperf.exe calls WideCharToMultiByte(CP_OEMCP, ...), so it's "oem". |
|
|
msg340632 - (view) |
Author: Steve Dower (steve.dower) *  |
Date: 2019-04-22 02:17 |
If the code page is set to UTF-8 then mbcs will still be the right encoding :) |
|
|
msg340797 - (view) |
Author: Lorenz Mende (LorenzMende) * |
Date: 2019-04-24 17:49 |
Sorry, was off some days. I tried to decode the output with mbcs, solves the issue partly - the counter name is still wrong. Was able to pick the localization specific counter name from registry and use it for the typeperf. But the tests fail after several seconds with Broken Pipe Error of the command_stdout pipe. @Ammar - why is the handle closed in start()? If I uncomment it, the load tracker workks fine. Added the fixed file, may someone evaluate the solution on another windows localization? |
|
|
msg340806 - (view) |
Author: Eryk Sun (eryksun) *  |
Date: 2019-04-24 19:57 |
It's "oem", not "mbcs". |
|
|
msg344293 - (view) |
Author: Андрей Казанцев (heckad) * |
Date: 2019-06-02 15:57 |
I have the same problem in Russian locale. Adding "oem" encoding in the decode method solve problem with decoding but got: File "C:\Users\User\Documents\Projects\cpython\lib\test\libregrtest\win_utils.py", line 98, in getloadavg load = float(toks[1].replace('"', '')) ValueError: could not convert string to float In typeperf_output text with description of the error: '\r\nВыполняется выход, подождите... \r\nОшибка: Счетчики не указаны.\r\n\r\r' Translation on English is "Exiting, wait... Error: Counters are not specified." Is it possible to check if the counters are found in advance? |
|
|
msg345076 - (view) |
Author: Lorenz Mende (LorenzMende) * |
Date: 2019-06-09 09:02 |
Did some minor changes with win_utils. Encoding changed to 'oem'. @heckad: does this bugfix work for u? @all: please verify working of the changes with different localizations. thx |
|
|
msg348719 - (view) |
Author: Sebastian Koslowski (skoslowski) * |
Date: 2019-07-30 08:08 |
I ran into this issue on a Win10 German box running the tests for version 3.7.4 Your changes fixes the issue for me. |
|
|
msg353554 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2019-09-30 08:14 |
On my Windows 10 version 1903, I get: C:\> typeperf "\System\Processor Queue Length" -si 1 Fin du programme, veuillez patienter... Erreur : aucun compteur valide. C:\> echo %errorlevel% -268435454 Error message in english: "Error: No valid counters" Because of this error, regrtest fails with: ... File "C:\vstinner\python\master\lib\test\libregrtest\win_utils.py", line 85, in getloadavg typeperf_output = self.read_output() File "C:\vstinner\python\master\lib\test\libregrtest\win_utils.py", line 82, in read_output return overlapped.getbuffer().decode() UnicodeDecodeError: 'utf-8' codec can't decode byte 0xff in position 74: invalid start byte I'm using: platform.architecture: 64bit WindowsPE platform.platform: Windows-10-10.0.18362-SP0 sys.windowsversion: sys.getwindowsversion(major=10, minor=0, build=18362, platform=2, service_pack='') Note: same error when testing as an administrator. It's not a permission issue. -- On the other side, "wmic cpu get loadpercentage" works as expected: C:\> wmic cpu get loadpercentage LoadPercentage 1 1 |
|
|
msg353555 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2019-09-30 08:29 |
I tested attached win_utils.py on my Windows 10. I uses the command: ['typeperf', '"\\Système\\Longueur de la file du processeur"', '-si', '5'] Oh wait, counter names are now translated? Oh ok. |
|
|
msg353556 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2019-09-30 08:56 |
We could avoid typeperf command by accessing directly performance counters: (1) The Performance Data Helper (PDH) interface, which provides high-level access to data from both version 1 and version 2 performance counter providers. (2) The registry interface, which provides low-level access to data from performance counter providers. (3) The performance library interface, which provides direct access to data from version 2 performance counter providers. https://docs.microsoft.com/en-us/windows/win32/perfctrs/consuming-counter-data (2) in short: RegQueryValueEx() with HKEY_PERFORMANCE_DATA and the PPERF_DATA_BLOCK structure Documentation: https://docs.microsoft.com/en-us/windows/win32/perfctrs/using-the-registry-functions-to-consume-counter-data PERF_DATA_BLOCK structure fields: https://docs.microsoft.com/en-us/windows/win32/api/winperf/ns-winperf-perf_data_block Example: https://docs.microsoft.com/en-us/windows/win32/api/winreg/nf-winreg-regqueryvalueexw Some examples mention "RegQueryValueEx function. Use HKEY_PERFORMANCE_DATA". Performance Data Format: https://docs.microsoft.com/en-us/windows/win32/perfctrs/performance-data-format -- PDH & friends was discussed in bpo-34060 which added the feature to libregrtest. |
|
|
msg353660 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2019-10-01 10:29 |
New changeset 982bfa4da07b2e5749a0f4e68f99e972bcc3a549 by Victor Stinner in branch 'master': bpo-36670: Multiple regrtest bugfixes (GH-16511) https://github.com/python/cpython/commit/982bfa4da07b2e5749a0f4e68f99e972bcc3a549 |
|
|
msg353664 - (view) |
Author: miss-islington (miss-islington) |
Date: 2019-10-01 10:47 |
New changeset 6b4c70abcaa348c84a2c1bb6f5a46596cf358e36 by Miss Islington (bot) in branch '3.8': bpo-36670: Multiple regrtest bugfixes (GH-16511) https://github.com/python/cpython/commit/6b4c70abcaa348c84a2c1bb6f5a46596cf358e36 |
|
|
msg353667 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2019-10-01 10:56 |
Thanks Lorenz Mende for the nice bug report, investigating the issue and proposing fix. I wrote a PR based on your work with some minor changes. I included it in a large regrtest change to fix other bugs. regrtest should work again with locales other than English. |
|
|
msg353669 - (view) |
Author: miss-islington (miss-islington) |
Date: 2019-10-01 10:58 |
New changeset d6a92b55944bf1ef4992e4375f02a7132717bf53 by Miss Islington (bot) in branch '3.7': bpo-36670: Multiple regrtest bugfixes (GH-16511) https://github.com/python/cpython/commit/d6a92b55944bf1ef4992e4375f02a7132717bf53 |
|
|
msg353670 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2019-10-01 11:01 |
> We could avoid typeperf command by accessing directly performance counters: (...) Honestly, it sounds very complicated. I don't think that it's worth it. With Lorenz's fix, regrtest now "just works". So I think that it's good enough. |
|
|
msg353731 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2019-10-02 11:35 |
New changeset 2ea71a07d0a720707094ee55f78fd232c40724bc by Victor Stinner in branch 'master': bpo-36670: regrtest bug fixes (GH-16537) https://github.com/python/cpython/commit/2ea71a07d0a720707094ee55f78fd232c40724bc |
|
|
msg353732 - (view) |
Author: miss-islington (miss-islington) |
Date: 2019-10-02 11:54 |
New changeset a72de9338882b8013a4bb8adb930fe3308682e28 by Miss Islington (bot) in branch '3.8': bpo-36670: regrtest bug fixes (GH-16537) https://github.com/python/cpython/commit/a72de9338882b8013a4bb8adb930fe3308682e28 |
|
|
msg353768 - (view) |
Author: David Bolen (db3l) * |
Date: 2019-10-02 20:33 |
Just an FYI that this change is generating warnings on my Windows 10 buildbot with some regularity about a failure to parse testperf output, such as: Warning -- Failed to parse typeperf output: '"10/01/2019 07:58:50.056"' from https://buildbot.python.org/all/#/builders/217/builds/487 Now, clearly there's no queue length in that output so the parsing warning is accurate, but does the overall build have to reflect a warning in such cases, given that it's just a test harness issue, and not anything going wrong with the actual tests? Previously any such cases would be ignored silently, so this probably isn't a new issue but just one that is now shows up as an overall build warning. I don't know why both fields aren't present although it seems plausible that it's just a partial line from the I/O (I don't think it guarantees it receives full lines), and the queue length field would appear on the following read. |
|
|
msg353770 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2019-10-02 20:54 |
> Just an FYI that this change is generating warnings on my Windows 10 buildbot with some regularity about a failure to parse testperf output, such as: Warning -- Failed to parse typeperf output: '"10/01/2019 07:58:50.056"' Aha, interesting. I added a warning to debug the code. > Now, clearly there's no queue length in that output so the parsing warning is accurate, but does the overall build have to reflect a warning in such cases, given that it's just a test harness issue, and not anything going wrong with the actual tests? The build is marked as "warning" (orange) which is different than "fail" (red). Warnings are used to detect bugs or interesting issues, but not considered as a regression. > I don't know why both fields aren't present although it seems plausible that it's just a partial line from the I/O (I don't think it guarantees it receives full lines), and the queue length field would appear on the following read. Right, the code doesn't ensure that a line ends with a newline character. Could you try to run manually the following command to check its output? typeperf "\System\Processor Queue Length" -si 1 Maybe uncomplete lines should be buffered in read_output(). |
|
|
msg353772 - (view) |
Author: David Bolen (db3l) * |
Date: 2019-10-02 21:05 |
Oh, I agree it's just a warning, and I suspect few people look into warnings, but since it's not from an actual test, I'm not sure the overall build should be flagged. The manual typeperf looks fine, but there's no way I could tell visually how the I/O is being done under the covers. My bet is typeperf is probably issuing multiple output calls, one for the leading timestamp and then one for each value. So regrtest just happens to interleave its own read in between the two. The subsequent read would then get the trailing ",####" which the current code would parse normally as it only cares about the second field. In which case it's not even affecting the load monitoring, other than the warning message. I suspect it's happening on the Windows 10 buildbot as the machine is reasonably fast. But to your earlier comment about things just working previously, I'm not sure there's that much value in adding code to deal with this case. I'd probably just remove the warning to restore the earlier behavior. The current code still ignores other issues like an actual read failure in read_output. Or, if there's a way to generate the message without it being considered an overall test build warning, that would work too. |
|
|
msg353779 - (view) |
Author: David Bolen (db3l) * |
Date: 2019-10-02 22:14 |
I've confirmed the partial read with some local modifications, and the failures are always split between time stamp and value: Warning -- Failed to parse typeperf output: '"10/02/2019 17:42:26.229"' 0.0 Warning -- Missing first field: ,"0.000000" 0.0 Adding multiple variables to the typeperf command can vary the split position, but I've only seen it at a variable boundary (starting with the comma). So I'm guessing with the current implementation the above is probably the only point where the I/Os can be interleaved. Also, CRLF seems to only appear at the start of each read, never at the end. You can see that behavior interactively too where the cursor waits at the end of the line between samples. So changes to wait for a complete line to be read would also delay load values by one sample interval. So I'm thinking just reverting to silently ignoring this case is probably simplest. |
|
|
msg353783 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2019-10-02 22:41 |
Ok, I managed to reproduce the bug using this change: diff --git a/Lib/test/libregrtest/win_utils.py b/Lib/test/libregrtest/win_utils.py index f0c17b906f..78429faa89 100644 --- a/Lib/test/libregrtest/win_utils.py +++ b/Lib/test/libregrtest/win_utils.py @@ -14,7 +14,7 @@ BUFSIZE = 8192 LOAD_FACTOR_1 = 0.9200444146293232478931553241 # Seconds per measurement -SAMPLING_INTERVAL = 5 +SAMPLING_INTERVAL = 0 # Windows registry subkey of HKEY_LOCAL_MACHINE where the counter names # of typeperf are registered COUNTER_REGISTRY_KEY = (r"SOFTWARE\Microsoft\Windows NT\CurrentVersion" I wrote PR 16550 to handle partial lines. |
|
|
msg353786 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2019-10-02 23:04 |
New changeset 3e04cd268ee9a57f95dc78d8974b21a6fac3f666 by Victor Stinner in branch 'master': bpo-36670, regrtest: Fix WindowsLoadTracker() for partial line (GH-16550) https://github.com/python/cpython/commit/3e04cd268ee9a57f95dc78d8974b21a6fac3f666 |
|
|
msg353832 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2019-10-03 08:53 |
New changeset c65119d5bfded03f80a9805889391b66fa7bf551 by Victor Stinner in branch 'master': bpo-36670: Enhance regrtest WindowsLoadTracker (GH-16553) https://github.com/python/cpython/commit/c65119d5bfded03f80a9805889391b66fa7bf551 |
|
|
msg353850 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2019-10-03 14:15 |
New changeset 098e25672f1c3578855d5ded4f5147795c9ed956 by Victor Stinner in branch 'master': bpo-36670: Enhance regrtest (GH-16556) https://github.com/python/cpython/commit/098e25672f1c3578855d5ded4f5147795c9ed956 |
|
|
msg353853 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2019-10-03 15:26 |
New changeset de3195c937d5fca0d79cc93dbafa76c0f89ca5b8 by Victor Stinner in branch '3.8': [3.8] bpo-36670, regrtest: Fix WindowsLoadTracker() for partial line (GH-16550) (GH-16560) https://github.com/python/cpython/commit/de3195c937d5fca0d79cc93dbafa76c0f89ca5b8 |
|
|
msg353857 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2019-10-03 15:31 |
Thanks for the bug report. I was impacted by the bug with my French locale as well. I pushed a fix based on Lorenz Mende's work, with minor changes. I also enhanced WindowsLoadTracker to handle partial write and report parsing errors as warnings rather than exception. I pushed other changes to enhance regrtest in general. The load average is not updated every second and it's value is initialized from the arithmetic mean of the first 5 values of the Processor Queue Length. |
|
|
msg353860 - (view) |
Author: miss-islington (miss-islington) |
Date: 2019-10-03 15:44 |
New changeset f9016e5fc9424d41c8e53de84f8699e78769a14a by Miss Islington (bot) in branch '3.7': [3.8] bpo-36670, regrtest: Fix WindowsLoadTracker() for partial line (GH-16550) (GH-16560) https://github.com/python/cpython/commit/f9016e5fc9424d41c8e53de84f8699e78769a14a |
|
|
msg366462 - (view) |
Author: STINNER Victor (vstinner) *  |
Date: 2020-04-14 23:05 |
New changeset b894b669c98cc365b84cbb8d20f531f1d0686f59 by Victor Stinner in branch '3.7': Update libregrtest from master (GH-19517) https://github.com/python/cpython/commit/b894b669c98cc365b84cbb8d20f531f1d0686f59 |
|
|