[bugfix] fn:transform() now logs xsl:message output

exist-core/src/main/java/org/exist/xquery/functions/fn/transform/Transform.java

@@ -53,6 +53,9 @@
 import net.sf.saxon.s9api.*;
 import net.sf.saxon.serialize.SerializationProperties;
 import net.sf.saxon.trans.UncheckedXPathException;
+
+import java.io.IOException;
+import java.io.StringWriter;
 import org.apache.logging.log4j.LogManager;
 import org.apache.logging.log4j.Logger;
 import org.exist.dom.QName;
@@ -67,8 +70,10 @@
 import org.w3c.dom.Node;
 
 import javax.annotation.Nonnull;
+import javax.annotation.Nullable;
 import javax.xml.transform.ErrorListener;
 import javax.xml.transform.Source;
+import javax.xml.transform.SourceLocator;
 import javax.xml.transform.TransformerException;
 import javax.xml.transform.dom.DOMSource;
 import java.net.URI;
@@ -161,6 +166,7 @@ public Sequence eval(final Sequence[] args, final Sequence contextSequence) thro
                 }
 
                 final Xslt30Transformer xslt30Transformer = xsltExecutable.load30();
+                xslt30Transformer.setMessageListener(new XsltMessageListener(context.getBroker().getBrokerPool().getSaxonProcessor()));
 
                 options.initialMode.ifPresent(qNameValue -> xslt30Transformer.setInitialMode(Convert.ToSaxon.of(qNameValue.getQName())));
                 xslt30Transformer.setInitialTemplateParameters(options.templateParams, false);
@@ -532,4 +538,53 @@ public PendingException(String message, Throwable cause) {
             super(message, cause);
         }
     }
+
+    private static class XsltMessageListener implements MessageListener {
+
+        private final Processor processor;
+
+        public XsltMessageListener(final Processor processor) {
+            this.processor = processor;
+        }
+
+        @Override
+        public void message(final XdmNode content, final boolean terminate, final SourceLocator locator) {
+
+            try (final StringWriter writer = new StringWriter()) {
+                final Serializer serializer = processor.newSerializer();
+                serializer.setOutputProperty(Serializer.Property.OMIT_XML_DECLARATION, "yes");
+                serializer.setOutputWriter(writer);
+                serializer.serializeNode(content);
+
+                @Nullable final String source;
+                final int sourceLine;
+                final int sourceColumn;
+                if (locator != null) {
+                    source = locator.getSystemId();
+                    sourceLine = locator.getLineNumber();
+                    sourceColumn = locator.getColumnNumber();
+                } else {
+                    source = null;
+                    sourceLine = -1;
+                    sourceColumn = -1;
+                }
+
+                final StringBuilder tag = new StringBuilder("<xsl:message terminate=\"" + terminate + "\"");
+                if (source != null) {
+                    tag.append(" source=\"").append(source).append("\"");
+                }
+                if (sourceLine != -1) {
+                    tag.append(" sourceLine=\"").append(sourceLine).append("\"");
+                    tag.append(" sourceColumn=\"").append(sourceColumn).append("\"");
+                }
+                tag.append(">");
+
+                LOGGER.info("{}{}</xsl:message>", tag, writer.toString());
+            } catch (final SaxonApiException e) {
+                LOGGER.error("Unable to serialize xsl:message content", e);
+            } catch (final IOException e) {
+                LOGGER.error("Unable to close xsl:message writer", e);
+            }
+        }
+    }
 }

exist-core/src/test/java/org/exist/xquery/functions/fn/transform/FunTransformITTest.java

@@ -21,6 +21,12 @@
 package org.exist.xquery.functions.fn.transform;
 
 import com.evolvedbinary.j8fu.tuple.Tuple2;
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.core.LogEvent;
+import org.apache.logging.log4j.core.Logger;
+import org.apache.logging.log4j.core.appender.AbstractAppender;
+import org.apache.logging.log4j.core.config.Property;
+import org.apache.logging.log4j.core.layout.PatternLayout;
 import org.exist.EXistException;
 import org.exist.collections.Collection;
 import org.exist.security.PermissionDeniedException;
@@ -49,6 +55,8 @@
 
 import javax.xml.transform.Source;
 import java.io.IOException;
+import java.util.ArrayList;
+import java.util.List;
 import java.util.Optional;
 
 import static com.evolvedbinary.j8fu.tuple.Tuple.Tuple;
@@ -247,6 +255,45 @@ public void identityMixedMemoryAndPersistentDom() throws XPathException, Permiss
         expectQuery(IDENTITY_MIXED_XSLT_QUERY_5, expected);
     }
 
+    @Test
+    public void xslMessageIsLogged() throws EXistException, PermissionDeniedException, IOException, XPathException {
+        final CapturingAppender appender = new CapturingAppender();
+        appender.start();
+
+        final Logger transformLogger = (Logger) LogManager.getLogger(Transform.class);
+        transformLogger.addAppender(appender);
+
+        try {
+            final String query =
+                "fn:transform(map {\n" +
+                "  \"stylesheet-text\": '<xsl:stylesheet xmlns:xsl=\"http://www.w3.org/1999/XSL/Transform\" version=\"2.0\">\n" +
+                "    <xsl:template match=\"/\">\n" +
+                "      <xsl:message>Hello from XSLT</xsl:message>\n" +
+                "    </xsl:template>\n" +
+                "  </xsl:stylesheet>',\n" +
+                "  \"source-node\": document { <in/> }\n" +
+                "})?output";
+
+            final BrokerPool pool = existEmbeddedServer.getBrokerPool();
+            try (final DBBroker broker = pool.get(Optional.of(pool.getSecurityManager().getSystemSubject()));
+                 final XQueryUtil.QueryResult queryResult = XQueryUtil.query(broker, new StringSource(query), false, null, null, null, null, null)) {
+                assertNotNull(queryResult.result);
+            }
+
+            String logged = null;
+            for (final String message : appender.getMessages()) {
+                if (message.contains("<xsl:message")) {
+                    logged = message;
+                    break;
+                }
+            }
+            assertNotNull("Expected an xsl:message log entry", logged);
+            assertTrue(logged.contains("Hello from XSLT"));
+        } finally {
+            transformLogger.removeAppender(appender);
+        }
+    }
+
     private static void expectQuery(final String query, final Source expected) throws EXistException, XPathException, PermissionDeniedException, IOException {
         final BrokerPool pool = existEmbeddedServer.getBrokerPool();
         try(final DBBroker broker = pool.get(Optional.of(pool.getSecurityManager().getSystemSubject()));
@@ -298,4 +345,23 @@ private static void createCollection(final DBBroker broker, final Txn transactio
             }
         }
     }
+
+
+    private static class CapturingAppender extends AbstractAppender {
+
+        private final List<String> messages = new ArrayList<>();
+
+        CapturingAppender() {
+            super("capturing-appender", null, PatternLayout.createDefaultLayout(), false, Property.EMPTY_ARRAY);
+        }
+
+        @Override
+        public void append(final LogEvent event) {
+            messages.add(event.getMessage().getFormattedMessage());
+        }
+
+        List<String> getMessages() {
+            return messages;
+        }
+    }
 }