search

papandreou / subset-font

Create a subset of a TrueType/OpenType/WOFF/WOFF2 font using the wasm build of harfbuzz/hb-subset
BSD 3-Clause "New" or "Revised" License
85 stars 6 forks source link

RuntimeError: memory access out of bounds #8

Closed zonyitoo closed 3 years ago

zonyitoo commented 3 years ago 
1|server  | Trace: RuntimeError: memory access out of bounds
1|server  |     at malloc (<anonymous>:wasm-function[0]:0x765)
1|server  |     at subsetFont (/fontmin-server/node_modules/subset-font/index.js:27:30)
1|server  |     at Application.<anonymous> (/fontmin-server/lib/server.js:175:13)
1|server  |     at Application.emit (events.js:376:20)
1|server  |     at Object.onerror (/fontmin-server/node_modules/koa/lib/context.js:127:14)
1|server  |     at onerror (/fontmin-server/node_modules/koa/lib/application.js:165:32)

It doesn't seem to be OOM because it still have plenty of memories in docker.

papandreou commented 3 years ago

We don't stand a chance of debugging this without steps to reproduce. Could you share the font that it happens with, as a minimum?

zonyitoo commented 3 years ago

MFZhuoHeiXinChao.ttf.zip

Here is the font I am using.

Just some of the requests may fail, I am trying to find a reproducible case.

papandreou commented 3 years ago

Thanks, please try to do that!

I tried to make a very quick stress test, but it works fine on my machine: https://github.com/papandreou/subset-font/compare/feature/stressTest

papandreou commented 3 years ago

All the subsetting operations share the same heap, but run serially due to the use of p-limit here: https://github.com/papandreou/subset-font/blob/0e7fc87d0b5532da70bdc9b59ceca0b5172e9c6e/index.js#L78

zonyitoo commented 3 years ago

One observation: The errors shows up after server starts about 15mins.

Here is some cases (with a different font):

FZZJ-ZSXKJW.ttf.zip

L💓遗憾、
A    -   ！ི浮生ུ,
心动😘柴宝贝🐕
ᝰᖇⅇꫜડꫝⅈρⅈꪖꪫ꫁⁵²⁰゛农村范ルヾ2
没有鱼丸？？？7
中國知網·綽号小伙伴，志丶
ᝰᖇⅇꫜડꫝⅈρⅈꪖꪫ꫁⁵²⁰゛农村范ルヾ2
大ྂ孖ྂ峰回路转
慕羡。久暖他心1
壹花一世界🍃小妞༊྄ཻᏴ࿆Ꮻ࿆Ꭶ࿆Ꮥ࿆℡🌍1

Format: woff2.

Is there any chances that it is because these usernames have special characters, like emoji, ...

But this case:

To:送你「难兄难弟纪念」心意卡，这是我送你的第张心意卡，一起继续加油鸭！

It is obviously that there is no special characters in this line.

zonyitoo commented 3 years ago 
let fontData = ...; // The font data of FZZJ-ZSXKJW.ttf
let text = [
  ':',  'T',  'o',  '「', '」',
  '一', '你', '兄', '加', '卡',
  '弟', '张', '心', '念', '意',
  '我', '是', '油', '的', '第',
  '纪', '继', '续', '起', '这',
  '送', '难', '鸭', '！', '，'
];
subsetFont(fontData, text, { targetFormat: 'woff2' });

Could you reproduce with this case? It is 100% reproducible on my server.

papandreou commented 3 years ago

Tried adding that to the stress test, still no luck reproducing it :man_shrugging:

Note that text has to be passed as a string per the documentation.

Are you sure you're using the latest version of subset-font? Some memory-related fixes went in and were released in 1.1.3 and 1.2.3.

zonyitoo commented 3 years ago

I am using 1.3.0.

BTW, it only reproducible after about 15mins on my server. The same request is Ok when the server starts.

zonyitoo commented 3 years ago

After I changed to text.join('') and the problem doesn't show again. Thanks for you help.

