Hi all, We managed to progress a little. It seems that Iotivity is not compatible with BlueZ 5.40 due to some changes in the device api. ( they removed the property GattServices from the device proxy object.)
So after downgrading it to 5.37 and removing the function that depends on the 3.19 kernel (SetDiscoveryFilter) we got different output. Now it seems that iotivity is able to connect to bluetooth device, find its services, make the multicast discover request but it can?t receive the response. I managed to get more logs and hopefully someone can make more meaning out of them as my knowledge in the bluetooth stack is limited. I suspect that the problem is the function ?CAGattClientOnCharacteristicPropertiesChanged? not being called. I will be posting them on pastebin to save some space. journalctl -u bluetooth: http://pastebin.com/QhW283td <http://pastebin.com/QhW283td> btm: http://pastebin.com/9bRBQuaR <http://pastebin.com/9bRBQuaR> Iotivity: http://pastebin.com/NFNVJ5dW <http://pastebin.com/NFNVJ5dW> Thanks, Hudo. > On Jul 6, 2016, at 4:18 PM, Hudo Assen?o <hudo.assenco at gmail.com> wrote: > > Hi all, > > After some more research I found this wiki page > https://wiki.iotivity.org/ble_for_linux > <https://wiki.iotivity.org/ble_for_linux> that list the kernel 3.19 as a > requirement for BLE to work. Unfortunately my platform only supports kernel > 3.10. > > Is there a way to make it work on a 3.10 kernel ? > > Thanks, > Hudo > >> On Jul 5, 2016, at 1:14 PM, Hudo Assen?o <hudo.assenco at gmail.com >> <mailto:hudo.assenco at gmail.com>> wrote: >> >> 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 >> <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. >> > -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://lists.iotivity.org/pipermail/iotivity-dev/attachments/20160711/c543a1e1/attachment.html>
