Bug 157098 - [hotbug_deferred] Repetitive file I/O by TLDCMDocumentManager$IncludeHelper.getContents() , caching solution provided, JSP validator slow due to repetitive parsing of fragments
Summary: [hotbug_deferred] Repetitive file I/O by TLDCMDocumentManager$IncludeHelper....
Status: RESOLVED FIXED
Alias: None
Product: WTP Source Editing
Classification: WebTools
Component: jst.jsp (show other bugs)
Version: 1.5   Edit
Hardware: PC Windows XP
: P2 major (vote)
Target Milestone: 3.0   Edit
Assignee: Nitin Dahyabhai CLA
QA Contact: David Williams CLA
URL:
Whiteboard:
Keywords: performance
Depends on:
Blocks:
 
Reported: 2006-09-12 15:39 EDT by Raj Mandayam CLA
Modified: 2008-04-28 16:00 EDT (History)
7 users (show)

See Also:


Attachments
patch with shared cache for included files (5.78 KB, patch)
2006-09-12 15:41 EDT, Raj Mandayam CLA
no flags Details | Diff
patch with shared cache for included files (6.10 KB, patch)
2006-09-20 10:29 EDT, Raj Mandayam CLA
no flags Details | Diff
modified patch (8.42 KB, patch)
2006-09-20 14:06 EDT, Nitin Dahyabhai CLA
no flags Details | Diff
proposed alternative patch (11.98 KB, patch)
2006-09-20 18:38 EDT, Raj Mandayam CLA
no flags Details | Diff
cleaned-up proposed patch (33.64 KB, patch)
2006-10-12 03:05 EDT, Nitin Dahyabhai CLA
no flags Details | Diff
updated patch based on review by Amy Wu (34.69 KB, patch)
2006-10-12 16:49 EDT, Nitin Dahyabhai CLA
no flags Details | Diff
updated patch to fix a bug in the original (34.84 KB, patch)
2006-10-12 17:19 EDT, Nitin Dahyabhai CLA
no flags Details | Diff
fixes a looping problem found by our JUnits (which was not present originally) (34.87 KB, patch)
2006-10-12 17:50 EDT, Nitin Dahyabhai CLA
no flags Details | Diff
incorporates some of David's feedback (33.01 KB, patch)
2006-10-15 00:26 EDT, Nitin Dahyabhai CLA
no flags Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Raj Mandayam CLA 2006-09-12 15:39:09 EDT
Hi Nitin,

   Chris Laffra and I noticed that in WTP 0831, if you build a web project with a lot of jsp's and a lot of the jsp's have @include stmts to fragment jspf's. These fragments were getting parsed a lot of times by TLDCMDocumentManager$IncludeHelper.getContents() when you build the project or run validation on them.

see example below

java.io.FileInputStream.<init>(FileInputStream.java:148)
org.eclipse.core.internal.filesystem.local.LocalFile.openInputStream(LocalFile.java:318)
org.eclipse.core.internal.localstore.FileSystemResourceManager.read(FileSystemResourceManager.java:609)
org.eclipse.core.internal.resources.File.getContents(File.java:334)
org.eclipse.core.internal.resources.File.getContents(File.java:323)
org.eclipse.jst.jsp.core.internal.contentmodel.tld.TLDCMDocumentManager$IncludeHelper.getContents(TLDCMDocumentManager.java:572)
org.eclipse.jst.jsp.core.internal.contentmodel.tld.TLDCMDocumentManager$IncludeHelper.parse(TLDCMDocumentManager.java:676)
org.eclipse.jst.jsp.core.internal.contentmodel.tld.TLDCMDocumentManager$DirectiveStructuredDocumentRegionHandler.processInclude(TLDCMDocumentManager.java:289)
org.eclipse.jst.jsp.core.internal.contentmodel.tld.TLDCMDocumentManager$DirectiveStructuredDocumentRegionHandler.processInclude(TLDCMDocumentManager.java:217)
org.eclipse.jst.jsp.core.internal.contentmodel.tld.TLDCMDocumentManager$DirectiveStructuredDocumentRegionHandler.nodeParsed(TLDCMDocumentManager.java:196)
org.eclipse.wst.xml.core.internal.parser.XMLSourceParser.fireNodeParsed(XMLSourceParser.java:125)
org.eclipse.jst.jsp.core.internal.parser.JSPSourceParser.parseNodes(JSPSourceParser.java:296)
org.eclipse.wst.xml.core.internal.parser.XMLSourceParser.getDocumentRegions(XMLSourceParser.java:162)
org.eclipse.wst.sse.core.internal.text.BasicStructuredDocument.reparse(BasicStructuredDocument.java:2326)
org.eclipse.jst.jsp.core.internal.contentmodel.TaglibController$FileBufferListener.bufferCreated(TaglibController.java:121)
org.eclipse.core.internal.filebuffers.TextFileBufferManager$11.run(TextFileBufferManager.java:536)
org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:37)
org.eclipse.core.internal.filebuffers.TextFileBufferManager.fireBufferCreated(TextFileBufferManager.java:534)
org.eclipse.core.internal.filebuffers.TextFileBufferManager.connect(TextFileBufferManager.java:123)
org.eclipse.wst.sse.core.internal.FileBufferModelManager.getModel(FileBufferModelManager.java:541)
org.eclipse.wst.sse.core.internal.model.ModelManagerImpl._commonGetModel(ModelManagerImpl.java:322)
org.eclipse.wst.sse.core.internal.model.ModelManagerImpl._commonGetModel(ModelManagerImpl.java:308)
org.eclipse.wst.sse.core.internal.model.ModelManagerImpl.getModelForRead(ModelManagerImpl.java:1068)
org.eclipse.jst.jsp.core.internal.validation.JSPELValidator.validateFile(JSPELValidator.java:42)
org.eclipse.jst.jsp.core.internal.validation.JSPValidator.validate(JSPValidator.java:208)
org.eclipse.jst.jsp.core.internal.validation.JSPValidator.validateInJob(JSPValidator.java:384)
org.eclipse.wst.validation.internal.operations.ValidatorJob.run(ValidatorJob.java:70)
org.eclipse.core.internal.jobs.Worker.run(Worker.java:58)

We looked at the code it calls getContents on fragments, like this

protected String getContents(IPath filePath) {
			StringBuffer s = new StringBuffer();
			IFile iFile = ResourcesPlugin.getWorkspace().getRoot().getFile(filePath);
			if (iFile != null && iFile.exists()) {
				String charset = detectCharset(iFile);
				InputStream contents = null;
				try {
					contents = iFile.getContents();
				

We were able to implement a caching solution similar to one implemented in getCMDocument(..) like using a shared cache that has reference counts and when the counts go to zero, its replaced by a weak reference. 

After implementing the solution,  in a simple web project with a few dozen jsp's with fragments, we saw number of calls to File.getContents() reduce from 40 to 10 here.

Please find the solution attached.
Comment 1 Raj Mandayam CLA 2006-09-12 15:41:10 EDT
Created attachment 49985 [details]
patch with shared cache for included files
Comment 2 Chris Laffra CLA 2006-09-12 15:46:35 EDT
This is a very important defect for products such as RAD. 

We noticed for a sample Portal workspace, the build time is reduced from 19s to 10s when using a caching solution. 

We hope this can still be added to 3.2.1
Comment 3 Chris Laffra CLA 2006-09-12 15:55:59 EDT
I was confused with another bug Raj and I are looking at.
The other bug with the larger gain is bug 143228.

This repetitive file I/O bug saves about 4s. Still nice to make it into 3.2.1
Comment 4 Raj Mandayam CLA 2006-09-12 15:57:44 EDT
Hi Nitin,

If you remember a few months back I had opened  defect where
if jsp's have @taglib tld references where they refer to a common tld file, and i had worked with you to not read that file again and again, 

This problem looks similar to that in the sense, a lot of jsp's have @include stmts where they refer to a common jspf file,  and during parsing they are re-read (the same jspf) again and again

Comment 5 Raj Mandayam CLA 2006-09-20 10:11:31 EDT
Hi Nitin, please fix this too. as you are fixing the java event notification problem
Comment 6 Raj Mandayam CLA 2006-09-20 10:27:36 EDT
Based on Nitin's request put in a timestamp information in the shared file, so that we do not return stale entries
Comment 7 Raj Mandayam CLA 2006-09-20 10:29:21 EDT
Created attachment 50559 [details]
patch with shared cache for included files
Comment 8 Nitin Dahyabhai CLA 2006-09-20 14:06:02 EDT
Created attachment 50582 [details]
modified patch
Comment 9 Raj Mandayam CLA 2006-09-20 18:38:08 EDT
Created attachment 50609 [details]
proposed alternative patch

please check its feasibility
Comment 10 Raj Mandayam CLA 2006-09-27 12:43:51 EDT
Chris Laffra has asked me to address this as a critical bug and hotbug. Please contact us if you need additional information.
Comment 11 Arthur Ryman CLA 2006-10-03 13:23:38 EDT
Jeffrey, pls track this.
Comment 12 Nitin Dahyabhai CLA 2006-10-12 03:05:20 EDT
Created attachment 51835 [details]
cleaned-up proposed patch

Raj, could you check performance with this latest patch?  It satisifies the requirements while encapsulating the cache management a little better and not overexposing the internals.  This is the version I'd be OK with.
Comment 13 Nitin Dahyabhai CLA 2006-10-12 16:49:18 EDT
Created attachment 51890 [details]
updated patch based on review by Amy Wu

New patch.  Eliminates some extra string creation and reverts an accidental change to internal API.
Comment 14 Nitin Dahyabhai CLA 2006-10-12 17:19:30 EDT
Created attachment 51895 [details]
updated patch to fix a bug in the original
Comment 15 Nitin Dahyabhai CLA 2006-10-12 17:50:48 EDT
Created attachment 51898 [details]
fixes a looping problem found by our JUnits (which was not present originally)
Comment 16 Nitin Dahyabhai CLA 2006-10-12 21:04:57 EDT
This patch introduces a new internal JSPFragmentBufferCache for use both by the JSP translator and the JSP model's custom tag library support.  The new class keeps a string buffer in memory as long as a model is using it and converts it into a weak reference so that when using (e.g. validating) multiple files that all refer to the same fragment, even if not at the same time, disk I/O can be reduced with minimal impact on memory usage.  It also ensures that each retrieval of a fragment's contents updates the buffer if the file was modified, so that callers always retrieve the correct copy of the file's contents when they request it.
Comment 17 Chris Laffra CLA 2006-10-12 21:11:11 EDT
We have seen total validation time for one particularly large workspace go down from ~600s to ~400s with just this patch applied. That is 33% faster. This looks like a great performance fix to us.

We are doing more testing right now.
Comment 18 Arthur Ryman CLA 2006-10-13 16:51:46 EDT
+1 for WTP 1.5.2

I don't understand the patch, but this is an important fix for a bad performance problem. I assume it has been adequately tested based on Chris Laffra's comment.
Comment 19 Raghunathan Srinivasan CLA 2006-10-13 17:09:19 EDT
+1

Agree on the need to fix this issue.

However, since it involves extensive code change, Can we get a better idea of the testing that is being done?
Comment 20 Nitin Dahyabhai CLA 2006-10-13 17:20:08 EDT
(In reply to comment #18)

I'd be glad to explain anything you don't understand.
Comment 21 Nitin Dahyabhai CLA 2006-10-13 17:30:14 EDT
(In reply to comment #19)
> However, since it involves extensive code change, Can we get a better idea of
> the testing that is being done?

All of the current unit tests, which include testing for tag library contributed Java variables and tags from within include files, have to keep passing.  The tests include verbatim character comparisons against the translated Java sources, and the 2006-10-12 17:19 patch actually contains a bug found by the unit tests.  We've also done local developer testing and the code's been reviewed by another person.  Apart from that, Chris and Raj are doing the performance runs to verify that the timing improves on their large workspace scenarios.
Comment 22 David Williams CLA 2006-10-14 22:04:52 EDT
-1
at least for now. 

I think this needs more work ... or, I just don't understand some things, so I'll need to be better educated.  

The "lazy init" getInstance isn't really thread safe (as many of our singleton's are not, but ... let's not make it worse :) 
I think in this case, the lazy init is not really needed, since is a very light init, so I'd just initialize the instance on class loading, 
private static JSPFragmentBufferCache _instance = new JSPFragmentBufferCache();
and just have getInstance() return that instance. 

I think the fact that you have static methods, which call instance methods on the singleton is a sign something's wrong with the design. I can't imagine why you'd need both, and my own prefrence is to avoid static methods like the plague! :) ... so, why not simply do away with the static methods, and require clients to use "getInstance()" first, then use the instance methods? (The theory is that singleton's and instance methods are good, since you _might_ in the future, find you need, for example, exactly two instances, instead of exactly one, which could be acomplished with evolution, where as if you use static methods, then they can not be evolved.)

I'd suggest using a synchronized hashmap, rather than a plain old hash map, for thread safty. 

I really do not understand the use of weak references in this context. Since you have explicit release's, isn't that enough? Why both? If you used weak references, why do you need reference counts? And if you really wanted weak references for some reason, why is a hashmap with strong keys and week references preferable to simply using a WeakHasMap? [As always, there may be perfectly good reasons for the way you've done it, but if so, I'd like them explained]. 

One minor complaint (or my confusion :) why is the "logStatus" so important during plugin shutdown? I'm not sure what important diagnostic information this would be telling anyone "in the field". (and, it does expose yet another public method). 

And one idealistic concern ... this cache, in theory, should be very "low level" and pretty transparent to everyone, but, requires 4 public methods? While its true the class is marked "internal", I would think most such low level caches would have no public methods, just default access. I guess another way of asking this is why do the TLDCMManager and the Translator have to use exactly the same caching mechanism ... just seems "odd" to me, not necessarily wrong. (and, maybe a sign there's an existing design issue, that these two "needs" have not been abstracted out to some other class). 
 

And, can you explain to me ... is the whole premise of this fix is to trade off repeatetive IO with larger memory requirements of cached StringBuffers. Isn't this sort of the job of the Operating System's file caching? What makes us think we can do better than the OS? My fear is that even if we can reduce IO, it's always at the cost of increased memory use. And then, could there be some cases out there in the wild that would max out memory with these remembered StringBuffers? What would be the performance tradeoffs then? Put another way, what is the memory required if there is, say, 1000 fragments, of, say, 10000 characters each? Is that 10 Meg of memory? Is that any concern? (especially following the rule if you think x is the maximum anyone would ever have, you should design for 10x?). Maybe you already have these numbers, if in runs where you say 33% improvement in time, what was the nubmer of files/fragments involved? What was the memory snapshots like? 

Has anyone tested explictly changing resources (such as a cvs check out) at the same time this cache is being used ... I think its that case that we always, in the past, decided to just re-read the file. Since this patch does not use scheduling rules, I'm wondering if there's any increased risk of deadlock or anything? 

Maybe this is more obvious to Raj, Chris, and Nitin that I know have been working hard on this, but, I'd just like to understand before we make this large a change to a quick maintenance release. So, appreciate the explainations, and all the hard work on this and similar issues. 





Comment 23 Nitin Dahyabhai CLA 2006-10-15 00:15:26 EDT
(In reply to comment #22)
Wow, that's a lot of good points up front.

> I really do not understand the use of weak references in this context. Since
> you have explicit release's, isn't that enough? Why both? If you used weak
> references, why do you need reference counts? And if you really wanted weak
> references for some reason, why is a hashmap with strong keys and week
> references preferable to simply using a WeakHasMap? [As always, there may be
> perfectly good reasons for the way you've done it, but if so, I'd like them
> explained].

In a WeakHashMap, the keys themselves are weakly held and the values are removed if the keys are garbage collected.  We're using the IPaths as keys and they're also held strongly by corresponding IFile instances, so we couldn't rely on them being collected.  The reference counting is used to keep the buffers strongly when we know they're being referred to by one or more live models--as it's the text contents only, it's hopefully not a large penalty.  I'll admit that might not scale if there are many different fragment files being used by many models.  The weak referencing gives us a chance to avoid the I/O for reading it back in if a validator or model requests one that isn't actively referred to but hasn't been collected, such as during validation.

> One minor complaint (or my confusion :) why is the "logStatus" so important
> during plugin shutdown? I'm not sure what important diagnostic information this
> would be telling anyone "in the field". (and, it does expose yet another public
> method).
I think I was just being overly cautious, particularly with methods being public as they are.  It's probably unneccessary.

> And one idealistic concern ... this cache, in theory, should be very "low
> level" and pretty transparent to everyone, but, requires 4 public methods?
> While its true the class is marked "internal", I would think most such low
> level caches would have no public methods, just default access. I guess another
> way of asking this is why do the TLDCMManager and the Translator have to use
> exactly the same caching mechanism ... just seems "odd" to me, not necessarily
> wrong. (and, maybe a sign there's an existing design issue, that these two
> "needs" have not been abstracted out to some other class).

I think it's exactly the latter case, where both are in need of the contents of any included fragments and were each loading them themselves, sometimes repeatedly.  The current patch shares the contents between those two classes and among any number of models also pointing to the same fragment.  There are other ways to structure the code, but none that I could think of that didn't require more significant changes to the calling classes.

> And, can you explain to me ... is the whole premise of this fix is to trade off
> repeatetive IO with larger memory requirements of cached StringBuffers. Isn't
> this sort of the job of the Operating System's file caching? What makes us
> think we can do better than the OS? My fear is that even if we can reduce IO,
> it's always at the cost of increased memory use. And then, could there be some
> cases out there in the wild that would max out memory with these remembered
> StringBuffers? What would be the performance tradeoffs then? Put another way,
> what is the memory required if there is, say, 1000 fragments, of, say, 10000
> characters each? Is that 10 Meg of memory? Is that any concern? (especially
> following the rule if you think x is the maximum anyone would ever have, you
> should design for 10x?). Maybe you already have these numbers, if in runs where
> you say 33% improvement in time, what was the nubmer of files/fragments
> involved? What was the memory snapshots like? 
> 
> Has anyone tested explictly changing resources (such as a cvs check out) at the
> same time this cache is being used ... I think its that case that we always, in
> the past, decided to just re-read the file. Since this patch does not use
> scheduling rules, I'm wondering if there's any increased risk of deadlock or
> anything? 
> 
> Maybe this is more obvious to Raj, Chris, and Nitin that I know have been
> working hard on this, but, I'd just like to understand before we make this
> large a change to a quick maintenance release. So, appreciate the
> explainations, and all the hard work on this and similar issues. 

It's actually never been obvious to me why an application would do its own caching, as I'd always considered it the Operating System's job to cache such things at its level.  But when Raj and Chris hand us a prototype patch with numbers to back it up, it's time to rethink it.  My only guess is that an OS-level cache doesn't know how likely we are to want to read one file vs. another on disk.  During long/large operations on large workspaces, any OS-level caching probably gets exhausted and keeps "missing" with the sheer number of resources being processed.

The performance tradeoff is to keep a copy of the contents of a fragment in memory when someone's using that fragment instead of rereading it in each time, creating a new temporary copy in memory and accessing the disk to do so.  It's not a full structured document, and the buffer is shared between models the same way the fragment is meant to be shared between JSP files.  The weak referencing should mitigate the impact if they're not as commonly reused as we expected.  My only other thought is to cap the number of strong references, varying them based on the number of characters held by all of the stringbuffers in memory and prioritizing the bigger buffers as strong references according to some arbitrary number of characters.

Your question of possible deadlock does get me thinking, though.  We're not forcing a refresh directly in these changes, nor do they call anything but the resource and content type manager APIs directly.  Without scheduling rules, do you think we're at risk of a deadlock somehow?

Raj or Chris, can you give us more specifics of your test runs apart from the timings?
Comment 24 Nitin Dahyabhai CLA 2006-10-15 00:26:20 EDT
Created attachment 51999 [details]
incorporates some of David's feedback
Comment 25 David Williams CLA 2006-10-16 09:47:59 EDT
Thanks Nitin, I like the latter version better and I understand your explainations. 

I think the remaining required work here is primarily to understand how the time improvements trades off with increased memory use. I'm assuming that would be favorable, but would like to see it tested and documented, or, at least some hypotetical cases computed. 

And while not strictly required (by me) I'd feel even better if the refernce counting and weak reference were seperated into two solutions, and tests ran to see if its actually only one of them that's helping in this case. If only one of them would suffice, then seems like extra code to do both. And, for example, if weak reference alone would suffice, then that helps offset the concern I have about increased memory use, since, presumably, those with low memory machines would continue to suffer the slower times, but at least not suddenly start running out of memory once this fix released. 

Also, again while not strictly required for approval, we should start to develop some mutli-job testing of areas like this, since its obviously sensitive to that.  I have tried to follow all the code and it appears basically correct, threading wise, but, it is pretty complicated, so hard to know for sure. Not sure how to solve that in general (that is, its hard to prove threading is correct, and impossible to completely test thread correctness). 

Again, much thanks, looks like a great improvement, if those preliminary tests hold up. 

Comment 26 David Williams CLA 2006-10-16 15:18:49 EDT
BTW, caching the string buffers of file contents would seem to solve the repetetive IO problem, but, I'm wondering if that's really just a prototype of the real solution ... the real solution, it would seem to me, would be to cache the end-result of what ever the file's contents were being used for. I'm not familar enough with this code to know what its being used for, but would assume its being scanned for varable definitions or something? Maybe it depends, but seems to me that follow on work should be considered. 
Comment 27 Nitin Dahyabhai CLA 2006-10-16 15:57:39 EDT
(In reply to comment #26)
> BTW, caching the string buffers of file contents would seem to solve the
> repetetive IO problem, but, I'm wondering if that's really just a prototype of
> the real solution ... the real solution, it would seem to me, would be to cache
> the end-result of what ever the file's contents were being used for. I'm not
> familar enough with this code to know what its being used for, but would assume
> its being scanned for varable definitions or something? Maybe it depends, but
> seems to me that follow on work should be considered.

When we originally discussed this problem, I pointed out that the fragment contents are run through the JSP parser and the parser events are used to drive  the handling of included fragments by the TLD support and translator.  Saving those is trickier because both functions are using parser events instead of walking through a fully created structured document (either from the platform's file buffers or its own mechanism), and that was a larger change than just introducing a caching mechanism for the contents.  Certainly larger than I would have proposed for 1.5.2, and maybe even for 1.5.3.
Comment 28 Arthur Ryman CLA 2006-10-17 10:46:03 EDT
David, I see you have rejected this. Could you please confirm is this fix was actually tested by Chris Laffra, and if so, did it improve performance?
Comment 29 Raj Mandayam CLA 2006-10-17 17:07:20 EDT
 Hi David, I was talking to Nitin and tried the fix, as far as time goes it reduced time in validation in commerce workspace by 40 seconds but i dont know if reducing it from 400 to 360 is a big success
 memory goes , there were 500 fragment files with file sizes ranging between 2000 and 7000 bytes
as far as working set goes i didnt see working set go above 300mb
this is all during validation
Comment 30 David Williams CLA 2006-10-17 18:14:08 EDT
Thanks Raj. Given the potential improvement is "only" 10%, I'd prefer to investigate and test this area more, before committing this sort of fix. 

While 10% is important, I'm not sure its in the "critical" range, and I have some concerns about this fix, as noted ... for example, perhaps not both reference counting and weak refernces needed ... perhaps some soft refernce cache could be used, or, as you've noted, perhaps the results of the parsing can be cached, rather than string buffers. 

So, I'll remove request for 1.5.2 and we'll target for 1.5.3. 

Much thanks ... let's keep up the momentium! :) 
Comment 31 David Williams CLA 2006-11-16 11:40:27 EST
I am not sure this is still literally a "hotbug request", since it appears to not be causing quite as much of a performance problem as originally thought. 

We should still investigate at "P2" level of priority, but I am not sure we know what the right fix is yet. 

Please correct me if I have misunderstood. 
Comment 32 Gary Karasiuk CLA 2006-12-18 11:02:47 EST
Is this still being investigated, and in particular is it being targeted for 1.5.3? 
Comment 33 Nitin Dahyabhai CLA 2008-04-28 16:00:26 EDT
Believed to be addressed by the addition and use of org.eclipse.jst.jsp.core.internal.util.FileContentCache.