Add/improve yang parser error reporting 66/27866/9
authorTom Pantelis <tpanteli@brocade.com>
Fri, 2 Oct 2015 16:18:50 +0000 (12:18 -0400)
committerGerrit Code Review <gerrit@opendaylight.org>
Mon, 9 Nov 2015 11:48:54 +0000 (11:48 +0000)
If a yang file fails to load/parse in karaf, it fails silently. The
first problem is that YangTextSchemaContextResolver#getSchemaContext
logs the SchemaResolutionException to debug as it retries with
getResolvedSources. But if getResolvedSources is empty, it ends up
silently returning an empty SchemaContext.

Another issue is that the underlying exceptions that are really relevant
are added as suppressed to the aggregating exception. This would be fine
if the underlying logger in karaf printed suppressed exceptions as
Throwable#printStackTrace does but it doesn't. The suppressed exceptions
do appear from maven (that underlying logger uses printStackTrace).

My first thought was to log the SchemaResolutionException if
SchemaResolutionException was empty but use printStackTrace to get the
suppressed exceptions. However there are 3 levels of exceptions which is
kind of ugly - one needs to sift thru a lot of noise and long stack
traces to find the relevant error.

So. to make it more user-friendly, I instead modified BundleGlobalContext
to log each source exception's suppressed exceptions as these contain the
actual parsing failures. I also only printed the exception message
normally to avoid the stack trace noise. The full trace can be seen with
debug enabled.

Change-Id: Ie603bab3caa4fabc421ffbd106fddd5176743d2b
Signed-off-by: Tom Pantelis <tpanteli@brocade.com>
Signed-off-by: Robert Varga <rovarga@cisco.com>
yang/yang-maven-plugin/src/main/java/org/opendaylight/yangtools/yang2sources/plugin/YangToSourcesProcessor.java
yang/yang-parser-impl/src/main/java/org/opendaylight/yangtools/yang/parser/repo/YangTextSchemaContextResolver.java
yang/yang-parser-impl/src/main/java/org/opendaylight/yangtools/yang/parser/stmt/reactor/BuildGlobalContext.java
yang/yang-parser-impl/src/main/java/org/opendaylight/yangtools/yang/parser/stmt/reactor/SourceSpecificContext.java
yang/yang-parser-impl/src/main/java/org/opendaylight/yangtools/yang/parser/stmt/rfc6020/YangStatementSourceImpl.java
yang/yang-parser-impl/src/test/java/org/opendaylight/yangtools/yang/stmt/retest/YangParserNegativeTest.java

index ccbbc3c4d7c843803263525d7496bdb82c627931..195c7f39ba2c43da6220827b81e3d975a3c24915 100644 (file)
@@ -11,6 +11,7 @@ import java.util.HashSet;
 import org.opendaylight.yangtools.yang.parser.stmt.reactor.CrossSourceStatementReactor;
 import org.opendaylight.yangtools.yang.parser.stmt.rfc6020.YangInferencePipeline;
 import com.google.common.annotations.VisibleForTesting;
+import com.google.common.base.Throwables;
 import com.google.common.collect.Maps;
 import java.io.Closeable;
 import java.io.File;
@@ -185,8 +186,9 @@ class YangToSourcesProcessor {
             // MojoExecutionException is thrown since execution cannot continue
         } catch (Exception e) {
             LOG.error("{} Unable to parse {} files from {}", LOG_PREFIX, Util.YANG_SUFFIX, yangFilesRootDir, e);
+            Throwable rootCause = Throwables.getRootCause(e);
             throw new MojoExecutionException(LOG_PREFIX + " Unable to parse " + Util.YANG_SUFFIX + " files from " +
-                    yangFilesRootDir, e);
+                    yangFilesRootDir, rootCause);
         }
     }
 
index 32cf1529a0248997a14a1377476a11bf34c9b25b..7c0c9763ce99e903baf643536551bd9604e6f789 100644 (file)
@@ -203,7 +203,7 @@ public final class YangTextSchemaContextResolver implements AutoCloseable, Schem
                     sc = Optional.of(f.checkedGet());
                     break;
                 } catch (SchemaResolutionException e) {
-                    LOG.debug("Failed to fully assemble schema context for {}", sources, e);
+                    LOG.info("Failed to fully assemble schema context for {}", sources, e);
                     sources = e.getResolvedSources();
                 }
             }
index 86307f2c821f9ced07d1a7bb2f4512127f6389d7..14d450d56714d76082c7735d372e65e64200954d 100644 (file)
@@ -43,8 +43,11 @@ import org.opendaylight.yangtools.yang.parser.spi.validation.ValidationBundlesNa
 import org.opendaylight.yangtools.yang.parser.spi.validation.ValidationBundlesNamespace.ValidationBundleType;
 import org.opendaylight.yangtools.yang.parser.stmt.reactor.SourceSpecificContext.PhaseCompletionProgress;
 import org.opendaylight.yangtools.yang.parser.stmt.rfc6020.effective.EffectiveSchemaContext;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 
 class BuildGlobalContext extends NamespaceStorageSupport implements NamespaceBehaviour.Registry {
+    private static final Logger LOG = LoggerFactory.getLogger(BuildGlobalContext.class);
 
     private static final List<ModelProcessingPhase> PHASE_EXECUTION_ORDER = ImmutableList.<ModelProcessingPhase>builder()
             .add(ModelProcessingPhase.SOURCE_LINKAGE)
@@ -125,7 +128,7 @@ class BuildGlobalContext extends NamespaceStorageSupport implements NamespaceBeh
 
     @SuppressWarnings({"unchecked", "rawtypes"})
     private <K, V, N extends IdentifierNamespace<K, V>> NamespaceBehaviourWithListeners<K, V, N> createNamespaceContext(
-            NamespaceBehaviour<K, V, N> potentialRaw) {
+            final NamespaceBehaviour<K, V, N> potentialRaw) {
         if (potentialRaw instanceof DerivedNamespaceBehaviour) {
             VirtualNamespaceContext derivedContext =
                     new VirtualNamespaceContext((DerivedNamespaceBehaviour) potentialRaw);
@@ -211,9 +214,41 @@ class BuildGlobalContext extends NamespaceStorageSupport implements NamespaceBeh
 
     private SomeModifiersUnresolvedException addSourceExceptions(final SomeModifiersUnresolvedException buildFailure,
             final List<SourceSpecificContext> sourcesToProgress) {
-        for(SourceSpecificContext failedSource : sourcesToProgress) {
-            SourceException sourceEx = failedSource.failModifiers(currentPhase);
-            buildFailure.addSuppressed(sourceEx);
+        boolean addedCause = false;
+        for (SourceSpecificContext failedSource : sourcesToProgress) {
+            final SourceException sourceEx = failedSource.failModifiers(currentPhase);
+
+            // Workaround for broken logging implementations which ignore suppressed exceptions
+            Throwable cause = sourceEx.getCause() != null ? sourceEx.getCause() : sourceEx;
+            if (LOG.isDebugEnabled()) {
+                LOG.error("Failed to parse YANG from source {}", failedSource, sourceEx);
+            } else {
+                LOG.error("Failed to parse YANG from source {}: {}", failedSource, cause.getMessage());
+            }
+
+            final Throwable[] suppressed = sourceEx.getSuppressed();
+            if (suppressed.length > 0) {
+                LOG.error("{} additional errors reported:", suppressed.length);
+
+                int i = 1;
+                for (Throwable t : suppressed) {
+                    // FIXME: this should be configured in the appender, really
+                    if (LOG.isDebugEnabled()) {
+                        LOG.error("Error {}: {}", i, t.getMessage(), t);
+                    } else {
+                        LOG.error("Error {}: {}", i, t.getMessage());
+                    }
+
+                    i++;
+                }
+            }
+
+            if(!addedCause) {
+                addedCause = true;
+                buildFailure.initCause(sourceEx);
+            } else {
+                buildFailure.addSuppressed(sourceEx);
+            }
         }
         return buildFailure;
     }
index 34959de19adbea0b41a2f8cfead889ce3b286325..86ff1afa870a2bc4aa4a9b70e3a322ccd40bcc6e 100644 (file)
@@ -14,6 +14,7 @@ import com.google.common.collect.Multimap;
 import java.util.ArrayList;
 import java.util.Collection;
 import java.util.Iterator;
+import java.util.List;
 import java.util.Map;
 import java.util.Objects;
 import javax.annotation.Nullable;
@@ -276,17 +277,28 @@ public class SourceSpecificContext implements NamespaceStorageNode, NamespaceBeh
     }
 
     SourceException failModifiers(final ModelProcessingPhase identifier) {
-        InferenceException sourceEx = new InferenceException("Fail to infer source relationships", root.getStatementSourceReference());
-
-
+        final List<SourceException> exceptions = new ArrayList<>();
         for (ModifierImpl mod : modifiers.get(identifier)) {
             try {
                 mod.failModifier();
             } catch (SourceException e) {
-                sourceEx.addSuppressed(e);
+                exceptions.add(e);
             }
         }
-        return sourceEx;
+
+        final String message = String.format("Yang model processing phase %s failed", identifier);
+        if (exceptions.isEmpty()) {
+            return new InferenceException(message, root.getStatementSourceReference());
+        }
+
+        final InferenceException e = new InferenceException(message, root.getStatementSourceReference(),
+            exceptions.get(0));
+        final Iterator<SourceException> it = exceptions.listIterator(1);
+        while (it.hasNext()) {
+            e.addSuppressed(it.next());
+        }
+
+        return e;
     }
 
     void loadStatements() throws SourceException {
index 8a5519f6781427422050fd5374d203e1d43803bf..7910044ba319fcfd4f6a7a75b4fe24959ae8fd92 100644 (file)
@@ -141,6 +141,11 @@ public final class YangStatementSourceImpl implements StatementStreamSource {
         return statementContext;
     }
 
+    @Override
+    public String toString() {
+        return sourceName;
+    }
+
 //    public InputStream getSourceStream() {
 //        return sourceStream;
 //    }
index bfaea689bc988b3f42f23a90d2fa1c9ab42ad82b..9d82d20d8f9ed63c4588a8e33abff2cb8d1e5e34 100644 (file)
@@ -24,6 +24,7 @@ import org.opendaylight.yangtools.yang.parser.spi.meta.SomeModifiersUnresolvedEx
 import org.opendaylight.yangtools.yang.parser.spi.source.SourceException;
 import org.opendaylight.yangtools.yang.parser.util.YangParseException;
 import org.opendaylight.yangtools.yang.parser.util.YangValidationException;
+import com.google.common.base.Throwables;
 
 public class YangParserNegativeTest {
 
@@ -36,10 +37,10 @@ public class YangParserNegativeTest {
                 fail("SomeModifiersUnresolvedException should be thrown");
             }
         } catch (SomeModifiersUnresolvedException e) {
-            final Throwable suppressed2levelsDown = e.getSuppressed()[0].getSuppressed()[0];
-            assertTrue(suppressed2levelsDown instanceof InferenceException);
-            assertTrue(suppressed2levelsDown.getMessage().startsWith("Imported module"));
-            assertTrue(suppressed2levelsDown.getMessage().endsWith("was not found."));
+            Throwable rootCause = Throwables.getRootCause(e);
+            assertTrue(rootCause instanceof InferenceException);
+            assertTrue(rootCause.getMessage().startsWith("Imported module"));
+            assertTrue(rootCause.getMessage().endsWith("was not found."));
         }
     }
 
@@ -73,11 +74,11 @@ public class YangParserNegativeTest {
                 }
             }
         } catch (SomeModifiersUnresolvedException e) {
-            final Throwable suppressed2levelsDown = e.getSuppressed()[0].getSuppressed()[0];
-            assertTrue(suppressed2levelsDown instanceof InferenceException);
+            final Throwable rootCause = Throwables.getRootCause(e);
+            assertTrue(rootCause instanceof InferenceException);
             assertEquals(
                     "Augment target not found: Absolute{path=[(urn:simple.container.demo?revision=1970-01-01)unknown]}",
-                    suppressed2levelsDown.getMessage());
+                    rootCause.getMessage());
         }
     }