font rendering performances

pepe · January 12, 2006, 10:13am

hello.
I know it’s retatively far from direct gaming, but i have a question about font rendering efficiency and i know that the right people are around.
I’m generating fonts into bitmaps, both using shapes and drawString(). At some sizes, the rendering suddenly gets from 6ms to 60ms and then increases lightly with size change…
Something like when going from pica 1-101 it takes from 1 to 7ms, and from 102 pica, suddenly jumps to 80ms and goes around 90ms at 250 pica. The peak changes based on the string length, but i could not relate it to bufferedimage surface (which is bounded to string in my case)

That peak is a huge problem to me. Has anyone got an idea on what’s the cause?

oNyx · January 12, 2006, 11:17am

Texture size maybe?

pepe · January 12, 2006, 2:24pm

t hought about that and made some tests, some time ago.
I must have screwed something when i did because i did the tests again and found a direct relation between the peak and a certain value…
When the bufferedimage is over 512KB (130Kpixels) BANG !! the drawing/alocation/don’t know what exactly takes 70ms more …
I’d love to have any information on why because 70ms is an eternity to me and i absolutly need to draw texts in less than 20ms…(pal 50hz…)

oNyx · January 12, 2006, 2:48pm

Uhm… yea. Try to stay within 2^16 pixels (256x256). Anything bigger is unlikely to get acceleration.

So, you would need 2 or 3 BIs then. A bit fiddly, but certainly faster.

pepe · January 12, 2006, 5:19pm

‘funnier’ is that i’m not even in part where acceleration ought to play any role.
I just render fonts in a bufferedImage and to my knowledge, this is not accelerated by graphic cards.
The blitting of that bufferedImage to somewhere else isn’t even the problem.

oNyx · January 12, 2006, 9:40pm

scratches head

Thought you would render to some texture and then using that texture for blitting onto the screen… oops.

Hmm… weird. Maybe the glyph representation gets more complex at that size?

swpalmer · January 12, 2006, 11:25pm

Maybe the Font class caches bitmaps for the glyphs at smaller point sizes?

trembovetski · January 12, 2006, 11:27pm

Pepe, could you post your benchmark? I’ll ask our font person to take a look.
(or send it to me: tdv at sun dot com)

Thanks,
Dmitri

pepe · January 13, 2006, 1:46pm

You can get a jar here:
http://frederic.barachant.com/sunTest/FontPerf.jar
The sources are included in the jar.

By the way, the test revealed that i’ts not the drawing of the font that is culprit, but allocation of the BufferedImage, as you will see with the example.

But, but… don’t release the font guy. I have a bounds calculation error that arises on some fonts. (the fonts are cut at the end…) who should i contact for this?

trembovetski · January 13, 2006, 11:07pm

[quote]You can get a jar here:
http://frederic.barachant.com/sunTest/FontPerf.jar
The sources are included in the jar.

By the way, the test revealed that i’ts not the drawing of the font that is culprit, but allocation of the BufferedImage, as you will see with the example.
[/quote]
Have you tried running with -verbose:gc? When the image gest sufficiently large (and you
create a BufferedImage on every render() call) a gc happens every time. Hopefully you
wan’t be creating a BI on very frame in the final version.

Also, I’d suggest to time rendering in a loop instead of just timing one single operation - you’ll
get more precise results.

I’d suggest looking at the J2DBench benchmark in j2se/src/share/demo/java2d/J2DBench in the mustang
j2se workspace for the ways of proper benchmarking.

Well, post the test case and he’ll take a look…
Or is it the same test? Then which font, what font size?

Thanks,
Dmitri

pepe · January 14, 2006, 5:07pm

Doh!!
Yes, of course… How could i not think about it [edit]( about GC, not about not using the same buffer each time)…
But… that’s around 100 times slower than an average GC… How comes that can happen with such a small example…
Anyway, after some tests, that ‘hickup’ disappears when using incremental garbage collector…

True, but… that was not the point. the numbers were big enough to sense the difference.

