Issue with compiling and compiler recursion

stakach · June 27, 2019, 12:33am

Wondering if anyone can help me with an issue I’m having where I’m hitting a complexity limit.

Stack overflow (e.g., infinite or very deep recursion)
[0x10c756057] *CallStack::print_backtrace:Int32 +39
[0x10c6a7a20] __crystal_sigfault_handler +96
[0x7fff68526b5d] _sigtramp +29
[0x10c0450ce] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2302
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
...
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
...
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c584dc8] *Crystal::MainVisitor#expand<Crystal::StringInterpolation>:Bool +1608
[0x10c0466f6] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +7974
[0x10c4ab1b8] *Crystal::MainVisitor#type_assign<Crystal::Var+, Crystal::ASTNode+, Crystal::Assign, Nil>:(Crystal::MetaVar | Nil) +40
[0x10c4aa1f3] *Crystal::MainVisitor#visit<Crystal::Assign>:Bool +83
[0x10c044fdc] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2060
[0x10c04768b] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +11963
[0x10c699a04] *Crystal::Call#instantiate<Crystal::Matches, Crystal::Type+, Nil, Bool>:Array(Crystal::Def+) +6708
[0x10c694bdf] *Crystal::Call#lookup_matches_in_type<Crystal::Type+, Array(Crystal::Type+), (Array(Crystal::NamedArgumentType) | Nil), Nil, String, Bool, Bool, Bool>:Array(Crystal::Def+) +6463
[0x10c69b43a] *Crystal::Call#lookup_matches_in:with_literals<Crystal::Type+, Array(Crystal::Type+), (Array(Crystal::NamedArgumentType) | Nil), Bool>:Array(Crystal::Def+) +154
[0x10c60e040] *Crystal::Call#lookup_matches:with_literals<Bool>:Array(Crystal::Def+) +2240
[0x10be29217] *Crystal::Call#recalculate:Nil +2503
[0x10c0cf8b3] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +6819
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0cecd4] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +3780
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c584dc8] *Crystal::MainVisitor#expand<Crystal::StringInterpolation>:Bool +1608
[0x10c0466f6] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +7974
[0x10c0ce165] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +853
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c4ab1b8] *Crystal::MainVisitor#type_assign<Crystal::Var+, Crystal::ASTNode+, Crystal::Assign, Nil>:(Crystal::MetaVar | Nil) +40
[0x10c4aa1f3] *Crystal::MainVisitor#visit<Crystal::Assign>:Bool +83
[0x10c044fdc] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2060
[0x10c04768b] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +11963
[0x10c699a04] *Crystal::Call#instantiate<Crystal::Matches, Crystal::Type+, Nil, Bool>:Array(Crystal::Def+) +6708
[0x10c694bdf] *Crystal::Call#lookup_matches_in_type<Crystal::Type+, Array(Crystal::Type+), (Array(Crystal::NamedArgumentType) | Nil), Nil, String, Bool, Bool, Bool>:Array(Crystal::Def+) +6463
[0x10c69b43a] *Crystal::Call#lookup_matches_in:with_literals<Crystal::Type+, Array(Crystal::Type+), (Array(Crystal::NamedArgumentType) | Nil), Bool>:Array(Crystal::Def+) +154
[0x10c60e040] *Crystal::Call#lookup_matches:with_literals<Bool>:Array(Crystal::Def+) +2240
[0x10be29217] *Crystal::Call#recalculate:Nil +2503
[0x10c0cf8b3] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +6819
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c0cecd4] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +3780
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c04768b] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +11963
[0x10c680414] *Crystal::Call#match_block_arg<Crystal::Match>:Tuple(Array(Crystal::Var+) | Nil, Crystal::Type+ | Nil) +5812
[0x10c698195] *Crystal::Call#instantiate<Crystal::Matches, Crystal::Type+, Nil, Bool>:Array(Crystal::Def+) +453
[0x10c694bdf] *Crystal::Call#lookup_matches_in_type<Crystal::Type+, Array(Crystal::Type+), (Array(Crystal::NamedArgumentType) | Nil), Nil, String, Bool, Bool, Bool>:Array(Crystal::Def+) +6463
[0x10c69b43a] *Crystal::Call#lookup_matches_in:with_literals<Crystal::Type+, Array(Crystal::Type+), (Array(Crystal::NamedArgumentType) | Nil), Bool>:Array(Crystal::Def+) +154
[0x10c60e040] *Crystal::Call#lookup_matches:with_literals<Bool>:Array(Crystal::Def+) +2240
[0x10be29217] *Crystal::Call#recalculate:Nil +2503
[0x10c0cf8b3] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +6819
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c04768b] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +11963
[0x10c4a857c] *Crystal::MainVisitor#visit<Crystal::Block>:(Bool | Nil) +2780
[0x10c4acb6a] *Crystal::MainVisitor#visit<Crystal::Yield>:Bool +1530
[0x10c045156] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2438
[0x10c04768b] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +11963
[0x10c699a04] *Crystal::Call#instantiate<Crystal::Matches, Crystal::Type+, Nil, Bool>:Array(Crystal::Def+) +6708
[0x10c694bdf] *Crystal::Call#lookup_matches_in_type<Crystal::Type+, Array(Crystal::Type+), (Array(Crystal::NamedArgumentType) | Nil), Nil, String, Bool, Bool, Bool>:Array(Crystal::Def+) +6463
[0x10c69b43a] *Crystal::Call#lookup_matches_in:with_literals<Crystal::Type+, Array(Crystal::Type+), (Array(Crystal::NamedArgumentType) | Nil), Bool>:Array(Crystal::Def+) +154
[0x10c60e040] *Crystal::Call#lookup_matches:with_literals<Bool>:Array(Crystal::Def+) +2240
[0x10be29217] *Crystal::Call#recalculate:Nil +2503
[0x10c0cf8b3] *Crystal::MainVisitor#visit<Crystal::Call>:Bool +6819
[0x10c0450d2] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +2306
[0x10c04768b] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::MainVisitor>:Nil +11963
[0x10c2e3df1] *Crystal::Program#visit_main<Crystal::ASTNode+, Crystal::MainVisitor, Bool, Bool>:Crystal::ASTNode+ +129
[0x10c1ecba1] *Crystal::Program#semantic<Crystal::ASTNode+, Bool>:Crystal::ASTNode+ +10769
[0x10c6c1117] *Crystal::Compiler#compile<Array(Crystal::Compiler::Source), String>:Crystal::Compiler::Result +71
[0x10c6aa622] *Crystal::Command#run:(Bool | Crystal::Compiler::Result | Nil) +1090
[0x10be01b7f] __crystal_main +14095

This happens when I add one too many functions to the code I’m working on. You can easily replicate this on your own device by:

requires a local running instance of redis-server
clone: https://github.com/aca-labs/crystal-engine-drivers
run: shards update
run: crystal run ./src/app.cr
browse to: http://localhost:3000/#/aca_drivers/drivers%2Fhelvar%2Fnet.cr?filter=
click run

This will compile and run a spec against a driver (we build commercial building automation systems and this is a development tool we built for writing drivers in crystal) - the Helvar::Net driver is the one triggering this behaviour

The build will probably succeed if you just clone the repository as I limited the number of functions being generated to prevent this compiling issue. But if you uncomment some of these lines the issue will occur

This might be something @asterite would have some experience with - also I am happy to delve deep into the compiler internals if this is something that can be converted from a recursive algorithm to a dynamic one.

Not a super pressing issue at the moment as I don’t need all the functions but would be good to resolve or even understand what is triggering the behaviour.

stakach · June 27, 2019, 1:00am

A slightly different backtrace on the same driver

Stack overflow (e.g., infinite or very deep recursion)
[0x1057c3057] *CallStack::print_backtrace:Int32 +39
[0x105714a20] __crystal_sigfault_handler +96
[0x7fff68526b5d] _sigtramp +29
[0x1053c76e4] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11108
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
...
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053fdd6f] *Crystal::CodeGenVisitor#visit<Crystal::Assign>:(Bool | Nil) +335
[0x1053c52f1] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +1905
[0x1053c5389] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +2057
[0x1053dc605] *Crystal::CodeGenVisitor#codegen_fun<String, Crystal::Def+, Crystal::Type+, Bool, Crystal::CodeGenVisitor::ModuleInfo, Bool, Bool>:LLVM::Function +4757
[0x1053f16ad] *Crystal::CodeGenVisitor#target_def_fun<Crystal::Def+, Crystal::Type+>:LLVM::Function +2445
[0x1053e9a90] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5616
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efeb4] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +1092
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efad3] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +99
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053fdd6f] *Crystal::CodeGenVisitor#visit<Crystal::Assign>:(Bool | Nil) +335
[0x1053c52f1] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +1905
[0x1053c5389] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +2057
[0x1053dc605] *Crystal::CodeGenVisitor#codegen_fun<String, Crystal::Def+, Crystal::Type+, Bool, Crystal::CodeGenVisitor::ModuleInfo, Bool, Bool>:LLVM::Function +4757
[0x1053f16ad] *Crystal::CodeGenVisitor#target_def_fun<Crystal::Def+, Crystal::Type+>:LLVM::Function +2445
[0x1053e9a90] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5616
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053efeb4] *Crystal::CodeGenVisitor#prepare_call_args_non_external<Crystal::Call, Crystal::Def+, Crystal::Type+>:Tuple(Array(LLVM::Value), Bool) +1092
[0x1053e9909] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5225
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053c5389] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +2057
[0x1053dc605] *Crystal::CodeGenVisitor#codegen_fun<String, Crystal::Def+, Crystal::Type+, Bool, Crystal::CodeGenVisitor::ModuleInfo, Bool, Bool>:LLVM::Function +4757
[0x1053c5e68] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +4840
[0x1053e9978] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +5336
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053c5389] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +2057
[0x1053ca918] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +23960
[0x1053c5389] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +2057
[0x1053ea1f2] *Crystal::CodeGenVisitor#visit<Crystal::Call>:Bool +7506
[0x1053c76e8] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +11112
[0x1053c5389] *Crystal::ASTNode+@Crystal::ASTNode#accept<Crystal::CodeGenVisitor>:Nil +2057
[0x10538d898] *Crystal::Compiler#codegen<Crystal::Program, Crystal::ASTNode+, Array(Crystal::Compiler::Source), String>:(Tuple(Array(Crystal::Compiler::CompilationUnit), Array(String)) | Nil) +760
[0x10572e147] *Crystal::Compiler#compile<Array(Crystal::Compiler::Source), String>:Crystal::Compiler::Result +119
[0x105717622] *Crystal::Command#run:(Bool | Crystal::Compiler::Result | Nil) +1090
[0x104e6eb7f] __crystal_main +14095
[0x104e73448] main +56

