[RHEL] How do I profile TCP/IP kernel times?

Solution Unverified - Updated -

Environment

  • Red Hat Enterprise Linux 5
  • Red Hat Enterprise Linux 6

Issue

  • Need to profile a datagram between the driver and the consuming application

Resolution

  • Use systemtap. Add the packages: systemtap, kernel-debuginfo, kernel-debuginfo-common, kernel-devel and gcc
  • Create the following systemtap script:
    /* Sample output:
Wed Mar  2 16:01:36 |I| drv-ip: 23 us,     ip-tcp: 34 us,      tcp-app: 189 us.     | Proc firefox, PID 19550
Wed Mar  2 15:01:37 |O| app-tcp: 3 us,     tcp-ip: 7 us,      ip-drv: 2 us.         | Proc firefox, PID 19550
Wed Mar  2 16:01:37 |I| drv-ip: 14 us,     ip-tcp: 21 us,      tcp-app: 231 us.     | Proc firefox, PID 19550
Wed Mar  2 15:01:41 |O| app-tcp: 5 us,     tcp-ip: 12 us,      ip-drv: 7 us.        | Proc firefox, PID 19550
Wed Mar  2 16:01:41 |I| drv-ip: 17 us,     ip-tcp: 15 us,      tcp-app: 147 us.     | Proc firefox, PID 19550
Wed Mar  2 15:01:41 |O| app-tcp: 4 us,     tcp-ip: 5 us,      ip-drv: 2 us.         | Proc firefox, PID 19550
Wed Mar  2 16:01:41 |I| drv-ip: 14 us,     ip-tcp: 15 us,      tcp-app: 189 us.     | Proc firefox, PID 19372
Wed Mar  2 15:01:43 |O| app-tcp: 6 us,     tcp-ip: 13 us,      ip-drv: 7 us.        | Proc firefox, PID 19372 */


// Global tap vars
global rcv_skb, ip_rcv, tcp_rcv, app_tx, tcp_tx, ip_tx

// NIC input buffer
probe kernel.function("netif_receive_skb") {
     rcv_skb[$skb] = gettimeofday_us()
}

// Kernel delivery
probe kernel.function("netif_rx") {
     rcv_skb[$skb] = gettimeofday_us()
}

// Enters IP stack
probe kernel.function("ip_rcv") {
     ip_rcv[$skb] = gettimeofday_us()
}

// Enters TCP stack
probe kernel.function("tcp_v4_rcv") {
     tcp_rcv[$skb] = gettimeofday_us()
}

// Delivered to the consuming app
probe kernel.function("skb_copy_datagram_iovec") {
     data = gettimeofday_s()
     // Adjust value below for the amount of seconds to add or remove from GMT to match your timezone
     data = data-0
     now = gettimeofday_us()
     // Trigger tap
     if ($skb in tcp_rcv) {
                     printf ("%s \b\b\b\b\b\b |I| drv-ip: %d us,\tip-tcp: %d us,\t tcp-app: %d us.\t| Proc %s, PID %d\n",
               ctime(data),
               ip_rcv[$skb] - rcv_skb[$skb],
               tcp_rcv[$skb] - ip_rcv[$skb],
               now - tcp_rcv[$skb],
               execname(), pid())
          // Clean vars
          delete rcv_skb[$skb]
          delete ip_rcv[$skb]
          delete tcp_rcv[$skb]
     }
}

// Register skb on TCP stack
probe kernel.function("tcp_v4_send_check") {
        tcp_tx[$skb] = gettimeofday_us()
}

// SK goes off TCP buff
probe kernel.function("tcp_transmit_skb") {
        app_tx[$skb] = gettimeofday_us()
}

// SK enters IP stack
probe kernel.function("ip_output") {
        ip_tx[$skb] = gettimeofday_us()
}

// Delivered to device xmit
probe kernel.function("dev_queue_xmit") {
        today = gettimeofday_s()
        data = today-0
        inicio = gettimeofday_us()
        if ($skb in app_tx) {
                printf ("%s \b\b\b\b\b\b |O| app-tcp: %d us,\ttcp-ip: %d us,\t ip-drv: %d us.\t\t| Proc %s, PID %d\n",
                        ctime(data),
                        tcp_tx[$skb] - app_tx[$skb],
                        ip_tx[$skb] - tcp_tx[$skb],
                        inicio - ip_tx[$skb],
               execname(), pid())

                delete app_tx[$skb]
                delete tcp_tx[$skb]
                delete ip_tx[$skb]
        }
}

This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.

Comments