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

wiljateiwaz · 2024-11-08T23:57:17Z

Describe the bug
I updated my instance after reading this PR #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("")}

The text was updated successfully, but these errors were encountered:

syeopite · 2024-11-09T00:00:20Z

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 · 2024-11-09T00:10:20Z

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 · 2024-11-09T00:12:55Z

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 · 2024-11-09T00:25:38Z

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 #5067 (comment)

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

krim404 · 2024-11-09T00:34:26Z

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 · 2024-11-09T00:54:16Z

i can confirm: reverting #5034 fixes this issue.

syeopite · 2024-11-09T01:07:09Z

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 · 2024-11-09T01:29:31Z

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 · 2024-11-09T01:41:05Z

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

shiny-comic · 2024-11-09T08:45:06Z

The error from crystal seems fixed since version 1.12.0.
crystal-lang/crystal#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 · 2024-11-09T09:38:56Z

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

SamantazFox · 2024-11-09T15:23:56Z

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:

invidious/src/invidious/yt_backend/extractors.cr

Line 76 in b173d4a

    
           published = item_contents.dig?("publishedTimeText", "simpleText").try { |t| decode_date(t.as_s) } || Time.local

Edit2: Actually, more likely these two, given OP's error message:

invidious/src/invidious/database/users.cr

Lines 19 to 23 in b173d4a

    
               if update_on_conflict 
        
                 request += <<-SQL 
        
                   ON CONFLICT (email) DO UPDATE 
        
                   SET updated = $1, subscriptions = $3 
        
                 SQL

invidious/src/invidious/database/users.cr

Lines 143 to 151 in b173d4a

    
             def clear_notifications(user : User) 
        
               request = <<-SQL 
        
                 UPDATE users 
        
                 SET notifications = '{}', updated = now() 
        
                 WHERE email = $1 
        
               SQL 
        
               PG_DB.exec(request, user.email) 
        
             end

wiljateiwaz added the bug Something isn't working label Nov 8, 2024

wiljateiwaz changed the title ~~[Bug]~~ [Bug] Invalid location name Nov 8, 2024

syeopite closed this as completed Nov 9, 2024

syeopite added question Further information is requested and removed bug Something isn't working labels Nov 9, 2024

syeopite reopened this Nov 9, 2024

syeopite added bug Something isn't working module:account Preferences & account management and removed question Further information is requested labels Nov 9, 2024

syeopite changed the title ~~[Bug] Invalid location name~~ [Bug] DB::MappingException with updated property of Invidious::User Nov 9, 2024

This comment was marked as off-topic.

Sign in to view

SamantazFox added the type:database Database issue label Nov 9, 2024

SamantazFox mentioned this issue Nov 9, 2024

Docker: Install tzdata in Dockerfile #5070

Merged

SamantazFox closed this as completed in #5070 Nov 10, 2024

wiljateiwaz mentioned this issue Nov 10, 2024

[Bug] The media could not be loaded, either because [...] #5077

Closed

hughobrien mentioned this issue Nov 12, 2024

invidious: 2.20240825.2 -> 2.20241110.0 NixOS/nixpkgs#355279

Merged

13 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

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

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

wiljateiwaz commented Nov 8, 2024

syeopite commented Nov 9, 2024

wiljateiwaz commented Nov 9, 2024

wiljateiwaz commented Nov 9, 2024

syeopite commented Nov 9, 2024 •

edited

Loading

krim404 commented Nov 9, 2024 •

edited

Loading

krim404 commented Nov 9, 2024

syeopite commented Nov 9, 2024 •

edited

Loading

syeopite commented Nov 9, 2024

krim404 commented Nov 9, 2024 •

edited

Loading

This comment was marked as off-topic.

shiny-comic commented Nov 9, 2024 •

edited

Loading

syeopite commented Nov 9, 2024 •

edited

Loading

SamantazFox commented Nov 9, 2024 •

edited

Loading

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

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

Comments

wiljateiwaz commented Nov 8, 2024

syeopite commented Nov 9, 2024

wiljateiwaz commented Nov 9, 2024

wiljateiwaz commented Nov 9, 2024

syeopite commented Nov 9, 2024 • edited Loading

krim404 commented Nov 9, 2024 • edited Loading

krim404 commented Nov 9, 2024

syeopite commented Nov 9, 2024 • edited Loading

syeopite commented Nov 9, 2024

krim404 commented Nov 9, 2024 • edited Loading

This comment was marked as off-topic.

shiny-comic commented Nov 9, 2024 • edited Loading

syeopite commented Nov 9, 2024 • edited Loading

SamantazFox commented Nov 9, 2024 • edited Loading

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

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

syeopite commented Nov 9, 2024 •

edited

Loading

krim404 commented Nov 9, 2024 •

edited

Loading

syeopite commented Nov 9, 2024 •

edited

Loading

krim404 commented Nov 9, 2024 •

edited

Loading

shiny-comic commented Nov 9, 2024 •

edited

Loading

syeopite commented Nov 9, 2024 •

edited

Loading

SamantazFox commented Nov 9, 2024 •

edited

Loading