Bug 129256 - ReDim is slow when array custom type is explicitly known
Summary: ReDim is slow when array custom type is explicitly known
Status: VERIFIED FIXED
Alias: None
Product: LibreOffice
Classification: Unclassified
Component: BASIC (show other bugs)
Version:
(earliest affected)
unspecified
Hardware: All All
: medium normal
Assignee: Not Assigned
URL:
Whiteboard: target:6.5.0 target:6.4.1
Keywords: perf
Depends on:
Blocks:
 
Reported: 2019-12-07 08:23 UTC by Mike Kaganski
Modified: 2020-01-09 09:10 UTC (History)
4 users (show)

See Also:
Crash report or crash signature:


Attachments
perf flamegraph (96.05 KB, application/x-bzip)
2019-12-07 13:46 UTC, Julien Nabet
Details
perf flamegraph for ReDimTest1 (77.26 KB, application/x-bzip)
2019-12-07 14:10 UTC, Julien Nabet
Details
perf flamegraph for ReDimTest2 (87.93 KB, application/x-bzip)
2019-12-07 14:12 UTC, Julien Nabet
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Mike Kaganski 2019-12-07 08:23:54 UTC
With this code:

> Type TCustomType
>   m_arr(20) As Long
>   m_str As String
> End Type
> 
> Sub CustomReDim1(ByRef A() As TCustomType, newU As Long)
>   ReDim Preserve A(newU)
> End Sub
> 
> Sub CustomReDim2(ByRef A(), newU As Long)
>   Dim oldU As Long, emptyVal As TCustomType, i As Long
>   oldU = UBound(A)
>   ReDim Preserve A(newU)
>   For i = oldU + 1 To newU
>     A(i) = emptyVal
>   Next i
> End Sub
> 
> Sub ReDimTest
>   Dim A1(0) As TCustomType, A2(0) As TCustomType, A3(0) As TCustomType, time1 As Date, i As Long, msg As String
>   time1 = Now()
>   Const maxIter = 2000
>   For i = 1 To maxIter
>     ReDim Preserve A1(i)
>   Next i
>   msg = "Testing ReDim Preserve: " & Format(now() - time1, "[s]"" s""") & Chr(13)
>   time1 = Now()
>   For i = 1 To maxIter
>     CustomReDim1(A2, i)
>   Next i
>   msg = msg & "Testing CustomReDim1: " & Format(now() - time1, "[s]"" s""") & Chr(13)
>   time1 = Now()
>   For i = 1 To maxIter
>     CustomReDim2(A3, i)
>   Next i
>   MsgBox msg & "Testing CustomReDim2: " & Format(now() - time1, "[s]"" s""")
> End Sub

I get this on current master Version: 6.5.0.0.alpha0+ (x64)
Build ID: 08615ce879927bc58924e9591985f27fe59a11fa
CPU threads: 12; OS: Windows 10.0 Build 18363; UI render: Skia/Raster; VCL: win; 
Locale: ru-RU (ru_RU); UI-Language: en-US
Calc: CL

44 s
44 s
5 s

See how much faster the result is when ReDim gets an array without the element type known in the function, and then assigning an empty value as it would happen when the type is known.

Of course, that is debug version, and thus slow, but it shows how inefficient the ReDim is for custom types, and in the same time, it can be much more efficient if ReDim doesn't know the custom type - still providing the same end result.

The code is affected by tdf#129227, so it would result in even greater difference in releases 5.3 to 6.3.3, so better test in master with the mentioned bug fixed. Note that the problem discussed in this issue was present in to v.5.2 and older.
Comment 1 Julien Nabet 2019-12-07 09:27:40 UTC
Would you like a Flamegraph or have you already pinpointed the root cause?
Comment 2 Mike Kaganski 2019-12-07 09:28:38 UTC
(In reply to Julien Nabet from comment #1)

A flamegraph would be very useful - thank you Julien!
Comment 3 Oliver Brinzing 2019-12-07 09:41:23 UTC
confirming with debug build:

Version: 6.5.0.0.alpha0+ (x64)
Build ID: 766ce853d18da813e8d435776f462470cd072538
CPU threads: 12; OS: Windows 10.0 Build 18363; UI render: GL; VCL: win; 
Locale: de-DE (de_DE); UI-Language: en-US
Calc: CL

Testing ReDim Preserve: 21 s
Testing CustomReDim1: 21 s
Testing CustomReDim2: 4 s
Comment 4 Julien Nabet 2019-12-07 11:53:31 UTC
Argh, it gives me:
"ERROR: No stack counts found" :-(
I'm gonna make the build from scratch
Comment 5 Julien Nabet 2019-12-07 13:46:06 UTC
Created attachment 156388 [details]
perf flamegraph

At least the Flamegraph :-)
Comment 6 Mike Kaganski 2019-12-07 13:48:22 UTC
(In reply to Julien Nabet from comment #5)

Thanks! Is that a flamegraph for CustomReDim1? Could you please also add another flamegraph for CustomReDim2, for comparison?
Comment 7 Julien Nabet 2019-12-07 13:52:54 UTC
It was for the whole test, I launched "ReDimTest"
If you think about specific tests, just tell me!
Comment 8 Mike Kaganski 2019-12-07 13:59:27 UTC
(In reply to Julien Nabet from comment #7)

Oh sorry! The ReDimTest is 3 tests. Could you please create two graphs separately for ReDimTest1 and ReDimTest2 in

> Type TCustomType
>   m_arr(20) As Long
>   m_str As String
> End Type
> 
> Sub CustomReDim1(ByRef A() As TCustomType, newU As Long)
>   ReDim Preserve A(newU)
> End Sub
> 
> Sub CustomReDim2(ByRef A(), newU As Long)
>   Dim oldU As Long, emptyVal As TCustomType, i As Long
>   oldU = UBound(A)
>   ReDim Preserve A(newU)
>   For i = oldU + 1 To newU
>     A(i) = emptyVal
>   Next i
> End Sub
> 
> Sub ReDimTest1
>   Dim A(0) As TCustomType, i As Long
>   Const maxIter = 2000
>   For i = 1 To maxIter
>     CustomReDim1(A, i)
>   Next i
> End Sub
> 
> Sub ReDimTest2
>   Dim A(0) As TCustomType, i As Long
>   Const maxIter = 2000
>   For i = 1 To maxIter
>     CustomReDim2(A, i)
>   Next i
> End Sub

Thank you!
Comment 9 Julien Nabet 2019-12-07 14:10:07 UTC
Created attachment 156389 [details]
perf flamegraph for ReDimTest1
Comment 10 Julien Nabet 2019-12-07 14:12:39 UTC
Created attachment 156390 [details]
perf flamegraph for ReDimTest2
Comment 11 Julien Nabet 2019-12-07 14:16:42 UTC
(note to myself: to avoid "No stack counts found", it seems perf record must be launched as soon as LO module is opened, not at the last moment)
Comment 12 Mike Kaganski 2019-12-07 15:05:17 UTC
Thanks a lot Julien!

So SbiRuntime::Step seems to spend much time in StepDCREATE_IMPL in case of ReDimTest1, and not so much time in StepREDIMP in case of ReDimTest2.
Comment 13 Julien Nabet 2019-12-07 15:10:06 UTC
(In reply to Mike Kaganski from comment #12)
> Thanks a lot Julien!
> 
> So SbiRuntime::Step seems to spend much time in StepDCREATE_IMPL in case of
> ReDimTest1, and not so much time in StepREDIMP in case of ReDimTest2.

No pb! if you think about another test, don't hesitate! :-)
Comment 14 Mike Kaganski 2019-12-08 11:08:08 UTC
Thanks Julien!
Comment 15 Commit Notification 2019-12-08 11:08:41 UTC
Mike Kaganski committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/bc1a8c682f889e488a7961faa0708568c480438a

tdf#129256: don't create objects only to destroy when moving preserved array

It will be available in 6.5.0.

The patch should be included in the daily builds available at
https://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
https://wiki.documentfoundation.org/Testing_Daily_Builds

Affected users are encouraged to test the fix and report feedback.
Comment 16 Xisco Faulí 2019-12-09 12:15:11 UTC
I get 

Testing ReDim Preserve: 1 s
Testing CustomReDim1: 0 s
Testing CustomReDim2: 1 s

in

Version: 6.5.0.0.alpha0+
Build ID: 46a07f2042a812fc552e26736183c7d06fe6aa35
CPU threads: 4; OS: Linux 4.15; UI render: default; VCL: gtk3; 
Locale: ca-ES (ca_ES.UTF-8); UI-Language: en-US
Calc: threaded

nice improvement. @Mike, thanks for fixing it!
Comment 17 Commit Notification 2020-01-09 09:10:30 UTC
Mike Kaganski committed a patch related to this issue.
It has been pushed to "libreoffice-6-4":

https://git.libreoffice.org/core/commit/f396be106a0886ba635b449c44627fb800a3bc25

tdf#129256: don't create objects only to destroy when moving preserved array

It will be available in 6.4.1.

The patch should be included in the daily builds available at
https://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
https://wiki.documentfoundation.org/Testing_Daily_Builds

Affected users are encouraged to test the fix and report feedback.