Master RTCM Timeout Regression in ASL3 (Build 22.10.1+asl3-3.10.5-1)

Great, thanks Greg.

Yes, if you can capture the console log at the same time from the Master RTCM to correlate with the Asterisk log, that would be helpful in trying to see who is initiating the timeout.

3.10.7 should significantly improve the packet processing on the host side, and reduce the amount of time/places we can get stuck processing client traffic.

I am working up another firmware release for the RTCM right now (will be 4.01), that addresses an identified issue that could be related. See Handle The ENC28J60 EIR_RXERIF Condition Properly and Keep StackTsk() From Being Flooded · Issue #36 · AllStarLink/Voter · GitHub for further explanation on the potential bug.

I am suspicious that there could be traffic keeping the RTCM busy processing incoming packets, instead of servicing the watchdog. But without seeing the console log from the Master RTCM, and correlating it with the Asterisk events, that is just speculation.

The incoming firmware update will also add a debug diagnostic to the firmware to see if the Ethernet chip is getting hammered and overflowing its RX buffer (which will lead to receive packets being dropped).

I need to compile and test that the firmware loads, then will advise when it is in the repository.

Lee

The aforementioned test firmware can be downloaded from: Voter/VOTER_RTCM-firmware/firmware-images/4.01 at fix-rxoverflow · AllStarLink/Voter · GitHub

Once it is installed, you can enable Debug 2 to monitor for receive buffer overflows. From the Main Menu: 14 --> 2 --> 99 --> r

The other fix in this firmware may help regardless, so you may or may not see any overflows (hopefully not).

I was able to force the buffer overflow by flooding the device with UDP traffic, so I can confirm the counter does in fact work.

Lee

Here's the last occurrence:

image

Interesting. When I try to post the latest screen shot, I get an error stating "An error occurred: Body is too similar to what you recently posted"

Apparently a spam filter is prohibiting my post. Let me see if I can work around this.

Trying again.

image

Let's see if this works.

