The Crystal Programming Language Forum

Does --debug disable/affect --release mode build?

Hello folks,

Been using --debug with release builds in order to collect as much backtrace information when exceptions are raised.

Take the following comparing example:

cat boom.cr
def boom
  raise "BOOM!"
end

def foo
  boom
end

foo

When compiled without options (crystal build boom.cr) here is the obtained backtrace of that exception:

./boom
Unhandled exception: BOOM! (Exception)
  from boom.cr:6:3 in 'foo'
  from /home/luis/.asdf/installs/crystal/1.1.1/share/crystal/src/crystal/once.cr:44:0 in '__crystal_main'
  from /home/luis/.asdf/installs/crystal/1.1.1/share/crystal/src/crystal/main.cr:110:5 in 'main_user_code'
  from /home/luis/.asdf/installs/crystal/1.1.1/share/crystal/src/crystal/main.cr:96:7 in 'main'
  from /home/luis/.asdf/installs/crystal/1.1.1/share/crystal/src/crystal/main.cr:119:3 in 'main'
  from __libc_start_main
  from _start
  from ???

This is similar to adding --debug option, but --release produces something different:

./boom
Unhandled exception: BOOM! (Exception)
  from boom.cr:2:3 in 'boom'
  from boom.cr:6:3 in 'foo'
  from /home/luis/.asdf/installs/crystal/1.1.1/share/crystal/src/string.cr:252:13 in '__crystal_main'
  from __libc_start_main
  from _start
  from ???

And combining both --release and --debug, produces the following:

./boom
Unhandled exception: BOOM! (Exception)
  from boom.cr:2:3 in 'boom'
  from boom.cr:6:3 in 'foo'
  from /home/luis/.asdf/installs/crystal/1.1.1/share/crystal/src/crystal/once.cr:44:0 in '__crystal_main'
  from /home/luis/.asdf/installs/crystal/1.1.1/share/crystal/src/crystal/main.cr:110:5 in 'main_user_code'
  from /home/luis/.asdf/installs/crystal/1.1.1/share/crystal/src/crystal/main.cr:96:7 in 'main'
  from /home/luis/.asdf/installs/crystal/1.1.1/share/crystal/src/crystal/main.cr:119:3 in 'main'
  from __libc_start_main
  from _start
  from ???

However, while this has provided me a rich and accurate backtraces, it also introduced some performance issues.

Take the following HTTP server program:

require "http/server"

server = HTTP::Server.new do |context|
  context.response.content_type = "text/plain"
  context.response.print "Hello world!"
end

Signal::INT.trap do
  puts "Shutdown requested."
  server.close
end

server.bind_tcp "0.0.0.0", 8080

puts "Listening on:"
server.addresses.each do |addr|
  puts "- #{addr}"
end
puts "Use Ctrl-C to stop"

server.listen

When compiled with just --release mode, it shows the following when performing some synthetic benchmarks:

$ plow -c 5 -d 30s http://localhost:8080/
Benchmarking http://localhost:8080/ for 30s using 5 connection(s).
@ Real-time charts is listening on http://127.0.0.1:18888/

Summary:
  Elapsed        30s
  Count      1064809
    2xx      1064809
  RPS      35492.713
  Reads    3.419MB/s
  Writes   1.963MB/s

Statistics    Min       Mean    StdDev    Max
  Latency     18µs     136µs     96µs   11.184ms
  RPS       32672.67  35492.35  787.3   36242.86

Latency Percentile:
  P50     P75    P90    P95    P99    P99.9   P99.99
  127µs  167µs  204µs  230µs  309µs  1.546ms  1.97ms

Latency Histogram:
  120µs    868738  81.59%
  184µs    165186  15.51%
  249µs     24780   2.33%
  407µs      4904   0.46%
  1.317ms     758   0.07%
  1.838ms     427   0.04%
  1.989ms      13   0.00%
  2.743ms       3   0.00%

Versus the exact same program build with --release --debug shows a ~30% slowdown:

$ plow -c 5 -d 30s http://localhost:8080/
Benchmarking http://localhost:8080/ for 30s using 5 connection(s).
@ Real-time charts is listening on http://127.0.0.1:18888/

Summary:
  Elapsed        30s
  Count       647954
    2xx       647954
  RPS      21597.793
  Reads    2.080MB/s
  Writes   1.195MB/s

Statistics    Min      Mean    StdDev    Max
  Latency    33µs     223µs    104µs   3.604ms
  RPS       20597.5  21597.24  345.18  22196.03

Latency Percentile:
  P50     P75    P90    P95    P99    P99.9   P99.99
  211µs  265µs  320µs  356µs  453µs  1.641ms  2.182ms

Latency Histogram:
  204µs    518839  80.07%
  260µs     83098  12.82%
  325µs     35479   5.48%
  417µs      9054   1.40%
  789µs      1097   0.17%
  1.574ms     267   0.04%
  1.831ms      95   0.01%
  2.17ms       25   0.00%

Only references I could find about debug symbols were around this issue and this PR associated with DWARF symbols.

Thoughts or recommendations?

Cheers,
Luis