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