It would be great if the function can check the type and report an error to me.

zonyitoo commented 3 years ago

No. The problem still exists. Example:

font: FZZJ-ZSXKJW, text: 小林林YYDS, format: woff2

The problem showed up after 25mins.

papandreou commented 3 years ago

I've tried to run the stress test with 100000 iterations of creating that exact subset of FZZJ-ZSXKJW.ttf as woff2, no luck :confused:

This is with node.js 12.16.1, which version are you on?

After I changed to text.join('') and the problem doesn't show again. Thanks for you help.

It would be great if the function can check the type and report an error to me.

Fixed for next release in f4a5297780289e69a695cbd3158eff667ec7b971

zonyitoo commented 3 years ago

I am running v14.17.0.

zonyitoo commented 3 years ago 
1|mmgamefontminlogicsvr  | Trace: RangeError: offset is out of bounds
1|mmgamefontminlogicsvr  |     at Uint8Array.set (<anonymous>)
1|mmgamefontminlogicsvr  |     at subsetFont (/home/qspace/mmgamefontminlogicsvr/fontmin-server/node_modules/subset-font/index.js:28:10)
1|mmgamefontminlogicsvr  |     at /home/qspace/mmgamefontminlogicsvr/fontmin-server/lib/server.js:158:17
1|mmgamefontminlogicsvr  |     at Generator.throw (<anonymous>)
1|mmgamefontminlogicsvr  |     at rejected (/home/qspace/mmgamefontminlogicsvr/fontmin-server/lib/server.js:6:65)
1|mmgamefontminlogicsvr  | 2021-07-01T14:58:44.158Z error: failed to getMinimizedFontCached, font: FZZJ-ZSXKJW, text: To:送你陪伴心意卡心意卡，一起继续加油鸭！, format: woff2
1|mmgamefontminlogicsvr  | Trace: RuntimeError: memory access out of bounds
1|mmgamefontminlogicsvr  |     at malloc (<anonymous>:wasm-function[0]:0x765)
1|mmgamefontminlogicsvr  |     at subsetFont (/home/qspace/mmgamefontminlogicsvr/fontmin-server/node_modules/subset-font/index.js:27:30)
1|mmgamefontminlogicsvr  |     at /home/qspace/mmgamefontminlogicsvr/fontmin-server/lib/server.js:158:17
1|mmgamefontminlogicsvr  |     at Generator.throw (<anonymous>)
1|mmgamefontminlogicsvr  |     at rejected (/home/qspace/mmgamefontminlogicsvr/fontmin-server/lib/server.js:6:65)

The first error is RangeError: offset is out of bounds.

After that, RuntimeError: memory access out of bounds starts to show up repeatedly.

Not all requests fail. But if a request fail, then it will always fail.

zonyitoo commented 3 years ago

Yes, I can confirm that when a process shows RangeError: offset is out of bounds once, then RuntimeError: memory access out of bounds will start to show.

It is an indicator.

zonyitoo commented 3 years ago

https://github.com/papandreou/subset-font/blob/f4a5297780289e69a695cbd3158eff667ec7b971/index.js#L31-L32

Isn't the second parmeter of Uint8Array.set is offset? doc

What's this exports.malloc returns?

papandreou commented 3 years ago

Isn't the second parmeter of Uint8Array.set is offset? doc

Yes, but offset is optional (defaults to 0).

What's this exports.malloc returns?

It returns a number that represents a pointer to an address/offset inside the WebAssembly heap. It's the location where originalFont.byteLength bytes have been allocated.

papandreou commented 3 years ago

I can't reproduce the issue with node.js 14.17.0 either. I tried different variants of the stress test with the fonts and texts you provided.

I'm not a WebAssembly expert, so I don't know if it's because of interference from something else your server or one of its dependencies are doing. I'm not sure there's much more I can do without an isolated reproduction. If you can share your full server setup I might be able to figure it out, although it'd of course be more work for me to narrow it down.

