buildSwiftOnARM icon indicating copy to clipboard operation
buildSwiftOnARM copied to clipboard

Slow initialization of String objects from Collection/Sequence

Open ScriptBasic opened this issue 5 years ago • 5 comments

It seems Swift for the RPi has performance issues. The following program is a good example.

// Swift 5.1.2 - 1mil3.swift

var s = ""
var t = ""
var a = [Int]()

for x in 1...1000000 {
  s += String(UnicodeScalar(UInt8(((x - 1) % 26) + 65)))
  a.append(x)
  if s.count == 26 {
    t += s
    s = ""
  }
}

let r = String(t.reversed())

print("r LEN: ", r.count)
print("Front: \(r.prefix(26))")
print("Back:  \(r.suffix(26))")
print("UBVal: ", a[100000 - 1])

RPI 4B 4GB

$ /usr/bin/time ./main
r LEN:  999986
Front: ZYXWVUTSRQPONMLKJIHGFEDCBA
Back:  ZYXWVUTSRQPONMLKJIHGFEDCBA
UBVal:  100000
322.51user 0.07system 5:22.70elapsed 99%CPU (0avgtext+0avgdata 13836maxresident)k
0inputs+0outputs (0major+3470minor)pagefaults 0swaps

(Without String reverse)

$ /usr/bin/time ./main
r LEN:  999986
Front: ABCDEFGHIJKLMNOPQRSTUVWXYZ
Back:  ABCDEFGHIJKLMNOPQRSTUVWXYZ
UBVal:  100000
36.12user 0.04system 0:36.17elapsed 99%CPU (0avgtext+0avgdata 12800maxresident)k
0inputs+0outputs (0major+2925minor)pagefaults 0swaps

Ubuntu Lenovo Laptop

$ /usr/bin/time ./main
r LEN:  999986
Front: ZYXWVUTSRQPONMLKJIHGFEDCBA
Back:  ZYXWVUTSRQPONMLKJIHGFEDCBA
UBVal:  100000
0.45user 0.01system 0:00.47elapsed 99%CPU (0avgtext+0avgdata 20132maxresident)k
0inputs+8outputs (0major+5273minor)pagefaults 0swaps

Swift 4.1.5 Windows Lenovo Laptop

PS C:\Swift\examples> Measure-Command {.\main.exe | Out-Default}
r LEN:  999986
Front: ZYXWVUTSRQPONMLKJIHGFEDCBA
Back:  ZYXWVUTSRQPONMLKJIHGFEDCBA
UBVal:  100000

Days              : 0
Hours             : 0
Minutes           : 0
Seconds           : 1
Milliseconds      : 305
Ticks             : 13053398
TotalDays         : 1.5108099537037E-05
TotalHours        : 0.000362594388888889
TotalMinutes      : 0.0217556633333333
TotalSeconds      : 1.3053398
TotalMilliseconds : 1305.3398

The Swift Online Playground also returns a result almost instantly.

Something is horribly wrong IMHO.

ScriptBasic avatar Dec 03 '19 20:12 ScriptBasic

Yes, that let r = String(t.reversed()) in particular is extremely slow. That reversed() is the generic reversal defined on Collections here, and appears to be executed lazily (has an internal _base String that points to the original t, but the actual reversal is an O(n) swap). But what adds 5 minutes or so of execution time is the String(Collection) initializer , as we can see running this modified sample using an Array:

var s = ""
var t = ""
var a =  [Int]()

for x in 1...1000000 {
  s += String(UnicodeScalar(UInt8(((x - 1) % 26) + 65)))
  if s.count == 26 {
    t += s
    s = ""
  }
}

var r = Array(t)
let count = t.count
for i in 0..<count/2 {
  r.swapAt(i, count - ((i + 1) as Int))
}

let str=String(r) // <-------- +5:00

It should be an O(n) operation with some additional conversions performed on all 32-bit platforms, but clearly there is something more going on.

Corner case as it may be, I'd open a ticket on https://bugs.swift.org/.

uraimo avatar Dec 04 '19 10:12 uraimo

I was able to get it down to 23 seconds.


// Swift 5.1.2 - 1mil3-3.swift

var s = ""
var t = ""
var a = [Int](repeating: 0, count: 1000001)

for x in 1...1000000 {
  let c = (x - 1) % 26
  s.append(String(UnicodeScalar(UInt8(c + 65))))
  a[x] = x
  if c == 25 {
    t.append(String(s.reversed()))
    s = ""
  }
}

print("t LEN: ", t.count)
print("Front: \(t.prefix(26))")
print("Back:  \(t.suffix(26))")
print("UBVal: ", a[100000])

pi@RPi4B:$ swiftc -O 1mil3-3.swift pi@RPi4B:$ ls -l main -rwxr-xr-x 1 pi pi 29316 Dec 9 22:37 main pi@RPi4B:$ timex ./main t LEN: 999986 Front: ZYXWVUTSRQPONMLKJIHGFEDCBA Back: ZYXWVUTSRQPONMLKJIHGFEDCBA UBVal: 100000 23.26user 0.03system 0:23.31elapsed 99%CPU (0avgtext+0avgdata 12012maxresident)k 0inputs+0outputs (0major+1890minor)pagefaults 0swaps pi@RPi4B:$ ]

ScriptBasic avatar Dec 10 '19 07:12 ScriptBasic

Hmm, the resulting string should be the same, but you are now creating 25 chars strings instead of using the 1million characters string you had before. The main issue here is that the performance of the initializer does not seem to decrease linearly as the string grows, it’s worse than that.

uraimo avatar Dec 10 '19 07:12 uraimo

I installed Ubuntu 19.10 64 bit server on the RPi 4B 4GB and Swift now runs as I would have expected and more inline with what I'm seeing on my Lenovo laptop.

ubuntu@rpi4b:$ swiftc -O 1mil4.swift ubuntu@rpi4b:$ ls -l main -rwxr-xr-x 1 ubuntu ubuntu 74600 Dec 15 19:13 main ubuntu@rpi4b:$ timex ./main t LEN: 999986 Front: ZYXWVUTSRQPONMLKJIHGFEDCBA Back: ZYXWVUTSRQPONMLKJIHGFEDCBA UBVal: 1000000 0.65user 0.02system 0:00.69elapsed 98%CPU (0avgtext+0avgdata 16392maxresident)k 0inputs+0outputs (0major+2811minor)pagefaults 0swaps ubuntu@rpi4b:$

ScriptBasic avatar Dec 22 '19 21:12 ScriptBasic

Hi, I know this issue already has a few months, but I wanted to share my experience too:

Raspberry Pi 4, Swift 5.1, Raspbian (armv7l): I can also say string manipulation, specially lowercased() and uppercased() functions are really expensive, but I guess this is because of the string initialization issue you mentioned before. In a library I was using a case insensitive search by advancing scalar by scalar and comparing their lowercased versions: on MacOS, this was almost immediate, on Linux it took literally minutes and the CPU was fixed at 100% usage.

Could this be related to the libicu dependency in any way?

jmartinesp avatar Feb 29 '20 06:02 jmartinesp