cariboulabs / cariboulite

CaribouLite turns any 40-pin Raspberry-Pi into a Tx/Rx 6GHz SDR
1.1k stars 104 forks source link

SMI driver issue #97

Open great9 opened 1 year ago

great9 commented 1 year ago

RPI 3B+ Kernel 5.4.0-1081-raspi aarch64 ubuntu focal cariboulite driver from develop_R1 branch

The driver does something to the RPI's cpu frequency.

Mar 23 13:02:54 localhost kernel: [ 4826.959520] smi-stream-dev soc:smi_dev: smi-stream-dev: smi-stream dev removed
Mar 23 13:02:54 localhost kernel: [ 4826.999442] smi-stream-dev: smi_stream_dev_probe
Mar 23 13:02:54 localhost kernel: [ 4826.999552] smi-stream-dev: creating a device and registering it with sysfs
Mar 23 13:02:54 localhost kernel: [ 4826.999814] smi-stream-dev soc:smi_dev: initialised
Mar 23 13:02:54 localhost kernel: [ 4827.000308] smi-stream-dev soc:smi_dev: SMI device opened.
Mar 23 13:02:55 localhost kernel: [ 4827.079710] smi-stream-dev soc:smi_dev: Enterred reader thread
Mar 23 13:02:55 localhost kernel: [ 4827.079713] smi-stream-dev soc:smi_dev: Enterred writer thread
Mar 23 13:02:55 localhost kernel: [ 4827.079749] smi-stream-dev soc:smi_dev: Reading SMI settings to user.
Mar 23 13:02:55 localhost kernel: [ 4827.079767] smi-stream-dev soc:smi_dev: Reading native buffer size information
Mar 23 13:02:55 localhost kernel: [ 4827.080123] smi-stream-dev soc:smi_dev: Setting user's SMI settings.
Mar 23 13:02:55 localhost kernel: [ 4827.377733] smi-stream-dev soc:smi_dev: Set STREAMING_STATUS = 1, cur_addr = 4
Mar 23 13:02:55 localhost kernel: [ 4827.388024] smi-stream-dev soc:smi_dev: Set STREAMING_STATUS = 0, cur_addr = 4
Mar 23 13:02:55 localhost kernel: [ 4827.589564] smi-stream-dev soc:smi_dev: Set STREAMING_STATUS = 2, cur_addr = 12
Mar 23 13:02:55 localhost kernel: [ 4827.599818] smi-stream-dev soc:smi_dev: Set STREAMING_STATUS = 0, cur_addr = 12
Mar 23 13:02:55 localhost kernel: [ 4828.021439] smi-stream-dev soc:smi_dev: Set STREAMING_STATUS = 1, cur_addr = 4
Mar 23 13:02:55 localhost kernel: [ 4828.031688] smi-stream-dev soc:smi_dev: Set STREAMING_STATUS = 0, cur_addr = 4
Mar 23 13:02:56 localhost kernel: [ 4828.268716] smi-stream-dev soc:smi_dev: Set STREAMING_STATUS = 2, cur_addr = 12
Mar 23 13:02:56 localhost kernel: [ 4828.278963] smi-stream-dev soc:smi_dev: Set STREAMING_STATUS = 0, cur_addr = 12
Mar 23 13:02:58 localhost kernel: [ 4830.183892] smi-stream-dev soc:smi_dev: Set STREAMING_STATUS = 2, cur_addr = 12
Mar 23 13:02:58 localhost kernel: [ 4830.194185] smi-stream-dev soc:smi_dev: Set STREAMING_STATUS = 0, cur_addr = 12
Mar 23 13:03:06 localhost kernel: [ 4838.353849] smi-stream-dev soc:smi_dev: Set STREAMING_STATUS = 1, cur_addr = 4
Mar 23 13:03:06 localhost kernel: [ 4838.364125] smi-stream-dev soc:smi_dev: Set STREAMING_STATUS = 0, cur_addr = 4
Mar 23 13:03:10 localhost kernel: [ 4842.385296] smi-stream-dev soc:smi_dev: Set STREAMING_STATUS = 1, cur_addr = 4
Mar 23 13:04:22 localhost kernel: [ 4914.362335] smi-stream-dev soc:smi_dev: Set STREAMING_STATUS = 0, cur_addr = 4
Mar 23 13:04:34 localhost kernel: [ 4926.675108] smi-stream-dev soc:smi_dev: Set STREAMING_STATUS = 2, cur_addr = 12
Mar 23 13:04:35 localhost kernel: [ 4927.697482] smi-stream-dev soc:smi_dev: DMA bounce timed out
Mar 23 13:04:45 localhost kernel: [ 4937.549999] smi-bcm2835 3f600000.smi: read_sgl: dma slave preparation failed!
Mar 23 13:04:45 localhost kernel: [ 4937.638209] smi-bcm2835 3f600000.smi: read_sgl: SMICS_ACTIVE didn't fall
Mar 23 13:04:45 localhost kernel: [ 4937.719880] smi-bcm2835 3f600000.smi: sgl submit failed
Mar 23 13:04:45 localhost kernel: [ 4937.783818] smi-bcm2835 3f600000.smi: read_sgl: dma slave preparation failed!
Mar 23 13:04:45 localhost kernel: [ 4937.872502] smi-bcm2835 3f600000.smi: read_sgl: SMICS_ACTIVE didn't fall
Mar 23 13:04:45 localhost kernel: [ 4937.954114] smi-bcm2835 3f600000.smi: sgl submit failed
Mar 23 13:04:45 localhost kernel: [ 4938.017775] smi-bcm2835 3f600000.smi: read_sgl: dma slave preparation failed!
Mar 23 13:04:46 localhost kernel: [ 4938.106277] smi-bcm2835 3f600000.smi: read_sgl: SMICS_ACTIVE didn't fall
Mar 23 13:04:46 localhost kernel: [ 4938.187761] smi-bcm2835 3f600000.smi: sgl submit failed
Mar 23 13:04:46 localhost kernel: [ 4938.251388] smi-bcm2835 3f600000.smi: read_sgl: dma slave preparation failed!
Mar 23 13:04:46 localhost kernel: [ 4938.342181] smi-bcm2835 3f600000.smi: read_sgl: SMICS_ACTIVE didn't fall
Mar 23 13:04:46 localhost kernel: [ 4938.431968] smi-bcm2835 3f600000.smi: sgl submit failed
Mar 23 13:04:46 localhost kernel: [ 4938.505373] hwmon hwmon1: Failed to get throttled (-12)
Mar 23 13:04:46 localhost kernel: [ 4938.508192] smi-bcm2835 3f600000.smi: read_sgl: dma slave preparation failed!
Mar 23 13:04:46 localhost kernel: [ 4938.673070] smi-bcm2835 3f600000.smi: read_sgl: SMICS_ACTIVE didn't fall
Mar 23 13:04:46 localhost kernel: [ 4938.680205] smi-bcm2835 3f600000.smi: sgl submit failed
Mar 23 13:04:46 localhost kernel: [ 4938.687378] smi-bcm2835 3f600000.smi: read_sgl: dma slave preparation failed!
Mar 23 13:04:46 localhost kernel: [ 4938.697320] smi-bcm2835 3f600000.smi: read_sgl: SMICS_ACTIVE didn't fall
Mar 23 13:04:46 localhost kernel: [ 4938.705790] smi-bcm2835 3f600000.smi: sgl submit failed
Mar 23 13:04:46 localhost kernel: [ 4938.712987] smi-bcm2835 3f600000.smi: read_sgl: dma slave preparation failed!
Mar 23 13:04:46 localhost kernel: [ 4938.721503] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 184467440737095>
Mar 23 13:04:46 localhost kernel: [ 4938.723814] smi-bcm2835 3f600000.smi: read_sgl: SMICS_ACTIVE didn't fall
Mar 23 13:04:46 localhost kernel: [ 4938.735038] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
Mar 23 13:04:46 localhost kernel: [ 4938.743250] smi-bcm2835 3f600000.smi: sgl submit failed
Mar 23 13:04:46 localhost kernel: [ 4938.754686] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 184467440737095>
Mar 23 13:04:46 localhost kernel: [ 4938.761757] smi-bcm2835 3f600000.smi: read_sgl: dma slave preparation failed!
Mar 23 13:04:46 localhost kernel: [ 4938.774803] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
Mar 23 13:04:46 localhost kernel: [ 4938.784417] smi-bcm2835 3f600000.smi: read_sgl: SMICS_ACTIVE didn't fall
Mar 23 13:04:46 localhost kernel: [ 4938.803324] smi-bcm2835 3f600000.smi: sgl submit failed

