What exactly is mangling p4a's output with [lots of missing output]... (and X more)?

[ghost]

I've noticed since a while that the python-for-android output is occasionally pretty broken with some apparent attempt to make it more terse, but actually it appears to hide vital information.

Example (copied from travis):

[INFO]:    -> running patch -t -d /home/user/.local/share/python-for-android/buil...(and 168 more)
Exception in thread background thread for pid 737:
Traceback (most recent call last):
  File "/usr/lib/python3.6/threading.py", line 916, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.6/threading.py", line 864, in run
    self._target(*self._args, **self._kwargs)
  File "/home/user/venv/lib/python3.6/site-packages/sh.py", line 1540, in wrap
    fn(*args, **kwargs)
  File "/home/user/venv/lib/python3.6/site-packages/sh.py", line 2459, in background_thread
    handle_exit_code(exit_code)
  File "/home/user/venv/lib/python3.6/site-packages/sh.py", line 2157, in fn
    return self.command.handle_command_exit_code(exit_code)
  File "/home/user/venv/lib/python3.6/site-packages/sh.py", line 815, in handle_command_exit_code
    raise exc
sh.ErrorReturnCode_1: 
  RAN: /usr/bin/patch -t -d /home/user/.local/share/python-for-android/build/other_builds/pyjnius-genericndkbuild-python3/armeabi-v7a__ndk_target_21/pyjnius -p1 -i /home/user/pythonforandroid/recipes/pyjnius/genericndkbuild_jnienv_getter.patch
  STDOUT:
patching file jnius/jnius_jvm_android.pxi
Hunk #1 FAILED at 1.
1 out of 1 hunk FAILED -- saving rejects to file jnius/jnius_jvm_android.pxi.rej
patching file setup.py
Hunk #1 FAILED at 53.
1 out of 1 hunk FAILED -- saving rejects to file setup.py.rej

This is not so good output, because the pyjnius install appears to be missing. Which pyjnius version was installed? Not sure it was printed, because (and 168 more) - but what is doing that?

I think whatever it is, even if it was added with good intentions it does appear to do more harm than good, we should possibly remove it.

But does anyone know what it even is?

Is it the thing that outputs it with strange STDOUT blocks, so maybe the sh module? Any educated guesses how we can rid of this shortening?

[inclement]

The truncation is applied when not running with --debug because the actual sh output here is mostly just so that you can see roughly what's happening, and that p4a isn't just hanging (because the line changes in place).

If the line isn't truncated, the log output gets messy because of line wrapping.

If something goes wrong, you should get a backtrace with more detailed output. This appears to be working, in your example /usr/bin/patch -t -d /home/user/.local/share/python-for-android/build/other_builds/pyjnius-genericndkbuild-python3/armeabi-v7a__ndk_target_21/pyjnius -p1 -i /home/user/pythonforandroid/recipes/pyjnius/genericndkbuild_jnienv_getter.patch is the line that failed.

[ghost]

Yes it is the line that failed but isn't the context kinda missing?

To me this truncation seems to do more harm than good, why not just not do this always? The output is giant anyway, and if anybody is going to look at it despite of that they don't want to see the interesting parts being missing, so I don't really get the point of it

It would actually make more sense to me to just print way less in the first place, so people realize the difference to --debug and they remember to use that if they need the output. (Because I didn't even realize I forgot --debug because it still looks so super verbose, just with that weird formatting on top that sometimes swallows things in a way that to me as a "user" just seems random and frustrating)

Am I the only one who finds this reformatting quite unpredictable and irritating? (non-rhetorical question!!) I mean if it's only me then I'm sorry for using up the time with the ticket 😱 it could be, I sometimes am strangely opinionated 😬 but to me this truncating just seems weird

[inclement]

It would actually make more sense to me to just print way less in the first place

Even if we did this, I really like the truncated output of the commands that are running. It's a great indicator that stuff is still going on (which otherwise isn't at all obvious when p4a sits for minutes on a long compile), and but the truncation and overwriting is explicitly because this output isn't something you'll be caring about if you use --debug.

I'm not against cutting down how much we log in general, we do have too many unnecessary messages. Maybe we should have an intermediate log level.

Also, even if we print a lot without --debug, adding --debug still logs dramatically more.

I actually specifically implemented things this way when first writing this version of the toolchain. It's the progressive result of slowly adding more tweaks as I got annoyed at not being able to follow enough of what was happening unless I added --debug, which in turn logged way too much to be a useful overview. As such, I like the way it currently is and am strongly opposed to significant changes. But, I'm also obviously biased.

