[erlang-questions] CT take a long time to warm up

[Roberto Ostinelli]

Hi all,

a very simple CT test takes forever to boot.

%%%%%% Module %%%%%%%%%

-module(mymodule).

-export([greetings/1]).

greetings(Text) ->

lists:flatten(io_lib:format("~s world!", [Text])).

%%%%%%%%%%%%%%%%%%%%%%%

%%%%%% CT test %%%%%%%%

-module(mymodule_SUITE).

-include_lib("common_test/include/ct.hrl").

-export([all/0]).

-export([greetings_test/1]).

all() ->

[greetings_test].

greetings_test(_Config) ->

"hello world!" = mymodule:greetings("hello"),

"goodbye world!" = mymodule:greetings("goodbye").

%%%%%%%%%%%%%%%%%%%%%%%

Here's the log:

==================

=== Suite started at 2012-09-23 17:22:24
=== Starting test, 1 test cases
=cases         1
=user          roberto
=host          robertos-MacBook-Pro.local
=hosts         robertos-MacBook-Pro.local 
=emulator_vsn  5.9.1
=emulator      beam
=otp_release   R15B01
=started       2012-09-23 17:22:24
=case          ct_framework:init_per_suite
=logfile       ct_framework.init_per_suite.html
=group_props   [{suite,mymodule_SUITE}]
=started       2012-09-23 17:22:44
=ended         2012-09-23 17:22:44
=result        ok
=elapsed       1.0e-6
=case          mymodule_SUITE:greetings_test
=logfile       mymodule_suite.greetings_test.html
=started       2012-09-23 17:22:44
=ended         2012-09-23 17:22:44
=result        ok
=elapsed       3.1e-4
=case          ct_framework:end_per_suite
=logfile       ct_framework.end_per_suite.html
=group_props   [{suite,mymodule_SUITE}]
=started       2012-09-23 17:22:44
=ended         2012-09-23 17:22:44
=result        ok
=elapsed       1.0e-6
=group_time    0.054s
=== TEST COMPLETE, 1 ok, 0 failed of 1 test cases

=finished      2012-09-23 17:22:44
=failed        0
=successful    1
=user_skipped  0
=auto_skipped  0

==================

it literally takes 20 seconds before the first (and only) test is run. Any ideas why?

Thank you,

r.

[Tim Watson]

I find common test very slow to start as well, so I'd be interested to find out why. Have you tried running this via ct:run_test/1 with profiling turned on?

_______________________________________________
erlang-questions mailing list
erlang-q...@erlang.org
http://erlang.org/mailman/listinfo/erlang-questions

[Roberto Ostinelli]

On Mon, Sep 24, 2012 at 1:38 AM, Tim Watson <watson....@gmail.com> wrote:

I find common test very slow to start as well, so I'd be interested to find out why. Have you tried running this via ct:run_test/1 with profiling turned on?

haven't tried that. weird thing, 20 seconds is consistent.

it is a fresh install on a mountain lion osx.

any pointers? this kinda defeats the purpose of TDD.

r. 

[Motiejus Jakštys]

On Wed, Sep 26, 2012 at 09:14:53AM -0700, Roberto Ostinelli wrote:
> On Mon, Sep 24, 2012 at 1:38 AM, Tim Watson <watson....@gmail.com>wrote:
>
> > I find common test very slow to start as well, so I'd be interested to
> > find out why. Have you tried running this via ct:run_test/1 with profiling
> > turned on?
> >
>
> haven't tried that. weird thing, 20 seconds is consistent.
>
> it is a fresh install on a mountain lion osx.
>
> any pointers?

How do you run it? Consistent 20 seconds sounds like a DNS timeout
issue (stab in the dark).

Motiejus

[Motiejus Jakštys]

On Wed, Sep 26, 2012 at 8:40 PM, Roberto Ostinelli <rob...@widetag.com> wrote:
>> How do you run it? Consistent 20 seconds sounds like a DNS timeout
>> issue (stab in the dark).
>
>

