Bug 36217

Summary: Web Inspector: Inspector tests sometimes fail due to full paths being printed instead of relative paths
Product: WebKit Reporter: Pavel Feldman <pfeldman>
Component: Web Inspector (Deprecated)Assignee: Pavel Feldman <pfeldman>
Status: RESOLVED FIXED    
Severity: Normal CC: aroben, commit-queue, dglazkov, eric, loislo, pfeldman, timothy, webkit.review.bot, yurys
Priority: P2 Keywords: InRadar, LayoutTestFailure, PlatformOnly
Version: 528+ (Nightly build)   
Hardware: All   
OS: All   
Bug Depends on:    
Bug Blocks: 33305    
Attachments:
Description Flags
[patch] Just first version of patch to check it on the try bots.
none
[patch] second iteration.
pfeldman: review-
[patch] next iteration
pfeldman: review-
[patch] just fix. none

Description Pavel Feldman 2010-03-17 06:52:52 PDT
inspector ...
inspector/console-dirxml.html -> failed
....
inspector/console-tests.html -> failed
.......
inspector/elements-panel-xhtml-structure.xhtml -> failed
.................

For some reason inspector is not being enabled now.
Comment 1 Adam Roben (:aroben) 2010-03-17 06:54:15 PDT
(In reply to comment #0)
> inspector ...
> inspector/console-dirxml.html -> failed
> ....
> inspector/console-tests.html -> failed
> .......
> inspector/elements-panel-xhtml-structure.xhtml -> failed
> .................
> 
> For some reason inspector is not being enabled now.

It doesn't seem that it isn't enabled. It seems that it's not stripping the URLs correctly.
Comment 2 Adam Roben (:aroben) 2010-03-17 06:55:46 PDT
I think r56095 is a red herring. Before that revision, so many tests were failing that the Windows bots were aborting the tests early. I think it's far more likely that these tests were failing before r56095, but they just weren't being run.
Comment 3 Pavel Feldman 2010-03-17 07:00:48 PDT
Clarification: the reason console messages have short urls is that there is a
resource entry with matching url. We trim long ones and use friendly shortcuts
in case there is matching resource entry. In this case, corresponding resource
entry is likely to be missing. Either resource tracking is disabled or resource
is not being reported as processed to the loader clients.
Comment 4 Adam Roben (:aroben) 2010-03-17 07:03:03 PDT
(In reply to comment #3)
> Clarification: the reason console messages have short urls is that there is a
> resource entry with matching url. We trim long ones and use friendly shortcuts
> in case there is matching resource entry. In this case, corresponding resource
> entry is likely to be missing. Either resource tracking is disabled or resource
> is not being reported as processed to the loader clients.

Another possibility is that the URLs of the messages and the URLs of the resources differ in some way. E.g., maybe one is canonicalized and the other isn't.
Comment 5 Adam Roben (:aroben) 2010-03-17 07:06:43 PDT
(In reply to comment #4)
> Another possibility is that the URLs of the messages and the URLs of the
> resources differ in some way. E.g., maybe one is canonicalized and the other
> isn't.

A little debugging shows that this doesn't seem to be the issue. I see the console-dirxml.html resource being added, and the console messages seem to have the same URL that the resource had.
Comment 6 Adam Roben (:aroben) 2010-04-05 08:54:31 PDT
<rdar://problem/7827667>
Comment 7 Adam Roben (:aroben) 2010-04-06 10:41:25 PDT
Ilya is looking into this. Our current theory is that, in Release builds, developer extras aren't getting enabled until after the main resource has already loaded, meaning that the main resources isn't in the Inspector's resource map.
Comment 8 Ilya Tikhonovsky 2010-04-08 08:07:00 PDT
I've made additional round of investigation:
Usually inspector tests are failing under stress conditions generated by CPU and Disk I/O intensive tasks.

In normal situation the sequence of test events is pretty clear.
1) WebInspector: loaded
2) new resource: file:///E:/chromium/src/third_party/WebKit/LayoutTests/inspector/console-dirxml.html
3) Request for display name of url: file:///E:/chromium/src/third_party/WebKit/LayoutTests/inspector/console-dirxml.html

