Hi all,
I am currently experiencing a problem with the BLE connection in iotivity. It
doesn?t find the GATT Services from my BLE Server (device). I ran through the
code and it looks like the function responsible to detect GATT services is
?CAGattClientOnDevicePropertiesChanged? which is connected through GDBUS with
the "g-properties-changed" signal.
The function is properly connected, as I verified that with
"g_signal_handler_is_connected". But it never gets called.
The only case that I can get ?CAGattClientOnDevicePropertiesChanged? to be
called is when I restart my device and at the same time I run the iotivity
stack. The log output is from this case.
I don?t know how to further debug this problem. Does any one have experience
with BlueZ and the BLE code in a way that could help me debug this ?
This is my Log output:
23:29.585 INFO: OIC_RI_STACK: Entering OCInit
23:29.585 DEBUG: OIC_CA_CONN_MGR: IoTivity version is v1.1.0
23:29.585 DEBUG: OIC_CA_CONN_MGR: CAInitialize
23:29.585 DEBUG: OIC_CA_INF_CTR: Set Receiver handle callback
23:29.585 DEBUG: OIC_CA_INF_CTR: Set network handle callback
23:29.585 DEBUG: OIC_CA_INF_CTR: Set error handle callback
23:29.585 DEBUG: UTHREADPOOL: IN
23:29.585 DEBUG: UTHREADPOOL: OUT
23:29.585 DEBUG: OIC_CA_QING: thread initialize..
23:29.585 DEBUG: UTHREADPOOL: IN
23:29.585 DEBUG: UTHREADPOOL: OUT
23:29.585 DEBUG: OIC_CA_QING: thread initialize..
23:29.585 DEBUG: OIC_CA_RETRANS: thread initialize
23:29.585 DEBUG: OIC_CA_BWT: CAInitializeBlockWiseTransfer
23:29.585 DEBUG: UTHREADPOOL: IN
23:29.585 DEBUG: OIC_CA_QING: message handler main thread start..
23:29.585 DEBUG: OIC_CA_QING: wait..
23:29.585 DEBUG: UTHREADPOOL: OUT
23:29.585 DEBUG: OIC_CA_RETRANS: retransmission main thread start
23:29.585 DEBUG: OIC_CA_INF_CTR: initialize adapters..
23:29.585 DEBUG: OIC_CA_RETRANS: wait..there is no retransmission data.
23:29.585 DEBUG: OIC_CA_IP_ADAP: IN
23:29.585 DEBUG: OIC_CA_INF_CTR: 1 type adapter, register complete!
23:29.585 INFO: OIC_CA_IP_ADAP: OUT IntializeIP is Success
23:29.585 DEBUG: OIC_CA_LE_ADAP: IN
23:29.585 DEBUG: OIC_CA_LE_ADAP: IN - CAInitLEAdapterMutex
23:29.585 DEBUG: OIC_CA_LE_ADAP: OUT
23:29.585 DEBUG: OIC_CA_LE_ADAP: IN
23:29.585 DEBUG: OIC_CA_LE_ADAP: OUT
23:29.585 DEBUG: OIC_CA_LE_ADAP: IN
23:29.585 DEBUG: OIC_CA_LE_ADAP: OUT
23:29.585 DEBUG: OIC_CA_LE_ADAP: IN
23:29.585 ERROR: OIC_CA_LE_ADAP: CALEConnectionStateChangedCb failed!
23:29.585 DEBUG: OIC_CA_LE_ADAP: OUT
23:29.585 DEBUG: OIC_CA_INF_CTR: 2 type adapter, register complete!
23:29.585 DEBUG: OIC_CA_LE_ADAP: OUT
23:29.585 DEBUG: OIC_CA_CONN_MGR: Selected network : 1
23:29.585 DEBUG: OIC_CA_NW_CONFIG: Create network list
23:29.585 DEBUG: OIC_CA_NW_CONFIG: Add network type(IP)
23:29.585 DEBUG: OIC_CA_INF_CTR: Start the adapter of CAConnectivityType[1]
23:29.585 DEBUG: OIC_CA_QING: thread initialize..
23:29.585 DEBUG: UTHREADPOOL: IN
23:29.585 DEBUG: UTHREADPOOL: OUT
23:29.585 DEBUG: OIC_CA_QING: message handler main thread start..
23:29.585 DEBUG: OIC_CA_QING: wait..
23:29.585 INFO: OIC_CA_IP_SERVER: IPv6 unicast port: 38892
23:29.585 INFO: OIC_CA_IP_SERVER: IPv4 unicast port: 57814
23:29.585 DEBUG: OIC_CA_IP_SERVER: socket summary: u6=3, u6s=4, u4=7, u4s=8,
m6=5, m6s=6, m4=9, m4s=10
23:29.585 DEBUG: OIC_CA_IP_SERVER: port summary: u6 port=38892, u6s port=55574,
u4 port=57814, u4s port=58348, m6 port=5683,m6s port=5684, m4 port=5683, m4s
port=5684
23:29.585 DEBUG: OIC_CA_IP_MONITOR: Got ifaddrs
23:29.585 DEBUG: OIC_CA_IP_MONITOR: Added interface: wlan0 (2)
23:29.585 DEBUG: OIC_CA_IP_MONITOR: Added interface: usb0 (2)
23:29.585 DEBUG: OIC_CA_IP_MONITOR: Added interface: usb0 (10)
23:29.585 DEBUG: OIC_CA_IP_SERVER: IP network interfaces found: 3
23:29.585 DEBUG: OIC_CA_IP_SERVER: IPv4 network interface: wlan0
23:29.585 DEBUG: OIC_CA_IP_SERVER: IPv4 network interface: usb0
23:29.585 DEBUG: OIC_CA_IP_SERVER: IPv6 network interface: usb0
23:29.585 DEBUG: UTHREADPOOL: IN
23:29.585 DEBUG: UTHREADPOOL: OUT
23:29.585 DEBUG: OIC_CA_IP_SERVER: CAReceiveHandler thread started successfully.
23:29.585 DEBUG: OIC_CA_CONN_MGR: CAAddNetworkType(CA_IP_ADAPTER) function
returns result: 0
23:29.585 DEBUG: OIC_CA_CONN_MGR: Selected network : 4
23:29.585 DEBUG: OIC_CA_NW_CONFIG: Add network type(EDR) - Not Supported
23:29.585 DEBUG: OIC_CA_CONN_MGR: CAAddNetworkType(CA_RFCOMM_ADAPTER) function
returns result : 12
23:29.585 DEBUG: OIC_CA_CONN_MGR: Selected network : 2
23:29.585 DEBUG: OIC_CA_NW_CONFIG: Add network type(LE)
23:29.585 DEBUG: OIC_CA_INF_CTR: Start the adapter of CAConnectivityType[2]
23:29.585 DEBUG: OIC_CA_LE_ADAP: CAStartLE
23:29.585 DEBUG: BLE_INTERFACE: CAStartLEAdapter
23:29.585 DEBUG: UTHREADPOOL: IN
23:29.585 DEBUG: UTHREADPOOL: OUT
23:29.635 DEBUG: OIC_CA_CONN_MGR: CAAddNetworkType(CA_GATT_ADAPTER) function
returns result : 0
23:29.635 DEBUG: OIC_CA_CONN_MGR: Selected network : 32
23:29.635 DEBUG: OIC_CA_NW_CONFIG: Add network type(NFC) - Not Supported
23:29.635 DEBUG: OIC_CA_CONN_MGR: CAAddNetworkType(CA_ADAPTER_NFC) function
returns result : 12
23:29.635 DEBUG: OIC_CA_CONN_MGR: CARegisterHandler
23:29.635 DEBUG: OIC_CA_CONN_MGR: CAStartDiscoveryServer
23:29.635 DEBUG: OIC_CA_IP_MONITOR: Got ifaddrs
23:29.635 DEBUG: OIC_CA_IP_MONITOR: Added interface: wlan0 (2)
23:29.635 DEBUG: OIC_CA_IP_MONITOR: Added interface: usb0 (2)
23:29.635 DEBUG: OIC_CA_IP_MONITOR: Added interface: usb0 (10)
23:29.635 DEBUG: OIC_CA_IP_SERVER: IP network interfaces found: 3
23:29.635 DEBUG: OIC_CA_IP_SERVER: IPv4 network interface: wlan0
23:29.635 DEBUG: OIC_CA_IP_SERVER: IPv4 network interface: usb0
23:29.635 DEBUG: OIC_CA_IP_SERVER: IPv6 network interface: usb0
23:29.635 DEBUG: OIC_CA_LE_ADAP: IN - CAStartLEDiscoveryServer
23:29.635 DEBUG: OIC_CA_LE_ADAP: IN
23:29.635 DEBUG: OIC_CA_LE_ADAP: IN - CAInitLEClientSenderQueue
23:29.635 DEBUG: OIC_CA_QING: thread initialize..
23:29.635 DEBUG: OIC_CA_LE_ADAP: OUT - CAInitLEClientSenderQueue
23:29.635 DEBUG: OIC_CA_LE_ADAP: IN - CAInitLEReceiverQueue
23:29.635 DEBUG: OIC_CA_QING: thread initialize..
23:29.635 DEBUG: UTHREADPOOL: IN
23:29.635 DEBUG: UTHREADPOOL: OUT
23:29.635 DEBUG: OIC_CA_LE_ADAP: OUT
23:29.635 DEBUG: OIC_CA_LE_ADAP: OUT
23:29.635 DEBUG: OIC_CA_LE_ADAP: Before CAStartLEGattClient
23:29.635 INFO: BLE_INTERFACE: IN - CAStartLEGattClient
23:29.635 DEBUG: OIC_CA_QING: message handler main thread start..
23:29.635 DEBUG: OIC_CA_QING: wait..
23:29.645 INFO: BLE_CENTRAL: IN - CACentralConnect. C7:6A:A9:0B:DD:5F
23:30.335 INFO: BLE_CLIENT: IN - CAGattClientInitialize
23:30.335 INFO: BLE_CLIENT: is g-properties-changed connected: 1
23:30.335 INFO: BLE_CLIENT: IN - CAGattClientSetupService
23:30.335 INFO: BLE_CLIENT: Check if GATT services have already been discovered.
23:30.335 INFO: BLE_CLIENT: GATT services not yet discovered on LE peripheral:
C7:6A:A9:0B:DD:5F
23:30.335 DEBUG: UTHREADPOOL: IN
23:30.335 DEBUG: UTHREADPOOL: OUT
23:30.335 DEBUG: OIC_CA_LE_ADAP: OUT
23:30.335 INFO: OIC_RI_STACK: Client mode: CAStartDiscoveryServer
23:30.335 ERROR: SRM-AMSMGR: FreeCARequestInfo: Can't free memory. Received
NULL requestInfo
23:30.335 INFO: BLE_CLIENT: IN - CAGattClientOnDevicePropertiesChanged:
C7:6A:A9:0B:DD:5F
23:30.335 INFO: BLE_CLIENT: IN - CAGattClientOnDevicePropertiesChanged:
{'Connected': <true>}
23:30.335 INFO: BLE_CLIENT: OUT - CAGattClientOnDevicePropertiesChanged
23:30.335 DEBUG: OIC_CA_QING: message handler main thread start..
23:30.335 DEBUG: OIC_CA_QING: wait..
23:34.335 INFO: OIC_RI_STACK: Entering OCDoResource
23:34.335 DEBUG: OIC_CA_CONN_MGR: CAGenerateToken
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: token len:8, token:
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: 71 2D 5C 4D E0 3F FB 98
23:34.335 INFO: OIC_RI_CLIENTCB: Adding client callback with token
23:34.335 INFO: OIC_RI_CLIENTCB: 71 2D 5C 4D E0 3F FB 98
23:34.335 INFO: OIC_RI_CLIENTCB: Added Callback for uri : /oic/res
23:34.335 DEBUG: OIC_RM_UTIL: IN
23:34.335 DEBUG: OIC_RM_UTIL: IN
23:34.335 ERROR: OIC_RM_UTIL: Invalid input:options
23:34.335 INFO: OIC_RM_UTIL: Route option is not present
23:34.335 ERROR: OIC_RM: RM not initialized
23:34.335 DEBUG: OIC_RM: RM not initialized
23:34.335 DEBUG: OIC_RM_RAP: IN
23:34.335 DEBUG: OIC_RM_RAP: createoption dlen 0 slen [0]
23:34.335 DEBUG: OIC_RM_RAP: Source and destination is not present
23:34.335 DEBUG: OIC_RM_RAP: OptValue NOR Message Type
23:34.335 INFO: OIC_RM_RAP: Option Length is 1
23:34.335 DEBUG: OIC_RM_RAP: OUT
23:34.335 DEBUG: OIC_RM_UTIL: OUT
23:34.335 DEBUG: OIC_CA_CONN_MGR: CASendRequest
23:34.335 DEBUG: OIC_CA_MSG_HANDLE: CAPrepareSendData IN
23:34.335 DEBUG: UQUEUE: Queue Count : 1
Discovery initialised
23:34.335 DEBUG: OIC_CA_QING: wake up..
23:34.335 DEBUG: OIC_CA_MSG_HANDLE: Multicast message
23:34.335 DEBUG: OIC_CA_MSG_HANDLE: requestInfo is available..
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: url : coap://[::]//oic/res
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: parse Head Opt: 1
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: Head opt ID: 65524
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: Head opt data: ?
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: Head opt length: 1
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: curOptNumber[11], prevOptNumber[11],
optValueLen[3], optLength[4], msgLength[4]
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: curOptNumber[11], prevOptNumber[11],
optValueLen[3], optLength[4], msgLength[8]
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: curOptNumber[17], prevOptNumber[17],
optValueLen[1], optLength[2], msgLength[10]
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: curOptNumber[65524], prevOptNumber[65524],
optValueLen[1], optLength[4], msgLength[14]
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: transport type: 2, payload size: 0
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: token info token length: 8, token :
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: 71 2D 5C 4D E0 3F FB 98
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: [oic] opt will be added.
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: [11] pdu length
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: [res] opt will be added.
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: [15] pdu length
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: [<] opt will be added.
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: [19] pdu length
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: [?] opt will be added.
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: [21] pdu length
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: [25] pdu length after option
23:34.335 DEBUG: OIC_CA_MSG_HANDLE: PDU Maker - payload : (null)
23:34.335 DEBUG: OIC_CA_MSG_HANDLE: pdu header data :
23:34.335 DEBUG: OIC_CA_MSG_HANDLE: D8 01 01 71 2D 5C 4D E0 3F FB 98 B3 6F 69
63 03
23:34.335 DEBUG: OIC_CA_MSG_HANDLE: 72 65 73 61 3C E1 FE D6 C0
23:34.335 DEBUG: OIC_CA_MSG_HANDLE: pdu to send :
23:34.335 DEBUG: OIC_CA_MSG_HANDLE: D8 01 01 71 2D 5C 4D E0 3F FB 98 B3 6F 69
63 03
23:34.335 DEBUG: OIC_CA_MSG_HANDLE: 72 65 73 61 3C E1 FE D6 C0
23:34.335 DEBUG: OIC_CA_LE_ADAP: IN - CASendLEMulticastData CHANGED
23:34.335 DEBUG: OIC_CA_LE_ADAP: g_adapterType: 3
23:34.335 DEBUG: OIC_CA_LE_ADAP: IN
23:34.335 DEBUG: OIC_CA_LE_ADAP: Data Sending to LE layer [25]
23:34.335 ERROR: CA: parameter is null
23:34.335 DEBUG: UQUEUE: Queue Count : 1
23:34.335 DEBUG: OIC_CA_LE_ADAP: OUT
23:34.335 DEBUG: OIC_CA_LE_ADAP: OUT - CASendLEMulticastData
23:34.335 DEBUG: OIC_CA_MSG_HANDLE: CADestroyData IN
23:34.335 DEBUG: OIC_CA_MSG_HANDLE: CADestroyData OUT
23:34.335 DEBUG: OIC_CA_QING: wait..
23:34.335 DEBUG: OIC_CA_QING: wake up..
23:34.335 DEBUG: OIC_CA_LE_ADAP: IN - CALEClientSendDataThread
23:34.335 DEBUG: OIC_CA_LE_ADAP: Sending Multicast Data
23:34.335 INFO: BLE_INTERFACE: IN - CAUpdateCharacteristicsToAllGattServers
23:34.335 INFO: BLE_CLIENT: IN - CAGattClientSendDataToAll
23:34.335 INFO: BLE_CLIENT: IN - CAGattClientSendDataToAll - Entering loop
23:34.335 ERROR: OIC_CA_LE_ADAP: Update characteristics (all) failed, result
[255]
23:34.335 DEBUG: OIC_CA_LE_ADAP: CALEErrorHandler IN
23:34.335 DEBUG: OIC_CA_INF_CTR: received error from adapter in
interfacecontroller
23:34.335 DEBUG: OIC_CA_MSG_HANDLE: CAErrorHandler IN
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: pdu parse-transport type : 2
23:34.335 DEBUG: OIC_CA_PRTCL_MSG: pdu parse ret: 1
23:34.335 INFO: OIC_CA_PRTCL_MSG: there is no version info in coap header
23:34.335 DEBUG: OIC_CA_MSG_HANDLE: CAGenerateHandlerData IN
23:34.345 DEBUG: OIC_CA_MSG_HANDLE: address :
23:34.345 DEBUG: OIC_CA_PRTCL_MSG: COAP URI element : oic
23:34.345 DEBUG: OIC_CA_PRTCL_MSG: COAP URI element : res
23:34.345 DEBUG: OIC_CA_PRTCL_MSG: COAP URI element : <
23:34.345 DEBUG: OIC_CA_PRTCL_MSG: option[17] has an unsupported format [60]
23:34.345 DEBUG: OIC_CA_PRTCL_MSG: COAP URI element : ?
23:34.345 DEBUG: OIC_CA_PRTCL_MSG: inside token length : 8
23:34.345 DEBUG: OIC_CA_PRTCL_MSG: URL length:8
23:34.345 DEBUG: OIC_CA_MSG_HANDLE: error Info :
23:34.345 DEBUG: OIC_CA_MSG_HANDLE: optionID: 65524
23:34.345 DEBUG: OIC_CA_MSG_HANDLE: list: ?
23:34.345 DEBUG: OIC_CA_MSG_HANDLE: token:
23:34.345 DEBUG: OIC_CA_MSG_HANDLE: 71 2D 5C 4D E0 3F FB 98
23:34.345 DEBUG: OIC_CA_MSG_HANDLE: msgID: 0
23:34.345 DEBUG: OIC_CA_MSG_HANDLE: CAGenerateHandlerData OUT
23:34.345 DEBUG: UQUEUE: Queue Count : 1
23:34.345 DEBUG: OIC_CA_MSG_HANDLE: CAErrorHandler OUT
23:34.345 DEBUG: OIC_CA_LE_ADAP: CALEErrorHandler OUT
23:34.345 DEBUG: OIC_CA_QING: wait..
23:34.345 DEBUG: OIC_CA_MSG_HANDLE: error callback error: 255
23:34.345 INFO: OIC_RI_STACK: Enter HandleCAErrorResponse
23:34.345 INFO: OIC_RI_STACK: Exit HandleCAErrorResponse
23:34.345 DEBUG: OIC_CA_MSG_HANDLE: CADestroyData IN
23:34.345 DEBUG: OIC_CA_MSG_HANDLE: CADestroyData OUT
Thanks,
Hudo.