asterite · June 27, 2019, 1:35am

Is there a way to reproduce this by calling crystal some_file.cr? Otherwise I’m not sure how to instruct that UI to use a different crystal executable which will have the debug info I need to find out why it’s crashing.

stakach · June 27, 2019, 2:16am

Yeah for sure:

cd crystal-engine-drivers
export COMPILE_DRIVER=drivers/helvar/net.cr
crystal build -o helvar_net src/build.cr

The driver code is required dynamically using the ENV var
Thanks for having a look!

asterite · June 27, 2019, 12:42pm

I debugged it a bit and it seems __build_helpers__ is doing something that’s generating a lot of code or I don’t know. The code is too complex and Crystal can’t handle it because the way Crystal works is it will type a call, and when there’s a call inside that it will type that call and so on. There’s a limit to that: the stack size. So apparently your code is generating code and more code and eventually it consumes the entire stack.

I won’t be able to help here.

My advice is to try to avoid macros at all cost and only use them for simple stuff. Traversing type hierarchies, listing methods, etc., is too complex for my taste and will probably give the compiler a bad time.

(plus I never really imagined Crystal being used in that way, I was aiming for a simpler language)

asterite · June 27, 2019, 12:47pm

In fact, I would gladly remove all the type introspection features of the macro language and just leave it to a bare minimum which is to process text, arrays and hashes. I believe introspecting such things and using them for code generations usually leads to code that is more complex than alternative solutions.

