On 31.7.2012 18:20, Florian Obser wrote:
>
> This looks like a bug in your collector, I looked at this flow:
>
> 2012-07-30 22:58:55.002 4294967003.000 UDP 66.68.13.57:47935 ->
> 10.161.53.99:32459 28 5349 1
> 2012-07-30 22:54:02.002 293.000 UDP 10.161.53.99:32459 -> 66.68.13.57:47935
> 32 3616 1
>
Hello,
could this two flows per state be product of
set state-defaults pflow in pf.conf ? You can see pf.conf in my first
mail. If it turns out that it's bug in nfdump, then this is wrong list :))
I will run your diff and post results/logs. And thank you for your time
and engagement. It's because of people like you I love and use OpenBSD :)
> These two flows are generated from the same state - there are allways
> two flows generated from one state, one for the incomming direction,
> one for outgoing.
>
> The various timestamps are the same for both flows on wire. I have no
> idea why it's once parsed as 4294967003.000 and once as 293.000 (this
> is the correct value btw.).
>
> Wireshark decode looks ok (it's the second udp packet in the pcap
> file):
> [...]
> User Datagram Protocol, Src Port: 55853 (55853), Dst Port: palace-3 (9994)
> Cisco NetFlow/IPFIX
> Version: 5
> Count: 30
> SysUptime: 24249000
> Timestamp: Jul 30, 2012 23:00:05.002421728
> CurrentSecs: 1343682005
> CurrentNSecs: 2421728
> FlowSequence: 591570
> EngineType: 42
> EngineId: 42
> 00.. .... .... .... = SamplingMode: No sampling mode configured (0)
> ..00 0000 0000 0000 = SampleRate: 0
> pdu 1/30
> SrcAddr: 66.68.13.57 (66.68.13.57)
> DstAddr: 10.161.53.99 (10.161.53.99)
> NextHop: 0.0.0.0 (0.0.0.0)
> InputInt: 0
> OutputInt: 0
> Packets: 28
> Octets: 5349
> [Duration: 293.000000000 seconds]
> StartTime: 23886.000000000 seconds
> EndTime: 24179.000000000 seconds
> SrcPort: 47935
> DstPort: 32459
> padding
> TCP Flags: 0x00
> Protocol: 17
> IP ToS: 0x00
> SrcAS: 0
> DstAS: 0
> SrcMask: 0 (prefix: 66.68.13.57/32)
> DstMask: 0 (prefix: 10.161.53.99/32)
> padding
> pdu 2/30
> SrcAddr: 10.161.53.99 (10.161.53.99)
> DstAddr: 66.68.13.57 (66.68.13.57)
> NextHop: 0.0.0.0 (0.0.0.0)
> InputInt: 0
> OutputInt: 0
> Packets: 32
> Octets: 3616
> [Duration: 293.000000000 seconds]
> StartTime: 23886.000000000 seconds
> EndTime: 24179.000000000 seconds
> SrcPort: 32459
> DstPort: 47935
> padding
> TCP Flags: 0x00
> Protocol: 17
> IP ToS: 0x00
> SrcAS: 0
> DstAS: 0
> SrcMask: 0 (prefix: 10.161.53.99/32)
> DstMask: 0 (prefix: 66.68.13.57/32)
> padding
> [...]
>
> We even parsed the tcpdump hexdump by hand in case wireshark fscked
> up.
>
> Except for pfsync I'm cautiously optimistic that the two patches fix
> the pflow problem.
>
> pfsync is an entirely different problem. When a state is synced it's
> creation time is expressed as "n seconds" ago. If the pfsync peer just
> rebooted this might be a negative number
> st->creation = time_uptime - ntohl(sp->creation);
> but st->creation is an unsigned. (There might be a problem with
> st->expire, too)
>
> There is a diff from dlg from last year which addresses this for
> pfsync by treating st->creation as a signed value (I'm simplifying
> here) but I'm afraid this won't help with pflow because the relevant
> fields are specified as unsigned in the RFC.
>
> That beeing said, I'm happy to entertain that there is still a
> problem. Can you run the following diff on top, I'm using this for
> debugging. It traces the calls to pf_unlink_state and prints this to
> the console (it's added to /var/log/messages, too):
>
> if (ntohl(flow1->flow_start) > ntohl(flow1->flow_finish))
> printf("pflow: start > finish, up: %lu, cr: %lu, ex: %lu, "
> "w: %d\n", time_uptime, st->creation, st->expire, where);
>
> ------------------------------------------------------------------------
>
> diff --git sys/net/if_pflow.c sys/net/if_pflow.c
> index ec07ad8..8ec15dc 100644
> --- sys/net/if_pflow.c
> +++ sys/net/if_pflow.c
> @@ -89,15 +89,15 @@ void pflow_timeout(void *);
> void pflow_timeout6(void *);
> void pflow_timeout_tmpl(void *);
> void copy_flow_data(struct pflow_flow *, struct pflow_flow *,
> - struct pf_state *, int, int);
> + struct pf_state *, int, int, int);
> void copy_flow4_data(struct pflow_flow4 *, struct pflow_flow4 *,
> - struct pf_state *, int, int);
> + struct pf_state *, int, int, int);
> void copy_flow6_data(struct pflow_flow6 *, struct pflow_flow6 *,
> - struct pf_state *, int, int);
> -int pflow_pack_flow(struct pf_state *, struct pflow_softc *);
> -int pflow_pack_flow_ipfix(struct pf_state *, struct pflow_softc *);
> + struct pf_state *, int, int, int);
> +int pflow_pack_flow(struct pf_state *, struct pflow_softc *, int);
> +int pflow_pack_flow_ipfix(struct pf_state *, struct pflow_softc *, int);
> int pflow_get_dynport(void);
> -int export_pflow_if(struct pf_state*, struct pflow_softc *);
> +int export_pflow_if(struct pf_state*, struct pflow_softc *, int);
> int copy_flow_to_m(struct pflow_flow *flow, struct pflow_softc *sc);
> int copy_flow4_to_m(struct pflow_flow4 *flow, struct pflow_softc *sc);
> int copy_flow6_to_m(struct pflow_flow6 *flow, struct pflow_softc *sc);
> @@ -532,7 +532,7 @@ pflow_get_mbuf(struct pflow_softc *sc, u_int16_t set_id)
>
> void
> copy_flow_data(struct pflow_flow *flow1, struct pflow_flow *flow2,
> - struct pf_state *st, int src, int dst)
> + struct pf_state *st, int src, int dst, int where)
> {
> struct pf_state_key *sk = st->key[PF_SK_WIRE];
>
> @@ -556,6 +556,9 @@ copy_flow_data(struct pflow_flow *flow1, struct
> pflow_flow *flow2,
> flow1->flow_start = flow2->flow_start =
> htonl(st->creation * 1000);
> flow1->flow_finish = flow2->flow_finish = htonl(st->expire * 1000);
> + if (ntohl(flow1->flow_start) > ntohl(flow1->flow_finish))
> + printf("pflow: start > finish, up: %lu, cr: %lu, ex: %lu, "
> + "w: %d\n", time_uptime, st->creation, st->expire, where);
>
> flow1->tcp_flags = flow2->tcp_flags = 0;
> flow1->protocol = flow2->protocol = sk->proto;
> @@ -564,7 +567,7 @@ copy_flow_data(struct pflow_flow *flow1, struct
> pflow_flow *flow2,
>
> void
> copy_flow4_data(struct pflow_flow4 *flow1, struct pflow_flow4 *flow2,
> - struct pf_state *st, int src, int dst)
> + struct pf_state *st, int src, int dst, int where)
> {
> struct pf_state_key *sk = st->key[PF_SK_WIRE];
>
> @@ -581,6 +584,9 @@ copy_flow4_data(struct pflow_flow4 *flow1, struct
> pflow_flow4 *flow2,
> flow1->flow_start = flow2->flow_start =
> htonl(st->creation * 1000);
> flow1->flow_finish = flow2->flow_finish = htonl(st->expire * 1000);
> + if (ntohl(flow1->flow_start) > ntohl(flow1->flow_finish))
> + printf("pflow: start > finish, up: %lu, cr: %lu, ex: %lu, "
> + "w: %d\n", time_uptime, st->creation, st->expire, where);
>
> flow1->protocol = flow2->protocol = sk->proto;
> flow1->tos = flow2->tos = st->rule.ptr->tos;
> @@ -588,7 +594,7 @@ copy_flow4_data(struct pflow_flow4 *flow1, struct
> pflow_flow4 *flow2,
>
> void
> copy_flow6_data(struct pflow_flow6 *flow1, struct pflow_flow6 *flow2,
> - struct pf_state *st, int src, int dst)
> + struct pf_state *st, int src, int dst, int where)
> {
> struct pf_state_key *sk = st->key[PF_SK_WIRE];
> bcopy(&sk->addr[src].v6, &flow1->src_ip, sizeof(flow1->src_ip));
> @@ -606,13 +612,16 @@ copy_flow6_data(struct pflow_flow6 *flow1, struct
> pflow_flow6 *flow2,
> flow1->flow_start = flow2->flow_start =
> htonl(st->creation * 1000);
> flow1->flow_finish = flow2->flow_finish = htonl(st->expire * 1000);
> + if (ntohl(flow1->flow_start) > ntohl(flow1->flow_finish))
> + printf("pflow: start > finish, up: %lu, cr: %lu, ex: %lu, "
> + "w: %d\n", time_uptime, st->creation, st->expire, where);
>
> flow1->protocol = flow2->protocol = sk->proto;
> flow1->tos = flow2->tos = st->rule.ptr->tos;
> }
>
> int
> -export_pflow(struct pf_state *st)
> +export_pflow(struct pf_state *st, int where)
> {
> struct pflow_softc *sc = NULL;
> struct pf_state_key *sk = st->key[PF_SK_WIRE];
> @@ -621,13 +630,13 @@ export_pflow(struct pf_state *st)
> switch (sc->sc_version) {
> case PFLOW_PROTO_5:
> if( sk->af == AF_INET )
> - export_pflow_if(st, sc);
> + export_pflow_if(st, sc, where);
> break;
> case PFLOW_PROTO_9:
> /* ... fall through ... */
> case PFLOW_PROTO_10:
> if( sk->af == AF_INET || sk->af == AF_INET6 )
> - export_pflow_if(st, sc);
> + export_pflow_if(st, sc, where);
> break;
> default: /* NOTREACHED */
> break;
> @@ -638,7 +647,7 @@ export_pflow(struct pf_state *st)
> }
>
> int
> -export_pflow_if(struct pf_state *st, struct pflow_softc *sc)
> +export_pflow_if(struct pf_state *st, struct pflow_softc *sc, int where)
> {
> struct pf_state pfs_copy;
> struct ifnet *ifp = &sc->sc_if;
> @@ -649,12 +658,12 @@ export_pflow_if(struct pf_state *st, struct pflow_softc
> *sc)
> return (0);
>
> if (sc->sc_version == PFLOW_PROTO_9 || sc->sc_version == PFLOW_PROTO_10)
> - return (pflow_pack_flow_ipfix(st, sc));
> + return (pflow_pack_flow_ipfix(st, sc, where));
>
> /* PFLOW_PROTO_5 */
> if ((st->bytes[0] < (u_int64_t)PFLOW_MAXBYTES)
> && (st->bytes[1] < (u_int64_t)PFLOW_MAXBYTES))
> - return (pflow_pack_flow(st, sc));
> + return (pflow_pack_flow(st, sc, where));
>
> /* flow > PFLOW_MAXBYTES need special handling */
> bcopy(st, &pfs_copy, sizeof(pfs_copy));
> @@ -665,7 +674,7 @@ export_pflow_if(struct pf_state *st, struct pflow_softc
> *sc)
> pfs_copy.bytes[0] = PFLOW_MAXBYTES;
> pfs_copy.bytes[1] = 0;
>
> - if ((ret = pflow_pack_flow(&pfs_copy, sc)) != 0)
> + if ((ret = pflow_pack_flow(&pfs_copy, sc, where)) != 0)
> return (ret);
> if ((bytes[0] - PFLOW_MAXBYTES) > 0)
> bytes[0] -= PFLOW_MAXBYTES;
> @@ -675,7 +684,7 @@ export_pflow_if(struct pf_state *st, struct pflow_softc
> *sc)
> pfs_copy.bytes[1] = PFLOW_MAXBYTES;
> pfs_copy.bytes[0] = 0;
>
> - if ((ret = pflow_pack_flow(&pfs_copy, sc)) != 0)
> + if ((ret = pflow_pack_flow(&pfs_copy, sc, where)) != 0)
> return (ret);
> if ((bytes[1] - PFLOW_MAXBYTES) > 0)
> bytes[1] -= PFLOW_MAXBYTES;
> @@ -684,7 +693,7 @@ export_pflow_if(struct pf_state *st, struct pflow_softc
> *sc)
> pfs_copy.bytes[0] = bytes[0];
> pfs_copy.bytes[1] = bytes[1];
>
> - return (pflow_pack_flow(&pfs_copy, sc));
> + return (pflow_pack_flow(&pfs_copy, sc, where));
> }
>
> int
> @@ -777,7 +786,7 @@ copy_flow6_to_m(struct pflow_flow6 *flow, struct
> pflow_softc *sc)
> }
>
> int
> -pflow_pack_flow(struct pf_state *st, struct pflow_softc *sc)
> +pflow_pack_flow(struct pf_state *st, struct pflow_softc *sc, int where)
> {
> struct pflow_flow flow1;
> struct pflow_flow flow2;
> @@ -787,9 +796,9 @@ pflow_pack_flow(struct pf_state *st, struct pflow_softc
> *sc)
> bzero(&flow2, sizeof(flow2));
>
> if (st->direction == PF_OUT)
> - copy_flow_data(&flow1, &flow2, st, 1, 0);
> + copy_flow_data(&flow1, &flow2, st, 1, 0, where);
> else
> - copy_flow_data(&flow1, &flow2, st, 0, 1);
> + copy_flow_data(&flow1, &flow2, st, 0, 1, where);
>
> if (st->bytes[0] != 0) /* first flow from state */
> ret = copy_flow_to_m(&flow1, sc);
> @@ -801,7 +810,7 @@ pflow_pack_flow(struct pf_state *st, struct pflow_softc
> *sc)
> }
>
> int
> -pflow_pack_flow_ipfix(struct pf_state *st, struct pflow_softc *sc)
> +pflow_pack_flow_ipfix(struct pf_state *st, struct pflow_softc *sc, int where)
> {
> struct pf_state_key *sk = st->key[PF_SK_WIRE];
> struct pflow_flow4 flow4_1, flow4_2;
> @@ -812,9 +821,9 @@ pflow_pack_flow_ipfix(struct pf_state *st, struct
> pflow_softc *sc)
> bzero(&flow4_2, sizeof(flow4_2));
>
> if (st->direction == PF_OUT)
> - copy_flow4_data(&flow4_1, &flow4_2, st, 1, 0);
> + copy_flow4_data(&flow4_1, &flow4_2, st, 1, 0, where);
> else
> - copy_flow4_data(&flow4_1, &flow4_2, st, 0, 1);
> + copy_flow4_data(&flow4_1, &flow4_2, st, 0, 1, where);
>
> if (st->bytes[0] != 0) /* first flow from state */
> ret = copy_flow4_to_m(&flow4_1, sc);
> @@ -826,9 +835,9 @@ pflow_pack_flow_ipfix(struct pf_state *st, struct
> pflow_softc *sc)
> bzero(&flow6_2, sizeof(flow6_2));
>
> if (st->direction == PF_OUT)
> - copy_flow6_data(&flow6_1, &flow6_2, st, 1, 0);
> + copy_flow6_data(&flow6_1, &flow6_2, st, 1, 0, where);
> else
> - copy_flow6_data(&flow6_1, &flow6_2, st, 0, 1);
> + copy_flow6_data(&flow6_1, &flow6_2, st, 0, 1, where);
>
> if (st->bytes[0] != 0) /* first flow from state */
> ret = copy_flow6_to_m(&flow6_1, sc);
> diff --git sys/net/if_pflow.h sys/net/if_pflow.h
> index b39e491..c258672 100644
> --- sys/net/if_pflow.h
> +++ sys/net/if_pflow.h
> @@ -270,7 +270,7 @@ struct pflowreq {
> };
>
> #ifdef _KERNEL
> -int export_pflow(struct pf_state *);
> +int export_pflow(struct pf_state *, int);
> int pflow_sysctl(int *, u_int, void *, size_t *, void *, size_t);
> #endif /* _KERNEL */
>
> diff --git sys/net/if_pfsync.c sys/net/if_pfsync.c
> index fef2734..ed4d2e9 100644
> --- sys/net/if_pfsync.c
> +++ sys/net/if_pfsync.c
> @@ -769,7 +769,7 @@ pfsync_in_clr(caddr_t buf, int len, int count, int flags)
> nexts = RB_NEXT(pf_state_tree_id, &tree_id, st);
> if (st->creatorid == creatorid) {
> SET(st->state_flags, PFSTATE_NOSYNC);
> - pf_unlink_state(st);
> + pf_unlink_state(st, 4);
> }
> }
> } else {
> @@ -785,7 +785,7 @@ pfsync_in_clr(caddr_t buf, int len, int count, int flags)
> if (si->s->creatorid == creatorid) {
> SET(si->s->state_flags,
> PFSTATE_NOSYNC);
> - pf_unlink_state(si->s);
> + pf_unlink_state(si->s, 5);
> }
> }
> }
> @@ -1091,7 +1091,7 @@ pfsync_in_del(caddr_t buf, int len, int count, int
> flags)
> continue;
> }
> SET(st->state_flags, PFSTATE_NOSYNC);
> - pf_unlink_state(st);
> + pf_unlink_state(st, 6);
> }
>
> return (0);
> @@ -1118,7 +1118,7 @@ pfsync_in_del_c(caddr_t buf, int len, int count, int
> flags)
> }
>
> SET(st->state_flags, PFSTATE_NOSYNC);
> - pf_unlink_state(st);
> + pf_unlink_state(st, 7);
> }
>
> return (0);
> diff --git sys/net/pf.c sys/net/pf.c
> index 58423a1..55c36e7 100644
> --- sys/net/pf.c
> +++ sys/net/pf.c
> @@ -734,7 +734,7 @@ pf_state_key_attach(struct pf_state_key *sk, struct
> pf_state *s, int idx)
> TAILQ_INSERT_HEAD(&s->key[idx]->states, si, entry);
>
> if (olds)
> - pf_unlink_state(olds);
> + pf_unlink_state(olds, 1);
>
> return (0);
> }
> @@ -1251,7 +1251,7 @@ pf_src_tree_remove_state(struct pf_state *s)
>
> /* callers should be at splsoftnet */
> void
> -pf_unlink_state(struct pf_state *cur)
> +pf_unlink_state(struct pf_state *cur, int where)
> {
> splsoftassert(IPL_SOFTNET);
>
> @@ -1271,7 +1271,7 @@ pf_unlink_state(struct pf_state *cur)
> RB_REMOVE(pf_state_tree_id, &tree_id, cur);
> #if NPFLOW > 0
> if (cur->state_flags & PFSTATE_PFLOW)
> - export_pflow(cur);
> + export_pflow(cur, where);
> #endif
> #if NPFSYNC > 0
> pfsync_delete_state(cur);
> @@ -1345,7 +1345,7 @@ pf_purge_expired_states(u_int32_t maxcheck)
> pf_free_state(cur);
> } else if (pf_state_expires(cur) <= time_uptime) {
> /* unlink and free expired state */
> - pf_unlink_state(cur);
> + pf_unlink_state(cur, 2);
> if (! locked) {
> rw_enter_write(&pf_consistency_lock);
> locked = 1;
> @@ -4518,7 +4518,7 @@ pf_test_state_tcp(struct pf_pdesc *pd, struct pf_state
> **state, u_short *reason)
> }
> /* XXX make sure it's the same direction ?? */
> (*state)->src.state = (*state)->dst.state = TCPS_CLOSED;
> - pf_unlink_state(*state);
> + pf_unlink_state(*state, 3);
> *state = NULL;
> return (PF_DROP);
> }
> diff --git sys/net/pf_ioctl.c sys/net/pf_ioctl.c
> index 99d387a..11bdc09 100644
> --- sys/net/pf_ioctl.c
> +++ sys/net/pf_ioctl.c
> @@ -1315,7 +1315,7 @@ pfioctl(dev_t dev, u_long cmd, caddr_t addr, int flags,
> struct proc *p)
> /* don't send out individual delete messages */
> SET(s->state_flags, PFSTATE_NOSYNC);
> #endif
> - pf_unlink_state(s);
> + pf_unlink_state(s, 8);
> killed++;
> }
> }
> @@ -1338,7 +1338,7 @@ pfioctl(dev_t dev, u_long cmd, caddr_t addr, int flags,
> struct proc *p)
> if (psk->psk_pfcmp.creatorid == 0)
> psk->psk_pfcmp.creatorid = pf_status.hostid;
> if ((s = pf_find_state_byid(&psk->psk_pfcmp))) {
> - pf_unlink_state(s);
> + pf_unlink_state(s, 9);
> psk->psk_killed = 1;
> }
> break;
> @@ -1384,7 +1384,7 @@ pfioctl(dev_t dev, u_long cmd, caddr_t addr, int flags,
> struct proc *p)
> !strcmp(psk->psk_label, s->rule.ptr->label))) &&
> (!psk->psk_ifname[0] || !strcmp(psk->psk_ifname,
> s->kif->pfik_name))) {
> - pf_unlink_state(s);
> + pf_unlink_state(s, 10);
> killed++;
> }
> }
> diff --git sys/net/pfvar.h sys/net/pfvar.h
> index 8ea5fa2..1c7c5e0 100644
> --- sys/net/pfvar.h
> +++ sys/net/pfvar.h
> @@ -1743,7 +1743,7 @@ extern struct pool pf_state_scrub_pl;
> extern void pf_purge_thread(void *);
> extern void pf_purge_expired_src_nodes(int);
> extern void pf_purge_expired_states(u_int32_t);
> -extern void pf_unlink_state(struct pf_state *);
> +extern void pf_unlink_state(struct pf_state *, int);
> extern void pf_free_state(struct pf_state *);
> extern int pf_state_insert(struct pfi_kif *,
> struct pf_state_key *,
