2013/05/29

Debugging ASL with jprobe


前幾篇文章有提到用 systemtap 來監視 ASL 呼叫的順序,但使用 systemtap 有幾個缺點:

  1. 要抓近 700 MB 的 debug symbols
  2. 要在裡頭加入自己的 c code 很麻煩

也因此小弟改用了 jprobe 來實作這個部分,並且加入了 ASL 整數參數的列印。以下是使用方式:

先抓 jprobe 程式,其中在 jprobes 資料匣中有個 acpica 資料匣,那是直接從 kernel source code drivers/acpi/acpica 中複製下來,我這裡是用 3.5.0-22,這裡可能會需要各位抓自己對應的 kernel 版本來用。

$ git clone https://github.com/fcwu/sys_prog.git
$ cd sys_prog/jprobes
$ make -C /lib/modules/`uname -r`/build M=`pwd`

插入模組,再清空 dmesg 訊息。

$ sudo insmod jprobe1.ko
$ sudo dmesg -c

最後按下會發出 Q event 的 hotkey,再執行 dmesg 就可以看到輸出結果如下:

[ 9113.652829] ASLP:_L13 >
[ 9113.652956] ASLP:_L13 <
[ 9113.652985] ASLP:_Q66 >
[ 9113.653043] ASLP:..NEVT >
[ 9113.653059] ASLP:....ECG1 >
[ 9113.653075] ASLP:......ECRW >
[ 9113.653081] ASLP:......  Op0: Integer 0000000000000007
[ 9113.653097] ASLP:........ECR2 >
[ 9113.653102] ASLP:........  Op0: Integer 0000000000000007
[ 9113.653115] ASLP:..........ECR1 >
[ 9113.653120] ASLP:..........  Op0: Integer 0000000000000007
[ 9113.653739] ASLP:..........ECR1 <
[ 9113.653773] ASLP:..........ECR1 >
[ 9113.653780] ASLP:..........  Op0: Integer 0000000000000008
[ 9113.654973] ASLP:..........ECR1 <
[ 9113.655005] ASLP:........ECR2 <
[ 9113.655016] ASLP:......ECRW <
[ 9113.655024] ASLP:....ECG1 <

ASL 真是愈來愈好追了。

2013/05/27

[vim] YouCompleteMe




最近因為密集的在 Ubuntu 上追 code,卻發現原本在 mac 的上可以用的 YouCompleteMe plugin,在 Ubuntu 卻因 vim 版本太舊不能用。於是小弟將 vim_7.3.923 放在了 PPA 上,若有剛好使用 vim 及 Ubuntu 的朋友們可以直接這樣安裝:

$ sudo add-apt-repository ppa:fcwu-tw/ppa
$ sudo apt-get update
$ sudo apt-get install vim

(只放了 12.04 and 13.04 這 2 個版本而已,13.10 已經是 7.4 不需更新) (放東西到 PPA 都要等個 20 小時才會幫我編,LP 真是杯具)

接著開始來安裝 YouCompleteMe,假設 vim plugins 是用 vundle 管理:

$ sudo apt-get install build-essential cmake python-dev
$ cd ~/.vim/bundle
$ git clone https://github.com/Valloric/YouCompleteMe
$ cd ~/.vim/bundle/YouCompleteMe
$ ./install.sh --clang-completer
$ # Then, add Bundle 'YouCompleteMe' to your .vimrc

最後,為什麼要用 YouCompleteMe 呢?請配上圖及以下解釋:

  • 不用按任何 tab 來啟用自動補齊
  • 它是使用 fuzzy 方式來當關鍵字,換句話說若是打 dir,可能出來的候選會有 dirxxx, xxxdir, xxxdirxxx,行為就像是其它 vim plugins Ctrl-T or FuzzyFinder
  • 它提供語意上的補齊(semantic completions),像在 python 裡打上 os. 它會幫你找出 os 這個 module 底下的所有 functions, modules 等

後記。在這次編 13.04 的 vim 時遇到 python configuration path 由原本 12.04 的 /usr/lib/python2.7/config 搬到 /usr/lib/python2.7/config-x86_64-linux/gnu,導致 vim configuration 有些地方要稍做修改...

2013/05/23

Linux Insert Module Error: Unknown symbol xxxxxxx


