Output() spends two and a half minutes on a hundred characters of Katibeh, and the cost does not come from the page

[jakejackson1]

Measured on gravitypdf at 28aec23. One <div> of Katibeh at useOTL => 0xFF, nothing else on the page, timing WriteHTML() and Output() separately:

characters	WriteHTML()	Output()
100	0.07 s	144.31 s
200	0.02 s	132.34 s
400	0.03 s	142.90 s
800	0.03 s	137.52 s
1,600	0.07 s	143.24 s

Sixteen times the text costs nothing. All of the shaping — Otl::applyOTL(), the whole reason useOTL is on — is the 0.03 s column. The ~140 s is a fixed cost per font inside makeSubset(), and it is not work proportional to what is being subset.

It does stop being flat eventually: the same font at 3,616 characters had not returned after 23 minutes of CPU, so there is something superlinear further up as well. But the flat part is the finding, because a hundred characters is a realistic page and it costs two and a half minutes.

At useOTL => 0 the same document is 0.03–0.16 s end to end.

Which fonts

Six families, measured the same way, all Arabic or Nastaliq:

family	upstream
Katibeh	ofl/katibeh/Katibeh-Regular.ttf
Mirza	ofl/mirza/Mirza-Regular.ttf
Aref Ruqaa	ofl/arefruqaa/ArefRuqaa-Regular.ttf
Aref Ruqaa Ink	ofl/arefruqaaink/ArefRuqaaInk-Regular.ttf
Estedad	variable upstream, statics from the family's download
Noto Nastaliq Urdu	variable upstream

They were found by a catalogue-wide render check stalling: four of them held a worker for 25 minutes each and the run stopped making progress at 1,839 of 3,328 faces. The checker now gives every render 45 seconds, which is how the six are counted rather than waited on.

Reproducing

$mpdf = new \Mpdf\Mpdf([
    'mode' => 'UTF-8',
    'fontDir' => [$dir],
    'fontdata' => ['probe' => ['R' => 'Katibeh-Regular.ttf', 'useOTL' => 0xFF]],
    'default_font' => 'probe',
]);
$mpdf->SetCompression(false);
$mpdf->WriteHTML('<div>' . $hundredCharactersOfArabic . '</div>');
$pdf = $mpdf->Output('', 'S');   // ~140 s

Suppress warnings while timing this, or it will throw first: these six also hit #114, which raises before Output() is reached.

Not #83

#83 was chaining-context subtables being re-read during shaping, and the fix moved WriteHTML(). Here WriteHTML() is already 0.03 s and every second is in Output(), after shaping has finished.