Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Performance issue when connected to network #3744

Closed
kisho23 opened this issue Mar 18, 2016 · 12 comments
Closed

Performance issue when connected to network #3744

kisho23 opened this issue Mar 18, 2016 · 12 comments
Labels
Milestone

Comments

@kisho23
Copy link

@kisho23 kisho23 commented Mar 18, 2016

Environment

  • JRuby version: 9.0.5.0
  • Operating system: Windows 7

Expected Behavior

I just playing around with asciidoctor.
I put all gems and specifications in the classpath.

The program should start in the same time either if the network is connected or not.

Actual Behavior

If the network is connected it needs 1 minute.
If the network is not connected it need 5 seconds

After some debugging I found out that

uri:classloader://specifications/asciidoctor-1.5.4.gemspec

yields to a

new File("//specifications/asciidoctor-1.5.4.gemspec").exists()

Under Windows "//specifications" is a network drive, which can not be resolved.
I think this is the reason for my performance problem in case the laptop is connected to the network.

@kisho23
Copy link
Author

@kisho23 kisho23 commented Mar 18, 2016

This is the java program:

    System.out.print("Load... ");
    long start = System.nanoTime();
    Asciidoctor asciidoctor = Asciidoctor.Factory.create();
    System.out.println(System.nanoTime() - start);

I put all needed gems and specifcations in the classpath.

I observed that the described behavior does not occur on every machine. Maybe because of some network setting regarding the resolution of resources beginning with '//'

@kisho23 kisho23 changed the title Performce issue when connected to network Performance issue when connected to network Mar 18, 2016
@kisho23
Copy link
Author

@kisho23 kisho23 commented Mar 18, 2016