asl3*CLI>
[2026-10-02 21:11:29.731] NOTICE[2806]: chan_voter.c:5414 voter_timer: VOTER 42833: Client Home_Rptr disconnect (timeout)
[2026-10-02 21:11:29.731] WARNING[2806]: chan_voter.c:5420 voter_timer: Lost master timing client, disconnecting remaining clients.
[2026-10-02 21:11:29.731] NOTICE[2806]: chan_voter.c:5424 voter_timer: VOTER 42833: Master changed from client Home_Rptr to NONE
[2026-10-02 21:11:29.731] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Pleasants_Peak
[2026-10-02 21:11:29.731] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Signal_Peak
[2026-10-02 21:11:29.731] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Pleasants_AstroTac
[2026-10-02 21:11:29.731] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Mirador
[2026-10-02 21:11:29.731] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: San_Miguel
[2026-10-02 21:11:29.731] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Mt_Wilson_Quantar
[2026-10-02 21:11:29.731] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Mt_Wilson_AstroTac
[2026-10-02 21:11:29.731] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Mt_Woodson
[2026-10-02 21:11:29.731] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Black_Mtn
[2026-10-02 21:11:29.731] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Lab_Test_Quantar
[2026-10-02 21:11:29.962] NOTICE[2805]: chan_voter.c:5976 voter_reader: VOTER 42833: Master changed from client NONE to Home_Rptr
[2026-10-02 21:11:35.292] WARNING[2805]: chan_voter.c:6030 voter_reader: VOTER lost master timing source!!
[2026-10-02 21:11:35.311] NOTICE[2806]: chan_voter.c:5414 voter_timer: VOTER 42833: Client Home_Rptr disconnect (timeout)
[2026-10-02 21:11:35.311] WARNING[2806]: chan_voter.c:5420 voter_timer: Lost master timing client, disconnecting remaining clients.
[2026-10-02 21:11:35.311] NOTICE[2806]: chan_voter.c:5424 voter_timer: VOTER 42833: Master changed from client Home_Rptr to NONE
[2026-10-02 21:11:35.311] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Pleasants_Peak
[2026-10-02 21:11:35.311] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Signal_Peak
[2026-10-02 21:11:35.311] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Pleasants_AstroTac
[2026-10-02 21:11:35.311] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Mirador
[2026-10-02 21:11:35.311] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: San_Miguel
[2026-10-02 21:11:35.311] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Mt_Wilson_Quantar
[2026-10-02 21:11:35.311] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Mt_Wilson_AstroTac
[2026-10-02 21:11:35.311] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Mt_Woodson
[2026-10-02 21:11:35.311] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Black_Mtn
[2026-10-02 21:11:35.311] WARNING[2806]: chan_voter.c:5435 voter_timer: Forcing disconnect of client: Lab_Test_Quantar
[2026-10-02 21:11:35.319] NOTICE[2805]: chan_voter.c:5729 voter_reader: Client Signal_Peak connection blocked until master client connects
[2026-10-02 21:11:35.676] NOTICE[2805]: chan_voter.c:5729 voter_reader: Client Mt_Woodson connection blocked until master client connects
[2026-10-02 21:11:36.174] NOTICE[2805]: chan_voter.c:5729 voter_reader: Client Black_Mtn connection blocked until master client connects
[2026-10-02 21:11:36.210] NOTICE[2805]: chan_voter.c:5729 voter_reader: Client Mt_Woodson connection blocked until master client connects
[2026-10-02 21:11:36.248] NOTICE[2805]: chan_voter.c:5865 voter_reader: VOTER 42833: Client Home_Rptr connected.
[2026-10-02 21:11:36.255] NOTICE[2805]: chan_voter.c:5976 voter_reader: VOTER 42833: Master changed from client NONE to Home_Rptr
[2026-10-02 21:11:36.280] NOTICE[2805]: chan_voter.c:5865 voter_reader: VOTER 29474: Client Pleasants_Peak connected.
[2026-10-02 21:11:36.358] NOTICE[2805]: chan_voter.c:5811 voter_reader: VOTER 29123: Client Mt_Wilson_AstroTac is sending mix mode flag, setting client to mix mode
[2026-10-02 21:11:36.358] NOTICE[2805]: chan_voter.c:5865 voter_reader: VOTER 29123: Client Mt_Wilson_AstroTac connected.
[2026-10-02 21:11:36.371] NOTICE[2805]: chan_voter.c:5865 voter_reader: VOTER 29474: Client Signal_Peak connected.
[2026-10-02 21:11:36.380] NOTICE[2805]: chan_voter.c:5865 voter_reader: VOTER 29123: Client Mt_Wilson_Quantar connected.
[2026-10-02 21:11:36.391] NOTICE[2805]: chan_voter.c:5811 voter_reader: VOTER 29476: Client San_Miguel is sending mix mode flag, setting client to mix mode
[2026-10-02 21:11:36.392] NOTICE[2805]: chan_voter.c:5865 voter_reader: VOTER 29476: Client San_Miguel connected.
[2026-10-02 21:11:36.421] NOTICE[2805]: chan_voter.c:5865 voter_reader: VOTER 29474: Client Pleasants_AstroTac connected.
[2026-10-02 21:11:36.445] NOTICE[2805]: chan_voter.c:5811 voter_reader: VOTER 29475: Client Mirador is sending mix mode flag, setting client to mix mode
[2026-10-02 21:11:36.445] NOTICE[2805]: chan_voter.c:5865 voter_reader: VOTER 29475: Client Mirador connected.
[2026-10-02 21:11:36.449] NOTICE[2805]: chan_voter.c:5811 voter_reader: VOTER 29111: Client Lab_Test_Quantar is sending mix mode flag, setting client to mix mode
[2026-10-02 21:11:36.449] NOTICE[2805]: chan_voter.c:5865 voter_reader: VOTER 29111: Client Lab_Test_Quantar connected.
[2026-10-02 21:11:36.682] NOTICE[2805]: chan_voter.c:5811 voter_reader: VOTER 29227: Client Black_Mtn is sending mix mode flag, setting client to mix mode
[2026-10-02 21:11:36.682] NOTICE[2805]: chan_voter.c:5865 voter_reader: VOTER 29227: Client Black_Mtn connected.
[2026-10-02 21:11:36.730] NOTICE[2805]: chan_voter.c:5811 voter_reader: VOTER 29222: Client Mt_Woodson is sending mix mode flag, setting client to mix mode
[2026-10-02 21:11:36.730] NOTICE[2805]: chan_voter.c:5865 voter_reader: VOTER 29222: Client Mt_Woodson connected.

10/03/2026 04:11:35.180 ERROR! Host response timeout
10/03/2026 04:11:35.180 Host Connection Lost (Pri) (10.4.73.22)
10/03/2026 04:11:36.220 Host Connection established (Pri) (10.4.73.22)