> rebar ct_suites=mymodule

Hi,
adding the list.

Please do

$TRACE_F rebar ct_suites=mymodule

and replace $TRACE_F with Max OS C equivalent of "strace -f". Then see
what it does just before the 20 second pause.

--
Motiejus Jakštys

[Tuncer Ayaz]

On Wed, Sep 26, 2012 at 9:44 PM, Motiejus Jakštys wrote:

> On Wed, Sep 26, 2012 at 8:40 PM, Roberto Ostinelli wrote:
> > > How do you run it? Consistent 20 seconds sounds like a DNS
> > > timeout issue (stab in the dark).
> >
> >
> > rebar ct_suites=mymodule
>
> Hi,
> adding the list.
>
> Please do
>
> $TRACE_F rebar ct_suites=mymodule

Make that

$TRACE_F rebar suites=mymodule

and also consider running rebar with fprof:

$TRACE_F rebar -p suites=mymodule
or
$TRACE_F rebar --profile suites=mymodule

, but make sure you update rebar first to avoid a faulty
call to fprof:apply/2.

If it's caused by name lookup, you can try a custom ERL_INETRC file:
http://www.erlang.org/doc/apps/erts/inet_cfg.html

> and replace $TRACE_F with Max OS C equivalent of "strace -f".
> Then see what it does just before the 20 second pause.

[Roberto Ostinelli]

Ok,

I finally managed to track this down but I'm totally unsure why this happens. Motiejus, you were right.

When I run REBAR, the process automountd tries to connect on port 111 (sunrpc) on my local NAT. When it times out, the CT tests are actually run. If I simply block this process with a firewall, tests start immediately.

I'm at disposal if anyone wants to dig further (tuncer?)

r.

[Tim Watson]

Whoa, this is fascinating Roberto. Did you try running common test from the shell by hand and see if it still happens, i.e., by running something like this:

ct:run_test([{logdir, LogDir},
{label, Label},
{auto_compile, true},
{suite, Suites}]).

Does the same thing happen?

[Dave Cottlehuber]

On 11 October 2012 10:45, Tim Watson <watson....@gmail.com> wrote:
> Whoa, this is fascinating Roberto. Did you try running common test from the shell by hand and see if it still happens, i.e., by running something like this:
>
> ct:run_test([{logdir, LogDir},
> {label, Label},
> {auto_compile, true},
> {suite, Suites}]).
>
> Does the same thing happen?
>
> On 11 Oct 2012, at 04:38, Roberto Ostinelli wrote:
>
>> Ok,
>>
>> I finally managed to track this down but I'm totally unsure why this happens. Motiejus, you were right.
>>
>> When I run REBAR, the process automountd tries to connect on port 111 (sunrpc) on my local NAT. When it times out, the CT tests are actually run. If I simply block this process with a firewall, tests start immediately.
>>
>> I'm at disposal if anyone wants to dig further (tuncer?)
>>
>> r.

Is anything in PATH or ERL_LIBS & similar environment vars referring
to a non-existent mountpoint?

A+
Dave

[Roberto Ostinelli]

On Thu, Oct 11, 2012 at 1:45 AM, Tim Watson <watson....@gmail.com> wrote:

Whoa, this is fascinating Roberto. Did you try running common test from the shell by hand and see if it still happens, i.e., by running something like this:

ct:run_test([{logdir, LogDir},
                     {label, Label},
                     {auto_compile, true},
                     {suite, Suites}]).

Does the same thing happen?

Tried:

ct_run -suite mymodule_SUITE

same thing happened.

r. 

[Roberto Ostinelli]

Is anything in PATH or ERL_LIBS & similar environment vars referring

to a non-existent mountpoint?

A+
Dave

$ echo $PATH

/opt/local/bin:/opt/local/sbin:/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/bin

$ERL_LIBS

$  

nothing much in there.

r.