autoload not threadsafe

I'm going to dump this on Tom, since he is most familiar with constant stuff (and I couldn't untangle where best to put the sync code). Tom, we can look at this together on Monday, perhaps.

Here's a proposed patch that I believe will fix this problem, but testing concurrent autoloads makes my head hurt. All our tests pass, at any rate.

After creating a test case for this, I realized that it can't work without really invasive modifications to constant lookup or without behavioral changes to autoload itself. I will attach a patch for current set of changes + test case shortly.

The problem is that autoload first deletes the existing constant and then does its require. So there's a period of time when the constant will be neither populated (which is presumably what the required file will do) nor tagged as an autoload. Any thread performing a lookup of this constant during that period, which could span the entire period when the require is executing, would see no constant value. In most cases, this would mean the constant search continues and eventually fails.

A few possible changes could make this work, but they're not going to happen before 1.1.6 (hence why I'm booting this to 1.1.7):

• We could synchronize all constant lookups against a per-constant mutex. This is obviously not an option; the locking cost would kill us.
• If we added a new marker for autoloads, one that says "autoload is in progress", then while the autoload is running all concurrent lookups would block waiting for it to complete. There's no risk of deadlock since there would be a single global autoload mutex. However, this represents a behavioral change because the constant would necessarily have to still point at the "in progress" marker. So defined? and friends would have to be made aware of this new marker...in fact, all cases where we look up constants would have to be made aware of it. It's a very invasive change.
• If autoload's behavior were modified to not delete the constant first, but only delete it after if it were still pointing at the autoload marker, we'd also be ok. Concurrent lookups would see the marker and try to acquire the autoload lock; upon acquiring it they would again check to see if the autoload marker was still present (this may be optional) and proceed to do the require. By the time the master autoload thread has completed, the constant would be nulled out or set by the required file. By the time all other threads acquire the lock, the require will have completed and the constant set, so they can bail out early. This requires similar changes as above, since currently defined? Foo inside the autoloaded script attached to Foo would show it's not defined.

Either way, I think we need to enlist ruby-core in this. Without threading guarantees autoload borders on useless, and the current behavior is not possible to make thread-safe.

Added a test case to the new patch.

My app uses autoload and used to sporadically encounters method not defined errors, which presumably has something to do with concurrent autoload during startup. I have noticed that the frequency has gone down significantly in the JRuby 1.2 RC, but I have seen a few cases.

Does this JRuby bug need to wait until the MRI bug is resolved before proceeding, or can JRuby implements something in the meantime in the form of thread-safe concurrent autoload?

The problem is that nobody's come up with a good way to resolve this. I've proposed a couple theoretical fixes, but never mocked any up, and the synchronization/threading is very tricky to get right. If we could come up with a way to fix it for certain, I think we could go ahead and implement it, but as it stands right now autoload is inherently broken under both MRI and JRuby, and there's no obvious fix.

Interestingly, I saw the release notes for the upcoming Rails 2.3 release, and it looks like the Rails team has switched to using autoload in order to reduce loading time.

This is now working in MRI 1.9.2 - or at least, it works for the test case here: http://stackoverflow.com/questions/2837912/is-autoload-thread-safe-in-ruby-1-9 which fails in jruby 1.6.0.RC1

+1 on hitting "uninitalized constant" threading problems with this

This limitation is still causing problems for multi-threaded apps. Any updates?

