# IO seems to be slower with \`--release\` flag

**URL:** <https://forum.crystal-lang.org/t/io-seems-to-be-slower-with-release-flag/2991>\
**Category:** Help & Support\
**Created:** [February 26, 2021, 12:36pm UTC](https://forum.crystal-lang.org/t/io-seems-to-be-slower-with-release-flag/2991 "2021-02-26T12:36:04Z")\
**Posts on this page:** 15\
**Page:** 1

<div class="post-metadata">

**Author:** ![gdotdesign](https://yyz2.discourse-cdn.com/flex036/user_avatar/forum.crystal-lang.org/gdotdesign/32/35_2.png) [@gdotdesign](https://forum.crystal-lang.org/u/gdotdesign)\
**Post date:** [February 26, 2021, 12:36pm UTC](https://forum.crystal-lang.org/t/io-seems-to-be-slower-with-release-flag/2991/1 "2021-02-26T12:36:04Z")

</div>

Hi folks 👋

I’m not sure if anyone came across with something like this before but actually Mint ([GitHub - mint-lang/mint: A refreshing programming language for the front-end web.](https://github.com/mint-lang/mint)) runs slower with `--release` flag - at least parts of it - then without.

With `--release` flag (built in alpine docker container and statically linked and also with build on developer machine):

```nohighlight
❯ time mint build
Mint - Building for production
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
⚙ Ensuring dependencies... 0μs
⚙ Clearing the "dist" directory... 3.392ms
⚙ Copying "public" folder contents... 14.85ms
⚙ Compiling your application:
  ➔ Parsing 153 source files... 18.442s
  ➔ Type checking: 132.299ms
  ➔ Compiling: 206.04ms
⚙ Writing index.html... 445μs
⚙ Writing manifest.json...51μs
⚙ Generating icons... 120.198ms
⚙ Creating service worker...17.826ms
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
All done in 22.701s!
./mint build 23,23s user 0,20s system 103% cpu 22,717 total

```

Without `--release` flag (built in development machine):

```nohighlight
❯ time mint-dev build
Mint - Building for production
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
⚙ Ensuring dependencies... 0μs
⚙ Clearing the "dist" directory... 790μs
⚙ Copying "public" folder contents... 3.201ms
⚙ Compiling your application:
  ➔ Parsing 153 source files... 8.391s
  ➔ Type checking: 218.748ms
  ➔ Compiling: 823.635ms
⚙ Writing index.html... 697μs
⚙ Writing manifest.json...145μs
⚙ Generating icons... 342.277ms
⚙ Creating service worker...12.597ms
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━
All done in 10.825s!
mint-dev build 11,59s user 0,46s system 105% cpu 11,377 total

```

It seems to me that IO related tasks - clearing dist folder, copying public folder, parsing files - are slower while CPU heavy tasks - type checking, compiling - are quicker.

I don’t remember this being the case before, but I haven’t been checking regularly.

I have two questions:

1. Anyone know why it is this way?
2. Anyone did in-depth profiling of Crystal applications? I’m interested in per method duration to see which parts are the bottlenecks. Flamegraph maybe?

Thanks

---

<div class="post-metadata">

**Author:** ![j8r](https://yyz2.discourse-cdn.com/flex036/user_avatar/forum.crystal-lang.org/j8r/32/111_2.png) [@j8r](https://forum.crystal-lang.org/u/j8r)\
**Post date:** [February 28, 2021, 6:25pm UTC](https://forum.crystal-lang.org/t/io-seems-to-be-slower-with-release-flag/2991/2 "2021-02-28T18:25:41Z")

</div>

Try compiling statically on Alpine with, and without `--release`. Then, the same on the developer machine directly. This way we will be able to know more precisely on which cases the binary is slower.

---

<div class="post-metadata">

**Author:** ![asterite](https://yyz2.discourse-cdn.com/flex036/user_avatar/forum.crystal-lang.org/asterite/32/60_2.png) [@asterite](https://forum.crystal-lang.org/u/asterite)\
**Post date:** [March 1, 2021, 7:42pm UTC](https://forum.crystal-lang.org/t/io-seems-to-be-slower-with-release-flag/2991/3 "2021-03-01T19:42:46Z")

</div>

> Anyone know why it is this way?

It would be nice if you could have a small benchmark program to see this in action, otherwise it’s pretty much impossible for others to try to figure out why this is happening.

> Anyone did in-depth profiling of Crystal applications? I’m interested in per method duration to see which parts are the bottlenecks. Flamegraph maybe?

If you are on Mac you can use XCode’s Instruments “Time Profiler”. But you’ll need to put the offending code in a loop to get good results.

---

<div class="post-metadata">

**Author:** ![gdotdesign](https://yyz2.discourse-cdn.com/flex036/user_avatar/forum.crystal-lang.org/gdotdesign/32/35_2.png) [@gdotdesign](https://forum.crystal-lang.org/u/gdotdesign)\
**Post date:** [March 2, 2021, 9:03am UTC](https://forum.crystal-lang.org/t/io-seems-to-be-slower-with-release-flag/2991/4 "2021-03-02T09:03:14Z")

</div>

```plaintext
Timings for the `mint build` command with different builds.

# 0.36.1 (alpine in docker)

Build args: --static
Timings: 14,47s user 0,21s system 106% cpu 13,730 total

Build args: --static --release
Timings: 25,18s user 0,23s system 102% cpu 24,677 total

# 0.35.1 (alpine in docker)

Build args: --static
Timings: 16,47s user 0,24s system 107% cpu 15,612 total

Build args: --static --release
Timings: 14,57s user 0,19s system 105% cpu 13,963 total

# 0.36.1

Build args: --error-on-warnings --error-trace --progress
Timings: 10,48s user 0,23s system 109% cpu 9,749 total

Build args: --error-on-warnings --error-trace --progress --release
Timings: 9,86s user 0,24s system 110% cpu 9,148 total

# 0.36.0

Build args: --error-on-warnings --error-trace --progress
Timings: 11,61s user 0,26s system 106% cpu 11,197 total

Build args: --error-on-warnings --error-trace --progress --release
Timings: 28,24s user 0,19s system 101% cpu 27,928 total

# 0.35.1

Build args: --error-on-warnings --error-trace --progress
Timings: 10,00s user 0,20s system 109% cpu 9,289 total

Build args: --error-on-warnings --error-trace --progress --release
Timings: 10,57s user 0,26s system 109% cpu 9,866 total

```

Locally it seems that the issue was with `0.36.0` since it’s not happening on `0.36.1` any more, but on alpine it seems still the case.

> If you are on Mac you can use XCode’s Instruments “Time Profiler”. But you’ll need to put the offending code in a loop to get good results.

Thanks but I’m on Linux and I want to find the offending code 😃

---

<div class="post-metadata">

**Author:** ![j8r](https://yyz2.discourse-cdn.com/flex036/user_avatar/forum.crystal-lang.org/j8r/32/111_2.png) [@j8r](https://forum.crystal-lang.org/u/j8r)\
**Post date:** [March 4, 2021, 9:48pm UTC](https://forum.crystal-lang.org/t/io-seems-to-be-slower-with-release-flag/2991/5 "2021-03-04T21:48:23Z")

</div>

What’s the result with the Ubuntu Docker image?

---

<div class="post-metadata">

**Author:** ![gdotdesign](https://yyz2.discourse-cdn.com/flex036/user_avatar/forum.crystal-lang.org/gdotdesign/32/35_2.png) [@gdotdesign](https://forum.crystal-lang.org/u/gdotdesign)\
**Post date:** [March 5, 2021, 4:25am UTC](https://forum.crystal-lang.org/t/io-seems-to-be-slower-with-release-flag/2991/6 "2021-03-05T04:25:17Z")

</div>

I’m using Elementary OS (which is based on Ubuntu 18.04 LTS (bionic)), the docker based images should be different?

---

<div class="post-metadata">

**Author:** ![j8r](https://yyz2.discourse-cdn.com/flex036/user_avatar/forum.crystal-lang.org/j8r/32/111_2.png) [@j8r](https://forum.crystal-lang.org/u/j8r)\
**Post date:** [March 5, 2021, 6:09pm UTC](https://forum.crystal-lang.org/t/io-seems-to-be-slower-with-release-flag/2991/7 "2021-03-05T18:09:35Z")

</div>

I guess you’re right.

The only way to be sure with your issue is to profile the binary, for example with Valgrind (I’ve no experience with this).

---

<div class="post-metadata">

**Author:** ![rogerdpack](https://yyz2.discourse-cdn.com/flex036/user_avatar/forum.crystal-lang.org/rogerdpack/32/117_2.png) [@rogerdpack](https://forum.crystal-lang.org/u/rogerdpack)\
**Post date:** [March 9, 2021, 6:22pm UTC](https://forum.crystal-lang.org/t/io-seems-to-be-slower-with-release-flag/2991/8 "2021-03-09T18:22:19Z")

</div>

IO is tricky to profile with crystal. You can profile cpu OK: [Performance - Crystal](https://crystal-lang.org/reference/guides/performance.html)

---

<div class="post-metadata">

**Author:** ![gdotdesign](https://yyz2.discourse-cdn.com/flex036/user_avatar/forum.crystal-lang.org/gdotdesign/32/35_2.png) [@gdotdesign](https://forum.crystal-lang.org/u/gdotdesign)\
**Post date:** [March 10, 2021, 9:24am UTC](https://forum.crystal-lang.org/t/io-seems-to-be-slower-with-release-flag/2991/9 "2021-03-10T09:24:26Z")

</div>

Thanks for pointing me to Valgrind, I’ve managed to record calls made which is helpful.

---

<div class="post-metadata">

**Author:** ![gdotdesign](https://yyz2.discourse-cdn.com/flex036/user_avatar/forum.crystal-lang.org/gdotdesign/32/35_2.png) [@gdotdesign](https://forum.crystal-lang.org/u/gdotdesign)\
**Post date:** [March 10, 2021, 9:25am UTC](https://forum.crystal-lang.org/t/io-seems-to-be-slower-with-release-flag/2991/10 "2021-03-10T09:25:31Z")

</div>

It might not be IO, so in theory what can make programs slower in `--release` mode?

---

<div class="post-metadata">

**Author:** ![rogerdpack](https://yyz2.discourse-cdn.com/flex036/user_avatar/forum.crystal-lang.org/rogerdpack/32/117_2.png) [@rogerdpack](https://forum.crystal-lang.org/u/rogerdpack)\
**Post date:** [May 13, 2021, 7:12pm UTC](https://forum.crystal-lang.org/t/io-seems-to-be-slower-with-release-flag/2991/11 "2021-05-13T19:12:03Z")

</div>

Maybe it hits the IO harder in release mode, which causes more contention on it, pulling the whole thing down…hard to tell…

---

<div class="post-metadata">

**Author:** ![erdnaxeli](https://yyz2.discourse-cdn.com/flex036/user_avatar/forum.crystal-lang.org/erdnaxeli/32/1242_2.png) [@erdnaxeli](https://forum.crystal-lang.org/u/erdnaxeli)\
**Post date:** [May 13, 2021, 7:43pm UTC](https://forum.crystal-lang.org/t/io-seems-to-be-slower-with-release-flag/2991/12 "2021-05-13T19:43:32Z")

</div>

I tried this code

```auto
50000.times do
  f = File.tempfile
  f << "hello world!"
  f.flush
  f.seek(0)
  puts f.gets_to_end
  f.delete
end

```

And it is not slower in release mode. In fact it is a bit faster: ~1.7s vs 1.5s on my computer.

---

<div class="post-metadata">

**Author:** ![gdotdesign](https://yyz2.discourse-cdn.com/flex036/user_avatar/forum.crystal-lang.org/gdotdesign/32/35_2.png) [@gdotdesign](https://forum.crystal-lang.org/u/gdotdesign)\
**Post date:** [May 23, 2021, 11:18am UTC](https://forum.crystal-lang.org/t/io-seems-to-be-slower-with-release-flag/2991/13 "2021-05-23T11:18:51Z")

</div>

So we finally figured out why it was slow: it wasn’t IO but exceptions:

Basically the parser of Mint used exceptions to exit early from functions and by [refactoring that](https://github.com/mint-lang/mint/pull/435) into checking `nil` caused a massive speed up in parsing.

With this and some other optimizations the parsing of the same code base went from the earlier reported `25.18s` to `499.643ms`.

I still don’t know why using the `--release` flag doubled the parsing time but I guess it does something to exceptions 🤷‍♂️ - if anyone has ideas let me know I’m curious 🙂

---

<div class="post-metadata">

**Author:** ![rogerdpack](https://yyz2.discourse-cdn.com/flex036/user_avatar/forum.crystal-lang.org/rogerdpack/32/117_2.png) [@rogerdpack](https://forum.crystal-lang.org/u/rogerdpack)\
**Post date:** [June 7, 2021, 9:47pm UTC](https://forum.crystal-lang.org/t/io-seems-to-be-slower-with-release-flag/2991/14 "2021-06-07T21:47:19Z")

</div>

Exceptions are slower in release? Any micro benchmarks to prove it? You could optionally profile it to try and find out [Performance - Crystal](https://crystal-lang.org/reference/guides/performance.html)

---

<div class="post-metadata">

**Author:** ![gdotdesign](https://yyz2.discourse-cdn.com/flex036/user_avatar/forum.crystal-lang.org/gdotdesign/32/35_2.png) [@gdotdesign](https://forum.crystal-lang.org/u/gdotdesign)\
**Post date:** [June 8, 2021, 8:09am UTC](https://forum.crystal-lang.org/t/io-seems-to-be-slower-with-release-flag/2991/15 "2021-06-08T08:09:38Z")

</div>

Given this code:

```auto
require "benchmark"

class SomeError < Exception
end

1000000.times do
  begin
    raise SomeError.new
  rescue
  end
end

```

Running it in different scenarios:

```auto
❯ crystal build benchmark.cr
❯ time ./benchmark           
./benchmark 4,00s user 0,04s system 111% cpu 3,636 total

❯ crystal build benchmark.cr --release
❯ time ./benchmark                    
./benchmark 3,02s user 0,10s system 111% cpu 2,793 total

❯ crystal build benchmark.cr --release --no-debug
❯ time ./benchmark                               
./benchmark 2,73s user 0,06s system 113% cpu 2,460 total

```

So it doesn’t seems to be the case that exceptions slow it down, maybe it’s a combination of exceptions and overloaded functions bur unfortunately I don’t have more time to investigate it.

If anyone wants to dig deeper into this, this is the PR that was lead to the improvement in parsing times:

> <https://github.com/mint-lang/mint/pull/435/files>
>
> This optimization speeds up parsing of https://github.com/mint-lang/mint-ui-webs…ite (27K LOC) from \`9.157s\` down to \`1.094s\` :rocket: that's 9 times faster :metal: