Unexpected nesting of log items in Log Viewer, inside method calls

Product Forums Katalon Studio
,
1

Not sure whether to write this as a general issue I’m facing (and maybe there’s some actionable step I can take to address it), or a bug with the Log Viewer…

… but it is a frustration.

I have this test case, where steps seem to get nested within each other in the logs. Here is snippet of it:

//Navigate to home page for consistent starting point
    WebUI.navigateToUrl(SMDConstants.DASHBOARD_PAGE_URL)

	goToPracticeCreationPage()
	
	CreatePracticePage page = new CreatePracticePage(WebUI.getUrl());

    fillInPracticeDetails(model, page);

    fillInContractAddressDetails(model);
	
    NPINumberHandler.GetInstance().handle(page.getNpiNumber(), { 
            GeneralWebUIUtils.HandleSaveButton(findTestObject('Page_Zoho shared repository/Practice subpages/Top row/Save button'))

            GeneralWebUIUtils.WaitForURLNotEquals(page.getUrl(), 5)
			
			WebUI.verifyElementText(findTestObject('Object Repository/Page_Practice - Zoho CRM/First Row Section/Status'),
				SMDConstants.ACTIVE)
        }, { StepFailedException ex ->
            if (!WebUI.verifyElementPresent(findTestObject('Object Repository/Page_Create Practice - Zoho CRM/Practice Details Section/NPI Number error message'), 
	            5,
				FailureHandling.OPTIONAL)) { 
            	throw new StepFailedException("Found an error on the page, for field: '${page.getLabelForFirstUserErrorField()}'");
            }
				
			return true;
        }, { 
            return page.generateAndEnterNPINumber();
        })

Test case fails, intentionally. I cause an error by commenting out a line of code in fillInContractAddressDetails(). It is defined to be:

void fillInContractAddressDetails(PracticeModel model) {
	WebUI.scrollToElement(findTestObject('Page_Create Practice - Zoho CRM/Contact Address Details Section/Contact Address Details section'), 0)
	
	//Set Address
	WebUI.setText(findTestObject('Page_Create Practice - Zoho CRM/Contact Address Details Section/Address 1 input field'),
		model.getContactInfo().getAddress())

//	WebUI.setText(findTestObject('Page_Create Practice - Zoho CRM/Contact Address Details Section/City input field'),
//		model.getContactInfo().getCity())

	WebUI.setText(findTestObject('Page_Create Practice - Zoho CRM/Contact Address Details Section/State Autocomplete/State autocomplete input field'),
		model.getContactInfo().getState())

	WebUI.waitForElementClickable(findTestObject('Page_Create Practice - Zoho CRM/Contact Address Details Section/State Autocomplete/First State dropdown option'),
		3)

	WebUI.click(findTestObject('Page_Create Practice - Zoho CRM/Contact Address Details Section/State Autocomplete/First State dropdown option'))

	WebUI.setText(findTestObject('Page_Create Practice - Zoho CRM/Contact Address Details Section/Zip Code input field'),
		model.getContactInfo().getZip())
}

The log message is fine for the test case entry itself. I see the error message that I wrote in it. However, when I go look down the rabbit hole, I see that I’ve been forced to put up with this:

image
image1476×283 29.1 KB

The last line of the last in-test-case method that was called, fillInContractAddressDetails() is like this:

WebUI.setText(findTestObject('Page_Create Practice - Zoho CRM/Contact Address Details Section/Zip Code input field'),
		model.getContactInfo().getZip())

and for some reason, anything that happens thereafter is getting nested into that last statement in the Log Viewer.

I should move these methods to the page, but I don’t see the logs for that, also that is another question altogether.

What is causing this?

2

I believe it is not a bug of the Log Viewer.

What do you want to see? Probablly you want everything that happes thereafter should NOT get nested into that statement in the Log Viewer. But it is irrational.

I think your “NPINumberHandler” class is responsible for making anything that happens thereafter is getting nested

NPINumberHandler seems require 3 arguments, all of these 3 are Groovy Closures. NPINumberHandler is primarily responsible for dealing with all Exceptions raised inside each Closures. Log Viewer would/could/should do nothing for the codes inside the Closures.

I think, if you want to see the StepFailedException raised inside the closure 2 to be displayed unnested in the Log Viewer, your NPINumberHandler class should behave as you want: NPINumberHandler must re-throw the StepFailedException to let the Katalon’s TestCaseExecutor be notified of the exception. But, possibly your NPINumberHandler class is silently consuming the exceptions. Possibly Katalon is not informed of the exception. Therefore Log Viewer marked the step green (passed), and the message from the exceptions are displayed as a nested information which you annotated “What the …?”. I think, this way of processing is appropriate.

All Katalon can do is to call NPINumberHandler.GetInstance().handle(...,...,...); and Katalon is doing it just fine.

Your code (NPINumberHandler) is causing this.

3

I was expecting to see the GetInstance().handle(...) as sibling to the unrelated setText() call, and closures as their own child entry to that, not the whole thing, as one child entry to some unrelated line of code.

Yup, it’s like this, by business requirement. NPI Numbers, by business definition, must be unique. If my code happens to generate one that’s already in the AUT system, it is expected to retry until it creates one that isn’t, logging each taken one in th esystem

Implementation is like this:

	/**
	 * @param record
	 * @param onSubmit @throws StepFailedException
	 * @param onCheckDuplicate
	 * @param onRetry
	 */
	public void handle(T record, Closure onSubmit, Closure<Boolean> onCheckDuplicate, Closure<T> onRetry) {
		this.handle([record], onSubmit, onCheckDuplicate, onRetry);
	}

	@Override
	protected void handleFailure(StepFailedException ex, Closure onSubmit, Closure<Boolean> onCheckDuplicate, Closure<T> onRetry,
			List<T> newRecords) throws StepFailedException {
		if (onCheckDuplicate(ex)) {
			newRecords.add(onRetry());
			return;
		}
		
		newRecords.pop();
		throw ex;
	}

	/**
	 * This method is on base class
	 * @param records
	 * @param onSubmit
	 * @param onCheckDuplicate
	 * @param onRetry
	 */
	public void handle(List<T> records, Closure onSubmit, Closure<Boolean> onCheckDuplicate, Closure<T> onRetry) {
		boolean keepTrying = true;

		while(keepTrying) {
			try {
				onSubmit();
				keepTrying = false;
			} catch (StepFailedException ex) {
				this.handleFailure(ex, onSubmit, onCheckDuplicate, onRetry, records);
			}
		}

		for (T record : records)
			this.handle(record);
	}

I was doing that inside the onCheckDuplicate callback (Closure number 2). I’m moving from that decision, as it was throwing Exception ex that was not helpful (it was throwing exception about the lack of NPI Number error message), also I was facing this exact same issue.

I guess I’ll live with this issue. It’s a minor inconvenience, especially as the end user of the test case gets the error message about what the fail was:

image
image1406×226 25.4 KB