Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

E/launcher - Error: TypeError: Cannot read property 'children' of undefined , Causing Report to generate empty results! #518

Closed
mtahat opened this issue Mar 30, 2020 · 7 comments

Comments

@mtahat
Copy link

mtahat commented Mar 30, 2020

Hello @jan-molak I am using Serenity-js with Cucumber, protractor & typescript ( see dependencies below) , I also have a hook.js that cleans the locale storage session after each feature/scenario. (see below).

I start getting Empty Reports after failed runs, I noticed this issue happen when the test timeout durning the execution ( for example the task code has wait.upto(Durations.seconds(60), " See task below")

FYI: I used the template cucumber/serenity template that you have here to build my project. see dependencies below, I am also using Mac book, VS Code IDE.

Exception 1: TypeError Cannot read property

 E/launcher - Error: TypeError: Cannot read property 'children' of undefined
[test:execute]     at /usr/src/app/node_modules/@serenity-js/serenity-bdd/src/stage/crew/serenity-bdd-reporter/reports/SceneReport.ts:150:35
[test:execute]     at SceneReport.withMutated (/usr/src/app/node_modules/@serenity-js/serenity-bdd/src/stage/crew/serenity-bdd-reporter/reports/SceneReport.ts:337:9)
[test:execute]     at SceneReport.activityStarted (/usr/src/app/node_modules/@serenity-js/serenity-bdd/src/stage/crew/serenity-bdd-reporter/reports/SceneReport.ts:140:21)
[test:execute]     at MatchesObjectsWithCommonPrototype.transformation (/usr/src/app/node_modules/@serenity-js/serenity-bdd/src/stage/crew/serenity-bdd-reporter/strategies/SceneSequenceReportingStrategy.ts:34:31)
[test:execute]     at MatchesObjectsWithCommonPrototype.MatcherRule.execute (/usr/src/app/node_modules/tiny-types/src/pattern-matching/rules/MatcherRule.ts:13:21)
[test:execute]     at ObjectMatcher.PatternMatcher.else (/usr/src/app/node_modules/tiny-types/src/pattern-matching/PatternMatcher.ts:17:71)
test:execute]     at SceneSequenceReportingStrategy.handle (/usr/src/app/node_modules/@serenity-js/serenity-bdd/src/stage/crew/serenity-bdd-reporter/strategies/SceneSequenceReportingStrategy.ts:45:18)
[test:execute]     at MatchesAnything.transformation (/usr/src/app/node_modules/@serenity-js/serenity-bdd/src/stage/crew/serenity-bdd-reporter/SerenityBDDReporter.ts:43:62)
[test:execute]     at MatchesAnything.MatcherRule.execute (/usr/src/app/node_modules/tiny-types/src/pattern-matching/rules/MatcherRule.ts:13:21)
[test:execute]     at ObjectMatcher.PatternMatcher.else (/usr/src/app/node_modules/tiny-types/src/pattern-matching/PatternMatcher.ts:17:71)
[test:execute]     at SerenityBDDReporter.notifyOf (/usr/src/app/node_modules/@serenity-js/serenity-bdd/src/stage/crew/serenity-bdd-reporter/SerenityBDDReporter.ts:41:14)
[test:execute]     at /usr/src/app/node_modules/@serenity-js/core/src/stage/StageManager.ts:33:59
[test:execute]     at Array.forEach (<anonymous>)
[test:execute]     at StageManager.notifyOf (/usr/src/app/node_modules/@serenity-js/core/src/stage/StageManager.ts:33:26)
[test:execute]     at Stage.announce (/usr/src/app/node_modules/@serenity-js/core/src/stage/Stage.ts:124:22)
[test:execute]     at Serenity.announce (/usr/src/app/node_modules/@serenity-js/core/src/Serenity.ts:174:20)
[test:execute] [14:33:54] E/launcher - Process exited with error code 100

Exception 2: TypeError: Cannot read property 'screenshots' of undefined

[test:execute]       ✗ Customer waits up to 30s until the Page Title does become clickable (30s 6ms)
[test:execute]   ⇢ When she hovers over My Account and clicks Account History
[test:execute]   ⇢ Then she should see the Account History page
[test:execute]   ✓ Customer executes a synchronous script (536ms)
[test:execute]   ✓ Customer executes a synchronous script (514ms)
[test:execute]   ✓ Customer logs: Session Cleared! (0ms)
[test:execute]     'Session Cleared!'
[test:execute] 
[test:execute] 
[test:execute] ✗ Execution failed with error (51s 290ms)
[test:execute] 
[test:execute]   Error: Some of the async operations have failed:
[test:execute]   [ArtifactArchiver] Saving 'photo-mac-os-x-chrome-80.0.3987.149-customer-waits-up-to-1m-until-the-my-account-menu-does-become-clickable-fa6046cdc9.png'... - TypeError: Cannot read property 'screenshots' of undefined
[test:execute]       at /node_modules/@serenity-js/serenity-bdd/src/stage/crew/serenity-bdd-reporter/reports/SceneReport.ts:237:71
[test:execute]       at SceneReport.withMutated (/node_modules/@serenity-js/serenity-bdd/src/stage/crew/serenity-bdd-reporter/reports/SceneReport.ts:337:9)
[test:execute]       at SceneReport.photoTaken (/Users/mtahat/workcenter/EU-AT-EndToEndTests/node_modules/@serenity-js/serenity-bdd/src/stage/crew/serenity-bdd-reporter/reports/SceneReport.ts:236:21)
[test:execute]       at MatchesIdentical.transformation (/node_modules/@serenity-js/serenity-bdd/src/stage/crew/serenity-bdd-reporter/strategies/SceneReportingStrategy.ts:51:57)
[test:execute]       at MatchesIdentical.MatcherRule.execute (/node_modules/tiny-types/src/pattern-matching/rules/MatcherRule.ts:13:21)
[test:execute]       at IdentityMatcher.PatternMatcher.else (/node_modules/tiny-types/src/pattern-matching/PatternMatcher.ts:17:71)
[test:execute]       at MatchesObjectsWithCommonPrototype.transformation (/node_modules/@serenity-js/serenity-bdd/src/stage/crew/serenity-bdd-reporter/strategies/SceneReportingStrategy.ts:52:22)
[test:execute]       at MatchesObjectsWithCommonPrototype.MatcherRule.execute (/node_modules/tiny-types/src/pattern-matching/rules/MatcherRule.ts:13:21)
[test:execute]       at ObjectMatcher.PatternMatcher.else (/node_modules/tiny-types/src/pattern-matching/PatternMatcher.ts:17:71)
[test:execute]       at SceneSequenceReportingStrategy.SceneReportingStrategy.handle (/node_modules/@serenity-js/serenity-bdd/src/stage/crew/serenity-bdd-reporter/strategies/SceneReportingStrategy.ts:53:18)
[test:execute]       at MatchesAnything.transformation (/node_modules/@serenity-js/serenity-bdd/src/stage/crew/serenity-bdd-reporter/strategies/SceneSequenceReportingStrategy.ts:45:36)
[test:execute]       at MatchesAnything.MatcherRule.execute (/Users/mtahat/workcenter/EU-AT-EndToEndTests/node_modules/tiny-types/src/pattern-matching/rules/MatcherRule.ts:13:21)
[test:execute]       at ObjectMatcher.PatternMatcher.else (node_modules/tiny-types/src/pattern-matching/PatternMatcher.ts:17:71)
[test:execute]       at SceneSequenceReportingStrategy.handle (/node_modules/@serenity-js/serenity-bdd/src/stage/crew/serenity-bdd-reporter/strategies/SceneSequenceReportingStrategy.ts:45:18)`

Task Used to Hover over top menu bar then click on sub-menu

import {Duration, Task} from '@serenity-js/core';
import {Click, Hover, isVisible, Target, Wait} from '@serenity-js/protractor';
import {By, element} from 'protractor';
 
export const UseTopNav = {
    with: (mainMenu: string, subMenu: string) =>
        Task.where(`#actor hovers over top menu item and then clicks sub menu item`,
            Wait.upTo(Duration.ofSeconds(15)).until(Target.the('top menu item').located(By.cssContainingText('.exc-nav-scroll > ul > li > a', mainMenu)), isVisible()),
            Click.on(Target.the(mainMenu).located(By.cssContainingText('.exc-nav-scroll > ul > li > a', mainMenu))),
            Wait.upTo(Duration.ofSeconds(5)).until(Target.the('sub menu item').located(By.cssContainingText('ul.exc-nav-top-L2 a', subMenu)), isVisible()),
            Click.on(Target.the(subMenu).located(By.cssContainingText('ul.exc-nav-top-L2 a', subMenu))),
    ),
};

Hooks.ts

import { actorCalled, actorInTheSpotlight, Log } from '@serenity-js/core';
import { ExecuteScript, ResizeBrowserWindow } from '@serenity-js/protractor';
import { After, Before } from 'cucumber';

Before( () => actorCalled('User').attemptsTo(
    ResizeBrowserWindow.toMaximum(),
));

After(() => actorInTheSpotlight().attemptsTo(
    ExecuteScript.sync(`window.sessionStorage.clear()`),
    ExecuteScript.sync(`window.localStorage.clear()`),
    Log.the('Session Cleared!'),
));

Dependencies

"dependencies": {
    "@types/cucumber": "^6.0.1",
    "@types/node": "^12.12.27",
    "axios": "^0.19.2",
    "chromedriver": "^79.0.3",
    "cucumber": "^6.0.5",
    "cucumber-html-reporter": "^5.1.0",
    "cucumber-junit": "^1.7.1",
    "dotenv": "^8.2.0",
    "is-ci": "^2.0.0",
    "moment": "^2.24.0",
    "npm-failsafe": "^0.4.1",
    "protractor": "^5.4.3",
    "rimraf": "^3.0.2",
    "ts-node": "^8.6.2",
    "tslint": "^5.20.1",
    "tslint-microsoft-contrib": "^6.2.0",
    "typescript": "^3.7.5"
  },
  "devDependencies": {
    "@serenity-js/assertions": "^2.1.5",
    "@serenity-js/console-reporter": "^2.1.5",
    "@serenity-js/core": "^2.1.5",
    "@serenity-js/cucumber": "^2.1.5",
    "@serenity-js/protractor": "^2.1.5",
    "@serenity-js/rest": "^2.1.5",
    "@serenity-js/serenity-bdd": "^2.1.5",
    "lodash": "^4.17.15"
  }

Protractor.config

require('dotenv').config()
const
    { ConsoleReporter } = require('@serenity-js/console-reporter'),
    { ArtifactArchiver } = require('@serenity-js/core'),
    { Photographer, TakePhotosOfInteractions } = require('@serenity-js/protractor'),
    { SerenityBDDReporter } = require('@serenity-js/serenity-bdd'),
    isCI = require('is-ci');

var tags = ['@' + process.env.OPCO];
if(process.env.TAGS) {
    const tagArray = process.env.TAGS.split(',');
    tags = tags.concat(tagArray);
    console.log('tags applied: ', tags);
}    
exports.config = {
    baseUrl: `https://abc.${process.env.SITE}.com`,
    SELENIUM_PROMISE_MANAGER: false,
    seleniumAddress: `http://${process.env.HUB}:4444/wd/hub`,
    

    allScriptsTimeout: 110000,

    framework:      'custom',
    frameworkPath:  require.resolve('@serenity-js/protractor/adapter'),

    specs: [ 'features/**/*.feature' ],

    serenity: {
        runner: 'cucumber',
        crew: [
            ArtifactArchiver.storingArtifactsAt('./target/site/serenity'),
            ConsoleReporter.forDarkTerminals(),
            Photographer.whoWill(TakePhotosOfInteractions),
            new SerenityBDDReporter(),
        ]
    },

    cucumberOpts: {
        require: [ 'features/**/*.ts'],
        'require-module':   [ 'ts-node/register'],
        tags:    tags,
        strict:  false,
    },

    capabilities: {
        browserName: 'chrome',

        // see https://github.com/SeleniumHQ/selenium/wiki/DesiredCapabilities#loggingpreferences-json-object
        loggingPrefs: {
            browser: 'SEVERE' // "OFF", "SEVERE", "WARNING", "INFO", "CONFIG", "FINE", "FINER", "FINEST", "ALL".
        },

        'goog:chromeOptions': {
            args: [
                '--incognito',
                //'--headless',
                '--no-sandbox',
                '--disable-infobars',
                '--disable-extensions',
                '--log-level=3',
                '--disable-gpu',
                '--window-size=1920,1080',
            ].concat(isCI ? ['--headless'] : []),
            'w3c': false    // run in headless mode on the CI server
        }
    }
};

