MLAT not working on system reboot

[magnum]

Morning,

i am running two devices, both with Raspbian, dump1090-fa and the FR24 script as documented.

I have the small problem that the status of FR24 on one of my devices shows "NO" on "MLAT running".
Once i use the webinterface and restart the software from there, MLAT is working.

Any ideas why it is not working during reboot? MLAT is set to yes in the Settings of the software
Attached a screenshot for it after i used the "restart software" function. Before that the status of MLAT running is "No"


27-05-_2020_06-40-22.jpg

[Oblivian]

'avr-tcp' is generally the answer. Or not enough mixed position+position-less aircraft at the time to check for a reference and start sending.

Officially. The only thing that uses MLAT once it hits the server is 'DVBT'. (apparently)

Unofficially, it seems to do the same thing with beast-tcp (port 30005) and even non DVB stick but beast compatible receivers anyway so your guess is as good as ours.

But given that attitude, I wouldn't be bothering yourself even if it said no. I even asked why show MLAT status yes/no if it's only valid for DVBT to stop these very queries.

[magnum]

I already thought about ignoring it. But i usually would like to understand the root cause

As said i have two receivers at this location, both running without issues. One receiver shows this missing MLAT after reboot, the other not, configuration is exactly the same except the differrent feeder ID

And i also feed several other major sites from both receivers, for all MLAT is working properly.

[Oblivian]

The only way to find out is look at the log/as it starts using the service stop and sudo fr24feed start.

These 'status' pages are just.. tripe. And un-informative.

But it's most likely as I describe. There is a sequence for MLAT, and during start it verifies all sorts of stuff-

Contacts 2 different servers, checks for NTP/time sync, looks for reference aircraft.

If any of those fail, or run out of order/get delayed it seems to go into fault mode.

20-05-27 19:12:24.675 [E] Local time: 2020-05-27 19:12:24 +1200
20-05-27 19:12:24.679 [E] GMT+0 time: 2020-05-27 07:12:24 +1200
20-05-27 19:12:24.679 [E] Your machine should be set as GMT+0 time zone!

...

2020-05-27 19:12:24 | [main][i]Copyright 2012-2020 Flightradar24 AB
2020-05-27 19:12:24 | [main][i]https://www.flightradar24.com
2020-05-27 19:12:24 | [main][i]DNS mode: PING
2020-05-27 19:12:24 | [main][i]Automatic updates are ENABLED
2020-05-27 19:12:24 | ERROR: rmmod: ERROR: Module dvb_usb_rtl28xxu is in use
2020-05-27 19:12:24 | info | [httpd]Server started, listening on 0.0.0.0:8754
2020-05-27 19:12:26 | [i]PacketSenderConfiguration::fetch_config(): Yoda configuration for this receiver is disabled
2020-05-27 19:12:26 | [d]TLSConnection::ctor(): Enable verify_peer in production code!
2020-05-27 19:12:26 | [master][i]Starting processing thread
2020-05-27 19:12:26 | [reader][i]Initializing reader
2020-05-27 19:12:26 | [reader][i]Connecting to DVBT receiver via (exe:///usr/bin/dump1090-mutability --raw --mlat)
2020-05-27 19:12:26 | [main][i]Reader thread started
2020-05-27 19:12:26 | [reader][i]Connected to the receiver, configuring
2020-05-27 19:12:26 | [reader][i]Configured, processing messages

Already waiting for MLAT stuff..
2020-05-27 19:12:26 | [mlat][i]Waiting for MLAT configuration
2020-05-27 19:12:26 | [main][i]MLAT data feed started
Wed May 27 19:12:26 2020 NZST dump1090-mutability v1.15~dev starting up.
Using sample converter: UC8, integer/table path
Found 1 device(s):
0: Realtek, RTL2838UHIDIR, SN: 00000001 (currently selected)
Detached kernel driver
Found Rafael Micro R820T tuner
2020-05-27 19:12:27 | [time][i]Synchronizing time via NTP
2020-05-27 19:12:27 | [time][i]Time synchronized correctly, offset -0.001 seconds
2020-05-27 19:12:27 | [main][i]Feed Network client started
2020-05-27 19:12:27 | [feed][i]Downloading configuration
2020-05-27 19:12:27 | [feed][d]fetching configuration
Max available gain is: 49.60 dB
Setting gain to: 49.60 dB
Gain reported by device: 49.60 dB
2020-05-27 19:12:29 | [feed][i]configuring decoder
2020-05-27 19:12:29 | [feed][c]Max range AIR: 350.0nm
2020-05-27 19:12:29 | [feed][c]Max range GND: 100.0nm
2020-05-27 19:12:29 | [feed][i]configuration changed
2020-05-27 19:12:29 | [feed][i]defined 3 servers
2020-05-27 19:12:29 | [feed][c]Timestamps: optional
2020-05-27 19:12:29 | info | Stopping ReceiverACSender threads for feed

(normal feed data server receiving)
2020-05-27 19:12:29 | info | Configured ReceiverACSender: 185.218.24.22:8099,185.218.24.23:8099,185.218.24.2 4:8099, feed: NZCH1, send_interval: 5s, max age: 15s, send metadata: true, mode: 0, filtering: true

2020-05-27 19:12:29 | info | [stats]Stats thread started
2020-05-27 19:12:29 | info | Network thread connecting to 185.218.24.22:8099 for feed NZCH1
2020-05-27 19:12:29 | [feed][n]NZCH1@185.218.24.22:8099/TCP
2020-05-27 19:12:29 | [feed][n]connecting
2020-05-27 19:12:30 | [feed][n]connected via TCP (fd 28)

Woohoo!:
2020-05-27 19:12:30 | [feed][i]Feed connected
2020-05-27 19:12:30 | [feed][n]working


2020-05-27 19:12:56 | [reader][i]Timestamp source changed from UNKNOWN to SYSTEM-VALIDATED

Now the config finally catches up with the MLAT starting earlier..

2020-05-27 19:12:57 | [mlat][i]MLAT configuration received, service ENABLED
2020-05-27 19:12:57 | [mlat][i]Starting MLAT with preconfigured position: xxxxxx
2020-05-27 19:12:57 | [mlat][i]MLAT bandwidth reduction active, level 1

And the MLAT local APAC upload server

2020-05-27 19:12:57 | [mlat][i]Configuring UDP connection udp://australia.fr24.com:19788


2020-05-27 19:12:57 | [mlat][i]Registering MLAT station
2020-05-27 19:12:57 | [mlat][i]Registering MLAT station: SUCCESS

And because no aircraft.. it will still show status 'down' until it gets some

2020-05-27 19:12:59 | [mlat][i]No ADS-B time reference available (0/0)
2020-05-27 19:12:59 | [mlat][i]Pinging the server
2020-05-27 19:12:59 | [mlat][i]Stats 1391530/1391530

When you do get some, it changes

2020-05-27 19:21:23 | [feed][i]sent 1,0 AC
2020-05-27 19:21:30 | [mlat][i]No ADS-B time reference available (0/1)
2020-05-27 19:21:30 | [feed][i]sent 1,0 AC
2020-05-27 19:21:36 | [feed][i]sent 1,0 AC
2020-05-27 19:21:40 | [mlat][i]Received ADS-B time references AC:
2020-05-27 19:21:40 | [mlat][i] C8200B

If you also look at the 8754/monitor.txt this is put into a plain text file

the Mlat_problem has been previously identified as 'last known error' And because it starts so early and has to wait logs that

mlat-mode="UDP"
mlat-number-seen="1"
mlat-ok="YES"
mlat-started="YES"
mlat-time-last-seen="1590564094"
mlat-time-stats="1590564096"
mlat-uplink-stats="0"
mlat_problem="no-config"
msg_ring_full="false"
msg_ring_length="0"
ntp_queries="3"
num_messages="25"
num_resyncs="0"
offline-mode="no"
open_fds="32"
rx_connected="1"
shutdown="no"
time_update_utc="1590564088"
time_update_utc_s="2020-05-27 07:21:28"
timestamp_source="SYSTEM-VALIDATED"
timing_is_valid="1"
timing_last_drift="-0.000"
timing_last_offset="-0.000"
timing_last_result="success"
timing_source="NTP"
timing_time_last_attempt="1590564080"
timing_time_last_success="1590564080"
timing_time_since_last_success="1590564080"

[magnum]

That's what i checked now.

Looks like the time sync of the device takes too long, so the MLAT process timed out.
This message appears a few seconds before the time sync of the device was successful.

2020-05-18 11:08:30 | [mlat][e]Receiver not compatible with MLAT, timestamps in wrong format![main][w]Failed to synchronize time, waiting 8 seconds

I will check if I can delay the start of the FR24 script for some seconds

[Oblivian]

AVR-TCP doesn't encode the time of arrival right

Change it to beast-tcp/30005

[magnum]

Change it to beast-tcp/30005

Changed it now on both receivers, i will see what happens on next reboot. Thanks for the advice