teslamate-org / teslamate

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

Fresh advanced (Traefik) docker installation won't accept tokens #3988

Closed bahree closed 2 months ago

bahree commented 2 months ago

Is there an existing issue for this?

What happened?

I am setting up another instance of Teslamate, in a docker container on a cloud VM - I already have one instance running for a while, and I wanted to get another one going. When I setup the advanced (Traefik) docker container and bring it up the first time, as expected I get the screen to enter the tokens, as shown below. But when I enter the tokens generated by the TeslaAuth app it doesn't like it.

I have also deleted the docker volume just to be sure and restored from the backup (of the other instance) and tried that - but no dice either. :(

image

Here is the image from the TeslaAuth app: image

Any ideas on what is wrong? I can see this in the logs (ssh'd into the vm): image

Expected Behavior

Able to authenticate and login.

Steps To Reproduce

Start the container and navigate to the FQDN

Relevant log output

database-1   |
database-1   | PostgreSQL Database directory appears to contain a database; Skipping initialization
database-1   |
database-1   | 2024-06-23 00:53:38.985 UTC [1] LOG:  starting PostgreSQL 16.3 (Debian 16.3-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
database-1   | 2024-06-23 00:53:38.991 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
database-1   | 2024-06-23 00:53:38.992 UTC [1] LOG:  listening on IPv6 address "::", port 5432
database-1   | 2024-06-23 00:53:38.995 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
database-1   | 2024-06-23 00:53:39.027 UTC [29] LOG:  database system was shut down at 2024-06-23 00:53:17 UTC
database-1   | 2024-06-23 00:53:39.048 UTC [1] LOG:  database system is ready to accept connections
proxy-1      | time="2024-06-23T00:53:39Z" level=info msg="Configuration loaded from flags."
grafana-1    | logger=settings t=2024-06-23T00:53:39.488614357Z level=info msg="Starting Grafana" version=11.0.0 commit=83b9528bce85cf9371320f6d6e450916156da3f6 branch=v11.0.x compiled=2024-06-23T00:53:39Z
grafana-1    | logger=settings t=2024-06-23T00:53:39.491150763Z level=info msg="Config loaded from" file=/usr/share/grafana/conf/defaults.ini
grafana-1    | logger=settings t=2024-06-23T00:53:39.491631152Z level=info msg="Config loaded from" file=/etc/grafana/grafana.ini
grafana-1    | logger=settings t=2024-06-23T00:53:39.491733533Z level=info msg="Config overridden from command line" arg="default.paths.data=/var/lib/grafana"
grafana-1    | logger=settings t=2024-06-23T00:53:39.491768959Z level=info msg="Config overridden from command line" arg="default.paths.logs=/var/log/grafana"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494348221Z level=info msg="Config overridden from command line" arg="default.paths.plugins=/var/lib/grafana/plugins"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494443208Z level=info msg="Config overridden from command line" arg="default.paths.provisioning=/etc/grafana/provisioning"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494466432Z level=info msg="Config overridden from command line" arg="default.log.mode=console"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494568832Z level=info msg="Config overridden from Environment variable" var="GF_PATHS_DATA=/var/lib/grafana"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494605335Z level=info msg="Config overridden from Environment variable" var="GF_PATHS_LOGS=/var/log/grafana"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494626997Z level=info msg="Config overridden from Environment variable" var="GF_PATHS_PLUGINS=/var/lib/grafana/plugins"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494646787Z level=info msg="Config overridden from Environment variable" var="GF_PATHS_PROVISIONING=/etc/grafana/provisioning"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494679351Z level=info msg="Config overridden from Environment variable" var="GF_SERVER_DOMAIN=RETRACTED"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494706561Z level=info msg="Config overridden from Environment variable" var="GF_SERVER_ROOT_URL=%(protocol)s://%(domain)s/grafana"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494731242Z level=info msg="Config overridden from Environment variable" var="GF_SERVER_SERVE_FROM_SUB_PATH=true"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494750089Z level=info msg="Config overridden from Environment variable" var="GF_ANALYTICS_REPORTING_ENABLED=false"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494781577Z level=info msg="Config overridden from Environment variable" var="GF_SECURITY_ADMIN_USER=amit"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494810158Z level=info msg="Config overridden from Environment variable" var="GF_SECURITY_ADMIN_PASSWORD=*********"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494831474Z level=info msg="Config overridden from Environment variable" var="GF_SECURITY_DISABLE_GRAVATAR=true"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494850094Z level=info msg="Config overridden from Environment variable" var="GF_SECURITY_ALLOW_EMBEDDING=true"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494888607Z level=info msg="Config overridden from Environment variable" var="GF_USERS_ALLOW_SIGN_UP=false"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494932569Z level=info msg="Config overridden from Environment variable" var="GF_AUTH_ANONYMOUS_ENABLED=false"
grafana-1    | logger=settings t=2024-06-23T00:53:39.494958933Z level=info msg="Config overridden from Environment variable" var="GF_AUTH_BASIC_ENABLED=false"
grafana-1    | logger=settings t=2024-06-23T00:53:39.495006203Z level=info msg=Target target=[all]
grafana-1    | logger=settings t=2024-06-23T00:53:39.49517064Z level=info msg="Path Home" path=/usr/share/grafana
grafana-1    | logger=settings t=2024-06-23T00:53:39.495216598Z level=info msg="Path Data" path=/var/lib/grafana
grafana-1    | logger=settings t=2024-06-23T00:53:39.498613206Z level=info msg="Path Logs" path=/var/log/grafana
grafana-1    | logger=settings t=2024-06-23T00:53:39.498721807Z level=info msg="Path Plugins" path=/var/lib/grafana/plugins
grafana-1    | logger=settings t=2024-06-23T00:53:39.498757507Z level=info msg="Path Provisioning" path=/etc/grafana/provisioning
grafana-1    | logger=settings t=2024-06-23T00:53:39.498780127Z level=info msg="App mode production"
grafana-1    | logger=sqlstore t=2024-06-23T00:53:39.499556107Z level=info msg="Connecting to DB" dbtype=sqlite3
grafana-1    | logger=migrator t=2024-06-23T00:53:39.551915482Z level=info msg="Locking database"
grafana-1    | logger=migrator t=2024-06-23T00:53:39.55260478Z level=info msg="Starting DB migrations"
grafana-1    | logger=migrator t=2024-06-23T00:53:39.708859317Z level=info msg="migrations completed" performed=0 skipped=558 duration=4.517174ms
grafana-1    | logger=migrator t=2024-06-23T00:53:39.712922394Z level=info msg="Unlocking database"
grafana-1    | logger=secrets t=2024-06-23T00:53:39.758953265Z level=info msg="Envelope encryption state" enabled=true currentprovider=secretKey.v1
grafana-1    | logger=plugin.angulardetectorsprovider.dynamic t=2024-06-23T00:53:39.930226079Z level=info msg="Restored cache from database" duration=744.899µs
grafana-1    | logger=plugin.store t=2024-06-23T00:53:39.945717529Z level=info msg="Loading plugins..."
grafana-1    | logger=plugins.registration t=2024-06-23T00:53:40.240113063Z level=error msg="Could not register plugin" pluginId=xychart error="plugin xychart is already registered"
grafana-1    | logger=plugins.initialization t=2024-06-23T00:53:40.240958966Z level=error msg="Could not initialize plugin" pluginId=xychart error="plugin xychart is already registered"
grafana-1    | logger=local.finder t=2024-06-23T00:53:40.241705385Z level=warn msg="Skipping finding plugins as directory does not exist" path=/usr/share/grafana/plugins-bundled
grafana-1    | logger=plugin.store t=2024-06-23T00:53:40.245594816Z level=info msg="Plugins loaded" count=54 duration=299.878307ms
grafana-1    | logger=query_data t=2024-06-23T00:53:40.284752428Z level=info msg="Query Service initialization"
grafana-1    | logger=live.push_http t=2024-06-23T00:53:40.303361477Z level=info msg="Live Push Gateway initialization"
grafana-1    | logger=ngalert.notifier.alertmanager org=1 t=2024-06-23T00:53:40.3192307Z level=info msg="Applying new configuration to Alertmanager" configHash=a013a3f424edb13bed8050eaf374d506
grafana-1    | logger=ngalert.state.manager t=2024-06-23T00:53:40.347216291Z level=info msg="Running in alternative execution of Error/NoData mode"
grafana-1    | logger=infra.usagestats.collector t=2024-06-23T00:53:40.36148146Z level=info msg="registering usage stat providers" usageStatsProvidersLen=2
grafana-1    | logger=provisioning.alerting t=2024-06-23T00:53:40.483131565Z level=info msg="starting to provision alerting"
grafana-1    | logger=provisioning.alerting t=2024-06-23T00:53:40.483882155Z level=info msg="finished to provision alerting"
grafana-1    | logger=ngalert.state.manager t=2024-06-23T00:53:40.495623799Z level=info msg="Warming state cache for startup"
grafana-1    | logger=ngalert.state.manager t=2024-06-23T00:53:40.501945896Z level=info msg="State cache has been initialized" states=0 duration=6.31373ms
grafana-1    | logger=provisioning.dashboard t=2024-06-23T00:53:40.504389483Z level=info msg="starting to provision dashboards"
grafana-1    | logger=grafanaStorageLogger t=2024-06-23T00:53:40.531365701Z level=info msg="Storage starting"
grafana-1    | logger=ngalert.multiorg.alertmanager t=2024-06-23T00:53:40.582802509Z level=info msg="Starting MultiOrg Alertmanager"
grafana-1    | logger=ngalert.scheduler t=2024-06-23T00:53:40.586407122Z level=info msg="Starting scheduler" tickInterval=10s maxAttempts=1
grafana-1    | logger=http.server t=2024-06-23T00:53:40.587711494Z level=info msg="HTTP Server Listen" address=[::]:3000 protocol=http subUrl=/grafana socket=
grafana-1    | logger=ticker t=2024-06-23T00:53:40.590594502Z level=info msg=starting first_tick=2024-06-23T00:53:50Z
grafana-1    | logger=provisioning.dashboard t=2024-06-23T00:53:41.059500536Z level=info msg="finished to provision dashboards"
grafana-1    | logger=grafana.update.checker t=2024-06-23T00:53:41.063266688Z level=info msg="Update check succeeded" duration=535.483872ms
grafana-1    | logger=plugins.update.checker t=2024-06-23T00:53:41.064350754Z level=info msg="Update check succeeded" duration=534.208508ms
grafana-1    | logger=grafana-apiserver t=2024-06-23T00:53:43.698182696Z level=info msg="Adding GroupVersion playlist.grafana.app v0alpha1 to ResourceManager"
grafana-1    | logger=grafana-apiserver t=2024-06-23T00:53:43.715933063Z level=info msg="Adding GroupVersion featuretoggle.grafana.app v0alpha1 to ResourceManager"
teslamate-1  | 2024-06-22 17:53:44.631 [info] Migrations already up
teslamate-1  | 2024-06-22 17:53:50.459 [info] System Info: Erlang/OTP 26 (jit)
teslamate-1  | 2024-06-22 17:53:50.459 [info] Version: 1.29.2
teslamate-1  | 2024-06-22 17:53:50.633 [info] Running TeslaMateWeb.Endpoint with cowboy 2.10.0 at :::4000 (http)
teslamate-1  | 2024-06-22 17:53:50.637 [info] Access TeslaMateWeb.Endpoint at [RETRACTED]
teslamate-1  | 2024-06-22 17:54:26.145 [info] GET /
teslamate-1  | 2024-06-22 17:54:26.153 [info] Sent 302 in 8ms
teslamate-1  | 2024-06-22 17:54:26.214 [info] GET /sign_in
teslamate-1  | 2024-06-22 17:54:26.221 [info] Sent 200 in 7ms
teslamate-1  | 2024-06-22 17:54:42.802 [error] POST https://auth.tesla.com/oauth2/v3/token -> 403 (87.732 ms)
grafana-1    | logger=infra.usagestats t=2024-06-23T00:55:15.558399218Z level=info msg="Usage stats are ready to report"
database-1   | 2024-06-23 00:58:39.122 UTC [27] LOG:  checkpoint starting: time
database-1   | 2024-06-23 00:58:39.531 UTC [27] LOG:  checkpoint complete: wrote 7 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.404 s, sync=0.002 s, total=0.410 s; sync files=4, longest=0.001 s, average=0.001 s; distance=15 kB, estimate=15 kB; lsn=0/1B5DC60, redo lsn=0/1B5DC28
grafana-1    | logger=cleanup t=2024-06-23T01:03:40.510637055Z level=info msg="Completed cleanup jobs" duration=7.657325ms
grafana-1    | logger=plugins.update.checker t=2024-06-23T01:03:41.130045915Z level=info msg="Update check succeeded" duration=63.834357ms

Screenshots

No response

Additional data

No response

Type of installation

Docker

Version

v1.29.2

bahree commented 2 months ago

I also wanted to add that this is on Digital Cloud if that makes a difference.

RocketSharks commented 2 months ago

hello,I had the same problem. Version | 1.29.2

bahree commented 2 months ago

What is interesting is that if I setup a new ubuntu VM on Azure, the same thing works - but not on Digital Cloud -- any suggestions?

bahree commented 2 months ago

hello,I had the same problem. Version | 1.29.2

@RocketSharks did you also try on Digital Cloud?

RocketSharks commented 2 months ago

No, I just tried it locally in docker

cwanja commented 2 months ago

Feel like I recall a period where Digital Ocean IPs were blocked by Tesla. My guess is that's the issue.

Would suggest opening a ticket with Digital Ocean, but it's beyond their control as Tesla implemented the blocker.

cwanja commented 2 months ago

What is interesting is that if I setup a new ubuntu VM on Azure, the same thing works - but not on Digital Cloud -- any suggestions?

Closing as this is not a TeslaMate issue.