Title: [228139] branches/safari-605-branch/Source

Diff

Modified: branches/safari-605-branch/Source/WebCore/ChangeLog (228138 => 228139)


--- branches/safari-605-branch/Source/WebCore/ChangeLog	2018-02-05 23:38:47 UTC (rev 228138)
+++ branches/safari-605-branch/Source/WebCore/ChangeLog	2018-02-06 00:15:58 UTC (rev 228139)
@@ -1,3 +1,46 @@
+2018-02-05  Jason Marcell  <jmarc...@apple.com>
+
+        Cherry-pick r227350. rdar://problem/37243993
+
+    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-02-04  Jason Marcell  <jmarc...@apple.com>
 
         Apply patch. rdar://problem/36547114

Modified: branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorker.cpp (228138 => 228139)


--- branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorker.cpp	2018-02-05 23:38:47 UTC (rev 228138)
+++ branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorker.cpp	2018-02-06 00:15:58 UTC (rev 228139)
@@ -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);
@@ -166,6 +173,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: branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorker.h (228138 => 228139)


--- branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorker.h	2018-02-05 23:38:47 UTC (rev 228138)
+++ branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorker.h	2018-02-06 00:15:58 UTC (rev 228139)
@@ -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: branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorkerContainer.cpp (228138 => 228139)


--- branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorkerContainer.cpp	2018-02-05 23:38:47 UTC (rev 228138)
+++ branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorkerContainer.cpp	2018-02-06 00:15:58 UTC (rev 228139)
@@ -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)));
 }
 
@@ -362,6 +376,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;
 
@@ -393,6 +409,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 {
@@ -420,7 +443,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));
 
@@ -440,6 +463,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");
@@ -457,7 +482,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) {
@@ -478,7 +503,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, { } });
@@ -492,7 +517,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);
@@ -601,6 +626,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: branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorkerContainer.h (228138 => 228139)


--- branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorkerContainer.h	2018-02-05 23:38:47 UTC (rev 228138)
+++ branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorkerContainer.h	2018-02-06 00:15:58 UTC (rev 228139)
@@ -84,6 +84,8 @@
 
     bool isStopped() const { return m_isStopped; };
 
+    bool isAlwaysOnLoggingAllowed() const;
+
 private:
     void scheduleJob(Ref<ServiceWorkerJob>&&);
 

Modified: branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorkerJobDataIdentifier.h (228138 => 228139)


--- branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorkerJobDataIdentifier.h	2018-02-05 23:38:47 UTC (rev 228138)
+++ branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorkerJobDataIdentifier.h	2018-02-06 00:15:58 UTC (rev 228139)
@@ -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: branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorkerRegistration.cpp (228138 => 228139)


--- branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorkerRegistration.cpp	2018-02-05 23:38:47 UTC (rev 228138)
+++ branches/safari-605-branch/Source/WebCore/workers/service/ServiceWorkerRegistration.cpp	2018-02-06 00:15:58 UTC (rev 228139)
@@ -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: branches/safari-605-branch/Source/WebCore/workers/service/server/SWServer.cpp (228138 => 228139)


--- branches/safari-605-branch/Source/WebCore/workers/service/server/SWServer.cpp	2018-02-05 23:38:47 UTC (rev 228138)
+++ branches/safari-605-branch/Source/WebCore/workers/service/server/SWServer.cpp	2018-02-06 00:15:58 UTC (rev 228139)
@@ -359,6 +359,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);
 }
@@ -377,6 +379,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);
 }
@@ -383,6 +390,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());
 }
@@ -590,6 +599,8 @@
     ASSERT(m_runningOrTerminatingWorkers.get(worker.identifier()) == &worker);
     ASSERT(!worker.isTerminating());
 
+    RELEASE_LOG(ServiceWorker, "%p - SWServer::terminateWorkerInternal: Terminating service worker %llu", this, worker.identifier().toUInt64());
+
     worker.setState(SWServerWorker::State::Terminating);
 
     auto contextConnectionIdentifier = worker.contextConnectionIdentifier();

Modified: branches/safari-605-branch/Source/WebCore/workers/service/server/SWServerJobQueue.cpp (228138 => 228139)


--- branches/safari-605-branch/Source/WebCore/workers/service/server/SWServerJobQueue.cpp	2018-02-05 23:38:47 UTC (rev 228138)
+++ branches/safari-605-branch/Source/WebCore/workers/service/server/SWServerJobQueue.cpp	2018-02-06 00:15:58 UTC (rev 228139)
@@ -161,6 +161,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.
@@ -266,6 +268,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;
@@ -273,9 +276,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: branches/safari-605-branch/Source/WebKit/ChangeLog (228138 => 228139)


--- branches/safari-605-branch/Source/WebKit/ChangeLog	2018-02-05 23:38:47 UTC (rev 228138)
+++ branches/safari-605-branch/Source/WebKit/ChangeLog	2018-02-06 00:15:58 UTC (rev 228139)
@@ -1,3 +1,21 @@
+2018-02-05  Jason Marcell  <jmarc...@apple.com>
+
+        Cherry-pick r227350. rdar://problem/37243993
+
+    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-02-04  Jason Marcell  <jmarc...@apple.com>
 
         Apply patch. rdar://problem/36547114

Modified: branches/safari-605-branch/Source/WebKit/StorageProcess/ServiceWorker/WebSWServerConnection.cpp (228138 => 228139)


--- branches/safari-605-branch/Source/WebKit/StorageProcess/ServiceWorker/WebSWServerConnection.cpp	2018-02-05 23:38:47 UTC (rev 228138)
+++ branches/safari-605-branch/Source/WebKit/StorageProcess/ServiceWorker/WebSWServerConnection.cpp	2018-02-06 00:15:58 UTC (rev 228139)
@@ -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);
+            }
         });
     };
 
@@ -205,16 +213,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);
 }
 
_______________________________________________
webkit-changes mailing list
webkit-changes@lists.webkit.org
https://lists.webkit.org/mailman/listinfo/webkit-changes

Reply via email to