zonyitoo commented 3 years ago

Well, you have passed the malloc allocated pointer as a number of offset passed to the set method.

Does the internal heap share the same memory location with heapu8?

zonyitoo commented 3 years ago

Here is a simplified server:

fontmin-server.zip

I deleted some of the unrelated logic codes.

npm i
node lib/server.js

should be able to start the server.

Test it with:

curl "http://127.0.0.1:28537/?font=FZZJ-ZSXKJW&text=aaa"

Online configuration:

  1. Run in a Docker with 2 cores and 8 GB memory
  2. Start server.js with pm2 in cluster mode with 2 instances.
zonyitoo commented 3 years ago

I have to rewrite the server with C++ now because this error have affected online users. Closing now but the issue still exists.

papandreou commented 3 years ago

I think there's something wrong with your fonts, maybe they've have been truncated? Suspisciously they're both 131072 bytes long:

[fontmin-server]$ ls -la lib/data/fonts/
total 268
drwxr-xr-x 2 andreas andreas   4096 jul  2 04:02 .
drwxr-xr-x 3 andreas andreas   4096 jul  2 03:52 ..
-rw-r--r-- 1 andreas andreas 131072 jul  2 03:51 FZZJ-ZSXKJW.ttf
-rw-r--r-- 1 andreas andreas     27 jul  2 03:51 .gitignore
-rw-r--r-- 1 andreas andreas      0 jul  2 03:50 .gitkeep
-rw-r--r-- 1 andreas andreas 131072 jul  2 03:51 MFZhuoHeiXinChao.ttf

ttx chokes on both of them:

[fontmin-server]$ ttx lib/data/fonts/FZZJ-ZSXKJW.ttf
Dumping "lib/data/fonts/FZZJ-ZSXKJW.ttf" to "lib/data/fonts/FZZJ-ZSXKJW.ttx"...
Dumping 'GlyphOrder' table...
ERROR: Unhandled exception has occurred
Traceback (most recent call last):
  File "/home/andreas/.local/lib/python2.7/site-packages/fontTools/ttx.py", line 401, in main
    process(jobs, options)
  File "/home/andreas/.local/lib/python2.7/site-packages/fontTools/ttx.py", line 375, in process
    action(input, output, options)
  File "/home/andreas/.local/lib/python2.7/site-packages/fontTools/misc/loggingTools.py", line 375, in wrapper
    return func(*args, **kwds)
  File "/home/andreas/.local/lib/python2.7/site-packages/fontTools/ttx.py", line 272, in ttDump
    newlinestr=options.newlinestr)
  File "/home/andreas/.local/lib/python2.7/site-packages/fontTools/ttLib/ttFont.py", line 228, in saveXML
    self._saveXML(writer, **kwargs)
  File "/home/andreas/.local/lib/python2.7/site-packages/fontTools/ttLib/ttFont.py", line 283, in _saveXML
    self._tableToXML(tableWriter, tag, splitGlyphs=splitGlyphs)
  File "/home/andreas/.local/lib/python2.7/site-packages/fontTools/ttLib/ttFont.py", line 314, in _tableToXML
    table.toXML(writer, self)
  File "/home/andreas/.local/lib/python2.7/site-packages/fontTools/ttLib/ttFont.py", line 796, in toXML
    glyphOrder = ttFont.getGlyphOrder()
  File "/home/andreas/.local/lib/python2.7/site-packages/fontTools/ttLib/ttFont.py", line 442, in getGlyphOrder
    glyphOrder = self['post'].getGlyphOrder()
  File "/home/andreas/.local/lib/python2.7/site-packages/fontTools/ttLib/ttFont.py", line 382, in __getitem__
    data = self.reader[tag]
  File "/home/andreas/.local/lib/python2.7/site-packages/fontTools/ttLib/sfnt.py", line 105, in __getitem__
    data = entry.loadData (self.file)
  File "/home/andreas/.local/lib/python2.7/site-packages/fontTools/ttLib/sfnt.py", line 479, in loadData
    assert len(data) == self.length
