justchokingaround / lobster

mmm lobster
GNU General Public License v2.0
541 stars 36 forks source link

Endless output on the terminal since the upgrade to mpv 0.37 #180

Closed pitsi closed 1 month ago

pitsi commented 7 months ago

Describe the bug Since mpv's upgrade to 0.37, lobster's output on the terminal is that endless wall of text which scrolls until the end of the strream.

To Reproduce Steps to reproduce the behavior:

  1. Make sure you have mpv 0.37 installed.
  2. Search and select something to watch as usual.
  3. Notice mpv's output on the terminal creating 10+ lines each second.

Expected behavior Mpv's output, the part where the time is, should be a single line with only the time updating, as you can see at the end.

Screenshots Terminal output instead of screenshot. All this was created in less than a second!

$ lobster 
Search Movie/TV Show: deadpool
Now Playing - Deadpool
The shared-script-properties property is deprecated and will be removed in the future. Use the user-data property instead.
     Video --vid=1 (h264 1920x800 23.976fps) (4500 kbps)
 (+) Video --vid=2 (h264 1728x720 23.976fps) (1800 kbps)
     Video --vid=3 (h264 864x360 23.976fps) (720 kbps)
     Audio --aid=1 (aac 2ch 48000Hz) (4500 kbps)
 (+) Audio --aid=2 (aac 2ch 48000Hz) (1800 kbps)
     Audio --aid=3 (aac 2ch 48000Hz) (720 kbps)
 (+) Subs  --sid=1 '3d56b43214d80ddd99204a238ae04484.vtt' (webvtt) (external)
Using hardware decoding (vaapi).
AO: [alsa] 48000Hz stereo 2ch float
VO: [gpu] 1728x720 vaapi[nv12]
NoW PlAyInG: Deadpool
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.017 Cache: 3.2s/216KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.015 Cache: 3.2s/215KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.014 Cache: 3.2s/213KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.012 Cache: 3.1s/211KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.011 Cache: 3.1s/209KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.010 Cache: 3.0s/208KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.009 Cache: 3.0s/206KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.008 Cache: 3.0s/205KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.007 Cache: 2.9s/203KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.007 Cache: 2.9s/202KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.006 Cache: 2.8s/199KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.005 Cache: 2.9s/232KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.005 Cache: 2.8s/230KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.004 Cache: 2.8s/229KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.004 Cache: 2.8s/227KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.003 Cache: 2.7s/226KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.003 Cache: 2.7s/224KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.003 Cache: 2.7s/223KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.003 Cache: 2.6s/221KB
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.002 Cache: 2.6s/219KB
[ffmpeg] https: Stream ends prematurely at 151797, should be 3059512
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.002 Cache: 2.6s/219KB
Exiting... (Quit)
AV: 00:00:00 / 01:48:06 (0%) A-V:  0.002 Cache: 2.6s/219KB
Stopped at - 00:00:00

Desktop (please complete the following information):

Additional context This is more of a question to see if it also happens for other users. It does not happen if I play any other online stream or file, or if I play the m3u8 lobster would play (getting it from lobster -j) as you can see here

$ mpv https://really.long.url/playlist.m3u8
The shared-script-properties property is deprecated and will be removed in the future. Use the user-data property instead.
     Video --vid=1 (h264 1920x800 23.976fps) (4500 kbps)
 (+) Video --vid=2 (h264 1728x720 23.976fps) (1800 kbps)
     Video --vid=3 (h264 864x360 23.976fps) (720 kbps)
     Audio --aid=1 (aac 2ch 48000Hz) (4500 kbps)
 (+) Audio --aid=2 (aac 2ch 48000Hz) (1800 kbps)
     Audio --aid=3 (aac 2ch 48000Hz) (720 kbps)
Using hardware decoding (vaapi).
AO: [alsa] 48000Hz stereo 2ch float
VO: [gpu] 1728x720 vaapi[nv12]
NoW PlAyInG: playlist.m3u8
AV: 00:00:14 / 01:48:06 (0%) A-V: -0.000 Cache: 593s/150MB

The message about shared-script-properties is from the osc I use for mpv and the "NoW PlAyInG" message is from the term-playing-msg parameter that I use. Please ignore them, they have nothing to do with the rest.

p.s. What use is knowing the browser on a script that has nothing to do with browsers? I replaced the requiested parts of the info above with the ones that really matter.

justchokingaround commented 6 months ago

can this be fixed using --msg-level=no ?

pitsi commented 6 months ago

Adding msg-level=all=no in mpv.conf, which seems to be the right syntax, removes ANY terminal output! But I have a bigger issue now. Lobster does not play anything, even if I comment out the option from mpv.conf! Here is a log if it can help.

lobster.log