You can use the same example and change the font to use “time new roman italic” that comes with windows. Try a text with a’V’, a’X’ or a ‘Y’ at the end.

I’ve been also trying to reproduce a jvm crash (yep…) when trying to generate a 0 sized arial text… (Please, no comment on the stupidity of that operation…) but could not reproduce… Still, i have a HS crash file at work that i got when this bug appeared. I’ll post it on monday, or make a bug report through normal ways, or… whatever you suggest.

trembovetski · January 14, 2006, 8:06pm

Yeah, please post the test for the crash here, I’ll file a bug - we’ll get to it faster that
way.

Thanks!

Dmitri

pepe · January 16, 2006, 10:07am

Here is the crash log. If you can’t get enough information from it, please tell me, i’ll compile an example for you. (i’ve removed the names of my classes, for some reasons linked to my job…)

#
# An unexpected error has been detected by HotSpot Virtual Machine:
#
#  EXCEPTION_FLT_DIVIDE_BY_ZERO (0xc000008e) at pc=0x01798292, pid=2268, tid=1640
#
# Java VM: Java HotSpot(TM) Client VM (1.5.0_05-b05 mixed mode)
# Problematic frame:
# j  java.lang.StrictMath.log(D)D+0
#

---------------  T H R E A D  ---------------

Current thread (0x0036b888):  JavaThread "main" [_thread_in_native, id=1640]

siginfo: ExceptionCode=0xc000008e, ExceptionInformation=0x00000000 

Registers:
EAX=0x00000000, EBX=0x077f44d0, ECX=0x00000000, EDX=0x07908fc0
ESP=0x0012f0b4, EBP=0x0012f0d8, ESI=0x077f44d0, EDI=0x0036b888
EIP=0x01798292, EFLAGS=0x00210206

Top of Stack: (sp=0x0012f0b4)
0x0012f0b4:   00000000 00000000 0012f0bc 00000000
0x0012f0c4:   0012f0ec 07908fc0 00000000 077f44d0
0x0012f0d4:   0012f0e8 0012f10c 0179294e 077f5750
0x0012f0e4:   0179644a 00000000 00000000 0012f0f0
0x0012f0f4:   078be081 0012f118 078bf338 00000000
0x0012f104:   078be088 0012f114 0012f138 0179294e
0x0012f114:   00000000 00000000 0012f11c 07990cb7
0x0012f124:   0012f180 07991cc0 00000000 07990d18 

Instructions: (pc=0x01798292)
0x01798282:   81 7d 0c 4a 64 79 01 0f 85 06 00 00 00 83 ec 08
0x01798292:   dd 1c 24 52 50 c7 87 e4 00 00 00 05 00 00 00 81 


Stack: [0x00030000,0x00130000),  sp=0x0012f0b4,  free space=1020k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
j  java.lang.StrictMath.log(D)D+0
j  java.lang.Math.log(D)D+1
j  java.awt.Font.defaultLineMetrics(Ljava/awt/font/FontRenderContext;)Lsun/font/FontLineMetrics;+167
j  java.awt.Font.getLineMetrics(Ljava/lang/String;IILjava/awt/font/FontRenderContext;)Ljava/awt/font/LineMetrics;+3
j  ***.init(L***;)V+233
j  ***.initContext(I)V+12
v  ~StubRoutines::call_stub
V  [jvm.dll+0x8295c]
V  [jvm.dll+0xd752e]
V  [jvm.dll+0x8282d]
V  [jvm.dll+0x8934c]
C  [spawndll.dll+0x10fc]
C  [exs.exe+0x216d7a]
C  [exs.exe+0x213e24]
C  [exs.exe+0x5c97c]
C  [exs.exe+0x5cab4]
C  [exs.exe+0x5c97c]
C  [exs.exe+0x2c7da]
C  [user32.dll+0x8734]
C  [user32.dll+0x8816]
C  [user32.dll+0xb4c0]
C  [user32.dll+0xb50c]
C  [ntdll.dll+0xeae3]
C  [user32.dll+0xb903]
C  [comctl32.dll+0x225f5]
C  [comctl32.dll+0x5f93d]
C  [comctl32.dll+0x60853]
C  [comctl32.dll+0x24712]
C  [user32.dll+0x8734]
C  [user32.dll+0x8816]
C  [user32.dll+0xb4c0]
C  [user32.dll+0x4850a]
C  [ntdll.dll+0xeae3]
C  [user32.dll+0x18798]
C  [user32.dll+0xe905]
C  [exs.exe+0x5ca60]
C  [exs.exe+0x5c97c]
C  [exs.exe+0x2c7da]
C  [user32.dll+0x8734]
C  [user32.dll+0x8816]
C  [user32.dll+0x89cd]
C  [user32.dll+0x96c7]
C  [exs.exe+0x79df4]
C  [exs.exe+0x21972b]
C  [kernel32.dll+0x16d4f]

Java frames: (J=compiled Java code, j=interpreted, Vv=VM code)
j  java.lang.StrictMath.log(D)D+0
j  java.lang.Math.log(D)D+1
j  java.awt.Font.defaultLineMetrics(Ljava/awt/font/FontRenderContext;)Lsun/font/FontLineMetrics;+167
j  java.awt.Font.getLineMetrics(Ljava/lang/String;IILjava/awt/font/FontRenderContext;)Ljava/awt/font/LineMetrics;+3
j  ***.init(L***;)V+233
j  ***.initContext(I)V+12
v  ~StubRoutines::call_stub

---------------  P R O C E S S  ---------------

Java Threads: ( => current thread )
  0x0be90db0 JavaThread "Java2D Disposer" daemon [_thread_blocked, id=3188]
  0x01754888 JavaThread "Low Memory Detector" daemon [_thread_blocked, id=3092]
  0x01753138 JavaThread "CompilerThread0" daemon [_thread_blocked, id=1364]
  0x01752250 JavaThread "Signal Dispatcher" daemon [_thread_blocked, id=2368]
  0x017494c8 JavaThread "Finalizer" daemon [_thread_blocked, id=260]
  0x01747ed0 JavaThread "Reference Handler" daemon [_thread_blocked, id=1940]
=>0x0036b888 JavaThread "main" [_thread_in_native, id=1640]

Other Threads:
  0x01743c98 VMThread [id=3232]
  0x01755fd0 WatcherThread [id=2860]

VM state:not at safepoint (normal execution)

VM Mutex/Monitor currently owned by a thread: None

Heap
 def new generation   total 576K, used 243K [0x03790000, 0x03830000, 0x03c70000)
  eden
[error occurred during error reporting, step 190, id 0xc000008e]

Dynamic libraries:
0x00400000 - 0x006dd000 	E:\***.exe
0x7c910000 - 0x7c9c7000 	D:\WINDOWS\system32\ntdll.dll
0x7c800000 - 0x7c904000 	D:\WINDOWS\system32\kernel32.dll
0x77d10000 - 0x77da0000 	D:\WINDOWS\system32\user32.dll
0x77ef0000 - 0x77f37000 	D:\WINDOWS\system32\GDI32.dll
0x77da0000 - 0x77e4c000 	D:\WINDOWS\system32\advapi32.dll
0x77e50000 - 0x77ee1000 	D:\WINDOWS\system32\RPCRT4.dll
0x770e0000 - 0x7716c000 	D:\WINDOWS\system32\oleaut32.dll
0x77be0000 - 0x77c38000 	D:\WINDOWS\system32\msvcrt.dll
0x774a0000 - 0x775dd000 	D:\WINDOWS\system32\ole32.dll
0x71a60000 - 0x71a72000 	D:\WINDOWS\system32\mpr.dll
0x77bd0000 - 0x77bd8000 	D:\WINDOWS\system32\version.dll
0x77390000 - 0x77492000 	D:\WINDOWS\WinSxS\X86_Microsoft.Windows.Common-Controls_6595b64144ccf1df_6.0.2600.2180_x-ww_a84f1ff9\comctl32.dll
0x77f40000 - 0x77fb6000 	D:\WINDOWS\system32\SHLWAPI.dll
0x76320000 - 0x7633d000 	D:\WINDOWS\system32\imm32.dll
0x72f50000 - 0x72f76000 	D:\WINDOWS\system32\winspool.drv
0x7c9d0000 - 0x7d1f3000 	D:\WINDOWS\system32\shell32.dll
0x76340000 - 0x7638a000 	D:\WINDOWS\system32\comdlg32.dll
0x76ae0000 - 0x76b0f000 	D:\WINDOWS\system32\winmm.dll
0x71a10000 - 0x71a1a000 	D:\WINDOWS\system32\wsock32.dll
0x719f0000 - 0x71a07000 	D:\WINDOWS\system32\WS2_32.dll
0x719e0000 - 0x719e8000 	D:\WINDOWS\system32\WS2HELP.dll
0x74780000 - 0x748ed000 	D:\WINDOWS\system32\quartz.dll
0x5b090000 - 0x5b0c8000 	D:\WINDOWS\system32\uxtheme.dll
0x74690000 - 0x746db000 	D:\WINDOWS\system32\MSCTF.dll
0x65780000 - 0x657a3000 	D:\Program Files\Alwil Software\Avast4\AhJsctNs.dll
0x76310000 - 0x76315000 	D:\WINDOWS\system32\msimg32.dll
0x5f140000 - 0x5f157000 	D:\WINDOWS\system32\olepro32.dll
0x01140000 - 0x011b2000 	E:\Dlls\g5k.dll
0x10000000 - 0x10008000 	E:\Dlls\spawndll.dll
0x7c340000 - 0x7c396000 	D:\WINDOWS\system32\MSVCR71.dll
0x71990000 - 0x719d0000 	D:\WINDOWS\system32\mswsock.dll
0x62e40000 - 0x62e99000 	D:\WINDOWS\system32\hnetcfg.dll
0x6d640000 - 0x6d7cc000 	D:\Program Files\***\Common\Jre\Bin\Client\jvm.dll
0x6d280000 - 0x6d288000 	D:\Program Files\***\Common\Jre\Bin\hpi.dll
0x76ba0000 - 0x76bab000 	D:\WINDOWS\system32\PSAPI.DLL
0x719d0000 - 0x719d8000 	D:\WINDOWS\System32\wshtcpip.dll
0x6d610000 - 0x6d61c000 	D:\Program Files\***\Common\Jre\bin\verify.dll
0x6d300000 - 0x6d31d000 	D:\Program Files\***\Common\Jre\bin\java.dll
0x6d630000 - 0x6d63f000 	D:\Program Files\***\Common\Jre\bin\zip.dll
0x6d000000 - 0x6d167000 	D:\Program Files\***\common\Jre\bin\awt.dll
0x778e0000 - 0x779d8000 	D:\WINDOWS\system32\SETUPAPI.dll
0x77b50000 - 0x77b72000 	D:\WINDOWS\system32\appHelp.dll
0x76f80000 - 0x76fff000 	D:\WINDOWS\system32\CLBCATQ.DLL
0x77000000 - 0x770d4000 	D:\WINDOWS\system32\COMRes.dll
0x765b0000 - 0x76606000 	D:\WINDOWS\System32\cscui.dll
0x76590000 - 0x765ad000 	D:\WINDOWS\System32\CSCDLL.dll
0x6fee0000 - 0x6ff34000 	D:\WINDOWS\system32\netapi32.dll
0x77720000 - 0x7788e000 	D:\WINDOWS\System32\shdocvw.dll
0x779e0000 - 0x77a76000 	D:\WINDOWS\system32\CRYPT32.dll
0x77a80000 - 0x77a92000 	D:\WINDOWS\system32\MSASN1.dll
0x76610000 - 0x76694000 	D:\WINDOWS\system32\CRYPTUI.dll
0x76be0000 - 0x76c0e000 	D:\WINDOWS\system32\WINTRUST.dll
0x76c40000 - 0x76c68000 	D:\WINDOWS\system32\IMAGEHLP.dll
0x77aa0000 - 0x77b47000 	D:\WINDOWS\system32\WININET.dll
0x76f10000 - 0x76f3d000 	D:\WINDOWS\system32\WLDAP32.dll
0x0cac0000 - 0x0cd86000 	D:\WINDOWS\system32\msi.dll
0x35270000 - 0x35277000 	D:\Program Files\Microsoft Office\Office10\MLSHEXT.DLL
0x732d0000 - 0x73327000 	D:\WINDOWS\System32\zipfldr.dll
0x77210000 - 0x772c1000 	D:\WINDOWS\system32\SXS.DLL
0x748f0000 - 0x74a20000 	D:\WINDOWS\System32\msxml3.dll
0x4d5e0000 - 0x4d638000 	D:\WINDOWS\system32\WINHTTP.dll
0x77170000 - 0x7720e000 	D:\WINDOWS\system32\urlmon.dll
0x75d30000 - 0x75dc1000 	D:\WINDOWS\system32\mlang.dll
0x6d240000 - 0x6d27d000 	D:\Program Files\***\common\Jre\bin\fontmanager.dll
0x736b0000 - 0x736f9000 	D:\WINDOWS\system32\ddraw.dll
0x73b10000 - 0x73b16000 	D:\WINDOWS\system32\DCIMAN32.dll
0x73890000 - 0x73960000 	D:\WINDOWS\system32\D3DIM700.DLL
0x6d4c0000 - 0x6d4d3000 	D:\Program Files\***\common\Jre\bin\net.dll
0x6d4e0000 - 0x6d4e9000 	D:\Program Files\***\common\Jre\bin\nio.dll

VM Arguments:
java_command: <unknown>

Environment Variables:
PATH=D:\WINDOWS\system32;D:\WINDOWS;
USERNAME=
OS=Windows_NT
PROCESSOR_IDENTIFIER=x86 Family 6 Model 8 Stepping 1, AuthenticAMD



---------------  S Y S T E M  ---------------

OS: Windows XP Build 2600 Service Pack 2

CPU:total 1 family 6, cmov, cx8, fxsr, mmx, sse

Memory: 4k page, physical 261620k(18924k free), swap 633072k(265292k free)

vm_info: Java HotSpot(TM) Client VM (1.5.0_05-b05) for windows-x86, built on Aug 26 2005 15:36:02 by "java_re" with MS VC++ 6.0

trembovetski · January 16, 2006, 7:24pm

Thanks for the crash log.

Problematic frame:

j java.lang.StrictMath.log(D)D+0

It looks like it died in the VM, not in the libraries.

Could you please try to see if you can reproduce it with -server (or with -client if
you’re running with server already)?

Thanks,
Dmitri

pepe · January 17, 2006, 9:20am

I’ve been trying to reproduce the bug and could not. it Seems that it has been corrected for 1.5.0_06 (we updated some days ago, after we got the crash), or was due to very specific conditions we can not establish again.

trembovetski · January 18, 2006, 5:54pm

I showed the bug to Azeem Jiva who’s been working on intrinsics, he’ll take a look.

He mentioned that there were no client changes between u5 and u6, so it’d be
surprising if the bug stopped reproducing.

Thanks,
Dmitri

ajiva · January 18, 2006, 6:03pm

Hi,
That’s weird, a crash in client in intrinsic code when client hasn’t changed much, and definitly there were no changes between update 5 and update 6. Very, very weird… I’m going to try to reproduce this, but I don’t have access to a Windows machine so this may take some time. If you can reproduce this with a debug build this would help alot. Thanks.

pepe · January 19, 2006, 7:52am

oh. okay.
I’ll make an app that will fill every combinations ([edit] of the limited set of parameters on caller method) to java.awt.Font.getLineMetrics() so that i can get a crash.
Once i get the context, i’ll post something that will help you finding what’s going on.
It might not come before monday as i’m on a deadline for tomorrow.