Bug#750785: Slowness with context and xetex

That certainly isn't working as intended. I tested the cache locally (not in
the context of XeTeX) and it works fine.

Can you dig into hb_shape_plan_matches() and see why it's never matching?

On 14-08-11 06:01 AM, Norbert Preining wrote:

Hi

I think I found the bug:

On Mon, 11 Aug 2014, Norbert Preining wrote:

This is about 100 times faster .... total runtime on that document, with debug output, real 1.845s.

I recompiled harfbuzz with some debug statements in the

function, and it turned out that when I do that:

(in src/hb-shape-plan.cc, function hb_shape_plan_create_cached

...

retry:

fprintf(stderr, "DEBUG harfbuzz: after retry label\n");

hb_face_t::plan_node_t *cached_plan_nodes = (hb_face_t::plan_node_t *) hb_atomic_ptr_get (&face->shape_plans);

for (hb_face_t::plan_node_t *node = cached_plan_nodes; node; node = node->next) {

fprintf(stderr, "DEBUG harfbuzz node for loop\n");

if (hb_shape_plan_matches (node->shape_plan, &proposal)) {

fprintf(stderr, "DEBUG harfbuzz return from node loop\n");

return hb_shape_plan_reference (node->shape_plan);

}

...

THat the loop is getting longer and longer and longer and longer.

For each iteration it loops one more time!! I only send you

the start of the log output:

.....

DEBUG [1407750920] <0> return from hb_shape_plan_create_cached

DEBUG [1407750920] hbFace=47040112, segment_props.script=1281455214, segment_props.direction=4, segment-props.language=47792128, engine->nFeatures=0, shaperList=¨1N

DEBUG harfbuzz: after retry label

DEBUG harfbuzz node for loop

DEBUG harfbuzz: before shape_plan_create

DEBUG harfbuzz: before calloc

DEBUG [1407750920] <0> return from hb_shape_plan_create_cached

DEBUG [1407750920] hbFace=47040112, segment_props.script=1281455214, segment_props.direction=4, segment-props.language=47792128, engine->nFeatures=0, shaperList=¨1N

DEBUG harfbuzz: after retry label

DEBUG harfbuzz node for loop

DEBUG harfbuzz: before shape_plan_create

DEBUG harfbuzz: before calloc

DEBUG [1407750920] <0> return from hb_shape_plan_create_cached

DEBUG [1407750920] hbFace=47040112, segment_props.script=1281455214, segment_props.direction=4, segment-props.language=47792128, engine->nFeatures=0, shaperList=¨1N

DEBUG harfbuzz: after retry label

DEBUG harfbuzz node for loop

DEBUG harfbuzz: before shape_plan_create

DEBUG harfbuzz: before calloc

DEBUG [1407750920] <0> return from hb_shape_plan_create_cached

SO with every char another loop element is added.

Still on the first page, I already had:

[~/foo] grep loop xelatexslow-debug-output.log | wc -l

6249880

...

That explains why it is getting soooo slow ...

I cannot dig into the code now, but this is for sure not

planned ;-)

Norbert

------------------------------------------------------------------------

PREINING, Norbert http://www.preining.info

JAIST, Japan TeX Live & Debian Developer

GPG: 0x860CDC13 fp: F7D8 A928 26E3 16A1 9FA0 ACF0 6CAC A448 860C DC13

------------------------------------------------------------------------

--
behdad
http://behdad.org/