JRuby (please use github issues at http://bugs.jruby.org)
  1. JRuby (please use github issues at http://bugs.jruby.org)
  2. JRUBY-2282

Unclosed, unflushed IO objects might not write contents before program exit

    Details

    • Type: Bug Bug
    • Status: Closed Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: JRuby 1.1RC2
    • Fix Version/s: JRuby 1.5
    • Component/s: Core Classes/Modules
    • Labels:
      None
    • Environment:
      Leopard on a Core 2 Duo
    • Number of attachments :
      1

      Description

      When writing some documents with REXML to a file, the output ends at around 16k, even if it's in the middle of a tag. This is not true for all documents, but for some. I guess it's an IO error (it works with StringIO), but I couldn't find anything that sounded quite like it in recent bug reports, so I hope this is not a hidden duplicate.

      Steps to reproduce:
      Unzip test.xml from: http://www.raschke.de/julian/xml_before_after.zip
      Run: jruby -rrexml/document -e "REXML::Document.new(File.new('test.xml')).write File.new('test2.xml', 'w')"
      Compare test.xml and test2.xml.

        Issue Links

          Activity

          Hide
          Thomas E Enebo added a comment -

          Base length limit issue still exists, but I have some info to dump here...

          A few notes:

          1. In current Ruby/rexml attributes with same name get overwritten:

          <x xxxx="1" xxxx="2"/>
          

          Will get written out with only a single xxxx attribute. Both MRI and JRuby do this properly. Differences between source and dest xml of this nature are fine.

          2. attribute order can swap

          13,14c13,14
          <     <xxxxxx xxxxxx='x' xxx='xxxxx//xxxxxxxxxxxxxxxx/xxxxx/xxxxxxxxxx/xxx'/>
          <     <xxxxxx xxxxxx='xx' xxx='xxxxx//xxxxxxxxxxxxxxxx/xxxxx/xxxxxxx/xxx'/>
          ---
          >     <xxxxxx xxx='xxxxx//xxxxxxxxxxxxxxxx/xxxxx/xxxxxxxxxx/xxx' xxxxxx='x'/>
          >     <xxxxxx xxx='xxxxx//xxxxxxxxxxxxxxxx/xxxxx/xxxxxxx/xxx' xxxxxx='xx'/>
          

          Both JRuby and MRI also do this...no problems here

          3. File.new as case specified still has issue reported, but interestingly $stdout works fine. So this is isolated to Files. I bet we are missing an implicit close. I suspect this bug is same as JRUBY-2305 and some other bug that I cannot find, but I know was not resolved (implicit finalization IO bug). BINGO!

          Adding output.flush to formatters/default.rb#write solves the issue. So this is due to us not finalizing the IO object as it goes away.

          Show
          Thomas E Enebo added a comment - Base length limit issue still exists, but I have some info to dump here... A few notes: 1. In current Ruby/rexml attributes with same name get overwritten: <x xxxx="1" xxxx="2"/> Will get written out with only a single xxxx attribute. Both MRI and JRuby do this properly. Differences between source and dest xml of this nature are fine. 2. attribute order can swap 13,14c13,14 < <xxxxxx xxxxxx='x' xxx='xxxxx//xxxxxxxxxxxxxxxx/xxxxx/xxxxxxxxxx/xxx'/> < <xxxxxx xxxxxx='xx' xxx='xxxxx//xxxxxxxxxxxxxxxx/xxxxx/xxxxxxx/xxx'/> --- > <xxxxxx xxx='xxxxx//xxxxxxxxxxxxxxxx/xxxxx/xxxxxxxxxx/xxx' xxxxxx='x'/> > <xxxxxx xxx='xxxxx//xxxxxxxxxxxxxxxx/xxxxx/xxxxxxx/xxx' xxxxxx='xx'/> Both JRuby and MRI also do this...no problems here 3. File.new as case specified still has issue reported, but interestingly $stdout works fine. So this is isolated to Files. I bet we are missing an implicit close. I suspect this bug is same as JRUBY-2305 and some other bug that I cannot find, but I know was not resolved (implicit finalization IO bug). BINGO! Adding output.flush to formatters/default.rb#write solves the issue. So this is due to us not finalizing the IO object as it goes away.
          Hide
          Thomas E Enebo added a comment -

          I guess I should also comment that in the test case given:

          REXML::Document.new(File.new('test.xml')).write File.new('test2.xml', 'w')
          

          The test2.xml File reference should be explicitly closed as a good practice. Otherwise you are depending on finalization to do it for you. Depending on GC being used this may not happen for a very long time (possibly never in a server process).

          A second comment is that perhap one could say that rexml should flush at the end of a document.write (or probably in formatter like I did). To me this seems like a reasonable thing for that library to do.

          We will still do our best to make this work. I wish I could find the base bug on this issue...Implementing the details in that issue (whereever it may be ) will make the supplied test case work since it will register open IO objects to ruby finalization (as well as to Java finalization).

          Show
          Thomas E Enebo added a comment - I guess I should also comment that in the test case given: REXML::Document.new(File.new('test.xml')).write File.new('test2.xml', 'w') The test2.xml File reference should be explicitly closed as a good practice. Otherwise you are depending on finalization to do it for you. Depending on GC being used this may not happen for a very long time (possibly never in a server process). A second comment is that perhap one could say that rexml should flush at the end of a document.write (or probably in formatter like I did). To me this seems like a reasonable thing for that library to do. We will still do our best to make this work. I wish I could find the base bug on this issue...Implementing the details in that issue (whereever it may be ) will make the supplied test case work since it will register open IO objects to ruby finalization (as well as to Java finalization).
          Hide
          Charles Oliver Nutter added a comment -

          Here's a really goofy and probably wrong patch that makes RubyIO a Finalizable and registers it with the runtime. This causes Ruby.tearDown to close all remaining open streams, so they'll flush and finalize properly.

          The problem with it is that it defines a finalize method, so Java finalization would hit it, and it assumes the entire chain of objects associated with the RubyIO are still valid. Ultimately this could cause it to try accessing objects that have already been reclaimed or cause objects to revivify (if that's possible on JVM).

          It doesn't fix all the issues, but it does cause the final flush, so the files have the same number of lines.

          Show
          Charles Oliver Nutter added a comment - Here's a really goofy and probably wrong patch that makes RubyIO a Finalizable and registers it with the runtime. This causes Ruby.tearDown to close all remaining open streams, so they'll flush and finalize properly. The problem with it is that it defines a finalize method, so Java finalization would hit it, and it assumes the entire chain of objects associated with the RubyIO are still valid. Ultimately this could cause it to try accessing objects that have already been reclaimed or cause objects to revivify (if that's possible on JVM). It doesn't fix all the issues, but it does cause the final flush, so the files have the same number of lines.
          Hide
          Vladimir Sizikov added a comment -

          Fixed in rev. 8e51e6e on master branch. This was actually a regression caused by IO subsystem rewrite long ago. ChannelStreams were not registered with finalizer queues to be executed at tearDown(). So, we relied only on GC to invoke finalizers, which not 100% reliable, esp. if the file was opened right before we exit JRuby.

          Show
          Vladimir Sizikov added a comment - Fixed in rev. 8e51e6e on master branch. This was actually a regression caused by IO subsystem rewrite long ago. ChannelStreams were not registered with finalizer queues to be executed at tearDown(). So, we relied only on GC to invoke finalizers, which not 100% reliable, esp. if the file was opened right before we exit JRuby.

            People

            • Assignee:
              Vladimir Sizikov
              Reporter:
              Julian Raschke
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: