Index: linux-2.6.15-rc5-rt2/drivers/net/e100.c =================================================================== --- linux-2.6.15-rc5-rt2.orig/drivers/net/e100.c 2005-12-16 17:24:41.000000000 -0500 +++ linux-2.6.15-rc5-rt2/drivers/net/e100.c 2005-12-16 17:26:29.000000000 -0500 @@ -152,6 +152,7 @@ #include #include #include +#include #define DRV_NAME "e100" @@ -1744,6 +1745,7 @@ struct rfd *rfd = (struct rfd *)skb->data; u16 rfd_status, actual_size; + edprint("in"); if(unlikely(work_done && *work_done >= work_to_do)) return -EAGAIN; @@ -1794,6 +1796,7 @@ rx->skb = NULL; + edprint("out"); return 0; } @@ -1804,6 +1807,7 @@ int restart_required = 0; struct rx *rx_to_start = NULL; + edprint("in"); /* are we already rnr? then pay attention!!! this ensures that * the state machine progression never allows a start with a * partially cleaned list, avoiding a race between hardware @@ -1811,6 +1815,7 @@ if(RU_SUSPENDED == nic->ru_running) restart_required = 1; + edprint("1"); /* Indicate newly arrived packets */ for(rx = nic->rx_to_clean; rx->skb; rx = nic->rx_to_clean = rx->next) { int err = e100_rx_indicate(nic, rx, work_done, work_to_do); @@ -1823,6 +1828,7 @@ break; /* No more to clean */ } + edprint("2"); /* save our starting point as the place we'll restart the receiver */ if(restart_required) rx_to_start = nic->rx_to_clean; @@ -1832,6 +1838,7 @@ if(unlikely(e100_rx_alloc_skb(nic, rx))) break; /* Better luck next time (see watchdog) */ } + edprint("3"); if(restart_required) { // ack the rnr? @@ -1840,6 +1847,7 @@ if(work_done) (*work_done)++; } + edprint("out"); } static void e100_rx_clean_list(struct nic *nic) @@ -1925,6 +1933,7 @@ unsigned int work_done = 0; int tx_cleaned; + edprint("in"); e100_rx_clean(nic, &work_done, work_to_do); tx_cleaned = e100_tx_clean(nic); @@ -1932,11 +1941,13 @@ if((!tx_cleaned && (work_done == 0)) || !netif_running(netdev)) { netif_rx_complete(netdev); e100_enable_irq(nic); + edprint("out"); return 0; } *budget -= work_done; netdev->quota -= work_done; + edprint("out"); return 1; } Index: linux-2.6.15-rc5-rt2/include/net/dst.h =================================================================== --- linux-2.6.15-rc5-rt2.orig/include/net/dst.h 2005-12-16 17:24:41.000000000 -0500 +++ linux-2.6.15-rc5-rt2/include/net/dst.h 2005-12-16 17:26:29.000000000 -0500 @@ -14,6 +14,7 @@ #include #include #include +#include /* * 0 - no debugging messages @@ -240,12 +241,15 @@ static inline int dst_input(struct sk_buff *skb) { int err; + edprint("in"); for (;;) { + edprint("input=%p",skb->dst->input); err = skb->dst->input(skb); if (likely(err == 0)) return err; + edprint("err=%d",err); /* Oh, Jamal... Seems, I will not forgive you this mess. :-) */ if (unlikely(err != NET_XMIT_BYPASS)) return err; Index: linux-2.6.15-rc5-rt2/include/net/sock.h =================================================================== --- linux-2.6.15-rc5-rt2.orig/include/net/sock.h 2005-12-16 17:24:41.000000000 -0500 +++ linux-2.6.15-rc5-rt2/include/net/sock.h 2005-12-16 17:26:29.000000000 -0500 @@ -48,6 +48,7 @@ #include #include /* struct sk_buff */ #include +#include #include @@ -1110,6 +1111,7 @@ int err = 0; int skb_len; + edprint("in"); /* Cast skb->rcvbuf to unsigned... It's pointless, but reduces number of warnings when compiling with -W --ANK */ @@ -1123,12 +1125,15 @@ with socket lock! We assume that users of this function are lock free. */ + edprint("1"); err = sk_filter(sk, skb, 1); + edprint("2"); if (err) goto out; skb->dev = NULL; skb_set_owner_r(skb, sk); + edprint("3"); /* Cache the SKB length before we tack it onto the receive * queue. Once it is added it no longer belongs to us and @@ -1139,9 +1144,12 @@ skb_queue_tail(&sk->sk_receive_queue, skb); - if (!sock_flag(sk, SOCK_DEAD)) + if (!sock_flag(sk, SOCK_DEAD)) { + edprint("sk=%p",sk->sk_data_ready); sk->sk_data_ready(sk, skb_len); + } out: + edprint("out"); return err; } Index: linux-2.6.15-rc5-rt2/kernel/irq/handle.c =================================================================== --- linux-2.6.15-rc5-rt2.orig/kernel/irq/handle.c 2005-12-16 17:24:41.000000000 -0500 +++ linux-2.6.15-rc5-rt2/kernel/irq/handle.c 2005-12-16 17:26:29.000000000 -0500 @@ -16,6 +16,7 @@ #include #include #include +#include #if defined(CONFIG_NO_IDLE_HZ) #include @@ -526,6 +527,7 @@ struct irqaction * action; unsigned int status; + edprint("irq=%d",irq); /* * If the task is currently running in user mode, don't * detect soft lockups. If CONFIG_DETECT_SOFTLOCKUP is not Index: linux-2.6.15-rc5-rt2/kernel/timer.c =================================================================== --- linux-2.6.15-rc5-rt2.orig/kernel/timer.c 2005-12-16 17:24:41.000000000 -0500 +++ linux-2.6.15-rc5-rt2/kernel/timer.c 2005-12-16 17:26:29.000000000 -0500 @@ -34,6 +34,7 @@ #include #include #include +#include #include #include @@ -471,6 +472,7 @@ { struct timer_list *timer; + edprint("in"); spin_lock_irq(&base->t_base.lock); while (time_after_eq(jiffies, base->timer_jiffies)) { struct list_head work_list = LIST_HEAD_INIT(work_list); @@ -513,7 +515,9 @@ spin_unlock_irq(&base->t_base.lock); { int preempt_count = preempt_count(); + edprint("fn=%p",fn); fn(data); + edprint("after fn"); if (preempt_count != preempt_count()) { print_symbol("BUG: unbalanced timer-handler preempt count in %s!\n", (unsigned long) fn); printk("entered with %08x, exited with %08x.\n", preempt_count, preempt_count()); @@ -527,6 +531,7 @@ } spin_unlock_irq(&base->t_base.lock); wake_up(&base->t_base.wait_for_running_timer); + edprint("out"); } #ifdef CONFIG_NO_IDLE_HZ @@ -1150,10 +1155,12 @@ { tvec_base_t *base = &__get_cpu_var(tvec_bases); + edprint("in"); update_times(); hrtimer_run_queues(); if (time_after_eq(jiffies, base->timer_jiffies)) __run_timers(base); + edprint("out"); } /* Index: linux-2.6.15-rc5-rt2/net/core/dev.c =================================================================== --- linux-2.6.15-rc5-rt2.orig/net/core/dev.c 2005-12-16 17:24:41.000000000 -0500 +++ linux-2.6.15-rc5-rt2/net/core/dev.c 2005-12-16 17:26:29.000000000 -0500 @@ -114,6 +114,7 @@ #include #endif /* CONFIG_NET_RADIO */ #include +#include /* * The list of packet types we will receive (as opposed to discard) @@ -1603,6 +1604,7 @@ int ret = NET_RX_DROP; unsigned short type; + edprint("in"); /* if we've gotten here through NAPI, check netpoll */ if (skb->dev->poll && netpoll_rx(skb)) return NET_RX_DROP; @@ -1623,6 +1625,7 @@ pt_prev = NULL; rcu_read_lock(); + edprint("1"); #ifdef CONFIG_NET_CLS_ACT if (skb->tc_verd & TC_NCLS) { @@ -1631,6 +1634,7 @@ } #endif + edprint("2"); list_for_each_entry_rcu(ptype, &ptype_all, list) { if (!ptype->dev || ptype->dev == skb->dev) { if (pt_prev) @@ -1639,6 +1643,7 @@ } } + edprint("3"); #ifdef CONFIG_NET_CLS_ACT if (pt_prev) { ret = deliver_skb(skb, pt_prev, orig_dev); @@ -1657,12 +1662,15 @@ skb->tc_verd = 0; ncls: #endif + edprint("4"); handle_diverter(skb); + edprint("5"); if (handle_bridge(&skb, &pt_prev, &ret, orig_dev)) goto out; + edprint("6"); type = skb->protocol; list_for_each_entry_rcu(ptype, &ptype_base[ntohs(type)&15], list) { if (ptype->type == type && @@ -1672,8 +1680,10 @@ pt_prev = ptype; } } + edprint("7"); if (pt_prev) { + edprint("prev = %p",pt_prev); ret = pt_prev->func(skb, skb->dev, pt_prev, orig_dev); } else { kfree_skb(skb); @@ -1684,7 +1694,9 @@ } out: + edprint("8"); rcu_read_unlock(); + edprint("out"); return ret; } @@ -1744,6 +1756,7 @@ raw_local_irq_disable(); queue = &__get_cpu_var(softnet_data); + edprint("in"); while (!list_empty(&queue->poll_list)) { struct net_device *dev; @@ -1777,6 +1790,7 @@ } } out: + edprint("out"); raw_local_irq_enable(); return; Index: linux-2.6.15-rc5-rt2/net/core/skbuff.c =================================================================== --- linux-2.6.15-rc5-rt2.orig/net/core/skbuff.c 2005-12-16 17:24:41.000000000 -0500 +++ linux-2.6.15-rc5-rt2/net/core/skbuff.c 2005-12-16 17:26:29.000000000 -0500 @@ -288,19 +288,23 @@ struct sk_buff *other; atomic_t *fclone_ref; + edprint("in"); skb_release_data(skb); switch (skb->fclone) { case SKB_FCLONE_UNAVAILABLE: + edprint("1"); kmem_cache_free(skbuff_head_cache, skb); break; case SKB_FCLONE_ORIG: + edprint("2"); fclone_ref = (atomic_t *) (skb + 2); if (atomic_dec_and_test(fclone_ref)) kmem_cache_free(skbuff_fclone_cache, skb); break; case SKB_FCLONE_CLONE: + edprint("3"); fclone_ref = (atomic_t *) (skb + 1); other = skb - 1; @@ -313,6 +317,7 @@ kmem_cache_free(skbuff_fclone_cache, other); break; }; + edprint("out"); } /** @@ -326,6 +331,7 @@ void __kfree_skb(struct sk_buff *skb) { + edprint("in"); dst_release(skb->dst); #ifdef CONFIG_XFRM secpath_put(skb->sp); @@ -351,7 +357,9 @@ #endif #endif + edprint("1"); kfree_skbmem(skb); + edprint("out"); } /** Index: linux-2.6.15-rc5-rt2/net/ipv4/ip_input.c =================================================================== --- linux-2.6.15-rc5-rt2.orig/net/ipv4/ip_input.c 2005-12-16 17:24:41.000000000 -0500 +++ linux-2.6.15-rc5-rt2/net/ipv4/ip_input.c 2005-12-16 17:26:29.000000000 -0500 @@ -130,6 +130,7 @@ #include #include #include +#include #include #include @@ -201,6 +202,7 @@ { int ihl = skb->nh.iph->ihl*4; + edprint("in"); __skb_pull(skb, ihl); /* Free reference early: we don't need it any more, and it may @@ -236,6 +238,7 @@ kfree_skb(skb); goto out; } + edprint("handler=%p",ipprot->handler); ret = ipprot->handler(skb); if (ret < 0) { protocol = -ret; @@ -256,6 +259,7 @@ } out: rcu_read_unlock(); + edprint("out"); return 0; } @@ -269,6 +273,7 @@ * Reassemble IP fragments. */ + edprint("in"); if (skb->nh.iph->frag_off & htons(IP_MF|IP_OFFSET)) { skb = ip_defrag(skb, IP_DEFRAG_LOCAL_DELIVER); if (!skb) @@ -334,6 +339,7 @@ static inline int ip_rcv_finish(struct sk_buff *skb) { struct iphdr *iph = skb->nh.iph; + edprint("in"); /* * Initialise the virtual path cache for the packet. It describes @@ -363,10 +369,12 @@ if (iph->ihl > 5 && ip_rcv_options(skb)) goto drop; + edprint("out"); return dst_input(skb); drop: kfree_skb(skb); + edprint("out"); return NET_RX_DROP; } @@ -378,6 +386,7 @@ struct iphdr *iph; u32 len; + edprint("in"); /* When the interface is in promisc. mode, drop all the crap * that it receives, do not try to analyse it. */ @@ -431,6 +440,7 @@ goto drop; } + edprint("out"); return NF_HOOK(PF_INET, NF_IP_PRE_ROUTING, skb, dev, NULL, ip_rcv_finish); @@ -439,6 +449,7 @@ drop: kfree_skb(skb); out: + edprint("out"); return NET_RX_DROP; } Index: linux-2.6.15-rc5-rt2/net/ipv4/udp.c =================================================================== --- linux-2.6.15-rc5-rt2.orig/net/ipv4/udp.c 2005-12-16 17:24:41.000000000 -0500 +++ linux-2.6.15-rc5-rt2/net/ipv4/udp.c 2005-12-16 17:26:29.000000000 -0500 @@ -108,6 +108,7 @@ #include #include #include +#include /* * Snmp MIB for the UDP layer @@ -994,6 +995,7 @@ { struct udp_sock *up = udp_sk(sk); + edprint("in"); /* * Charge it to the socket, dropping if the queue is full. */ @@ -1002,6 +1004,7 @@ return -1; } + edprint("1"); if (up->encap_type) { /* * This is an encapsulation socket, so let's see if this is @@ -1014,12 +1017,14 @@ */ int ret; + edprint("2"); ret = udp_encap_rcv(sk, skb); if (ret == 0) { /* Eat the packet .. */ kfree_skb(skb); return 0; } + edprint("3"); if (ret < 0) { /* process the ESP packet */ ret = xfrm4_rcv_encap(skb, up->encap_type); @@ -1029,6 +1034,7 @@ /* FALLTHROUGH -- it's a UDP Packet */ } + edprint("4"); if (sk->sk_filter && skb->ip_summed != CHECKSUM_UNNECESSARY) { if (__udp_checksum_complete(skb)) { UDP_INC_STATS_BH(UDP_MIB_INERRORS); @@ -1037,6 +1043,7 @@ } skb->ip_summed = CHECKSUM_UNNECESSARY; } + edprint("5"); if (sock_queue_rcv_skb(sk,skb)<0) { UDP_INC_STATS_BH(UDP_MIB_INERRORS); @@ -1044,6 +1051,7 @@ return -1; } UDP_INC_STATS_BH(UDP_MIB_INDATAGRAMS); + edprint("out"); return 0; } @@ -1125,6 +1133,7 @@ u32 daddr = skb->nh.iph->daddr; int len = skb->len; + edprint("in"); /* * Validate the packet and the UDP length. */ @@ -1147,7 +1156,9 @@ if(rt->rt_flags & (RTCF_BROADCAST|RTCF_MULTICAST)) return udp_v4_mcast_deliver(skb, uh, saddr, daddr); + edprint("1"); sk = udp_v4_lookup(saddr, uh->source, daddr, uh->dest, skb->dev->ifindex); + edprint("2"); if (sk != NULL) { int ret = udp_queue_rcv_skb(sk, skb); @@ -1156,6 +1167,7 @@ /* a return value > 0 means to resubmit the input, but * it it wants the return to be -protocol, or 0 */ + edprint("out"); if (ret > 0) return -ret; return 0; @@ -1163,10 +1175,12 @@ if (!xfrm4_policy_check(NULL, XFRM_POLICY_IN, skb)) goto drop; + edprint("3"); /* No socket. Drop packet silently, if checksum is wrong */ if (udp_checksum_complete(skb)) goto csum_error; + edprint("4"); UDP_INC_STATS_BH(UDP_MIB_NOPORTS); icmp_send(skb, ICMP_DEST_UNREACH, ICMP_PORT_UNREACH, 0); @@ -1176,6 +1190,7 @@ * don't wanna listen. Ignore it. */ kfree_skb(skb); + edprint("out"); return(0); short_packet: @@ -1189,6 +1204,7 @@ no_header: UDP_INC_STATS_BH(UDP_MIB_INERRORS); kfree_skb(skb); + edprint("out"); return(0); csum_error: @@ -1205,6 +1221,7 @@ drop: UDP_INC_STATS_BH(UDP_MIB_INERRORS); kfree_skb(skb); + edprint("out"); return(0); } Index: linux-2.6.15-rc5-rt2/net/sunrpc/xprtsock.c =================================================================== --- linux-2.6.15-rc5-rt2.orig/net/sunrpc/xprtsock.c 2005-12-16 17:24:41.000000000 -0500 +++ linux-2.6.15-rc5-rt2/net/sunrpc/xprtsock.c 2005-12-16 17:26:29.000000000 -0500 @@ -480,6 +480,7 @@ int err, repsize, copied; u32 _xid, *xp; + edprint("in"); read_lock(&sk->sk_callback_lock); dprintk("RPC: xs_udp_data_ready...\n"); if (!(xprt = xprt_from_sock(sk))) @@ -497,39 +498,51 @@ goto dropit; } + edprint("1"); /* Copy the XID from the skb... */ xp = skb_header_pointer(skb, sizeof(struct udphdr), sizeof(_xid), &_xid); + edprint("2"); if (xp == NULL) goto dropit; + edprint("3"); /* Look up and lock the request corresponding to the given XID */ spin_lock(&xprt->transport_lock); rovr = xprt_lookup_rqst(xprt, *xp); + edprint("4"); if (!rovr) goto out_unlock; task = rovr->rq_task; + edprint("5"); if ((copied = rovr->rq_private_buf.buflen) > repsize) copied = repsize; + edprint("6"); /* Suck it into the iovec, verify checksum if not done by hw. */ if (csum_partial_copy_to_xdr(&rovr->rq_private_buf, skb)) goto out_unlock; + edprint("7"); /* Something worked... */ dst_confirm(skb->dst); + edprint("8"); xprt_adjust_cwnd(task, copied); xprt_update_rtt(task); xprt_complete_rqst(task, copied); + edprint("9"); out_unlock: spin_unlock(&xprt->transport_lock); dropit: + edprint("10"); skb_free_datagram(sk, skb); out: + edprint("11"); read_unlock(&sk->sk_callback_lock); + edprint("out"); } static inline size_t xs_tcp_copy_data(skb_reader_t *desc, void *p, size_t len) Index: linux-2.6.15-rc5-rt2/kernel/hrtimer.c =================================================================== --- linux-2.6.15-rc5-rt2.orig/kernel/hrtimer.c 2005-12-16 17:26:18.000000000 -0500 +++ linux-2.6.15-rc5-rt2/kernel/hrtimer.c 2005-12-16 17:26:47.000000000 -0500 @@ -34,6 +34,7 @@ #include #include #include +#include #include @@ -893,6 +894,7 @@ struct rb_node *node; spin_lock_irq(&base->lock); + edprint("in"); while ((node = base->first)) { struct hrtimer *timer; @@ -904,6 +906,7 @@ if (now.tv64 <= timer->expires.tv64) break; + edprint("func=%p",timer->function); fn = timer->function; data = timer->data; set_curr_timer(base, timer); @@ -921,6 +924,7 @@ restart = fn(data); spin_lock_irq(&base->lock); + edprint("after func"); if (restart == HRTIMER_RESTART) enqueue_hrtimer(timer, base); @@ -929,6 +933,7 @@ set_curr_timer(base, NULL); } spin_unlock_irq(&base->lock); + edprint("out"); } /* @@ -943,8 +948,10 @@ struct hrtimer_base *base = __get_cpu_var(hrtimer_bases); int i; + edprint("in"); hrtimer_check_clocks(); + edprint("%s",hrtimer_hres_active?"active":"inactive"); if (hrtimer_hres_active) return;