net: Allow filtering on debug traces in the net subsystem

Add several levels of DEBUG prints so that you can limit the noise to
the severety of your problem.

DEBUG_LL_STATE = Link local state machine changes
DEBUG_DEV_PKT = Packets or info directed to the device
DEBUG_NET_PKT = Packets on info on the network at large
DEBUG_INT_STATE = Internal network state changes

Signed-off-by: Joe Hershberger <joe.hershberger@ni.com>
This commit is contained in:
Joe Hershberger 2012-05-23 08:01:04 +00:00
parent c697576262
commit 4ef8d53caa
8 changed files with 68 additions and 38 deletions

View file

@ -83,6 +83,8 @@ int nc_input_packet(uchar *pkt, unsigned dest, unsigned src, unsigned len)
if (dest != nc_port || !len) if (dest != nc_port || !len)
return 0; /* not for us */ return 0; /* not for us */
debug_cond(DEBUG_DEV_PKT, "input: \"%*.*s\"\n", len, len, pkt);
if (input_size == sizeof(input_buffer)) if (input_size == sizeof(input_buffer))
return 1; /* no space */ return 1; /* no space */
if (len > sizeof(input_buffer) - input_size) if (len > sizeof(input_buffer) - input_size)
@ -112,6 +114,8 @@ static void nc_send_packet(const char *buf, int len)
uchar *ether; uchar *ether;
IPaddr_t ip; IPaddr_t ip;
debug_cond(DEBUG_DEV_PKT, "output: \"%*.*s\"\n", len, len, buf);
eth = eth_get_dev(); eth = eth_get_dev();
if (eth == NULL) if (eth == NULL)
return; return;

View file

@ -729,13 +729,6 @@ int gunzip(void *, int, unsigned char *, unsigned long *);
int zunzip(void *dst, int dstlen, unsigned char *src, unsigned long *lenp, int zunzip(void *dst, int dstlen, unsigned char *src, unsigned long *lenp,
int stoponerr, int offset); int stoponerr, int offset);
/* lib/net_utils.c */
#include <net.h>
static inline IPaddr_t getenv_IPaddr (char *var)
{
return (string_to_ip(getenv(var)));
}
/* lib/qsort.c */ /* lib/qsort.c */
void qsort(void *base, size_t nmemb, size_t size, void qsort(void *base, size_t nmemb, size_t size,
int(*compar)(const void *, const void *)); int(*compar)(const void *, const void *));
@ -804,6 +797,13 @@ void fputc(int file, const char c);
int ftstc(int file); int ftstc(int file);
int fgetc(int file); int fgetc(int file);
/* lib/net_utils.c */
#include <net.h>
static inline IPaddr_t getenv_IPaddr(char *var)
{
return string_to_ip(getenv(var));
}
/* /*
* CONSOLE multiplexing. * CONSOLE multiplexing.
*/ */

View file

@ -19,6 +19,10 @@
#include <asm/cache.h> #include <asm/cache.h>
#include <asm/byteorder.h> /* for nton* / ntoh* stuff */ #include <asm/byteorder.h> /* for nton* / ntoh* stuff */
#define DEBUG_LL_STATE 0 /* Link local state machine changes */
#define DEBUG_DEV_PKT 0 /* Packets or info directed to the device */
#define DEBUG_NET_PKT 0 /* Packets on info on the network at large */
#define DEBUG_INT_STATE 0 /* Internal network state changes */
/* /*
* The number of receive packet buffers, and the required packet buffer * The number of receive packet buffers, and the required packet buffer
@ -480,6 +484,7 @@ static inline void net_set_state(enum net_loop_state state)
{ {
extern enum net_loop_state net_state; extern enum net_loop_state net_state;
debug_cond(DEBUG_INT_STATE, "--- NetState set to %d\n", state);
net_state = state; net_state = state;
} }

View file

@ -55,7 +55,7 @@ void arp_raw_request(IPaddr_t sourceIP, const uchar *targetEther,
struct arp_hdr *arp; struct arp_hdr *arp;
int eth_hdr_size; int eth_hdr_size;
debug("ARP broadcast %d\n", NetArpWaitTry); debug_cond(DEBUG_DEV_PKT, "ARP broadcast %d\n", NetArpWaitTry);
pkt = NetArpTxPacket; pkt = NetArpTxPacket;
@ -135,7 +135,7 @@ void ArpReceive(struct ethernet_hdr *et, struct ip_udp_hdr *ip, int len)
* address; so if we receive such a packet, we set * address; so if we receive such a packet, we set
* the server ethernet address * the server ethernet address
*/ */
debug("Got ARP\n"); debug_cond(DEBUG_NET_PKT, "Got ARP\n");
arp = (struct arp_hdr *)ip; arp = (struct arp_hdr *)ip;
if (len < ARP_HDR_SIZE) { if (len < ARP_HDR_SIZE) {
@ -160,7 +160,7 @@ void ArpReceive(struct ethernet_hdr *et, struct ip_udp_hdr *ip, int len)
switch (ntohs(arp->ar_op)) { switch (ntohs(arp->ar_op)) {
case ARPOP_REQUEST: case ARPOP_REQUEST:
/* reply with our IP address */ /* reply with our IP address */
debug("Got ARP REQUEST, return our IP\n"); debug_cond(DEBUG_DEV_PKT, "Got ARP REQUEST, return our IP\n");
pkt = (uchar *)et; pkt = (uchar *)et;
eth_hdr_size = net_update_ether(et, et->et_src, PROT_ARP); eth_hdr_size = net_update_ether(et, et->et_src, PROT_ARP);
pkt += eth_hdr_size; pkt += eth_hdr_size;
@ -203,7 +203,8 @@ void ArpReceive(struct ethernet_hdr *et, struct ip_udp_hdr *ip, int len)
/* matched waiting packet's address */ /* matched waiting packet's address */
if (reply_ip_addr == NetArpWaitReplyIP) { if (reply_ip_addr == NetArpWaitReplyIP) {
debug("Got ARP REPLY, set eth addr (%pM)\n", debug_cond(DEBUG_DEV_PKT,
"Got ARP REPLY, set eth addr (%pM)\n",
arp->ar_data); arp->ar_data);
/* save address for later use */ /* save address for later use */

View file

@ -93,7 +93,7 @@ static void configure_wait(void)
/* set deadline_ms to the point in time when we timeout */ /* set deadline_ms to the point in time when we timeout */
deadline_ms = MONOTONIC_MS() + timeout_ms; deadline_ms = MONOTONIC_MS() + timeout_ms;
debug("...wait %d %s nprobes=%u, nclaims=%u\n", debug_cond(DEBUG_DEV_PKT, "...wait %d %s nprobes=%u, nclaims=%u\n",
timeout_ms, eth_get_name(), nprobes, nclaims); timeout_ms, eth_get_name(), nprobes, nclaims);
NetSetTimeout(timeout_ms, link_local_timeout); NetSetTimeout(timeout_ms, link_local_timeout);
@ -131,7 +131,7 @@ static void link_local_timeout(void)
have been received, so we can progress through the states */ have been received, so we can progress through the states */
if (nprobes < PROBE_NUM) { if (nprobes < PROBE_NUM) {
nprobes++; nprobes++;
debug("probe/%u %s@%pI4\n", debug_cond(DEBUG_LL_STATE, "probe/%u %s@%pI4\n",
nprobes, eth_get_name(), &ip); nprobes, eth_get_name(), &ip);
arp_raw_request(0, NetEtherNullAddr, ip); arp_raw_request(0, NetEtherNullAddr, ip);
timeout_ms = PROBE_MIN * 1000; timeout_ms = PROBE_MIN * 1000;
@ -140,7 +140,7 @@ static void link_local_timeout(void)
/* Switch to announce state */ /* Switch to announce state */
state = ANNOUNCE; state = ANNOUNCE;
nclaims = 0; nclaims = 0;
debug("announce/%u %s@%pI4\n", debug_cond(DEBUG_LL_STATE, "announce/%u %s@%pI4\n",
nclaims, eth_get_name(), &ip); nclaims, eth_get_name(), &ip);
arp_raw_request(ip, NetOurEther, ip); arp_raw_request(ip, NetOurEther, ip);
timeout_ms = ANNOUNCE_INTERVAL * 1000; timeout_ms = ANNOUNCE_INTERVAL * 1000;
@ -152,7 +152,7 @@ static void link_local_timeout(void)
to the announce state */ to the announce state */
state = ANNOUNCE; state = ANNOUNCE;
nclaims = 0; nclaims = 0;
debug("announce/%u %s@%pI4\n", debug_cond(DEBUG_LL_STATE, "announce/%u %s@%pI4\n",
nclaims, eth_get_name(), &ip); nclaims, eth_get_name(), &ip);
arp_raw_request(ip, NetOurEther, ip); arp_raw_request(ip, NetOurEther, ip);
timeout_ms = ANNOUNCE_INTERVAL * 1000; timeout_ms = ANNOUNCE_INTERVAL * 1000;
@ -163,7 +163,7 @@ static void link_local_timeout(void)
the states */ the states */
if (nclaims < ANNOUNCE_NUM) { if (nclaims < ANNOUNCE_NUM) {
nclaims++; nclaims++;
debug("announce/%u %s@%pI4\n", debug_cond(DEBUG_LL_STATE, "announce/%u %s@%pI4\n",
nclaims, eth_get_name(), &ip); nclaims, eth_get_name(), &ip);
arp_raw_request(ip, NetOurEther, ip); arp_raw_request(ip, NetOurEther, ip);
timeout_ms = ANNOUNCE_INTERVAL * 1000; timeout_ms = ANNOUNCE_INTERVAL * 1000;
@ -216,10 +216,11 @@ void link_local_receive_arp(struct arp_hdr *arp, int len)
if ((int)(diff) < 0) { if ((int)(diff) < 0) {
/* Current time is greater than the expected timeout /* Current time is greater than the expected timeout
time. This should never happen */ time. This should never happen */
debug("missed an expected timeout\n"); debug_cond(DEBUG_LL_STATE,
"missed an expected timeout\n");
timeout_ms = 0; timeout_ms = 0;
} else { } else {
debug("adjusting timeout\n"); debug_cond(DEBUG_INT_STATE, "adjusting timeout\n");
timeout_ms = diff | 1; /* never 0 */ timeout_ms = diff | 1; /* never 0 */
} }
} }
@ -239,13 +240,13 @@ void link_local_receive_arp(struct arp_hdr *arp, int len)
} }
*/ */
debug("%s recv arp type=%d, op=%d,\n", debug_cond(DEBUG_INT_STATE, "%s recv arp type=%d, op=%d,\n",
eth_get_name(), ntohs(arp->ar_pro), eth_get_name(), ntohs(arp->ar_pro),
ntohs(arp->ar_op)); ntohs(arp->ar_op));
debug("\tsource=%pM %pI4\n", debug_cond(DEBUG_INT_STATE, "\tsource=%pM %pI4\n",
&arp->ar_sha, &arp->ar_sha,
&arp->ar_spa); &arp->ar_spa);
debug("\ttarget=%pM %pI4\n", debug_cond(DEBUG_INT_STATE, "\ttarget=%pM %pI4\n",
&arp->ar_tha, &arp->ar_tha,
&arp->ar_tpa); &arp->ar_tpa);
@ -271,8 +272,9 @@ void link_local_receive_arp(struct arp_hdr *arp, int len)
target_ip_conflict = 1; target_ip_conflict = 1;
} }
debug("state = %d, source ip conflict = %d, target ip conflict = %d\n", debug_cond(DEBUG_NET_PKT,
state, source_ip_conflict, target_ip_conflict); "state = %d, source ip conflict = %d, target ip conflict = "
"%d\n", state, source_ip_conflict, target_ip_conflict);
switch (state) { switch (state) {
case PROBE: case PROBE:
case ANNOUNCE: case ANNOUNCE:

View file

@ -310,6 +310,7 @@ int NetLoop(enum proto_t protocol)
NetRestarted = 0; NetRestarted = 0;
NetDevExists = 0; NetDevExists = 0;
NetTryCount = 1; NetTryCount = 1;
debug_cond(DEBUG_INT_STATE, "--- NetLoop Entry\n");
bootstage_mark_name(BOOTSTAGE_ID_ETH_START, "eth_start"); bootstage_mark_name(BOOTSTAGE_ID_ETH_START, "eth_start");
net_init(); net_init();
@ -330,6 +331,7 @@ restart:
* here on, this code is a state machine driven by received * here on, this code is a state machine driven by received
* packets and timer events. * packets and timer events.
*/ */
debug_cond(DEBUG_INT_STATE, "--- NetLoop Init\n");
NetInitLoop(); NetInitLoop();
switch (net_check_prereq(protocol)) { switch (net_check_prereq(protocol)) {
@ -460,6 +462,9 @@ restart:
net_cleanup_loop(); net_cleanup_loop();
eth_halt(); eth_halt();
puts("\nAbort\n"); puts("\nAbort\n");
/* include a debug print as well incase the debug
messages are directed to stderr */
debug_cond(DEBUG_INT_STATE, "--- NetLoop Abort!\n");
goto done; goto done;
} }
@ -487,6 +492,7 @@ restart:
} }
#endif /* CONFIG_SYS_FAULT_ECHO_LINK_DOWN, ... */ #endif /* CONFIG_SYS_FAULT_ECHO_LINK_DOWN, ... */
#endif /* CONFIG_MII, ... */ #endif /* CONFIG_MII, ... */
debug_cond(DEBUG_INT_STATE, "--- NetLoop timeout\n");
x = timeHandler; x = timeHandler;
timeHandler = (thand_f *)0; timeHandler = (thand_f *)0;
(*x)(); (*x)();
@ -514,10 +520,12 @@ restart:
} }
eth_halt(); eth_halt();
ret = NetBootFileXferSize; ret = NetBootFileXferSize;
debug_cond(DEBUG_INT_STATE, "--- NetLoop Success!\n");
goto done; goto done;
case NETLOOP_FAIL: case NETLOOP_FAIL:
net_cleanup_loop(); net_cleanup_loop();
debug_cond(DEBUG_INT_STATE, "--- NetLoop Fail!\n");
goto done; goto done;
case NETLOOP_CONTINUE: case NETLOOP_CONTINUE:
@ -605,6 +613,7 @@ rxhand_f *net_get_udp_handler(void)
void net_set_udp_handler(rxhand_f *f) void net_set_udp_handler(rxhand_f *f)
{ {
debug_cond(DEBUG_INT_STATE, "--- NetLoop UDP handler set (%p)\n", f);
if (f == NULL) if (f == NULL)
udp_packet_handler = dummy_handler; udp_packet_handler = dummy_handler;
else else
@ -618,6 +627,7 @@ rxhand_f *net_get_arp_handler(void)
void net_set_arp_handler(rxhand_f *f) void net_set_arp_handler(rxhand_f *f)
{ {
debug_cond(DEBUG_INT_STATE, "--- NetLoop ARP handler set (%p)\n", f);
if (f == NULL) if (f == NULL)
arp_packet_handler = dummy_handler; arp_packet_handler = dummy_handler;
else else
@ -635,8 +645,12 @@ void
NetSetTimeout(ulong iv, thand_f *f) NetSetTimeout(ulong iv, thand_f *f)
{ {
if (iv == 0) { if (iv == 0) {
debug_cond(DEBUG_INT_STATE,
"--- NetLoop timeout handler cancelled\n");
timeHandler = (thand_f *)0; timeHandler = (thand_f *)0;
} else { } else {
debug_cond(DEBUG_INT_STATE,
"--- NetLoop timeout handler set (%p)\n", f);
timeHandler = f; timeHandler = f;
timeStart = get_timer(0); timeStart = get_timer(0);
timeDelta = iv; timeDelta = iv;
@ -672,7 +686,7 @@ int NetSendUDPPacket(uchar *ether, IPaddr_t dest, int dport, int sport,
/* if MAC address was not discovered yet, do an ARP request */ /* if MAC address was not discovered yet, do an ARP request */
if (memcmp(ether, NetEtherNullAddr, 6) == 0) { if (memcmp(ether, NetEtherNullAddr, 6) == 0) {
debug("sending ARP for %pI4\n", &dest); debug_cond(DEBUG_DEV_PKT, "sending ARP for %pI4\n", &dest);
/* save the ip and eth addr for the packet to send after arp */ /* save the ip and eth addr for the packet to send after arp */
NetArpWaitPacketIP = dest; NetArpWaitPacketIP = dest;
@ -687,7 +701,8 @@ int NetSendUDPPacket(uchar *ether, IPaddr_t dest, int dport, int sport,
ArpRequest(); ArpRequest();
return 1; /* waiting */ return 1; /* waiting */
} else { } else {
debug("sending UDP to %pI4/%pM\n", &dest, ether); debug_cond(DEBUG_DEV_PKT, "sending UDP to %pI4/%pM\n",
&dest, ether);
NetSendPacket(NetTxPacket, pkt_hdr_size + payload_len); NetSendPacket(NetTxPacket, pkt_hdr_size + payload_len);
return 0; /* transmitted */ return 0; /* transmitted */
} }
@ -910,7 +925,7 @@ NetReceive(uchar *inpkt, int len)
#endif #endif
ushort cti = 0, vlanid = VLAN_NONE, myvlanid, mynvlanid; ushort cti = 0, vlanid = VLAN_NONE, myvlanid, mynvlanid;
debug("packet received\n"); debug_cond(DEBUG_NET_PKT, "packet received\n");
NetRxPacket = inpkt; NetRxPacket = inpkt;
NetRxPacketLen = len; NetRxPacketLen = len;
@ -941,8 +956,6 @@ NetReceive(uchar *inpkt, int len)
eth_proto = ntohs(et->et_protlen); eth_proto = ntohs(et->et_protlen);
debug("packet received\n");
if (eth_proto < 1514) { if (eth_proto < 1514) {
struct e802_hdr *et802 = (struct e802_hdr *)et; struct e802_hdr *et802 = (struct e802_hdr *)et;
/* /*
@ -962,7 +975,7 @@ NetReceive(uchar *inpkt, int len)
struct vlan_ethernet_hdr *vet = struct vlan_ethernet_hdr *vet =
(struct vlan_ethernet_hdr *)et; (struct vlan_ethernet_hdr *)et;
debug("VLAN packet received\n"); debug_cond(DEBUG_NET_PKT, "VLAN packet received\n");
/* too small packet? */ /* too small packet? */
if (len < VLAN_ETHER_HDR_SIZE) if (len < VLAN_ETHER_HDR_SIZE)
@ -984,7 +997,7 @@ NetReceive(uchar *inpkt, int len)
len -= VLAN_ETHER_HDR_SIZE; len -= VLAN_ETHER_HDR_SIZE;
} }
debug("Receive from protocol 0x%x\n", eth_proto); debug_cond(DEBUG_NET_PKT, "Receive from protocol 0x%x\n", eth_proto);
#if defined(CONFIG_CMD_CDP) #if defined(CONFIG_CMD_CDP)
if (iscdp) { if (iscdp) {
@ -1013,7 +1026,7 @@ NetReceive(uchar *inpkt, int len)
break; break;
#endif #endif
case PROT_IP: case PROT_IP:
debug("Got IP\n"); debug_cond(DEBUG_NET_PKT, "Got IP\n");
/* Before we start poking the header, make sure it is there */ /* Before we start poking the header, make sure it is there */
if (len < IP_UDP_HDR_SIZE) { if (len < IP_UDP_HDR_SIZE) {
debug("len bad %d < %lu\n", len, debug("len bad %d < %lu\n", len,
@ -1022,11 +1035,12 @@ NetReceive(uchar *inpkt, int len)
} }
/* Check the packet length */ /* Check the packet length */
if (len < ntohs(ip->ip_len)) { if (len < ntohs(ip->ip_len)) {
printf("len bad %d < %d\n", len, ntohs(ip->ip_len)); debug("len bad %d < %d\n", len, ntohs(ip->ip_len));
return; return;
} }
len = ntohs(ip->ip_len); len = ntohs(ip->ip_len);
debug("len=%d, v=%02x\n", len, ip->ip_hl_v & 0xff); debug_cond(DEBUG_NET_PKT, "len=%d, v=%02x\n",
len, ip->ip_hl_v & 0xff);
/* Can't deal with anything except IPv4 */ /* Can't deal with anything except IPv4 */
if ((ip->ip_hl_v & 0xf0) != 0x40) if ((ip->ip_hl_v & 0xf0) != 0x40)
@ -1036,7 +1050,7 @@ NetReceive(uchar *inpkt, int len)
return; return;
/* Check the Checksum of the header */ /* Check the Checksum of the header */
if (!NetCksumOk((uchar *)ip, IP_HDR_SIZE / 2)) { if (!NetCksumOk((uchar *)ip, IP_HDR_SIZE / 2)) {
puts("checksum bad\n"); debug("checksum bad\n");
return; return;
} }
/* If it is not for us, ignore it */ /* If it is not for us, ignore it */
@ -1085,6 +1099,10 @@ NetReceive(uchar *inpkt, int len)
return; return;
} }
debug_cond(DEBUG_DEV_PKT,
"received UDP (to=%pI4, from=%pI4, len=%d)\n",
&dst_ip, &src_ip, len);
#ifdef CONFIG_UDP_CHECKSUM #ifdef CONFIG_UDP_CHECKSUM
if (ip->udp_xsum != 0) { if (ip->udp_xsum != 0) {
ulong xsum; ulong xsum;

View file

@ -45,7 +45,7 @@ static int ping_send(void)
/* XXX always send arp request */ /* XXX always send arp request */
debug("sending ARP for %pI4\n", &NetPingIP); debug_cond(DEBUG_DEV_PKT, "sending ARP for %pI4\n", &NetPingIP);
NetArpWaitPacketIP = NetPingIP; NetArpWaitPacketIP = NetPingIP;
@ -93,7 +93,7 @@ void ping_receive(struct ethernet_hdr *et, struct ip_udp_hdr *ip, int len)
case ICMP_ECHO_REQUEST: case ICMP_ECHO_REQUEST:
eth_hdr_size = net_update_ether(et, et->et_src, PROT_IP); eth_hdr_size = net_update_ether(et, et->et_src, PROT_IP);
debug("Got ICMP ECHO REQUEST, return " debug_cond(DEBUG_DEV_PKT, "Got ICMP ECHO REQUEST, return "
"%d bytes\n", eth_hdr_size + len); "%d bytes\n", eth_hdr_size + len);
ip->ip_sum = 0; ip->ip_sum = 0;

View file

@ -45,7 +45,7 @@ void rarp_receive(struct ip_udp_hdr *ip, unsigned len)
{ {
struct arp_hdr *arp; struct arp_hdr *arp;
debug("Got RARP\n"); debug_cond(DEBUG_NET_PKT, "Got RARP\n");
arp = (struct arp_hdr *)ip; arp = (struct arp_hdr *)ip;
if (len < ARP_HDR_SIZE) { if (len < ARP_HDR_SIZE) {
printf("bad length %d < %d\n", len, ARP_HDR_SIZE); printf("bad length %d < %d\n", len, ARP_HDR_SIZE);
@ -63,7 +63,7 @@ void rarp_receive(struct ip_udp_hdr *ip, unsigned len)
if (NetServerIP == 0) if (NetServerIP == 0)
NetCopyIP(&NetServerIP, &arp->ar_data[6]); NetCopyIP(&NetServerIP, &arp->ar_data[6]);
memcpy(NetServerEther, &arp->ar_data[0], 6); memcpy(NetServerEther, &arp->ar_data[0], 6);
debug("Got good RARP\n"); debug_cond(DEBUG_DEV_PKT, "Got good RARP\n");
net_auto_load(); net_auto_load();
} }
} }