Wonderful. Thank you Brooks for sharing your finding. I will add a note
to documentation, it seems very relevant.
Paolo
On Sun, Oct 13, 2019 at 12:50:43PM -0400, Brooks Swinnerton wrote:
> Got it! I think for some reason BIRD didn't like that both BGP instances
> were sharing the same address. Here is the new configuration on both sides
> which works:
>
> ```
> !
> ! pmacctd configuration example
> !
> ! Did you know CONFIG-KEYS contains the detailed list of all configuration
> keys
> ! supported by 'nfacctd' and 'pmacctd' ?
> !
> ! debug: true
> daemonize: false
> pcap_interface: ens3
> pmacctd_as: bgp
> pmacctd_net: bgp
> sampling_rate: 10
> !
> bgp_daemon: true
> bgp_daemon_ip: 127.0.0.2
> bgp_daemon_port: 180
> bgp_daemon_max_peers: 10
> bgp_agent_map: /etc/pmacct/peering_agent.map
> bgp_table_dump_file: /tmp/bgp-$peer_src_ip-%H%M.log
> bgp_table_dump_refresh_time: 120
> !
> aggregate: src_host, dst_host, src_port, dst_port, src_as, dst_as, proto
> !
> plugins: kafka
> kafka_output: json
> kafka_broker_host: kafka.fqdn.com
> kafka_topic: pmacct.acct
> kafka_refresh_time: 10
> kafka_history: 5m
> kafka_history_roundoff: m
> ```
>
> And in BIRD:
>
> ```
> protocol bgp AS000000v4c1 from monitor46 {
> description "pmacctd";
> local 127.0.0.1 as 000000;
> neighbor 127.0.0.2 port 180 as 000000;
> rr client;
> }
> ```
>
> Thank you so much for the tip about 127.0.0.2, Paolo!
>
> On Sun, Oct 13, 2019 at 11:35 AM Paolo Lucente <pa...@pmacct.net> wrote:
>
> >
> > So the session comes up and gets established: this would rule out firewall
> > filters, TCP MD5 or session mis-configurations (AS numbers, capabilities,
> > etc.). This should also mean that the BGP OPEN process is successful (this
> > is also confirmed by pmacct log you sent earlier on).
> >
> > Now, from the tcpdump output you sent, looking at the tiny packet sizes
> > i would almost say those are BGP keepalives; if not timestamps reveal they
> > do take place too frequently (so they are not BGP keepalives). They could
> > still be BGP UPDATEs and it would take longer to transfer 150k prefixes at
> > that pace but, yeah, weird. It would be great to confirm if those packets
> > are BGP UPDATEs: perhaps tcpdump sees port 180/tcp and does not apply
> > the BGP decoder (and hence you can't see the expected BGP cleartext in the
> > tcpdump output); you could save it and open and decode with Wireshark (or
> > setup a 127.0.0.2 and do a 127.0.0.1:179 <-> 127.0.0.2:179 peering.
> >
> > Really not sure what is going on :-? Also, if you prefer, we could continue
> > the troubleshooting via unicast email and summarize findings on list later.
> >
> > Paolo
> >
> > On Sun, Oct 13, 2019 at 10:55:55AM -0400, Brooks Swinnerton wrote:
> > > Oops, sorry I mismatched the tcpdump and bgp table dump values. They were
> > > both indeed using 55881 at the time, but here is another capture that
> > will
> > > make more sense:
> > >
> > > ```
> > > {"timestamp": "2019-10-13 14:48:00", "peer_ip_src": "127.0.0.1",
> > > "peer_tcp_port": 36143, "event_type": "dump_close", "entries": 0,
> > "tables":
> > > 1, "seq": 4}
> > > {"timestamp": "2019-10-13 14:50:00", "peer_ip_src": "127.0.0.1",
> > > "peer_tcp_port": 36143, "event_type": "dump_init", "dump_period": 120,
> > > "seq": 5}
> > > {"timestamp": "2019-10-13 14:50:00", "peer_ip_src": "127.0.0.1",
> > > "peer_tcp_port": 36143, "event_type": "dump_close", "entries": 0,
> > "tables":
> > > 1, "seq": 5}
> > > {"timestamp": "2019-10-13 14:52:00", "peer_ip_src": "127.0.0.1",
> > > "peer_tcp_port": 36143, "event_type": "dump_init", "dump_period": 120,
> > > "seq": 6}
> > > {"timestamp": "2019-10-13 14:52:00", "peer_ip_src": "127.0.0.1",
> > > "peer_tcp_port": 36143, "event_type": "dump_close", "entries": 0,
> > "tables":
> > > 1, "seq": 6}
> > > {"timestamp": "2019-10-13 14:54:00", "peer_ip_src": "127.0.0.1",
> > > "peer_tcp_port": 36143, "event_type": "dump_init", "dump_period": 120,
> > > "seq": 7}
> > > {"timestamp": "2019-10-13 14:54:00", "peer_ip_src": "127.0.0.1",
> > > "peer_tcp_port": 36143, "event_type": "dump_close", "entries": 0,
> > "tables":
> > > 1, "seq": 7}
> > > ```
> > >
> > > ```
> > > $ sudo tcpdump -nv -i any tcp port 180 and host 127.0.0.1
> > > tcpdump: listening on any, link-type LINUX_SLL (Linux cooked), capture
> > size
> > > 262144 bytes
> > > 14:55:05.277665 IP (tos 0xc0, ttl 64, id 3378, offset 0, flags [DF],
> > proto
> > > TCP (6), length 79)
> > > 127.0.0.1.36143 > 127.0.0.1.180: Flags [P.], cksum 0xfe43 (incorrect
> > ->
> > > 0x58be), seq 100499878:100499905, ack 1900709696, win 342, options
> > > [nop,nop,TS val 1973199584 ecr 1973197086], length 27
> > > 14:55:05.277694 IP (tos 0x0, ttl 64, id 35509, offset 0, flags [DF],
> > proto
> > > TCP (6), length 52)
> > > 127.0.0.1.180 > 127.0.0.1.36143: Flags [.], cksum 0xfe28 (incorrect
> > ->
> > > 0x383e), ack 27, win 342, options [nop,nop,TS val 1973199584 ecr
> > > 1973199584], length 0
> > > 14:55:05.282623 IP (tos 0xc0, ttl 64, id 3379, offset 0, flags [DF],
> > proto
> > > TCP (6), length 83)
> > > 127.0.0.1.36143 > 127.0.0.1.180: Flags [P.], cksum 0xfe47 (incorrect
> > ->
> > > 0x64b5), seq 27:58, ack 1, win 342, options [nop,nop,TS val 1973199589
> > ecr
> > > 1973199584], length 31
> > > 14:55:05.282652 IP (tos 0x0, ttl 64, id 35510, offset 0, flags [DF],
> > proto
> > > TCP (6), length 52)
> > > 127.0.0.1.180 > 127.0.0.1.36143: Flags [.], cksum 0xfe28 (incorrect
> > ->
> > > 0x3815), ack 58, win 342, options [nop,nop,TS val 1973199589 ecr
> > > 1973199589], length 0
> > > 14:55:05.436293 IP (tos 0xc0, ttl 64, id 3380, offset 0, flags [DF],
> > proto
> > > TCP (6), length 91)
> > > 127.0.0.1.36143 > 127.0.0.1.180: Flags [P.], cksum 0xfe4f (incorrect
> > ->
> > > 0xb7db), seq 58:97, ack 1, win 342, options [nop,nop,TS val 1973199742
> > ecr
> > > 1973199589], length 39
> > > 14:55:05.436330 IP (tos 0x0, ttl 64, id 35511, offset 0, flags [DF],
> > proto
> > > TCP (6), length 52)
> > > 127.0.0.1.180 > 127.0.0.1.36143: Flags [.], cksum 0xfe28 (incorrect
> > ->
> > > 0x36bb), ack 97, win 342, options [nop,nop,TS val 1973199743 ecr
> > > 1973199742], length 0
> > > ```
> > >
> > > On Sun, Oct 13, 2019 at 10:53 AM Brooks Swinnerton <
> > bswinner...@gmail.com>
> > > wrote:
> > >
> > > > > 1) as super extra check, can you capture stuff with Wireshark and see
> > > > what is going on 'on the wire'? Do you see the routes being sent and
> > > > landing onto pmacct, etc.?
> > > >
> > > > Gosh, I'm stumped. I do see traffic on port 180 and the port that is
> > > > referenced in the table dump, but it's not the cleartext BGP traffic I
> > was
> > > > expecting:
> > > >
> > > > ```
> > > > 127.0.0.1.36143 > 127.0.0.1.180: Flags [P.], cksum 0xfe4b
> > (incorrect
> > > > -> 0xfc0d), seq 9200:9235, ack 234, win 342, options [nop,nop,TS val
> > > > 1972706066 ecr 1972699157], length 35
> > > > 14:46:51.746910 IP (tos 0x0, ttl 64, id 34830, offset 0, flags [DF],
> > proto
> > > > TCP (6), length 52)
> > > > 127.0.0.1.180 > 127.0.0.1.36143: Flags [.], cksum 0xfe28
> > (incorrect ->
> > > > 0x9b98), ack 9235, win 342, options [nop,nop,TS val 1972706066 ecr
> > > > 1972706066], length 0
> > > > 14:46:51.988455 IP (tos 0xc0, ttl 64, id 2700, offset 0, flags [DF],
> > proto
> > > > TCP (6), length 91)
> > > > 127.0.0.1.36143 > 127.0.0.1.180: Flags [P.], cksum 0xfe4f
> > (incorrect
> > > > -> 0x1b06), seq 9235:9274, ack 234, win 342, options [nop,nop,TS val
> > > > 1972706308 ecr 1972706066], length 39
> > > > 14:46:51.988488 IP (tos 0x0, ttl 64, id 34831, offset 0, flags [DF],
> > proto
> > > > TCP (6), length 52)
> > > > 127.0.0.1.180 > 127.0.0.1.36143: Flags [.], cksum 0xfe28
> > (incorrect ->
> > > > 0x998d), ack 9274, win 342, options [nop,nop,TS val 1972706308 ecr
> > > > 1972706308], length 0
> > > > ```
> > > >
> > > > Which aligns with:
> > > >
> > > > ```
> > > > {"timestamp": "2019-10-13 14:40:00", "peer_ip_src": "127.0.0.1",
> > > > "peer_tcp_port": 55881, "event_type": "dump_init", "dump_period": 120,
> > > > "seq": 0}
> > > > {"timestamp": "2019-10-13 14:40:00", "peer_ip_src": "127.0.0.1",
> > > > "peer_tcp_port": 55881, "event_type": "dump_close", "entries": 0,
> > "tables":
> > > > 1, "seq": 0}
> > > > {"timestamp": "2019-10-13 14:42:00", "peer_ip_src": "127.0.0.1",
> > > > "peer_tcp_port": 55881, "event_type": "dump_init", "dump_period": 120,
> > > > "seq": 1}
> > > > {"timestamp": "2019-10-13 14:42:00", "peer_ip_src": "127.0.0.1",
> > > > "peer_tcp_port": 55881, "event_type": "dump_close", "entries": 0,
> > "tables":
> > > > 1, "seq": 1}
> > > > ```
> > > >
> > > > Is it normal that `peer_tcp_port` is a random port and not 179? I know
> > > > pmacctd's BGP port is listening on 180, but the peer port (BIRD) is
> > 179:
> > > >
> > > > ```
> > > > bgp_daemon: true
> > > > bgp_daemon_ip: 127.0.0.1
> > > > bgp_daemon_port: 180
> > > > ```
> > > >
> > > > I've also went ahead and removed any filters that were previously in
> > place
> > > > in BIRD so it should be sending all prefixes.
> > > >
> > > > On Sun, Oct 13, 2019 at 10:08 AM Paolo Lucente <pa...@pmacct.net>
> > wrote:
> > > >
> > > >>
> > > >> Hi Brooks,
> > > >>
> > > >> Wow, interesting yes. Your decoding is right: BGP table is empty. May
> > i
> > > >> ask you two things: 1) as super extra check, can you capture stuff
> > with
> > > >> Wireshark and see what is going on 'on the wire'? Do you see the
> > routes
> > > >> being sent and landing onto pmacct, etc.? 2) Should that be the case,
> > > >> ie. all looks good, could you try master code on GitHub? Should also
> > > >> that one not work, we should find a way for me to reproduce this (as i
> > > >> tested the scenario and it appears to work for me against an ExaBGP)
> > or,
> > > >> let me just mention it, troubleshoot stuff on your box.
> > > >>
> > > >> Paolo
> > > >>
> > > >> On Sun, Oct 13, 2019 at 08:46:47AM -0400, Brooks Swinnerton wrote:
> > > >> > Thank you Paolo,
> > > >> >
> > > >> > Interesting, it looks like the pmacctd end of the BGP session isn't
> > > >> picking
> > > >> > up the routes if I'm reading the `bgp_table_dump_file` correctly:
> > > >> >
> > > >> > ```
> > > >> > {"timestamp": "2019-10-13 12:42:00", "peer_ip_src": "127.0.0.1",
> > > >> > "peer_tcp_port": 39587, "event_type": "dump_init", "dump_period":
> > 120,
> > > >> > "seq": 0}
> > > >> > {"timestamp": "2019-10-13 12:42:00", "peer_ip_src": "127.0.0.1",
> > > >> > "peer_tcp_port": 39587, "event_type": "dump_close", "entries": 0,
> > > >> "tables":
> > > >> > 1, "seq": 0}
> > > >> > ```
> > > >> >
> > > >> > But looking at the BIRD side of things, I can see the routes are
> > indeed
> > > >> > being exported:
> > > >> >
> > > >> > ```
> > > >> > bird> show route export AS000000v4 count
> > > >> > 172973 of 336950 routes for 173059 networks in table master4
> > > >> > ```
> > > >> >
> > > >> > On Sun, Oct 13, 2019 at 8:30 AM Paolo Lucente <pa...@pmacct.net>
> > wrote:
> > > >> >
> > > >> > >
> > > >> > > Hi Brooks,
> > > >> > >
> > > >> > > +1 to Felix's answer. Also maybe two obvious pointsa: 1) with an
> > iBGP
> > > >> > > peering setup, AS0 can mean unknown or your own ASN (being a
> > number
> > > >> > > rather than a string, null is not an option) and 2) until routes
> > are
> > > >> > > received, source/destination IP prefixes can get associated to
> > AS0.
> > > >> > >
> > > >> > > Config looks good as well as the log extract you posted. For more
> > > >> debug
> > > >> > > info you can perhaps dump routes received via BGP just to make
> > extra
> > > >> > > sure all is well on that side of the things too, ie.:
> > > >> > >
> > > >> > > bgp_table_dump_file: /path/to/spool/bgp-$peer_src_ip-%H%M.log
> > > >> > > bgp_table_dump_refresh_time: 120
> > > >> > >
> > > >> > > Let us know how it goes.
> > > >> > >
> > > >> > > Paolo
> > > >> > >
> > > >> > > On Sat, Oct 12, 2019 at 11:36:12PM -0400, Brooks Swinnerton wrote:
> > > >> > > > Hello there!
> > > >> > > >
> > > >> > > > I have pmacctd working with the Kafka addon and am attempting to
> > > >> include
> > > >> > > > `src_as` and `dst_as` information based on the BGP sessions
> > running
> > > >> on
> > > >> > > the
> > > >> > > > same machine using the [BIRD router](https://bird.network.cz).
> > > >> > > >
> > > >> > > > I was able to successfully get the BGP session stood up using a
> > > >> loopback
> > > >> > > > address, but in both the Kafka consumer and `pmacct -s`, I do
> > not
> > > >> see the
> > > >> > > > AS values:
> > > >> > > >
> > > >> > > > ```
> > > >> > > > {"event_type": "purge", "as_src": 0, "as_dst": 0, "ip_src":
> > > >> "1.1.1.138",
> > > >> > > > "ip_dst": "5.9.43.211", "port_src": 443, "port_dst": 48268,
> > > >> "ip_proto":
> > > >> > > > "tcp", "stamp_inserted": "2019-10-13 02:50:00", "stamp_updated":
> > > >> > > > "2019-10-13 02:53:31", "packets": 1, "bytes": 52, "writer_id":
> > > >> > > > "default_kafka/3725"}
> > > >> > > > ```
> > > >> > > >
> > > >> > > > The pmacct log seems good:
> > > >> > > >
> > > >> > > > ```
> > > >> > > > Oct 13 02:51:37 bdr-nyiix pmacctd[3666]: INFO ( default/core ):
> > > >> > > Promiscuous
> > > >> > > > Mode Accounting Daemon, pmacctd 1.7.3-git (20190418-00+c4)
> > > >> > > > Oct 13 02:51:37 bdr-nyiix pmacctd[3666]: INFO ( default/core ):
> > > >> > > > '--enable-kafka' '--enable-jansson' '--enable-l2'
> > '--enable-64bit'
> > > >> > > > '--enable-traffic-bins' '-
> > > >> > > > Oct 13 02:51:37 bdr-nyiix pmacctd[3666]: INFO ( default/core ):
> > > >> Reading
> > > >> > > > configuration file '/etc/pmacct/pmacctd.peering.conf'.
> > > >> > > > Oct 13 02:51:37 bdr-nyiix pmacctd[3666]: INFO (
> > default_kafka/kafka
> > > >> ):
> > > >> > > > cache entries=16411 base cache memory=54878384 bytes
> > > >> > > > Oct 13 02:51:38 bdr-nyiix pmacctd[3666]: INFO ( default/core ):
> > > >> [ens3,0]
> > > >> > > > link type is: 1
> > > >> > > > Oct 13 02:51:38 bdr-nyiix pmacctd[3666]: INFO ( default/core ):
> > > >> > > > [/etc/pmacct/peering_agent.map] (re)loading map.
> > > >> > > > Oct 13 02:51:38 bdr-nyiix pmacctd[3666]: INFO ( default/core ):
> > > >> > > > [/etc/pmacct/peering_agent.map] map successfully (re)loaded.
> > > >> > > > Oct 13 02:51:38 bdr-nyiix pmacctd[3666]: INFO (
> > default_kafka/kafka
> > > >> ):
> > > >> > > > JSON: setting object handlers.
> > > >> > > > Oct 13 02:51:38 bdr-nyiix pmacctd[3666]: INFO (
> > default/core/BGP ):
> > > >> > > maximum
> > > >> > > > BGP peers allowed: 2
> > > >> > > > Oct 13 02:51:38 bdr-nyiix pmacctd[3666]: INFO (
> > default/core/BGP ):
> > > >> > > waiting
> > > >> > > > for BGP data on 127.0.0.1:180
> > > >> > > > Oct 13 02:51:41 bdr-nyiix pmacctd[3666]: INFO (
> > default_kafka/kafka
> > > >> ):
> > > >> > > ***
> > > >> > > > Purging cache - START (PID: 3673) ***
> > > >> > > > Oct 13 02:51:41 bdr-nyiix pmacctd[3666]: INFO (
> > default_kafka/kafka
> > > >> ):
> > > >> > > ***
> > > >> > > > Purging cache - END (PID: 3673, QN: 0/0, ET: 0) ***
> > > >> > > > Oct 13 02:51:41 bdr-nyiix pmacctd[3666]: INFO (
> > default/core/BGP ):
> > > >> > > > [127.0.0.1] BGP peers usage: 1/2
> > > >> > > > Oct 13 02:51:41 bdr-nyiix pmacctd[3666]: INFO (
> > default/core/BGP ):
> > > >> > > > [1.1.1.1] Capability: MultiProtocol [1] AFI [1] SAFI [1]
> > > >> > > > Oct 13 02:51:41 bdr-nyiix pmacctd[3666]: INFO (
> > default/core/BGP ):
> > > >> > > > [1.1.1.1] Capability: 4-bytes AS [41] ASN [300000]
> > > >> > > > Oct 13 02:51:41 bdr-nyiix pmacctd[3666]: INFO (
> > default/core/BGP ):
> > > >> > > > [1.1.1.1] BGP_OPEN: Local AS: 300000 Remote AS: 397143
> > HoldTime: 90
> > > >> > > > Oct 13 02:51:51 bdr-nyiix pmacctd[3666]: INFO (
> > default_kafka/kafka
> > > >> ):
> > > >> > > ***
> > > >> > > > Purging cache - START (PID: 3678) ***
> > > >> > > > Oct 13 02:51:53 bdr-nyiix pmacctd[3666]: INFO (
> > default_kafka/kafka
> > > >> ):
> > > >> > > ***
> > > >> > > > Purging cache - END (PID: 3678, QN: 679/679, ET: 0) ***
> > > >> > > > ```
> > > >> > > >
> > > >> > > > And the configuration is as follows:
> > > >> > > >
> > > >> > > > ```
> > > >> > > > !
> > > >> > > > ! pmacctd configuration example
> > > >> > > > !
> > > >> > > > ! Did you know CONFIG-KEYS contains the detailed list of all
> > > >> > > configuration
> > > >> > > > keys
> > > >> > > > ! supported by 'nfacctd' and 'pmacctd' ?
> > > >> > > > !
> > > >> > > > ! debug: true
> > > >> > > > daemonize: false
> > > >> > > > pcap_interface: ens3
> > > >> > > > aggregate: src_host, dst_host, src_port, dst_port, src_as,
> > dst_as,
> > > >> proto
> > > >> > > > sampling_rate: 10
> > > >> > > > !
> > > >> > > > plugins: kafka
> > > >> > > > kafka_output: json
> > > >> > > > kafka_broker_host: kafka-broker.fqdn.com
> > > >> > > > kafka_topic: pmacct.acct
> > > >> > > > kafka_refresh_time: 10
> > > >> > > > kafka_history: 5m
> > > >> > > > kafka_history_roundoff: m
> > > >> > > > !
> > > >> > > > bgp_daemon: true
> > > >> > > > bgp_daemon_ip: 127.0.0.1
> > > >> > > > bgp_daemon_port: 180
> > > >> > > > bgp_daemon_max_peers: 1
> > > >> > > > bgp_agent_map: /etc/pmacct/peering_agent.map
> > > >> > > > pmacctd_as: bgp
> > > >> > > > ```
> > > >> > > >
> > > >> > > > With the /etc/pmacct/peering_agent.map as:
> > > >> > > >
> > > >> > > > ```
> > > >> > > > bgp_ip=1.1.1.1 ip=0.0.0.0/0
> > > >> > > > ```
> > > >> > > >
> > > >> > > > And the other end of the BGP configuration (in BIRD) being:
> > > >> > > >
> > > >> > > > ```
> > > >> > > > protocol bgp AS300000v4c1 from transit_customer4 {
> > > >> > > > description "pmacctd";
> > > >> > > > local 127.0.0.1 port 179 as 300000;
> > > >> > > > neighbor 127.0.0.1 port 180 as 300000;
> > > >> > > > rr client;
> > > >> > > > }
> > > >> > > > ```
> > > >> > > >
> > > >> > > > And it has exported ~150k routes.
> > > >> > > >
> > > >> > > > Is there anything obvious that I'm doing wrong or perhaps a way
> > > >> that I
> > > >> > > can
> > > >> > > > turn on more debugging to lead me on the right trail?
> > > >> > >
> > > >> > > > _______________________________________________
> > > >> > > > pmacct-discussion mailing list
> > > >> > > > http://www.pmacct.net/#mailinglists
> > > >> > >
> > > >> > >
> > > >> > > _______________________________________________
> > > >> > > pmacct-discussion mailing list
> > > >> > > http://www.pmacct.net/#mailinglists
> > > >> > >
> > > >>
> > > >
> >
_______________________________________________
pmacct-discussion mailing list
http://www.pmacct.net/#mailinglists
