Suppressing "Unable to find element located by..." log message

kyilmaz · March 18, 2020, 5:31pm

Hi everyone,

Is there any way to suppress the warnings logged by Katalon when an element isn’t found? FailureHandling.OPTIONAL still logs warnings. For example:

if (WebUI.verifyElementPresent(element, timeOut, FailureHandling.OPTIONAL) {
    elementFoundHandler()
} else {
    elementAbsentHandler()
}

If “element” is not found, I’ll get a log readout like:

Unable to find the element located by ‘By.xpath: //span[@class=“element-xpath”]’. Please recheck the objects properties to make sure the desired element is located.

Is there a way to suppress these readouts, or check for elements? The message makes it seem like there is an error, even if an absent element is acceptable.

Russ_Thomas · March 18, 2020, 4:40pm

OPTIONAL logs warnings, not errors. I don’t see any issue with the code you proposed. Can you show me the “errors” you’re seeing?

kyilmaz · March 18, 2020, 5:30pm

Hi Russ, apologies for the terminology. I was trying to say that it looks like an error, but you are correct that it is indeed a warning. The “error” was the warning posted above. I’ve fixed it in the OP.

For me, it would be useful to be able to check for an element, then perform a whatever logic without warnings logged. The warnings can make our logs harder more verbose and harder to comb through.

Would it be possible to have something like FailureHandling.NONE, or is there another workaround for suppressing any logs from KeywordMain.stepFailed() (or one to avoid stepFailed() altogether)?

Russ_Thomas · March 18, 2020, 6:18pm

Yes there is, but it’s not exactly Go here, open this, set x to y and you’re good to go.

Firstly, you need to seize control away from the Katalon WebUI APIs that you want to prevent from cluttering your reports. There are two ways I know to do that:

Use metaprogramming to alter the way those WebUI methods work. @kazurayam might be able to help here.
Don’t use those APIs and write your own. This is what I do.

Both of the above techniques involve writing code in new Groovy classes/methods which you can control yourself.

If those answers don’t sound like your kind of solution, then you could try wrapping the code in a try-catch block (but I think the warning may still get through - not sure, never tried it).

kazurayam · March 18, 2020, 10:03pm

You can read the source of WebUI.verifyElementPresent() at

github.com

katalon-studio/katalon-studio-testing-framework/blob/master/Include/scripts/groovy/com/kms/katalon/core/webui/keyword/builtin/VerifyElementPresentKeyword.groovy

package com.kms.katalon.core.webui.keyword.builtin

import groovy.transform.CompileStatic

import java.text.MessageFormat
import java.util.concurrent.TimeUnit

import org.apache.commons.io.FileUtils
import org.openqa.selenium.Alert
import org.openqa.selenium.By
import org.openqa.selenium.Dimension
import org.openqa.selenium.JavascriptExecutor
import org.openqa.selenium.NoSuchElementException
import org.openqa.selenium.NoSuchWindowException
import org.openqa.selenium.TimeoutException
import org.openqa.selenium.WebDriver
import org.openqa.selenium.WebDriverException
import org.openqa.selenium.WebElement
import org.openqa.selenium.interactions.Actions
import org.openqa.selenium.support.ui.ExpectedCondition

This file has been truncated. show original

though the version of this source is unstated, could be old one.

At line #80:

    foundElement = WebUIAbstractKeyword.findWebElement(to, timeOut)
    if (foundElement != null) {
        logger.logPassed(MessageFormat.format(
            StringConstants.KW_LOG_PASSED_OBJ_X_IS_PRESENT, to.getObjectId()))
    }

@kyilmaz wants to erase (or comment out) this line of logger.logPasses(Message....).

I agree with the 2 options that @Russ_Thomas suggested.

kazurayam · March 19, 2020, 1:44am

The 3rd option to try:

You can also lessen the logs details by using INFO level.

or you can even more lessen the logs details by using ERROR level.

kyilmaz · March 20, 2020, 2:45pm

Hi all,

Sorry for the delayed reponse, and I really appreciate your answers and help . I would love to make our own API, but I’m not sure the team would want to deal with the refactoring haha.

I can look into the metaprogramming (not sure what that is yet)

The logging level also helps a lot! I didn’t know that configuration existed.

Thanks for all of the suggestions!

kyilmaz · March 31, 2020, 9:37pm

Hi @kazurayam

Sorry to necro the thread, but I’ve decided to make my own API like you guys suggested. And I may need some more help. Your suggestion below only changes the log if the web element is found.

At line #80:
    foundElement = WebUIAbstractKeyword.findWebElement(to, timeOut)
    if (foundElement != null) {
        logger.logPassed(MessageFormat.format(
            StringConstants.KW_LOG_PASSED_OBJ_X_IS_PRESENT, to.getObjectId()))
    }
@kyilmaz wants to erase (or comment out) this line of logger.logPasses(Message....) .

I agree with the 2 options that @Russ_Thomas suggested.

After narrowing it down, I have found that the warning lies within WebUiCommonHelper.findWebElement(), which then implements findWebElements(), which is a huge amount of code to port and change. (FindWebElements is in this same file)

github.com

katalon-studio/katalon-studio-testing-framework/blob/aec97e9b5ffb371676c205596ec2e54e7998528c/Include/scripts/groovy/com/kms/katalon/core/webui/common/WebUiCommonHelper.java#L1102-L1115


public static WebElement findWebElement(TestObject testObject, int timeOut) throws WebElementNotFoundException {
    WebElement cachedWebElement = testObject.getCachedWebElement();
    if (cachedWebElement != null) {
        logger.logDebug("Using cached web element");
        return cachedWebElement;
    }
    logger.logDebug("Finding web element from Test Object's properties");
    List<WebElement> elements = findWebElements(testObject, timeOut);
    if (elements != null && elements.size() > 0) {
        return elements.get(0);
    } else {
        throw new WebElementNotFoundException(testObject.getObjectId(), buildLocator(testObject));
    }
}

I feel like since I’m going that deep, I might as well just use webdriver (as that’s what I’ll be porting anyway).

@Russ_Thomas
Did you do anything different in your custom API?

Russ_Thomas · March 31, 2020, 10:39pm

Very much so. After coding tests for a few months I took a step back and asked the question, why am I messing about with Test Objects, Object Repo’s and a bunch of XPath when I know the WWW is built on HTML, JavaScript and CSS? You can probably guess where this is heading…

So I wrote my own API in Groovy/JS.

This is not a solution for everyone, obviously, but it alleviates a lot of the “worries” about “what exactly is api X doing here?” because I wrote the API.

Example: all of my “wait” logic is groovy loops that call out to browser JavaScript to test for DOM presence/visibility etc.

kazurayam · April 1, 2020, 9:39am

I have made and published a demo project on GitHub:

https://github.com/kazurayam/SuppressingUnableToFindElementLocatedByLogMessage

Problem to solve

When you run Test Cases/TC2, you will see the following messages in the Console:

2020-04-01 10:55:28.585 DEBUG fyElementPresent failed to find a button - 2: navigateToUrl("https://katalon-demo-cura.herokuapp.com/")
2020-04-01 10:55:32.748 DEBUG fyElementPresent failed to find a button - 3: verifyElementPresent(findTestObject("Object Repository/Page_CURA Healthcare Service/a_no_such_button"), 5, OPTIONAL)
2020-04-01 10:55:40.701 WARN  c.k.k.core.keyword.internal.KeywordMain  - com.kms.katalon.core.webui.exception.WebElementNotFoundException: Web element with id: 'Object Repository/Page_CURA Healthcare Service/a_no_such_button' located by 'By.xpath: id("btn-no-such-button")' not found (Root cause: com.kms.katalon.core.exception.StepFailedException: com.kms.katalon.core.webui.exception.WebElementNotFoundException: Web element with id: 'Object Repository/Page_CURA Healthcare Service/a_no_such_button' located by 'By.xpath: id("btn-no-such-button")' not found
	at com.kms.katalon.core.webui.keyword.internal.WebUIKeywordMain.stepFailed(WebUIKeywordMain.groovy:64)
	at com.kms.katalon.core.webui.keyword.builtin.VerifyElementPresentKeyword$_verifyElementPresent_closure1.doCall(VerifyElementPresentKeyword.groovy:85)
	at com.kms.katalon.core.webui.keyword.builtin.VerifyElementPresentKeyword$_verifyElementPresent_closure1.call(VerifyElementPresentKeyword.groovy)
	at com.kms.katalon.core.webui.keyword.internal.WebUIKeywordMain.runKeyword(WebUIKeywordMain.groovy:20)
	at com.kms.katalon.core.webui.keyword.builtin.VerifyElementPresentKeyword.verifyElementPresent(VerifyElementPresentKeyword.groovy:92)
	at com.kms.katalon.core.webui.keyword.builtin.VerifyElementPresentKeyword.execute(VerifyElementPresentKeyword.groovy:68)
	at com.kms.katalon.core.keyword.internal.KeywordExecutor.executeKeywordForPlatform(KeywordExecutor.groovy:72)
	at com.kms.katalon.core.webui.keyword.WebUiBuiltInKeywords.verifyElementPresent(WebUiBuiltInKeywords.groovy:1418)
	at com.kms.katalon.core.webui.keyword.WebUiBuiltInKeywords$verifyElementPresent$1.call(Unknown Source)
	at TC2 verifyElementPresent failed to find a button.run(TC2 verifyElementPresent failed to find a button:11)
	at com.kms.katalon.core.main.ScriptEngine.run(ScriptEngine.java:194)
	at com.kms.katalon.core.main.ScriptEngine.runScriptAsRawText(ScriptEngine.java:119)
	at com.kms.katalon.core.main.TestCaseExecutor.runScript(TestCaseExecutor.java:337)
	at com.kms.katalon.core.main.TestCaseExecutor.doExecute(TestCaseExecutor.java:328)
	at com.kms.katalon.core.main.TestCaseExecutor.processExecutionPhase(TestCaseExecutor.java:307)
	at com.kms.katalon.core.main.TestCaseExecutor.accessMainPhase(TestCaseExecutor.java:299)
	at com.kms.katalon.core.main.TestCaseExecutor.execute(TestCaseExecutor.java:233)
	at com.kms.katalon.core.main.TestCaseMain.runTestCase(TestCaseMain.java:114)
	at com.kms.katalon.core.main.TestCaseMain.runTestCase(TestCaseMain.java:105)
	at com.kms.katalon.core.main.TestCaseMain$runTestCase$0.call(Unknown Source)
	at TempTestCase1585706119073.run(TempTestCase1585706119073.groovy:23)
)
2020-04-01 10:55:40.771 DEBUG fyElementPresent failed to find a button - 4: closeBrowser()
2020-04-01 10:55:41.006 INFO  c.k.katalon.core.main.TestCaseExecutor   - END Test Cases/TC2 verifyElementPresent failed to find a button

The originator of the forum discussion wants to suppress this warnings because he can accept element’s absense.

Solution

As described in View and Customize Execution Log / Logs configuration in Katalon Document, by editing Include/config/log.properties file, you can configure the log level for Katalon classes. You can make Katalon classes less verbose.

Description

Demo

Try running Test Cases/TC3. You will see following far-less verbose message in the Console.

2020-04-01 11:11:13.961 DEBUG g level is tuned to make it less verbose - 2: navigateToUrl("https://katalon-demo-cura.herokuapp.com/")
2020-04-01 11:11:18.176 DEBUG g level is tuned to make it less verbose - 3: waitForElementPresent(findTestObject("Object Repository/Page_CURA Healthcare Service/a_no_such_button"), 5, OPTIONAL)
2020-04-01 11:11:23.573 DEBUG g level is tuned to make it less verbose - 4: closeBrowser()

Please find Include/config/log.properties. In there I added 2 lines to configure log level of Katalon classes.

logging.level.com.kms.katalon.core.webui.common.WebUiCommonHelper=WARN
logging.level.com.kms.katalon.core.webui.keyword.builtin.WaitForElementPresentKeyword=ERROR

These 2 lines drastically changed the verbosity of the console messages.

But how to write log.properties? Which FQDN to be tuned?

Try commenting out the 2 lines in the log.properties file, and run TC3. You will see the following noisy message:

2020-04-01 11:17:04.215 DEBUG g level is tuned to make it less verbose - 2: navigateToUrl("https://katalon-demo-cura.herokuapp.com/")
2020-04-01 11:17:07.428 DEBUG g level is tuned to make it less verbose - 3: waitForElementPresent(findTestObject("Object Repository/Page_CURA Healthcare Service/a_no_such_button"), 5, OPTIONAL)
2020-04-01 11:17:12.834 INFO  c.k.k.c.webui.common.WebUiCommonHelper   - Unable to find the element located by 'By.xpath: id("btn-no-such-button")'. Please recheck the objects properties to make sure the desired element is located. 
2020-04-01 11:17:12.850 WARN  k.k.c.w.k.b.WaitForElementPresentKeyword - Object 'Object Repository/Page_CURA Healthcare Service/a_no_such_button' is not present after 5 second(s)
2020-04-01 11:17:12.853 DEBUG g level is tuned to make it less verbose - 4: closeBrowser()

Here I found 2 names:

c.k.k.c.webui.common.WebUiCommonHelper
k.k.c.w.k.b.WaitForElementPresentKeyword

Well, c.k.k.c and k.k.c.w.k.b must be some mystified abbreviation. By looking at the source I know the FQDN of Katalon classes should be

com.kms.katalon.core.webui.common.WebUiCommonHelper
com.kms.katalon.core.webui.keyword.builtin.WaitForElementPresentKeyword

So I changed the log.properties to assign higher log levels to these 2 classes, to make them quiet.

why `waitForElementPresent` instead of `verifyElementPresent` ?

I personally prefer verifyElementPreset keyword behave as is because I use it frequently and I use it in a situation where I do NOT accept element being absent.

I personally do not use waitForElementPresent frequently so do not mind it changing its behavior. And I think that the name “wait for …” is better describing a situation where I DO accept element being absent.