search

iv-org / invidious

Invidious is an alternative front-end to YouTube
https://invidious.io
GNU Affero General Public License v3.0
16.47k stars 1.85k forks source link

[Bug] `DB::MappingException` with `updated` property of `Invidious::User` #5067

Closed wiljateiwaz closed 2 weeks ago

wiljateiwaz commented 2 weeks ago

Describe the bug I updated my instance after reading this PR https://github.com/iv-org/invidious/pull/5059 because I had the error with YouTube as well. I used the latest built image on quay quay.io/invidious/invidious:2024.11.08-b173d4a

The instance started but the homepage (subscriptions) shows an error, I can't go to any other page.

Steps to Reproduce Update image in place on docker-composer.yml from 2024.09.16-de918b9 to quay.io/invidious/invidious:2024.11.08-b173d4a with an instance setting location set to Europe/Paris.

Logs

Title: `Invalid location name: Europe/Paris
  deserializing Invidious::User#updated (DB::MappingException)`
Date: `2024-11-08T23:46:52Z`
Route: `/feed/subscriptions`
Version: `2024.11.08-b173d4a @ master`

<details>
<summary>Backtrace</summary>
<p>

'''
Invalid location name: Europe/Paris
  deserializing Invidious::User#updated (DB::MappingException)
  from lib/db/src/db/serializable.cr:105:7 in 'read'
  from lib/db/src/db/query_methods.cr:128:9 in 'select!:email'
  from src/invidious/routes/before_all.cr:84:16 in '->'
  from lib/kemal/src/kemal/filter_handler.cr:82:62 in '->'
  from lib/kemal/src/kemal/filter_handler.cr:58:23 in 'call_block_for_path_type'
  from lib/kemal/src/kemal/filter_handler.cr:16:7 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:30:7 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:30:7 in 'call_next'
  from src/invidious/helpers/handlers.cr:94:12 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:30:7 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:30:7 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:30:7 in 'call_next'
  from src/ext/kemal_static_file_handler.cr:106:14 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:30:7 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:30:7 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:30:7 in 'call'
  from /usr/share/crystal/src/http/server/request_processor.cr:51:11 in 'handle_client'
  from /usr/share/crystal/src/fiber.cr:141:11 in 'run'
  from ???
Caused by: Invalid location name: Europe/Paris (Time::Location::InvalidLocationNameError)
  from /usr/share/crystal/src/time/location/loader.cr:23:8 in 'load'
  from lib/pg/src/pg/connection.cr:53:7 in '->'
  from /usr/share/crystal/src/hash.cr:1149:15 in 'decode'
  from lib/pg/src/pg/result_set.cr:91:7 in 'read'
  from lib/db/src/db/result_set.cr:85:15 in 'read'
  from lib/db/src/db/serializable.cr:105:7 in 'read'
  from lib/db/src/db/query_methods.cr:128:9 in 'select!:email'
  from src/invidious/routes/before_all.cr:84:16 in '->'
  from lib/kemal/src/kemal/filter_handler.cr:82:62 in '->'
  from lib/kemal/src/kemal/filter_handler.cr:58:23 in 'call_block_for_path_type'
  from lib/kemal/src/kemal/filter_handler.cr:16:7 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:30:7 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:30:7 in 'call_next'
  from src/invidious/helpers/handlers.cr:94:12 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:30:7 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:30:7 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:30:7 in 'call_next'
  from src/ext/kemal_static_file_handler.cr:106:14 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:30:7 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:30:7 in 'call'
  from /usr/share/crystal/src/http/server/handler.cr:30:7 in 'call'
  from /usr/share/crystal/src/http/server/request_processor.cr:51:11 in 'handle_client'
  from /usr/share/crystal/src/fiber.cr:141:11 in 'run'
  from ???
'''
</p>
</details>

Screenshots N/D

Additional context Using docker compose to deploy the instance, with external PostgreSQL database.

inv-sig-helper also shows an error:

inv_sig_helper-1  | [2024-11-05T22:24:11Z ERROR inv_sig_helper_rust::player] Could not fetch the test video: error sending request for url (https://www.youtube.com/watch?v=jNQXAC9IVRw)

and some warnings:

inv_sig_helper-1  | [2024-11-04T21:32:37Z INFO  inv_sig_helper_rust::player] Fetching player JS URL: https://www.youtube.com/s/player/81ef9024/player_ias.vflset/en_US/base.js
inv_sig_helper-1  | [2024-11-04T21:32:37Z 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  | [2024-11-04T21:32:37Z INFO  inv_sig_helper_rust::player] sig code: var ICa;var SL={hR:function(a,b){var c=a[0];a[0]=a[b%a.length];a[b%a.length]=c},
inv_sig_helper-1  |     k6:function(a){a.reverse()},
inv_sig_helper-1  |     K9:function(a,b){a.splice(0,b)}};ICa=function(a){a=a.split("");SL.K9(a,2);SL.k6(a,36);SL.hR(a,42);return a.join("")}
inv_sig_helper-1  | [2024-11-05T09:38:25Z INFO  inv_sig_helper_rust::player] Fetching player JS URL: https://www.youtube.com/s/player/4e23410d/player_ias.vflset/en_US/base.js
inv_sig_helper-1  | [2024-11-05T09:38:26Z 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  | [2024-11-05T09:38:26Z INFO  inv_sig_helper_rust::player] sig code: var ECa;var RL={Ys:function(a){a.reverse()},
inv_sig_helper-1  |     N3:function(a,b){var c=a[0];a[0]=a[b%a.length];a[b%a.length]=c},
inv_sig_helper-1  |     vz:function(a,b){a.splice(0,b)}};ECa=function(a){a=a.split("");RL.vz(a,1);RL.N3(a,45);RL.N3(a,52);RL.vz(a,3);RL.Ys(a,31);RL.vz(a,3);RL.Ys(a,30);return a.join("")}
inv_sig_helper-1  | [2024-11-05T22:17:19Z INFO  inv_sig_helper_rust::player] Fetching player JS URL: https://www.youtube.com/s/player/81ef9024/player_ias.vflset/en_US/base.js
inv_sig_helper-1  | [2024-11-05T22:17:20Z 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  | [2024-11-05T22:17:20Z INFO  inv_sig_helper_rust::player] sig code: var ICa;var SL={hR:function(a,b){var c=a[0];a[0]=a[b%a.length];a[b%a.length]=c},
inv_sig_helper-1  |     k6:function(a){a.reverse()},
inv_sig_helper-1  |     K9:function(a,b){a.splice(0,b)}};ICa=function(a){a=a.split("");SL.K9(a,2);SL.k6(a,36);SL.hR(a,42);return a.join("")}
syeopite commented 2 weeks ago

By location you mean the region setting in the configs right? Only the following country codes are supported.

AE, AR, AT, AU, AZ, BA, BD, BE, BG, BH, BO, BR, BY, CA, CH, CL, CO, CR,
CY, CZ, DE, DK, DO, DZ, EC, EE, EG, ES, FI, FR, GB, GE, GH, GR, GT, HK,
HN, HR, HU, ID, IE, IL, IN, IQ, IS, IT, JM, JO, JP, KE, KR, KW, KZ, LB,
LI, LK, LT, LU, LV, LY, MA, ME, MK, MT, MX, MY, NG, NI, NL, NO, NP, NZ,
OM, PA, PE, PG, PH, PK, PL, PR, PT, PY, QA, RO, RS, RU, SA, SE, SG, SI,
SK, SN, SV, TH, TN, TR, TW, TZ, UA, UG, US, UY, VE, VN, YE, ZA, ZW
wiljateiwaz commented 2 weeks ago

I'm not meaning anything, I'm telling what the homepage and the logs of Docker are showing.

I didn't try to put Europe/Paris anywhere, I only changed the image tag and restarted, the error shows up. I know my setting in the config is indeed FR. Hence my concern about a link with the update and an issue that you already closed...

wiljateiwaz commented 2 weeks ago

Reverting image to quay.io/invidious/invidious:2024.10.30-2e3a7ad, then force refresh the page in the browser's tab work just fine. Except I have again the error related to YouTube:

Youtube API returned error 400 with message:
"Request contains an invalid argument."
syeopite commented 2 weeks ago

Okay that's strange. I'm assuming the culprit is likely #5034

The updated version of crystal-db we're using seems to have added more places where DB::MappingException is rasied whereas it might've just been silently ignored in the past the actual problem is here https://github.com/iv-org/invidious/issues/5067#issuecomment-2465959249

Thanks for the report! Apologies about my haste in closing the issue

krim404 commented 2 weeks ago

Can confirm, i have a similar issue:

Title: `Invalid location name: Etc/UTC
  deserializing Invidious::User#updated (DB::MappingException)`
Date: `2024-11-09T00:33:04Z`
Route: `/preferences?referer=`
Version: `2024.11.09-b04c1a3 @ (HEAD detached at b04c1a3)`

Invalid location name: Etc/UTC
  deserializing Invidious::User#updated (DB::MappingException)
  from lib/db/src/db/serializable.cr:105:7 in 'initialize:__set_for_db_serializable'
  from src/invidious/user/user.cr:4:3 in 'new'
  from lib/db/src/db/result_set.cr:79:7 in 'read'
  from lib/db/src/db/query_methods.cr:128:9 in 'query_one:as'
  from src/invidious/database/users.cr:207:12 in 'select!:email'
  from src/invidious/routes/before_all.cr:84:16 in 'handle'
  from src/invidious.cr:211:3 in '->'
  from lib/kemal/src/kemal/filter_handler.cr:82:62 in '->'
  from lib/kemal/src/kemal/filter_handler.cr:86:16 in 'call'
  from lib/kemal/src/kemal/filter_handler.cr:58:23 in 'call_block_for_path_type'
  from lib/kemal/src/kemal/filter_handler.cr:16:7 in 'call'
  from /usr/lib/crystal/core/http/server/handler.cr:30:7 in 'call_next'
  from src/invidious/helpers/handlers.cr:157:5 in 'call'
  from /usr/lib/crystal/core/http/server/handler.cr:30:7 in 'call_next'
  from src/invidious/helpers/handlers.cr:94:12 in 'call'
  from /usr/lib/crystal/core/http/server/handler.cr:30:7 in 'call_next'
  from src/invidious/helpers/handlers.cr:146:5 in 'call'
  from /usr/lib/crystal/core/http/server/handler.cr:30:7 in 'call_next'
  from src/invidious/helpers/handlers.cr:70:5 in 'call'
  from /usr/lib/crystal/core/http/server/handler.cr:30:7 in 'call_next'
  from src/ext/kemal_static_file_handler.cr:162:16 in 'call'
  from /usr/lib/crystal/core/http/server/handler.cr:30:7 in 'call_next'
  from lib/kemal/src/kemal/exception_handler.cr:8:7 in 'call'
  from /usr/lib/crystal/core/http/server/handler.cr:30:7 in 'call_next'
  from src/invidious/helpers/logger.cr:21:35 in 'call'
  from /usr/lib/crystal/core/http/server/handler.cr:30:7 in 'call_next'
  from lib/kemal/src/kemal/init_handler.cr:12:7 in 'call'
  from /usr/lib/crystal/core/http/server/request_processor.cr:51:11 in 'process'
  from /usr/lib/crystal/core/http/server.cr:521:5 in 'handle_client'
  from /usr/lib/crystal/core/http/server.cr:451:5 in '->'
  from /usr/lib/crystal/core/fiber.cr:146:11 in 'run'
  from /usr/lib/crystal/core/fiber.cr:98:34 in '->'
  from ???
Caused by: Invalid location name: Etc/UTC (Time::Location::InvalidLocationNameError)
  from /usr/lib/crystal/core/time/location/loader.cr:22 in 'load'
  from lib/pg/src/pg/connection.cr:53:26 in '->'
  from /usr/lib/crystal/core/hash.cr:1173:15 in '[]'
  from lib/pg/src/pg/connection.cr:63:9 in 'time_zone'
  from lib/pg/src/pg/decoder.cr:428:19 in 'decode'
  from lib/pg/src/pg/result_set.cr:91:7 in 'read'
  from lib/db/src/db/result_set.cr:85:15 in 'read'
  from lib/db/src/db/serializable.cr:105:7 in 'initialize:__set_for_db_serializable'
  from src/invidious/user/user.cr:4:3 in 'new'
  from lib/db/src/db/result_set.cr:79:7 in 'read'
  from lib/db/src/db/query_methods.cr:128:9 in 'query_one:as'
  from src/invidious/database/users.cr:207:12 in 'select!:email'
  from src/invidious/routes/before_all.cr:84:16 in 'handle'
  from src/invidious.cr:211:3 in '->'
  from lib/kemal/src/kemal/filter_handler.cr:82:62 in '->'
  from lib/kemal/src/kemal/filter_handler.cr:86:16 in 'call'
  from lib/kemal/src/kemal/filter_handler.cr:58:23 in 'call_block_for_path_type'
  from lib/kemal/src/kemal/filter_handler.cr:16:7 in 'call'
  from /usr/lib/crystal/core/http/server/handler.cr:30:7 in 'call_next'
  from src/invidious/helpers/handlers.cr:157:5 in 'call'
  from /usr/lib/crystal/core/http/server/handler.cr:30:7 in 'call_next'
  from src/invidious/helpers/handlers.cr:94:12 in 'call'
  from /usr/lib/crystal/core/http/server/handler.cr:30:7 in 'call_next'
  from src/invidious/helpers/handlers.cr:146:5 in 'call'
  from /usr/lib/crystal/core/http/server/handler.cr:30:7 in 'call_next'
  from src/invidious/helpers/handlers.cr:70:5 in 'call'
  from /usr/lib/crystal/core/http/server/handler.cr:30:7 in 'call_next'
  from src/ext/kemal_static_file_handler.cr:162:16 in 'call'
  from /usr/lib/crystal/core/http/server/handler.cr:30:7 in 'call_next'
  from lib/kemal/src/kemal/exception_handler.cr:8:7 in 'call'
  from /usr/lib/crystal/core/http/server/handler.cr:30:7 in 'call_next'
  from src/invidious/helpers/logger.cr:21:35 in 'call'
  from /usr/lib/crystal/core/http/server/handler.cr:30:7 in 'call_next'
  from lib/kemal/src/kemal/init_handler.cr:12:7 in 'call'
  from /usr/lib/crystal/core/http/server/request_processor.cr:51:11 in 'process'
  from /usr/lib/crystal/core/http/server.cr:521:5 in 'handle_client'
  from /usr/lib/crystal/core/http/server.cr:451:5 in '->'
  from /usr/lib/crystal/core/fiber.cr:146:11 in 'run'
  from /usr/lib/crystal/core/fiber.cr:98:34 in '->'
  from ???
krim404 commented 2 weeks ago

i can confirm: reverting https://github.com/iv-org/invidious/pull/5034 fixes this issue.

syeopite commented 2 weeks ago

Version v0.27.0 of the pg dependency began parsing the timezone of postgres columns with a type of TIMESTAMPTZ

And for some reason Crystal isn't able to parse the timezone provided

syeopite commented 2 weeks ago

Please let me know if this patch fixes the problem!

diff --git a/docker/Dockerfile b/docker/Dockerfile
index 3d9323fd..ac0eaa79 100644
--- a/docker/Dockerfile
+++ b/docker/Dockerfile
@@ -1,6 +1,6 @@
 FROM crystallang/crystal:1.12.1-alpine AS builder

-RUN apk add --no-cache sqlite-static yaml-static
+RUN apk add --no-cache sqlite-static yaml-static tzdata

 ARG release

diff --git a/docker/Dockerfile.arm64 b/docker/Dockerfile.arm64
index f054b326..ef47948a 100644
--- a/docker/Dockerfile.arm64
+++ b/docker/Dockerfile.arm64
@@ -1,5 +1,5 @@
 FROM alpine:3.19 AS builder
-RUN apk add --no-cache 'crystal=1.10.1-r0' shards sqlite-static yaml-static yaml-dev libxml2-static zlib-static openssl-libs-static openssl-dev musl-dev xz-static
+RUN apk add --no-cache 'crystal=1.10.1-r0' shards sqlite-static yaml-static yaml-dev libxml2-static zlib-static openssl-libs-static openssl-dev musl-dev xz-static tzdata

 ARG release
krim404 commented 2 weeks ago

(cross)compiling right now, will report in a few minutes edit: no. adding tzdata is not fixing it.

RoiArthurB commented 2 weeks ago

Edit by SamantazFox: This problem is https://github.com/iv-org/invidious/issues/5021 and is not related to the problem reported above.

Update on my side, the issue also happens on quay.io/invidious/invidious:2024.10.30-2e3a7ad for me...

invidious-1       | 2024-11-09 02:07:20 UTC [error] YoutubeAPI: Got error 400 when requesting /youtubei/v1/browse
invidious-1       | 2024-11-09 02:07:20 UTC [error] YoutubeAPI: Request contains an invalid argument.
invidious-1       | 2024-11-09 02:07:20 UTC [info] YoutubeAPI: POST data was: {"context" => {"client" => {"hl" => "en", "gl" => "US", "clientName" => "WEB", "clientVersion" => "2.20240814.00.00", "clientScreen" => "WATCH_FULL_SCREEN", "osName" => "Windows", "osVersion" => "10.0", "platform" => "DESKTOP", "visitorData" => "CgtWbmgwWWlxWUdCQSiQyLC2BjIKCgJTRxIEGgAgGg%3D%3D"}}, "continuation" => "4qmFsgKvARIYVUMxb1JUNjUwRVhZOHFDSnJZdDZBQ3hRGmQ4Z1pJR2taNlJBb1lDaFpGWjBsSlFVTm5lVTFCUlRSSWEyZENWVUZCSlRORUVpWUtKREF3TURBd01EQXdMVEF3TURBdE1EQXdNQzB3TURBd0xUQXdNREF3TURBd01EQXdNQmdCmgIsYnJvd3NlLWZlZWRVQzFvUlQ2NTBFWFk4cUNKcll0NkFDeFF2aWRlb3MxMDI%3D"}
invidious-1       | 2024-11-09 02:07:20 UTC [error] RefreshChannelsJob: UC1oRT650EXY8qCJrYt6ACxQ : Could not extract JSON. Youtube API returned error 400 with message:<br>"Request contains an invalid argument."
invidious-1       | 2024-11-09 02:07:20 UTC [error] RefreshChannelsJob: UC1oRT650EXY8qCJrYt6ACxQ fiber : backing off for 00:16:00s

EDIT: But 2024.11.08-b173d4a does work just fine now... 🤪

shiny-comic commented 2 weeks ago

The error from crystal seems fixed since version 1.12.0. https://github.com/crystal-lang/crystal/pull/14185

So I built the image with this diff patch and can confirm the error is gone.

diff --git a/docker/Dockerfile.arm64 b/docker/Dockerfile.arm64
index f054b326..3e3bc11e 100644
--- a/docker/Dockerfile.arm64
+++ b/docker/Dockerfile.arm64
@@ -1,5 +1,5 @@
-FROM alpine:3.19 AS builder
-RUN apk add --no-cache 'crystal=1.10.1-r0' shards sqlite-static yaml-static yaml-dev libxml2-static zlib-static openssl-libs-static openssl-dev musl-dev xz-static
+FROM alpine:3.20 AS builder
+RUN apk add --no-cache 'crystal=1.12.2-r0' shards sqlite-static yaml-static yaml-dev libxml2-static zlib-static openssl-libs-static openssl-dev musl-dev xz-static

 ARG release

@@ -32,7 +32,7 @@ RUN if [[ "${release}" == 1 ]] ; then \
         --link-flags "-lxml2 -llzma"; \
     fi

-FROM alpine:3.18
+FROM alpine:3.20
 RUN apk add --no-cache rsvg-convert ttf-opensans tini
 WORKDIR /invidious
 RUN addgroup -g 1000 -S invidious && \

(maybe tzdata is not needed)

EDIT: Sorry this is not able to watch video

EDIT2 : For someone having "Please sign in" error when trying to watch videos, you need to remove visitor_data and po_token from INVIDIOUS_CONFIG

syeopite commented 2 weeks ago

From what I understand the tzdata package should allow Crystal to understand etc/utc regardless of the Crystal version.

SamantazFox commented 2 weeks ago

I understand that Etc/UTC was a problem. But I'm concerned about the database returning Europe/Paris in OP's case. Invidious should always work with UTC times, they're (or at least should) never localized, until used.

Edit: We might have a culprit: https://github.com/iv-org/invidious/blob/b173d4acf21563d47d26718eca7932878fb424e6/src/invidious/yt_backend/extractors.cr#L76

Edit2: Actually, more likely these two, given OP's error message: https://github.com/iv-org/invidious/blob/b173d4acf21563d47d26718eca7932878fb424e6/src/invidious/database/users.cr#L19-L23 https://github.com/iv-org/invidious/blob/b173d4acf21563d47d26718eca7932878fb424e6/src/invidious/database/users.cr#L143-L151