Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Running multiple mpv instances #126

Open
smallnetbuilder opened this issue Jul 20, 2020 · 21 comments
Open

Running multiple mpv instances #126

smallnetbuilder opened this issue Jul 20, 2020 · 21 comments

Comments

@smallnetbuilder
Copy link

I need to run multiple instances of mpv. Each player will have its own property observer that I would like to log to a separate file.

I think I need to do this by putting the player and its decorated property observer in a separate thread.
Is the ability to do this built into python-mpv or does it need to be done in the script that calls your interface?

@jaseg
Copy link
Owner

jaseg commented Jul 20, 2020

You can create multiple MPV instances in the same thread. The observers are called from a per-instance event handling thread that is automatically spawned in the background when you construct the instance. Here's an example of running two at the same time:

#!/usr/bin/env python3
import time
import sys

import mpv

player1 = mpv.MPV(log_handler=print, loglevel='debug', vo='x11')
time.sleep(0.2)
player2 = mpv.MPV(log_handler=print, loglevel='debug', vo='x11')

player1.loop = True
player2.loop = True
player1.play('test.webm')
time.sleep(0.2)
player2.play('test.webm')

def make_observer(player_name):
    def observer(_prop_name, prop_val):
        print(f'{player_name}: {prop_val}')
    return observer
player1.observe_property('time-pos', make_observer('player1'))
player2.observe_property('time-pos', make_observer('player2'))

player1.wait_for_playback()

Testing this I got some crashes in the default opengl vo when launching both players at the same time, but I suspect that is an upstream bug specific to my setup.

@smallnetbuilder
Copy link
Author

Thanks again. I'll see if I can get this running.

I'm writing a test application to see if new Wi-Fi 7 APs and routers are really better at handling multiple video streams.
I need to run 37 player instances playing RTSP streams. The RTSP streamer easily handles the load. But getting a single system capable of running 37 players, even running 3Mbps steams is going to be a challenge.

@jaseg
Copy link
Owner

jaseg commented Jul 20, 2020

Instead of actually playing these streams you could just dump them to disk using mpv, then analyze variables like momentary throughput and packet latency using tcpdump/wireshark.

@smallnetbuilder
Copy link
Author

That's good thought. Could I retrieve video stats too like frame and bit rate and A/V sync?

I've got four players launched so far using your suggested code. I'm working through getting both the player log messages and decorated property observer output also written to a log per player.

Your interface and help have been invaluable! Thank you!

@smallnetbuilder
Copy link
Author

I'm trying to write a log file per player. Do I need to define a loghandler per player or is there a way I can pass a logfile name to one handler?

Or is it easier to direct all player logging to a single file, with logging tagged with a player ID?

@jaseg
Copy link
Owner

jaseg commented Jul 21, 2020

I'm trying to write a log file per player. Do I need to define a loghandler per player or is there a way I can pass a logfile name to one handler?

Or is it easier to direct all player logging to a single file, with logging tagged with a player ID?

You could e.g. use functools.partial, that sets the given functions first few arguments and returns a new function:

from functools import partial

def log_handler(logfile, level, prefix, text):
    print(level, prefix, text, file=logfile)

some_logfile = open('some.log', 'w+')
player = mpv.MPV(log_handler=partial(log_handler, some_logfile), loglevel='debug')

@jaseg
Copy link
Owner

jaseg commented Jul 21, 2020

That's good thought. Could I retrieve video stats too like frame and bit rate and A/V sync?

Bitrate should definitely be possible with wireshark's statistics. Does A/V sync depend on the network? I thought you'd transport some container format over RTSP and that would have a fixed A/V sync? If audio and video are separate RTSP streams you might be able to measure that if there are some frame numbers/timestamps in the packet that wireshark can understand.

@smallnetbuilder
Copy link
Author

Thanks for both replies. Both are helpful suggestions.

@smallnetbuilder
Copy link
Author

Having a problem implementing the partial log_handler. Here's the code

def logtofile(logfile, level, prefix, text):
	# print to terminal
	print(f'{logfile} {datetime.datetime.now():%Y-%m-%d %H:%M:%S} \033[38;5;246m{level:>8} \033[38;5;{col(prefix)}m{prefix}:\033[0m {text}')
	# print to logfile
	print(f'{logfile}{datetime.datetime.now():%Y-%m-%d %H:%M:%S} [{level}] {prefix}: {text}', file=logfile)
	
# Create players and logfiles
for n in range(numplayers):
	print('>>> Creating player %s logfile' % n)
	logfilename = 'player_'+str(n)+'_vidtest.log'
	logfile = open(logfilename, 'w+')
	atexit.register(logfile.close)
	logfilelist.append(logfile)
	
	print('>>> Creating player %s' % n)
	playerInstance = mpv.MPV(log_handler=partial(logtofile,logfile), loglevel='warn')
	playerInstance.window_scale = 0.25
	vidplayerlist.append(playerInstance)
	
	print('>>> Starting player %s' % n)
	playerInstance.play(streamtoplay)
	time.sleep(2)

When I run it, mpv errors all are sent to player_0_vidtest.log.
The _io.TextIOWrapper name is the same for all the players, i.e. 'player_0_vidtest.log'

What did I do wrong?

>>> Creating player 0 logfile
>>> Creating player 0
>>> Starting player 0
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 12:20:11    error ffmpeg/video: h264: co located POCs unavailable
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 12:20:11    error ffmpeg/video: h264: co located POCs unavailable
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 12:20:11    error ffmpeg/video: h264: co located POCs unavailable
>>> Creating player 1 logfile
>>> Creating player 1
>>> Starting player 1
>>> Creating player 2 logfile
>>> Creating player 2
>>> Starting player 2
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 12:20:15    error ffmpeg/video: h264: co located POCs unavailable
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 12:20:15    error ffmpeg/video: h264: co located POCs unavailable
>>> Creating player 3 logfile
>>> Creating player 3
>>> Starting player 3
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 12:20:17    error ffmpeg/video: h264: co located POCs unavailable
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 12:20:17    error ffmpeg/video: h264: co located POCs unavailable
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 12:20:17    error ffmpeg/video: h264: co located POCs unavailable
>>> Creating player 4 logfile
>>> Creating player 4
>>> Starting player 4
>>> Creating player 5 logfile
>>> Creating player 5
>>> Starting player 5
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 12:20:21    error ffmpeg/video: h264: co located POCs unavailable
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 12:20:21    error ffmpeg/video: h264: co located POCs unavailable
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 12:20:21    error ffmpeg/video: h264: co located POCs unavailable
>>> Creating player 6 logfile
>>> Creating player 6
>>> Starting player 6
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 12:20:23    error ffmpeg/video: h264: co located POCs unavailable
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 12:20:23    error ffmpeg/video: h264: co located POCs unavailable
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 12:20:23    error ffmpeg/video: h264: co located POCs unavailable
>>> Creating player 7 logfile
>>> Creating player 7
>>> Starting player 7

