Skip to content

Conversation

@peaBerberian
Copy link
Collaborator

@peaBerberian peaBerberian commented Jun 25, 2024

A large amount of time spent when maintaining the RxPlayer is actually spent on debugging device-specific issues.

Consequently, we beefed-up our debugging capabilities: we added a LOT of logs, developed our own specialized remote
debugger
so we can be monitoring low-end devices for a long amount of time (unlike chromium's or webkit's debugger), added the DEBUG_ELEMENT feature, developed some reverse-engineering tools as well as (closed-source) visual logging tools.

Now that we have many tools at our disposition, I see that our regular logs (that can e.g. be produced by calling RxPlayer.LogLevel = "DEBUG") - the most relied on way by application developpers - are lacking.

The most evident lacking data is some kind of timestamp, to better understand time-related issues, which are frequent.

But more than that, there's a lot of comfort in being able to rely on our aforementioned RxPaired remote debugger, so I was wondering if we could allow the production of logs in a format that could be easily imported by it.

Hence the idea of a supplementary RxPlayer.LogFormat property. It is by default set to "standard" - which is the currently-existing format, but can also be set to the RxPaired-compatible "full" format which:

  • Immediately produces the [Init] log, which today only serves to provide a way to convert between date representations (date on the device or monotonic timestamp since the page was opened) inside RxPaired (and also ultimately perform protocol version detection).

  • Prepend each log with a timestamp and the "namespace" of the log (e.g. [error] for error logs).

Here, we could tell application developpers not only to call:

RxPlayer.LogLevel = "DEBUG";

But also:

RxPlayer.LogFormat = "full";

