CVS history fails for very large projects

[pratikone]

We are trying to deploy Opengrok in our office environment. Opengrok is programmed to index our project and multiple branches, all under the same project folder. Everything works fine except for History. We are using CVS for version control.

What is happening ?

• History works totally fine for indexing a single CVS branch.
• For anything larger, (multiple CVS branches to be indexed together), it doesn't work
• History link in the Opegrok only shows the latest revision and not the earlier ones.
• Sometimes CVS HistoryException with exitcode : 1 is thrown. But mostly it fails silently. No error is recorded even in index logs.

From extensive test trials of checking out branches one by one and indexing sequentially to changing memory footprint and number of running threads of Opengrok, nothing has worked. Some posts on StackOverflow hint that CVS might be getting overwhelmed by parallel requests by HistoryExecutioner and reducing number of threads may solve this. But it also has not solved this .

What could be the issue here ?

[tarzanek]

What does it mean:
For anything larger, (multiple CVS branches to be indexed together), it doesn't work
?

e.g. you have a checkout of single branch in every subdir like:
src_root / branch1-co
src_root / branch2-co
src_root / branch3-co
branch1-3 have the same CVS parent
or I got it wrong?
if yes, then the thing is that opengrok indexes as many projects parallel as you have available cpus, this variable is however tunable (check opengrok jar options) so you can decrease it to allow one/two projects to be indexed at the same time to allow CVS to recover

I also suggest to move away from CVS, it's 2015 already ;)
(and I cannot remember any single feature of CVS that isn't present in modern SCMs)

[tarzanek]

https://github.com/OpenGrok/OpenGrok/blob/master/src/org/opensolaris/opengrok/index/CommandLineOptions.java#L106

-T - and make it as low as possible, e.g. 1 or 2
the drawback will be slow index generation since only 1 or 2 projects will be indexed at the same time

[vladak]

Is the CVS Root remote or local ?

[pratikone]

Thanks for the quick responses.

@tarzanek you are right, inside src_root/ there are multiple branches of same CVS parent. They contact the same CVS repo.

As I mentioned above reducing the number of threads -T 1 doesn't work at all. I am editing bin/Opengrok and adding -T 1 to the command line arguments section there as passing ./Opengrok index <src_root> -T 1 is not working at all.

I know CVS is a pain in the ***, but my local build team is heavily dependent on it and moving to something like git may take easily an year.

@vladak our CVS Root is a remote server.

The baffling part is how it could fail silently ? I searched few forums where there was a similar problem with Mercurial. The solution suggested was to reduce timeout for non-response timeout timer (possibly in Opengrok), though, it was not mentioned where to change it in Opengrok

[vladak]

It's definitely weird that logs do not give any hints whatsoever. I'd try simulating this on command line - start with one repo and keep adding. One hypothesis would be that CVS server gives up silently and truncates the log output.

Also, how long does each of these cvs log commands take in average ? I am asking because the changes for #429 and #487 introduced timeout for command execution, it's set to 10 minutes by default. However, subsequent change (cset bf60a46) added a report to log. What OpenGrok version are you running ?

[vladak]

Also, for the cases where CVS HistoryException with exitcode 1 is thrown could you share the log context ?

[vladak]

I did a small experiment. My laptop has 4 virtual CPUs; according to Indexer.java#main() the number of threads is determined as:

126 int noThreads = 2 + (2 * Runtime.getRuntime().availableProcessors());

which correspond to the -T command line option. So I cloned 10 OpenBSD repositories (just src/sys/arch, not the whole repo) with branches from OPENBSD_4_8 to OPENBSD_5_7 to make the machine fully loaded and ran the indexer (stock 0.12.1). Indeedy, the indexer created 10 ctags processes and 10 cvs log processes. My logging,properties file had this line:

.level= FINE

so it was possible to see every command executed (okay, I could get that with execsnoop dtrace script too). No failures were recorded.

However, there is one noticeable thing. Since cset 3ad4470 (also see the changes for #516) the history for CVS repository with branches is determined using -r branchname, e.g. for one file in the OpenBSD 5.7 repository (checked out with cvs -qd anoncvs@ftp5.eu.openbsd.org:/cvs get -d openbsd-5.7 -rOPENBSD_5_7 -P src/sys/arch) the command executed would look like this:

/usr/bin/cvs log -rOPENBSD_5_7 amd64/include/signal.h

the output of which will contain zero history entries - as opposed to the command without -rOPENBSD_5_7. So all in all the problem could be in different expectations of what history of individual files in CVS repository with non-default branch should contain. The -r branchname will display just revisions on that branch.

[tarzanek]

I understand the prob is with scalability ... the other option is to index history one by one
e.g. disable history indexing for all but one repo - I think we have some file which if present will disable history for the repo, no? @vladak do you remember what file needs to be touched? wondering if it's documented :)

anyways worst case rename the CVS dir under every branch, then rename back just for one branch, reindex, then rename CVS again, and enable some other dir, reindex ...
I guess this could be even scripted.
I am not sure if you have other options, since it seems to me you hit the limits of cvs server here

[pratikone]

Hi,

I tried the same thing as @tarzanek . It works perfectly fine for smaller folder checkout as proof of concept but spectacularly fails for the original case.
Same as the above, no errors are present in the index logs.

However, these have come in tomcat logs

22-May-2015 10:29:44.997 SEVERE [Thread-7] org.opensolaris.opengrok.util.Executor$1.run Error during process pipe listening
 java.io.IOException: Stream closed
    at java.io.BufferedInputStream.getBufIfOpen(BufferedInputStream.java:170)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:291)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
    at java.io.FilterInputStream.read(FilterInputStream.java:107)
    at org.opensolaris.opengrok.util.Executor$SpoolHandler.processStream(Executor.java:323)
    at org.opensolaris.opengrok.util.Executor$1.run(Executor.java:151)
    at java.lang.Thread.run(Thread.java:745)

22-May-2015 10:29:45.001 SEVERE [http-nio-8080-exec-3] org.opensolaris.opengrok.util.Executor.exec Failed to read from process: /usr/bin/cvs
 java.io.IOException: Stream closed
    at java.io.BufferedInputStream.getBufIfOpen(BufferedInputStream.java:170)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:336)
    at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
    at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
    at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
    at java.io.InputStreamReader.read(InputStreamReader.java:184)
    at java.io.BufferedReader.fill(BufferedReader.java:161)
    at java.io.BufferedReader.readLine(BufferedReader.java:324)
    at java.io.BufferedReader.readLine(BufferedReader.java:389)
    at org.opensolaris.opengrok.history.CVSHistoryParser.processStream(CVSHistoryParser.java:142)
    at org.opensolaris.opengrok.util.Executor.exec(Executor.java:178)
    at org.opensolaris.opengrok.history.CVSHistoryParser.parse(CVSHistoryParser.java:163)
    at org.opensolaris.opengrok.history.CVSRepository.getHistory(CVSRepository.java:262)
    at org.opensolaris.opengrok.history.FileHistoryCache.get(FileHistoryCache.java:490)
    at org.opensolaris.opengrok.history.HistoryGuru.getHistory(HistoryGuru.java:229)
    at org.opensolaris.opengrok.history.HistoryGuru.getHistoryUI(HistoryGuru.java:200)
    at org.apache.jsp.history_jsp._jspService(history_jsp.java:413)
    at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
    at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:432)
    at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:403)
    at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:347)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:301)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:503)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:136)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:78)
    at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:610)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:526)
    at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1033)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:652)
    at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:222)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1566)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1523)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:745)

