From mboxrd@z Thu Jan  1 00:00:00 1970
From: Joel Brobecker <brobecker@gnat.com>
To: gdb-patches@sources.redhat.com
Subject: Re: [RFA/testsuite] Workaround timeout in default.exp
Date: Fri, 21 May 2004 01:14:00 -0000
Message-id: <20040521011443.GG10684@gnat.com>
References: <20040518210147.GQ10684@gnat.com> <20040518214255.GC4036@nevyn.them.org> <20040520014811.GR10684@gnat.com> <20040520022747.GA451@nevyn.them.org>
X-SW-Source: 2004-05/msg00623.html

> If you're trying to debug expect matching, I recommend "exp_internal 1"
> before the block (and maybe "exp_internal 0" after).  That will let you
> see exactly what's going on, and why my crackpot theory is wrong :)

Nice command, that really helped understand better what was going on.

Roughly, it seems that what is hurting us is that expect is eating up
the output from GDB reeeaaaal slooooowwww. Not expect's fault, I imagine,
but by counting characters in the first few iterations, it looks like
expect gets the output 12-15 characters at a time. It takes a total
of 113 reads to fetch the entire command output, which contains ~9000
characters, which makes around 80 chars per read.

And from watching it run and spit the expect debug data, it seems as if
expect is getting slower and slower at each iteration. It looks like an
algorithm that's not linear, but something exponential instead.

As an experiment, I tried increasing the timeout value to 600secs,
and the test did complete successfully... After 18mins!

It seemed to be slowing down on the evaluation of one specific regexp:

        ".*\(gdb\) $"? no

So I uncommented it in gdb_test_multiple as follow, just to see what
effect it would have:

        #  -re ".*$gdb_prompt $" {
        #     if ![string match "" $message] then {
        #       fail "$message"
        #     }
        #     set result 1
        # }

You are going to be surprised. That specific test takes less than 40secs
to run. The whole default.exp test takes a total of 1mn45secs.

And what's curious, even after have is that I still see expect try the
same regexp. Before commenting out the code above, the sequence of
regexp evaluations looked like:

        "Undefined[a-z]* command:.*\(gdb\) $"? no
        "Ambiguous command.*\(gdb\) $"? no
        "Program exited with code [0-9]+.*\(gdb\) $"? no
        "EXIT code [0-9\r\n]+Program exited normally.*\(gdb\) $"? no
        "The program is not being run.*\(gdb\) $"? no
        ".*\(gdb\) $"? no
        "<return>"? no
        "\(y or n\) "? no

After, it was slightly transformed into:

        "Undefined[a-z]* command:.*\(gdb\) $"? no
        "Ambiguous command.*\(gdb\) $"? no
        "Program exited with code [0-9]+.*\(gdb\) $"? no
        "EXIT code [0-9\r\n]+Program exited normally.*\(gdb\) $"? no
        "The program is not being run.*\(gdb\) $"? no
        "#"? no
        ".*\(gdb\) $"? no
        "<return>"? no
        "\(y or n\) "? no

At this point, no comprendo anymore... :-/
(where does the "#" come from, and why is the gdb_prompt check
still there?)

-- 
Joel