after a few reboots it's still having issues:

Mar 23 17:28:16 localhost kernel: [  271.713430] raspberrypi_fw_set_rate: 105 callbacks suppressed
Mar 23 17:28:16 localhost kernel: [  271.713441] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
Mar 23 17:28:16 localhost kernel: [  271.736662] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 1844674407370955
1604 (-34)
Mar 23 17:28:16 localhost kernel: [  271.750898] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
Mar 23 17:28:16 localhost kernel: [  271.764223] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 1844674407370955
1604 (-34)
Mar 23 17:28:16 localhost kernel: [  271.778381] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -12
Mar 23 17:28:16 localhost kernel: [  271.802401] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 1844674407370955
1604 (-34)
maholli commented 1 year ago

Should be using main branch at this point. Better yet, use @konimaru 's fork for the latest fixes. See #82

great9 commented 1 year ago

Should be using main branch at this point. Better yet, use @konimaru 's fork for the latest fixes. See #82

I tried it. Now i can only start SoapySDRUtil -info once and afterwards I can't access the device anymore

[39850.893365] cariboulite_tes: page allocation failure: order:10, mode:0x40cc0(GFP_KERNEL|__GFP_COMP), nodemask=(null),cpuset=/,mems_allowed=0
[39850.893398] CPU: 0 PID: 47938 Comm: cariboulite_tes Tainted: G         C OE     5.4.0-1081-raspi #92-Ubuntu
[39850.893401] Hardware name: Raspberry Pi 3 Model B Rev 1.2 (DT)
[39850.893405] Call trace:
[39850.893417]  dump_backtrace+0x0/0x1e0
[39850.893421]  show_stack+0x28/0x38
[39850.893429]  dump_stack+0xd8/0x134
[39850.893437]  warn_alloc+0x110/0x180
[39850.893442]  __alloc_pages_slowpath+0xbd4/0xc00
[39850.893447]  __alloc_pages_nodemask+0x2b4/0x330
[39850.893452]  kmalloc_order+0x34/0x80
[39850.893458]  kmalloc_order_trace+0x40/0x120
[39850.893463]  __kmalloc+0x358/0x398
[39850.893469]  __kfifo_alloc+0x5c/0xa8
[39850.893483]  smi_stream_open+0x68/0x1c0 [smi_stream_dev]
[39850.893489]  chrdev_open+0xac/0x1a8
[39850.893499]  do_dentry_open+0x11c/0x390
[39850.893504]  vfs_open+0x3c/0x48
[39850.893509]  do_last+0x17c/0x8c8
[39850.893513]  path_openat+0x88/0x260
[39850.893518]  do_filp_open+0x88/0x110
[39850.893522]  do_sys_open+0x188/0x2f0
[39850.893527]  __arm64_sys_openat+0x30/0x40
[39850.893533]  el0_svc_common.constprop.0+0x84/0x230
[39850.893537]  el0_svc_handler+0x38/0xa0
[39850.893543]  el0_svc+0x10/0x140
[39850.893548] Mem-Info:
[39850.893565] active_anon:23387 inactive_anon:25338 isolated_anon:54
                active_file:80779 inactive_file:52886 isolated_file:96
                unevictable:4186 dirty:51 writeback:0 unstable:0
                slab_reclaimable:11513 slab_unreclaimable:11062
                mapped:14802 shmem:8478 pagetables:706 bounce:0
                free:14295 free_pcp:942 free_cma:1033