22-May-2015 10:29:45.002 WARNING [http-nio-8080-exec-3] org.opensolaris.opengrok.util.Executor.exec Non-zero exit status 1 from command [/usr/bin/cvs, log, -rHEAD] in directory /home/srpg/Source/HEAD/panos

This error is consistent and occurs in every run where the History does not work. I was ignoring it till last run, then when I saw it this time too, I grew suspicious and hence, posting it here.
Edit : Sorry for the confusion. These are old logs . They did not occur in the recent operation of removing the folder, keeping the history cache and then adding the folder one by one. So, here also the History does not work for full BIG folder, but this error also does NOT show up.

[tarzanek]

well I don't have any big cvs project anymore ...
(I used to have one, but this was like 6 years ago ... :( )
so the best thing would be to clone the code, fire up netbeans
make indexer listen for debug (jars are generated with debug if I remember correctly) and connect netbeans and try to trace CVS repository and parser ...

(on java debugging try here: http://stackoverflow.com/questions/138511/what-are-java-command-line-options-to-set-to-allow-jvm-to-be-remotely-debugged )

once you've observer what happens inside code we will be smarter (and I can try to dig up that old repo, but I doubt I will find it and that its server will still work)

[pratikone]

Hi,

I found the error of the issue and resolved it. Thanks for pointing out to see the command getting sent in logs of indexing data.
The assumption that CVS is getting overwhelmed by requests was wrong. The real culprit was CVS server. It doesn't send the right logs when tags are used in cvs log command
Actually, the following command was getting issued :
cvs log -rHEAD <source>
for our HEAD project. But at the same level, we have multiple tags polluted at root level which refer to daily builds.
so, cvs log -rHEAD <source> was fetching the log of some daily build log diff-ed with previous build.

If one does cvs log <source> , whole log history of default tag (HEAD) is correctly fetched by Opengrok.

How to fix the issue ?

do a cvs checkout as cvs checkout <source> instead of cvs checkout -rHEAD <source> and then do indexing in Opengrok.
I fear that this tag problem is specific to our CVS server and will be contacting the build team.

Hence, the cvs server is not working properly. There is no problem with Opengrok.
Thanks for the awesome piece of software.
I will mark this issue as resolved.

[vladak]

It depends on what is correct for CVS or what do the users expect. Certainly we can modify the history executor for CVS to treat HEAD in special way.

[pratikone]

@vladak well yes, we have to see what is correct for CVS. However, I did not get what is meant by treating HEAD in a special way ? For Opengrok, it was just another tag through which it fetched. It was the CVS server, which did not provide correct info on running the command with tag.

Also, I couldn't find a way to close the issue so please close it yourself.

[vladak]

I mean if the branch of the repo is HEAD (i.e. was checked out with -rHEAD so there exists CVS/Tag file which contains THEAD) then instead of running hg log -rHEAD run just cvs log.

[rajgreets]

http://versioncontrol.wikia.com/wiki/List_history_on_branch

following the above link i tried 'cvs log -r::HEAD', it fetches complete history as we expect it to be.
the same can be tried for branches of HEAD (eg: cvs log -r::branch-name).

PS: i tried everything manual on my cvs code. introducing scope resolution operator might solve the problem with opengrok (not tested).