- Revision
- 293782
- Author
- n...@apple.com
- Date
- 2022-05-04 12:03:42 -0700 (Wed, 04 May 2022)
Log Message
Add push service result logging
https://bugs.webkit.org/show_bug.cgi?id=240035
Reviewed by Geoffrey Garen.
This adds logging to make it easier to debug certain errors we have seen internally (e.g.
unexpectedly missing subscriptions and service workers that aren't spawning to service push
events):
1. In some cases, it appears that a push event is coming in, but the service worker to
handle the event never spawns. This can happen if we think an origin doesn't have
permission to show a notification in UIProcess and we bail out early. Currently we don't
have logging for this case.
To fix this, I removed the early bail-out in NetworkProcessProxy::processPushMessage
entirely. Instead, we always IPC the message to NetworkProcess::processPushMessage.
This will trigger existing logging around whether a service worker spawns to handle the
push event on the NetworkProcess side. The optimization to not spawn NetworkProcess in
the permission-denied case will not be used in the long run, because we plan to move the
subscription to the ignore list in this case (see the FIXME in
NetworkProcess::processPushMessage), which requires spawning NetworkProcess to message
webpushd anyway.
2. For push service requests that produce a result, we additionally log whether or not the
result exists (e.g. to know if a push subscription exists or not).
3. Add logging for the cases where WebKit explicitly asks webpushd to bulk-remove
subscriptions.
* NetworkProcess/NetworkProcess.cpp:
(WebKit::NetworkProcess::processPushMessage):
* UIProcess/Network/NetworkProcessProxy.cpp:
(WebKit::NetworkProcessProxy::processPushMessage):
* webpushd/PushService.mm:
(WebPushD::PushServiceRequestImpl::fulfill):
(WebPushD::PushService::removeRecordsForBundleIdentifier):
(WebPushD::PushService::removeRecordsForBundleIdentifierAndOrigin):
Canonical link: https://commits.webkit.org/250261@main
Modified Paths
Diff
Modified: trunk/Source/WebKit/ChangeLog (293781 => 293782)
--- trunk/Source/WebKit/ChangeLog 2022-05-04 18:14:22 UTC (rev 293781)
+++ trunk/Source/WebKit/ChangeLog 2022-05-04 19:03:42 UTC (rev 293782)
@@ -1,3 +1,44 @@
+2022-05-03 Ben Nham <n...@apple.com>
+
+ Add push service result logging
+ https://bugs.webkit.org/show_bug.cgi?id=240035
+
+ Reviewed by Geoffrey Garen.
+
+ This adds logging to make it easier to debug certain errors we have seen internally (e.g.
+ unexpectedly missing subscriptions and service workers that aren't spawning to service push
+ events):
+
+ 1. In some cases, it appears that a push event is coming in, but the service worker to
+ handle the event never spawns. This can happen if we think an origin doesn't have
+ permission to show a notification in UIProcess and we bail out early. Currently we don't
+ have logging for this case.
+
+ To fix this, I removed the early bail-out in NetworkProcessProxy::processPushMessage
+ entirely. Instead, we always IPC the message to NetworkProcess::processPushMessage.
+
+ This will trigger existing logging around whether a service worker spawns to handle the
+ push event on the NetworkProcess side. The optimization to not spawn NetworkProcess in
+ the permission-denied case will not be used in the long run, because we plan to move the
+ subscription to the ignore list in this case (see the FIXME in
+ NetworkProcess::processPushMessage), which requires spawning NetworkProcess to message
+ webpushd anyway.
+
+ 2. For push service requests that produce a result, we additionally log whether or not the
+ result exists (e.g. to know if a push subscription exists or not).
+
+ 3. Add logging for the cases where WebKit explicitly asks webpushd to bulk-remove
+ subscriptions.
+
+ * NetworkProcess/NetworkProcess.cpp:
+ (WebKit::NetworkProcess::processPushMessage):
+ * UIProcess/Network/NetworkProcessProxy.cpp:
+ (WebKit::NetworkProcessProxy::processPushMessage):
+ * webpushd/PushService.mm:
+ (WebPushD::PushServiceRequestImpl::fulfill):
+ (WebPushD::PushService::removeRecordsForBundleIdentifier):
+ (WebPushD::PushService::removeRecordsForBundleIdentifierAndOrigin):
+
2022-05-04 Kimmo Kinnunen <kkinnu...@apple.com>
DisplayList::Recorder has redundant, unused flushContext
Modified: trunk/Source/WebKit/NetworkProcess/NetworkProcess.cpp (293781 => 293782)
--- trunk/Source/WebKit/NetworkProcess/NetworkProcess.cpp 2022-05-04 18:14:22 UTC (rev 293781)
+++ trunk/Source/WebKit/NetworkProcess/NetworkProcess.cpp 2022-05-04 19:03:42 UTC (rev 293782)
@@ -2329,7 +2329,7 @@
void NetworkProcess::processPushMessage(PAL::SessionID sessionID, WebPushMessage&& pushMessage, PushPermissionState permissionState, CompletionHandler<void(bool)>&& callback)
{
if (auto* session = networkSession(sessionID)) {
- LOG(Push, "Networking process handling a push message from UI process in session %llu", sessionID.toUInt64());
+ RELEASE_LOG(Push, "Networking process handling a push message from UI process in session %llu", sessionID.toUInt64());
auto origin = SecurityOriginData::fromURL(pushMessage.registrationURL);
if (permissionState == PushPermissionState::Prompt) {
@@ -2362,7 +2362,7 @@
callback(result);
});
} else
- LOG(Push, "Networking process asked to handle a push message from UI process in session %llu, but that session doesn't exist", sessionID.toUInt64());
+ RELEASE_LOG_ERROR(Push, "Networking process asked to handle a push message from UI process in session %llu, but that session doesn't exist", sessionID.toUInt64());
}
#else
Modified: trunk/Source/WebKit/UIProcess/Network/NetworkProcessProxy.cpp (293781 => 293782)
--- trunk/Source/WebKit/UIProcess/Network/NetworkProcessProxy.cpp 2022-05-04 18:14:22 UTC (rev 293781)
+++ trunk/Source/WebKit/UIProcess/Network/NetworkProcessProxy.cpp 2022-05-04 19:03:42 UTC (rev 293782)
@@ -1766,11 +1766,6 @@
if (auto it = permissions.find(origin); it != permissions.end())
permission = it->value ? PushPermissionState::Granted : PushPermissionState::Denied;
- if (permission == PushPermissionState::Denied) {
- callback(false);
- return;
- }
-
sendWithAsyncReply(Messages::NetworkProcess::ProcessPushMessage { sessionID, pushMessage, permission }, WTFMove(callback));
}
Modified: trunk/Source/WebKit/webpushd/PushService.mm (293781 => 293782)
--- trunk/Source/WebKit/webpushd/PushService.mm 2022-05-04 18:14:22 UTC (rev 293781)
+++ trunk/Source/WebKit/webpushd/PushService.mm 2022-05-04 19:03:42 UTC (rev 293782)
@@ -207,8 +207,12 @@
void fulfill(ResultType result)
{
- RELEASE_LOG(Push, "Finished pushServiceRequest %{public}s (%p) with result for bundleID = %{public}s, scope = %{private}s", description().characters(), this, m_bundleIdentifier.utf8().data(), m_scope.utf8().data());
+ bool hasResult = true;
+ if constexpr (std::is_constructible_v<bool, ResultType>)
+ hasResult = static_cast<bool>(result);
+ RELEASE_LOG(Push, "Finished pushServiceRequest %{public}s (%p) with result (hasResult: %d) for bundleID = %{public}s, scope = %{private}s", description().characters(), this, hasResult, m_bundleIdentifier.utf8().data(), m_scope.utf8().data());
+
m_resultHandler(WTFMove(result));
finish();
}
@@ -521,11 +525,13 @@
void PushService::removeRecordsForBundleIdentifier(const String& bundleIdentifier, CompletionHandler<void(unsigned)>&& handler)
{
+ RELEASE_LOG(Push, "Removing push subscriptions associated with %{public}s", bundleIdentifier.utf8().data());
removeRecordsImpl(bundleIdentifier, std::nullopt, WTFMove(handler));
}
void PushService::removeRecordsForBundleIdentifierAndOrigin(const String& bundleIdentifier, const String& securityOrigin, CompletionHandler<void(unsigned)>&& handler)
{
+ RELEASE_LOG(Push, "Removing push subscriptions associated with %{public}s %{private}s", bundleIdentifier.utf8().data(), securityOrigin.utf8().data());
removeRecordsImpl(bundleIdentifier, securityOrigin, WTFMove(handler));
}