When the idea is about communicating logs to us (if they just want to display logs for initial debugging steps of an issue potentially on their side or the content's side, the "standard" format may be clearer to them as less verbose).

Thoughts?

@peaBerberian peaBerberian added the proposal This Pull Request or Issue is only a proposal for a change with the expectation of a debate on it label Jun 25, 2024
@peaBerberian peaBerberian changed the title Proposal: add LogFormat static property [Proposal] add LogFormat static property Jun 25, 2024
@peaBerberian peaBerberian force-pushed the misc/log-format branch 2 times, most recently from 420fc87 to c0031b3 Compare June 25, 2024 13:42
@peaBerberian
Copy link
Collaborator Author

peaBerberian commented Jun 25, 2024

Note that with this solution there's a risk of double formatting on RxPaired's side when both LogFormat = "full" is set and RxPaired is enabled.

There's not a lot of reason in doing that however.

Maybe we could at worst handle explicitly that case in RxPaired's inspector (and perhaps server) side?
(Of course the most logical would be to do so in the client but I like the idea of it staying as dumb as possible and to still just send prefixed logs - which here do contain information we already can know)

@peaBerberian peaBerberian force-pushed the misc/log-format branch 2 times, most recently from b980ea0 to 1cefd7a Compare June 25, 2024 14:11
A large amount of time spent when maintaining the RxPlayer is actually
spent on debugging device-specific issues.

Consequently, we beefed-up our debugging capabilities: we added a LOT of
logs, developed [our own specialized remote
debugger](https://github.com/canalplus/RxPaired/) so we can be
monitoring low-end devices for a long amount of time (unlike chrome's or
webkit's debugger), developed some reverse-engineering tools as well as
(closed-source) visual logging tools.

Now that we have many tools at our disposition, I see that our regular
logs (that can e.g. be produced by calling `RxPlayer.LogLevel =
"DEBUG"`) - the most relied on way by application developpers - are
lacking.

The most evident lacking data is some kind of timestamp, to better
understand time-related issues, which are frequent.

But more than that, there's a lot of comfort in being able to rely on our
aforementioned RxPaired remote debugger, so I was wondering if we could
allow the production of logs in a format that could be easily imported by
it.

Hence the idea of a supplementary `RxPlayer.LogFormat` property.
It is by default set to `"standard"` - which is the currently-existing
format, but can also be set to the RxPaired-compatible `"full"` format
which:

  - Immediately produces the `[Init]` log, which today only serves to
    provide a way to convert between date representations (date on the
    device or monotonic timestamp since the page was opened) inside
    RxPaired (and also ultimately perform protocol version detection).

  - Prepend each log with a timestamp and the "namespace" of the log
    (e.g. `[error]` for error logs).

Here, we could tell application developpers not only to call:
```js
RxPlayer.LogLevel = "DEBUG";
```

But also:
```js
RxPlayer.LogLevel = "full";
```

When the idea is about communicating logs to us (if they just want to
display logs for initial debugging steps of an issue potentially on
their side or the content's side, the `"standard"` format may be clearer
to them as less verbose).
@Florent-Bouisset
Copy link
Collaborator

Note that with this solution there's a risk of double formatting on RxPaired's side when both LogFormat = "full" is set and RxPaired is enabled.

There's not a lot of reason in doing that however.

Maybe we could at worst handle explicitly that case in RxPaired's inspector (and perhaps server) side? (Of course the most logical would be to do so in the client but I like the idea of it staying as dumb as possible and to still just send prefixed logs - which here do contain information we already can know)

Yes, we could imagine that the RxPaired client can also use the RxPlayer.logFormat = "full" instead of patching the console in its client code. This will only work for version >= 4.2.

@peaBerberian
Copy link
Collaborator Author

Yes, we could imagine that the RxPaired client can also use the RxPlayer.logFormat = "full" instead of patching the console in its client code. This will only work for version >= 4.2.

But that would mean that you could have no way of having standard RxPlayer logs in the console AND RxPaired running, which could be wanted (or not)?

Copy link
Collaborator

@Florent-Bouisset Florent-Bouisset left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Seems good to me, maybe in the future we could also create a github template for issue and mention to set logLevel and logFormat when recording logs

@peaBerberian peaBerberian added this to the 4.2.0 milestone Jun 27, 2024
peaBerberian added a commit to canalplus/RxPaired that referenced this pull request Jun 28, 2024
Once canalplus/rx-player#1469 is merged, we risk
to be in a situation where the `timestamp [namespace] log` format as
exported by the RxPaired's inspector (and can be imported by it) would
be unnecessarily repeating.

This is a proposal for fixing it by updating the inspector's code so we
can detect and just keep the first timestamp+namespace combo

To reduce the possibility of false positives and especially to avoid
loss of information, I check that the "namespace" are the same.

False positives are still a possibility though.
peaBerberian added a commit to canalplus/RxPaired that referenced this pull request Jun 28, 2024
Once canalplus/rx-player#1469 is merged, we risk
to be in a situation where the `timestamp [namespace] log` format as
exported by the RxPaired's inspector (and can be imported by it) would
be unnecessarily repeating.

This is a proposal for fixing it by updating the inspector's code so we
can detect and just keep the first timestamp+namespace combo

To reduce the possibility of false positives and especially to avoid
loss of information, I check that the "namespace" are the same.

False positives are still a possibility though.
@Florent-Bouisset
Copy link
Collaborator

no

Ok I understand, maybe this was not a good idea because we could not have different log format in console and rxPaired

@peaBerberian peaBerberian merged commit 990221b into dev Jul 8, 2024
@peaBerberian peaBerberian deleted the misc/log-format branch July 26, 2024 16:54
peaBerberian added a commit to canalplus/RxPaired that referenced this pull request Jan 9, 2025
This is an alternative attempt (after
#22) at fixing the
"double formatting" situation brought by
canalplus/rx-player#1469 that may be made much
more frequent by canalplus/rx-player#1625.

This solution fixes it client-side instead, which could be seen as
arguably less ugly.

The idea is to rely on the fact that the RxPlayer does full formatting
by calling log functions with at least three arguments:
  1. The timestamp in a string format with always numbers after a comma
  2. A "namespace" (e.g. "[warn]")
  3-n. The log message's arguments

By considering this, we can very easily detect client-side a probable
case of full formatting.
peaBerberian added a commit to canalplus/RxPaired that referenced this pull request Jan 9, 2025
This is an alternative attempt (after
#22) at fixing the
"double formatting" situation brought by
canalplus/rx-player#1469 that may be made much
more frequent by canalplus/rx-player#1625.

This solution fixes it client-side instead, which could be seen as
arguably less ugly.

The idea is to rely on the fact that the RxPlayer does full formatting
by calling log functions with at least three arguments:
  1. The timestamp in a string format with always numbers after a comma
  2. A "namespace" (e.g. "[warn]")
  3-n. The log message's arguments

By considering this, we can very easily detect client-side a probable
case of full formatting.
peaBerberian added a commit to canalplus/RxPaired that referenced this pull request Jan 9, 2025
Once canalplus/rx-player#1469 is merged,
there will be a difference between debug logs enabled because of
the global `__RX_PLAYER_DEBUG_MODE__` boolean and those because the
RxPlayer class was passed as an argument to the global
`__RX_INSPECTOR_RUN__` function (generally the former is relied on
when the RxPlayer is not yet loaded and the latter whne it is).

This commit fixes that difference: full logs in all cases.

Alternatively, we could inside the RxPlayer just regularly re-check for
the global `RX_PLAYER_DEBUG_MODE__` boolean which might make everything
simpler.
peaBerberian added a commit to canalplus/RxPaired that referenced this pull request Mar 17, 2025
This is an alternative attempt (after
#22) at fixing the
"double formatting" situation brought by
canalplus/rx-player#1469 that may be made much
more frequent by canalplus/rx-player#1625.

This solution fixes it client-side instead, which could be seen as
arguably less ugly.

The idea is to rely on the fact that the RxPlayer does full formatting
by calling log functions with at least three arguments:
  1. The timestamp in a string format with always numbers after a comma
  2. A "namespace" (e.g. "[warn]")
  3-n. The log message's arguments

By considering this, we can very easily detect client-side a probable
case of full formatting.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

proposal This Pull Request or Issue is only a proposal for a change with the expectation of a debate on it

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants