Truncated Output or Killed Child Process When Output Streamer Suppresses UnicodeDecodeError Exceptions from popen_process.stdout.readline()

[rmartin16]

Describe the bug

Practically all processes are opened in text mode such that subprocess automatically decodes all piped output. While these processes are running, the output streamer continuously reads stdout with readline() so it can be logged. Additionally, this is wrapped in a try/except for ValueError which is suppressed because the process should be dead; this can manifest when a user spams CTRL+C, for instance, causing the process to close stdout on its end.

Given all this, the call to readline() on stdout can throw a UnicodeDecodeError for invalid data given the codec for decoding; since UnicodeDecodeError subclasses ValueError, this exception is suppressed.

Once this occurs, the output streamer waits 3 seconds for the processes to terminate...after which it forcibly kills it. This can result in truncated output (if the process happens to terminate within 3 seconds) or the process can be forcibly killed for seemingly no reason.

Steps to reproduce

I have been encountering this when using a forked copy of the linuxdeploy GTK plugin when the DEBUG environment variable is set while testing #1132.

I haven't been able to assess whether this is something in my environment...or an issue with the plugin.

Expected behavior

The "bad" data should be accommodated such that normal operation of Briefcase isn't affected. So, some setting of errors should probably be used with subprocess.

Screenshots

No response

Environment

• Operating System: pop os 22.04
• Python version: 3.10
• Software versions:
  • Briefcase: 0.3.13.dev180+g18f59eef.d20230319

Logs

This log includes the exception since I updated the output streamer to re-raise.
briefcase.2023_03_19-18_52_42.build.log

Additional context

No response

[rmartin16]

Interesting...

So, for whatever reason, using cp --verbose on CentOS 7 includes "smart" quotes in the output; these quotes are multi-byte characters in UTF-8. Additionally, linuxdeploy lets you know whether a plugin's output was to stdout or stderr.

What we see is stdout and stderr from the plugin are being clobbered together.....such that some of these multi-byte characters are being split in half. In the example log file, it happens at \n[gtk/stdout] \xe2\x80[gtk/stderr] ++.....and since \xe2\x80 isn't valid UTF-8....Python chokes on it; the full UTF-8 character is \xe2\x80\x98.

Larger excerpt:
\xe2\x80\x98girepository-1.0/Atk-1.0.typelib\xe2\x80\x99 -> \xe2\x80\x98/app/Hello World.AppDir//usr/lib/girepository-1.0/Atk-1.0.typelib\xe2\x80\x99\n[gtk/stdout] \xe2\x80[gtk/stderr] ++ realpath --relative-to=/usr/lib64 /usr/lib64/girepository-1.0\n[gtk/stderr] + cp girepository-1.0 --archive --parents \'--target-directory=/app/Hello World.AppDir//usr/lib\' --verbose\n\x98girepository-1.0/SoupGNOME-2.4.typelib\xe2\x80\x99 -> \xe2\x80\x98/app/Hello World.AppDir//usr/lib/girepository-1.0/SoupGNOME-2.4.typelib\xe2\x80\x99\n

[rmartin16]

ref:

• Collation of stdout and stderr from a Plugin can Result in Output Corruption linuxdeploy/linuxdeploy#246