Remove over-killed output processing (#16519)

Co-authored-by: Jerry Johns <[email protected]>

.github/.wordlist.txt

@@ -1437,3 +1437,4 @@ UTF
 localedef
 nameserver
 nmcli
+tsan

.github/workflows/tests.yaml

@@ -274,7 +274,7 @@ jobs:
             - name: Run Tests
               timeout-minutes: 30
               run: |
-                    scripts/run_in_build_env.sh './scripts/tests/run_python_test.py --app chip-all-clusters-app --factoryreset -- -t 3600 --disable-test ClusterObjectTests.TestTimedRequestTimeout'
+                    scripts/run_in_build_env.sh './scripts/tests/run_python_test.py --app out/linux-x64-all-clusters-no-ble-no-wifi-tsan-clang/chip-all-clusters-app --factoryreset --script-args "-t 3600 --disable-test ClusterObjectTests.TestTimedRequestTimeout"'
             - name: Uploading core files
               uses: actions/upload-artifact@v2
               if: ${{ failure() }} && ${{ !env.ACT }}
@@ -356,7 +356,7 @@ jobs:
             - name: Run Tests
               timeout-minutes: 30
               run: |
-                    scripts/run_in_build_env.sh './scripts/tests/run_python_test.py --app chip-all-clusters-app --factoryreset --app-params "--discriminator 3840 --interface-id -1" -- -t 3600 --disable-test ClusterObjectTests.TestTimedRequestTimeout'
+                    scripts/run_in_build_env.sh './scripts/tests/run_python_test.py --app out/darwin-x64-all-clusters-no-ble-no-wifi-tsan-clang/chip-all-clusters-app --factoryreset --app-args "--discriminator 3840 --interface-id -1" --script-args "-t 3600 --disable-test ClusterObjectTests.TestTimedRequestTimeout"'
             - name: Uploading core files
               uses: actions/upload-artifact@v2
               if: ${{ failure() }} && ${{ !env.ACT }}

docs/guides/matter-repl.md

@@ -224,23 +224,20 @@ example, you can run:
 It provides some extra options, for example:
 
 ```
-  --app TEXT         Local application to use, omit to use external apps, use
-                     a path for a specific binary or use a filename to search
-                     under the current matter checkout.
-
-  --factoryreset     Remove app config and repl configs (/tmp/chip* and
-                     /tmp/repl*) before running the tests.
-
-  --app-params TEXT  The extra parameters passed to the device.
-  --script PATH      Test script to use.
-  --help             Show this message and exit.
+optional arguments:
+  -h, --help                show this help message and exit
+  --app APP                 Path to local application to use, omit to use external apps.
+  --factoryreset            Remove app config and repl configs (/tmp/chip* and /tmp/repl*) before running the tests.
+  --app-args APP_ARGS       The extra parameters passed to the device side app.
+  --script SCRIPT           Path to the test script to use, omit to use the default test script (mobile-device-test.py).
+  --script-args SCRIPT_ARGS Arguments for the REPL test script
 ```
 
 You can pass your own flags for mobile-device-test.py by appending them to the
 command line with two dashes, for example:
 
 ```
-./scripts/tests/run_python_test.py --app chip-all-clusters-app --factoryreset -- -t 90 --disable-test ClusterObjectTests.TestTimedRequestTimeout
+./scripts/tests/run_python_test.py --app out/linux-x64-all-clusters-no-ble-no-wifi-tsan-clang/chip-all-clusters-app --factoryreset --script-args "-t 90 --disable-test ClusterObjectTests.TestTimedRequestTimeout"
 ```
 
 will pass `-t 90 --disable-test ClusterObjectTests.TestTimedRequestTimeout` to

scripts/tests/run_python_test.py

@@ -32,17 +32,6 @@
     os.path.join(os.path.dirname(__file__), '..', '..'))
 
 
-def FindBinaryPath(name: str):
-    for path in pathlib.Path(DEFAULT_CHIP_ROOT).rglob(name):
-        if not path.is_file():
-            continue
-        if path.name != name:
-            continue
-        return str(path)
-
-    return None
-
-
 def EnqueueLogOutput(fp, tag, q):
     for line in iter(fp.readline, b''):
         timestamp = time.time()
@@ -52,8 +41,9 @@ def EnqueueLogOutput(fp, tag, q):
                 line = line[19:]
             except Exception as ex:
                 pass
-        q.put((tag, line, datetime.datetime.fromtimestamp(
-            timestamp).isoformat(sep=" ")))
+        sys.stdout.buffer.write(
+            (f"[{datetime.datetime.fromtimestamp(timestamp).isoformat(sep=' ')}]").encode() + tag + line)
+        sys.stdout.flush()
     fp.close()
 
 
@@ -64,15 +54,6 @@ def RedirectQueueThread(fp, tag, queue) -> threading.Thread:
     return log_queue_thread
 
 
-def DumpLogOutput(q: queue.Queue):
-    # TODO: Due to the nature of os pipes, the order of the timestamp is not guaranteed, need to figure out a better output format.
-    while True:
-        line = q.get_nowait()
-        sys.stdout.buffer.write(
-            (f"[{line[2]}]").encode() + line[0] + line[1])
-        sys.stdout.flush()
-
-
 def DumpProgramOutputToQueue(thread_list: typing.List[threading.Thread], tag: str, process: subprocess.Popen, queue: queue.Queue):
     thread_list.append(RedirectQueueThread(process.stdout,
                                            (f"[{tag}][\33[33mSTDOUT\33[0m]").encode(), queue))
@@ -81,12 +62,12 @@ def DumpProgramOutputToQueue(thread_list: typing.List[threading.Thread], tag: st
 
 
 @click.command()
-@click.option("--app", type=str, default=None, help='Local application to use, omit to use external apps, use a path for a specific binary or use a filename to search under the current matter checkout.')
+@click.option("--app", type=click.Path(exists=True), default=None, help='Path to local application to use, omit to use external apps.')
 @click.option("--factoryreset", is_flag=True, help='Remove app config and repl configs (/tmp/chip* and /tmp/repl*) before running the tests.')
-@click.option("--app-params", type=str, default='', help='The extra parameters passed to the device.')
-@click.option("--script", type=click.Path(exists=True), default=FindBinaryPath("mobile-device-test.py"), help='Test script to use.')
-@click.argument("script-args", nargs=-1, type=str)
-def main(app: str, factoryreset: bool, app_params: str, script: str, script_args: typing.List[str]):
+@click.option("--app-args", type=str, default='', help='The extra arguments passed to the device.')
+@click.option("--script", type=click.Path(exists=True), default=os.path.join(DEFAULT_CHIP_ROOT, 'src', 'controller', 'python', 'test', 'test_scripts', 'mobile-device-test.py'), help='Test script to use.')
+@click.option("--script-args", type=str, default='', help='Path to the test script to use, omit to use the default test script (mobile-device-test.py).')
+def main(app: str, factoryreset: bool, app_args: str, script: str, script_args: str):
     if factoryreset:
         retcode = subprocess.call("rm -rf /tmp/chip* /tmp/repl*", shell=True)
         if retcode != 0:
@@ -98,54 +79,35 @@ def main(app: str, factoryreset: bool, app_params: str, script: str, script_args
     app_process = None
     if app:
         if not os.path.exists(app):
-            app = FindBinaryPath(app)
             if app is None:
                 raise FileNotFoundError(f"{app} not found")
-        app_args = [app] + shlex.split(app_params)
+        app_args = [app] + shlex.split(app_args)
         logging.info(f"Execute: {app_args}")
         app_process = subprocess.Popen(
             app_args, stdout=subprocess.PIPE, stderr=subprocess.PIPE, bufsize=0)
         DumpProgramOutputToQueue(
             log_cooking_threads, "\33[34mAPP \33[0m", app_process, log_queue)
 
     script_command = ["/usr/bin/env", "python3", script,
-                      '--log-format', '%(message)s'] + [v for v in script_args]
+                      '--log-format', '%(message)s'] + shlex.split(script_args)
     logging.info(f"Execute: {script_command}")
     test_script_process = subprocess.Popen(
         script_command, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
     DumpProgramOutputToQueue(log_cooking_threads, "\33[32mTEST\33[0m",
                              test_script_process, log_queue)
 
-    test_script_exit_code = test_script_process.poll()
-    while test_script_exit_code is None:
-        try:
-            DumpLogOutput(log_queue)
-        except queue.Empty:
-            pass
-        test_script_exit_code = test_script_process.poll()
+    test_script_exit_code = test_script_process.wait()
 
     test_app_exit_code = 0
     if app_process:
         app_process.send_signal(2)
-
-        test_app_exit_code = app_process.poll()
-        while test_app_exit_code is None:
-            try:
-                DumpLogOutput(log_queue)
-            except queue.Empty:
-                pass
-            test_app_exit_code = app_process.poll()
+        test_app_exit_code = app_process.wait()
 
     # There are some logs not cooked, so we wait until we have processed all logs.
     # This procedure should be very fast since the related processes are finished.
     for thread in log_cooking_threads:
         thread.join()
 
-    try:
-        DumpLogOutput(log_queue)
-    except queue.Empty:
-        pass
-
     if test_script_exit_code != 0:
         sys.exit(test_script_exit_code)
     else: