Bluetooth no longer working after fresh install

psyke83

No need to clone a new copy - simply make sure that you're in the same directory as the existing RetroPie-Setup script:

cd ~/RetroPie-Setup
git checkout 12cb7eb1bc9d810e98adbc8ec7f9a8369ed1f25e^

Note that you omitted the caret to signify the commit preceding the commit specified, so make sure to include it (since you want to test the script right before that commit).

charleszimm

@psyke83 Sorry for the delay. Here's the response:

pi@theaterretropie:~/RetroPie-Setup $ pwd
/home/pi/RetroPie-Setup
pi@theaterretropie:~/RetroPie-Setup $ git checkout 12cb7eb1bc9d810e98adbc8ec7f9a8369ed1f25e^
error: pathspec '12cb7eb1bc9d810e98adbc8ec7f9a8369ed1f25e^' did not match any file(s) known to git.

psyke83

@charleszimm said in Bluetooth no longer working after fresh install:

git checkout 12cb7eb1bc9d810e98adbc8ec7f9a8369ed1f25e^

Huh that's odd. Try to fetch origin before checkout:

git fetch origin

I just tried a fresh clone of the repo and was able to checkout that commit without any problem (on my Pi and laptop).

charleszimm

I keep getting flagged as spam but tried the git fetch origin and then the commit point but same message. I recloned the entire RetroPie-Setup from GitHub and tried it again and got the same error.

psyke83

@charleszimm

Not sure what's going on there, sorry. Perhaps the caret is causing issues somehow, so it might help to specify another commit that precedes the change. Try:

git checkout 2c9fa79a1ae41c2988d21bd179c33ce515e29245

charleszimm

@psyke83 said in Bluetooth no longer working after fresh install:

git checkout 2c9fa79a1ae41c2988d21bd179c33ce515e29245

Nope.

pi@theaterretropie:~/RetroPie-Setup $ git checkout 2c9fa79a1ae41c2988d21bd179c33ce515e29245
fatal: reference is not a tree: 2c9fa79a1ae41c2988d21bd179c33ce515e29245

psyke83

@charleszimm said in Bluetooth no longer working after fresh install:

@psyke83 said in Bluetooth no longer working after fresh install:

git checkout 2c9fa79a1ae41c2988d21bd179c33ce515e29245

Nope.

pi@theaterretropie:~/RetroPie-Setup $ git checkout 2c9fa79a1ae41c2988d21bd179c33ce515e29245
fatal: reference is not a tree: 2c9fa79a1ae41c2988d21bd179c33ce515e29245

Very odd. Did you clone from a forked repository instead of the official one? What's the output of git remote -v in that folder?

P.S. You should encapsulate code via the code tag icon in the editor to avoid the spam filter (and to keep the text tidy).

charleszimm

@psyke83 Oh yeah good point. It was more of a laziness thing on my part I won't lie. :-)

pi@theaterretropie:~/RetroPie-Setup $ git remote -v
origin	https://github.com/RetroPie/RetroPie-Setup.git (fetch)
origin	https://github.com/RetroPie/RetroPie-Setup.git (push)

psyke83

@charleszimm said in Bluetooth no longer working after fresh install:

@psyke83 Oh yeah good point. It was more of a laziness thing on my part I won't lie. :-)
pi@theaterretropie:~/RetroPie-Setup $ git remote -v
origin	https://github.com/RetroPie/RetroPie-Setup.git (fetch)
origin	https://github.com/RetroPie/RetroPie-Setup.git (push)

Really bizarre. The only possibility I can think of is that you somehow have a shallow copy of the repository, so it doesn't include the history of commits up to what we need.

Make sure you're on the master branch, then try to force the whole history to be downloaded:

git checkout master
git pull --unshallow

You can see what the oldest commit is via git log --reverse - in my case, it shows the very first commit to the repository from 2012.

psyke83

Ah yes that makes complete sense! Our instructions will have you clone a shallow copy (--depth=1): https://github.com/RetroPie/RetroPie-Setup/blob/master/README.md

Forcing an unshallow will fix the issue.

charleszimm

@psyke83 Hey that worked!

HEAD is now at 179e2f37... Merge pull request #2591 from cmitu/dolphin-build

When I go into the Setup script, the last commit is now listed as three weeks ago along with the HEAD number. I cleaned out the entire registered Bluetooth device list in bluetoothctl. Let me do some testing and get back to you.

