search

teslamate-org / teslamate

A self-hosted data logger for your Tesla 🚘
https://docs.teslamate.org
MIT License
5.85k stars 731 forks source link

Problems due to version mismatch in index "cars_eid_index": file version 132, current version 4, minimal supported version 2 #2886

Closed ptar closed 2 years ago

ptar commented 2 years ago

Is there an existing issue for this?

What happened?

There's a problem with an index In the database-log, I can see ERROR: version mismatch in index "cars_eid_index": file version 132, current version 4, minimal supported version 2

In the teslamate log I can see a follow-up; ** (Postgrex.Error) ERROR XX002 (index_corrupted) version mismatch in index "cars_eid_index": file version 132, current version 4, minimal supported version 2 and a restart (full logs see below)

Expected Behavior

There shouldn't be an index problem and Teslamate should start normally.

Steps To Reproduce

  1. Start docker-compose up -d
  2. Wait for it to be started
  3. Check for the logs of database and teslamate

Relevant log output

(Times do not match for teslamate and database log)

teslamate_1  | 2022-09-08 22:16:49.274 [info] Migrations already up
teslamate_1  | 2022-09-08 22:16:54.716 [info] System Info: Erlang/OTP 24 (emu)
teslamate_1  | 2022-09-08 22:16:54.716 [info] Version: 1.27.1
teslamate_1  | 2022-09-08 22:16:55.592 [info] POST https://auth.tesla.com/oauth2/v3/token -> 200 (762.822 ms)
teslamate_1  | 2022-09-08 22:16:55.594 [info] Refreshed api tokens
teslamate_1  | 2022-09-08 22:16:56.033 [info] Scheduling token refresh in 6 h
teslamate_1  | 2022-09-08 22:16:56.054 [info] Running TeslaMateWeb.Endpoint with cowboy 2.9.0 at :::4000 (http)
teslamate_1  | 2022-09-08 22:16:56.061 [info] Access TeslaMateWeb.Endpoint at http://localhost
teslamate_1  | 2022-09-08 22:16:56.256 [info] Starting logger for 'xxxxxx'
teslamate_1  | 2022-09-08 22:16:56.266 [info] Postgrex.Protocol (#PID<0.2375.0>) disconnected: ** (DBConnection.ConnectionError) client #PID<0.2511.0> exited
teslamate_1  | 2022-09-08 22:16:56.281 [notice] Application teslamate exited: TeslaMate.Application.start(:normal, []) returned an error: shutdown: failed to start child: TeslaMate.Vehicles
teslamate_1  |     ** (EXIT) an exception was raised:
teslamate_1  |         ** (Postgrex.Error) ERROR XX002 (index_corrupted) version mismatch in index "cars_eid_index": file version 132, current version 4, minimal supported version 2
teslamate_1  |             (ecto_sql 3.8.3) lib/ecto/adapters/sql.ex:932: Ecto.Adapters.SQL.raise_sql_call_error/1
teslamate_1  |             (ecto_sql 3.8.3) lib/ecto/adapters/sql.ex:847: Ecto.Adapters.SQL.execute/6
teslamate_1  |             (ecto 3.8.4) lib/ecto/repo/queryable.ex:221: Ecto.Repo.Queryable.execute/4
teslamate_1  |             (ecto 3.8.4) lib/ecto/repo/queryable.ex:19: Ecto.Repo.Queryable.all/3
teslamate_1  |             (ecto 3.8.4) lib/ecto/repo/queryable.ex:147: Ecto.Repo.Queryable.one/3
teslamate_1  |             (teslamate 1.27.1) lib/teslamate/vehicles.ex:113: TeslaMate.Vehicles.create_or_update!/1
teslamate_1  |             (teslamate 1.27.1) lib/teslamate/vehicles.ex:53: anonymous fn/2 in TeslaMate.Vehicles.init/1
teslamate_1  |             (elixir 1.13.4) lib/enum.ex:1593: Enum."-map/2-lists^map/1-0-"/2
teslamate_1  | {"Kernel pid terminated",application_controller,"{application_start_failure,teslamate,{{shutdown,{failed_to_start_child,'Elixir.TeslaMate.Vehicles',{#{'__exception__' => true,'__struct__' => 'Elixir.Postgrex.Error',connection_id => 372,message => nil,postgres => #{code => index_corrupted,file => <<\"nbtpage.c\">>,line => <<\"155\">>,message => <<\"version mismatch in index \\"cars_eid_index\\": file version 132, current version 4, minimal supported version 2\">>,pg_code => <<\"XX002\">>,routine => <<\"_bt_getmeta\">>,severity => <<\"ERROR\">>,unknown => <<\"ERROR\">>},query => nil},[{'Elixir.Ecto.Adapters.SQL',raise_sql_call_error,1,[{file,\"lib/ecto/adapters/sql.ex\"},{line,932},{error_info,#{module => 'Elixir.Exception'}}]},{'Elixir.Ecto.Adapters.SQL',execute,6,[{file,\"lib/ecto/adapters/sql.ex\"},{line,847}]},{'Elixir.Ecto.Repo.Queryable',execute,4,[{file,\"lib/ecto/repo/queryable.ex\"},{line,221}]},{'Elixir.Ecto.Repo.Queryable',all,3,[{file,\"lib/ecto/repo/queryable.ex\"},{line,19}]},{'Elixir.Ecto.Repo.Queryable',one,3,[{file,\"lib/ecto/repo/queryable.ex\"},{line,147}]},{'Elixir.TeslaMate.Vehicles','create_or_update!',1,[{file,\"lib/teslamate/vehicles.ex\"},{line,113}]},{'Elixir.TeslaMate.Vehicles','-init/1-fun-1-',2,[{file,\"lib/teslamate/vehicles.ex\"},{line,53}]},{'Elixir.Enum','-map/2-lists^map/1-0-',2,[{file,\"lib/enum.ex\"},{line,1593}]}]}}},{'Elixir.TeslaMate.Application',start,[normal,[]]}}}"}
teslamate_1  | Kernel pid terminated (application_controller) ({application_start_failure,teslamate,{{shutdown,{failed_to_start_child,'Elixir.TeslaMate.Vehicles',{#{'__exception__' => true,'__struct__' => 'Elixir.Postgrex.Error',connection_id => 372,message => nil,postgres => #{code => index_corrupted,file => <<"nbtpage.c">>,line => <<"155">>,message => <<"version mismatch in index \"cars_eid_index\": file version 132, current version 4, minimal supported version 2">>,pg_code => <<"XX002">>,routine => <<"_bt_getmeta">>,severity => <<"ERROR">>,unknown => <<"ERROR">>},query => nil},[{'Elixir.Ecto.Adapters.SQL',raise_sql_call_error,1,[{file,"lib/ecto/adapters/sql.ex"},{line,932},{error_info,#{module => 'Elixir.Exception'}}]},{'Elixir.Ecto.Adapters.SQL',execute,6,[{file,"lib/ecto/adapters/sql.ex"},{line,847}]},{'Elixir.Ecto.Repo.Queryable',execute,4,[{file,"lib/ecto/repo/queryable.ex"},{line,221}]},{'Elixir.Ecto.Repo.Queryable',all,3,[{file,"lib/ecto/repo/queryable.ex"},{line,19}]},{'Elixir.Ecto.Repo.Queryable',one,3,[{file,"l
teslamate_1  | 
teslamate_1  | Crash dump is being written to: erl_crash.dump...done

--------------------------------------------------------------------------------

database_1   | 
database_1   | PostgreSQL Database directory appears to contain a database; Skipping initialization
database_1   | 
database_1   | 2022-09-08 22:49:03.241 UTC [1] LOG:  starting PostgreSQL 13.8 (Debian 13.8-1.pgdg110+1) on arm-unknown-linux-gnueabihf, compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 32-bit
database_1   | 2022-09-08 22:49:03.242 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
database_1   | 2022-09-08 22:49:03.243 UTC [1] LOG:  listening on IPv6 address "::", port 5432
database_1   | 2022-09-08 22:49:03.383 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
database_1   | 2022-09-08 22:49:03.543 UTC [27] LOG:  database system was shut down at 2022-09-08 22:47:37 UTC
database_1   | 2022-09-08 22:49:03.649 UTC [1] LOG:  database system is ready to accept connections
database_1   | 2022-09-08 22:50:41.276 UTC [40] ERROR:  version mismatch in index "cars_eid_index": file version 132, current version 4, minimal supported version 2
database_1   | 2022-09-08 22:50:41.276 UTC [40] STATEMENT:  SELECT c0."id", c0."name", c0."efficiency", c0."model", c0."trim_badging", c0."marketing_name", c0."exterior_color", c0."wheel_type", c0."spoiler_type", c0."eid", c0."vid", c0."vin", c0."settings_id", c0."inserted_at", c0."updated_at" FROM "cars" AS c0 WHERE (c0."vin" = $1)
database_1   | 2022-09-08 22:50:41.389 UTC [42] ERROR:  canceling statement due to user request
database_1   | 2022-09-08 22:50:41.389 UTC [42] STATEMENT:  SELECT s0."drive_id" FROM (SELECT sp0."drive_id" AS "drive_id", count(*) FILTER (WHERE NOT (sp0."odometer" IS NULL) AND (sp0."ideal_battery_range_km" IS NULL)) AS "streamed_count" FROM "positions" AS sp0 WHERE (NOT (sp0."drive_id" IS NULL)) GROUP BY sp0."drive_id") AS s0 WHERE (s0."streamed_count" = 0)
database_1   | 2022-09-08 22:50:41.390 UTC [48] FATAL:  terminating connection due to administrator command
database_1   | 2022-09-08 22:50:41.390 UTC [48] STATEMENT:  SELECT s0."drive_id" FROM (SELECT sp0."drive_id" AS "drive_id", count(*) FILTER (WHERE NOT (sp0."odometer" IS NULL) AND (sp0."ideal_battery_range_km" IS NULL)) AS "streamed_count" FROM "positions" AS sp0 WHERE (NOT (sp0."drive_id" IS NULL)) GROUP BY sp0."drive_id") AS s0 WHERE (s0."streamed_count" = 0)
database_1   | 2022-09-08 22:50:41.390 UTC [49] FATAL:  terminating connection due to administrator command
database_1   | 2022-09-08 22:50:41.390 UTC [49] STATEMENT:  SELECT s0."drive_id" FROM (SELECT sp0."drive_id" AS "drive_id", count(*) FILTER (WHERE NOT (sp0."odometer" IS NULL) AND (sp0."ideal_battery_range_km" IS NULL)) AS "streamed_count" FROM "positions" AS sp0 WHERE (NOT (sp0."drive_id" IS NULL)) GROUP BY sp0."drive_id") AS s0 WHERE (s0."streamed_count" = 0)
database_1   | 2022-09-08 22:50:41.402 UTC [1] LOG:  background worker "parallel worker" (PID 48) exited with exit code 1
database_1   | 2022-09-08 22:50:41.406 UTC [1] LOG:  background worker "parallel worker" (PID 49) exited with exit code 1
database_1   | 2022-09-08 22:50:41.408 UTC [42] LOG:  could not send data to client: Broken pipe
database_1   | 2022-09-08 22:50:41.408 UTC [42] FATAL:  connection to client lost
database_1   | 2022-09-08 22:51:11.462 UTC [64] ERROR:  version mismatch in index "cars_eid_index": file version 132, current version 4, minimal supported version 2
database_1   | 2022-09-08 22:51:11.462 UTC [64] STATEMENT:  SELECT c0."id", c0."name", c0."efficiency", c0."model", c0."trim_badging", c0."marketing_name", c0."exterior_color", c0."wheel_type", c0."spoiler_type", c0."eid", c0."vid", c0."vin", c0."settings_id", c0."inserted_at", c0."updated_at" FROM "cars" AS c0 WHERE (c0."vin" = $1)

Screenshots

No response

Additional data

No response

Type of installation

Docker

Version

pulled it before the test (2022-09-09)

ptar commented 2 years ago

I found a - kind of - easy solution to the problem: I could just reindex the table.

This is what I did:

  1. Connect to the database and open a prompt docker-compose exec database psql teslamate teslamate
  2. Find the table with the problematic index select tablename from pg_indexes where indexname = 'cars_eid_index';
  3. Reindex the table reindex table cars;
  4. Check, if you can access the table again select * from cars;

Suggestion: On getting a broken index, this could be the default solution within Teslamate. Maybe you could implement some 'check and fix indexes'?

ptar commented 2 years ago

The rest of the story to close the issue...

Due to the broken index the pg_dump failed to generate a complete backup, starting at the end of August. After fixing the index, I encountered another problem: The table charges wasn't completely selectable (using offset and limit I could get all rows below 190 and beyond 300 up to ~25000). So I extracted the rows missing from the last backup. I prepared a bck-file containing only the charges-entries (since no other table is depending on charges). Then I dropped charges and restored the table with the prepared bck-file.

After that, I could vacuum all the tables and pg_dump runs again, so I created a complete backup.

I purged all the images and recreated them from scratch. After restoring the complete backup, everything but the very last charging session was back there again, including all drives in September!

Hurray!