Freika
Import Job (photoprism) fails
OS & Hardware Synology NAS
Version 0.25.4
Describe the bug I imported photos from photoprism before - it worked. After upgrading the dockers from both the import job fails without details
To Reproduce Steps to reproduce the behavior: Create a new import job to import photos from photoprism
Expected behavior A clear and concise description of what you expected to happen.
Screenshots If applicable, add screenshots to help explain your problem.
Logs
If applicable, add logs from containers dawarich_app and dawarich_sidekiq to help explain your problem.
dawarich_app:
I, [2025-04-19T16:22:17.074283 #119] INFO -- : {"method":null,"path":null,"format":null,"params":null,"controller":"ImportsChannel","action":"unsubscribe","status":200,"allocations":21,"duration":0.07}
I, [2025-04-19T16:22:17.075181 #119] INFO -- : {"method":null,"path":null,"format":null,"params":{},"controller":"ApplicationCable::Connection","action":"disconnect","status":200,"allocations":185,"duration":7.31}
D, [2025-04-19T16:22:17.598944 #119] DEBUG -- : User Load (0.7ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 ORDER BY "users"."id" ASC LIMIT $2 [["id", 1], ["LIMIT", 1]]
D, [2025-04-19T16:22:17.599886 #119] DEBUG -- : ↳ app/channels/application_cable/connection.rb:14:in 'ApplicationCable::Connection#find_verified_user'
I, [2025-04-19T16:22:17.604318 #119] INFO -- : {"method":null,"path":null,"format":null,"params":{},"controller":"ApplicationCable::Connection","action":"connect","status":200,"allocations":1069,"duration":8.65}
I, [2025-04-19T16:22:17.705693 #119] INFO -- : {"method":null,"path":null,"format":null,"params":null,"controller":"NotificationsChannel","action":"subscribe","status":200,"allocations":97,"duration":61.09}
I, [2025-04-19T16:22:17.740695 #119] INFO -- : {"method":null,"path":null,"format":null,"params":null,"controller":"PointsChannel","action":"subscribe","status":200,"allocations":97,"duration":17.62}
I, [2025-04-19T16:22:17.745221 #119] INFO -- : {"method":null,"path":null,"format":null,"params":null,"controller":"ImportsChannel","action":"subscribe","status":200,"allocations":113,"duration":3.47}
D, [2025-04-19T16:22:18.179738 #119] DEBUG -- : User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."api_key" IS NULL LIMIT $1 [["LIMIT", 1]]
D, [2025-04-19T16:22:18.180462 #119] DEBUG -- : ↳ app/controllers/api_controller.rb:22:in 'ApiController#current_api_user'
I, [2025-04-19T16:22:18.181215 #119] INFO -- : {"method":"GET","path":"/api/v1/health","format":"/","controller":"Api::V1::HealthController","action":"index","status":200,"allocations":897,"duration":3.09,"view":0.27,"db":0.52}
D, [2025-04-19T16:22:18.339305 #119] DEBUG -- : User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 ORDER BY "users"."id" ASC LIMIT $2 [["id", 1], ["LIMIT", 1]]
D, [2025-04-19T16:22:18.340141 #119] DEBUG -- : ↳ app/controllers/application_controller.rb:11:in 'ApplicationController#unread_notifications'
D, [2025-04-19T16:22:18.346513 #119] DEBUG -- : Import Load (1.1ms) SELECT "imports".* FROM "imports" WHERE "imports"."id" = $1 LIMIT $2 [["id", 13], ["LIMIT", 1]]
D, [2025-04-19T16:22:18.348218 #119] DEBUG -- : ↳ app/controllers/imports_controller.rb:57:in 'ImportsController#set_import'
D, [2025-04-19T16:22:18.350649 #119] DEBUG -- : Rendering layout layouts/application.html.erb
D, [2025-04-19T16:22:18.350786 #119] DEBUG -- : Rendering imports/show.html.erb within layouts/application
D, [2025-04-19T16:22:18.561198 #119] DEBUG -- : Notification Load (118.4ms) SELECT "notifications".* FROM "notifications" WHERE "notifications"."user_id" = $1 AND "notifications"."read_at" IS NULL ORDER BY "notifications"."created_at" DESC [["user_id", 1]]
D, [2025-04-19T16:22:18.562164 #119] DEBUG -- : ↳ app/views/shared/_navbar.html.erb:93
I, [2025-04-19T16:22:18.685240 #119] INFO -- : {"method":"GET","path":"/imports/13","format":"html","controller":"ImportsController","action":"show","status":200,"allocations":28615,"duration":347.7,"view":217.52,"db":119.92}
D, [2025-04-19T16:22:19.791026 #119] DEBUG -- : User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 ORDER BY "users"."id" ASC LIMIT $2 [["id", 1], ["LIMIT", 1]]
D, [2025-04-19T16:22:19.791763 #119] DEBUG -- : ↳ app/controllers/application_controller.rb:11:in 'ApplicationController#unread_notifications'
D, [2025-04-19T16:22:19.876517 #119] DEBUG -- : Rendering layout layouts/application.html.erb
D, [2025-04-19T16:22:19.876694 #119] DEBUG -- : Rendering imports/index.html.erb within layouts/application
D, [2025-04-19T16:22:19.878779 #119] DEBUG -- : Import Exists? (0.7ms) SELECT 1 AS one FROM "imports" WHERE "imports"."user_id" = $1 LIMIT $2 OFFSET $3 [["user_id", 1], ["LIMIT", 1], ["OFFSET", 0]]
D, [2025-04-19T16:22:19.879656 #119] DEBUG -- : ↳ app/views/imports/index.html.erb:21
D, [2025-04-19T16:22:19.882367 #119] DEBUG -- : Import Count (0.4ms) SELECT COUNT(*) FROM "imports" WHERE "imports"."user_id" = $1 [["user_id", 1]]
D, [2025-04-19T16:22:19.883077 #119] DEBUG -- : ↳ app/views/imports/index.html.erb:35
D, [2025-04-19T16:22:19.884181 #119] DEBUG -- : Import Load (0.3ms) SELECT "imports"."id", "imports"."name", "imports"."source", "imports"."created_at", "imports"."processed" FROM "imports" WHERE "imports"."user_id" = $1 ORDER BY "imports"."created_at" DESC LIMIT $2 OFFSET $3 [["user_id", 1], ["LIMIT", 25], ["OFFSET", 0]]
D, [2025-04-19T16:22:19.885009 #119] DEBUG -- : ↳ app/views/imports/index.html.erb:53
D, [2025-04-19T16:22:19.887071 #119] DEBUG -- : Point Count (0.6ms) SELECT COUNT(*) FROM "points" WHERE "points"."import_id" = $1 AND "points"."reverse_geocoded_at" IS NOT NULL [["import_id", 13]]
D, [2025-04-19T16:22:19.887733 #119] DEBUG -- : ↳ app/models/import.rb:22:in 'Import#reverse_geocoded_points_count'
D, [2025-04-19T16:22:20.030557 #119] DEBUG -- : Notification Load (73.1ms) SELECT "notifications".* FROM "notifications" WHERE "notifications"."user_id" = $1 AND "notifications"."read_at" IS NULL ORDER BY "notifications"."created_at" DESC [["user_id", 1]]
D, [2025-04-19T16:22:20.031374 #119] DEBUG -- : ↳ app/views/shared/_navbar.html.erb:93
I, [2025-04-19T16:22:20.178962 #119] INFO -- : {"method":"GET","path":"/imports","format":"html","controller":"ImportsController","action":"index","status":200,"allocations":30863,"duration":390.44,"view":227.56,"db":75.58}
D, [2025-04-19T16:22:21.475527 #113] DEBUG -- : User Load (2.9ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 ORDER BY "users"."id" ASC LIMIT $2 [["id", 1], ["LIMIT", 1]]
D, [2025-04-19T16:22:21.482266 #113] DEBUG -- : ↳ app/controllers/application_controller.rb:11:in 'ApplicationController#unread_notifications'
D, [2025-04-19T16:22:21.540352 #113] DEBUG -- : Import Load (4.7ms) SELECT "imports".* FROM "imports" WHERE "imports"."id" = $1 LIMIT $2 [["id", 13], ["LIMIT", 1]]
D, [2025-04-19T16:22:21.542765 #113] DEBUG -- : ↳ app/controllers/imports_controller.rb:57:in 'ImportsController#set_import'
D, [2025-04-19T16:22:21.606246 #113] DEBUG -- : TRANSACTION (3.5ms) BEGIN
D, [2025-04-19T16:22:21.617324 #113] DEBUG -- : ↳ app/services/imports/destroy.rb:12:in 'Imports::Destroy#call'
D, [2025-04-19T16:22:21.623270 #113] DEBUG -- : Point Load (23.7ms) SELECT "points".* FROM "points" WHERE "points"."import_id" = $1 [["import_id", 13]]
D, [2025-04-19T16:22:21.626855 #113] DEBUG -- : ↳ app/services/imports/destroy.rb:12:in 'Imports::Destroy#call'
D, [2025-04-19T16:22:21.693469 #113] DEBUG -- : ActiveStorage::Attachment Load (1.2ms) SELECT "active_storage_attachments".* FROM "active_storage_attachments" WHERE "active_storage_attachments"."record_id" = $1 AND "active_storage_attachments"."record_type" = $2 AND "active_storage_attachments"."name" = $3 LIMIT $4 [["record_id", 13], ["record_type", "Import"], ["name", "file"], ["LIMIT", 1]]
D, [2025-04-19T16:22:21.696757 #113] DEBUG -- : ↳ app/services/imports/destroy.rb:12:in 'Imports::Destroy#call'
D, [2025-04-19T16:22:21.717346 #113] DEBUG -- : ActiveStorage::Attachment Destroy (8.8ms) DELETE FROM "active_storage_attachments" WHERE "active_storage_attachments"."id" = $1 [["id", 6]]
D, [2025-04-19T16:22:21.722718 #113] DEBUG -- : ↳ app/services/imports/destroy.rb:12:in 'Imports::Destroy#call'
D, [2025-04-19T16:22:21.750584 #113] DEBUG -- : Import Destroy (0.5ms) DELETE FROM "imports" WHERE "imports"."id" = $1 [["id", 13]]
D, [2025-04-19T16:22:21.752074 #113] DEBUG -- : ↳ app/services/imports/destroy.rb:12:in 'Imports::Destroy#call'
D, [2025-04-19T16:22:21.766995 #113] DEBUG -- : TRANSACTION (10.8ms) COMMIT
D, [2025-04-19T16:22:21.768682 #113] DEBUG -- : ↳ app/services/imports/destroy.rb:12:in 'Imports::Destroy#call'
D, [2025-04-19T16:22:21.799543 #113] DEBUG -- : ActiveStorage::Blob Load (1.0ms) SELECT "active_storage_blobs".* FROM "active_storage_blobs" WHERE "active_storage_blobs"."id" = $1 LIMIT $2 [["id", 6], ["LIMIT", 1]]
D, [2025-04-19T16:22:21.802413 #113] DEBUG -- : ↳ app/models/import.rb:43:in 'Import#remove_attached_file'
I, [2025-04-19T16:22:21.838689 #113] INFO -- : Enqueued ActiveStorage::PurgeJob (Job ID: be17b48e-7294-41c2-8049-ed8d6af2a11a) to Sidekiq(default) with arguments: #<GlobalID:0x00007f1ef79801d0 @uri=#<URI::GID gid://dawarich/ActiveStorage::Blob/6>>
I, [2025-04-19T16:22:21.846377 #113] INFO -- : ↳ app/models/import.rb:43:in 'Import#remove_attached_file'
I, [2025-04-19T16:22:21.852710 #113] INFO -- : Enqueued ActiveStorage::PurgeJob (Job ID: c34bfcdd-d6ee-49ba-8692-58a279f06741) to Sidekiq(default) with arguments: #<GlobalID:0x00007f1ef79fe080 @uri=#<URI::GID gid://dawarich/ActiveStorage::Blob/6>>
I, [2025-04-19T16:22:21.856387 #113] INFO -- : ↳ app/services/imports/destroy.rb:12:in 'Imports::Destroy#call'
D, [2025-04-19T16:22:21.929073 #113] DEBUG -- : Stat Maximum (1.1ms) SELECT MAX("stats"."updated_at") FROM "stats" WHERE "stats"."user_id" = $1 [["user_id", 1]]
D, [2025-04-19T16:22:21.931421 #113] DEBUG -- : ↳ app/services/stats/bulk_calculator.rb:20:in 'Stats::BulkCalculator#fetch_timestamps'
D, [2025-04-19T16:22:21.951478 #113] DEBUG -- : Point Pluck (1.9ms) SELECT "points"."timestamp" FROM "points" WHERE "points"."user_id" = $1 AND "points"."timestamp" BETWEEN $2 AND $3 [["user_id", 1], ["timestamp", 1745079226], ["timestamp", 1745079741]]
D, [2025-04-19T16:22:21.952883 #113] DEBUG -- : ↳ app/services/stats/bulk_calculator.rb:24:in 'Stats::BulkCalculator#fetch_timestamps'
I, [2025-04-19T16:22:21.962754 #113] INFO -- : {"method":"DELETE","path":"/imports/13","format":"turbo_stream","controller":"ImportsController","action":"destroy","status":303,"allocations":9014,"duration":513.57,"view":0.0,"db":60.0,"location":"http://dawarich.happy-pc.ch/imports"}
D, [2025-04-19T16:22:22.066341 #119] DEBUG -- : User Load (0.5ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 ORDER BY "users"."id" ASC LIMIT $2 [["id", 1], ["LIMIT", 1]]
D, [2025-04-19T16:22:22.067139 #119] DEBUG -- : ↳ app/controllers/application_controller.rb:11:in 'ApplicationController#unread_notifications'
D, [2025-04-19T16:22:22.068987 #119] DEBUG -- : Rendering layout layouts/application.html.erb
D, [2025-04-19T16:22:22.069075 #119] DEBUG -- : Rendering imports/index.html.erb within layouts/application
D, [2025-04-19T16:22:22.070702 #119] DEBUG -- : Import Exists? (0.5ms) SELECT 1 AS one FROM "imports" WHERE "imports"."user_id" = $1 LIMIT $2 OFFSET $3 [["user_id", 1], ["LIMIT", 1], ["OFFSET", 0]]
D, [2025-04-19T16:22:22.071280 #119] DEBUG -- : ↳ app/views/imports/index.html.erb:21
D, [2025-04-19T16:22:22.354475 #119] DEBUG -- : Notification Load (198.6ms) SELECT "notifications".* FROM "notifications" WHERE "notifications"."user_id" = $1 AND "notifications"."read_at" IS NULL ORDER BY "notifications"."created_at" DESC [["user_id", 1]]
D, [2025-04-19T16:22:22.355143 #119] DEBUG -- : ↳ app/views/shared/_navbar.html.erb:93
I, [2025-04-19T16:22:22.557692 #119] INFO -- : {"method":"GET","path":"/imports","format":"turbo_stream","controller":"ImportsController","action":"index","status":200,"allocations":28701,"duration":493.51,"view":289.71,"db":199.58}
D, [2025-04-19T16:22:25.373891 #113] DEBUG -- : User Load (0.6ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 ORDER BY "users"."id" ASC LIMIT $2 [["id", 1], ["LIMIT", 1]]
D, [2025-04-19T16:22:25.376679 #113] DEBUG -- : ↳ app/controllers/application_controller.rb:11:in 'ApplicationController#unread_notifications'
I, [2025-04-19T16:22:25.383179 #113] INFO -- : Enqueued EnqueueBackgroundJob (Job ID: e2e6847a-0e5c-4a47-98bb-11f650169c74) to Sidekiq(reverse_geocoding) with arguments: "start_photoprism_import", 1
I, [2025-04-19T16:22:25.385024 #113] INFO -- : ↳ app/controllers/settings/background_jobs_controller.rb:14:in 'Settings::BackgroundJobsController#create'
I, [2025-04-19T16:22:25.388200 #113] INFO -- : {"method":"POST","path":"/settings/background_jobs","format":"turbo_stream","controller":"Settings::BackgroundJobsController","action":"create","status":302,"allocations":1723,"duration":18.61,"view":0.0,"db":0.6,"location":"http://dawarich.happy-pc.ch/imports"}
D, [2025-04-19T16:22:25.450819 #119] DEBUG -- : User Load (0.8ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 ORDER BY "users"."id" ASC LIMIT $2 [["id", 1], ["LIMIT", 1]]
D, [2025-04-19T16:22:25.453680 #119] DEBUG -- : ↳ app/controllers/application_controller.rb:11:in 'ApplicationController#unread_notifications'
D, [2025-04-19T16:22:25.481340 #119] DEBUG -- : Rendering layout layouts/application.html.erb
D, [2025-04-19T16:22:25.481777 #119] DEBUG -- : Rendering imports/index.html.erb within layouts/application
D, [2025-04-19T16:22:25.485438 #119] DEBUG -- : Import Exists? (1.0ms) SELECT 1 AS one FROM "imports" WHERE "imports"."user_id" = $1 LIMIT $2 OFFSET $3 [["user_id", 1], ["LIMIT", 1], ["OFFSET", 0]]
D, [2025-04-19T16:22:25.488892 #119] DEBUG -- : ↳ app/views/imports/index.html.erb:21
D, [2025-04-19T16:22:25.974253 #119] DEBUG -- : Notification Load (98.1ms) SELECT "notifications".* FROM "notifications" WHERE "notifications"."user_id" = $1 AND "notifications"."read_at" IS NULL ORDER BY "notifications"."created_at" DESC [["user_id", 1]]
D, [2025-04-19T16:22:25.974986 #119] DEBUG -- : ↳ app/views/shared/_navbar.html.erb:93
I, [2025-04-19T16:22:26.183520 #119] INFO -- : {"method":"GET","path":"/imports","format":"turbo_stream","controller":"ImportsController","action":"index","status":200,"allocations":28918,"duration":736.84,"view":624.03,"db":99.78}
D, [2025-04-19T16:22:29.451895 #119] DEBUG -- : User Load (3.8ms) SELECT "users".* FROM "users" WHERE "users"."api_key" IS NULL LIMIT $1 [["LIMIT", 1]]
D, [2025-04-19T16:22:29.457760 #119] DEBUG -- : ↳ app/controllers/api_controller.rb:22:in 'ApiController#current_api_user'
I, [2025-04-19T16:22:29.459847 #119] INFO -- : {"method":"GET","path":"/api/v1/health","format":"/","controller":"Api::V1::HealthController","action":"index","status":200,"allocations":898,"duration":95.7,"view":1.62,"db":3.77}
D, [2025-04-19T16:22:39.692557 #119] DEBUG -- : User Load (5.5ms) SELECT "users".* FROM "users" WHERE "users"."api_key" IS NULL LIMIT $1 [["LIMIT", 1]]
D, [2025-04-19T16:22:39.693936 #119] DEBUG -- : ↳ app/controllers/api_controller.rb:22:in 'ApiController#current_api_user'
I, [2025-04-19T16:22:39.694789 #119] INFO -- : {"method":"GET","path":"/api/v1/health","format":"/","controller":"Api::V1::HealthController","action":"index","status":200,"allocations":897,"duration":26.73,"view":0.15,"db":5.48}
D, [2025-04-19T16:22:49.964356 #113] DEBUG -- : User Load (5.7ms) SELECT "users".* FROM "users" WHERE "users"."api_key" IS NULL LIMIT $1 [["LIMIT", 1]]
D, [2025-04-19T16:22:49.995013 #113] DEBUG -- : ↳ app/controllers/api_controller.rb:22:in 'ApiController#current_api_user'
I, [2025-04-19T16:22:50.012449 #113] INFO -- : {"method":"GET","path":"/api/v1/health","format":"/","controller":"Api::V1::HealthController","action":"index","status":200,"allocations":897,"duration":155.38,"view":2.91,"db":3.81}
D, [2025-04-19T16:23:00.160429 #119] DEBUG -- : User Load (1.3ms) SELECT "users".* FROM "users" WHERE "users"."api_key" IS NULL LIMIT $1 [["LIMIT", 1]]
D, [2025-04-19T16:23:00.162532 #119] DEBUG -- : ↳ app/controllers/api_controller.rb:22:in 'ApiController#current_api_user'
I, [2025-04-19T16:23:00.163971 #119] INFO -- : {"method":"GET","path":"/api/v1/health","format":"/","controller":"Api::V1::HealthController","action":"index","status":200,"allocations":897,"duration":11.0,"view":0.11,"db":0.51}
D, [2025-04-19T16:23:10.399678 #119] DEBUG -- : User Load (1.5ms) SELECT "users".* FROM "users" WHERE "users"."api_key" IS NULL LIMIT $1 [["LIMIT", 1]]
D, [2025-04-19T16:23:10.402672 #119] DEBUG -- : ↳ app/controllers/api_controller.rb:22:in 'ApiController#current_api_user'
I, [2025-04-19T16:23:10.403875 #119] INFO -- : {"method":"GET","path":"/api/v1/health","format":"/","controller":"Api::V1::HealthController","action":"index","status":200,"allocations":897,"duration":8.78,"view":0.3,"db":1.47}
Sidekiq:
D, [2025-04-19T16:13:45.812937 #7] DEBUG -- : ↳ app/models/concerns/distanceable.rb:62:in 'block in Distanceable::ClassMethods#calculate_distance_for_array'
D, [2025-04-19T16:13:45.813354 #7] DEBUG -- : (0.2ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (9.3388034 46.8334297)"], [nil, "POINT (9.3387519 46.8336512)"]]
D, [2025-04-19T16:13:45.813858 #7] DEBUG -- : ↳ app/models/concerns/distanceable.rb:62:in 'block in Distanceable::ClassMethods#calculate_distance_for_array'
D, [2025-04-19T16:13:45.814325 #7] DEBUG -- : (0.3ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (9.3387519 46.8336512)"], [nil, "POINT (9.3388852 46.8336142)"]]
D, [2025-04-19T16:13:45.814830 #7] DEBUG -- : ↳ app/models/concerns/distanceable.rb:62:in 'block in Distanceable::ClassMethods#calculate_distance_for_array'
D, [2025-04-19T16:13:45.815308 #7] DEBUG -- : (0.3ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (9.3388852 46.8336142)"], [nil, "POINT (9.338767 46.8335745)"]]
D, [2025-04-19T16:13:45.815740 #7] DEBUG -- : ↳ app/models/concerns/distanceable.rb:62:in 'block in Distanceable::ClassMethods#calculate_distance_for_array'
D, [2025-04-19T16:13:45.816174 #7] DEBUG -- : (0.2ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (9.338767 46.8335745)"], [nil, "POINT (9.3386261 46.8335004)"]]
D, [2025-04-19T16:13:45.816679 #7] DEBUG -- : ↳ app/models/concerns/distanceable.rb:62:in 'block in Distanceable::ClassMethods#calculate_distance_for_array'
D, [2025-04-19T16:13:45.817096 #7] DEBUG -- : (0.2ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (9.3386261 46.8335004)"], [nil, "POINT (9.3384657 46.8334037)"]]
D, [2025-04-19T16:13:45.817507 #7] DEBUG -- : ↳ app/models/concerns/distanceable.rb:62:in 'block in Distanceable::ClassMethods#calculate_distance_for_array'
D, [2025-04-19T16:13:45.817986 #7] DEBUG -- : (0.2ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (9.3384657 46.8334037)"], [nil, "POINT (9.3386578 46.8334759)"]]
D, [2025-04-19T16:13:45.819955 #7] DEBUG -- : ↳ app/models/concerns/distanceable.rb:62:in 'block in Distanceable::ClassMethods#calculate_distance_for_array'
D, [2025-04-19T16:13:45.820547 #7] DEBUG -- : (0.3ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (9.3386578 46.8334759)"], [nil, "POINT (9.338852 46.8335533)"]]
D, [2025-04-19T16:13:45.820994 #7] DEBUG -- : ↳ app/models/concerns/distanceable.rb:62:in 'block in Distanceable::ClassMethods#calculate_distance_for_array'
D, [2025-04-19T16:13:45.821487 #7] DEBUG -- : (0.3ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (9.338852 46.8335533)"], [nil, "POINT (9.3386961 46.833536)"]]
D, [2025-04-19T16:13:45.821904 #7] DEBUG -- : ↳ app/models/concerns/distanceable.rb:62:in 'block in Distanceable::ClassMethods#calculate_distance_for_array'
D, [2025-04-19T16:13:45.822441 #7] DEBUG -- : (0.3ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (9.3386961 46.833536)"], [nil, "POINT (9.3388297 46.833525)"]]
D, [2025-04-19T16:13:45.822886 #7] DEBUG -- : ↳ app/models/concerns/distanceable.rb:62:in 'block in Distanceable::ClassMethods#calculate_distance_for_array'
D, [2025-04-19T16:13:45.823352 #7] DEBUG -- : (0.3ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (9.3388297 46.833525)"], [nil, "POINT (9.3389339 46.833662)"]]
D, [2025-04-19T16:13:45.823802 #7] DEBUG -- : ↳ app/models/concerns/distanceable.rb:62:in 'block in Distanceable::ClassMethods#calculate_distance_for_array'
D, [2025-04-19T16:13:45.824263 #7] DEBUG -- : (0.2ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (9.3389339 46.833662)"], [nil, "POINT (9.3388636 46.8335851)"]]
D, [2025-04-19T16:13:45.824744 #7] DEBUG -- : ↳ app/models/concerns/distanceable.rb:62:in 'block in Distanceable::ClassMethods#calculate_distance_for_array'
D, [2025-04-19T16:13:46.360793 #7] DEBUG -- : Point Load (417.9ms) SELECT "points"."id", "points"."battery_status", "points"."ping", "points"."battery", "points"."tracker_id", "points"."topic", "points"."altitude", "points"."longitude", "points"."velocity", "points"."trigger", "points"."bssid", "points"."ssid", "points"."connection", "points"."vertical_accuracy", "points"."accuracy", "points"."timestamp", "points"."latitude", "points"."mode", "points"."inrids", "points"."in_regions", "points"."import_id", "points"."city", "points"."country", "points"."created_at", "points"."updated_at", "points"."user_id", "points"."geodata", "points"."visit_id", "points"."reverse_geocoded_at", "points"."course", "points"."course_accuracy", "points"."external_track_id", "points"."lonlat", "points"."lonlat", "points"."timestamp", "points"."city", "points"."country" FROM "points" WHERE "points"."user_id" = $1 AND "points"."timestamp" BETWEEN $2 AND $3 ORDER BY "points"."timestamp" ASC [["user_id", 1], ["timestamp", 1743465600], ["timestamp", 1745971200]]
D, [2025-04-19T16:13:46.363004 #7] DEBUG -- : ↳ app/services/countries_and_cities.rb:13:in 'Enumerable#reject'
D, [2025-04-19T16:13:46.929509 #7] DEBUG -- : Stat Update (9.7ms) UPDATE "stats" SET "updated_at" = $1, "daily_distance" = $2 WHERE "stats"."id" = $3 [["updated_at", "2025-04-19 16:13:46.918623"], ["daily_distance", "[[1,161.19],[2,192.17],[3,25.06],[4,306.36],[5,148.13],[6,141.24],[7,22.09],[8,92.57],[9,21.39],[10,8.42],[11,189.23],[12,34.76],[13,137.6],[14,187.58],[15,194.28],[16,197.38],[17,383.33],[18,8.51],[19,30.58],[20,0],[21,0],[22,0],[23,0],[24,0],[25,0],[26,0],[27,0],[28,0],[29,0],[30,0]]"], ["id", 28]]
D, [2025-04-19T16:13:46.930311 #7] DEBUG -- : ↳ app/services/stats/calculate_month.rb:38:in 'block in Stats::CalculateMonth#update_month_stats'
D, [2025-04-19T16:13:47.017217 #7] DEBUG -- : TRANSACTION (85.4ms) COMMIT
D, [2025-04-19T16:13:47.017895 #7] DEBUG -- : ↳ app/services/stats/calculate_month.rb:29:in 'Stats::CalculateMonth#update_month_stats'
D, [2025-04-19T16:13:47.018654 #7] DEBUG -- : User Load (0.4ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 LIMIT $2 [["id", 1], ["LIMIT", 1]]
D, [2025-04-19T16:13:47.019148 #7] DEBUG -- : ↳ app/jobs/stats/calculating_job.rb:17:in 'Stats::CalculatingJob#create_stats_updated_notification'
D, [2025-04-19T16:13:47.021114 #7] DEBUG -- : TRANSACTION (0.2ms) BEGIN
D, [2025-04-19T16:13:47.022171 #7] DEBUG -- : ↳ app/services/notifications/create.rb:14:in 'Notifications::Create#call'
D, [2025-04-19T16:13:47.027923 #7] DEBUG -- : Notification Create (6.9ms) INSERT INTO "notifications" ("title", "content", "user_id", "kind", "read_at", "created_at", "updated_at") VALUES ($1, $2, $3, $4, $5, $6, $7) RETURNING "id" [["title", "Stats updated for April of 2025"], ["content", "Stats updated for April of 2025"], ["user_id", 1], ["kind", 0], ["read_at", nil], ["created_at", "2025-04-19 16:13:47.020380"], ["updated_at", "2025-04-19 16:13:47.020380"]]
D, [2025-04-19T16:13:47.028870 #7] DEBUG -- : ↳ app/services/notifications/create.rb:14:in 'Notifications::Create#call'
D, [2025-04-19T16:13:47.055639 #7] DEBUG -- : TRANSACTION (26.4ms) COMMIT
D, [2025-04-19T16:13:47.056391 #7] DEBUG -- : ↳ app/services/notifications/create.rb:14:in 'Notifications::Create#call'
I, [2025-04-19T16:13:47.057825 #7] INFO -- : Performed Stats::CalculatingJob (Job ID: f6bc38ab-d034-408f-9e59-be6bdf4fb49a) from Sidekiq(stats) in 34694.65ms
I, [2025-04-19T16:13:47.058902 #7] INFO -- : done
I, [2025-04-19T16:13:47.742658 #7] INFO -- : start
I, [2025-04-19T16:13:47.766383 #7] INFO -- : Performing EnqueueBackgroundJob (Job ID: 2da178ca-a094-4237-a906-69ff610ca240) from Sidekiq(reverse_geocoding) enqueued at 2025-04-19T16:13:47.740301321Z with arguments: "start_photoprism_import", 1
I, [2025-04-19T16:13:47.768981 #7] INFO -- : Enqueued Import::PhotoprismGeodataJob (Job ID: 09618122-10bb-4915-950a-200d1454e730) to Sidekiq(imports) with arguments: 1
I, [2025-04-19T16:13:47.770136 #7] INFO -- : ↳ app/jobs/enqueue_background_job.rb:11:in 'EnqueueBackgroundJob#perform'
I, [2025-04-19T16:13:47.770448 #7] INFO -- : Performed EnqueueBackgroundJob (Job ID: 2da178ca-a094-4237-a906-69ff610ca240) from Sidekiq(reverse_geocoding) in 4.28ms
I, [2025-04-19T16:13:47.770334 #7] INFO -- : start
I, [2025-04-19T16:13:47.772048 #7] INFO -- : done
I, [2025-04-19T16:13:47.781954 #7] INFO -- : Performing Import::PhotoprismGeodataJob (Job ID: 09618122-10bb-4915-950a-200d1454e730) from Sidekiq(imports) enqueued at 2025-04-19T16:13:47.767774904Z with arguments: 1
D, [2025-04-19T16:13:47.784056 #7] DEBUG -- : User Load (0.6ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 LIMIT $2 [["id", 1], ["LIMIT", 1]]
D, [2025-04-19T16:13:47.784660 #7] DEBUG -- : ↳ app/jobs/import/photoprism_geodata_job.rb:8:in 'Import::PhotoprismGeodataJob#perform'
D, [2025-04-19T16:13:49.082174 #7] DEBUG -- : Flushed 4 metrics
D, [2025-04-19T16:13:50.371305 #7] DEBUG -- : Import Load (7.4ms) SELECT "imports".* FROM "imports" WHERE "imports"."user_id" = $1 AND "imports"."name" = $2 AND "imports"."source" = $3 LIMIT $4 [["user_id", 1], ["name", "photoprism-geodata-roger.heckly@happy-pc.ch-from-2013-07-31-to-2025-04-18.json"], ["source", 7], ["LIMIT", 1]]
D, [2025-04-19T16:13:50.372025 #7] DEBUG -- : ↳ app/services/photoprism/import_geodata.rb:36:in 'Photoprism::ImportGeodata#find_or_create_import'
D, [2025-04-19T16:13:50.431148 #7] DEBUG -- : TRANSACTION (0.3ms) BEGIN
D, [2025-04-19T16:13:50.432461 #7] DEBUG -- : ↳ app/services/photoprism/import_geodata.rb:32:in 'Photoprism::ImportGeodata#create_and_process_import'
D, [2025-04-19T16:13:50.434253 #7] DEBUG -- : Import Create (3.6ms) INSERT INTO "imports" ("name", "user_id", "source", "created_at", "updated_at", "raw_points", "doubles", "processed", "raw_data", "points_count") VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10) RETURNING "id" [["name", "photoprism-geodata-roger.heckly@happy-pc.ch-from-2013-07-31-to-2025-04-18.json"], ["user_id", 1], ["source", 7], ["created_at", "2025-04-19 16:13:50.430133"], ["updated_at", "2025-04-19 16:13:50.430133"], ["raw_points", 0], ["doubles", 0], ["processed", 0], ["raw_data", nil], ["points_count", 0]]
D, [2025-04-19T16:13:50.435091 #7] DEBUG -- : ↳ app/services/photoprism/import_geodata.rb:32:in 'Photoprism::ImportGeodata#create_and_process_import'
D, [2025-04-19T16:13:50.442870 #7] DEBUG -- : ActiveStorage::Blob Load (5.8ms) SELECT "active_storage_blobs".* FROM "active_storage_blobs" INNER JOIN "active_storage_attachments" ON "active_storage_blobs"."id" = "active_storage_attachments"."blob_id" WHERE "active_storage_attachments"."record_id" = $1 AND "active_storage_attachments"."record_type" = $2 AND "active_storage_attachments"."name" = $3 LIMIT $4 [["record_id", 13], ["record_type", "Import"], ["name", "file"], ["LIMIT", 1]]
D, [2025-04-19T16:13:50.444233 #7] DEBUG -- : ↳ app/services/photoprism/import_geodata.rb:32:in 'Photoprism::ImportGeodata#create_and_process_import'
D, [2025-04-19T16:13:50.446871 #7] DEBUG -- : ActiveStorage::Attachment Load (0.5ms) SELECT "active_storage_attachments".* FROM "active_storage_attachments" WHERE "active_storage_attachments"."record_id" = $1 AND "active_storage_attachments"."record_type" = $2 AND "active_storage_attachments"."name" = $3 LIMIT $4 [["record_id", 13], ["record_type", "Import"], ["name", "file"], ["LIMIT", 1]]
D, [2025-04-19T16:13:50.447996 #7] DEBUG -- : ↳ app/services/photoprism/import_geodata.rb:32:in 'Photoprism::ImportGeodata#create_and_process_import'
D, [2025-04-19T16:13:50.451271 #7] DEBUG -- : ActiveStorage::Blob Create (1.0ms) INSERT INTO "active_storage_blobs" ("key", "filename", "content_type", "metadata", "service_name", "byte_size", "checksum", "created_at") VALUES ($1, $2, $3, $4, $5, $6, $7, $8) RETURNING "id" [["key", "30653hkb850tv4yds2wewta39qj0"], ["filename", "photoprism-geodata-roger.heckly@happy-pc.ch-from-2013-07-31-to-2025-04-18.json"], ["content_type", "application/json"], ["metadata", "{"identified":true}"], ["service_name", "local"], ["byte_size", 480772], ["checksum", "ei7Ag25MkkRelw8GJL9jaA=="], ["created_at", "2025-04-19 16:13:50.449429"]]
D, [2025-04-19T16:13:50.453173 #7] DEBUG -- : ↳ app/services/photoprism/import_geodata.rb:32:in 'Photoprism::ImportGeodata#create_and_process_import'
D, [2025-04-19T16:13:50.456680 #7] DEBUG -- : ActiveStorage::Attachment Create (1.6ms) INSERT INTO "active_storage_attachments" ("name", "record_type", "record_id", "blob_id", "created_at") VALUES ($1, $2, $3, $4, $5) RETURNING "id" [["name", "file"], ["record_type", "Import"], ["record_id", 13], ["blob_id", 6], ["created_at", "2025-04-19 16:13:50.453855"]]
D, [2025-04-19T16:13:50.459067 #7] DEBUG -- : ↳ app/services/photoprism/import_geodata.rb:32:in 'Photoprism::ImportGeodata#create_and_process_import'
D, [2025-04-19T16:13:50.461339 #7] DEBUG -- : Import Update (0.5ms) UPDATE "imports" SET "updated_at" = $1 WHERE "imports"."id" = $2 [["updated_at", "2025-04-19 16:13:50.459505"], ["id", 13]]
D, [2025-04-19T16:13:50.462218 #7] DEBUG -- : ↳ app/services/photoprism/import_geodata.rb:32:in 'Photoprism::ImportGeodata#create_and_process_import'
D, [2025-04-19T16:13:50.473376 #7] DEBUG -- : TRANSACTION (10.9ms) COMMIT
D, [2025-04-19T16:13:50.475106 #7] DEBUG -- : ↳ app/services/photoprism/import_geodata.rb:32:in 'Photoprism::ImportGeodata#create_and_process_import'
I, [2025-04-19T16:13:50.478272 #7] INFO -- : Disk Storage (2.4ms) Uploaded file to key: 30653hkb850tv4yds2wewta39qj0 (checksum: ei7Ag25MkkRelw8GJL9jaA==)
I, [2025-04-19T16:13:50.479641 #7] INFO -- : Enqueued Import::ProcessJob (Job ID: 1021e615-428c-4664-bf85-3878faecd7ee) to Sidekiq(imports) with arguments: 13
I, [2025-04-19T16:13:50.480057 #7] INFO -- : ↳ app/models/import.rb:9:in 'block in class:Import'
I, [2025-04-19T16:13:50.481885 #7] INFO -- : start
D, [2025-04-19T16:13:50.482044 #7] DEBUG -- : TRANSACTION (0.2ms) BEGIN
D, [2025-04-19T16:13:50.484078 #7] DEBUG -- : ↳ app/services/photoprism/import_geodata.rb:32:in 'Photoprism::ImportGeodata#create_and_process_import'
D, [2025-04-19T16:13:50.484961 #7] DEBUG -- : ActiveStorage::Blob Update (3.1ms) UPDATE "active_storage_blobs" SET "metadata" = $1 WHERE "active_storage_blobs"."id" = $2 [["metadata", "{"identified":true,"analyzed":true}"], ["id", 6]]
D, [2025-04-19T16:13:50.486182 #7] DEBUG -- : ↳ app/services/photoprism/import_geodata.rb:32:in 'Photoprism::ImportGeodata#create_and_process_import'
D, [2025-04-19T16:13:50.489465 #7] DEBUG -- : ActiveStorage::Attachment Load (0.7ms) SELECT "active_storage_attachments".* FROM "active_storage_attachments" WHERE "active_storage_attachments"."blob_id" = $1 [["blob_id", 6]]
D, [2025-04-19T16:13:50.491031 #7] DEBUG -- : ↳ app/services/photoprism/import_geodata.rb:32:in 'Photoprism::ImportGeodata#create_and_process_import'
D, [2025-04-19T16:13:50.493291 #7] DEBUG -- : Import Load (0.6ms) SELECT "imports".* FROM "imports" WHERE "imports"."id" = $1 [["id", 13]]
D, [2025-04-19T16:13:50.494871 #7] DEBUG -- : ↳ app/services/photoprism/import_geodata.rb:32:in 'Photoprism::ImportGeodata#create_and_process_import'
D, [2025-04-19T16:13:50.499525 #7] DEBUG -- : Import Update (0.6ms) UPDATE "imports" SET "updated_at" = $1 WHERE "imports"."id" = $2 [["updated_at", "2025-04-19 16:13:50.498282"], ["id", 13]]
D, [2025-04-19T16:13:50.500842 #7] DEBUG -- : ↳ app/services/photoprism/import_geodata.rb:32:in 'Photoprism::ImportGeodata#create_and_process_import'
I, [2025-04-19T16:13:50.514662 #7] INFO -- : Performing Import::ProcessJob (Job ID: 1021e615-428c-4664-bf85-3878faecd7ee) from Sidekiq(imports) enqueued at 2025-04-19T16:13:50.478508309Z with arguments: 13
D, [2025-04-19T16:13:50.521958 #7] DEBUG -- : TRANSACTION (20.9ms) COMMIT
D, [2025-04-19T16:13:50.522940 #7] DEBUG -- : ↳ app/services/photoprism/import_geodata.rb:32:in 'Photoprism::ImportGeodata#create_and_process_import'
I, [2025-04-19T16:13:50.523332 #7] INFO -- : Performed Import::PhotoprismGeodataJob (Job ID: 09618122-10bb-4915-950a-200d1454e730) from Sidekiq(imports) in 2741.61ms
I, [2025-04-19T16:13:50.524344 #7] INFO -- : done
D, [2025-04-19T16:13:50.526110 #7] DEBUG -- : Import Load (7.6ms) SELECT "imports".* FROM "imports" WHERE "imports"."id" = $1 LIMIT $2 [["id", 13], ["LIMIT", 1]]
D, [2025-04-19T16:13:50.527544 #7] DEBUG -- : ↳ app/jobs/import/process_job.rb:7:in 'Import::ProcessJob#perform'
D, [2025-04-19T16:13:50.532775 #7] DEBUG -- : User Load (1.5ms) SELECT "users".* FROM "users" WHERE "users"."id" = $1 LIMIT $2 [["id", 1], ["LIMIT", 1]]
D, [2025-04-19T16:13:50.533494 #7] DEBUG -- : ↳ app/models/import.rb:18:in 'Import#process!'
D, [2025-04-19T16:13:50.535382 #7] DEBUG -- : TRANSACTION (0.2ms) BEGIN
D, [2025-04-19T16:13:50.536320 #7] DEBUG -- : ↳ app/services/notifications/create.rb:14:in 'Notifications::Create#call'
D, [2025-04-19T16:13:50.539284 #7] DEBUG -- : Notification Create (4.3ms) INSERT INTO "notifications" ("title", "content", "user_id", "kind", "read_at", "created_at", "updated_at") VALUES ($1, $2, $3, $4, $5, $6, $7) RETURNING "id" [["title", "Import failed"], ["content", "Import "photoprism-geodata-roger.heckly@happy-pc.ch-from-2013-07-31-to-2025-04-18.json" failed: undefined method 'each' for nil, stacktrace: /var/app/app/services/photos/import_parser.rb:15:in 'Photos::ImportParser#call'\n/var/app/app/services/imports/create.rb:12:in 'Imports::Create#call'\n/var/app/app/models/import.rb:18:in 'Import#process!'\n/var/app/app/jobs/import/process_job.rb:9:in 'Import::ProcessJob#perform'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activejob-8.0.1/lib/active_job/execution.rb:68:in 'block in ActiveJob::Execution#_perform_job'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/callbacks.rb:120:in 'block in ActiveSupport::Callbacks#run_callbacks'\n/var/app/vendor/bundle/ruby/3.4.0/gems/i18n-1.14.7/lib/i18n.rb:353:in 'I18n::Base#with_locale'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activejob-8.0.1/lib/active_job/translation.rb:9:in 'block (2 levels) in module:Translation'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/callbacks.rb:129:in 'BasicObject#instance_exec'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/callbacks.rb:129:in 'block in ActiveSupport::Callbacks#run_callbacks'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/core_ext/time/zones.rb:65:in 'Time.use_zone'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activejob-8.0.1/lib/active_job/timezones.rb:9:in 'block (2 levels) in module:Timezones'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/callbacks.rb:129:in 'BasicObject#instance_exec'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/callbacks.rb:129:in 'block in ActiveSupport::Callbacks#run_callbacks'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/callbacks.rb:140:in 'ActiveSupport::Callbacks#run_callbacks'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activejob-8.0.1/lib/active_job/execution.rb:67:in 'ActiveJob::Execution#_perform_job'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activejob-8.0.1/lib/active_job/instrumentation.rb:32:in 'ActiveJob::Instrumentation#_perform_job'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activejob-8.0.1/lib/active_job/execution.rb:51:in 'ActiveJob::Execution#perform_now'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activejob-8.0.1/lib/active_job/instrumentation.rb:26:in 'block in ActiveJob::Instrumentation#perform_now'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.1/lib/active_record/railties/job_runtime.rb:13:in 'block in ActiveRecord::Railties::JobRuntime#instrument'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activejob-8.0.1/lib/active_job/instrumentation.rb:40:in 'block in ActiveJob::Instrumentation#instrument'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/notifications.rb:210:in 'block in ActiveSupport::Notifications.instrument'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/notifications/instrumenter.rb:58:in 'ActiveSupport::Notifications::Instrumenter#instrument'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/notifications.rb:210:in 'ActiveSupport::Notifications.instrument'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activejob-8.0.1/lib/active_job/instrumentation.rb:39:in 'ActiveJob::Instrumentation#instrument'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activerecord-8.0.1/lib/active_record/railties/job_runtime.rb:11:in 'ActiveRecord::Railties::JobRuntime#instrument'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activejob-8.0.1/lib/active_job/instrumentation.rb:26:in 'ActiveJob::Instrumentation#perform_now'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activejob-8.0.1/lib/active_job/logging.rb:32:in 'block in ActiveJob::Logging#perform_now'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activejob-8.0.1/lib/active_job/logging.rb:41:in 'ActiveJob::Logging#tag_logger'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activejob-8.0.1/lib/active_job/logging.rb:32:in 'ActiveJob::Logging#perform_now'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sentry-rails-5.23.0/lib/sentry/rails/active_job.rb:8:in 'Sentry::Rails::ActiveJobExtensions#perform_now'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activejob-8.0.1/lib/active_job/execution.rb:29:in 'block in ActiveJob::Execution::ClassMethods#execute'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/callbacks.rb:120:in 'block in ActiveSupport::Callbacks#run_callbacks'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activejob-8.0.1/lib/active_job/railtie.rb:95:in 'block (4 levels) in class:Railtie'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/reloader.rb:77:in 'block in ActiveSupport::Reloader.wrap'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/execution_wrapper.rb:87:in 'ActiveSupport::ExecutionWrapper.wrap'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/reloader.rb:74:in 'ActiveSupport::Reloader.wrap'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activejob-8.0.1/lib/active_job/railtie.rb:94:in 'block (3 levels) in class:Railtie'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/callbacks.rb:129:in 'BasicObject#instance_exec'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/callbacks.rb:129:in 'block in ActiveSupport::Callbacks#run_callbacks'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/callbacks.rb:140:in 'ActiveSupport::Callbacks#run_callbacks'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activejob-8.0.1/lib/active_job/execution.rb:27:in 'ActiveJob::Execution::ClassMethods#execute'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/rails.rb:13:in 'Sidekiq::ActiveJob::Wrapper#perform'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:220:in 'Sidekiq::Processor#execute_job'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:185:in 'block (4 levels) in Sidekiq::Processor#process'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/middleware/chain.rb:180:in 'Sidekiq::Middleware::Chain#traverse'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/middleware/chain.rb:183:in 'block in Sidekiq::Middleware::Chain#traverse'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/job/interrupt_handler.rb:9:in 'Sidekiq::Job::InterruptHandler#call'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/middleware/chain.rb:182:in 'Sidekiq::Middleware::Chain#traverse'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/middleware/chain.rb:183:in 'block in Sidekiq::Middleware::Chain#traverse'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/metrics/tracking.rb:26:in 'Sidekiq::Metrics::ExecutionTracker#track'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/metrics/tracking.rb:134:in 'Sidekiq::Metrics::Middleware#call'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/middleware/chain.rb:182:in 'Sidekiq::Middleware::Chain#traverse'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/middleware/chain.rb:173:in 'Sidekiq::Middleware::Chain#invoke'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:184:in 'block (3 levels) in Sidekiq::Processor#process'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:145:in 'block (6 levels) in Sidekiq::Processor#dispatch'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/job_retry.rb:118:in 'Sidekiq::JobRetry#local'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:144:in 'block (5 levels) in Sidekiq::Processor#dispatch'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/rails.rb:27:in 'block in Sidekiq::Rails::Reloader#call'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/reloader.rb:77:in 'block in ActiveSupport::Reloader.wrap'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/execution_wrapper.rb:91:in 'ActiveSupport::ExecutionWrapper.wrap'\n/var/app/vendor/bundle/ruby/3.4.0/gems/activesupport-8.0.1/lib/active_support/reloader.rb:74:in 'ActiveSupport::Reloader.wrap'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/rails.rb:26:in 'Sidekiq::Rails::Reloader#call'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:139:in 'block (4 levels) in Sidekiq::Processor#dispatch'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:281:in 'Sidekiq::Processor#stats'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:134:in 'block (3 levels) in Sidekiq::Processor#dispatch'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/job_logger.rb:15:in 'Sidekiq::JobLogger#call'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:133:in 'block (2 levels) in Sidekiq::Processor#dispatch'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/job_retry.rb:85:in 'Sidekiq::JobRetry#global'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:132:in 'block in Sidekiq::Processor#dispatch'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/job_logger.rb:40:in 'Sidekiq::JobLogger#prepare'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:131:in 'Sidekiq::Processor#dispatch'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:183:in 'block (2 levels) in Sidekiq::Processor#process'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:182:in 'Thread.handle_interrupt'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:182:in 'block in Sidekiq::Processor#process'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:181:in 'Thread.handle_interrupt'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:181:in 'Sidekiq::Processor#process'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:86:in 'Sidekiq::Processor#process_one'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/processor.rb:76:in 'Sidekiq::Processor#run'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/component.rb:10:in 'Sidekiq::Component#watchdog'\n/var/app/vendor/bundle/ruby/3.4.0/gems/sidekiq-7.3.9/lib/sidekiq/component.rb:19:in 'block in Sidekiq::Component#safe_thread'"], ["user_id", 1], ["kind", 2], ["read_at", nil], ["created_at", "2025-04-19 16:13:50.534324"], ["updated_at", "2025-04-19 16:13:50.534324"]]
D, [2025-04-19T16:13:50.540239 #7] DEBUG -- : ↳ app/services/notifications/create.rb:14:in 'Notifications::Create#call'
D, [2025-04-19T16:13:50.550030 #7] DEBUG -- : TRANSACTION (9.5ms) COMMIT
D, [2025-04-19T16:13:50.550707 #7] DEBUG -- : ↳ app/services/notifications/create.rb:14:in 'Notifications::Create#call'
I, [2025-04-19T16:13:50.551729 #7] INFO -- : Performed Import::ProcessJob (Job ID: 1021e615-428c-4664-bf85-3878faecd7ee) from Sidekiq(imports) in 37.31ms
I, [2025-04-19T16:13:50.553620 #7] INFO -- : done
D, [2025-04-19T16:13:59.085511 #7] DEBUG -- : Flushed 4 metrics
Additional context Add any other context about the problem here.
