Better handling of invalid XML: a) prevent infinite loop on EOF; b) better logging

If the XML was truncated for some reason then ExecuteReadProcessors() would get into an infinite loop, using high CPU. Now it detects EOF (and several other error cases) and aborts.

The rest of the changes just improve logging of XML in case of errors, so that we can see what the bad XML is.

5 files changed, 115 insertions, 69 deletions

diff --git a/OpenSim/Framework/Serialization/External/ExternalRepresentationUtils.cs b/OpenSim/Framework/Serialization/External/ExternalRepresentationUtils.cs
index 1254086..55640ac 100644
--- a/OpenSim/Framework/Serialization/External/ExternalRepresentationUtils.cs
+++ b/OpenSim/Framework/Serialization/External/ExternalRepresentationUtils.cs
@@ -27,6 +27,7 @@
 
 using System;
 using System.Collections.Generic;
+using System.Diagnostics;
 using System.IO;
 using System.Reflection;
 using System.Xml;
@@ -47,7 +48,7 @@ namespace OpenSim.Framework.Serialization.External
         /// Populate a node with data read from xml using a dictinoary of processors
         /// </summary>
         /// <param name="nodeToFill"></param>
-        /// <param name="processors">/param>
+        /// <param name="processors"></param>
         /// <param name="xtr"></param>
         /// <returns>true on successful, false if there were any processing failures</returns>
         public static bool ExecuteReadProcessors<NodeType>(
@@ -57,10 +58,10 @@ namespace OpenSim.Framework.Serialization.External
                 nodeToFill,
                 processors,
                 xtr,
-                (o, name, e)
-                    => m_log.DebugFormat(
-                        "[ExternalRepresentationUtils]: Exception while parsing element {0}, continuing.  Exception {1}{2}",
-                        name, e.Message, e.StackTrace));
+                (o, nodeName, e) => {
+                    m_log.Debug(string.Format("[ExternalRepresentationUtils]: Error while parsing element {0} ",
+                        nodeName), e);
+                });
         }
 
         /// <summary>
