Bug 185780 – forums.swift.org doesn't render in STP 56

• Status: RESOLVED
• Resolution: WORKSFORME
• Component: Layout and Rendering

[Jon]

STP has been having issues rendering forums.swift.org for a while now, but a reload ignoring cache usually fixed it. However, with STP 56, forums.swift.org is rendered blank 100% of the time, with these errors in the console:

[Error] ReferenceError: Can't find variable: I18n
	(anonymous function) (forums.swift.org:226)
	Global Code (forums.swift.org:231)

[Error] undefined is not an object (evaluating 'r.get(this,"router").startRouting')
startRouting@https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:8:11605
didBecomeReady@https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:8:17139
invokeWithOnError@https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:19393
flush@https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:19833
flush@https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:20599
end@https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:20944
run@https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:22014
p@https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:2:9026
https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:2:9325
	error
	u (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:11:30380)
	o (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:11:30275)
	invokeWithOnError (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:19408)
	flush (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:19834)
	flush (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:20600)
	end (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:20945)
	run (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:22015)
	p (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:2:9027)
	(anonymous function) (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:2:9326)

[Error] undefined is not an object (evaluating 'r.get(this,"router").startRouting')
startRouting@https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:8:11605
didBecomeReady@https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:8:17139
invokeWithOnError@https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:19393
flush@https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:19833
flush@https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:20599
end@https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:20944
run@https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:22014
p@https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:2:9026
https://discourse-cdn-sjc1.com/swift/brotli_asset/ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:2:9325
	error
	u (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:11:30380)
	o (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:11:30275)
	i (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:14:28458)
	trigger (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:19:5889)
	(anonymous function) (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:19:7873)
	invokeWithOnError (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:19394)
	flush (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:19834)
	flush (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:20600)
	end (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:20945)
	run (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:7:22015)
	p (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:2:9027)
	(anonymous function) (ember_jquery-27e777857b8c0730dacfe09cb11711365d21a5db4f9ee0b85d494e4259cf6cda.js:2:9326)

Safari 11.1 (13605.1.33.1.4) renders correctly.

[Jon]

Downloading the failed render as a web archive and then opening it seems to have allowed STP to start rendering the site and the errors in the console are gone.

[Radar WebKit Bug Importer]

<rdar://problem/40376092>

[Simon Fraser (smfr)]

I can't reproduce. Can you try turning off Safari extensions, and trying in a new user account?

[Jon]

Only plugins are 1Blocker and 1Password. I turned off 1Blocker before reporting the bug, there was no change. I never tried another user.

Investigating this a bit more and I'm pretty sure it's not specific to forums.swift.org (though that's where I see it most often). Sorry about that. 

However, I do have a hypothesis. 

I recently started observing similar behavior for superuser.com. STP would start the load but would just seem to hang. Looking in the inspector it seemed that one of the site resource loads was hanging (in this case, for the primary.css file). On forums.swift.org, this was one or more of the JS files. I thought it was a transitory network issue with forums.swift.org until I saw it again today with superuser.com.

In Console, attempting to load superuser.com creates many logs, but I found the logs for com.apple.WebKit.Networking most interesting. It seems that most of the requests result in some logging like this: 

default	00:36:00.951220 -0400	com.apple.WebKit.Networking	0x10dbbc000 - NetworkResourceLoader::start: Checking cache for resource (pageID = 18, frameID = 1, resourceID = 16, isMainResource = 1, isSynchronous = 0)
default	00:36:00.951297 -0400	com.apple.WebKit.Networking	0x10dbbc000 - NetworkResourceLoader::retrieveCacheEntry: Resource not in cache (pageID = 18, frameID = 1, resourceID = 16, isMainResource = 1, isSynchronous = 0)
default	00:36:00.951321 -0400	com.apple.WebKit.Networking	0x10dbbc000 - NetworkResourceLoader::startNetworkLoad: (pageID = 18, frameID = 1, resourceID = 16, isMainResource = 1, isSynchronous = 0)
default	00:36:00.951466 -0400	com.apple.WebKit.Networking	0x10dbbc000 - NetworkResourceLoader::startNetworkLoad: (pageID = 18, frameID = 1, resourceID = 16, description = <__NSCFLocalDataTask: 0x7fdf3224eb70>{ taskIdentifier: 203 } { running })

I'm not familiar with how this process works, but there did seem to be a correlation between the number of tasks I saw this logging for, and the number of successfully loaded resources. For task 203 I later saw these messages:

default	00:36:00.951812 -0400	com.apple.WebKit.Networking	Task <B8500B17-DF78-4AA0-80E5-7F7AC4CFB030>.<203> now using Connection 72
default	00:36:00.952123 -0400	com.apple.WebKit.Networking	Task <B8500B17-DF78-4AA0-80E5-7F7AC4CFB030>.<203> sent request, body N
default	00:36:01.011952 -0400	com.apple.WebKit.Networking	Task <B8500B17-DF78-4AA0-80E5-7F7AC4CFB030>.<203> received response, status 200 content K
default	00:36:01.037768 -0400	com.apple.WebKit.Networking	Task <B8500B17-DF78-4AA0-80E5-7F7AC4CFB030>.<203> response ended

However, interspersed with these messages were messages for a task 204, which never logged the earlier NetworkResourceLoader messages. Instead, I this for that task:

default	00:36:00.952070 -0400	com.apple.WebKit.Networking	Task <01EF60AF-89A0-40EF-ACDC-63384C33E60E>.<204> now using Connection 1
default	00:36:00.952131 -0400	com.apple.WebKit.Networking	Task <01EF60AF-89A0-40EF-ACDC-63384C33E60E>.<204> sent request, body N

And then nothing more, until a minute later, when this was logged:

error	00:37:01.918511 -0400	com.apple.WebKit.Networking	Task <01EF60AF-89A0-40EF-ACDC-63384C33E60E>.<204> finished with error - code: -1001

It seems suspicious to me that there were no logs for the loader creating this task, and that it tried to use connection 1. But even now, 20 minutes after I start the load of superuser.com, it's still going in the inspector, the load of primary.css having never completed while I wrote this message. I'm also guessing that my load of forums.swift.org from a webarchive allowed the resource loader to properly see some cached resourced or otherwise was able to reset whatever code path was causing the hang.

If none of this is plausible, let me know what else you'd like to see for the hangs I'm observing.

[Simon Fraser (smfr)]

Does 'curl' download the primary.css file OK?

[Jon]

Yes, I was able to copy the cURL command from the inspector and run it successfully.

[youenn fablet]

Hi Jon,

It seems that some script defining I18n is not received properly.
It might be related to a service worker issue.
I was unable to reproduce your issue with STP56.
Can you try on your side with service worker enabled and disabled to check whether that makes a difference?
You can enable/disable service worker through Develop menu -> "Experimental Features" -> "Service Workers".

[Jon]

youenn, if you see my follow up comment, it seems that the loading issue can happen for other sites, but you're likely correct for the JS errors I was originally seeing: forums.swift.org wasn't able to load the JS file it needed and so those errors were produced. However, I think the issue may be more lower level than service workers.

I'll keep an eye out, but it once it fixes itself, it take a little while to happen again, and may happen to other sites. And if whatever fails to load on those sites doesn't break the page in some way, I may not notice it. If I do see, I'll disable service workers and see if it helps.

[Keith Rollin]

Jon, if you could take a sysdiagnose after the problem occurs and attach it, I could take a look at the logging it includes.

[Alexey Proskuryakov]

Also, does this only happen for you when logged in to the forum?

[Jon]

I haven't had the issue reoccur in over a week or so, basically since I loaded the webarchive. There's been a new tech preview (or two), as well as a macOS update in that time. If it does happen again I'll get a sysdiagnose. When it did occur, I'm pretty sure I was logged in at the time. I did see the same behavior for a bit from superuser.com, as I mentioned, but both sites are working fine now.

[Alexey Proskuryakov]

Same as bug 187197?

[Keith Rollin]

Seems safe to close now as "Cannot reproduce".