Hey everyone, I could use a little help troubleshooting one of my feeders. I’ve noticed over the past few months that one of my stations keeps dropping off inexplicably. I initially thought it was some dodgy power getting to this particular Pi 3A+ so I would just throw a quick power cycle to get it going again. Sometimes it ran for weeks after the reboot, then sometimes a run might only last for a few days before it drops out. I even got to the point where I threw a smart plug on it just so I could cycle it remotely.
Finally had a bit of time recently to dig into it a little and recorded this after the latest outage:
pi@piaware:~ $ sudo piaware-status
PiAware master process (piaware) is running with pid 430.
PiAware ADS-B client (faup1090) is running with pid 4021.
PiAware ADS-B UAT client (faup978) is not running (disabled by configuration settings)
PiAware mlat client (fa-mlat-client) is running with pid 9150.
Local ADS-B receiver (dump1090-fa) is running with pid 414.
dump1090-fa (pid 414) is listening for ES connections on port 30005.
faup1090 is NOT connected to the ADS-B receiver.
piaware is NOT connected to FlightAware.
dump1090 is producing data on localhost:30005.
Your feeder ID is [omitted] (configured at /boot/piaware-config.txt:84)
There was also this on the tail end of the piaware.log:
Aug 23 23:11:12 piaware piaware[430]: mlat-client(9150): Receiver status: connected
Aug 23 23:11:12 piaware piaware[430]: mlat-client(9150): Server status: synchronized with 392 nearby receivers
Aug 23 23:11:12 piaware piaware[430]: mlat-client(9150): Receiver: 456.7 msg/s received 175.0 msg/s processed (38%)
Aug 23 23:11:12 piaware piaware[430]: mlat-client(9150): Server: 0.0 kB/s from server 0.0kB/s TCP to server 1.6kB/s UDP to server
Aug 23 23:11:12 piaware piaware[430]: mlat-client(9150): Results: 4.0 positions/minute
Aug 23 23:11:12 piaware piaware[430]: mlat-client(9150): Aircraft: 17 of 43 Mode S, 48 of 74 ADS-B used
Aug 23 23:11:38 piaware piaware[430]: 2566168 msgs recv'd from dump1090-fa (4235 in last 5m); 2565061 msgs sent to FlightAware
Aug 23 23:16:38 piaware piaware[430]: 2571210 msgs recv'd from dump1090-fa (5042 in last 5m); 2570103 msgs sent to FlightAware
Aug 23 23:21:38 piaware piaware[430]: 2575893 msgs recv'd from dump1090-fa (4683 in last 5m); 2574786 msgs sent to FlightAware
Aug 23 23:23:11 piaware piaware[430]: mlat-client(9150): Route MTU changed to 1500
Aug 23 23:23:44 piaware piaware[430]: mlat-client(9150): Route MTU changed to 1476
Aug 23 23:26:12 piaware piaware[430]: mlat-client(9150): Receiver status: connected
Aug 23 23:26:12 piaware piaware[430]: mlat-client(9150): Server status: synchronized with 398 nearby receivers
Aug 23 23:26:12 piaware piaware[430]: mlat-client(9150): Receiver: 483.7 msg/s received 170.1 msg/s processed (35%)
Aug 23 23:26:12 piaware piaware[430]: mlat-client(9150): Server: 0.0 kB/s from server 0.0kB/s TCP to server 1.6kB/s UDP to server
Aug 23 23:26:12 piaware piaware[430]: mlat-client(9150): Results: 0.5 positions/minute
Aug 23 23:26:12 piaware piaware[430]: mlat-client(9150): Aircraft: 15 of 58 Mode S, 49 of 70 ADS-B used
Aug 23 23:26:38 piaware piaware[430]: 2580300 msgs recv'd from dump1090-fa (4407 in last 5m); 2579193 msgs sent to FlightAware
Aug 23 23:31:38 piaware piaware[430]: 2584852 msgs recv'd from dump1090-fa (4552 in last 5m); 2583745 msgs sent to FlightAware
Aug 23 23:36:38 piaware piaware[430]: 2589660 msgs recv'd from dump1090-fa (4808 in last 5m); 2588553 msgs sent to FlightAware
Aug 23 23:41:13 piaware piaware[430]: mlat-client(9150): Receiver status: connected
Aug 23 23:41:13 piaware piaware[430]: mlat-client(9150): Server status: synchronized with 379 nearby receivers
Aug 23 23:41:13 piaware piaware[430]: mlat-client(9150): Receiver: 453.5 msg/s received 149.8 msg/s processed (33%)
Aug 23 23:41:13 piaware piaware[430]: mlat-client(9150): Server: 0.0 kB/s from server 0.0kB/s TCP to server 1.4kB/s UDP to server
Aug 23 23:41:13 piaware piaware[430]: mlat-client(9150): Results: 1.7 positions/minute
Aug 23 23:41:13 piaware piaware[430]: mlat-client(9150): Aircraft: 20 of 50 Mode S, 44 of 64 ADS-B used
Aug 23 23:41:38 piaware piaware[430]: 2594500 msgs recv'd from dump1090-fa (4840 in last 5m); 2593393 msgs sent to FlightAware
Aug 23 23:46:38 piaware piaware[430]: 2599763 msgs recv'd from dump1090-fa (5263 in last 5m); 2598656 msgs sent to FlightAware
Aug 23 23:51:38 piaware piaware[430]: 2605011 msgs recv'd from dump1090-fa (5248 in last 5m); 2603904 msgs sent to FlightAware
Aug 23 23:56:13 piaware piaware[430]: mlat-client(9150): Receiver status: connected
Aug 23 23:56:13 piaware piaware[430]: mlat-client(9150): Server status: synchronized with 414 nearby receivers
Aug 23 23:56:13 piaware piaware[430]: mlat-client(9150): Receiver: 502.9 msg/s received 167.7 msg/s processed (33%)
Aug 23 23:56:13 piaware piaware[430]: mlat-client(9150): Server: 0.0 kB/s from server 0.0kB/s TCP to server 1.4kB/s UDP to server
Aug 23 23:56:13 piaware piaware[430]: mlat-client(9150): Results: 4.9 positions/minute
Aug 23 23:56:13 piaware piaware[430]: mlat-client(9150): Aircraft: 22 of 83 Mode S, 44 of 61 ADS-B used
Aug 23 23:56:38 piaware piaware[430]: 2611559 msgs recv'd from dump1090-fa (6548 in last 5m); 2610452 msgs sent to FlightAware
Aug 23 23:57:20 piaware piaware[430]: Lost connection to adept server at piaware.flightaware.com/1200: server closed connection
Things I’ve tried so far:
Reimaged to the latest version of PiAware (output before the reimage was very similar to the above capture)
Double checked that I had nothing on my network conflicting with my Pi which I believe there is none
Restarting the piaware service via sudo systemctl restart piaware seems to act the same as a full reboot since it’s forcing a reconnection with the FA servers
Given that it’s the server closing the connection, is there anything else I could try on my end? I figured if it was a hardware issue I’d see some other sign in the normal Linux logs but the adept server connection loss line stood out to me since it was consistent even after the reimage.
Interesting stuff. So seems like I’ll be sticking with my smart plug remote reboot solution for now until 7.3 comes around. Maybe I should dust off the old scripting skills and create a cronjob that checks piaware status and automatically restart it to make it completely handsfree hah!
I’d be happy to provide more logs to help troubleshoot the next time I get notified that station drops out. For posterity’s sake, I did verify that the image I made was indeed the latest one and was using the FA patched tcl-tls:
I do find it interesting as I also have another station still on 6.1 that’s had no issues at all. I’m fairly certain this troublesome station was also on 6.1 before I reimaged. The only difference between my other station is that one is a 3B, otherwise they run the same basic 1090 antenna, blue ProStick, and 16 GB Micro Center microSD card.
Actually just encountered another disconnect right as I posted the above. Here’s the latest piaware.log:
Sep 1 01:23:19 piaware piaware[6941]: mlat-client(13664): Receiver status: connected
Sep 1 01:23:19 piaware piaware[6941]: mlat-client(13664): Server status: synchronized with 372 nearby receivers
Sep 1 01:23:19 piaware piaware[6941]: mlat-client(13664): Receiver: 339.9 msg/s received 119.5 msg/s processed (35%)
Sep 1 01:23:19 piaware piaware[6941]: mlat-client(13664): Server: 0.0 kB/s from server 0.0kB/s TCP to server 1.2kB/s UDP to server
Sep 1 01:23:19 piaware piaware[6941]: mlat-client(13664): Results: 6.9 positions/minute
Sep 1 01:23:19 piaware piaware[6941]: mlat-client(13664): Aircraft: 11 of 61 Mode S, 42 of 53 ADS-B used
Sep 1 01:23:25 piaware piaware[6941]: 4216708 msgs recv'd from dump1090-fa (2826 in last 5m); 4215106 msgs sent to FlightAware
Sep 1 01:27:10 piaware piaware[6941]: NOTICE from adept server: 18% of multilateration messages (UDP) are not reaching the server - check your network?
Sep 1 01:28:12 piaware piaware[6941]: NOTICE from adept server: 15% of multilateration messages (UDP) are not reaching the server - check your network?
Sep 1 01:28:25 piaware piaware[6941]: 4219579 msgs recv'd from dump1090-fa (2871 in last 5m); 4217977 msgs sent to FlightAware
Sep 1 01:29:49 piaware piaware[6941]: data isn't making it to FlightAware, reconnecting...
Sep 1 01:29:49 piaware piaware[6941]: multilateration data no longer required, disabling mlat client
Sep 1 01:29:50 piaware piaware[6941]: fa-mlat-client exited normally
Sep 1 01:29:50 piaware piaware[6941]: reconnecting in 5 seconds...
Sep 1 01:29:50 piaware piaware[6941]: mlat-client(13664): Disconnecting from localhost:30005: Lost connection to multilateration server, no need for input data
Sep 1 01:29:50 piaware piaware[6941]: mlat-client(13664): Exiting on connection loss
Sep 1 01:29:55 piaware piaware[6941]: Connecting to FlightAware adept server at piaware.flightaware.com/1200
Sep 1 01:29:55 piaware piaware[6941]: Connection with adept server at piaware.flightaware.com/1200 established
Sep 1 01:29:55 piaware piaware[6941]: TLS handshake with adept server at piaware.flightaware.com/1200 completed
Sep 1 01:29:55 piaware piaware[6941]: FlightAware server certificate validated
Sep 1 01:29:55 piaware piaware[6941]: encrypted session established with FlightAware
Sep 1 01:29:56 piaware piaware[6941]: logged in to FlightAware as user therandomuser
Sep 1 01:29:56 piaware piaware[6941]: my feeder ID is [omitted]
Sep 1 01:29:56 piaware piaware[6941]: site statistics URL: https://flightaware.com/adsb/stats/user/therandomuser#stats-123743
Sep 1 01:29:56 piaware piaware[6941]: multilateration data requested
Sep 1 01:29:56 piaware piaware[6941]: Starting multilateration client: /usr/lib/piaware/helpers/fa-mlat-client --input-connect localhost:30005 --input-type dump1090 --results beast,connect,localhost:30104 --results beast,listen,30105 --results ext_basestation,listen,30106 --udp-transport 2620:13d:c000:11::196:11961:2380866583
Sep 1 01:29:56 piaware piaware[6941]: mlat-client(25458): fa-mlat-client 0.2.12 starting up
Sep 1 01:29:56 piaware piaware[6941]: mlat-client(25458): Using UDP transport to 2620:13d:c000:11::196 port 11961
Sep 1 01:29:56 piaware piaware[6941]: mlat-client(25458): Listening for Beast-format results connection on port 30105
Sep 1 01:29:56 piaware piaware[6941]: mlat-client(25458): Listening for Extended Basestation-format results connection on port 30106
Sep 1 01:29:56 piaware piaware[6941]: mlat-client(25458): Route MTU changed to 1500
Sep 1 01:29:56 piaware piaware[6941]: mlat-client(25458): Input connected to localhost:30005
Sep 1 01:29:56 piaware piaware[6941]: mlat-client(25458): Input format changed to BEAST, 12MHz clock
Sep 1 01:29:57 piaware piaware[6941]: mlat-client(25458): Beast-format results connection with ::1:30104: connection established
Sep 1 01:30:33 piaware piaware[6941]: mlat-client(25458): Route MTU changed to 1476
Sep 1 01:33:25 piaware piaware[6941]: 4223568 msgs recv'd from dump1090-fa (3989 in last 5m); 4221905 msgs sent to FlightAware
Sep 1 01:34:07 piaware piaware[6941]: Lost connection to adept server at piaware.flightaware.com/1200: server closed connection