@@ -80,18 +81,22 @@ namespace OpenSim.Framework.Serialization.External
             Action<NodeType, string, Exception> parseExceptionAction)
         {
             bool errors = false;
+            int numErrors = 0;
+
+            Stopwatch timer = new Stopwatch();
+            timer.Start();
 
             string nodeName = string.Empty;
             while (xtr.NodeType != XmlNodeType.EndElement)
             {
                 nodeName = xtr.Name;
 
-//                        m_log.DebugFormat("[ExternalRepresentationUtils]: Processing: {0}", nodeName);
+                // m_log.DebugFormat("[ExternalRepresentationUtils]: Processing node: {0}", nodeName);
 
                 Action<NodeType, XmlReader> p = null;
                 if (processors.TryGetValue(xtr.Name, out p))
                 {
-//                            m_log.DebugFormat("[ExternalRepresentationUtils]: Found {0} processor, nodeName);
+                    // m_log.DebugFormat("[ExternalRepresentationUtils]: Found processor for {0}", nodeName);
 
                     try
                     {
@@ -101,6 +106,18 @@ namespace OpenSim.Framework.Serialization.External
                     {
                         errors = true;
                         parseExceptionAction(nodeToFill, nodeName, e);
+                        
+                        if (xtr.EOF)
+                        {
+                            m_log.Debug("[ExternalRepresentationUtils]: Aborting ExecuteReadProcessors due to unexpected end of XML");
+                            break;
+                        }
+                        
+                        if (++numErrors == 10)
+                        {
+                            m_log.Debug("[ExternalRepresentationUtils]: Aborting ExecuteReadProcessors due to too many parsing errors");
+                            break;
+                        }
 
                         if (xtr.NodeType == XmlNodeType.EndElement)
                             xtr.Read();
@@ -108,9 +125,16 @@ namespace OpenSim.Framework.Serialization.External
                 }
                 else
                 {
-                    // m_log.DebugFormat("[LandDataSerializer]: caught unknown element {0}", nodeName);
+                    // m_log.DebugFormat("[ExternalRepresentationUtils]: found unknown element \"{0}\"", nodeName);
                     xtr.ReadOuterXml(); // ignore
                 }
+
+                if (timer.Elapsed.TotalSeconds >= 60)
+                {
+                    m_log.Debug("[ExternalRepresentationUtils]: Aborting ExecuteReadProcessors due to timeout");
+                    errors = true;
+                    break;
+                }
             }
 
             return errors;
diff --git a/OpenSim/Framework/Util.cs b/OpenSim/Framework/Util.cs
index 875f4ad..a5f798d 100644
--- a/OpenSim/Framework/Util.cs
+++ b/OpenSim/Framework/Util.cs
@@ -2910,6 +2910,16 @@ namespace OpenSim.Framework
 
             return name;
         }
+
+        public static void LogFailedXML(string message, string xml)
+        {
+            int length = xml.Length;
+            if (length > 2000)
+                xml = xml.Substring(0, 2000) + "...";
+
+            m_log.ErrorFormat("{0} Failed XML ({1} bytes) = {2}", message, length, xml);
+        }
+
     }
 
     public class DoubleQueue<T> where T:class
diff --git a/OpenSim/Region/Framework/Scenes/Scene.Inventory.cs b/OpenSim/Region/Framework/Scenes/Scene.Inventory.cs
index ac27716..b838177 100644
--- a/OpenSim/Region/Framework/Scenes/Scene.Inventory.cs
+++ b/OpenSim/Region/Framework/Scenes/Scene.Inventory.cs
@@ -2243,13 +2243,25 @@ namespace OpenSim.Region.Framework.Scenes
 
                         if (isSingleObject || isAttachment)
                         {
-                            SceneObjectGroup g = SceneObjectSerializer.FromOriginalXmlFormat(reader);
+                            SceneObjectGroup g;
+                            try
+                            {
+                                g = SceneObjectSerializer.FromOriginalXmlFormat(reader);
+                            }
+                            catch (Exception e)
+                            {
+                                m_log.Error("[AGENT INVENTORY]: Deserialization of xml failed ", e);
+                                Util.LogFailedXML("[AGENT INVENTORY]:", xmlData);
+                                g = null;
+                            }
+                            
                             if (g != null)
                             {
                                 objlist.Add(g);
                                 veclist.Add(Vector3.Zero);
                                 bbox = g.GetAxisAlignedBoundingBox(out offsetHeight);
                             }
+
                             return true;
                         }
                         else
@@ -2291,9 +2303,8 @@ namespace OpenSim.Region.Framework.Scenes
             }
             catch (Exception e)
             {
-                m_log.Error(
-                    "[AGENT INVENTORY]: Deserialization of xml failed when looking for CoalescedObject tag.  Exception ", 
-                    e);
+                m_log.Error("[AGENT INVENTORY]: Deserialization of xml failed when looking for CoalescedObject tag ", e);
+                Util.LogFailedXML("[AGENT INVENTORY]:", xmlData);
             }
 
             return true;
diff --git a/OpenSim/Region/Framework/Scenes/Serialization/CoalescedSceneObjectsSerializer.cs b/OpenSim/Region/Framework/Scenes/Serialization/CoalescedSceneObjectsSerializer.cs
index a556f9d..998789d 100644
--- a/OpenSim/Region/Framework/Scenes/Serialization/CoalescedSceneObjectsSerializer.cs
+++ b/OpenSim/Region/Framework/Scenes/Serialization/CoalescedSceneObjectsSerializer.cs
@@ -178,10 +178,8 @@ namespace OpenSim.Region.Framework.Scenes.Serialization
             }
             catch (Exception e)
             {
-                m_log.Error(string.Format(
-                    "[COALESCED SCENE OBJECTS SERIALIZER]: Deserialization of xml failed with {0} ", 
-                    e.Message), e);
-                        
+                m_log.Error("[COALESCED SCENE OBJECTS SERIALIZER]: Deserialization of xml failed ",  e);
+                Util.LogFailedXML("[COALESCED SCENE OBJECTS SERIALIZER]:", xml);
                 return false;
             }                        
             
