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.

Sign up for GitHub

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

Jump to bottom

haml-lint hangs with JRuby 9.1.12.0 #4734

Closed
HarlemSquirrel opened this issue Aug 4, 2017 · 11 comments
Closed

haml-lint hangs with JRuby 9.1.12.0 #4734

HarlemSquirrel opened this issue Aug 4, 2017 · 11 comments
Labels
regression
Milestone
JRuby 9.1.13.0

Comments

@HarlemSquirrel
Copy link

Environment

➤  ruby -v
jruby 9.1.12.0 (2.3.3) 2017-06-15 33c6439 OpenJDK 64-Bit Server VM 25.131-b11 on 1.8.0_131-8u131-b11-2ubuntu1.16.04.3-b11 +jit [linux-x86_64]

➤  bundle show haml_lint                                                                                                         7 ↵
~/.rvm/gems/jruby-9.1.12.0/gems/haml_lint-0.26.0

Expected Behavior

With JRuby 9.1.7.0 haml-lint runs as expected in a few seconds

➤  JRUBY_OPTS='--dev --profile' haml-lint app/**/*.html.haml   
Profiling enabled; ^C shutdown will now dump profile info
warning: parser/current is loading parser/ruby23, which recognizes
warning: 2.3.3-compliant syntax, but you are running 2.3.1.
warning: please see https://github.com/whitequark/parser#compatibility-with-ruby-mri.
app/views/auth/logout.html.haml:6 [W] SpaceInsideHashAttributes: Hash attribute should start with one space after the opening brace
app/views/auth/logout.html.haml:6 [W] SpaceInsideHashAttributes: Hash attribute should end with one space before the closing brace
app/views/auth/logout.html.haml:6 [W] LineLength: Line is too long. [95/80]
...
app/views/services/show.html.haml:18 [W] RuboCop: unexpected token tCOLON
(Using Ruby 2.1 parser; configure using `TargetRubyVersion` parameter, under `AllCops`)

32 files inspected, 236 lints detected

main profile results:
Total time: 9.19

     total        self    children       calls  method
----------------------------------------------------------------
      8.27        0.07        8.20          29  Kernel.load
      8.03        0.12        7.91         284  Kernel.eval
      6.28        0.04        6.23       83047  Array#each
      5.52        0.01        5.51       27823  Array#map
      5.30        0.00        5.30           1  HamlLint::CLI#run
      5.29        0.00        5.29           1  HamlLint::CLI#act_on_options
      5.29        0.00        5.29           1  HamlLint::CLI#scan_for_lints
      5.29        0.00        5.29           1  HamlLint::Runner#run
      5.25        0.00        5.25           1  HamlLint::Runner#report
      5.25        0.00        5.25           1  HamlLint::Runner#process_files
      5.25        0.00        5.25          32  HamlLint::Runner#process_file
      5.23        0.00        5.23          32  HamlLint::Runner#collect_lints
      5.08        0.00        5.07         896  HamlLint::Linter#run
      5.07        0.00        5.07       21634  HamlLint::HamlVisitor.visit
      4.71        0.05        4.66       43268  HamlLint::HamlVisitor.safe_send
      4.70        0.01        4.69      137108  Kernel.send
      3.32        0.02        3.30        2111  Kernel.require
      3.09        0.00        3.09        1014  Kernel.require
      2.67        0.00        2.67          32  HamlLint::Linter::RuboCop#visit_root
      2.60        0.00        2.60          32  HamlLint::Linter::RuboCop#find_lints
      2.60        0.00        2.60          32  HamlLint::Linter::RuboCop#with_ruby_from_stdin
      2.59        0.00        2.59          32  HamlLint::Linter::RuboCop#lint_file
      2.59        0.00        2.59          32  RuboCop::CLI#run
      2.37        0.00        2.37       21634  HamlLint::HamlVisitor.visit_children
      2.36        0.08        2.28       98355  Class#new
      2.34        0.00        2.34          32  RuboCop::CLI#execute_runner
      2.34        0.00        2.34          32  RuboCop::Runner#run
      2.33        0.00        2.33          32  RuboCop::Runner#inspect_files
      2.33        0.00        2.33         522  Enumerable.inject
      2.33        0.00        2.33          32  RuboCop::Runner#each_inspected_file
      2.32        0.00        2.32          32  RuboCop::Runner#process_file
      2.32        0.00        2.32          32  RuboCop::Runner#file_offenses
      2.32        0.00        2.32          32  RuboCop::Runner#file_offense_cache
      2.06        0.00        2.06        1108  Parser::Base#parse
      2.06        0.00        2.06       15282  BasicObject#__send__
      2.05        0.00        2.04        1108  Racc::Parser#do_parse
      2.04        0.06        1.98        1108  Racc::Parser#_racc_do_parse_c
      1.67        0.00        1.67        1076  HamlLint::RubyParser#parse
      1.60        0.01        1.60        8817  Parser::Base#next_token
      1.60        1.12        0.48        8817  Parser::Lexer#advance
      1.58        0.02        1.56         205  Kernel.loop
      1.38        0.00        1.38          32  RuboCop::Runner#do_inspection_loop
      1.38        0.00        1.38          32  RuboCop::Runner#iterate_until_no_changes
      1.37        0.00        1.37          32  RuboCop::Runner#inspect_file
      1.24        0.13        1.11        2433  Enumerable.find
      1.12        0.00        1.11         902  Gem::Specification.find_active_stub_by_path
      0.98        0.00        0.98         596  HamlLint::Linter::InstanceVariables#visit_script
      0.81        0.00        0.81         115  HamlLint::Tree::ScriptNode#parsed_script
      0.76        0.00        0.76           1  Gem::ExecutableHooks.run
      0.75        0.00        0.75          32  RuboCop::Cop::Team#inspect_file