So this:

10/03/2026 04:11:35.180 ERROR! Host response timeout

Occurs before this:

[2026-10-02 21:11:35.292] WARNING[2805]: chan_voter.c:6030 voter_reader: VOTER lost master timing source!!

That seems to indicate that the Master RTCM thinks it hasn't heard from the host in >6 seconds, so it is the one that drops the connection. Not the host missing packets coming from the Master RTCM for 100ms.

Since we're using GPS timing here, I am hoping that those timestamps are very accurate. But the only way to get the "Host response timeout" is for the RTCM to be missing traffic for >6 seconds.

What is the duplex setting of Home_Rptr again?

Are these logs you just posted with the 4.01 firmware on the RTCM, or the original 3.00 firmware?

Lee

They are from the 3.00 firmware. The Master RTCM Ethernet Duplex is set to Full.

I installed 4.01 and am trying it now.

With 4.01, after about seven minutes I saw the Connection Lost/ Connection Established messages on the RTCM but no overflow messages.

Ok, thanks for the update, Greg.

I've got a couple other things to try and fix on the transmit side in the firmware in the RTCM, so I will work on those next, then go back to looking at the channel driver some more.

Can you describe what the network looks like between where Home_Rptr is and the Asterisk host?

I know above you mentioned that they are on the same VLAN, but physically separated. What exactly does that entail, including the types of switches being used?

Lee

The server has two switches between it and the router. The Master has two switches between it and the router, with the switch closest to the router being common for both devices.

The router is a Ubiquiti UDM SE which is connected to a Ubiquiti 48-port switch. The server is connected to another Ubiquiti 16-port switch, which is connected to the main 48-port switch. The Master RTCM is connected to a 24-port Cisco switch which is connected to the 48-port main switch.

Thanks, that helps me understand the architecture a bit better.

Have you looked at the port stats on the Cisco switch to see if the port is taking errors? I know I have seen my C3850's get unhappy in the past... can't remember why off the top of my head, but it effectively bounced the port once in a while.

My notes say I had to switch the port to 10/auto to clean things up... but I don't quote me on that.

I do know the RTCM doesn't do auto-negotiate. So an attached switch may not properly detect the 10mb/s speed... like a Cisco which may be too smart for its own good sometimes.

Still working on another firmware update to fix some transmit path bugs in the TCP/IP stack.

Lee

Do you happen to have 802.3x Ethernet flow control enabled on the switch? I have run into problems with switches that have it enabled where a sudden burst of traffic from a real-time source, like a node or RTCM, has hit the packet threshold and locked the port out for a period of time.

It did not used to be enabled by default, but it seems like a lot of things I encounter recently have it turned on. I am assuming it helps some other use case for it to be on, but I don’t know what it is. But I’m a network curmudgeon :slight_smile:

I have this setting on my UniFi switches. It doesn't specifically mention 802.3x, but it sounds consistent with what you’ve described. It isn't enabled by default although this is the way it's been configured for several years and I never had these issues until recently.

This is the current configuration of the Cisco switch:

So, there's a problem.

You said the RTCM was set for full duplex, but the Cisco is set for 10/half (looking at the actual negotiated port config on the right).

Turn of autonegotiation, the RTCM doesn't support it.

Manually set the port to 10/full, to match what the RTCM is configured for.

Lee

I changed to 10/Full, but same problem

The reason I suggested it is because if it's some code bug flooding enough packets at once to trigger flow control, that could be what's causing the drop and would hint at something to look at.

But my current settings are correct, right?

You have flow control disabled so that rules out what I was asking about.

Glad you got the duplex issue sorted out, Greg. That could definitely be a contributing factor for creating excess colissions and errors.

I've update the 4.01 firmware to add some more fixes for Microchip silicon errata that wasn't necessarily being handled well/properly in the firmware.

And in particular, there is a bug fix that could have prevented keepalive packets from being sent on the proper cadence under certain network conditions, which could lead to timeouts.

The updated firmware is still 4.01, but with today's date. It can be pulled from: Voter/VOTER_RTCM-firmware/firmware-images/4.01 at fix-ENC28J60-txrx · AllStarLink/Voter · GitHub

AFAIK, that should address the outstanding firmware issues, that I have been able to find.

Now back to looking at chan_voter.

Lee