From 24611ea42e0cd9927768acda14efc6bcaa568874 Mon Sep 17 00:00:00 2001 From: Cezar Leahu Date: Tue, 13 Nov 2018 15:22:38 +0000 Subject: [PATCH] ATS-176 : Log improvements with Slf4j --- .../AlfrescoPdfRendererController.java | 20 ++-- .../transformer/ImageMagickController.java | 11 +- .../transformer/LibreOfficeController.java | 11 +- .../executors/JodConverterSharedInstance.java | 72 +++++------- .../executors/LibreOfficeJavaExecutor.java | 6 +- alfresco-docker-tika/pom.xml | 11 -- .../alfresco/transformer/TikaController.java | 10 +- .../AbstractTransformerController.java | 104 ++++++++++++------ .../transformer/TransformController.java | 38 +++---- .../executors/CommandExecutor.java | 4 +- .../transformer/logging/LogEntry.java | 6 +- .../probes/ProbeTestTransform.java | 11 +- .../transformer/AbstractHttpRequestTest.java | 2 +- .../AbstractTransformerControllerTest.java | 2 +- pom.xml | 16 --- 15 files changed, 160 insertions(+), 164 deletions(-) diff --git a/alfresco-docker-alfresco-pdf-renderer/src/main/java/org/alfresco/transformer/AlfrescoPdfRendererController.java b/alfresco-docker-alfresco-pdf-renderer/src/main/java/org/alfresco/transformer/AlfrescoPdfRendererController.java index 48ec051d..060fcec5 100644 --- a/alfresco-docker-alfresco-pdf-renderer/src/main/java/org/alfresco/transformer/AlfrescoPdfRendererController.java +++ b/alfresco-docker-alfresco-pdf-renderer/src/main/java/org/alfresco/transformer/AlfrescoPdfRendererController.java @@ -28,8 +28,8 @@ import javax.servlet.http.HttpServletRequest; import org.alfresco.transformer.executors.PdfRendererCommandExecutor; import org.alfresco.transformer.logging.LogEntry; import org.alfresco.transformer.probes.ProbeTestTransform; -import org.apache.commons.logging.Log; -import org.apache.commons.logging.LogFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.core.io.Resource; import org.springframework.http.MediaType; @@ -62,7 +62,7 @@ import org.springframework.web.multipart.MultipartFile; @Controller public class AlfrescoPdfRendererController extends AbstractTransformerController { - private static final Log logger = LogFactory.getLog(AlfrescoPdfRendererController.class); + private static final Logger logger = LoggerFactory.getLogger(AlfrescoPdfRendererController.class); @Autowired private PdfRendererCommandExecutor commandExecutor; @@ -92,8 +92,8 @@ public class AlfrescoPdfRendererController extends AbstractTransformerController public ProbeTestTransform getProbeTestTransform() { // See the Javadoc on this method and Probes.md for the choice of these values. - return new ProbeTestTransform(this, logger, "quick.pdf", "quick.png", - 7455, 1024, 150, 10240, 60*20+1, 60*15-15) + return new ProbeTestTransform(this, "quick.pdf", "quick.png", + 7455, 1024, 150, 10240, 60 * 20 + 1, 60 * 15 - 15) { @Override protected void executeTransformCommand(File sourceFile, File targetFile) @@ -107,6 +107,9 @@ public class AlfrescoPdfRendererController extends AbstractTransformerController public void processTransform(File sourceFile, File targetFile, Map transformOptions, Long timeout) { + logger.debug("Processing request with: sourceFile '{}', targetFile '{}', transformOptions" + + " '{}', timeout {} ms", sourceFile, targetFile, transformOptions, timeout); + String page = transformOptions.get("page"); Integer pageOption = page == null ? null : Integer.parseInt(page); @@ -153,7 +156,7 @@ public class AlfrescoPdfRendererController extends AbstractTransformerController String options = buildTransformOptions(page, width, height, allowEnlargement, maintainAspectRatio); commandExecutor.run(options, sourceFile, targetFile, timeout); - + final ResponseEntity body = createAttachment(targetFilename, targetFile); LogEntry.setTargetSize(targetFile.length()); long time = LogEntry.setStatusCodeAndMessage(OK.value(), "Success"); @@ -162,9 +165,8 @@ public class AlfrescoPdfRendererController extends AbstractTransformerController return body; } - - private static String buildTransformOptions(Integer page,Integer width,Integer height,Boolean - allowEnlargement,Boolean maintainAspectRatio) + private static String buildTransformOptions(Integer page, Integer width, Integer height, Boolean + allowEnlargement, Boolean maintainAspectRatio) { StringJoiner args = new StringJoiner(" "); if (width != null && width >= 0) diff --git a/alfresco-docker-imagemagick/src/main/java/org/alfresco/transformer/ImageMagickController.java b/alfresco-docker-imagemagick/src/main/java/org/alfresco/transformer/ImageMagickController.java index 520e6587..c1b5e7f1 100644 --- a/alfresco-docker-imagemagick/src/main/java/org/alfresco/transformer/ImageMagickController.java +++ b/alfresco-docker-imagemagick/src/main/java/org/alfresco/transformer/ImageMagickController.java @@ -25,11 +25,11 @@ import java.util.Map; import javax.servlet.http.HttpServletRequest; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import org.alfresco.transformer.executors.ImageMagickCommandExecutor; import org.alfresco.transformer.logging.LogEntry; import org.alfresco.transformer.probes.ProbeTestTransform; -import org.apache.commons.logging.Log; -import org.apache.commons.logging.LogFactory; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.core.io.Resource; import org.springframework.http.MediaType; @@ -64,7 +64,7 @@ import org.springframework.web.multipart.MultipartFile; @Controller public class ImageMagickController extends AbstractTransformerController { - private static final Log logger = LogFactory.getLog(ImageMagickController.class); + private static final Logger logger = LoggerFactory.getLogger(ImageMagickController.class); @Autowired private ImageMagickCommandExecutor commandExecutor; @@ -94,7 +94,7 @@ public class ImageMagickController extends AbstractTransformerController public ProbeTestTransform getProbeTestTransform() { // See the Javadoc on this method and Probes.md for the choice of these values. - return new ProbeTestTransform(this, logger, "quick.jpg", "quick.png", + return new ProbeTestTransform(this, "quick.jpg", "quick.png", 35593, 1024, 150, 1024, 60*15+1,60*15) { @Override @@ -189,6 +189,9 @@ public class ImageMagickController extends AbstractTransformerController public void processTransform(final File sourceFile, final File targetFile, final Map transformOptions, final Long timeout) { + logger.debug("Processing request with: sourceFile '{}', targetFile '{}', transformOptions" + + " '{}', timeout {} ms", sourceFile, targetFile, transformOptions, timeout); + final String options = OptionsBuilder .builder() .withStartPage(transformOptions.get("startPage")) diff --git a/alfresco-docker-libreoffice/src/main/java/org/alfresco/transformer/LibreOfficeController.java b/alfresco-docker-libreoffice/src/main/java/org/alfresco/transformer/LibreOfficeController.java index 872efe47..a6cf8b41 100644 --- a/alfresco-docker-libreoffice/src/main/java/org/alfresco/transformer/LibreOfficeController.java +++ b/alfresco-docker-libreoffice/src/main/java/org/alfresco/transformer/LibreOfficeController.java @@ -27,8 +27,8 @@ import javax.servlet.http.HttpServletRequest; import org.alfresco.transformer.executors.LibreOfficeJavaExecutor; import org.alfresco.transformer.logging.LogEntry; import org.alfresco.transformer.probes.ProbeTestTransform; -import org.apache.commons.logging.Log; -import org.apache.commons.logging.LogFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.core.io.Resource; import org.springframework.http.MediaType; @@ -62,7 +62,7 @@ import org.springframework.web.multipart.MultipartFile; @Controller public class LibreOfficeController extends AbstractTransformerController { - private static final Log logger = LogFactory.getLog(LibreOfficeController.class); + private static final Logger logger = LoggerFactory.getLogger(LibreOfficeController.class); @Autowired private LibreOfficeJavaExecutor javaExecutor; @@ -92,7 +92,7 @@ public class LibreOfficeController extends AbstractTransformerController public ProbeTestTransform getProbeTestTransform() { // See the Javadoc on this method and Probes.md for the choice of these values. - return new ProbeTestTransform(this, logger, "quick.doc", "quick.pdf", + return new ProbeTestTransform(this, "quick.doc", "quick.pdf", 11817, 1024, 150, 10240, 60*30+1, 60*15+20) { @Override @@ -131,6 +131,9 @@ public class LibreOfficeController extends AbstractTransformerController public void processTransform(File sourceFile, File targetFile, Map transformOptions, Long timeout) { + logger.debug("Processing request with: sourceFile '{}', targetFile '{}', transformOptions" + + " '{}', timeout {} ms", sourceFile, targetFile, transformOptions, timeout); + javaExecutor.call(sourceFile, targetFile); } } diff --git a/alfresco-docker-libreoffice/src/main/java/org/alfresco/transformer/executors/JodConverterSharedInstance.java b/alfresco-docker-libreoffice/src/main/java/org/alfresco/transformer/executors/JodConverterSharedInstance.java index 4bc63ca2..e4188d16 100644 --- a/alfresco-docker-libreoffice/src/main/java/org/alfresco/transformer/executors/JodConverterSharedInstance.java +++ b/alfresco-docker-libreoffice/src/main/java/org/alfresco/transformer/executors/JodConverterSharedInstance.java @@ -37,11 +37,11 @@ import javax.annotation.PostConstruct; import javax.annotation.PreDestroy; import org.alfresco.error.AlfrescoRuntimeException; -import org.apache.commons.logging.Log; -import org.apache.commons.logging.LogFactory; import org.artofsolving.jodconverter.office.DefaultOfficeManagerConfiguration; import org.artofsolving.jodconverter.office.OfficeException; import org.artofsolving.jodconverter.office.OfficeManager; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; ///////// THIS FILE WAS A COPY OF THE CODE IN alfresco-repository ///////////// @@ -53,7 +53,7 @@ import org.artofsolving.jodconverter.office.OfficeManager; */ public class JodConverterSharedInstance implements JodConverter { - private static final Log logger = LogFactory.getLog(JodConverterSharedInstance.class); + private static final Logger logger = LoggerFactory.getLogger(JodConverterSharedInstance.class); private OfficeManager officeManager; private boolean isAvailable = false; @@ -137,10 +137,7 @@ public class JodConverterSharedInstance implements JodConverter { // Logging this as an error as this property would prevent JodConverter & therefore // OOo from starting as specified - if (logger.isErrorEnabled()) - { - logger.error("Unparseable value for property '" + sys + ".portNumbers': " + s); - } + logger.error("Unparseable value for property '{}.portNumbers': {}", sys, s); // We'll not rethrow the exception, instead allowing the problem to be picked up // when the OOoJodConverter subsystem is started. } @@ -268,10 +265,7 @@ public class JodConverterSharedInstance implements JodConverter } catch (NumberFormatException nfe) { - if (logger.isDebugEnabled()) - { - logger.debug("Cannot parse numerical value from " + string); - } + logger.debug("Cannot parse numerical value from {}", string); } return null; } @@ -300,20 +294,20 @@ public class JodConverterSharedInstance implements JodConverter if (logger.isDebugEnabled()) { logger.debug("JodConverter settings (null settings will be replaced by jodconverter defaults):"); - logger.debug(" officeHome = " + officeHome); - logger.debug(" enabled = " + isEnabled()); - logger.debug(" portNumbers = " + getString(portNumbers)); - logger.debug(" ooo.exe = " + deprecatedOooExe); - logger.debug(" ooo.enabled = " + deprecatedOooEnabled); - logger.debug(" ooo.port = " + getString(deprecatedOooPortNumbers)); - logger.debug(" jodConverter.enabled = " + enabled); - logger.debug(" jodconverter.portNumbers = " + getString(this.portNumbers)); - logger.debug(" jodconverter.officeHome = " + this.officeHome); - logger.debug(" jodconverter.maxTasksPerProcess = " + maxTasksPerProcess); - logger.debug(" jodconverter.taskExecutionTimeout = " + taskExecutionTimeout); - logger.debug(" jodconverter.taskQueueTimeout = " + taskQueueTimeout); - logger.debug(" jodconverter.connectTimeout = " + connectTimeout); - logger.debug(" jodconverter.url = " + url); + logger.debug(" officeHome = {}", officeHome); + logger.debug(" enabled = {}", isEnabled()); + logger.debug(" portNumbers = {}", getString(portNumbers)); + logger.debug(" ooo.exe = {}", deprecatedOooExe); + logger.debug(" ooo.enabled = {}", deprecatedOooEnabled); + logger.debug(" ooo.port = {}", getString(deprecatedOooPortNumbers)); + logger.debug(" jodConverter.enabled = {}", enabled); + logger.debug(" jodconverter.portNumbers = {}", getString(this.portNumbers)); + logger.debug(" jodconverter.officeHome = {}", this.officeHome); + logger.debug(" jodconverter.maxTasksPerProcess = {}", maxTasksPerProcess); + logger.debug(" jodconverter.taskExecutionTimeout = {}", taskExecutionTimeout); + logger.debug(" jodconverter.taskQueueTimeout = {}", taskQueueTimeout); + logger.debug(" jodconverter.connectTimeout = {}", connectTimeout); + logger.debug(" jodconverter.url = {}", url); } // Only start the JodConverter instance(s) if the subsystem is enabled. @@ -362,33 +356,25 @@ public class JodConverterSharedInstance implements JodConverter officeManager = defaultOfficeMgrConfig.buildOfficeManager(); officeManager.start(); } - catch (IllegalStateException isx) + catch (IllegalStateException e) { - if (logger.isErrorEnabled()) - { - logger.error("Unable to pre-initialise JodConverter library. " - + "The following error is shown for informational purposes only.", isx); - } + logger.error("Unable to pre-initialise JodConverter library. " + + "The following error is shown for informational purposes only.", e); return; } - catch (OfficeException ox) + catch (OfficeException e) { - if (logger.isErrorEnabled()) - { - logger.error("Unable to start JodConverter library. " - + "The following error is shown for informational purposes only.", ox); - } + logger.error("Unable to start JodConverter library. " + + "The following error is shown for informational purposes only.", e); // We need to let it continue (comment-out return statement) even if an error occurs. See MNT-13706 and associated issues. //return; } - catch (Exception x) + catch (Exception e) { - if (logger.isErrorEnabled()) - { - logger.error("Unexpected error in configuring or starting the JodConverter library." - + "The following error is shown for informational purposes only.", x); - } + logger.error( + "Unexpected error in configuring or starting the JodConverter library." + + "The following error is shown for informational purposes only.", e); return; } } diff --git a/alfresco-docker-libreoffice/src/main/java/org/alfresco/transformer/executors/LibreOfficeJavaExecutor.java b/alfresco-docker-libreoffice/src/main/java/org/alfresco/transformer/executors/LibreOfficeJavaExecutor.java index 052899c4..f147800b 100644 --- a/alfresco-docker-libreoffice/src/main/java/org/alfresco/transformer/executors/LibreOfficeJavaExecutor.java +++ b/alfresco-docker-libreoffice/src/main/java/org/alfresco/transformer/executors/LibreOfficeJavaExecutor.java @@ -9,8 +9,8 @@ import java.io.IOException; import javax.annotation.PostConstruct; import org.alfresco.transformer.exceptions.TransformException; -import org.apache.commons.logging.Log; -import org.apache.commons.logging.LogFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import org.apache.pdfbox.pdmodel.PDDocument; import org.apache.pdfbox.pdmodel.PDPage; import org.apache.pdfbox.pdmodel.PDPageContentStream; @@ -28,7 +28,7 @@ import com.sun.star.task.ErrorCodeIOException; @Component public class LibreOfficeJavaExecutor implements JavaExecutor { - private static final Log logger = LogFactory.getLog(LibreOfficeJavaExecutor.class); + private static final Logger logger = LoggerFactory.getLogger(LibreOfficeJavaExecutor.class); private static final int JODCONVERTER_TRANSFORMATION_ERROR_CODE = 3088; private static final String OFFICE_HOME = "/opt/libreoffice5.4"; diff --git a/alfresco-docker-tika/pom.xml b/alfresco-docker-tika/pom.xml index 8fd1799b..a48aa4c1 100644 --- a/alfresco-docker-tika/pom.xml +++ b/alfresco-docker-tika/pom.xml @@ -49,17 +49,6 @@ alfresco-data-model - - org.slf4j - slf4j-api - 1.7.24 - - - org.slf4j - slf4j-log4j12 - 1.7.25 - - org.apache.tika diff --git a/alfresco-docker-tika/src/main/java/org/alfresco/transformer/TikaController.java b/alfresco-docker-tika/src/main/java/org/alfresco/transformer/TikaController.java index f4694b5b..19ab6142 100644 --- a/alfresco-docker-tika/src/main/java/org/alfresco/transformer/TikaController.java +++ b/alfresco-docker-tika/src/main/java/org/alfresco/transformer/TikaController.java @@ -37,8 +37,8 @@ import org.alfresco.transformer.exceptions.TransformException; import org.alfresco.transformer.executors.TikaJavaExecutor; import org.alfresco.transformer.logging.LogEntry; import org.alfresco.transformer.probes.ProbeTestTransform; -import org.apache.commons.logging.Log; -import org.apache.commons.logging.LogFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.core.io.Resource; import org.springframework.http.MediaType; @@ -72,7 +72,7 @@ import org.springframework.web.multipart.MultipartFile; @Controller public class TikaController extends AbstractTransformerController { - private static final Log logger = LogFactory.getLog(TikaController.class); + private static final Logger logger = LoggerFactory.getLogger(TikaController.class); @Autowired private TikaJavaExecutor javaExecutor; @@ -103,7 +103,7 @@ public class TikaController extends AbstractTransformerController { // See the Javadoc on this method and Probes.md for the choice of these values. // the livenessPercentage is a little large as Tika does tend to suffer from slow transforms that class with a gc. - return new ProbeTestTransform(this, logger, "quick.pdf", "quick.txt", + return new ProbeTestTransform(this, "quick.pdf", "quick.txt", 60, 16, 400, 10240, 60 * 30 + 1, 60 * 15 + 20) { @Override @@ -160,6 +160,8 @@ public class TikaController extends AbstractTransformerController public void processTransform(File sourceFile, File targetFile, Map transformOptions, Long timeout) { + logger.debug("Processing request with: sourceFile '{}', targetFile '{}', transformOptions" + + " '{}', timeout {} ms", sourceFile, targetFile, transformOptions, timeout); String transform = transformOptions.get("transform"); Boolean includeContents = stringToBoolean("includeContents"); diff --git a/alfresco-transformer-base/src/main/java/org/alfresco/transformer/AbstractTransformerController.java b/alfresco-transformer-base/src/main/java/org/alfresco/transformer/AbstractTransformerController.java index 0c67dc30..14de0678 100644 --- a/alfresco-transformer-base/src/main/java/org/alfresco/transformer/AbstractTransformerController.java +++ b/alfresco-transformer-base/src/main/java/org/alfresco/transformer/AbstractTransformerController.java @@ -44,8 +44,8 @@ import org.alfresco.transformer.exceptions.TransformException; import org.alfresco.transformer.logging.LogEntry; import org.alfresco.transformer.model.FileRefResponse; import org.alfresco.util.TempFileProvider; -import org.apache.commons.logging.Log; -import org.apache.commons.logging.LogFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import org.springframework.beans.factory.annotation.Autowired; import org.springframework.core.io.Resource; import org.springframework.http.HttpHeaders; @@ -91,7 +91,7 @@ import org.springframework.web.client.HttpClientErrorException; */ public abstract class AbstractTransformerController implements TransformController { - private static final Log logger = LogFactory.getLog(AbstractTransformerController.class); + private static final Logger logger = LoggerFactory.getLogger(AbstractTransformerController.class); @Autowired private AlfrescoSharedFileStoreClient alfrescoSharedFileStoreClient; @@ -114,6 +114,8 @@ public abstract class AbstractTransformerController implements TransformControll public ResponseEntity transform(@RequestBody TransformRequest request, @RequestParam(value = "timeout", required = false) Long timeout) { + logger.info("Received {}, timeout {} ms", request, timeout); + final TransformReply reply = new TransformReply(); reply.setRequestId(request.getRequestId()); reply.setSourceReference(request.getSourceReference()); @@ -127,8 +129,8 @@ public abstract class AbstractTransformerController implements TransformControll reply.setErrorDetails(errors.getAllErrors().stream().map(Object::toString) .collect(Collectors.joining(", "))); - return new ResponseEntity<>(reply, - HttpStatus.valueOf(reply.getStatus())); + logger.error("Invalid request, sending {}", reply); + return new ResponseEntity<>(reply, HttpStatus.valueOf(reply.getStatus())); } // Load the source file @@ -137,51 +139,56 @@ public abstract class AbstractTransformerController implements TransformControll { sourceFile = loadSourceFile(request.getSourceReference()); } - catch (TransformException te) + catch (TransformException e) { - reply.setStatus(te.getStatusCode()); - reply .setErrorDetails("Failed at reading the source file. " + te.getMessage()); + reply.setStatus(e.getStatusCode()); + reply.setErrorDetails(messageWithCause("Failed at reading the source file", e)); + logger.error("Failed to load source file (TransformException), sending " + reply, e); return new ResponseEntity<>(reply, HttpStatus.valueOf(reply.getStatus())); } - catch (HttpClientErrorException hcee) + catch (HttpClientErrorException e) { - reply.setStatus(hcee.getStatusCode().value()); - reply .setErrorDetails("Failed at reading the source file. " + hcee.getMessage()); + reply.setStatus(e.getStatusCode().value()); + reply.setErrorDetails(messageWithCause("Failed at reading the source file", e)); + logger.error("Failed to load source file (HttpClientErrorException), sending " + + reply, e); return new ResponseEntity<>(reply, HttpStatus.valueOf(reply.getStatus())); } catch (Exception e) { reply.setStatus(INTERNAL_SERVER_ERROR.value()); - reply.setErrorDetails("Failed at reading the source file. " + e.getMessage()); + reply.setErrorDetails(messageWithCause("Failed at reading the source file", e)); + logger.error("Failed to load source file (Exception), sending " + reply, e); return new ResponseEntity<>(reply, HttpStatus.valueOf(reply.getStatus())); } // Create local temp target file in order to run the transformation - String targetFilename = createTargetFileName(sourceFile.getName(), + final String targetFilename = createTargetFileName(sourceFile.getName(), request.getTargetExtension()); - File targetFile = buildFile(targetFilename); + final File targetFile = buildFile(targetFilename); // Run the transformation try { - processTransform(sourceFile, targetFile, - request.getTransformRequestOptions(), timeout); + processTransform(sourceFile, targetFile, request.getTransformRequestOptions(), timeout); } - catch (TransformException te) + catch (TransformException e) { - reply.setStatus(te.getStatusCode()); - reply.setErrorDetails("Failed at processing transformation. " + te.getMessage()); + reply.setStatus(e.getStatusCode()); + reply.setErrorDetails(messageWithCause("Failed at processing transformation", e)); + logger.error("Failed to perform transform (TransformException), sending " + reply, e); return new ResponseEntity<>(reply, HttpStatus.valueOf(reply.getStatus())); } catch (Exception e) { reply.setStatus(INTERNAL_SERVER_ERROR.value()); - reply.setErrorDetails("Failed at processing transformation. " + e.getMessage()); + reply.setErrorDetails(messageWithCause("Failed at processing transformation", e)); + logger.error("Failed to perform transform (Exception), sending " + reply, e); return new ResponseEntity<>(reply, HttpStatus.valueOf(reply.getStatus())); } @@ -191,25 +198,29 @@ public abstract class AbstractTransformerController implements TransformControll { targetRef = alfrescoSharedFileStoreClient.saveFile(targetFile); } - catch (TransformException te) + catch (TransformException e) { - reply.setStatus(te.getStatusCode()); - reply.setErrorDetails("Failed at writing the transformed file. " + te.getMessage()); + reply.setStatus(e.getStatusCode()); + reply.setErrorDetails(messageWithCause("Failed at writing the transformed file", e)); + logger.error("Failed to save target file (TransformException), sending " + reply, e); return new ResponseEntity<>(reply, HttpStatus.valueOf(reply.getStatus())); } - catch (HttpClientErrorException hcee) + catch (HttpClientErrorException e) { - reply.setStatus(hcee.getStatusCode().value()); - reply.setErrorDetails("Failed at writing the transformed file. " + hcee.getMessage()); + reply.setStatus(e.getStatusCode().value()); + reply.setErrorDetails(messageWithCause("Failed at writing the transformed file. ", e)); + logger.error("Failed to save target file (HttpClientErrorException), sending {}" + + reply, e); return new ResponseEntity<>(reply, HttpStatus.valueOf(reply.getStatus())); } catch (Exception e) { reply.setStatus(INTERNAL_SERVER_ERROR.value()); - reply.setErrorDetails("Failed at writing the transformed file. " + e.getMessage()); + reply.setErrorDetails(messageWithCause("Failed at writing the transformed file. ", e)); + logger.error("Failed to save target file (Exception), sending " + reply, e); return new ResponseEntity<>(reply, HttpStatus.valueOf(reply.getStatus())); } @@ -219,7 +230,8 @@ public abstract class AbstractTransformerController implements TransformControll } catch (Exception e) { - logger.error("Failed to delete target local temp file " + targetFile, e); + logger.error("Failed to delete local temp target file '{}'. Error will be ignored ", + targetFile, e); } try { @@ -233,6 +245,7 @@ public abstract class AbstractTransformerController implements TransformControll reply.setTargetReference(targetRef.getEntry().getFileRef()); reply.setStatus(HttpStatus.CREATED.value()); + logger.info("Sending successful {}, timeout {} ms", reply); return new ResponseEntity<>(reply, HttpStatus.valueOf(reply.getStatus())); } @@ -249,7 +262,7 @@ public abstract class AbstractTransformerController implements TransformControll * @param sourceReference reference to the file in Alfresco Shared File Store * @return the file containing the source content for the transformation */ - private File loadSourceFile(final String sourceReference) + private File loadSourceFile(final String sourceReference) throws Exception { ResponseEntity responseEntity = alfrescoSharedFileStoreClient .retrieveFile(sourceReference); @@ -262,17 +275,36 @@ public abstract class AbstractTransformerController implements TransformControll MediaType contentType = headers.getContentType(); long size = headers.getContentLength(); - Resource body = responseEntity.getBody(); + final Resource body = responseEntity.getBody(); + if (body == null) + { + throw new Exception("Failed to retrieve the file body from the request"); + } File file = TempFileProvider.createTempFile("source_", "." + extension); - if (logger.isDebugEnabled()) - { - logger.debug( - "Read source content " + sourceReference + " length=" - + size + " contentType=" + contentType); - } + logger.debug("Read source content {} length={} contentType={}", + sourceReference, size, contentType); + save(body, file); LogEntry.setSource(filename, size); return file; } + + private static String messageWithCause(final String prefix, Throwable e) + { + final StringBuilder sb = new StringBuilder(); + sb.append(prefix).append(" - ") + .append(e.getClass().getSimpleName()).append(": ") + .append(e.getMessage()); + + while (e.getCause() != null) + { + e = e.getCause(); + sb.append(", cause ") + .append(e.getClass().getSimpleName()).append(": ") + .append(e.getMessage()); + } + + return sb.toString(); + } } diff --git a/alfresco-transformer-base/src/main/java/org/alfresco/transformer/TransformController.java b/alfresco-transformer-base/src/main/java/org/alfresco/transformer/TransformController.java index b744ba4e..d44c2719 100644 --- a/alfresco-transformer-base/src/main/java/org/alfresco/transformer/TransformController.java +++ b/alfresco-transformer-base/src/main/java/org/alfresco/transformer/TransformController.java @@ -1,5 +1,6 @@ package org.alfresco.transformer; +import static java.text.MessageFormat.format; import static org.springframework.http.HttpStatus.BAD_REQUEST; import java.io.File; @@ -15,8 +16,8 @@ import org.alfresco.transform.client.model.TransformRequest; import org.alfresco.transformer.exceptions.TransformException; import org.alfresco.transformer.logging.LogEntry; import org.alfresco.transformer.probes.ProbeTestTransform; -import org.apache.commons.logging.Log; -import org.apache.commons.logging.LogFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; import org.springframework.beans.TypeMismatchException; import org.springframework.http.ResponseEntity; import org.springframework.ui.Model; @@ -34,7 +35,7 @@ import org.springframework.web.bind.annotation.ResponseBody; */ public interface TransformController { - Log logger = LogFactory.getLog(TransformController.class); + Logger logger = LoggerFactory.getLogger(TransformController.class); ResponseEntity transform(TransformRequest transformRequest, Long timeout); @@ -97,49 +98,44 @@ public interface TransformController default void handleParamsTypeMismatch(HttpServletResponse response, MissingServletRequestParameterException e) throws IOException { - String transformerName = getTransformerName(); - String name = e.getParameterName(); - String message = "Request parameter " + name + " is of the wrong type"; - int statusCode = BAD_REQUEST.value(); + final String message = format("Request parameter ''{0}'' is of the wrong type", e + .getParameterName()); + final int statusCode = BAD_REQUEST.value(); - logger.error(message); + logger.error(message, e); LogEntry.setStatusCodeAndMessage(statusCode, message); - response.sendError(statusCode, transformerName + " - " + message); + response.sendError(statusCode, getTransformerName() + " - " + message); } @ExceptionHandler(MissingServletRequestParameterException.class) default void handleMissingParams(HttpServletResponse response, MissingServletRequestParameterException e) throws IOException { - String transformerName = getTransformerName(); - String name = e.getParameterName(); - String message = "Request parameter " + name + " is missing"; - int statusCode = BAD_REQUEST.value(); + final String message = format("Request parameter ''{0}'' is missing", e.getParameterName()); + final int statusCode = BAD_REQUEST.value(); - logger.error(message); + logger.error(message, e); LogEntry.setStatusCodeAndMessage(statusCode, message); - response.sendError(statusCode, transformerName + " - " + message); + response.sendError(statusCode, getTransformerName() + " - " + message); } @ExceptionHandler(TransformException.class) default void transformExceptionWithMessage(HttpServletResponse response, TransformException e) throws IOException { - String transformerName = getTransformerName(); - String message = e.getMessage(); - int statusCode = e.getStatusCode(); + final String message = e.getMessage(); + final int statusCode = e.getStatusCode(); - logger.error(message); + logger.error(message, e); long time = LogEntry.setStatusCodeAndMessage(statusCode, message); getProbeTestTransform().recordTransformTime(time); - // Forced to include the transformer name in the message (see commented out version of this method) - response.sendError(statusCode, transformerName + " - " + message); + response.sendError(statusCode, getTransformerName() + " - " + message); } //endregion } diff --git a/alfresco-transformer-base/src/main/java/org/alfresco/transformer/executors/CommandExecutor.java b/alfresco-transformer-base/src/main/java/org/alfresco/transformer/executors/CommandExecutor.java index 95ba382b..eef3bdea 100644 --- a/alfresco-transformer-base/src/main/java/org/alfresco/transformer/executors/CommandExecutor.java +++ b/alfresco-transformer-base/src/main/java/org/alfresco/transformer/executors/CommandExecutor.java @@ -30,8 +30,8 @@ public interface CommandExecutor run(properties, targetFile, timeout); } - default void run(String options, File sourceFile, String pageRange, File - targetFile, Long timeout) + default void run(String options, File sourceFile, String pageRange, File targetFile, + Long timeout) { LogEntry.setOptions(pageRange + (pageRange.isEmpty() ? "" : " ") + options); diff --git a/alfresco-transformer-base/src/main/java/org/alfresco/transformer/logging/LogEntry.java b/alfresco-transformer-base/src/main/java/org/alfresco/transformer/logging/LogEntry.java index 28839cc0..6cf2b348 100644 --- a/alfresco-transformer-base/src/main/java/org/alfresco/transformer/logging/LogEntry.java +++ b/alfresco-transformer-base/src/main/java/org/alfresco/transformer/logging/LogEntry.java @@ -35,8 +35,8 @@ import java.util.Deque; import java.util.concurrent.ConcurrentLinkedDeque; import java.util.concurrent.atomic.AtomicInteger; -import org.apache.commons.logging.Log; -import org.apache.commons.logging.LogFactory; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * Provides setter and getter methods to allow the current Thread to set various log properties and for these @@ -46,7 +46,7 @@ import org.apache.commons.logging.LogFactory; */ public final class LogEntry { - private static final Log logger = LogFactory.getLog(LogEntry.class); + private static final Logger logger = LoggerFactory.getLogger(LogEntry.class); // TODO allow ProbeTestTransform to find out if there are any transforms running longer than the max time. private static final AtomicInteger count = new AtomicInteger(0); diff --git a/alfresco-transformer-base/src/main/java/org/alfresco/transformer/probes/ProbeTestTransform.java b/alfresco-transformer-base/src/main/java/org/alfresco/transformer/probes/ProbeTestTransform.java index bc0a9442..34bc55a1 100644 --- a/alfresco-transformer-base/src/main/java/org/alfresco/transformer/probes/ProbeTestTransform.java +++ b/alfresco-transformer-base/src/main/java/org/alfresco/transformer/probes/ProbeTestTransform.java @@ -46,7 +46,8 @@ import org.alfresco.transformer.AbstractTransformerController; import org.alfresco.transformer.exceptions.TransformException; import org.alfresco.transformer.logging.LogEntry; import org.alfresco.util.TempFileProvider; -import org.apache.commons.logging.Log; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; /** * Provides the logic performing test transformations by the live and ready probes. @@ -72,14 +73,14 @@ import org.apache.commons.logging.Log; */ public abstract class ProbeTestTransform { + private final Logger logger = LoggerFactory.getLogger(ProbeTestTransform.class); + private static final int AVERAGE_OVER_TRANSFORMS = 5; private final String sourceFilename; private final String targetFilename; private final long minExpectedLength; private final long maxExpectedLength; - private final Log logger; - private int livenessPercent; private long probeCount; private int transCount; @@ -117,13 +118,11 @@ public abstract class ProbeTestTransform * @param maxTransformSeconds default values normally supplied by helm. Not identical so we can be sure which value is used. * @param livenessTransformPeriodSeconds default values normally supplied by helm. Not identical so we can be sure which value is used. */ - public ProbeTestTransform(AbstractTransformerController controller, Log logger, + public ProbeTestTransform(AbstractTransformerController controller, String sourceFilename, String targetFilename, long expectedLength, long plusOrMinus, int livenessPercent, long maxTransforms, long maxTransformSeconds, long livenessTransformPeriodSeconds) { - this.logger = logger; - this.sourceFilename = sourceFilename; this.targetFilename = targetFilename; minExpectedLength = Math.max(0, expectedLength-plusOrMinus); diff --git a/alfresco-transformer-base/src/test/java/org/alfresco/transformer/AbstractHttpRequestTest.java b/alfresco-transformer-base/src/test/java/org/alfresco/transformer/AbstractHttpRequestTest.java index fe3e46f5..789ef982 100644 --- a/alfresco-transformer-base/src/test/java/org/alfresco/transformer/AbstractHttpRequestTest.java +++ b/alfresco-transformer-base/src/test/java/org/alfresco/transformer/AbstractHttpRequestTest.java @@ -95,7 +95,7 @@ public abstract class AbstractHttpRequestTest private void assertMissingParameter(String name) { assertTransformError(true, - getTransformerName() + " - Request parameter " + name + " is missing"); + getTransformerName() + " - Request parameter '" + name + "' is missing"); } private void assertTransformError(boolean addFile, String errorMessage) diff --git a/alfresco-transformer-base/src/test/java/org/alfresco/transformer/AbstractTransformerControllerTest.java b/alfresco-transformer-base/src/test/java/org/alfresco/transformer/AbstractTransformerControllerTest.java index 6de4388b..b8c1cd66 100644 --- a/alfresco-transformer-base/src/test/java/org/alfresco/transformer/AbstractTransformerControllerTest.java +++ b/alfresco-transformer-base/src/test/java/org/alfresco/transformer/AbstractTransformerControllerTest.java @@ -237,7 +237,7 @@ public abstract class AbstractTransformerControllerTest { mockMvc.perform(mockMvcRequest("/transform", sourceFile)) .andExpect(status().is(BAD_REQUEST.value())) - .andExpect(status().reason(containsString("Request parameter targetExtension is missing"))); + .andExpect(status().reason(containsString("Request parameter 'targetExtension' is missing"))); } @Test diff --git a/pom.xml b/pom.xml index b0bddf25..ba2be877 100644 --- a/pom.xml +++ b/pom.xml @@ -23,7 +23,6 @@ 7.3 8.8 3.0.1.1 - 1.2.3 ${project.version} 0.0.7 @@ -45,21 +44,6 @@ - - ch.qos.logback - logback-core - ${dependency.ch-qos-logback.version} - - - ch.qos.logback - logback-access - ${dependency.ch-qos-logback.version} - - - ch.qos.logback - logback-classic - ${dependency.ch-qos-logback.version} - org.alfresco alfresco-core