rfcomm Permission denied

Asked by Erik.Westman on 2015-02-06

Hi,
I have a problem using bluetooth serial device i.e. rfcomm works perfectly ok if run as root. For instance: the command: rfcomm connect rfcomm0 00:12:6F:07:5E:B ends up with: Can't open RFCOMM device: Permission denied. The same command run as ROOT runs ok.

This is the debugging which isn't working. Down below it is the same run as root.

Feb 6 09:39:40 x17 udevd[352]: seq 2107 queued, 'add' 'bluetooth'
Feb 6 09:39:40 x17 udevd[352]: passed 180 bytes to monitor 0x7f5b700292d0
Feb 6 09:39:40 x17 udevd-work[3627]: seq 2107 running
Feb 6 09:39:40 x17 udevd-work[3627]: device 0x7f5b70039f50 has devpath '/devices/pci0000:00/0000:00:12.0/usb3/3-3/3-3:1.0/bluetooth/hci0'
Feb 6 09:39:40 x17 udevd-work[3627]: device 0x7f5b70043130 has devpath '/devices/pci0000:00/0000:00:12.0/usb3/3-3/3-3:1.0'
Feb 6 09:39:40 x17 udevd-work[3627]: device 0x7f5b7003c4d0 has devpath '/devices/pci0000:00/0000:00:12.0/usb3/3-3'
Feb 6 09:39:40 x17 udevd-work[3627]: device 0x7f5b7003c860 has devpath '/devices/pci0000:00/0000:00:12.0/usb3'
Feb 6 09:39:40 x17 udevd-work[3627]: device 0x7f5b7003cce0 has devpath '/devices/pci0000:00/0000:00:12.0'
Feb 6 09:39:40 x17 udevd-work[3627]: device 0x7f5b7003cfd0 has devpath '/devices/pci0000:00'
Feb 6 09:39:40 x17 udevd-work[3627]: RUN 'socket:@/org/freedesktop/hal/udev_event' /lib/udev/rules.d/90-hal.rules:2
Feb 6 09:39:40 x17 udevd-work[3627]: RUN '/usr/sbin/bluetoothd --udev' /lib/udev/rules.d/97-bluetooth.rules:3
Feb 6 09:39:40 x17 udevd-work[3627]: passed 225 bytes to monitor 0x7f5b700293d0
Feb 6 09:39:40 x17 udevd-work[3627]: '/usr/sbin/bluetoothd --udev' started
Feb 6 09:39:40 x17 udevd-work[3627]: '/usr/sbin/bluetoothd --udev' returned with exitcode 0
Feb 6 09:39:40 x17 udevd-work[3627]: passed -1 bytes to monitor 0x7f5b7003a2e0
Feb 6 09:39:40 x17 udevd-work[3627]: seq 2107 processed with 0
Feb 6 09:39:40 x17 udevd[352]: seq 2107 done with 0
Feb 6 09:39:40 x17 bluetoothd[3048]: link_key_request (sba=00:10:60:D1:97:93, dba=00:12:6F:07:5E:B2)
Feb 6 09:39:40 x17 udevd[352]: seq 2108 queued, 'add' 'tty'
Feb 6 09:39:40 x17 udevd[352]: passed 151 bytes to monitor 0x7f5b700292d0
Feb 6 09:39:40 x17 udevd-work[3627]: seq 2108 running
Feb 6 09:39:40 x17 udevd-work[3627]: device 0x7f5b70039f50 has devpath '/devices/virtual/tty/rfcomm0'
Feb 6 09:39:40 x17 udevd-work[3627]: LINK 'char/216:0' /lib/udev/rules.d/50-udev-default.rules:4
Feb 6 09:39:40 x17 udevd-work[3627]: GROUP 20 /lib/udev/rules.d/50-udev-default.rules:19
Feb 6 09:39:40 x17 udevd-work[3627]: RUN 'socket:@/org/freedesktop/hal/udev_event' /lib/udev/rules.d/90-hal.rules:2
Feb 6 09:39:40 x17 udevd-work[3627]: no node name set, will use kernel supplied name 'rfcomm0'
Feb 6 09:39:40 x17 udevd-work[3627]: created db link (rfcomm0 char/216:0)
Feb 6 09:39:40 x17 udevd-work[3627]: creating device node '/dev/rfcomm0', devnum=216:0, mode=0660, uid=0, gid=20
Feb 6 09:39:40 x17 udevd-work[3627]: preserve file '/dev/rfcomm0', because it has correct dev_t
Feb 6 09:39:40 x17 udevd-work[3627]: chmod(/dev/rfcomm0, 020660)
Feb 6 09:39:40 x17 udevd-work[3627]: chown(/dev/rfcomm0, 0, 20)
Feb 6 09:39:40 x17 udevd-work[3627]: creating symlink '/dev/char/216:0' to '../rfcomm0'
Feb 6 09:39:40 x17 udevd-work[3627]: passed 182 bytes to monitor 0x7f5b7003d170
Feb 6 09:39:40 x17 udevd-work[3627]: passed -1 bytes to monitor 0x7f5b7003a2e0
Feb 6 09:39:40 x17 udevd-work[3627]: seq 2108 processed with 0
Feb 6 09:39:40 x17 udevd[352]: seq 2108 done with 0
Feb 6 09:39:40 x17 udevd[352]: seq 2109 queued, 'remove' 'tty'
Feb 6 09:39:40 x17 udevd[352]: passed 154 bytes to monitor 0x7f5b700292d0
Feb 6 09:39:40 x17 udevd-work[3627]: seq 2109 running
Feb 6 09:39:40 x17 udevd-work[3627]: device 0x7f5b70039f50 filled with db symlink data '/dev/rfcomm0'
Feb 6 09:39:40 x17 udevd-work[3627]: RUN '/lib/udev/gpsd.hotplug.wrapper' /lib/udev/rules.d/40-gpsd.rules:43
Feb 6 09:39:40 x17 udevd-work[3627]: RUN 'socket:@/org/freedesktop/hal/udev_event' /lib/udev/rules.d/90-hal.rules:2
Feb 6 09:39:40 x17 udevd-work[3627]: no reference left, remove '/dev/char/216:0'
Feb 6 09:39:40 x17 udevd-work[3627]: device node '/dev/rfcomm0' not found
Feb 6 09:39:40 x17 udevd-work[3627]: '/lib/udev/gpsd.hotplug.wrapper' started
Feb 6 09:39:40 x17 udevd-work[3627]: '/lib/udev/gpsd.hotplug.wrapper' returned with exitcode 0
Feb 6 09:39:40 x17 udevd-work[3627]: passed 188 bytes to monitor 0x7f5b7003c8e0
Feb 6 09:39:40 x17 udevd-work[3627]: passed -1 bytes to monitor 0x7f5b7003a2e0
Feb 6 09:39:40 x17 udevd-work[3627]: seq 2109 processed with 0
Feb 6 09:39:40 x17 udevd[352]: seq 2109 done with 0
Feb 6 09:39:43 x17 udevd[352]: seq 2110 queued, 'remove' 'bluetooth'
Feb 6 09:39:43 x17 udevd[352]: passed 183 bytes to monitor 0x7f5b700292d0
Feb 6 09:39:43 x17 udevd-work[3627]: seq 2110 running
Feb 6 09:39:43 x17 udevd-work[3627]: RUN 'socket:@/org/freedesktop/hal/udev_event' /lib/udev/rules.d/90-hal.rules:2
Feb 6 09:39:43 x17 udevd-work[3627]: passed 231 bytes to monitor 0x7f5b70043130
Feb 6 09:39:43 x17 udevd-work[3627]: passed -1 bytes to monitor 0x7f5b7003a2e0
Feb 6 09:39:43 x17 udevd-work[3627]: seq 2110 processed with 0
Feb 6 09:39:43 x17 udevd[352]: seq 2110 done with 0

RUN as ROOT.

Feb 6 09:37:40 x17 udevd[352]: seq 2100 queued, 'add' 'bluetooth'
Feb 6 09:37:40 x17 udevd[352]: passed 180 bytes to monitor 0x7f5b700292d0
Feb 6 09:37:40 x17 udevd-work[3627]: seq 2100 running
Feb 6 09:37:40 x17 udevd-work[3627]: device 0x7f5b70039fd0 has devpath '/devices/pci0000:00/0000:00:12.0/usb3/3-3/3-3:1.0/bluetooth/hci0'
Feb 6 09:37:40 x17 udevd-work[3627]: device 0x7f5b7003a100 has devpath '/devices/pci0000:00/0000:00:12.0/usb3/3-3/3-3:1.0'
Feb 6 09:37:40 x17 udevd-work[3627]: device 0x7f5b70042dc0 has devpath '/devices/pci0000:00/0000:00:12.0/usb3/3-3'
Feb 6 09:37:40 x17 udevd-work[3627]: device 0x7f5b7003c620 has devpath '/devices/pci0000:00/0000:00:12.0/usb3'
Feb 6 09:37:40 x17 udevd-work[3627]: device 0x7f5b7003c960 has devpath '/devices/pci0000:00/0000:00:12.0'
Feb 6 09:37:40 x17 udevd-work[3627]: device 0x7f5b7003cc50 has devpath '/devices/pci0000:00'
Feb 6 09:37:40 x17 udevd-work[3627]: RUN 'socket:@/org/freedesktop/hal/udev_event' /lib/udev/rules.d/90-hal.rules:2
Feb 6 09:37:40 x17 udevd-work[3627]: RUN '/usr/sbin/bluetoothd --udev' /lib/udev/rules.d/97-bluetooth.rules:3
Feb 6 09:37:40 x17 udevd-work[3627]: passed 225 bytes to monitor 0x7f5b70029330
Feb 6 09:37:40 x17 udevd-work[3627]: '/usr/sbin/bluetoothd --udev' started
Feb 6 09:37:40 x17 udevd-work[3627]: '/usr/sbin/bluetoothd --udev' returned with exitcode 0
Feb 6 09:37:40 x17 udevd-work[3627]: passed -1 bytes to monitor 0x7f5b7003a2e0
Feb 6 09:37:40 x17 udevd-work[3627]: seq 2100 processed with 0
Feb 6 09:37:40 x17 udevd[352]: seq 2100 done with 0
Feb 6 09:37:40 x17 bluetoothd[3048]: link_key_request (sba=00:10:60:D1:97:93, dba=00:12:6F:07:5E:B2)
Feb 6 09:37:40 x17 udevd[352]: seq 2101 queued, 'add' 'tty'
Feb 6 09:37:40 x17 udevd[352]: passed 151 bytes to monitor 0x7f5b700292d0
Feb 6 09:37:40 x17 udevd[352]: seq 2102 queued, 'move' 'tty'
Feb 6 09:37:40 x17 udevd-work[3627]: seq 2101 running
Feb 6 09:37:40 x17 udevd-work[3627]: LINK 'char/216:0' /lib/udev/rules.d/50-udev-default.rules:4
Feb 6 09:37:40 x17 udevd-work[3627]: GROUP 20 /lib/udev/rules.d/50-udev-default.rules:19
Feb 6 09:37:40 x17 udevd-work[3627]: RUN 'socket:@/org/freedesktop/hal/udev_event' /lib/udev/rules.d/90-hal.rules:2
Feb 6 09:37:40 x17 udevd-work[3627]: no node name set, will use kernel supplied name 'rfcomm0'
Feb 6 09:37:40 x17 udevd-work[3627]: created db link (rfcomm0 char/216:0)
Feb 6 09:37:40 x17 udevd-work[3627]: creating device node '/dev/rfcomm0', devnum=216:0, mode=0660, uid=0, gid=20
Feb 6 09:37:40 x17 udevd-work[3627]: preserve file '/dev/rfcomm0', because it has correct dev_t
Feb 6 09:37:40 x17 udevd-work[3627]: chmod(/dev/rfcomm0, 020660)
Feb 6 09:37:40 x17 udevd-work[3627]: chown(/dev/rfcomm0, 0, 20)
Feb 6 09:37:40 x17 udevd-work[3627]: creating symlink '/dev/char/216:0' to '../rfcomm0'
Feb 6 09:37:40 x17 udevd-work[3627]: passed 182 bytes to monitor 0x7f5b70043270
Feb 6 09:37:40 x17 udevd-work[3627]: passed -1 bytes to monitor 0x7f5b7003a2e0
Feb 6 09:37:40 x17 udevd-work[3627]: seq 2101 processed with 0
Feb 6 09:37:40 x17 udevd[352]: seq 2101 done with 0
Feb 6 09:37:40 x17 udevd[352]: passed 245 bytes to monitor 0x7f5b700292d0
Feb 6 09:37:40 x17 udevd-work[3627]: seq 2102 running
Feb 6 09:37:40 x17 udevd-work[3627]: RUN 'socket:@/org/freedesktop/hal/udev_event' /lib/udev/rules.d/90-hal.rules:2
Feb 6 09:37:40 x17 udevd-work[3627]: device 0x7f5b70043130 has devpath '/devices/pci0000:00/0000:00:12.0/usb3/3-3/3-3:1.0/bluetooth/hci0/hci0:39'
Feb 6 09:37:40 x17 udevd-work[3627]: device 0x7f5b7003d120 has devpath '/devices/pci0000:00/0000:00:12.0/usb3/3-3/3-3:1.0/bluetooth/hci0'
Feb 6 09:37:40 x17 udevd-work[3627]: device 0x7f5b70029420 has devpath '/devices/pci0000:00/0000:00:12.0/usb3/3-3/3-3:1.0'
Feb 6 09:37:40 x17 udevd-work[3627]: device 0x7f5b70042fc0 has devpath '/devices/pci0000:00/0000:00:12.0/usb3/3-3'
Feb 6 09:37:40 x17 udevd-work[3627]: device 0x7f5b7003c8c0 has devpath '/devices/pci0000:00/0000:00:12.0/usb3'
Feb 6 09:37:40 x17 udevd-work[3627]: device 0x7f5b7003cc40 has devpath '/devices/pci0000:00/0000:00:12.0'
Feb 6 09:37:40 x17 udevd-work[3627]: device 0x7f5b700295d0 has devpath '/devices/pci0000:00'
Feb 6 09:37:40 x17 udevd-work[3627]: passed 299 bytes to monitor 0x7f5b70029800
Feb 6 09:37:40 x17 udevd-work[3627]: passed -1 bytes to monitor 0x7f5b7003a2e0
Feb 6 09:37:40 x17 udevd[352]: seq 2102 done with 0
Feb 6 09:37:40 x17 udevd-work[3627]: seq 2102 processed with 0

Config error or kernel error?

Best regard, Erik

Question information

Language:
English Edit question
Status:
Solved
For:
Ubuntu linux Edit question
Assignee:
No assignee Edit question
Solved by:
Erik.Westman
Solved:
2015-02-08
Last query:
2015-02-08
Last reply:
2015-02-08

What is the output of:

ls -la /dev/rfcomm0

Thanks

Erik.Westman (hanwes) said : #2

The output as root:
 ls -ls /dev/rfcomm0
0 crw-rw---- 1 root dialout 216, 0 2015-02-06 10:34 /dev/rfcomm0

The output as eriwes (me as a user) isn't possible to see. Device doesn't stay up.

user eriwes belong to group dialout.

Try:

sudo chown eriwes:dialout /dev/rfcomm0

Then test, does it work ok?

Erik.Westman (hanwes) said : #4

Hi,

Sorry, it doesn't work. The /dev/rfcomm0 interface is up about half a second, then it disappears. I have manage to catch the status during that half second, this is the result:

crw-rw---- 1 root dialout 216, 0 2015-02-08 15:41 /dev/rfcomm0

rfcomm connect rfcomm0 00:12:6F:07:5E:B2
Can't open RFCOMM device: Permission denied
eriwes@x17:~$

Manfred Hampl (m-hampl) said : #5

You are sure that you are member of the group dialout?

what is the output of the terminal commands

groups
grep dialout /etc/groups
ls -l `which rfcomm`

Erik.Westman (hanwes) said : #6

Hi.

The group:
id eriwes
uid=1000(eriwes) gid=1000(eriwes) grupper=1000(eriwes),4(adm),7(lp),20(dialout),24(cdrom),25(floppy),26(tape),29(audio),30(dip),44(video),46(plugdev),100(users),104(fuse),106(lpadmin),108(mlocate),112(netdev),114(pulse),115(pulse-access),121(admin),122(sambashare),127(vboxusers)

eriwes is me.

I'll guess you didn't mean /etc/groups (with s).
grep dialout /etc/group
dialout:x:20:eriwes

ls -l `which rfcomm`

-rwxr-xr-x 1 root dialout 40352 2010-04-09 13:25 /usr/bin/rfcomm

Erik.Westman (hanwes) said : #7

Hi

I solved it myself. Maybe this is a security risk, but I set the "set group id" the rfcomm
before:
-rwxr-xr-x 1 root dialout 40352 2010-04-09 13:25 /usr/bin/rfcomm

chmod 4750 /usr/bin/rfcomm
RESULT:
-rwsr-x--- 1 root dialout 40352 2010-04-09 13:25 /usr/bin/rfcomm

Now it works perfectly ok!

Tank's all