Operation not permitted (-1)

Submitted by flyndr on #1

Using virtual here client on win10 to server on raspberry pi. It is working with usb key or webcam.
Now trying to connect to my telescope (usb with usb to serial converter). This works on usb on my computer direct, but on the client. I select once and get the above message. Select again and it connects but telescope software cannot see the serial port.
Any clues gratefully accepted.

Submitted by Michael on Thu, 2018/11/08 - 07:15

#2

In the virtualhere client, right click on the telescope and select Custom Event Handler and enter 

onReset.$VENDOR_ID$.$PRODUCT_ID$=

then press OK. Unplug and replug the telescope and now try to use it via virtualhere.

Submitted by flyndr on Thu, 2018/11/08 - 07:37

#3

No Avail,
I already tried that but did it again. Usb connects but telescope does not recognize the com port. I think it might be an issue with usb/serial converter in the system

Submitted by flyndr on Thu, 2018/11/08 - 07:40

#4

10:38:47 INFO :VirtualHere Client 4.6.1 starting (Compiled: Oct 12 2018 19:03:04)
10:38:47 INFO :Using config at C:\Users\Terry\AppData\Roaming\vhui.ini
10:38:47 INFO :IPC available at \\.\pipe\vhclient
10:38:47 INFO :Auto-find (Bonjour) on
10:38:47 INFO :Auto-find (Bonjour SSL) on
10:38:47 INFO :ReverseLookupService listening on port 7573 (IPv6 dual-stack)
10:38:47 INFO :SSLReverseLookupService listening on port 7572 (IPv6 dual-stack)
10:38:49 INFO :Error 'No such host is known. ' getaddrinfo failed for raspberrypi-2.local.:7575
10:38:52 INFO :Drivers are up-to-date
10:38:52 INFO :Connected to the VirtualHere Client Driver (Version 2)

Submitted by Michael on Thu, 2018/11/08 - 08:00

#5

Have a look on the server in the /var/log/syslog file. It will say BIND_ERROR in the log and the reasons will be around that line in the log

Submitted by flyndr on Thu, 2018/11/08 - 10:20

#6

took a while. The client on first select (double click device) usually comes up with an error message. Second selection usually results in connect (ding on computer when usb is plugged in) I can get this connect but it does not recognise rs232 serial port attached to the usb.
2 different log snippets here where you can see this I think.

