All messages from EventListenerTextWriter goes to console output independent on stream name

[nvborisenko]

I want to put some hidden message from test to ITestEventListener extensions.

public void Test()
{
  (new NUnit.Framework.Internal.Execution.EventListenerTextWriter("DiagnosticStream", System.IO.TextWriter.Null)).WriteLine("This is message from custom stream");
}

But this message also goes to console output. Is there some way to accomplish my needs?

[CharliePoole]

This seems like something that could be needed in general: a way to send messages from the framework to the engine and/or runner.

The example code creates an event in XML with element name textout, which conceptually represents text output from the text. The event has a stream attribute which is used by runners to decide how to output the text. A special stream name would mean "this is not really text output, ignore it."

Piggybacking on top of text output like this seems a bit messy. It's equally easy to create a new type of event element for the purpose of communicating with the engine. Let's accept this and label for design. I have some ideas which I'll post later, when I'm actually awake!

[nvborisenko]

Right, I need communication between test domain and engine domain. This communication should be dedicated only for me and no others participants should react on these messages. Thanks @CharliePoole

[CharliePoole]

Currently, our convention is that unknown event types (XML elements) are ignored. Unknown text streams ate displayed to avoid information loss.

[CharliePoole]

Some thoughts for the @nunit/framework-and-engine-team on design...

1. If this is to be handled as an event, i.e. going through the framework event pump, then it will be completely asynchronous. If a synchronous message is wanted, that's a couple of orders of magnitude more in re-design.

2. At a minimum, I think a new message element is needed, rather than piggybacking on text output. It's reasonable to think that all text output events will result in the output of text!

3. In designing a new element, we should consider carefully whether it will be targeted at a particular extension, at all extensions, at the engine or at the engine and runners. In particular, I'm wondering if we should only handle some messages within the engine and its extensions and avoid forwarding them to runners. Should there be some attribute in the new element that indicates how far to distribute?

4. I think some refactoring is called for so that we actually have an identifiable messaging facility in the engine. The current messages would then make use of it rather than creating their EventListenerTextWriters directly. Use of a EventListenerTextWriter would then be an implementation detail within the messaging facility.

[jnm2]

I would like to hear more details about the use case. If the communication should be dedicated to a specific engine, why not use remoting to talk cross-appdomain as usual? Why should NUnit's framework be involved?

[CharliePoole]

@jnm2 He described the use case in nunit/nunit#2908. I asked for a separate issue.

I'm not understanding your question exactly. NUnit does use remoting and the framework is already involved as the sender. To me, the decision is whether to tailor something for communicating general messages other than text output or to just let him piggyback on top of text output and suffer the consequence of too much output. IMO having a defined output stream that is not really output can only lead to confusion and a proliferation of string constants for special streams.

[jnm2]

Thanks, long week already! nunit/nunit#2908 (comment)

@CharliePoole Since the tests are executing in the same process as the engine extension but a different AppDomain, the first solution that occurs to me is to replace TestContext.Progress.WriteLine with
ReportPortalCustomization.Log which would be implemented to communicate cross-appdomain to the ReportPortalCustomization engine extension.

[CharliePoole]

@jnm2 Engine extensions run in the original process.

[jnm2]

@CharliePoole Ah, I'm sorry! That's the missing piece for me.

Re: #433 (comment)

1. Since this is about logging, it seems like there isn't a need for two-way communication. (What would it mean for there to be a synchronous version of TestContext.Progress.WriteLine, for example.)

2. Agree very much!

3. It would be nice to design the XML to leave open the possibility of future kinds of targets. Can you think of a use case for sending a message from your tests to more than one specific extension or one specific runner?

4. 👍

[CharliePoole]

@jnm2

1. Right, it doesn't make sense. I wanted to be sure to state that the existing mechanism is asynchronous. Two way synchronous communication would require a different channel, probably custom-built as a part of the extension, since the TestListener extension point is itself asynchronous.
2. Check
3. Current practice is that the engine and all listeners get all events and decide if which ones to handle. That will be easiest to implement since it's what we already do. IF a target wants a specific message, it can use a well-known name to recognize its own messages. Personally, I think this is adequate to the purpose, but again I wanted to spell it out. If the engine has to actually decide which extensions get which messages, that will be more complicated.
4. And double-check!

