I had some time to test a bit more and tried to catcth some logs. I've not been able to reproduce the exact same scenario as described above (yet).
One thing I did notice is that:
if a phone unpairs from moOde it can't pair back again until it's manually deleted from the BT trust list. Is this the intended behaviour?
This will cause an issue since the moOde UI is not accessible for anyone in this training facility.
I'm not familiar with this application so I'm not sure if any of the logging helps.
DCERPC_NCA_S_OP_RNG_ERROR - Machine is not connected to Internet, seems maybe related?
Please remove executable permission bits. Unknown vendor codec.
Couldn't open ALSA mixer: Mixer element not found
/th-cmd --socket /var/run/thd.socket --passfd --udev' failed
One thing I did notice is that:
if a phone unpairs from moOde it can't pair back again until it's manually deleted from the BT trust list. Is this the intended behaviour?
This will cause an issue since the moOde UI is not accessible for anyone in this training facility.
I'm not familiar with this application so I'm not sure if any of the logging helps.
DCERPC_NCA_S_OP_RNG_ERROR - Machine is not connected to Internet, seems maybe related?
Code:
Apr 7 11:59:46 moode winbindd[516]: [2024/04/07 11:59:46.782060, 0] ../../source3/rpc_server/rpc_ncacn_np.c:454(rpcint_dispatch)
Apr 7 11:59:46 moode winbindd[516]: rpcint_dispatch: DCE/RPC fault in call lsarpc:32 - DCERPC_NCA_S_OP_RNG_ERROR
Apr 7 11:59:46 moode winbindd[516]: [2024/04/07 11:59:46.783622, 0] ../../source3/rpc_server/rpc_ncacn_np.c:454(rpcint_dispatch)
Apr 7 11:59:46 moode winbindd[516]: rpcint_dispatch: DCE/RPC fault in call lsarpc:32 - DCERPC_NCA_S_OP_RNG_ERROR
Apr 7 12:00:03 moode systemd[1]: Starting system activity accounting tool...
Apr 7 12:00:03 moode systemd[1]: sysstat-collect.service: Succeeded.
Apr 7 12:00:03 moode systemd[1]: Finished system activity accounting tool.
Apr 7 12:04:46 moode winbindd[516]: [2024/04/07 12:04:46.787448, 0] ../../source3/rpc_server/rpc_ncacn_np.c:454(rpcint_dispatch)
Apr 7 12:04:46 moode winbindd[516]: rpcint_dispatch: DCE/RPC fault in call lsarpc:32 - DCERPC_NCA_S_OP_RNG_ERROR
Apr 7 12:04:46 moode winbindd[516]: [2024/04/07 12:04:46.788879, 0] ../../source3/rpc_server/rpc_ncacn_np.c:454(rpcint_dispatch)
Apr 7 12:04:46 moode winbindd[516]: rpcint_dispatch: DCE/RPC fault in call lsarpc:32 - DCERPC_NCA_S_OP_RNG_ERROR
Apr 7 12:09:46 moode winbindd[516]: [2024/04/07 12:09:46.791393, 0] ../../source3/rpc_server/rpc_ncacn_np.c:454(rpcint_dispatch)
Apr 7 12:09:46 moode winbindd[516]: rpcint_dispatch: DCE/RPC fault in call lsarpc:32 - DCERPC_NCA_S_OP_RNG_ERROR
Apr 7 12:09:46 moode winbindd[516]: [2024/04/07 12:09:46.793202, 0] ../../source3/rpc_server/rpc_ncacn_np.c:454(rpcint_dispatch)
Apr 7 12:09:46 moode winbindd[516]: rpcint_dispatch: DCE/RPC fault in call lsarpc:32 - DCERPC_NCA_S_OP_RNG_ERROR
Apr 7 12:10:03 moode systemd[1]: Starting system activity accounting tool...
Apr 7 12:10:03 moode systemd[1]: sysstat-collect.service: Succeeded.
Apr 7 12:10:03 moode systemd[1]: Finished system activity accounting tool.
Apr 7 12:14:46 moode winbindd[516]: [2024/04/07 12:14:46.795272, 0] ../../source3/rpc_server/rpc_ncacn_np.c:454(rpcint_dispatch)
Apr 7 12:14:47 moode winbindd[516]: rpcint_dispatch: DCE/RPC fault in call lsarpc:32 - DCERPC_NCA_S_OP_RNG_ERROR
Apr 7 12:14:47 moode winbindd[516]: [2024/04/07 12:14:46.796712, 0] ../../source3/rpc_server/rpc_ncacn_np.c:454(rpcint_dispatch)
Apr 7 12:14:47 moode winbindd[516]: rpcint_dispatch: DCE/RPC fault in call lsarpc:32 - DCERPC_NCA_S_OP_RNG_ERROR
Apr 7 12:19:43 moode rngd[448]: stats: bits received from HRNG source: 620064
Apr 7 12:19:43 moode rngd[448]: stats: bits sent to kernel pool: 570240
Apr 7 12:19:43 moode rngd[448]: stats: entropy added to kernel pool: 570240
Apr 7 12:19:43 moode rngd[448]: stats: FIPS 140-2 successes: 31
Apr 7 12:19:43 moode rngd[448]: stats: FIPS 140-2 failures: 0
Apr 7 12:19:43 moode rngd[448]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Apr 7 12:19:43 moode rngd[448]: stats: FIPS 140-2(2001-10-10) Poker: 0
Apr 7 12:19:43 moode rngd[448]: stats: FIPS 140-2(2001-10-10) Runs: 0
Apr 7 12:19:43 moode rngd[448]: stats: FIPS 140-2(2001-10-10) Long run: 0
Apr 7 12:19:43 moode rngd[448]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Apr 7 12:19:43 moode rngd[448]: stats: HRNG source speed: (min=300.740; avg=819.994; max=925.696)Kibits/s
Apr 7 12:19:43 moode rngd[448]: stats: FIPS tests speed: (min=22.952; avg=40.457; max=51.550)Mibits/s
Apr 7 12:19:43 moode rngd[448]: stats: Lowest ready-buffers level: 2
Apr 7 12:19:43 moode rngd[448]: stats: Entropy starvations: 0
Apr 7 12:19:43 moode rngd[448]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Apr 7 12:19:46 moode winbindd[516]: [2024/04/07 12:19:46.799776, 0] ../../source3/rpc_server/rpc_ncacn_np.c:454(rpcint_dispatch)
Apr 7 12:19:46 moode winbindd[516]: rpcint_dispatch: DCE/RPC fault in call lsarpc:32 - DCERPC_NCA_S_OP_RNG_ERROR
Apr 7 12:19:46 moode winbindd[516]: [2024/04/07 12:19:46.801214, 0] ../../source3/rpc_server/rpc_ncacn_np.c:454(rpcint_dispatch)
Apr 7 12:19:46 moode winbindd[516]: rpcint_dispatch: DCE/RPC fault in call lsarpc:32 - DCERPC_NCA_S_OP_RNG_ERROR
Apr 7 12:20:03 moode systemd[1]: Starting system activity accounting tool... Please remove executable permission bits. Unknown vendor codec.
Code:
Apr 7 17:08:26 moode bluealsa[479]: bluealsa: [479] D: bluez.c:1304: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved()
Apr 7 17:08:26 moode bluealsa[479]: bluealsa: [479] D: bluez.c:1304: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved()
Apr 7 17:08:26 moode bluealsa[479]: bluealsa: [479] D: bluez.c:1304: Signal: org.freedesktop.DBus.ObjectManager.InterfacesRemoved()
Apr 7 17:08:26 moode systemd[1]: Configuration file /etc/systemd/system/bluealsa-aplay@.service is marked executable. Please remove executable permission bits. Proceed
ing anyway.
Apr 7 17:08:26 moode systemd[1]: Configuration file /etc/systemd/system/bluealsa-aplay@.service is marked executable. Please remove executable permission bits. Proceed
ing anyway.
Apr 7 17:08:26 moode systemd[1]: Configuration file /etc/systemd/system/bluealsa-aplay@.service is marked executable. Please remove executable permission bits. Proceed
ing anyway.
Apr 7 17:08:29 moode bluealsa[479]: bluealsa: [479] D: bluez.c:1193: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
Apr 7 17:08:29 moode bluealsa[479]: bluealsa: [479] D: bluez.c:1289: Adding new Stream End-Point: D4:3A:2C:A4:4A:96: SBC
Apr 7 17:08:29 moode bluealsa[479]: bluealsa: [479] D: bluez.c:1193: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
Apr 7 17:08:29 moode bluealsa[479]: bluealsa: [479] D: bluez.c:1289: Adding new Stream End-Point: D4:3A:2C:A4:4A:96: AAC
Apr 7 17:08:29 moode bluealsa[479]: bluealsa: [479] D: bluez.c:1193: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
Apr 7 17:08:29 moode bluealsa[479]: bluealsa: [479] D: bluez.c:1289: Adding new Stream End-Point: D4:3A:2C:A4:4A:96: aptX
Apr 7 17:08:29 moode bluealsa[479]: bluealsa: [479] D: bluez.c:1193: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
Apr 7 17:08:29 moode bluealsa[479]: bluealsa: [479] D: bluez.c:1289: Adding new Stream End-Point: D4:3A:2C:A4:4A:96: LDAC
Apr 7 17:08:29 moode bluealsa[479]: bluealsa: [479] D: bluez.c:1193: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
Apr 7 17:08:29 moode bluealsa[479]: bluealsa: [479] D: a2dp.c:289: Unknown vendor codec [len=7]: e0000000010092
Apr 7 17:08:29 moode bluealsa[479]: bluealsa: [479] D: bluez.c:1289: Adding new Stream End-Point: D4:3A:2C:A4:4A:96: (null)
Apr 7 17:08:29 moode bluealsa[479]: bluealsa: [479] D: bluez.c:1193: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
Apr 7 17:08:29 moode blueaqCouldn't open ALSA mixer: Mixer element not found
Code:
Apr 7 17:08:38 moode bluealsa[479]: bluealsa: [479] D: ba-transport.c:448: Created BT socket duplicate: [15]: 18
Apr 7 17:08:38 moode bluealsa[479]: bluealsa: [25266] D: a2dp-aptx-hd.c:278: IO loop: START: a2dp_aptx_hd_dec_thread: A2DP Sink (aptX HD)
Apr 7 17:08:38 moode bluealsa[479]: bluealsa: [479] D: ba-transport.c:1949: Created new IO thread [ba-a2dp-aptx-hd]: A2DP Sink (aptX HD)
Apr 7 17:08:38 moode bluealsa-aplay[25231]: bluealsa-aplay: [25233] D: aplay.c:649: Opening ALSA playback PCM: name=_audioout channels=2 rate=48000
Apr 7 17:08:38 moode bluealsa-aplay[25231]: bluealsa-aplay: [25233] D: aplay.c:664: Opening ALSA mixer: name=default elem=Master index=0
Apr 7 17:08:38 moode bluealsa-aplay[25231]: bluealsa-aplay: [25233] W: aplay.c:668: Couldn't open ALSA mixer: Mixer element not found
Apr 7 17:09:04 moode winbindd[539]: [2024/04/07 17:09:04.603930, 0] ../../source3/rpc_server/rpc_ncacn_np.c:454(rpcint_dispatch)
Apr 7 17:09:04 moode winbindd[539]: rpcint_dispatch: DCE/RPC fault in call lsarpc:32 - DCERPC_NCA_S_OP_RNG_ERROR
Apr 7 17:09:04 moode winbindd[539]: [2024/04/07 17:09:04.605560, 0] ../../source3/rpc_server/rpc_ncacn_np.c:454(rpcint_dispatch)
Apr 7 17:09:04 moode winbindd[539]: rpcint_dispatch: DCE/RPC fault in call lsarpc:32 - DCERPC_NCA_S_OP_RNG_ERROR
Apr 7 17:10:03 moode systemd[1]: Starting system activity accounting tool...
Apr 7 17:10:03 moode systemd[1]: sysstat-collect.service: Succeeded.
Apr 7 17:10:03 moode systemd[1]: Finished system activity accounting tool./th-cmd --socket /var/run/thd.socket --passfd --udev' failed
Code:
Apr 7 16:48:03 moode systemd[1]: Started Music Player Daemon.
Apr 7 16:48:03 moode systemd[1]: Configuration file /etc/systemd/system/bluealsa-aplay@.service is marked executable. Please remove executable permission bits. Proceed
ing anyway.
Apr 7 16:48:03 moode systemd[1]: Started Bluealsa-aplay.
Apr 7 16:48:03 moode bluealsa-aplay[22260]: bluealsa-aplay: [22260] D: aplay.c:1181: Starting main loop
Apr 7 16:48:03 moode systemd-udevd[22241]: event1: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1.
Apr 7 16:48:03 moode bluealsa[479]: bluealsa: [479] D: bluez.c:1193: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded()
Apr 7 16:48:03 moode bluealsa[479]: bluealsa: [479] D: dbus.c:47: Called: org.bluez.MediaEndpoint1.SetConfiguration() on /org/bluez/hci0/A2DP/SBC/sink/1
Apr 7 16:48:03 moode bluealsa[479]: bluealsa: [479] D: a2dp.c:383: Selected A2DP SBC bit-pool range: [2, 53]
Apr 7 16:48:03 moode bluealsa[479]: bluealsa: [479] D: storage.c:117: Loading storage: /var/lib/bluealsa/B8:7B:C5:AE:FD:08
Apr 7 16:48:03 moode bluealsa[479]: bluealsa: [479] D: bluez.c:412: A2DP Sink (SBC) configured for device B8:7B:C5:AE:FD:08
Apr 7 16:48:03 moode bluealsa[479]: bluealsa: [479] D: bluez.c:415: A2DP selected configuration blob [len=4]: 21150235
Apr 7 16:48:03 moode bluealsa[479]: bluealsa: [479] D: bluez.c:417: PCM configuration: channels: 2, sampling: 44100
Apr 7 16:48:03 moode bluealsa[479]: bluealsa: [479] D: bluez.c:590: Creating media endpoint object: /org/bluez/hci0/A2DP/SBC/sink/3
Apr 7 16:48:03 moode bluealsa[479]: bluealsa: [479] D: bluez.c:501: Registering media endpoint: /org/bluez/hci0/A2DP/SBC/sink/3
Apr 7 16:48:03 moode bluealsa-aplay[22260]: bluealsa-aplay: [22260] D: aplay.c:831: Creating IO worker B8:7B:C5:AE:FD:08
Apr 7 16:48:03 moode bluealsa-aplay[22260]: bluealsa-aplay: [22266] D: aplay.c:499: Opening BlueALSA source PCM: /org/bluealsa/hci0/dev_B8_7B_C5_AE_FD_08/a2dpsnk/sourc
e 