Diff
Modified: trunk/Source/WebCore/ChangeLog (227349 => 227350)
--- trunk/Source/WebCore/ChangeLog 2018-01-22 21:01:12 UTC (rev 227349)
+++ trunk/Source/WebCore/ChangeLog 2018-01-22 21:08:46 UTC (rev 227350)
@@ -1,3 +1,42 @@
+2018-01-22 Chris Dumez <cdu...@apple.com>
+
+ Add release logging to help debug issues related to service workers
+ https://bugs.webkit.org/show_bug.cgi?id=181935
+ <rdar://problem/36735900>
+
+ Reviewed by Brady Eidson.
+
+ * workers/service/ServiceWorker.cpp:
+ (WebCore::ServiceWorker::ServiceWorker):
+ (WebCore::ServiceWorker::scheduleTaskToUpdateState):
+ (WebCore::ServiceWorker::postMessage):
+ (WebCore::ServiceWorker::isAlwaysOnLoggingAllowed const):
+ * workers/service/ServiceWorker.h:
+ * workers/service/ServiceWorkerContainer.cpp:
+ (WebCore::ServiceWorkerContainer::addRegistration):
+ (WebCore::ServiceWorkerContainer::removeRegistration):
+ (WebCore::ServiceWorkerContainer::updateRegistration):
+ (WebCore::ServiceWorkerContainer::jobFailedWithException):
+ (WebCore::ServiceWorkerContainer::jobResolvedWithRegistration):
+ (WebCore::ServiceWorkerContainer::jobResolvedWithUnregistrationResult):
+ (WebCore::ServiceWorkerContainer::startScriptFetchForJob):
+ (WebCore::ServiceWorkerContainer::jobFinishedLoadingScript):
+ (WebCore::ServiceWorkerContainer::jobFailedLoadingScript):
+ (WebCore::ServiceWorkerContainer::isAlwaysOnLoggingAllowed const):
+ * workers/service/ServiceWorkerContainer.h:
+ * workers/service/ServiceWorkerRegistration.cpp:
+ (WebCore::ServiceWorkerRegistration::ServiceWorkerRegistration):
+ (WebCore::ServiceWorkerRegistration::updateStateFromServer):
+ (WebCore::ServiceWorkerRegistration::scheduleTaskToFireUpdateFoundEvent):
+ * workers/service/server/SWServer.cpp:
+ (WebCore::SWServer::scriptContextFailedToStart):
+ (WebCore::SWServer::didFinishInstall):
+ (WebCore::SWServer::didFinishActivation):
+ (WebCore::SWServer::terminateWorkerInternal):
+ * workers/service/server/SWServerJobQueue.cpp:
+ (WebCore::SWServerJobQueue::didResolveRegistrationPromise):
+ (WebCore::SWServerJobQueue::runRegisterJob):
+
2018-01-22 Youenn Fablet <you...@apple.com>
Safari Tech Preview can't use GitHub login at forums.swift.org
Modified: trunk/Source/WebCore/workers/service/ServiceWorker.cpp (227349 => 227350)
--- trunk/Source/WebCore/workers/service/ServiceWorker.cpp 2018-01-22 21:01:12 UTC (rev 227349)
+++ trunk/Source/WebCore/workers/service/ServiceWorker.cpp 2018-01-22 21:08:46 UTC (rev 227350)
@@ -30,6 +30,7 @@
#include "Document.h"
#include "EventNames.h"
+#include "Logging.h"
#include "MessagePort.h"
#include "SWClientConnection.h"
#include "ScriptExecutionContext.h"
@@ -40,6 +41,9 @@
#include <runtime/JSCJSValueInlines.h>
#include <wtf/NeverDestroyed.h>
+#define WORKER_RELEASE_LOG_IF_ALLOWED(fmt, ...) RELEASE_LOG_IF(isAlwaysOnLoggingAllowed(), ServiceWorker, "%p - ServiceWorker::" fmt, this, ##__VA_ARGS__)
+#define WORKER_RELEASE_LOG_ERROR_IF_ALLOWED(fmt, ...) RELEASE_LOG_ERROR_IF(isAlwaysOnLoggingAllowed(), ServiceWorker, "%p - ServiceWorker::" fmt, this, ##__VA_ARGS__)
+
namespace WebCore {
Ref<ServiceWorker> ServiceWorker::getOrCreate(ScriptExecutionContext& context, ServiceWorkerData&& data)
@@ -59,6 +63,8 @@
relaxAdoptionRequirement();
updatePendingActivityForEventDispatch();
+
+ WORKER_RELEASE_LOG_IF_ALLOWED("ServiceWorker: ID: %llu, state: %u", identifier().toUInt64(), m_data.state);
}
ServiceWorker::~ServiceWorker()
@@ -76,6 +82,7 @@
context->postTask([this, protectedThis = makeRef(*this), state](ScriptExecutionContext&) {
ASSERT(this->state() != state);
+ WORKER_RELEASE_LOG_IF_ALLOWED("scheduleTaskToUpdateState: Updating service worker %llu state from %u to %u. Registration ID: %llu", identifier().toUInt64(), m_data.state, state, registrationIdentifier().toUInt64());
m_data.state = state;
if (state != State::Installing && !m_isStopped) {
ASSERT(m_pendingActivityForEventDispatch);
@@ -111,8 +118,10 @@
// FIXME: Support sending the channels.
auto channels = channelsOrException.releaseReturnValue();
- if (!channels.isEmpty())
+ if (!channels.isEmpty()) {
+ WORKER_RELEASE_LOG_ERROR_IF_ALLOWED("postMessage: Passing MessagePort objects to postMessage is not yet supported");
return Exception { NotSupportedError, ASCIILiteral("Passing MessagePort objects to postMessage is not yet supported") };
+ }
ServiceWorkerOrClientIdentifier sourceIdentifier;
if (is<ServiceWorkerGlobalScope>(context))
@@ -170,6 +179,19 @@
m_pendingActivityForEventDispatch = makePendingActivity(*this);
}
+bool ServiceWorker::isAlwaysOnLoggingAllowed() const
+{
+ auto* context = scriptExecutionContext();
+ if (!context)
+ return false;
+
+ auto* container = context->serviceWorkerContainer();
+ if (!container)
+ return false;
+
+ return container->isAlwaysOnLoggingAllowed();
+}
+
} // namespace WebCore
#endif // ENABLE(SERVICE_WORKER)
Modified: trunk/Source/WebCore/workers/service/ServiceWorker.h (227349 => 227350)
--- trunk/Source/WebCore/workers/service/ServiceWorker.h 2018-01-22 21:01:12 UTC (rev 227349)
+++ trunk/Source/WebCore/workers/service/ServiceWorker.h 2018-01-22 21:08:46 UTC (rev 227350)
@@ -78,6 +78,8 @@
bool canSuspendForDocumentSuspension() const final;
void stop() final;
+ bool isAlwaysOnLoggingAllowed() const;
+
ServiceWorkerData m_data;
bool m_isStopped { false };
RefPtr<PendingActivity<ServiceWorker>> m_pendingActivityForEventDispatch;
Modified: trunk/Source/WebCore/workers/service/ServiceWorkerContainer.cpp (227349 => 227350)
--- trunk/Source/WebCore/workers/service/ServiceWorkerContainer.cpp 2018-01-22 21:01:12 UTC (rev 227349)
+++ trunk/Source/WebCore/workers/service/ServiceWorkerContainer.cpp 2018-01-22 21:08:46 UTC (rev 227350)
@@ -52,6 +52,9 @@
#include <wtf/RunLoop.h>
#include <wtf/Scope.h>
+#define CONTAINER_RELEASE_LOG_IF_ALLOWED(fmt, ...) RELEASE_LOG_IF(isAlwaysOnLoggingAllowed(), ServiceWorker, "%p - ServiceWorkerContainer::" fmt, this, ##__VA_ARGS__)
+#define CONTAINER_RELEASE_LOG_ERROR_IF_ALLOWED(fmt, ...) RELEASE_LOG_ERROR_IF(isAlwaysOnLoggingAllowed(), ServiceWorker, "%p - ServiceWorkerContainer::" fmt, this, ##__VA_ARGS__)
+
namespace WebCore {
ServiceWorkerContainer::ServiceWorkerContainer(ScriptExecutionContext& context, NavigatorBase& navigator)
@@ -127,11 +130,13 @@
jobData.scriptURL = context->completeURL(relativeScriptURL);
if (!jobData.scriptURL.isValid()) {
+ CONTAINER_RELEASE_LOG_ERROR_IF_ALLOWED("addRegistration: Invalid scriptURL");
promise->reject(Exception { TypeError, ASCIILiteral("serviceWorker.register() must be called with a valid relative script URL") });
return;
}
if (!SchemeRegistry::canServiceWorkersHandleURLScheme(jobData.scriptURL.protocol().toStringWithoutCopying())) {
+ CONTAINER_RELEASE_LOG_ERROR_IF_ALLOWED("addRegistration: Invalid scriptURL scheme is not HTTP or HTTPS");
promise->reject(Exception { TypeError, ASCIILiteral("serviceWorker.register() must be called with a script URL whose protocol is either HTTP or HTTPS") });
return;
}
@@ -138,6 +143,7 @@
String path = jobData.scriptURL.path();
if (path.containsIgnoringASCIICase("%2f") || path.containsIgnoringASCIICase("%5c")) {
+ CONTAINER_RELEASE_LOG_ERROR_IF_ALLOWED("addRegistration: scriptURL contains invalid character");
promise->reject(Exception { TypeError, ASCIILiteral("serviceWorker.register() must be called with a script URL whose path does not contain '%2f' or '%5c'") });
return;
}
@@ -148,6 +154,7 @@
jobData.scopeURL = URL(jobData.scriptURL, "./");
if (!jobData.scopeURL.isNull() && !SchemeRegistry::canServiceWorkersHandleURLScheme(jobData.scopeURL.protocol().toStringWithoutCopying())) {
+ CONTAINER_RELEASE_LOG_ERROR_IF_ALLOWED("addRegistration: scopeURL scheme is not HTTP or HTTPS");
promise->reject(Exception { TypeError, ASCIILiteral("Scope URL provided to serviceWorker.register() must be either HTTP or HTTPS") });
return;
}
@@ -154,10 +161,13 @@
path = jobData.scopeURL.path();
if (path.containsIgnoringASCIICase("%2f") || path.containsIgnoringASCIICase("%5c")) {
+ CONTAINER_RELEASE_LOG_ERROR_IF_ALLOWED("addRegistration: scopeURL contains invalid character");
promise->reject(Exception { TypeError, ASCIILiteral("Scope URL provided to serviceWorker.register() cannot have a path that contains '%2f' or '%5c'") });
return;
}
+ CONTAINER_RELEASE_LOG_IF_ALLOWED("addRegistration: Registering service worker. Job ID: %llu", jobData.identifier().jobIdentifier.toUInt64());
+
jobData.clientCreationURL = context->url();
jobData.topOrigin = SecurityOriginData::fromSecurityOrigin(context->topOrigin());
jobData.type = ServiceWorkerJobType::Register;
@@ -187,6 +197,8 @@
jobData.type = ServiceWorkerJobType::Unregister;
jobData.scopeURL = scopeURL;
+ CONTAINER_RELEASE_LOG_IF_ALLOWED("removeRegistration: Unregistering service worker. Job ID: %llu", jobData.identifier().jobIdentifier.toUInt64());
+
scheduleJob(ServiceWorkerJob::create(*this, WTFMove(promise), WTFMove(jobData)));
}
@@ -211,6 +223,8 @@
jobData.scopeURL = scopeURL;
jobData.scriptURL = scriptURL;
+ CONTAINER_RELEASE_LOG_IF_ALLOWED("removeRegistration: Updating service worker. Job ID: %llu", jobData.identifier().jobIdentifier.toUInt64());
+
scheduleJob(ServiceWorkerJob::create(*this, WTFMove(promise), WTFMove(jobData)));
}
@@ -360,6 +374,8 @@
jobDidFinish(job);
});
+ CONTAINER_RELEASE_LOG_ERROR_IF_ALLOWED("jobFailedWithException: Job %llu failed with error %s", job.identifier().toUInt64(), exception.message().utf8().data());
+
if (!job.promise())
return;
@@ -391,6 +407,13 @@
jobDidFinish(job);
});
+ if (job.data().type == ServiceWorkerJobType::Register)
+ CONTAINER_RELEASE_LOG_IF_ALLOWED("jobResolvedWithRegistration: Registration job %llu succeeded", job.identifier().toUInt64());
+ else {
+ ASSERT(job.data().type == ServiceWorkerJobType::Update);
+ CONTAINER_RELEASE_LOG_IF_ALLOWED("jobResolvedWithRegistration: Update job %llu succeeded", job.identifier().toUInt64());
+ }
+
WTF::Function<void()> notifyWhenResolvedIfNeeded = [] { };
if (shouldNotifyWhenResolved == ShouldNotifyWhenResolved::Yes) {
notifyWhenResolvedIfNeeded = [connection = m_swConnection, registrationKey = data.key.isolatedCopy()]() mutable {
@@ -418,7 +441,7 @@
auto registration = ServiceWorkerRegistration::getOrCreate(context, *this, WTFMove(data));
- LOG(ServiceWorker, "Container %p resolved job with registration %p", this, registration.ptr());
+ CONTAINER_RELEASE_LOG_IF_ALLOWED("jobResolvedWithRegistration: Resolving promise for job %llu. Registration ID: %llu", job->identifier().toUInt64(), registration->identifier().toUInt64());
job->promise()->resolve<IDLInterface<ServiceWorkerRegistration>>(WTFMove(registration));
@@ -438,6 +461,8 @@
jobDidFinish(job);
});
+ CONTAINER_RELEASE_LOG_IF_ALLOWED("jobResolvedWithUnregistrationResult: Unregister job %llu finished. Success? %d", job.identifier().toUInt64(), unregistrationResult);
+
auto* context = scriptExecutionContext();
if (!context) {
LOG_ERROR("ServiceWorkerContainer::jobResolvedWithUnregistrationResult called but the containers ScriptExecutionContext is gone");
@@ -455,7 +480,7 @@
ASSERT(m_creationThread.ptr() == &Thread::current());
#endif
- LOG(ServiceWorker, "SeviceWorkerContainer %p starting script fetch for job %s", this, job.identifier().loggingString().utf8().data());
+ CONTAINER_RELEASE_LOG_IF_ALLOWED("startScriptFetchForJob: Starting script fetch for job %llu", job.identifier().toUInt64());
auto* context = scriptExecutionContext();
if (!context) {
@@ -476,7 +501,7 @@
ASSERT(m_creationThread.ptr() == &Thread::current());
#endif
- LOG(ServiceWorker, "SeviceWorkerContainer %p finished fetching script for job %s", this, job.identifier().loggingString().utf8().data());
+ CONTAINER_RELEASE_LOG_IF_ALLOWED("jobFinishedLoadingScript: Successfuly finished fetching script for job %llu", job.identifier().toUInt64());
callOnMainThread([connection = m_swConnection, jobDataIdentifier = job.data().identifier(), registrationKey = job.data().registrationKey(), script = script.isolatedCopy(), contentSecurityPolicy = contentSecurityPolicy.isolatedCopy()] {
connection->finishFetchingScriptInServer({ jobDataIdentifier, registrationKey, script, contentSecurityPolicy, { } });
@@ -490,7 +515,7 @@
#endif
ASSERT_WITH_MESSAGE(job.promise() || job.data().type == ServiceWorkerJobType::Update, "Only soft updates have no promise");
- LOG(ServiceWorker, "SeviceWorkerContainer %p failed fetching script for job %s", this, job.identifier().loggingString().utf8().data());
+ CONTAINER_RELEASE_LOG_ERROR_IF_ALLOWED("jobFinishedLoadingScript: Failed to fetch script for job %llu, error: %s", job.identifier().toUInt64(), error.localizedDescription().utf8().data());
if (exception && job.promise())
job.promise()->reject(*exception);
@@ -597,6 +622,19 @@
return downcast<Document>(*scriptExecutionContext()).identifier();
}
+bool ServiceWorkerContainer::isAlwaysOnLoggingAllowed() const
+{
+ auto* context = scriptExecutionContext();
+ if (!context)
+ return false;
+
+ if (is<Document>(*context))
+ return downcast<Document>(*context).sessionID().isAlwaysOnLoggingAllowed();
+
+ // FIXME: No logging inside service workers for now.
+ return false;
+}
+
} // namespace WebCore
#endif // ENABLE(SERVICE_WORKER)
Modified: trunk/Source/WebCore/workers/service/ServiceWorkerContainer.h (227349 => 227350)
--- trunk/Source/WebCore/workers/service/ServiceWorkerContainer.h 2018-01-22 21:01:12 UTC (rev 227349)
+++ trunk/Source/WebCore/workers/service/ServiceWorkerContainer.h 2018-01-22 21:08:46 UTC (rev 227350)
@@ -84,6 +84,8 @@
bool isStopped() const { return m_isStopped; };
+ bool isAlwaysOnLoggingAllowed() const;
+
private:
void scheduleJob(Ref<ServiceWorkerJob>&&);
Modified: trunk/Source/WebCore/workers/service/ServiceWorkerJobDataIdentifier.h (227349 => 227350)
--- trunk/Source/WebCore/workers/service/ServiceWorkerJobDataIdentifier.h 2018-01-22 21:01:12 UTC (rev 227349)
+++ trunk/Source/WebCore/workers/service/ServiceWorkerJobDataIdentifier.h 2018-01-22 21:08:46 UTC (rev 227350)
@@ -35,12 +35,10 @@
SWServerConnectionIdentifier connectionIdentifier;
ServiceWorkerJobIdentifier jobIdentifier;
-#ifndef NDEBUG
String loggingString() const
{
return connectionIdentifier.loggingString() + "-" + jobIdentifier.loggingString();
}
-#endif
template<class Encoder> void encode(Encoder&) const;
template<class Decoder> static std::optional<ServiceWorkerJobDataIdentifier> decode(Decoder&);
Modified: trunk/Source/WebCore/workers/service/ServiceWorkerRegistration.cpp (227349 => 227350)
--- trunk/Source/WebCore/workers/service/ServiceWorkerRegistration.cpp 2018-01-22 21:01:12 UTC (rev 227349)
+++ trunk/Source/WebCore/workers/service/ServiceWorkerRegistration.cpp 2018-01-22 21:08:46 UTC (rev 227350)
@@ -37,6 +37,9 @@
#include "ServiceWorkerTypes.h"
#include "WorkerGlobalScope.h"
+#define REGISTRATION_RELEASE_LOG_IF_ALLOWED(fmt, ...) RELEASE_LOG_IF(m_container->isAlwaysOnLoggingAllowed(), ServiceWorker, "%p - ServiceWorkerRegistration::" fmt, this, ##__VA_ARGS__)
+#define REGISTRATION_RELEASE_LOG_ERROR_IF_ALLOWED(fmt, ...) RELEASE_LOG_ERROR_IF(m_container->isAlwaysOnLoggingAllowed(), ServiceWorker, "%p - ServiceWorkerRegistration::" fmt, this, ##__VA_ARGS__)
+
namespace WebCore {
Ref<ServiceWorkerRegistration> ServiceWorkerRegistration::getOrCreate(ScriptExecutionContext& context, Ref<ServiceWorkerContainer>&& container, ServiceWorkerRegistrationData&& data)
@@ -64,6 +67,8 @@
if (m_registrationData.activeWorker)
m_activeWorker = ServiceWorker::getOrCreate(context, WTFMove(*m_registrationData.activeWorker));
+ REGISTRATION_RELEASE_LOG_IF_ALLOWED("ServiceWorkerRegistration: ID %llu, installing: %llu, waiting: %llu, active: %llu", identifier().toUInt64(), m_installingWorker ? m_installingWorker->identifier().toUInt64() : 0, m_waitingWorker ? m_waitingWorker->identifier().toUInt64() : 0, m_activeWorker ? m_activeWorker->identifier().toUInt64() : 0);
+
m_container->addRegistration(*this);
relaxAdoptionRequirement();
@@ -171,12 +176,15 @@
{
switch (state) {
case ServiceWorkerRegistrationState::Installing:
+ REGISTRATION_RELEASE_LOG_IF_ALLOWED("updateStateFromServer: Setting registration %llu installing worker to %llu", identifier().toUInt64(), serviceWorker ? serviceWorker->identifier().toUInt64() : 0);
m_installingWorker = WTFMove(serviceWorker);
break;
case ServiceWorkerRegistrationState::Waiting:
+ REGISTRATION_RELEASE_LOG_IF_ALLOWED("updateStateFromServer: Setting registration %llu waiting worker to %llu", identifier().toUInt64(), serviceWorker ? serviceWorker->identifier().toUInt64() : 0);
m_waitingWorker = WTFMove(serviceWorker);
break;
case ServiceWorkerRegistrationState::Active:
+ REGISTRATION_RELEASE_LOG_IF_ALLOWED("updateStateFromServer: Setting registration %llu active worker to %llu", identifier().toUInt64(), serviceWorker ? serviceWorker->identifier().toUInt64() : 0);
m_activeWorker = WTFMove(serviceWorker);
break;
}
@@ -192,6 +200,8 @@
if (m_isStopped)
return;
+ REGISTRATION_RELEASE_LOG_IF_ALLOWED("scheduleTaskToFireUpdateFoundEvent: Firing updatefound event for registration %llu", identifier().toUInt64());
+
ASSERT(m_pendingActivityForEventDispatch);
dispatchEvent(Event::create(eventNames().updatefoundEvent, false, false));
});
Modified: trunk/Source/WebCore/workers/service/server/SWServer.cpp (227349 => 227350)
--- trunk/Source/WebCore/workers/service/server/SWServer.cpp 2018-01-22 21:01:12 UTC (rev 227349)
+++ trunk/Source/WebCore/workers/service/server/SWServer.cpp 2018-01-22 21:08:46 UTC (rev 227350)
@@ -334,6 +334,8 @@
if (!jobDataIdentifier)
return;
+ RELEASE_LOG_ERROR(ServiceWorker, "%p - SWServer::scriptContextFailedToStart: Failed to start SW for job %s, error: %s", this, jobDataIdentifier->loggingString().utf8().data(), message.utf8().data());
+
if (auto* jobQueue = m_jobQueues.get(worker.registrationKey()))
jobQueue->scriptContextFailedToStart(*jobDataIdentifier, worker.identifier(), message);
}
@@ -352,6 +354,11 @@
if (!jobDataIdentifier)
return;
+ if (wasSuccessful)
+ RELEASE_LOG(ServiceWorker, "%p - SWServer::didFinishInstall: Successfuly finished SW install for job %s", this, jobDataIdentifier->loggingString().utf8().data());
+ else
+ RELEASE_LOG_ERROR(ServiceWorker, "%p - SWServer::didFinishInstall: Failed SW install for job %s", this, jobDataIdentifier->loggingString().utf8().data());
+
if (auto* jobQueue = m_jobQueues.get(worker.registrationKey()))
jobQueue->didFinishInstall(*jobDataIdentifier, worker.identifier(), wasSuccessful);
}
@@ -358,6 +365,8 @@
void SWServer::didFinishActivation(SWServerWorker& worker)
{
+ RELEASE_LOG(ServiceWorker, "%p - SWServer::didFinishActivation: Finished activation for service worker %llu", this, worker.identifier().toUInt64());
+
if (auto* registration = getRegistration(worker.registrationKey()))
registration->didFinishActivation(worker.identifier());
}
@@ -575,6 +584,8 @@
ASSERT(m_runningOrTerminatingWorkers.get(worker.identifier()) == &worker);
ASSERT(worker.isRunning());
+ RELEASE_LOG(ServiceWorker, "%p - SWServer::terminateWorkerInternal: Terminating service worker %llu", this, worker.identifier().toUInt64());
+
worker.setState(SWServerWorker::State::Terminating);
auto* connection = SWServerToContextConnection::connectionForIdentifier(worker.contextConnectionIdentifier());
Modified: trunk/Source/WebCore/workers/service/server/SWServerJobQueue.cpp (227349 => 227350)
--- trunk/Source/WebCore/workers/service/server/SWServerJobQueue.cpp 2018-01-22 21:01:12 UTC (rev 227349)
+++ trunk/Source/WebCore/workers/service/server/SWServerJobQueue.cpp 2018-01-22 21:08:46 UTC (rev 227350)
@@ -159,6 +159,8 @@
ASSERT(registration);
ASSERT(registration->installingWorker());
+ RELEASE_LOG(ServiceWorker, "%p - SWServerJobQueue::didResolveRegistrationPromise: Registration ID: %llu. Now proceeding with install", this, registration->identifier().toUInt64());
+
// Queue a task to fire an event named updatefound at all the ServiceWorkerRegistration objects
// for all the service worker clients whose creation URL matches registration's scope url and
// all the service workers whose containing service worker registration is registration.
@@ -263,6 +265,7 @@
registration->setIsUninstalling(false);
auto* newestWorker = registration->getNewestWorker();
if (newestWorker && equalIgnoringFragmentIdentifier(job.scriptURL, newestWorker->scriptURL()) && job.registrationOptions.updateViaCache == registration->updateViaCache()) {
+ RELEASE_LOG(ServiceWorker, "%p - SWServerJobQueue::runRegisterJob: Found directly reusable registration %llu for job %s (DONE)", this, registration->identifier().toUInt64(), job.identifier().loggingString().utf8().data());
m_server.resolveRegistrationJob(job, registration->data(), ShouldNotifyWhenResolved::No);
finishCurrentJob();
return;
@@ -270,9 +273,12 @@
// This is not specified yet (https://github.com/w3c/ServiceWorker/issues/1189).
if (registration->updateViaCache() != job.registrationOptions.updateViaCache)
registration->setUpdateViaCache(job.registrationOptions.updateViaCache);
+ RELEASE_LOG(ServiceWorker, "%p - SWServerJobQueue::runRegisterJob: Found registration %llu for job %s but it needs updating", this, registration->identifier().toUInt64(), job.identifier().loggingString().utf8().data());
} else {
auto newRegistration = std::make_unique<SWServerRegistration>(m_server, m_registrationKey, job.registrationOptions.updateViaCache, job.scopeURL, job.scriptURL);
m_server.addRegistration(WTFMove(newRegistration));
+
+ RELEASE_LOG(ServiceWorker, "%p - SWServerJobQueue::runRegisterJob: No existing registration for job %s, constructing a new one.", this, job.identifier().loggingString().utf8().data());
}
runUpdateJob(job);
Modified: trunk/Source/WebKit/ChangeLog (227349 => 227350)
--- trunk/Source/WebKit/ChangeLog 2018-01-22 21:01:12 UTC (rev 227349)
+++ trunk/Source/WebKit/ChangeLog 2018-01-22 21:08:46 UTC (rev 227350)
@@ -1,3 +1,17 @@
+2018-01-22 Chris Dumez <cdu...@apple.com>
+
+ Add release logging to help debug issues related to service workers
+ https://bugs.webkit.org/show_bug.cgi?id=181935
+ <rdar://problem/36735900>
+
+ Reviewed by Brady Eidson.
+
+ * StorageProcess/ServiceWorker/WebSWServerConnection.cpp:
+ (WebKit::WebSWServerConnection::startFetch):
+ (WebKit::WebSWServerConnection::didFinishFetch):
+ (WebKit::WebSWServerConnection::didFailFetch):
+ (WebKit::WebSWServerConnection::didNotHandleFetch):
+
2018-01-22 Brent Fulgham <bfulg...@apple.com>
[iOS] REGRESSION (r225763): Allow access to power logging features
Modified: trunk/Source/WebKit/StorageProcess/ServiceWorker/WebSWServerConnection.cpp (227349 => 227350)
--- trunk/Source/WebKit/StorageProcess/ServiceWorker/WebSWServerConnection.cpp 2018-01-22 21:01:12 UTC (rev 227349)
+++ trunk/Source/WebKit/StorageProcess/ServiceWorker/WebSWServerConnection.cpp 2018-01-22 21:08:46 UTC (rev 227350)
@@ -56,6 +56,9 @@
namespace WebKit {
+#define SWSERVERCONNECTION_RELEASE_LOG_IF_ALLOWED(fmt, ...) RELEASE_LOG_IF(m_sessionID.isAlwaysOnLoggingAllowed(), ServiceWorker, "%p - WebSWServerConnection::" fmt, this, ##__VA_ARGS__)
+#define SWSERVERCONNECTION_RELEASE_LOG_ERROR_IF_ALLOWED(fmt, ...) RELEASE_LOG_ERROR_IF(m_sessionID.isAlwaysOnLoggingAllowed(), ServiceWorker, "%p - WebSWServerConnection::" fmt, this, ##__VA_ARGS__)
+
WebSWServerConnection::WebSWServerConnection(SWServer& server, IPC::Connection& connection, SessionID sessionID)
: SWServer::Connection(server)
, m_sessionID(sessionID)
@@ -130,6 +133,7 @@
{
auto* worker = server().activeWorkerFromRegistrationID(serviceWorkerRegistrationIdentifier);
if (!worker) {
+ SWSERVERCONNECTION_RELEASE_LOG_ERROR_IF_ALLOWED("startFetch: fetchIdentifier: %llu -> DidNotHandle because no active worker", fetchIdentifier);
m_contentConnection->send(Messages::ServiceWorkerClientFetch::DidNotHandle { }, fetchIdentifier);
return;
}
@@ -140,6 +144,7 @@
return;
if (!success) {
+ SWSERVERCONNECTION_RELEASE_LOG_ERROR_IF_ALLOWED("startFetch: fetchIdentifier: %llu -> DidNotHandle because worker did not become activated", fetchIdentifier);
m_contentConnection->send(Messages::ServiceWorkerClientFetch::DidNotHandle { }, fetchIdentifier);
return;
}
@@ -148,10 +153,13 @@
if (!weakThis)
return;
- if (success)
+ if (success) {
+ SWSERVERCONNECTION_RELEASE_LOG_IF_ALLOWED("startFetch: Starting fetch %llu via service worker %llu", fetchIdentifier, serviceWorkerIdentifier.toUInt64());
sendToContextProcess(contextConnection, Messages::WebSWContextManagerConnection::StartFetch { identifier(), fetchIdentifier, serviceWorkerIdentifier, request, options, formData, referrer });
- else
+ } else {
+ SWSERVERCONNECTION_RELEASE_LOG_ERROR_IF_ALLOWED("startFetch: fetchIdentifier: %llu -> DidNotHandle because failed to run service worker", fetchIdentifier);
m_contentConnection->send(Messages::ServiceWorkerClientFetch::DidNotHandle { }, fetchIdentifier);
+ }
});
};
@@ -201,16 +209,19 @@
void WebSWServerConnection::didFinishFetch(uint64_t fetchIdentifier)
{
+ SWSERVERCONNECTION_RELEASE_LOG_IF_ALLOWED("didFinishFetch: fetchIdentifier: %llu", fetchIdentifier);
m_contentConnection->send(Messages::ServiceWorkerClientFetch::DidFinish { }, fetchIdentifier);
}
void WebSWServerConnection::didFailFetch(uint64_t fetchIdentifier)
{
+ SWSERVERCONNECTION_RELEASE_LOG_ERROR_IF_ALLOWED("didFailFetch: fetchIdentifier: %llu", fetchIdentifier);
m_contentConnection->send(Messages::ServiceWorkerClientFetch::DidFail { }, fetchIdentifier);
}
void WebSWServerConnection::didNotHandleFetch(uint64_t fetchIdentifier)
{
+ SWSERVERCONNECTION_RELEASE_LOG_IF_ALLOWED("didNotHandleFetch: fetchIdentifier: %llu", fetchIdentifier);
m_contentConnection->send(Messages::ServiceWorkerClientFetch::DidNotHandle { }, fetchIdentifier);
}
