debian下使用dynamic printk分析usb轉串口驅動執行流程 linux下無線鼠標驅動執行流程 debian下使用dynamic printk分析usb網卡驅動

看了一篇文章《debug by printing》,文中提到了多種經過printk來調試驅動的方法,其中最有用的就是"Dynamic debugging"。html

「Dynamic debugging"的官方文檔:http://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/tree/Documentation/dynamic-debug-howto.txt?id=HEADnode

"Dyanmic debugging"的功能適用於全部的linux內核,因此也能夠用於嵌入式開發板中調試驅動程序。linux

 

在使用"Dynamic debugging"前須要在內核中使能Dynamic printk選項(可用於控制代碼代碼中的pr_debug和dev_dbg的信息是否輸出)。git

默認官方debian內核中沒有使能這個選項,能夠參考個人博文《debian下配置dynamic printk以及從新編譯內核 》從新編譯和配置內核才能使用該功能。函數

 

本文用一個usb轉串口線(核心芯片是pl2303)的例子來講明如何使用"Dynamic debugging",內核版本是linux-3.2.57。post

 

先插入usb轉串口線,獲得下面的信息:ui

[    8.728526] usbcore: registered new interface driver usbserial [ 8.728669] USB Serial support registered for generic [ 8.728720] usbcore: registered new interface driver usbserial_generic [ 8.728722] usbserial: USB Serial Driver core [ 8.737942] USB Serial support registered for pl2303 [ 8.737963] pl2303 5-2:1.0: pl2303 converter detected [ 8.750530] usb 5-2: pl2303 converter now attached to ttyUSB0 [ 8.750565] usbcore: registered new interface driver pl2303 [ 8.750568] pl2303: Prolific PL2303 USB to serial adaptor driver

 

pl2303驅動中用到了pl2303的驅動,查看pl2303驅動信息:url

$ sudo modinfo pl2303
filename:       /lib/modules/3.2.57/kernel/drivers/usb/serial/pl2303.ko
license:        GPL
description:    Prolific PL2303 USB to serial adaptor driver
alias:          usb:v0B8Cp2303d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v0B63p6530d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v11ADp0001d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v054Cp0437d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v04B8p0522d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v04B8p0521d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v03F0p3524d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v5372p2303d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v05ADp0FBAd*dc*dsc*dp*ic*isc*ip*
alias:          usb:v07AAp002Ad*dc*dsc*dp*ic*isc*ip*
alias:          usb:v11F6p2001d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v058Fp9720d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v050Dp0257d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v0731p2003d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v0E55p110Bd*dc*dsc*dp*ic*isc*ip*
alias:          usb:v0413p2101d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v079Bp0027d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v10B5pAC70d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v078Bp1234d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v0745p0001d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v04A5p4027d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v11F5p0005d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v11F5p0004d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v11F5p0003d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v11F5p0001d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v04E8p8001d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v11F7p02DFd*dc*dsc*dp*ic*isc*ip*
alias:          usb:v6189p2068d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v0731p0528d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v1453p4026d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v2478p2008d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v0584pB000d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v0DF7p0620d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v0EBAp2080d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v0EBAp1080d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v056Ep5004d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v056Ep5003d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v0547p2008d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v0557p2008d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v04BBp0A0Ed*dc*dsc*dp*ic*isc*ip*
alias:          usb:v04BBp0A03d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v067Bp0307d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v067Bp331Ad*dc*dsc*dp*ic*isc*ip*
alias:          usb:v067Bp0609d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v067Bp0612d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v067Bp0611d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v067BpAAA0d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v067BpAAA2d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v067Bp1234d*dc*dsc*dp*ic*isc*ip*
alias:          usb:v067Bp04BBd*dc*dsc*dp*ic*isc*ip*
alias:          usb:v067Bp2303d*dc*dsc*dp*ic*isc*ip*
depends:        usbserial,usbcore
intree:         Y
vermagic:       3.2.57 SMP mod_unload modversions 686 
parm:           debug:Debug enabled or not (bool)

能夠看到pl2303又依賴於usbserial和usbcore.spa

 

下載linux內核源碼(能夠參考個人博文《debian下配置dynamic printk以及從新編譯內核》),解壓縮後進入該文件夾。線程

$ grep 'pl2303' drivers/usb/serial/Makefile
obj-$(CONFIG_USB_SERIAL_PL2303)            += pl2303.o
$ grep 'usbserial' drivers/usb/serial/Makefile
obj-$(CONFIG_USB_SERIAL)            += usbserial.o
usbserial-y := usb-serial.o generic.o bus.o
usbserial-$(CONFIG_USB_SERIAL_CONSOLE)    += console.o
usbserial-$(CONFIG_USB_EZUSB)        += ezusb.o
$ grep 'usbcore' drivers/usb/core/Makefile
usbcore-y := usb.o hub.o hcd.o urb.o message.o driver.o
usbcore-y += config.o file.o buffer.o sysfs.o endpoint.o
usbcore-y += devio.o notify.o generic.o quirks.o devices.o
usbcore-$(CONFIG_PCI)        += hcd-pci.o
usbcore-$(CONFIG_USB_DEVICEFS)    += inode.o
obj-$(CONFIG_USB)        += usbcore.o

從搜索結果能夠看出:

pl2303驅動由drivers/usb/serial/pl2303.c文件來生成的。

usbserial驅動是由drivers/usb/serial下的usb-serial.c generic.c bus.c這三個文件來生成的。

usbcore是由drivers/usb/core/下面的usb.c hub.c hcd.c urb.c message.c driver.c config.c file.c buffer.c sysfs.c endpoint.c

devio.c notify.c generic.c quirks.c devices.c hcd-pci.c inode.c這些文件生成的。

 

切換到root用戶:

su

掛載debugfs:

# mount -t debugfs none /sys/kernel/debug/

對上面提到的全部文件使能"Dynamic debugging":

root@debian:~# echo 'file drivers/usb/serial/pl2303.c +p' > /sys/kernel/debug/dynamic_debug/control 
root@debian:~# echo 'file drivers/usb/serial/usb-serial.c +p' > /sys/kernel/debug/dynamic_debug/control 
root@debian:~# echo 'file drivers/usb/serial/generic.c +p' > /sys/kernel/debug/dynamic_debug/control 
root@debian:~# echo 'file drivers/usb/serial/bus.c +p' > /sys/kernel/debug/dynamic_debug/control 
root@debian:~# echo 'file drivers/usb/core/usb.c +p' > /sys/kernel/debug/dynamic_debug/control^C
root@debian:~# echo 'file drivers/usb/core/hub.c +p' > /sys/kernel/debug/dynamic_debug/control
root@debian:~# echo 'file drivers/usb/core/hcd.c +p' > /sys/kernel/debug/dynamic_debug/control
root@debian:~# echo 'file drivers/usb/core/urb.c +p' > /sys/kernel/debug/dynamic_debug/control
root@debian:~# echo 'file drivers/usb/core/message.c +p' > /sys/kernel/debug/dynamic_debug/control
root@debian:~# echo 'file drivers/usb/core/driver.c +p' > /sys/kernel/debug/dynamic_debug/control
root@debian:~# echo 'file drivers/usb/core/config.c +p' > /sys/kernel/debug/dynamic_debug/control
root@debian:~# echo 'file drivers/usb/core/file.c +p' > /sys/kernel/debug/dynamic_debug/control
root@debian:~# echo 'file drivers/usb/core/buffer.c +p' > /sys/kernel/debug/dynamic_debug/control
root@debian:~# echo 'file drivers/usb/core/sysfs.c +p' > /sys/kernel/debug/dynamic_debug/control
root@debian:~# echo 'file drivers/usb/core/endpoint.c +p' > /sys/kernel/debug/dynamic_debug/control
root@debian:~# echo 'file drivers/usb/core/device.c +p' > /sys/kernel/debug/dynamic_debug/control
root@debian:~# echo 'file drivers/usb/core/notify.c +p' > /sys/kernel/debug/dynamic_debug/control
root@debian:~# echo 'file drivers/usb/core/generic.c +p' > /sys/kernel/debug/dynamic_debug/control
root@debian:~# echo 'file drivers/usb/core/quirks.c +p' > /sys/kernel/debug/dynamic_debug/control
root@debian:~# echo 'file drivers/usb/core/devices.c +p' > /sys/kernel/debug/dynamic_debug/control
root@debian:~# echo 'file drivers/usb/core/hci-pci.c +p' > /sys/kernel/debug/dynamic_debug/control
root@debian:~# echo 'file drivers/usb/core/inode.c +p' > /sys/kernel/debug/dynamic_debug/control

 

先拔掉usb轉串口線,而後刪除pl2303驅動(由於以前已經插入過usb轉串口,pl2303已經加載):

sudo rmmod pl2303

再插入usb轉串口線,在另外一個控制檯下執行命令:

