* A problem with "rfcomm bind" and wvdial
@ 2014-01-03 18:24 Andrey Vihrov
0 siblings, 0 replies; 4+ messages in thread
From: Andrey Vihrov @ 2014-01-03 18:24 UTC (permalink / raw)
To: linux-bluetooth
[-- Attachment #1.1: Type: text/plain, Size: 1643 bytes --]
Hello,
I'm writing to this mailing list because I was told on IRC that it's the
best place to discuss Linux Bluetooth problems, and I want to report
one.
I have a Nokia N70 phone which I use as a modem through Bluetooth. Up
until recently (~half a year ago), my workflow to establish a connection
was to
a) Call "rfcomm bind /dev/rfcomm0 <addr> <channel>" at system start (in
the past I also used /etc/bluetooth/rfcomm.conf, but that stopped
working at some point)
b) Run wvdial, which will open /dev/rfcomm0 as a modem/serial port
Now, however, when I run wvdial, I get
Cannot open /dev/rfcomm0: Transport endpoint is not connected
I have found empirically that if I use "rfcomm connect" instead of
"rfcomm bind", and then run wvdial, then it works fine. Thus, it would
seem that the connection is not established automatically when an
application opens /dev/rfcomm0.
I have reproduced this on Arch Linux with BlueZ 5.13 and the
linux-bluetooth kernel. I'm also attaching logs of bluetoothd, btmon and
hcidump at the moment when wvdial is run.
Regarding the btmon log, I've observed that wvdial reports the
"Transport endpoint is not connected" error nearly at the same time as
the first
> HCI Event: Command Status (0x0f) plen 4 [hci0] 3.436738
Create Connection (0x01|0x0005) ncmd 1
Status: Success (0x00)
is printed, and the rest of the log is printed when wvdial has already
exited.
Thanks in advance,
--
Andrey Vihrov <andrey.vihrov@gmail.com>
[-- Attachment #1.2: bluetoothd --]
[-- Type: text/plain, Size: 11783 bytes --]
bluetoothd[4444]: Bluetooth daemon 5.13
bluetoothd[4444]: src/main.c:parse_config() parsing main.conf
bluetoothd[4444]: src/main.c:parse_config() discovto=0
bluetoothd[4444]: src/main.c:parse_config() pairto=0
bluetoothd[4444]: src/main.c:parse_config() Key file does not have key 'AutoConnectTimeout'
bluetoothd[4444]: src/main.c:parse_config() name=%h
bluetoothd[4444]: src/main.c:parse_config() Key file does not have key 'Class'
bluetoothd[4444]: src/main.c:parse_config() Key file does not have key 'DeviceID'
bluetoothd[4444]: src/main.c:parse_config() Key file does not have key 'ReverseServiceDiscovery'
bluetoothd[4444]: src/adapter.c:adapter_init() sending read version command
bluetoothd[4444]: Starting SDP server
bluetoothd[4444]: src/sdpd-service.c:register_device_id() Adding device id record for 0002:1d6b:0246:050d
bluetoothd[4444]: src/plugin.c:plugin_init() Loading builtin plugins
bluetoothd[4444]: src/plugin.c:add_plugin() Loading hostname plugin
bluetoothd[4444]: src/plugin.c:add_plugin() Loading wiimote plugin
bluetoothd[4444]: src/plugin.c:add_plugin() Loading autopair plugin
bluetoothd[4444]: src/plugin.c:add_plugin() Loading policy plugin
bluetoothd[4444]: src/plugin.c:add_plugin() Loading a2dp plugin
bluetoothd[4444]: src/plugin.c:add_plugin() Loading avrcp plugin
bluetoothd[4444]: src/plugin.c:add_plugin() Loading network plugin
bluetoothd[4444]: src/plugin.c:add_plugin() Loading input plugin
bluetoothd[4444]: src/plugin.c:add_plugin() Loading hog plugin
bluetoothd[4444]: src/plugin.c:add_plugin() Loading gatt plugin
bluetoothd[4444]: src/plugin.c:add_plugin() Loading scanparam plugin
bluetoothd[4444]: src/plugin.c:add_plugin() Loading deviceinfo plugin
bluetoothd[4444]: src/plugin.c:plugin_init() Loading plugins /usr/lib/bluetooth/plugins
bluetoothd[4444]: profiles/input/suspend-dummy.c:suspend_init()
bluetoothd[4444]: profiles/input/suspend-dummy.c:suspend_init() Created suspend-dummy FIFO on /tmp/hogsuspend
bluetoothd[4444]: profiles/network/manager.c:read_config() Config options: Security=true
bluetoothd[4444]: plugins/hostname.c:read_dmi_fallback() chassis: laptop
bluetoothd[4444]: plugins/hostname.c:read_dmi_fallback() major: 0x01 minor: 0x03
bluetoothd[4444]: src/main.c:main() Entering main loop
bluetoothd[4444]: plugins/hostname.c:property_changed() static hostname: tenshi
bluetoothd[4444]: plugins/hostname.c:property_changed() pretty hostname:
bluetoothd[4444]: plugins/hostname.c:property_changed() chassis: laptop
bluetoothd[4444]: Bluetooth management interface 1.4 initialized
bluetoothd[4444]: src/adapter.c:read_version_complete() sending read supported commands command
bluetoothd[4444]: src/adapter.c:read_version_complete() sending read index list command
bluetoothd[4444]: src/rfkill.c:rfkill_event() RFKILL event idx 0 type 2 op 0 soft 0 hard 0
bluetoothd[4444]: src/adapter.c:read_commands_complete() Number of commands: 42
bluetoothd[4444]: src/adapter.c:read_commands_complete() Number of events: 21
bluetoothd[4444]: src/adapter.c:read_index_list_complete() Number of controllers: 1
bluetoothd[4444]: src/adapter.c:read_index_list_complete() Found index 0
bluetoothd[4444]: src/adapter.c:index_added() index 0
bluetoothd[4444]: src/adapter.c:btd_adapter_new() System name: %h
bluetoothd[4444]: src/adapter.c:btd_adapter_new() Major class: 0
bluetoothd[4444]: src/adapter.c:btd_adapter_new() Minor class: 0
bluetoothd[4444]: src/adapter.c:btd_adapter_new() Modalias: usb:v1D6Bp0246d050D
bluetoothd[4444]: src/adapter.c:btd_adapter_new() Discoverable timeout: 0 seconds
bluetoothd[4444]: src/adapter.c:btd_adapter_new() Pairable timeout: 0 seconds
bluetoothd[4444]: src/adapter.c:index_added() sending read info command for index 0
bluetoothd[4444]: src/adapter.c:read_info_complete() index 0 status 0x00
bluetoothd[4444]: src/adapter.c:clear_uuids() sending clear uuids command for index 0
bluetoothd[4444]: src/attrib-server.c:btd_adapter_gatt_server_start() Start GATT server in hci0
bluetoothd[4444]: src/attrib-server.c:attrib_db_add_new() handle=0x0001
bluetoothd[4444]: src/attrib-server.c:attrib_db_add_new() handle=0x0004
bluetoothd[4444]: src/attrib-server.c:attrib_db_add_new() handle=0x0006
bluetoothd[4444]: src/attrib-server.c:attrib_db_add_new() handle=0x0007
bluetoothd[4444]: src/attrib-server.c:attrib_db_add_new() handle=0x0008
bluetoothd[4444]: src/adapter.c:adapter_service_add() /org/bluez/hci0
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Adding record with handle 0x10001
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000007-0000-1000-8000-00805f9
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00001800-0000-1000-8000-00805f9
bluetoothd[4444]: src/adapter.c:adapter_service_insert() /org/bluez/hci0
bluetoothd[4444]: src/adapter.c:add_uuid() sending add uuid command for index 0
bluetoothd[4444]: src/attrib-server.c:attrib_db_add_new() handle=0x0010
bluetoothd[4444]: src/adapter.c:adapter_service_add() /org/bluez/hci0
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Adding record with handle 0x10002
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000007-0000-1000-8000-00805f9
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00001801-0000-1000-8000-00805f9
bluetoothd[4444]: src/adapter.c:adapter_service_insert() /org/bluez/hci0
bluetoothd[4444]: src/adapter.c:add_uuid() sending add uuid command for index 0
bluetoothd[4444]: profiles/audio/a2dp.c:media_server_probe() path /org/bluez/hci0
bluetoothd[4444]: plugins/hostname.c:hostname_probe()
bluetoothd[4444]: plugins/hostname.c:update_name() name: tenshi
bluetoothd[4444]: src/adapter.c:adapter_set_name() name: tenshi
bluetoothd[4444]: src/adapter.c:adapter_set_name() alias: tenshi
bluetoothd[4444]: src/adapter.c:set_name() sending set local name command for index 0
bluetoothd[4444]: plugins/hostname.c:update_class() major: 0x01 minor: 0x03
bluetoothd[4444]: src/adapter.c:btd_adapter_set_class() class: major 1 minor 3
bluetoothd[4444]: src/adapter.c:set_dev_class() sending set device class command for index 0
bluetoothd[4444]: profiles/network/manager.c:panu_server_probe() path /org/bluez/hci0
bluetoothd[4444]: profiles/network/server.c:server_register() Registered interface org.bluez.NetworkServer1 on path /org/bluez/hci0
bluetoothd[4444]: profiles/network/manager.c:gn_server_probe() path /org/bluez/hci0
bluetoothd[4444]: profiles/network/manager.c:nap_server_probe() path /org/bluez/hci0
bluetoothd[4444]: profiles/audio/avrcp.c:avrcp_controller_server_probe() path /org/bluez/hci0
bluetoothd[4444]: src/adapter.c:adapter_service_add() /org/bluez/hci0
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Adding record with handle 0x10003
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 0000110f-0000-1000-8000-00805f9
bluetoothd[4444]: src/adapter.c:adapter_service_insert() /org/bluez/hci0
bluetoothd[4444]: src/adapter.c:add_uuid() sending add uuid command for index 0
bluetoothd[4444]: profiles/audio/avrcp.c:avrcp_target_server_probe() path /org/bluez/hci0
bluetoothd[4444]: src/adapter.c:adapter_service_add() /org/bluez/hci0
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Adding record with handle 0x10004
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000017-0000-1000-8000-00805f9
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00000100-0000-1000-8000-00805f9
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 00001002-0000-1000-8000-00805f9
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 0000110c-0000-1000-8000-00805f9
bluetoothd[4444]: src/sdpd-service.c:add_record_to_server() Record pattern UUID 0000110e-0000-1000-8000-00805f9
bluetoothd[4444]: src/adapter.c:adapter_service_insert() /org/bluez/hci0
bluetoothd[4444]: src/adapter.c:add_uuid() sending add uuid command for index 0
bluetoothd[4444]: profiles/audio/a2dp.c:a2dp_sink_server_probe() path /org/bluez/hci0
bluetoothd[4444]: profiles/audio/a2dp.c:a2dp_source_server_probe() path /org/bluez/hci0
bluetoothd[4444]: src/adapter.c:btd_adapter_unblock_address() hci0 00:00:00:00:00:00
bluetoothd[4444]: src/device.c:device_create_from_storage() address 00:1B:33:57:E1:03
bluetoothd[4444]: src/device.c:device_new() address 00:1B:33:57:E1:03
bluetoothd[4444]: src/device.c:device_new() Creating device /org/bluez/hci0/dev_00_1B_33_57_E1_03
bluetoothd[4444]: src/device.c:device_probe_profiles() Probing profiles for device 00:1B:33:57:E1:03
bluetoothd[4444]: src/device.c:device_set_bonded() bonded 1
bluetoothd[4444]: src/adapter.c:load_link_keys() hci0 keys 1 debug_keys 0
bluetoothd[4444]: src/adapter.c:adapter_service_insert() /org/bluez/hci0
bluetoothd[4444]: src/adapter.c:add_uuid() sending add uuid command for index 0
bluetoothd[4444]: src/adapter.c:set_did() hci0 source 2 vendor 1d6b product 246 version 50d
bluetoothd[4444]: src/adapter.c:adapter_register() Adapter /org/bluez/hci0 registered
bluetoothd[4444]: src/adapter.c:set_dev_class() sending set device class command for index 0
bluetoothd[4444]: src/adapter.c:set_name() sending set local name command for index 0
bluetoothd[4444]: src/adapter.c:set_mode() sending set mode command for index 0
bluetoothd[4444]: src/adapter.c:set_mode() sending set mode command for index 0
bluetoothd[4444]: src/adapter.c:set_discoverable() sending set mode command for index 0
bluetoothd[4444]: src/adapter.c:load_link_keys_complete() link keys loaded for hci0
bluetoothd[4444]: src/adapter.c:property_set_mode() sending Set Powered command for index 0
bluetoothd[4444]: src/adapter.c:dev_class_changed_callback() Class: 0x00010c
bluetoothd[4444]: src/attrib-server.c:attrib_db_update() handle=0x0008
bluetoothd[4444]: src/adapter.c:property_set_mode_complete() Success (0x00)
bluetoothd[4444]: src/adapter.c:new_settings_callback() Settings: 0x0000009b
bluetoothd[4444]: src/adapter.c:settings_changed() Changed settings: 0x00000001
bluetoothd[4444]: src/adapter.c:adapter_start() adapter /org/bluez/hci0 has been enabled
bluetoothd[4444]: src/adapter.c:connected_callback() hci0 device 00:1B:33:57:E1:03 connected eir_len 8
bluetoothd[4444]: src/adapter.c:dev_disconnected() Device 00:1B:33:57:E1:03 disconnected, reason 2
bluetoothd[4444]: src/adapter.c:adapter_remove_connection()
bluetoothd[4444]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr 00:1B:33:57:E1:03 type 0 status 0xe
bluetoothd[4444]: src/device.c:device_bonding_complete() bonding (nil) status 0x0e
bluetoothd[4444]: src/device.c:device_bonding_failed() status 14
bluetoothd[4444]: src/adapter.c:resume_discovery()
[-- Attachment #1.3: btmon --]
[-- Type: text/plain, Size: 11197 bytes --]
Bluetooth monitor ver 5.13
= New Index: 00:1F:E2:D9:95:A4 (BR/EDR,USB,hci0) [hci0] 0.040271
< HCI Command: Create Connection (0x01|0x0005) plen 13 [hci0] 3.434535
Address: 00:1B:33:57:E1:03 (Nokia Danmark A/S)
Packet type: 0xcc18
Page scan repetition mode: R2 (0x02)
Page scan mode: Mandatory (0x00)
Clock offset: 0x0000
Role switch: Allow slave (0x01)
> HCI Event: Command Status (0x0f) plen 4 [hci0] 3.436738
Create Connection (0x01|0x0005) ncmd 1
Status: Success (0x00)
> HCI Event: Connect Complete (0x03) plen 11 [hci0] 6.455010
Status: Success (0x00)
Handle: 11
Address: 00:1B:33:57:E1:03 (Nokia Danmark A/S)
Link type: ACL (0x01)
Encryption: Disabled (0x00)
< HCI Command: Read Remote Supported Features (0x01|0x001b) plen 2 [hci0] 6.455259
Handle: 11
> HCI Event: Read Remote Supported Features (0x0b) plen 11 [hci0] 6.456931
Status: Success (0x00)
Handle: 11
Features: 0xbf 0xee 0x0f 0x46 0x98 0x19 0x00 0x00
3 slot packets
5 slot packets
Encryption
Slot offset
Timing accuracy
Role switch
Sniff mode
Power control requests
Channel quality driven data rate (CQDDR)
SCO link
HV3 packets
u-law log synchronous data
A-law log synchronous data
CVSD synchronous data
Paging parameter negotiation
Power control
Transparent synchronous data
Enhanced Data Rate ACL 2 Mbps mode
Enhanced Data Rate ACL 3 Mbps mode
RSSI with inquiry results
AFH capable slave
AFH classification slave
3-slot Enhanced Data Rate ACL packets
5-slot Enhanced Data Rate ACL packets
AFH capable master
AFH classification master
< ACL Data TX: Handle 11 flags 0x02 dlen 10 [hci0] 6.457022
L2CAP: Information Request (0x0a) ident 1 len 2
Type: Extended features supported (0x0002)
> HCI Event: Command Status (0x0f) plen 4 [hci0] 6.458891
Read Remote Supported Features (0x01|0x001b) ncmd 1
Status: Success (0x00)
< HCI Command: Remote Name Request (0x01|0x0019) plen 10 [hci0] 6.458911
Address: 00:1B:33:57:E1:03 (Nokia Danmark A/S)
Page scan repetition mode: R2 (0x02)
Page scan mode: Mandatory (0x00)
Clock offset: 0x0000
> HCI Event: Command Status (0x0f) plen 4 [hci0] 6.459915
Remote Name Request (0x01|0x0019) ncmd 1
Status: Success (0x00)
> HCI Event: Page Scan Repetition Mode Change (0x20) plen 7 [hci0] 6.475926
Address: 00:1B:33:57:E1:03 (Nokia Danmark A/S)
Page scan repetition mode: R1 (0x01)
> HCI Event: Max Slots Change (0x1b) plen 3 [hci0] 6.477917
Handle: 11
Max slots: 5
> HCI Event: Remote Name Req Complete (0x07) plen 255 [hci0] 6.534004
Status: Success (0x00)
Address: 00:1B:33:57:E1:03 (Nokia Danmark A/S)
Name: Mokona
@ Device Connected: 00:1B:33:57:E1:03 (0) flags 0x0000
07 09 4d 6f 6b 6f 6e 61 ..Mokona
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 6.685951
Num handles: 1
Handle: 11
Count: 1
> ACL Data RX: Handle 11 flags 0x02 dlen 16 [hci0] 6.689951
L2CAP: Information Response (0x0b) ident 1 len 8
Type: Extended features supported (0x0002)
Result: Success (0x0000)
Features: 0x00000003
Flow control mode
Retransmission mode
< ACL Data TX: Handle 11 flags 0x02 dlen 12 [hci0] 6.690033
L2CAP: Connection Request (0x02) ident 2 len 4
PSM: 3 (0x0003)
Source CID: 64
> ACL Data RX: Handle 11 flags 0x02 dlen 10 [hci0] 6.698952
L2CAP: Information Request (0x0a) ident 1 len 2
Type: Extended features supported (0x0002)
< ACL Data TX: Handle 11 flags 0x02 dlen 16 [hci0] 6.699033
L2CAP: Information Response (0x0b) ident 1 len 8
Type: Extended features supported (0x0002)
Result: Success (0x0000)
Features: 0x000002b8
Enhanced Retransmission Mode
Streaming Mode
FCS Option
Fixed Channels
Unicast Connectionless Data Reception
> ACL Data RX: Handle 11 flags 0x02 dlen 16 [hci0] 6.700917
L2CAP: Connection Response (0x03) ident 2 len 8
Destination CID: 64
Source CID: 64
Result: Connection successful (0x0000)
Status: No further information available (0x0000)
< ACL Data TX: Handle 11 flags 0x02 dlen 16 [hci0] 6.700987
L2CAP: Configure Request (0x04) ident 3 len 8
Destination CID: 64
Flags: 0x0000
Option: Maximum Transmission Unit (0x01)
MTU: 1013
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 6.702942
Num handles: 1
Handle: 11
Count: 2
> ACL Data RX: Handle 11 flags 0x02 dlen 12 [hci0] 6.707953
L2CAP: Configure Request (0x04) ident 2 len 4
Destination CID: 64
Flags: 0x0000
< ACL Data TX: Handle 11 flags 0x02 dlen 18 [hci0] 6.708040
L2CAP: Configure Response (0x05) ident 2 len 10
Source CID: 64
Flags: 0x0000
Result: Success (0x0000)
Option: Maximum Transmission Unit (0x01)
MTU: 672
> ACL Data RX: Handle 11 flags 0x02 dlen 18 [hci0] 6.708953
L2CAP: Configure Response (0x05) ident 3 len 10
Source CID: 64
Flags: 0x0000
Result: Success (0x0000)
Option: Maximum Transmission Unit (0x01)
MTU: 672
< ACL Data TX: Handle 11 flags 0x02 dlen 8 [hci0] 6.709118
Channel: 64 len 4 [PSM 3 mode 0] {chan 0}
03 3f 01 1c .?..
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 6.712024
Num handles: 1
Handle: 11
Count: 2
> ACL Data RX: Handle 11 flags 0x02 dlen 8 [hci0] 6.715916
Channel: 64 len 4 [PSM 3 mode 0] {chan 0}
03 73 01 d7 .s..
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 6.936047
Num handles: 1
Handle: 11
Count: 1
> ACL Data RX: Handle 11 flags 0x02 dlen 12 [hci0] 8.730078
L2CAP: Disconnection Request (0x06) ident 3 len 4
Destination CID: 64
Source CID: 64
< ACL Data TX: Handle 11 flags 0x02 dlen 12 [hci0] 8.730170
L2CAP: Disconnection Response (0x07) ident 3 len 4
Destination CID: 64
Source CID: 64
> HCI Event: Number of Completed Packets (0x13) plen 5 [hci0] 8.936081
Num handles: 1
Handle: 11
Count: 1
< HCI Command: Disconnect (0x01|0x0006) plen 3 [hci0] 10.732120
Handle: 11
Reason: Remote User Terminated Connection (0x13)
> HCI Event: Command Status (0x0f) plen 4 [hci0] 10.735276
Disconnect (0x01|0x0006) ncmd 1
Status: Success (0x00)
> HCI Event: Disconnect Complete (0x05) plen 4 [hci0] 10.898262
Status: Success (0x00)
Handle: 11
Reason: Connection Terminated By Local Host (0x16)
@ Device Disconnected: 00:1B:33:57:E1:03 (0) reason 2
[-- Attachment #1.4: hcidump --]
[-- Type: text/plain, Size: 3809 bytes --]
HCI sniffer - Bluetooth packet analyzer ver 5.13
device: hci0 snap_len: 1500 filter: 0xffffffffffffffff
< HCI Command: Create Connection (0x01|0x0005) plen 13
bdaddr 00:1B:33:*:*:* ptype 0xcc18 rswitch 0x01 clkoffset 0x0000
Packet type: DM1 DM3 DM5 DH1 DH3 DH5
> HCI Event: Command Status (0x0f) plen 4
Create Connection (0x01|0x0005) status 0x00 ncmd 1
> HCI Event: Connect Complete (0x03) plen 11
status 0x00 handle 11 bdaddr 00:1B:33:*:*:* type ACL encrypt 0x00
< HCI Command: Read Remote Supported Features (0x01|0x001b) plen 2
handle 11
> HCI Event: Read Remote Supported Features (0x0b) plen 11
status 0x00 handle 11
Features: 0xbf 0xee 0x0f 0x46 0x98 0x19 0x00 0x00
< ACL data: handle 11 flags 0x02 dlen 10
L2CAP(s): Info req: type 2
> HCI Event: Command Status (0x0f) plen 4
Read Remote Supported Features (0x01|0x001b) status 0x00 ncmd 1
< HCI Command: Remote Name Request (0x01|0x0019) plen 10
bdaddr 00:1B:33:*:*:* mode 2 clkoffset 0x0000
> HCI Event: Command Status (0x0f) plen 4
Remote Name Request (0x01|0x0019) status 0x00 ncmd 1
> HCI Event: Page Scan Repetition Mode Change (0x20) plen 7
bdaddr 00:1B:33:*:*:* mode 1
> HCI Event: Max Slots Change (0x1b) plen 3
handle 11 slots 5
> HCI Event: Remote Name Req Complete (0x07) plen 255
status 0x00 bdaddr 00:1B:33:*:*:* name 'Mokona'
> HCI Event: Number of Completed Packets (0x13) plen 5
handle 11 packets 1
> ACL data: handle 11 flags 0x02 dlen 16
L2CAP(s): Info rsp: type 2 result 0
Extended feature mask 0x0003
Flow control mode
Retransmission mode
< ACL data: handle 11 flags 0x02 dlen 12
L2CAP(s): Connect req: psm 3 scid 0x0040
> ACL data: handle 11 flags 0x02 dlen 10
L2CAP(s): Info req: type 2
< ACL data: handle 11 flags 0x02 dlen 16
L2CAP(s): Info rsp: type 2 result 0
Extended feature mask 0x02b8
Enhanced Retransmission mode
Streaming mode
FCS Option
Fixed Channels
Unicast Connectless Data Reception
> ACL data: handle 11 flags 0x02 dlen 16
L2CAP(s): Connect rsp: dcid 0x0040 scid 0x0040 result 0 status 0
Connection successful
< ACL data: handle 11 flags 0x02 dlen 16
L2CAP(s): Config req: dcid 0x0040 flags 0x00 clen 4
MTU 1013
> HCI Event: Number of Completed Packets (0x13) plen 5
handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 12
L2CAP(s): Config req: dcid 0x0040 flags 0x00 clen 0
< ACL data: handle 11 flags 0x02 dlen 18
L2CAP(s): Config rsp: scid 0x0040 flags 0x00 result 0 clen 4
MTU 672
> ACL data: handle 11 flags 0x02 dlen 18
L2CAP(s): Config rsp: scid 0x0040 flags 0x00 result 0 clen 4
MTU 672
< ACL data: handle 11 flags 0x02 dlen 8
L2CAP(d): cid 0x0040 len 4 [psm 3]
RFCOMM(s): SABM: cr 1 dlci 0 pf 1 ilen 0 fcs 0x1c
> HCI Event: Number of Completed Packets (0x13) plen 5
handle 11 packets 2
> ACL data: handle 11 flags 0x02 dlen 8
L2CAP(d): cid 0x0040 len 4 [psm 3]
RFCOMM(s): UA: cr 1 dlci 0 pf 1 ilen 0 fcs 0xd7
> HCI Event: Number of Completed Packets (0x13) plen 5
handle 11 packets 1
> ACL data: handle 11 flags 0x02 dlen 12
L2CAP(s): Disconn req: dcid 0x0040 scid 0x0040
< ACL data: handle 11 flags 0x02 dlen 12
L2CAP(s): Disconn rsp: dcid 0x0040 scid 0x0040
> HCI Event: Number of Completed Packets (0x13) plen 5
handle 11 packets 1
< HCI Command: Disconnect (0x01|0x0006) plen 3
handle 11 reason 0x13
Reason: Remote User Terminated Connection
> HCI Event: Command Status (0x0f) plen 4
Disconnect (0x01|0x0006) status 0x00 ncmd 1
> HCI Event: Disconn Complete (0x05) plen 4
status 0x00 handle 11 reason 0x16
Reason: Connection Terminated by Local Host
[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 198 bytes --]
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: A problem with "rfcomm bind" and wvdial
@ 2014-01-05 15:49 Gianluca Anzolin
2014-01-06 11:33 ` Gianluca Anzolin
0 siblings, 1 reply; 4+ messages in thread
From: Gianluca Anzolin @ 2014-01-05 15:49 UTC (permalink / raw)
To: andrey.vihrov; +Cc: peter, marcel, gregkh, jslaby, linux-bluetooth
Hello,
I looked at your problem this afternoon and I think I know what's happening:
wvdial is opening the port with the flag O_NONBLOCK. As expected the rfcomm
code returns immediately instead of waiting for the BT connection to come
up. Then wvdial sends the AT commands and the writes fail.
In the past it worked because the carrier_raised() logic was open coded inside
the rfcomm code: it always waited for a successful or failed connection even
with a non-blocking tty.
But now the code uses the tty_port methods and won't wait for a successful
bluetooth connection on open().
But there is more: when wvdial terminates, it will set the CLOCAL flag for the
tty and this will result in the same behaviour described above, even without
setting the O_NONBLOCK flag. This will affect other users of the tty.
These two cases make clear that the use of carrier_raised() method was not that
fair after all: while that allowed us to remove some code we now have to work
around it to get the previous behaviour.
For example we could mask off the O_NONBLOCK flag before opening the port and
then restore it when the tty_port_open() is completed. We could do something
similar for the CLOCAL flag: always remove it in rfcomm_tty_set_termios().
The alternative is to remove the carrier_raised() method and wait for the BT
connection in rfcomm_dev_activate() like the old code did.
I'm CC-ing some people who know the code better than me to get a suggestion
on how to proceed.
Thank you,
Gianluca
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: A problem with "rfcomm bind" and wvdial
2014-01-05 15:49 A problem with "rfcomm bind" and wvdial Gianluca Anzolin
@ 2014-01-06 11:33 ` Gianluca Anzolin
2014-01-06 16:06 ` Andrey Vihrov
0 siblings, 1 reply; 4+ messages in thread
From: Gianluca Anzolin @ 2014-01-06 11:33 UTC (permalink / raw)
To: andrey.vihrov; +Cc: peter, marcel, gregkh, jslaby, linux-bluetooth
[-- Attachment #1: Type: text/plain, Size: 550 bytes --]
On Sun, Jan 05, 2014 at 04:49:42PM +0100, Gianluca Anzolin wrote:
> Hello,
>
> I looked at your problem this afternoon and I think I know what's happening:
> wvdial is opening the port with the flag O_NONBLOCK. As expected the rfcomm
> code returns immediately instead of waiting for the BT connection to come
> up. Then wvdial sends the AT commands and the writes fail.
Hi,
could you please test the attached patch?
If it works and people are ok with it I'll submit it along with the other fixes
I already sent to the list.
Thank you,
Gianluca
[-- Attachment #2: 0001-rfcomm-always-wait-for-a-bt-connection-on-open.patch --]
[-- Type: text/x-diff, Size: 5303 bytes --]
>From 2da1095aceb22bc323ceb9e1a4f43d92ebe5c2b6 Mon Sep 17 00:00:00 2001
From: Gianluca Anzolin <gianluca@sottospazio.it>
Date: Mon, 6 Jan 2014 12:19:51 +0100
Subject: [PATCH] rfcomm: always wait for a bt connection on open()
This patch fixes a regression introduced with the recent rfcomm tty
rework.
The current code uses the carrier_raised() method to wait for the
bluetooth connection when a process opens the tty. However processes may
open the port with the O_NONBLOCK flag or set the CLOCAL termios flag.
In those cases the open() syscall returns immediately without waiting
for the bluetooth connection to complete. This behaviour confuses
userspace which expects a working bluetooth connection.
The patch removes the carries_raised() method and restores the previous
working behaviour by waiting for the connection in rfcomm_dev_activate().
Signed-off-by: Gianluca Anzolin <gianluca@sottospazio.it>
Reported-by: Andrey Vihrov <andrey.vihrov@gmail.com>
---
net/bluetooth/rfcomm/tty.c | 79 ++++++++++++++++++++++++++++------------------
1 file changed, 49 insertions(+), 30 deletions(-)
diff --git a/net/bluetooth/rfcomm/tty.c b/net/bluetooth/rfcomm/tty.c
index 84fcf9f..e9683bb 100644
--- a/net/bluetooth/rfcomm/tty.c
+++ b/net/bluetooth/rfcomm/tty.c
@@ -58,6 +58,7 @@ struct rfcomm_dev {
uint modem_status;
struct rfcomm_dlc *dlc;
+ wait_queue_head_t conn_wait;
struct device *tty_dev;
@@ -103,20 +104,57 @@ static void rfcomm_dev_destruct(struct tty_port *port)
module_put(THIS_MODULE);
}
-/* device-specific initialization: open the dlc */
-static int rfcomm_dev_activate(struct tty_port *port, struct tty_struct *tty)
+static struct device *rfcomm_get_device(struct rfcomm_dev *dev)
{
- struct rfcomm_dev *dev = container_of(port, struct rfcomm_dev, port);
+ struct hci_dev *hdev;
+ struct hci_conn *conn;
+
+ hdev = hci_get_route(&dev->dst, &dev->src);
+ if (!hdev)
+ return NULL;
+
+ conn = hci_conn_hash_lookup_ba(hdev, ACL_LINK, &dev->dst);
+
+ hci_dev_put(hdev);
- return rfcomm_dlc_open(dev->dlc, &dev->src, &dev->dst, dev->channel);
+ return conn ? &conn->dev : NULL;
}
-/* we block the open until the dlc->state becomes BT_CONNECTED */
-static int rfcomm_dev_carrier_raised(struct tty_port *port)
+/* device-specific initialization: open the dlc */
+static int rfcomm_dev_activate(struct tty_port *port, struct tty_struct *tty)
{
struct rfcomm_dev *dev = container_of(port, struct rfcomm_dev, port);
+ DEFINE_WAIT(wait);
+ int err;
- return (dev->dlc->state == BT_CONNECTED);
+ err = rfcomm_dlc_open(dev->dlc, &dev->src, &dev->dst, dev->channel);
+ if (err)
+ return err;
+
+ while (1) {
+ prepare_to_wait(&dev->conn_wait, &wait, TASK_INTERRUPTIBLE);
+
+ if (dev->dlc->state == BT_CLOSED) {
+ err = -dev->err;
+ break;
+ } else if (dev->dlc->state == BT_CONNECTED)
+ break;
+ else if (signal_pending(current)) {
+ err = -ERESTARTSYS;
+ break;
+ }
+
+ tty_unlock(tty);
+ schedule();
+ tty_lock(tty);
+ }
+ finish_wait(&dev->conn_wait, &wait);
+
+ if (!err)
+ device_move(dev->tty_dev, rfcomm_get_device(dev),
+ DPM_ORDER_DEV_AFTER_PARENT);
+
+ return err;
}
/* device-specific cleanup: close the dlc */
@@ -135,7 +173,6 @@ static const struct tty_port_operations rfcomm_port_ops = {
.destruct = rfcomm_dev_destruct,
.activate = rfcomm_dev_activate,
.shutdown = rfcomm_dev_shutdown,
- .carrier_raised = rfcomm_dev_carrier_raised,
};
static struct rfcomm_dev *__rfcomm_dev_get(int id)
@@ -169,22 +206,6 @@ static struct rfcomm_dev *rfcomm_dev_get(int id)
return dev;
}
-static struct device *rfcomm_get_device(struct rfcomm_dev *dev)
-{
- struct hci_dev *hdev;
- struct hci_conn *conn;
-
- hdev = hci_get_route(&dev->dst, &dev->src);
- if (!hdev)
- return NULL;
-
- conn = hci_conn_hash_lookup_ba(hdev, ACL_LINK, &dev->dst);
-
- hci_dev_put(hdev);
-
- return conn ? &conn->dev : NULL;
-}
-
static ssize_t show_address(struct device *tty_dev, struct device_attribute *attr, char *buf)
{
struct rfcomm_dev *dev = dev_get_drvdata(tty_dev);
@@ -258,6 +279,7 @@ static int rfcomm_dev_add(struct rfcomm_dev_req *req, struct rfcomm_dlc *dlc)
tty_port_init(&dev->port);
dev->port.ops = &rfcomm_port_ops;
+ init_waitqueue_head(&dev->conn_wait);
skb_queue_head_init(&dev->pending);
@@ -575,12 +597,9 @@ static void rfcomm_dev_state_change(struct rfcomm_dlc *dlc, int err)
BT_DBG("dlc %p dev %p err %d", dlc, dev, err);
dev->err = err;
- if (dlc->state == BT_CONNECTED) {
- device_move(dev->tty_dev, rfcomm_get_device(dev),
- DPM_ORDER_DEV_AFTER_PARENT);
+ wake_up_interruptible(&dev->conn_wait);
- wake_up_interruptible(&dev->port.open_wait);
- } else if (dlc->state == BT_CLOSED)
+ if (dlc->state == BT_CLOSED)
tty_port_tty_hangup(&dev->port, false);
}
@@ -1096,7 +1115,7 @@ int __init rfcomm_init_ttys(void)
rfcomm_tty_driver->subtype = SERIAL_TYPE_NORMAL;
rfcomm_tty_driver->flags = TTY_DRIVER_REAL_RAW | TTY_DRIVER_DYNAMIC_DEV;
rfcomm_tty_driver->init_termios = tty_std_termios;
- rfcomm_tty_driver->init_termios.c_cflag = B9600 | CS8 | CREAD | HUPCL;
+ rfcomm_tty_driver->init_termios.c_cflag = B9600 | CS8 | CREAD | HUPCL | CLOCAL;
rfcomm_tty_driver->init_termios.c_lflag &= ~ICANON;
tty_set_operations(rfcomm_tty_driver, &rfcomm_ops);
--
1.8.5.2
^ permalink raw reply related [flat|nested] 4+ messages in thread
* Re: A problem with "rfcomm bind" and wvdial
2014-01-06 11:33 ` Gianluca Anzolin
@ 2014-01-06 16:06 ` Andrey Vihrov
0 siblings, 0 replies; 4+ messages in thread
From: Andrey Vihrov @ 2014-01-06 16:06 UTC (permalink / raw)
To: Gianluca Anzolin; +Cc: peter, marcel, gregkh, jslaby, linux-bluetooth
[-- Attachment #1: Type: text/plain, Size: 848 bytes --]
Hello,
Thanks for the update. I applied the patch to the bluetooth-next
kernel and it seems to work as expected. I ran wvdial several times in a
row, and it was able to connect every time.
> On Sun, Jan 05, 2014 at 04:49:42PM +0100, Gianluca Anzolin wrote:
> > Hello,
> >
> > I looked at your problem this afternoon and I think I know what's happening:
> > wvdial is opening the port with the flag O_NONBLOCK. As expected the rfcomm
> > code returns immediately instead of waiting for the BT connection to come
> > up. Then wvdial sends the AT commands and the writes fail.
>
> Hi,
>
> could you please test the attached patch?
>
> If it works and people are ok with it I'll submit it along with the other fixes
> I already sent to the list.
>
> Thank you,
> Gianluca
--
Andrey Vihrov <andrey.vihrov@gmail.com>
[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 198 bytes --]
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2014-01-06 16:06 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2014-01-05 15:49 A problem with "rfcomm bind" and wvdial Gianluca Anzolin
2014-01-06 11:33 ` Gianluca Anzolin
2014-01-06 16:06 ` Andrey Vihrov
-- strict thread matches above, loose matches on Subject: below --
2014-01-03 18:24 Andrey Vihrov
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox