libusb阻塞

这两天发现手头一个usb指纹头出现了一点状况，若libusb以同步方式发送bulk transfer出现阻塞。经过测试发现跟timeout有些关系：若timeout为0（无timeout），不会阻塞；若timeout为1000或者2000，则会。另外，若采用异步方式传送bulk transfer，则不会阻塞。

 

同步方式

libusb_bulk_transfer(devh, ep_bulk, buf, CAM_BUF_SZ, &len, timeout);

进入libusb研究，发现libusb是采用异步方式来实现的。在do_sync_bulk_transfer中：

 

 

staticint do_sync_bulk_transfer(struct libusb_device_handle *dev_handle,

unsignedchar endpoint,unsignedchar*buffer,int length,

int*transferred,unsignedint timeout,unsignedchar type)

{

libusb_fill_bulk_transfer(transfer, dev_handle, endpoint, buffer, length,

bulk_transfer_cb,&completed, timeout);

transfer->type = type;

 

r = libusb_submit_transfer(transfer);

if(r <0){

libusb_free_transfer(transfer);

return r;

}

 

while(!completed){

r = libusb_handle_events(HANDLE_CTX(dev_handle));

}

}

这里libusb_fill_bulk_transfer来填充bulk transfer，然后libusb_submit_transfer提交bulk transfer，最后用libusb_handle_events来等待完成。当收到回应后，bulk_transfer_cb回调设置completed，从而阻塞被接触，函数返回。

 

分段处理bulk transfer

libusb_submit_transfer最终调到了submit_bulk_transfer。该函数会检查buffer大小，如果大于MAX_BULK_BUFFER_LENGTH（16K），则分成若干16K大小的urb，每个urb指向用户buffer的适当位置，然后用ioctl(IOCTL_USBFS_SUBMITURB)提交每个urb。

 

收到数据时会判断是否收齐所有urb。在handle_bulk_completion中，若urb_idx为最后一个urb，则认为收齐了所有的urb。最终会调用usbi_handle_transfer_completion来调用urb callback。

 

timeout处理

若libusb_bulk_transfer传入的timeout为0，则没有timeout，libusb会一直等待数据。在libusb_handle_events中设置了一个2s的poll timeout，libusb会在while中一直poll，每次poll的timeout为2s。

 

若设置了timeout，libusb_submit_transfer会按照timeout升序将transfer插入到libusb_context的flying_transfers列表中，然后提交transfer（当然会分段了，如上所述）

 

libusb_handle_events会根据自己设置的2s timeout和flying_transfers中的timeout得出实际timeout，然后用poll查询usb fd。

 

问题根源

libusb阻塞的原因就是超时。有时usb指纹头返回数据较慢，在指定的timeout时间内没有完成所有urb请求，进入超时处理。handle_timeout()会cancel掉为完成的urb（IOCTL_USBFS_DISCARDURB）。在do_sync_bulk_transfer中，由于未完成所有urb，bulk_transfer_cb没有被调用，从而会阻塞。libusb_handle_events会继续以2s超时来查询fd，但由于urb已经取消，设备会返回-2（ENOENT）。

 

按道理讲，即使超时，libusb也应该在超时后返回。libusb为什么没有返回呢？handle_bulk_completion函数中，若读到ENOENT，awaiting_discard会递减至0。与awaiting_discard一起的还有awaiting_reap，若二者均为0，也会调用bulk_transfer_cb通知用户。

 

awaiting_discard在超时时cancel urb时被设置。若ioctl(IOCTL_USBFS_DISCARDURB)返回EINVAL，则awaiting_reap会递增。

 

经过打印验证，发现在cancel urb时，对于已经完成的urb，会返回EINVAL。而未完成的urb，则返回0。我想这大概是一个bug，正确做法应该是不要取消已经完成的urb。

 

附：

阻塞时libusb打印

found usbfs at /dev/bus/usb
found usb devices in sysfs
add fd 9 events 1
created default context

scan usb1
sysfs descriptors available
bus=1 dev=1
busnum 1 devaddr 1 session_id 257
allocating new device for1/1(session 257)
scan 1-1
bus=1 dev=2
busnum 1 devaddr 2 session_id 258
allocating new device for1/2(session 258)
scan 1-1.1
bus=1 dev=3
busnum 1 devaddr 3 session_id 259
allocating new device for1/3(session 259)



open 1.3
add fd 11 events 4
destroy device 1.1
destroy device 1.2
configuration 1
interface0
next timeout in2.499878s
poll()2 fds with timeout in2000ms
poll() returned 1
urb type=2 status=0 transferred=0
handling completion status 0
actual_length=0（control transfer的回调）
next timeout in2.499909s
poll()2 fds with timeout in2000ms
poll() returned 1
urb type=2 status=0 transferred=0
handling completion status 0
actual_length=0（另一个control transfer的回调）
need 10 urbs fornew transfer with length 153600
next timeout in0.997836s（从这里开始查询bulk）
poll()2 fds with timeout in998ms
poll() returned 1
urb type=3 status=0 transferred=16384
handling completion status 0 of bulk urb 1/10
next timeout in0.379086s
poll()2 fds with timeout in380ms
poll() returned 1
urb type=3 status=0 transferred=16384
handling completion status 0 of bulk urb 2/10
next timeout in0.253080s
poll()2 fds with timeout in254ms
poll() returned 0

all URBs have already been processed for timeouts （超时）
poll()2 fds with timeout in2000ms
poll() returned 1
urb type=3 status=-2 transferred=9728
handling completion status -2 of bulk urb 3/10
CANCEL: detected a cancelled URB
all URBs have already been processed for timeouts
poll()2 fds with timeout in2000ms
poll() returned 1
urb type=3 status=-2 transferred=0
handling completion status -2 of bulk urb 4/10
CANCEL: detected a cancelled URB
all URBs have already been processed for timeouts
poll()2 fds with timeout in2000ms
poll() returned 1
urb type=3 status=-2 transferred=0
handling completion status -2 of bulk urb 5/10
CANCEL: detected a cancelled URB
all URBs have already been processed for timeouts
poll()2 fds with timeout in2000ms
poll() returned 1
urb type=3 status=-2 transferred=0
handling completion status -2 of bulk urb 6/10
CANCEL: detected a cancelled URB
all URBs have already been processed for timeouts
poll()2 fds with timeout in2000ms
poll() returned 1
urb type=3 status=-2 transferred=0
handling completion status -2 of bulk urb 7/10
CANCEL: detected a cancelled URB
all URBs have already been processed for timeouts
poll()2 fds with timeout in2000ms
poll() returned 1
urb type=3 status=-2 transferred=0
handling completion status -2 of bulk urb 8/10
CANCEL: detected a cancelled URB
all URBs have already been processed for timeouts
poll()2 fds with timeout in2000ms
poll() returned 1
urb type=3 status=-2 transferred=0
handling completion status -2 of bulk urb 9/10
CANCEL: detected a cancelled URB
all URBs have already been processed for timeouts
poll()2 fds with timeout in2000ms
poll() returned 1
urb type=3 status=-2 transferred=0
handling completion status -2 of bulk urb 10/10
CANCEL: detected a cancelled URB
all URBs have already been processed for timeouts
poll()2 fds with timeout in2000ms
poll() returned 0
all URBs have already been processed for timeouts
poll()2 fds with timeout in2000ms
poll() returned 0
all URBs have already been processed for timeouts
poll()2 fds with timeout in2000ms
poll() returned 0
all URBs have already been processed for timeouts
poll()2 fds with timeout in2000ms
poll() returned 0
all URBs have already been processed for timeouts
poll()2 fds with timeout in2000ms
poll() returned 0
all URBs have already been processed for timeouts
poll()2 fds with timeout in2000ms
poll() returned 0
all URBs have already been processed for timeouts
poll()2 fds with timeout in2000ms
poll() returned 0
all URBs have already been processed for timeouts
poll()2 fds with timeout in2000ms
^C

kernel usbmon的打印：

e8c3a240 1032172219 S Co:1:003:0 s 00090001000000000
e8c3a240 1032173347 C Co:1:003:000
e8c3a240 1032174262 S Co:1:003:0 s 40 e0 0000000000000
e8c3a240 1032174597 C Co:1:003:000
e8c3a240 1032175054 S Co:1:003:0 s 02010000008100000
e8c3a240 1032249749 C Co:1:003:000
e8c3a240 1032250298 S Co:1:003:0 s 40 e5 0000000000000
e8c3a240 1032250634 C Co:1:003:000
e8c3a240 1032251121 S Bi:1:003:1-11516384<
e8c3a440 1032251365 S Bi:1:003:1-11516384<
e8c3a1c0 1032252890 S Bi:1:003:1-11516384<
e8c3a2c0 1032254018 S Bi:1:003:1-11516384<
e8c3a740 1032254475 S Bi:1:003:1-11516384<
e8c3a7c0 1032254871 S Bi:1:003:1-11516384<
e8c3a5c0 1032255268 S Bi:1:003:1-11516384<
e8c3a0c0 1032255695 S Bi:1:003:1-11516384<
e8c3a640 1032256091 S Bi:1:003:1-11516384<
e849ce20 1032256518 S Bi:1:003:1-1156144<
e8c3a240 1032561640 C Bi:1:003:1016384=40e5000000000000 a59fa89e b3a3a09c a899989b 8b8a9ba09f9392a0929f8498
e8c3a440 1033162310 C Bi:1:003:1016384=909e8a928d99898d908f94909ba197a18ba5a69d9396959d948d9e9e968c9584
e8c3a1c0 1033653347 C Bi:1:003:1016384= d1d9d0d8 d3cdd2d7 d1d8c5d6 c5cfd1d3 d0ccd0d4 d0cbd1d1 bed2d2d0 d9dad4d9
e8c3a2c0 1034152250 C Bi:1:003:1016384= a79fa0aa ada2bab2 b6b3a5ad aeae9bb0 b2aa9eaa 9396a8a6 afa5af95 9daaa5ba
e8c3a740 1034753624 C Bi:1:003:1-216320= d6d0d5d2 ccd4c7cc cdd6cfc9 d3d2d2ce cfcfd5c8 d0c4cdc7 cdc9c6ca d4d0cec2
e8c3a2c0 1034753776 S Co:1:002:0 s 23089031000100000
e8c3a2c0 1034754111 C Co:1:002:000
e8c3a7c0 1034755026 C Bi:1:003:1-264= a3a9bda3 a5a4a9a5 93a69e98949d9294 aa9d8d9d 9b91a6a4 a793a097 9b8f8f96
e8c3a2c0 1034755117 S Co:1:002:0 s 23089031000100000
e8c3a2c0 1034755483 C Co:1:002:000
e8c3a5c0 1034756215 C Bi:1:003:1-264= d1c7d2d5 dad6d6db ded1d0da d8d2d4da d3d8d8d6 dbd4dedd d2d5ded5 dbd6d7d8
e8c3a2c0 1034756459 S Co:1:002:0 s 23089031000100000
e8c3a2c0 1034756855 C Co:1:002:000
e8c3a0c0 1034757587 C Bi:1:003:1-264= b04a5e59 637c82707f8483787f7e7881838f8497988a8389938c8f928b8ca28c
e8c3a2c0 1034757648 S Co:1:002:0 s 23089031000100000
e8c3a2c0 1034757983 C Co:1:002:000
e8c3a640 1034758715 C Bi:1:003:1-20
e8c3a2c0 1034758776 S Co:1:002:0 s 23089031000100000
e8c3a2c0 1034759111 C Co:1:002:000
e849ce20 1034759569 C Bi:1:003:1-20
e8c3a2c0 1034759630 S Co:1:002:0 s 23089031000100000
e8c3a2c0 1034759995 C Co:1:002:000