Window is never opened

[route]

I'm seeing intermittent bug with Page.windowOpen event. If window is opened and closed and then the same window is opened again sometimes target is never created:

>>> {"method":"Target.getTargets","params":{},"id":1}
    <<< {"id":1,"result":{"targetInfos":[{"targetId":"90BB0C73814BE736A40D261B380563CC","type":"page","title":"about:blank","url":"about:blank","attached":false,"browserContextId":"1E00F0958941B7AAD647A7028B4D0636"}]}}

>>> {"method":"Target.createBrowserContext","params":{},"id":2}
    <<< {"id":2,"result":{"browserContextId":"22F803B05CB3A6C20B0DDE1506E87016"}}

>>> {"method":"Target.createTarget","params":{"url":"about:blank","browserContextId":"22F803B05CB3A6C20B0DDE1506E87016"},"id":3}
    <<< {"id":3,"result":{"targetId":"16AF8DDE988E5B84C57653C6754E9753"}}

>>> {"method":"Target.attachToTarget","params":{"targetId":"16AF8DDE988E5B84C57653C6754E9753"},"id":4}
    <<< {"method":"Target.attachedToTarget","params":{"sessionId":"10B97AF9C5A1277AA5849D70C2FDACAE","targetInfo":{"targetId":"16AF8DDE988E5B84C57653C6754E9753","type":"page","title":"","url":"about:blank","attached":true,"browserContextId":"22F803B05CB3A6C20B0DDE1506E87016"},"waitingForDebugger":false}}
    <<< {"id":4,"result":{"sessionId":"10B97AF9C5A1277AA5849D70C2FDACAE"}}

>>> {"method":"Page.enable","params":{},"id":1}
    <<< {"id":1,"result":{}}

>>> {"method":"DOM.enable","params":{},"id":2}
    <<< {"id":2,"result":{}}

>>> {"method":"CSS.enable","params":{},"id":3}
    <<< {"id":3,"result":{}}

>>> {"method":"Runtime.enable","params":{},"id":4}
    <<< {"method":"Runtime.executionContextCreated","params":{"context":{"id":1,"origin":"://","name":"","auxData":{"isDefault":true,"type":"default","frameId":"16AF8DDE988E5B84C57653C6754E9753"}}}}
    <<< {"id":4,"result":{}}

>>> {"method":"Log.enable","params":{},"id":5}
    <<< {"id":5,"result":{}}

>>> {"method":"Network.enable","params":{},"id":6}
    <<< {"id":6,"result":{}}

>>> {"method":"Network.setCacheDisabled","params":{"cacheDisabled":true},"id":7}
    <<< {"id":7,"result":{}}

...

>>> {"method":"Page.navigate","params":{"url":"http://127.0.0.1:43421/"},"id":11}
    <<< {"method":"Network.requestWillBeSent","params":{"requestId":"296E6964502622885C7BB4BEFDB8B7E7","loaderId":"296E6964502622885C7BB4BEFDB8B7E7","documentURL":"http://127.0.0.1:43421/","request":{"url":"http://127.0.0.1:43421/","method":"GET","headers":{"Upgrade-Insecure-Requests":"1","User-Agent":"Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) HeadlessChrome/71.0.3578.98 Safari/537.36"},"mixedContentType":"none","initialPriority":"VeryHigh","referrerPolicy":"no-referrer-when-downgrade"},"timestamp":140477.12295,"wallTime":1548748108.851862,"initiator":{"type":"other"},"type":"Document","frameId":"16AF8DDE988E5B84C57653C6754E9753","hasUserGesture":false}}
    <<< {"method":"Network.responseReceived","params":{"requestId":"296E6964502622885C7BB4BEFDB8B7E7","loaderId":"296E6964502622885C7BB4BEFDB8B7E7","timestamp":140477.130297,"type":"Document","response":{"url":"http://127.0.0.1:43421/","status":200,"statusText":"OK","headers":{"Content-Type":"text/html;charset=utf-8","Set-Cookie":"capybara=root+cookie; domain=127.0.0.1; path=/","X-XSS-Protection":"1; mode=block","X-Content-Type-Options":"nosniff","Content-Length":"45"},"headersText":"HTTP/1.1 200 OK\r\nContent-Type: text/html;charset=utf-8\r\nSet-Cookie: capybara=root+cookie; domain=127.0.0.1; path=/\r\nX-XSS-Protection: 1; mode=block\r\nX-Content-Type-Options: nosniff\r\nContent-Length: 45\r\n\r\n","mimeType":"text/html","requestHeaders":{"Host":"127.0.0.1:43421","Connection":"keep-alive","Pragma":"no-cache","Cache-Control":"no-cache","Upgrade-Insecure-Requests":"1","User-Agent":"Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) HeadlessChrome/71.0.3578.98 Safari/537.36","Accept":"text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8","Accept-Encoding":"gzip, deflate, br"},"requestHeadersText":"GET / HTTP/1.1\r\nHost: 127.0.0.1:43421\r\nConnection: keep-alive\r\nPragma: no-cache\r\nCache-Control: no-cache\r\nUpgrade-Insecure-Requests: 1\r\nUser-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) HeadlessChrome/71.0.3578.98 Safari/537.36\r\nAccept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8\r\nAccept-Encoding: gzip, deflate, br\r\n","connectionReused":false,"connectionId":13,"remoteIPAddress":"127.0.0.1","remotePort":43421,"fromDiskCache":false,"fromServiceWorker":false,"encodedDataLength":204,"timing":{"requestTime":140477.123057,"proxyStart":-1,"proxyEnd":-1,"dnsStart":0.146,"dnsEnd":0.16,"connectStart":0.16,"connectEnd":0.248,"sslStart":-1,"sslEnd":-1,"workerStart":-1,"workerReady":-1,"sendStart":0.284,"sendEnd":0.299,"pushStart":0,"pushEnd":0,"receiveHeadersEnd":7.083},"protocol":"http/1.1","securityState":"neutral"},"frameId":"16AF8DDE988E5B84C57653C6754E9753"}}
    <<< {"id":11,"result":{"frameId":"16AF8DDE988E5B84C57653C6754E9753","loaderId":"296E6964502622885C7BB4BEFDB8B7E7"}}
    <<< {"method":"Page.frameStartedLoading","params":{"frameId":"16AF8DDE988E5B84C57653C6754E9753"}}
    <<< {"method":"Network.dataReceived","params":{"requestId":"296E6964502622885C7BB4BEFDB8B7E7","timestamp":140477.131159,"dataLength":45,"encodedDataLength":45}}
    <<< {"method":"Runtime.executionContextDestroyed","params":{"executionContextId":1}}
    <<< {"method":"Runtime.executionContextsCleared","params":{}}
    <<< {"method":"Page.frameNavigated","params":{"frame":{"id":"16AF8DDE988E5B84C57653C6754E9753","loaderId":"296E6964502622885C7BB4BEFDB8B7E7","url":"http://127.0.0.1:43421/","securityOrigin":"http://127.0.0.1:43421","mimeType":"text/html"}}}
    <<< {"method":"Runtime.executionContextCreated","params":{"context":{"id":2,"origin":"http://127.0.0.1:43421","name":"","auxData":{"isDefault":true,"type":"default","frameId":"16AF8DDE988E5B84C57653C6754E9753"}}}}
    <<< {"method":"DOM.documentUpdated","params":{}}
    <<< {"method":"Network.loadingFinished","params":{"requestId":"296E6964502622885C7BB4BEFDB8B7E7","timestamp":140477.1306,"encodedDataLength":249,"shouldReportCorbBlocking":false}}
    <<< {"method":"Page.loadEventFired","params":{"timestamp":140477.133037}}
    <<< {"method":"Page.frameStoppedLoading","params":{"frameId":"16AF8DDE988E5B84C57653C6754E9753"}}
    <<< {"method":"DOM.documentUpdated","params":{}}
    <<< {"method":"Page.domContentEventFired","params":{"timestamp":140477.134574}}

>>> {"method":"DOM.getDocument","params":{"depth":0},"id":12}
    <<< {"id":12,"result":{"root":{"nodeId":1,"backendNodeId":3,"nodeType":9,"nodeName":"#document","localName":"","nodeValue":"","childNodeCount":1,"documentURL":"http://127.0.0.1:43421/","baseURL":"http://127.0.0.1:43421/","xmlVersion":""}}}

>>> {"method":"Runtime.callFunctionOn","params":{"functionDeclaration":"function() {             window.open(\"/cuprite/simple\", \"popup\")\n }","returnByValue":true,"arguments":[],"executionContextId":2},"id":13}
    <<< {"method":"Page.windowOpen","params":{"url":"http://127.0.0.1:43421/cuprite/simple","windowName":"popup","windowFeatures":["menubar","toolbar","status","scrollbars","resizable"],"userGesture":false}}
    <<< {"id":13,"result":{"result":{"type":"undefined"}}}

>>> {"method":"Target.getTargets","params":{},"id":5}
    <<< {"id":5,"result":{"targetInfos":[{"targetId":"712883E25D7105B6A3C10D20C6834052","type":"page","title":"","url":"http://127.0.0.1:43421/cuprite/simple","attached":false,"openerId":"16AF8DDE988E5B84C57653C6754E9753","browserContextId":"22F803B05CB3A6C20B0DDE1506E87016"},{"targetId":"16AF8DDE988E5B84C57653C6754E9753","type":"page","title":"127.0.0.1:43421","url":"http://127.0.0.1:43421/","attached":true,"browserContextId":"22F803B05CB3A6C20B0DDE1506E87016"},{"targetId":"90BB0C73814BE736A40D261B380563CC","type":"page","title":"about:blank","url":"about:blank","attached":false,"browserContextId":"1E00F0958941B7AAD647A7028B4D0636"}]}}

>>> {"method":"Target.attachToTarget","params":{"targetId":"712883E25D7105B6A3C10D20C6834052"},"id":6}
    <<< {"method":"Target.attachedToTarget","params":{"sessionId":"340E9F5CFA6D97F3CCA47DBA8DAFCE56","targetInfo":{"targetId":"712883E25D7105B6A3C10D20C6834052","type":"page","title":"Test","url":"http://127.0.0.1:43421/cuprite/simple","attached":true,"openerId":"16AF8DDE988E5B84C57653C6754E9753","browserContextId":"22F803B05CB3A6C20B0DDE1506E87016"},"waitingForDebugger":false}}
    <<< {"id":6,"result":{"sessionId":"340E9F5CFA6D97F3CCA47DBA8DAFCE56"}}

...

>>> {"method":"Target.detachFromTarget","params":{"sessionId":"340E9F5CFA6D97F3CCA47DBA8DAFCE56"},"id":7}
    <<< {"method":"Target.detachedFromTarget","params":{"sessionId":"340E9F5CFA6D97F3CCA47DBA8DAFCE56","targetId":"712883E25D7105B6A3C10D20C6834052"}}
    <<< {"id":7,"result":{}}
    <<< {"method":"CSS.mediaQueryResultChanged","params":{}}

>>> {"method":"Target.closeTarget","params":{"targetId":"712883E25D7105B6A3C10D20C6834052"},"id":8}
    <<< { "method": "Inspector.detached", "params": { "reason": "target_closed"} }
    <<< {"id":8,"result":{"success":true}}

>>> {"method":"Runtime.callFunctionOn","params":{"functionDeclaration":"function() {             window.open(\"/cuprite/simple\", \"popup\")\n }","returnByValue":true,"arguments":[],"executionContextId":2},"id":14}
    <<< {"method":"Page.windowOpen","params":{"url":"http://127.0.0.1:43421/cuprite/simple","windowName":"popup","windowFeatures":["menubar","toolbar","status","scrollbars","resizable"],"userGesture":false}}
    <<< {"id":14,"result":{"result":{"type":"undefined"}}}

>>> {"method":"Target.getTargets","params":{},"id":9}
    <<< {"id":9,"result":{"targetInfos":[{"targetId":"16AF8DDE988E5B84C57653C6754E9753","type":"page","title":"127.0.0.1:43421","url":"http://127.0.0.1:43421/","attached":true,"browserContextId":"22F803B05CB3A6C20B0DDE1506E87016"},{"targetId":"90BB0C73814BE736A40D261B380563CC","type":"page","title":"about:blank","url":"about:blank","attached":false,"browserContextId":"1E00F0958941B7AAD647A7028B4D0636"}]}}

As you can see Page.windowOpen event happened but target is never created no matter how long you wait for it.

[JoelEinbinder]

Does the pop up window actually open? Maybe some pop up blocking logic is being invoked?

[route]

@JoelEinbinder I cannot find target to attach to to check, there are only 2 targets main page and default context target. Feels like Page.windowOpen event happens and target is never created tried on many Chrome and Chromium versions. Though on my local machine it happens like 1 out 50 attempts but on CI I see 1 out of 6 and build is always failing https://travis-ci.org/machinio/cuprite/jobs/485380005 No no alerts or confirm dialogs involved, only plain windows.

[route]

I think the reason is that in the test I'm trying to open the same window twice (url is eventually the same) and it happens very fast so that this bug shows up. Looking at events you see that previous window is successfully closed and target is detached, though new window isn't opened.

[JoelEinbinder]

Hm. Maybe Target.closeTarget is not waiting for the target to be destroyed. In that case you would have a race between the next window.open call and the target actually closing. If you called window.open before TargetDestroyed, it would focus the old window instead of opening a new one. Try awaiting targetDestroyed on the first window before opening the second, see if that fixes it

[route]

>>> {"method":"Target.closeTarget","params":{"targetId":"712883E25D7105B6A3C10D20C6834052"},"id":8}
    <<< { "method": "Inspector.detached", "params": { "reason": "target_closed"} }
    <<< {"id":8,"result":{"success":true}}

It returns success and there's no such target anymore if I try to call Target.getTargets. Yes feels like race condition but seems it's not in my lib, I was also thinking that maybe caching is involved but turning it off didn't improve it.

[JoelEinbinder]

I don’t disagree that it’s probably not in your lib. It would just help me track down the bug faster when I go to fix it tomorrow.

[route]

@JoelEinbinder I'm open-minded, I just tried debugging it for a day or so and didn't find anything in my code haha :) Adding sleep between next attempt to open window helps and build is green now https://travis-ci.org/machinio/cuprite/builds/485782599

[route]

@JoelEinbinder btw if you could point me to the code related to the devtools protocol it would help me a lot to understand everything, I would spend some time playing around

[TimvdLippe]

This repository is related to Chrome DevTools Protocol, but does not track issues regarding its definition or implementation. If you want to file an issue for the Chrome DevTools Protocol, please open an issue on https://crbug.com under component: Platform>DevTools>Platform. Thanks in advance!