So after upgrading my version of MODEP to the latest release for some reason I can no longer connect the PiSound app to my Pi4 running MODEP. I pressed the button 1 second to make it bluetooth discoverable and it blinks continuously for a few minutes. On my phone I click “Scan” and it’s never listed in the available devices. Anyone else seeing this?
You can try running sudo bluethootctl and see what’s going on when you enable discoverability. It should show something. Alternatively, you can enable discoverable mode by additionally executing discoverable on while running in bluetoothctl. Exit with quit command.
Let us know if you see any errors (or nothing at all) there.
So I finally got around to testing this. Here’s the output of bluetoothctl:
patch@patchbox:~ $ sudo bluetoothctl
Agent registered
[CHG] Controller DC:A6:32:30:33:32 Discoverable: yes
[NEW] Device 58:24:29:89:A8:DE Pixel 5
[CHG] Device 58:24:29:89:A8:DE Connected: no
[CHG] Device 58:24:29:89:A8:DE Connected: yes
[CHG] Device 58:24:29:89:A8:DE Connected: no
So the “NEW” is when I tried to connect to the RPi with my Pixel 5. Then almost immediately it changed to “Connected: no”. I tried connecting again and it showed “Connected: yes” with an almost immediate change to “Connected: no”.
I will also post the screenshot of my phone.
On other test here. In this case I’m trying to pair my Dell Latitude 7210 tablet to the RPi:
patch@patchbox:~ $ sudo bluetoothctl
Agent registered
[CHG] Controller DC:A6:32:30:33:32 Discoverable: yes
[CHG] Device F8:5E:A0:0F:71:EC Connected: yes
[CHG] Device F8:5E:A0:0F:71:EC Connected: no
[CHG] Device F8:5E:A0:0F:71:EC Connected: yes
[CHG] Device F8:5E:A0:0F:71:EC Connected: no
[bluetooth]#
Same result, it connects but then immediately disconnects.
Does dmesg report any errors soon after the connection attempts?
@Giedrius after a connection attempt there are no new messages shown in dmesg. Including the output here if that helps.
[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 5.15.36-rt41-v7l+ (giedrius@giedrius-vb) (arm-linux-gnueabihf-gcc (Ubuntu/Linaro 7.5.0-3ubuntu1~18.04) 7.5.0, GNU ld (GNU Binutils for Ubuntu) 2.30) #1 SMP PREEMPT_RT Mon May 9 12:16:02 EEST 2022
[ 0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d
[ 0.000000] CPU: div instructions available: patching division code
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
[ 0.000000] OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.1
[ 0.000000] random: fast init done
[ 0.000000] Memory policy: Data cache writealloc
[ 0.000000] Reserved memory: created CMA memory pool at 0x000000002ac00000, size 64 MiB
[ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
[ 0.000000] Zone ranges:
[ 0.000000] DMA [mem 0x0000000000000000-0x000000002fffffff]
[ 0.000000] Normal empty
[ 0.000000] HighMem [mem 0x0000000030000000-0x00000000fbffffff]
[ 0.000000] Movable zone start for each node
[ 0.000000] Early memory node ranges
[ 0.000000] node 0: [mem 0x0000000000000000-0x000000003b3fffff]
[ 0.000000] node 0: [mem 0x0000000040000000-0x00000000fbffffff]
[ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000000fbffffff]
[ 0.000000] percpu: Embedded 16 pages/cpu s34456 r8192 d22888 u65536
[ 0.000000] pcpu-alloc: s34456 r8192 d22888 u65536 alloc=16*4096
[ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1011200
[ 0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=1280 bcm2708_fb.fbheight=720 bcm2708_fb.fbswap=1 smsc95xx.macaddr=DC:A6:32:30:33:2F vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 console=ttyS0,115200 console=tty1 root=PARTUUID=724b57b8-02 rootfstype=ext4 fsck.repair=yes rootwait
[ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
[ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.000000] software IO TLB: mapped [mem 0x0000000024c80000-0x0000000028c80000] (64MB)
[ 0.000000] Memory: 3867936K/4050944K available (10240K kernel code, 1385K rwdata, 3248K rodata, 2048K init, 593K bss, 117472K reserved, 65536K cma-reserved, 3264512K highmem)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[ 0.000000] ftrace: allocating 34999 entries in 103 pages
[ 0.000000] ftrace: allocated 103 pages with 5 groups
[ 0.000000] trace event string verifier disabled
[ 0.000000] rcu: Preemptible hierarchical RCU implementation.
[ 0.000000] rcu: RCU priority boosting: priority 1 delay 500 ms.
[ 0.000000] rcu: RCU_SOFTIRQ processing moved to rcuc kthreads.
[ 0.000000] No expedited grace period (rcu_normal_after_boot).
[ 0.000000] Trampoline variant of Tasks RCU enabled.
[ 0.000000] Rude variant of Tasks RCU enabled.
[ 0.000000] Tracing variant of Tasks RCU enabled.
[ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
[ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[ 0.000000] GIC: Using split EOI/Deactivate mode
[ 0.000000] random: random: get_random_bytes called from start_kernel+0x588/0x758 with crng_init=1
[ 0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys).
[ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
[ 0.000000] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
[ 0.000015] Switching to timer-based delay loop, resolution 18ns
[ 0.000309] Console: colour dummy device 80x30
[ 0.000330] printk: console [tty1] enabled
[ 0.000369] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=54000)
[ 0.000385] pid_max: default: 32768 minimum: 301
[ 0.000513] LSM: Security Framework initializing
[ 0.000741] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[ 0.000761] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[ 0.002252] CPU: Testing write buffer coherency: ok
[ 0.002309] CPU0: Spectre BHB: using loop workaround
[ 0.002740] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[ 0.004496] Setting up static identity map for 0x200000 - 0x20003c
[ 0.004715] rcu: Hierarchical SRCU implementation.
[ 0.006679] smp: Bringing up secondary CPUs ...
[ 0.008452] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[ 0.008467] CPU1: Spectre BHB: using loop workaround
[ 0.010328] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[ 0.010343] CPU2: Spectre BHB: using loop workaround
[ 0.012125] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[ 0.012141] CPU3: Spectre BHB: using loop workaround
[ 0.012338] smp: Brought up 1 node, 4 CPUs
[ 0.012351] SMP: Total of 4 processors activated (432.00 BogoMIPS).
[ 0.012362] CPU: All CPU(s) started in HYP mode.
[ 0.012367] CPU: Virtualization extensions available.
[ 0.013170] devtmpfs: initialized
[ 0.065392] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0
[ 0.066036] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
[ 0.066062] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[ 0.068086] pinctrl core: initialized pinctrl subsystem
[ 0.070360] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[ 0.073639] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[ 0.077607] audit: initializing netlink subsys (disabled)
[ 0.077878] audit: type=2000 audit(0.076:1): state=initialized audit_enabled=0 res=1
[ 0.079749] thermal_sys: Registered thermal governor 'step_wise'
[ 0.080828] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[ 0.080839] hw-breakpoint: maximum watchpoint size is 8 bytes.
[ 0.081272] Serial: AMBA PL011 UART driver
[ 0.096146] bcm2835-mbox fe00b880.mailbox: mailbox enabled
[ 0.121748] raspberrypi-firmware soc:firmware: Attached to firmware from 2022-10-26T11:09:05, variant start
[ 0.122759] raspberrypi-firmware soc:firmware: Firmware hash is c72ad6b26ff40c91ef776b847436094ee63fabee
[ 0.311273] Kprobes globally optimized
[ 0.318824] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1
[ 0.327255] vgaarb: loaded
[ 0.328272] SCSI subsystem initialized
[ 0.328939] usbcore: registered new interface driver usbfs
[ 0.329128] usbcore: registered new interface driver hub
[ 0.329250] usbcore: registered new device driver usb
[ 0.329649] usb_phy_generic phy: supply vcc not found, using dummy regulator
[ 0.330557] pps_core: LinuxPPS API ver. 1 registered
[ 0.330564] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[ 0.330603] PTP clock support registered
[ 0.333990] clocksource: Switched to clocksource arch_sys_counter
[ 0.489961] VFS: Disk quotas dquot_6.6.0
[ 0.490058] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[ 0.490351] FS-Cache: Loaded
[ 0.490735] CacheFiles: Loaded
[ 0.517406] NET: Registered PF_INET protocol family
[ 0.517692] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
[ 0.519488] tcp_listen_portaddr_hash hash table entries: 512 (order: 1, 12288 bytes, linear)
[ 0.519523] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
[ 0.519610] TCP bind hash table entries: 8192 (order: 5, 163840 bytes, linear)
[ 0.519787] TCP: Hash tables configured (established 8192 bind 8192)
[ 0.520056] UDP hash table entries: 512 (order: 2, 24576 bytes, linear)
[ 0.520108] UDP-Lite hash table entries: 512 (order: 2, 24576 bytes, linear)
[ 0.520556] NET: Registered PF_UNIX/PF_LOCAL protocol family
[ 0.521600] RPC: Registered named UNIX socket transport module.
[ 0.521609] RPC: Registered udp transport module.
[ 0.521616] RPC: Registered tcp transport module.
[ 0.521623] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.521637] PCI: CLS 0 bytes, default 64
[ 0.523945] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available
[ 1.621411] Initialise system trusted keyrings
[ 1.621729] workingset: timestamp_bits=30 max_order=20 bucket_order=0
[ 1.663340] zbud: loaded
[ 1.669730] FS-Cache: Netfs 'nfs' registered for caching
[ 1.672330] NFS: Registering the id_resolver key type
[ 1.672363] Key type id_resolver registered
[ 1.672376] Key type id_legacy registered
[ 1.672902] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 1.672911] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[ 1.676908] Key type asymmetric registered
[ 1.676923] Asymmetric key parser 'x509' registered
[ 1.677126] bounce: pool size: 64 pages
[ 1.677222] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247)
[ 1.677445] io scheduler mq-deadline registered
[ 1.677455] io scheduler kyber registered
[ 1.688656] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
[ 1.688695] brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff]
[ 1.688798] brcm-pcie fd500000.pcie: MEM 0x0600000000..0x063fffffff -> 0x00c0000000
[ 1.688895] brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x00bfffffff -> 0x0400000000
[ 1.728119] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC)
[ 1.728894] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
[ 1.728913] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 1.728928] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff])
[ 1.729046] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
[ 1.729314] pci 0000:00:00.0: PME# supported from D0 D3hot
[ 1.733888] PCI: bus0: Fast back to back transfers disabled
[ 1.734524] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330
[ 1.734652] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
[ 1.735182] pci 0000:01:00.0: PME# supported from D0 D3cold
[ 1.739685] PCI: bus1: Fast back to back transfers disabled
[ 1.739749] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
[ 1.739782] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]
[ 1.739861] pci 0000:00:00.0: PCI bridge to [bus 01]
[ 1.739882] pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff]
[ 1.740499] pcieport 0000:00:00.0: enabling device (0140 -> 0142)
[ 1.741157] pcieport 0000:00:00.0: PME: Signaling with IRQ 58
[ 1.743339] bcm2708_fb soc:fb: FB found 1 display(s)
[ 1.769757] Console: switching to colour frame buffer device 160x45
[ 1.774240] bcm2708_fb soc:fb: Registered framebuffer for display 0, size 1280x720
[ 1.787818] iproc-rng200 fe104000.rng: hwrng registered
[ 1.788174] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[ 1.790432] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
[ 1.825228] brd: module loaded
[ 1.852099] loop: module loaded
[ 1.853335] Loading iSCSI transport class v2.0-870.
[ 1.866067] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000
[ 1.926173] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus
[ 1.929432] usbcore: registered new interface driver r8152
[ 1.929619] usbcore: registered new interface driver lan78xx
[ 1.929814] usbcore: registered new interface driver smsc95xx
[ 1.931569] xhci_hcd 0000:01:00.0: enabling device (0140 -> 0142)
[ 1.931729] xhci_hcd 0000:01:00.0: xHCI Host Controller
[ 1.931774] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
[ 1.937636] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x00003c0000000890
[ 1.939889] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.15
[ 1.939906] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 1.939917] usb usb1: Product: xHCI Host Controller
[ 1.939927] usb usb1: Manufacturer: Linux 5.15.36-rt41-v7l+ xhci-hcd
[ 1.939936] usb usb1: SerialNumber: 0000:01:00.0
[ 1.941828] hub 1-0:1.0: USB hub found
[ 1.941931] hub 1-0:1.0: 1 port detected
[ 1.943374] xhci_hcd 0000:01:00.0: xHCI Host Controller
[ 1.943397] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
[ 1.943416] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
[ 1.944127] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.15
[ 1.944142] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 1.944153] usb usb2: Product: xHCI Host Controller
[ 1.944162] usb usb2: Manufacturer: Linux 5.15.36-rt41-v7l+ xhci-hcd
[ 1.944171] usb usb2: SerialNumber: 0000:01:00.0
[ 1.946134] hub 2-0:1.0: USB hub found
[ 1.946217] hub 2-0:1.0: 4 ports detected
[ 1.949623] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[ 1.949937] dwc_otg: FIQ enabled
[ 1.949943] dwc_otg: NAK holdoff enabled
[ 1.949949] dwc_otg: FIQ split-transaction FSM enabled
[ 1.950026] Module dwc_common_port init
[ 1.950586] usbcore: registered new interface driver uas
[ 1.950826] usbcore: registered new interface driver usb-storage
[ 1.951286] mousedev: PS/2 mouse device common for all mice
[ 1.959157] sdhci: Secure Digital Host Controller Interface driver
[ 1.959166] sdhci: Copyright(c) Pierre Ossman
[ 1.959787] sdhci-pltfm: SDHCI platform and OF driver helper
[ 1.965674] hid: raw HID events driver (C) Jiri Kosina
[ 1.966061] usbcore: registered new interface driver usbhid
[ 1.966069] usbhid: USB HID core driver
[ 1.973687] Initializing XFRM netlink socket
[ 1.973750] NET: Registered PF_PACKET protocol family
[ 1.973937] Key type dns_resolver registered
[ 1.974346] Registering SWP/SWPB emulation handler
[ 1.975944] printk: console [tty1]: printing thread started
[ 1.976237] registered taskstats version 1
[ 1.976269] Loading compiled-in X.509 certificates
[ 1.977569] Key type ._fscrypt registered
[ 1.977584] Key type .fscrypt registered
[ 1.977596] Key type fscrypt-provisioning registered
[ 1.999893] uart-pl011 fe201000.serial: there is not valid maps for state default
[ 2.000296] uart-pl011 fe201000.serial: cts_event_workaround enabled
[ 2.000463] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 32, base_baud = 0) is a PL011 rev2
[ 2.013498] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[ 2.014286] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[ 2.016126] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0
[ 2.016140] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated
[ 2.048802] of_cfs_init
[ 2.049148] of_cfs_init: OK
[ 2.087947] mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA
[ 2.088438] Waiting for root device PARTUUID=724b57b8-02...
[ 2.154041] mmc1: new high speed SDIO card at address 0001
[ 2.191028] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[ 2.195030] mmc0: new ultra high speed DDR50 SDHC card at address aaaa
[ 2.196594] mmcblk0: mmc0:aaaa SM32G 29.7 GiB
[ 2.202848] mmcblk0: p1 p2
[ 2.204250] mmcblk0: mmc0:aaaa SM32G 29.7 GiB
[ 2.219250] EXT4-fs (mmcblk0p2): INFO: recovery required on readonly filesystem
[ 2.219263] EXT4-fs (mmcblk0p2): write access will be enabled during recovery
[ 2.319696] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21
[ 2.319718] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[ 2.319731] usb 1-1: Product: USB2.0 Hub
[ 2.324814] hub 1-1:1.0: USB hub found
[ 2.325136] hub 1-1:1.0: 4 ports detected
[ 2.610032] usb 1-1.4: new full-speed USB device number 3 using xhci_hcd
[ 2.696664] usb 1-1.4: New USB device found, idVendor=239a, idProduct=80f4, bcdDevice= 1.00
[ 2.696687] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 2.696700] usb 1-1.4: Product: Pico
[ 2.696710] usb 1-1.4: Manufacturer: Raspberry Pi
[ 2.696719] usb 1-1.4: SerialNumber: E6614103E7750F37
[ 2.723960] usb-storage 1-1.4:1.2: USB Mass Storage device detected
[ 2.726862] scsi host0: usb-storage 1-1.4:1.2
[ 2.739091] input: Raspberry Pi Pico Keyboard as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4:1.3/0003:239A:80F4.0001/input/input0
[ 2.794655] input: Raspberry Pi Pico Mouse as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4:1.3/0003:239A:80F4.0001/input/input1
[ 2.795897] hid-generic 0003:239A:80F4.0001: input,hidraw0: USB HID v1.11 Keyboard [Raspberry Pi Pico] on usb-0000:01:00.0-1.4/input3
[ 3.058826] EXT4-fs (mmcblk0p2): orphan cleanup on readonly fs
[ 3.184964] EXT4-fs (mmcblk0p2): 147 orphan inodes deleted
[ 3.185054] EXT4-fs (mmcblk0p2): recovery complete
[ 3.281495] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none.
[ 3.281620] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[ 3.282785] devtmpfs: mounted
[ 3.292518] Freeing unused kernel image (initmem) memory: 2048K
[ 3.292847] Run /sbin/init as init process
[ 3.292854] with arguments:
[ 3.292860] /sbin/init
[ 3.292865] with environment:
[ 3.292871] HOME=/
[ 3.292877] TERM=linux
[ 3.663270] systemd[1]: System time before build time, advancing clock.
[ 3.752204] scsi 0:0:0:0: Direct-Access Raspberr Pico 1.0 PQ: 0 ANSI: 2
[ 3.755839] sd 0:0:0:0: [sda] 2049 512-byte logical blocks: (1.05 MB/1.00 MiB)
[ 3.759995] sd 0:0:0:0: [sda] Write Protect is on
[ 3.760014] sd 0:0:0:0: [sda] Mode Sense: 03 00 80 00
[ 3.762459] sd 0:0:0:0: [sda] No Caching mode page found
[ 3.762474] sd 0:0:0:0: [sda] Assuming drive cache: write through
[ 3.780039] sda: sda1
[ 3.786456] sd 0:0:0:0: [sda] Attached SCSI removable disk
[ 3.883926] NET: Registered PF_INET6 protocol family
[ 3.886434] Segment Routing with IPv6
[ 3.886484] In-situ OAM (IOAM) with IPv6
[ 3.980330] systemd[1]: systemd 247.3-7+rpi1+deb11u1 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +ZSTD +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=unified)
[ 3.981550] systemd[1]: Detected architecture arm.
[ 4.001096] systemd[1]: Set hostname to <patchbox>.
[ 5.153633] systemd[1]: /lib/systemd/system/plymouth-start.service:16: Unit configured to use KillMode=none. This is unsafe, as it disables systemd's process lifecycle management for the service. Please update your service to use a safer KillMode=, such as 'mixed' or 'control-group'. Support for KillMode=none is deprecated and will eventually be removed.
[ 5.468888] systemd[1]: Queued start job for default target Graphical Interface.
[ 5.471800] random: systemd: uninitialized urandom read (16 bytes read)
[ 5.477611] systemd[1]: Created slice system-getty.slice.
[ 5.483262] random: systemd: uninitialized urandom read (16 bytes read)
[ 5.485038] systemd[1]: Created slice system-modprobe.slice.
[ 5.491287] random: systemd: uninitialized urandom read (16 bytes read)
[ 5.492923] systemd[1]: Created slice system-systemd\x2dfsck.slice.
[ 5.500253] systemd[1]: Created slice User and Session Slice.
[ 5.505606] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[ 5.511809] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[ 5.517345] systemd[1]: Reached target Slices.
[ 5.522231] systemd[1]: Reached target Swap.
[ 5.528293] systemd[1]: Listening on Syslog Socket.
[ 5.533699] systemd[1]: Listening on fsck to fsckd communication Socket.
[ 5.538808] systemd[1]: Listening on initctl Compatibility Named Pipe.
[ 5.544951] systemd[1]: Listening on Journal Audit Socket.
[ 5.550609] systemd[1]: Listening on Journal Socket (/dev/log).
[ 5.556680] systemd[1]: Listening on Journal Socket.
[ 5.562495] systemd[1]: Listening on udev Control Socket.
[ 5.567941] systemd[1]: Listening on udev Kernel Socket.
[ 5.573526] systemd[1]: Condition check resulted in Huge Pages File System being skipped.
[ 5.581729] systemd[1]: Mounting POSIX Message Queue File System...
[ 5.595442] systemd[1]: Mounting RPC Pipe File System...
[ 5.609676] systemd[1]: Mounting Kernel Debug File System...
[ 5.627418] systemd[1]: Mounting Kernel Trace File System...
[ 5.632942] systemd[1]: Condition check resulted in Kernel Module supporting RPCSEC_GSS being skipped.
[ 5.644142] systemd[1]: Starting Restore / save the current clock...
[ 5.658636] systemd[1]: Starting Set the console keyboard layout...
[ 5.676905] systemd[1]: Starting Create list of static device nodes for the current kernel...
[ 5.695753] systemd[1]: Starting Load Kernel Module configfs...
[ 5.712872] systemd[1]: Starting Load Kernel Module drm...
[ 5.729817] systemd[1]: Starting Load Kernel Module fuse...
[ 5.739581] systemd[1]: Condition check resulted in Set Up Additional Binary Formats being skipped.
[ 5.758150] systemd[1]: Starting File System Check on Root Device...
[ 5.795069] systemd[1]: Starting Journal Service...
[ 5.837293] fuse: init (API version 7.34)
[ 5.841529] systemd[1]: Starting Load Kernel Modules...
[ 5.901515] systemd[1]: Starting Coldplug All udev Devices...
[ 5.935415] systemd[1]: Mounted POSIX Message Queue File System.
[ 5.944144] systemd[1]: Mounted RPC Pipe File System.
[ 5.952035] systemd[1]: Mounted Kernel Debug File System.
[ 5.960819] systemd[1]: Mounted Kernel Trace File System.
[ 5.979284] systemd[1]: Finished Restore / save the current clock.
[ 5.988804] systemd[1]: Finished Create list of static device nodes for the current kernel.
[ 6.001270] systemd[1]: modprobe@configfs.service: Succeeded.
[ 6.009197] systemd[1]: Finished Load Kernel Module configfs.
[ 6.017790] systemd[1]: modprobe@fuse.service: Succeeded.
[ 6.020604] systemd[1]: Finished Load Kernel Module fuse.
[ 6.047945] systemd[1]: Finished Load Kernel Modules.
[ 6.061012] systemd[1]: modprobe@drm.service: Succeeded.
[ 6.063314] systemd[1]: Finished Load Kernel Module drm.
[ 6.083643] systemd[1]: Mounting FUSE Control File System...
[ 6.125626] systemd[1]: Mounting Kernel Configuration File System...
[ 6.173958] systemd[1]: Started File System Check Daemon to report status.
[ 6.218265] systemd[1]: Starting Apply Kernel Variables...
[ 6.242786] systemd[1]: Finished File System Check on Root Device.
[ 6.252832] systemd[1]: Mounted FUSE Control File System.
[ 6.261749] systemd[1]: Finished Set the console keyboard layout.
[ 6.267929] systemd[1]: Mounted Kernel Configuration File System.
[ 6.283703] systemd[1]: Starting Remount Root and Kernel File Systems...
[ 6.304886] systemd[1]: Finished Apply Kernel Variables.
[ 6.441944] systemd[1]: Started Journal Service.
[ 6.543693] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null). Quota mode: none.
[ 6.626606] systemd-journald[162]: Received client request to flush runtime journal.
[ 6.666120] systemd-journald[162]: File /var/log/journal/fcc9f3a539bb4c99b7cb810aa7ed8965/system.journal corrupted or uncleanly shut down, renaming and replacing.
[ 7.725059] random: crng init done
[ 7.725072] random: 7 urandom warning(s) missed due to ratelimiting
[ 8.114307] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000
[ 8.120522] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000
[ 8.121518] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000
[ 8.122434] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000
[ 8.357305] mc: Linux media interface: v0.10
[ 8.361351] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[ 8.367606] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[ 8.367626] [vc_sm_connected_init]: start
[ 8.372963] [vc_sm_connected_init]: installed successfully
[ 8.793183] videodev: Linux video capture interface: v2.00
[ 8.862792] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
[ 8.887264] bcm2835_audio bcm2835_audio: card created with 4 channels
[ 8.915310] bcm2835_audio bcm2835_audio: card created with 4 channels
[ 9.229664] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[ 9.424893] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
[ 9.436185] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13
[ 9.441309] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14
[ 9.445287] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15
[ 9.452714] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16
[ 9.452746] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
[ 9.452765] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
[ 9.452783] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
[ 9.452805] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
[ 9.458898] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
[ 9.473703] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video20
[ 9.477384] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video21
[ 9.481446] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video22
[ 9.483820] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video23
[ 9.483861] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
[ 9.483881] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
[ 9.483898] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
[ 9.483915] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
[ 9.484674] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp
[ 9.493776] pisound: Searching for spi device...
[ 9.493793] pisound: Found!
[ 9.551128] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
[ 9.571655] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
[ 9.571702] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
[ 9.577686] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
[ 9.577746] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
[ 9.606533] pisound: Detected Pisound card:
[ 9.606546] pisound: Serial: PS-0N3JHP7
[ 9.606553] pisound: Firmware Version: 1.03
[ 9.606561] pisound: Hardware Version: 1.1
[ 9.606567] pisound: Id: 1e9315385832313338153531
[ 9.619915] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
[ 9.619962] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
[ 9.623950] bcm2835-codec bcm2835-codec: Device registered as /dev/video18
[ 9.624039] bcm2835-codec bcm2835-codec: Loaded V4L2 image_fx
[ 9.632610] bcm2835-codec bcm2835-codec: Device registered as /dev/video31
[ 9.633309] bcm2835-codec bcm2835-codec: Loaded V4L2 encode_image
[ 10.634525] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[ 11.008354] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[ 11.214873] cdc_acm 1-1.4:1.0: ttyACM0: USB ACM device
[ 11.215327] usbcore: registered new interface driver cdc_acm
[ 11.215339] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[ 11.248265] cfg80211: loaded regulatory.db is malformed or signature is missing/invalid
[ 11.432646] sd 0:0:0:0: Attached scsi generic sg0 type 0
[ 11.707496] usbcore: registered new interface driver snd-usb-audio
[ 11.795421] brcmfmac: F1 signature read @0x18000000=0x15264345
[ 11.815518] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[ 11.819336] usbcore: registered new interface driver brcmfmac
[ 12.372833] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[ 12.409395] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60
[ 14.314292] uart-pl011 fe201000.serial: no DMA platform data
[ 14.715205] 8021q: 802.1Q VLAN Support v1.8
[ 14.765629] Adding 102396k swap on /var/swap. Priority:-2 extents:1 across:102396k SSFS
[ 15.264718] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
[ 15.493344] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay)
[ 15.494820] bcmgenet fd580000.ethernet eth0: Link is Down
[ 19.077640] systemd-journald[162]: File /var/log/journal/fcc9f3a539bb4c99b7cb810aa7ed8965/user-1000.journal corrupted or uncleanly shut down, renaming and replacing.
[ 21.155487] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 23.592425] Bluetooth: Core ver 2.22
[ 23.595290] NET: Registered PF_BLUETOOTH protocol family
[ 23.595319] Bluetooth: HCI device and connection manager initialized
[ 23.595361] Bluetooth: HCI socket layer initialized
[ 23.595377] Bluetooth: L2CAP socket layer initialized
[ 23.595445] Bluetooth: SCO socket layer initialized
[ 23.624823] Bluetooth: HCI UART driver ver 2.3
[ 23.624834] Bluetooth: HCI UART protocol H4 registered
[ 23.627271] Bluetooth: HCI UART protocol Three-wire (H5) registered
[ 23.631948] Bluetooth: HCI UART protocol Broadcom registered
[ 24.213957] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[ 24.214002] Bluetooth: BNEP filters: protocol multicast
[ 24.214020] Bluetooth: BNEP socket layer initialized
[ 24.245041] NET: Registered PF_ALG protocol family
[ 24.295632] cryptd: max_cpu_qlen set to 1000
[ 24.640324] Bluetooth: RFCOMM TTY layer initialized
[ 24.640384] Bluetooth: RFCOMM socket layer initialized
[ 24.640553] Bluetooth: RFCOMM ver 1.11
[ 32.229070] cam-dummy-reg: disabling
What output do you get from bluetoothd --version?
Try checking out the bluetooth logs:
journalctl -u bluetooth -f
Also, try adding --experimental flag to bluetooth service as described here: Install Bluez — Bluez documentation (reboot after modifying the .service file)
@Giedrius the output of bluetoothd --version is: 5.5
And here’s the output of the journalctl command:
– Journal begins at Tue 2022-05-17 08:32:17 CDT. –
Dec 01 19:58:49 patchbox bluetoothd[871]: Bluetooth daemon 5.55
Dec 01 19:58:49 patchbox systemd[1]: Started Bluetooth service.
Dec 01 19:58:49 patchbox bluetoothd[871]: Starting SDP server
Dec 01 19:58:49 patchbox bluetoothd[871]: Bluetooth management interface 1.21 initialized
Dec 01 19:58:49 patchbox bluetoothd[871]: profiles/sap/server.c:sap_server_register() Sap driver initialization failed.
Dec 01 19:58:49 patchbox bluetoothd[871]: sap-server: Operation not permitted (1)
Dec 01 19:58:49 patchbox bluetoothd[871]: Endpoint registered: sender=:1.27 path=/MediaEndpoint/A2DPSink/sbc
Dec 01 19:58:49 patchbox bluetoothd[871]: Endpoint registered: sender=:1.27 path=/MediaEndpoint/A2DPSource/sbc
Dec 01 19:58:49 patchbox bluetoothd[871]: src/profile.c:ext_start_servers() RFCOMM server failed for Headset unit: rfcomm_bind: Address already in use (98)
Dec 01 19:58:49 patchbox bluetoothd[871]: Failed to set privacy: Rejected (0x0b)
And…of course…I put the Pi in discoverable mode by pressing the button for one second and the app connects this time without issue. However, I decided to power cycle the Pi and when it came back up I was unable to connect via the app. I kept getting a “Connection error” in the app at the bottom of the screen. Running the journalctl command again produced the following:
– Journal begins at Tue 2022-05-17 08:32:17 CDT. –
Dec 01 21:19:54 patchbox bluetoothd[857]: Bluetooth daemon 5.55
Dec 01 21:19:54 patchbox systemd[1]: Started Bluetooth service.
Dec 01 21:19:54 patchbox bluetoothd[857]: Starting SDP server
Dec 01 21:19:54 patchbox bluetoothd[857]: Bluetooth management interface 1.21 initialized
Dec 01 21:19:54 patchbox bluetoothd[857]: profiles/sap/server.c:sap_server_register() Sap driver initialization failed.
Dec 01 21:19:54 patchbox bluetoothd[857]: sap-server: Operation not permitted (1)
Dec 01 21:19:54 patchbox bluetoothd[857]: Endpoint registered: sender=:1.24 path=/MediaEndpoint/A2DPSink/sbc
Dec 01 21:19:54 patchbox bluetoothd[857]: Endpoint registered: sender=:1.24 path=/MediaEndpoint/A2DPSource/sbc
Dec 01 21:19:54 patchbox bluetoothd[857]: src/profile.c:ext_start_servers() RFCOMM server failed for Pisound Control Service: rfcomm_bind: Address already in use (98)
Dec 01 21:19:54 patchbox bluetoothd[857]: Failed to set privacy: Rejected (0x0b)
I then added the --experimental flag as suggested but still cannot connect. The output of journalctl after adding the --experimental flag:
– Journal begins at Tue 2022-05-17 08:32:17 CDT. –
Dec 01 21:24:32 patchbox systemd[1]: Starting Bluetooth service…
Dec 01 21:24:33 patchbox bluetoothd[881]: Bluetooth daemon 5.55
Dec 01 21:24:33 patchbox systemd[1]: Started Bluetooth service.
Dec 01 21:24:33 patchbox bluetoothd[881]: Starting SDP server
Dec 01 21:24:33 patchbox bluetoothd[881]: Bluetooth management interface 1.21 initialized
Dec 01 21:24:33 patchbox bluetoothd[881]: Endpoint registered: sender=:1.25 path=/MediaEndpoint/A2DPSink/sbc
Dec 01 21:24:33 patchbox bluetoothd[881]: Endpoint registered: sender=:1.25 path=/MediaEndpoint/A2DPSource/sbc
Dec 01 21:24:33 patchbox bluetoothd[881]: Failed to set privacy: Rejected (0x0b)
Dec 01 21:24:34 patchbox bluetoothd[881]: src/profile.c:ext_start_servers() RFCOMM server failed for Pisound Control Service: rfcomm_bind: Address already in use (98)
– Boot 56c6a82b9ae143e9b37d49e087f3c887 –
Dec 01 21:30:02 patchbox systemd[1]: bluetooth.service: Current command vanished from the unit file, execution of the command list won’t be resumed.
I even uninstalled/reinstalled the app. Still get “Connection error” when trying to connect in the app to the Pi
This part seems to be important. Could you please add -d option to bluetoothd.service, so it produces more debug output, and reproduce such log? It should help us to get to the bottom of the issue.
gives me:
b 09 09:20:57 galmplaat bluetoothd[1008]: Bluetooth daemon 5.55
Feb 09 09:20:57 galmplaat systemd[1]: Started Bluetooth service.
Feb 09 09:20:57 galmplaat bluetoothd[1008]: Starting SDP server
Feb 09 09:20:57 galmplaat bluetoothd[1008]: Bluetooth management interface 1.21 initialized
Feb 09 09:20:58 galmplaat bluetoothd[1008]: profiles/sap/server.c:sap_server_register() Sap driver initialization failed.
Feb 09 09:20:58 galmplaat bluetoothd[1008]: sap-server: Operation not permitted (1)
Feb 09 09:20:58 galmplaat bluetoothd[1008]: Endpoint registered: sender=:1.23 path=/MediaEndpoint/A2DPSink/sbc
Feb 09 09:20:58 galmplaat bluetoothd[1008]: Endpoint registered: sender=:1.23 path=/MediaEndpoint/A2DPSource/sbc
Feb 09 09:20:58 galmplaat bluetoothd[1008]: Failed to set privacy: Rejected (0x0b)
Feb 09 09:20:59 galmplaat bluetoothd[1008]: src/profile.c:ext_start_servers() RFCOMM server failed for Pisound Control Service: rfcomm_bind: Address already in use (98)
Same output after reboot, after uninstall/reinstall of pisound app…
I get one block of the above on each try to connect so there is some form of interaction…
I’m having the same problem, so I added -d to the line:
in
/etc/systemd/system/bluetooth.target.wants/bluetooth.service
and restarted the service using
sudo systemctl daemon-reload (because the file changed)
and
sudo service bluetooth restart
after that I get different output on trying to connect
Feb 09 09:36:13 galmplaat bluetoothd[3340]: src/adapter.c:connected_callback() hci0 device 48:01:C5:77:EE:DC connected eir_len 17
Feb 09 09:36:17 galmplaat bluetoothd[3340]: src/adapter.c:dev_disconnected() Device 48:01:C5:77:EE:DC disconnected, reason 2
Feb 09 09:36:17 galmplaat bluetoothd[3340]: src/adapter.c:adapter_remove_connection()
Feb 09 09:36:17 galmplaat bluetoothd[3340]: plugins/policy.c:disconnect_cb() reason 2
Feb 09 09:36:17 galmplaat bluetoothd[3340]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr 48:01:C5:77:EE:DC type 0 status 0xe
Feb 09 09:36:17 galmplaat bluetoothd[3340]: src/device.c:device_bonding_complete() bonding (nil) status 0x0e
Feb 09 09:36:17 galmplaat bluetoothd[3340]: src/device.c:device_bonding_failed() status 14
Feb 09 09:36:17 galmplaat bluetoothd[3340]: src/adapter.c:resume_discovery()
same output after reboot of the pi, and reinstall of the app.
I get one block of the above on each try to connect…
1 Like
Is there some other Bluetooth servers running on your Pi? Or are you using some Bluetooth devices like mouse or keyboard?
no it’s a virgin RPI4 8Gb with a fresh install of patchbox OS. I have not installed anything on it. I did do an apt-get update / apt-get upgrade.
I can see the pisound from the app, I just cannot connect to it…
I have another PiSound in my app list, but I don’t know if this is interfering with it? I don’t know how to remove it…
@Giedrius sounds like the exact same messages I was getting. I dropped the ball on following back up with you, big conversion project at work. I too was getting the “address in use” message. Sounds like @Kasper_Jordaens and I have the same setup too, RPI4 8GB.
What should we check for next?
I seem to experience the same problem. Error connecting via Bluetooth.
1 Like
I would also like to add to the conversation that I didn’t have any bluetooth connection issues on the previous version of MODEP so it’s probably not a hardware issue but rather a software one.
I’ve just released an updated pisound-ctl version 1.03-10 - it will select the RFCOMM channel automatically, it should sort out the ‘address in use’ error. Run:
sudo apt update
sudo apt install pisound-ctl
1 Like