$ dmesg | tail -n 35
[ 3405.314567] hub 1-0:1.0: state 7 ports 8 chg 0000 evt 0100
[ 3405.314587] hub 1-0:1.0: port 8, status 0501, change 0001, 480 Mb/s
[ 3405.472015] hub 1-0:1.0: debounce: port 8: total 125ms stable 100ms status 0x501
[ 3405.528178] hub 1-0:1.0: port 8 not reset yet, waiting 50ms
[ 3405.528197] usb usb5: usb wakeup-resume
[ 3405.528203] usb usb5: usb auto-resume
[ 3405.568011] hub 5-0:1.0: hub_resume
[ 3405.568027] hub 5-0:1.0: port 2: status 0101 change 0001
[ 3405.584034] hub 1-0:1.0: state 7 ports 8 chg 0000 evt 0100
[ 3405.672026] hub 5-0:1.0: state 7 ports 2 chg 0004 evt 0000
[ 3405.672041] hub 5-0:1.0: port 2, status 0101, change 0000, 12 Mb/s
[ 3405.784018] usb 5-2: new full-speed USB device number 4 using uhci_hcd
[ 3405.936037] usb 5-2: default language 0x0409
[ 3405.946039] usb 5-2: udev 4, busnum 5, minor = 515
[ 3405.946044] usb 5-2: New USB device found, idVendor=067b, idProduct=2303
[ 3405.946049] usb 5-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 3405.946053] usb 5-2: Product: USB-Serial Controller
[ 3405.946057] usb 5-2: Manufacturer: Prolific Technology Inc.
[ 3405.946151] bus: 'usb': add device 5-2
[ 3405.946228] usb 5-2: usb_probe_device
[ 3405.946234] usb 5-2: configuration #1 chosen from 1 choice
[ 3405.949040] usb 5-2: adding 5-2:1.0 (config #1, interface 0)
[ 3405.949061] bus: 'usb': add device 5-2:1.0
[ 3405.949110] usbserial_generic 5-2:1.0: usb_probe_interface
[ 3405.949115] usbserial_generic 5-2:1.0: usb_probe_interface - got id
[ 3406.014058] bus: 'usb-serial': add driver pl2303
[ 3406.014092] USB Serial support registered for pl2303
[ 3406.014096] bus: 'usb': add driver pl2303
[ 3406.027529] pl2303 5-2:1.0: usb_probe_interface
[ 3406.027533] pl2303 5-2:1.0: usb_probe_interface - got id
[ 3406.027539] pl2303 5-2:1.0: pl2303 converter detected
[ 3406.039051] bus: 'usb-serial': add device ttyUSB0
[ 3406.039201] usb 5-2: pl2303 converter now attached to ttyUSB0
[ 3406.039221] usbcore: registered new interface driver pl2303
[ 3406.039223] pl2303: Prolific PL2303 USB to serial adaptor driver

明顯多了不少調試信息,更便於跟蹤實際代碼的執行狀況。

 

下面分析插入usb轉串口線時的執行狀況.

 

考慮「[ 3405.314567] hub 1-0:1.0: state 7 ports 8 chg 0000 evt 0100」這一行輸出信息。

咱們只考慮driver/usb下執行的代碼,因此只在該文件夾下搜索源代碼。

$ grep -rnHi 'chg.*evt'  drivers/usb/
drivers/usb/core/hub.c:3586:        dev_dbg(hub_dev, "state %d ports %d chg %04x evt %04x\n", 

 這一行代碼位於hub_events函數,該函數被hub_thread調用:

static int hub_thread(void *__unused)
{   
     /* khubd needs to be freezable to avoid intefering with USB-PERSIST
      * port handover.  Otherwise it might see that a full-speed device
      * was gone before the EHCI controller had handed its port over to
      * the companion full-speed controller.
      */
     set_freezable();
     
     do {
         hub_events();
         wait_event_freezable(khubd_wait,
                 !list_empty(&hub_event_list) ||
                 kthread_should_stop());
     } while (!kthread_should_stop() || !list_empty(&hub_event_list));
     
     pr_debug("%s: khubd exiting\n", usbcore_name);
     return 0;
 }   

hub_thread是在usb_hub_init中建立的一個內核線程khubd的執行函數,這個內核線程開機後就會一直處於運行狀態。

 

考慮「[ 3405.314587] hub 1-0:1.0: port 8, status 0501, change 0001, 480 Mb/s」這一行輸出信息:

$ grep -rnHi 'port.*status.*change.*\\n'  drivers/usb/
drivers/usb/core/hub.c:859:                    "port %d: status %04x change %04x\n",
drivers/usb/core/hub.c:3329:        "port %d, status %04x, change %04x, %s\n",
drivers/usb/gadget/dummy_hcd.c:1753:        dev_dbg(dummy_dev(dum_hcd), "port status 0x%08x has changes\n",
drivers/usb/host/xhci-ring.c:1565:    xhci_dbg(xhci, "Port Status Change Event for port %d\n", port_id);

能夠看出只有第兩行輸出信息可能和當前的輸出有關係,此行代碼位於hub_port_connect_change函數,

而hub_port_connect_change被hub_events函數調用。

 

考慮下一行輸出「[ 3405.472015] hub 1-0:1.0: debounce: port 8: total 125ms stable 100ms status 0x501」。

$ grep -rnHi 'debounce:'  drivers/usb/
drivers/usb/core/hub.c:2898:        "debounce: port %d: total %dms stable %dms status 0x%x\n",

該行輸出信息位於hub_port_debounce函數,hub_port_debounce函數又被hub_port_connect_change所調用。

 

考慮下一行輸出「[ 3405.528178] hub 1-0:1.0: port 8 not reset yet, waiting 50ms」。

$ grep -rnHi 'reset yet,'  drivers/usb/
drivers/usb/core/hub.c:2203:            "port %d not %sreset yet, waiting %dms\n",

這行代碼位於hub_port_wait_reset函數,hub_port_wait_reset又被hub_port_reset函數調用,hub_port_reset又被hub_port_init調用,

hub_port_init又被hub_port_connect_change函數調用。

 

下一行輸出「[ 3405.528197] usb usb5: usb wakeup-resume」。

$ grep -rnHi '%sresume'  drivers/usb/core
drivers/usb/core/hcd.c:2012:    dev_dbg(&rhdev->dev, "usb %sresume\n",
drivers/usb/core/hub.c:2686:        dev_dbg(&udev->dev, "usb %sresume\n",
drivers/usb/core/hub.c:2737:        dev_dbg(&udev->dev, "usb %sresume\n", "wakeup-");

查看代碼後得知,與之匹配的是hub.c中2737行代碼,位於usb_remote_wakeup中.

usb_remote_wakeup在好幾個地方被調用,不清楚是哪一個函數調用引發的。

 

下一行輸出信息是:[ 3405.528203] usb usb5: usb auto-resume

根據上面的查新結果,極可能是被usb_port_resume或者hcd_bus_resume函數調用,而這兩個函數都是被generic_resume函數所調用。

下一行輸出信息:[ 3405.568011] hub 5-0:1.0: hub_resume

沒有用grep搜索到有用信息,可是極可能是執行hub_resume函數輸出的,查看hub_resume定義:

 static int hub_resume(struct usb_interface *intf)
 {
     struct usb_hub *hub = usb_get_intfdata(intf);
 
     dev_dbg(&intf->dev, "%s\n", __func__);
     hub_activate(hub, HUB_RESUME);
     return 0;
 }

果真代碼中有__func__,就是hub_resume。hub_resume沒有被直接調用,它在hub_driver.resume=hub_resume中被定義。

 

下一行輸出信息是:[ 3405.568027] hub 5-0:1.0: port 2: status 0101 change 0001

$ grep -rnHi 'port.*status.*change.*\\n'  drivers/usb/
drivers/usb/core/hub.c:859:                    "port %d: status %04x change %04x\n",
drivers/usb/core/hub.c:3329:        "port %d, status %04x, change %04x, %s\n",
drivers/usb/gadget/dummy_hcd.c:1753:        dev_dbg(dummy_dev(dum_hcd), "port status 0x%08x has changes\n",
drivers/usb/host/xhci-ring.c:1565:    xhci_dbg(xhci, "Port Status Change Event for port %d\n", port_id);

第一行搜索到的信息格式和輸出信息相匹配。此行代碼位於hub_activate中。而上一行中hub_resume剛好調用了hub_activate函數。

 

接下來三行輸出信息:

[ 3405.584034] hub 1-0:1.0: state 7 ports 8 chg 0000 evt 0100
[ 3405.672026] hub 5-0:1.0: state 7 ports 2 chg 0004 evt 0000
[ 3405.672041] hub 5-0:1.0: port 2, status 0101, change 0000, 12 Mb/s

這三行信息和最前面的兩行輸出信息相似,再也不重複分析了。 可是這裏又從新從hub_event的開頭部分開始執行程序。

 

下一行輸出信息:[ 3405.784018] usb 5-2: new full-speed USB device number 4 using uhci_hcd

 

$ grep -rnHi 'USB device number'  drivers/usb/
drivers/usb/core/hub.c:3035:                "%s %s USB device number %d using %s\n",
drivers/usb/core/hub.c:3149:                        "%s SuperSpeed USB device number %d using %s\n",

 

第一行搜索到內容與輸出信息徹底匹配,該代碼位於hub_port_init中。hub_port_init又被hub_port_connect_change調用。

 

下一行輸出信息:[ 3405.936037] usb 5-2: default language 0x0409

$ grep -rnHi 'default language'  drivers/usb/
drivers/usb/core/message.c:790:    dev_dbg(&dev->dev, "default language 0x%04x\n",

該行代碼位於usb_get_langid中,usb_get_langid又被usb_string函數調用。調用usb_string的函數很差分析,留待之後再看。

 

 

 下一行輸出信息:[ 3405.946039] usb 5-2: udev 4, busnum 5, minor = 515

$ grep -rnHi 'udev.*busnum.*minor'  drivers/usb/
drivers/usb/core/hub.c:1971:    dev_dbg(&udev->dev, "udev %d, busnum %d, minor = %d\n",

該代碼位於usb_new_device中,而usb_new_device又被usb_port_connect_change函數所調用。

而查看該行代碼前,執行了usb_enumerate_device函數。該函數調用了usb_cache_string,而usb_cache_string又調用了usb_string.

因此上一行的輸出信息就是在調用usb_enumerate_device時產生的。

 

接下來四行信息:

[ 3405.946044] usb 5-2: New USB device found, idVendor=067b, idProduct=2303
[ 3405.946049] usb 5-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 3405.946053] usb 5-2: Product: USB-Serial Controller
[ 3405.946057] usb 5-2: Manufacturer: Prolific Technology Inc.

 以前在個人博文《linux下無線鼠標驅動執行流程》中已經找到了執行這幾行代碼的函數,其名稱是announce_device,該函數也被usb_new_device調用。

 

下一行輸出信息:[ 3405.946151] bus: 'usb': add device 5-2

這行輸出信息在函數bus_add_device(drivers/base/bus.c)被執行。這是由於我在配置"dynamic debugging"時執行了下面的命令:

echo 'file bus.c +p' > /sys/kernel/debug/dynamic_debug/control 

後來看沒有隻是打開了drivers/base/bus.c,而不是打開drivers/usb/core/bus.c的"dynamic debugging"功能,因此才添加了路徑名稱來保證惟一性。

可是之前打開的drivers/base/bus.c中的"dynamic debugging"功能並無關閉,因此這裏有相關的信息顯示。

bus_add_device在device_add函數中被調用,device_add又被usb_new_device調用。

 

下一行輸出信息:[ 3405.946228] usb 5-2: usb_probe_device

猜測是執行usb_probe_device時顯示的信息,查看usb_probe_device函數代碼發現果真有下面一行代碼:

dev_dbg(dev, "%s\n", __func__);

usb_probe_device多是在device_add調用bus_probe_device時調用的(過程比較複雜,再也不詳述)。

 

 下一行輸出信息:[ 3405.946234] usb 5-2: configuration #1 chosen from 1 choice

$ grep -rnHi 'chosen from'  drivers/usb/
drivers/usb/core/generic.c:145:            "configuration #%d chosen from %d choice%s\n",
drivers/usb/core/generic.c:150:            "no configuration chosen from %d choice%s\n",

只有第一行搜索信息與實際輸出信息格式相匹配。

該行代碼位於usb_choose_configuration函數中,usb_choose_configuration函數又被generic_probe函數調用。

代碼中顯示usb_generic_driver和usb_serial_generic_driver這兩個驅動都使用了generic_probe函數執行probe功能。

此處應該使用的是usb_generic_driver的generic_probe函數。

 

 下一行輸出信息:[ 3405.949040] usb 5-2: adding 5-2:1.0 (config #1, interface 0)

$ grep -rnHi 'adding.*config.*interface'  drivers/usb/
drivers/usb/core/message.c:1861:            "adding %s (config #%d, interface %d)\n",

該代碼位於usb_set_configuration中,usb_set_configuration函數被generic_probe函數所調用。

 

下一行輸出信息:[ 3405.949061] bus: 'usb': add device 5-2:1.0

跟前面其中一行的狀況相同,執行bus_add_device時調用了這個函數,bus_add_device又被device_add函數所調用。

 

下一行輸出信息:[ 3405.949110] usbserial_generic 5-2:1.0: usb_probe_interface

$ grep -rnHi 'usbserial_generic'  drivers/usb/
drivers/usb/serial/generic.c:53:    .name =        "usbserial_generic",

看起來很像是執行usb_probe_interface時給出的輸出信息,查看函數源碼,果真有下一行代碼:

 dev_dbg(dev, "%s\n", __func__);

 

下一行輸出信息:[ 3405.949115] usbserial_generic 5-2:1.0: usb_probe_interface - got id

在查看usb_probe_interface函數源碼時看到有相似於"got id"之類的輸出,因此是在usb_probe_interface中被調用。

 

下一行輸出信息:[ 3406.014058] bus: 'usb-serial': add driver pl2303

$ grep -rnHi 'add driver' drivers/base
drivers/base/bus.c:635:    pr_debug("bus: '%s': add driver %s\n", bus->name, drv->name);

看輸出信息中第一個冒號前是usb,再拿前面的例子做對比,能夠知道應該是在drivers/base下執行代碼產生相似的輸出。

 該代碼位於bus_add_driver中,bus_add_driver又被driver_register函數所調用。

 

下一行輸出信息:[ 3406.014092] USB Serial support registered for pl2303

$ grep -rnHi 'registered for' drivers/usb
drivers/usb/serial/usb-serial.c:1389:        printk(KERN_INFO "USB Serial support registered for %s\n",
drivers/usb/gadget/s3c-hsotg.c:3121: * registered for each available).

搜索到的第一行信息與輸出信息格式一致。

該代碼位於usb_serial_register中,usb_serial_register又被pl2303_init所調用。

 

下一行輸出信息:[ 3406.039051] bus: 'usb-serial': add device ttyUSB0

跟前面一些輸出信息相似,也是被bus_add_device調用,bus_add_device又被device_add調用。

 

下一行輸出信息:[ 3406.039201] usb 5-2: pl2303 converter now attached to ttyUSB0

$ grep -rnHi 'attached to ttyUSB' drivers/usb
drivers/usb/serial/bus.c:83:         "%s converter now attached to ttyUSB%d\n",

此代碼位於usb_serial_device_probe中。代碼中還有這樣的賦值:usb_serial_bus_type.probe=usb_serial_device_probe

 

下一行信息輸出:[ 3406.039221] usbcore: registered new interface driver pl2303

$ grep -rnHi 'registered new interface' drivers/usb
drivers/usb/core/driver.c:888:    pr_info("%s: registered new interface driver %s\n",

該代碼位於usb_register_driver函數中。

文件include/linux/usb.h中有下面的定義:

#define usb_register(driver) \
      usb_register_driver(driver, THIS_MODULE, KBUILD_MODNAME)

因此有多是調用usb_register時輸出了這行信息。 pl2303_init也調用了usb_register。

 

最後一行輸出信息:[ 3406.039223] pl2303: Prolific PL2303 USB to serial adaptor driver

這行輸出信息對應pl2303_init中的下列代碼:

printk(KERN_INFO KBUILD_MODNAME ": " DRIVER_DESC "\n");

 

 從上面的分析能夠看出,執行程序時會運行drivers/base下的一些代碼。

拔掉usb轉串口線,而後使能drivers/base下全部文件的"dynamic debugging"功能。

從幫助文件中查到下面的命令:

echo 'file drivers/base/* +p' > /sys/kernel/debug/dynamic_debug/control 

可是執行後卻沒有做用,貌似還只能一個一個文件的使能"dynamic debugging"。

另外,使能命令中的+p能夠修改爲+flmpt,這樣會顯示出了模塊名稱和函數名稱、行號、線程信息等。

 

後注:

上面提到使用drivers/base/下的文件,關聯文件:

$ head -n 7 drivers/base/Makefile 
# Makefile for the Linux device tree

obj-y            := core.o sys.o bus.o dd.o syscore.o \
               driver.o class.o platform.o \
               cpu.o firmware.o init.o map.o devres.o \
               attribute_container.o transport_class.o \
               topology.o

 

週末在我本身電腦上又想執行上面的配置,可是一個一個的輸入命令太麻煩了,我寫了一個小腳本,內容以下:

#!/bin/sh

DYNAMIC_CONTROL=/sys/kernel/debug/dynamic_debug/control
echo 'file drivers/usb/serial/usb-serial.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/serial/genemic.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/serial/bus.c +flmpt' > $DYNAMIC_CONTROL

echo 'file drivers/usb/core/usb.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/core/hub.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/core/hcd.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/core/urb.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/core/message.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/core/driver.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/core/config.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/core/file.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/core/buffer.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/core/sysfs.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/core/endpoint.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/core/device.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/core/notify.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/core/generic.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/core/quirks.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/core/devices.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/core/hci-pci.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/usb/core/inode.c +flmpt' > $DYNAMIC_CONTROL

echo 'file drivers/base/core.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/base/sys.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/base/bus.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/base/dd.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/base/syscore.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/base/driver.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/base/class.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/base/platform.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/base/cpu.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/base/firmware.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/base/init.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/base/map.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/base/devres.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/base/attribute_container.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/base/transport_class.c +flmpt' > $DYNAMIC_CONTROL
echo 'file drivers/base/topology.c +flmpt' > $DYNAMIC_CONTROL

掛載debugfs,執行這個腳本,而後插入和移除usb轉串口獲得下面的信息:

[24923.523302] [17335] usbcore:usb_remote_wakeup:2737: usb usb1: usb wakeup-resume
[24923.523314] [17335] usbcore:hcd_bus_resume:2013: usb usb1: usb auto-resume
[24923.536972] [17335] usbcore:hub_resume:2810: hub 1-0:1.0: hub_resume
[24923.536995] [17335] usbcore:hub_activate:860: hub 1-0:1.0: port 1: status 0101 change 0001
[24923.537013] [17335] usbcore:hub_activate:860: hub 1-0:1.0: port 4: status 0507 change 0000
[24923.640857] [164] usbcore:hub_events:3592: hub 1-0:1.0: state 7 ports 4 chg 0002 evt 0000
[24923.640884] [164] usbcore:hub_port_connect_change:3330: hub 1-0:1.0: port 1, status 0101, change 0000, 12 Mb/s
[24923.752690] usb 1-1: new full-speed USB device number 26 using xhci_hcd
[24923.769191] [164] usbcore:usb_get_langid:791: usb 1-1: default language 0x0409
[24923.769490] [164] usbcore:usb_new_device:1973: usb 1-1: udev 26, busnum 1, minor = 25
[24923.769498] usb 1-1: New USB device found, idVendor=067b, idProduct=2303
[24923.769502] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[24923.769507] usb 1-1: Product: USB-Serial Controller D
[24923.769510] usb 1-1: Manufacturer: Prolific Technology Inc. 
[24923.769520] [164] core:device_add:973: device: '1-1': device_add
[24923.769685] [164] bus:bus_add_device:502: bus: 'usb': add device 1-1
[24923.769761] [164] dd:driver_probe_device:211: bus: 'usb': driver_probe_device: matched device 1-1 with driver usb
[24923.769772] [164] dd:really_probe:114: bus: 'usb': really_probe: probing driver usb with device 1-1
[24923.769793] [164] usbcore:usb_probe_device:228: usb 1-1: usb_probe_device
[24923.769805] [164] usbcore:usb_choose_configuration:146: usb 1-1: configuration #1 chosen from 1 choice
[24923.769984] [164] usbcore:usb_set_configuration:1863: usb 1-1: adding 1-1:1.0 (config #1, interface 0)
[24923.769993] [164] core:device_add:973: device: '1-1:1.0': device_add
[24923.770019] [164] bus:bus_add_device:502: bus: 'usb': add device 1-1:1.0
[24923.770082] [164] dd:driver_probe_device:211: bus: 'usb': driver_probe_device: matched device 1-1:1.0 with driver usbserial_generic
[24923.770096] [164] dd:really_probe:114: bus: 'usb': really_probe: probing driver usbserial_generic with device 1-1:1.0
[24923.770119] [164] usbcore:usb_probe_interface:279: usbserial_generic 1-1:1.0: usb_probe_interface
[24923.770130] [164] usbcore:usb_probe_interface:297: usbserial_generic 1-1:1.0: usb_probe_interface - got id
[24923.770157] [164] dd:really_probe:152: usbserial_generic: probe of 1-1:1.0 rejects match -19
[24923.770181] [164] core:device_add:973: device: 'ep_81': device_add
[24923.770228] [164] core:device_add:973: device: 'ep_02': device_add
[24923.770258] [164] core:device_add:973: device: 'ep_83': device_add
[24923.770299] [164] dd:driver_bound:41: driver: '1-1': driver_bound: bound to device 'usb'
[24923.770306] [164] dd:really_probe:137: bus: 'usb': really_probe: bound device 1-1 to driver usb
[24923.770317] [164] core:device_add:973: device: 'ep_00': device_add
[24923.796744] [17709] bus:bus_add_driver:702: bus: 'usb-serial': add driver pl2303
[24923.796779] USB Serial support registered for pl2303
[24923.796787] [17709] bus:bus_add_driver:702: bus: 'usb': add driver pl2303
[24923.796814] [17709] dd:driver_probe_device:211: bus: 'usb': driver_probe_device: matched device 1-1:1.0 with driver pl2303
[24923.796820] [17709] dd:really_probe:114: bus: 'usb': really_probe: probing driver pl2303 with device 1-1:1.0
[24923.796831] [17709] usbcore:usb_probe_interface:279: pl2303 1-1:1.0: usb_probe_interface
[24923.796837] [17709] usbcore:usb_probe_interface:297: pl2303 1-1:1.0: usb_probe_interface - got id
[24923.796845] pl2303 1-1:1.0: pl2303 converter detected
[24923.797497] [17709] core:device_add:973: device: 'ttyUSB0': device_add
[24923.797518] [17709] bus:bus_add_device:502: bus: 'usb-serial': add device ttyUSB0
[24923.797573] [17709] dd:driver_probe_device:211: bus: 'usb-serial': driver_probe_device: matched device ttyUSB0 with driver pl2303
[24923.797582] [17709] dd:really_probe:114: bus: 'usb-serial': really_probe: probing driver pl2303 with device ttyUSB0
[24923.797601] [17709] core:device_add:973: device: 'ttyUSB0': device_add
[24923.797753] usb 1-1: pl2303 converter now attached to ttyUSB0
[24923.797760] [17709] dd:driver_bound:41: driver: 'ttyUSB0': driver_bound: bound to device 'pl2303'
[24923.797768] [17709] dd:really_probe:137: bus: 'usb-serial': really_probe: bound device ttyUSB0 to driver pl2303
[24923.797778] [17709] dd:driver_bound:41: driver: '1-1:1.0': driver_bound: bound to device 'pl2303'
[24923.797786] [17709] dd:really_probe:137: bus: 'usb': really_probe: bound device 1-1:1.0 to driver pl2303
[24923.797816] usbcore: registered new interface driver pl2303
[24923.797820] pl2303: Prolific PL2303 USB to serial adaptor driver
[24933.777560] [164] usbcore:hub_events:3592: hub 1-0:1.0: state 7 ports 4 chg 0000 evt 0002
[24933.777599] [164] usbcore:hub_port_connect_change:3330: hub 1-0:1.0: port 1, status 0100, change 0001, 12 Mb/s
[24933.777608] usb 1-1: USB disconnect, device number 26
[24933.777615] [164] usbcore:usb_disconnect:1745: usb 1-1: unregistering device
[24933.777622] [164] usbcore:usb_disable_device:1165: usb 1-1: unregistering interface 1-1:1.0
[24933.777631] [164] core:device_unregister:1208: device: 'ep_81': device_unregister
[24933.777696] [164] core:device_unregister:1208: device: 'ep_02': device_unregister
[24933.777723] [164] core:device_unregister:1208: device: 'ep_83': device_unregister
[24933.777771] [164] bus:bus_remove_device:586: bus: 'usb': remove device 1-1:1.0
[24933.777803] [164] bus:bus_remove_device:586: bus: 'usb-serial': remove device ttyUSB0
[24933.777829] [164] core:device_unregister:1208: device: 'ttyUSB0': device_unregister
[24933.778102] [164] core:device_create_release:1469: device: 'ttyUSB0': device_create_release
[24933.778108] pl2303 ttyUSB0: pl2303 converter now disconnected from ttyUSB0
[24933.778127] pl2303 1-1:1.0: device disconnected
[24933.778158] [164] usbcore:usb_disable_device:1183: usb 1-1: usb_disable_device nuking all URBs
[24933.778244] [164] core:device_unregister:1208: device: 'ep_00': device_unregister
[24933.778359] [164] bus:bus_remove_device:586: bus: 'usb': remove device 1-1
[24933.905540] [164] usbcore:hub_port_debounce:2899: hub 1-0:1.0: debounce: port 1: total 100ms stable 100ms status 0x100
[24935.902567] [17602] usbcore:hub_suspend:2799: hub 1-0:1.0: hub_suspend
[24935.902585] [17602] usbcore:hcd_bus_suspend:1977: usb usb1: bus auto-suspend, wakeup 1

從這個輸出信息來看就比較清楚了,哪一個模塊的那個函數的某一行執行的什麼功能,不須要搜索代碼就能夠看的一清二楚。

代碼執行流程和usb網卡的執行過程很相似,能夠參看《debian下使用dynamic printk分析usb網卡驅動》有更詳細的介紹。

 

還能夠將腳本中全部+flmpt替換成-flmpt號,就能去除上面全部文件中的動態調試信息。

相關文章
相關標籤/搜索