iOS Bluetooth LE with background-central stops after 1-10 minute

[Rollo62 639]

Hi there,

 

I have a very nasty problem again with BLE background mode.

Since I have the feeling that I have read all available articles and references about this topic worldwide, I still got no clue howto get this working.

All is working as expected under forground mode.

I hope that I can find some help or new ideas from here, because my head is going to be empty right now.

 

My setup is:
Rx10.3.3, XCode 11.4.1, iOS13.4.1, modern iPhone/iPad devices, all running fine with debug and release

 

My task:

I need to connect external Bluetooth LE peripherials, which works well in foreground.

They send data string (20 bytes) via unspecific custom characteristics, and I receive a HEX string, all that is fine.

With integrated logging functions in the app, I can monitor all behaviour in fore- and background.
Also debugging in fore- and background is no problem.

The devices send new datastring every < 2 sec., and the other every < 12 sec., anyway, both get killed after a while.
Maybe there are some restrictions in the datarate, I have read somewhere that peripherals > 2 sec. might considered to be killed (?),

but I cannot find anything about that in the official docs (also not much in the forums, seems only one case).

The connected devices stay connected, I cannot see any unusual behaviour, moreover I test with three different hardware types, all behave same.
So the issue seems not to be caused by the peripheral hardware.

 

I use the following settings:

Background modes:

    audio, bluetooth-central 

   (audio is used for Tts text-to-speech also in background, but its not used currently when receiving the data sting).

 

Info PList

    NSBluetoothPeripheralUsageDescription (deprecated, but shouldn't it be there for older devices ?)

                                                                       I didn't see any hint that this might be harmful.

    NSBluetoothAlwaysUsageDescription      (defining both should be any problem, right ?)

 

Permissions

  FMLocalNotificationPermission = true;

 

  Location: I do not use that, since Apple rejected this once, for adding an "unused background operation".
                   Some time before I added this background location as workaround to keep background mode permanently running.

                   I've made also some experiments before to add bluetooth-peripheral mode, as workaround to keep background mode permanently running.

                   Both workarounds should be not necessary, but I was searching for a stable way to keep background active.

  I touch the location in foreground, so that the Location permission alert appears to the user,, since I think that location
  might be relevant for Bluetooth as well, same as is under Android.
  But I don't use Location in foreground, but in the past it seems that location permission alert seemed to help keeping background active..
  When I take the location out completely, then also the Bluetooth LE permission alert seems not to appear every time, so sometimes BLE stays unavailable,
  and I need re-install to fix that problem.
  Thats why I touch the location in foreground, to enable location, and then I don't use the location any more, but BLE works with that approach in foreground.

                 

Device capabilities:

   I don't set specific BluetoothLE capabilities (UIRequiredDeviceCapabilities - bluetooth-le), as I never had to,

   and it works in foreground.

 

Application events, I handle all of them, and especially

    at WillEnterBackground
        I stop some unneeded timers and
        delay the Threaded ringbuffer for receiving and processing the data,
        by TThread.Sleep(500);.

        (I used this sleep method before, and it seem to work well under older iOS, but I never checked that too deeply).

    on BecameActive I restart the timer and threads

 

With TThread.Sleep(500); I throttle the thread which processes the incoming data (there is no data overflow, datarate is too small).

I can see the processed incoming data, also in background, the ReadCharacteristic appends the data to the ring buffer,

and then every 500ms the thread still seems to run and process this.

 

In background I stop running timer, and I can see data from the periperal coming in.
So far, so good, but longer operation (> 1min, > 10min) might kill the app in background.

With kill I mean, its not only in background stopped, but the app is killed and restarts fresh.

There is no other resource shortage, enough memory, etc., no need to be killed IMHO.

 

I don't see any place where my app could get stucked, so that Apple might push me out of business, I tried to implement all measures

to keep everything lightweight, asynchronously, only the threaded ringuffer sleeps for 500ms every cycle.

I can see the data package running through the process handler, even debugging in background is possible.

 

Please let me know if you have some helpful hints here, because I got stucked a while now by this issue,

I'm at my wits end right now.

 

 

 

 

 

 

Edited May 12, 2020 by Rollo62

[Rollo62 639]

To illustrate the problem I want to show some log file, from the background mode

 

//--> I'm starting BLE connection in foreground, the (F) shows when I'm in FG, the (B) means background
20:47:42.454 (F) - TS4Log: BLE_W: EvOnTimerProcess (2i) IsDiscoveringDev
20:47:42.962 (F) - TS4Log: BLE_W: <==== BLE DEVICE_READY 
20:47:42.962 (F) - TS4Log: BLE_W: <==== BLE_MANAGER MEASURE: 1;t1;22;°C;1;12;t2;21;°C;1;2
//--> The BLE MEASURE means: a data package received from the IoT device.
20:47:42.963 (F) - TS4Log: BLE_W: <==== BLE DEVICE_ENTER 
20:47:42.964 (F) - TS4Log: BLE_W: <==== BLE TTS BG_NOTE: 1
//--> The BLE TTS means: a test Tts speech output (saying "1") is launched, I can hear the TTS
20:47:44.406 (F) - TS4Log: BLE_W: EvOnTimerProcess (2i) IsDiscoveringDev
20:47:44.906 (F) - TS4Log: BLE_W: EvOnTimerProcess (2i) IsDiscoveringDev
20:47:45.407 (F) - TS4Log: BLE_W: EvOnTimerProcess (2i) IsDiscoveringDev
20:47:45.908 (F) - TS4Log: BLE_W: EvOnTimerProcess (2i) IsDiscoveringDev
20:47:46.408 (F) - TS4Log: BLE_W: EvOnTimerProcess (2i) IsDiscoveringDev
20:47:46.893 (F) - TS4Log: COMMN: <==== APP_EVENTS WillBecomeInactive
20:47:46.893 (F) - TS4Log: COMMN: <==== APP_EVENTS_WILL_BECOME_INACTIVE
20:47:46.893 (F) - TS4Log: BLE_W: TS4App_Feature_BLE.Request_Background (1) begin
20:47:46.893 (F) - TS4Log: BLE_W: TS4App_Feature_BLE.Request_Background (5) end
20:47:46.893 (F) - TS4Log: COMMN: TS4App_Feature_TtsSpeak.DoRefreshSettings: Background grant
20:47:46.893 (F) - TS4Log: COMMN: TS4App_Feature_TtsSpeak.DoRefreshSettings: Background granted
20:47:46.893 (F) - TS4Log: COMMN: TS4App_Feature_TtsSpeak.DoRefreshSettings: Background Audio request
20:47:46.894 (F) - TS4Log: COMMN: TS4App_Feature_TtsSpeak.DoRefreshSettings: Background Audio requested
20:47:47.557 (F) - TS4Log: BLE_W: <==== BLE_MANAGER MEASURE: 1;t1;22;°C;1;12;t2;21;°C;1;2
//--> The MEASURE means: a new data package arrived from the IoT device
20:47:47.558 (F) - TS4Log: BLE_W: <==== BLE TTS BG_NOTE: 2
//--> And the BLE TTS count the no. of received data packages (saying "2") is launched, I can hear the TTS
20:47:47.853 (F) - TS4Log: COMMN: <==== APP_EVENTS EnteredBackground
--> From here the app is in in BG mode, see (B)ackground (Timers stopped, receive thread throttled, BLE still receiving)
20:47:47.853 (B) - TS4Log: COMMN: <==== APP_EVENTS_ENTERED_BACKGROUND
20:47:48.245 (B) - TS4Log: BLE_W: TS4App_Feature_BLE.Request_Background (2) permit
20:47:48.245 (B) - TS4Log: BLE_W: TS4App_Feature_BLE.Request_Background (3) OK
20:47:48.245 (B) - TS4Log: BLE_W: TS4App_Feature_BLE.Request_Background (1) begin
20:47:48.245 (B) - TS4Log: BLE_W: TS4App_Feature_BLE.Request_Background (5) end
20:47:52.057 (B) - TS4Log: BLE_W: <==== BLE_MANAGER MEASURE: 1;t1;22;°C;1;12;t2;21;°C;1;2
//--> The first BLE MEASURE in BG mode, all is OK
20:47:52.059 (B) - TS4Log: BLE_W: <==== BLE TTS BG_NOTE: 3
//--> The first BLE TTS in BG: (saying "3"), I can hear the TTS voice, all OK
20:47:56.617 (B) - TS4Log: BLE_W: <==== BLE_MANAGER MEASURE: 1;t1;22;°C;1;12;t2;21;°C;1;2
20:47:56.619 (B) - TS4Log: BLE_W: <==== BLE TTS BG_NOTE: 4
20:48:01.177 (B) - TS4Log: BLE_W: <==== BLE_MANAGER MEASURE: 1;t1;22;°C;1;12;t2;21;°C;1;2
20:48:01.179 (B) - TS4Log: BLE_W: <==== BLE TTS BG_NOTE: 5
20:48:05.737 (B) - TS4Log: BLE_W: <==== BLE_MANAGER MEASURE: 1;t1;22;°C;1;12;t2;21;°C;1;2
20:48:05.741 (B) - TS4Log: BLE_W: <==== BLE TTS BG_NOTE: 6
20:48:10.297 (B) - TS4Log: BLE_W: <==== BLE_MANAGER MEASURE: 1;t1;22;°C;1;12;t2;21;°C;1;2
20:48:10.300 (B) - TS4Log: BLE_W: <==== BLE TTS BG_NOTE: 7
20:48:14.857 (B) - TS4Log: BLE_W: <==== BLE_MANAGER MEASURE: 1;t1;22;°C;1;12;t2;21;°C;1;2
20:48:14.859 (B) - TS4Log: BLE_W: <==== BLE TTS BG_NOTE: 8
20:48:19.417 (B) - TS4Log: BLE_W: <==== BLE_MANAGER MEASURE: 1;t1;22;°C;1;12;t2;21;°C;1;2
20:48:19.419 (B) - TS4Log: BLE_W: <==== BLE TTS BG_NOTE: 9
20:48:23.977 (B) - TS4Log: BLE_W: <==== BLE_MANAGER MEASURE: 1;t1;22;°C;1;12;t2;21;°C;1;2
20:48:23.980 (B) - TS4Log: BLE_W: <==== BLE TTS BG_NOTE: 10
20:48:28.538 (B) - TS4Log: BLE_W: <==== BLE_MANAGER MEASURE: 1;t1;22;°C;1;12;t2;21;°C;1;2
20:48:28.539 (B) - TS4Log: BLE_W: <==== BLE TTS BG_NOTE: 11
20:48:33.098 (B) - TS4Log: BLE_W: <==== BLE_MANAGER MEASURE: 1;t1;22;°C;1;12;t2;21;°C;1;2
20:48:33.100 (B) - TS4Log: BLE_W: <==== BLE TTS BG_NOTE: 12
--> Here suddenly its killed by Apple, but why, why, WHY ???

--> What else can be the reason to get killed suddenly, while TTS and BLE work fin in FG and BG ?

--> BTW: In foreground it may run until the battery is down, so its not a leak or something.

 

[Dave Nottage 662]

3 hours ago, Rollo62 said:

The devices send new datastring every < 2 sec.

My first guess would be that the data rate is too fast for too long, and iOS kills your app. Before I dive headlong into a deeper look, you might want to read this:

 

https://stackoverflow.com/a/34122794/3164070

 

..which links to:

 

https://developer.apple.com/library/archive/documentation/NetworkingInternetWeb/Conceptual/CoreBluetooth_concepts/CoreBluetoothBackgroundProcessingForIOSApps/PerformingTasksWhileYourAppIsInTheBackground.html

[Rollo62 639]

@Dave Nottage

Thanks for the comments, yes I also have considered the data rate.
But I have many different test devices, so in this app I tested with about 2 sec., 12. sec., and a manual, transmit on demand device.

I can say the data rate is not too fast, since a few bytes every 2 sec. shouldn't be a problem.

 

If the data rate is too low, then this might cause problems.
Although I think Aple should be happy with low data rate, as this is energy saving, and all longtime battery operated IoT try to do this.

As I said before, I had found one article somewhere where they considered a too low data rate as problem, but there was no answer if yes or no.

But I consider this as possible problem too.

 

Even if I do trigger a short text.-to-speech output with every data reception, the app doesn't get killed earlier,
I think its not an issue of too much data processing in the CPU.
What I do with the data is, to decode it, to store it in an sqlite DB.

 

I can even restart timers in the background during that processing (what I actually of course don't do).
In the logs I can see that when data is received, the phones wakes up, and timer start running normally (I tested a 500ms cycle).

Then after 5-10 sec. timers fall to sleep again, enough time to process my tasks.

Interesting finding, but I don't use timers in the background.

 

What I assume is that the app awakes with more or less normal features and performance, probably on a lower CPU task priority,
but since I have no other apps running at the same time there should be no problem.

 

These app killings happen already in testflight, and in debug, so before Apple is asking for a reason.

When I add some unused background modes to keep apps running, as workaround,

then Apple might ask for the reason I do require this, and I shall explain the functionality.

 

In my last workaround Apple noted that I shouldn't put an unused background mode.
So I've tried to remove that, but maybe I could explain to Apple that I need this to keep the app running in background ?

Would they accept this, I think they don't but never checked that ?

 

One possibility would be to invent a pseudo-function, which is not really needed in the app, but what I could show and explain to Apple as reason

 

Edit:

Another possibility beside the timings could be the ressources:

Quote

For the "normal" background transition, without background mode:

- Discard any images or media that you read directly from files.
- Discard any large, in-memory objects that you can recreate or reload from disk.
- Release access to the camera and other shared hardware resources.

I don't really clean up all available ressources, and since my app runs alone in a huge memory space,
thats why I think iOS is likely not getting into an out-of-memory situation.
Or did anybody has seen such crashes or other issues by not freeing memory ressources ?

 

Did Delphi implements already some kind of freeing ressources when entering background, like clearing imagelists, etc. ?

I'm afraid that is not done.

 

 

Edit 2:

The same app, 1:1, only with added bluetooth-peripheral background mode seems to keep the app active, and not get killed.

This are the same findings as I had before, used as workaround, but I think this is against Apples requirements (unused BG mode),

und will be likely to be rejected.
This cannot be the right solution, although it seems to work, isn't there any other clean option ?

 

Edit 3:

Not quite ready with Edit 2, the app seems still active right now, also data is received in the logs,
but the text-to-speech function isn't working in background any more (in foreground it still does).

Only sometimes this do speak in background, but maybe this issue is something else, maybe still some timer issues I have to check with TTS.

 

 

 

Edited May 13, 2020 by Rollo62

[Rollo62 639]

Some more tests regarding the missing background audio, it seems the TTS is started, but keeps silent.

 

11:23:16.355 (B) - TS4Log: AUD_P: TS4Measure_Tts.SpeakFree prepare: 7
11:23:16.356 (B) - TS4Log: AUD_P: TextToSpeechImplementation.SpeechRate_Set 100
11:23:16.356 (B) - TS4Log: AUD_P: TextToSpeechImplementation.Speak LUtterance.setRate
11:23:16.359 (B) - TS4Log: AUD_P: TextToSpeechImplementation.Speak BG granted
11:23:16.359 (B) - TS4Log: AUD_P: TS4App_Feature_TtsSpeak.Request_Background
11:23:16.360 (B) - TS4Log: AUD_P: <=== AUDIO_PLAY IOS SESSION ENABLE
11:23:16.360 (B) - TS4Log: AUD_P: <=== AUDIO_PLAY IOS SESSION AVAudioSession created
--> The AVAudioSession is prepared for AVAudioSessionCategoryPlayback category and setActive( True ), without errors.
11:23:16.369 (B) - TS4Log: AUD_P: TS4App_Feature_TtsSpeak.Request_Background AV BG enabled
11:23:16.369 (B) - TS4Log: AUD_P: TextToSpeechImplementation.Speak BG granted
11:23:16.369 (B) - TS4Log: AUD_P: TextToSpeechImplementation.Conf_SpeechSynthesizer release
11:23:16.369 (B) - TS4Log: AUD_P: TextToSpeechImplementation.Conf_SpeechSynthesizer re-created
11:23:16.370 (B) - TS4Log: AUD_P: TextToSpeechImplementation.Speak set voice
11:23:16.371 (B) - TS4Log: AUD_P: TextToSpeechImplementation.Speak play (speakUtterance)
11:23:16.372 (B) - TS4Log: BLE_W: <==== BLE TTS BG_NOTE: 7
11:23:17.180 (B) - TS4Log: AUD_P: TextToSpeech speechSynthesizerDidStartSpeechUtterance
--> This shows TTS is started, as the event has fired, but its still silent in BG

 

[Rollo62 639]

I have analysed the crash report, see enclosed, which gives some hints.

Quote

Wakeups:          45001 wakeups over the last 244 seconds (184 wakeups per second average), exceeding limit of 150 wakeups per second over 300 seconds

But I don't have threads that wakeup so frequently (I reduced the processing thread to 500ms, as said, by TThread.Sleep())

 

Maybe the reason could be the TextToSpeech thread, which is also in the stacklist, I have to check where this sits and what it does exaclty.

Are there any known background issues with the TTS ?

 

This looks to me like blocking something, trying to finish, while it cant.

From above logs I have seen that TTS has launched (speechSynthesizerDidStartSpeechUtterance),
but no sound and no EndOfSpeech event occurs     (speechSynthesizerDidFinishSpeechUtterance).

Probably somewhere inbetween sits the troublemaker.

 

What else could cause so many wakeups, and what exaclty wakes up (Thread.Sleep) ?

Maybe the Sleep method is not the best, I will try with TEvent.

 

Stack.txt

Edited May 14, 2020 by Rollo62

[Rollo62 639]

I have done some more tests, but cannot really say that I know whats going on here.

 

Maybe I point out some more facts I can see:

- The app works fine in foreground (FG), and may crash in (BG)

- The BG crash occurs when the phone looses the IoT device, while connected in BG all is fine.

- The BG crash never happens in my office, I can even move out-of-range while the IoT gracefully disconnects,
   and can be reconnect after that (while app in BG can be opened, its not a new start).

- The app in BG can send a notification when disconnect, all this is OK.

- When connected in FG, I can move about 15m, still the connection keeps active (no disconnect, no crash)

  When connected in BG, when I move 15m, the connection gets disconnected (no crash).
- It seems that BG operation uses maybe less energy or less QoS

 

All that would be OK, only

- in some critical places the same app on same phone crashes directly when entering BG
   these places are offices where a lot of RF noise can be seen (about 50 BLE devices in the scan, manye WiFi devices, ...).
- these places contain many surrounding IoT devices, like smartwatches, several nearby (< 50m) WiFi company routers

- in normal places, I also have about 20 IoT devices, and some WiFi devices nearby, but maybe not that many as in above.

 

What happens in those critical places is

- The app works fine in foreground (FG), and crash directly when entering (BG)

- No notification is sended before, means OnDisconnect is not normally fired

- The app cannot really be logged, as it can be in normal places

 

When I make experiments with different IoT, one 2sec, one 12sec., both are two different devices,

so maybe also they have other different settings.
 

The interesting I can see in the critical places:

- the 2sec. device work in BG, no crash
- the 12sec. device shows all negative behaviour from above

 

This leads me to the question:

Does the iOS Phones switch to different power-mode, or energy-saving mode, when the data rate is lower (e.g. < 10sec.) ?

This would be my only explanation for the odd behaviour, that a fast sending device keeps iOS more active (maybe within the 10 sec. range),

so the Phone has better capabilities to keep the connection.

Is there any paper or site from Apple that would explain such behaviour ?

 

I have searched the web deeply, but I have not found any matching info to my assumption, maybe there is some help out there ?

 

This is interesting reading

https://github.com/opentrace-community/opentrace-ios/issues/4

Also regarding background state restoration.

I have not implemented that, but of course that may help, but its not supported in FMX.

 

I've put this questions also as double-post into the German DP.

 

Edited June 3, 2020 by Rollo62