[jboss-dev] Further profling: Where should I focus?

[David M. Lloyd]

Caching behavior depends on the filesystem.  For zip mounts, "isDirectory" 
and "lastModified" don't even hit the filesystem (in most cases).  Don't 
take JProfiler data as real-world timing; it's useful to find slow spots, 
sometimes, but it's not an accurate reflection of what the real speed of 
the thing is.

For real filesystem stuff, you CAN NOT EVER do any form of caching of file 
metainformation because the backing data is not owned by VFS, and thus can 
change without any sort of notice.

Try the test again with a "warmed up" JVM and no profiler agent installed 
and you'll probably see a different story.

- DML

On 01/05/2010 02:05 PM, John Bailey wrote:
>
> I have been running the tests through JProfiler.  Not sure if I just have not optimized the profilers settings, but I am getting numbers all over the board, and some are well over double the time of a JUnit execution.  The non-profiler time to run the test seems to be<300ms.
>
> With the profiler enable, I can see ~30% of the total time is in the VFS.mountZip call.  With>10% of the total test time taken up by the 5,085 calls to org.jboss.vfs.util.PathTokenizer.getTokens.
>
> The org.jboss.classloading.plugins.vfs.PackageVisitor.determineAllPackages call is taking ~35% of the total test time to run.  With ~14% of the total test time in VirutalFile.isDirectory.
>
> Maybe there is room for more caching of this isDirectory like calls.  There may be a problem with caching the info as the actual file system can change for a given VirutalFile, and the cached information is not guaranteed to remain accurate.
>
> John
>
>
> On Jan 5, 2010, at 1:42 PM, Bill Burke wrote:
>
>>
>>
>> David M. Lloyd wrote:
>>> On 01/05/2010 12:27 PM, Bill Burke wrote:
>>>>
>>>> David M. Lloyd wrote:
>>>>> Anyway this has all been covered, benchmarked, and fixed by VFS3.
>>>>>
>>>> Well....not really.
>>>>
>>>> 446ms now for the PackageTest.
>>>>
>>>> 65% is still VFS initialization.
>>> Using VFS3?  If so, can you post details?
>>
>> Gonna help John Bailey get up to running JProfiler.  That cool?
>>
>> Preliminary, it looks like a lot of things aren't getting cached (isDirectory, lastModified, isFile, children, etc..).  This results in a lot of hash lookups.  Looks like they aren't getting cached because of mounting?? Not sure.
>>
>> But, I found a problem with my initialization code (see below).  It was trying to mount children.  I commented out that part and it ran in 251ms.  40% in VFS init if profile CPU time, 60% in actual time. Sometimes jprofiler is weird.
>>
>>
>>
>>    public List<Closeable>  recursiveMount(VirtualFile file) throws IOException
>>    {
>>       ArrayList<Closeable>  mounts = new ArrayList<Closeable>();
>>
>>       if (!file.isDirectory()&&  file.getName().matches("^.*\\.([EeWwJj][Aa][Rr]|[Zz][Ii][Pp])$"))
>>          mounts.add(VFS.mountZip(file, file, provider));
>>
>>       /****** Doubled speedup when this was commented out!!!!!!!!!!!!
>>       if (file.isDirectory())
>>          for (VirtualFile child : file.getChildren())
>>             mounts.addAll(recursiveMount(child));
>>             */
>>
>>
>>       return mounts;
>>    }
>>
>>    private TempFileProvider provider;
>>
>>    protected void setUp() throws Exception
>>    {
>>       super.setUp();
>>
>>       provider = TempFileProvider.create("test", new ScheduledThreadPoolExecutor(2));
>>    }
>>
>>    protected void tearDown() throws Exception
>>    {
>>       provider.close();
>>    }
>>
>>
>>
>>
>>
>>
>> Bill
>>
>> --
>> Bill Burke
>> JBoss, a division of Red Hat
>> http://bill.burkecentral.com
>
> --
>    John Bailey
>    JBoss by Red Hat
> --
>
>
>
>
>
> _______________________________________________
> jboss-development mailing list
> jboss-development at lists.jboss.org
> https://lists.jboss.org/mailman/listinfo/jboss-development