And here is the stack


  Main01 JVPMS [Java Application] 
      de.gpfeifer.asciidoctor.Main01 at localhost:6768    
          Thread [main] (Suspended)   
              WinNTFileSystem.getBooleanAttributes(File) line: not available [native method]  
              File.exists() line: 819 
              WinNTFileSystem.canonicalize(String) line: 434  
              File.getCanonicalPath() line: 618   
              RubyFile.canonicalizePath(String) line: 1718    
              RubyFile.expandPathInternal(ThreadContext, IRubyObject, IRubyObject[], boolean, boolean) line: 1575 
              RubyFile.expand_path19(ThreadContext, IRubyObject, IRubyObject[]) line: 781 
              RubyFile$INVOKER$s$0$1$expand_path19.call(ThreadContext, IRubyObject, RubyModule, String, IRubyObject[]) line: not available    
              RubyFile$INVOKER$s$0$1$expand_path19(JavaMethod$JavaMethodN).call(ThreadContext, IRubyObject, RubyModule, String, IRubyObject, Block) line: 717 
              RubyFile$INVOKER$s$0$1$expand_path19(DynamicMethod).call(ThreadContext, IRubyObject, RubyModule, String, IRubyObject) line: 197 
              NormalCachingCallSite(CachingCallSite).cacheAndCall(IRubyObject, RubyClass, ThreadContext, IRubyObject, IRubyObject) line: 313  
              NormalCachingCallSite(CachingCallSite).call(ThreadContext, IRubyObject, IRubyObject, IRubyObject) line: 163 
              InterpreterEngine.processCall(ThreadContext, Instr, Operation, DynamicScope, StaticScope, Object[], IRubyObject) line: 316  
              StartupInterpreterEngine.interpret(ThreadContext, Block, IRubyObject, InterpreterContext, RubyModule, String, IRubyObject[], Block) line: 77    
              StartupInterpreterEngine(InterpreterEngine).interpret(ThreadContext, Block, IRubyObject, InterpreterContext, RubyModule, String, IRubyObject, Block) line: 86   
              InterpretedIRMethod.INTERPRET_METHOD(ThreadContext, InterpreterContext, RubyModule, IRubyObject, String, IRubyObject, Block) line: 193  
              InterpretedIRMethod.call(ThreadContext, IRubyObject, RubyModule, String, IRubyObject, Block) line: 180  
              InterpretedIRMethod(DynamicMethod).call(ThreadContext, IRubyObject, RubyModule, String, IRubyObject) line: 197  
              NormalCachingCallSite(CachingCallSite).cacheAndCall(IRubyObject, RubyClass, ThreadContext, IRubyObject, IRubyObject) line: 313  
              NormalCachingCallSite(CachingCallSite).call(ThreadContext, IRubyObject, IRubyObject, IRubyObject) line: 163 
              InterpreterEngine.processCall(ThreadContext, Instr, Operation, DynamicScope, StaticScope, Object[], IRubyObject) line: 316  
              StartupInterpreterEngine.interpret(ThreadContext, Block, IRubyObject, InterpreterContext, RubyModule, String, IRubyObject[], Block) line: 77    
              StartupInterpreterEngine(InterpreterEngine).interpret(ThreadContext, Block, IRubyObject, InterpreterContext, RubyModule, String, Block) line: 80    
              InterpretedIRMethod.INTERPRET_METHOD(ThreadContext, InterpreterContext, RubyModule, IRubyObject, String, Block) line: 165   
              InterpretedIRMethod.call(ThreadContext, IRubyObject, RubyModule, String, Block) line: 152   
              InterpretedIRMethod(DynamicMethod).call(ThreadContext, IRubyObject, RubyModule, String) line: 189   
              NormalCachingCallSite(CachingCallSite).cacheAndCall(IRubyObject, RubyClass, ThreadContext, IRubyObject) line: 293   
              NormalCachingCallSite(CachingCallSite).call(ThreadContext, IRubyObject, IRubyObject) line: 131  
              InterpreterEngine.processCall(ThreadContext, Instr, Operation, DynamicScope, StaticScope, Object[], IRubyObject) line: 332  
              StartupInterpreterEngine.interpret(ThreadContext, Block, IRubyObject, InterpreterContext, RubyModule, String, IRubyObject[], Block) line: 77    
              StartupInterpreterEngine(InterpreterEngine).interpret(ThreadContext, Block, IRubyObject, InterpreterContext, RubyModule, String, IRubyObject, Block) line: 86   
              InterpretedIRMethod.INTERPRET_METHOD(ThreadContext, InterpreterContext, RubyModule, IRubyObject, String, IRubyObject, Block) line: 193  
              InterpretedIRMethod.call(ThreadContext, IRubyObject, RubyModule, String, IRubyObject, Block) line: 180  
              InterpretedIRMethod(DynamicMethod).call(ThreadContext, IRubyObject, RubyModule, String, IRubyObject) line: 197  
              NormalCachingCallSite(CachingCallSite).cacheAndCall(IRubyObject, RubyClass, ThreadContext, IRubyObject, IRubyObject) line: 313  
              NormalCachingCallSite(CachingCallSite).call(ThreadContext, IRubyObject, IRubyObject, IRubyObject) line: 163 
              InterpreterEngine.processCall(ThreadContext, Instr, Operation, DynamicScope, StaticScope, Object[], IRubyObject) line: 316  
              StartupInterpreterEngine.interpret(ThreadContext, Block, IRubyObject, InterpreterContext, RubyModule, String, IRubyObject[], Block) line: 77    
              StartupInterpreterEngine(InterpreterEngine).interpret(ThreadContext, Block, IRubyObject, InterpreterContext, RubyModule, String, IRubyObject, Block) line: 86   
              InterpretedIRMethod.INTERPRET_METHOD(ThreadContext, InterpreterContext, RubyModule, IRubyObject, String, IRubyObject, Block) line: 193  
              InterpretedIRMethod.call(ThreadContext, IRubyObject, RubyModule, String, IRubyObject, Block) line: 180  
              InterpretedIRMethod(DynamicMethod).call(ThreadContext, IRubyObject, RubyModule, String, IRubyObject) line: 197  
              NormalCachingCallSite(CachingCallSite).cacheAndCall(IRubyObject, RubyClass, ThreadContext, IRubyObject, IRubyObject) line: 313  
              NormalCachingCallSite(CachingCallSite).call(ThreadContext, IRubyObject, IRubyObject, IRubyObject) line: 163 
              InterpreterEngine.processCall(ThreadContext, Instr, Operation, DynamicScope, StaticScope, Object[], IRubyObject) line: 316  
              StartupInterpreterEngine.interpret(ThreadContext, Block, IRubyObject, InterpreterContext, RubyModule, String, IRubyObject[], Block) line: 77    
              StartupInterpreterEngine(InterpreterEngine).interpret(ThreadContext, Block, IRubyObject, InterpreterContext, RubyModule, String, IRubyObject, Block) line: 86   
              InterpretedIRMethod.INTERPRET_METHOD(ThreadContext, InterpreterContext, RubyModule, IRubyObject, String, IRubyObject, Block) line: 193  
              InterpretedIRMethod.call(ThreadContext, IRubyObject, RubyModule, String, IRubyObject, Block) line: 180  
              InterpretedIRMethod(DynamicMethod).call(ThreadContext, IRubyObject, RubyModule, String, IRubyObject) line: 197  
              FunctionalCachingCallSite(CachingCallSite).cacheAndCall(IRubyObject, RubyClass, ThreadContext, IRubyObject, IRubyObject) line: 313  
              FunctionalCachingCallSite(CachingCallSite).call(ThreadContext, IRubyObject, IRubyObject, IRubyObject) line: 163 
              InterpreterEngine.processCall(ThreadContext, Instr, Operation, DynamicScope, StaticScope, Object[], IRubyObject) line: 316  
              StartupInterpreterEngine.interpret(ThreadContext, Block, IRubyObject, InterpreterContext, RubyModule, String, IRubyObject[], Block) line: 77    
              Interpreter.INTERPRET_ROOT(ThreadContext, IRubyObject, InterpreterContext, RubyModule, String) line: 112    
              Interpreter.execute(Ruby, IRScriptBody, IRubyObject) line: 99   
              Interpreter.execute(Ruby, IRScriptBody, Object) line: 35    
              Interpreter(IRTranslator<R,S>).execute(Ruby, ParseResult, S) line: 42   
              Ruby.evalScriptlet(String, DynamicScope) line: 471  
              Ruby.evalScriptlet(String) line: 447    
              JavaEmbedUtils$2.eval(Ruby, String) line: 147   
              JRubyAsciidoctorModuleFactory.createAsciidoctorModule() line: 23    
              JRubyAsciidoctor.createJRubyAsciidoctorInstance(Map<String,String>) line: 132   
              JRubyAsciidoctor.create() line: 57  
              Asciidoctor$Factory.create() line: 668  
              Main01.main(String[]) line: 20  
          Daemon Thread [Ruby-0-JIT-1] (Running)  
      C:\Program Files\Java\jdk1.8.0_31\bin\javaw.exe (18.03.2016, 15:01:39)  