[jnm2]

Point 3 seems complex for the consumer (extension writer and test writer). What if an extension could open a channel with a chosen string ID and we did a simple filter?

[CharliePoole]

@jnm2 I could be missing the complexity you are finding here...

Test writer would not be using this as I understand it. Test writer does not want to "send a message to an extension" they want to do something like log information about the test. The framework extension they use would provide an API like CustomThingy.Log.

The extension writer would need to know more, obviously. CustomThingy.Log would make use of our messaging API, say TestExecutionContext.SendMessage. (We haven't designed this yet, of course) There would be a destination string arg to the message that indicated who it was for, maybe a key word, maybe a guid... depends on the extension author.

The engine extension would implement TestEventListener. It would get all events and only deal with the ones it cared about, just as now. In this case, it would care about the messaging event, which we have to define, rather than the text output event. It would look at the destination and decide if this message was intended for it. This is pretty much what we now do in looking for the text output event and checking the stream.

By letting everyone see every event, we have two advantages:

1. That's our current architecture, so we don't have to invent too much.
2. It's now possible to write a message tracing extension that tracks and logs all messages for debugging.

I think you are suggesting that we create some way that the message can only be received by a particular extension. That means each extension would need to register an identifier by which it can receive messages and the engine would have to keep track of them. It also means that these messages arrive out of sync with other events rather than in sequence. We would have to implement a communications protocol or create an equivalent to the event pump and queue to avoid context spillover. Possibly technically superior, but a ton more work it seems.

I think the main difference is that I'm seeing this as an internal API for extension writers and therefore able to be a bit more complex than the average test writing API. It would be the extender who writes the user API for their extension.

[jnm2]

@CharliePoole Good points. To keep each extension from having to reinvent parsing, what if we had two string parameters, channel and message? We would pass both everywhere, the same as if we had only message, so that avoids all registration and filtering. Each extension could then do a very cheap, very straightforward string comparison on channel.

[CharliePoole]

Yes, that's what I was trying to suggest (without spelling it out because I don't like to micro-manage what a contributor might do).

Compare to text output: parameter is "stream" which tells how the text should be handled. In this case, "dest" or "destination" would indicate the intended recipient. Key issue I see for the implementor to resolve is how we avoid collisions between independently developed extensions.

[jnm2]

@CharliePoole Why would collisions be a concern that NUnit should solve? I would think it would be like any other namespacing. (And any way to become aware of collisions would be by definition registration, right?)

[CharliePoole]

@jnm2 Good point. Maybe the solution to it is to ignore it. My view is that whoever takes this on should address the question. I dislike micro-managing or advance-planning what somebody else is going to do. I guess in my life I've had too many bosses who did that. 😸

[jnm2]

@CharliePoole Yes, I don't want to micromanage. Since we call for a design phase for each issue, sometimes leading to fully speccing and putting it up for grabs, what's a good rule of thumb?

[CharliePoole]

OK... if you have started to call for a design phase for each issue, etc. you should do that. I wasn't aware that was the new process.

My personal rule of thumb would be to specify as much as you feel you need to control and leave the execution up to the guy doing the work. That's why I keep talking about ideas, possibilities and suggestions for the person who takes this on, whether it's a team member or a contributor.

As I say, that's my personal rule of thumb. You guys are not operating that way and are somewhat tightening up on rules for coding, specification and code review. That may make me the wrong guy to ask about where to draw the line.

On the other hand, some kinds of things do need to be specified. In particular, if there are constraints as to what you will accept in a PR I think you should spell them out.

[jnm2]

I would have thought I learned it from you, in the context of which pipelines/labels are appropriate to use and when. But that makes good sense.
I've been wanting to put everything up for grabs because that scales better for us, and I've been holding back thinking that we needed a lot more detail to be specced in each issue.

[CharliePoole]

Like I say, I'm probably now the wrong guy to comment on this as I'm phasing out and you guys are moving in the direction you want to move. If you want everything to be up for grabs, then careful specification makes sense.

OTOH, what if the person who takes on the task is either part of the organization or a frequent, known contributor? If you have it all tightly speced out, then that may make them less likely to take on the issue but will leave it for a newby. I'm pretty sure I'd react that way.

It's tricky to figure out where to stop specifying and leave room for the programmer to be creative, no doubt about it.

[nvborisenko]

Hello everybody, any progress here?

[CharliePoole]

The @nunit/engine-team has neither accepted nor turned down this request. Guys?

[ChrisMaddock]

Sorry, busy time of year! The ideas above sounds sensible to me.

@jnm2 - you happy for this to be put up for grabs for someone to implement?

[jnm2]

@ChrisMaddock Yes.

[vitali-sonchyk-epam]

@ChrisMaddock do you have any updates regarding this issue?

[ChrisMaddock]

Looks like we decided this idea was ready for someone to pick up and implement. It now just needs a volunteer to do that. 🙂

[nvborisenko]

@ChrisMaddock any technical overview for contributors? Not sure what exact way you chose to implement it. I just proposed a very simple way in PR, I guess you are going to do something more generic.

[fjody]

So as I see, there isn't any good option for formatting or disallow-ing the nunit log in VisualStudio console.

These logs are always there:
{"Attach":null,"Level":0,"TestItemId":null,"Text":"2018-09-05 12:57:50,144 INFO UITestBase : SetupBase - Start browser...","Time":"\/Date(1536137870430+0200)\/"} {"Attach":{"Data":[137,,...many numbers, since its a picture ...,96,130],"MimeType":null,"Name":"GVC.png"},"Level":1,"TestItemId":null,"Text":"2018-09-05 12:57:55,909 CP ChatSteps : CheckChatPanelIsDisappeared - Check that Chat panel is disappeared","Time":"\/Date(1536137875909+0200)\/"} {"Attach":null,"Level":0,"TestItemId":null,"Text":"2018-09-05 12:57:55,946 INFO UITestBase : TearDownBase - Stop browser...","Time":"\/Date(1536137875946+0200)\/"}

So the concept is something like this from nunit:
{Attach...[Data:{MimeType,Name}]...Level...TestItemId...Text...Time}

[CharliePoole]

@fjody This repo is for the nunit-console project and the issue relates to running nunit3-console.exe. There is no connection to running in VS.

[ChrisMaddock]

@nvborisenko I'm sorry, this isn't an area of NUnit I'm familiar with.

@CharliePoole/@jnm2 - would either of you be able to provide more detail on a rough implementation guide that which would match what was discussed above, for @nvborisenko to pick up?

I'll remove the help wanted label while we figure things out.

[CharliePoole]

If I were doing this, I would model it after TextOutput, but I would not use TextOutput.

[Reasons for not using TextOutput:

1. TextOutput is for outputting text. Adding some special arg to text output to indicate it is not really text output confuses the API for the majority of users, merely to make this easy to implement.
2. Duplicating the logic in TextOutput in another class is a very small duplication and it may not remain a duplication as the feature evolves because the purpose of a feature is what drives (or should drive) change.]

Anyway, I would create the following pieces:

1. Define a new xml element to represent the message. I would have this reviewed by the team before implementing since it's the most important piece.

2. A way to create this message: probably a new constructor or a property of EventListenerTextWriter that specifies a different XML element to use.

3. A mechanism to send a message to a particular extension or other engine component. For example TestContext.SendMessage(string destination, string message);

Provided we are not handling the messages in the engine itself, but only in extensions, no more is needed. All NUnit components will ignore the new XML element.

Again... the first piece is the critical one and it will go easier if it's reviewed first as a design element. The rest can be handled through code review.

[nvborisenko]

Closing it, implemented as

TestContext.SendMessage(string destination, string message);

[jnm2]

Closed by nunit/nunit#3018. Thanks, Nikolay!