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

Regression: Sequel's literals contain additional quotation marks under JRuby 9k head but not under pre2 #2976

Closed
deepj opened this issue May 22, 2015 · 8 comments

Comments

@deepj
Copy link

deepj commented May 22, 2015

This is a weird bug. Sometimes it is not possible reproduce and conversely.

$ ruby -v
jruby 9.0.0.0-SNAPSHOT (2.2.2) 2015-05-13 6b59f27 Java HotSpot(TM) 64-Bit Server VM 25.45-b02 on 1.8.0_45-b14 +jit [darwin-x86_64]
$ ruby -Ispec spec/core/expression_filters_spec.rb
Run options: --seed 40387

# Running:

.................F................................................................................................................................................................

Finished in 1.289473s, 138.0409 runs/s, 378.4492 assertions/s.

  1) Failure:
Blockless Ruby Filters#test_0021_should support LiteralString [spec/core/expression_filters_spec.rb:171]:
Expected: "((y = z) AND x)"
  Actual: "(('y' = z) AND x)"

178 runs, 488 assertions, 1 failures, 0 errors, 0 skips

How to reproduce:

git clone git@github.com:jeremyevans/sequel.git
cd sequel
bundle
ruby -Ispec spec/core/expression_filters_spec.rb
@deepj deepj changed the title Regression: Sequel's literals contains additional quotation marks under JRuby 9k head but not under pre2 Regression: Sequel's literals contain additional quotation marks under JRuby 9k head but not under pre2 May 22, 2015
@headius
Copy link
Member

headius commented May 26, 2015

Huh, what a weird one. I imagine we're calling some method to coerce the string that C Ruby does not, and it is producing these quotes...but that's just a guess.

@headius
Copy link
Member

headius commented May 26, 2015

I could not reproduce running the file directly...is that what you mean about it not reproducing all the time?

[] ~/projects/sequel $ jruby -Ilib:test spec/core/expression_filters_spec.rb 
Run options: --seed 17092

# Running:

..................................................................................................................................................................................

Finished in 1.217929s, 146.1497 runs/s, 407.2487 assertions/s.

178 runs, 496 assertions, 0 failures, 0 errors, 0 skips

@deepj
Copy link
Author

deepj commented May 26, 2015

Now with jruby-head it is rare to trigger the issue. But I've been successful in 1 of 5 tries.

$ ruby -v
jruby 9.0.0.0-SNAPSHOT (2.2.2) 2015-05-26 ce40bac Java HotSpot(TM) 64-Bit Server VM 25.45-b02 on 1.8.0_45-b14 +jit [darwin-x86_64]
$ ruby -Ilib:test spec/core/expression_filters_spec.rb
Run options: --seed 38491

# Running:

..........................................................................................................................F.......................................................

Finished in 1.460553s, 121.8717 runs/s, 334.1201 assertions/s.

  1) Failure:
Blockless Ruby Filters#test_0021_should support LiteralString [spec/core/expression_filters_spec.rb:171]:
Expected: "((y = z) AND x)"
  Actual: "(('y' = z) AND x)"

178 runs, 488 assertions, 1 failures, 0 errors, 0 skips
$ ruby -Ilib:test spec/core/expression_filters_spec.rb
Run options: --seed 29655

# Running:

..................................................................................................................................................................................

Finished in 1.704551s, 104.4263 runs/s, 290.9857 assertions/s.

178 runs, 496 assertions, 0 failures, 0 errors, 0 skips
citadela:sequel deepj$ ruby -Ilib:test spec/core/expression_filters_spec.rb
Run options: --seed 27555

# Running:

..................................................................................................................................................................................

Finished in 1.484806s, 119.8810 runs/s, 334.0503 assertions/s.

178 runs, 496 assertions, 0 failures, 0 errors, 0 skips
$ ruby -Ilib:test spec/core/expression_filters_spec.rb
un options: --seed 52500

# Running:

..................................................................................................................................................................................

Finished in 1.541043s, 115.5062 runs/s, 321.8600 assertions/s.

178 runs, 496 assertions, 0 failures, 0 errors, 0 skips
$ ruby -Ilib:test spec/core/expression_filters_spec.rb
Run options: --seed 35099

# Running:

..................................................................................................................................................................................

Finished in 1.582662s, 112.4688 runs/s, 313.3961 assertions/s.

178 runs, 496 assertions, 0 failures, 0 errors, 0 skips
$ ruby -Ilib:test spec/core/expression_filters_spec.rb
Run options: --seed 34756

# Running:

..................................................................................................................................................................................

Finished in 1.689408s, 105.3623 runs/s, 293.5939 assertions/s.

178 runs, 496 assertions, 0 failures, 0 errors, 0 skips
$ ruby -Ilib:test spec/core/expression_filters_spec.rb
Run options: --seed 45612

# Running:

..................................................................................................................................................................................

Finished in 1.545929s, 115.1411 runs/s, 320.8427 assertions/s.

178 runs, 496 assertions, 0 failures, 0 errors, 0 skips

Anyway, take a look at Sequel's Travis => https://travis-ci.org/jeremyevans/sequel/jobs/63967115

@headius
Copy link
Member

headius commented May 26, 2015

Ugh, that makes even less sense. Ok, thanks.

@headius
Copy link
Member

headius commented May 26, 2015

I tried running the code that fails in a loop and discovered that either every iteration fails or no iterations fail. This is consistent up to 10000 iterations. So something is getting tweaked early on that causes it to format differently forever.

@headius
Copy link
Member

headius commented May 26, 2015

It seems that somehow, some runs are not using a LiteralString for the y key, which causes it to fall back into the more conservative SQL logic that uses single quotes. This class output is in Sequel.expr in the Hash case:

[] ~/projects/sequel $ jruby -Ilib -rsequel -e 'db = Sequel::Database.new[:items]; def db.l(*args); literal(filter_expr(*args)); end; p db.l(Sequel.expr(Sequel.lit("y") => Sequel.lit("z")))'
Sequel::LiteralString
"(y = z)"

[] ~/projects/sequel $ jruby -Ilib -rsequel -e 'db = Sequel::Database.new[:items]; def db.l(*args); literal(filter_expr(*args)); end; p db.l(Sequel.expr(Sequel.lit("y") => Sequel.lit("z")))'
String
"('y' = z)"

@headius
Copy link
Member

headius commented May 26, 2015

@deepj Thanks for the report...this would have been a really weird bug to hunt down in production if we had released it.

The problem here was that we were overzealously attempting to deduplicate string keys in hashes. Where MRI only does it for literal strings in a literal hash, we were doing it for all strings going into hash keys. In addition, our deduplication logic had a critical flaw, allowing non-natural strings (e.g. subclasses like Sequel::LiteralString) to participate in deduplication.

The two issues combined in a wacky way:

  • An early natural string "y" key got deduplicated.
  • Later on, a LiteralString "y" attempted to deduplicate when going into a literal hash.
  • If the weak reference wrapping the earlier natural string "y" had been vacated, the LiteralString stayed a LiteralString and the code worked right.
  • If the weak reference had not been vacated, the LiteralString magically turned into a String, causing the bug.

The fix for now was to remove our overzealous string deduplication and make the dedup cache as strict as it's supposed to be (only natural Strings). I filed #2990 to cover the re-application of dedup optimizations that MRI has decided are safe for Ruby semantics.

@deepj
Copy link
Author

deepj commented May 26, 2015

@headius Great! To issue: Just wow. It is a bit sad I can't help more than only reporting issues :( Anyway, more reports are under way :)

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

No branches or pull requests

3 participants