marq24 / UUID0xFD6FTracer

Scan your current environment for devices running an app that make us of the ExposureNotification Service
GNU General Public License v3.0
122 stars 6 forks source link

Doesn't work on my phone #9

Open adolfintel opened 3 years ago

adolfintel commented 3 years ago

I found the app on F-Droid but it doesn't seem to work for me, nothing happens when I start the scanner.

Oneplus 3T Lineage 17.1 (Android 10) No gapps

marq24 commented 3 years ago

Would you mind providing more details? - Is the Scanner not starting at all ? Do you get the Sticky Notification? Is the play/stop button toggling it's icon - and do you have a second phone in range that is sending a Beacon UUID FD6F Signal (which is obviously only the case if this is either an iPhone or a Android with installed GoogleServices...

Might be a screenshot could/would help - even better a logcat trace output

adolfintel commented 3 years ago

Here's what happens:

Here's what I see in logcat:

2020-09-10 20:37:03.649 18106-18106/? W/SCANNER: Service created
2020-09-10 20:37:03.649 18106-18106/? I/SCANNER: onBind called Intent { cmp=com.emacberry.uuid0xfd6fscan/.ScannerService }
2020-09-10 20:37:03.654 18106-18106/? W/SCANNER: onStartCommand() start
2020-09-10 20:37:03.654 18106-18106/? D/SCANNER: initBtLE() started...
2020-09-10 20:37:03.668 18106-18106/? W/SCANNER: onStartCommand() completed
2020-09-10 20:37:08.670 18106-18106/? W/SCANNER: checkForScannStart() triggered - mScannIsRunning: FALSE
2020-09-10 20:37:33.285 18106-18106/? I/SCANNER: onUnbind called Intent { cmp=com.emacberry.uuid0xfd6fscan/.ScannerService }
2020-09-10 20:37:34.763 18106-18106/? W/SCANNER: checkForScannStart() triggered - mScannIsRunning: FALSE
2020-09-10 20:37:39.176 18106-18106/? W/SCANNER: checkForScannStart() triggered - mScannIsRunning: FALSE
2020-09-10 20:37:39.753 18106-18106/? W/SCANNER: checkForScannStart() triggered - mScannIsRunning: FALSE
2020-09-10 20:37:42.916 18106-18106/? W/SCANNER: Service.onDestroy() called - shutting down Scanner
2020-09-10 20:37:42.938 18106-18106/? W/SCANNER: Service destroyed!!! (fine)
2020-09-10 20:37:44.170 18106-18106/? W/SCANNER: Service created
2020-09-10 20:37:44.170 18106-18106/? I/SCANNER: onBind called Intent { cmp=com.emacberry.uuid0xfd6fscan/.ScannerService }
2020-09-10 20:37:44.177 18106-18106/? W/SCANNER: onStartCommand() start
2020-09-10 20:37:44.177 18106-18106/? D/SCANNER: initBtLE() started...
2020-09-10 20:37:44.184 18106-18106/? W/SCANNER: onStartCommand() completed
2020-09-10 20:37:45.708 18465-18465/? W/SCANNER: Service created
2020-09-10 20:37:45.708 18465-18465/? W/SCANNER: onStartCommand() start
2020-09-10 20:37:45.708 18465-18465/? D/SCANNER: initBtLE() started...
2020-09-10 20:37:45.722 18465-18465/? W/SCANNER: onStartCommand() completed
2020-09-10 20:37:46.405 18465-18465/? I/SCANNER: onBind called Intent { cmp=com.emacberry.uuid0xfd6fscan/.ScannerService }
2020-09-10 20:37:50.717 18535-18535/? W/SCANNER: Service created
2020-09-10 20:37:50.717 18535-18535/? W/SCANNER: onStartCommand() start
2020-09-10 20:37:50.717 18535-18535/? D/SCANNER: initBtLE() started...
2020-09-10 20:37:50.734 18535-18535/? W/SCANNER: onStartCommand() completed
2020-09-10 20:37:52.575 18535-18535/? D/SCANNER: start intent extras: Bundle[mParcelledData.dataSize=40]
2020-09-10 20:37:53.923 18535-18535/? I/SCANNER: onBind called Intent { cmp=com.emacberry.uuid0xfd6fscan/.ScannerService }

Here's a crash:

2020-09-10 20:37:54.041 18535-18535/? E/AndroidRuntime: FATAL EXCEPTION: main
    Process: com.emacberry.uuid0xfd6fscan, PID: 18535
    java.lang.NullPointerException: Attempt to invoke virtual method 'int java.lang.String.hashCode()' on a null object reference
        at com.emacberry.uuid0xfd6fscan.ScannerService.getBeaconCountByType(ScannerService.java:643)
        at com.emacberry.uuid0xfd6fscan.ScannerActivity$1.onServiceConnected(ScannerActivity.java:66)
        at android.app.LoadedApk$ServiceDispatcher.doConnected(LoadedApk.java:1953)
        at android.app.LoadedApk$ServiceDispatcher$RunConnection.run(LoadedApk.java:1985)
        at android.os.Handler.handleCallback(Handler.java:883)
        at android.os.Handler.dispatchMessage(Handler.java:100)
        at android.os.Looper.loop(Looper.java:214)
        at android.app.ActivityThread.main(ActivityThread.java:7356)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:491)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:940)    

Edit: forgot the screenshots photo_2020-09-10_20-39-43 photo_2020-09-10_20-39-49

marq24 commented 3 years ago

THANKS a lot for all the Details...

I'll just have provided a new build/update that is including a fix for the crash (nullpointer) - Nevertheless there is an important thing to know - the Service is trying to "detect" if it's successfully running - therefor the code checks, if a Beacon was found after the start of the service - and IF not the code restarts the internal ScanService...

This means, as long as you do not have a Phone in Range that have a active Beacon running (that can be received by the app), then the restart will be triggered... This will be tried till a first beacon comes in range.

adolfintel commented 3 years ago

If it can help you, check out my app, OpenPods: https://github.com/adolfintel/OpenPods

It implements a BLE scanner similar to yours.

ljl-covid commented 3 years ago

Another open source app that can spot 0xFD6F broadcasts (and all other BLE broadcasts) is on F-Droid as BLExplorer.

Maybe I should open a separate issue for this, but I'm not sure it's a different issue, and also I've got no logcat to show... yesterday it was showing me 0 beacons even though I knew I had another phone next to me broadcasting one, and when I looked with BLExplorer, sure enough, it was there, the line containing 0xfd6f.

marq24 commented 3 years ago

@ljl-covid there exist plenty of different core BT-Scanners - I have mentioned RaMBLE myself in the readme and I use nRF from Nordic... But these general scanners have the limitation that they require some knowledge, how to use them.

UUID 0xFD6F Tracer tries to make the use as simple as possible - If you report, that UUID 0xFD6F Tracer did not show you a Beacon while another App (on the same device) is showing it, then this can have so many different reasons - plenty of them have to do with timing issues - others with the differences between a core Bluetooth Scanner and a special BluetoothLE Scanner.

I do not doubt, that UUID 0xFD6F Tracer might not see a BTLE Beacon with UUID 0xFD6F at the same time as another app - but over time both apps should be able to discover the same Beacons (if this beacon have been created by the enabled ExposureNotificationFramwork). If you observe a different behaviour - fire up AndroidStudio, clone this repro and debug it locally in order to find the root cause.

Here locally at my home we have 3 iPhones sending a ExpouseNotificationSignal and I have two addition Android phones - and each time somebody is leaving home I can see this after a short while in the number that will be displayed... But as explained here #1 there are some timeouts implemented as well (so a beacon out of range will still be "visible" (as number).

@adolfintel I hope with the 0.9.1.8 that null pointer is fixed (also you can check in the logcat he scan sequence (and the restarts if no beacon will be found after a certain amount of time)

ljl-covid commented 3 years ago

@marq24 sorry, I didn't mention BLExplorer as "competition", merely as another open source BLE scanner in case its code could also be useful, and because of this quirk that happens on my device, to show it wasn't a quirk on the emitting device side.

I do observe a different behavior... letting your app sit there, it sometimes says, for long periods of time, "Active beacons: 0" and only "Scanning Environment..." without a number in the notification. I did that while having it sit next to a device with the Immuni app installed for a while, and BLExplorer could see that. It was a "static" situation. I also noticed that if I stopped your app and then started it again, then it would see the device. But I don't have Android Studio and due to its EULA I don't plan to install it, so I guess the best I can offer is logcat.

marq24 commented 3 years ago

Logcat output of 5-10min filtered by 'SCANNER' would be interesting to see... I just can assume, that we will see plenty of 'checkForScannStart() triggered - mScannIsRunning: FALSE' - but that's just wild guessing. Something that could be also possible is, that just the notification update is failing (would be also worth checking, if you keep the activity open, if this would/will show you the one device?) This would indicate, that Service running in "FORGROUND" is not possible - but let's wait for the logcat output and then let's speculate...

marq24 commented 3 years ago

Ok - after the first coffee in the morning... When you compare a BTLE-Scanner App running as Activity with the UUID-Trace running as Background Service (and display the result via the Notification), then you are comparing apple with pears. Specially when you say, that an App restart would show the expected result.

My assumption is, that you have configured/customize your phone to have as less background processes running as possible (which is of course totally reasonable) - but you have to understand, that this app is doing it's main task/job as background service - so please make sure that you allow the app to be running in the background/as foreground service.

You might need to add the app to the "none optimized" Apps - AppInfo -> Advanced -> Battery -> Background restrictions -> Remove Apps - AppInfo -> Advanced -> Battery -> battery optimisation -> add the app to 'not optimized' list

marq24 commented 3 years ago

@adolfintel @ljl-covid would be cool to get some feedback, if the added switch (to disable background optimization) in 0.9.1.9/10 would solve fix your issues (of course only when the os-optimization will be disabled)

adolfintel commented 3 years ago

Sorry for the late reply. It seems to work now :)

ljl-covid commented 3 years ago

@marq24 with the new version, after disabling battery optimizatinos, I've left the phone in standby without touching it for an hour or so, so that presumably Doze mode kicked in; afterwards it was indicating 4 beacons, so apparently the issue isn't there anymore... but it only happened sometimes, so I'll have to test for a bit longer to know for sure.

I'm confused about this, though: isn't the fact that the app has a foreground notification supposed to prevent it from being suspended? I think it's that way with other apps I have...

ljl-covid commented 3 years ago

@marq24 nope, after the night it's doing it again, even with battery optimizations disabled. I managed to take a screenshot to demonstrate (originally I wanted to do it split-screen between UUID 0xFD6F Scanner and BLExplorer, but the former seems not to support split-screen):

Screenshot_20200922-160745_BLExplorer

The device at the bottom is broadcasting a 0xFD6F beacon, but UUID 0xFD6F Scanner's notification is not showing it (and it says "0" in the actual screen, too, of course).

The app is running with "1 process and 1 service" when I check it in the "Running services" window:

Screenshot_20200922-161450_Settings

Here is some logcat (grepped for the package name):

09-22 05:05:57.284 24592 24592 E ActivityThread: Performing stop of activity that is already stopped: {com.emacberry.uuid0xfd6fscan/com.emacberry.uuid0xfd6fscan.ScannerActivity}
09-22 05:05:57.284 24592 24592 E ActivityThread: java.lang.RuntimeException: Performing stop of activity that is already stopped: {com.emacberry.uuid0xfd6fscan/com.emacberry.uuid0xfd6fscan.ScannerActivity}
09-22 15:25:38.084  1226 17853 I ActivityManager: START u0 {flg=0x20000000 cmp=com.emacberry.uuid0xfd6fscan/.ScannerActivity (has extras)} from uid 10519
09-22 15:25:38.096  1226 17853 W ActivityManager: startActivity called from non-Activity context; forcing Intent.FLAG_ACTIVITY_NEW_TASK for: Intent { flg=0x20000000 cmp=com.emacberry.uuid0xfd6fscan/.ScannerActivity (has extras) }
09-22 15:25:38.338 24592 24592 E ActivityThread: Performing stop of activity that is already stopped: {com.emacberry.uuid0xfd6fscan/com.emacberry.uuid0xfd6fscan.ScannerActivity}
09-22 15:25:38.338 24592 24592 E ActivityThread: java.lang.RuntimeException: Performing stop of activity that is already stopped: {com.emacberry.uuid0xfd6fscan/com.emacberry.uuid0xfd6fscan.ScannerActivity}
09-22 15:25:38.379  1226 17853 I ActivityManager: Activity reported stop, but no longer stopping: ActivityRecord{974567b u0 com.emacberry.uuid0xfd6fscan/.ScannerActivity t26786}
09-22 15:25:38.389  1226 17853 D WindowManager: relayoutVisibleWindow: Window{23d159d u0 com.emacberry.uuid0xfd6fscan/com.emacberry.uuid0xfd6fscan.ScannerActivity EXITING} mAnimatingExit=true, mRemoveOnExit=false, mDestroying=false
09-22 16:05:32.553  1226  2604 I ActivityManager: START u0 {flg=0x20000000 cmp=com.emacberry.uuid0xfd6fscan/.ScannerActivity (has extras)} from uid 10519
09-22 16:05:32.594  1226  2604 W ActivityManager: startActivity called from non-Activity context; forcing Intent.FLAG_ACTIVITY_NEW_TASK for: Intent { flg=0x20000000 cmp=com.emacberry.uuid0xfd6fscan/.ScannerActivity (has extras) }
09-22 16:06:49.748  1226  1894 I WindowManager: Failed to capture screenshot of Token{7cd6c3a ActivityRecord{4c69765 u0 com.emacberry.uuid0xfd6fscan/.ScannerActivity t26787}} appWin=Window{8e153da u0 com.emacberry.uuid0xfd6fscan/com.emacberry.uuid0xfd6fscan.ScannerActivity} drawState=4
09-22 16:29:37.307  1226  1271 I ActivityManager: START u0 {act=android.settings.APPLICATION_DETAILS_SETTINGS dat=package:com.emacberry.uuid0xfd6fscan flg=0x10008000 cmp=com.android.settings/.applications.InstalledAppDetails bnds=[102,595][982,819]} from uid 1000
09-22 16:29:38.502 22671 22671 E AppInfoBase: Package: com.emacberry.uuid0xfd6fscan not found for user: 10

Clearly(?) some things are about me taking a screenshot of it, then the user 10 thing, I do have a second user on the system but I don't know why that's coming up... I'm not really sure the culprit is in this logcat, but this is all it shows me.

marq24 commented 3 years ago

BLExplorer is an Activity (at least I think so) - and you can't compare this Activity with the BackgroundService - but I don't want to go into details here - PRO/CONS about Activity vs. Service and when to use what for which purpose.

So it looks like that for what ever reason the running service (even if it's requesting "Foreground with Notification") will be stopped/halted/paused on your device after a certain time. Of course this should not happen - but I'll do all i could in order to prevent that... but I am fully aware, that's the nature of an OS to keep the house clean...

Since you have already logcat running - please grab for SCANNER which is the internal log tag of the Service - the logcat output you just shared is generated by the OS - and not by uuid0xfd6fscan [and it's just about the additional Activity that I have implemented that shows you the same info then the Notification + the option to go to the settings] - so the only thing that can help us to find a possible reason is to search for the 'ScannerService' class and log tag 'SCANNER'