react-native-background-fetch: Fetch callback works intermittently [iOS]

I’ve been investigating an issue in our app where on random app startups the BackgroundFetch.configure call seems to not register properly, resulting in the following warning when a fetch is simulated:

Warning: Application delegate received call to -application:performFetchWithCompletionHandler: but the completion handler was never called.

Your Environment

• Plugin version: 3.0.5
• Platform: iOS
• OS version: 13.4.1 (physical device) and 13.5 (Simulator)
• Device manufacturer / model: iPhone 7 (physical) and iPhone 11 (Simulator)
• React Native version (react-native -v): 0.61.5
• Plugin config:

{
      minimumFetchInterval: 15,
      requiredNetworkType: BackgroundFetch.NETWORK_TYPE_ANY,

      // Android specific options
      startOnBoot: true,
      stopOnTerminate: false,
      enableHeadless: true
    }

Expected Behavior

On startup two logs are expected to prove the configure call has run:

> Background Task Registering
> Background Task Registered

When xcode sends “Simulate Background Fetch” the app should log:

> [Qflow Background Task Started]: ${taskId}

Actual Behavior

• The registration logs appear every time, so the JS side should be working
• 80% of the time the app receives the fetch call, but on random startups the following output is received instead:

2020-05-28 12:52:54.532136+0100 Qflow[94885:4831970] RNBackgroundFetch AppDelegate received fetch event
2020-05-28 12:52:54.532409+0100 Qflow[94885:4831970] [TSBackgroundFetch performFetchWithCompletionHandler]
2020-05-28 12:52:54.532612+0100 Qflow[94885:4831970] [TSBackgroundFetch scheduleBGAppRefresh] com.transistorsoft.fetch
2020-05-28 12:52:54.533045+0100 Qflow[94885:4831970] Warning: Application delegate received call to -application:performFetchWithCompletionHandler: but the completion handler was never called.

Steps to Reproduce

I have not been able to consistently reproduce this issue, it may well be a race condition related to other dependencies within the app, but I’m at a loss what this package could interact with, so any ideas there would be welcome.

There does seem to be a correlation with the device (or rather the Mac host when using a simulator) being offline when the app is started, but I’ve seen it while online too.

registerBackgroundWorker() is called at the module level in App.js, but was previously called from a useEffect in a component and had the same issue. This is based on a suggestion in #223

// background-worker.js

// console.error everywhere simply forces these logs into the xcode debug console for now
export function registerBackgroundWorker() {
  console.error('Background Task Registering')

  BackgroundFetch.configure(
    {
      minimumFetchInterval: FETCH_INTERVAL_MINS,
      requiredNetworkType: BackgroundFetch.NETWORK_TYPE_ANY,

      // Android specific options
      startOnBoot: true,
      stopOnTerminate: false,
      enableHeadless: true
    },
    async taskId => {
      console.error(`[Qflow Background Task Started]: ${taskId}`)
      BackgroundFetch.finish(taskId)
    },
    status => {
      console.error(`[Qflow Background Task Failure]`, console.error)
    }
  )

  console.error('Background Task Registered')
}

// AppDelegate.m

#import "AppDelegate.h"

#import <React/RCTBridge.h>
#import <React/RCTBundleURLProvider.h>
#import <React/RCTRootView.h>

#import <BugsnagReactNative/BugsnagReactNative.h>
#import "BugsnagConfiguration.h"

// https://github.com/transistorsoft/react-native-background-fetch/blob/master/docs/INSTALL-AUTO-IOS.md
#import <TSBackgroundFetch/TSBackgroundFetch.h>

@implementation AppDelegate

- (BOOL)application:(UIApplication *)application didFinishLaunchingWithOptions:(NSDictionary *)launchOptions
{
  BugsnagConfiguration *config = [BugsnagConfiguration new];
  config.releaseStage = [[NSBundle mainBundle] objectForInfoDictionaryKey:@"BugsnagEnvironment"];;
  [BugsnagReactNative startWithConfiguration:config];

  RCTBridge *bridge = [[RCTBridge alloc] initWithDelegate:self launchOptions:launchOptions];
  RCTRootView *rootView = [[RCTRootView alloc] initWithBridge:bridge
                                                   moduleName:@"qflow"
                                            initialProperties:nil];

  rootView.backgroundColor = [[UIColor alloc] initWithRed:1.0f green:1.0f blue:1.0f alpha:1];

  self.window = [[UIWindow alloc] initWithFrame:[UIScreen mainScreen].bounds];
  UIViewController *rootViewController = [UIViewController new];
  rootViewController.view = rootView;
  self.window.rootViewController = rootViewController;
  [self.window makeKeyAndVisible];

  // Disable dark mode in iOS13 to fix display date-picker going invisible
  if (@available(iOS 13.0, *)) {
    rootView.overrideUserInterfaceStyle = UIUserInterfaceStyleLight;
  }
  
  // https://github.com/transistorsoft/react-native-background-fetch/blob/master/docs/INSTALL-AUTO-IOS.md
  [[TSBackgroundFetch sharedInstance] didFinishLaunching];

  return YES;
}

- (BOOL)application:(UIApplication *)app openURL:(NSURL *)url options:(NSDictionary<NSString *, id> *) options {
    return [self.authorizationFlowManagerDelegate resumeExternalUserAgentFlowWithURL:url];
}

- (NSURL *)sourceURLForBridge:(RCTBridge *)bridge
{
#if DEBUG
  return [[RCTBundleURLProvider sharedSettings] jsBundleURLForBundleRoot:@"index" fallbackResource:nil];
#else
  return [[NSBundle mainBundle] URLForResource:@"main" withExtension:@"jsbundle"];
#endif
}

@end

Additional info:

• “Launch due to a background fetch event” is enabled
• Both iOS “Background Modes” have been added, though I’m not using schedule right now so I expect only “Background Fetch” is needed, and should work fine on iOS 13?
• “com.transistorsoft.fetch” is listed in “Permitted background task scheduler identifiers”

Finally, I have cloned and run the example app, and couldn’t reproduce it there, so am sure it’s related to a combination of other app setup/dependencies rather than a direct issue with this library. Any advice debugging would be very welcome, and I’m hoping that this issue can help document the solution(s) for anyone else who faces similar issues.

Debug logs

Example ‘startup & simulate fetch’ log

2020-05-28 11:38:52.155074+0100 Qflow[85619:4744382] [TSBackgroundFetch load]: (
)
2020-05-28 11:38:52.155585+0100 Qflow[85619:4744382] [TSBGAppRefreshSubscriber load]: {
    "react-native-background-fetch" = "<TSBGAppRefreshSubscriber identifier=react-native-background-fetch, executed=0, enabled=1>";
}
WARN : BSG_KSCrashSentry.c (103): BSG_KSCrashType bsg_kscrashsentry_installWithContext(BSG_KSCrash_SentryContext *, BSG_KSCrashType, void (*)(void *)): KSCrash: App is running in a debugger. Only user reported events will be handled.
2020-05-28 11:38:52.343661+0100 Qflow[85619:4744382] RNBackgroundFetch AppDelegate received fetch event
2020-05-28 11:38:52.343807+0100 Qflow[85619:4744382] [TSBackgroundFetch performFetchWithCompletionHandler]
2020-05-28 11:38:52.343928+0100 Qflow[85619:4744382] [TSBackgroundFetch scheduleBGAppRefresh] com.transistorsoft.fetch

2020-05-28 11:38:52.617909+0100 Qflow[85619:4744625] [Client] Synchronous remote object proxy returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service on pid 0 named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service on pid 0 named com.apple.commcenter.coretelephony.xpc was invalidated.}
2020-05-28 11:38:52.617970+0100 Qflow[85619:4744622] [Client] Updating selectors failed with: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service on pid 0 named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service on pid 0 named com.apple.commcenter.coretelephony.xpc was invalidated.}
2020-05-28 11:38:52.618154+0100 Qflow[85619:4744622] [Client] Updating selectors after delegate addition failed with: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service on pid 0 named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service on pid 0 named com.apple.commcenter.coretelephony.xpc was invalidated.}
2020-05-28 11:38:52.618723+0100 Qflow[85619:4744625] [Client] Synchronous remote object proxy returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service on pid 0 named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service on pid 0 named com.apple.commcenter.coretelephony.xpc was invalidated.}
2020-05-28 11:38:52.634606+0100 Qflow[85619:4744622] [Client] Updating selectors failed with: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service on pid 0 named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service on pid 0 named com.apple.commcenter.coretelephony.xpc was invalidated.}
2020-05-28 11:38:52.635393+0100 Qflow[85619:4744625] [Client] Synchronous remote object proxy returned error: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service on pid 0 named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service on pid 0 named com.apple.commcenter.coretelephony.xpc was invalidated.}
2020-05-28 11:38:52.635452+0100 Qflow[85619:4744627] [Client] Updating selectors failed with: Error Domain=NSCocoaErrorDomain Code=4099 "The connection to service on pid 0 named com.apple.commcenter.coretelephony.xpc was invalidated." UserInfo={NSDebugDescription=The connection to service on pid 0 named com.apple.commcenter.coretelephony.xpc was invalidated.}
2020-05-28 11:38:52.645247+0100 Qflow[85619:4744382] [TSBackgroundFetch scheduleBGAppRefresh] com.transistorsoft.fetch
2020-05-28 11:38:52.685287+0100 Qflow[85619:4744628] Sent 5 sessions to Bugsnag
2020-05-28 11:38:52.702 [error][tid:com.facebook.react.JavaScript] [Qflow Background Task Started] OK
2020-05-28 11:38:52.733 [info][tid:main][RNGestureHandlerManager.m:136] [GESTURE HANDLER] Initialize gesture handler for root view <RCTRootContentView: 0x7f89ecb10dd0; reactTag: 1; frame = (0 0; 414 896); gestureRecognizers = <NSArray: 0x6000015c2c40>; layer = <CALayer: 0x600001bd81e0>>
2020-05-28 11:38:52.735 [error][tid:com.facebook.react.JavaScript] [Qflow Background Task Finished]: OK
INFO : BSG_KSCrash.m (286): -[BSG_KSCrash sendAllReportsWithCompletion:]: Sending 0 crash reports
2020-05-28 11:42:02.658568+0100 Qflow[85619:4744382] RNBackgroundFetch AppDelegate received fetch event
2020-05-28 11:42:02.658956+0100 Qflow[85619:4744382] [TSBackgroundFetch performFetchWithCompletionHandler]
2020-05-28 11:42:02.659963+0100 Qflow[85619:4744382] [TSBackgroundFetch scheduleBGAppRefresh] com.transistorsoft.fetch
2020-05-28 11:42:02.660936+0100 Qflow[85619:4744382] Warning: Application delegate received call to -application:performFetchWithCompletionHandler: but the completion handler was never called.