Skip to content

improve logging levels #2712

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
tballison merged 1 commit into from
Mar 24, 2026
Merged

improve logging levels #2712

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion tika-core/src/main/resources/pipes-fork-server-default-log4j2.xml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,7 @@
specific language governing permissions and limitations
under the License.
-->
<Configuration status="INFO">
<Configuration status="WARN">
<Appenders>
<Console name="console" target="SYSTEM_ERR">
<PatternLayout
Expand Down
4 changes: 2 additions & 2 deletions tika-pipes/tika-async-cli/src/main/java/org/apache/tika/async/cli/TikaAsyncCLI.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -95,10 +95,10 @@ public static void main(String[] args) throws Exception {
}

private static void processCommandLine(String[] args) throws Exception {
LOG.warn("processing args " + args.length);
LOG.debug("processing args " + args.length);
if (args.length == 1) {
if (args[0].endsWith(".json")) {
LOG.warn("processing args");
LOG.debug("processing args");
TikaJsonConfig tikaJsonConfig = TikaJsonConfig.load(Paths.get(args[0]));
Optional<PipesIterator> pipesIteratorOpt = PipesIteratorManager.load(TikaPluginManager.load(tikaJsonConfig), tikaJsonConfig);
if (pipesIteratorOpt.isEmpty()) {
Expand Down
14 changes: 9 additions & 5 deletions ...ipes/tika-pipes-core/src/main/java/org/apache/tika/pipes/core/PerClientServerManager.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -116,7 +116,11 @@ public int handleCrashAndGetExitCode() {
process.waitFor(1, TimeUnit.SECONDS);
if (!process.isAlive()) {
int exitValue = process.exitValue();
LOG.warn("clientId={}: process exited with code {}", clientId, exitValue);
if (exitValue == 0) {
LOG.info("clientId={}: process exited cleanly", clientId);
} else {
LOG.warn("clientId={}: process exited with code {}", clientId, exitValue);
}
return exitValue;
} else {
LOG.warn("clientId={}: process still running after crash", clientId);
Expand Down Expand Up @@ -193,7 +197,7 @@ private void startServer() throws IOException, InterruptedException, TimeoutExce
serverSocket.bind(new InetSocketAddress(InetAddress.getLoopbackAddress(), 0), 50);
port = serverSocket.getLocalPort();

LOG.info("clientId={}: starting server on port={}", clientId, port);
LOG.trace("clientId={}: starting server on port={}", clientId, port);

tmpDir = Files.createTempDirectory("pipes-server-" + clientId + "-");
ProcessBuilder pb = new ProcessBuilder(getCommandline());
Expand Down Expand Up @@ -341,7 +345,7 @@ private String[] getCommandline() throws IOException {
commandLine.add("-Djava.awt.headless=true");
}
if (hasExitOnOOM) {
LOG.warn("I notice that you have a jdk setting to exit/crash on OOM. If you run heavy external processes " +
LOG.info("I notice that you have a jdk setting to exit/crash on OOM. If you run heavy external processes " +
"like tesseract, this setting may result in orphaned processes which could be disastrous for performance.");
}
if (!hasLog4j) {
Expand All @@ -355,7 +359,7 @@ private String[] getCommandline() throws IOException {
commandLine.add(Integer.toString(port));
commandLine.add(tikaConfigPath.toAbsolutePath().toString());

LOG.info("clientId={}: commandline: {}", clientId, commandLine);
LOG.debug("clientId={}: commandline: {}", clientId, commandLine);
return commandLine.toArray(new String[0]);
}

Expand All @@ -365,7 +369,7 @@ private Path writeArgFile() throws IOException {
String normalizedClasspath = classpath.replace("\\", "/");
String content = "-cp\n\"" + normalizedClasspath + "\"\n";
Files.writeString(argFile, content, StandardCharsets.UTF_8);
LOG.info("clientId={}: wrote argfile with classpath ({} chars) to {}, content starts with: {}",
LOG.debug("clientId={}: wrote argfile with classpath ({} chars) to {}, content starts with: {}",
clientId, classpath.length(), argFile, content.substring(0, Math.min(100, content.length())));
return argFile;
}
Expand Down
4 changes: 2 additions & 2 deletions tika-pipes/tika-pipes-core/src/main/java/org/apache/tika/pipes/core/PipesClient.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -382,7 +382,7 @@ private PipesResult waitForServer(FetchEmitTuple t, IntermediateResult intermedi
throw new IOException("Unexpected message type from server: " + msg.type());
}
} catch (SocketTimeoutException e) {
LOG.warn("clientId={}: Socket timeout exception while waiting for server", pipesClientId, e);
LOG.info("clientId={}: Socket timeout exception while waiting for server", pipesClientId, e);
// Mark for restart - server is stuck on current request and needs to be restarted
serverManager.markServerForRestart();
closeConnection();
Expand Down Expand Up @@ -431,7 +431,7 @@ private PipesResult buildFatalResult(String id, EmitKey emitKey, PipesResult.RES
private void waitForStartup() throws IOException {
PipesMessage msg = PipesMessage.read(connectionTuple.input);
if (msg.type() == PipesMessageType.READY) {
LOG.debug("clientId={}: server ready", pipesClientId);
LOG.info("clientId={}: server successfully started", pipesClientId);
} else if (msg.type() == PipesMessageType.STARTUP_FAILED) {
// Send ACK for startup failure
PipesMessage.ack().write(connectionTuple.output);
Expand Down
4 changes: 2 additions & 2 deletions tika-pipes/tika-pipes-core/src/main/java/org/apache/tika/pipes/core/SharedServerManager.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -255,7 +255,7 @@ private void startServer() throws IOException, InterruptedException, TimeoutExce
new SecureRandom().nextBytes(token);
currentToken = token;

LOG.warn("\n\n" +
LOG.info("\n\n" +
" __ __ ___ _ ___ \n" +
" \\ \\ / / / _ \\ | | / _ \\ \n" +
" \\ V / | | | | | | | | | |\n" +
Expand Down Expand Up @@ -446,7 +446,7 @@ private String[] getCommandline() throws IOException {
commandLine.add("-Djava.awt.headless=true");
}
if (hasExitOnOOM) {
LOG.warn("ExitOnOutOfMemoryError/CrashOnOutOfMemoryError is set. In shared mode, " +
LOG.info("ExitOnOutOfMemoryError/CrashOnOutOfMemoryError is set. In shared mode, " +
"an OOM will kill the shared server, affecting all clients.");
}
if (!hasLog4j) {
Expand Down
11 changes: 10 additions & 1 deletion ...es/tika-pipes-core/src/main/java/org/apache/tika/pipes/core/server/ConnectionHandler.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@
import java.io.IOException;
import java.net.Socket;
import java.net.SocketException;
import java.net.SocketTimeoutException;
import java.time.Duration;
import java.time.Instant;
import java.util.Locale;
Expand Down Expand Up @@ -133,7 +134,15 @@ private void mainLoop() {

while (running) {
try {
PipesMessage msg = PipesMessage.read(input);
PipesMessage msg;
try {
msg = PipesMessage.read(input);
} catch (SocketTimeoutException e) {
// Socket timeout while idle is the normal inactivity shutdown path.
LOG.info("handlerId={}: socket timeout while waiting for task, closing connection",
handlerId);
return;
}
LOG.trace("handlerId={}: received message type={}", handlerId, msg.type());

switch (msg.type()) {
Expand Down
10 changes: 5 additions & 5 deletions tika-pipes/tika-pipes-core/src/main/java/org/apache/tika/pipes/core/server/EmitHandler.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -107,10 +107,10 @@ private PipesResult emit(String taskId, EmitKey emitKey,
emitter = emitterManager.getEmitter(emitKey.getEmitterId());
} catch (org.apache.tika.pipes.api.emitter.EmitterNotFoundException e) {
String noEmitterMsg = getNoEmitterMsg(taskId);
LOG.warn(noEmitterMsg);
LOG.info(noEmitterMsg);
return new PipesResult(PipesResult.RESULT_STATUS.EMITTER_NOT_FOUND, noEmitterMsg);
} catch (IOException | TikaException e) {
LOG.warn("Couldn't initialize emitter for task id '" + taskId + "'", e);
LOG.info("Couldn't initialize emitter for task id '" + taskId + "'", e);
return new PipesResult(PipesResult.RESULT_STATUS.EMITTER_INITIALIZATION_EXCEPTION, ExceptionUtils.getStackTrace(e));
}
try {
Expand All @@ -124,7 +124,7 @@ private PipesResult emit(String taskId, EmitKey emitKey,
emitter.emit(emitKey.getEmitKey(), parseData.getMetadataList(), parseContext);
}
} catch (IOException e) {
LOG.warn("emit exception", e);
LOG.info("emit exception", e);
String msg = ExceptionUtils.getStackTrace(e);
//for now, we're hiding the parse exception if there was also an emit exception
return new PipesResult(PipesResult.RESULT_STATUS.EMIT_EXCEPTION, msg);
Expand All @@ -134,7 +134,7 @@ private PipesResult emit(String taskId, EmitKey emitKey,
try {
passbackFilter.filter(parseData.metadataList);
} catch (TikaException e) {
LOG.warn("problem filtering for pass back", e);
LOG.info("problem filtering for pass back", e);
}
if (StringUtils.isBlank(parseExceptionStack)) {
return new PipesResult(PipesResult.RESULT_STATUS.EMIT_SUCCESS_PASSBACK, new EmitDataImpl(emitKey.getEmitKey(), parseData.metadataList));
Expand Down Expand Up @@ -250,7 +250,7 @@ private void filterMetadata(MetadataListAndEmbeddedBytes parseData, ParseContext
try {
parseData.filter(filter, parseContext);
} catch (TikaException e) {
LOG.warn("failed to filter metadata list", e);
LOG.info("failed to filter metadata list", e);
}
}

Expand Down
4 changes: 2 additions & 2 deletions tika-pipes/tika-pipes-core/src/main/java/org/apache/tika/pipes/core/server/FetchHandler.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -60,10 +60,10 @@ private FetcherOrResult getFetcher(FetchEmitTuple t) {
return new FetcherOrResult(fetcherManager.getFetcher(t.getFetchKey().getFetcherId()), null);
} catch (IllegalArgumentException e) {
String noFetcherMsg = getNoFetcherMsg(t.getFetchKey().getFetcherId());
LOG.warn(noFetcherMsg);
LOG.info(noFetcherMsg);
return new FetcherOrResult(null, new PipesResult(PipesResult.RESULT_STATUS.FETCHER_NOT_FOUND, noFetcherMsg));
} catch (IOException | TikaException e) {
LOG.warn("Couldn't initialize fetcher for fetch id={}", t.getId(), e);
LOG.info("Couldn't initialize fetcher for fetch id={}", t.getId(), e);
return new FetcherOrResult(null, new PipesResult(PipesResult.RESULT_STATUS.FETCHER_INITIALIZATION_EXCEPTION,
ExceptionUtils.getStackTrace(e)));
}
Expand Down
22 changes: 11 additions & 11 deletions tika-pipes/tika-pipes-core/src/main/java/org/apache/tika/pipes/core/server/ParseHandler.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -142,7 +142,7 @@ private void _preParse(FetchEmitTuple t, TikaInputStream tis, Metadata metadata,
parseContext.set(SkipContainerDocumentDigest.class,
SkipContainerDocumentDigest.INSTANCE);
} catch (IOException e) {
LOG.warn("problem digesting: " + t.getId(), e);
LOG.info("problem digesting: " + t.getId(), e);
}
}
// Signal to detectors that parsing will follow, so they can prepare
Expand All @@ -154,7 +154,7 @@ private void _preParse(FetchEmitTuple t, TikaInputStream tis, Metadata metadata,
EmbeddedDocumentUtil.normalizeMediaType(mt.toString()));
metadata.set(TikaCoreProperties.CONTENT_TYPE_PARSER_OVERRIDE, mt.toString());
} catch (IOException e) {
LOG.warn("problem detecting: " + t.getId(), e);
LOG.info("problem detecting: " + t.getId(), e);
}
UnpackConfig unpackConfig = parseContext.get(UnpackConfig.class);
if (unpackConfig != null &&
Expand All @@ -163,7 +163,7 @@ private void _preParse(FetchEmitTuple t, TikaInputStream tis, Metadata metadata,
try (InputStream is = Files.newInputStream(tis.getPath())) {
unpackHandler.add(0, metadata, is);
} catch (IOException e) {
LOG.warn("problem reading source file into embedded document byte store", e);
LOG.info("problem reading source file into embedded document byte store", e);
}
}
}
Expand Down Expand Up @@ -201,14 +201,14 @@ public List<Metadata> parseRecursive(FetchEmitTuple fetchEmitTuple,
try {
recursiveParserWrapper.parse(stream, handler, metadata, parseContext);
} catch (SAXException e) {
LOG.warn("sax problem:" + fetchEmitTuple.getId(), e);
LOG.info("sax problem:" + fetchEmitTuple.getId(), e);
} catch (EncryptedDocumentException e) {
LOG.warn("encrypted document:" + fetchEmitTuple.getId(), e);
LOG.info("encrypted document:" + fetchEmitTuple.getId(), e);
} catch (SecurityException e) {
LOG.warn("security exception:" + fetchEmitTuple.getId(), e);
LOG.info("security exception:" + fetchEmitTuple.getId(), e);
throw e;
} catch (Exception e) {
LOG.warn("parse exception: " + fetchEmitTuple.getId(), e);
LOG.info("parse exception: " + fetchEmitTuple.getId(), e);
} finally {
if (LOG.isTraceEnabled()) {
LOG.trace("timer -- parse only time: {} ms", System.currentTimeMillis() - start);
Expand Down Expand Up @@ -242,19 +242,19 @@ public List<Metadata> parseConcatenated(FetchEmitTuple fetchEmitTuple,
autoDetectParser.parse(stream, handler, metadata, parseContext);
} catch (SAXException e) {
containerException = ExceptionUtils.getStackTrace(e);
LOG.warn("sax problem:" + fetchEmitTuple.getId(), e);
LOG.info("sax problem:" + fetchEmitTuple.getId(), e);
if (WriteLimitReachedException.isWriteLimitReached(e)) {
writeLimitReached = true;
}
} catch (EncryptedDocumentException e) {
containerException = ExceptionUtils.getStackTrace(e);
LOG.warn("encrypted document:" + fetchEmitTuple.getId(), e);
LOG.info("encrypted document:" + fetchEmitTuple.getId(), e);
} catch (SecurityException e) {
LOG.warn("security exception:" + fetchEmitTuple.getId(), e);
LOG.info("security exception:" + fetchEmitTuple.getId(), e);
throw e;
} catch (Exception e) {
containerException = ExceptionUtils.getStackTrace(e);
LOG.warn("parse exception: " + fetchEmitTuple.getId(), e);
LOG.info("parse exception: " + fetchEmitTuple.getId(), e);
} finally {
metadata.add(TikaCoreProperties.TIKA_CONTENT, handler.toString());
metadata.set(TikaCoreProperties.TIKA_CONTENT_HANDLER_TYPE,
Expand Down
18 changes: 17 additions & 1 deletion tika-pipes/tika-pipes-core/src/main/java/org/apache/tika/pipes/core/server/PipesServer.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@
import java.net.InetAddress;
import java.net.InetSocketAddress;
import java.net.Socket;
import java.net.SocketTimeoutException;
import java.nio.charset.StandardCharsets;
import java.nio.file.Path;
import java.nio.file.Paths;
Expand Down Expand Up @@ -319,7 +320,22 @@ public void mainLoop() {
//main loop
try {
while (true) {
PipesMessage msg = PipesMessage.read(input);
PipesMessage msg;
try {
msg = PipesMessage.read(input);
} catch (SocketTimeoutException e) {
// Socket timeout while idle is the normal inactivity shutdown path.
// Exit cleanly — PipesClient will restart the server if needed.
LOG.info("pipesClientId={}: socket timeout while waiting for task, shutting down",
pipesClientId);
try {
close();
} catch (Exception ex) {
//swallow
}
System.exit(0);
return; // unreachable, but needed for compilation
}
LOG.trace("pipesClientId={}: received message type={}", pipesClientId, msg.type());

switch (msg.type()) {
Expand Down
4 changes: 2 additions & 2 deletions tika-pipes/tika-pipes-core/src/main/java/org/apache/tika/pipes/core/server/PipesWorker.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -560,7 +560,7 @@ protected ParseDataOrPipesResult parseFromTuple() throws TikaException, Interrup
try {
localContext = setupParseContext();
} catch (IOException e) {
LOG.warn("fetcher initialization exception id={}", fetchEmitTuple.getId(), e);
LOG.info("fetcher initialization exception id={}", fetchEmitTuple.getId(), e);
return new ParseDataOrPipesResult(null,
new PipesResult(PipesResult.RESULT_STATUS.FETCHER_INITIALIZATION_EXCEPTION, ExceptionUtils.getStackTrace(e)));
}
Expand All @@ -587,7 +587,7 @@ protected ParseDataOrPipesResult parseFromTuple() throws TikaException, Interrup
LOG.error("security exception id={}", fetchEmitTuple.getId(), e);
throw e;
} catch (TikaException | IOException e) {
LOG.warn("fetch exception id={}", fetchEmitTuple.getId(), e);
LOG.info("fetch exception id={}", fetchEmitTuple.getId(), e);
return new ParseDataOrPipesResult(null,
new PipesResult(PipesResult.RESULT_STATUS.UNSPECIFIED_CRASH, ExceptionUtils.getStackTrace(e)));
}
Expand Down
2 changes: 1 addition & 1 deletion tika-pipes/tika-pipes-core/src/main/resources/pipes-fork-server-default-log4j2.xml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,7 @@
specific language governing permissions and limitations
under the License.
-->
<Configuration status="INFO">
<Configuration status="WARN">
<Appenders>
<Console name="console" target="SYSTEM_ERR">
<PatternLayout
Expand Down
Loading