When some test is failed then typical sequence looks like the next one:
1) WebInspector: loaded
2) new resource: file:///E:/chromium/src/third_party/WebKit/LayoutTests/inspector/console-dirxml.html
3) new resource: file:///E:/chromium/src/third_party/WebKit/LayoutTests/inspector/console-format-collections.html
4) WebInspector: reset 
5) new resource: undefined 
6) Request for url: file:///E:/chromium/src/third_party/WebKit/LayoutTests/inspector/console-format-collections.html

WebInspector is closing asynchronously and that is the reason. 
Under stress conditions the next can accidentally use WebInspector of previous test.
I'll try to fix that today/tomorrow.
Comment 9 Adam Roben (:aroben) 2010-04-08 09:23:26 PDT
Thanks for the analysis, Ilya!
Comment 10 Ilya Tikhonovsky 2010-04-10 05:25:28 PDT
Created attachment 53039 [details]
[patch] Just first version of patch to check it on the try bots.
Comment 11 Pavel Feldman 2010-04-10 07:51:28 PDT
Comment on attachment 53039 [details]
[patch] Just first version of patch to check it on the try bots.

> -void InspectorController::disconnectFrontend()
> +void InspectorController::disconnectFrontend(InspectorFrontend* frontend)
>  {
> -    if (!m_frontend)
> +    if (m_frontend != frontend)
>          return;

I think we should cut this control flow earlier. I.e. when connection is terminated upon backend request, there should be no further disconnect calls re-entering backend from within front-end. I think we've discussed it. Leaving it your way would make design less clean and make socket implementation tough.
Comment 12 WebKit Review Bot 2010-04-10 11:59:03 PDT
Attachment 53039 [details] did not build on chromium:
Build output: http://webkit-commit-queue.appspot.com/results/1590418
Comment 13 Ilya Tikhonovsky 2010-04-11 02:50:23 PDT
pfeldman: we have four different ways to close inspector.
1) by LayoutTestController;
2) by navigation to other domain;
3) by close button of inspector when it is in attached state;
4) by native window button when it is in detached state;

We have problem with async close only in the first case.
and we should be able to do that when disconnect is initiated by inspector itself.
Comment 14 Ilya Tikhonovsky 2010-04-11 02:54:51 PDT
Created attachment 53083 [details]
[patch] second iteration.
Comment 15 Pavel Feldman 2010-04-12 06:59:31 PDT
(In reply to comment #13)
> pfeldman: we have four different ways to close inspector.
> 1) by LayoutTestController;
> 2) by navigation to other domain;
> 3) by close button of inspector when it is in attached state;
> 4) by native window button when it is in detached state;
> 
> We have problem with async close only in the first case.
> and we should be able to do that when disconnect is initiated by inspector
> itself.

I'd like to see more clarity in the code still. We have two parties (inspector on one side and front-end on another side) with serialized asynchronous connection in between. We need to have a proper connection handshake / termination routines. This connection can be terminated by either of the parties. I'd like to see clear methods for closing the connection initiated by inspector and the front-end. And once connection has been terminated, I don't expect echo methods to be called upon closed connection. In you code I see:

Inspector initiates disconnect -> sends message to frontend and cuts the pipe -> front-end initiates disconnect. And the reason you don't re-enter code on front-end is that the pipe is already cut. This sounds confusing. Front-end should only initiate disconnect when its host or close button or whatever on its side initiates disconnect.
Comment 16 Pavel Feldman 2010-04-12 07:00:24 PDT
Comment on attachment 53083 [details]
[patch] second iteration.

(I don't see how my comments are addressed in this patch).
Comment 17 Yury Semikhatsky 2010-04-12 07:29:01 PDT
(In reply to comment #15)
> Front-end
> should only initiate disconnect when its host or close button or whatever on
> its side initiates disconnect.
If WebInspector.close is asynchronous, there is another possible scenario:
1. The IC->FE pointer is cleared
2. WebInspector.close is called 
3. FE window close is handled and IC->disconnectFE is called.
At the third step it's possible that IC has already open another FE. This means that every FE client should track whether it was closed from the IC or not.
Comment 18 Pavel Feldman 2010-04-12 07:32:57 PDT
(In reply to comment #17)
> (In reply to comment #15)
> > Front-end
> > should only initiate disconnect when its host or close button or whatever on
> > its side initiates disconnect.
> If WebInspector.close is asynchronous, there is another possible scenario:
> 1. The IC->FE pointer is cleared

At this point we should also clear the pointer from the transport implementation to inspector controller on the inspector page side, so that no more incoming messages are coming down this pipe.

> 2. WebInspector.close is called 
> 3. FE window close is handled and IC->disconnectFE is called.
> At the third step it's possible that IC has already open another FE. This means
> that every FE client should track whether it was closed from the IC or not.
Comment 19 Yury Semikhatsky 2010-04-12 07:37:39 PDT
(In reply to comment #18)
> (In reply to comment #17)
> > (In reply to comment #15)
> > > Front-end
> > > should only initiate disconnect when its host or close button or whatever on
> > > its side initiates disconnect.
> > If WebInspector.close is asynchronous, there is another possible scenario:
> > 1. The IC->FE pointer is cleared
> 
> At this point we should also clear the pointer from the transport
> implementation to inspector controller on the inspector page side, so that no
> more incoming messages are coming down this pipe.
> 
We can easily do this with remote frontend but in case of in-process FE we need FE client to handle this.
Comment 20 Ilya Tikhonovsky 2010-04-14 12:34:49 PDT
Created attachment 53352 [details]
[patch] next iteration

WebInspector.updateResource wants to have url in the each update payload because that property will be used if resource map has no such request.
Comment 21 Pavel Feldman 2010-04-14 12:42:58 PDT
Comment on attachment 53352 [details]
[patch] next iteration

Hm. How do we end up in a state where we have resource with given id in the front-end, but it has lost its url? This should not be possible.
Comment 22 Ilya Tikhonovsky 2010-04-14 14:13:58 PDT
Created attachment 53367 [details]
[patch] just fix.
Comment 23 Ilya Tikhonovsky 2010-04-16 09:21:29 PDT
User scenario

0) run release webkit on windows
1) open inspector
2) enable resource tracking
3) close inspector
4) print yahoo.com into address bar
5) press enter and then immediately open inspector by Ctrl-Shift-I

Expected: resource pane should have a list of loaded resources with their names etc.
Actual: the first resource has no name, content and other attributes.
Comment 24 Adam Roben (:aroben) 2010-04-21 06:38:02 PDT
*** Bug 36946 has been marked as a duplicate of this bug. ***
Comment 25 Adam Roben (:aroben) 2010-04-21 06:38:36 PDT
Dupe bug 36946 says that this affects Tiger as well.
Comment 26 Eric Seidel (no email) 2010-04-22 04:19:11 PDT
This is one of the more common failures these days.  Hit it again just now:
http://build.webkit.org/results/Tiger%20Intel%20Release/r58084%20(11119)/inspector/console-log-before-inspector-open-pretty-diff.html

Glad to see we have a fix posted.  Any chance of review?
Comment 27 Eric Seidel (no email) 2010-04-22 04:19:42 PDT
I know next-to-nothing about the inspector or I would be happy to review it myself.
Comment 28 Adam Roben (:aroben) 2010-04-22 08:36:50 PDT
(In reply to comment #26)
> This is one of the more common failures these days.  Hit it again just now:
> http://build.webkit.org/results/Tiger%20Intel%20Release/r58084%20(11119)/inspector/console-log-before-inspector-open-pretty-diff.html
> 
> Glad to see we have a fix posted.  Any chance of review?

Last I heard, Pavel doesn't think this fix will work. I'm not sure why he hasn't r-ed it yet.
Comment 29 WebKit Commit Bot 2010-04-23 02:51:42 PDT
Comment on attachment 53367 [details]
[patch] just fix.

Clearing flags on attachment: 53367

Committed r58162: <http://trac.webkit.org/changeset/58162>
Comment 30 WebKit Commit Bot 2010-04-23 02:51:49 PDT
All reviewed patches have been landed.  Closing bug.
Comment 31 Adam Roben (:aroben) 2010-04-23 05:16:22 PDT
Pavel, can you comment on whether you think attachment 53367 [details] (landed in r58162) was the right fix for this issue? Last I heard, you had issues with it.
Comment 32 Adam Roben (:aroben) 2010-04-23 09:18:56 PDT
(In reply to comment #31)
> Pavel, can you comment on whether you think attachment 53367 [details] (landed in r58162)
> was the right fix for this issue? Last I heard, you had issues with it.

Pavel said on IRC:

"I was wrong about the patch. loislo did the right fix. I was too sure async close was to blame. We should still fix it, bug it gets lower priority."