Strange bottleneck in Utf8.charCodeAt discovered with HxScout

[Lars Doucet]

So I've been using hxScout to profile some things in OpenFL, since I had noticed that text field rendering was rather slow when using -Dnext.

Maybe I'm totally confused about how I'm supposed to be using Utf8 and stuff, but here are my observations nonetheless.

First, I found my bottleneck.

Turns out nearly ALL of the time was spent in this function in OpenFL's CairoTextField.hx:

 private static function getLineBreaks (textField:TextField):Int {
 
     //returns the number of line breaks in the text
 
     var lines = 0;
 
     for (i in 0...Utf8.length (textField.text)) {
 
         var char = Utf8.charCodeAt(textField.text, i);
 
         if (char == __utf8_endline_code) {
 
             lines++;
 
         }
 
     }
 
     return lines;
 
 }

Specifically on this single line:

var char = Utf8.charCodeAt(textField.text, i);

According to hxScout ~90% of the entire text field rendering slowdown was coming from this line, almost all of it the result of GC's. The first thing I did was move the var declaration outside of the loop, and that seemed to help a little, but not much. Next I drilled down to see what Utf8.charCodeAt was doing, turns out it resolves to this function in String.cpp in hxcpp:

Dynamic String::charCodeAt(int inPos) const
{
   if (inPos<0 || inPos>=length)
      return null();


   #ifdef HX_UTF8_STRINGS
   // really "byte code at" ...
   //const unsigned char *p = (const unsigned char *)(__s + inPos);
   //return DecodeAdvanceUTF8(p);
   return (int)( ((unsigned char *)__s) [inPos]);
   #else
   return (int)(__s[inPos]);
   #endif
}

This was interesting, so I did some experiments. I put a printf in both of the #ifdef blocks to see which result was being called. printf("utf8 block!\n") in the #if and printf("not utf8 block!\n") in the other.

When I used this:

char = Utf8.charCodeAt(textField.text, i);

It would print "utf8 block!". 

When I used this:

char = textField.charCodeAt(i);

It would print "utf8 block!".

So regardless of whether I use the Utf8 class or not, it resolved to the same line of C++ code. Which makes sense when you look at the C++ code -- it's an #ifdef driving which block it chooses, which is declared at compile time and never changes, right? So either you're using HX_UTF8_STRINGS or you aren't, and it no longer matters whether you invoke charCodeAt() with Utf8. or not. So that's one thing.

But get this!

Regular (non-Utf8. prefixed) textField.charCodeAt(i) is waaaaaay faster! When I switched to that my results were the same but there were no longer any GC's happening, and suddenly text rendering became lots faster.

So my observations:

• someString.charCodeAt(index) is apparently equivalent to Utf8.charCodeAt(someString,index), when the API makes me expect them to be different.
• the (uncommented) code in the UTF8 block doesn't seem to actually be UTF8-aware...
• Utf8.charCodeAt() generates lots of garbage but regular charCodeAt() doesn't, even though they resolve to doing the exact same thing

So if someone could explain what's going on here that'd be swell :)

[Juraj Kirchheim]

What Utf8.charCodeAt does, is to ensure that on platforms with ASCII encoding, you get the nth UNICODE character from an utf8 string. When you compile in such a manner that you have unicode strings (which are usually far more sophisticated than doing all the work on utf8 encoded strings), then haxe.Utf8 just falls through to the native string implementation.

The non-native Utf8.charCodeAt implementation has O(N) average cost (N being the Utf8.length(string)) because of how utf8 encoding works, so looping through a string as shown there has O(N * N) cost. What you should do instead is to use Utf8.iter, as that brings the cost back down to O(N).

Best,

Juraj

--
To post to this group haxe...@googlegroups.com
http://groups.google.com/group/haxelang?hl=en
---
You received this message because you are subscribed to the Google Groups "Haxe" group.
For more options, visit https://groups.google.com/d/optout.

[Robert Konrad]

You're looking at the wrong Utf8.charCodeAt, the one that's actually called in C++ is here: https://github.com/HaxeFoundation/haxe/blob/development/std/cpp/_std/haxe/Utf8.hx

Generally, using utf8 encoded strings like that would be pretty slow in any language, because getting a char at a specific position is an O(n) operation (as is getting the length). Use Utf8.iter instead where possible.

[Lars Doucet]

Okay, that explains some things, but what I really want to know is where is this GC overhead coming from? It falls through to the exact same line of code in my environment, but with the Utf8. invocation GC magically appears.

[Lars Doucet]

Thanks, that's helpful.

Now, if I'm looking at the wrong Utf8.charCodeAt, then why are the printf's activating? Shouldn't this not activate at all if the Utf8.hx code you linked is happening?

[Lars Doucet]

Well, regardless of what's happening, I think this pefectly explains the GC activity:

 public static function charCodeAt( s : String, index : Int ) : Int {
      var array:Array<Int> = untyped __global__.__hxcpp_utf8_string_to_char_array(s);
 return array[index];
 }

It creates an array every time and then returns one value from it, so if this is really being called then that's the culprit. Iterator it is.

[Nicolas Cannasse]

Le 24/07/2015 17:31, Lars Doucet a écrit :
> So I've been using hxScout to profile some things in OpenFL, since I had
> noticed that text field rendering was rather slow when using -Dnext.
> Maybe I'm totally confused about how I'm supposed to be using Utf8 and
> stuff, but here are my observations nonetheless.
>
> First, I found my bottleneck.
>
> Turns out nearly ALL of the time was spent in this function in OpenFL's
> CairoTextField.hx:
>
> |

> privatestaticfunctiongetLineBreaks (textField:TextField):Int{

>
> //returns the number of line breaks in the text
>
> varlines =0;
>
> for(i in0...Utf8.length (textField.text)){
>
> varchar=Utf8.charCodeAt(textField.text,i);

This is a very bad way to iterate on UTF8 chars. Given the character has
various size, you have to start again from the start of the string for
each char, so it takes O(n2) time.

Best,
Nicolas

[Nicolas Cannasse]

Le 24/07/2015 18:07, Lars Doucet a écrit :
> Well, regardless of what's happening, I think this pefectly explains the
> GC activity:
>
> |
> publicstaticfunctioncharCodeAt(s :String,index :Int):Int{
> vararray:Array<Int>=untyped __global__.__hxcpp_utf8_string_to_char_array(s);
> returnarray[index];
> }

Ouch !
Open an issue for it, that should definitely be patched.

Best,
Nicolas

[Lars Doucet]

Cool, I issued a PR to openfl that seems to solve our immediate issues by using the proper Utf8.iter() solution:

https://github.com/openfl/openfl/commit/66348a7adb3253afab6a74460ae808ad22c64e6a

And I'll open an issue about the charCodeAt() function. I assume it shouldn't allocate and then immediately throw away that array?

[Lars Doucet]

Done:

https://github.com/HaxeFoundation/haxe/issues/4440

Did I do it right?

[Hugh]

Removing the allocation is not going to hide the fact that you SHOULD NOT CALL THIS FUNCTION!

Really, just remove the function and the problems is solved, otherwise you are still O(N2)

Hugh