前幾天在幫 NAS 灌上 Virtualbox 時編譯 kernel module(DKMS) 時出錯,後來手動編譯,卻在 insmod 時 出現錯誤,dmesg 也出現下面這樣的錯誤訊息:

$ insmod vboxdrv/vboxdrv.ko
insmod: error inserting 'vboxdrv/vboxdrv.ko': -1 Invalid parameters
$ dmesg | tail
[84167.691738] vboxdrv: disagrees about version of symbol sched_setscheduler
[84167.698665] vboxdrv: Unknown symbol sched_setscheduler (err -22)
[84167.704799] vboxdrv: disagrees about version of symbol wake_up_process
[84167.711336] vboxdrv: Unknown symbol wake_up_process (err -22)
[84167.717174] vboxdrv: disagrees about version of symbol __free_pages
[84167.723506] vboxdrv: Unknown symbol __free_pages (err -22)

會出現這樣的錯誤,大概是因為我沒有原本 NAS 的 kernel source code and config,所以只能用 uname -r 找到一個差不多的版本,再參考其 header 編譯造成。但是該如何解這樣的問題呢?

首先確定每個 unknown symbol 的位址,以 sched_setscheduler 為例:

$ grep 'T sched_setscheduler$' /proc/kallsyms
ffffffff8105c250 T sched_setscheduler

接著準備 symbol address map,如下:

$ tee addrs.dat <%lt;EOF
SECTIONS
{
sched_setscheduler = 0xffffffff8105c250;
wake_up_process = 0xffffffff8105a400;
__free_pages = 0xffffffff81111de0;
}
EOF

這個格式應該很容易懂,大概就是 <unknown symbol> = <address> 這樣的格式。最後重新 link ko 用以下指令:

$ ld -r -o vboxdrv/vboxdrv-1.ko vboxdrv/vboxdrv.ko -R addrs.dat

打完收工。

2013/05/21

Debug ACPI in Ubuntu





做為一位 Ubuntu on x86 的軟體工程師,一定都會碰到 ACPI 相關問題(是嗎?),這次就來談談 ACPI 的除錯方法。本文的測試環境為 Ubuntu 12.04 kernel 3.5.0-22。


匯出 ACPI tables



除錯的第一步,可以先看看 ACPI tables 有沒有正確被寫進 100000h 以下的位置,方法百百種,推薦用

$ sudo fwts acpidump -
$ # acpidump 是另一個工具,如果需要對照 hex 輸出可選用它
$ # sudo acpidump > acpidump.dat

匯出的結果大概如這般

Dump ACPI tables.
----------------------------------------------------------------------------------------------------
Test 1 of 1: Dump ACPI tables.
RSDP @ f0490 (36 bytes)
---------------
[0x000 0000   8]                                Signature: RSD PTR
[0x008 0008   1]                                 Checksum: 0x51
[0x009 0009   6]                                   OEM ID: DELL
[0x00f 0015   1]                                 Revision: 0x02
[0x010 0016   4]                              RsdtAddress: 0xd6ff3028
[0x014 0020   4]                                   Length: 0x00000024
[0x018 0024   8]                              XsdtAddress: 0x00000000d6ff3080
[0x020 0032   1]                        Extended Checksum: 0x57
[0x021 0033   3]                                 Reserved: 0x00 [0]
[0x021 0033   3]                                 Reserved: 0x00 [1]
[0x021 0033   3]                                 Reserved: 0x00 [2]

通常比較有參考價值的是 FACP,像是 SMI command port, ACPI enable/disable value, PM block and GPE block 等等。相關資料也可在 ACPI spec 4.8 ACPI Register Model 裡找到。

另外,DSDT and SSDT(s) 這 2 類 table 由於放了 AML 紀錄,像是熱插拔,Q, L, E event 的實作,也常會需要拿來除錯,並且多半有問題的都是 DSDT。這些 tables 可以用下面方法匯出:

$ sudo cp /sys/firmware/acpi/tables/DSDT ./ && sudo chown doro DSDT
$ sudo cp /sys/firmware/acpi/tables/SSDT ./ && sudo chown doro SSDT*
$ # 若是剛才有用 acpidump,這裡可用
$ # acpixtract -sSSDT acpidump.dat
$ # acpixtract -sDSDT acpidump.dat

接著,再把那些 AML 反組譯成 ASL,如下:

$ iasl -d DSDT.dat SSDT*.dat

結果變存成 DSDT.dsl and SSDT*.dsl。得到 ASL 後,痛苦的除錯便開始了。


追蹤 ASL(DSDT)



一般來說,若只是要追 ACPI events 有沒有被呼叫,可以先用 acpi_listen 來做初步的確認,如下:

$ sudo acpi_listen
video LCD 00000087 00000000
video LCD 00000086 00000000

看來 LCD 亮度調整的 event 有送出,非常好。如是沒有只好再進入下一步:追 ASL。

目前小弟知道有 2 種可以追蹤 ASL 的方法,第一種是重編 kernel 把 CONFIG_ACPI_DEBUG 設成 y,如此便能用 /sys/module/acpi/parameters/debug_{layer,level} 來追流程。這種方法可以參考 ACPI Tricks and Tips 這份文件的方法。雖然這種方法確實不錯用,可惜小弟上次除錯遇到了極端的例子,問題一重編 kernel 就不見了,於是只好用第二種 systemtap 的方法。

首先,先安裝 kernel debug symbols

$ sudo tee /etc/apt/sources.list.d/ddebs.list << EOF
deb http://ddebs.ubuntu.com/ precise          main restricted universe multiverse
deb http://ddebs.ubuntu.com/ precise-security main restricted universe multiverse
deb http://ddebs.ubuntu.com/ precise-updates  main restricted universe multiverse
deb http://ddebs.ubuntu.com/ precise-proposed main restricted universe multiverse
EOF
$ sudo apt-key adv --keyserver keyserver.ubuntu.com --recv-keys ECDCAD72428D7C01
$ sudo apt-get update
$ sudo apt-get install linux-image-$(uname -r)-dbgsym

接著應該再 sudo apt-get install systemtap 即可,但小弟又遇到 Ubuntu 12.04 的 systemtap 版本太舊的問題,於是只好抓 12.10 的 package 來用,這裡會用到有:

  1. systemtap, http://packages.ubuntu.com/quantal/systemtap
  2. systemtap-common, http://packages.ubuntu.com/quantal/systemtap-common
  3. systemtap-runtime, http://packages.ubuntu.com/quantal/systemtap-runtime

這些抓下來後 sudo dpkg -i *.deb 即安裝成功。接下來請再下載 systemtap script aml.stp,最後我們便能用 sudo stap -g aml.stp 追蹤所有 ASL 的 operations,一開始除錯時通常會配合著 grep Evaluate and Call 先對整個 method 呼叫流程有初步認識,如下:

$ sudo stap -g aml.stp | ts | tee acpi_ok.log | grep '\(Evalua\|Call\)'
May 21 09:47:13 Evaluate _Q66():
May 21 09:47:13 Call NEVT():
May 21 09:47:13 Call ECG1():
May 21 09:47:13 Call ECRW():
May 21 09:47:13 Call ECR2():
May 21 09:47:13 Call ECR1():
May 21 09:47:13 Call ECR1():
May 21 09:47:13 Call ECGD():
May 21 09:47:13 Call ECRW():
May 21 09:47:13 Call ECR2():
May 21 09:47:13 Call ECR1():
May 21 09:47:13 Call ECR1():
May 21 09:47:13 Call EV4_():
May 21 09:47:13 Call WMNF():
May 21 09:47:13 Call SWEV():
May 21 09:47:13 Call SMIE():
May 21 09:47:13 Call GENS():
May 21 09:47:13 Call SMBI():
May 21 09:47:13 Call SNVC():
May 21 09:47:13 Evaluate _WED():

這是我在 NB 上面按下亮度的 hotkey,大概可以看到一開始 Q event 被發動,接著就很長很長一段不想看的... 我就說痛苦的除錯吧


覆蓋 DSDT



在經過一翻波折好不容易用找到 DSDT 的問題所在,接著便會想把解法在不修改 BIOS 情況下覆蓋上去,目前小弟得知有 2 種以上方法。一是改用 kernel 編譯參數,小弟很懶沒試,有興趣可參考 Debian Wiki,第二種比較推薦,因為只需加 grub 參數即可,但前提是 grub2 才有支援 (Ubuntu 在很早以前就是 grub2 了)。

假設你已經由 iasl 拿到 dsdt.dsl 了,並且在 dsdt.dsl 加入自己想要改的東西,再用 iasl 組譯 dsdt.dsl 成 dsdt.aml,接在把它複製到 /boot/ 下:

$ # make some modification you need
$ iasl -tc dsdt.dsl
$ # it may have warning and error, debug it by yourself
$ sudo cp dsdt.aml /boot/

最後修改 /boot/grub/grub.cfg 裡的 linux 開機參數,找到

linux   /boot/vmlinuz-3.5.0-22-generic root=UUID=026d718b-cb17-41af-a0b3-cb5fa97db936 ro   quiet splash 
initrd  /boot/initrd.img-3.5.0-22-generic

結尾加上 acpi /boot/dsdt.aml

linux   /boot/vmlinuz-3.5.0-22-generic root=UUID=026d718b-cb17-41af-a0b3-cb5fa97db936 ro   quiet splash
initrd  /boot/initrd.img-3.5.0-22-generic
acpi /boot/dsdt.aml

重開機後,再 dump 一次 dsdt 就會發現剛才加的 code 已經被塞進去了。


References



  1. Using systemtap to do runtime aml, http://smackerelofopinion.blogspot.tw/2011/06/using-systemtap-to-do-runtime-aml.html
  2. SystemTap print statements from "embedded C" functions, http://smackerelofopinion.blogspot.tw/2011/09/systemtap-print-statements-from.html

終於寫完了,我的 bug 還在痛苦的除錯中...

Update 2013/8/10


systemtap 2.2.1 for 12.04 已經 backport 到我的 PPA 裡 ppa:fcwu-tw/ppa

2013/05/02

Debug Linux Kernel Module: hid-multitouch



最近在看 Linux Kernel module: hid-multitouch 的問題,在這裡將相關用到的 debug 技巧紀錄下來。

(內容會有點零亂不全,畢竟相關資料小弟沒看幾天)


USB 裝置連線問題


舉凡 USB 插上後沒預期反應可先確認裝置是否有被 USB Hub 偵測到,可用 lsusb 或 dmesg 查看 log。如下
$ dmesg | tail
[ 1589.450251] usb 2-1.2: new full-speed USB device number 5 using ehci_hcd
[ 1589.547043] input: Logitech USB Receiver as /devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.2/2-1.2:1.0/input/input14
[ 1589.547234] generic-usb 0003:046D:C52E.0009: input,hidraw1: USB HID v1.11 Keyboard [Logitech USB Receiver] on usb-0000:00:1d.0-1.2/input0
[ 1589.549531] input: Logitech USB Receiver as /devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.2/2-1.2:1.1/input/input15
[ 1589.549852] generic-usb 0003:046D:C52E.000A: input,hiddev0,hidraw2: USB HID v1.11 Mouse [Logitech USB Receiver] on usb-0000:00:1d.0-1.2/input1

看起來有被偵測到。再用 lsusb 看一下 USB 列表,有時會再下 -vv 看一些 USB 的參數,像 USB 3.0 or 2.1(參數 bcdUSB)。
$ lsusb
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
Bus 002 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
Bus 001 Device 003: ID 0a5c:21d7 Broadcom Corp.
Bus 001 Device 006: ID 2149:2003
Bus 001 Device 005: ID 0c45:649c Microdia
Bus 002 Device 005: ID 046d:c52e Logitech, Inc.


USB 封包監聽


如果很不幸的,問題是發生在 driver/kernel 或更底層的問題,以及大大們有能力弄懂 USB protocol 的話,可以用 wireshark and usbmon 來監聽 USB traffic。安裝/打開 wireshark 之前,要先做一些前置動作

$ # 掛 usbmon
$ sudo modprobe usbmomn
$ # 掛 debugfs, 如果已掛上了就不用做
$ mount -t debugfs / /sys/kernel/debug

接著打開 wireshark,就會看到多了幾個可監聽的 USB hubs 可以選,如第一張圖。


driver 沒上(熱插拔)