[39850.893578] Node 0 active_anon:93548kB inactive_anon:101352kB active_file:323116kB inactive_file:211544kB unevictable:16744kB isolated(anon):216kB isolated(file):384kB mapped:59208kB dirty:204kB writeback:0kB shmem:33912kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no
[39850.893593] DMA free:57180kB min:22528kB low:28160kB high:33792kB active_anon:93180kB inactive_anon:101472kB active_file:322260kB inactive_file:211208kB unevictable:16844kB writepending:252kB present:970752kB managed:927896kB mlocked:16876kB kernel_stack:3540kB pagetables:2824kB bounce:0kB free_pcp:3772kB local_pcp:1432kB free_cma:4132kB
[39850.893598] lowmem_reserve[]: 0 0 0 0
[39850.893613] DMA: 1311*4kB (UMEC) 740*8kB (UMEC) 252*16kB (UMEC) 290*32kB (UMEC) 139*64kB (UMEC) 52*128kB (UMEC) 21*256kB (UMEC) 7*512kB (UMC) 4*1024kB (MC) 2*2048kB (M) 0*4096kB = 57180kB
[39850.893675] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
[39850.893682] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=32768kB
[39850.893689] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
[39850.893695] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=64kB
[39850.893701] 143898 total pagecache pages
[39850.893713] 208 pages in swap cache
[39850.893719] Swap cache stats: add 3300, delete 3092, find 596/764
[39850.893725] Free swap  = 2085116kB
[39850.893730] Total swap = 2097148kB
[39850.893735] 242688 pages RAM
[39850.893740] 0 pages HighMem/MovableOnly
[39850.893751] 10714 pages reserved
[39850.893756] 16384 pages cma reserved
[39850.893765] smi-stream-dev: error rx kfifo_alloc
K7MDL2 commented 1 year ago

Can you get it running on a standard RPi OS like the current bullesye?

I have things working here for the most part, on a Pi4B with standard 64bit bullseye installed. Today I transmitted on the air and received a SSB signal on 1296.1MHz with a line-of-sight station and transmitted back a carrier with the test app. Have not tried transmitting voice yet.

I would eliminate the variables, get it working, then get adventurous.

great9 commented 1 year ago

Can you get it running on a standard RPi OS like the current bullesye?

No spare SD cards and the rpi is running a service that must not be offline for too long.