Offline while sending messages


#1

Hi all,

I’m observing a strange behaviour of piaware 1.17. After upgrading to it, first everything looked fine. But in the middle of the night, FA stopped accepting my messages. This night I was able to match the logfile and the behaviour of the stats webpage.


11/17/2014 01:30:17 36642 msgs recv'd from dump1090 (24 in last 5m); 36840 msgs sent to FlightAware
11/17/2014 01:35:17 36653 msgs recv'd from dump1090 (11 in last 5m); 36852 msgs sent to FlightAware
11/17/2014 01:36:47 timed out waiting for alive message from FlightAware, reconnecting...
11/17/2014 01:36:47 reconnecting after 60s...
invalid command name "connect"
    while executing
"connect"
    ("after" script)
11/17/2014 01:40:17 36685 msgs recv'd from dump1090 (32 in last 5m); 36858 msgs sent to FlightAware
11/17/2014 01:45:17 36709 msgs recv'd from dump1090 (24 in last 5m); 36858 msgs sent to FlightAware
11/17/2014 01:50:17 36732 msgs recv'd from dump1090 (23 in last 5m); 36858 msgs sent to FlightAware
11/17/2014 01:55:17 36755 msgs recv'd from dump1090 (23 in last 5m); 36858 msgs sent to FlightAware
11/17/2014 02:00:17 36797 msgs recv'd from dump1090 (42 in last 5m); 36858 msgs sent to FlightAware
11/17/2014 02:05:17 36815 msgs recv'd from dump1090 (18 in last 5m); 36858 msgs sent to FlightAware
11/17/2014 02:10:17 36835 msgs recv'd from dump1090 (20 in last 5m); 36858 msgs sent to FlightAware
11/17/2014 02:15:17 36853 msgs recv'd from dump1090 (18 in last 5m); 36858 msgs sent to FlightAware
11/17/2014 02:20:17 36885 msgs recv'd from dump1090 (32 in last 5m); 36858 msgs sent to FlightAware


The error message looks like piaware is trying to reconnect but does not manage to do so. It continues to send messages without a connection…

All messages after 01:36:47 have not been counted by FA.

This continues till I manually restarted piaware:


11/17/2014 07:32:46 piaware is shutting down because it received a shutdown signal (SIGTERM) from the system...
11/17/2014 07:32:46 stop_faup1090: no need to stop faup1090, it's not running
11/17/2014 07:32:46 removing pidfile /var/run/piaware.pid
11/17/2014 07:32:46 piaware is exiting...
11/17/2014 07:32:54 ****************************************************
11/17/2014 07:32:54 piaware version 1.17 is running, process ID 2214
11/17/2014 07:32:54 your system info is: Linux raspberrypi 3.10.25+ #622 PREEMPT Fri Jan 3 18:41:00 GMT 2014 armv6l GNU/Linux
11/17/2014 07:32:54 connecting to FlightAware eyes.flightaware.com/1200
11/17/2014 07:32:56 FlightAware server SSL certificate validated
11/17/2014 07:32:56 encrypted session established with FlightAware
11/17/2014 07:32:56 autoUpdate is not configured in /etc/piaware or by piaware-config
11/17/2014 07:32:56 manualUpdate is not configured in /etc/piaware or by piaware-config
11/17/2014 07:32:57 ADS-B data program 'dump1090' is listening on port 30005, so far so good
11/17/2014 07:32:57 i see dump1090 serving on port 10001
11/17/2014 07:32:57 connecting to dump1090 on port 10001...
11/17/2014 07:32:57 piaware is connected to dump1090 on port 10001
11/17/2014 07:32:57 dump1090 is listening for connections on FA-style port 10001
11/17/2014 07:32:57 logged in to FlightAware as user jbrosowski
11/17/2014 07:33:01 piaware received a message from the ADS-B source!
11/17/2014 07:33:11 piaware has successfully sent several msgs to FlightAware!
11/17/2014 07:33:27 18 msgs recv'd from dump1090; 18 msgs sent to FlightAware
11/17/2014 07:33:55 server is sending alive messages; we will expect them
11/17/2014 07:38:27 186 msgs recv'd from dump1090 (168 in last 5m); 188 msgs sent to FlightAware
11/17/2014 07:43:27 269 msgs recv'd from dump1090 (83 in last 5m); 271 msgs sent to FlightAware


Any ideas?


#2

Something to do with syncing SSL keys that got self- corrected with the restart? Just speculating though.

I typically do a “clean restart” after updating software anyway, I.e., “sudo reboot” … But that’s just me. I want to make sure that the system will properly restart if there is a power loss (we occasionally get power “blinks” where I live…)


#3

My tcl is basically nonexistent but by comparison to other uses of “after” this looks like a bug in close_socket_and_reopen - shouldn’t it be using “[list $this connect]” not “[list adept connect]”?


#4

Thanks for the report. We rushed 1.17 to fix a problem and it appears this is a glitch – expect a 1.18 beta this morning.


#5

Can you try re-installing 1.17? I think you downloaded during a brief window on Saturday where we had the wrong build up.


#6

Okay, let’s test a reinstall.


#7

Tonight the reconnect worked fine.


11/18/2014 01:13:39 18262 msgs recv'd from dump1090 (8 in last 5m); 18371 msgs sent to FlightAware
11/18/2014 01:18:39 18264 msgs recv'd from dump1090 (2 in last 5m); 18374 msgs sent to FlightAware
11/18/2014 01:23:09 seconds since last message or startup (538) less than threshold for action (3600), waiting...
11/18/2014 01:23:09 dump1090 is listening for connections on FA-style port 10001
11/18/2014 01:23:39 18264 msgs recv'd from dump1090 (0 in last 5m); 18375 msgs sent to FlightAware
11/18/2014 01:28:09 seconds since last message or startup (838) less than threshold for action (3600), waiting...
11/18/2014 01:28:09 dump1090 is listening for connections on FA-style port 10001
11/18/2014 01:28:39 18264 msgs recv'd from dump1090 (0 in last 5m); 18376 msgs sent to FlightAware
11/18/2014 01:33:09 seconds since last message or startup (1138) less than threshold for action (3600), waiting...
11/18/2014 01:33:09 dump1090 is listening for connections on FA-style port 10001
11/18/2014 01:33:39 18264 msgs recv'd from dump1090 (0 in last 5m); 18377 msgs sent to FlightAware
11/18/2014 01:35:07 timed out waiting for alive message from FlightAware, reconnecting...
11/18/2014 01:35:07 reconnecting after 60s...
11/18/2014 01:36:07 connecting to FlightAware 70.42.6.203/1200
11/18/2014 01:36:08 FlightAware server SSL certificate validated
11/18/2014 01:36:08 encrypted session established with FlightAware
11/18/2014 01:36:09 autoUpdate is not configured in /etc/piaware or by piaware-config
11/18/2014 01:36:09 manualUpdate is not configured in /etc/piaware or by piaware-config
11/18/2014 01:36:10 logged in to FlightAware as user jbrosowski
11/18/2014 01:37:08 server is sending alive messages; we will expect them
11/18/2014 01:38:09 seconds since last message or startup (1438) less than threshold for action (3600), waiting...
11/18/2014 01:38:09 dump1090 is listening for connections on FA-style port 10001
11/18/2014 01:38:39 18264 msgs recv'd from dump1090 (0 in last 5m); 18378 msgs sent to FlightAware
11/18/2014 01:43:39 18270 msgs recv'd from dump1090 (6 in last 5m); 18385 msgs sent to FlightAware

Thank you very much for your help!!!