Bug 193701

Summary: STP: Occasional WebProcess hangs
Product: WebKit Reporter: Jon <jon>
Component: WebKit2Assignee: Nobody <webkit-unassigned>
Status: RESOLVED DUPLICATE    
Severity: Major CC: ap, cdumez, webkit-bug-importer
Priority: P2 Keywords: InRadar
Version: Safari Technology Preview   
Hardware: Mac   
OS: macOS 10.14   
Attachments:
Description Flags
spindump of apparently hung WebProcess
none
spindump from process associated with the log message none

Jon
Reported 2019-01-22 17:58:17 PST
Created attachment 359826 [details] spindump of apparently hung WebProcess Sorry for the non-descriptive title. For the last couple STP builds I've noticed a tab hanging problem. This usually occurs after I Google something, navigate back to the search results, and then try to navigate to another result. I lose interactivity with the web content (no hover behavior, no selection, but scrolling still works) and when I try to reload, the tab beachballs. However, it isn't only on Google results as I just saw it on aviation.stackexchange.com. I went to a topic, navigated back to root, then tried to go to another topic and I lost interactivity. Attempting to reload produced the beachball. This has happened on multiple machines, Mojave, STP ~71 - 73. Safari UI is still fully functional, so closing the tab makes the beachball go away. Attached is a spindump from the aviation.stackexchange.com WebProcess.
Attachments
spindump of apparently hung WebProcess (1.03 MB, application/zip)
2019-01-22 17:58 PST, Jon 		no flags
Details
spindump from process associated with the log message (1.40 MB, application/zip)
2019-01-23 10:11 PST, Jon 		no flags
Details
View All Add attachment proposed patch, testcase, etc.
Alexey Proskuryakov
Comment 1 2019-01-23 09:41:25 PST
The spindump shows WebContent processes idle, none of them appear hung. The symptoms do look like hung WebContent indeed. Could you please try capturing more spindumps? Are there any in Console.app that were automatically captured for beachball events?
Radar WebKit Bug Importer
Comment 2 2019-01-23 09:41:40 PST
<rdar://problem/47483542>
Jon
Comment 3 2019-01-23 10:11:51 PST
Created attachment 359900 [details] spindump from process associated with the log message
Jon
Comment 4 2019-01-23 10:14:47 PST
I've been able to replicate this fairly easily by quickly navigating between a Google search and result pages (typically on StackOverflow). This time it hung while on the blank page between pages. Here are the (hopefully relevant) togs from the time: default 13:04:53.015494 -0500 com.apple.WebKit.WebContent 0x5abd20578 - WebResourceLoader::didReceiveResponse: (pageID = 82, frameID = 26, resourceID = 148, status = 200) default 13:04:53.016257 -0500 com.apple.WebKit.WebContent 0x5abd20578 - WebResourceLoader::didReceiveData: Started receiving data (pageID = 82, frameID = 26, resourceID = 148) default 13:04:53.028990 -0500 com.apple.WebKit.WebContent 0x5abd20578 - WebResourceLoader::didFinishResourceLoad: (pageID = 82, frameID = 26, resourceID = 148, length = 1042) default 13:04:53.029037 -0500 com.apple.WebKit.WebContent 0x5927c6b00 - SubresourceLoader::didFinishLoading: (frame = 0x5a31ead68, frameLoader = 0x7fe7b5f7f940, resourceID = 148) default 13:04:53.036049 -0500 com.apple.WebKit.WebContent 0x5a3ed6bb0 - ProgressTracker::progressCompleted: frame 0x5a31ead68, value 0.500000, tracked frames 1, originating frame 0x5a31ead68, isMainLoad 0 default 13:04:53.036093 -0500 com.apple.WebKit.WebContent 0x5a3ed6bb0 - ProgressTracker::finalProgressComplete: value 0.500000, tracked frames 0, originating frame 0x5a31ead68, isMainLoad 0, isMainLoadProgressing 0 default 13:04:53.036129 -0500 com.apple.WebKit.WebContent 0x7fe7b5f7f940 - FrameLoader::checkLoadCompleteForThisFrame: Finished frame load (frame = 0x5a31ead68, main = 0) default 13:04:53.036324 -0500 com.apple.WebKit.WebContent 0x7fe7b5f7fbe0 - FrameLoader::urlSelected: frame load started (frame = 0x5a7609e70, main = 1) default 13:04:53.036370 -0500 com.apple.WebKit.WebContent 0x7fe7b5f7fbe0 - FrameLoader::loadFrameRequest: frame load started (frame = 0x5a7609e70, main = 1) default 13:04:53.036406 -0500 com.apple.WebKit.WebContent 0x7fe7b5f7fbe0 - FrameLoader::loadURL: frame load started (frame = 0x5a7609e70, main = 1) default 13:04:53.036441 -0500 com.apple.WebKit.WebContent 0x7fe7b5f7fbe0 - FrameLoader::loadWithNavigationAction: frame load started (frame = 0x5a7609e70, main = 1) default 13:04:53.036468 -0500 com.apple.WebKit.WebContent 0x7fe7b5f7fbe0 - FrameLoader::loadWithDocumentLoader: frame load started (frame = 0x5a7609e70, main = 1) default 13:04:53.036488 -0500 com.apple.WebKit.WebContent 0x7fe7b5f7fbe0 - FrameLoader::loadWithDocumentLoader: main frame load started (frame = 0x5a7609e70, main = 1) default 13:04:53.036531 -0500 com.apple.WebKit.WebContent Memory usage info dump at MainFrameLoadStarted: default 13:04:53.036553 -0500 com.apple.WebKit.WebContent phys_footprint: 139698176 default 13:04:53.036580 -0500 com.apple.WebKit.WebContent internal: 140496896 default 13:04:53.036692 -0500 com.apple.WebKit.WebContent pagecache_page_count: 0 default 13:04:53.036900 -0500 com.apple.WebKit.WebContent javascript_gc_heap_capacity: 33378886 default 13:04:53.036949 -0500 com.apple.WebKit.WebContent javascript_gc_heap_extra_memory_size: 5904902 default 13:04:53.037010 -0500 com.apple.WebKit.WebContent document_count: 11 default 13:04:53.037095 -0500 com.apple.WebKit.WebContent compressed: 0 default 13:04:53.037127 -0500 com.apple.WebKit.WebContent virtual_size: 109329633280 default 13:04:53.037153 -0500 com.apple.WebKit.WebContent resident_size: 210198528 default 13:04:53.037507 -0500 com.apple.WebKit.WebContent 0x7fe7b5f7f940 - FrameLoader::urlSelected: frame load started (frame = 0x5a31ead68, main = 0) default 13:04:53.037547 -0500 com.apple.WebKit.WebContent 0x7fe7b5f7f940 - FrameLoader::loadFrameRequest: frame load started (frame = 0x5a31ead68, main = 0) default 13:04:53.037576 -0500 com.apple.WebKit.WebContent 0x7fe7b5f7f940 - FrameLoader::loadURL: frame load started (frame = 0x5a31ead68, main = 0) default 13:04:53.037607 -0500 com.apple.WebKit.WebContent 0x7fe7b5f7f940 - FrameLoader::loadWithNavigationAction: frame load started (frame = 0x5a31ead68, main = 0) default 13:04:53.037636 -0500 com.apple.WebKit.WebContent 0x7fe7b5f7f940 - FrameLoader::loadWithDocumentLoader: frame load started (frame = 0x5a31ead68, main = 0) default 13:04:53.039000 -0500 com.apple.WebKit.WebContent 0x7fe7b5f7f940 - FrameLoader::prepareForLoadStart: Starting frame load (frame = 0x5a31ead68, main = 0) default 13:04:53.039053 -0500 com.apple.WebKit.WebContent 0x5a3ed6bb0 - ProgressTracker::progressStarted: frame 0x5a31ead68, value 0.100000, tracked frames 1, originating frame 0x5a31ead68, isMainLoad 0 default 13:04:53.044202 -0500 com.apple.WebKit.WebContent 0x5a3ed6bb0 - ProgressTracker::progressCompleted: frame 0x5a31ead68, value 0.100000, tracked frames 1, originating frame 0x5a31ead68, isMainLoad 0 default 13:04:53.044235 -0500 com.apple.WebKit.WebContent 0x5a3ed6bb0 - ProgressTracker::finalProgressComplete: value 0.100000, tracked frames 0, originating frame 0x5a31ead68, isMainLoad 0, isMainLoadProgressing 0 default 13:04:53.044271 -0500 com.apple.WebKit.WebContent 0x7fe7b5f7f940 - FrameLoader::checkLoadCompleteForThisFrame: Finished frame load (frame = 0x5a31ead68, main = 0) default 13:04:53.044309 -0500 com.apple.WebKit.WebContent 0x5aa6e5100 - DocumentLoader::startLoadingMainResource: Returning empty document (frame = 0x5a31ead68, main = 0) default 13:04:53.044397 -0500 com.apple.WebKit.WebContent 0x7fe7b5f7fbe0 - FrameLoader::continueLoadAfterNavigationPolicy: can't continue loading frame due to the following reasons (frame = 0x5a7609e70, main = 1, allowNavigationToInvalidURL = 0, requestURLIsValid = 0, shouldContinue = 1) default 13:04:53.051416 -0500 com.apple.WebKit.WebContent HTMLMediaElement::scheduleUpdatePlayState(2DA8A344) task scheduled default 13:04:53.051479 -0500 com.apple.WebKit.WebContent HTMLMediaElement::setPlaybackWithoutUserGesture(2DA8A344) None default 13:04:53.051539 -0500 com.apple.WebKit.WebContent HTMLMediaElement::scheduleUpdatePlayState(2DA8A345) task scheduled default 13:04:53.051578 -0500 com.apple.WebKit.WebContent HTMLMediaElement::setPlaybackWithoutUserGesture(2DA8A345) None default 13:04:53.051616 -0500 com.apple.WebKit.WebContent HTMLMediaElement::scheduleUpdatePlayState(2DA8A346) task scheduled default 13:04:53.051717 -0500 com.apple.WebKit.WebContent HTMLMediaElement::setPlaybackWithoutUserGesture(2DA8A346) None default 13:04:53.052438 -0500 com.apple.WebKit.WebContent [NowPlayingInfo] Setting identical nowPlayingInfo, skipping update. default 13:04:53.052474 -0500 com.apple.WebKit.WebContent [NowPlayingInfo] Clearing nowPlayingInfo default 13:04:53.146592 -0500 com.apple.WebKit.WebContent HTMLMediaElement::setShouldPlayToPlaybackTarget(1DA6C8A5) false default 13:04:53.160454 -0500 com.apple.WebKit.WebContent LSExceptions shared instance invalidated for timeout. This line stood out: default 13:04:53.044397 -0500 com.apple.WebKit.WebContent 0x7fe7b5f7fbe0 - FrameLoader::continueLoadAfterNavigationPolicy: can't continue loading frame due to the following reasons (frame = 0x5a7609e70, main = 1, allowNavigationToInvalidURL = 0, requestURLIsValid = 0, shouldContinue = 1) So I captured the spindump for the associated process, and has been attached.
Alexey Proskuryakov
Comment 5 2019-01-23 10:22:50 PST
I've been unable to reproduce with STP 73 on Mojave, and the second spindump also doesn't show a hung process. Chris, does this ring a bell?
Jon
Comment 6 2019-02-12 18:10:53 PST
Still seeing this with STP 75, most frequently on the various Stack Exchange sites. What can I do to gather more diagnostics?
Chris Dumez
Comment 7 2019-02-12 19:45:31 PST
I believe this is a dupe. We have fixed this very recently. The fix is not in STP yet. *** This bug has been marked as a duplicate of bug 194522 ***
Note You need to log in before you can comment on or make changes to this bug.