Re: HVR-4000 DVB can't scan or tune (properly) with Xen

[Konrad Rzeszutek Wilk <konrad.wilk@oracle.com>]

On Tue, Nov 15, 2011 at 12:52:56AM +0000, jonathanjstevens@gmail.com wrote:
> >
> > Excellent. Everything that is new.
> 
> Shiney. :)
> 
> >
> >>
> >> When I boot without Xen the DVB PCI cards can tune and scan perfectly.
> >> I also have a USB DVB unit, which can tune and scan regardless of
> >> whether Xen is running. However when I try to scan and tune with the
> >> PCI DVB cards it fails.
> >
> > OK, and you are _not_ passing it to a guest right?
> 
> Indeed not, this is in dom0. I do not have IOMMU so my dvb stuff will
> run in dom0.
> 
> 
> >>
> >> [   26.572693] cx88[1]/1: IRQ loop detected, disabling interrupts
> >> [   26.574810] cx88[1]: irq aud [0x1001] dn_risci1* dn_sync*
> >
> > Great. Can you do a couple of tests:
> 
> Certainly. However, first I will say that I have made the above
> messages go away. I had been trying various boot options based on what
> I had been reading on net. I was using irqpoll at the time that those
> messages appeared. Removing irqpoll has stopped them from occurring.
> Hopefully that is useful information in itself.

Why did pick irqpoll? Was there something in the past that was hanging on your box.

> 
> >
> > 1). Boot your Linux machine with 'mem=3G' and see if that makes the issue
> >    disappear.
> 
> I have tried mem=2G and 4G (not 3 but I will if you think it'll be different).
> I have also been trying with ballooning disabled, and with dom0_mem=2G / 4G
> I also tried swiotlb=65762
> I have tried most combinations of the above - but not necessarily all.

And all fail? Was this with the irqpoll option?
Is this a two socket box?

> 
> 
> >
> > 2). Tell me what is the 'scan' tool you use? Is it there a command
> >   line version of the tool that triggers this?
> >
> I've been using as many as I can try.
> Mainly it's the F16 provided scandvb, which I think is just a renamed
> dvbscan and also w_scan.
> I've also tried mplayer, xine, kaffeine, and mythtv. I haven't got vlc
> to compile yet...

rpmfusion has a version of it built for F16.