asterite · June 27, 2019, 12:49pm

Many of Crystal features exist because at one point we thought “Could this be done? Yes, cool!” without actually thinking about use cases or how it would affect compilation times or even the mess of the resulting code. So I would really like to remove many of those things.

stakach · June 27, 2019, 1:24pm

Thanks for your help - I’ll look to simplify it.
The macro system is super powerful and really useful - we’re using it there to generate a public method dispatch and metadata about the driver.

It would be really annoying to have to code that by hand.

stakach · June 28, 2019, 10:00am

Solved the issue!
This rubbish looking code was causing the issue:

  # provide introspection into available functions
  @@functions : String?
  def self.functions : String
    functions = @@functions
    return functions if functions

      list = %({
      {% for method in methods %}
        {% index = 0 %}
        {% args = [] of Crystal::Macros::Arg %}
        {% for arg in method.args %}
          {% if !method.splat_index || index < method.splat_index %}
            {% args << arg %}
          {% end %}
          {% index = index + 1 %}
        {% end %}

        {{method.name.stringify}}: {
          {% for arg in args %}
            {% if !arg.restriction.is_a?(Union) && arg.restriction.resolve < ::Enum %}
              {% if arg.default_value.is_a?(Nop) %}
                {{arg.name.stringify}}: ["String"],
              {% else %}
                {{arg.name.stringify}}: ["String", "#{{{arg.default_value}}.to_s.to_json}"],
              {% end %}
            {% else %}
              {% if arg.default_value.is_a?(Nop) %}
                {{arg.name.stringify}}: [{{arg.restriction.stringify}}],
              {% else %}
                {{arg.name.stringify}}: [{{arg.restriction.stringify}}, "#{{{arg.default_value}}.to_json}"],
              {% end %}
            {% end %}
          {% end %}
        },
      {% end %}})

    # Remove whitespace, remove all ',' followed by a '}'
    @@functions = list.gsub(/\s/, "").gsub(",}", "}")
  end

