Hi, On Mon, Jul 30, 2012 at 11:35:35PM +0200, Hrvoje Popovski wrote: > Hello, > > I have applied your new patch on top of old one and I still see 4294* > flow duration.
thanks for patiently testing this. > I have tcpdumped 5 min netflow traffic on collector and have same 5 min > netflow data if you are interested. > > http://kosjenka.srce.hr/~hrvoje/netflow.pcap > http://kosjenka.srce.hr/~hrvoje/netflow.txt 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 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 *, -- I'm not entirely sure you are real.
