raspberry 3 : Bluetooth hciconfig up fails

[lah]

On raspberry3, to enable onboard bluetooth you must read this thread viewtopic.php?f=67&t=10017 and install packages given.
So far it worked. Today after an update I did not get bluetooth after startup. If I plug an USB dongle I get same issue.

This rule fires bluetooth poweron :
$this->bbcode_second_pass_code('', '
# Set bluetooth power up
ACTION=="add", KERNEL=="hci[0-9]*", RUN+="/bin/hciconfig %k up"
')

According to these logs, rule is fired but hciconfig command returns an error :

$this->bbcode_second_pass_code('', '
>hcitool dev
Devices:
>hciconfig
hci1: Type: Primary Bus: UART
BD Address: B8:27:EB:20:B4:C3 ACL MTU: 1021:8 SCO MTU: 64:1
DOWN
RX bytes:654 acl:0 sco:0 events:33 errors:0
TX bytes:419 acl:0 sco:0 commands:33 errors:0

hci0: Type: Primary Bus: USB
BD Address: 00:02:72:CD:29:71 ACL MTU: 1021:8 SCO MTU: 64:1
DOWN
RX bytes:870 acl:0 sco:0 events:35 errors:0
TX bytes:383 acl:0 sco:0 commands:35 errors:0
>systemctl status systemd-udevd
● systemd-udevd.service - udev Kernel Device Manager
Loaded: loaded (/usr/lib/systemd/system/systemd-udevd.service; static; vendor preset: disabled)
Active: active (running) since Wed 2016-11-30 14:56:33 CET; 24h ago
Docs: man:systemd-udevd.service(8)
man:udev(7)
Main PID: 212 (systemd-udevd)
Status: "Processing with 16 children at max"
Tasks: 1
CGroup: /system.slice/systemd-udevd.service
└─212 /usr/lib/systemd/systemd-udevd

nov. 30 14:56:33 a4h-rpi-rel systemd[1]: Started udev Kernel Device Manager.
nov. 30 14:56:34 a4h-rpi-rel systemd-udevd[220]: Process '/usr/bin/alsactl restore 0' failed with exit code 99.
nov. 30 14:56:34 a4h-rpi-rel systemd-udevd[226]: Process '/usr/bin/alsactl restore 0' failed with exit code 99.
nov. 30 14:56:34 a4h-rpi-rel systemd-udevd[238]: Process '/usr/bin/set-wireless-regdom' failed with exit code 1.
nov. 30 14:56:34 a4h-rpi-rel systemd-udevd[226]: Process '/bin/hciconfig hci0 up' failed with exit code 1.
déc. 01 15:33:41 a4h-rpi-rel systemd-udevd[376]: Process '/bin/hciconfig hci1 up' failed with exit code 1.
')

Error returned is :
$this->bbcode_second_pass_code('', '
Can't open HCI socket.: Protocol not supported
')

But manually, hciconfig command works :
$this->bbcode_second_pass_code('', '
sudo hciconfig hci0 up && hcitool dev
Devices:
hci0 00:02:72:CD:29:71
')

I think it is because of a timing issue. So when rules is triggered I start a service :

$this->bbcode_second_pass_code('', '
cat /etc/udev/rules.d/50-bluetooth-hci-auto-poweron.rules
# Set bluetooth power up
#ACTION=="add", KERNEL=="hci[0-9]*", RUN+="/bin/hciconfig %k up"
ACTION=="add", KERNEL=="hci[0-9]*", RUN+="/home/remi/system_workarounds/bluetooth-auto.sh %k"
> sudo udevadm control --reload-rules
')

$this->bbcode_second_pass_code('', '
> cat /home/remi/system_workarounds/bluetooth-auto.sh
#!/bin/sh
echo "HCI_DEV=$1" > /tmp/.bluetooth-auto.args
/usr/bin/systemctl start bluetooth-auto-poweron.service
')

$this->bbcode_second_pass_code('', '
chmod a+x /home/remi/system_workarounds/bluetooth-auto.sh
')

$this->bbcode_second_pass_code('', '
> cat /etc/systemd/system/bluetooth-auto-poweron.service
[Unit]
Description=BT auto power

[Service]
Type=simple
RemainAfterExit=no
EnvironmentFile=/tmp/.bluetooth-auto.args
ExecStart=/bin/hciconfig $HCI_DEV up

[Install]
WantedBy=multi-user.target
')

$this->bbcode_second_pass_code('', '
sudo systemctl enable bluetooth-auto-poweron.service
')
This workaround solved this problem, but deeper investigations must be done to found root cause.
I have these bluetooth packages :

$this->bbcode_second_pass_code('', '
pacman -Qs bluetooth
local/bluez 5.43-2
Daemons for the bluetooth protocol stack
local/bluez-utils 5.43-2
Development and debugging utilities for the bluetooth protocol stack
local/pi-bluetooth 1-1
Services, firmware and udev rules to get integrated bluetooth running in Raspberry Pi 3
')

And recent update :

$this->bbcode_second_pass_code('', '
[2016-12-01 10:51] [PACMAN] Running 'pacman -Syu'
[2016-12-01 10:51] [PACMAN] synchronizing package lists
[2016-12-01 10:51] [PACMAN] starting full system upgrade
[2016-12-01 10:55] [ALPM] transaction started
[2016-12-01 10:55] [ALPM] upgraded tzdata (2016i-1 -> 2016j-1)
[2016-12-01 10:55] [ALPM] upgraded ncurses (6.0-4 -> 6.0+20161112-1)
[2016-12-01 10:55] [ALPM] upgraded bash (4.4-1 -> 4.4.005-1)
[2016-12-01 10:55] [ALPM] upgraded collectd (5.6.1-2 -> 5.6.2-1)
[2016-12-01 10:55] [ALPM] upgraded xz (5.2.2-1 -> 5.2.2-2)
[2016-12-01 10:55] [ALPM] upgraded libgpg-error (1.24-1 -> 1.25-1)
[2016-12-01 10:55] [ALPM] upgraded libsystemd (231-4 -> 232-4)
[2016-12-01 10:55] [ALPM] upgraded systemd (231-4 -> 232-4)
[2016-12-01 10:59] [ALPM] upgraded libdrm (2.4.73-1 -> 2.4.74-1)
[2016-12-01 10:59] [ALPM] upgraded llvm-libs (3.9.0-1.1 -> 3.9.0-3)
[2016-12-01 10:59] [ALPM] upgraded mesa (13.0.1-1 -> 13.0.2-1)
[2016-12-01 10:59] [ALPM] upgraded mesa-libgl (13.0.1-1 -> 13.0.2-1)
[2016-12-01 10:59] [ALPM] upgraded libtiff (4.0.6-2 -> 4.0.7-1)
[2016-12-01 11:00] [ALPM] upgraded ffmpeg (1:3.2-2 -> 1:3.2.1-1)
[2016-12-01 11:01] [ALPM] upgraded gnupg (2.1.15-2 -> 2.1.16-1)
[2016-12-01 11:03] [ALPM] upgraded godep (2:74-1 -> 2:75-1)
[2016-12-01 11:03] [ALPM] upgraded iputils (20160308.0db72a4-1 -> 20161105.1f2bb12-1)
[2016-12-01 11:03] [ALPM] upgraded iw (4.7-1 -> 4.9-1)
[2016-12-01 11:03] [ALPM] upgraded linux-raspberrypi (4.4.33-1 -> 4.4.35-1)
[2016-12-01 11:05] [ALPM-SCRIPTLET] >>> Updating module dependencies. Please wait ...
[2016-12-01 11:05] [ALPM] upgraded nodejs (7.1.0-1 -> 7.2.0-1)
[2016-12-01 11:05] [ALPM] upgraded protobuf (2.6.1-2 -> 3.0.2-2)
[2016-12-01 11:06] [ALPM] upgraded raspberrypi-firmware-bootloader (20161116-1 -> 20161122-1)
[2016-12-01 11:06] [ALPM] upgraded raspberrypi-firmware-bootloader-x (20161116-1 -> 20161122-1)
[2016-12-01 11:06] [ALPM] upgraded raspberrypi-firmware-tools (20161116-1 -> 20161122-1)
[2016-12-01 11:06] [ALPM] upgraded raspberrypi-firmware-examples (20161116-1 -> 20161122-1)
[2016-12-01 11:07] [ALPM] upgraded raspberrypi-firmware (20161116-1 -> 20161122-1)
[2016-12-01 11:07] [ALPM] upgraded ruby (2.3.2-1 -> 2.3.3-2)
[2016-12-01 11:07] [ALPM] upgraded systemd-sysvcompat (231-4 -> 232-4)
[2016-12-01 11:07] [ALPM] transaction completed
[2016-12-01 11:07] [ALPM] running 'texinfo-install.hook'...
[2016-12-01 11:09] [ALPM] running 'udev-hwdb.hook'...

')

I hope this issue will be solved.