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

Marshal.load takes forever when deserializing Rails unicode db in WEBrick

    Details

    • Number of attachments :
      3

      Description

      There is a very long delay (~100 seconds) when deserializing the Rails unicode DB using Marshal.load running in WEBrick.

      File.open(ActiveSupport::Multibyte::Unicode::UnicodeDatabase.filename, 'rb')

      { |f| puts 'start loading unicode db' Marshal.load f.read puts 'finished loading unicode db' }

      This is a 800kb binary file, the issue appears to be WEBrick specific, as it does not occur in Rails Console or when running the JRuby app using winstone.

      Please see attached file with sample app, and refer to "home/index" action.

      Thanks,
      Keith

      1. marshal_output
        116 kB
        Xavier Shay

        Activity

        Hide
        Charles Oliver Nutter added a comment -

        I am so far unable to reproduce this...it runs in well under a second for me on JRuby master and 1.6.7, on Java 6 and 7.

        A few things for you to try:

        • Try setting JAVA_OPTS=-Xprof in the server's environment. The JVM will dump a sampled profile.
        • When it's in the middle of the long loading period you see, hit Control+\ to get a thread dump (or use the "jstack <pid>" command). This will show us what the threads are doing.
        Show
        Charles Oliver Nutter added a comment - I am so far unable to reproduce this...it runs in well under a second for me on JRuby master and 1.6.7, on Java 6 and 7. A few things for you to try: Try setting JAVA_OPTS=-Xprof in the server's environment. The JVM will dump a sampled profile. When it's in the middle of the long loading period you see, hit Control+\ to get a thread dump (or use the "jstack <pid>" command). This will show us what the threads are doing.
        Hide
        Keith Gaputis added a comment - - edited

        Charles, thank you for looking into this. I missed the notification email from your response a couple weeks back.

        I have recreated this problem on both my win7 x64 development machines. Please see attached zip file for server and jstack output from both machines when using -Xprof.

        • Execution 1 in both cases is a Ctrl+\ during hanging request followed by Ctrl+C once it finally finishes
        • Execution 2 in both cases is a Ctrl+C during hanging request

        Thanks, please let me know what I can do to help further if you cannot recreate this.

        Show
        Keith Gaputis added a comment - - edited Charles, thank you for looking into this. I missed the notification email from your response a couple weeks back. I have recreated this problem on both my win7 x64 development machines. Please see attached zip file for server and jstack output from both machines when using -Xprof. Execution 1 in both cases is a Ctrl+\ during hanging request followed by Ctrl+C once it finally finishes Execution 2 in both cases is a Ctrl+C during hanging request Thanks, please let me know what I can do to help further if you cannot recreate this.
        Hide
        Xavier Shay added a comment -

        I am seeing this in development mode also, but only when the database is loaded within the context of a web request using webrick.

        If I load it on server startup it works fine.
        I cannot reproduce using thin.

        Still trying to cut down a minimal test case. Attaching jstack output.

        On OSX.

        Show
        Xavier Shay added a comment - I am seeing this in development mode also, but only when the database is loaded within the context of a web request using webrick. If I load it on server startup it works fine. I cannot reproduce using thin. Still trying to cut down a minimal test case. Attaching jstack output. On OSX.
        Hide
        Xavier Shay added a comment -

        jstack output when JRuby is taking forever to Marshal load unicode database.

        Show
        Xavier Shay added a comment - jstack output when JRuby is taking forever to Marshal load unicode database.
        Hide
        Xavier Shay added a comment - - edited

        Confirm I can reproduce with Keith's stripped down test case on jruby-1.6.7.2.

        It occurs in both 1.8 and 1.9 modes, takes about twice as long in 1.9.

        Show
        Xavier Shay added a comment - - edited Confirm I can reproduce with Keith's stripped down test case on jruby-1.6.7.2. It occurs in both 1.8 and 1.9 modes, takes about twice as long in 1.9.
        Hide
        Charles Oliver Nutter added a comment -

        From the -Xprof dumps it looks like transcoding is to blame here. It's possible we are (or were) transcoding too much or too often or unnecessarily.

        I'll try to reproduce again on master today.

        Show
        Charles Oliver Nutter added a comment - From the -Xprof dumps it looks like transcoding is to blame here. It's possible we are (or were) transcoding too much or too often or unnecessarily. I'll try to reproduce again on master today.
        Hide
        Charles Oliver Nutter added a comment -

        Well it's hard to tell, but it seems to be ok on master. In 1.9 mode, I did bundle exec rails s, which started up WEBrick. I hit /home/index, and after chewing for a second it returned. Subsequent requests sped up.

        I'll call this resolved. If someone else can reproduce the slowness, reopen and we'll try to investigate further.

        Show
        Charles Oliver Nutter added a comment - Well it's hard to tell, but it seems to be ok on master. In 1.9 mode, I did bundle exec rails s, which started up WEBrick. I hit /home/index, and after chewing for a second it returned. Subsequent requests sped up. I'll call this resolved. If someone else can reproduce the slowness, reopen and we'll try to investigate further.

          People

          • Assignee:
            Charles Oliver Nutter
            Reporter:
            Keith Gaputis
          • Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: