[TS_SELENIUM] Increase logging of tests steps

[Ohrimenko1988]

For now we have tests output which reports just for failed or passed tests and stack trace.

It will be helpful to have more information about processes which happen in the tests. It will simplify debugging and searching a root reason in the case of failure.
Also it will give relevant information for the person who launches tests locally, because it will show what test doing at that moment.

[Ohrimenko1988]

First of all, let's decide WHAT we should have. After that, we may decide HOW we will do that.
I suggest having something like that:

Logs marked by " -->" and " ---->" should be spread to different layers and handled by environment variables, besides I suppose to have separated "log.txt" file with full log output.

[dmytro-ndp]

That logs look better. And currently there are primarily substeps need to be logged, to make it possible to localize particular failing operation:

        await driverHelper.navigateToUrl(workspaceUrl);
        await loginPage.login();

In the logs substeps might have high-level clear description like:

       ✓ Open workspace (2183ms)
         ➤ go to <workspaceUrl>
         ➤ login

       ✓ Wait workspace running state (67998ms)
...

And it would be nice to write implementation specific info like DriverHelper.waitVisibility(... into dedicated file. An example of such approach http://www.sulhome.com/blog/9/restify-project-seed-with-typescript-and-unit-test.
https://www.npmjs.com/package/log4js could be used to log into the file.

[Ohrimenko1988]

@dmytro-ndp
Here I mentioned that we should write a full log to the dedicated file.
#13686 (comment)

Also I am -1 for using something like "got to workspaceUrl" and etc instead of methods name because it will complicate debugging

But also I agree that your marks look better

[rhopp]

I was thinking we could implement something like four basic levels.
ERROR - for loging errors.
INFO - (default level) - This would print what we have now - suite and test names + duration...
DEBUG - something like "functional" level - logs on this level would be describing >what< is the test doing without any excessive boilerplate (like specific selectors etc. - kind of what Dmytro is suggesting in his comment).
TRACE - this is the finest level - here should be all the waits, clicks, and lowest level operation with all the selectors etc.

When executing tests, one should be able to select which logging level he want (by env var?).

Maybe a plus would be, if the log messages were prepended by filename & method name from where they were called, but I have no idea how easy/complicated that would be.

[Ohrimenko1988]

@rhopp @dmytro-ndp
I have implemented some changes and output looks like:

DEBUG

TRACE

What do you think about this?

[Ohrimenko1988]

What about adding xpath to the "DEBUG" level ?
For example:
ProjectTree.expandItem <xpath> instead of ProjectTree.expandItem
And some additional information to other methods?

[rhopp]

I would say, that as a general rule of thumb, on the debug level I would like to know "What's happening", on the trace level I would like to know "how exactly is it happening". So - I would put selector to "debug" only in some certain cases, where it really matters (and the selector is not very long, etc.)

[Ohrimenko1988]

@rhopp
What about this version?

[dmytro-ndp]

@Ohrimenko1988: newer variant mush closer to what was asked here.
Could this approach be spread to other methods like:

- Ide.waitRightToolbarButtonSelection "Login"
- Ide.waitAndClickRightToolbarButton "Login"
...

[Ohrimenko1988]

@dmytro-ndp Of course, this is just a draft

[rhopp]

Nice ;-) I like that ;-)

[Ohrimenko1988]

Done