Wait for app to exit normally after log streaming

[rmartin16]

Changes

• Ensure the app has exited once it has indicated an exit condition in its output while log streaming
• Also, closes the log streaming Popen process after log streaming and uses poll() to determine the returncode

Notes

• This doesn't affect app log streaming using --test because Briefcase doesn't care what happens to the app after the exit condition is found in its output.
• However, when an app includes the exit condition in its output while not under testing, then Briefcase uses the returncode of the app's Popen process to determine success.
• In general, it does seem better to wait for the app to exit on its own...since that should be what it's doing anyway
• Alternatively, we could change log streaming to always use the returncode in the output exit condition to determine success....I think I'm mostly ambivalent on this...

PR Checklist:

• All new features have been tested
• All new features have been documented
• I have read the CONTRIBUTING.md file
• I will abide by the code of conduct

[freakboy3742]

This change makes sense; however, I don't think it's covering all the problem (or, at least, there's some interesting interactions in the edge cases you've described and the behavior).

To my reckoning, this is the full set of possible outcomes:

1. Streamed output (e.g., macOS app)
   1. App exits normally
      1. App reports success
      2. App reports an error
      3. App doesn't report an exit state
   2. App exits with error
      1. App reports success
      2. App reports an error
      3. App doesn't report an exit state
   3. App doesn't exit
      1. App reports success
      2. App reports an error
      3. App doesn't report an exit state
2. Non-streamed output (e.g., Linux app, or dev mode)
   1. App exits normally
      1. App reports success
      2. App reports an error
      3. App doesn't report an exit state
   2. App exits with error
      1. App reports success
      2. App reports an error
      3. App doesn't report an exit state
   3. App doesn't exit
      1. App reports success
      2. App reports an error
      3. App doesn't report an exit state

1.iii.c and 2.iii.c are of no concern, because there's been no exit condition.

In the 1.* cases, we only have the "reported" exit code (i.e., from the regex). There's no way to differentiate between case 1.i.X, 1.ii.X and 1.iii.X (for matching X). Ideally, case 1.ii.c would report an error to the user; on macOS, we get "Application quit abnormally (Exit code X)!" reported by the operating system, but that's not (and can't be?) caught by Briefcase. So - we just use the regex return value in each of the 1.* cases.

However, in the 2.* cases, we have both a process exit code and a "reported" exit code. Cases 2.i.a and 2.ii.b are consistent, so there's no observable problem (although it might be helpful to know if the process and reported error code are inconsistent in case 2.ii.b). 2.i.c and 2.ii.c are the "normal Toga app" cases, and they work fine as well. 2.iii.b also seems to work.

The problems I see are with:

• 2.i.b - the reported error and the successful exit code are inconsistent.
• 2.ii.a - the reported success and the failure exit code are inconsistent.
• 2.iii.a - as of this PR, this case is reported as a failure.

I'd suggest that if either source reports a failure, a failure should be surfaced - so both 2.i.b and 2.ii.a should be failures, but reported differently to the user (so they can differentiate between the two). Case 2.iii.a should be a success; it's currently failing because the log stream has been killed (so the popen return code is nonzero).

[rmartin16]

I was initially quite confused by the labeling of 1 and 2; I think that "proxied app log streaming" and "direct app log streaming", respectively, may help better differentiate the two cases.

This also doesn't really incorporate the added complexity of running with and without the --test flag....but given the goal of your comment seems to mostly want to effectively remove those differences, it probably doesn't matter too much.

As for what this PR does in relation to this analysis, IMO, it doesn't really do anything about 2.iii.a...because this PR was just ensuring the existing code would always be consistent with what it was trying to do.

Right now, if you aren't using the --test flag and an App reports success, Briefcase enters in to a race condition with sending a signal to force the app to exit and the app already trying to exit. So, sometimes the app exits before receiving this signal and Briefcase is happy....other times, the app receives the signal while it is in the middle of trying to exit and the app then exits "abnormally". Alternatively, if the app wasn't actually trying to exit at all despite reporting success, then it will always receive the signal and then exit abnormally.

All that said....you're suggesting we change the existing behavior to evaluate both outcomes in an AND condition.

I kinda think we should go the other direction...

So, I think we should consider the use-cases. Why is someone running briefcase run/dev and having the app report an exit condition? The most likely case is that they are testing a specific outcome that will be captured in the reported outcome. Presently when they do this, they don't have to also then have their app exit....because Briefcase will kindly do that for them. If we also require a successful process outcome, that will likely be confusing because it will be Briefcase that killed the app process and that's why it's reporting failure....but that probably won't be clear to them.

Given this, I feel like we should treat the run as successful if the reported outcome is successful....regardless of the returncode from the app process. This is already true if you're running in --test mode; I just think we should extend this to non---test mode with a reported outcome.

However, when not using --test and not reporting an exit condition, then the returncode from the app process should drive whether Briefcase reports success.

A bit long-winded...but thoughts?

[rmartin16]

on macOS, we get "Application quit abnormally (Exit code X)!" reported by the operating system, but that's not (and can't be?) caught by Briefcase.

FWIW, a while back, we implemented briefcase.integrations.subprocess.get_process_id_by_command() to find the PID of the app if it's started asynchronously. So, it might be possible to incorporate this in to app log streaming.

[freakboy3742]

All that said....you're suggesting we change the existing behavior to evaluate both outcomes in an AND condition.

I'm suggesting that if we have both, they should be the same; if they're not, we should report that fact (and that case is itself an error... but then, one of the two exit values has already indicated that there's an error of some kind).

If we only have one, we should report it, but in a way that I can tell that there's a difference between "the app exited on it's own" and "My log sentinel stopped the app".

The general expectation (whether test run or not) should be that the sentinel is immediately followed by an app exit with the same exit status. The only real exception to this is the case of mobile apps, which don't ever really "exit".

FWIW, a while back, we implemented briefcase.integrations.subprocess.get_process_id_by_command() to find the PID of the app if it's started asynchronously. So, I definitely think we could incorporate this in to app log streaming.

We already do use this to track if the app has exited on macOS. What we can't do is extract the status code of the process when it exits.

[rmartin16]

Well, what if we consider this discussion orthogonal (or parallel?) to this PR?

Whether we change anything about differences in "reported outcome" vs "process outcome", the changes in this PR are necessary because regardless of how all this behaves, we have to allow the app some time to exit on its own before we command it to exit....and that's all this PR is doing.

I'm also saying this because I already have so many dependent PRs in flight and I wasn't trying to refactor all this right now.

[freakboy3742]

Well, what if we consider this discussion orthogonal (or parallel?) to this PR?

Whether we change anything about differences in "reported outcome" vs "process outcome", the changes in this PR are necessary because regardless of how all this behaves, we have to allow the app some time to exit on its own before we command it to exit....and that's all this PR is doing.

That's fair. I raised this in my review because I was seeing some inconsistent behavior in how sentinel values were handled in the non-test case - but they're no less consistent as a result of this patch, it's just more obvious because I was looking at it.

I'm also saying this because I already have so many dependent PRs in flight and I wasn't trying to refactor all this right now.

:-)