Empty Report after test is done

[test:execute] npm ERR! code ELIFECYCLE
[test:execute] npm ERR! errno 100
[test:execute] npm ERR! acceptance-tests@1.0.0 test:execute: `protractor ./protractor.conf.js`
[test:execute] npm ERR! Exit status 100
[test:execute] npm ERR! 
[test:execute] npm ERR! Failed at the acceptance-tests@1.0.0 test:execute script.
[test:execute] npm ERR! This is probably not a problem with npm. There is likely additional logging output above.
[test:execute] 
[test:execute] npm ERR! A complete log of this run can be found in:
[test:execute] npm ERR!     /.npm/_logs/2020-03-28T16_06_07_600Z-debug.log
[failsafe] Script 'test:execute' exited with code 100
[test:report] 
[test:report] > acceptance-tests@1.0.0 test:report /Users/mtahat/workcenter/EU-AT-EndToEndTests
[test:report] > serenity-bdd run --features ./features
[test:report] 
[test:report] Spawning: /Library/Java/JavaVirtualMachines/jdk-13.0.2.jdk/Contents/Home/bin/java -DLOG_LEVEL=warn -Dlogback.configurationFile=/node_modules/@serenity-js/serenity-bdd/resources/logback.config.xml -jar node_modules/@serenity-js/cache/serenity-cli-2.1.9-all.jar --features ./features --destination target/site/serenity --source target/site/serenity --project e2e test
[test:report] -------------------------------
[test:report] SERENITY COMMAND LINE INTERFACE
[test:report] -------------------------------
[test:report] Loading test outcomes from target/site/serenity
[test:report] Writing aggregated report to target/site/serenity
[test:report] 
[test:report] WARNING: An illegal reflective access operation has occurred
[test:report] WARNING: Illegal reflective access by com.google.inject.internal.cglib.core.$ReflectUtils$1 (file:/Users/mtahat/workcenter/EU-AT-EndToEndTests/node_modules/@serenity-js/cache/serenity-cli-2.1.9-all.jar) to method java.lang.ClassLoader.defineClass(java.lang.String,byte[],int,int,java.security.ProtectionDomain)
[test:report] WARNING: Please consider reporting this to the maintainers of com.google.inject.internal.cglib.core.$ReflectUtils$1
[test:report] WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
[test:report] WARNING: All illegal access operations will be denied in a future release
[test:report] Report generation done
[failsafe] Script 'test:report' exited with code 0
npm ERR! Test failed.  See above for more details.

image

@jan-molak
Copy link
Member

Hey @mtahat and thanks for the detailed report!

This looks like a synchronisation issue that typically happens if the cucumber step does not return the Promise from the actor flow.

For example, the below sample would cause a synchronisation issue:

Given(/some step/, () => {
    // note no `return` statement:
    actorInTheSpotlight().attemptsTo(/*... tasks ...*/);
});

While both the below samples would work correctly:

Given(/some step/, () => {
    // explicit `return` statement
    return actorInTheSpotlight().attemptsTo(/*... tasks ...*/);
});
// `return` is implied with one-liner fat arrow functions with no curly brackets
Given(/some step/, () => actorInTheSpotlight().attemptsTo(
    /*... tasks ...*/
));

Could you please have a look at your cucumber steps implementation and check if they are synchronised with Serenity/JS actor flow (the actor.attemptsTo())

Best,
Jan

@jan-molak jan-molak added this to Ideas in Serenity/JS Board via automation Mar 30, 2020
@jan-molak jan-molak moved this from Ideas to Awaiting feedback in Serenity/JS Board Mar 30, 2020
@mtahat
Copy link
Author

mtahat commented Mar 30, 2020

@jan-molak Thank you for your suggestion.
looks like my steps already use the one liner fat arrow functions with no curly brackets.
I am passing two args for this function and then use them in the tasks.
Here is the code snippet.. Any thoughts?

Step file:

When(/(?:he|she|user) hovers over (.*) and clicks (.*)/, (arg1: string, arg2: string) =>
    actorInTheSpotlight().attemptsTo(
        UseTopNav.with(arg1, arg2),
    ));

Tasks in UseTopNav

import {Duration, Task} from '@serenity-js/core';
import {Click, Hover, isVisible, Target, Wait} from '@serenity-js/protractor';
import {By, element} from 'protractor';
export const UseTopNav = {
    with: (mainMenu: string, subMenu: string) =>
      Task.where(`#actor hovers over top menu item and then clicks sub menu item`,
            Wait.upTo(Duration.ofSeconds(15)).until(Target.the(mainMenu)
            .located(By.cssContainingText('.exc-nav-scroll > ul > li > a', mainMenu)), isVisible()),
            Click.on(Target.the(mainMenu).located(By.cssContainingText('.exc-nav-scroll > ul > li > a', mainMenu))),
            Wait.upTo(Duration.ofSeconds(5)).until(Target.the(`${subMenu} sub menu item`)
            .located(By.cssContainingText('ul.exc-nav-top-L2 a', subMenu)), isVisible()),
            Click.on(Target.the(subMenu).located(By.cssContainingText('ul.exc-nav-top-L2 a', subMenu))),
        ),
};

@jan-molak
Copy link
Member

jan-molak commented Mar 30, 2020

Could you please add a StreamReporter to your crew and paste the events.ndjson log it has created when the issue happened, please?

// protractor.conf.js
const { StreamReporter } = require('@serenity-js/core');
const fs = require('fs');

module.exports = {
    crew: [
        new StreamReporter(fs.createWriteStream('./events.ndjson')) 
        // other crew members
    ],

    // other config
};

Also, I noticed that the timeouts for your waits are really long - 15 and 5 seconds, which might be reasonable if the system under test is this slow.

However, if that's the case then it's possible that your cucumber step times out before your Serenity/JS tasks. Check out my post on StackOverflow.

If you want to adjust your cucumber step timeout, try the following:

When(/(?:he|she|user) hovers over (.*) and clicks (.*)/, { timeout: 30 * 1000 }, (arg1: string, arg2: string) =>
    actorInTheSpotlight().attemptsTo(
        UseTopNav.with(arg1, arg2),
    ));

@mtahat
Copy link
Author

mtahat commented Mar 30, 2020

@jan-molak Yes, our website is so slow! some of the wait statements goes up to 1 minute!
so it might be the reason that I am seeing this issue. I wonder is there anyway to set the time out for cucumber step from config file? can I use the protractor.config --> CucumberOption to set this?

I will also add the Stream reporter to my config file and run again.
Thanks for the suggestions.

@mtahat
Copy link
Author

mtahat commented Mar 31, 2020

@jan-molak I tried to increase the cucumber timeout as suggested, I added
The followings to my Protractor.config, also I added timeout.js to my support folder to increase the cucumber default step timeout.. Although I am still seeing the same issue see the events.ndjson attached below.. Any help will be appreciated.

Protractor.config

cucumberOpts: {
     require: [ 'features/**/*.ts', 'support/timeout.ts'],
    //reset of configs..
 },
 allScriptsTimeout: 100000,
 ignoreUncaughtExceptions: true,
 getPageTimeout: 100000,

timeout.ts

// support/timeout.ts
var { setDefaultTimeout } = require("cucumber");
setDefaultTimeout(100 * 1000);

Here is the output of my StreamReporter--
events.ndjson file size is a little big to upload.. I trimmed it and removed all other features (only kept the features that cause the issue and changed the file extension to .txt ).
my Feature file also have multiple tags in the Example table
image

FYI: the tests fails when I run: npm test ( around 25 tests will run) and the report will show empty results as above..

image

events.txt

@jan-molak
Copy link
Member

Thanks, @mtahat, based on the events log, it definitely looks like a synchronisation problem.

If you analyse the event log you'll see:

{"type":"TaskStarts","event":{"timestamp":"2020-03-31T01:19:38.744Z","value":{"correlationId":"ck8f7rlyw00bytiri6hwbcoej","name":"When user hovers over Safety & Community and clicks Employee Volunteering"}}}
{"type":"TaskStarts","event":{"timestamp":"2020-03-31T01:19:38.745Z","value":{"correlationId":"ck8f7rlyx00bztirigb3jam0y","name":"Customer hovers over top menu item and then clicks sub menu item"}}}
{"type":"InteractionStarts","event":{"timestamp":"2020-03-31T01:19:38.745Z","value":{"correlationId":"ck8f7rlyx00c0tiri8y6nejo2","name":"Customer waits up to 15s until the Safety & Community does become visible"}}}
{"type":"TaskFinished","event":{"outcome":{"code":2,"error":{"name":"TypeError","stack":"TypeError: Converting circular structure to JSON\n [...]"}},"timestamp":"2020-03-31T01:19:39.076Z","value":{"correlationId":"ck8f7qbth009ltiri8q5dea39","name":"Customer performs ClickButton"}}}

So this corresponds to this sequence of tasks:

When user hovers over Safety & Community and clicks Employee Volunteering
  Customer hovers over top menu item and then clicks sub menu item
    Customer waits up to 15s until the Safety & Community does become visible

But then I see an end of the following task, instead of the end of the wait interaction I'd expect:

Customer performs ClickButton

So it feels like whatever wraps the wait of 15 seconds does not have a sufficient timeout.

I'd suggest:

  • running the failing test on its own to see if it passes
    • if it doesn't, you have your culprit so you can try to fix it
    • if it does, then try experimenting with setting the allScriptsTimeout and your Cucumber timeouts to some silly high values, i.e. an hour for the allScriptsTimeout and a couple of minutes for the Cucumber timeout and see if that passes. If it does, then at least you have your tests stable and you can start to work on the website to make it faster (i.e. mock 3rd party dependencies, disable stuff you don't need to have loaded for the purposes of test and so on)

It's difficult for me to suggest more without seeing your actual code base and the system itself.

@mtahat
Copy link
Author

mtahat commented Apr 1, 2020

Yup I agree..it is indeed sync issue! I pumped up the cucumber time out and it seemed to be more stable. I am considering integrating a service virtualization tool (hoverfly) to eliminate some of the flakiness in the backend.

I will add an actor who can send API calls and see how stable the service even before running the test..

Again, Thank you so much for your quick responses! I am closing this issue since it is not related to serenity js.

@mtahat mtahat closed this as completed Apr 1, 2020
Serenity/JS Board automation moved this from Awaiting feedback to Done Apr 1, 2020
jan-molak added a commit that referenced this issue Oct 24, 2020
…rter

In cases where Cucumber interrupts execution of an already started Serenity/JS activity (i.e. when a
Cucumber step times out before actor finishes what they're doing), some internal domain events could
arrive during the subsequnt scenario, confusing SerenityBDDReporter and making it throw a bit of a
cryptic error along the lines of "Cannot read property 'children' of undefined". This new
implementation of the reporter resolves this issue by aggregating scenario-specific events before
they're analysed, making sure they're ordered correctly, and generating the report only when all the
events are available.

Closes #518
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
Development

No branches or pull requests

2 participants