chemistry-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Bindu Wavell <bwav...@google.com>
Subject Re: Infinite loop in AtomEntryParser
Date Sat, 22 Mar 2014 20:21:49 GMT
I'm relatively certain there is a "bug" in chemistry 0.7, I'm relatively
certain it is fixed in 0.10. The reason I put bug in double quotes is that
the actual bug is really a problem in either xerces or woodstox or
something else that interacts with xml under chemistry. But, this bug is
triggered by something chemistry is doing that I suspect is naughty.

In the skip() method in AtomEntryParser in 0.7 you'll see a while loop
calling next(). There is a try catch wrapping parser.next() and an
IOException wrapped in an XMLStreamException (yeah next in
BasicStreamReader in woodstox does that for read timed out, reaching end of
file before we are done parsing, etc) hits the catch block and is eaten and
breaks us out of the while loop in skip(). Then an extra next() is called
in skip(). This call to next() after the stream has thrown the IO exception
seems quite dubious. And with the xerces/woodstox included with Alfresco
4.1.3 calling next after this exception causes the stream to reset and we
start re-parsing the atom entry all over again.

In chemistry 0.10 (maybe earlier) the try catch is removed and the
exception bubbles up and the additional next() is not called meaning we
don't (at least in this case) end up in an infinite loop reading the same
stuff over and over again.

For what it's worth, we have a createDocument atompub document you can send
to alfresco 4.1.3 using netcat and trigger this issue. If this is
interesting to folks on the chemistry team I can provide the file and
instructions. As the issue appears to be resolved in newer versions of
chemistry, I'm guessing it's not that important, but do let me know if you
want the file. On the other hand, I think this can be used to trigger a
denial of service attack against any code using the chemistry 0.7 server
stuff, so might be worth groking and possibly notifying some folks...





On Thu, Mar 20, 2014 at 11:38 AM, Bindu Wavell <bwavell@google.com> wrote:

