growing number of opengrok directories in Tomcat temporary area

[vladak]

In the /var/tomcat8/temp/ directory I see lots of empty directories with opengrok prefix, e.g.:

drwx------   2 webservd webservd       2 Jul 30 08:05 opengrok408091792513120463
drwx------   2 webservd webservd       2 Jul 30 08:05 opengrok5126593944445059938
drwx------   2 webservd webservd       2 Jul 30 08:05 opengrok1504167965668909705
drwx------   2 webservd webservd       2 Jul 30 08:05 opengrok6408331709879366844
drwx------   2 webservd webservd       2 Jul 30 08:05 opengrok8730009372603513500
drwx------   2 webservd webservd       2 Jul 30 08:05 opengrok3899762656954060544
drwx------   2 webservd webservd       2 Jul 30 08:05 opengrok2633702641013476723
drwx------   2 webservd webservd       2 Jul 30 08:05 opengrok5410711030578992205
drwx------   2 webservd webservd       2 Jul 30 08:05 opengrok4951472061130336907
drwx------   2 webservd webservd       2 Jul 30 08:05 opengrok4621036241443139481
drwx------   2 webservd webservd       2 Jul 30 08:06 opengrok9076596853661318875
drwx------   2 webservd webservd       2 Jul 30 08:06 opengrok8389696774557015597
drwx------   2 webservd webservd       2 Jul 30 08:06 opengrok688709581457593757
drwx------   2 webservd webservd       2 Jul 30 08:06 opengrok5227950753932224750
drwx------   2 webservd webservd       2 Jul 30 08:06 opengrok7727174665308681446
drwx------   2 webservd webservd       2 Jul 30 08:06 opengrok725675884455545561
drwx------   2 webservd webservd       2 Jul 30 08:06 opengrok7295946628718278133
drwx------   2 webservd webservd       2 Jul 30 08:06 opengrok5832858987571345938
drwx------   2 webservd webservd       2 Jul 30 08:06 opengrok3700590860536061517
drwx------   2 webservd webservd       2 Jul 30 08:06 opengrok1010355954905738740
drwx------   2 webservd webservd       2 Jul 30 08:06 opengrok8881200868190539397
drwx------   2 webservd webservd       2 Jul 30 08:06 opengrok4392975536131186015
drwx------   2 webservd webservd       2 Jul 30 08:06 opengrok2625372493496774060

Looks like multiple directories are created per minute.

Also, there are Chronicle map related files under the same directory such as:

# cat /var/tomcat8/temp/opengrok9212611386581889448chronicle
{"cmap":[""]}

however they do not appear as frequently as the directories:

-rw-------   1 webservd webservd      13 Jul 28 00:05 opengrok6649520946815519002chronicle
-rw-------   1 webservd webservd      13 Jul 28 00:07 opengrok9106171499083133495chronicle
-rw-------   1 webservd webservd      13 Jul 28 04:03 opengrok5114893838613878230chronicle
-rw-------   1 webservd webservd      13 Jul 28 16:00 opengrok6987868686171172772chronicle
-rw-------   1 webservd webservd      13 Jul 28 20:03 opengrok2672774992496671185chronicle
-rw-------   1 webservd webservd      13 Jul 29 20:00 opengrok956049573391528559chronicle
-rw-------   1 webservd webservd      13 Jul 29 20:07 opengrok9212611386581889448chronicle

The chronicle files are related to suggester. The directories seem to be present before the release with suggester was first deployed.

[vladak]

As an additional data point during the index I can see webapp doing:

/2942568:   open("/var/tomcat8/temp/opengrok4364902765925845673/opengrok_input_0.tmp", O_RDONLY) = 2075

/2942568:   open("/var/tomcat8/temp/opengrok4364902765925845673/opengrok_sort_1.tmp", O_WRONLY|O_CREAT|O_EXCL, 0666) = 2075

and writing to the file what seems like terms separated by a divider, e.g.:

/2944844:   open("/var/tomcat8/temp/opengrok8020746619175106447/opengrok_sort_1.tmp", O_WRONLY|O_CREAT|O_EXCL, 0666) = 1518
/2944844:   write(1518, "\005 .7FFFFC18\0\f . m a".., 8192) = 8192
/2944844:   write(1518, "0F a d i , a x i - i 2 s".., 8185) = 8185
/2944844:   write(1518, " a m i m o u s e7FFFFFFF".., 8185) = 8185
/2944844:   write(1518, " a t 9 1 - q i l _ a 9 2".., 8183) = 8183
/2944844:   write(1518, " b 1 p c m c i a7FFFFFFF".., 8192) = 8192
/2944844:   write(1518, "\n b k m _ a 87FFFFFFF\0".., 8192) = 8192
/2944844:   write(1518, "\0\f b r c m s m a c7FFF".., 8188) = 8188
/2944844:   write(1518, " c d e f b f 5 3 77FFFFF".., 8189) = 8189
/2944844:   write(1518, " c l k - u x 5 0 07FFFFF".., 8184) = 8184
/2944844:   write(1518, " c o n n e c t i o n7FFF".., 8184) = 8184
/2944844:   write(1518, " c s 5 5 3 6 _ m f g p t".., 8174) = 8174
/2944844:   write(1518, " d a t a _ b r e a k p o".., 8185) = 8185
/2944844:   write(1518, " d i v a _ d i d d7FFFFF".., 8192) = 8192
/2944844:   write(1518, " d s 1 _ c t r l7FFFFFFF".., 8182) = 8182
/2944844:   write(1518, " e h c i - p s 37FFFFFFF".., 8192) = 8192
/2944844:   write(1518, "\00E e x t a b l e _ 3 2".., 8185) = 8185
/2944844:   write(1518, " f i m c7FFFFFFF\010 f i".., 8177) = 8177
/2944844:   write(1518, " f t r a c e _ e v e n t".., 8184) = 8184
/2944844:   write(1518, " g p i o - p c a 9 5 3 x".., 8192) = 8192
...

