Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Bug]: ~30s delays displaying push notifications when using OneSignalExtension.didReceiveNotificationExtensionRequest #1425

Open
1 task done
johnmalatras opened this issue May 2, 2024 · 16 comments

Comments

@johnmalatras
Copy link

johnmalatras commented May 2, 2024

What happened?

We've been trying to debug some sort of delay or throttling of our push notifications that occurs when a user gets > 1 communication notification in a row. The first one arrives instantly and then each one after arrives about 30 seconds after the last. After debugging through, it seems that this function call:

OneSignalExtension.didReceiveNotificationExtensionRequest(
    receivedRequest,
    with: bestAttemptContent,
    withContentHandler: contentHandler
)

causes the hang. If I directly call contentHandler?(bestAttemptContent) instead the notifications all show instantly.

I've tried to debug further by setting a verbose log level but OneSignal.Debug.setLogLevel(.LL_VERBOSE) doesn't appear to be available in OneSignalExtension. Also, serviceExtensionTimeWillExpire is not hit at any point.

Steps to reproduce?

1. Build an `INSendMessageIntent` for a communication notification
2. Create an `INInteraction` with the intent and donate it
3. Update the notification content with the intent
4. Call OneSignalExtension.didReceiveNotificationExtensionRequest with the updated notification contents

What did you expect to happen?

Push notifications are displayed as soon as they're received.

OneSignal iOS SDK version

3.12.7

iOS version

17

Specific iOS version

iOS 17.2

Relevant log output

No response

Code of Conduct

  • I agree to follow this project's Code of Conduct
@emawby
Copy link
Contributor

emawby commented May 3, 2024

@johnmalatras Thank you for reaching out we will investigate. In order for debug logs to show up you must debug the NotificationServiceExtension target rather than the app target. The easiest way to do this is to start debugging the app and send the device a notification. Then go to "Debug" -> "Attach to Process" -> "OneSignalNotificationServiceExtension". Now you can send more notifications to the device and should get debug logs/breakpoints enabled.

If you need to get logs from the first push a device receives you can also use Mac's Console app to search for the logs.

@johnmalatras
Copy link
Author

Hi, I've been debugging the NotificationServiceExtension target without issue. That's how I pinpointed that OneSignalExtension.didReceiveNotificationExtensionRequest is the cause of the delay.

The logging issue I mentioned is specifically around getting the OneSignal SDK to output verbose logging in the extension. The documentation mentions setting OneSignal.Debug.setLogLevel(.LL_VERBOSE) but that is not available in OneSignalExtension. I was hoping this logging might indicate what the issue in the SDK is as we found some code that manually adds a delay:

[OneSignalLog onesignalLog:ONE_S_LL_VERBOSE message:[NSString stringWithFormat:@"OneSignal onNotificationReceived sendReceiveReceipt with delay: %i", randomDelay]];

@emawby
Copy link
Contributor

emawby commented May 3, 2024

Ah I see the issue is that the OneSignal class is likely not available in the notification service extension so you can use OneSignalLog.Debug.setLogLevel(.LL_VERBOSE) instead.

@emawby
Copy link
Contributor

emawby commented May 3, 2024

The issue appears to be that the random delay for sending confirmed deliveries is run on the main thread which could be blocking delivery of subsequent notifications to the NSE until the delay has ended.

However, I am not able to reproduce this behavior. I added logging before and after OneSignal processes the notification send and this was my result sending 3 notifications subsequently:

######## Start NotificationService!
START!!!!!! request.content.userInfo: {
aps = {
alert = "Subsequent notification test 1";
"mutable-content" = 1;
sound = default;
};
}
######## Start NotificationService!
START!!!!!! request.content.userInfo: {
aps = {
alert = "Subsequent notification test 2";
"mutable-content" = 1;
sound = default;
};
}
######## Start NotificationService!
START!!!!!! request.content.userInfo: {
aps = {
alert = "Subsequent notification test 3";
"mutable-content" = 1;
sound = default;
};
}
######## END NotificationService!
######## END NotificationService!
######## END NotificationService!

Each notification was delivered immediately regardless of the delay in confirmed delivery processing.

@johnmalatras
Copy link
Author

johnmalatras commented May 3, 2024

Are you displaying these as a communication notifications in the extension? To be clear they're delivered immediately for us too when it's a plain notification. The delays only occur for communication notifications (aka notifications where we update the contents with let content = try request.content.updating(from: intent) where intent is a INSendMessageIntent before calling OneSignalExtension.didReceiveNotificationExtensionRequest

@emawby
Copy link
Contributor

emawby commented May 3, 2024

@johnmalatras I am still not able to reproduce using the below (objective-c not swift)

INPersonHandle *handle = [[INPersonHandle alloc] initWithValue:@"test" type:INPersonHandleTypeUnknown];
INPerson *sender = [[INPerson alloc] initWithPersonHandle:handle nameComponents:nil displayName:@"test" image:nil contactIdentifier:nil customIdentifier:nil];
INSendMessageIntent *messageIntent = [[INSendMessageIntent alloc] initWithRecipients:nil content:@"test content" groupName:nil serviceName:nil sender:sender];
if (@available(iOS 15.0, *)) {
    self.bestAttemptContent = [[request.content contentByUpdatingWithProvider:messageIntent error:nil] mutableCopy];
} else {
    // Fallback on earlier versions
}

@johnmalatras
Copy link
Author

Weird. The only notable differences I see are that:

  1. Our sender has an image that's a INImage initialized from a URL
  2. We're donating the intent via an INInteraction before updating the content and hitting OneSignalExtension.didReceiveNotificationExtensionRequest:
let interaction = INInteraction(intent: intent, response: nil)
interaction.direction = .incoming

interaction.donate { [weak self] error in
    if let error {
        Analytics.trackError(
            error,
            context: "Error updating notification with intent"
        )
        return
    }

    guard let self else { return }

    do {
        let content = try request.content.updating(from: intent)
        if let mutableUpdated = content.mutableCopy()
                as? UNMutableNotificationContent
        {
            mutableUpdated.body = bodyOverride ?? mutableUpdated.body
            self.bestAttemptContent = mutableUpdated
        }
    } catch {
        Analytics.trackError(
            error,
            context: "Error updating notification with intent"
        )
    }
    
    self.forwardRequestToExtension()
}

@emawby
Copy link
Contributor

emawby commented May 3, 2024

@johnmalatras Does self.forwardRequestToExtension() need to be called inside of the intent donation completion block? I am able to reproduce the issue if it is inside of the completion block, but if I move it outside of the intent donation it works as normal.

@johnmalatras
Copy link
Author

@emawby If the call is outside of the intent donation completion block then the notification isn't rendered as a communication notification

@emawby
Copy link
Contributor

emawby commented May 3, 2024

@johnmalatras Instead of calling it inside the completion can you await on the donation and then call it afterwards like they do in the documentation here?

@johnmalatras
Copy link
Author

johnmalatras commented May 3, 2024

Interesting, I actually don't see an async version of func didReceive(_ request: UNNotificationRequest, withContentHandler contentHandler: @escaping (UNNotificationContent) -> Void) available despite it being in that doc. If I kick off a Task though and await the donation instead of using the completion handler the bug persists though.

@emawby
Copy link
Contributor

emawby commented May 3, 2024

I am still working in Objective-C, but it works for me if I mock await behavior using dispatch semaphores. This allowed me to make sure the interaction was donated and still have notifications delivered immediately. You can try something similar in Swift as a workaround.

The issue is that in order to have a random delay for confirmed deliveries we need to keep the process alive. To do this we are waiting on a dispatch_semaphore after submitting the notification content to the handler. It looks like doing this while in the completion block hangs the entire service extension process. We will look for other ways to get the desired behavior.

dispatch_semaphore_t semaphore = dispatch_semaphore_create(0);
[interaction donateInteractionWithCompletion:^(NSError * _Nullable error) {
    self.bestAttemptContent = [[request.content contentByUpdatingWithProvider:messageIntent error:nil] mutableCopy];
    dispatch_semaphore_signal(semaphore);
}];
dispatch_semaphore_wait(semaphore, dispatch_time(DISPATCH_TIME_NOW, 30 * NSEC_PER_SEC));
[OneSignalExtension didReceiveNotificationExtensionRequest:self.receivedRequest
                       withMutableNotificationContent:self.bestAttemptContent
                                   withContentHandler:self.contentHandler];

@johnmalatras
Copy link
Author

johnmalatras commented May 7, 2024

@emawby I have what I believe should be similar semaphore functionality in Swift but still no cigar; doesn't fix the delay:

let semaphore = DispatchSemaphore(value: 0)
interaction.donate { [weak self] error in
    defer {
        semaphore.signal()
    }

    if let error {
        Analytics.trackError(
            error,
            context: "Error updating notification with intent"
        )
        return
    }

    guard let self else { return }

    do {
        let content = try request.content.updating(from: intent)
        if let bodyOverride,
            let mutableUpdated = content.mutableCopy()
                as? UNMutableNotificationContent
        {
            mutableUpdated.body = bodyOverride
            self.bestAttemptContent = mutableUpdated
        }
    } catch {
        Analytics.trackError(
            error,
            context: "Error updating notification with intent"
        )
    }
}

semaphore.wait()
self.forwardRequestToExtension()

@emawby
Copy link
Contributor

emawby commented May 10, 2024

Interesting your code works for me in Swift, and I am able to reproduce the issue without the semaphore. The only thing I changed was removing the analytics error tracking code and the bodyOverride code.

@emawby
Copy link
Contributor

emawby commented May 23, 2024

@johnmalatras Fixing this issue for communication notifications will likely require an update to the SDK's public interface to either separate the confirmed delivery call from the notification processing, or marking a notification as a communication notification which I don't believe we can detect automatically today. However the option we go with is somewhat dependent on whether or not the dispatch semaphore workaround noted above works for all cases. If you were never able to get that to work please let me know!

@johnmalatras
Copy link
Author

Sorry for the delayed follow up @emawby - we had a potential fix out yet and wanted to let it bake for a bit to ensure nothing was unexpectedly going wrong. We were indeed able to fix with a conceptually similar solution to what you proposed. Directly using a semaphore didn't work but running our handleNotificationReceived explicitly in a detached task (Task.detached) did seem to fix it! I'm not exactly sure if there's other consequences of this but I haven't noticed any yet.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants