pwarren/rtl-entropy

sync read failed: -1 on gentoo hardened

Closed this issue · 4 comments

hi
current master d174d4a on gentoo running
Linux io 4.2.5-hardened-dom0-kvm-at-gw18 #2 SMP Mon Nov 2 22:12:22 CET 2015 x86_64 Intel(R) Celeron(R) CPU J1900 @ 1.99GHz GenuineIntel GNU/Linux
gives me:
--8<--
»root@io:~/rtl-entropy/src (master)# rtl_entropy
No configuration file found, continuing with defaults.
Options parsed, continuing.
Found 1 device(s):
0: Generic RTL2832U OEM
Using device 0: Generic RTL2832U OEM
Found Rafael Micro R820T tuner
[R82XX] PLL not locked!
Setting Frequency to 70000000
Your device is capable of gains at...
: 0.00
: 0.90
: 1.40
: 2.70
: 3.70
: 7.70
: 8.70
: 12.50
: 14.40
: 15.70
: 16.60
: 19.70
: 20.70
: 22.90
: 25.40
: 28.00
: 29.70
: 32.80
: 33.80
: 36.40
: 37.20
: 38.60
: 40.20
: 42.10
: 43.40
: 43.90
: 44.50
: 48.00
: 49.60
Setting gain to 49.60
Doing FIPS init
Reading samples in sync mode...
ERROR: sync read failed: -1

Library error -1, exiting...
--8<--
lsusb:
[...]
Bus 001 Device 115: ID 0bda:2838 Realtek Semiconductor Corp. RTL2838 DVB-T
[...]

dmesg:
--8<--
[3416257.386927] rtl_entropy: page allocation failure: order:10, mode:0x2040d0
[3416257.386935] CPU: 0 PID: 11102 Comm: rtl_entropy Tainted: G W 4.2.5-hardened-dom0-kvm-at-gw18 #2
[3416257.386937] Hardware name: Gigabyte Technology Co., Ltd. To be filled by O.E.M./J1900N-D3V, BIOS F1 01/22/2014
[3416257.386939] 00000000002040d0 ffffc90005223b18 ffffffff817d9e84 000000000000003e
[3416257.386944] 0000000000000001 ffffc90005223ba8 ffffffff8116e516 ffffffff81ae6b00
[3416257.386947] 0000ffff81ae5f00 0000000000000000 fffffffffffffc00 ffffffff81ae6b38
[3416257.386951] Call Trace:
[3416257.386960] [] dump_stack+0x45/0x57
[3416257.386965] [] warn_alloc_failed+0x100/0x115
[3416257.386969] [] __alloc_pages_nodemask+0x5e8/0x63c
[3416257.386973] [] cache_alloc_refill+0x242/0x449
[3416257.386976] [] __kmalloc+0x78/0xca
[3416257.386980] [] usbdev_ioctl+0x1714/0x1c72
[3416257.386985] [] ? n_tty_open+0xd2/0xd2
[3416257.386989] [] do_vfs_ioctl+0x46c/0x631
[3416257.386993] [] ? entry_SYSCALL_64_fastpath+0x35/0x79
[3416257.386996] [] SyS_ioctl+0x4f/0x7e
[3416257.386999] [] entry_SYSCALL_64_fastpath+0x12/0x79
[3416257.387000] Mem-Info:
[3416257.387007] active_anon:2415133 inactive_anon:263 isolated_anon:0
active_file:601294 inactive_file:601307 isolated_file:0
unevictable:3917 dirty:65 writeback:0 unstable:0
slab_reclaimable:174690 slab_unreclaimable:15107
mapped:4624 shmem:444 pagetables:6808 bounce:0
free:230805 free_pcp:331 free_cma:0
[3416257.387016] DMA free:15836kB min:12kB low:12kB high:16kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15992kB managed:15836kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
[3416257.387017] lowmem_reserve[]: 0 2875 15938 15938
[3416257.387028] DMA32 free:204436kB min:2912kB low:3640kB high:4368kB active_anon:1746248kB inactive_anon:56kB active_file:414188kB inactive_file:414120kB unevictable:3152kB isolated(anon):0kB isolated(file):0kB present:3022876kB managed:2945204kB mlocked:3152kB dirty:36kB writeback:0kB mapped:3544kB shmem:216kB slab_reclaimable:124460kB slab_unreclaimable:10364kB kernel_stack:1104kB pagetables:4904kB unstable:0kB bounce:0kB free_pcp:684kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:100 all_unreclaimable? no
[3416257.387029] lowmem_reserve[]: 0 0 13062 13062
[3416257.387040] Normal free:702948kB min:13232kB low:16540kB high:19848kB active_anon:7914284kB inactive_anon:996kB active_file:1990988kB inactive_file:1990852kB unevictable:12516kB isolated(anon):0kB isolated(file):0kB present:13631488kB managed:13376456kB mlocked:12516kB dirty:224kB writeback:0kB mapped:14952kB shmem:1560kB slab_reclaimable:574300kB slab_unreclaimable:50064kB kernel_stack:3792kB pagetables:22328kB unstable:0kB bounce:0kB free_pcp:644kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:128 all_unreclaimable? no
[3416257.387041] lowmem_reserve[]: 0 0 0 0
[3416257.387045] DMA: 1_4kB (U) 1_8kB (U) 1_16kB (U) 0_32kB 1_64kB (U) 1_128kB (U) 1_256kB (U) 0_512kB 1_1024kB (U) 1_2048kB (U) 3_4096kB (M) = 15836kB
[3416257.387060] DMA32: 31810_4kB (UEM) 5098_8kB (UEM) 2275_16kB (UEM) 7_32kB (U) 1_64kB (U) 0_128kB 0_256kB 0_512kB 0_1024kB 0_2048kB 0_4096kB = 204712kB
[3416257.387073] Normal: 137280_4kB (UEM) 12961_8kB (UEM) 3168_16kB (UEM) 1_32kB (U) 0_64kB 0_128kB 0_256kB 0_512kB 0_1024kB 0_2048kB 0*4096kB = 703528kB
[3416257.387085] 1204554 total pagecache pages
[3416257.387088] 0 pages in swap cache
[3416257.387089] Swap cache stats: add 0, delete 0, find 0/0
[3416257.387090] Free swap = 0kB
[3416257.387091] Total swap = 0kB
[3416257.387092] 4167589 pages RAM
[3416257.387093] 0 pages HighMem/MovableOnly
[3416257.387094] 83215 pages reserved
--8<--
dont know if it has something to do with hardened opts in the kernel. I will try with non hardened kernel but really like to have it running with.

