首页 > 代码库 > debian下使用dynamic printk分析usb转串口驱动执行流程

debian下使用dynamic printk分析usb转串口驱动执行流程

看了一篇文章《debug by printing》,文中提到了多种通过printk来调试驱动的方法,其中最有用的就是"Dynamic debugging"。

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

"Dyanmic debugging"的功能适用于所有的linux内核,所以也可以用于嵌入式开发板中调试驱动程序。

 

在使用"Dynamic debugging"前需要在内核中使能Dynamic printk选项(可用于控制代码代码中的pr_debug和dev_dbg的信息是否输出)。

默认官方debian内核中没有使能这个选项,可以参考我的博文《debian下配置dynamic printk以及重新编译内核 》重新编译和配置内核才能使用该功能。

 

本文用一个usb转串口线(核心芯片是pl2303)的例子来说明如何使用"Dynamic debugging",内核版本是linux-3.2.57。

 

先插入usb转串口线,得到下面的信息:

[    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驱动信息:

$ sudo modinfo pl2303filename:       /lib/modules/3.2.57/kernel/drivers/usb/serial/pl2303.kolicense:        GPLdescription:    Prolific PL2303 USB to serial adaptor driveralias:          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,usbcoreintree:         Yvermagic:       3.2.57 SMP mod_unload modversions 686 parm:           debug:Debug enabled or not (bool)

可以看到pl2303又依赖于usbserial和usbcore.

 

下载linux内核源码(可以参考我的博文《debian下配置dynamic printk以及重新编译内核》),解压缩后进入该文件夹。

$ grep pl2303 drivers/usb/serial/Makefileobj-$(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/coredrivers/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/basedrivers/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/usbdrivers/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/usbdrivers/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/usbdrivers/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 

再插入和移除usb转串口线,可以得到下面的信息:

[18177.932295] hub 1-0:1.0: state 7 ports 8 chg 0000 evt 0100[18177.932311] hub 1-0:1.0: port 8, status 0501, change 0001, 480 Mb/s[18178.060035] hub 1-0:1.0: debounce: port 8: total 100ms stable 100ms status 0x501[18178.116224] hub 1-0:1.0: port 8 not reset yet, waiting 50ms[18178.116237] usb usb5: usb wakeup-resume[18178.116242] usb usb5: usb auto-resume[18178.156009] hub 5-0:1.0: hub_resume[18178.156023] hub 5-0:1.0: port 2: status 0101 change 0001[18178.172085] hub 1-0:1.0: state 7 ports 8 chg 0000 evt 0100[18178.260062] hub 5-0:1.0: state 7 ports 2 chg 0004 evt 0000[18178.260079] hub 5-0:1.0: port 2, status 0101, change 0000, 12 Mb/s[18178.372037] usb 5-2: new full-speed USB device number 11 using uhci_hcd[18178.525033] usb 5-2: default language 0x0409[18178.535037] usb 5-2: udev 11, busnum 5, minor = 522[18178.535041] usb 5-2: New USB device found, idVendor=067b, idProduct=2303[18178.535043] usb 5-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0[18178.535045] usb 5-2: Product: USB-Serial Controller[18178.535047] usb 5-2: Manufacturer: Prolific Technology Inc.[18178.535130] bus: usb: add device 5-2[18178.535182] usb 5-2: usb_probe_device[18178.535186] usb 5-2: configuration #1 chosen from 1 choice[18178.538030] usb 5-2: adding 5-2:1.0 (config #1, interface 0)[18178.538042] bus: usb: add device 5-2:1.0[18178.538071] usbserial_generic 5-2:1.0: usb_probe_interface[18178.538074] usbserial_generic 5-2:1.0: usb_probe_interface - got id[18178.538085] pl2303 5-2:1.0: usb_probe_interface[18178.538088] pl2303 5-2:1.0: usb_probe_interface - got id[18178.538092] pl2303 5-2:1.0: pl2303 converter detected[18178.550035] bus: usb-serial: add device ttyUSB0[18178.550140] usb 5-2: pl2303 converter now attached to ttyUSB0[18383.168069] hub 5-0:1.0: state 7 ports 2 chg 0000 evt 0004[18383.168095] hub 5-0:1.0: port 2, status 0100, change 0003, 12 Mb/s[18383.168101] usb 5-2: USB disconnect, device number 11[18383.168105] usb 5-2: unregistering device[18383.168109] usb 5-2: unregistering interface 5-2:1.0[18383.168209] bus: usb: remove device 5-2:1.0[18383.168238] bus: usb-serial: remove device ttyUSB0[18383.168351] pl2303 ttyUSB0: pl2303 converter now disconnected from ttyUSB0[18383.168374] pl2303 5-2:1.0: device disconnected[18383.168402] usb 5-2: usb_disable_device nuking all URBs[18383.168746] bus: usb: remove device 5-2[18383.296029] hub 5-0:1.0: debounce: port 2: total 100ms stable 100ms status 0x100[18386.008044] hub 5-0:1.0: hub_suspend[18386.008058] usb usb5: bus auto-suspend, wakeup 1

18177和18178开头部分是插入usb转串口时产生的信息。

而18383和18386开头部分是移除usb转串口时产生的信息。

 

仔细看了一下输出信息,似乎和之前的输出信息并没有什么差别,也不再仔细分析了,感兴趣的话可以自己分析看看。