__WD_Error() minimizing the amount of messages #290

mlipok · 2022-04-10T23:52:58Z

Pull request

Proposed changes

Describe the big picture of your changes here to communicate to the maintainers why we should accept this pull request.

Please ensure you have read and noticed the checklist below.

Checklist

Put an x in the boxes that apply. If you're unsure about any of them, don't hesitate to ask. We are here to help!

This is simply a reminder of what we are going to look for before merging your code.

I have read and noticed the CODE OF CONDUCT document
I have read and noticed the CONTRIBUTING document
I have added necessary documentation or screenshots (if appropriate)

Types of changes

Please check x the type of change your PR introduces:

Bugfix (change which fixes an issue)
Feature (change which adds functionality)
Code style update (formatting, renaming)
Refactoring (functional, structural)
Documentation content changes
Other (please describe)

What is the current behavior?

Currently UDF throws to many messages to console.

Very often they are duplicated.
for example $sResponseText is showed by __WD_Delete and _WD_DeleteSession

according to the ENUMS order:

Global Enum _
		$_WD_DEBUG_None = 0, _ ; No logging to console
		$_WD_DEBUG_Error, _    ; logging to console in case of Error
		$_WD_DEBUG_Info, _     ; logging to console with additional information
		$_WD_DEBUG_Full        ; logging to console with information for developers of WebDriver UDF

$_WD_DEBUG_Error should show less information than $_WD_DEBUG_Info .

But currently $_WD_DEBUG_Info shows only URL

	__WD_ConsoleWrite($sFuncName & ": URL=" & $sURL, $_WD_DEBUG_Info)

which means that $_WD_DEBUG_Info shows less information than $_WD_DEBUG_Error which shows entire $sResponseText

	Local $sMessage = (($sResponseText) ? ("ResponseText=" & StringLeft($sResponseText, $_WD_RESPONSE_TRIM) & "...") : (""))
	Return SetError(__WD_Error($sFuncName, $iResult, $sMessage), 0, $sResponseText)

What is the new behavior?

