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 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 node for loop
> 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 node for loop
> DEBUG harfbuzz node for loop
> 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/
Reply to: