search

NordicSemiconductor / Android-nRF-Mesh-Library

The Bluetooth Mesh Provisioner and Configurator library.
https://www.nordicsemi.com/
BSD 3-Clause "New" or "Revised" License
407 stars 175 forks source link

nrf mesh app not connecting after provisioning #79

Closed 3bu1 closed 5 years ago

3bu1 commented 5 years ago

Bug description Hi, I am trying to use nrf mesh android app to switch on light, I am facing issue some times during reconnect after provisioning. My observation is after provisioning if i disconnect and try to connect again, device is not connecting at one shot, instead app gives me below issue

  1. It just says connecting, nothing happens... as shown in this screenshot or
  2. It goes back to ProvisionedNodesScannerActivity as shown in this screenshot , if i click on available device, it might connect or go back to issue 1.

To Reproduce Steps to reproduce the behavior:

  1. After provisioning, go to network fragment screen
  2. Click on "connect" button
  3. ProvisionedNodesScannerActivity screen is displayed with list of available devices
  4. Click on one of the node for connection

Expected behavior App should connect to the device with in few seconds.

Platform details:

Logs / Screenshots Screen shots are linked as urls

I have also cloned project from github and tried building app from android studio still same issue. Any advice or help will be a great. thank you in advance.

roshanrajaratnam commented 5 years ago

@3bu1 Thanks for reporting this issue you are facing, usually if the device times out while connecting it should go back to the scanning screen. I will look in to this

3bu1 commented 5 years ago

@roshanrajaratnam any update regarding above issue? where you able to re-iterate and check it?

roshanrajaratnam commented 5 years ago

This issue is fixed internally so far. Unfortunately I currently don't have the same device as yours to reproduce this though. This will bug fix will be out in the next app release.

3bu1 commented 5 years ago

@roshanrajaratnam that's great. Thanks for help, will be in touch for app improvements.

3bu1 commented 5 years ago

I am using standard NRF52 board, and when will the next update going to be live? Is there any way i can get the changes (may be in a separate branch) before the release, so that i can also do a round of testing.

roshanrajaratnam commented 5 years ago

@3bu1 you may clone the dev branch and give it a go

3bu1 commented 5 years ago

@roshanrajaratnam i have cloned dev branch and tested, i see issue is still there. Is the code merged with Dev branch ?

roshanrajaratnam commented 5 years ago

Yes it's merged with dev branch. the issue is that I am unable to reproduce the same issue as you are having. Is it possible for you to test against another device? Also could you share the error log on the Android Studio console?

3bu1ihub commented 5 years ago

Here are couple of logs i found, i am not sure if they are useful, 

2018-12-13 14:07:31.139 1110-1152/? E/ANDR-PERF-MPCTL: Invalid profile no. 0, total profiles 0 only
2018-12-13 14:07:32.637 32589-32589/no.nordicsemi.android.nrfmeshprovisioner E/ActivityThread: Failed to find provider info for no.nordicsemi.android.log
2018-12-13 14:07:34.540 3236-3284/? E/bt_btif: bta_dm_acl_change new acl connetion:count = 2
2018-12-13 14:07:34.540 3236-3284/? E/bt_btif: bta_gattc_cache_load: can't open GATT cache file /data/misc/bluetooth/gatt_cache_ e7:aa:b3:a6:9c:32 for reading, error: No such file or directory
2018-12-13 14:07:36.159 1276-1460/? E/storaged: getDiskStats failed with result NOT_SUPPORTED and size 0
2018-12-13 14:07:36.679 3236-3257/? E/bt_btif_gattc: btif_gattc_upstreams_evt: Unhandled event (7)!
2018-12-13 14:07:36.679 3236-3257/? E/bt_btif_gattc: btif_gattc_upstreams_evt: Unhandled event (7)!
2018-12-13 14:07:37.027 3236-3284/? E/bt_btif: bta_gattc_process_indicate, ignore HID ind/notificiation
2018-12-13 14:07:37.458 17775-17775/? E/SearchServiceStarter: Task 174 failed or timed out. Client 78176821336072124 disconnecting from SearchService!
    java.util.concurrent.CancellationException: Task was cancelled.
        at com.google.common.r.a.d.fb(SourceFile:101)
        at com.google.common.r.a.d.get(SourceFile:80)
        at com.google.common.r.a.cw.l(SourceFile:1)
        at com.google.common.r.a.bd.n(SourceFile:34)
        at com.google.common.r.a.bf.run(SourceFile:4)
        at com.google.android.apps.gsa.shared.util.concurrent.b.bj.run(SourceFile:2)
        at android.os.Handler.handleCallback(Handler.java:873)
        at android.os.Handler.dispatchMessage(Handler.java:99)
        at android.os.Looper.loop(Looper.java:193)
        at android.app.ActivityThread.main(ActivityThread.java:6912)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:860)
2018-12-13 14:07:37.597 32589-32589/no.nordicsemi.android.nrfmeshprovisioner E/ActivityThread: Failed to find provider info for no.nordicsemi.android.log
2018-12-13 14:07:54.807 7156-7156/? E/roid.apps.turb: Not starting debugger since process cannot load the jdwp agent.
2018-12-13 14:08:00.305 6057-6241/? E/GoogleTagManager: Invalid macro: _gtm.loadEventEnabled
2018-12-13 14:08:01.674 7204-7204/? E/riersettingsex: Not starting debugger since process cannot load the jdwp agent.
2018-12-13 14:08:01.829 1108-2651/? E/LocSvc_APIClientBase: onCtrlCollectiveResponseCb:189] ERROR: 3 ID: 9280
2018-12-13 14:08:01.915 7224-7224/? E/.android.diale: Not starting debugger since process cannot load the jdwp agent.
2018-12-13 14:08:28.867 1108-2651/? E/LocSvc_APIClientBase: onCtrlCollectiveResponseCb:189] ERROR: 3 ID: 9287
2018-12-13 14:08:29.105 1108-2651/? E/LocSvc_APIClientBase: onCtrlCollectiveResponseCb:189] ERROR: 3 ID: 9294
2018-12-13 14:08:29.881 1108-2651/? E/LocSvc_APIClientBase: onCtrlCollectiveResponseCb:189] ERROR: 3 ID: 9301
2018-12-13 14:08:35.225 7303-7303/? E/stagram.androi: Not starting debugger since process cannot load the jdwp agent.
2018-12-13 14:08:35.237 7310-7310/? E/net.one97.payt: Not starting debugger since process cannot load the jdwp agent.
2018-12-13 14:08:35.670 7303-7303/? E/ACRA: Initializing ANR detector for process: com.instagram.android
2018-12-13 14:08:35.739 7310-7310/? E/WXSDKEngine: WXEnvironment.sApplication is null
2018-12-13 14:08:35.882 7310-7369/? E/jsengine: startupPie :1
2018-12-13 14:08:35.901 894-894/? E/SELinux: avc:  denied  { find } for interface=vendor.qti.hardware.perf::IPerf pid=7303 scontext=u:r:untrusted_app_27:s0:c512,c768 tcontext=u:object_r:hal_perf_hwservice:s0 tclass=hwservice_manager permissive=0
2018-12-13 14:08:35.901 7303-7303/? E/ANDR-PERF: IPerf::tryGetService failed!
2018-12-13 14:08:36.091 7380-7384/? E/jsengine: wson init
2018-12-13 14:08:36.160 1276-1460/? E/storaged: getDiskStats failed with result NOT_SUPPORTED and size 0
2018-12-13 14:08:36.445 7310-7339/? E/GoogleTagManager: Invalid macro: _gtm.loadEventEnabled
2018-12-13 14:08:36.718 7310-7501/? E/GoogleTagManager: Invalid macro: _gtm.loadEventEnabled
2018-12-13 14:08:36.724 7310-7337/? E/GoogleTagManager: Invalid macro: _gtm.loadEventEnabled
2018-12-13 14:08:36.861 7310-7337/? E/GoogleTagManager: Invalid macro: _gtm.loadEventEnabled
2018-12-13 14:08:36.872 7310-7535/? E/GoogleTagManager: Invalid macro: _gtm.loadEventEnabled
2018-12-13 14:08:36.958 7310-7546/? E/GoogleTagManager: Invalid macro: _gtm.loadEventEnabled
2018-12-13 14:08:37.045 7552-7552/? E/oid:videoplaye: Not starting debugger since process cannot load the jdwp agent.
2018-12-13 14:08:37.070 7569-7569/? E/am.android:mqt: Not starting debugger since process cannot load the jdwp agent.
2018-12-13 14:08:37.457 7552-7552/? E/ACRA: Skipping ANR Detector for process: com.instagram.android:videoplayer
2018-12-13 14:08:37.514 7569-7569/? E/ACRA: Skipping ANR Detector for process: com.instagram.android:mqtt
2018-12-13 14:08:38.791 7613-7613/? E/android.gms:ca: Not starting debugger since process cannot load the jdwp agent.
2018-12-13 14:08:50.984 3538-26316/? E/WakeLock: GCM_HB_ALARM release without a matched acquire!
2018-12-13 14:09:00.249 1108-2651/? E/LocSvc_APIClientBase: onCtrlCollectiveResponseCb:189] ERROR: 3 ID: 9308
2018-12-13 14:09:10.416 7686-7686/? E/meweatherwidge: Not starting debugger since process cannot load the jdwp agent.
2018-12-13 14:09:10.806 7706-7706/? E/viders.calenda: Not starting debugger since process cannot load the jdwp agent.
2018-12-13 14:09:19.448 7737-7737/? E/d.process.acor: Not starting debugger since process cannot load the jdwp agent.
2018-12-13 14:09:36.161 1276-1460/? E/storaged: getDiskStats failed with result NOT_SUPPORTED and size 0
2018-12-13 14:09:38.698 1108-2651/? E/LocSvc_APIClientBase: onCtrlCollectiveResponseCb:189] ERROR: 3 ID: 9315
2018-12-13 14:09:38.885 1108-2651/? E/LocSvc_APIClientBase: onCtrlCollectiveResponseCb:189] ERROR: 3 ID: 9322
2018-12-13 14:09:39.676 1108-2651/? E/LocSvc_APIClientBase: onCtrlCollectiveResponseCb:189] ERROR: 3 ID: 9329
2018-12-13 14:09:43.971 2006-2158/? E/libprocessgroup: Error encountered killing process cgroup uid 99120 pid 5977: No such file or directory
2018-12-13 14:10:01.833 7818-7818/? E/.apps.messagin: Not starting debugger since process cannot load the jdwp agent.
2018-12-13 14:10:08.130 1108-2651/? E/LocSvc_APIClientBase: onCtrlCollectiveResponseCb:189] ERROR: 3 ID: 9336
2018-12-13 14:10:24.166 1108-2651/? E/LocSvc_APIClientBase: onCtrlCollectiveResponseCb:189] ERROR: 3 ID: 9343
2018-12-13 14:10:25.144 1108-2651/? E/LocSvc_APIClientBase: onCtrlCollectiveResponseCb:189] ERROR: 3 ID: 9350
2018-12-13 14:10:36.163 1276-1460/? E/storaged: getDiskStats failed with result NOT_SUPPORTED and size 0
2018-12-13 14:11:08.378 3538-26316/? E/WakeLock: GCM_HB_ALARM release without a matched acquire!
2018-12-13 14:11:36.165 1276-1460/? E/storaged: getDiskStats failed with result NOT_SUPPORTED and size 0
2018-12-13 14:12:02.464 7818-7855/? E/Bugle: BuglePhoneNumberUtils: Not able to parse phone number MSISDN{} for country IN
    Error type: NOT_A_NUMBER. The string supplied did not seem to be a phone number.
        at owd.b(SourceFile:269)
        at fdr.e(SourceFile:53)
        at fdr.d(SourceFile:37)
        at fdr.a(SourceFile:78)
        at fek.b(SourceFile:26)
        at dkt.a(SourceFile:363)
        at com.google.android.apps.messaging.shared.datamodel.ParticipantRefresh.c(SourceFile:140)
        at com.google.android.apps.messaging.shared.datamodel.ParticipantRefresh.a(SourceFile:135)
        at com.google.android.apps.messaging.shared.datamodel.ParticipantRefresh.refreshParticipants(SourceFile:60)
        at com.google.android.apps.messaging.shared.datamodel.ParticipantRefresh.a(SourceFile:1)
        at com.google.android.apps.messaging.shared.datamodel.action.SelfParticipantsRefreshAction.doThrottledWork(SourceFile:3)
        at dcj.a(SourceFile:74)
        at com.google.android.apps.messaging.shared.datamodel.action.common.ThrottledAction.doBackgroundWork(SourceFile:13)
        at ddn.a(SourceFile:9)
        at dcx.run(SourceFile:8)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
        at java.lang.Thread.run(Thread.java:764)
2018-12-13 14:12:03.128 1110-1152/? E/ANDR-PERF-MPCTL: Invalid profile no. 0, total profiles 0 only
2018-12-13 14:12:03.251 3236-3284/? E/bt_stack: [ERROR:bta_gattc_utils.cc(464)] bta_gattc_mark_bg_conn unable to find the bg connection mask for: e7:aa:b3:a6:9c:32
2018-12-13 14:12:13.460 17775-17775/? E/SearchServiceStarter: Task 174 failed or timed out. Client 78176821336072126 disconnecting from SearchService!
    java.util.concurrent.CancellationException: Task was cancelled.
        at com.google.common.r.a.d.fb(SourceFile:101)
        at com.google.common.r.a.d.get(SourceFile:80)
        at com.google.common.r.a.cw.l(SourceFile:1)
        at com.google.common.r.a.bd.n(SourceFile:34)
        at com.google.common.r.a.bf.run(SourceFile:4)
        at com.google.android.apps.gsa.shared.util.concurrent.b.bj.run(SourceFile:2)
        at android.os.Handler.handleCallback(Handler.java:873)
        at android.os.Handler.dispatchMessage(Handler.java:99)
        at android.os.Looper.loop(Looper.java:193)
        at android.app.ActivityThread.main(ActivityThread.java:6912)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:860)
2018-12-13 14:12:13.548 7978-7978/? E/earhead:vanago: Not starting debugger since process cannot load the jdwp agent.
2018-12-13 14:12:13.683 7995-7995/? E/gearhead:share: Not starting debugger since process cannot load the jdwp agent.
2018-12-13 14:12:25.301 1110-1152/? E/ANDR-PERF-MPCTL: Invalid profile no. 0, total profiles 0 only
2018-12-13 14:12:26.692 32589-32589/no.nordicsemi.android.nrfmeshprovisioner E/ActivityThread: Failed to find provider info for no.nordicsemi.android.log
2018-12-13 14:12:28.613 3236-3284/? E/bt_btif: bta_dm_acl_change new acl connetion:count = 2
2018-12-13 14:12:28.613 3236-3284/? E/bt_btif: bta_gattc_cache_load: can't open GATT cache file /data/misc/bluetooth/gatt_cache_ e7:aa:b3:a6:9c:32 for reading, error: No such file or directory
2018-12-13 14:12:30.791 3236-3257/? E/bt_btif_gattc: btif_gattc_upstreams_evt: Unhandled event (7)!
2018-12-13 14:12:30.791 3236-3257/? E/bt_btif_gattc: btif_gattc_upstreams_evt: Unhandled event (7)!
2018-12-13 14:12:31.134 3236-3284/? E/bt_btif: bta_gattc_process_indicate, ignore HID ind/notificiation
2018-12-13 14:12:31.694 32589-32589/no.nordicsemi.android.nrfmeshprovisioner E/ActivityThread: Failed to find provider info for no.nordicsemi.android.log
2018-12-13 14:12:36.166 1276-1460/? E/storaged: getDiskStats failed with result NOT_SUPPORTED and size 0
2018-12-13 14:12:58.882 3538-26316/? E/WakeLock: GCM_HB_ALARM release without a matched acquire!
2018-12-13 14:12:58.977 8069-8069/? E/id.gms.learnin: Not starting debugger since process cannot load the jdwp agent.
roshanrajaratnam commented 5 years ago

@3bu1 Don't see anything here really. May be you should set your log filter to selected application so you can logs just from the mesh app. Also please try the latest version of the dev branch as this has some more fixes that have improved the issue you're facing

3bu1ihub commented 5 years ago

@roshanrajaratnam thank you will try dev branch once.