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=0control 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

 

原文地址:https://www.cnblogs.com/heyp/p/3421800.html