p.s. Due to broken vaapi decoding since the upgrade to mesa 23.3.x, I am forced to use xv since 2-3 weeks ago. And xv, even on 720p, gives me framedrops because the cpu has to do all the rendering. For me, a user who has been using vdpau since it first came out 15 years ago and vaapi since it was at a pre-pre-pre-alpha level, this feels like returning to the middle ages! Or to using modern day fedora which disabled vaapi for radeon since September 2022. That is the only reason I have stopped using lobster lately, but I will return once vaapi is fixed.

justchokingaround commented 6 months ago

yeah, lobster is broken atm, refer to this: https://github.com/justchokingaround/lobster/issues/184

😔

pitsi commented 6 months ago

It's ok, we can wait :) Who knows, maybe the new version of lobster will come out in time with a patched/updated mesa for vaapi. Thank you for showing me msg-level, I will search for that specific parameter that kills the excessive output.

I assume that lobster uses mpv like so, so there is nothing to check in the script itself. mpv video.m3u --sub-file=subs.vtt

justchokingaround commented 6 months ago

yep

pitsi commented 6 months ago

Testing time now that lobster works again!

Setting the msg-level to info (msg-level=all=info) makes mpv have the normal output I mentioned above. This has a few weird side effects though, both on lobster and elsewhere. On lobster, mpv does not exit with q, so I have to press the x button to close it, which makes lobster quit with this /home/user/bin/lobster: 484: [: Illegal number:

On a perl script that I use for youtube (youtube-viewer by trizen), mpv outputs this in the terminal NoW PlAyInG: (a 5 mile long url, spanning across 6-7 lines) instead of nothing at all.

p.s. As I have said above, the "NoW PlAyInG" part comes from this parameter on my mpv.conf term-playing-msg="NoW PlAyInG: ${media-title}" Weird setting I know, but I want it to show what song I am listening to when I use mpv to play a youtube playlist as audio only.

pitsi commented 3 months ago

Now that lobster is working, and 3.5 months after my last post here, I can finally test it again. Mpv was upgraded to 0.38 on early May, mesa was upgraded to 24.x on early May too and finally brought back vaapi, so lobster was the last one to complete the month.

Sadly, mpv 0.38 still pops the same endless output when lobster runs it and not on any other occasion, like I have already described. However, I noticed on another issue report that an arch user with mpv 0.37 had the same endless output, so it may be an mpv issue after all. The problem is I can not open an issue report on their github...

pitsi commented 2 months ago

I tried v4.3 and it does fix the issue! Please tell me how you did it! :)

justchokingaround commented 2 months ago

it happens when you redirect mpv's stderr to stdout and use tee to copy that stream to a file. u can try it urself if u run this command:

mpv <local file / url> 2>&1 | tee log.txt

i fixed it by not using tee directly after the mpv command (https://github.com/justchokingaround/lobster/blob/v4.3/lobster.sh#L508-L509) and also by creating 2 additional file descriptors, namely 3 and 4, since i use tee to wrap the whole code in order to be able to save a lobster.log file (https://github.com/justchokingaround/lobster/blob/v4.3/lobster.sh#L182)

pitsi commented 2 months ago

Nice find! Thank you :)

Meanwhile, stupid me was on 4.3 since yesterday and today I ran --update and it rolled me back to 4.2.7 :D

ttx99 commented 2 months ago

still persist on windows 1

pitsi commented 2 months ago

Are you on v4.3?

pitsi commented 1 month ago

Can I ask for a small favor? As you can see above, in that enless output of v4.2.x, mpv reports some really interesting stats like the cache. This does not happen on v4.3

$ lobster 
Search Movie/TV Show: deadpool
Now Playing - Deadpool
     Video --vid=1 (h264 1920x800 23.976fps) (4500 kbps)
 (+) Video --vid=2 (h264 1728x720 23.976fps) (1800 kbps)
     Video --vid=3 (h264 864x360 23.976fps) (720 kbps)
     Audio --aid=1 (aac 2ch 48000Hz) (4500 kbps)
 (+) Audio --aid=2 (aac 2ch 48000Hz) (1800 kbps)
     Audio --aid=3 (aac 2ch 48000Hz) (720 kbps)
 (+) Subs  --sid=1 '3d56b43214d80ddd99204a238ae04484.vtt' (webvtt) (external)
Using hardware decoding (vaapi).
AO: [alsa] 48000Hz stereo 2ch float
VO: [gpu] 1728x720 vaapi[nv12]
Now playing: Deadpool

But when mpv plays the m3u8 url directly, the stats are there