charleszimm

@charleszimm Hung at the Searching... loop. That's what we expected to see, right?

psyke83

@charleszimm said in Bluetooth no longer working after fresh install:

@charleszimm Hung at the Searching... loop. That's what we expected to see, right?

Maybe, yes. To bypass that, make sure to remove any devices that are causing the Connected: yes/no messages to loop in bluetoothctl before selecting the "Register" menu option.

It might be OK to run a bluetoothctl session in a separate shell if you want to monitor what's happening in the Bluetooth stack at the same time as you're running the script.

charleszimm

@psyke83 Okay I lied. It didn't hang but it takes about roughly 2 minutes before it completed searching. I left the Searching... screen up in the SSH session, went to grab a drink, came back, and the results were there.

I was able to connect the controller without problems in Switch mode through the setup script without any problems (which that was always how I had my SN30 Pro setup, even back when I was running Jessie). Restarted the Pi and was able to reconnect the controller without any problems.

So what has changed between the commits?

Bluetooth.service still gives some weird messages that don't leave me warm and fuzzy however.

pi@theaterretropie:~ $ systemctl status bluetooth.service
● bluetooth.service - Bluetooth service
   Loaded: loaded (/lib/systemd/system/bluetooth.service; enabled; vendor preset: enabled)
   Active: active (running) since Wed 2019-02-20 13:20:59 EST; 2min 38s ago
     Docs: man:bluetoothd(8)
 Main PID: 515 (bluetoothd)
   Status: "Running"
   CGroup: /system.slice/bluetooth.service
           └─515 /usr/lib/bluetooth/bluetoothd

Feb 20 13:20:59 theaterretropie bluetoothd[515]: Starting SDP server
Feb 20 13:20:59 theaterretropie bluetoothd[515]: Bluetooth management interface 1.14 initialized
Feb 20 13:20:59 theaterretropie bluetoothd[515]: Failed to obtain handles for "Service Changed" characteristic
Feb 20 13:20:59 theaterretropie bluetoothd[515]: setsockopt(L2CAP_OPTIONS): Invalid argument (22)
Feb 20 13:20:59 theaterretropie bluetoothd[515]: avrcp-controller: Protocol not supported (93)
Feb 20 13:20:59 theaterretropie bluetoothd[515]: setsockopt(L2CAP_OPTIONS): Invalid argument (22)
Feb 20 13:20:59 theaterretropie bluetoothd[515]: audio-avrcp-target: Protocol not supported (93)
Feb 20 13:20:59 theaterretropie bluetoothd[515]: Sap driver initialization failed.
Feb 20 13:20:59 theaterretropie bluetoothd[515]: sap-server: Operation not permitted (1)
Feb 20 13:21:01 theaterretropie bluetoothd[515]: Failed to set privacy: Rejected (0x0b)

psyke83

My daemon log shows similar (but not all of your) errors:

● bluetooth.service - Bluetooth service
   Loaded: loaded (/lib/systemd/system/bluetooth.service; enabled; vendor preset: enabled)
   Active: active (running) since Tue 2019-02-19 17:57:35 GMT; 24h ago
     Docs: man:bluetoothd(8)
 Main PID: 527 (bluetoothd)
   Status: "Running"
   CGroup: /system.slice/bluetooth.service
           └─527 /usr/lib/bluetooth/bluetoothd

Feb 19 17:57:35 retropie systemd[1]: Starting Bluetooth service...
Feb 19 17:57:35 retropie bluetoothd[527]: Bluetooth daemon 5.43
Feb 19 17:57:35 retropie systemd[1]: Started Bluetooth service.
Feb 19 17:57:35 retropie bluetoothd[527]: Starting SDP server
Feb 19 17:57:35 retropie bluetoothd[527]: Bluetooth management interface 1.14 initialized
Feb 19 17:57:35 retropie bluetoothd[527]: Failed to obtain handles for "Service Changed" characteristic
Feb 19 17:57:35 retropie bluetoothd[527]: Sap driver initialization failed.
Feb 19 17:57:35 retropie bluetoothd[527]: sap-server: Operation not permitted (1)
Feb 19 17:57:35 retropie bluetoothd[527]: Endpoint registered: sender=:1.5 path=/A2DP/SBC/Source/1
Feb 19 17:57:35 retropie bluetoothd[527]: Failed to set privacy: Rejected (0x0b)

Are you absolutely certain that you tested the latest master script, making sure to remove the device before registration?

Again, to return to master:

git checkout master

I can't really see how my changes would negatively affect the authentication phase, as I didn't change anything in that part of the script.

charleszimm

@psyke83 I'm positive. I looked through the commit log and I agree: It doesn't quite look like any of the changes that were made should really affect the handoff between the device and the service.

I removed the controller, checked back out to master, confirmed in the Setup script that we're at 5dff90ef, and tried to resync the controller through the Bluetooth menu. With the controller in the same mode (Switch) that worked on 179e2f37, I'm back to getting the message:

An error occurred connecting to the bluetooth device (Creating device failed: org.bluez.Error.AuthenicationFailed: Authentication Failed)

If I go into bluetoothctl, I get the familiar Yes/No:

[bluetooth]# connect 98:B6:E9:42:4B:35
Attempting to connect to 98:B6:E9:42:4B:35
[CHG] Device 98:B6:E9:42:4B:35 Connected: yes
[CHG] Device 98:B6:E9:42:4B:35 Connected: no

I'm not sure where you're located but I'm in the northeast of the US and we're getting pounded with snow so I'm going to start our digging out. Let me know if you want me try anything else today!

psyke83

@charleszimm

We can try to zero in on what may possibly cause the issue.
See this test change: https://github.com/RetroPie/RetroPie-Setup/compare/master...psyke83:bluez_test

This will break sixaxis pairing, but let's see if it helps in your case.

You can test by adding my repo as a remote and then check out the branch:

git remote add psyke https://github.com/psyke83/RetroPie-Setup.git
git fetch psyke
git checkout psyke/bluez_test

As far as I can tell, enabling and setting the default-agent takes effect for the active bluetoothctl session only, and should be unregistered as soon as the scanning has finished... so I'm skeptical as to whether this is the root of the issue.

I've also created another commit on a separate branch that will still set up the agent, but only removes the part that responds to authorization challenges: https://github.com/RetroPie/RetroPie-Setup/compare/master...psyke83:bluez_test2

To test this one (assuming you've already added the psyke remote):

git checkout psyke/bluez_test2

I'd appreciate if you could try both and let me know which ones work (or not), and we can move on from there.

I suspect that both will work, and might see the potential issue. If your device is actually producing an authorization prompt, the final "disconnect" command may be turning off your controller just before you reach the security type section. But, let's wait and see.

Good luck with the excavation and keep safe! :)

charleszimm

@psyke83 Okay I have survived clearing my driveway and have a whiskey in hand so let's continue.

I cleared out the devices from bluetoothctl and on the psyke/bluez_test build (854a114e), I get the bluez Authentication Failed message, along with the Connected Yes/No in bluetoothctl.

Moving on to bluez_test2 (f2d44077), same result. Authentication failed, Connected Yes/No in bluetoothctl.

psyke83

@charleszimm

I'm a bit stumped, then. I don't see any significant changes to explain why you're having this problem.

Am I missing something obvious?

git diff master 2c9fa79a1ae41c2988d21bd179c33ce515e29245 -- scriptmodules/supplementary/bluetooth.sh

The only behaviour difference is the method in which commands are redirected to the bluetoothctl shell (with a deliberate 1 second pause between lines), but I really don't see why that'd cause this issue, as it only affects the "Scanning" phase and not the subsequent authorization which is done via bluez-simple-agent.

You're certain that for each test you've followed the same procedure to remove/register, turned on the controller in the appropriate mode and selected the same security type? Was the successful pairing with the older version of the script a fluke or does it work reliably every time?

I'm not sure what else to suggest as the bluez_test branch has very little changed apart from the "slow echo" code which I don't think would change anything.

charleszimm

@psyke83 Positive same scenario. Here's the results from the git diff:

diff --git a/scriptmodules/supplementary/bluetooth.sh b/scriptmodules/supplementary/bluetooth.sh
index f0c0b3d5..3cdd4c49 100644
--- a/scriptmodules/supplementary/bluetooth.sh
+++ b/scriptmodules/supplementary/bluetooth.sh
@@ -46,37 +46,34 @@ function get_script_bluetooth() {
     echo "$name"
 }
 