> Thanks for your reply Florian. I too would like to be able to reproduce
> this issue, it would make things much easier to debug. Even having a live
> system experiencing the issue, it is quite difficult to get enough
> information from a profiler (can't attach a debugger to our live systems)
> to really understand in detail what the problem is.
>
> It seems to me that woodstox has an issue where next() is looping
> infinitely or we are producing an atompub document with a hell of a lot of
> atom:entry elements. I'm leaning towards the former. Partly because I am
> able to reproduce a different issue that seems to be related.
>
> I have a document where the document name contains some strange
> characters, when I upload this document via Alfresco Workdesk using their
> html5 drag-and-drop uploader the create atom pub document ends with
> <chemistry:filename>  i.e. the document is incomplete. This results in an
> invalid space exception from woodstox when alfresco/opencmis-server tries
> to parse the document.
>
> Here is the incomplete creation atompub document that is sent to alfresco:
>
> <?xml version='1.0' encoding='UTF-8'?><atom:entry xmlns:atom="
> http://www.w3.org/2005/Atom" xmlns:cmis="
> http://docs.oasis-open.org/ns/cmis/core/200908/" xmlns:cmisra="
> http://docs.oasis-open.org/ns/cmis/restatom/200908/" xmlns:chemistry="
> http://chemistry.apache.org/"><atom:id>urn:uuid:00000000-0000-0000-0000-00000000000</atom:id><atom:title>Exhibit
> 2.2(c) to Series F Disclosure Schedule
> </atom:title><atom:updated>2014-03-20T16:56:51Z</atom:updated><cmisra:content><cmisra:mediatype>application/vnd.openxmlformats-officedocument.spreadsheetml.sheet</cmisra:mediatype><chemistry:filename>
>
> Here is a zip containing the document with the strange characters in the
> name, note the zip may also have the strange characters in the name. I made
> the zip to protect the original filename as certain things like email
> clients will "fix" the name of an attachment...
>
>
> https://dl.dropboxusercontent.com/u/54062/forum%20attachments/Exhibit%202.2(c)%20to%20Series%20F%20Disclosure%20Schedule%20%E2%80%93%20Capitalization%20Table.xlsx.zip
>
> For what it's worth, I don't think that this particular use case triggers
> the memory explosion, but it is indicative of some problems with
> serializing and deserializing in
> wordkesk/alfresco/opencmis/woodstox/xerces...
>
> We are using Tomcat, I'll see if I can find an open network connection
> that is spewing a lot of data the next time the issue occurs (for what it's
> worth I looked in my YourKit dump and did not see that, but I'm not
> confident in that answer.)
>
> I'm not sure which timeouts you are referring to, we have timeouts
> configured for opencmis-client in workdesk, not sure if alfresco configures
> timeouts (I assume they do)... We have increased the timeouts for workdesk.
> We have the connection timeout set to 10000 and the readtimeout set to
> 60000. I'm not sure if there is a write timeout, but I don't see one in the
> config, so I assume it would use the default.
>
>
>
> On Thu, Mar 20, 2014 at 10:51 AM, Florian Müller <fmui@apache.org> wrote:
>
>> Hi Bindu,
>>
>> I've scanned the OpenCMIS and Woodstox code again, but I can't find the
>> cause of this issue. It's difficult without being able to reproduce this.
>> I can exclude at least that OpenCMIS parses the entry over and over
>> again. The incoming stream is directly read and parsed. There is (at least
>> for OpenCMIS) no way to jump back and parse it again.
>>
>> There might be some kind of IO issue (see the exceptions). What servlet
>> container do you use? Is there a proxy or firewall between the client and
>> the server?
>> In one of your emails I found this: "Frozen for at least 47m 15 sec".
>> Usually a connection times out when no bytes are transferred. Did you
>> disable the timeout on the client and the server? If not, the client must
>> send more and more data, but I don't know how. The OpenCMIS client doesn't
>> do that. Could you check if there is steady incoming network traffic when
>> the server is in that state?
>>
>> - Florian
>>
>>
>>
>>  I should add that I'm seeing 3.6 million of the following three
>>> exceptions
>>> (with associate stacks resulting in the exception):
>>>
>>> com.ctc.wstx.exc.WstxParsingException
>>>   BasicStreamReader.readPIPrimary()
>>>     BasicStreamReader.nextFromTree()
>>>       BasicStreamReader.next()
>>>         AtomEntryParser.next()
>>>           AtomEntryParser.skip()
>>>             AtomEntryParser.parseCmisContent()
>>>               AtomEntryParser.parseEntry()
>>>                 AtomEntryParser.parse()
>>>                   ObjectService.create()
>>>
>>> java.io.IOException
>>>   ChunkedInputFilter.doRead()
>>>     InternalInputBuffer.doRead()
>>>       Request.doRead()
>>>         InputBuffer.realReadBytes()
>>>           ByteChunk.substract()
>>>             InputBuffer.read()
>>>               CoyoteInputStream.read()
>>>                 UTF8Reader.loadMore()
>>>                   UTF8Reader.read()
>>>                     ReaderSource.readInto()
>>>                       BranchingReaderSource.readInto()
>>>                         StreamScanner.loadMore()
>>>
>>> com.ctc.wstx.exc.WstxIOException
>>>   BasicStreamReader.next()
>>>     AtomEntryParser.next()
>>>       AtomEntryParser.skip()
>>>         AtomEntryParser.parseCmisContent()
>>>           AtomEntryParser.parseEntry()
>>>             AtomEntryParser.parse()
>>>               ObjectService.create()
>>>
>>>
>>> Looking at the 3.2.4 version of com.ctc.wstx.sr.BasicStreamReader I see
>>> the
>>> following in readPIPrimary()
>>>
>>>
>>> if (target.equalsIgnoreCase
>>>
>>> <http://grepcode.com/file/repository.grepcode.com/java/
>>> root/jdk/openjdk/6-b27/java/lang/String.java#String.
>>> equalsIgnoreCase%28java.lang.String%29>("xml"))
>>>
>>> {
>>>
>>>     // 07-Oct-2005, TSa: Still legal in multi-doc mode...
>>>
>>>     if (!mConfig
>>>
>>> <http://grepcode.com/file/repo1.maven.org/maven2/org.
>>> codehaus.woodstox/wstx-asl/3.2.4/com/ctc/wstx/sr/StreamScanner.java#
>>> StreamScanner.0mConfig>.inputParsingModeDocuments
>>>
>>> <http://grepcode.com/file/repo1.maven.org/maven2/org.
>>> codehaus.woodstox/wstx-asl/3.2.4/com/ctc/wstx/api/ReaderConfig.java#
>>> ReaderConfig.inputParsingModeDocuments%28%29>())
>>> {
>>>
>>>         throwParseError
>>>
>>> <http://grepcode.com/file/repo1.maven.org/maven2/org.
>>> codehaus.woodstox/wstx-asl/3.2.4/com/ctc/wstx/sr/StreamScanner.java#
>>> StreamScanner.throwParseError%28java.lang.String%2Cjava.lang.Object%29
>>> >(ErrorConsts
>>>
>>> <http://grepcode.com/file/repo1.maven.org/maven2/org.
>>> codehaus.woodstox/wstx-asl/3.2.4/com/ctc/wstx/cfg/
>>> ErrorConsts.java#ErrorConsts.0ERR_WF_PI_XML_TARGET>.ERR_WF_PI_XML_TARGET
>>>
>>> <http://grepcode.com/file/repo1.maven.org/maven2/org.
>>> codehaus.woodstox/wstx-asl/3.2.4/com/ctc/wstx/cfg/
>>> ErrorConsts.java#ErrorConsts.0ERR_WF_PI_XML_TARGET>,
>>>
>>> target);
>>>
>>>     }
>>>
>>>
>>> I also see next() catching IOException and throwing
>>> com.ctc.wstx.exc.WstxIOException.
>>>
>>> Does this mean that cmisra:content somehow contains another xml document
>>> with an xml root processing instruction? Since I'm not sure how to
>>> capture
>>> the source AtomPub document that is triggering this I find that I'm
>>> really
>>> grasping at straws, I hope someone with more experience in the code base
>>> can shed some light :)
>>>
>>> Thanks for reading through my ramblings...
>>>
>>>
>>>
>>> On Wed, Mar 19, 2014 at 8:33 PM, Bindu Wavell <bwavell@google.com>
>>> wrote:
>>>
>>>  As I said we had a bunch of very large string arrays allocated and
>>>> collected... These huge arrays have the following list of strings over
>>>> and
>>>> again (as indicated in the linked picture):
>>>>
>>>> atom
>>>> entry
>>>> http://www.w3.org/2005/Atom
>>>> cmisra
>>>> content
>>>> http://docs.oasis-open.org/ns/cmis/restatom/200908/
>>>> chemistry
>>>> filename
>>>> http://chemistry.apache.org/
>>>>
>>>> Since Alfresco Workdesk 4.1.1.1 is using the openchemistry 0.8.0 AtomPub
>>>> client the chemistry:filename element is included in the cmisra:content
>>>> element. The parser in openchemistry 0.7.0 is trying to skip this
>>>> (because
>>>> it doesn't know about the chemistry:filename extension.) Notice that we
>>>> aren't seeing cmisra:mediatype or cmisra:base64 here.
>>>>
>>>> For some reason this is introducing a parsing loop where we re-parse the
>>>> atom:entry over and over again. I guess it's possible the client is
>>>> producing this repetition too...
>>>>
>>>>
>>>>
>>>> On Wed, Mar 19, 2014 at 3:18 PM, Bindu Wavell <bwavell@google.com>
>>>> wrote:
>>>>
>>>>  I believe they are using 3.2.4, assuming this is the right
>>>>> jar: wstx-asl-3.2.4.jar
>>>>>
>>>>>
>>>>> On Wed, Mar 19, 2014 at 2:11 PM, Florian Müller <fmui@apache.org>
>>>>> wrote:
>>>>>
>>>>>  Hi Bindu,
>>>>>>
>>>>>> I've never seen something like this. Do you know which Woodstox
>>>>>> version
>>>>>> is used?
>>>>>>
>>>>>> The CappedInputStream is something different. It prevents malicious
>>>>>> clients from sending an endless XML and consuming server resources.
>>>>>>
>>>>>>
>>>>>> - Florian
>>>>>>
>>>>>>
>>>>>>
>>>>>> > Our server is Alfresco Enterprise 4.1.3.0 which is in turn using
>>>>>> > openchemistry 0.7.0. Our client is Alfresco Workdesk 4.1.1.1
which
>>>>>> is
>>>>>> in
>>>>>> > turn using openchemistry 0.8.0.
>>>>>> >
>>>>>> > For the last few weeks we have run into a situation where the
>>>>>> Alfresco
>>>>>> > server becomes unresponsive. Specifically it doesn't crash it
simply
>>>>>> > becomes so overloaded that we can't login via Workdesk/CMIS.
Using
>>>>>> > JConsole and subsequently YourKit we can see that the server
runs
>>>>>> fine
>>>>>> > and uses between 3-6GB of RAM with nice slow growth and cleanup.
>>>>>> Then
>>>>>> at
>>>>>> > some point we see a huge amount of memory allocation and
>>>>>> deallocation
>>>>>> > between 3GB and 15GB every couple of seconds and this occurs
forever
>>>>>> > until we restart the server. The parallel GC cleaning up this
memory
>>>>>> > consumes so much CPU that folks can't actually use the system.
>>>>>> >
>>>>>> > To begin with we took a stackshot every 10 seconds for a minute.
We
>>>>>> saw
>>>>>> > that there were 5 opencmis threads "frozen" while parsing an
AtomPub
>>>>>> > document. They were not deadlocked. Subsequently we found the
same
>>>>>> thing
>>>>>> > using YourKit, it calls these frozen threads. Following is an
>>>>>> example
>>>>>> > stack trace from YourKit:
>>>>>> >
>>>>>> > http-127.0.0.1-8080-2 <--- Frozen for at least 47m 15 sec
>>>>>> > com.ctc.wstx.sr.StreamScanner.getNext()
>>>>>> > com.ctc.wstx.sr.BasicStreamReader.skipToken()
>>>>>> > com.ctc.wstx.sr.BasicStreamReader.nextFromTree()
>>>>>> > com.ctc.wstx.sr.BasicStreamReader.next()
>>>>>> >
>>>>>>
>>>>>> org.apache.chemistry.opencmis.server.impl.atompub.
>>>>>> AtomEntryParser.next(XMLStreamReader)
>>>>>> >
>>>>>>
>>>>>> org.apache.chemistry.opencmis.server.impl.atompub.
>>>>>> AtomEntryParser.skip(XMLStreamReader)
>>>>>> >
>>>>>>
>>>>>> org.apache.chemistry.opencmis.server.impl.atompub.AtomEntryParser.
>>>>>> parseCmisContent(XMLStreamReader)
>>>>>> >
>>>>>>
>>>>>> org.apache.chemistry.opencmis.server.impl.atompub.
>>>>>> AtomEntryParser.parseEntry(XMLStreamReader)
>>>>>> >
>>>>>>
>>>>>> org.apache.chemistry.opencmis.server.impl.atompub.
>>>>>> AtomEntryParser.parse(InputStream)
>>>>>> >
>>>>>>
>>>>>> org.apache.chemistry.opencmis.server.impl.atompub.
>>>>>> ObjectService.create(CallContext,
>>>>>> > CmisService, String, HttpServletRequest, HttpServletResponse)
>>>>>> > sun.reflect.NativeMethodAccessorImpl.invoke0(Method, Object,
>>>>>> Object[])
>>>>>> > sun.reflect.NativeMethodAccessorImpl.invoke(Object, Object[])
>>>>>> > sun.reflect.DelegatingMethodAccessorImpl.invoke(Object, Object[])
>>>>>> > java.lang.reflect.Method.invoke(Object, Object[])
>>>>>> > org.apache.chemistry.opencmis.server.shared.Dispatcher.
>>>>>> dispatch(String,
>>>>>> > String, CallContext, CmisService, String, HttpServletRequest,
>>>>>> > HttpServletResponse)
>>>>>> >
>>>>>>
>>>>>> org.apache.chemistry.opencmis.server.impl.atompub.
>>>>>> CmisAtomPubServlet.dispatch(CallContext,
>>>>>> > HttpServletRequest, HttpServletResponse)
>>>>>> >
>>>>>>
>>>>>> org.apache.chemistry.opencmis.server.impl.atompub.
>>>>>> CmisAtomPubServlet.service(HttpServletRequest,
>>>>>> > HttpServletResponse)
>>>>>> > javax.servlet.http.HttpServlet.service(ServletRequest,
>>>>>> ServletResponse)
>>>>>> >
>>>>>>
>>>>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(
>>>>>> ServletRequest,
>>>>>> > ServletResponse)
>>>>>> >
>>>>>>
>>>>>> org.apache.catalina.core.ApplicationFilterChain.
>>>>>> doFilter(ServletRequest,
>>>>>> > ServletResponse)
>>>>>> >
>>>>>>
>>>>>> org.alfresco.web.app.servlet.GlobalLocalizationFilter.
>>>>>> doFilter(ServletRequest,
>>>>>> > ServletResponse, FilterChain)
>>>>>> >
>>>>>>
>>>>>> org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(
>>>>>> ServletRequest,
>>>>>> > ServletResponse)
>>>>>> >
>>>>>>
>>>>>> org.apache.catalina.core.ApplicationFilterChain.
>>>>>> doFilter(ServletRequest,
>>>>>> > ServletResponse)
>>>>>> > org.apache.catalina.core.StandardWrapperValve.invoke(Request,
>>>>>> Response)
>>>>>> > org.apache.catalina.core.StandardContextValve.invoke(Request,
>>>>>> Response)
>>>>>> > org.apache.catalina.authenticator.AuthenticatorBase.invoke(Request,
>>>>>> > Response)
>>>>>> > org.apache.catalina.core.StandardHostValve.invoke(Request,
>>>>>> Response)
>>>>>> > org.apache.catalina.valves.ErrorReportValve.invoke(Request,
>>>>>> Response)
>>>>>> > org.apache.catalina.core.StandardEngineValve.invoke(Request,
>>>>>> Response)
>>>>>> > org.apache.catalina.connector.CoyoteAdapter.service(Request,
>>>>>> Response)
>>>>>> > org.apache.coyote.http11.Http11Processor.process(Socket)
>>>>>> >
>>>>>>
>>>>>> org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.
>>>>>> process(Socket)
>>>>>> > org.apache.tomcat.util.net.JIoEndpoint$Worker.run()
>>>>>> > java.lang.Thread.run()
>>>>>> >
>>>>>> > By inspecting garbage collected objects we can see that this
is
>>>>>> almost
>>>>>> > all string[] tied back to AtomEntryParser (and the woodstox
parser
>>>>>> stuff
>>>>>> > under it.) If we look at one of these arrays we see the same
stuff
>>>>>> over
>>>>>> > and over again... see a screenshot here of the first few elements
in
>>>>>> > such an array: http://i.imgur.com/RzNQBYG.png . There are a
bunch
>>>>>> of
>>>>>> > these VERY large string arrays and they all look like they are
>>>>>> looping
>>>>>> > over the front of an AtomPub document.
>>>>>> >
>>>>>> > I noticed in opencmis 0.9.0 in the implementation of AtomEntryParser
>>>>>> > that a CappedInputStream was added while parsing the AtomPub
stream.
>>>>>> > This appears to be limited to 10MB. Not sure if that is related
to
>>>>>> this
>>>>>> > issue. Or if others have run into this issue. Any thought/guidance
>>>>>> would
>>>>>> > be greatly appreciated.
>>>>>> >
>>>>>> > I'm bcc'ing Florian and Gab (the spy) but figured it was worth
>>>>>> having
>>>>>> > this public as I've been trying to track this issue down for
a while
>>>>>> and
>>>>>> > have not found an answer.
>>>>>> >
>>>>>> > Thanks all!
>>>>>>
>>>>>>
>>>>>
>>>>>
>>>>
>>
>

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message