$ mpv https://really.long.url/playlist.m3u8
     Video --vid=1 (h264 1920x800 23.976fps) (4500 kbps)
 (+) Video --vid=2 (h264 1728x720 23.976fps) (1800 kbps)
     Video --vid=3 (h264 864x360 23.976fps) (720 kbps)
     Audio --aid=1 (aac 2ch 48000Hz) (4500 kbps)
 (+) Audio --aid=2 (aac 2ch 48000Hz) (1800 kbps)
     Audio --aid=3 (aac 2ch 48000Hz) (720 kbps)
Using hardware decoding (vaapi).
AO: [alsa] 48000Hz stereo 2ch float
VO: [gpu] 1728x720 vaapi[nv12]
Now playing: playlist.m3u8
AV: 00:00:15 / 01:48:06 (0%) A-V: -0.000 Cache: 52s/15MB

Can it be added back somehow? Thank you in advance.

p.s. The video I was watching earlier stopped twice, so I had to replay it from lobster's "Replay episode" funtion on the last fzf menu.

justchokingaround commented 1 month ago

what do u need them for? implementing that is not very easy

pitsi commented 1 month ago

I just answered above. If it is too hard to do, I will find some way to make mpv show it like the "now playing" message.

justchokingaround commented 1 month ago

u can see the cache inside the player itself

pitsi commented 1 month ago

Do you mean on the on screen controls? I will post a screenshot if needed. Yes I can, but they are not always visible (they hide so to let the video show only) and there is nothing I can do if it stops because its cache is empty.

Btw, v4.3 works great without a config file.

justchokingaround commented 1 month ago

when it stops u can just hover over it and see the cache, no? i don't get ur use case for when it'd be useful to see cache in the terminal

pitsi commented 1 month ago

When it stops, it stops because it runs out of cached content. Screenshots with the cache filling up to a point (150mb, dark orange line on the first screenshot) and when the video stops and it does not fill any further. Plus, it pops these errors in the terminal. Mpv does not exit, it just stops at that last cached frame. The script or mpv or anything else is not to blame for that, it is the server that does not send any data.

mpv-shot0001

mpv-shot0002

[ffmpeg] tls: IO error: Connection timed out
[ffmpeg/demuxer] hls: keepalive request failed for 'https://some.long.url/seg-181-v1-a1.ts' with error: 'Connection timed out' when opening url, retrying with new connection
[ffmpeg] tls: Unknown error

In order to grab the screenshots, I let it buffer for all those 150mb and then I clicked a few seconds before the end of the dark orange line. It did not download new content. Usecase of all this? You want to move the video a few minutes later, e.g. to avoid a boring or a gory scene.

---edit It was a bad idea to switch to 360p in order to take the screenshots faster :P

pitsi commented 1 month ago

I tried term-status-msg="${demuxer-cache-duration}" and although it shows something like this for "regular" playback (the very last line shows the cached seconds)

$ mpv https://long.url/playlist.m3u8
     Video --vid=1 (h264 1920x800 23.976fps) (4500 kbps)
     Video --vid=2 (h264 1728x720 23.976fps) (1800 kbps)
 (+) Video --vid=3 (h264 864x360 23.976fps) (720 kbps)
     Audio --aid=1 (aac 2ch 48000Hz) (4500 kbps)
     Audio --aid=2 (aac 2ch 48000Hz) (1800 kbps)
 (+) Audio --aid=3 (aac 2ch 48000Hz) (720 kbps)
Using hardware decoding (vaapi).
AO: [alsa] 48000Hz stereo 2ch float
VO: [gpu] 864x360 vaapi[nv12]
184.256 

it completely disappears on lobster

$ lobster 
Search Movie/TV Show: deadpool
Now Playing - Deadpool
     Video --vid=1 (h264 1920x800 23.976fps) (4500 kbps)
     Video --vid=2 (h264 1728x720 23.976fps) (1800 kbps)
 (+) Video --vid=3 (h264 864x360 23.976fps) (720 kbps)
     Audio --aid=1 (aac 2ch 48000Hz) (4500 kbps)
     Audio --aid=2 (aac 2ch 48000Hz) (1800 kbps)
 (+) Audio --aid=3 (aac 2ch 48000Hz) (720 kbps)
 (+) Subs  --sid=1 '3d56b43214d80ddd99204a238ae04484.vtt' (webvtt) (external)
Using hardware decoding (vaapi).
AO: [alsa] 48000Hz stereo 2ch float
VO: [gpu] 864x360 vaapi[nv12]
justchokingaround commented 1 month ago

that kinda makes sense, i'll see what can be done

justchokingaround commented 1 month ago

https://github.com/justchokingaround/lobster/commit/942ad9f466a1056fe48961826c1ff34da4beb976

pitsi commented 1 month ago

Thank you for releasing 3.4. If you have any idea about the missing stats line, please comment here and I will test it.

justchokingaround commented 1 month ago

sure, i'll keep it in mind, but i dont have any ideas yet