[erlang-bugs] common_test + test_server_io errors

[Tim Watson]

Hi Peter!

Now you've caught me on vacation! :)

I'll read through this properly ASAP and get back to you.

Thanks!

Tim

On 6 Aug 2013, at 16:47, Peter Andersson <peppe@REDACTED> wrote:

> Hi Tim,
> 
> A call to ct:log/2 when Common Test is not running (i.e. before or after
> the execution of the ct_run program or the ct:run_test/1 function), is
> ignored, both in R15 and R16.
> 
> For calls to ct:log/2 when Common Test is running, this is the change
> from R15 to R16:
> 
> In R15:
> If ct:log/2 is called on a test case process, or one that has inherited
> the group leader from a test case process (typically one spawned from a
> test case), the string is printed to the test case log. This is true if
> the test case in question is still running. Otherwise the log file is no
> longer open. And if the latter, Common Test will either print the string
> to the current test case log instead, if one (and only one!) test case
> is executing, otherwise print the string to the CT Framework log. This
> means that in R15, printouts by means of ct:log/2 from processes unknown
> to Common Test, end up either in a test case log or in the CT Framework
> log.
> 
> In R16:
> If ct:log/2 is called on a test case process, or one that has inherited
> the group leader from a test case process, the string is printed to the
> test case log (as in R15). If the test case in question is finished and
> the log file has been closed, the string is printed to the "unexpected
> i/o" log (via the test_server_io process) instead. Printouts by means of
> ct:log/2 from processes unknown to Common Test, also always end up in
> the unexpected i/o log.
> 
> Printouts from CT hook functions are "safe" in the sense that they
> execute sequentially pre/post test suite/group/case execution. It's not
> possible that a call to ct:log/2 from a hook function "comes in too soon
> or late", i.e. gets handled before/after Common Test has
> started/finished executing.
> 
> In general, if one knows that Common Test is running (which is the time
> between the CT hook init and terminate call, or the start_logging and
> stop_logging event message), it is safe to call ct:log/2 or ct:pal/2
> from anywhere and find the data in either the test case logs or in the
> unexpected i/o log (depending on the group leader setting). Printouts
> that happen before or after the execution of a test suite, group or
> case, end up in the unexpected i/o log.
> 
> The reason for the exit you reported initially, is that if a log call
> happens during startup or shutdown of Common Test, then, during a short
> window, it's possible that Common Test fails to communicate with Test
> Server and crashes.
> 
> Before I try to answer your question below, I need to understand better
> what you want to happen to the log printouts that take place during your
> configuration/setup phase (before the test run starts) and/or during the
> teardown phase (when Common Test has shut down). If Common Test - in an
> offline mode (i.e. not running) - should attempt to write incoming
> ct:log/2 strings to a file, the best it can do really, is to
> write/append them to say a circular log file in the current working
> directory. This is possible, but it will be difficult to know which
> printouts belong to which test runs when analyzing the logs, and as far
> as I understand, this is the sort of thing you're trying to avoid anyway.
> 
> As far as I see, it's quite possible to do something clever with log
> printouts that happen *before* Common Test starts. They could be
> buffered in a temporary file then read and resent by a CT hook init
> function so that this data ends up first in the unexpected i/o log for
> the test run. The problem here is what to do with printouts that happen
> *after* Common Test has stopped but before your teardown is finished.
> Another possibility could maybe be, if possible, to change the order of
> the whole session so that Common Test is always started before your
> configuration/setup (CT hooks can for example be added dynamically) and
> not stopped until teardown is also finished. Perhaps an init and
> terminate function in a high prio CT hook module could be used to
> synchronize this. Sounds feasible to me.
> 
> Let me know if I understand your problem correctly and tell me what
> ideas/requests you have and let's move on from there.
> 
> Best regards,
> Peter
> 
> Ericsson AB, Erlang/OTP
> 
> Tim Watson wrote:
>> So chaps, I've found the commit that altered the IO handling in
>> test_server (in fact, the addition of test_server_io). To clarify,
>> prior to the addition of test_server_io, calls to ct:log/2 (and
>> friends, e.g., ct:pal/2 and so on) would succeed even if no test was
>> running and end up being handled as if they resided in before/after
>> suite and/or before/after testcase functions. Now it seems that I've
>> got to vet all the processes that might end up calling ct:log/2
>> (indirectly via my event manager) somehow, but there's no proper API
>> to determine whether or not it is safe to do so. Having all my
>> debug/info level testing framework logs emitted to the HTML files was
>> a big reason for choosing common_test, so I'm loth to redirect them
>> elsewhere. My code is basically doing lots of custom (data driven)
>> setup/teardown before and after test suites and test cases, and even
>> though some of this runs before (or during) the common_test test run
>> is started, I *really* don't want to have to create yet another file
>> location that needs to be inspected when tests fail. I'm also not keen
>> on filling up stdio with lots of logging noise.
>> 
>> Any ideas how I can work around this situation without shooting myself
>> in the head/foot? ;)
>> 
>> Cheers,
>> Tim
>> 
>> On 12 Jul 2013, at 08:36, Tim Watson wrote:
>> 
>>> Hi Lukas, thanks for letting me know!
>>> 
>>> Cheers,
>>> Tim
>>> 
>>> On 12 Jul 2013, at 08:29, Lukas Larsson <lukas@REDACTED
>>> <mailto:lukas@REDACTED>> wrote:
>>> 
>>>> Hello Tim,
>>>> 
>>>> Peter is currently away enjoying the sunny summer here in Sweden.
>>>> I'm sure he will get back to you when he comes back!
>>>> 
>>>> Lukas
>>>> On 12/07/13 02:03, Tim Watson wrote:
>>>>> On 1 July 2013 10:25, Tim Watson <watson.timothy@REDACTED
>>>>> <mailto:watson.timothy@REDACTED>> wrote:> We should try to rule
>>>>> out that there's a bug that causes test_server
>>>>> 
>>>>>> failure.
>>>>> 
>>>>>    How can I assist in verifying that?
>>>>> 
>>>>> 
>>>>> Any more news on this? Is there anything more I can do to assist?
>>>>> 
>>>>> Cheers,
>>>>> Tim
>>>>> 
>>>>> 
>>>>> _______________________________________________
>>>>> erlang-bugs mailing list
>>>>> erlang-bugs@REDACTED
>>>>> http://erlang.org/mailman/listinfo/erlang-bugs
>>>>> 
>>>> 
>> 
>