pointers to get it running are appreciated.

From what I can see, it's failing when setting up a DMA transfer from the usb device, not something I do directly, so may be a bug in either the rtl-sdr library, or perhaps libusb stuff?

does rtl_test -S do the same thing?

Hi...sorry for the delay.
rtl_test seems to run fine (no errors on the console).
I'm now running

# uname -a
Linux io 4.4.6-hardened-r1-dom0-kvm-at-gw23 #2 SMP Sun Apr 3 15:01:37 CEST 2016 x86_64 Intel(R) Celeron(R) CPU J1900 @ 1.99GHz GenuineIntel GNU/Linux

but rtl_entropy still fails with "library error" (same as above) and also the page allocation failure.

if it helps this is the libusb version installed:
[ebuild U ] dev-libs/libusb-1.0.19-r1:1::gentoo [1.0.19:1::gentoo] USE="udev -debug -doc -examples -static-libs {-test}" 510

# rtl_test -S
Found 1 device(s):
  0:  Realtek, RTL2838UHIDIR, SN: 00000001

Using device 0: Generic RTL2832U OEM
Found Rafael Micro R820T tuner
Supported gain values (29): 0.0 0.9 1.4 2.7 3.7 7.7 8.7 12.5 14.4 15.7 16.6 19.7 20.7 22.9 25.4 28.0 29.7 32.8 33.8 36.4 37.2 38.6 40.2 42.1 43.4 43.9 44.5 48.0 49.6 
[R82XX] PLL not locked!
Sampling at 2048000 S/s.

Info: This tool will continuously read from the device, and report if
samples get lost. If you observe no further output, everything is fine.

Reading samples in sync mode...
(Samples are being lost but not reported.)
^CSignal caught, exiting!

User cancel, exiting...
Samples per million lost (minimum): 0