replaced it with a string builder and everything works wonderfully now!

  # provide introspection into available functions
  @@functions : String?
  def self.functions : String
    functions = @@functions
    return functions if functions

    list = String.build do |str|
      str << "{"
      {% for method in methods %}
        {% index = 0 %}
        {% args = [] of Crystal::Macros::Arg %}
        {% for arg in method.args %}
          {% if !method.splat_index || index < method.splat_index %}
            {% args << arg %}
          {% end %}
          {% index = index + 1 %}
        {% end %}

        str << '"'
        str << {{method.name.stringify}}
        str << %(": {)
          {% for arg in args %}
            str << '"'
            str << {{arg.name.stringify}}

            {% if !arg.restriction.is_a?(Union) && arg.restriction.resolve < ::Enum %}
              {% if arg.default_value.is_a?(Nop) %}
                str << %(": ["String"],)
              {% else %}
                str << %(": ["String", ")
                str << {{arg.default_value}}.to_s.to_json
                str << %("],)
              {% end %}
            {% else %}
              str << %(": [")
              str << {{arg.restriction.stringify}}
              {% if !arg.default_value.is_a?(Nop) %}
                str << %(", ")
                str << {{arg.default_value}}.to_json
              {% end %}
              str << %("],)
            {% end %}
          {% end %}
        str << "},"
      {% end %}
      str << "}"
    end

    # Remove whitespace, remove all ',' followed by a '}'
    @@functions = funcs = list.gsub(/\s/, "").gsub(",}", "}")
    funcs
  end

Thanks for the advice @asterite I made a whole lot of other improvements too however this was the only thing that actually prevented the compilation.

asterite · June 28, 2019, 11:37am

Nice! I’m happy that it worked!

I should have mentioned, in my stack trace I printed the calls causing the segfault and it was dying at something like:

((((((((((((((((((((((((((((((((((((((((String::Builder.new(...

I thought it could have been a deeply nested string building (via nested interpolations) but I didn’t browse the code that much to understand it.

I’ll try to find a way to reproduce that in a smaller code and think about ways to fix it, I’m not sure it’s possible.

stakach · June 28, 2019, 12:03pm

Yeah, it was super weird. Literally the last bit of code I played around with as it doesn’t interact with anything. So I’m very much of the opinion that it was probably me.
In the end what I thought were the much more complex operations were working fine.

Out of interest, how would one go about debugging the compiler like that?
Any online resources or links to a guide would be awesome. I’m sure this won’t be the last time I push the boundaries of what is possible

asterite · June 28, 2019, 12:21pm

So, what I did was:

Get the compiler’s source code (well, I already have that)
The trace was pointing to Crystal::MainVisitor#visit<Crystal::Call>:Bool. That’s the method where a call is typed (or prepared to be typed). I went to that method and added this line: p! node, node.location to see the trace of calls being typed.
Then I compile the compiler with make clean crystal
Finally, I use the compiled compiler with the problematic program. You just need to call bin/crystal and then the program, though from the problematic program’s path, so in my case it’s /Users/asterite/Projects/crystal/bin/crystal. Because I don’t want to type that all the type I have alias ccrystal="/Users/asterite/Projects/crystal/bin/crystal" in my bash profile.

And that’s it!

For stuff that I can reduce to simpler code I usually add a compiler spec, which involves other steps. But anyone can modify the compiler, compile it and then use it on any other program with some changes.

asterite · June 28, 2019, 12:29pm

So, I wrote this Crystal program:

# foo.cr
times = 3000
puts(String.build do |io|
  io << "puts "
  times.times do
    io << %("a\#{)
  end
  io << 1
  times.times do
    io << %(}")
  end
end)

then I do:

crystal foo.cr > bar.cr

and then:

crystal bar.cr

and with that I get the stack overflow.

But we can run it with Ruby too!

ruby bar.cr

I get:

$ ruby bar.cr
bar.cr:1: memory exhausted
...a#{"a#{"a#{"a#{"a#{"a#{"a#{"a#{"a#{"a#{"a#{"a#{"a#{"a#{"a#{"...

I even get that with times = 1500 in Ruby, but with that number Crystal works fine.

So I guess in your case it was a really deep nested interpolation.

I don’t think there’s nothing we can do to improve this.

asterite · June 28, 2019, 12:43pm

By the way, I was surprised to see that the total number of Crystal lines of code in the repo, including lib, is about 20K. And for me the initial compilation takes about 7 seconds, but subsequent compilations take 2 seconds. It’s acceptable, I think!

stakach · June 28, 2019, 2:43pm

Awesome! Thank you so much for the explanation!
The deeply nested interpolation was definitely a mistake on my part

I find the compile times to be very good - really blows my mind how good the language is. I am so much more productive than I have been on Ruby. 99% of the time, when something compiles, it works first go and I often find myself breaking tests deliberately to make certain that they are running.

Thus far we’ve migrated everything but our Authentication service to Crystal and should have the Crystal version released by August.
You can see an overview of the project here: https://docs.google.com/document/d/1fT7GSghFxovsQkLimmthc28xnWAac9d8ojIH56MhusU/edit?usp=sharing

The system we’re building is a distributed building automation platform - the ruby version had hot loading, but was fairly monolithic - the crystal version compiles drivers and launches a process for each type of hardware (one process might control thousands of LCD displays across an organisation for example)
The driver compiling and process launching aspect on the servers is dynamic, driven by the database and coordinated by services written in Crystal.

The whole thing is open source so I might make an announcement once it’s production ready

girng · June 29, 2019, 5:34am

Yeah, that’s quite nice. I still don’t understand why people complained about slow compile times.

I complain about weird stuff too, so I guess it makes sense.

stakach · June 29, 2019, 8:52am

Yeah, given the compile + startup time of running the app above takes roughly the same time as launching a rails app, I am as productive as I’ve ever been