grain icon indicating copy to clipboard operation
grain copied to clipboard

Tail-call-optimization broken in current builds 0.6+

Open mortax opened this issue 2 years ago • 6 comments

I have small recursive program. When compiled with Grain 0.5.13, using --experimental-wasm-tail-call my suite took a little over one minute to run.

I was excited for some of the improvements coming in 0.6. I started doing nightly builds on my own. When f6e5b00 was committed (11 March), I removed the --experimental-wasm-tail-call compiler option.

A little over a month later, things started to run slowly. Running my suite ballooned from one minute to over an hour (before I stopped them). After some frustration, I was able to get the performance back by pinning the source to 8ccea28 (from 19 April). That stopped working at some point and I switched to the Preview release -- but performance was terrible again. (I have since reverted back to 0.5.13).

TL;DR: Is it known that TCO isn't working in 0.6 and will/can it be fixed?

mortax avatar Nov 04 '23 19:11 mortax

Hey @mortax. Can you post the program and let us know how you're running it?

ospencer avatar Nov 14 '23 23:11 ospencer

i can't post the program as is but i'll try to create an example as a replacement this weekend.

mortax avatar Nov 14 '23 23:11 mortax

Thank you, it's much appreciated.

ospencer avatar Nov 14 '23 23:11 ospencer

If I remember correctly, v0.5 leaked memory for tail calls. The next version properly cleans them up (after #1927) but that's obviously going to take longer then when we were leaking memory. I'm going to close this out.

phated avatar Jan 29 '24 15:01 phated

Actually, I read the original issue wrong. Let's leave it open for now

phated avatar Jan 29 '24 15:01 phated

This may be fixed by #1993. There was a bug that under certain circumstances could lead to memory corruption which in turn might make the program hang.

@mortax Once that's merged (in about ~1 hour) could you rebuild from main and see if the issue goes away?

ospencer avatar Jan 29 '24 15:01 ospencer

I'm going to close for now. I believe this should no longer be an issue, but feel free to reopen if you encounter this again.

ospencer avatar Apr 05 '24 20:04 ospencer

@ospencer (or @phated) i do have have an option to reopen this issue. do you?

this is still happening. my tests no longer complete:

before:

== 03-29-12-58-10/results.txt ==

gr: 64 tests passed 01:01.945 [real 45.96 user 45.91 sys 0.00]

{[ Total elapsed run-time was 36:56 ]}

now:

== 04-18-21-55-25/results.txt ==

gr: 2/64 tests failed, 2 timed out 1:04:22.425 [real 2043.00 user 2035.35 sys 0.00]

{[ Total elapsed run-time was 1:43:00 ]}

note: it used to run my full test suite as quickly at 29 seconds:

times/2023/02-13-12-07-29/results.txt:gr: 63 tests passed 01:36.333 [real 0.23 user 57.26 sys 0.00]
times/2023/02-15-11-55-37/results.txt:gr: 63 tests passed 01:36.517 [real 72.10 user 64.25 sys 0.00]
times/2023/02-15-19-22-12/results.txt:gr: 63 tests passed 01:36.759 [real 70.55 user 63.46 sys 0.00]
times/2023/02-22-21-33-27/results.txt:gr: 63 tests passed 01:36.398 [real 72.23 user 50.96 sys 0.00]
times/2023/02-23-21-54-24/results.txt:gr: 63 tests passed 01:53.375 [real 80.97 user 69.82 sys 0.00]
times/2023/02-24-17-03-31/results.txt:gr: 63 tests passed 01:41.393 [real 0.12 user 6.16 sys 0.00]
times/2023/03-03-08-45-13/results.txt:gr: 63 tests passed 01:31.901 [real 5.85 user 58.27 sys 13.05]
times/2023/04-12-21-31-16/results.txt:gr: 63 tests passed 01:36.829 [real 72.79 user 65.42 sys 0.00]
times/2023/04-22-17-13-33/results.txt:gr: 63 tests passed 00:43.123 [real 0.29 user 0.00 sys 0.80]
times/2023/04-23-12-29-14/results.txt:gr: 63 tests passed 00:43.664 [real 35.69 user 23.41 sys 0.00]
times/2023/04-23-22-15-01/results.txt:gr: 63 tests passed 00:42.061 [real 33.17 user 22.22 sys 0.00]
times/2023/05-09-22-08-21/results.txt:gr: 63 tests passed 00:43.762 [real 33.39 user 0.00 sys 12.99]
times/2023/05-26-22-13-16/results.txt:gr: 63 tests passed 00:43.412 [real 5.41 user 3.62 sys 0.01]
times/2023/06-02-17-20-27/results.txt:gr: 63 tests passed 00:43.060 [real 0.82 user 0.08 sys 0.02]
times/2023/06-17-21-10-21/results.txt:gr: 63 tests passed 00:22.570 [real 1.05 user 9.66 sys 0.00]
times/2023/06-23-21-59-00/results.txt:gr: 63 tests passed 00:20.629 [real 0.93 user 8.80 sys 3.64]
times/2023/06-24-09-21-10/results.txt:gr: 63 tests passed 00:29.204 [real 17.32 user 0.00 sys 0.82]

is there a non-public way i can share my source-code? i'd do not want to have it publicly available but i definitely want to allow you all to use it to find the issue.

mortax avatar Jun 03 '24 05:06 mortax

@mortax You can send it to me on Discord and I can take a look that way.

ospencer avatar Jun 03 '24 15:06 ospencer