@enebo
Copy link
Member

@enebo enebo commented Mar 18, 2016

Yikes obviously a "//foo/bar" which does not exist will take time on windows but since this is originally a url this is clearly stripping the url bits off wrong.

@enebo
Copy link
Member

@enebo enebo commented Mar 18, 2016

Hmm I should say root cause of this is not that windows takes a long time to resolve non-existent UNC paths (which it seems to take forever in explorer too) but that we are not properly processing our URLs to paths properly internally.

@kares
Copy link
Member

@kares kares commented Mar 18, 2016

uri:classloader://xxx needs special care when removing uri:classloader: prefix to not leave //

kares added a commit to kares/jruby that referenced this issue Mar 19, 2016
@kares kares added this to the JRuby 9.1.0.0 milestone Mar 19, 2016
kares added a commit that referenced this issue Mar 19, 2016
@enebo
Copy link
Member

@enebo enebo commented Mar 30, 2016

HAHAHA @kares I was looking into this afternoon and did not see your commit. I was so confused why the result seemed to be correct :)

@kisho23 could you verify that our nightly fixes this: http://ci.jruby.org/ ?

@kares
Copy link
Member

@kares kares commented Mar 31, 2016

@enebo yeah, forgot to comment - sorry. this could still use a test case (on Windows which I'm not).

@kisho23
Copy link
Author

@kisho23 kisho23 commented Mar 31, 2016

@enebo
Yeah, your nightly fix it. From more than 1 minute down to under 4 seconds. Great! Thank you.

Using jruby-complete-9.0.5.0.jar
Load... 01:09:025-980190 mm:ss:ms-ns

Using jruby-complete-9.1.0.0-SNAPSHOT.jar
Load... 03:995-670151 ss:ms-ns

@enebo
Copy link
Member

@enebo enebo commented Mar 31, 2016

@kisho23 also do you happen to also test this against jruby 1.7.x? I think that is current JRuby still supported by asciidoctor isn't it?

enebo added a commit that referenced this issue Mar 31, 2016
@kisho23
Copy link
Author

@kisho23 kisho23 commented Apr 1, 2016

Hello,
No I do not test this with 1.7x. According to http://discuss.asciidoctor.org/Asciidoctor-YAML-style-file-for-PDF-and-maven-td3849.html#a3857 I use JRuby 9.
Best regards
Kisho

@headius
Copy link
Member

@headius headius commented Apr 20, 2016

@enebo I suggest we close this as fixed for 9.1. If someone else reports it against 1.7 we can fix it there in a separate issue.

@enebo enebo closed this Apr 20, 2016
@enebo
Copy link
Member

@enebo enebo commented Apr 20, 2016

@headius yeah until github issues allows us to maintain two milestones for one issue we should be doing that anyways.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
4 participants
You can’t perform that action at this time.