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.
0.8.2-post-fixes
Oren Hurvitz 2015-07-05 16:05:01 +03:00
parent 373455a6fa
commit 4ad1468165
5 changed files with 115 additions and 69 deletions

View File

@ -27,6 +27,7 @@
using System; using System;
using System.Collections.Generic; using System.Collections.Generic;
using System.Diagnostics;
using System.IO; using System.IO;
using System.Reflection; using System.Reflection;
using System.Xml; 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 /// Populate a node with data read from xml using a dictinoary of processors
/// </summary> /// </summary>
/// <param name="nodeToFill"></param> /// <param name="nodeToFill"></param>
/// <param name="processors">/param> /// <param name="processors"></param>
/// <param name="xtr"></param> /// <param name="xtr"></param>
/// <returns>true on successful, false if there were any processing failures</returns> /// <returns>true on successful, false if there were any processing failures</returns>
public static bool ExecuteReadProcessors<NodeType>( public static bool ExecuteReadProcessors<NodeType>(
@ -57,10 +58,10 @@ namespace OpenSim.Framework.Serialization.External
nodeToFill, nodeToFill,
processors, processors,
xtr, xtr,
(o, name, e) (o, nodeName, e) => {
=> m_log.DebugFormat( m_log.Debug(string.Format("[ExternalRepresentationUtils]: Error while parsing element {0} ",
"[ExternalRepresentationUtils]: Exception while parsing element {0}, continuing. Exception {1}{2}", nodeName), e);
name, e.Message, e.StackTrace)); });
} }
/// <summary> /// <summary>
@ -80,18 +81,22 @@ namespace OpenSim.Framework.Serialization.External
Action<NodeType, string, Exception> parseExceptionAction) Action<NodeType, string, Exception> parseExceptionAction)
{ {
bool errors = false; bool errors = false;
int numErrors = 0;
Stopwatch timer = new Stopwatch();
timer.Start();
string nodeName = string.Empty; string nodeName = string.Empty;
while (xtr.NodeType != XmlNodeType.EndElement) while (xtr.NodeType != XmlNodeType.EndElement)
{ {
nodeName = xtr.Name; nodeName = xtr.Name;
// m_log.DebugFormat("[ExternalRepresentationUtils]: Processing: {0}", nodeName); // m_log.DebugFormat("[ExternalRepresentationUtils]: Processing node: {0}", nodeName);
Action<NodeType, XmlReader> p = null; Action<NodeType, XmlReader> p = null;
if (processors.TryGetValue(xtr.Name, out p)) 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 try
{ {
@ -101,6 +106,18 @@ namespace OpenSim.Framework.Serialization.External
{ {
errors = true; errors = true;
parseExceptionAction(nodeToFill, nodeName, e); 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) if (xtr.NodeType == XmlNodeType.EndElement)
xtr.Read(); xtr.Read();
@ -108,9 +125,16 @@ namespace OpenSim.Framework.Serialization.External
} }
else else
{ {
// m_log.DebugFormat("[LandDataSerializer]: caught unknown element {0}", nodeName); // m_log.DebugFormat("[ExternalRepresentationUtils]: found unknown element \"{0}\"", nodeName);
xtr.ReadOuterXml(); // ignore xtr.ReadOuterXml(); // ignore
} }
if (timer.Elapsed.TotalSeconds >= 60)
{
m_log.Debug("[ExternalRepresentationUtils]: Aborting ExecuteReadProcessors due to timeout");
errors = true;
break;
}
} }
return errors; return errors;

View File

@ -2910,6 +2910,16 @@ namespace OpenSim.Framework
return name; 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 public class DoubleQueue<T> where T:class

View File

@ -2243,13 +2243,25 @@ namespace OpenSim.Region.Framework.Scenes
if (isSingleObject || isAttachment) 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) if (g != null)
{ {
objlist.Add(g); objlist.Add(g);
veclist.Add(Vector3.Zero); veclist.Add(Vector3.Zero);
bbox = g.GetAxisAlignedBoundingBox(out offsetHeight); bbox = g.GetAxisAlignedBoundingBox(out offsetHeight);
} }
return true; return true;
} }
else else
@ -2291,9 +2303,8 @@ namespace OpenSim.Region.Framework.Scenes
} }
catch (Exception e) catch (Exception e)
{ {
m_log.Error( m_log.Error("[AGENT INVENTORY]: Deserialization of xml failed when looking for CoalescedObject tag ", e);
"[AGENT INVENTORY]: Deserialization of xml failed when looking for CoalescedObject tag. Exception ", Util.LogFailedXML("[AGENT INVENTORY]:", xmlData);
e);
} }
return true; return true;

View File

@ -178,10 +178,8 @@ namespace OpenSim.Region.Framework.Scenes.Serialization
} }
catch (Exception e) catch (Exception e)
{ {
m_log.Error(string.Format( m_log.Error("[COALESCED SCENE OBJECTS SERIALIZER]: Deserialization of xml failed ", e);
"[COALESCED SCENE OBJECTS SERIALIZER]: Deserialization of xml failed with {0} ", Util.LogFailedXML("[COALESCED SCENE OBJECTS SERIALIZER]:", xml);
e.Message), e);
return false; return false;
} }

View File

@ -62,8 +62,20 @@ namespace OpenSim.Region.Framework.Scenes.Serialization
{ {
String fixedData = ExternalRepresentationUtils.SanitizeXml(xmlData); String fixedData = ExternalRepresentationUtils.SanitizeXml(xmlData);
using (XmlTextReader wrappedReader = new XmlTextReader(fixedData, XmlNodeType.Element, null)) using (XmlTextReader wrappedReader = new XmlTextReader(fixedData, XmlNodeType.Element, null))
{
using (XmlReader reader = XmlReader.Create(wrappedReader, new XmlReaderSettings() { IgnoreWhitespace = true, ConformanceLevel = ConformanceLevel.Fragment })) 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> /// <summary>
@ -76,42 +88,32 @@ namespace OpenSim.Region.Framework.Scenes.Serialization
//m_log.DebugFormat("[SOG]: Starting deserialization of SOG"); //m_log.DebugFormat("[SOG]: Starting deserialization of SOG");
//int time = System.Environment.TickCount; //int time = System.Environment.TickCount;
SceneObjectGroup sceneObject = null; int linkNum;
try reader.ReadToFollowing("RootPart");
reader.ReadToFollowing("SceneObjectPart");
SceneObjectGroup sceneObject = new SceneObjectGroup(SceneObjectPart.FromXml(reader));
reader.ReadToFollowing("OtherParts");
if (reader.ReadToDescendant("Part"))
{ {
int linkNum; do
reader.ReadToFollowing("RootPart");
reader.ReadToFollowing("SceneObjectPart");
sceneObject = new SceneObjectGroup(SceneObjectPart.FromXml(reader));
reader.ReadToFollowing("OtherParts");
if (reader.ReadToDescendant("Part"))
{ {
do if (reader.ReadToDescendant("SceneObjectPart"))
{ {
if (reader.ReadToDescendant("SceneObjectPart")) SceneObjectPart part = SceneObjectPart.FromXml(reader);
{ linkNum = part.LinkNum;
SceneObjectPart part = SceneObjectPart.FromXml(reader); sceneObject.AddPart(part);
linkNum = part.LinkNum; part.LinkNum = linkNum;
sceneObject.AddPart(part); part.TrimPermissions();
part.LinkNum = linkNum; }
part.TrimPermissions(); }
} while (reader.ReadToNextSibling("Part"));
} }
while (reader.ReadToNextSibling("Part"));
}
// Script state may, or may not, exist. Not having any, is NOT // Script state may, or may not, exist. Not having any, is NOT
// ever a problem. // ever a problem.
sceneObject.LoadScriptState(reader); sceneObject.LoadScriptState(reader);
}
catch (Exception e)
{
m_log.ErrorFormat("[SERIALIZER]: Deserialization of xml failed. Exception {0}", e);
return null;
}
return sceneObject; return sceneObject;
} }
@ -236,7 +238,8 @@ namespace OpenSim.Region.Framework.Scenes.Serialization
if (parts.Count == 0) 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; return null;
} }
@ -280,7 +283,8 @@ namespace OpenSim.Region.Framework.Scenes.Serialization
} }
catch (Exception e) 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; return null;
} }
} }
@ -708,7 +712,7 @@ namespace OpenSim.Region.Framework.Scenes.Serialization
private static void ProcessShape(SceneObjectPart obj, XmlReader reader) private static void ProcessShape(SceneObjectPart obj, XmlReader reader)
{ {
List<string> errorNodeNames; List<string> errorNodeNames;
obj.Shape = ReadShape(reader, "Shape", out errorNodeNames); obj.Shape = ReadShape(reader, "Shape", out errorNodeNames, obj);
if (errorNodeNames != null) if (errorNodeNames != null)
{ {
@ -1599,18 +1603,21 @@ namespace OpenSim.Region.Framework.Scenes.Serialization
reader.ReadStartElement("SceneObjectPart"); reader.ReadStartElement("SceneObjectPart");
ExternalRepresentationUtils.ExecuteReadProcessors( bool errors = ExternalRepresentationUtils.ExecuteReadProcessors(
obj, obj,
m_SOPXmlProcessors, m_SOPXmlProcessors,
reader, reader,
(o, nodeName, e) (o, nodeName, e) => {
=> m_log.DebugFormat( m_log.Debug(string.Format("[SceneObjectSerializer]: Error while parsing element {0} in object {1} {2} ",
"[SceneObjectSerializer]: Exception while parsing {0} in object {1} {2}: {3}{4}", nodeName, ((SceneObjectPart)o).Name, ((SceneObjectPart)o).UUID), e);
((SceneObjectPart)o).Name, ((SceneObjectPart)o).UUID, nodeName, e.Message, e.StackTrace)); });
if (errors)
throw new XmlException(string.Format("Error parsing object {0} {1}", obj.Name, obj.UUID));
reader.ReadEndElement(); // SceneObjectPart 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; 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="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> /// <param name="errors">a list containing the failing node names. If no failures then null.</param>
/// <returns>The shape parsed</returns> /// <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; List<string> internalErrorNodeNames = null;
@ -1674,18 +1681,14 @@ namespace OpenSim.Region.Framework.Scenes.Serialization
shape, shape,
m_ShapeXmlProcessors, m_ShapeXmlProcessors,
reader, reader,
(o, nodeName, e) (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);
// m_log.DebugFormat(
// "[SceneObjectSerializer]: Exception while parsing Shape property {0}: {1}{2}",
// nodeName, e.Message, e.StackTrace);
if (internalErrorNodeNames == null)
internalErrorNodeNames = new List<string>();
internalErrorNodeNames.Add(nodeName); if (internalErrorNodeNames == null)
} internalErrorNodeNames = new List<string>();
); internalErrorNodeNames.Add(nodeName);
});
reader.ReadEndElement(); // Shape reader.ReadEndElement(); // Shape