bird became slow

[Alexander Shikov]

On Wed, Nov 09, 2016 at 09:12:03AM +0200, Alexander Shikov wrote:
> Hello!
> 
> My bird handles ~170 BGP peers, ~60000 routes. Every peer is in
> the separate table, then routes from peers' tables are exported
> to main table and vice versa.
> 
> Yesterday bird became very slow, BGP sessions started flapping.
> If I restart bird, it is stable for 5-10 minutes, and after that
> problem occurs again.
> 
> I see following messages in log:
> 
> Nov  9 09:00:30 rs0 kernel: sonewconn: pcb 0xfffff8005e640620: Listen queue overflow: 13 already in queue awaiting acceptance (637 occurrences)
> Nov  9 09:01:30 rs0 kernel: sonewconn: pcb 0xfffff8005e640620: Listen queue overflow: 13 already in queue awaiting acceptance (614 occurrences)
> Nov  9 09:01:56 rs0 bird: I/O loop cycle took 447740 ms for 427 events
> Nov  9 09:02:30 rs0 kernel: sonewconn: pcb 0xfffff8005e640620: Listen queue overflow: 13 already in queue awaiting acceptance (557 occurrences)
> 
> I'm still running 1.5.0, FreeBSD 10.3-RELEASE.
> Is that known issue? Has it been fixed in later releases?

I noticed today that it happens exact at a time when bird is 
being reconfigured. After reconfiguration bird is not able to 
process BGP KEEPALIVE for certain amount of time:

Nov 10 00:09:18 rs0 bird: ITCONS: Got KEEPALIVE
Nov 10 00:09:22 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 00:09:47 rs0 bird: ITCONS: Got KEEPALIVE
Nov 10 00:09:49 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 00:10:08 rs0 bird: ITCONS: Reconfigured
Nov 10 00:10:17 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 00:10:42 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 00:11:11 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 00:11:34 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 00:12:04 rs0 bird: ITCONS: Sending KEEPALIVE

...

Nov 10 02:09:29 rs0 bird: ITCONS: Got KEEPALIVE
Nov 10 02:09:51 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 02:09:58 rs0 bird: ITCONS: Got KEEPALIVE
Nov 10 02:10:10 rs0 bird: ITCONS: Reconfigured
Nov 10 02:10:18 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 02:10:48 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 02:11:18 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 02:11:42 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 02:12:12 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 02:12:40 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 02:13:09 rs0 bird: ITCONS: Sending KEEPALIVE

...

Nov 10 06:09:12 rs0 bird: ITCONS: Got KEEPALIVE
Nov 10 06:09:26 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 06:09:42 rs0 bird: ITCONS: Got KEEPALIVE
Nov 10 06:09:51 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 06:10:03 rs0 bird: ITCONS: Reconfigured
Nov 10 06:10:21 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 06:10:50 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 06:11:19 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 06:11:45 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 06:12:13 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 06:12:39 rs0 bird: ITCONS: Sending KEEPALIVE
Nov 10 06:13:04 rs0 bird: ITCONS: Sending KEEPALIVE


And sometimes it may be enough for bird to start closing
BGP sessions.

What am I missing?

-- 
Alexander Shikov
Technical Staff, Digital Telecom IX
Tel.: +380 44 201 14 07
http://dtel-ix.net/