More user friendly information in case of $_WD_DEBUG_Error

	Return SetError(__WD_Error($sFuncName, $iResult, "Error occurs with URL=" & $sURL), 0,

More detailed information in case of $_WD_DEBUG_Info or $_WD_DEBUG_Full

	Local $sMessage = (($sResponseText) ? (" ResponseText=" & StringLeft($sResponseText, $_WD_RESPONSE_TRIM) & "...") : (""))
	__WD_ConsoleWrite($sFuncName & $sMessage, $_WD_DEBUG_Info)

Not duplicated $sResponseText in console.

Additional context

The debug flag may be helpful, but in all honesty it’s so verbose that whenever I’ve tried to look at it, it’s been like trying to find a needle in a haystack and I’m not familiar with the output so I don’t even know what the needle looks like…

System under test

Not related

Remarks:
This is only a modest begining of PR.
If you agree this direction of changes, then entire UDF should be reviewed in the same way.

mlipok · 2022-04-11T08:18:22Z

Waiting on your comments

Danp2 · 2022-04-11T16:03:04Z

$_WD_DEBUG_Error should show less information than $_WD_DEBUG_Info

Please provide a short code snippet that demonstrates the behavior you describe.

mlipok · 2022-04-11T22:08:35Z

#include "z:\!!!_SVN_AU3\UDF_Forum\Other_Members\Official_AutoIt_Forum\WebDriver\____ORG_VESION\wd_helper.au3 "
;~ #include "..\wd_helper.au3"

$_WD_DEBUG = $_WD_DEBUG_Full
_WD_DeleteSession("")


+CURRENT:
>"Z:\AutoItPortable\App\SciTE\..\AutoIt3.exe" "Z:\!!!_SVN_AU3\UDF_Forum\Other_Members\Official_AutoIt_Forum\WebDriver\Testing\wd_capabilities_TESTING_DeleteSession.au3" /ErrorStdOut /UserParams    
__WD_Delete: URL=HTTP://127.0.0.1:0/session/
__WD_Delete ==> Send / Recv error (6) : ResponseText=WinHTTP request timed out before Webdriver...
_WD_DeleteSession ==> Webdriver Exception (10) : WinHTTP request timed out before Webdriver
>Exit code: 0    Time: 2.464

+NEW PROPOSAL
>"Z:\AutoItPortable\App\SciTE\..\AutoIt3.exe" "Z:\!!!_SVN_AU3\UDF_Forum\Other_Members\Official_AutoIt_Forum\WebDriver\Testing\wd_capabilities_TESTING_DeleteSession.au3" /ErrorStdOut /UserParams    
__WD_Delete ResponseText=WinHTTP request timed out before Webdriver...
__WD_Delete ==> Send / Recv error (6) : Error occurs with URL=HTTP://127.0.0.1:0/session/
_WD_DeleteSession ==> Webdriver Exception (10) : Error occurs when trying to delete session
>Exit code: 0    Time: 2.472

The current version twicely says WinHTTP request timed out before Webdriver

The main idea is to only __WD_Post and __WD_Get and __WD_Delete should show ResponseText with __WD_Error

All other function should'nt do that.

mlipok · 2022-04-11T22:12:35Z

What is strange to me is that:

__WD_Delete() trims the $sResponseText

_WD_DeleteSession() shows entire $sResponse

Danp2 · 2022-04-11T22:25:02Z

$_WD_DEBUG_Error should show less information than $_WD_DEBUG_Info

Please provide a short code snippet that demonstrates the behavior you describe.

I thought this was a pretty simple request, but the code you posted doesn't fulfill it.

Danp2 · 2022-04-11T22:32:21Z

What is strange to me is that: __WD_Delete() trims the $sResponseText
_WD_DeleteSession() shows entire $sResponse

As you are probably already aware, _WD_Option('debugtrim') can be used to adjust the trim length. This feature wasn't always implemented, so there are some commands that could be retrofitted to trim down the response.

mlipok · 2022-04-11T22:33:43Z

Trim feature is good.
I'm only wondering why this is not consistent behavior.

mlipok · 2022-04-11T23:23:42Z

$_WD_DEBUG_Error should show less information than $_WD_DEBUG_Info

Please provide a short code snippet that demonstrates the behavior you describe.

I thought this was a pretty simple request, but the code you posted doesn't fulfill it.

I see your point.
It relates how long response text will be, and which WebDriver you use.

I have done some work in background.
Will back with this soon.

mlipok · 2022-04-12T00:01:14Z

as for now using DemoElements from wd_demo.au3
I have this kind of result:

__WD_Get: URL=HTTP://127.0.0.1:4444/session/8108e3ad-4c93-4edc-affa-dd3742c7e36d/element/7c4c3d46-04ca-4803-a643-ae8fb937df6a/property/value
__WD_Get ==> Success (0) HTTP status = 200 : ResponseText={"value":""}...
_WD_ElementAction ==> Success (0) HTTP status = 200 : 	$sCommand=property	$sOption=value

__WD_Post: URL=HTTP://127.0.0.1:4444/session/8108e3ad-4c93-4edc-affa-dd3742c7e36d/element/7c4c3d46-04ca-4803-a643-ae8fb937df6a/clear; $sData={"id":"7c4c3d46-04ca-4803-a643-ae8fb937df6a"}
__WD_Post ==> Success (0) HTTP status = 200 : ResponseText={"value":null}...
_WD_ElementAction ==> Success (0) HTTP status = 200 : 	$sCommand=clear	$sOption=

__WD_Post: URL=HTTP://127.0.0.1:4444/session/8108e3ad-4c93-4edc-affa-dd3742c7e36d/element/7c4c3d46-04ca-4803-a643-ae8fb937df6a/value; $sData={"id":"7c4c3d46-04ca-4803-a643-ae8fb937df6a", "text":"abc xyz"}
__WD_Post ==> Element interaction issue (14) HTTP status = 400 : ResponseText={"value":{"error":"element not interactable","message":"Element <input class=\"gLFyf gsfi\" name=\"q...
_WD_ElementAction ==> Element interaction issue (14) HTTP status = 400 : 	$sCommand=value	$sOption=abc xyz

__WD_Get: URL=HTTP://127.0.0.1:4444/session/8108e3ad-4c93-4edc-affa-dd3742c7e36d/element/7c4c3d46-04ca-4803-a643-ae8fb937df6a/property/value
__WD_Get ==> Success (0) HTTP status = 200 : ResponseText={"value":""}...
_WD_ElementAction ==> Success (0) HTTP status = 200 : 	$sCommand=property	$sOption=value

ResponeText is not duplicated any more.
Additionall NEW LINE is before __WD_Post , __WD_Get and __WD_Delete

Danp2 · 2022-04-13T14:13:38Z

I'm having some issues with the PR --

You've made a statement that I've asked you to substantiate, but you haven't done so thus far. Please either acknowledge that the statement was incorrect or show proof that it was accurate.
The proposed changes don't match the topic in my opinion. You have suggested changes to the displayed messages, but I don't see anything that would represent "minimizing the amount of messages". I was expecting the PR to reduce the amount of messages since the very first issue listed under Current Behavior was "Currently UDF throws to many messages to console.".
Your proposed changes to _WD_DeleteSession have resulted in the incorrect value being returned on Success

I will follow this up with a separate post outlining some alternative solutions.

mlipok · 2022-04-13T14:34:26Z

give me some time to answer.... work in progress in background.....

mlipok · 2022-04-13T21:53:20Z

Today I get

__WD_Post ==> No alert present (12) HTTP status = 404 : ResponseText={"value":{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/...
_WD_Alert ==> No alert present (12) HTTP status = 404 : {"value":{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm:183:5\nNoSuchAlertError@chrome://remote/content/shared/webdriver/Errors.jsm:384:5\nGeckoDriver.prototype._checkIfAlertIsPresent@chrome://remote/content/marionette/driver.js:2575:11\nGeckoDriver.prototype.acceptDialog@chrome://remote/content/marionette/driver.js:2498:8\ndespatch@chrome://remote/content/marionette/server.js:306:40\nexecute@chrome://remote/content/marionette/server.js:279:16\nonPacket/<@chrome://remote/content/marionette/server.js:252:20\nonPacket@chrome://remote/content/marionette/server.js:253:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.js:500:20\n"}}

It was disscussed here: #254 (comment)

in my opinion it should looks like:

__WD_Post ==> No alert present (12) HTTP status = 404 : Full ResponseText={"value":{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/shared/webdriver/Errors.jsm:183:5\nNoSuchAlertError@chrome://remote/content/shared/webdriver/Errors.jsm:384:5\nGeckoDriver.prototype._checkIfAlertIsPresent@chrome://remote/content/marionette/driver.js:2575:11\nGeckoDriver.prototype.acceptDialog@chrome://remote/content/marionette/driver.js:2498:8\ndespatch@chrome://remote/content/marionette/server.js:306:40\nexecute@chrome://remote/content/marionette/server.js:279:16\nonPacket/<@chrome://remote/content/marionette/server.js:252:20\nonPacket@chrome://remote/content/marionette/server.js:253:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.js:500:20\n"}}
_WD_Alert ==> No alert present (12) HTTP status = 404 : Trimmed ResponseText={"value":{"error":"no such alert","message":"","stacktrace":"WebDriverError@chrome://remote/content/...

And in case of success:

__WD_Post ==> Success (0) HTTP status = 200 : 
_WD_Alert ==> Success (0) HTTP status = 200 :

Who matters about RESPONSE text in LOG when Success was taken ?
If somebody cares then he should put it to LOG on his own.

mlipok · 2022-04-13T22:21:14Z

Who matters about RESPONSE text in LOG when Success was taken ?
If somebody cares then he should put it to LOG on his own.

I would like to propose such changes:

	Local $sMessage = (($iResult Or $_WD_DEBUG > $_WD_DEBUG_Info) ? ("Full ResponseText=" & StringLeft($sResponseText, $_WD_RESPONSE_TRIM)) : (""))
	Return SetError(__WD_Error($sFuncName, $iResult, $sMessage), 0, $sResponseText)
EndFunc   ;==>__WD_Post

the same for __WD_Delete and __WD_Get
just testing it.

mlipok · 2022-04-15T10:38:28Z

I merge to current realase, because I will post my current changes, and do not want to duplicate already accpeted changes in comparition modes.

wd_core.au3

mlipok · 2022-04-15T13:27:31Z

$_WD_DEBUG_Error should show less information than $_WD_DEBUG_Info

Please provide a short code snippet that demonstrates the behavior you describe.

Using currently commited version, with this example:

;~ #include "z:\!!!_SVN_AU3\UDF_Forum\Other_Members\Official_AutoIt_Forum\WebDriver\____ORG_VESION\wd_helper.au3"
#include "wd_helper.au3"

ConsoleWrite("> TEST 1" & @CRLF)
$_WD_DEBUG = $_WD_DEBUG_Info
_WD_DeleteSession("")

ConsoleWrite("> TEST 2" & @CRLF)
$_WD_DEBUG = $_WD_DEBUG_Full
_WD_DeleteSession("")

I get this:

> TEST 1
__WD_Delete: URL=HTTP://127.0.0.1:0/session/
__WD_Delete ==> Send / Recv error (6)
_WD_DeleteSession ==> Webdriver Exception (10) : Error occurs when trying to delete session
> TEST 2
__WD_Delete: URL=HTTP://127.0.0.1:0/session/
__WD_Delete ==> Send / Recv error (6) : ResponseText=WinHTTP request timed out before Webdriver
_WD_DeleteSession ==> Webdriver Exception (10) : Error occurs when trying to delete session

Danp2 · 2022-04-15T13:49:05Z

Using currently commited version

You'll need to be more specific as to which source code you mean. Your original statement was made before the changes in this PR, so I ran the code from master branch, which gave this output --

> TEST 1
__WD_Delete: URL=HTTP://127.0.0.1:0/session/
__WD_Delete ==> Send / Recv error (6) : ResponseText=WinHTTP request timed out before Webdriver...
_WD_DeleteSession ==> Webdriver Exception (10) : WinHTTP request timed out before Webdriver
> TEST 2
__WD_Delete: URL=HTTP://127.0.0.1:0/session/
__WD_Delete ==> Send / Recv error (6) : ResponseText=WinHTTP request timed out before Webdriver...
_WD_DeleteSession ==> Webdriver Exception (10) : WinHTTP request timed out before Webdriver

mlipok · 2022-04-15T17:00:52Z

Currently commited in this PR

Danp2 · 2022-04-15T17:30:19Z

Currently commited in this PR

Ok, But then I'm not understanding that the code is supposed to be demonstrating. Please explain what is should be looking for or what isn't functioning properly in your opinion.

mlipok · 2022-04-15T20:35:44Z

You was asking here: #290 (comment)

$_WD_DEBUG_Error should show less information than $_WD_DEBUG_Info

Please provide a short code snippet that demonstrates the behavior you describe.

So I created such example using updated version from this PR.

This version also follows the rules which was defined here: #280 (comment)

So you can use wd_demo.au3 from my branch related to this PR to check if it works as it was defined in the link I mention before.
And also to check if it fit to your requirements.

wd_core.au3

Tidy moving this comments to fit indentation. To avoid thi I move them manually w lines below, and remove the work "check" as it is now after `If... Then`

mlipok · 2022-06-20T20:23:01Z

@Danp2 I'm waiting on yours opinion here.

full logging isn't enabled

mlipok · 2022-06-24T20:45:55Z

Nice mod

wd_core.au3

wd_helper.au3

Danp2

Why didn't you perform the updates to $_WD_DEBUG outside of the While loop? That would also eliminate the logging associated with _WD_ExecuteScript.

mlipok · 2022-07-02T10:38:21Z

Why didn't you perform the updates to $_WD_DEBUG outside of the While loop? That would also eliminate the logging associated with _WD_ExecuteScript.

Thanks. Good point.

Please take a look on:
_WD_LoadWait Prevent logging part 2

mlipok · 2022-07-03T12:37:31Z

Hope next few days we will be able to finally merge this PR as it takes us almost 3 months.

Danp2 · 2022-07-03T13:20:29Z

This recent blog post is worth reading and could help with producing more manageable PRs. 😉

__WD_Error() minimizing the number of messages

60a699c

mlipok changed the title ~~__WD_Error() minimizing the number of messages~~ __WD_Error() minimizing the amount of messages Apr 10, 2022

mlipok added 2 commits April 11, 2022 02:03

small changes

06c2c55

further refactor

8212d19

Danp2 mentioned this pull request Apr 11, 2022

wd_capabilities.au3 - TODO better error handling #105

Closed

Danp2 mentioned this pull request Apr 13, 2022

__WD_ConsoleWrite() $_WD_DEBUG_Full + $sMsg #291

Closed

9 tasks

Danp2 mentioned this pull request Apr 14, 2022

message written to a log + error codes, HTTP status, etc. #280

Closed

Merge branch 'Danp2:master' into patch-6

916d558

mlipok added 2 commits April 15, 2022 12:44

core: __WD_Error() usage reviewed

42a360d

_WD_DeleteSession small refactor

38ce051

mlipok commented Apr 15, 2022

View reviewed changes

wd_core.au3 Show resolved Hide resolved

mlipok and others added 5 commits June 6, 2022 00:09

_WD_WaitElement() should exits on error

2a6080d

prevent multiple errors from _WD_FindElement()

b1cfd23

_WD_WaitElement - $_WD_DEBUG_Full and $sParameters

7d532fa

WD_ElementAction - $bParameters_Option

cfb9821

Update header / revise comments

bb8a23a

Danp2 reviewed Jun 11, 2022

View reviewed changes

wd_core.au3 Outdated Show resolved Hide resolved

mlipok added 2 commits June 12, 2022 22:25

_WD_Navigate #forceref removal

91dd97a

comments moved because of tidy

f5671d5

Tidy moving this comments to fit indentation. To avoid thi I move them manually w lines below, and remove the work "check" as it is now after `If... Then`

mlipok requested a review from Danp2 June 20, 2022 20:23

Danp2 added 2 commits June 24, 2022 14:31

Parameter logging for _WD_Action, _WD_Window

74986cd

_WD_ElementAction: Mask option param when

f78e30d

full logging isn't enabled

mlipok commented Jun 24, 2022

View reviewed changes

wd_core.au3 Show resolved Hide resolved

Danp2 and others added 3 commits June 25, 2022 09:02

Refactor _WD_Attach

9da3264

Improve logging

ec5a3cf

_WD_LoadWait...

c581e7f

mlipok commented Jun 28, 2022

View reviewed changes

wd_helper.au3 Outdated Show resolved Hide resolved

_WD_LoadWait prevent multiple errors

2c552e5

Danp2 reviewed Jul 2, 2022

View reviewed changes

_WD_LoadWait Prevent logging part 2

7d2283d

Danp2 added 2 commits July 4, 2022 11:12

_WD_Navigate: Log parameters

0feeadf

formatting

ae2f083

Danp2 approved these changes Jul 4, 2022

View reviewed changes

Danp2 merged commit 839859e into Danp2:master Jul 5, 2022

mlipok deleted the patch-6 branch July 5, 2022 14:30

mlipok mentioned this pull request Jul 21, 2022

GDPR (law act) better accordance #326

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

__WD_Error() minimizing the amount of messages #290

__WD_Error() minimizing the amount of messages #290

mlipok commented Apr 10, 2022 •

edited

Loading

mlipok commented Apr 11, 2022

Danp2 commented Apr 11, 2022

mlipok commented Apr 11, 2022

mlipok commented Apr 11, 2022 •

edited

Loading

Danp2 commented Apr 11, 2022

Danp2 commented Apr 11, 2022

mlipok commented Apr 11, 2022

mlipok commented Apr 11, 2022

mlipok commented Apr 12, 2022 •

edited

Loading

Danp2 commented Apr 13, 2022

mlipok commented Apr 13, 2022

mlipok commented Apr 13, 2022 •

edited

Loading

mlipok commented Apr 13, 2022 •

edited

Loading

mlipok commented Apr 15, 2022 •

edited

Loading

mlipok commented Apr 15, 2022 •

edited

Loading

Danp2 commented Apr 15, 2022

mlipok commented Apr 15, 2022

Danp2 commented Apr 15, 2022

mlipok commented Apr 15, 2022

mlipok commented Jun 20, 2022

mlipok commented Jun 24, 2022

Danp2 left a comment

mlipok commented Jul 2, 2022 •

edited

Loading

mlipok commented Jul 3, 2022

Danp2 commented Jul 3, 2022

__WD_Error() minimizing the amount of messages #290

__WD_Error() minimizing the amount of messages #290

Conversation

mlipok commented Apr 10, 2022 • edited Loading

Pull request

Proposed changes

Checklist

Types of changes

What is the current behavior?

What is the new behavior?

Additional context

System under test

mlipok commented Apr 11, 2022

Danp2 commented Apr 11, 2022

mlipok commented Apr 11, 2022

mlipok commented Apr 11, 2022 • edited Loading

Danp2 commented Apr 11, 2022

Danp2 commented Apr 11, 2022

mlipok commented Apr 11, 2022

mlipok commented Apr 11, 2022

mlipok commented Apr 12, 2022 • edited Loading

Danp2 commented Apr 13, 2022

mlipok commented Apr 13, 2022

mlipok commented Apr 13, 2022 • edited Loading

mlipok commented Apr 13, 2022 • edited Loading

mlipok commented Apr 15, 2022 • edited Loading

mlipok commented Apr 15, 2022 • edited Loading

Danp2 commented Apr 15, 2022

mlipok commented Apr 15, 2022

Danp2 commented Apr 15, 2022

mlipok commented Apr 15, 2022

mlipok commented Jun 20, 2022

mlipok commented Jun 24, 2022

Danp2 left a comment

Choose a reason for hiding this comment

mlipok commented Jul 2, 2022 • edited Loading

mlipok commented Jul 3, 2022

Danp2 commented Jul 3, 2022

mlipok commented Apr 10, 2022 •

edited

Loading

mlipok commented Apr 11, 2022 •

edited

Loading

mlipok commented Apr 12, 2022 •

edited

Loading

mlipok commented Apr 13, 2022 •

edited

Loading

mlipok commented Apr 13, 2022 •

edited

Loading

mlipok commented Apr 15, 2022 •

edited

Loading

mlipok commented Apr 15, 2022 •

edited

Loading

mlipok commented Jul 2, 2022 •

edited

Loading