ATS-176 : Log improvements with Slf4j

This commit is contained in:
Cezar Leahu
2018-11-13 15:22:38 +00:00
parent 2dfab69dd2
commit 24611ea42e
15 changed files with 160 additions and 164 deletions

View File

@@ -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<TransformReply> 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<Resource> 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();
}
}

View File

@@ -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<TransformReply> 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
}

View File

@@ -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);

View File

@@ -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);

View File

@@ -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);

View File

@@ -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)

View File

@@ -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