iv-org/invidious

[Bug] Error with inv_sig_helper after multiple restart attempts

Closed this issue · 8 comments

Describe the bug

When restarting docker container, repeated errors on inv_sig_helper happen, and can't run the service.

Steps to Reproduce
1 Pull new docker images
2 Bring up docker container with docker-compose up -d

Logs

Attaching to invidious_invidious_1, invidious_invidious-db_1, invidious_inv_sig_helper_1
inv_sig_helper_1 | [2024-12-09T17:41:05Z INFO inv_sig_helper_rust] Fetching player
inv_sig_helper_1 | [2024-12-09T17:41:05Z INFO inv_sig_helper_rust::player] Fetching player JS URL: https://www.youtube.com/s/player/3bb1f723/player_ias.vflset/en_US/base.js
inv_sig_helper_1 | [2024-12-09T17:41:05Z WARN inv_sig_helper_rust::player] nsig function ending did not work: =\sfunction(([\w]+){\svar\s+[\w\s]+=[\w.\s]+?.call\s*([\w\s$]+?,[()",\s]+)[\S\s]?}\sreturn [\w.\s$]+?.call\s*([\w\s$]+?\s*,[()",\s]+)\s*}\s*;)
inv_sig_helper_1 | thread 'main' panicked at src/player.rs:150:10:
inv_sig_helper_1 | called Option::unwrap() on a None value
inv_sig_helper_1 | note: run with RUST_BACKTRACE=1 environment variable to display a backtrace
inv_sig_helper_1 | [2024-12-09T17:41:07Z INFO inv_sig_helper_rust] Fetching player
inv_sig_helper_1 | [2024-12-09T17:41:08Z INFO inv_sig_helper_rust::player] Fetching player JS URL: https://www.youtube.com/s/player/3bb1f723/player_ias.vflset/en_US/base.js
inv_sig_helper_1 | [2024-12-09T17:41:08Z WARN inv_sig_helper_rust::player] nsig function ending did not work: =\sfunction(([\w]+){\svar\s+[\w\s]+=[\w.\s]+?.call\s*([\w\s$]+?,[()",\s]+)[\S\s]?}\sreturn [\w.\s$]+?.call\s*([\w\s$]+?\s*,[()",\s]+)\s*}\s*;)
inv_sig_helper_1 | thread 'main' panicked at src/player.rs:150:10:
inv_sig_helper_1 | called Option::unwrap() on a None value
inv_sig_helper_1 | note: run with RUST_BACKTRACE=1 environment variable to display a backtrace
inv_sig_helper_1 | [2024-12-09T17:41:09Z INFO inv_sig_helper_rust] Fetching player
inv_sig_helper_1 | [2024-12-09T17:41:10Z INFO inv_sig_helper_rust::player] Fetching player JS URL: https://www.youtube.com/s/player/3bb1f723/player_ias.vflset/en_US/base.js
inv_sig_helper_1 | [2024-12-09T17:41:10Z WARN inv_sig_helper_rust::player] nsig function ending did not work: =\sfunction(([\w]+){\svar\s+[\w\s]+=[\w.\s]+?.call\s*([\w\s$]+?,[()",\s]+)[\S\s]?}\sreturn [\w.\s$]+?.call\s*([\w\s$]+?\s*,[()",\s]+)\s*}\s*;)
inv_sig_helper_1 | thread 'main' panicked at src/player.rs:150:10:
inv_sig_helper_1 | called Option::unwrap() on a None value
inv_sig_helper_1 | note: run with RUST_BACKTRACE=1 environment variable to display a backtrace
inv_sig_helper_1 | [2024-12-09T17:41:11Z INFO inv_sig_helper_rust] Fetching player
inv_sig_helper_1 | [2024-12-09T17:41:12Z INFO inv_sig_helper_rust::player] Fetching player JS URL: https://www.youtube.com/s/player/3bb1f723/player_ias.vflset/en_US/base.js
inv_sig_helper_1 | [2024-12-09T17:41:12Z WARN inv_sig_helper_rust::player] nsig function ending did not work: =\sfunction(([\w]+){\svar\s+[\w\s]+=[\w.\s]+?.call\s*([\w\s$]+?,[()",\s]+)[\S\s]?}\sreturn [\w.\s$]+?.call\s*([\w\s$]+?\s*,[()",\s]+)\s*}\s*;)
inv_sig_helper_1 | thread 'main' panicked at src/player.rs:150:10:
inv_sig_helper_1 | called Option::unwrap() on a None value
inv_sig_helper_1 | note: run with RUST_BACKTRACE=1 environment variable to display a backtrace
inv_sig_helper_1 | [2024-12-09T17:41:13Z INFO inv_sig_helper_rust] Fetching player
inv_sig_helper_1 | [2024-12-09T17:41:14Z INFO inv_sig_helper_rust::player] Fetching player JS URL: https://www.youtube.com/s/player/3bb1f723/player_ias.vflset/en_US/base.js
inv_sig_helper_1 | [2024-12-09T17:41:14Z WARN inv_sig_helper_rust::player] nsig function ending did not work: =\sfunction(([\w]+){\svar\s+[\w\s]+=[\w.\s]+?.call\s*([\w\s$]+?,[()",\s]+)[\S\s]?}\sreturn [\w.\s$]+?.call\s*([\w\s$]+?\s*,[()",\s]+)\s*}\s*;)
inv_sig_helper_1 | thread 'main' panicked at src/player.rs:150:10:
inv_sig_helper_1 | called Option::unwrap() on a None value
inv_sig_helper_1 | note: run with RUST_BACKTRACE=1 environment variable to display a backtrace
inv_sig_helper_1 | [2024-12-09T17:41:16Z INFO inv_sig_helper_rust] Fetching player
inv_sig_helper_1 | [2024-12-09T17:41:17Z INFO inv_sig_helper_rust::player] Fetching player JS URL: https://www.youtube.com/s/player/3bb1f723/player_ias.vflset/en_US/base.js
inv_sig_helper_1 | [2024-12-09T17:41:17Z WARN inv_sig_helper_rust::player] nsig function ending did not work: =\sfunction(([\w]+){\svar\s+[\w\s]+=[\w.\s]+?.call\s*([\w\s$]+?,[()",\s]+)[\S\s]?}\sreturn [\w.\s$]+?.call\s*([\w\s$]+?\s*,[()",\s]+)\s*}\s*;)
inv_sig_helper_1 | thread 'main' panicked at src/player.rs:150:10:
inv_sig_helper_1 | called Option::unwrap() on a None value
inv_sig_helper_1 | note: run with RUST_BACKTRACE=1 environment variable to display a backtrace
inv_sig_helper_1 | [2024-12-09T17:41:21Z INFO inv_sig_helper_rust] Fetching player
inv_sig_helper_1 | [2024-12-09T17:41:21Z INFO inv_sig_helper_rust::player] Fetching player JS URL: https://www.youtube.com/s/player/3bb1f723/player_ias.vflset/en_US/base.js
inv_sig_helper_1 | [2024-12-09T17:41:21Z WARN inv_sig_helper_rust::player] nsig function ending did not work: =\sfunction(([\w]+){\svar\s+[\w\s]+=[\w.\s]+?.call\s*([\w\s$]+?,[()",\s]+)[\S\s]?}\sreturn [\w.\s$]+?.call\s*([\w\s$]+?\s*,[()",\s]+)\s*}\s*;)
inv_sig_helper_1 | thread 'main' panicked at src/player.rs:150:10:
inv_sig_helper_1 | called Option::unwrap() on a None value
inv_sig_helper_1 | note: run with RUST_BACKTRACE=1 environment variable to display a backtrace
inv_sig_helper_1 | [2024-12-09T17:41:28Z INFO inv_sig_helper_rust] Fetching player
inv_sig_helper_1 | [2024-12-09T17:41:29Z INFO inv_sig_helper_rust::player] Fetching player JS URL: https://www.youtube.com/s/player/3bb1f723/player_ias.vflset/en_US/base.js
inv_sig_helper_1 | [2024-12-09T17:41:29Z WARN inv_sig_helper_rust::player] nsig function ending did not work: =\sfunction(([\w]+){\svar\s+[\w\s]+=[\w.\s]+?.call\s*([\w\s$]+?,[()",\s]+)[\S\s]?}\sreturn [\w.\s$]+?.call\s*([\w\s$]+?\s*,[()",\s]+)\s*}\s*;)
inv_sig_helper_1 | thread 'main' panicked at src/player.rs:150:10:
inv_sig_helper_1 | called Option::unwrap() on a None value
inv_sig_helper_1 | note: run with RUST_BACKTRACE=1 environment variable to display a backtrace
inv_sig_helper_1 | [2024-12-09T17:41:43Z INFO inv_sig_helper_rust] Fetching player
inv_sig_helper_1 | [2024-12-09T17:41:44Z INFO inv_sig_helper_rust::player] Fetching player JS URL: https://www.youtube.com/s/player/3bb1f723/player_ias.vflset/en_US/base.js
inv_sig_helper_1 | [2024-12-09T17:41:44Z WARN inv_sig_helper_rust::player] nsig function ending did not work: =\sfunction(([\w]+){\svar\s+[\w\s]+=[\w.\s]+?.call\s*([\w\s$]+?,[()",\s]+)[\S\s]?}\sreturn [\w.\s$]+?.call\s*([\w\s$]+?\s*,[()",\s]+)\s*}\s*;)
inv_sig_helper_1 | thread 'main' panicked at src/player.rs:150:10:
inv_sig_helper_1 | called Option::unwrap() on a None value
inv_sig_helper_1 | note: run with RUST_BACKTRACE=1 environment variable to display a backtrace
inv_sig_helper_1 | [2024-12-09T17:42:10Z INFO inv_sig_helper_rust] Fetching player
inv_sig_helper_1 | [2024-12-09T17:42:11Z INFO inv_sig_helper_rust::player] Fetching player JS URL: https://www.youtube.com/s/player/3bb1f723/player_ias.vflset/en_US/base.js
inv_sig_helper_1 | [2024-12-09T17:42:11Z WARN inv_sig_helper_rust::player] nsig function ending did not work: =\sfunction(([\w]+){\svar\s+[\w\s]+=[\w.\s]+?.call\s*([\w\s$]+?,[()",\s]+)[\S\s]?}\sreturn [\w.\s$]+?.call\s*([\w\s$]+?\s*,[()",\s]+)\s*}\s*;)
inv_sig_helper_1 | thread 'main' panicked at src/player.rs:150:10:
inv_sig_helper_1 | called Option::unwrap() on a None value
inv_sig_helper_1 | note: run with RUST_BACKTRACE=1 environment variable to display a backtrace
inv_sig_helper_1 | [2024-12-09T17:43:03Z INFO inv_sig_helper_rust] Fetching player
inv_sig_helper_1 | [2024-12-09T17:43:03Z INFO inv_sig_helper_rust::player] Fetching player JS URL: https://www.youtube.com/s/player/3bb1f723/player_ias.vflset/en_US/base.js
inv_sig_helper_1 | [2024-12-09T17:43:03Z WARN inv_sig_helper_rust::player] nsig function ending did not work: =\sfunction(([\w]+){\svar\s+[\w\s]+=[\w.\s]+?.call\s*([\w\s$]+?,[()",\s]+)[\S\s]?}\sreturn [\w.\s$]+?.call\s*([\w\s$]+?\s*,[()",\s]+)\s*}\s*;)
inv_sig_helper_1 | thread 'main' panicked at src/player.rs:150:10:
inv_sig_helper_1 | called Option::unwrap() on a None value
inv_sig_helper_1 | note: run with RUST_BACKTRACE=1 environment variable to display a backtrace
invidious-db_1 |
invidious-db_1 | PostgreSQL Database directory appears to contain a database; Skipping initialization
invidious-db_1 |
invidious-db_1 | 2024-12-09 17:41:06.018 UTC [1] LOG: starting PostgreSQL 14.15 (Debian 14.15-1.pgdg120+1) on aarch64-unknown-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
invidious-db_1 | 2024-12-09 17:41:06.018 UTC [1] LOG: listening on IPv4 address "0.0.0.0", port 5432
invidious-db_1 | 2024-12-09 17:41:06.018 UTC [1] LOG: listening on IPv6 address "::", port 5432
invidious-db_1 | 2024-12-09 17:41:06.155 UTC [1] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
invidious-db_1 | 2024-12-09 17:41:06.238 UTC [27] LOG: database system was shut down at 2024-12-09 17:39:48 UTC
invidious-db_1 | 2024-12-09 17:41:06.290 UTC [1] LOG: database system is ready to accept connections
invidious_1 | 2024-12-09 17:41:07 UTC [info] SigHelper: Using helper at 'inv_sig_helper:12999'
invidious_1 | 2024-12-09 17:41:08 UTC [info] SigHelper: Connection to helper died with 'Error reading socket (#TCPSocket:0x7ffee7716d20): Connection reset by peer' trying to reconnect...
invidious_1 | 2024-12-09 17:41:11 UTC [info] SigHelper: Using helper at 'inv_sig_helper:12999'
invidious_1 | 2024-12-09 17:41:11 UTC [info] SigHelper: Reconnected to SigHelper!
invidious_1 | 2024-12-09 17:41:12 UTC [info] SigHelper: Connection to helper died with 'Error reading socket (#TCPSocket:0x7ffee7716930): Connection reset by peer' trying to reconnect...
invidious_1 | 2024-12-09 17:41:21 UTC [info] SigHelper: Using helper at 'inv_sig_helper:12999'
invidious_1 | 2024-12-09 17:41:21 UTC [info] SigHelper: Reconnected to SigHelper!
invidious_1 | 2024-12-09 17:41:21 UTC [info] SigHelper: Connection to helper died with 'Error reading socket (#TCPSocket:0x7ffee7716540): Connection reset by peer' trying to reconnect...
invidious_1 | 2024-12-09 17:41:44 UTC [info] SigHelper: Using helper at 'inv_sig_helper:12999'
invidious_1 | 2024-12-09 17:41:44 UTC [info] SigHelper: Reconnected to SigHelper!
invidious_1 | 2024-12-09 17:41:44 UTC [info] SigHelper: Connection to helper died with 'Error reading socket (#TCPSocket:0x7ffee741fd20): Connection reset by peer' trying to reconnect...

