Re: Query is over 2x slower with jit=on

> On Aug 22, 2018, at 7:13 PM, Andres Freund <andres(at)anarazel(dot)de> wrote:
>
> On 2018-08-22 18:29:58 -0400, Jonathan S. Katz wrote:
>>
>>> On Aug 22, 2018, at 2:58 PM, Andreas Joseph Krogh <andreas(at)visena(dot)com> wrote:
>>>
>>> På onsdag 22. august 2018 kl. 20:52:05, skrev Andres Freund <andres(at)anarazel(dot)de <mailto:andres(at)anarazel(dot)de>>:
>>> On 2018-08-22 19:51:12 +0200, Andreas Joseph Krogh wrote:
>>>> I thought JITing of prepared queries happended once (in "prepare")
>>>
>>> No, it happens when the first JITed function is executed.
>>>
>>>
>>>> so it didn't have to do the JITing every time the query is
>>>> executed. Isn't the previously generated bytecode usable for
>>>> subsequent queries?
>>>
>>> No, not currently. There's some reasons preventing that (primarily that
>>> we currently rely on addresses of certain things not to change during
>>> execution). There's ongoing work to change that, but that's certainly
>>> not going to be ready for v11.
>>>
>>> Greetings,
>>>
>>> Andres Freund
>>>
>>>
>>> Ok, thanks for clarifying.
>>
>> Per earlier note[1] I was able to reproduce this issue with similar results to
>> Andreas while running 11 Beta 3.
>>
>> jit = on
>> https://explain.depesz.com/s/vgzD <https://explain.depesz.com/s/vgzD>
>>
>> Planning Time: 0.921 ms
>> JIT:
>> Functions: 193
>> Generation Time: 121.595 ms
>> Inlining: false
>> Inlining Time: 0.000 ms
>> Optimization: false
>> Optimization Time: 58.045 ms
>> Emission Time: 1201.100 ms
>> Execution Time: 1628.017 ms
>>
>> jit = off
>> https://explain.depesz.com/s/AvZM <https://explain.depesz.com/s/AvZM>
>>
>> Planning Time: 1.398 ms
>> Execution Time: 256.473 ms
>>
>> I increased the the search range I used in the query by 3x, and got these numbers:
>>
>> jit=on
>> Planning Time: 0.931 ms
>> JIT:
>> Functions: 184
>> Generation Time: 126.587 ms
>> Inlining: true
>> Inlining Time: 98.865 ms
>> Optimization: true
>> Optimization Time: 20518.982 ms
>> Emission Time: 7270.963 ms
>> Execution Time: 28772.576 ms
>>
>> jit=off
>> Planning Time: 1.527 ms
>> Execution Time: 959.160 ms
>
> For the archives sake: This likely largely is the consequence of
> building with LLVM's expensive assertions enabled, as confirmed by
> Jonathan over IM.

I recompiled with the release version of LLVM. jit=on was still slower,
but the discrepancy was not as bad as the previously reported result:

jit = off
Planning Time: 0.938 ms
Execution Time: 935.599 ms

jit = on
Planning Time: 0.951 ms
JIT:
Functions: 184
Generation Time: 17.605 ms
Inlining: true
Inlining Time: 20.522 ms
Optimization: true
Optimization Time: 1001.034 ms
Emission Time: 665.319 ms
Execution Time: 2491.560 ms

However, it was still 2x+ slower, so still +1ing for open items.

Jonathan