metisvela / sailtrack-core

Central component of the SailTrack system, it manages connections and gathers data.
GNU General Public License v3.0
13 stars 0 forks source link

Bug in Automation_Custom_Script.sh #24

Closed Magform closed 10 months ago

Magform commented 1 year ago

After installing the system, tail -f /var/tmp/dietpi/logs/dietpi-firstrun-setup.log show:

[  OK  ] DietPi-Services | restart : cron
[  OK  ] DietPi-Services | restart : telegraf
[ INFO ] DietPi-Services | skip : sailtrack-status (disabled)
[ INFO ] DietPi-Services | skip : sailtrack-timesync (disabled)
[ INFO ] DietPi-Services | skip : sailtrack-tileserver (disabled)
[ INFO ] DietPi-Services | skip : sailtrack-processor (disabled)
[ INFO ] DietPi-Software | Starting installed services not controlled by DietPi-Services
[  OK  ] DietPi-Software | systemctl start hostapd
[  OK  ] DietPi-Software | systemctl start isc-dhcp-server

And the dashboard is not displayed correctly and by checking the journalctl we see:

Nov 05 16:52:58 sailtrack-core systemd[1]: Starting Telegraf...
Nov 05 16:52:59 sailtrack-core telegraf[6367]: 2023-11-05T15:52:59Z I! Loading config: /etc/telegraf/telegraf.conf
Nov 05 16:52:59 sailtrack-core telegraf[6367]: 2023-11-05T15:52:59Z I! Loading config: /etc/telegraf/telegraf.d/sailtrack-telegraf.conf
Nov 05 16:52:59 sailtrack-core telegraf[6367]: 2023-11-05T15:52:59Z I! Starting Telegraf 1.28.3 brought to you by InfluxData the makers of InfluxDB
Nov 05 16:52:59 sailtrack-core telegraf[6367]: 2023-11-05T15:52:59Z I! Available plugins: 240 inputs, 9 aggregators, 29 processors, 24 parsers, 59 outputs, 5 secret-stores
Nov 05 16:52:59 sailtrack-core telegraf[6367]: 2023-11-05T15:52:59Z I! Loaded inputs: cpu disk diskio kernel mem mqtt_consumer (2x) processes swap system
Nov 05 16:52:59 sailtrack-core telegraf[6367]: 2023-11-05T15:52:59Z I! Loaded aggregators:
Nov 05 16:52:59 sailtrack-core telegraf[6367]: 2023-11-05T15:52:59Z I! Loaded processors:
Nov 05 16:52:59 sailtrack-core telegraf[6367]: 2023-11-05T15:52:59Z I! Loaded secretstores:
Nov 05 16:52:59 sailtrack-core telegraf[6367]: 2023-11-05T15:52:59Z I! Loaded outputs: influxdb websocket
Nov 05 16:52:59 sailtrack-core telegraf[6367]: 2023-11-05T15:52:59Z I! Tags enabled: host=sailtrack-core
Nov 05 16:52:59 sailtrack-core telegraf[6367]: 2023-11-05T15:52:59Z I! [agent] Config: Interval:10s, Quiet:false, Hostname:"sailtrack-core", Flush Interval:10s
Nov 05 16:52:59 sailtrack-core systemd[1]: Started Telegraf.
Nov 05 16:52:59 sailtrack-core influxd-systemd-start.sh[5182]: ts=2023-11-05T15:52:59.137298Z lvl=info msg="Executing query" log_id=0lK1BWZ0000 service=query query="CREATE DATABASE \"sailtrack-data\""
Nov 05 16:52:59 sailtrack-core influxd-systemd-start.sh[5182]: [httpd] ::1 - admin [05/Nov/2023:16:52:59 +0100] "POST /query HTTP/1.1 {'q': 'CREATE DATABASE "sailtrack-data"'}" 200 57 "-" "Telegraf/1.28.3 Go/1.21.3" 64ac87aa-7bf3-11ee-8062-b827ebad2359 1603
Nov 05 16:52:59 sailtrack-core grafana[5231]: logger=authn.service t=2023-11-05T16:52:59.141326694+01:00 level=info msg="Failed to authenticate request" client=auth.client.api-key error="[api-key.invalid] API key is invalid"
Nov 05 16:52:59 sailtrack-core grafana[5231]: logger=context userId=0 orgId=0 uname= t=2023-11-05T16:52:59.141753725+01:00 level=info msg="Request Completed" method=GET path=/api/live/push/sailtrack-data status=403 remote_addr=[::1] time_ms=0 duration=579.583µs size=32 referer= handler=/api/live/push/:streamId
Nov 05 16:52:59 sailtrack-core telegraf[6367]: 2023-11-05T15:52:59Z E! [agent] Failed to connect to [outputs.websocket], retrying in 15s, error was "error dial: websocket: bad handshake"
Nov 05 16:53:14 sailtrack-core grafana[5231]: logger=authn.service t=2023-11-05T16:53:14.146443302+01:00 level=info msg="Failed to authenticate request" client=auth.client.api-key error="[api-key.invalid] API key is invalid"
Nov 05 16:53:14 sailtrack-core grafana[5231]: logger=context userId=0 orgId=0 uname= t=2023-11-05T16:53:14.146811532+01:00 level=info msg="Request Completed" method=GET path=/api/live/push/sailtrack-data status=403 remote_addr=[::1] time_ms=0 duration=544.791µs size=32 referer= handler=/api/live/push/:streamId
Nov 05 16:53:14 sailtrack-core telegraf[6367]: 2023-11-05T15:53:14Z E! [telegraf] Error running agent: connecting output outputs.websocket: error connecting to output "outputs.websocket": error dial: websocket: bad handshake
Nov 05 16:53:14 sailtrack-core systemd[1]: telegraf.service: Main process exited, code=exited, status=1/FAILURE
Nov 05 16:53:14 sailtrack-core systemd[1]: telegraf.service: Failed with result 'exit-code'.
Nov 05 16:53:14 sailtrack-core systemd[1]: telegraf.service: Scheduled restart job, restart counter is at 111.
Nov 05 16:53:14 sailtrack-core systemd[1]: Stopped Telegraf.

So the problem seems to be that telgraf can't communicate properly with grafana because the service did not start properly.. Through further analysis I seem to have noticed that the problem may be related to Automation_Custom_Script.sh Specifically at the end of/var/tmp/dietpi/logs/dietpi-automation_custom_script.log it shows:

[FAILED] /boot/dietpi/dietpi-services dietpi_controlled telegraf
[FAILED] Unable to continue, command will now terminate.
Magform commented 1 year ago

I solved the problem and subsequently also updated the process for obtaining Grafana API keys for Telegraf which now requires the creation of a service account. Probably same updates are needed also in Sailtrack Ground

matteocarnelos commented 1 year ago

I solved the problem and subsequently also updated the process for obtaining Grafana API keys for Telegraf which now requires the creation of a service account.

Exactly, that seems to be the issue here. I will test the fix in #25 as soon as I have some time.