Derzeit bin ich gerade dabei meine App Seewetter Pro (im AppStore, auf Facebook, bei Twitter) zu aktualisieren. Ein ganz besonderes Feature dieser App ist u.a. der Ankeralarm, eine Funktion, die mit Hilfe des GPS eines iPhone/iPad die Position eines Segelbootes vor Anker überwacht. Damit diese Überwachung über mindestens volle 8 Stunden funktioniert, muss die Überwachung im Hintergrund funktionieren, denn die App kann nicht einfach 8 Stunden lang das Display an lassen, und die Nutzer wollen natürlich auch zwischendurch nochmal ihre Mails einsehen können trotz Überwachung.
Das jedoch bedeutet, die Positionsüberwachung muss auch dann 100 Prozent funktionieren, wenn die App im Hintergrund ist und dazu gehört z.B. wenn ich kurz den LockScreen sehe (Lock-Taste gedrückt oder AutoLock), oder wenn ich den Homebutton doppeltippe um die Taskbar unten zu sehen und es gehört ganz klassisch dazu die App zu schließen mit dem Home-Button. Das Gerät schaut dann aus als würde es nichts tun, es tut aber doch etwas, und das merkt man dann auch später am Stromverbrauch.
Vier Screenshots vom Ankeralarm auf einem iPod 5
Hintergrundaktivitäten sind von Apple allerdings starken Einschränkungen unterworfen, und eine ebensolche Einschränkung habe ich unter iOS 6 bemerkt als ich jetzt mein Update freigeben wollte und einen letzten Test gemacht habe. Obwohl meine App zu der Kategorie Apps gehört, denen Hintergrundaktivität explizit erlaubt ist (weil die Positionsüberwachung per GPS zu dieser Art Funktionen gehört, für die es erlaubt ist) funktionierte der Ankeralarm plötzlich nur noch ca. 5 Stunden lang (ja ich führe Echttests durch die mehr als 8 Stunden dauern). Große Verwunderung machte sich bei mir breit, denn der Algorithmus den ich dafür implementiert hatte lief noch unter iOS 5 perfekt den ganzen Tag hindurch beliebig lange.
Nun muss ich dazu sagen, dass Apple für Hintergrund GPS Nutzung eine spezielle Art vorgibt, wie das zu funktionieren hat. Der CLLocationManger (des CoreLocation Framework) muss dafür in exakt dem Moment, in dem die App in den Hintergrund geht seinen CLLocationMangerDelegate gesetzt haben. Der Delegate muss die Methode didUpdateLocations implementieren, die dann aufgerufen wird sobald der CLLocationManager eine neue Position ermittelt hat. Beim in-den-Hintergrund-gehen muss man (auch wenn CLLocationManager zuvor schon Positionen übermittelt hat also aktiv war) erneut startUpdatingLocation aufrufen in einem Extrathread. Und das ist unter iOS 6 definitiv neu & leider notwendig.
Soweit so unkompliziert. Im Hintergrund wird nun obwohl der Rest der App „schläft“ (z.B. sämtliche NSTimer) einzig didUpdateLocations noch aufgerufen. Wie genau das passiert ist mir immer noch unklar, denn der Aufruf im Hintergrund unterliegt so einigen Beschränkungen. So ist es z.B. nicht möglich ein Audio auszugeben im Hintergrund. Zumindest nicht innerhalb dieses didUpdateLocations-Aufruf und das obwohl ich auch das Hintergrundflag für Audio gesetzt hatte. Für den Ankeralarm war das leider keine Lösung. Ich brauche unbedingt Audiofeedback für den Nutzer (siehe Screenshot 3).
Ein Workaround stellen sogenannte Backgroundtasks dar, die man sobald die App in den Hintergrund geht anmelden kann, und die je nachdem ca. 10 bis 20 Minuten lang laufen dürfen, dann werden diese aber beendet. Einen solchen Backgroundtask hatte ich unter iOS 5 eingerichtet, dieser hatte seinen eigenen NSTimer und war in der Lage z.B. alle 10 Sekunden ein Audio abzuspielen (z.B: einen „Beep“), was in didUpdateLocations ja nicht möglich war. So konnte man gut erkennen, ob im Hintergrund noch alles läuft, weil man es ja auch hören kann per Audiofeedback.
In diesem Backgroundtask, der wie gesagt Laufzeitbegrenzt ist auf wenige Minuten, habe ich dann regelmäßig die aktualisierte Positionsinformation ausgewertet und verarbeitet (z.B. ein Protokoll der Positionsänderungen auf Disk geschrieben). Wurde eine kritische Positionsänderung festgestellt, so löste dieser Backgroundtask den Alarm aus. Damit der Task jedoch nicht irgendwann einfach endet, habe ich ihn immer nach einem festen Zeitintervall selbst beendet und sofort einen neuen angelegt. Bei dem lief der Zeitcountdown dann wieder von Neuem los. Und genau dieses Vorgehen sollte sich als problematisch erweisen in iOS 6.
3 Tage Debugging später…
Ich bin nunmehr zu folgender Erkenntnis gelangt: Man kann nur noch maximal 64 Backgroundtasks in Folge erzeugen. Danach wird die gesamte App suspended und sogar so drastisch angehalten, dass sie abstürzt. In den Screenshots oben kann man sehen, wie ich dem Problem auf die Spur gekommen bin. Nachdem ich festgestellt hatte, dass meine Hintergrundtasks nicht mehr unbegrenzt weiterlaufen, habe ich zunächst versucht an die Consolenmeldungen des Device zu gelangen, denn dort geben ich in Log-Statements Debuginfos aus. Problem war jedoch, sobald die App sich aufgehangen hatte enthielt das Log die relevanten Einträge nicht mehr (bzw. man hat es zu spät mitbekommen und die Logeinträge neuer Ereignisse haben die alten überschrieben).
Der Ausweg waren LocalNotifications, denn die sind noch da, selbst wenn das Consolenlog schon längst weg ist und sie werden vom iOS verwaltet, das ja weiterhin einwandfrei lief. Ich hab einfach zum Debuggen als die BackgroundtaskId’s größer als 62 wurden eine LocalNotification ausgegeben (Screen ganz rechts). Und siehe da, es scheint eine harte Grenze an erlaubten Backgroundtasks zu geben. Auf allen Geräten mit denen ich unter iOS 6 getestet habe gab es diese Grenze, denn alle zeigten die zwei LocalNotifications für id 63 und 64 und danach reagierte die App nicht mehr. Wohlgemerkt nach deutlich über 8 Stunden erfolgreicher Laufzeit. Das Consolen-Log sah dann so aus:
Aug 6 07:43:35 dev-pod5 Nautical[16452] <Warning>: EXECUTING BACKGROUND TASKS IN INACTIVE/BACK
Aug 6 07:43:35 dev-pod5 Nautical[16452] <Warning>: MONITORING IS: ON
Aug 6 07:43:35 dev-pod5 Nautical[16452] <Warning>: VARIO FREQUENCY: 51 %
Aug 6 07:43:35 dev-pod5 Nautical[16452] <Warning>: CHECKING BATTERY LEVEL: 0.90
Aug 6 07:43:35 dev-pod5 Nautical[16452] <Warning>: TIMEINTERVAL: 53.60 SECONDS
Aug 6 07:43:35 dev-pod5 Nautical[16452] <Warning>: ATTENTION #3: RESPAWNING
Aug 6 07:43:35 dev-pod5 Nautical[16452] <Warning>: ATTENTION #1: BACKGROUND TASK 64 STILL FINE (TIME REMAINING: inf MINUTES AND 0 SECONDS )
Aug 6 07:43:35 dev-pod5 Nautical[16452] <Warning>: ATTENTION #2: APPLICATION STATE = 2
Aug 6 07:43:35 dev-pod5 Nautical[16452] <Warning>: ATTENTION #2: SPAWNING NEW TIMER BECAUSE WE ARE BACKGROUND ...
Aug 6 07:43:36 dev-pod5 Nautical[16452] <Warning>: ATTENTION #4: BG TASK #64 FINE (TIME REMAINING: inf MINUTES AND 0 SECONDS )
Aug 6 07:43:36 dev-pod5 Nautical[16452] <Warning>: ATTENTION #4: BG TASK #64 ELAPSED: 15 MINUTES )
Aug 6 07:43:36 dev-pod5 Nautical[16452] <Warning>: ATTENTION #4: BG TASK REACHED END OF LIFE, CLOSING OLD BG TASK #64...
Aug 6 07:43:36 dev-pod5 Nautical[16452] <Warning>: ATTENTION #4: BG TASK CLOSED. SPAWNING NEW BG TASK...
Aug 6 07:43:36 dev-pod5 Nautical[16452] <Warning>: ATTENTION #1: SPAWNING NEW BACKGROUND TASK WHILE BACKGROUND ...
Aug 6 07:43:45 dev-pod5 Nautical[16452] <Warning>: ATTENTION #3: TIMER FIRED
Aug 6 07:43:45 dev-pod5 Nautical[16452] <Warning>: EXECUTING BACKGROUND TASKS IN INACTIVE/BACK
Aug 6 07:43:45 dev-pod5 Nautical[16452] <Warning>: MONITORING IS: ON
Aug 6 07:43:45 dev-pod5 Nautical[16452] <Warning>: VARIO FREQUENCY: 51 %
Aug 6 07:43:45 dev-pod5 Nautical[16452] <Warning>: CHECKING BATTERY LEVEL: 0.90
Aug 6 07:43:45 dev-pod5 Nautical[16452] <Warning>: TIMEINTERVAL: 43.55 SECONDS
Aug 6 07:43:45 dev-pod5 Nautical[16452] <Warning>: ATTENTION #3: RESPAWNING
Aug 6 07:43:45 dev-pod5 Nautical[16452] <Warning>: ATTENTION #1: SPAWNING NEW BACKGROUND TASK WHILE BACKGROUND ...
Aug 6 07:43:49 dev-pod5 kernel[0] <Debug>: 1269100.775 IO80211AWDLPeerManager::setAwdlQuiet flags 5 quiet -> 0
Aug 6 07:43:49 dev-pod5 kernel[0] <Debug>: 1269100.776012 wlan.A[63085] AppleBCMWLANProximityInterface::setSYNC_ENABLED(): ON
Aug 6 07:43:49 dev-pod5 kernel[0] <Debug>: IO80211AWDLMulticastPeer::queuePacket ff:ff:ff:ff:ff:ff alllocate queue for ac 0
Aug 6 07:43:51 dev-pod5 kernel[0] <Debug>: IO80211AWDLPeerManager::doMonitorTimer browsing device idle for txQUni 0(ms) txQMulti 2295(ms) statechange 57290215(ms) serviceupdate 159858095(ms) pkt 1 -> quiet
Aug 6 07:43:51 dev-pod5 kernel[0] <Debug>: 1269103.095 IO80211AWDLPeerManager::setAwdlQuiet flags 3 quiet -> 1
Aug 6 07:43:51 dev-pod5 kernel[0] <Debug>: 1269103.095600 wlan.A[63086] AppleBCMWLANProximityInterface::setSYNC_ENABLED(): OFF
Aug 6 07:43:57 dev-pod5 backboardd[15262] <Notice>: Posting 'com.apple.iokit.hid.displayStatus' notifyState=1
Aug 6 07:43:57 dev-pod5 kernel[0] <Debug>: set_crc_notification_state 0
Aug 6 07:43:57 dev-pod5 backboardd[15262] <Notice>: MultitouchHID: detection mode: 255->0 (deferring until bootloaded)
Aug 6 07:43:57 dev-pod5 backboardd[15262] <Notice>: MultitouchHID: device bootloaded
Aug 6 07:43:57 dev-pod5 backboardd[15262] <Notice>: MultitouchHID: detection mode: 0->0
Aug 6 07:43:57 dev-pod5 kernel[0] <Debug>: ALS: AppleARMBacklight::handleMessageGated - framebufferState -> 1
Aug 6 07:43:57 dev-pod5 kernel[0] <Debug>: ALS: AppleARMBacklight::setBacklightEnableGated 1 (set level to 0x644)
Aug 6 07:43:58 dev-pod5 profiled[16600] <Notice>: (Note ) profiled: Service starting...
Aug 6 07:43:58 dev-pod5 profiled[16600] <Notice>: (Note ) profiled: Recomputing passcode requirement message
Aug 6 07:44:01 dev-pod5 kernel[0] <Debug>: launchd[16603] Builtin profile: syncdefaultsd (sandbox)
Aug 6 07:44:53 dev-pod5 backboardd[15262] <Warning>: com.noxymo.seewetterpro failed to resume in time
Aug 6 07:44:53 dev-pod5 backboardd[15262] <Warning>: Forcing crash report of Nautical[16452]...
Aug 6 07:44:54 dev-pod5 backboardd[15262] <Warning>: Finished crash reporting.
Aug 6 07:44:54 dev-pod5 ReportCrash[16604] <Error>: libMobileGestalt copySystemVersionDictionaryValue: Could not lookup ReleaseType from system version dictionary
Aug 6 07:44:54 dev-pod5 com.apple.launchd[1] (UIKitApplication:com.noxymo.seewetterpro[0x5626][16452]) <Notice>: (UIKitApplication:com.noxymo.seewetterpro[0x5626]) Exited: Killed: 9
Aug 6 07:44:54 dev-pod5 backboardd[15262] <Warning>: Application 'UIKitApplication:com.noxymo.seewetterpro[0x5626]' exited abnormally with signal 9: Killed: 9
Mein finaler Workaround ist nun der, dass ich die maximal erlaubte Laufzeit eines Backgroundtask tatsächlich auch maximal ausnutze und nicht wie in dem Log ersichtlich nach 15 Minuten pauschal den Task beende und durch einen neuen ersetze. Das hatte ich aus Vorsicht getan, um nicht unerwartet beendet zu werden. Man kann aber jederzeit prüfen, wie lange einem noch erlaubt wird diesen BGTask laufen zu lassen. So kann man rechtzeitig vor Beendigung reagieren. Oft sind deutlich mehr als der üblichen 10 Minuten erlaubt, im Log steht dort sogar „inf“ für infinite, das täuscht jedoch, denn dieser Wert kann sich urplötzlich verwandeln in einen echten Countdown von verbleibenden 10 Minuten. 10 * 64 Minuten sind aber zumindest schonmal 10 Stunden und 40 Minuten Laufzeit, das ist für den Ankeralarm durchaus ausreichend. Durch Ausdehnen der Intervalle auf das Maximum ist aber deutlich mehr erreichbar und das ist was ich jetzt getan habe.
Insgesamt war das ein recht aufwändig zu debuggendes Problem, und die Zahl 64 als hartes Limit scheint kein Zufall zu sein, man fragt sich dennoch warum das sein muss. Problem zumindest vorerst für iOS 6 gelöst! Nun bin ich gespannt, was in iOS 7 wohl wieder alles nicht gehen wird… :-)
Übrigens:
Hinweise die mir bei der Lösung des Problems geholfen haben waren u.a. diese StackOverflow entries & links.
- http://stackoverflow.com/questions/5323634/ios-application-executing-tasks-in-background
- http://www.raywenderlich.com/29948/backgrounding-for-ios
- App States and Multitasking (Apple Dokumentation)
- https://developer.apple.com/support/technical/submit/
- http://stackoverflow.com/questions/9840911/how-keep-nstimer-when-application-entering-background
- http://stackoverflow.com/questions/15092016/how-to-run-nstimer-in-background-and-sleep-in-ios
- http://stackoverflow.com/questions/8415870/scheduled-nstimer-when-app-is-in-background
Ich habe auch einen Prototyp app gebaut, die das Problem isolierte. Eventuell pack‘ ich die irgendwann mal wenn ich wieder Zeit habe auf github.