請先自己想辦法找到對應的 driver,再手動 insmod 即可。要找的方法很多,而且因裝置而異,我這裡就不提了。

通常最常遇到的只是 driver 內沒包含裝置的 vendor and product ID,可以先用 sysfs 內的 new_id 來先做測試,如下
$ # 先把 driver 掛上
$ sudo modprobe hid-multitouch
$ # 接著用 lsusb 確認 vendor and product id
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
Bus 002 Device 002: ID 8087:0024 Intel Corp. Integrated Rate Matching Hub
Bus 001 Device 003: ID 0a5c:21d7 Broadcom Corp.
Bus 001 Device 006: ID 2149:2003
Bus 001 Device 005: ID 0c45:649c Microdia
Bus 002 Device 005: ID 046d:c52e Logitech, Inc.
$ # 看到了觸控裝置 2149:2003
$ echo 2149 2003 > /sys/module/hid_multitouch/drivers/hid\:hid-multitouch/new_id

到這裡這隻 driver 應該就起作用了。緊接著,若想以後能自動插入 driver 可修改 udev 的 rules,如下:
$ cat /etc/udev/rules.d/41-hid-multitouch.rules
SUBSYSTEM=="usb", ATTRS{idVendor}=="2149", ATTRS{idProduct}=="2003", RUN+="/bin/sh /etc/udev/load_hid_multitouch.sh $env{ID_VENDOR_ID} $env{ID_MODEL_ID}"


input event 監聽


若是 driver 掛上了,行為有點不如預期,可能是有些 input event 會自動消失或是不準的,可以用 evtest 來監看所有的 input event。

$ sudo evtest /dev/input/event11
Input driver version is 1.0.1
Input device ID: bus 0x3 vendor 0x2149 product 0x2003 version 0x110
Input device name: "Advanced Silicon S.A. CoolTouch(TM) System"
Supported events:
  Event type 0 (EV_SYN)
  Event type 1 (EV_KEY)
    Event code 330 (BTN_TOUCH)
  Event type 3 (EV_ABS)
    Event code 0 (ABS_X)
      Value   9104
      Min        0
      Max    32767
    Event code 1 (ABS_Y)
      Value  18364
      Min        0
      Max    32767
    Event code 47 (ABS_MT_SLOT)
      Value      0
      Min        0
      Max        9
    Event code 53 (ABS_MT_POSITION_X)
      Value      0
      Min        0
      Max    32767
    Event code 54 (ABS_MT_POSITION_Y)
      Value      0
      Min        0
      Max    32767
    Event code 57 (ABS_MT_TRACKING_ID)
      Value      0
      Min        0
      Max    65535
Testing ... (interrupt to exit)
Event: time 1367477844.348301, type 3 (EV_ABS), code 57 (ABS_MT_TRACKING_ID), value 50
Event: time 1367477844.348303, type 3 (EV_ABS), code 53 (ABS_MT_POSITION_X), value 9655
Event: time 1367477844.348303, type 3 (EV_ABS), code 54 (ABS_MT_POSITION_Y), value 10190
Event: time 1367477844.348313, type 1 (EV_KEY), code 330 (BTN_TOUCH), value 1
Event: time 1367477844.348315, type 3 (EV_ABS), code 0 (ABS_X), value 9655
Event: time 1367477844.348315, type 3 (EV_ABS), code 1 (ABS_Y), value 10190
Event: time 1367477844.348316, -------------- SYN_REPORT ------------
Event: time 1367477844.493292, type 3 (EV_ABS), code 57 (ABS_MT_TRACKING_ID), value -1
Event: time 1367477844.493301, type 1 (EV_KEY), code 330 (BTN_TOUCH), value 0
Event: time 1367477844.493302, -------------- SYN_REPORT ------------

最後的問題有可能是出現在 driver or application,這就看自己的造化了。小弟我遇到的問題是都有,還好 upstream 都解了。最後提一下,在看 driver 前除了有基本的知識外,舉例來說在解 USB HID multitouch driver 時,最好可以從 USB protocol 到 hid-multitouch 都有基本的了解,USB protocol 網上資料一堆,hid-multitouch 則看 kernel 裡的 Documentation/input/multi-touch-protocol.txt 即可。

(唉,解 bug 花的時間沒寫文章的多)

Reference