>>> Log file list: [<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'>, <_io.TextIOWrapper name='player_1_vidtest.log' mode='w+' encoding='UTF-8'>, <_io.TextIOWrapper name='player_2_vidtest.log' mode='w+' encoding='UTF-8'>, <_io.TextIOWrapper name='player_3_vidtest.log' mode='w+' encoding='UTF-8'>, <_io.TextIOWrapper name='player_4_vidtest.log' mode='w+' encoding='UTF-8'>, <_io.TextIOWrapper name='player_5_vidtest.log' mode='w+' encoding='UTF-8'>, <_io.TextIOWrapper name='player_6_vidtest.log' mode='w+' encoding='UTF-8'>, <_io.TextIOWrapper name='player_7_vidtest.log' mode='w+' encoding='UTF-8'>]

>>> Playerlist: [<mpv.MPV object at 0x7fa673dfac50>, <mpv.MPV object at 0x7fa673e080f0>, <mpv.MPV object at 0x7fa673e084a8>, <mpv.MPV object at 0x7fa673e08860>, <mpv.MPV object at 0x7fa673e08c18>, <mpv.MPV object at 0x7fa673e08fd0>, <mpv.MPV object at 0x7fa673e123c8>, <mpv.MPV object at 0x7fa673e12780>]

@jaseg
Copy link
Owner

jaseg commented Jul 21, 2020

What did I do wrong?

The code you posted is fine! I added the missing parts and got the script below. The output is as expected. I'm guessing you maybe have a global somewhere that's shadowing something? Are you testing this as a script or in an interactive interpreter? If you're testing this in ipython or similar make sure you're actually running the code you posted by restarting the session.

#!/usr/bin/env python3
import mpv
import atexit
import time
import datetime
import functools

nice_cols = [49, 118, 27, 196, 208, 206, 229, 87]
@functools.lru_cache(maxsize=None)
def col(seed):
    global nice_cols
    rv, *nice_cols = nice_cols
    nice_cols = [*nice_cols, rv]
    return rv


def logtofile(logfile, level, prefix, text):
	# print to terminal
	print(f'{logfile} {datetime.datetime.now():%Y-%m-%d %H:%M:%S} \033[38;5;246m{level:>8} \033[38;5;{col(prefix)}m{prefix}:\033[0m {text}')
	# print to logfile
	print(f'{logfile}{datetime.datetime.now():%Y-%m-%d %H:%M:%S} [{level}] {prefix}: {text}', file=logfile)

# Create players and logfiles
logfilelist = []
vidplayerlist = []
for n in range(5):
	print('>>> Creating player %s logfile' % n)
	logfilename = '/tmp/player_'+str(n)+'_vidtest.log'
	logfile = open(logfilename, 'w+')
	atexit.register(logfile.close)
	logfilelist.append(logfile)

	print('>>> Creating player %s' % n)
	playerInstance = mpv.MPV(log_handler=functools.partial(logtofile,logfile), loglevel='warn')
	playerInstance.window_scale = 0.25
	vidplayerlist.append(playerInstance)

	print('>>> Starting player %s' % n)
	playerInstance.play('test.webm')
	time.sleep(2)

Output:

dev-pypi~/python-mpv <3 python3 demo6.py                                                                                                                                                                                              master
>>> Creating player 0 logfile
>>> Creating player 0
>>> Starting player 0
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 18:45:20    error file: Cannot open file 'test.webm': No such file or directory
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 18:45:20    error stream: Failed to open test.webm.
>>> Creating player 1 logfile
>>> Creating player 1
>>> Starting player 1
<_io.TextIOWrapper name='/tmp/player_1_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 18:45:22    error file: Cannot open file 'test.webm': No such file or directory
<_io.TextIOWrapper name='/tmp/player_1_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 18:45:22    error stream: Failed to open test.webm.
>>> Creating player 2 logfile
>>> Creating player 2
>>> Starting player 2
<_io.TextIOWrapper name='/tmp/player_2_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 18:45:24    error file: Cannot open file 'test.webm': No such file or directory
<_io.TextIOWrapper name='/tmp/player_2_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 18:45:24    error stream: Failed to open test.webm.
^CTraceback (most recent call last):
  File "demo6.py", line 40, in <module>
    time.sleep(2)
KeyboardInterrupt
dev-pypi~/python-mpv <3 cat /tmp/player_0_vidtest.log                                                                                                                                                                             (1) master
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>2020-07-21 18:45:20 [error] file: Cannot open file 'test.webm': No such file or directory
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>2020-07-21 18:45:20 [error] stream: Failed to open test.webm.
dev-pypi~/python-mpv <3 cat /tmp/player_1_vidtest.log                                                                                                                                                                                 master
<_io.TextIOWrapper name='/tmp/player_1_vidtest.log' mode='w+' encoding='UTF-8'>2020-07-21 18:45:22 [error] file: Cannot open file 'test.webm': No such file or directory
<_io.TextIOWrapper name='/tmp/player_1_vidtest.log' mode='w+' encoding='UTF-8'>2020-07-21 18:45:22 [error] stream: Failed to open test.webm.

@smallnetbuilder
Copy link
Author

I'm testing as a script.

I think I found a problem. When running the script, my streaming source failed. Note the difference in io.TextIOWrapper names for errors from ffmpeg/demuxer and the other sources.

python3 videotestmulti.py
>>> Creating player 0 testlogfile
>>> testlogfilename: player_0_vidtest.log
>>> testlogfile: <_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'>
>>> Creating player 0
>>> Starting player 0
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 15:05:08    error ffmpeg/demuxer: rtsp: method DESCRIBE failed: 404 Not Found
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 15:05:08    error lavf: avformat_open_input() failed
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 15:05:08    error cplayer: Failed to recognize file format.
>>> Creating player 1 testlogfile
>>> testlogfilename: player_1_vidtest.log
>>> testlogfile: <_io.TextIOWrapper name='player_1_vidtest.log' mode='w+' encoding='UTF-8'>
>>> Creating player 1
>>> Starting player 1
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 15:05:10    error ffmpeg/demuxer: rtsp: method DESCRIBE failed: 404 Not Found
<_io.TextIOWrapper name='player_1_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 15:05:10    error lavf: avformat_open_input() failed
<_io.TextIOWrapper name='player_1_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 15:05:10    error cplayer: Failed to recognize file format.
>>> Creating player 2 testlogfile
>>> testlogfilename: player_2_vidtest.log
>>> testlogfile: <_io.TextIOWrapper name='player_2_vidtest.log' mode='w+' encoding='UTF-8'>
>>> Creating player 2
>>> Starting player 2
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 15:05:12    error ffmpeg/demuxer: rtsp: method DESCRIBE failed: 404 Not Found
<_io.TextIOWrapper name='player_2_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 15:05:12    error lavf: avformat_open_input() failed
<_io.TextIOWrapper name='player_2_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 15:05:12    error cplayer: Failed to recognize file format.
>>> Creating player 3 testlogfile
>>> testlogfilename: player_3_vidtest.log
>>> testlogfile: <_io.TextIOWrapper name='player_3_vidtest.log' mode='w+' encoding='UTF-8'>
>>> Creating player 3
>>> Starting player 3
<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 15:05:14    error ffmpeg/demuxer: rtsp: method DESCRIBE failed: 404 Not Found
<_io.TextIOWrapper name='player_3_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 15:05:14    error lavf: avformat_open_input() failed
<_io.TextIOWrapper name='player_3_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-21 15:05:14    error cplayer: Failed to recognize file format.

>>> Log file list: [<_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'>, <_io.TextIOWrapper name='player_1_vidtest.log' mode='w+' encoding='UTF-8'>, <_io.TextIOWrapper name='player_2_vidtest.log' mode='w+' encoding='UTF-8'>, <_io.TextIOWrapper name='player_3_vidtest.log' mode='w+' encoding='UTF-8'>]

>>> Playerlist: [<mpv.MPV object at 0x7f9a084db0f0>, <mpv.MPV object at 0x7f9a084db668>, <mpv.MPV object at 0x7f9a0850a550>, <mpv.MPV object at 0x7f9a08503b70>

@smallnetbuilder
Copy link
Author

Were you able to determine why ffmpeg doesn't use the correct io.TextIOWrapper name?

@jaseg
Copy link
Owner

jaseg commented Jul 23, 2020

No, I tried reproducing it using your code but with the script I put it into everything worked. It must have been something outside of the code you posted above.

@smallnetbuilder
Copy link
Author

Could it be ffmpeg version and/or python-mpv version? I'm using 0.4.0 due to issue 116

@jaseg
Copy link
Owner

jaseg commented Jul 23, 2020

That should definitely not cause this kind of behavior.

@smallnetbuilder
Copy link
Author

Sorry for the long post.

tldr; I suspect log_handler is not properly handling multiple instances. No matter what I try, ffmpeg errors are always logged to the first log_handler instance.

I took your demo6.py script, ran it on my system and got the same result. File 'test.webm' doesn't exist on my system either.

I then changed playerInstance.play to play a valid rtsp stream and saw the same result as before; ffmpeg errors are written to player_0_vidtest.log.

I then modified the script to print logfile value in the for loop and again in logtofile:

#!/usr/bin/env python3
import mpv
import atexit
import time
import datetime
import functools

nice_cols = [49, 118, 27, 196, 208, 206, 229, 87]
@functools.lru_cache(maxsize=None)
def col(seed):
    global nice_cols
    rv, *nice_cols = nice_cols
    nice_cols = [*nice_cols, rv]
    return rv


def logtofile(logfile, level, prefix, text):
	print('>>> logtofile: logfile= ', (logfile)) #<<ADDED THIS PRINT
	# print to terminal
	print(f'{logfile} {datetime.datetime.now():%Y-%m-%d %H:%M:%S} \033[38;5;246m{level:>8} \033[38;5;{col(prefix)}m{prefix}:\033[0m {text}')
	# print to logfile
	#print(f'{logfile}{datetime.datetime.now():%Y-%m-%d %H:%M:%S} [{level}] {prefix}: {text}', file=logfile)

# Create players and logfiles
logfilelist = []
vidplayerlist = []
for n in range(2):
	print('>>> Creating player %s logfile' % n)
	logfilename = '/tmp/player_'+str(n)+'_vidtest.log'
	logfile = open(logfilename, 'w+')
	print('\n>>> Creating player %s logfile: %s' % (n,logfile)) #<<ADDED THIS PRINT
	atexit.register(logfile.close)
	logfilelist.append(logfile)

	print('>>> Creating player %s' % n)
	playerInstance = mpv.MPV(log_handler=functools.partial(logtofile,logfile), loglevel='warn')
	#playerInstance = mpv.MPV(log_handler=print, loglevel='warn')
	playerInstance.window_scale = 0.25
	vidplayerlist.append(playerInstance)

	print('>>> Starting player %s' % n)
	#playerInstance.play('rtsp://172.16.28.101:8554/testfile')
	playerInstance.play('foo.mp4')
	time.sleep(2)
	
vidplayerlist[0].wait_for_playback()

When I try to play a nonexistent file, the _io.TextIOWrapper name values match in both print statements.

$ python3 samplecode.py
>>> Creating player 0 logfile

>>> Creating player 0 logfile: <_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>
>>> Creating player 0
>>> Starting player 0
>>> logtofile: logfile=  <_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-23 11:50:41    error file: Cannot open file 'foo.mp4': No such file or directory
>>> logtofile: logfile=  <_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-23 11:50:41    error stream: Failed to open foo.mp4.
>>> Creating player 1 logfile

>>> Creating player 1 logfile: <_io.TextIOWrapper name='/tmp/player_1_vidtest.log' mode='w+' encoding='UTF-8'>
>>> Creating player 1
>>> Starting player 1
>>> logtofile: logfile=  <_io.TextIOWrapper name='/tmp/player_1_vidtest.log' mode='w+' encoding='UTF-8'>
<_io.TextIOWrapper name='/tmp/player_1_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-23 11:50:43    error file: Cannot open file 'foo.mp4': No such file or directory
>>> logtofile: logfile=  <_io.TextIOWrapper name='/tmp/player_1_vidtest.log' mode='w+' encoding='UTF-8'>
<_io.TextIOWrapper name='/tmp/player_1_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-23 11:50:43    error stream: Failed to open foo.mp4.

When I play a valid file, they don't. But all errors come from ffmpeg.

$ python3 samplecode.py
>>> Creating player 0 logfile

>>> Creating player 0 logfile: <_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>
>>> Creating player 0
>>> Starting player 0
>>> Creating player 1 logfile

>>> Creating player 1 logfile: <_io.TextIOWrapper name='/tmp/player_1_vidtest.log' mode='w+' encoding='UTF-8'>
>>> Creating player 1
>>> Starting player 1
>>> logtofile: logfile=  <_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-23 12:03:41    error ffmpeg/video: h264: left block unavailable for requested intra4x4 mode -1
>>> logtofile: logfile=  <_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-23 12:03:41    error ffmpeg/video: h264: error while decoding MB 0 61, bytestream 2745
>>> logtofile: logfile=  <_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-23 12:03:41    error ffmpeg/video: h264: left block unavailable for requested intra4x4 mode -1
>>> logtofile: logfile=  <_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-23 12:03:41    error ffmpeg/video: h264: error while decoding MB 0 61, bytestream 2745
>>> logtofile: logfile=  <_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-23 12:03:53    error ffmpeg/video: h264: left block unavailable for requested intra4x4 mode -1
>>> logtofile: logfile=  <_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-23 12:03:53    error ffmpeg/video: h264: error while decoding MB 0 50, bytestream 9543
>>> logtofile: logfile=  <_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-23 12:03:53    error ffmpeg/video: h264: left block unavailable for requested intra4x4 mode -1
>>> logtofile: logfile=  <_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-23 12:03:53    error ffmpeg/video: h264: error while decoding MB 0 50, bytestream 9543
>>> logtofile: logfile=  <_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-23 12:03:54    error ffmpeg/video: h264: left block unavailable for requested intra4x4 mode -1
>>> logtofile: logfile=  <_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-23 12:03:54    error ffmpeg/video: h264: error while decoding MB 0 62, bytestream 2535
>>> logtofile: logfile=  <_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-23 12:03:54    error ffmpeg/video: h264: left block unavailable for requested intra4x4 mode -1
>>> logtofile: logfile=  <_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-23 12:03:54    error ffmpeg/video: h264: error while decoding MB 0 62, bytestream 2535
>>> logtofile: logfile=  <_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'>
<_io.TextIOWrapper name='/tmp/player_0_vidtest.log' mode='w+' encoding='UTF-8'> 2020-07-23 12:04:02    error ffmpeg/video: h264: error while decoding MB 106 66, bytestream -17

I then changed the script to eliminate functools.partial. I created multiple logtofile functions, changing the print statement to include the function name, i.e.

def logtofile0(level, prefix, text):
	print('>>> logtofile0: logfile= ', (logfile))
	# print to terminal
	print(f'logtofile0: {datetime.datetime.now():%Y-%m-%d %H:%M:%S} \033[38;5;246m{level:>8} \033[38;5;{col(prefix)}m{prefix}:\033[0m {text}')
	
def logtofile1(level, prefix, text):
	print('>>> logtofile1: logfile= ', (logfile))
	# print to terminal
	print(f'logtofile1:{datetime.datetime.now():%Y-%m-%d %H:%M:%S} \033[38;5;246m{level:>8} \033[38;5;{col(prefix)}m{prefix}:\033[0m {text}')

All errors still go to the first logfile.

$ python3 samplecode.py

>>> Creating player 0 logfile
>>> Opened player 0 logfile: <_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'>
>>> Creating player 0 with logfile <_io.TextIOWrapper name='player_0_vidtest.log' mode='w+' encoding='UTF-8'>
>>> Starting player 0

>>> Creating player 1 logfile
>>> Opened player 1 logfile: <_io.TextIOWrapper name='player_1_vidtest.log' mode='w+' encoding='UTF-8'>
>>> Creating player 1 with logfile <_io.TextIOWrapper name='player_1_vidtest.log' mode='w+' encoding='UTF-8'>
>>> Starting player 1
logtofile0: 2020-07-23 13:05:50    error ffmpeg/video: h264: co located POCs unavailable
logtofile0: 2020-07-23 13:05:51    error ffmpeg/video: h264: co located POCs unavailable
logtofile0: 2020-07-23 13:05:56    error ffmpeg/video: h264: left block unavailable for requested intra mode
logtofile0: 2020-07-23 13:05:56    error ffmpeg/video: h264: error while decoding MB 0 51, bytestream 8033
logtofile0: 2020-07-23 13:05:56    error ffmpeg/video: h264: left block unavailable for requested intra mode
logtofile0: 2020-07-23 13:05:56    error ffmpeg/video: h264: error while decoding MB 0 51, bytestream 8033
logtofile0: 2020-07-23 13:05:57    error ffmpeg/video: h264: left block unavailable for requested intra4x4 mode -1
logtofile0: 2020-07-23 13:05:57    error ffmpeg/video: h264: error while decoding MB 0 57, bytestream 3975
logtofile0: 2020-07-23 13:05:57    error ffmpeg/video: h264: left block unavailable for requested intra4x4 mode -1
logtofile0: 2020-07-23 13:05:57    error ffmpeg/video: h264: error while decoding MB 0 57, bytestream 3975

I know both players are getting errors because I see them when I launch multiple mpv players manually.

@smallnetbuilder
Copy link
Author

Since you can't reproduce this, it's probably time to close this bug.

@ghost
Copy link

ghost commented Aug 12, 2020

ffmpeg has a global log callback, so the first mpv instance or so gets all ffmpeg log messages. This is a problem that needs to be fixed in ffmpeg itself.

@smallnetbuilder
Copy link
Author

Thanks wm4. I thought something like that was happening. But I don't know why jaseg wasn't seeing the same behavior. Maybe this has already been addressed in a newer version of ffmpeg than I'm using?

@jaseg
Copy link
Owner

jaseg commented Nov 5, 2020

@smallnetbuilder I probably was not seeing the issue since I did not get any ffmpeg errors. mpv's regular output gets redirected as intended, after all.

You might be interested in what we're doing in the unit tests to silence libmpv/ffmpeg: We /dev/null C stdin/stdout while creating new stdin/stdout handles for python to use. This does not help you disambiguate where a particular ffmpeg log message comes from, but you could use this to just discard all of them. I am fairly sure any serious error will eventually bubble up into mpv's own output anyway.

@smallnetbuilder
Copy link
Author

Thanks for the follow up @jaseg

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants