Summary: | REGRESSION (r261812): editing/async-clipboard/clipboard-item-get-type-basic.html is flaky | ||||||||||||||||||||||||||||||||
---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
Product: | WebKit | Reporter: | Jason Lawrence <Lawrence.j> | ||||||||||||||||||||||||||||||
Component: | HTML Editing | Assignee: | Wenson Hsieh <wenson_hsieh> | ||||||||||||||||||||||||||||||
Status: | RESOLVED FIXED | ||||||||||||||||||||||||||||||||
Severity: | Normal | CC: | ap, bdakin, benjamin, cdumez, cmarcelo, esprehn+autocc, ews-watchlist, kangil.han, megan_gardner, thorton, webkit-bot-watchers-bugzilla, webkit-bug-importer, wenson_hsieh | ||||||||||||||||||||||||||||||
Priority: | P2 | Keywords: | InRadar | ||||||||||||||||||||||||||||||
Version: | WebKit Nightly Build | ||||||||||||||||||||||||||||||||
Hardware: | iPhone / iPad | ||||||||||||||||||||||||||||||||
OS: | iOS 13 | ||||||||||||||||||||||||||||||||
Attachments: |
|
Description
Jason Lawrence
2020-05-22 14:48:06 PDT
I have marked this test as flaky failing while this issue is investigated. https://trac.webkit.org/changeset/262078/webkit I am able to reproduce this issue on 261815 using the command below, but I cannot reproduce it on 261811. run-webkit-tests --ios-simulator --device-type iPhone SE --iterations 99 --exit-after-n-failures 3 --force editing/async-clipboard/clipboard-item-get-type-basic.html r261815: [27/99] editing/async-clipboard/clipboard-item-get-type-basic.html failed unexpectedly (text diff) [41/99] editing/async-clipboard/clipboard-item-get-type-basic.html failed unexpectedly (text diff) [47/99] editing/async-clipboard/clipboard-item-get-type-basic.html failed unexpectedly (text diff) Exiting early after 3 failures. 47 tests run. 44 tests ran as expected, 3 didn't (52 didn't run): r261811: All 99 tests ran as expected. r261812 is the only editing change in this range, and a very timing sensitive one. I’m unable to reproduce this locally. I ran for 600 iterations several times at full parallelization (10 test runners on my machine). Created attachment 400259 [details]
Repro attempt #1
Created attachment 400260 [details]
Repro attempt #2
Created attachment 400261 [details]
Repro attempt #3
Created attachment 400262 [details]
Repro attempt #4
Created attachment 400263 [details]
Repro attempt #5
Created attachment 400344 [details]
Repro attempt #6
Created attachment 400348 [details]
Repro attempt #7 (more logging)
Created attachment 400354 [details]
Repro attempt #8 (and force EWS to fail)
Created attachment 400385 [details]
Repro attempt #9
Created attachment 400486 [details]
Repro attempt #10
Created attachment 400497 [details]
Repro attempt #11
(In reply to Wenson Hsieh from comment #16) > Created attachment 400497 [details] > Repro attempt #11 I think I’ve finally found a smoking gun...! 13:46:36.213 17986 <WK>: Has active session? no 13:46:36.213 17986 <WK>: - changeCountAtStart 12 13:46:36.213 17986 <WK>: - m_activeSession->changeCount 0 13:46:36.213 17986 <WK>: void WebKit::WebPasteboardProxy::allPasteboardItemInfo(IPC::Connection &, const WTF::String &, int64_t, CompletionHandler<void (Optional<Vector<WebCore::PasteboardItemInfo> > &&)> &&) 13:46:36.213 17986 <WK>: BAILING BECAUSE CHANGE COUNTS DIFFER (12, 14) 13:46:36.213 17986 <WK>: Got pasteboard item info? no 13:46:36.213 17986 <WK>: Number of items: 0 13:46:36.271 17986 "ruby --version" took 0.06s 13:46:37.716 17986 "ruby -I /Volumes/Data/worker/iOS-13-Simulator-WK2-Tests-EWS/build/Websites/bugs.webkit.org/PrettyPatch /Volumes/Data/worker/iOS-13-Simulator-WK2-Tests-EWS/build/Websites/bugs.webkit.org/PrettyPatch/prettify.rb /Volumes/Data/worker/iOS-13-Simulator-WK2-Tests-EWS/build/layout-test-results/editing/async-clipboard/clipboard-item-get-type-basic-1-diff.txt" took 1.44s 13:46:37.722 16182 [4601/46006] editing/async-clipboard/clipboard-item-get-type-basic-1.html failed unexpectedly (text diff) We’re bailing in PlatformPasteboard::allPasteboardItemInfo because the change count has been bumped beneath us. Need to drill further to figure out what’s causing the change count to increment (twice, even!) Created attachment 400523 [details]
Repro attempt #12
(In reply to Wenson Hsieh from comment #18) > Created attachment 400523 [details] > Repro attempt #12 <WK>: Committed load: <blank> <WK>: Committed load: </Volumes/Data/worker/iOS-13-Simulator-WK2-Tests-EWS/build/LayoutTests/editing/async-clipboard/clipboard-item-get-type-basic-8.html> <WK>: Waiting for autocorrection context... <WK>: void WebKit::WebPasteboardProxy::getPasteboardChangeCount(const WTF::String &, CompletionHandler<void (int64_t)> &&) => 32 <WK>: Writing custom data. <WK>: void WebKit::WebPasteboardProxy::writeCustomData(IPC::Connection &, const Vector<WebCore::PasteboardCustomData> &, const WTF::String &, CompletionHandler<void (int64_t)> &&) <WK>: int64_t WebCore::PlatformPasteboard::write(const Vector<WebCore::PasteboardCustomData> &) <WK>: -[WKContentView(WKInteraction) _pasteboardChanged] <WK>: 0 WebKit 0x00000001078ec54a -[WKContentView(WKInteraction) _pasteboardChanged] + 104 <WK>: 1 CoreFoundation 0x000000010962ed0c __CFNOTIFICATIONCENTER_IS_CALLING_OUT_TO_AN_OBSERVER__ + 12 <WK>: 2 CoreFoundation 0x000000010962e185 _CFXRegistrationPost1 + 421 <WK>: 3 CoreFoundation 0x000000010962def1 ___CFXNotificationPost_block_invoke + 193 <WK>: 4 CoreFoundation 0x000000010972b2d3 -[_CFXNotificationRegistrar find:object:observer:enumerator:] + 1795 <WK>: 5 CoreFoundation 0x000000010962d846 _CFXNotificationPost + 950 <WK>: 6 Foundation 0x0000000108ce2e2b -[NSNotificationCenter postNotificationName:object:userInfo:] + 59 <WK>: 7 UIKitCore 0x000000011797a6ca _sendPasteboardChangedNotification + 90 <WK>: 8 UIKitCore 0x000000011797a553 -[_UIConcretePasteboard _saveItemCollection:] + 192 <WK>: 9 UIKitCore 0x0000000117981552 -[_UIConcretePasteboard _setItemsAndSave:options:coerceStringsToURLs:] + 1539 <WK>: 10 UIKitCore 0x000000011797cbf1 -[_UIConcretePasteboard setItemProviders:localOnly:expirationDate:] + 590 <WK>: 11 WebCore 0x000000010b67cda2 _ZN7WebCoreL25registerItemsToPasteboardEP7NSArrayIP35WebItemProviderRegistrationInfoListEPU29objcproto18AbstractPasteboard11objc_object + 402 … <WK>: <WK>: ...done waiting! <WK>: void WebKit::WebPasteboardProxy::getPasteboardChangeCount(const WTF::String &, CompletionHandler<void (int64_t)> &&) => 33 <WK>: -[WKContentView(WKInteraction) supportsImagePaste] => NO <WK>: 0 WebKit 0x00000001078ec6b0 -[WKContentView(WKInteraction) supportsImagePaste] + 148 <WK>: 1 UIKitCore 0x000000011786009e -[UIKeyboardImpl delegateSupportsImagePaste] + 444 <WK>: 2 UIKitCore 0x000000011785fe00 -[UIKeyboardImpl updateDelegatePasteSupport] + 274 <WK>: 3 UIKitCore 0x000000011785fbfc -[UIKeyboardImpl didSetDelegate] + 222 … <WK>: <WK>: void WebKit::WebPasteboardProxy::getPasteboardChangeCount(const WTF::String &, CompletionHandler<void (int64_t)> &&) => 35 <WK>: Requesting DOM paste access... <WK>: ...passed. <WK>: <WK>: Has active session? no <WK>: - changeCountAtStart 35 <WK>: - m_activeSession->changeCount 0 <WK>: void WebKit::WebPasteboardProxy::allPasteboardItemInfo(IPC::Connection &, const WTF::String &, int64_t, CompletionHandler<void (Optional<Vector<WebCore::PasteboardItemInfo> > &&)> &&) <WK>: BAILING BECAUSE CHANGE COUNTS DIFFER (33, 35) <WK>: Got pasteboard item info? no <WK>: Number of items: 0 It seems like what’s happening is that code in UIKit (-[UIKeyboardImpl delegateSupportsImagePaste]) that was added in support of Memojis in the software keyboard kicks in after we focus an element, pins a temporary PNG image to the pasteboard, clears the pinned PNG image, and finally restores the contents of the pasteboard to what it was before pinning. This causes the changeCount of the pasteboard to be incremented twice, which interferes with WebKit’s logic (in both the web and UI processes) that prevents the page from accessing the clipboard if the changeCount has changed underneath us. Coincidentally, this seems to have been fixed after a recent UIKit change, <rdar://problem/60891825>. That explains why iOS bots running shipping software are hitting this... Created attachment 400548 [details]
Patch
Created attachment 400551 [details]
Patch for EWS
Committed r262283: <https://trac.webkit.org/changeset/262283> All reviewed patches have been landed. Closing bug and clearing flags on attachment 400551 [details]. |