ov 8 08:52:35 raspberrypi systemd-timesyncd[269]: Synchronized to time server 202.46.185.18:123 (2.debian.pool.ntp.org).
Nov 8 08:52:35 raspberrypi systemd[491]: Time has been changed
Nov 8 08:52:35 raspberrypi systemd[1]: apt-daily-upgrade.timer: Adding 54min 21.484858s random time.
Nov 8 08:52:35 raspberrypi systemd[1]: apt-daily.timer: Adding 11h 20min 27.265025s random time.
Nov 8 08:53:00 raspberrypi kernel: [ 67.874669] pl2303 ttyUSB0: pl2303 converter now disconnected from ttyUSB0
Nov 8 08:53:00 raspberrypi kernel: [ 67.874767] pl2303 1-1.1.2:1.0: device disconnected
Nov 8 08:53:00 raspberrypi kernel: [ 67.971539] usb 1-1.1.2: reset full-speed USB device number 4 using dwc_otg
Nov 8 08:53:00 raspberrypi vhusbdarm[431]: Error -1 resetting device 0x067b/0x2303 for capture
Nov 8 08:53:00 raspberrypi vhusbdarm[431]: Error binding device 1112 [067b:2303] to connection 1, BIND_ERROR
Nov 8 08:53:00 raspberrypi vhusbdarm[431]: Unmanaging device 1112 [067b:2303]
Nov 8 08:53:00 raspberrypi kernel: [ 68.102315] usb 1-1.1.2: device firmware changed
Nov 8 08:53:00 raspberrypi kernel: [ 68.103039] usb 1-1.1.2: USB disconnect, device number 4
Nov 8 08:53:00 raspberrypi kernel: [ 68.201546] usb 1-1.1.2: new full-speed USB device number 6 using dwc_otg
Nov 8 08:53:00 raspberrypi vhusbdarm[431]: Found Full speed device [067b:2303] "Prolific Technology Inc. , USB-Serial Controller D" at address 1112
Nov 8 08:53:00 raspberrypi kernel: [ 68.333816] usb 1-1.1.2: New USB device found, idVendor=067b, idProduct=2303
Nov 8 08:53:00 raspberrypi kernel: [ 68.333831] usb 1-1.1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Nov 8 08:53:00 raspberrypi kernel: [ 68.333840] usb 1-1.1.2: Product: USB-Serial Controller D
Nov 8 08:53:00 raspberrypi kernel: [ 68.333849] usb 1-1.1.2: Manufacturer: Prolific Technology Inc.
Nov 8 08:53:00 raspberrypi mtp-probe: checking bus 1, device 6: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1/1-1.1.2"
Nov 8 08:53:00 raspberrypi mtp-probe: bus: 1, device: 6 was not an MTP device
Nov 8 08:53:03 raspberrypi kernel: [ 71.311547] usb 1-1.1.2: reset full-speed USB device number 6 using dwc_otg
Nov 8 08:53:03 raspberrypi vhusbdarm[431]: Device 1112 [067b:2303] BOUND to connection 1
Nov 8 08:53:04 raspberrypi kernel: [ 71.731582] usb 1-1.1.2: reset full-speed USB device number 6 using dwc_otg
Nov 8 08:53:46 raspberrypi vhusbdarm[431]: Connection 1 remotely disconnected gracefully (rx msg size)
Nov 8 08:53:55 raspberrypi vhusbdarm[431]: Device 1112 [067b:2303] UNBOUND from connection 1
Nov 8 08:53:55 raspberrypi vhusbdarm[431]: Connection 1 successfully removed (reason:timeout)
Nov 8 08:56:02 raspberrypi vhusbdarm[431]: 192.168.189.53 connected as connection 3
Nov 8 08:56:25 raspberrypi kernel: [ 272.851053] usb 1-1.1.2: reset full-speed USB device number 6 using dwc_otg
Nov 8 08:56:25 raspberrypi vhusbdarm[431]: Device 1112 [067b:2303] BOUND to connection 3
Nov 8 08:56:25 raspberrypi kernel: [ 273.281032] usb 1-1.1.2: reset full-speed USB device number 6 using dwc_otg
Nov 8 08:57:25 raspberrypi systemd-modules-load[84]: Inserted module 'i2c_dev'
Nov 8 08:57:25 raspberrypi fake-hwclock[85]: Wed 7 Nov 19:17:02 UTC 2018
Nov 8 08:57:25 raspberrypi kernel: [ 0.000000] Booting Linux on physical CPU 0x0

Nov 8 08:21:03 raspberrypi vhusbdarm[401]: 192.168.189.53 connected as connection 1
Nov 8 08:21:22 raspberrypi kernel: [ 54.632408] pl2303 ttyUSB0: pl2303 converter now disconnected from ttyUSB0
Nov 8 08:21:22 raspberrypi kernel: [ 54.632506] pl2303 1-1.1.2:1.0: device disconnected
Nov 8 08:21:22 raspberrypi kernel: [ 54.731514] usb 1-1.1.2: reset full-speed USB device number 4 using dwc_otg
Nov 8 08:21:22 raspberrypi vhusbdarm[401]: Error -1 resetting device 0x067b/0x2303 for capture
Nov 8 08:21:22 raspberrypi vhusbdarm[401]: Error binding device 1112 [067b:2303] to connection 1, BIND_ERROR
Nov 8 08:21:22 raspberrypi vhusbdarm[401]: Unmanaging device 1112 [067b:2303]
Nov 8 08:21:22 raspberrypi kernel: [ 54.872310] usb 1-1.1.2: device firmware changed
Nov 8 08:21:22 raspberrypi kernel: [ 54.872548] usb 1-1.1.2: USB disconnect, device number 4
Nov 8 08:21:22 raspberrypi kernel: [ 54.971518] usb 1-1.1.2: new full-speed USB device number 6 using dwc_otg
Nov 8 08:21:22 raspberrypi vhusbdarm[401]: Found Full speed device [067b:2303] "Prolific Technology Inc. , USB-Serial Controller D" at address 1112
Nov 8 08:21:22 raspberrypi kernel: [ 55.103810] usb 1-1.1.2: New USB device found, idVendor=067b, idProduct=2303
Nov 8 08:21:22 raspberrypi kernel: [ 55.103825] usb 1-1.1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Nov 8 08:21:22 raspberrypi kernel: [ 55.103834] usb 1-1.1.2: Product: USB-Serial Controller D
Nov 8 08:21:22 raspberrypi kernel: [ 55.103842] usb 1-1.1.2: Manufacturer: Prolific Technology Inc.
Nov 8 08:21:22 raspberrypi mtp-probe: checking bus 1, device 6: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1/1-1.1.2"
Nov 8 08:21:22 raspberrypi mtp-probe: bus: 1, device: 6 was not an MTP device
Nov 8 08:21:29 raspberrypi kernel: [ 61.881524] usb 1-1.1.2: reset full-speed USB device number 6 using dwc_otg
Nov 8 08:21:29 raspberrypi vhusbdarm[401]: Device 1112 [067b:2303] BOUND to connection 1
Nov 8 08:21:30 raspberrypi kernel: [ 62.301523] usb 1-1.1.2: reset full-speed USB device number 6 using dwc_otg

I am thinking that pi needs to be configured somehow to talk to the rs232 serial converter which is built into the telescope. Difficult to use tty for testing because of this I think.

Submitted by Michael on Thu, 2018/11/08 - 12:48

#7

Ok this should work, i see the reset handling has not been properly added.

Can you try again

1. Do not use the "Prolific Technology Inc. , USB-Serial Controller D" via virtualhere
2. Right click on it and select "Custom Event Handler..." and enter exactly this line 

onReset.$VENDOR_ID$.$PRODUCT_ID$=

the press OK.

3. Now try to use the "Prolific Technology Inc. , USB-Serial Controller D" again via virtualhere

Submitted by flyndr on Thu, 2018/11/08 - 13:37

#8

No Different.
First please accept my appreciation for all your help here. This is just about taking as much of your time as mine! I am trying to get this going and if it works I will buy the program.I want to run camera as well as telescope. Camera works fine. And yes i am doing this with only the telescope connected.
I followed the above and there is no change. From my computer the telescope (rs232) is seen over usb and a com port is allocated. This is not happening using vh. The usb connects but no port allocated. Any further ideas?

Submitted by Michael on Thu, 2018/11/08 - 13:44

#9

Post the contents of the /var/log/syslog again i want to see if the reset is being skipped.

Submitted by flyndr on Thu, 2018/11/08 - 14:33

#10

New Log.
This done after following the above custom event handler was updated.

6:59:16 raspberrypi kernel: [ 1.669349] Segment Routing with IPv6
Nov 8 16:59:16 raspberrypi kernel: [ 1.671555] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
Nov 8 16:59:16 raspberrypi systemd[1]: Started D-Bus System Message Bus.
Nov 8 16:59:16 raspberrypi kernel: [ 1.679382] ip_tables: (C) 2000-2006 Netfilter Core Team
Nov 8 16:59:16 raspberrypi kernel: [ 1.703666] random: systemd: uninitialized urandom read (16 bytes read)
Nov 8 16:59:16 raspberrypi kernel: [ 1.744393] random: systemd: uninitialized urandom read (16 bytes read)
Nov 8 16:59:16 raspberrypi kernel: [ 1.761371] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read)
Nov 8 16:59:16 raspberrypi cron[360]: (CRON) INFO (Running @reboot jobs)
Nov 8 16:59:16 raspberrypi kernel: [ 1.802202] usb 1-1.1: New USB device found, idVendor=0424, idProduct=2514
Nov 8 16:59:16 raspberrypi kernel: [ 1.802219] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Nov 8 16:59:16 raspberrypi kernel: [ 1.803019] hub 1-1.1:1.0: USB hub found
Nov 8 16:59:16 raspberrypi dhcpcd[347]: dev: loaded udev
Nov 8 16:59:16 raspberrypi kernel: [ 1.803197] hub 1-1.1:1.0: 3 ports detected
Nov 8 16:59:16 raspberrypi kernel: [ 1.901577] usb 1-1.2: new low-speed USB device number 4 using dwc_otg
Nov 8 16:59:16 raspberrypi kernel: [ 2.133345] usb 1-1.2: New USB device found, idVendor=1241, idProduct=1503
Nov 8 16:59:16 raspberrypi kernel: [ 2.133359] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Nov 8 16:59:16 raspberrypi dhcpcd[347]: forked to background, child pid 383
Nov 8 16:59:16 raspberrypi kernel: [ 2.133368] usb 1-1.2: Product: USB Keyboard
Nov 8 16:59:16 raspberrypi kernel: [ 2.133376] usb 1-1.2: Manufacturer:
Nov 8 16:59:16 raspberrypi kernel: [ 2.151569] usb 1-1.1.2: new full-speed USB device number 5 using dwc_otg
Nov 8 16:59:16 raspberrypi avahi-daemon[345]: Found user 'avahi' (UID 108) and group 'avahi' (GID 112).
Nov 8 16:59:16 raspberrypi avahi-daemon[345]: Successfully dropped root privileges.
Nov 8 16:59:16 raspberrypi avahi-daemon[345]: avahi-daemon 0.6.32 starting up.
Nov 8 16:59:16 raspberrypi liblogging-stdlog: [origin software="rsyslogd" swVersion="8.24.0" x-pid="338" x-info="http://www.rsyslog.com"] start
Nov 8 16:59:16 raspberrypi kernel: [ 2.181011] input: USB Keyboard as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2/1-1.2:1.0/0003:1241:1503.0001/input/input0
Nov 8 16:59:16 raspberrypi kernel: [ 2.244495] hid-generic 0003:1241:1503.0001: input,hidraw0: USB HID v1.10 Keyboard [ USB Keyboard] on usb-3f980000.usb-1.2/input0
Nov 8 16:59:16 raspberrypi kernel: [ 2.284086] usb 1-1.1.2: New USB device found, idVendor=067b, idProduct=2303
Nov 8 16:59:16 raspberrypi kernel: [ 2.284101] usb 1-1.1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Nov 8 16:59:16 raspberrypi kernel: [ 2.284116] usb 1-1.1.2: Product: USB-Serial Controller D
Nov 8 16:59:16 raspberrypi kernel: [ 2.284135] usb 1-1.1.2: Manufacturer: Prolific Technology Inc.
Nov 8 16:59:16 raspberrypi kernel: [ 2.293246] i2c /dev entries driver
Nov 8 16:59:16 raspberrypi kernel: [ 2.313700] input: USB Keyboard as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2/1-1.2:1.1/0003:1241:1503.0002/input/input1
Nov 8 16:59:16 raspberrypi kernel: [ 2.382426] hid-generic 0003:1241:1503.0002: input,hidraw1: USB HID v1.10 Device [ USB Keyboard] on usb-3f980000.usb-1.2/input1
Nov 8 16:59:16 raspberrypi kernel: [ 2.581799] usb 1-1.1.1: new high-speed USB device number 6 using dwc_otg
Nov 8 16:59:16 raspberrypi kernel: [ 2.712092] usb 1-1.1.1: New USB device found, idVendor=0424, idProduct=7800
Nov 8 16:59:16 raspberrypi kernel: [ 2.712110] usb 1-1.1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
Nov 8 16:59:16 raspberrypi kernel: [ 2.812506] usb 1-1.3: new low-speed USB device number 7 using dwc_otg
Nov 8 16:59:16 raspberrypi kernel: [ 2.962122] usb 1-1.3: New USB device found, idVendor=1267, idProduct=0210
Nov 8 16:59:16 raspberrypi kernel: [ 2.962140] usb 1-1.3: New USB device strings: Mfr=0, Product=2, SerialNumber=0
Nov 8 16:59:16 raspberrypi kernel: [ 2.962149] usb 1-1.3: Product: PS/2+USB Mouse
Nov 8 16:59:16 raspberrypi kernel: [ 2.978794] input: PS/2+USB Mouse as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/0003:1267:0210.0003/input/input2
Nov 8 16:59:16 raspberrypi kernel: [ 2.979319] hid-generic 0003:1267:0210.0003: input,hidraw2: USB HID v1.00 Mouse [PS/2+USB Mouse] on usb-3f980000.usb-1.3/input0
Nov 8 16:59:16 raspberrypi kernel: [ 2.988585] libphy: lan78xx-mdiobus: probed
Nov 8 16:59:16 raspberrypi kernel: [ 3.149077] usbcore: registered new interface driver usbserial
Nov 8 16:59:16 raspberrypi kernel: [ 3.149154] usbcore: registered new interface driver usbserial_generic
Nov 8 16:59:16 raspberrypi kernel: [ 3.149212] usbserial: USB Serial support registered for generic
Nov 8 16:59:16 raspberrypi kernel: [ 3.160183] usbcore: registered new interface driver pl2303
Nov 8 16:59:16 raspberrypi kernel: [ 3.160259] usbserial: USB Serial support registered for pl2303
Nov 8 16:59:16 raspberrypi kernel: [ 3.160371] pl2303 1-1.1.2:1.0: pl2303 converter detected
Nov 8 16:59:16 raspberrypi kernel: [ 3.175551] usb 1-1.1.2: pl2303 converter now attached to ttyUSB0
Nov 8 16:59:16 raspberrypi kernel: [ 8.359339] random: crng init done

A bit later
6:59:18 raspberrypi vhusbdarm[480]: Server licensed to=unlicensed max_devices=1
Nov 8 16:59:18 raspberrypi vhusbdarm[480]: Using large URB's
Nov 8 16:59:18 raspberrypi vhusbdarm[480]: Listening on all network interfaces at TCP port 7575
Nov 8 16:59:18 raspberrypi vhusbdarm[480]: Found Full speed device [067b:2303] "Prolific Technology Inc. , USB-Serial Controller D" at address 1112
Nov 8 16:59:18 raspberrypi vhusbdarm[480]: Found Low speed device [1267:0210] "0x1267, PS/2+USB Mouse" at address 113
Nov 8 16:59:18 raspberrypi vhusbdarm[480]: Found Low speed device [1241:1503] " , USB Keyboard" at address 112
Nov 8 16:59:19 raspberrypi raspi-config[340]: Checking if shift key is held down: No. Switching to ondemand scaling governor.
Nov 8 16:59:19 raspberrypi systemd[1]: Started LSB: Switch to ondemand cpu governor (unless shift key is pressed).
Nov 8 16:59:19 raspberrypi dhcpcd[383]: wlan0: carrier acquired

At the end
Nov 8 17:06:04 raspberrypi systemd-timesyncd[281]: Synchronized to time server 203.99.128.48:123 (2.debian.pool.ntp.org).
Nov 8 17:06:04 raspberrypi systemd[1]: Time has been changed
Nov 8 17:06:04 raspberrypi systemd[1]: apt-daily.timer: Adding 6h 36min 57.742430s random time.
Nov 8 17:06:04 raspberrypi systemd[1]: apt-daily-upgrade.timer: Adding 14min 13.408787s random time.
Nov 8 17:10:12 raspberrypi vhusbdarm[480]: Set custom event "onReset.067b.2303="
Nov 8 17:10:18 raspberrypi vhusbdarm[480]: Executed "" for onReset.067b.2303
Nov 8 17:10:18 raspberrypi vhusbdarm[480]: Device 1112 [067b:2303] BOUND to connection 1
Nov 8 17:10:18 raspberrypi kernel: [ 296.583786] pl2303 ttyUSB0: pl2303 converter now disconnected from ttyUSB0
Nov 8 17:10:18 raspberrypi kernel: [ 296.583890] pl2303 1-1.1.2:1.0: device disconnected
Nov 8 17:10:18 raspberrypi vhusbdarm[480]: Executed "" for onReset.067b.2303
Nov 8 17:10:49 raspberrypi vhusbdarm[480]: Device 1112 [067b:2303] UNBOUND from connection 1
Nov 8 17:10:49 raspberrypi kernel: [ 327.563805] usb 1-1.1.2: usbfs: process 919 (vhusbdarm) did not claim interface 0 before use

Hope this is relevant

Submitted by Michael on Thu, 2018/11/08 - 15:21

#11

Ok use the prolific adapter via virtualhere then in windows open Device Manager find the adapter under COM devices and right click on it and select Properties . Does it have a Power Events tab, if so UNcheck "Allow Windows to turn off this device to save power"

Submitted by flyndr on Thu, 2018/11/08 - 15:41

#12

I was looking at com ports when I recieved your advice.
Nexremote (the software I am using to connect with the device) does not like com port above 16. It was on com port 27 (because of all my attempts to connect). I changed com port to 15 and modified power management as well and now it works.
I will try it a bit then register it for a license. It is a good program. Pi lacks a bit of bandwidth for 2 cameras and telescope but not using all at the same time except telescope running in the background.
The software is very good. Thanks for all your time and help