diff --git a/OpenSim/Region/Framework/Scenes/Serialization/SceneObjectSerializer.cs b/OpenSim/Region/Framework/Scenes/Serialization/SceneObjectSerializer.cs
index 463ef22..4caa9cb 100644
--- a/OpenSim/Region/Framework/Scenes/Serialization/SceneObjectSerializer.cs
+++ b/OpenSim/Region/Framework/Scenes/Serialization/SceneObjectSerializer.cs
@@ -62,8 +62,20 @@ namespace OpenSim.Region.Framework.Scenes.Serialization
         {
             String fixedData = ExternalRepresentationUtils.SanitizeXml(xmlData);
             using (XmlTextReader wrappedReader = new XmlTextReader(fixedData, XmlNodeType.Element, null))
+            {
                 using (XmlReader reader = XmlReader.Create(wrappedReader, new XmlReaderSettings() { IgnoreWhitespace = true, ConformanceLevel = ConformanceLevel.Fragment }))
-                    return FromOriginalXmlFormat(reader);
+                {
+                    try {
+                        return FromOriginalXmlFormat(reader);
+                    }
+                    catch (Exception e)
+                    {
+                        m_log.Error("[SERIALIZER]: Deserialization of xml failed ", e);
+                        Util.LogFailedXML("[SERIALIZER]:", fixedData);
+                        return null;
+                    }
+                }
+            }
         }
 
         /// <summary>
@@ -76,43 +88,33 @@ namespace OpenSim.Region.Framework.Scenes.Serialization
             //m_log.DebugFormat("[SOG]: Starting deserialization of SOG");
             //int time = System.Environment.TickCount;
 
-            SceneObjectGroup sceneObject = null;
+            int linkNum;
 
-            try
-            {
-                int           linkNum;
+            reader.ReadToFollowing("RootPart");
+            reader.ReadToFollowing("SceneObjectPart");
+            SceneObjectGroup sceneObject = new SceneObjectGroup(SceneObjectPart.FromXml(reader));
+            reader.ReadToFollowing("OtherParts");
 
-                reader.ReadToFollowing("RootPart");
-                reader.ReadToFollowing("SceneObjectPart");
-                sceneObject = new SceneObjectGroup(SceneObjectPart.FromXml(reader));
-                reader.ReadToFollowing("OtherParts");
-
-                if (reader.ReadToDescendant("Part"))
+            if (reader.ReadToDescendant("Part"))
+            {
+                do
                 {
-                    do
+                    if (reader.ReadToDescendant("SceneObjectPart"))
                     {
-                        if (reader.ReadToDescendant("SceneObjectPart"))
-                        {
-                            SceneObjectPart part = SceneObjectPart.FromXml(reader);
-                            linkNum = part.LinkNum;
-                            sceneObject.AddPart(part);
-                            part.LinkNum = linkNum;
-                            part.TrimPermissions();
-                        }
-                    }                    
-                    while (reader.ReadToNextSibling("Part"));
-                }
-
-                // Script state may, or may not, exist. Not having any, is NOT
-                // ever a problem.
-                sceneObject.LoadScriptState(reader);
-            }
-            catch (Exception e)
-            {
-                m_log.ErrorFormat("[SERIALIZER]: Deserialization of xml failed.  Exception {0}", e);
-                return null;
+                        SceneObjectPart part = SceneObjectPart.FromXml(reader);
+                        linkNum = part.LinkNum;
+                        sceneObject.AddPart(part);
+                        part.LinkNum = linkNum;
+                        part.TrimPermissions();
+                    }
+                }                    
+                while (reader.ReadToNextSibling("Part"));
             }
 
+            // Script state may, or may not, exist. Not having any, is NOT
+            // ever a problem.
+            sceneObject.LoadScriptState(reader);
+
             return sceneObject;
         }
 
@@ -236,7 +238,8 @@ namespace OpenSim.Region.Framework.Scenes.Serialization
 
                 if (parts.Count == 0)
                 {
-                    m_log.ErrorFormat("[SERIALIZER]: Deserialization of xml failed: No SceneObjectPart nodes. xml was " + xmlData);
+                    m_log.Error("[SERIALIZER]: Deserialization of xml failed: No SceneObjectPart nodes");
+                    Util.LogFailedXML("[SERIALIZER]:", xmlData);
                     return null;
                 }
 
@@ -280,7 +283,8 @@ namespace OpenSim.Region.Framework.Scenes.Serialization
             }
             catch (Exception e)
             {
-                m_log.ErrorFormat("[SERIALIZER]: Deserialization of xml failed with {0}.  xml was {1}", e, xmlData);
+                m_log.Error("[SERIALIZER]: Deserialization of xml failed ", e);
+                Util.LogFailedXML("[SERIALIZER]:", xmlData);
                 return null;
             }
         }
@@ -708,7 +712,7 @@ namespace OpenSim.Region.Framework.Scenes.Serialization
         private static void ProcessShape(SceneObjectPart obj, XmlReader reader)
         {
             List<string> errorNodeNames;
-            obj.Shape = ReadShape(reader, "Shape", out errorNodeNames);
+            obj.Shape = ReadShape(reader, "Shape", out errorNodeNames, obj);
 
             if (errorNodeNames != null)
             {
@@ -1599,18 +1603,21 @@ namespace OpenSim.Region.Framework.Scenes.Serialization
 
             reader.ReadStartElement("SceneObjectPart");
 
-            ExternalRepresentationUtils.ExecuteReadProcessors(
+            bool errors = ExternalRepresentationUtils.ExecuteReadProcessors(
                 obj,
                 m_SOPXmlProcessors,
                 reader,
-                (o, nodeName, e)
-                    => m_log.DebugFormat(
-                        "[SceneObjectSerializer]: Exception while parsing {0} in object {1} {2}: {3}{4}",
-                        ((SceneObjectPart)o).Name, ((SceneObjectPart)o).UUID, nodeName, e.Message, e.StackTrace));
+                (o, nodeName, e) => {
+                    m_log.Debug(string.Format("[SceneObjectSerializer]: Error while parsing element {0} in object {1} {2} ",
+                        nodeName, ((SceneObjectPart)o).Name, ((SceneObjectPart)o).UUID), e);
+                });
+
+            if (errors)
+                throw new XmlException(string.Format("Error parsing object {0} {1}", obj.Name, obj.UUID));
 
             reader.ReadEndElement(); // SceneObjectPart
 
-            //m_log.DebugFormat("[XXX]: parsed SOP {0} - {1}", obj.Name, obj.UUID);
+            // m_log.DebugFormat("[SceneObjectSerializer]: parsed SOP {0} {1}", obj.Name, obj.UUID);
             return obj;
         }
 
@@ -1655,7 +1662,7 @@ namespace OpenSim.Region.Framework.Scenes.Serialization
         /// <param name="name">The name of the xml element containing the shape</param>
         /// <param name="errors">a list containing the failing node names.  If no failures then null.</param>
         /// <returns>The shape parsed</returns>
-        public static PrimitiveBaseShape ReadShape(XmlReader reader, string name, out List<string> errorNodeNames)
+        public static PrimitiveBaseShape ReadShape(XmlReader reader, string name, out List<string> errorNodeNames, SceneObjectPart obj)
         {
             List<string> internalErrorNodeNames = null;
 
@@ -1674,18 +1681,14 @@ namespace OpenSim.Region.Framework.Scenes.Serialization
                 shape,
                 m_ShapeXmlProcessors,
                 reader,
-                (o, nodeName, e)
-                    =>
-                    {
-//                        m_log.DebugFormat(
-//                            "[SceneObjectSerializer]: Exception while parsing Shape property {0}: {1}{2}",
-//                            nodeName, e.Message, e.StackTrace);
-                        if (internalErrorNodeNames == null)
-                            internalErrorNodeNames = new List<string>();
+                (o, nodeName, e) => {
+                    m_log.Debug(string.Format("[SceneObjectSerializer]: Error while parsing element {0} in Shape property of object {1} {2} ",
+                        nodeName, obj.Name, obj.UUID), e);
 
-                        internalErrorNodeNames.Add(nodeName);
-                    }
-            );
+                    if (internalErrorNodeNames == null)
+                            internalErrorNodeNames = new List<string>();
+                    internalErrorNodeNames.Add(nodeName);
+                });
 
             reader.ReadEndElement(); // Shape