master branch might solve this problem. require is not threadsafe as CRuby (see http://redmine.ruby-lang.org/issues/921) but autoload itself is threadsafe now at master branch.

Though we still have some issue about this, I want to ensure that we fix this problem for the next release (1.6.2 or 1.7). Michael, do you have a reproducible script/application to check this?

I found a test script at http://stackoverflow.com/questions/2837912/is-autoload-thread-safe-in-ruby-1-9

And I found the current master still has this problem. I'm still misunderstanding something...

This is an ad-hoc fix (CAUTION: it changes public method signature). Charles: Is this the right way?

diff --git a/src/org/jruby/RubyKernel.java b/src/org/jruby/RubyKernel.java
index e72f135..4b31fba 100644
--- a/src/org/jruby/RubyKernel.java
+++ b/src/org/jruby/RubyKernel.java
@@ -203,13 +203,8 @@ public class RubyKernel {
             /**
              * @see org.jruby.runtime.load.IAutoloadMethod#load(Ruby, String)
              */
-            public IRubyObject load(Ruby runtime, String name) {
-                boolean required = loadService.require(file());
-                
-                // File to be loaded by autoload has already been or is being loaded.
-                if (!required) return null;
-                
-                return module.fastGetConstant(baseName);
+            public boolean load(Ruby runtime, String name) {
+                return loadService.require(file());
             }
         });
         return runtime.getNil();
diff --git a/src/org/jruby/RubyModule.java b/src/org/jruby/RubyModule.java
index 567862b..851db37 100644
--- a/src/org/jruby/RubyModule.java
+++ b/src/org/jruby/RubyModule.java
@@ -2868,7 +2868,9 @@ public class RubyModule extends RubyObject {
     public IRubyObject resolveUndefConstant(Ruby runtime, String name) {
         if (!runtime.is1_9()) deleteConstant(name);
         
-        return runtime.getLoadService().autoload(getName() + "::" + name);
+        runtime.getLoadService().autoload(getName() + "::" + name);
+        
+        return fetchConstant(name);
     }
 
     /**
diff --git a/src/org/jruby/runtime/load/IAutoloadMethod.java b/src/org/jruby/runtime/load/IAutoloadMethod.java
index b041c5e..aae6f39 100644
--- a/src/org/jruby/runtime/load/IAutoloadMethod.java
+++ b/src/org/jruby/runtime/load/IAutoloadMethod.java
@@ -36,5 +36,5 @@ import org.jruby.runtime.builtin.IRubyObject;
  */
 public interface IAutoloadMethod {
     public String file();
-    public IRubyObject load(Ruby runtime, String name);
+    public boolean load(Ruby runtime, String name);
 }
diff --git a/src/org/jruby/runtime/load/LoadService.java b/src/org/jruby/runtime/load/LoadService.java
index c3b1895..62cbaf4 100644
--- a/src/org/jruby/runtime/load/LoadService.java
+++ b/src/org/jruby/runtime/load/LoadService.java
@@ -468,12 +468,11 @@ public class LoadService {
         autoloadMap.remove(name);
     }
 
-    public IRubyObject autoload(String name) {
+    public void autoload(String name) {
         IAutoloadMethod loadMethod = autoloadMap.remove(name);
         if (loadMethod != null) {
-            return loadMethod.load(runtime, name);
+            loadMethod.load(runtime, name);
         }
-        return null;
     }
 
     public void addAutoload(String name, IAutoloadMethod loadMethod) {

Note for me: LoadService#autoloadMap should be thread-safe for real fix.

I fixed this problem on require_protection branch.
https://github.com/jruby/jruby/commit/be86b9ace6e2b218f6c25e2763519ee1723af98a

I'm going to merge the branch to master after a while.

Fixed by be86b9ace6e2b218f6c25e2763519ee1723af98a.

JRUBY-3194: Make autoload thread-safe.

To make autoload thread-safe, remove loadMethod from loadService.autoloadMap after loading file, not before.
Removing loadMethod before loading file would cause the second thread raising NameError since the target constant could not be defined yet.

And this commit introduces 3 states as a resulting value of internal require method: LoadService#requireCommon()
 * LOADED ........... specified file is loaded.
 * ALREADY_LOADED ... specified file is already loaded.
 * CIRCULAR ......... circular require.

For Kernel.require, ALREADY_LOADED and CIRCULAR are treated as 'false' as a resulting value.
For Kenrel.autoload, when it gets CIRCULAR from requireCommon(), it returns nil instead of defined constant.
CIRCULAR helps the following autoload situation.

  autoload :Java, 'java'
  require 'java' #=> 'module Java ...' => invoke autoload for :Java => circular require of 'java' => NameError since Java is not yet defined.

NB: JRuby 1.6.1 does not have this circular autoload problem because 1.6.1 was using $LOADED_FEATURES for protecting runtime from threaded require.
Recursive autoload just returns nil since the feature is marked as 'already loaded'.

Oops. I should not close this ticket.

My fix was for 1.9. autoload is still not thread-safe in 1.8 mode. autoload of CRuby 1.9 is thread safe, and not for CRuby 1.8.

I talked to @shyouhei who is the branch maintainer of CRuby 1.8, and we agreed that it's a bug of CRuby 1.8 which should be fixed. (CRuby dev hat) I don't know if we can fix it in the next patch release but (JRuby dev hat) we can fix this on ahead. I'll fix it for 1.8 mode, too.

Here's the "FIX" (simple!), but it causes 2 RubySpec failures.

diff --git a/src/org/jruby/RubyModule.java b/src/org/jruby/RubyModule.java
index 567862b..bca4aca 100644
--- a/src/org/jruby/RubyModule.java
+++ b/src/org/jruby/RubyModule.java
@@ -2866,8 +2866,6 @@ public class RubyModule extends RubyObject {
     }
     
     public IRubyObject resolveUndefConstant(Ruby runtime, String name) {
-        if (!runtime.is1_9()) deleteConstant(name);
-        
         return runtime.getLoadService().autoload(getName() + "::" + name);
     }
 

Failures.

1)
Module#autoload removes the constant from the constant table if load fails FAILED
Expected ModuleSpecs::Autoload NOT to have constant 'Fail' but it does
/home/nahi/git/jruby/spec/ruby/core/module/autoload_spec.rb:163:in `(root)'
org/jruby/RubyKernel.java:1957:in `instance_eval'
org/jruby/RubyEnumerable.java:1267:in `all?'
org/jruby/RubyArray.java:1602:in `each'
/home/nahi/git/jruby/spec/ruby/core/module/autoload_spec.rb:15:in `(root)'
org/jruby/RubyKernel.java:1064:in `load'
/home/nahi/git/jruby/spec/ruby/core/module/autoload_spec.rb:56:in `files'
org/jruby/RubyKernel.java:1957:in `instance_eval'
org/jruby/RubyArray.java:1602:in `each'

2)
Module#autoload removes the constant from the constant table if the loaded files does not define it FAILED
Expected ModuleSpecs::Autoload NOT to have constant 'O' but it does
/home/nahi/git/jruby/spec/ruby/core/module/autoload_spec.rb:171:in `(root)'
org/jruby/RubyKernel.java:1957:in `instance_eval'
org/jruby/RubyEnumerable.java:1267:in `all?'
org/jruby/RubyArray.java:1602:in `each'
/home/nahi/git/jruby/spec/ruby/core/module/autoload_spec.rb:15:in `(root)'
org/jruby/RubyKernel.java:1064:in `load'
/home/nahi/git/jruby/spec/ruby/core/module/autoload_spec.rb:56:in `files'
org/jruby/RubyKernel.java:1957:in `instance_eval'
org/jruby/RubyArray.java:1602:in `each'

CRuby/JRuby 1.8 removes the constant first so the above 2 expectations are OK. CRuby/JRuby 1.9 does not remove the constant so both does not satisfy it.

I think that RubySpec should be corrected but I'm going to talk CRuby 1.8 guys how we treat this.

Re getting 1.8 changed and fixing RubySpec: yes, I agree. It's a visible change, but a minor one, and it would allow making 1.8 autoloads thread-safe.

My 'fix' for autoload thread-safety above was incomplete.

% cat autoload.rb
autoload :Foo, 'constant.rb'

Thread.abort_on_exception = true

t1 = Thread.new {
  puts "thread #{Thread.current} accessing X"
  p Foo::X
}
t2 = Thread.new {
  puts "thread #{Thread.current} accessing X"
  p Foo::X
}

t1.join
t2.join
% cat constant.rb
puts "#{Thread.current} in constant.rb"

module Foo
  # simulate a slow file load or a deep chain of requires
  # !Foo is already defined!
  sleep 1
  # define X
  X = 1
end
% jruby163 autoload.rb 
thread #<Thread:0x63d982d> accessing X
thread #<Thread:0x71051c99> accessing X
NameError: uninitialized constant Foo
  const_missing at org/jruby/RubyModule.java:2569
       __file__ at autoload.rb:11
           call at org/jruby/RubyProc.java:268
           call at org/jruby/RubyProc.java:232
#<Thread:0x63d982d> in constant.rb
zsh: exit 1     /home/nahi/java/jruby-1.6.3/bin/jruby autoload.rb

'sleep 1' before defining Foo in constant.rb is OK, but 'sleep 1' after defining Foo does not work.

And now I implemented (hopefully) actual thread-safe autoload in autoload-threadsafe branch. Above script works as expected.

• https://github.com/jruby/jruby/compare/91f73c...6f159f (fast* lookup deprecation)
• https://github.com/jruby/jruby/compare/e56d92...6b52bf (actual autoload fix)

I added autoloadingMap to RubyModule for keeping autoloading states. It consists of a RubyThread which invokes autoloading and an Object assigned to the autoload constant while autoloading. Keeping RubyThread in a cache while autoloading can be a problem?

While autoloading, constantMap keeps UNDEF for the constant and autoloadingMap keeps the assigned object instead. Constant lookup checks if the value in constantMap is UNDEF, and iif it's UNDEF, it checks autloadingMap as well.

Unlike predicted beforehand, there's no perf drop. Introducing (lazy init) autoloadingMap for each module might be a memory consumer but it's negligible for general autoload usage I think.

As a side effect, in 1.8 mode, Module#autoload does not remove the constant from constant table if
the loaded files does not define it. This causes 3 RubySpec failures. This behavior is as same as
CRuby 1.9, and needed for autoload thread-safety. CRuby 1.8 removes the constant, and it's hard to be thread-safe as far as it keeps the current behavior.

I believe this JRuby/CRuby behavior incompatibility on 1.8 mode is OK to introduce since the behavior is hard to imagine before trying it so no one would depend on the behavior intentionally.

How do you think?

The changes seems logical, and the behavioral difference for 1.8 mode seems like it's unavoidable. I've also spent a lot of time thinking through this, and without the constant holding some kind of marker to indicate there's an autoload in progress (requiring it to remain definde) there's no way to make autoload threadsafe.

I think your code may need some locking though. For example, line 2251 in RubyModule retrieves any current autoload and the following line checks if it is null. Since this is not an atomic operation, another thread could come in and install an autoload immediately after that retrieval. Odd, and buggy code on the user's part, but it's a case to consider.

You also should be synchronizing around the construction of the autoload map, so another thread doesn't swoop in, create a map, populate it with an autoload, and then it gets wiped out. There may be other places where some locking is needed. I can help, if you like.

Does your fix depend on the fast* deprecation? We don't deprecate for minor releases (1.6.4) but it would still be good to get the autoload thread-safety fix in if possible. Maybe it's too invasive for a minor release too?

Thanks for comment, Charles. Replies.

• For line 2251 in RubyModule, are you pointing LoadService.java#483? RubyModule.java#2251 seems to be a comment line in autoload-threadsafe branch. I think LoadService.java#843 is OK since it checks if it's null or not against a variable got from autoloadMap. I could be seeing wrong line.

• For autoloadMap construction, I added synchronize to getAutoloadingMapForWrite() in RubyModule.java#200. I just copied this line from getConstantMapForWrite() so it's safe, too.

• My fix does not depend on fast* deprecation. I wanted to narrow down the occurrences where look up constantMap and autoloadingMap. I could be able to create a commit without deprecating fast* methods now, but I think it's hard to merge this fix into 1.6. 1.6 still has a bug around cyclic require and concurrent autoload (be86b9ace6e2b218f6c25e2763519ee1723af98a) and the new fix depends on it. Should we merge all fixes in this issue to 1.6?

I fixed a concurrency issue at eef82e77 [1]. The root cause of the concurrency issue is that the autoloadingMap I added to RubyModule need to sync with autoloadMap at VM global LoadService. I merged these maps into autoloadMap in RubyModule and simplified synchronizing strategy.

In Ruby < 1.8, autoload is only allowed at top-level. VM global LoadService was OK for the spec. CRuby 1.8 added to support per-Module autoload and current JRuby uses 'Module#name + :: + constname' as a key for autoloadMap.

I removed autoloadMap in LoadService and moved it to RubyModule at eef82e77. There's no need to use 'Module#name + ::' prefix in the new implementation.

[3] is the patch of whole fix. This patch can be applied after the patch [2] (fast* deprecation). Ant test passes. Ant spec marks 3 fails but I think it's OK as I stated in the previous comment.

Do you think it's OK to merge?

For jruby-1_6 branch, I think we should not merge it as far as we don't receive user's request.

[1] https://github.com/jruby/jruby/commit/eef82e7708011596a23e23dc7c2f836b1d562f2f
[2] https://github.com/jruby/jruby/compare/91f73c...6f159f (fast* lookup deprecation)
[3] https://github.com/jruby/jruby/compare/e56d92...eef82e77 (autoload threadsafe fix)

Nahi, feel free to merge on master. From your discussions with me last week and the fact that we want as much bake time as possible please land it now [We can always back it out if we discover a serious problem]

It would be nice to make some torture tests over the next couple of months to verify the completeness of the fixes you have made.

Thomas, thanks for your comment. It's a big relief that you got back from Japan safely.

Merged to master at [6d182d07]. CRuby is the next to be fixed, and RubySpec is the last.

Closing.

I fixed CRuby trunk based on the same logic, and it will be released as 1.9.4 or 2.0. RubySpec won't be changed since CRuby 1.8 won't be fixed.

Will it be released on 1.6.x branch?

Gabriel: not planned. It would be released as 1.7.0, in months I heard.

Did the problem bite you on 1.6.4? How does it go on 1.7.0.dev?

You can get 1.7.0.dev snapshot package from
http://ci.jruby.org/job/jruby-dist/lastSuccessfulBuild/artifact/dist/

Yes, it's a major block for me on 1.6.x. I'm using jruby-head (from rvm) so, now everything is working fine.

I think not many people are using threads with ruby/rails application so they are cool with it. I'm using threads to migrate massive amount of data with some rake tasks and active record, and by using jruby (1.7) with threads I got like 5x performance improvement

I'm hitting this consistently on 1.6.5 with a couple of jetty/rack (fishwife) + Sinatra applications. A workaround is to preload the autoload early, before thread pool is loaded. However, every time I take a Sinatra or Rack upgrade the set of necessary pre-loads changes and I break again.

1.9 mode is not working for me yet.

Any chance the fix for this could be back-ported to a 1.6.6?

Let me know if I can try and help.

David, can you try 1.7.0.dev to confirm the issue is actually what we've fixed at master branch? You can obtain the snapshot build from http://ci.jruby.org/snapshots/master/.

And I'm now discussing with @headius about how we can fix this issue at coming 1.6.6. Please stay tuned.

Sure, I can try that. But do I need to get my app working in 1.9 mode to even bring this new fix into play?

No, you don't need to run it in 1.9. The fix is both for 1.8 and 1.9 in JRuby.

To close the circle on some of this discussion, we are considering including in 1.6.6 an optional flag you can enable to force all requires to synchronize against the same global lock. This is an indirect, brute-force way to solve autoload thread safety, since autoload uses require at its core. There will be libraries that block within a require, like current Rails does when you run "rails server", but this may be an acceptable middle ground for folks using 1.6.x that need both concurrency and thread-safe autoloads.

The experience gained from having the global require lock flag in the wild will also doubtless lead to library fixes (such as fixes Yehuda already plans to make for "rails server"), and give both us and MRI real-world information on the implications of a global require lock.

Preliminary findings, using my app and comparing the following two jruby versions:

jruby 1.6.5 (ruby-1.8.7-p330) (2011-10-25 9dcd388) (Java HotSpot(TM) Server VM 1.7.0_02) [linux-i386-java]
jruby 1.7.0.dev (ruby-1.8.7-p357) (2012-01-18 29168ec) (Java HotSpot(TM) Server VM 1.7.0_02) [linux-i386-java]

Where the 1.7.0.dev I built from 29168ec jruby master branch today. The 1.8 mode is shown, but I also tested with 1.9.

I can reproduce the problem on both builds, and both 1.8 and 1.9 modes. However, where the problem is reproduced on 1.6.5 nearly 100% of time; I see it maybe 50% of the time on 1.7.0.dev. Here are examples of stack dumps:

(NameError) uninitialized constant Rack::Builder
	at org.jruby.RubyModule.const_missing(org/jruby/RubyModule.java:2610)
	at RUBY.new(/home/david/.gem/jruby/1.8/gems/sinatra-1.3.2/lib/sinatra/base.rb:1321)
	at RUBY.prototype(/home/david/.gem/jruby/1.8/gems/sinatra-1.3.2/lib/sinatra/base.rb:1311)
	at RUBY.call(/home/david/.gem/jruby/1.8/gems/sinatra-1.3.2/lib/sinatra/base.rb:1334)
	at RUBY.synchronize(/home/david/.gem/jruby/1.8/gems/sinatra-1.3.2/lib/sinatra/base.rb:1416)
	at RUBY.call(/home/david/.gem/jruby/1.8/gems/sinatra-1.3.2/lib/sinatra/base.rb:1334)
	at RUBY.service(/home/david/.gem/jruby/1.8/gems/fishwife-1.1.1-java/lib/fishwife/rack_servlet.rb:83)
	at org.jruby.RubyKernel.catch(org/jruby/RubyKernel.java:1115)
	at RUBY.service(/home/david/.gem/jruby/1.8/gems/fishwife-1.1.1-java/lib/fishwife/rack_servlet.rb:82)

(NameError) uninitialized constant Rack::Protection::IPSpoofing
	at org.jruby.RubyModule.const_missing(org/jruby/RubyModule.java:2590)
	at #<Class:0x186f2c>.new(/home/david/.gem/jruby/1.8/gems/rack-protection-1.2.0/lib/rack/protection.rb:24)
	at org.jruby.RubyKernel.instance_eval(org/jruby/RubyKernel.java:2062)
	at Rack::Builder.initialize(/home/david/.gem/jruby/1.8/gems/rack-1.3.6/lib/rack/builder.rb:51)
	at #<Class:0x11badec>.new(/home/david/.gem/jruby/1.8/gems/rack-protection-1.2.0/lib/rack/protection.rb:22)
	at Rack::Builder.use(/home/david/.gem/jruby/1.8/gems/rack-1.3.6/lib/rack/builder.rb:78)
	at org.jruby.RubyProc.call(org/jruby/RubyProc.java:270)
	at org.jruby.RubyProc.call(org/jruby/RubyProc.java:220)
	at Rack::Builder.to_app(/home/david/.gem/jruby/1.8/gems/rack-1.3.6/lib/rack/builder.rb:130)
	at org.jruby.RubyArray.each(org/jruby/RubyArray.java:1612)
	at org.jruby.RubyEnumerable.inject(org/jruby/RubyEnumerable.java:830)
	at Rack::Builder.to_app(/home/david/.gem/jruby/1.8/gems/rack-1.3.6/lib/rack/builder.rb:130)
	at #<Class:0xed0ded>.new(/home/david/.gem/jruby/1.8/gems/sinatra-1.3.2/lib/sinatra/base.rb:1321)
	at Rack::Builder.use(/home/david/.gem/jruby/1.8/gems/rack-1.3.6/lib/rack/builder.rb:78)
	at org.jruby.RubyProc.call(org/jruby/RubyProc.java:270)
	at org.jruby.RubyProc.call(org/jruby/RubyProc.java:220)
	at Rack::Builder.to_app(/home/david/.gem/jruby/1.8/gems/rack-1.3.6/lib/rack/builder.rb:130)
	at org.jruby.RubyArray.each(org/jruby/RubyArray.java:1612)
	at org.jruby.RubyEnumerable.inject(org/jruby/RubyEnumerable.java:830)
	at Rack::Builder.to_app(/home/david/.gem/jruby/1.8/gems/rack-1.3.6/lib/rack/builder.rb:130)
	at #<Class:0xed0ded>.new(/home/david/.gem/jruby/1.8/gems/sinatra-1.3.2/lib/sinatra/base.rb:1321)
	at #<Class:0xed0ded>.prototype(/home/david/.gem/jruby/1.8/gems/sinatra-1.3.2/lib/sinatra/base.rb:1311)
	at #<Class:0xaa0c76>.call(/home/david/.gem/jruby/1.8/gems/sinatra-1.3.2/lib/sinatra/base.rb:1334)
	at #<Class:0xed0ded>.synchronize(/home/david/.gem/jruby/1.8/gems/sinatra-1.3.2/lib/sinatra/base.rb:1416)
	at #<Class:0xed0ded>.call(/home/david/.gem/jruby/1.8/gems/sinatra-1.3.2/lib/sinatra/base.rb:1334)
	at Fishwife::RackServlet.service(/home/david/.gem/jruby/1.8/gems/fishwife-1.1.1-java/lib/fishwife/rack_servlet.rb:83)
	at org.jruby.RubyKernel.catch(org/jruby/RubyKernel.java:1192)
	at Fishwife::RackServlet.service(/home/david/.gem/jruby/1.8/gems/fishwife-1.1.1-java/lib/fishwife/rack_servlet.rb:82)

(NameError) uninitialized constant Rack::NullLogger
	at org.jruby.RubyModule.const_missing(org/jruby/RubyModule.java:2590)
	at #<Class:0x1fa3ae8>.setup_null_logger(/home/david/.gem/jruby/1.9/gems/sinatra-1.3.2/lib/sinatra/base.rb:1361)
	at #<Class:0x1fa3ae8>.setup_logging(/home/david/.gem/jruby/1.9/gems/sinatra-1.3.2/lib/sinatra/base.rb:1356)
	at #<Class:0x1fa3ae8>.setup_default_middleware(/home/david/.gem/jruby/1.9/gems/sinatra-1.3.2/lib/sinatra/base.rb:1342)
	at #<Class:0x1fa3ae8>.build(/home/david/.gem/jruby/1.9/gems/sinatra-1.3.2/lib/sinatra/base.rb:1327)
	at #<Class:0x1fa3ae8>.new(/home/david/.gem/jruby/1.9/gems/sinatra-1.3.2/lib/sinatra/base.rb:1321)
	at #<Class:0x1fa3ae8>.prototype(/home/david/.gem/jruby/1.9/gems/sinatra-1.3.2/lib/sinatra/base.rb:1311)
	at #<Class:0x1cc488d>.call(/home/david/.gem/jruby/1.9/gems/sinatra-1.3.2/lib/sinatra/base.rb:1334)
	at #<Class:0x1fa3ae8>.synchronize(/home/david/.gem/jruby/1.9/gems/sinatra-1.3.2/lib/sinatra/base.rb:1416)
	at #<Class:0x1fa3ae8>.call(/home/david/.gem/jruby/1.9/gems/sinatra-1.3.2/lib/sinatra/base.rb:1334)
	at Fishwife::RackServlet.service(/home/david/.gem/jruby/1.9/gems/fishwife-1.2.0-java/lib/fishwife/rack_servlet.rb:83)
	at org.jruby.RubyKernel.catch(org/jruby/RubyKernel.java:1206)
	at Fishwife::RackServlet.service(/home/david/.gem/jruby/1.9/gems/fishwife-1.2.0-java/lib/fishwife/rack_servlet.rb:82)

The trick with this is that it happens only on the first parallel requests as startup; and at least with these builds self-corrects on subsequent requests.

Would it help if we created a small test bed for this? Minimal self contained app and test?

Thank you. Hmm, I'll investigate it today.

> Would it help if we created a small test bed for this? Minimal self contained app and test?

It would help much. Small and minimal is good of course, but not a must. Please send me directly if you think it's not fit for public location.

I'm now trying to backport thread-safe autoload to jruby-1_6. I'll check the test bed against the backport.

Ok, here is a self contained (well, after "bundle install") app and basic test driver:

https://github.com/dekellum/sinatra-threaded-autoload

Please let me know if you have any trouble or questions with it. Hope it helps!

Thank you! I could easily confirm the reproduction of the errors. I'll investigate it on master and write again. After all, I'll continue to backport the fixes to jruby-1_6.

This should fix the issue on master.

commit 698e1e39911f68536d7b670dddc0f5b90a0f3834
Author: Hiroshi Nakamura <nahi@ruby-lang.org>
Date:   Thu Jan 19 16:39:03 2012 +0900

    JRUBY-3194: Avoid NameError for concurrent autoload access
    
    Revert the synchronize change at d7ff5b9d.  I wrote 'removing
    unnecessary synchronized block' but I was wrong.
    
    IAutoloadMethod#load which is defined in RubyKernel.java removes
    Autoload object from RubyModule#autoloadMap after successful
    autoloading, and it must be done in synchronized block.  If not, other
    Threads could see orphan autoloadMap just between successful loading and
    autoloadMap clean-up by the initial Thread.  This causes NameError for
    constant access.
    
    PoC project is at [1].  Many thanks to David Kellum who prepared this
    for us!
    
    [1] https://github.com/dekellum/sinatra-threaded-autoload

I'll try backporting to jruby-1_6.

Here's my brute-force backport to jruby-1_6: https://github.com/nahi/jruby/tree/autoload-threadsafe_16
The diff from jruby-1_6: https://github.com/nahi/jruby/compare/jruby:jruby-1_6...nahi:autoload-threadsafe_16

ant test passes. ant spec causes a few autoload spec failures caused by behavior change of autolaod.

I have no idea how I can make this change opt-in...

Reopening since there's some ongoing work here.

We decided to just roll threadsafe autoloads directly into JRuby 1.6.6.