[Since when are we top-posting? grr...] On 13.03.2015 21:17, Bert Huijben wrote: > Are you requesting the results in the same order in both cases? (I > don't know what the arguments in your code represent) > > If you retrieve oldest to youngest some delay is expected as then > first all interesting revisions are fetched (youngest to oldest) and > then results+detailed are spooled back the other way.
It's a standard youngest-to-oldest log; parameters for getLogs are (paths, start-revision, end-revision, limit, ...). > The normal svn invocation you compare to is the most efficient one... > > Bert > ------------------------------------------------------------------------ > From: Marc Strapetz <mailto:marc.strap...@syntevo.com> > Sent: 13-3-2015 20:35 > To: dev@subversion.apache.org <mailto:dev@subversion.apache.org> > Subject: 1.9.x JavaHL: long initial delay when performing a log > > I'm experiencing a strange initial delay when performing a log using > JavaHL. > > svn log http://svn.apache.org/repos/asf/subversion/branches/1.8.x > > shows first results after 2-3 seconds, while following code snippet > takes at least 20 seconds (sometimes significantly more, might depend on > the server's load): > > ISVNRemote session = > factory.openRemoteSession("http://svn.apache.org/repos/asf";); > > List<String> paths = > Collections.singletonList("subversion/branches/1.8.x"); > > session.getLog(paths, Revision.SVN_INVALID_REVNUM, 0, 0, false, > false, false, null, new LogMessageCallback() { > public void singleMessage(Set<ChangePath> changedPaths, > long revision, Map<String, byte[]> revprops, boolean hasChildren) { > System.out.println("DATA"); > } > }); > > Once the log responds, a bunch of revisions are reported, so it seems > that there is some kind of caching of log records. I tried this with a slight change, setting the limit parameter of getLog() to 1 instead of 0; here are the results: $ time svn log --limit 1 http://svn.apache.org/repos/asf/subversion/branches/1.8.x ... real 0m1.574s user 0m0.007s sys 0m0.006s $ time java -cp ... -Djava.library.path=... TestStatus DATA real 0m1.430s user 0m0.138s sys 0m0.036s So, no real difference here. Without the limit, it does take a bit more than 10 seconds to begin displaying results. So I tested when the callback was actually invoked: I added code to print the current time just before the call to getLog(), and the current time and revision in the log receiver callback. The output confirms that the delay is real and not, for example, an artefact of some caching in stdout, for example: $ time java -cp ... -Djava.library.path=... TestStatus 2015-03-13 21:59:46.731 2015-03-13 21:59:57.223 1666354 2015-03-13 21:59:57.223 1666269 ... 2015-03-13 22:00:27.318 836421 2015-03-13 22:00:27.318 836420 > I've tested with latest 1.9.x sources on Windows but have seen the same > behavior with javahl-1.8-extensions branch on Linux, too. Same here on OSX. However, I can't any place in the code that would cause the delay. I added similar time-printing code to the C++ part of JavaHL and got extremely strange results: TestStatus (Java): 2015-03-13 22:21:40.403 svn_ra_get_log2: 2015-03-13T21:21:40.404731Z callback: 2015-03-13T21:21:50.098592Z invoke: 2015-03-13T21:21:50.098671Z TestStatus (Java): 2015-03-13 22:21:50.098 1666354 return: 2015-03-13T21:21:50.099058Z (note that there's an hour of difference between local time printed by Java and UTC printed from the native code). This confirms that there is an actual delay of 10 seconds in the *native* code between the call to svn_ra_get_log2() and the first invocation of the (native) callback wrapper; each callback invocation takes about half a millisecond. Now I'm really beginning to wonder what the native JavaHL implementation is doing differently from libsvn_client. -- Brane
