'Error during process pipe listening' when indexing

[vladak]

After our internal instance was upgraded to 1.1-rc20 I added a new project and pretty much since that every indexing run exhibits this problem:

2018-02-14 12:03:01.577+0100 INFO t54 Statistics.report: Done historycache for /ws-local/on11u4 (took 8.850 seconds)
2018-02-14 12:03:01.578+0100 INFO t1 Statistics.report: Done historycache for all repositories (took 8.867 seconds)
2018-02-14 12:03:01.578+0100 INFO t1 Indexer.prepareIndexer: Done...
2018-02-14 12:03:01.580+0100 INFO t1 Indexer.doIndexerExecution: Starting indexing
2018-02-14 12:03:01.586+0100 SEVERE t55 Executor$1.run: Error during process pipe listening
java.io.IOException: Stream Closed
        at java.io.FileInputStream.readBytes(Native Method)
        at java.io.FileInputStream.read(FileInputStream.java:233)
        at java.lang.UNIXProcess$DeferredCloseInputStream.read(UNIXProcess.java:647)
        at org.opensolaris.opengrok.util.Executor$SpoolHandler.processStream(Executor.java:363)
        at org.opensolaris.opengrok.util.Executor$1.run(Executor.java:183)
        at java.lang.Thread.run(Thread.java:748)

Interestingly all other (already indexed) projects do not have this problem.

[vladak]

DeferredCloseInputStream was discussed a bit in #2050, except there it was impacting history indexing. I wonder if this could be related.

[vladak]

In doIndexerExecution() the Executor is used only for launching ctags. So this could also be related to cset b92758c that introduced Ctags object pool.

[vladak]

Actually, Ctags class uses processBuilder to execute ctags directly, not Executor.

[vladak]

Cherry-picked the changes for cset e766735 on top of 1.1-rc21, the initial part of the log in full:

2018-04-05 17:26:44.092+0200 INFO t1 Statistics.report: done invalidating repositories (took 805 ms)
2018-04-05 17:26:44.159+0200 INFO t1 Indexer.prepareIndexer: Generating history cache for repositories: on11u4-clone
2018-04-05 17:26:44.163+0200 INFO t1 HistoryGuru.createCacheReal: Creating historycache for 1 repositories
2018-04-05 17:26:44.169+0200 INFO t54 HistoryGuru.createCache: Creating historycache for /ws-local/on11u4-clone (MercurialRepository)
2018-04-05 17:26:52.462+0200 WARNING t54 HistoryGuru.createCache: An error occured while creating cache for /ws-local/on11u4-clone (MercurialRepository)
java.nio.file.InvalidPathException: Malformed input or input contains unmappable characters: /ws-local/on11u4-clone/usr/src/cmd/cmd-crypto/etc/certs/CA/T??RKTRUST_Elektronik_Sertifika_Hizmet_Sa??lay??c??s??_H6.pem
        at sun.nio.fs.UnixPath.encode(UnixPath.java:147)
        at sun.nio.fs.UnixPath.<init>(UnixPath.java:71)
        at sun.nio.fs.UnixFileSystem.getPath(UnixFileSystem.java:281)
        at java.nio.file.Paths.get(Paths.java:84)
        at org.opensolaris.opengrok.util.PathUtils.getRelativeToCanonical(PathUtils.java:124)
        at org.opensolaris.opengrok.configuration.RuntimeEnvironment.getPathRelativeToSourceRoot(RuntimeEnvironment.java:419)
        at org.opensolaris.opengrok.configuration.RuntimeEnvironment.getPathRelativeToSourceRoot(RuntimeEnvironment.java:396)
        at org.opensolaris.opengrok.history.MercurialHistoryParser.processStream(MercurialHistoryParser.java:145)
        at org.opensolaris.opengrok.util.Executor.exec(Executor.java:216)
        at org.opensolaris.opengrok.history.MercurialHistoryParser.parse(MercurialHistoryParser.java:81)
        at org.opensolaris.opengrok.history.MercurialRepository.getHistory(MercurialRepository.java:592)
        at org.opensolaris.opengrok.history.Repository.createCache(Repository.java:331)
        at org.opensolaris.opengrok.history.HistoryGuru.createCache(HistoryGuru.java:589)
        at org.opensolaris.opengrok.history.HistoryGuru.access$000(HistoryGuru.java:63)
        at org.opensolaris.opengrok.history.HistoryGuru$1.run(HistoryGuru.java:640)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)

2018-04-05 17:26:52.463+0200 SEVERE t55 Executor$1.run: Error while executing command [/usr/bin/hg, log, -r, reverse(0::'s11u4'), --template, changeset: {rev}:{node|short}\nuser: {author}\ndate: {date|isodate}\ndescription: {desc|strip|obfuscate}\nfiles: {files}\nfile_copies: {file_copies}\nmercurial_history_end_of_entry\n, /ws-local/on11u4-clone] in directory /ws-local/on11u4-clone
2018-04-05 17:26:52.465+0200 INFO t54 Statistics.report: Done historycache for /ws-local/on11u4-clone (took 8.296 seconds)
2018-04-05 17:26:52.468+0200 SEVERE t55 Executor$1.run: Error during process pipe listening
java.io.IOException: Stream Closed
        at java.io.FileInputStream.readBytes(Native Method)
        at java.io.FileInputStream.read(FileInputStream.java:233)
        at java.lang.UNIXProcess$DeferredCloseInputStream.read(UNIXProcess.java:647)
        at org.opensolaris.opengrok.util.Executor$SpoolHandler.processStream(Executor.java:366)
        at org.opensolaris.opengrok.util.Executor$1.run(Executor.java:183)
        at java.lang.Thread.run(Thread.java:748)

2018-04-05 17:26:52.469+0200 INFO t1 Statistics.report: Done historycache for all repositories (took 8.308 seconds)
2018-04-05 17:26:52.474+0200 INFO t1 Indexer.prepareIndexer: Done...

The error seems to be happening while creating history index. Not sure if the earlier problem with certificate file that has non-ASCII characters in its file name could cause the issue further along the way.

[vladak]

Yep. Once I modified MercurialHistoryParser#processStream() to catch InvalidPathException in the block around getPathRelativeToSourceRoot() the history index progressed until it hit #2050. I guess we need a test for such funky (in this case Turkish) names.

[idodeclare]

Might running OpenGrok after having set export LC_ALL=UTF-8 resolve that "input contains unmappable characters" problem for a SRC_ROOT having Unicode(non-ASCII) file names?

[vladak]

Running with LC_ALL=en_US.UTF-8 works fine, that's useful workaround.