[ghost]

@inclement the problem why I got here is I think because pip also does terminal rewriting for a progress indicator especially also with new pep517 (which most of you probably haven't seen yet in action, it's in pip 19+ and for the new pyproject.toml building, it comes with / is vaguely related to the build isolation problems that I reported to the pip developers but also is output that way without build isolation enabled), and the toolchain rewriting seems to clash quite badly with this at times.

So I get the potential value of it if it works, but this clash-with-pip issue combined with that e.g. in the above case it doesn't unroll more of the "swallowed" messages that occurred before the error to give me a proper context just make it more frustrating than useful to me in practice.

Basically I'm saying it's not a bad idea necessarily, but I'm not sure this issue with pip is even fundamentally ever solvable so this might be a bigger problem in the future and I wonder if it is worth keeping this around?

Why not instead do something like ./configure does and just never output any command execution or output until it fails, and when it does provide a means to get the full thing? (Configure does this by pointing at a separate configure.log I think, but for p4a the easiest would probably be to just "swallow" the entire output including what p4a itself outputs up to fairly minimal info, and throw out the last X lines of the full output if p4a terminates with exit code not 0. With --debug it could just always throw out the unfiltered thing immediately as always)

Edit: basically I'm suggesting to do something more drastic than some live rewriting to somewhat compress it that also is quite error prone while retaining more context in the actual error case

[inclement]

We should have full control of writing the output from pip, so I'm not clear why we can't prevent formatting issues? I'm happy to believe there are issues I haven't seen before, but not clear how they arise.

So I get the potential value of it if it works, but this clash-with-pip issue combined with that e.g. in the above case it doesn't unroll more of the "swallowed" messages that occurred before the error to give me a proper context just make it more frustrating than useful to me in practice.

It sounds like there are two issues here. The first is the clashing with pip which causes some issues with the output, which can be fixed (or found impossible/impractical to fix for whatever reason) independently of anything else. The second is the logging of more context when something goes wrong, which you could also do without removing the truncated logging if that's what you want.

Why not instead do something like ./configure does and just never output any command execution or output until it fails,

Specifically because I preferred having an indicator of what's happening while it happens. Just like, for instance, pip apparently does :p

[ghost]

Specifically because I preferred having an indicator of what's happening while it happens. Just like, for instance, pip apparently does :p

That seems a bit like a niche use for the rewriting complexity though, in my opinion. Is this really worth it?

What in p4a runs so long anyway (as a single step) that a progress indicator would be important to tell it didn't get stuck? I can't think of any step except maybe the python modules install step, but there we could just remove the -v from the pip command and print that out fully since then it's actually not that spammy and informing about progress more nicely than p4a's current truncation attempts (in my opinion)

I think pip could be get to work by identifying & filtering the ANSI control characters it uses for this, although it would probably lead to travis-equivalent spammy 500-lines-that-were-meant-to-be-one broken progress indicator things. But we may have to do that in any case even if going with a simpler output suppressor without rewriting, which is what I still would suggest as a better long term option

[inclement]

That seems a bit like a niche use for the rewriting complexity though, in my opinion. Is this really worth it?

Well, I think yes.

What in p4a runs so long anyway (as a single step) that a progress indicator would be important to tell it didn't get stuck?

Some of the compile steps can take a few minutes, possibly especially on whatever machine I was using at the time. Again, I specifically made it this way because I preferred it to seeing nothing - it's an aesthetic choice made to my preferences, not something that's necessary in an abstract sense, so subjectively I'm guaranteed to like it!

I don't think I really understand the concern about it, except the broken pip output which is clearly a real issue but can be fixed.

[ghost]

I don't think I really understand the concern about it, except the broken pip output which is clearly a real issue but can be fixed.

Hm you are right, I might just be biased right now because for me it didn't fully work and it took me a while to trace down what even did the reformatting (for a while I thought it was pip itself) which was a little annoying. But I suppose wanting to remove it may be an overreaction on my side

I'll look into fixing the pip issue and ponder this some more

[github-actions]

👋 We use the issue tracker exclusively for bug reports and feature requests. However, this issue appears to be a support request. Please use our support channels to get help with the project.

If you're having trouble installing or using python-for-android, maybe you could be interested in our quickstart guide.

Let us know if this comment was made in error, and we'll be happy to reopen the issue.