Hello,
i have a problem with the VirtualHere client. I am using the x64 console version on Ubuntu 14.10 server. My server is a RaspberryPi.
When i connect a USB device on the raspberry, i get these log entries on my Ubuntu server (virtualhere client):
[ 21.293947] usbip_core: USB/IP Core v1.0.0
[ 21.306922] vhci_hcd vhci_hcd: USB/IP Virtual Host Controller
[ 21.306933] vhci_hcd vhci_hcd: new USB bus registered, assigned bus number 3
[ 21.320112] usb usb3: New USB device found, idVendor=1d6b, idProduct=0002
[ 21.320112] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 21.320112] usb usb3: Product: USB/IP Virtual Host Controller
[ 21.320112] usb usb3: Manufacturer: Linux 3.16.0-34-generic vhci_hcd
[ 21.320112] usb usb3: SerialNumber: vhci_hcd
[ 21.320907] hub 3-0:1.0: USB hub found
[ 21.320923] hub 3-0:1.0: 8 ports detected
[ 21.321205] vhci_hcd: USB/IP 'Virtual' Host Controller (VHCI) Driver v1.0.0
[ 21.762454] vhci_hcd vhci_hcd: rhport(0) sockfd(15) devid(4) speed(2) speed_str(full-speed)
[ 21.976181] usb 3-1: new full-speed USB device number 2 using vhci_hcd
[ 22.088106] usb 3-1: SetAddress Request (2) to port 0
[ 22.128720] usb 3-1: New USB device found, idVendor=1b1f, idProduct=c00f
[ 22.128729] usb 3-1: New USB device strings: Mfr=4, Product=14, SerialNumber=36
[ 22.128733] usb 3-1: Product: HM-CFG-USB
[ 22.128736] usb 3-1: Manufacturer: eQ-3
[ 22.128739] usb 3-1: SerialNumber: LEQ0659519
[ 22.153503] hid-generic 0003:1B1F:C00F.0002: hiddev0,hidraw1: USB HID v1.10 Device [eQ-3 HM-CFG-USB] on usb-vhci_hcd-1/input0
[ 22.175126] init: plymouth-upstart-bridge main process ended, respawning
[ 29.511392] systemd-logind[1276]: New seat seat0.
[ 29.516932] systemd-logind[1276]: Watching system buttons on /dev/input/event0 (Power Button)
[ 29.517185] systemd-logind[1276]: Watching system buttons on /dev/input/event1 (Sleep Button)
[ 29.547611] systemd-logind[1276]: Failed to start unit user [at] 1000.service: Unknown unit: user [at] 1000.service
[ 29.548007] systemd-logind[1276]: Failed to start user service: Unknown unit: user [at] 1000.service
[ 29.572227] systemd-logind[1276]: New session 1 of user openhab.
[ 47.886308] vhci_hcd: dequeue a urb ffff88003bffd780
[ 47.886319] vhci_hcd: device ffff88003ae96290 seems to be still connected
[ 47.888920] vhci_hcd: unlink->seqnum 58
[ 47.888925] vhci_hcd: cannot find the pending unlink 0
[ 57.937031] vhci_hcd: dequeue a urb ffff88003b4ad840
[ 57.937047] vhci_hcd: device ffff88003ae96290 seems to be still connected
[ 57.942008] vhci_hcd: unlink->seqnum 58
[ 57.942025] vhci_hcd: unlink->seqnum 72
[ 57.942036] vhci_hcd: cannot find the pending unlink 0
[ 67.989349] vhci_hcd: dequeue a urb ffff8800365fac00
[ 67.989359] vhci_hcd: device ffff88003ae96290 seems to be still connected
[ 67.991741] vhci_hcd: unlink->seqnum 58
[ 67.991747] vhci_hcd: unlink->seqnum 72
[ 67.991749] vhci_hcd: unlink->seqnum 86
[ 67.991751] vhci_hcd: cannot find the pending unlink 0
[ 78.037664] vhci_hcd: dequeue a urb ffff88003b7ae240
[ 78.037674] vhci_hcd: device ffff88003ae96290 seems to be still connected
[ 78.039926] vhci_hcd: unlink->seqnum 58
[ 78.039930] vhci_hcd: unlink->seqnum 72
[ 78.039932] vhci_hcd: unlink->seqnum 86
[ 78.039934] vhci_hcd: unlink->seqnum 100
[ 78.039936] vhci_hcd: cannot find the pending unlink 0
[ 88.087926] vhci_hcd: dequeue a urb ffff88000007f180
[ 88.087942] vhci_hcd: device ffff88003ae96290 seems to be still connected
[ 88.091408] vhci_hcd: unlink->seqnum 58
[ 88.091416] vhci_hcd: unlink->seqnum 72
[ 88.091420] vhci_hcd: unlink->seqnum 86
[ 88.091423] vhci_hcd: unlink->seqnum 100
[ 88.091426] vhci_hcd: unlink->seqnum 114
[ 88.091429] vhci_hcd: cannot find the pending unlink 0
[ 98.139228] vhci_hcd: dequeue a urb ffff88003b686780
[ 98.139239] vhci_hcd: device ffff88003ae96290 seems to be still connected
[ 98.142717] vhci_hcd: unlink->seqnum 58
[ 98.142721] vhci_hcd: unlink->seqnum 72
[ 98.142723] vhci_hcd: unlink->seqnum 86
[ 98.142724] vhci_hcd: unlink->seqnum 100
[ 98.142726] vhci_hcd: unlink->seqnum 114
[ 98.142728] vhci_hcd: unlink->seqnum 128
[ 98.142729] vhci_hcd: cannot find the pending unlink 0
[ 108.188771] vhci_hcd: dequeue a urb ffff88003b686780
[ 108.188781] vhci_hcd: device ffff88003ae96290 seems to be still connected
[ 108.191031] vhci_hcd: unlink->seqnum 58
[ 108.191037] vhci_hcd: unlink->seqnum 72
[ 108.191040] vhci_hcd: unlink->seqnum 86
[ 108.191118] vhci_hcd: unlink->seqnum 100
[ 108.191120] vhci_hcd: unlink->seqnum 114
[ 108.191121] vhci_hcd: unlink->seqnum 128
[ 108.191123] vhci_hcd: unlink->seqnum 142
[ 108.191125] vhci_hcd: cannot find the pending unlink 0
the last part continues until my hard drive is full.
After a day or so the virtualhere client crashes.
Can someone help me with my problem ?
Thanks in advance.
Greetings Adrian
Seems the linux kernel
Seems the linux kernel maintainers used pr_info instead of pr_debug in the kernel module code, so you will need to redirect these messages from rsyslog to nothing.
Edit the /etc/rsyslog.d/50-defaults.conf
and add in a filter like the example here http://serverfault.com/questions/15106/is-there-a-way-to-filter-syslog-…
and use the string "vhci_hcd" instead
It seems to fix my problem.
It seems to fix my problem. Thank you.
But when I run vhclientx86_64 -t="LIST" I get this message:
IPC client timeout waiting for server...
The VirtualHere IPC server on this machine could not be contacted
but my USB device is still connected and working. Do you know what is wrong?
Greetings Adrian
Are you running it like this:
Are you running it like this:
sudo ./vhclientx86_64 -nto run it in the background then:
./vhclientx86_64 -t LISTetc. to get a list?
I start the client via the
I start the client via the init-script which is linked at the download page.
When I start the client the -t command works, but agter a day or so I can't connect to the client anymore. And as I said the USB devices are still connected and working.
OK i found the bug, could you
OK i found the bug, could you try this build and let me know if its ok and it still works after a day or so
http://www.virtualhere.com/adi961/vhclientx86_64
thank you, it is working. I
thank you, it is working. I will let you know if it is still working in a few days.
that didn't helped out. I
that didn't helped out. I still can't connect to the client after some time I still get this message:
openhab@openHAB:~$ vhclientx86_64 -t "LIST"
IPC client timeout waiting for server...
The VirtualHere IPC server on this machine could not be contacted.
Additionally I get these log entries:
[431800.569174] vhci_hcd: the urb (seqnum 588499) was already given back
[431800.569176] vhci_hcd: unlink cleanup rx 588526
[431800.569177] vhci_hcd: the urb (seqnum 588526) was already given back
[431800.569179] vhci_hcd: unlink cleanup rx 588540
[431800.569181] vhci_hcd: the urb (seqnum 588540) was already given back
[431800.569182] vhci_hcd: unlink cleanup rx 588554
[431800.569184] vhci_hcd: the urb (seqnum 588554) was already given back
[431800.569186] vhci_hcd: unlink cleanup rx 588568
[431800.569187] vhci_hcd: the urb (seqnum 588568) was already given back
[431800.569189] vhci_hcd: unlink cleanup rx 588582
[431800.569190] vhci_hcd: the urb (seqnum 588582) was already given back
[431800.569192] vhci_hcd: unlink cleanup rx 588596
[431800.569194] vhci_hcd: the urb (seqnum 588596) was already given back
[431800.569195] vhci_hcd: unlink cleanup rx 588610
[431800.569197] vhci_hcd: the urb (seqnum 588610) was already given back
[431800.569198] vhci_hcd: unlink cleanup rx 588624
[431800.569200] vhci_hcd: the urb (seqnum 588624) was already given back
[431800.569202] vhci_hcd: unlink cleanup rx 588638
[431800.569203] vhci_hcd: the urb (seqnum 588638) was already given back
[431800.569205] vhci_hcd: unlink cleanup rx 588652
[431800.569207] vhci_hcd: the urb (seqnum 588652) was already given back
[431800.569220] vhci_hcd: disconnect device
[431800.569744] usb 3-1: USB disconnect, device number 3
[431800.569859] vhci_hcd: dequeue a urb ffff88003c603a80
[431800.569862] vhci_hcd: device ffff88003ae96290 seems to be disconnected
[431800.569865] vhci_hcd: gives back urb ffff88003c603a80
[431809.356259] vhci_hcd vhci_hcd: rhport(0) sockfd(13) devid(4) speed(2) speed_str(full-speed)
[431809.574286] usb 3-1: new full-speed USB device number 4 using vhci_hcd
[431809.689845] usb 3-1: SetAddress Request (4) to port 0
[431809.731166] usb 3-1: New USB device found, idVendor=1b1f, idProduct=c00f
[431809.731179] usb 3-1: New USB device strings: Mfr=4, Product=14, SerialNumber=36
[431809.731187] usb 3-1: Product: HM-CFG-USB
[431809.731193] usb 3-1: Manufacturer: eQ-3
[431809.731198] usb 3-1: SerialNumber: LEQ0659519
[431809.760809] hid-generic 0003:1B1F:C00F.0004: hiddev0,hidraw1: USB HID v1.10 Device [eQ-3 HM-CFG-USB] on usb-vhci_hcd-1/input0
[431837.039867] vhci_hcd: dequeue a urb ffff8800365a8600
[431837.040696] vhci_hcd: device ffff88003ae96290 seems to be still connected
[431837.044306] vhci_hcd: unlink->seqnum 588730
[431837.044316] vhci_hcd: cannot find the pending unlink 0
[431857.715889] vhci_hcd: dequeue a urb ffff88003b99bc00
[431857.715931] vhci_hcd: device ffff88003ae96290 seems to be still connected
[431857.718370] vhci_hcd: unlink->seqnum 588730
[431857.718420] vhci_hcd: unlink->seqnum 588757
[431857.718562] vhci_hcd: cannot find the pending unlink 0
[431867.767116] vhci_hcd: dequeue a urb ffff88003b99bc00
[431867.767132] vhci_hcd: device ffff88003ae96290 seems to be still connected
[431867.778208] vhci_hcd: unlink->seqnum 588730
[431867.778213] vhci_hcd: unlink->seqnum 588757
[431867.778215] vhci_hcd: unlink->seqnum 588771
[431867.778217] vhci_hcd: cannot find the pending unlink 0
[431877.816318] vhci_hcd: dequeue a urb ffff88003b99bc00
[431877.816361] vhci_hcd: device ffff88003ae96290 seems to be still connected
[431877.819511] vhci_hcd: unlink->seqnum 588730
[431877.819520] vhci_hcd: unlink->seqnum 588757
[431877.819524] vhci_hcd: unlink->seqnum 588771
[431877.819527] vhci_hcd: unlink->seqnum 588785
[431877.819531] vhci_hcd: cannot find the pending unlink 0
[431887.867817] vhci_hcd: dequeue a urb ffff88003b99bc00
[431887.867833] vhci_hcd: device ffff88003ae96290 seems to be still connected
[431887.870895] vhci_hcd: unlink->seqnum 588730
[431887.870905] vhci_hcd: unlink->seqnum 588757
[431887.870909] vhci_hcd: unlink->seqnum 588771
[431887.870912] vhci_hcd: unlink->seqnum 588785
[431887.870915] vhci_hcd: unlink->seqnum 588799
[431887.870918] vhci_hcd: cannot find the pending unlink 0
[431897.917846] vhci_hcd: dequeue a urb ffff88003b0c4a80
[431897.917888] vhci_hcd: device ffff88003ae96290 seems to be still connected
[431897.921101] vhci_hcd: unlink->seqnum 588730
[431897.921108] vhci_hcd: unlink->seqnum 588757
[431897.921112] vhci_hcd: unlink->seqnum 588771
[431897.921115] vhci_hcd: unlink->seqnum 588785
[431897.921118] vhci_hcd: unlink->seqnum 588799
[431897.921121] vhci_hcd: unlink->seqnum 588813
[431897.921124] vhci_hcd: cannot find the pending unlink 0
[431907.968536] vhci_hcd: dequeue a urb ffff88003a1d1f00
[431907.968577] vhci_hcd: device ffff88003ae96290 seems to be still connected
[431907.971897] vhci_hcd: unlink->seqnum 588730
[431907.971906] vhci_hcd: unlink->seqnum 588757
[431907.971910] vhci_hcd: unlink->seqnum 588771
[431907.971913] vhci_hcd: unlink->seqnum 588785
[431907.971916] vhci_hcd: unlink->seqnum 588799
[431907.971919] vhci_hcd: unlink->seqnum 588813
[431907.971922] vhci_hcd: unlink->seqnum 588827
[431907.971925] vhci_hcd: cannot find the pending unlink 0
[431918.028521] vhci_hcd: dequeue a urb ffff8800365a83c0
[431918.028567] vhci_hcd: device ffff88003ae96290 seems to be still connected
[431918.031717] vhci_hcd: unlink->seqnum 588730
[431918.031726] vhci_hcd: unlink->seqnum 588757
[431918.031730] vhci_hcd: unlink->seqnum 588771
[431918.031734] vhci_hcd: unlink->seqnum 588785
[431918.031737] vhci_hcd: unlink->seqnum 588799
[431918.031739] vhci_hcd: unlink->seqnum 588813
[431918.031742] vhci_hcd: unlink->seqnum 588827
[431918.031745] vhci_hcd: unlink->seqnum 588841
[431918.031748] vhci_hcd: cannot find the pending unlink 0
[431928.068675] vhci_hcd: dequeue a urb ffff8800365a83c0
[431928.068722] vhci_hcd: device ffff88003ae96290 seems to be still connected
[431928.072174] vhci_hcd: unlink->seqnum 588730
[431928.072184] vhci_hcd: unlink->seqnum 588757
[431928.072188] vhci_hcd: unlink->seqnum 588771
[431928.072191] vhci_hcd: unlink->seqnum 588785
[431928.072194] vhci_hcd: unlink->seqnum 588799
[431928.072196] vhci_hcd: unlink->seqnum 588813
[431928.072199] vhci_hcd: unlink->seqnum 588827
[431928.072202] vhci_hcd: unlink->seqnum 588841
[431928.072205] vhci_hcd: unlink->seqnum 588855
[431928.072208] vhci_hcd: cannot find the pending unlink 0
[431938.119370] vhci_hcd: dequeue a urb ffff880036e193c0
[431938.119412] vhci_hcd: device ffff88003ae96290 seems to be still connected
[431938.122207] vhci_hcd: unlink->seqnum 588730
[431938.122216] vhci_hcd: unlink->seqnum 588757
[431938.122220] vhci_hcd: unlink->seqnum 588771
[431938.122223] vhci_hcd: unlink->seqnum 588785
[431938.122226] vhci_hcd: unlink->seqnum 588799
[431938.122229] vhci_hcd: unlink->seqnum 588813
[431938.122232] vhci_hcd: unlink->seqnum 588827
[431938.122234] vhci_hcd: unlink->seqnum 588841
[431938.122237] vhci_hcd: unlink->seqnum 588855
[431938.122240] vhci_hcd: unlink->seqnum 588869
[431938.122243] vhci_hcd: cannot find the pending unlink 0
[431948.169819] vhci_hcd: dequeue a urb ffff880036e193c0
[431948.169860] vhci_hcd: device ffff88003ae96290 seems to be still connected
[431948.173695] vhci_hcd: unlink->seqnum 588730
[431948.173702] vhci_hcd: unlink->seqnum 588757
[431948.173705] vhci_hcd: unlink->seqnum 588771
[431948.173709] vhci_hcd: unlink->seqnum 588785
[431948.173712] vhci_hcd: unlink->seqnum 588799
[431948.173714] vhci_hcd: unlink->seqnum 588813
[431948.173717] vhci_hcd: unlink->seqnum 588827
[431948.173720] vhci_hcd: unlink->seqnum 588841
[431948.173723] vhci_hcd: unlink->seqnum 588855
[431948.173726] vhci_hcd: unlink->seqnum 588869
[431948.173728] vhci_hcd: unlink->seqnum 588883
[431948.173732] vhci_hcd: cannot find the pending unlink 0
[431958.218580] vhci_hcd: dequeue a urb ffff880036e190c0
[431958.218616] vhci_hcd: device ffff88003ae96290 seems to be still connected
[431958.221180] vhci_hcd: unlink->seqnum 588730
[431958.221187] vhci_hcd: unlink->seqnum 588757
[431958.221191] vhci_hcd: unlink->seqnum 588771
[431958.221194] vhci_hcd: unlink->seqnum 588785
[431958.221197] vhci_hcd: unlink->seqnum 588799
[431958.221200] vhci_hcd: unlink->seqnum 588813
[431958.221203] vhci_hcd: unlink->seqnum 588827
[431958.221205] vhci_hcd: unlink->seqnum 588841
[431958.221208] vhci_hcd: unlink->seqnum 588855
[431958.221211] vhci_hcd: unlink->seqnum 588869
[431958.221214] vhci_hcd: unlink->seqnum 588883
[431958.221217] vhci_hcd: unlink->seqnum 588897
[431958.221220] vhci_hcd: cannot find the pending unlink 0
[431968.270320] vhci_hcd: dequeue a urb ffff8800365a8f00
[431968.270335] vhci_hcd: device ffff88003ae96290 seems to be still connected
[431968.273091] vhci_hcd: unlink->seqnum 588730
[431968.273098] vhci_hcd: unlink->seqnum 588757
[431968.273101] vhci_hcd: unlink->seqnum 588771
[431968.273104] vhci_hcd: unlink->seqnum 588785
[431968.273107] vhci_hcd: unlink->seqnum 588799
[431968.273110] vhci_hcd: unlink->seqnum 588813
[431968.273113] vhci_hcd: unlink->seqnum 588827
[431968.273116] vhci_hcd: unlink->seqnum 588841
[431968.273118] vhci_hcd: unlink->seqnum 588855
[431968.273121] vhci_hcd: unlink->seqnum 588869
[431968.273124] vhci_hcd: unlink->seqnum 588883
[431968.273127] vhci_hcd: unlink->seqnum 588897
[431968.273129] vhci_hcd: unlink->seqnum 588911
[431968.273132] vhci_hcd: cannot find the pending unlink 0
[431976.857025] vhci_hcd: connection closed
[431976.857133] vhci_hcd: stop threads
[431976.857143] vhci_hcd: release socket
[431976.857148] vhci_hcd: unlink cleanup rx 588720
[431976.857152] vhci_hcd: the urb (seqnum 588720) was already given back
[431976.857155] vhci_hcd: unlink cleanup rx 588747
[431976.857158] vhci_hcd: the urb (seqnum 588747) was already given back
[431976.857161] vhci_hcd: unlink cleanup rx 588761
[431976.857164] vhci_hcd: the urb (seqnum 588761) was already given back
[431976.857167] vhci_hcd: unlink cleanup rx 588775
[431976.857170] vhci_hcd: the urb (seqnum 588775) was already given back
[431976.857173] vhci_hcd: unlink cleanup rx 588789
[431976.857176] vhci_hcd: the urb (seqnum 588789) was already given back
[431976.857178] vhci_hcd: unlink cleanup rx 588803
[431976.857181] vhci_hcd: the urb (seqnum 588803) was already given back
[431976.857184] vhci_hcd: unlink cleanup rx 588817
[431976.857187] vhci_hcd: the urb (seqnum 588817) was already given back
[431976.857190] vhci_hcd: unlink cleanup rx 588831
[431976.857193] vhci_hcd: the urb (seqnum 588831) was already given back
[431976.857196] vhci_hcd: unlink cleanup rx 588845
[431976.857198] vhci_hcd: the urb (seqnum 588845) was already given back
[431976.857201] vhci_hcd: unlink cleanup rx 588859
[431976.857204] vhci_hcd: the urb (seqnum 588859) was already given back
[431976.857207] vhci_hcd: unlink cleanup rx 588873
[431976.857210] vhci_hcd: the urb (seqnum 588873) was already given back
[431976.857213] vhci_hcd: unlink cleanup rx 588887
[431976.857215] vhci_hcd: the urb (seqnum 588887) was already given back
[431976.857218] vhci_hcd: unlink cleanup rx 588901
[431976.857221] vhci_hcd: the urb (seqnum 588901) was already given back
[431976.857231] vhci_hcd: disconnect device
[431976.857296] usb 3-1: USB disconnect, device number 4
[431984.136917] vhci_hcd vhci_hcd: rhport(0) sockfd(25) devid(4) speed(2) speed_str(full-speed)
[431984.356291] usb 3-1: new full-speed USB device number 5 using vhci_hcd
[431984.470238] usb 3-1: SetAddress Request (5) to port 0
[431989.484259] vhci_hcd: dequeue a urb ffff880036ebc240
[431989.484274] vhci_hcd: device ffff88003ae96290 seems to be still connected
[431989.486292] vhci_hcd: unlink->seqnum 588927
[431989.486302] vhci_hcd: cannot find the pending unlink 0
[432031.266740] vhci_hcd vhci_hcd: rhport(1) sockfd(28) devid(5) speed(2) speed_str(full-speed)
openhab@openHAB:/dev$
when I connect a second device (USB-serial adapter) I can connect it via the client, but ubuntu doesn't recognize it (it doesn't show up in dmesg and in the /dev directory the ttyUSB0 device is missing.
It looks to me like a kernel
It looks to me like a kernel bug, what i think is happening is that the virtualhere client is submitting data to the linux kernel from the remote usb device and the kernel never returns so the virtualhere client becomes stuck when trying to add a new device. I think try upgrading the linux kernel to ubuntu 15.04 (it uses 3.19) otherewise im pretty sure its a bug in the linux kernel and you will have to wait until its fixed. Possibly you could restart the client at the end of the day and see if that helps the issue.
Ok I will try to upgrade
Ok I will try to upgrade Ubuntu.
I finally upgraded Ubuntu. I
I finally upgraded Ubuntu. I think the client doesn't crash anymore but the strange log entries are still the same.
[ 1144.439942] vhci_hcd: dequeue a urb ffff88003d63c480
[ 1144.439959] vhci_hcd: device ffff88003d519298 seems to be still connected
[ 1144.443063] vhci_hcd: unlink->seqnum 76
[ 1144.443074] vhci_hcd: unlink->seqnum 90
[ 1144.443078] vhci_hcd: unlink->seqnum 104
[ 1144.443082] vhci_hcd: unlink->seqnum 109
[ 1144.443085] vhci_hcd: unlink->seqnum 167
[ 1144.443087] vhci_hcd: unlink->seqnum 181
[ 1144.443090] vhci_hcd: unlink->seqnum 207
[ 1144.443092] vhci_hcd: unlink->seqnum 221
[ 1144.443095] vhci_hcd: unlink->seqnum 235
[ 1144.443098] vhci_hcd: cannot find the pending unlink 0
Ok those entries cannot be
Ok those entries cannot be turned off as they are in the kernel for some reason, i dont know why the linux kernel keeps these debugging messages on by default, seems like they should be off by default.