Screenshots

Additional context

Confirm. Same on my instance. Residential IP.

Same on my instance, on a residential IP. Here is the full rust backtrace from inv_sig_helper

inv_sig_helper-1  | [2024-12-09T18:15:58Z INFO  inv_sig_helper_rust] Fetching player
inv_sig_helper-1  | [2024-12-09T18:15:59Z INFO  inv_sig_helper_rust::player] Fetching player JS URL: https://www.youtube.com/s/player/3bb1f723/player_ias.vflset/en_US/base.js
inv_sig_helper-1  | [2024-12-09T18:15:59Z WARN  inv_sig_helper_rust::player] nsig function ending did not work: =\s*function(\([\w]+\)\{\s*var\s+[\w\s]+=[\w\.\s]+?\.call\s*\([\w\s$]+?,[\(\)\",\s]+\)[\S\s]*?\}\s*return [\w\.\s$]+?\.call\s*\([\w\s$]+?\s*,[\(\)\",\s]+\)\s*\}\s*;)
inv_sig_helper-1  | thread 'main' panicked at src/player.rs:150:10:
inv_sig_helper-1  | called `Option::unwrap()` on a `None` value
inv_sig_helper-1  | stack backtrace:
inv_sig_helper-1  |    0:     0x768bf86ea0f1 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::h706c9783aace6373
inv_sig_helper-1  |    1:     0x768bf85467fb - core::fmt::write::h7221bf2763310748
inv_sig_helper-1  |    2:     0x768bf86c3ce2 - std::io::Write::write_fmt::h5f543a3ea7d45c3d
inv_sig_helper-1  |    3:     0x768bf86ef269 - std::sys_common::backtrace::print::hf2079bcf21b5d607
inv_sig_helper-1  |    4:     0x768bf86eea56 - std::panicking::default_hook::{{closure}}::hd6a41ed4ba4d9cdd
inv_sig_helper-1  |    5:     0x768bf86efe61 - std::panicking::rust_panic_with_hook::he62aa99a29ab1fe6
inv_sig_helper-1  |    6:     0x768bf86ef59a - std::panicking::begin_panic_handler::{{closure}}::h4295830cbed5c147
inv_sig_helper-1  |    7:     0x768bf86ef529 - std::sys_common::backtrace::__rust_end_short_backtrace::h29724adceafc0e2c
inv_sig_helper-1  |    8:     0x768bf86ef516 - rust_begin_unwind
inv_sig_helper-1  |    9:     0x768bf84c0192 - core::panicking::panic_fmt::h5822797b7c57c9a6
inv_sig_helper-1  |   10:     0x768bf84c032b - core::panicking::panic::h576d2b304e82d017
inv_sig_helper-1  |   11:     0x768bf84c06e8 - core::option::unwrap_failed::hf12f69fdafb5c188
inv_sig_helper-1  |   12:     0x768bf84fdc7e - inv_sig_helper_rust::player::fetch_update::{{closure}}::h61359dd4904a6910
inv_sig_helper-1  |   13:     0x768bf8516c18 - inv_sig_helper_rust::main::{{closure}}::h92460df08abff2f1
inv_sig_helper-1  |   14:     0x768bf850ddca - inv_sig_helper_rust::main::h4c6ed7911b8effb7
inv_sig_helper-1  |   15:     0x768bf84d58c3 - std::sys_common::backtrace::__rust_begin_short_backtrace::h65fca62ed9181c86
inv_sig_helper-1  |   16:     0x768bf851a154 - main

https://pol1.pi.ggtyler.dev/ runs strangely enough without any problems.

Would invidious companion fix this?

(looks like an experiment slowly being rolled out)

Here's a patch to gracefully handle pattern mismatch https://0x0.st/X7dZ.patch, fixed the problem on my instance

Matrix message.

@rottenwheel Thanks.

It mostly works now but I'm still getting an error in logs:

ERROR inv_sig_helper_rust::jobs] JavaScript interpreter error (nsig code): Some(Exception { message: Some("'decrypt_nsig' is not defined"), file: None, line: Some(1), column: Some(1), stack: Some("    at <eval> (eval_script:1:1)\n") })

That fix just prevents the inv_sig_helper from crashing, but doesn't solve the issue. The player JS has changed and it looks like its not the only thing.

In order to fix the matching problem you need to change the REGEX_SIGNATURE_FUNCTION line in src/const.rs to:

pub static REGEX_SIGNATURE_FUNCTION: &Lazy<Regex> =
    regex!("\\b[a-zA-Z]+&&\\([a-zA-Z]+=([a-zA-Z0-9$]{2,})\\(decodeURIComponent\\([a-zA-Z]+\\)\\)");

This will make the inv_sig_helper work just as before, unfortunately (at least for me) it doesn't mean that invidious will play the videos as it looks like something else has changed too.

Closing in favor of iv-org/inv_sig_helper#36