Some Eclipse Foundation services are deprecated, or will be soon. Please ensure you've read this important communication.

Bug 361444

Summary: Long refresh times on file/folder creation
Product: [ECD] Orion Reporter: John Arthorne <john.arthorne>
Component: ClientAssignee: Project Inbox <orion.client-inbox>
Status: RESOLVED WORKSFORME QA Contact:
Severity: normal    
Priority: P3 CC: simon_kaegi
Version: 0.3   
Target Milestone: ---   
Hardware: PC   
OS: Windows 7   
Whiteboard:
Bug Depends on: 362241    
Bug Blocks:    
Attachments:
Description Flags
Profile trace none

Description John Arthorne CLA 2011-10-19 13:53:46 EDT
0.3 RC2 running on orion.eclipse.org

I frequently see up to 5 seconds delay after clicking Ok in file/folder creation dialog before the new file appears in the navigator. I just did a quick stopwatch test and found it took: 5.8s, 3.8s, 4.5s, 7.7s. 

The actual network activity only seems to be 100-300ms in total (one POST followed by one GET). It's not clear where the rest of the time is going here. Just clicking around in the Navigator also does a GET and has much faster response time.
Comment 1 Susan McCourt CLA 2011-10-19 14:32:00 EDT
this was the impetus for bug 361006.
delete has a similar problem.
I bet our refresh code is doing something stupid.  (In the delete case, I know we refresh for every deleted item)...
Comment 2 Susan McCourt CLA 2011-10-27 16:39:32 EDT
(In reply to comment #0)
> 0.3 RC2 running on orion.eclipse.org
> 
> I frequently see up to 5 seconds delay after clicking Ok in file/folder
> creation dialog before the new file appears in the navigator. I just did a
> quick stopwatch test and found it took: 5.8s, 3.8s, 4.5s, 7.7s. 

I've seen this as well.  

> 
> The actual network activity only seems to be 100-300ms in total (one POST
> followed by one GET). It's not clear where the rest of the time is going here.
> Just clicking around in the Navigator also does a GET and has much faster
> response time.

Looking at the code...we do three things:
1) post to create
2) get to get the new list of children
3) rebuild the tree DOM

I started playing with eliminating step (2) because in theory we should be able to avoid the extra round trip on the get, by inserting the newly created item into our tree model.  However I got blocked by bug 362241 while experimenting with this.

It could be that step 3 is really the costly part, though, but I would expect then for all clicking in the navigator to be costly.
Comment 3 Susan McCourt CLA 2011-10-27 16:53:09 EDT
(In reply to comment #2)

> It could be that step 3 is really the costly part, though, but I would expect
> then for all clicking in the navigator to be costly.

Just had another thought.  Both John and I have observed that you can drill into the nav and it's pretty snappy, while creating something new is slow.

One difference is that drilling into the nav will do a get and then build the treetable from scratch.  This sounds like it would be more expensive, but in practice this means that the table builds all the rows and inserts them into the table, and THEN inserts the table into the DOM.  So there's no refreshing of the rendering until we're done.

When you add an item to the table, we fetch the children and then update the table by removing the dom nodes for the old child rows and then add rows based on the new children list.  In theory this sounds smarter/faster (just refresh the parts that need it) but at this point the table is in the DOM, so there could be more work being done by the browser.  

So...NOT optimizing the add, and instead saying "just rebuild the entire tree" might be faster!  Or at least, we could hide the table while rebuilding the rows and then show it again. 

To pursue these theories we need to get in a state where we see this happening.  If it is indeed a DOM updating problem, then we could expect to see different behavior in different browsers.

John, I recall seeing this in Chrome, not sure I've seen in FF.  Do you recall when/where you saw it?
Comment 4 John Arthorne CLA 2011-10-28 09:21:30 EDT
Strangely I can't repreduce this today running the latest on orion.eclipse.org. I don't know if something has changed but I'm seeing near instantaneous creation updates.

When I did see this, I spent a bit of time in the Chrome profiler looking at it. The initial POST and GET happened very quickly, but then there was a long period afterwards where it was busy doing *something* on the client side. I couldn't make much sense of it because it was a large mass of little parse blocks. I can still see this today but overall it is much quicker. I also upgraded to Chrome 15 this week so I guess they might have optimized something there.
Comment 5 John Arthorne CLA 2011-10-28 09:22:57 EDT
Created attachment 206129 [details]
Profile trace

Although the overall time is fast in this case, you can see where the time is going. The POST and GET to server are in blue and only take a small amount of the total time. Then there is a large block of time in navigate/built-table.js that is just full of "parse" events.
Comment 6 Susan McCourt CLA 2011-10-28 13:39:54 EDT
If you notice the slowdown in the future, can you do the following:
- grab a profile trace
- try it on a self hosting workspace and if the problem shows there, grab a profile trace (more readable results in a non-built orion)
Comment 7 Simon Kaegi CLA 2012-06-08 16:02:19 EDT
I haven't see this in some time and now if there are delays they are genuine network slowdowns.