# Test Failure

The unit tests run by "make check" fail with the following error:

    tests.c:61:F:Lasso keys:test08_lasso_key:0: No logging output expected: message «ID _E3F8E9116EE08F0E2607CF9789649BB4 already defined
    » was emitted for domain «Lasso» at the level «128»

This is not a regression in Lasso, rather the failure is caused by one of the components Lasso is dependent upon. It was first observed when the identical Lasso package was built in Fedora 22, no problems were observed in Fedora 21. This implies one or more updated components in Fedora 22 is the cause.

This was a particularity difficult error to track down, first one had to identify who was emitting the message and on what file descriptor (stream) and who was triggering on the message emission and causing a check failure. The obvious assumption the check library was responsible for detecting the message emission and failing the test is wrong.

# Who is emitting the message and why?

The message is emitted by libxml2 in the function xmlAddID() (valid.c:2578). It occurs at the end of xmlAddID() when it detects the ID (which is supposed to be unique to the document is already defined, which for valid XML is illegal (violates uniquenesss constraint). The message emission occurs because of the code fragment

        if (xmlHashAddEntry(table, value, ret) < 0) {
    #ifdef LIBXML_VALID_ENABLED
            /*
             * The id is already defined in this DTD.
             */
            xmlErrValidNode(ctxt, attr->parent, XML_DTD_ID_REDEFINED,
                            "ID %s already defined\n", value, NULL, NULL);
    #endif /* LIBXML_VALID_ENABLED */
            xmlFreeID(ret);
            return(NULL);
        }

# Why is the message emission different between libxml2 versions?

The change occured between libxml2 version 2.9.1 and 2.9.2 in commit a16eb968075a82ec33b2c1e77db8909a35b44620

    commit a16eb968075a82ec33b2c1e77db8909a35b44620
    Author: Daniel Veillard <veillard@redhat.com>
    Date:   Tue Jun 10 16:06:14 2014 +0800

        erroneously ignores a validation error if no error callback set

        Reported by Stefan Behnel
        https://bugzilla.gnome.org/show_bug.cgi?id=724903

    diff --git a/valid.c b/valid.c
    index aedd9d7..1e03a7c 100644
    --- a/valid.c
    +++ b/valid.c
    @@ -2633,11 +2633,8 @@ xmlAddID(xmlValidCtxtPtr ctxt, xmlDocPtr doc, const xmlChar *value,
            /*
             * The id is already defined in this DTD.
             */
    -   if ((ctxt != NULL) && (ctxt->error != NULL)) {
    -       xmlErrValidNode(ctxt, attr->parent, XML_DTD_ID_REDEFINED,
    -                       "ID %s already defined\n",
    -                       value, NULL, NULL);
    -   }
    +   xmlErrValidNode(ctxt, attr->parent, XML_DTD_ID_REDEFINED,
    +                   "ID %s already defined\n", value, NULL, NULL);
     #endif /* LIBXML_VALID_ENABLED */
            xmlFreeID(ret);
            return(NULL);

In both versions of libxml2 the conditional complilation LIBXML_VALID_ENABLED is enabled by default via the configure script. What is different is the the requirement ctxt be non-NULL. Lasso invokes xmlAddID with a NULL ctxt parameter. Because the NULL test for ctxt is absent in libxlm2 2.9.2 the message is now emitted where previously it was not.

# Who triggers on messge emission and fails the test?

This is a Lasso feature, it is not part of libcheck. In tests/tests.c is the following function

    void error_logger(const gchar *log_domain, GLogLevelFlags log_level,
                    const gchar *message, G_GNUC_UNUSED gpointer user_data)
    {
            fail("No logging output expected: message «%s» was emitted for domain «%s» at the level"
                            " «%d»", message, log_domain, log_level);
    }

Before the test are run the error_logger function is installed as a glib handler

    g_log_set_default_handler(error_logger, NULL);

When the message is emitted the error_logger traps it and invokes the libcheck (deprecated) function fail() which aborts the test case.

# Why does test08_lasso_key cause an XML validation failure?

test08_lasso_key invokes lasso_key_saml2_xml_verify() twice on the same XML document. Any time lasso_key_saml2_xml_verify() is called more than once the XML validation will fail on the second and subsequent invocations. This occurs because lasso_key_saml2_xml_verify() invokes lasso_verify_signature() passing it the node id in the id_attr_name parameter. Inside lasso_verify_signature() is this code fragment:

    /* Find ID */
    if (id_attr_name) {
            id = xmlGetProp(signed_node, (xmlChar*)id_attr_name);
            if (id) {
                    xmlAddID(NULL, doc, id, xmlHasProp(signed_node, (xmlChar*)id_attr_name));
            }
    }

Note that it unconditionally invokes xmlAddID(), which adds the ID to the set of unique element ID's in the document. But if you invoke xmlAddID() more than once with the same ID in the same document you violate the uniqueness constraint.

The ID needs to be registered in the document because the <Reference> element of the <SignedInfo> may utilize an XPointer reference to the signed data. In it's simplest form the XPointer reference is an ID attribute on a node. Thus to locate the signed data referenced by the ID it should (must?) be in a table of ID's for the document.

# Simple Solution (patch)

The solution is simple now that the problem is understood. The ID should not be unconditionally added to the document, instead it should only be added if it's not already registered. Prior to calling xmlAddID() one should call xmlGetID() and test for a NULL result indicating the ID has not be registered previously.

    diff --git a/lasso/xml/tools.c b/lasso/xml/tools.c
    index 555ab68..b467876 100644
    --- a/lasso/xml/tools.c
    +++ b/lasso/xml/tools.c
    @@ -1549,7 +1549,7 @@ lasso_verify_signature(xmlNode *signed_node, xmlDoc *doc, const char *id_attr_na
            /* Find ID */
            if (id_attr_name) {
                    id = xmlGetProp(signed_node, (xmlChar*)id_attr_name);
    -           if (id) {
    +           if (id && (xmlGetID(doc, id) == NULL)) {
                            xmlAddID(NULL, doc, id, xmlHasProp(signed_node, (xmlChar*)id_attr_name));
                    }
            }