<xsl:message> of an XML element also recursively prints its descendants

[chrispy-snps]

Expected Behavior

When I use <xsl:message> to print an element:

    <xsl:template match="*[contains-token(@class, 'topic/p')]">
        <xsl:message>***BEGIN***</xsl:message>
        <xsl:message><xsl:sequence select="."/></xsl:message>
        <xsl:message>***END***</xsl:message>
        <xsl:next-match/>
    </xsl:template>

and the element being printed has descendant elements in it:

<p>1
  <ph>2
    <ph>3
      <ph>4</ph>
    5</ph>
  6</ph>
7</p>

then I expect the element to be printed, serialized as it exists in the document:

     [xslt] ***BEGIN***
     [xslt] <p xmlns:dita-ot="http://dita-ot.sourceforge.net/ns/201007/dita-ot" xmlns:ditaarch="http://dita.oasis-open.org/architecture/2005/" class="- topic/p ">1
     [xslt]   <ph class="- topic/ph ">2
     [xslt]     <ph class="- topic/ph ">3
     [xslt]       <ph class="- topic/ph ">4</ph>
     [xslt]     5</ph>
     [xslt]   6</ph>
     [xslt] 7</p>
     [xslt] ***END***

Actual Behavior

Somehow the element is printed once normally, then the contents of its descendants are also recursively printed:

     [xslt] ***BEGIN***
     [xslt] <p xmlns:dita-ot="http://dita-ot.sourceforge.net/ns/201007/dita-ot"
     [xslt]    xmlns:ditaarch="http://dita.oasis-open.org/architecture/2005/"
     [xslt]    class="- topic/p ">1
     [xslt]   <ph class="- topic/ph ">2
     [xslt]     <ph class="- topic/ph ">3
     [xslt]       <ph class="- topic/ph ">4</ph>
     [xslt]     5</ph>
     [xslt]   6</ph>
     [xslt] 7</p>1
     [xslt]   <ph xmlns:dita-ot="http://dita-ot.sourceforge.net/ns/201007/dita-ot"
     [xslt]     xmlns:ditaarch="http://dita.oasis-open.org/architecture/2005/"
     [xslt]     class="- topic/ph ">2
     [xslt]     <ph class="- topic/ph ">3
     [xslt]       <ph class="- topic/ph ">4</ph>
     [xslt]     5</ph>
     [xslt]   6</ph>2
     [xslt]     <ph xmlns:dita-ot="http://dita-ot.sourceforge.net/ns/201007/dita-ot"
     [xslt]     xmlns:ditaarch="http://dita.oasis-open.org/architecture/2005/"
     [xslt]     class="- topic/ph ">3
     [xslt]       <ph class="- topic/ph ">4</ph>
     [xslt]     5</ph>3
     [xslt]       <ph xmlns:dita-ot="http://dita-ot.sourceforge.net/ns/201007/dita-ot"
     [xslt]     xmlns:ditaarch="http://dita.oasis-open.org/architecture/2005/"
     [xslt]     class="- topic/ph ">4</ph>4
     [xslt]     5
     [xslt]   6
     [xslt] 7
     [xslt] ***END***

Possible Solution

I think this is related to the fix for #3662. Note that the "expected behavior" above comes from DITA-OT 3.5.4, before the original bug was introduced.

Steps to Reproduce

1. Extract the following testcase: ditaot_message_nested_elements.zip
2. Install the plugin:
   dita install com.debug.message.zip
3. Run the following command:
   dita -i topic.dita -f html5 -o out -Dgenerate-debug-attributes=no --verbose
4. Uninstall the plugin:
   dita uninstall com.debug.message

Environment

• DITA-OT version: 3.7.2
• Operating system and version: Linux (Ubuntu 20.04 LTS)
• How did you run DITA-OT? dita command
• Transformation type: any

[raducoravu]

Indeed looks like a side effect of #3662
@jelovirt I also suspect that the way in which this method iterates "org.dita.dost.util.XMLUtils.toMessageListener(DITAOTLogger)" to output content for all descendants

            final String msg = content
                    .select(descendant(
                            hasLocalName("level").or(hasLocalName("error-code"))
                                    .and(hasType(ItemType.PROCESSING_INSTRUCTION_NODE))
                            .negate()))
                    .map(n -> n.toString())
                    .collect(Collectors.joining());

the code ends up calling "toString()" on all nodes, ancestors and descendants alike and the information is duplicated.
Maybe only the child axis should be iterated?

[raducoravu]

I added a pull request for this.

[chrispy-snps]

Thank you @raducoravu!