Freika
Upgrade 0.24.1 -> 0.25.3 failed: undefined method 'y' for nil
OS & Hardware Raspbian, Raspberry Pi 5
Version 0.25.3
Describe the bug
I upgraded from 0.24.1 (which is working fine) to 0.25.3. While doing so I compared the Docker-Compose.yml files and did not find any differences. After deploying the stack the container dawarich_app took some time to start up, but finally Portainer stated it was running. I logged in, providing my credentials, and ended up in the undefined method 'y' for nil screen observed by many others. This is persistent, reloading the page does not change anything.
I entered the commands stated in the release notes for 0.25.2, rake data_cleanup:remove_duplicate_points, rake points:migrate_to_lonlat and rake users:activate, in Portainer in into the container console of dawarich_app container. That console does not provide a bash shell but allows me to enter a command which will then be executed. Unfortunately I cannot see when the command finished executing because no prompt will be displayed in that console and I did not find a clear screen output indicating that the task had finished. So I waited for half an hour after issuing a command until I disconnected from that Portainer console, and reconnected for executing the next command.
I checked Sidekiq and see that there are only the usual batch of reverse geocoding jobs in the queue. This queue encompasses about 3.000.000 geopoints, number slowly decreasing, since I use photon.komoot.io. So on the Sidekiq page I cannot see anything unusual, but maybe I am looking into the wrong places, because I also did not see anything changing there while executing the commands.
To Reproduce see above
Expected behavior In 0.25.3. I'd expect all required migration to be performed during initial startup, so the normal map page is displayed, not the page indicating an error.
Me also, almost the same scenario. I am running Docker under Debian on Proxmox.
Same here on the synology. I would suggest splitting the conversion into 10 000 point blocks so that the server has a chance to process the data
Will running the following in the console resolve your issues?
puts 'Updating points to use lonlat...'
ActiveRecord::Base.connection.execute('REINDEX TABLE points;')
ActiveRecord::Base.transaction do
ActiveRecord::Base.connection.execute('ALTER TABLE points DISABLE TRIGGER ALL;')
# Update the data
result = ActiveRecord::Base.connection.execute(<<~SQL)
UPDATE points
SET lonlat = ST_SetSRID(ST_MakePoint(longitude, latitude), 4326)::geography
WHERE lonlat IS NULL
AND longitude IS NOT NULL
AND latitude IS NOT NULL;
SQL
ActiveRecord::Base.connection.execute('ALTER TABLE points ENABLE TRIGGER ALL;')
puts "Successfully updated #{result.cmd_tuples} points with lonlat values"
end
ActiveRecord::Base.connection.execute('ANALYZE points;')
Also, I don't think it's necessary to create a separate issue for the problem that was already recognized in multiple other issues, and you have clearly seen it @solderdot72 https://github.com/Freika/dawarich/issues/973
Please refrain from creating duplicated issues. Thank you
@Freika : Sure. Will try to do so. Reason for me creating the ticket was that I've seen plenty of people reporting issues while upgrading to 0.25.0 or 0.25.2, but none following the upgrade path to 0.25.3. But maybe I missed some.
I just did the upgrade to 0.25.3 again, and this time things look different: This time Portainer shows all containers are healthy (in contrast to the 1st attempt) and Sidekiq shows a Job DataMigrations::MigratePointsLatlonJob being processed (in contrast to the 2nd attempt). The data migration job is now executing for nearly an hour. I assume this migration will take some time with some 4M geopoints on a Raspi.
I will check back tomorrow on the status of the data migration and write an update here.
I have no idea what went wrong in the previous 2 attempts. But this time it looks promising.
Hi, i have the same issue as i upgraded from 0.24.1 directly to 0.25.3. (Sidekiq says "idle" with 54 failed. )
@coordinates = @points.pluck(:lonlat, :battery, :altitude, :timestamp, :velocity, :id, :country) .map { |lonlat, *rest| [lonlat.y, lonlat.x, *rest.map(&:to_s)] }
As from here https://dawarich.app/docs/updating-guides#errors-on-the-map-page I got maybe 100 errors "Caused by PG::UniqueViolation: ERROR:" and removed them - I believe. If i recall the function
User.includes(:tracked_points).find_each do |user| user.tracked_points.where(lonlat: nil).update_all('lonlat = ST_SetSRID(ST_MakePoint(longitude, latitude), 4326)') end
it now says:
`[14] pry(main)> User.includes(:tracked_points).find_each do |user| [14] pry(main)> User.includes(:tracked_points).find_each do |user|etSRID(ST_MakePoint(longitude, latitude), 4326)') user.tracked_points.where(lonlat: nil).update_all('lonlat = ST_SetSRID(ST_MakePoint(longitude, latitude), 4326)') D, [2025-03-29T19:41:09.060769 #2946] DEBUG -- : User Load (0.9ms) SELECT "users".* FROM "users" ORDER BY "users"."id" ASC LIMIT $1 [["LIMIT", 1000]]
D, [2025-03-29T19:41:12.140301 #2946] DEBUG -- : Point Load (3073.4ms) SELECT "points".* FROM "points" WHERE "points"."user_id" = $1 [["user_id", 1]]
D, [2025-03-29T19:41:14.338538 #2946] DEBUG -- : Point Update All (5.1ms) UPDATE "points" SET lonlat = ST_SetSRID(ST_MakePoint(longitude, latitude), 4326) WHERE "points"."user_id" = $1 AND "points"."lonlat" IS NULL [["user_id", 1]] => nil
`
It worked for a few minutes, but after these few minutes i get the error "nil" again and i am not able to remove the error as i did before. I cant see anything running inside sidekiq
I use Owntracks and i am connected using wireshark.
Btw. is there a "faster" way to remove double entries instead of doing it manually for every timestamp. I run dawarich inside a Proxmox container with docker/portainer. Even if the "app" isnt reachable - does the dawarich still process new data points?
So... Next morning the DataMigrations::MigratePointsLatlonJob was no longer visible in Sidwkiq and the web frontend worked fine. The error was gone.
The data migration took something between 1 hour and 7 hours - I did not check the logs to figure out the actual processing time. So if you've got a couple million geopoints in your database, expect the migration to take quite a while. The 1/2 hour I granted the job in my 2nd attempt when I entered the commands manually obviously was way too short.
I have no ideat why it worked this time but in the two attempts beforehand the data migration task was not visible in Sidekiq. Maybe, for all the others out there, facing a similar problem, it might be worth attempting multiple times, before each new attempt restoring the backup. That's at least what I did...
For 8 million points it also took hours but newly added points already had the new format so the next day it worked
Hi,
so... it should work - and I did something wrong. I reverted the changes and i am back to 0.24.1 (thanks to Proxmox VM Backups)
How is the current update path from 24.1 to the latest version 0.25.3.
When I read the release notes of 25.3 I would think that the "lonlat Update" is done when 25.3 is installed. So I "only" should handle the double entries "duplicate key value violates unique constraint "index_points"?
Is there a way to do it for all duplicate keys or do I have to do it manualy for every key myself?
And is Visit.suggested.destroy_all from 0.25.0 needed?
Btw. where do the double entries came from -> probably i had OwnTracks and Home assistant active the same time?
@maltejahn For me the upgrade path was just installing 0.25.3. Then the migration task started automatially, and once that finished, the error message vanished and Dawarich worked fine. For me there was no need to enter any of the commands that described in the release notes or in the issues here.
Hi,
After nearly 24h the map is again reachable( N100 Proxmox with a vm for docker). Never thought it could take that long.
Thanks for your reply.
Malte
I once got those issues a long time ago and was able to fix it but now i have it again after I was able to fire up a reverse geocoding job when i am going to places.
I did all 3 rake commands and they appear to have been successfully executed but the issue is still there.
I am talking about those 3 commands
To remove duplicate points, run rake data_cleanup:remove_duplicate_points
To migrate points coordinates to lonlat column, run rake points:migrate_to_lonlat
To activate your users, run rake users:activate
maybe the rake command did not complete ..i just noticed an abort message:
/var/app # rake points:migrate_to_lonlat
[dotenv] Set DATABASE_PORT
[dotenv] Loaded .env.development
Updating points to use lonlat...
D, [2025-05-19T10:27:25.206053 #11513] DEBUG -- : Point Load (117877.3ms) 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"."country_id" FROM "points" WHERE "points"."longitude" IS NULL AND "points"."latitude" IS NULL ORDER BY "points"."id" ASC LIMIT $1 [["LIMIT", 1000]]
D, [2025-05-19T10:27:25.209770 #11513] DEBUG -- : ↳ lib/tasks/points.rake:10:in 'block (2 levels) in
i just did ran the command with --trace ....but does not look like that it provides more valuable information
/var/app # rake points:migrate_to_lonlat --trace
** Invoke points:migrate_to_lonlat (first_time)
** Invoke environment (first_time)
** Execute environment
[dotenv] Set DATABASE_PORT
[dotenv] Loaded .env.development
** Execute points:migrate_to_lonlat
Updating points to use lonlat...
D, [2025-05-19T10:30:42.209515 #11973] DEBUG -- : Point Load (3549.7ms) 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"."country_id" FROM "points" WHERE "points"."longitude" IS NULL AND "points"."latitude" IS NULL ORDER BY "points"."id" ASC LIMIT $1 [["LIMIT", 1000]]
D, [2025-05-19T10:30:42.215677 #11973] DEBUG -- : ↳ lib/tasks/points.rake:10:in 'block (2 levels) in
i did an upgrade to the latest version and this time rake ran for a couple of hours but now it feels like I am in a loop. Below is the output from 2 runs. Maybe I am missing something but I assumed that this command will take care of all points which needs to get upgraded and there is no need to run it multiple times, right?
thanks :)
rake points:migrate_to_lonlat --trace
** Invoke points:migrate_to_lonlat (first_time)
** Invoke environment (first_time)
** Execute environment
[dotenv] Set DATABASE_PORT
[dotenv] Loaded .env.development
** Execute points:migrate_to_lonlat
Updating points to use lonlat...
D, [2025-05-21T10:07:42.173382 #75416] DEBUG -- : Point Load (8.4ms) SELECT "points".* FROM "points" WHERE "points"."longitude" IS NULL AND "points"."latitude" IS NULL ORDER BY "points"."id" ASC LIMIT $1 [["LIMIT", 1000]]
D, [2025-05-21T10:07:42.174072 #75416] DEBUG -- : ↳ lib/tasks/points.rake:10:in 'block (2 levels) in
D, [2025-05-21T10:09:21.192594 #75416] DEBUG -- : ↳ lib/tasks/points.rake:20:in 'block (3 levels) in
rake points:migrate_to_lonlat --trace
** Invoke points:migrate_to_lonlat (first_time)
** Invoke environment (first_time)
** Execute environment
[dotenv] Set DATABASE_PORT
[dotenv] Loaded .env.development
** Execute points:migrate_to_lonlat
Updating points to use lonlat...
D, [2025-05-21T10:11:23.546270 #75737] DEBUG -- : Point Load (10.2ms) SELECT "points".* FROM "points" WHERE "points"."longitude" IS NULL AND "points"."latitude" IS NULL ORDER BY "points"."id" ASC LIMIT $1 [["LIMIT", 1000]]
D, [2025-05-21T10:11:23.546855 #75737] DEBUG -- : ↳ lib/tasks/points.rake:10:in 'block (2 levels) in
D, [2025-05-21T10:15:03.862355 #75737] DEBUG -- : ↳ lib/tasks/points.rake:20:in 'block (3 levels) in
the funny thing is that there are also indicators that they are no more of such points. Please have a look here:
bin/rails console [dotenv] Set DATABASE_PORT [dotenv] Loaded .env.development Loading development environment (Rails 8.0.2) [1] pry(main)> user = User.find_by(email: '[email protected]') D, [2025-05-24T06:48:50.307691 #87567] DEBUG -- : User Load (60.0ms) SELECT "users".* FROM "users" WHERE "users"."email" = $1 LIMIT $2 [["email", "[email protected]"], ["LIMIT", 1]] => #<User id: 1, email: "[email protected]", created_at: "2024-07-06 17:50:47.546768000 +0200", updated_at: "2025-05-23 08:02:33.952932000 +0200", api_key: [FILTERED], theme: "light", settings: {"maps" => {"url" => "", "name" => "", "distance_unit" => "km"}, "immich_url" => "http://192.168.178.186:2283/", "immich_api_key" => "#################", "photoprism_url" => "", "photoprism_api_key" => ""}, admin: true, status: "active", active_until: "3025-04-09 11:03:34.716798000 +0100"> [2] pry(main)> user.tracked_points.where(latitude: nil, longitude: nil).size D, [2025-05-24T06:49:09.514570 #87567] DEBUG -- : Point Count (46.4ms) SELECT COUNT() FROM "points" WHERE "points"."user_id" = $1 AND "points"."latitude" IS NULL AND "points"."longitude" IS NULL [["user_id", 1]] => 0 [3] pry(main)> user.tracked_points.where.not(latitude: nil, longitude: nil).where(lonlat: nil).size D, [2025-05-24T06:54:16.804992 #87567] DEBUG -- : Point Count (285108.9ms) SELECT COUNT() FROM "points" WHERE "points"."user_id" = $1 AND NOT ("points"."latitude" IS NULL AND "points"."longitude" IS NULL) AND "points"."lonlat" IS NULL [["user_id", 1]] => 0
Do I miss something?
thanks and kind regards :)
I just thought i should mention that i am only getting the error when i go to visited places. I can look at the map without any issues and I am also able to go to points without any error message.
Check also user.tracked_points.where(lonlat: nil).size
Just in case, can you provide exact error you're experiencing with its surroundings and logs? Thanks
[3] pry(main)> user.tracked_points.where(lonlat: nil).size D, [2025-05-25T14:29:53.869908 #247975] DEBUG -- : Point Count (181015.3ms) SELECT COUNT(*) FROM "points" WHERE "points"."user_id" = $1 AND "points"."lonlat" IS NULL [["user_id", 1]] => 0
these are the last logs from sidekiq
D, [2025-05-25T14:22:01.293308 #23] DEBUG -- : ↳ app/models/concerns/distanceable.rb:54:in 'block in Distanceable::ClassMethods#calculate_distance_for_array' D, [2025-05-25T14:22:01.294082 #23] DEBUG -- : (0.7ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (8.412688 49.4657379)"], [nil, "POINT (8.4126863 49.4657323)"]] D, [2025-05-25T14:22:01.294278 #23] DEBUG -- : ↳ app/models/concerns/distanceable.rb:54:in 'block in Distanceable::ClassMethods#calculate_distance_for_array' D, [2025-05-25T14:22:01.294619 #23] DEBUG -- : (0.2ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (8.4126863 49.4657323)"], [nil, "POINT (8.412701 49.4657398)"]] D, [2025-05-25T14:22:01.294795 #23] DEBUG -- : ↳ app/models/concerns/distanceable.rb:54:in 'block in Distanceable::ClassMethods#calculate_distance_for_array' D, [2025-05-25T14:22:01.295008 #23] DEBUG -- : (0.1ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (8.412701 49.4657398)"], [nil, "POINT (8.4126903 49.4657394)"]] D, [2025-05-25T14:22:01.295199 #23] DEBUG -- : ↳ app/models/concerns/distanceable.rb:54:in 'block in Distanceable::ClassMethods#calculate_distance_for_array' D, [2025-05-25T14:22:01.295391 #23] DEBUG -- : (0.1ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (8.4126903 49.4657394)"], [nil, "POINT (8.4126744 49.4657297)"]] D, [2025-05-25T14:22:01.295565 #23] DEBUG -- : ↳ app/models/concerns/distanceable.rb:54:in 'block in Distanceable::ClassMethods#calculate_distance_for_array' D, [2025-05-25T14:22:01.295796 #23] DEBUG -- : (0.1ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (8.4126744 49.4657297)"], [nil, "POINT (8.4126861 49.465738)"]] D, [2025-05-25T14:22:01.295970 #23] DEBUG -- : ↳ app/models/concerns/distanceable.rb:54:in 'block in Distanceable::ClassMethods#calculate_distance_for_array' D, [2025-05-25T14:22:01.296255 #23] DEBUG -- : (0.2ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (8.4126861 49.465738)"], [nil, "POINT (8.4126787 49.4657346)"]] D, [2025-05-25T14:22:01.296433 #23] DEBUG -- : ↳ app/models/concerns/distanceable.rb:54:in 'block in Distanceable::ClassMethods#calculate_distance_for_array' D, [2025-05-25T14:22:01.296630 #23] DEBUG -- : (0.1ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (8.4126787 49.4657346)"], [nil, "POINT (8.4126784 49.4657294)"]] D, [2025-05-25T14:22:01.296805 #23] DEBUG -- : ↳ app/models/concerns/distanceable.rb:54:in 'block in Distanceable::ClassMethods#calculate_distance_for_array' D, [2025-05-25T14:22:01.297060 #23] DEBUG -- : (0.2ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (8.4126784 49.4657294)"], [nil, "POINT (8.4126868 49.465732)"]] D, [2025-05-25T14:22:01.297243 #23] DEBUG -- : ↳ app/models/concerns/distanceable.rb:54:in 'block in Distanceable::ClassMethods#calculate_distance_for_array' D, [2025-05-25T14:22:01.297434 #23] DEBUG -- : (0.1ms) SELECT ST_Distance(ST_GeomFromEWKT($1)::geography, ST_GeomFromEWKT($2)::geography) [[nil, "POINT (8.4126868 49.465732)"], [nil, "POINT (8.4126736 49.4657309)"]] D, [2025-05-25T14:22:01.297608 #23] DEBUG -- : ↳ app/models/concerns/distanceable.rb:54:in 'block in Distanceable::ClassMethods#calculate_distance_for_array' D, [2025-05-25T14:24:26.431484 #23] DEBUG -- : Point Load (145006.5ms) 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"."country_id", "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", 1746057600], ["timestamp", 1748649600]] D, [2025-05-25T14:24:26.431848 #23] DEBUG -- : ↳ app/services/countries_and_cities.rb:13:in 'Enumerable#reject' D, [2025-05-25T14:24:31.727824 #23] DEBUG -- : Stat Update (3567.0ms) UPDATE "stats" SET "distance" = $1, "toponyms" = $2, "updated_at" = $3, "daily_distance" = $4 WHERE "stats"."id" = $5 [["distance", 1877], ["toponyms", "[{"country":"Portugal","cities":[{"city":"Porto","points":6736,"timestamp":1746189896,"stayed_for":2204},{"city":"Vila Nova de Gaia","points":406,"timestamp":1746191694,"stayed_for":1672},{"city":"Matosinhos","points":57,"timestamp":1746122862,"stayed_for":115},{"city":"Aveiro","points":2221,"timestamp":1746203207,"stayed_for":168},{"city":"Alcobaça","points":1497,"timestamp":1746349515,"stayed_for":2351},{"city":"Nazaré","points":9395,"timestamp":1746349312,"stayed_for":2344},{"city":"Valado dos Frades","points":175,"timestamp":1746349022,"stayed_for":2334},{"city":"Caldas da Rainha","points":835,"timestamp":1746349819,"stayed_for":1380},{"city":"Óbidos","points":1517,"timestamp":1746350093,"stayed_for":1379},{"city":"Rebolo","points":16,"timestamp":1746349276,"stayed_for":1197},{"city":"Cela-Velha","points":15,"timestamp":1746349169,"stayed_for":1193},{"city":"Sintra","points":4012,"timestamp":1746467115,"stayed_for":1913},{"city":"Oeiras","points":2592,"timestamp":1746524805,"stayed_for":2870},{"city":"Cascais",
....
D, [2025-05-25T14:24:31.728289 #23] DEBUG -- : ↳ app/services/stats/calculate_month.rb:42:in 'block in Stats::CalculateMonth#update_month_stats' D, [2025-05-25T14:24:31.855803 #23] DEBUG -- : TRANSACTION (127.2ms) COMMIT D, [2025-05-25T14:24:31.856296 #23] DEBUG -- : ↳ app/services/stats/calculate_month.rb:33:in 'Stats::CalculateMonth#update_month_stats' I, [2025-05-25T14:24:31.856369 #23] INFO -- : Performed Stats::CalculatingJob (Job ID: e324d9f2-61c7-4036-ab59-ecfa5fbf3cf5) from Sidekiq(stats) in 1434847.43ms I, [2025-05-25T14:24:31.856878 #23] INFO -- : done D, [2025-05-25T14:24:37.653708 #23] DEBUG -- : Flushed 2 metrics
I just go to the main page ...see the map ...all fine and then go to visited place and i get the error
here are the last lines from the log from the app
D, [2025-05-25T14:42:32.505528 #117] DEBUG -- : User Load (0.3ms) SELECT "users".* FROM "users" WHERE "users"."api_key" IS NULL LIMIT $1 [["LIMIT", 1]] D, [2025-05-25T14:42:32.505925 #117] DEBUG -- : ↳ app/controllers/api_controller.rb:22:in 'ApiController#current_api_user' I, [2025-05-25T14:42:32.506105 #117] INFO -- : {"method":"GET","path":"/api/v1/health","format":"/","controller":"Api::V1::HealthController","action":"index","status":200,"allocations":903,"duration":1.94,"view":0.04,"db":0.23} D, [2025-05-25T14:42:42.559383 #117] DEBUG -- : User Load (0.1ms) SELECT "users".* FROM "users" WHERE "users"."api_key" IS NULL LIMIT $1 [["LIMIT", 1]] D, [2025-05-25T14:42:42.559672 #117] DEBUG -- : ↳ app/controllers/api_controller.rb:22:in 'ApiController#current_api_user' I, [2025-05-25T14:42:42.559805 #117] INFO -- : {"method":"GET","path":"/api/v1/health","format":"/","controller":"Api::V1::HealthController","action":"index","status":200,"allocations":903,"duration":1.15,"view":0.03,"db":0.14} D, [2025-05-25T14:42:52.632575 #117] DEBUG -- : User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."api_key" IS NULL LIMIT $1 [["LIMIT", 1]] D, [2025-05-25T14:42:52.632881 #117] DEBUG -- : ↳ app/controllers/api_controller.rb:22:in 'ApiController#current_api_user' I, [2025-05-25T14:42:52.633028 #117] INFO -- : {"method":"GET","path":"/api/v1/health","format":"/","controller":"Api::V1::HealthController","action":"index","status":200,"allocations":903,"duration":1.24,"view":0.03,"db":0.2} D, [2025-05-25T14:43:02.681298 #117] DEBUG -- : User Load (0.2ms) SELECT "users".* FROM "users" WHERE "users"."api_key" IS NULL LIMIT $1 [["LIMIT", 1]] D, [2025-05-25T14:43:02.681588 #117] DEBUG -- : ↳ app/controllers/api_controller.rb:22:in 'ApiController#current_api_user' I, [2025-05-25T14:43:02.681725 #117] INFO -- : {"method":"GET","path":"/api/v1/health","format":"/","controller":"Api::V1::HealthController","action":"index","status":200,"allocations":903,"duration":1.14,"view":0.03,"db":0.17}
and here are the last log lines from the db
2025-05-25 13:20:32.291 UTC [26] LOG: checkpoint starting: time 2025-05-25 13:20:44.003 UTC [26] LOG: checkpoint complete: wrote 42 buffers (0.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=6.394 s, sync=1.976 s, total=11.713 s; sync files=23, longest=0.421 s, average=0.086 s; distance=229 kB, estimate=2482 kB; lsn=F/E87DAD50, redo lsn=F/E87DACC0 2025-05-25 13:25:32.099 UTC [26] LOG: checkpoint starting: time 2025-05-25 13:25:58.739 UTC [26] LOG: checkpoint complete: wrote 57 buffers (0.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=8.959 s, sync=10.012 s, total=26.641 s; sync files=24, longest=1.457 s, average=0.418 s; distance=344 kB, estimate=2268 kB; lsn=F/E88504D8, redo lsn=F/E8831038 2025-05-25 13:30:34.754 UTC [26] LOG: checkpoint starting: time 2025-05-25 13:31:07.690 UTC [26] LOG: checkpoint complete: wrote 40 buffers (0.2%); 0 WAL file(s) added, 0 removed, 0 recycled; write=8.706 s, sync=12.204 s, total=33.890 s; sync files=24, longest=1.665 s, average=0.509 s; distance=254 kB, estimate=2067 kB; lsn=F/E8876098, redo lsn=F/E8870878 2025-05-25 13:50:00.930 UTC [47385] ERROR: duplicate key value violates unique constraint "index_points_on_lonlat_timestamp_user_id" 2025-05-25 13:50:00.930 UTC [47385] DETAIL: Key (lonlat, "timestamp", user_id)=(0101000020E61000002BB8C4364ED3204080D591239DBB4840, 1748180590, 1) already exists. 2025-05-25 13:50:00.930 UTC [47385] STATEMENT: INSERT INTO "points" ("battery_status", "ping", "battery", "tracker_id", "topic", "altitude", "longitude", "velocity", "trigger", "bssid", "ssid", "connection", "vertical_accuracy", "accuracy", "timestamp", "latitude", "mode", "inrids", "in_regions", "raw_data", "import_id", "city", "country", "created_at", "updated_at", "user_id", "geodata", "visit_id", "reverse_geocoded_at", "course", "course_accuracy", "external_track_id", "lonlat", "country_id") VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17, $18, $19, $20, $21, $22, $23, $24, $25, $26, $27, $28, $29, $30, $31, $32, $33, $34) RETURNING "id" 2025-05-25 13:50:33.089 UTC [26] LOG: checkpoint starting: time 2025-05-25 13:51:53.960 UTC [26] LOG: checkpoint complete: wrote 57 buffers (0.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=19.874 s, sync=31.478 s, total=80.872 s; sync files=33, longest=2.933 s, average=0.954 s; distance=277 kB, estimate=1888 kB; lsn=F/E88B7C40, redo lsn=F/E88B5FF0 2025-05-25 13:55:34.060 UTC [26] LOG: checkpoint starting: time 2025-05-25 13:56:05.221 UTC [26] LOG: checkpoint complete: wrote 46 buffers (0.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=6.166 s, sync=13.961 s, total=31.162 s; sync files=24, longest=2.167 s, average=0.582 s; distance=262 kB, estimate=1725 kB; lsn=F/E8919060, redo lsn=F/E88F7A60 2025-05-25 14:00:34.321 UTC [26] LOG: checkpoint starting: time 2025-05-25 14:00:51.425 UTC [26] LOG: checkpoint complete: wrote 56 buffers (0.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=7.349 s, sync=4.763 s, total=17.105 s; sync files=25, longest=0.715 s, average=0.191 s; distance=298 kB, estimate=1583 kB; lsn=F/E896A530, redo lsn=F/E8942268 2025-05-25 14:05:34.525 UTC [26] LOG: checkpoint starting: time 2025-05-25 14:05:50.465 UTC [26] LOG: checkpoint complete: wrote 54 buffers (0.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=6.363 s, sync=4.026 s, total=15.940 s; sync files=24, longest=1.471 s, average=0.168 s; distance=352 kB, estimate=1460 kB; lsn=F/E899A4F8, redo lsn=F/E899A468 2025-05-25 14:10:42.372 UTC [47449] ERROR: duplicate key value violates unique constraint "index_points_on_lonlat_timestamp_user_id" 2025-05-25 14:10:42.372 UTC [47449] DETAIL: Key (lonlat, "timestamp", user_id)=(0101000020E6100000FE5F75E448D32040E5B4A7E49CBB4840, 1748182193, 1) already exists. 2025-05-25 14:10:42.372 UTC [47449] STATEMENT: INSERT INTO "points" ("battery_status", "ping", "battery", "tracker_id", "topic", "altitude", "longitude", "velocity", "trigger", "bssid", "ssid", "connection", "vertical_accuracy", "accuracy", "timestamp", "latitude", "mode", "inrids", "in_regions", "raw_data", "import_id", "city", "country", "created_at", "updated_at", "user_id", "geodata", "visit_id", "reverse_geocoded_at", "course", "course_accuracy", "external_track_id", "lonlat", "country_id") VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10, $11, $12, $13, $14, $15, $16, $17, $18, $19, $20, $21, $22, $23, $24, $25, $26, $2~ # 28, $29, $30, $31, $32, $33, $34) RETURNING "id"
i just noticed that if i open declined or suggested it works well. Only the confirmed section throws the error. By the way .....i am pretty confident that i have a very low number of confirmed entries there ......
i added a pgadmin container to easily get some visbility .....there are 74 entries in the visited table. 60 with status 0 - i guess those are the unconfirmed ones. I am wondering what happens when i just delete those entries? I guess i can get them again when i run another job since at the end the visits are just made from the raw data which i am not touching, right?
this command shows 512 rows => SELECT * FROM public.places where lonlat isnull Could this be my issue?
there is only one line with lonlat=NULL when i do this: SELECT * FROM public.visits, public.places where public.visits.place_id = public.places.id order by lonlat desc