##########################################################################################

       PIDVR-12: FreeSat adapter is detected but unusable (DVBSky S960)

##########################################################################################


Issue Type: Bug 
-----------------------------------------------------------------------------------------

Issue Information
====================

Priority: Major					Status:      Closed
Resolution:  Won't Fix (2015-01-21 03:08:57)
Project: PiDVR (PIDVR)


Reported By: btasker					
Assigned To: btasker


Affected Versions:		
	- Virtualisation specific Issues  			


Targeted for fix in version: 
	- Virtualisation specific Issues

Labels: DVBSkyS960, Passthrough, USB, VirtualBox, 

Time Estimate: 0 minutes
Time Logged:   0 minutes


-----------------------------------------------------------------------------------------

Issue Description
==================

Following an unknown event in the OS (guest or host?) the FreeSat adapter is presented to
the Guest OS but isn't being initialised correctly by the driver.

Dmesg contains the following


-- BEGIN SNIPPET --

holly kernel: [  659.876236] DVB: registering new adapter (DVBSky S960/S860)
holly kernel: [  661.887998] dvbsky_usb MAC address=00:00:00:00:00:00
holly kernel: [  661.888054] usb 1-1: dvb_usb_v2: MAC address: 00:00:00:00:00:00
holly kernel: [  661.890833] M88DS3103 tuner read stops = 0.
holly kernel: [  663.893311] DS3000 chip version: ffffff92 attached.
holly kernel: [  667.893870] TS202x chip version[1]: ffffff92 attached.
holly kernel: [  671.893335] m88ds3103_tuner_writereg: writereg error(err == -110, reg ==
0x00, value == 0x03)
holly kernel: [  675.909693] TS202x chip version[2]: ffffff92 attached.
holly kernel: [  675.910266] usb 1-1: dvb_usb_v2: 'DVBSky S960/S860' error while loading
driver (-19)
holly kernel: [  675.912972] usb 1-1: dvb_usb_v2: 'DVBSky S960/S860' successfully
deinitialized and disconnected

 -- END SNIPPET --


A reset of the USB subsytem (tried in both Guest and Host) didn't work


-- BEGIN SNIPPET --

for i in $(ls /sys/bus/pci/drivers/ehci_hcd/|grep :);  do echo $i >
/sys/bus/pci/drivers/ehci_hcd/unbind;  echo $i > /sys/bus/pci/drivers/ehci_hcd/bind; done

 -- END SNIPPET --

A reboot of the Host also hasn't resolved the issue.

-----------------------------------------------------------------------------------------

Activity
==========

	
-----------------------------------------------------------------------------------------
2014-12-01 12:58:56              btasker
-----------------------------------------------------------------------------------------

Following a powerdown of the Freesat adapter, the adapter still isn't being initialised,
but _dmesg_ now contains a little more information


-- BEGIN SNIPPET --

[    8.505747] usbcore: registered new interface driver dvb_usb_dvbsky
[    8.506972] dvbsky_identify_state, build on Nov 28 2014 05:41:02(),delay=0
[   10.604478] usb 1-1: dvb_usb_v2: usb_bulk_msg() failed=-110
[   10.604810] usb 1-1: dvb_usb_dvbsky: dvbsky_gpio_ctrl() failed=-110
[   12.604274] usb 1-1: dvb_usb_v2: usb_bulk_msg() failed=-110
[   12.604789] usb 1-1: dvb_usb_dvbsky: dvbsky_gpio_ctrl() failed=-110
[   14.710221] usb 1-1: dvb_usb_v2: usb_bulk_msg() failed=-110
[   14.711265] usb 1-1: dvb_usb_dvbsky: dvbsky_gpio_ctrl() failed=-110
[   16.708670] usb 1-1: dvb_usb_v2: usb_bulk_msg() failed=-110
[   16.709646] usb 1-1: dvb_usb_dvbsky: dvbsky_gpio_ctrl() failed=-110
[   16.764141] usb 1-1: dvb_usb_v2: found a 'DVBSky S960/S860' in warm state
[   16.764235] usb 1-1: dvb_usb_v2: will pass the complete MPEG2 transport stream to the
software demuxer
[   18.766241] usb 1-1: dvb_usb_v2: usb_bulk_msg() failed=-110
[   18.767322] usb 1-1: dvb_usb_dvbsky: dvbsky_i2c_xfer() failed=-110
[   18.767921] dvbsky_usb MAC address=00:00:00:00:00:00
[   18.768497] usb 1-1: dvb_usb_v2: MAC address: 00:00:00:00:00:00
[   20.840232] usb 1-1: dvb_usb_v2: usb_bulk_msg() failed=-110
[   20.840902] usb 1-1: dvb_usb_dvbsky: dvbsky_i2c_xfer() failed=-110
[   22.848789] usb 1-1: dvb_usb_v2: usb_bulk_msg() failed=-110
[   22.849316] usb 1-1: dvb_usb_dvbsky: dvbsky_i2c_xfer() failed=-110
[   24.848274] usb 1-1: dvb_usb_v2: usb_bulk_msg() failed=-110
[   24.849150] usb 1-1: dvb_usb_dvbsky: dvbsky_i2c_xfer() failed=-110
[   26.849707] usb 1-1: dvb_usb_v2: usb_bulk_msg() failed=-110
[   26.851187] usb 1-1: dvb_usb_dvbsky: dvbsky_i2c_xfer() failed=-110
[   28.850195] usb 1-1: dvb_usb_v2: usb_bulk_msg() failed=-110
[   28.851247] usb 1-1: dvb_usb_dvbsky: dvbsky_i2c_xfer() failed=-110
[   31.108109] usb 1-1: dvb_usb_v2: usb_bulk_msg() failed=-110
[   31.108527] usb 1-1: dvb_usb_dvbsky: dvbsky_i2c_xfer() failed=-110
[   33.108842] usb 1-1: dvb_usb_v2: usb_bulk_msg() failed=-110
[   33.109225] usb 1-1: dvb_usb_dvbsky: dvbsky_i2c_xfer() failed=-110
[   33.110352] dvbsky_s960_attach fail.
[   33.110683] usb 1-1: dvb_usb_v2: 'DVBSky S960/S860' error while loading driver (-19)
[   33.113705] usb 1-1: dvb_usb_v2: 'DVBSky S960/S860' successfully deinitialized and
disconnected

 -- END SNIPPET --


	
-----------------------------------------------------------------------------------------
2014-12-01 13:02:31              btasker
-----------------------------------------------------------------------------------------

With Host and Guest running,

- Unplugged the USB lead
- Unplugged the power supply

Waited 30 seconds and then reconnected


-- BEGIN SNIPPET --

[ 1482.721057] dvbsky_identify_state, build on Nov 28 2014 05:41:02(),delay=0
[ 1483.779809] usb 1-1: dvb_usb_v2: found a 'DVBSky S960/S860' in warm state
[ 1483.779904] usb 1-1: dvb_usb_v2: will pass the complete MPEG2 transport stream to the
software demuxer
[ 1483.786586] dvbsky_usb MAC address=00:18:42:54:96:0c
[ 1483.786594] usb 1-1: dvb_usb_v2: MAC address: 00:18:42:54:96:0c
[ 1485.360242] m88ds3103_load_firmware: Waiting for firmware upload (dvb-fe-ds3103.fw)...
[ 1485.930054] usb 1-1: firmware: agent loaded dvb-fe-ds3103.fw into memory
[ 1487.568828] Registered IR keymap rc-dvbsky
[ 1487.569604] usb 1-1: dvb_usb_v2: schedule remote query interval to 300 msecs
[ 1487.569610] usb 1-1: dvb_usb_v2: 'DVBSky S960/S860' successfully initialized and
connected

root@holly:~# ls /dev/dvb/
adapter0

 -- END SNIPPET --

The adapter is now available for use again, though need to try to get to the bottom of
exactly why the adapter went away (as having to physically disconnect it isn't practical,
and missing recordings because of an unknown issue would be irritating).

	
-----------------------------------------------------------------------------------------
2014-12-01 13:07:01              btasker
-----------------------------------------------------------------------------------------

For reference, the complete _dmesg_ output when the adapter is successfully detected is


-- BEGIN SNIPPET --

[ 1470.221242] usb 1-1: dvb_usb_v2: 'DVBSky S960/S860' error while loading driver (-19)
[ 1470.223051] usb 1-1: dvb_usb_v2: 'DVBSky S960/S860' successfully deinitialized and
disconnected
[ 1478.739235] usb 1-1: USB disconnect, device number 3
[ 1482.536659] usb 1-1: new high-speed USB device number 4 using ehci_hcd
[ 1482.715358] usb 1-1: New USB device found, idVendor=0572, idProduct=6831
[ 1482.715366] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1482.715373] usb 1-1: Product: S960
[ 1482.715380] usb 1-1: Manufacturer: Bestunar
[ 1482.715383] usb 1-1: SerialNumber: 20120511
[ 1482.721057] dvbsky_identify_state, build on Nov 28 2014 05:41:02(),delay=0
[ 1483.779809] usb 1-1: dvb_usb_v2: found a 'DVBSky S960/S860' in warm state
[ 1483.779904] usb 1-1: dvb_usb_v2: will pass the complete MPEG2 transport stream to the
software demuxer
[ 1483.779998] DVB: registering new adapter (DVBSky S960/S860)
[ 1483.786586] dvbsky_usb MAC address=00:18:42:54:96:0c
[ 1483.786594] usb 1-1: dvb_usb_v2: MAC address: 00:18:42:54:96:0c
[ 1483.788488] M88DS3103 tuner read stops = 0.
[ 1483.794431] DS3000 chip version: d0 attached.
[ 1483.805340] TS202x chip version[1]: c1 attached.
[ 1484.342287] TS202x chip version[2]: c3 attached.
[ 1485.360242] m88ds3103_load_firmware: Waiting for firmware upload (dvb-fe-ds3103.fw)...
[ 1485.930054] usb 1-1: firmware: agent loaded dvb-fe-ds3103.fw into memory
[ 1485.930061] m88ds3103_load_firmware: Waiting for firmware upload(2)...
[ 1487.496322] usb 1-1: DVB: registering adapter 0 frontend 0 (Montage DS3103/TS2022)...
[ 1487.568828] Registered IR keymap rc-dvbsky
[ 1487.569104] input: DVBSky S960/S860 as
/devices/pci0000:00/0000:00:0b.0/usb1/1-1/rc/rc0/input6
[ 1487.569598] rc0: DVBSky S960/S860 as /devices/pci0000:00/0000:00:0b.0/usb1/1-1/rc/rc0
[ 1487.569604] usb 1-1: dvb_usb_v2: schedule remote query interval to 300 msecs
[ 1487.569610] usb 1-1: dvb_usb_v2: 'DVBSky S960/S860' successfully initialized and
connected

 -- END SNIPPET --

The first difference that jumps out, is that on the failed entries the device's MAC
address is presented as _00:00:00:00:00:00_ 
	
-----------------------------------------------------------------------------------------
2014-12-01 13:11:35              btasker
-----------------------------------------------------------------------------------------

Couldn't get TVHeadend to mapp services to channels, and the adapter wouldn't seem to tune
to any channel. Have reset TVHeadend's configuration to allow a start from scratch


-- BEGIN SNIPPET --

root@holly:~# service tvheadend stop
root@holly:~# mv /home/hts/.hts/tvheadend/ /home/hts/.hts/tvheadend.old
root@holly:~# dpkg-reconfigure tvheadend

 -- END SNIPPET --

TVHeadend is currently mapping the MUXes, so can at least talk to the adapter now.
	
-----------------------------------------------------------------------------------------
2014-12-01 13:13:44              
-----------------------------------------------------------------------------------------

btasker added 'DVBSkyS960 Passthrough USB VirtualBox' to labels
	
-----------------------------------------------------------------------------------------
2014-12-02 13:24:37              btasker
-----------------------------------------------------------------------------------------

At 06:17 this morning, the hardware became unusable again


*Guest syslog*

-- BEGIN SNIPPET --

Dec  1 15:26:23 holly kernel: [ 6585.456009] hrtimer: interrupt took 6643400 ns
Dec  2 06:17:34 holly kernel: [60056.521002] m88ds3103_tuner_writereg: writereg error(err
== -110, reg == 0x10, value == 0x0a)
Dec  2 06:17:40 holly kernel: [60062.534612] m88ds3103_tuner_writereg: writereg error(err
== -110, reg == 0x11, value == 0x40)
Dec  2 06:17:48 holly kernel: [60070.534484] m88ds3103_tuner_writereg: writereg error(err
== -110, reg == 0x01, value == 0x00)
Dec  2 06:17:54 holly kernel: [60076.534697] m88ds3103_tuner_writereg: writereg error(err
== -110, reg == 0x02, value == 0xae)
Dec  2 06:17:58 holly kernel: [60080.535023] m88ds3103_tuner_writereg: writereg error(err
== -110, reg == 0x03, value == 0x06)
Dec  2 06:18:04 holly kernel: [60086.534786] m88ds3103_tuner_writereg: writereg error(err
== -110, reg == 0x51, value == 0x0f)
Dec  2 06:18:10 holly kernel: [60092.794722] m88ds3103_tuner_writereg: writereg error(err
== -110, reg == 0x51, value == 0x1f)
Dec  2 06:18:16 holly kernel: [60098.794765] m88ds3103_tuner_writereg: writereg error(err
== -110, reg == 0x50, value == 0x10)
Dec  2 06:18:20 holly kernel: [60102.794726] m88ds3103_tuner_writereg: writereg error(err
== -110, reg == 0x50, value == 0x00)

 -- END SNIPPET --


Host's syslog doesn't show anything, and there's nothing around that time in the
VirtualBox logs either

	
-----------------------------------------------------------------------------------------
2014-12-03 23:40:38              btasker
-----------------------------------------------------------------------------------------

It seems there are a few known issues with the driver, but support should have been added
in-kernel since 3.18, so going to ignore the fact it makes me feel dirty and install a
Ubuntu kernel


*Remove the compiled module*


-- BEGIN SNIPPET --

root@holly:~# cd /usr/src/media_build-bst-13/
root@holly:/usr/src/media_build-bst-13# make rminstall
root@holly:/usr/src/media_build-bst-13# reboot

 -- END SNIPPET --



*Check current Kernel version*

-- BEGIN SNIPPET --

root@holly:~# uname -a
Linux holly.home 3.2.0-4-486 #1 Debian 3.2.63-2+deb7u1 i686 GNU/Linux

 -- END SNIPPET --



*Grab and install the Ubuntu Kernel*


-- BEGIN SNIPPET --

root@holly:~# wget
http://kernel.ubuntu.com/~kernel-ppa/mainline/v3.18-rc1-utopic/linux-headers-3.18.0-031800rc1_3.18.0-031800rc1.201410192135_all.deb
root@holly:~# wget
http://kernel.ubuntu.com/~kernel-ppa/mainline/v3.18-rc1-utopic/linux-headers-3.18.0-031800rc1-generic_3.18.0-031800rc1.201410192135_i386.deb
root@holly:~# wget
http://kernel.ubuntu.com/~kernel-ppa/mainline/v3.18-rc1-utopic/linux-image-3.18.0-031800rc1-generic_3.18.0-031800rc1.201410192135_i386.deb
root@holly:~# dpkg -i linux-headers-3.18*.deb linux-image-3.18*.deb
root@holly:~# reboot

root@holly:~# modprobe m88ds3103
root@holly:/lib/modules# modprobe m88ts2022


 -- END SNIPPET --


Dmesg gives


-- BEGIN SNIPPET --

[ 1014.044333] usb 2-1: new full-speed USB device number 2 using ohci-pci
[ 1014.322072] usb 2-1: not running at top speed; connect to a high speed hub
[ 1014.348953] usb 2-1: New USB device found, idVendor=0572, idProduct=6831
[ 1014.348964] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1014.348971] usb 2-1: Product: S960
[ 1014.348976] usb 2-1: Manufacturer: Bestunar
[ 1014.348981] usb 2-1: SerialNumber: 20120511

 -- END SNIPPET --

Figured a reboot was probably in order to get it back into high speed mode, unfortunately
the device now doesn't appear in dmesg at all.

Am also going to compile _v4l_ to see whether that works (and is more stable) than the
driver provided by DVBSky

	
-----------------------------------------------------------------------------------------
2014-12-04 00:30:13              btasker
-----------------------------------------------------------------------------------------

Building the v4l tree


-- BEGIN SNIPPET --

root@holly:/media_build# apt-get install git patchutils libproc-processtable-perl
root@holly:/# git clone git://linuxtv.org/media_build.git --depth=1
Cloning into 'media_build'...
remote: Counting objects: 135, done.
remote: Compressing objects: 100% (123/123), done.
remote: Total 135 (delta 13), reused 70 (delta 7)
Receiving objects: 100% (135/135), 182.65 KiB | 120 KiB/s, done.
Resolving deltas: 100% (13/13), done.
root@holly:/# cd media_build/
root@holly:/media_build# ./build 
root@holly:/media_build# make install
root@holly:/media_build# reboot

 -- END SNIPPET --

Which gets us


-- BEGIN SNIPPET --

[   10.832108] usb 2-1: dvb_usb_v2: found a 'DVBSky S960/S860' in warm state
[   10.832240] usb 2-1: dvb_usb_v2: this USB2.0 device cannot be run on a USB1.1 port (it
lacks a hardware PID filter)
[   10.833412] usbcore: registered new interface driver dvb_usb_dvbsky

 -- END SNIPPET --

Does look like Virtualbox has decided to pass it through as a 1.1 device again:


-- BEGIN SNIPPET --

root@holly:~# lsusb
Bus 002 Device 002: ID 0572:6831 Conexant Systems (Rockwell), Inc. 
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub

 -- END SNIPPET --
	
-----------------------------------------------------------------------------------------
2014-12-04 00:39:10              btasker
-----------------------------------------------------------------------------------------

Actually, on the host, it's also showing as a 1.1 device


-- BEGIN SNIPPET --

[root@starbug ~]# lsusb
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 001 Device 002: ID 0572:6831 Conexant Systems (Rockwell), Inc. 
Bus 001 Device 003: ID 26bd:9917  
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 004 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 003 Device 002: ID 7392:7711 Edimax Technology Co., Ltd EW-7711UTn nLite Wireless
Adapter [Ralink RT2870]
Bus 001 Device 004: ID 04f2:b23b Chicony Electronics Co., Ltd 
Bus 001 Device 005: ID 0bda:0138 Realtek Semiconductor Corp. RTS5138 Card Reader
Controller

 -- END SNIPPET --
	
-----------------------------------------------------------------------------------------
2014-12-04 00:44:02              btasker
-----------------------------------------------------------------------------------------

Device definitely showing as capable of 2.0


-- BEGIN SNIPPET --

[root@starbug ~]# lsusb -v -s 1:6

Bus 001 Device 006: ID 0572:6831 Conexant Systems (Rockwell), Inc. 
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               2.00
  bDeviceClass            0 (Defined at Interface level)
  bDeviceSubClass         0 
  bDeviceProtocol         0 
  bMaxPacketSize0        64
  idVendor           0x0572 Conexant Systems (Rockwell), Inc.
  idProduct          0x6831 
  bcdDevice            0.00
  iManufacturer           1 Bestunar
  iProduct                2 S960
  iSerial                 3 20120511
  bNumConfigurations      1

 -- END SNIPPET --

Will have to play around with it some more later
	
-----------------------------------------------------------------------------------------
2014-12-04 00:55:01              btasker
-----------------------------------------------------------------------------------------

Couldn't quite bring myself to give up.....

A reset of the USB subsystem seems to have done it


-- BEGIN SNIPPET --

[root@starbug ~]# for i in $(ls /sys/bus/pci/drivers/ehci_hcd/|grep :);  do echo $i >
/sys/bus/pci/drivers/ehci_hcd/unbind;  echo $i > /sys/bus/pci/drivers/ehci_hcd/bind; done

[root@starbug ~]# lsusb
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 001 Device 006: ID 0572:6831 Conexant Systems (Rockwell), Inc. 
Bus 001 Device 003: ID 26bd:9917  
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 004 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 003 Device 002: ID 7392:7711 Edimax Technology Co., Ltd EW-7711UTn nLite Wireless
Adapter [Ralink RT2870]
Bus 001 Device 004: ID 04f2:b23b Chicony Electronics Co., Ltd 
Bus 001 Device 005: ID 0bda:0138 Realtek Semiconductor Corp. RTS5138 Card Reader
Controller

 -- END SNIPPET --



Guest now sees the device as USB2 but something else has gone wrong


-- BEGIN SNIPPET --

[   10.880735] usb 1-1: dvb_usb_v2: found a 'DVBSky S960/S860' in warm state
[   10.880922] usb 1-1: dvb_usb_v2: will pass the complete MPEG2 transport stream to the
software demuxer
[   10.881265] DVB: registering new adapter (DVBSky S960/S860)
[   10.884247] usb 1-1: dvb_usb_v2: MAC address: 00:18:42:54:96:0c
[   10.916900] i2c i2c-0: m88ds3103_attach: chip_id=00
[   10.916938] usb 1-1: dvbsky_s960_attach fail.

 -- END SNIPPET --

No other info in dmesg/syslog.

Giving up for the night I think


	
-----------------------------------------------------------------------------------------
2015-01-21 03:08:57              btasker
-----------------------------------------------------------------------------------------

Marking as Won't fix as it doesn't seem worth pursuing virtualisation with this adapter.

See comment in PIDVR-11
	
-----------------------------------------------------------------------------------------
2015-01-21 03:08:57              
-----------------------------------------------------------------------------------------

btasker changed status from 'Open' to 'Resolved'
	
-----------------------------------------------------------------------------------------
2015-01-21 03:08:57              
-----------------------------------------------------------------------------------------

btasker added 'Won't Fix' to resolution
	
-----------------------------------------------------------------------------------------
2015-01-21 03:09:04              
-----------------------------------------------------------------------------------------

btasker changed status from 'Resolved' to 'Closed'