real    0m28.772s
user    0m0.090s
sys 0m0.180s
#

doing > strace rtl_entropy

....
open("/dev/bus/usb/001/006", O_RDWR)    = 11
ioctl(11, SNDRV_CTL_IOCTL_TLV_READ or USBDEVFS_GET_CAPABILITIES, 0x48f27e790) = 0
write(7, "\1", 1)                       = 1
read(6, "\1", 1)                        = 1
ioctl(11, USBDEVFS_GETDRIVER, 0x3d3180c7400) = -1 ENODATA (No data available)
ioctl(11, USBDEVFS_CLAIMINTERFACE, 0x3d3180c74cc) = 0
timerfd_settime(10, TFD_TIMER_ABSTIME, {it_interval={0, 0}, it_value={251852, 551069000}}, NULL) = 0
ioctl(11, USBDEVFS_SUBMITURB, 0x48f28e2e0) = 0
poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLOUT}], 4, 60000) = 1 ([{fd=11, revents=POLLOUT}])
ioctl(11, USBDEVFS_REAPURBNDELAY, 0x3d3180c72f0) = 0
timerfd_settime(10, 0, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
ioctl(11, USBDEVFS_REAPURBNDELAY, 0x3d3180c72f0) = -1 EAGAIN (Resource temporarily unavailable)
timerfd_settime(10, TFD_TIMER_ABSTIME, {it_interval={0, 0}, it_value={251852, 553075000}}, NULL) = 0
ioctl(11, USBDEVFS_SUBMITURB, 0x48f28e2e0) = 0
poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLOUT}], 4, 60000) = 1 ([{fd=11, revents=POLLOUT}])
ioctl(11, USBDEVFS_REAPURBNDELAY, 0x3d3180c72c0) = 0
timerfd_settime(10, 0, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
ioctl(11, USBDEVFS_REAPURBNDELAY, 0x3d3180c72c0) = -1 EAGAIN (Resource temporarily unavailable)
timerfd_settime(10, TFD_TIMER_ABSTIME, {it_interval={0, 0}, it_value={251852, 555049000}}, NULL) = 0
ioctl(11, USBDEVFS_SUBMITURB, 0x48f28e2e0) = 0
poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLOUT}], 4, 60000) = 1 ([{fd=11, revents=POLLOUT}])
ioctl(11, USBDEVFS_REAPURBNDELAY, 0x3d3180c72c0) = 0
timerfd_settime(10, 0, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
ioctl(11, USBDEVFS_REAPURBNDELAY, 0x3d3180c72c0) = -1 EAGAIN (Resource temporarily unavailable)
timerfd_settime(10, TFD_TIMER_ABSTIME, {it_interval={0, 0}, it_value={251852, 556984000}}, NULL) = 0
ioctl(11, USBDEVFS_SUBMITURB, 0x48f28e2e0) = 0
poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLOUT}], 4, 60000) = 1 ([{fd=11, revents=POLLOUT}])
ioctl(11, USBDEVFS_REAPURBNDELAY, 0x3d3180c72c0) = 0
timerfd_settime(10, 0, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
ioctl(11, USBDEVFS_REAPURBNDELAY, 0x3d3180c72c0) = -1 EAGAIN (Resource temporarily unavailable)
timerfd_settime(10, TFD_TIMER_ABSTIME, {it_interval={0, 0}, it_value={251852, 559104000}}, NULL) = 0
ioctl(11, USBDEVFS_SUBMITURB, 0x48f28e2e0) = 0
poll([{fd=6, events=POLLIN}, {fd=8, events=POLLIN}, {fd=10, events=POLLIN}, {fd=11, events=POLLOUT}], 4, 60000) = 1 ([{fd=11, revents=POLLOUT}])
ioctl(11, USBDEVFS_REAPURBNDELAY, 0x3d3180c72c0) = 0
timerfd_settime(10, 0, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
ioctl(11, USBDEVFS_REAPURBNDELAY, 0x3d3180c72c0) = -1 EAGAIN (Resource temporarily unavailable)

not an expert here but to me it looks like it has problems reading from the usb device. any clue?

so after looking on the trace more closely i discovered that the req. usb driver could not be loaded. after kernel recompile it looks like it works.
sorry seems to be entirely my fault.