AssertionError

Seems like subset-font is missing some error handling for that case. When I run your server in the vscode debugger and the curl comamnd, I can see that it ends up with a 0 byte buffer here, which breaks wawoff2 when trying to encode it.

This doesn't match the symptoms you originally described, maybe something went wrong when you created the zip?

... But I can at least try to see if I can detect this condition and report a proper error, so thanks no matter what :)

papandreou commented 3 years ago

Well, you have passed the malloc allocated pointer as a number of offset passed to the set method.

Does the internal heap share the same memory location with heapu8?

Yeah, heapu8 is the WebAssembly heap exposed as a Uint8Array. As far as I know, using its exported malloc function to allocate memory inside it, then mutating the byte range like this is the correct way to get data into the heap from JS land.

papandreou commented 3 years ago

Added a bit of error handling in 1.3.1

zonyitoo commented 3 years ago

maybe something went wrong when you created the zip?

Maybe... BTW, the two fonts I have already sent to you in this issue, you could try to reproduce it locally.

papandreou commented 3 years ago

Still no luck reproducing it after adding the FZZJ-ZSXKJW.ttf from previously. I tried with thousands of curl requests (with a counter added to text to avoid getting the cached result.

I also tried disabling the cache in the server and letting apache bench loose on it, but it all went fine :man_shrugging:

$ ab -c 100 -n 10000 'http://127.0.0.1:28537/?font=FZZJ-ZSXKJW&text=L%F0%9F%92%93%E9%81%97%E6%86%BE%E3%80%81%0AA%20%20%20%20-%20%20%20%EF%BC%81%E0%BD%B2%E6%B5%AE%E7%94%9F%E0%BD%B4%2C%0A%E5%BF%83%E5%8A%A8%F0%9F%98%98%E6%9F%B4%E5%AE%9D%E8%B4%9D%F0%9F%90%95%0A%E1%9D%B0%E1%96%87%E2%85%87%EA%AB%9C%E0%AA%A1%EA%AB%9D%E2%85%88%CF%81%E2%85%88%EA%AA%96%EA%AA%AB%EA%AB%81%E2%81%B5%C2%B2%E2%81%B0%E3%82%9B%E5%86%9C%E6%9D%91%E8%8C%83%E3%83%AB%E3%83%BE2%0A%E6%B2%A1%E6%9C%89%E9%B1%BC%E4%B8%B8%EF%BC%9F%EF%BC%9F%EF%BC%9F7%0A%E4%B8%AD%E5%9C%8B%E7%9F%A5%E7%B6%B2%C2%B7%E7%B6%BD%E5%8F%B7%E5%B0%8F%E4%BC%99%E4%BC%B4%EF%BC%8C%E5%BF%97%E4%B8%B6%0A%E1%9D%B0%E1%96%87%E2%85%87%EA%AB%9C%E0%AA%A1%EA%AB%9D%E2%85%88%CF%81%E2%85%88%EA%AA%96%EA%AA%AB%EA%AB%81%E2%81%B5%C2%B2%E2%81%B0%E3%82%9B%E5%86%9C%E6%9D%91%E8%8C%83%E3%83%AB%E3%83%BE2%0A%E5%A4%A7%E0%BE%82%E5%AD%96%E0%BE%82%E5%B3%B0%E5%9B%9E%E8%B7%AF%E8%BD%AC%0A%E6%85%95%E7%BE%A1%E3%80%82%E4%B9%85%E6%9A%96%E4%BB%96%E5%BF%831%0A%E5%A3%B9%E8%8A%B1%E4%B8%80%E4%B8%96%E7%95%8C%F0%9F%8D%83%E5%B0%8F%E5%A6%9E%E0%BC%8A%E0%BE%84%E0%BD%BB%E1%8F%B4%E0%BF%86%E1%8F%AB%E0%BF%86%E1%8E%A6%E0%BF%86%E1%8F%95%E0%BF%86%E2%84%A1%F0%9F%8C%8D1'
This is ApacheBench, Version 2.3 <$Revision: 1843412 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking 127.0.0.1 (be patient)
Completed 1000 requests
Completed 2000 requests
Completed 3000 requests
Completed 4000 requests
Completed 5000 requests
Completed 6000 requests
Completed 7000 requests
Completed 8000 requests
Completed 9000 requests
Completed 10000 requests
Finished 10000 requests

Server Software:        
Server Hostname:        127.0.0.1
Server Port:            28537

Document Path:          /?font=FZZJ-ZSXKJW&text=L%F0%9F%92%93%E9%81%97%E6%86%BE%E3%80%81%0AA%20%20%20%20-%20%20%20%EF%BC%81%E0%BD%B2%E6%B5%AE%E7%94%9F%E0%BD%B4%2C%0A%E5%BF%83%E5%8A%A8%F0%9F%98%98%E6%9F%B4%E5%AE%9D%E8%B4%9D%F0%9F%90%95%0A%E1%9D%B0%E1%96%87%E2%85%87%EA%AB%9C%E0%AA%A1%EA%AB%9D%E2%85%88%CF%81%E2%85%88%EA%AA%96%EA%AA%AB%EA%AB%81%E2%81%B5%C2%B2%E2%81%B0%E3%82%9B%E5%86%9C%E6%9D%91%E8%8C%83%E3%83%AB%E3%83%BE2%0A%E6%B2%A1%E6%9C%89%E9%B1%BC%E4%B8%B8%EF%BC%9F%EF%BC%9F%EF%BC%9F7%0A%E4%B8%AD%E5%9C%8B%E7%9F%A5%E7%B6%B2%C2%B7%E7%B6%BD%E5%8F%B7%E5%B0%8F%E4%BC%99%E4%BC%B4%EF%BC%8C%E5%BF%97%E4%B8%B6%0A%E1%9D%B0%E1%96%87%E2%85%87%EA%AB%9C%E0%AA%A1%EA%AB%9D%E2%85%88%CF%81%E2%85%88%EA%AA%96%EA%AA%AB%EA%AB%81%E2%81%B5%C2%B2%E2%81%B0%E3%82%9B%E5%86%9C%E6%9D%91%E8%8C%83%E3%83%AB%E3%83%BE2%0A%E5%A4%A7%E0%BE%82%E5%AD%96%E0%BE%82%E5%B3%B0%E5%9B%9E%E8%B7%AF%E8%BD%AC%0A%E6%85%95%E7%BE%A1%E3%80%82%E4%B9%85%E6%9A%96%E4%BB%96%E5%BF%831%0A%E5%A3%B9%E8%8A%B1%E4%B8%80%E4%B8%96%E7%95%8C%F0%9F%8D%83%E5%B0%8F%E5%A6%9E%E0%BC%8A%E0%BE%84%E0%BD%BB%E1%8F%B4%E0%BF%86%E1%8F%AB%E0%BF%86%E1%8E%A6%E0%BF%86%E1%8F%95%E0%BF%86%E2%84%A1%F0%9F%8C%8D1
Document Length:        13400 bytes

Concurrency Level:      100
Time taken for tests:   792.782 seconds
Complete requests:      10000
Failed requests:        0
Total transferred:      135780000 bytes
HTML transferred:       134000000 bytes
Requests per second:    12.61 [#/sec] (mean)
Time per request:       7927.825 [ms] (mean)
Time per request:       79.278 [ms] (mean, across all concurrent requests)
Transfer rate:          167.26 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.6      0       6
Processing:   285 7892 248.3   7921    9637
Waiting:      256 7216 997.1   7518    8361
Total:        285 7892 248.4   7922    9637

Percentage of the requests served within a certain time (ms)
  50%   7922
  66%   7948
  75%   7968
  80%   7986
  90%   8032
  95%   8072
  98%   8274
  99%   8313
 100%   9637 (longest request)