Actual Behavior

Command runs extremely slowly or hangs until ^C is issued when running with 9.1.12.0.

➤  JRUBY_OPTS='--dev --profile' haml-lint app/**/*.html.haml   
Profiling enabled; ^C shutdown will now dump profile info
app/views/auth/logout.html.haml:6 [W] SpaceInsideHashAttributes: Hash attribute should start with one space after the opening brace
app/views/auth/logout.html.haml:6 [W] SpaceInsideHashAttributes: Hash attribute should end with one space before the closing brace
app/views/auth/logout.html.haml:6 [W] LineLength: Line is too long. [95/80]
app/views/auth/logout.html.haml:6 [W] RuboCop: Space inside { missing.
app/views/auth/logout.html.haml:6 [W] RuboCop: Use the new Ruby 1.9 hash syntax.
app/views/auth/logout.html.haml:6 [W] RuboCop: Prefer single-quoted strings when you don't need string interpolation or special symbols.
app/views/auth/logout.html.haml:6 [W] RuboCop: Use the new Ruby 1.9 hash syntax.
app/views/auth/logout.html.haml:6 [W] RuboCop: Prefer single-quoted strings when you don't need string interpolation or special symbols.
app/views/auth/logout.html.haml:6 [W] RuboCop: Use the new Ruby 1.9 hash syntax.
app/views/auth/logout.html.haml:6 [W] RuboCop: Prefer single-quoted strings when you don't need string interpolation or special symbols.
app/views/auth/logout.html.haml:6 [W] RuboCop: Use the new Ruby 1.9 hash syntax.
app/views/auth/logout.html.haml:6 [W] RuboCop: Prefer single-quoted strings when you don't need string interpolation or special symbols.
app/views/auth/logout.html.haml:6 [W] RuboCop: Space inside } missing.
^C
Exiting... Interrupt again to exit immediately.
^C
main profile results:
Total time: 1.44

     total        self    children       calls  method
----------------------------------------------------------------
    126.85      113.70       13.15    24165653  Racc::Parser#_racc_evalact
      7.95        7.95        0.00   205486175  Array#[]
      6.24        5.41        0.84    12091140  BasicObject#!=
      2.61        2.61        0.00    24170062  Array#push
      2.31        1.43        0.87    24192617  Array#length
      2.29        0.02        2.27        2990  Kernel.require
      2.23        2.23        0.00    24166561  Array#pop
      1.35        1.35        0.00    24168699  Fixnum#-@
      0.93       -0.49        1.42       13646  Array#each
      0.89        0.00        0.89           1  Gem::ExecutableHooks.run
      0.85        0.07        0.78       15219  Class#new
      0.84        0.84        0.00    12105334  BasicObject#!
      0.83        0.00        0.83       16143  Kernel.send
      0.80       -0.26        1.05        3216  Array#map
      0.76        0.00        0.76          49  HamlLint::Linter#run
      0.76        0.00        0.76         715  HamlLint::HamlVisitor.visit
      0.74        0.00        0.74        1425  HamlLint::HamlVisitor.safe_send
      0.73        0.00        0.73         111  Kernel.require
      0.71        0.00        0.71           2  HamlLint::Linter::RuboCop#visit_root
      0.70        0.00        0.70           2  HamlLint::Linter::RuboCop#find_lints
      0.70        0.00        0.70           2  HamlLint::Linter::RuboCop#with_ruby_from_stdin
      0.70        0.00        0.70           2  HamlLint::Linter::RuboCop#lint_file
      0.70        0.00        0.70           2  RuboCop::CLI#run
      0.69        0.00        0.69         404  Enumerable.inject
      0.68        0.00        0.68           2  RuboCop::CLI#execute_runner
      0.68        0.00        0.68           2  RuboCop::Runner#run
      0.68        0.00        0.68           2  RuboCop::Runner#inspect_files
      0.68        0.00        0.68           2  RuboCop::Runner#each_inspected_file
      0.68        0.00        0.68           2  RuboCop::Runner#process_file
      0.68        0.00        0.68           2  RuboCop::Runner#file_offenses
      0.68        0.00        0.68           2  RuboCop::Runner#file_offense_cache
      0.62        0.00        0.62        2173  Proc#call
      0.59        0.00        0.59           1  Noexec#check
      0.59        0.00        0.59           1  Noexec#setup
      0.50        0.00        0.50           2  HamlLint::Runner#process_file
      0.50       -0.01        0.51           2  HamlLint::Runner#collect_lints
      0.48        0.00        0.48           1  Noexec#candidate?
      0.42       -1.25        1.67          29  Kernel.load
      0.40        0.01        0.39         235  Gem::Specification.load
      0.35        0.01        0.35          18  Kernel.loop
      0.33        0.00        0.33         229  Gem::StubSpecification#to_spec
      0.32        0.14        0.18         266  Kernel.eval
      0.29        0.00        0.29           1  Gem.load_executable_plugins
      0.29        0.00        0.29           1  Gem.find_latest_files
      0.26        0.00        0.26           2  RuboCop::Runner#do_inspection_loop
      0.26        0.00        0.26           2  RuboCop::Runner#iterate_until_no_changes
      0.26        0.00        0.26           2  RuboCop::Runner#inspect_file
      0.25        0.00        0.25           1  Gem::Specification.latest_specs
      0.25        0.00        0.25           2  Gem::Specification._all
      0.24        0.00        0.24        2067  BasicObject#__send__
Exception in thread "Thread-1" java.lang.IllegalStateException: Shutdown in progress
	at java.lang.ApplicationShutdownHooks.add(ApplicationShutdownHooks.java:66)
	at java.lang.Runtime.addShutdownHook(Runtime.java:211)
	at org.jruby.runtime.profile.builtin.ProfileOutput.footerAndCleanupOnShutdown(ProfileOutput.java:36)
	at org.jruby.runtime.profile.builtin.ProfileOutput.printProfile(ProfileOutput.java:31)
	at org.jruby.runtime.profile.builtin.BuiltinProfilingService$DefaultProfileReporter.report(BuiltinProfilingService.java:120)
	at org.jruby.Ruby.printProfileData(Ruby.java:3331)
	at org.jruby.Ruby.tearDown(Ruby.java:3291)
	at org.jruby.Ruby.tearDown(Ruby.java:3189)
	at org.jruby.Main$1.run(Main.java:283)

I also opened this issue with haml-lint
sds/haml-lint#257
@headius
Copy link
Member

headius commented Aug 7, 2017

We need more information or an easy way to reproduce.

When it's obvious it's hanging, you can grab a dump of all threads with Ctrl+\ on *nix or Ctrl+Break on Windows. Link us a gist of that output.

You might also try bumping up the JVM memory by passing -J-Xmx###M where ### is something larger than the default 500M we cap the VM at.

@HarlemSquirrel
Copy link
Author

@headius OK, here's the dump: https://gist.github.com/HarlemSquirrel/d4a135c0c8d0cc3dd2b7f3683611f310

I'm going to try to run now with more memory.

@HarlemSquirrel
Copy link
Author

No improvement increasing memory up to 1024M. She still hangs and seems to spend the most time on Racc::Parser#_racc_evalact

@enebo enebo added this to the JRuby 9.1.13.0 milestone Aug 16, 2017
@enebo
Copy link
Member

enebo commented Aug 17, 2017

@HarlemSquirrel The next obvious thing to ask would be to bisect JRuby until you figured out which commit causes this. I know that sucks but I did not see anything jump out at me in that gist.

@HarlemSquirrel
Copy link
Author

HarlemSquirrel commented Aug 17, 2017 •
edited
Loading

@enebo OK, my first investigation has been to try all JRuby versions from 9.1.7.0 - 9.1.12.0 and it seems like the issues starts with version 9.1.9.0.

https://gist.github.com/HarlemSquirrel/34a14f7e6c2a8de9fb1fb12484c96b3c

So I guess the issue is somewhere in 9.1.8.0...9.1.9.0

@HarlemSquirrel
Copy link
Author

HarlemSquirrel commented Aug 17, 2017 •
edited
Loading

I starting working on the bisect but am having issues running haml-lint during the bisect.

LoadError: no such file to load -- racc/parser

Here's what I'm running

git bisect start tags/9.1.9.0 tags/9.1.8.0
git bisect run sh haml_lint_bisect.sh

The script that runs each time

#!/bin/sh

export JRUBY_OPTS='--dev'

./mvnw
bin/jruby -S gem install haml_lint
timeout 10 bin/jruby -S haml-lint ../services-directory/app/views/layouts/_flash_messages.html.haml

Update
According to https://github.com/tenderlove/racc#requirements
Racc should be included with Ruby 1.8+
I can reproduce this error during any bisect step

➤  echo "require 'racc/parser'; puts 'working'" | bin/jruby
LoadError: no such file to load -- racc/parser

@enebo
Copy link
Member

enebo commented Aug 17, 2017

@HarlemSquirrel I think you may need to change that to ./mvnw cleaan; ./mvn since it may be packaging. Many times we can incrementally build and it all works but I am guessing something is not getting packaged properly.

@HarlemSquirrel
Copy link
Author

@enebo I just discovered this too after reading https://github.com/jruby/jruby/blob/master/BUILDING.md#clean-build. I needed to clean before each new build.

@HarlemSquirrel
Copy link
Author

Looks like I've found the commit

3fe1cc2353e8b051a7541d3cb63d5210e99d8539 is the first bad commit
commit 3fe1cc2353e8b051a7541d3cb63d5210e99d8539
Author: Charles Oliver Nutter <headius@headius.com>
Date:   Mon May 15 14:02:39 2017 -0500

    Use actual racc/parser.rb from MRI 2.3. For #4603.

:040000 040000 9e6b985b8bfa9ec600c86d3932476ab8b1964b9f b96df1b32d1741fd54d1f696c578c3ef3d499ece M	lib
bisect run success

@enebo enebo closed this as completed in 4d42ac3 Aug 17, 2017
enebo added a commit that referenced this issue Aug 17, 2017
@enebo
Fixes #4734. haml-lint hangs with JRuby 9.1.12.0.
baeaad1 
pure-Ruby was loading and not our native extension.
@enebo
Copy link
Member

enebo commented Aug 17, 2017

@HarlemSquirrel Your bisect made this trivial. A merge did not happen correctly and we stopped loading the native extesion version of racc. Can you please verify the problem you are seeing is gone (there were some other changes in that commit)?

@HarlemSquirrel
Copy link
Author

@enebo Nice! haml-lint is working beautifully with JRuby built from master this morning! 🎊

@HarlemSquirrel HarlemSquirrel mentioned this issue Aug 24, 2017
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
regression
Projects
None yet
Milestone
JRuby 9.1.13.0
Development

No branches or pull requests
3 participants
@headius @enebo @HarlemSquirrel