I/O reactor status: STOPPED

[cadm-frank]

We've got our instances of fscrawler setup to make a run every 15 minutes, but one instance randomly fails and just doesn't do anything:

-- Logs begin at Tue 2021-09-21 02:31:32 CEST, end at Tue 2021-09-21 11:07:52 CEST. --
Sep 21 02:43:33 myserver fscrawler[14023]: Error while crawling /Volumes: Request cannot be executed; I/O reactor status: STOPPED
Sep 21 02:58:33 myserver fscrawler[14023]: Error while crawling /Volumes: Request cannot be executed; I/O reactor status: STOPPED
Sep 21 03:13:33 myserver fscrawler[14023]: Error while crawling /Volumes: Request cannot be executed; I/O reactor status: STOPPED
Sep 21 03:28:33 myserver fscrawler[14023]: Error while crawling /Volumes: Request cannot be executed; I/O reactor status: STOPPED
Sep 21 03:43:33 myserver fscrawler[14023]: Error while crawling /Volumes: Request cannot be executed; I/O reactor status: STOPPED

I have no idea what that is supposed to mean...

[dadoonet]

Interesting. Never saw this issue before.

I'd suspect that something is going wrong with the communication with Elasticsearch.

I saw this SOF discussion which also mentions Elasticsearch so may be I should try to add more logs or change some listeners...

Is that happening always with the same fscrawler instance? If so, could you turn it to debug mode while it is running?

Which FSCrawler version is it?

[dadoonet]

How do I enable debug mode while it's running?

If you are using FSCrawler 2.7, you should be able to change the log levels (https://fscrawler.readthedocs.io/en/fscrawler-2.7/admin/logger.html), by changing the config/log4j2.xml file:

<Properties>
   <Property name="LOG_LEVEL">debug</Property>
   <Property name="DOC_LEVEL">info</Property>
   <Property name="LOG_DIR">logs</Property>
</Properties>

It should be picked up after 30s.

[dadoonet]

BTW I'd recommend using Elasticsearch 7.14.1.

[cadm-frank]

We just saw this error again. Changing the logging to debug yielded this:

Sep 27 15:05:15 myserver fscrawler[2496]: Fs crawler is now waking up again...
Sep 27 15:05:15 myserver fscrawler[2496]: Fs crawler thread [myserver] is now running. Run #272...
Sep 27 15:05:16 myserver fscrawler[2496]: indexing [/Volumes] content
Sep 27 15:05:16 myserver fscrawler[2496]: Listing local files from /Volumes
Sep 27 15:05:16 myserver fscrawler[2496]: 4 local files found
Sep 27 15:05:16 myserver fscrawler[2496]: Error while crawling /Volumes: Request cannot be executed; I/O reactor status: STOPPED
Sep 27 15:05:17 myserver fscrawler[2496]: Full stacktrace
Sep 27 15:05:17 myserver fscrawler[2496]: java.lang.RuntimeException: Request cannot be executed; I/O reactor status: STOPPED
Sep 27 15:05:17 myserver fscrawler[2496]:         at org.elasticsearch.client.RestClient.extractAndWrapCause(RestClient.java:887) ~[elasticsearch-rest-client-7.10.1.jar:7.10.1]
Sep 27 15:05:17 myserver fscrawler[2496]:         at org.elasticsearch.client.RestClient.performRequest(RestClient.java:283) ~[elasticsearch-rest-client-7.10.1.jar:7.10.1]
Sep 27 15:05:17 myserver fscrawler[2496]:         at org.elasticsearch.client.RestClient.performRequest(RestClient.java:270) ~[elasticsearch-rest-client-7.10.1.jar:7.10.1]
Sep 27 15:05:17 myserver fscrawler[2496]:         at org.elasticsearch.client.RestHighLevelClient.internalPerformRequest(RestHighLevelClient.java:1632) ~[elasticsearch-rest-high-level-client-7.10.1.jar:7.10.1]
Sep 27 15:05:17 myserver fscrawler[2496]:         at org.elasticsearch.client.RestHighLevelClient.performRequest(RestHighLevelClient.java:1602) ~[elasticsearch-rest-high-level-client-7.10.1.jar:7.10.1]
Sep 27 15:05:17 myserver fscrawler[2496]:         at org.elasticsearch.client.RestHighLevelClient.performRequestAndParseEntity(RestHighLevelClient.java:1572) ~[elasticsearch-rest-high-level-client-7.10.1.jar:7.10.1]
Sep 27 15:05:17 myserver fscrawler[2496]:         at org.elasticsearch.client.RestHighLevelClient.search(RestHighLevelClient.java:1088) ~[elasticsearch-rest-high-level-client-7.10.1.jar:7.10.1]
Sep 27 15:05:17 myserver fscrawler[2496]:         at fr.pilato.elasticsearch.crawler.fs.client.v7.ElasticsearchClientV7.search(ElasticsearchClientV7.java:499) ~[fscrawler-elasticsearch-client-v7-2.7-SNAPSHOT.jar:?]
Sep 27 15:05:17 myserver fscrawler[2496]:         at fr.pilato.elasticsearch.crawler.fs.FsParserAbstract.getFileDirectory(FsParserAbstract.java:367) ~[fscrawler-core-2.7-SNAPSHOT.jar:?]
Sep 27 15:05:17 myserver fscrawler[2496]:         at fr.pilato.elasticsearch.crawler.fs.FsParserAbstract.addFilesRecursively(FsParserAbstract.java:246) ~[fscrawler-core-2.7-SNAPSHOT.jar:?]
Sep 27 15:05:17 myserver fscrawler[2496]:         at fr.pilato.elasticsearch.crawler.fs.FsParserAbstract.run(FsParserAbstract.java:160) [fscrawler-core-2.7-SNAPSHOT.jar:?]
Sep 27 15:05:17 myserver fscrawler[2496]:         at java.lang.Thread.run(Thread.java:832) [?:?]
Sep 27 15:05:17 myserver fscrawler[2496]: Caused by: java.lang.IllegalStateException: Request cannot be executed; I/O reactor status: STOPPED
Sep 27 15:05:17 myserver fscrawler[2496]:         at org.apache.http.util.Asserts.check(Asserts.java:46) ~[httpcore-4.4.14.jar:4.4.14]
Sep 27 15:05:17 myserver fscrawler[2496]:         at org.apache.http.impl.nio.client.CloseableHttpAsyncClientBase.ensureRunning(CloseableHttpAsyncClientBase.java:90) ~[httpasyncclient-4.1.4.jar:4.1.4]
Sep 27 15:05:17 myserver fscrawler[2496]:         at org.apache.http.impl.nio.client.InternalHttpAsyncClient.execute(InternalHttpAsyncClient.java:123) ~[httpasyncclient-4.1.4.jar:4.1.4]
Sep 27 15:05:17 myserver fscrawler[2496]:         at org.elasticsearch.client.RestClient.performRequest(RestClient.java:279) ~[elasticsearch-rest-client-7.10.1.jar:7.10.1]
Sep 27 15:05:17 myserver fscrawler[2496]:         ... 10 more
Sep 27 15:05:17 myserver fscrawler[2496]: Fs crawler is going to sleep for 15m

[dadoonet]

Hmmmm. I think I understand.
FSCrawler is running every x minutes in this scenario (which is expected) and it could happen that no new files are found.
This could happen for a long time and it could happen that the "connection" with Elasticsearch has been closed.

We should "retry" the connection when such an error is happening.

I'm going to move this discussion to an issue.

[dadoonet]

Issue opened at #1264