Skip to content

Commit

Permalink
Add more debug and trace logging (frankframework#5255)
Browse files Browse the repository at this point in the history
  • Loading branch information
nielsm5 authored Aug 29, 2023
1 parent 9b327ed commit 1a6d9d2
Show file tree
Hide file tree
Showing 9 changed files with 60 additions and 43 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -337,7 +337,7 @@ public void close() {
Entry<AutoCloseable, String> entry = it.next();
AutoCloseable closeable = entry.getKey();
try {
log.warn("messageId ["+getMessageId()+"] auto closing resource "+entry.getValue());
log.info("messageId ["+getMessageId()+"] auto closing resource "+entry.getValue());
closeable.close();
} catch (Exception e) {
log.warn("Exception closing resource", e);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -43,10 +43,10 @@ public TransactionalDbmsSupportAwareDataSourceProxy(DataSource delegate) {

public Map<String, String> getMetaData() throws SQLException {
if(metadata == null) {
log.debug("populating metadata from getMetaData");
try (Connection connection = getConnection()) {
populateMetadata(connection);
}
log.debug("populated metadata from getMetaData");
}
return metadata;
}
Expand Down Expand Up @@ -86,8 +86,8 @@ public String getDestinationName() throws SQLException {
public Connection getConnection() throws SQLException {
Connection conn = super.getConnection();
if(metadata == null) {
log.debug("populating metadata from getConnection");
populateMetadata(conn);
log.debug("populated metadata from getConnection");
}

return conn;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -243,7 +243,7 @@ public void configure() throws ConfigurationException {
throw new ConfigurationException("while configuring sender",e);
}
if (getSender() instanceof HasPhysicalDestination) {
log.info("has sender on {}", ((HasPhysicalDestination)getSender()).getPhysicalDestinationName());
log.debug("has sender on {}", () -> ((HasPhysicalDestination)getSender()).getPhysicalDestinationName());
}
if (getListener() != null) {
if (getSender().isSynchronous()) {
Expand All @@ -255,7 +255,7 @@ public void configure() throws ConfigurationException {
throw new ConfigurationException("while configuring listener",e);
}
if (getListener() instanceof HasPhysicalDestination) {
log.info("has listener on {}", ((HasPhysicalDestination)getListener()).getPhysicalDestinationName());
log.debug("has listener on {}", () -> ((HasPhysicalDestination)getListener()).getPhysicalDestinationName());
}
}

Expand Down Expand Up @@ -314,7 +314,7 @@ public void configure() throws ConfigurationException {
messageLog.configure();
if (messageLog instanceof HasPhysicalDestination) {
String msg = "has messageLog in "+((HasPhysicalDestination)messageLog).getPhysicalDestinationName();
log.info(msg);
log.debug(msg);
if (getAdapter() != null)
getAdapter().getMessageKeeper().add(msg);
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -102,7 +102,7 @@ public void execute() {
try {
adapter = findAdapter(adapterName);
} catch (IllegalStateException e) {
getMessageKeeper().add("unable to add schedule ["+key+"]", e);
getMessageKeeper().add("unable to add schedule ["+key+"]: " + e.getMessage());
continue;
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -38,12 +38,9 @@ public MessageDataSource(Message message) throws IOException {
}

public MessageDataSource(Message message, String newContentType) throws IOException {
if(message.isNull()) {
if(Message.isNull(message)) {
throw new IllegalArgumentException("message may not be null");
}
if(message.getContext() == null) {
throw new IllegalArgumentException("no message context available");
}

this.message = message;
this.message.preserve();
Expand Down
25 changes: 13 additions & 12 deletions core/src/main/java/nl/nn/adapterframework/util/MessageUtils.java
Original file line number Diff line number Diff line change
Expand Up @@ -75,14 +75,7 @@ public static MessageContext getContext(Iterator<MimeHeader> mimeHeaders) {
while (mimeHeaders.hasNext()) {
MimeHeader header = mimeHeaders.next();
String name = header.getName();
if("Content-Transfer-Encoding".equals(name)) {
try {
Charset charset = Charset.forName(header.getValue());
result.withCharset(charset);
} catch (Exception e) {
LOG.warn("Could not determine charset", e);
}
} else if("Content-Type".equals(name)) {
if("Content-Type".equals(name)) {
result.withMimeType(header.getValue());
} else {
result.put(MessageContext.HEADER_PREFIX + name, header.getValue());
Expand Down Expand Up @@ -179,13 +172,16 @@ public static MimeType getMimeType(Message message) {

MimeType mimeType = (MimeType)message.getContext().get(MessageContext.METADATA_MIMETYPE);
if(mimeType == null) {
LOG.trace("no mimetype found in MessageContext");
return null;
}

if(message.getCharset() != null) { //and is character data?
LOG.trace("found mimetype [{}] in MessageContext with charset [{}]", ()->mimeType, message::getCharset);
return new MimeType(mimeType, Charset.forName(message.getCharset()));
}

LOG.trace("found mimetype [{}] in MessageContext without charset", mimeType);
return mimeType;
}

Expand Down Expand Up @@ -215,13 +211,15 @@ public static MimeType computeMimeType(Message message, String filename) {
}

MessageContext context = message.getContext();
MimeType mimeType = getMimeType(message);
if(mimeType != null) {
return mimeType;
MimeType contextMimeType = getMimeType(message);
if(contextMimeType != null) {
LOG.debug("returning predetermined mimetype [{}]", contextMimeType);
return contextMimeType;
}

String name = (String) context.get(MessageContext.METADATA_NAME);
if(StringUtils.isNotEmpty(filename)) {
LOG.trace("using filename from MessageContext [{}]", name);
name = filename;
}

Expand All @@ -235,14 +233,17 @@ public static MimeType computeMimeType(Message message, String filename) {
return null;
}
org.apache.tika.mime.MediaType tikaMediaType = tika.getDetector().detect(new ByteArrayInputStream(magic), metadata);
mimeType = MimeType.valueOf(tikaMediaType.toString());
MimeType mimeType = MimeType.valueOf(tikaMediaType.toString());
context.withMimeType(mimeType);
if("text".equals(mimeType.getType()) || message.getCharset() != null) { // is of type 'text' or message has charset
Charset charset = computeDecodingCharset(message);
if(charset != null) {
LOG.debug("found mimetype [{}] with charset [{}]", mimeType, charset);
return new MimeType(mimeType, charset);
}
}

LOG.debug("found mimetype [{}]", mimeType);
return mimeType;
} catch (Exception t) {
LOG.warn("error parsing message to determine mimetype", t);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -29,13 +29,26 @@ public class MessageUtilsTest {
public void testCharset() throws Exception {
MockHttpServletRequest request = new MockHttpServletRequest();
request.setCharacterEncoding("tja"); //overridden by content-type header
request.setContentType("application/pdf; charset=utf-8"); //2 spaces
request.setContentType("application/xml; charset=utf-8"); //2 spaces
request.setContent("request".getBytes());
MessageContext context = MessageUtils.getContext(request);

assertEquals("UTF-8", context.get(MessageContext.METADATA_CHARSET));
assertEquals((long) 7, context.get(MessageContext.METADATA_SIZE));
assertEquals(MimeType.valueOf("application/pdf; charset=UTF-8"), context.get(MessageContext.METADATA_MIMETYPE));
assertEquals(MimeType.valueOf("application/xml; charset=UTF-8"), context.get(MessageContext.METADATA_MIMETYPE));
}

@Test
public void testCharsetUtf8() throws Exception {
MockHttpServletRequest request = new MockHttpServletRequest();
request.setCharacterEncoding("tja"); //overridden by content-type header
request.setContentType("application/xml; charset=utf-16"); //2 spaces
request.setContent("request".getBytes());
MessageContext context = MessageUtils.getContext(request);

assertEquals("UTF-16", context.get(MessageContext.METADATA_CHARSET));
assertEquals((long) 7, context.get(MessageContext.METADATA_SIZE));
assertEquals(MimeType.valueOf("application/xml; charset=UTF-16"), context.get(MessageContext.METADATA_MIMETYPE));
}

@Test
Expand Down Expand Up @@ -143,34 +156,37 @@ public void testMessageDataSource() throws Exception {
URL url = TestFileUtils.getTestFileURL("/file.xml");
assertNotNull(url);
Message message = new UrlMessage(url);
MessageDataSource ds = new MessageDataSource(message);
assertEquals("file.xml", ds.getName(), "filename should be the same");
assertEquals("application/xml", ds.getContentType(),"content-type should be the same"); //determined from file extension
assertEquals(StreamUtil.streamToString(url.openStream()), StreamUtil.streamToString(ds.getInputStream()), "contents should be the same");
assertEquals(StreamUtil.streamToString(url.openStream()), StreamUtil.streamToString(ds.getInputStream()), "should be able to read the content twice");
try (MessageDataSource ds = new MessageDataSource(message)) {
assertEquals("file.xml", ds.getName(), "filename should be the same");
assertEquals("application/xml", ds.getContentType(),"content-type should be the same"); //determined from file extension
assertEquals(StreamUtil.streamToString(url.openStream()), StreamUtil.streamToString(ds.getInputStream()), "contents should be the same");
assertEquals(StreamUtil.streamToString(url.openStream()), StreamUtil.streamToString(ds.getInputStream()), "should be able to read the content twice");
}
}

@Test
public void testMessageDataSourceFromStringDataWithoutXmlDeclaration() throws Exception {
URL url = TestFileUtils.getTestFileURL("/file.xml");
assertNotNull(url);
Message message = new UrlMessage(url);
MessageDataSource ds = new MessageDataSource(Message.asMessage(message.asString()));
assertEquals(null, ds.getName(), "filename is unknown");
assertEquals("application/octet-stream", ds.getContentType(), "content-type cannot be determined");
assertEquals(StreamUtil.streamToString(url.openStream()), StreamUtil.streamToString(ds.getInputStream()), "contents should be the same");
assertEquals(StreamUtil.streamToString(url.openStream()), StreamUtil.streamToString(ds.getInputStream()), "should be able to read the content twice");
try (Message message = new UrlMessage(url)) {
MessageDataSource ds = new MessageDataSource(Message.asMessage(message.asString()));
assertEquals(null, ds.getName(), "filename is unknown");
assertEquals("application/octet-stream", ds.getContentType(), "content-type cannot be determined");
assertEquals(StreamUtil.streamToString(url.openStream()), StreamUtil.streamToString(ds.getInputStream()), "contents should be the same");
assertEquals(StreamUtil.streamToString(url.openStream()), StreamUtil.streamToString(ds.getInputStream()), "should be able to read the content twice");
}
}

@Test
public void testMessageDataSourceFromStringDataWithXmlDeclaration() throws Exception {
URL url = TestFileUtils.getTestFileURL("/log4j4ibis.xml");
assertNotNull(url);
Message message = new UrlMessage(url);
MessageDataSource ds = new MessageDataSource(Message.asMessage(message.asString()));
assertEquals(null, ds.getName(), "filename is unknown");
assertEquals(ds.getContentType(),"application/xml", "content-type cannot be determined");
assertEquals(StreamUtil.streamToString(ds.getInputStream()), StreamUtil.streamToString(url.openStream()), "contents should be the same");
assertEquals(StreamUtil.streamToString(url.openStream()), StreamUtil.streamToString(ds.getInputStream()), "should be able to read the content twice");
try (Message message = new UrlMessage(url)) {
MessageDataSource ds = new MessageDataSource(Message.asMessage(message.asString()));
assertEquals(null, ds.getName(), "filename is unknown");
assertEquals("application/xml", ds.getContentType(), "content-type cannot be determined");
assertEquals(StreamUtil.streamToString(ds.getInputStream()), StreamUtil.streamToString(url.openStream()), "contents should be the same");
assertEquals(StreamUtil.streamToString(url.openStream()), StreamUtil.streamToString(ds.getInputStream()), "should be able to read the content twice");
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -215,7 +215,7 @@ public static void invokeSetter(Object bean, Method method, String valueToSet) {

try {//Only always grab the first value because we explicitly check method.getParameterTypes().length != 1
Object castValue = parseValueToSet(method, valueToSet);
if(log.isDebugEnabled()) log.debug("trying to set method ["+method.getName()+"] with value ["+valueToSet+"] of type ["+castValue.getClass().getCanonicalName()+"] on ["+ClassUtils.nameOf(bean)+"]");
log.trace("trying to set method [{}] with value [{}] of type [{}] on [{}]", method::getName, ()->valueToSet, ()->castValue.getClass().getCanonicalName(), ()->ClassUtils.nameOf(bean));

method.invoke(bean, castValue);
} catch (IllegalAccessException | InvocationTargetException e) {
Expand Down
3 changes: 3 additions & 0 deletions test/src/main/resources/DeploymentSpecifics.properties
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,9 @@ jdbc.dbms.default=h2
#jdbc.dbms.default=db2
#jdbc.dbms.default=db2-xa

#When running DB2 XA, the REORG command does not work.
#jdbc.migrator.datasource=jdbc/ibis4test-db2

jdbc.datasource.default=jdbc/${instance.name.lc}-${jdbc.dbms.default}

# reduce database reload interval to once per hour, to avoid the log filling (unnecessarily) with check reload messages.
Expand Down

0 comments on commit 1a6d9d2

Please sign in to comment.