-function _slowecho_bluetooth() {
-    local line
-
-    IFS=$'\n'
-    for line in $(echo -e "${1}"); do
-        echo -e "$line"
-        sleep 1
-    done
-    unset IFS
-}
-
 function bluez_cmd_bluetooth() {
     # create a named pipe & fd for input for bluetoothctl
     local fifo="$(mktemp -u)"
     mkfifo "$fifo"
     exec 3<>"$fifo"
     local line
-    while true; do
-        _slowecho_bluetooth "$1" >&3
-        # collect output for specified amount of time, then echo it
-        while read -r line; do
-            printf '%s\n' "$line"
-            # (slow) reply to any optional challenges
-            if [[ -n "$3" && "$line" =~ $3 ]]; then
-                _slowecho_bluetooth "$4" >&3
+    while read -r line; do
+        if [[ "$line" == *"[bluetooth]"* ]]; then
+            echo -e "$1" >&3
+            read -r line
+            if [[ -n "$2" ]]; then
+                # collect output for specified amount of time, then echo it
+                local buf
+                while read -r -t "$2" line; do
+                    buf+=("$line")
+                    # reply to any optional challenges
+                    if [[ -n "$4" && "$line" == *"$3"* ]]; then
+                        echo -e "$4" >&3
+                    fi
+                done
+                printf '%s\n' "${buf[@]}"
             fi
-        done
-        _slowecho_bluetooth "quit\n" >&3
-        break
+            sleep 1
+            echo -e "quit" >&3
+            break
+        fi
     # read from bluetoothctl buffered line by line
-    done < <(timeout "$2" stdbuf -oL bluetoothctl --agent=NoInputNoOutput <&3)
+    done < <(stdbuf -oL bluetoothctl <&3)
     exec 3>&-
 }
 
@@ -86,15 +83,16 @@ function list_available_bluetooth() {
     local info_text="\n\nSearching ..."
 
     # sixaxis: add USB pairing information
-    [[ -n "$(lsmod | grep hid_sony)" ]] && info_text="Searching ...\n\nDualShock registration: while this text is visible, unplug and replug the controller, then press the PS/SHARE button."
+    [[ -n "$(lsmod | grep hid_sony)" ]] && info_text="Searching ...\n\n(To register a DualShock controller, please unplug and replug your controller while this text is visible...)"
 
     dialog --backtitle "$__backtitle" --infobox "$info_text" 7 60 >/dev/tty
     if hasPackage bluez 5; then
         # sixaxis: reply to authorization challenge on USB cable connect
+        [[ -n "$(lsmod | grep hid_sony)" ]] && bluez_cmd_bluetooth "default-agent" "10" "Authorize" "yes" >/dev/null &
         while read mac_address; read device_name; do
             echo "$mac_address"
             echo "$device_name"
-        done < <(bluez_cmd_bluetooth "default-agent\nscan on" "15" "Authorize service$" "yes\ntrust\ndisconnect" >/dev/null; bluez_cmd_bluetooth "devices" "3" | grep "^Device " | cut -d" " -f2,3- | sed 's/ /\n/')
+        done < <(bluez_cmd_bluetooth "scan on" "10" >/dev/null; bluez_cmd_bluetooth "devices" "2" | grep "^Device " | cut -d" " -f2,3- | sed 's/ /\n/')
     else
         while read; read mac_address; read device_name; do
             echo "$mac_address"
@@ -400,7 +398,7 @@ function gui_bluetooth() {
         local choice=$("${cmd[@]}" "${options[@]}" 2>&1 >/dev/tty)
         if [[ -n "$choice" ]]; then
             # temporarily restore Bluetooth stack (if needed)
-            service sixad status &>/dev/null && sixad -r
+            service sixad status >/dev/null && sixad -r
             case "$choice" in
                 R)
                     register_bluetooth
@@ -427,7 +425,7 @@ function gui_bluetooth() {
             esac
         else
             # restart sixad (if running)
-            service sixad status &>/dev/null && service sixad restart && printMsgs "dialog" "NOTICE: The ps3controller driver was temporarily interrupted in order to allow compatibility with standard Bluetooth peripherals. Please re-pair your Dual Shock controller to continue (or disregard this message if currently using another controller)."
+            service sixad status >/dev/null && service sixad restart && printMsgs "dialog" "NOTICE: The ps3controller driver was temporarily interrupted in order to allow compatibility with standard Bluetooth peripherals. Please re-pair your Dual Shock controller to continue (or disregard this message if currently using another controller)."
             break
         fi
     done