console.lua: add script-opt --max-msg-level

[catcake]

I have been writing scripts to extend mpv for a few months and eventually grew annoyed that the console did not allow trace messages, so I made an option to control this (mentioned in #11761).

If you aren't interested in using the console for trace messages (which is probably more sane), the option can still be useful for nearly the opposite reason. The console can be restricted to only important messages, while the terminal shows more granularity.

These commits are functional & already implement what's mentioned above, but I have a couple related ideas and questions:

debug and trace message styles/colors I think they're identical, at least in the terminal on Windows (and trace wasn't relevant to the console before this). Looking at the theme that the console pulls from (here), would gui05 (#747369) be a good color for trace to differentiate it from debug messages?

a non-static default for --max-msg-level Rather than info, when --max-msg-level is not explicitly set, maybe determine the most noisy level set in --msg-level and use that? I actually wrote this already, but I wasn't sure if it was desirable to anyone other than myself.

I've tried to be thorough, but please let me know if there's anything I should correct! Thanks!

[hooke007]

default value: Why is it not "auto" (to follow the same value of --msg-level)?

[catcake]

Does the most recent commit address this sufficiently?

[hooke007]

Sry i might misunderstand this option previously. I thought it generates logs independently.

if it uses the same lv from option --msg-level, actually it did nothing. We just need set it trace to share the same output.

[catcake]

I'm not sure that trace as the default is optimal. The original reasoning for discarding them is still valid: https://github.com/mpv-player/mpv/blob/effc68063bc3b4c856d70b8c6800d5bdb072815c/player/lua/console.lua#L828-L832

If someone were to use --msg-level=all=trace, the console would be unusable. I think it could actually be lowered from debug (effectively the behavior before this PR) to verbose or info.

[hooke007]

But the current commit is the same as set it "trace"

[catcake]

Lol, true. I'll swap back to my first commit tomorrow. It didn't bother trying to detect anything from --msg-level. Initially I used info as the default. Does this sound good, or should it be raised to verbose?

[hooke007]

As a win-user, I always use console instead of cmd. verbose would be better.

[catcake]

Please excuse the mess above!

v (verbose) is now the default for --max_msg_level and the --msg-level detection has been removed!

Let me know if any if there are any other issues.

[hooke007]

I'm not sure if it was caused from mpv itself or this commit. msg-level=all=trace showed much less info than --msg-level=all=v.

[Dudemanguy]

I think it might be silent mode flushing the log buffers so the log-message event never gets them, but it's not obvious to me why that would happen because of this commit.

[catcake]

I don't think the new changes are at fault.

A minimally modified (to output the messages it receives to a file) console.lua (from mpv/master) also results in many dropped messages at levels higher than info (compared to the number of messages at any level from --log-file). It seems like the buffer only stores a few dozen messages (seemingly below 100), which is probably fine if the console isn't active. When the console is active, it seems like it can't keep up with the incoming messages.

diff of mpv/master console.lua and min-modified-console.lua

--- mpv-master-console.lua
+++ min-modified-console.lua
@@ -813,6 +813,8 @@
 -- until enable_messages is called again without the silent: prefix.
 mp.enable_messages('silent:terminal-default')
 
+local console_log_file =  io.open('min-modified-console.log', 'w')
+
 mp.register_event('log-message', function(e)
     -- Ignore log messages from the OSD because of paranoia, since writing them
     -- to the OSD could generate more messages in an infinite loop.
@@ -829,7 +831,7 @@
     -- level includes them. These aren't too useful for an on-screen display
     -- without scrollback and they include messages that are generated from the
     -- OSD display itself.
-    if e.level == 'trace' then return end
+    if e.level == 'trace' or e.level == 'debug' then return end
 
     -- Use color for debug/v/warn/error/fatal messages. Colors are stolen from
     -- base16 Eighties by Chris Kempson.
@@ -847,6 +849,12 @@
     end
 
     log_add(style, '[' .. e.prefix .. '] ' .. e.text)
+    console_log_file:write(e.level .. '\t\t' .. e.prefix .. ': ' .. e.text)
+    console_log_file:flush()  -- Preserve the message order.
 end)
 
+mp.register_event('shutdown', function()
+    console_log_file:close()
+end)
+
 collectgarbage()

[catcake]

Using: --msg-level=all=v and min_modified_console.lua Steps:

1. open video (--pause=yes)
2. wait for cache to fill
3. activate the console
4. quit mpv

files:

• 1.log-file.log (mpv log, 449 lines total)
• 1.min_modified_console.log (console log, 94 lines total)

mpv log lines <335 were presumably pushed out of the console's buffer. mpv log lines 335-423 = console logs lines 1-89 mpv log lines 424-431 are purposely omitted from the console log (from an osd module). mpv log lines 432-434 = console log lines 90-92 mpv log lines 435,436 are purposely omitted from the console log (from an osd module). mpv log lines 437,438 = console log lines 93,94 mpv log lines >438 are about mpv exiting and are not present in the console log.

1.log-file.log 1.min_modified_console.log

I'll try to look into this more, particularly at how the console falls behind when mpv generates more messages than it can handle.

[kasper93]

@catcake: please rebase

@guidocella: do you have opinion on that?

[guidocella]

Logging code is now very different with the addition of suggestion and terminal styles so it's up to the author if he's willing to update this.