> 
> I think I have a bit more information for you after today's hacking about.
> First off there was a kernel update, so I'm now at
> 
> Linux mythtvtuner.home 3.1.1-1.fc16.x86_64 #1 SMP Fri Nov 11 21:47:56
> UTC 2011 x86_64 x86_64 x86_64 GNU/Linux
> 
> 
> >From what I can see I think in fact the tuning works OK, but there is
> some sort of issue getting at the streams once tuned.
> e.g. tzap will get a lock OK
> > tzap -a 1 -f 1 -d 1 -c ~/tzap.channels.conf "BBC ONE(BBC)"
> using '/dev/dvb/adapter1/frontend1' and '/dev/dvb/adapter1/demux1'
> tuning to 650000000 Hz
> video pid 0x0065, audio pid 0x0066
> status 01 | signal 5151 | snr 8000 | ber 00003fff | unc 00000000 |
> status 1f | signal 4e4e | snr ffff | ber 00000000 | unc 00000000 | FE_HAS_LOCK
> status 1f | signal 4e4e | snr ffff | ber 00000000 | unc 00000000 | FE_HAS_LOCK
> 
> 
> I don't know if the following is useful?
> 
> root@mythtvtuner jon]# strace -f -v scandvb -a 1 -f1 -d 0 -5 -v -v -v
> ~jon/dvbscan.channels.conf
> execve("/usr/bin/scandvb", ["scandvb", "-a", "1", "-f1", "-d", "0",
> "-5", "-v", "-v", "-v", "/home/jon/dvbscan.channels.conf"],
> ["XDG_SESSION_ID=69", "HOSTNAME=mythtvtuner.home", "SHELL=/bin/bash",
> "TERM=xterm", "HISTSIZE=1000", "SSH_CLIENT=192.168.2.179 48391 2"...,
> "SSH_TTY=/dev/pts/7", "USER=jon",
> "LS_COLORS=rs=0:di=01;34:ln=01;36"...,
> "PATH=/usr/lib64/ccache:/usr/loca"..., "MAIL=/var/spool/mail/jon",
> "PWD=/home/jon", "XMODIFIERS=@im=none", "LANG=en_US.UTF-8",
> "KDE_IS_PRELINKED=1", "KDEDIRS=/usr", "HISTCONTROL=ignoredups",
> "HOME=/root", "SHLVL=2", "LOGNAME=jon", "CVS_RSH=ssh",
> "SSH_CONNECTION=192.168.2.179 483"...,
> "LESSOPEN=||/usr/bin/lesspipe.sh "...,
> "XDG_RUNTIME_DIR=/run/user/jon", "_=/usr/bin/strace"]) = 0
> brk(0)                                  = 0x20fe000
> mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
> 0) = 0x7ff5ccd7a000
> access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
> open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
> fstat(3, {st_dev=makedev(253, 1), st_ino=132752, st_mode=S_IFREG|0644,
> st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=224,
> st_size=112482, st_atime=2011/11/14-12:23:08,
> st_mtime=2011/11/14-12:23:06, st_ctime=2011/11/14-12:23:06}) = 0
> mmap(NULL, 112482, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7ff5ccd5e000
> close(3)                                = 0
> open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
> read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260\27\2\2008\0\0\0"...,
> 832) = 832
> fstat(3, {st_dev=makedev(253, 1), st_ino=157705, st_mode=S_IFREG|0755,
> st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=4032,
> st_size=2063512, st_atime=2011/11/14-23:30:01,
> st_mtime=2011/10/26-20:57:26, st_ctime=2011/11/09-23:29:49}) = 0
> mmap(0x3880000000, 3884344, PROT_READ|PROT_EXEC,
> MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3880000000
> mprotect(0x38801aa000, 2097152, PROT_NONE) = 0
> mmap(0x38803aa000, 24576, PROT_READ|PROT_WRITE,
> MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1aa000) = 0x38803aa000
> mmap(0x38803b0000, 17720, PROT_READ|PROT_WRITE,
> MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x38803b0000
> close(3)                                = 0
> mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
> 0) = 0x7ff5ccd5d000
> mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
> 0) = 0x7ff5ccd5c000
> mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
> 0) = 0x7ff5ccd5b000
> arch_prctl(ARCH_SET_FS, 0x7ff5ccd5c700) = 0
> mprotect(0x38803aa000, 16384, PROT_READ) = 0
> mprotect(0x387fe21000, 4096, PROT_READ) = 0
> munmap(0x7ff5ccd5e000, 112482)          = 0
> write(2, "scanning /home/jon/dvbscan.chann"..., 41scanning
> /home/jon/dvbscan.channels.conf
> ) = 41
> write(2, "using '/dev/dvb/adapter1/fronten"..., 67using
> '/dev/dvb/adapter1/frontend1' and '/dev/dvb/adapter1/demux0'
> ) = 67
> open("/dev/dvb/adapter1/frontend1", O_RDWR) = 3
> ioctl(3, FE_GET_INFO, 0x60a640)         = 0
> rt_sigaction(SIGINT, {0x403300, [INT], SA_RESTORER|SA_RESTART,
> 0x3880036320}, {SIG_DFL, [], 0}, 8) = 0
> brk(0)                                  = 0x20fe000
> brk(0x211f000)                          = 0x211f000
> brk(0)                                  = 0x211f000
> open("/home/jon/dvbscan.channels.conf", O_RDONLY) = 4
> fstat(4, {st_dev=makedev(253, 16), st_ino=1704027,
> st_mode=S_IFREG|0664, st_nlink=1, st_uid=1000, st_gid=1000,
> st_blksize=4096, st_blocks=8, st_size=1028,
> st_atime=2011/11/14-15:05:46, st_mtime=2011/11/10-23:05:38,
> st_ctime=2011/11/10-23:05:38}) = 0
> mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,
> 0) = 0x7ff5ccd79000
> read(4, "#-------------------------------"..., 4096) = 1028
> write(2, "initial transponder 650000000 0 "..., 44initial transponder
> 650000000 0 9 9 6 2 4 4
> ) = 44
> write(2, "initial transponder 754000000 0 "..., 44initial transponder
> 754000000 0 3 9 3 1 0 0
> ) = 44
> write(2, "initial transponder 794000000 0 "..., 44initial transponder
> 794000000 0 2 9 3 1 0 0
> ) = 44
> write(2, "initial transponder 738000000 0 "..., 44initial transponder
> 738000000 0 2 9 3 1 0 0
> ) = 44
> write(2, "initial transponder 690000000 0 "..., 44initial transponder
> 690000000 0 2 9 3 1 0 0
> ) = 44
> write(2, "initial transponder 722000000 0 "..., 44initial transponder
> 722000000 0 2 9 3 1 0 0
> ) = 44
> write(2, "initial transponder 706000000 0 "..., 44initial transponder
> 706000000 0 9 9 6 2 4 4
> ) = 44
> write(2, "initial transponder 842000000 0 "..., 44initial transponder
> 842000000 0 9 9 6 2 4 4
> ) = 44
> read(4, "", 4096)                       = 0
> close(4)                                = 0
> munmap(0x7ff5ccd79000, 4096)            = 0
> write(2, ">>> tune to: ", 13>>> tune to: )           = 13
> write(2, "650000000:", 10650000000:)              = 10
> write(2, "INVERSION_AUTO:", 15INVERSION_AUTO:)         = 15
> write(2, "BANDWIDTH_8_MHZ:", 16BANDWIDTH_8_MHZ:)        = 16
> write(2, "FEC_AUTO:", 9FEC_AUTO:)                = 9
> write(2, "FEC_AUTO:", 9FEC_AUTO:)                = 9
> write(2, "QAM_AUTO:", 9QAM_AUTO:)                = 9
> write(2, "TRANSMISSION_MODE_AUTO:", 23TRANSMISSION_MODE_AUTO:) = 23
> write(2, "GUARD_INTERVAL_AUTO:", 20GUARD_INTERVAL_AUTO:)    = 20
> write(2, "HIERARCHY_AUTO", 14HIERARCHY_AUTO)          = 14
> write(2, "\n", 1
> )                       = 1
> ioctl(3, FE_SET_FRONTEND, 0x7fffe82681c0) = 0
> nanosleep({0, 200000000}, NULL)         = 0
> ioctl(3, FE_READ_STATUS, 0x7fffe82681ec) = 0
> write(2, ">>> tuning status == 0x01\n", 26>>> tuning status == 0x01
> ) = 26
> nanosleep({0, 200000000}, NULL)         = 0
> ioctl(3, FE_READ_STATUS, 0x7fffe82681ec) = 0
> write(2, ">>> tuning status == 0x1f\n", 26>>> tuning status == 0x1f
> ) = 26
> open("/dev/dvb/adapter1/demux0", O_RDWR|O_NONBLOCK) = 4
> ioctl(4, DMX_SET_FILTER, 0x7fffe8266fc0) = 0
> open("/dev/dvb/adapter1/demux0", O_RDWR|O_NONBLOCK) = 5
> ioctl(5, DMX_SET_FILTER, 0x7fffe8266fc0) = 0
> open("/dev/dvb/adapter1/demux0", O_RDWR|O_NONBLOCK) = 6
> ioctl(6, DMX_SET_FILTER, 0x7fffe8266fc0) = 0
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> poll([{fd=6, events=POLLIN}, {fd=5, events=POLLIN}, {fd=4,
> events=POLLIN}], 3, 1000) = 0 (Timeout)
> write(2, "WARNING: filter timeout pid 0x00"..., 35WARNING: filter
> timeout pid 0x0011
> ) = 35
> ioctl(5, DMX_STOP, 0x38803b0a80)        = 0
> close(5)                                = 0
> poll([{fd=6, events=POLLIN}, {fd=4, events=POLLIN}], 2, 1000) = 0 (Timeout)
> write(2, "WARNING: filter timeout pid 0x00"..., 35WARNING: filter
> timeout pid 0x0000
> ) = 35
> ioctl(4, DMX_STOP, 0x38803b0a80)        = 0
> close(4)                                = 0
> poll([{fd=6, events=POLLIN}], 1, 1000)  = 0 (Timeout)
> poll([{fd=6, events=POLLIN}], 1, 1000)  = 0 (Timeout)
> poll([{fd=6, events=POLLIN}], 1, 1000)  = 0 (Timeout)
> poll([{fd=6, events=POLLIN}], 1, 1000^C <unfinished ...>
> 
> etc...
> 
> Occasionally the POLLIN doesn't timeout (since kernel upgrade), but
> the data can't seem to be interpreted (my guess) and I can't find what
> makes this occur (and I can't seem to make it happen right now
> annoyingly!).
> I don't want to bombard you with unwanted diags but can capture more
> fully similar to above if useful?
> 
> 
> 
> > 3). Or does this happend when you just load the module and it starts
> >   doing the IRQ loop detected' thingy?
> 
> Not entirely sure, can recreate by turning irqpoll back on and testing
> if you want? From memory there were very few of the
> >> [   26.572693] cx88[1]/1: IRQ loop detected, disabling interrupts
> 
> but lots and lots of:
> >> [   26.574810] cx88[1]: irq aud [0x1001] dn_risci1* dn_sync*


Well, that one is the worry some one. It reads as if it can't get the
interrupts fast enough, which would be worrysome.

I think I need to look at the code itself to get a better understanding
of where that 'irq aud ..' is.


Are there cheap versions of these DVB cards? I've only Hauppage PV-150 which
works for me, but that is not a DVB type card.