[ahornace]

It might be caused by the WFSTCompletionLookup -> it needs temporary file. I thought it handled the removal by itself but maybe not. I think it is worth investigating.

[vladak]

Ok, marking as bug for now.

[vladak]

This is most probably it:

73      private static final String TEMP_DIR_PREFIX = "opengrok";
...
209      private WFSTCompletionLookup createWFST() throws IOException {
210          return new WFSTCompletionLookup(FSDirectory.open(Files.createTempDirectory(TEMP_DIR_PREFIX)), TEMP_DIR_PREFIX);
211      }

[vladak]

Looks like suggester needs a copy of IOUtils#removeRecursive() or FileUtilities#removeDirs().

[vladak]

Also, TEMP_DIR_PREFIX should probably be changed to better reflect what the directory is used for.

[ahornace]

Looks like suggester needs a copy of IOUtils#removeRecursive() or FileUtilities#removeDirs().

There is already Apache Commons IO as a dependency so no need to copy anything.

[vladak]

The other place that matches the temporary files with opengrok prefix and chronicle suffix is in ChronicleMapAdapter#resize() however that seems to be deleted:

121          Path tempFile = Files.createTempFile("opengrok", "chronicle");
122  
123          map.getAll(tempFile.toFile());
124  
125          String field = map.name();
126  
127          map.close();
128  
129          Files.delete(f.toPath());
130  
131          ChronicleMap<BytesRef, Integer> m = ChronicleMap.of(BytesRef.class, Integer.class)
132                  .name(field)
133                  .averageKeySize(newMapAvgKey)
134                  .entries(newMapSize)
135                  .keyReaderAndDataAccess(BytesRefSizedReader.INSTANCE, new BytesRefDataAccess())
136                  .createOrRecoverPersistedTo(f);
137  
138          m.putAll(tempFile.toFile());
139  
140          Files.delete(tempFile);

so there has to be some way how it remains there. In the log I can see exceptions like:

07-Aug-2018 20:06:39.098 SEVERE [pool-1629-thread-1] org.opengrok.suggest.Suggester.lambda$getRebuildRunnable$1 Could not rebuild suggester
 java.io.IOException: The file /opengrok/data/suggester/on11u4-clone/date_search_count.db the map is serialized from has unexpected length 0, probably corrupted. Data store s
ize is 6400
        at net.openhft.chronicle.map.ChronicleMapBuilder.openWithExistingFile(ChronicleMapBuilder.java:1780)
        at net.openhft.chronicle.map.ChronicleMapBuilder.createWithFile(ChronicleMapBuilder.java:1620)
        at net.openhft.chronicle.map.ChronicleMapBuilder.createPersistedTo(ChronicleMapBuilder.java:1549)
        at net.openhft.chronicle.map.ChronicleMapBuilder.createOrRecoverPersistedTo(ChronicleMapBuilder.java:1571)
        at net.openhft.chronicle.map.ChronicleMapBuilder.createOrRecoverPersistedTo(ChronicleMapBuilder.java:1560)
        at net.openhft.chronicle.map.ChronicleMapBuilder.createOrRecoverPersistedTo(ChronicleMapBuilder.java:1554)
        at org.opengrok.suggest.popular.impl.chronicle.ChronicleMapAdapter.resize(ChronicleMapAdapter.java:107)
        at org.opengrok.suggest.FieldWFSTCollection.initSearchCountMap(FieldWFSTCollection.java:282)
        at org.opengrok.suggest.FieldWFSTCollection.rebuild(FieldWFSTCollection.java:198)
        at org.opengrok.suggest.Suggester.lambda$getRebuildRunnable$1(Suggester.java:220)
        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)

which make the file to remain there.

[vladak]

The directories were fixed via cset 28949f5.

[peterlubs]

I have a variation of this problem, my tomcat temp directory is filing up with opengrok_suggester_wfst_input_XX.tmp files to the point I run out of disk space. Each one is large, almost 500 mb. I'm using the latest OpenGrok. The files in that directory never get cleaned up.

When I manually deleted all the files, I got this error in the logs: SEVERE: Could not initialize suggester data for java.io.EOFException at org.apache.lucene.store.InputStreamDataInput.readByte(InputStreamDataInput.java:35) at org.apache.lucene.store.DataInput.readInt(DataInput.java:101) at org.apache.lucene.codecs.CodecUtil.checkHeader(CodecUtil.java:194) at org.apache.lucene.util.fst.FST.(FST.java:288) at org.apache.lucene.util.fst.FST.(FST.java:274) at org.apache.lucene.search.suggest.fst.WFSTCompletionLookup.load(WFSTCompletionLookup.java:151) at org.apache.lucene.search.suggest.Lookup.load(Lookup.java:200) at org.opengrok.suggest.SuggesterProjectData.loadStoredWFST(SuggesterProjectData.java:210) at org.opengrok.suggest.SuggesterProjectData.loadStoredWFSTs(SuggesterProjectData.java:192) at org.opengrok.suggest.SuggesterProjectData.init(SuggesterProjectData.java:151) at org.opengrok.suggest.Suggester.lambda$getInitRunnable$1(Suggester.java:183) at java.util.concurrent.ForkJoinTask$AdaptedRunnableAction.exec(ForkJoinTask.java:1386)

For now, I'm going to delete files older than 7 days and watch the logs for errors.