node.jsasync-awaitpuppeteerforever

Node JS with async unexpected infinite loop


I have a JS file that repeats itself automatically only when an error is expected dues to a timeout such as:

This creates a memory leak error message for reasons that ellude me. Have checked for such an issue to try and figure out if it was linked to Node JS, the Puppeteer or Forever libraries somehow but have not encountered someone else facing this. This is the closest I found but his script doesn't seem to have errors in it though according to the answers here.

The JS file basically creates a server with a basic url and listens to port 88. When someone enters "http://localhost:88/some_parameters it seems as if the code reaches the first try-catch and then goes back to console.log(6) through console.log(2) indefinitely until the try catch either succeeds of fails.

I do not understand this behaviour, as I would have expected the script being executed up to the try catch, then wait for the response and then moe on depending on a success or error being returned.

I have entered both commands and got the same result in both cases: forever start forever.json node loadPage.js

I've spent quite some time trying to solve this and still don't understand this behaviour. I get the images I want but it's still strange and pollutes the logs in the end.

Any help would be most welcome!

Update

This weird behaviour only happens when a try-catch returns an error. When successful responses are returned then the code executes normally without repeating anything.

loadPage.js

var http = require('http');
var url = require('url');
const puppeteer = require('puppeteer');
const { exit } = require('process');


let baseUrl = "http://localhost:88";
// let url = "chrome://gpu";
// demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1

console.log(1);
http.createServer(function (req, res) {
    console.log(2);
    (async () => {

        console.log(3);
        // headless set to false opens new browser and closes it when process is completed
        const browser = await puppeteer.launch({
            headless: true,
            args: ['--no-sandbox'],
            timeout: 10000,
            devtools: true
        });
        console.log(4);
        const completeUrl = `${baseUrl}${req.url}`;
        console.log(5);
        const parsedUrl = url.parse(completeUrl, true);
        console.log(6);
        const page = await browser.newPage();
        console.log(7);

        // Variable to help determine and log required time for different operations lower in the code.
        let t0 = Date.now();

        // Console logs used in logs to make them easier to read
        // new Date().toISOString().replace('T', ' ').substr(0, 19) converts time in acceptable format
        // with space instead of weird characters.
        console.log("[" + new Date().toISOString().replace('T', ' ').substr(0, 19) + "] - " +
            "------------------------------Process start for new url------------------------------"
        );
        console.log("[" + new Date().toISOString().replace('T', ' ').substr(0, 19) + "] - " +
            "The url being called is: " + `${baseUrl}${parsedUrl.pathname}${parsedUrl.search}`
        );


        // ------------------------------START - GO TO URL PART------------------------------
        // Try-Catch reaching the targeted url
        try {
            await page.goto(`${baseUrl}${parsedUrl.pathname}${parsedUrl.search}`, {
                waitUntil: 'networkidle0',
                timeout: 10000
            }).then(() => {
                console.log("[" + new Date().toISOString().replace('T', ' ').substr(0, 19) + "] - " +
                    "Reached the website!"
                );
            });

        } catch (error) {
            console.log("[" + new Date().toISOString().replace('T', ' ').substr(0, 19) + "] - " +
                "the following 'go to url action' error happened: ",
                error
            );
            console.log("[" + new Date().toISOString().replace('T', ' ').substr(0, 19) + "] - " +
                "------------------------------Error 'go to action' end for new url------------------------------"
            );
            browser.close();
            process.exit();
        }

        let t2 = Date.now();
        console.log("[" + new Date().toISOString().replace('T', ' ').substr(0, 19) + "] - " +
            "The 'go to url action' took " + (t2 - t0) + " milliseconds."
        );
        // ------------------------------END - GO TO URL PART------------------------------


        // ------------------------------START - WAIT FOR SELECTOR PART------------------------------
        // try catch to detect the agreed tag's ID selector
        // Once that selected is detected then it means that the model if fully loaded
        try {
            await page.waitForSelector('#uploadsuccess', {
                timeout: 30000
            }).then(() => {
                console.log("[" + new Date().toISOString().replace('T', ' ').substr(0, 19) + "] - " +
                    "Got the selector!"
                );
            });
        } catch (error) {
            console.log("[" + new Date().toISOString().replace('T', ' ').substr(0, 19) + "] - " +
                "the following 'wait for selector action' error happened: ",
                error
            );
            console.log("[" + new Date().toISOString().replace('T', ' ').substr(0, 19) + "] - " +
                "------------------------------Error 'wait for selector action' end for new url------------------------------"
            );
            browser.close();
            process.exit();
        }

        let t3 = Date.now();
        console.log("[" + new Date().toISOString().replace('T', ' ').substr(0, 19) + "] - " +
            "The 'waitForSelector' action took " + (t3 - t2) + " milliseconds."
        );
        // ------------------------------END - WAIT FOR SELECTOR PART------------------------------


        // ------------------------------START - IMAGE SAVING PART------------------------------
        // Take a printscreen and saving the image in the corresponding folder
        try {
            await page.screenshot({
                path: "./images/" + new Date().toISOString().replace('T', ' ').substr(0, 19) + "-apm-3d.png"
            }).then(() => {
                console.log("[" + new Date().toISOString().replace('T', ' ').substr(0, 19) + "] - " +
                    "Image saved"
                );
            });

        } catch (error) {
            console.log("[" + new Date().toISOString().replace('T', ' ').substr(0, 19) + "] - " +
                "the following 'image saving' error happened: ",
                error
            );
            console.log("[" + new Date().toISOString().replace('T', ' ').substr(0, 19) + "] - " +
                "------------------------------Error 'image saving' end for new url------------------------------"
            );
            browser.close();
            process.exit();
        }
        // ------------------------------END - IMAGE SAVING PART------------------------------


        let t1 = Date.now();
        console.log("[" + new Date().toISOString().replace('T', ' ').substr(0, 19) + "] - " +
            "The whole process took " + (t1 - t0) + " milliseconds."
        );
        console.log("[" + new Date().toISOString().replace('T', ' ').substr(0, 19) + "] - " +
            "------------------------------Process end for new url------------------------------"
        );
        browser.close();

    })()

}).listen(88)

forever.log

1
2
3
4
5
6
7
[2020-09-09 10:52:14] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:14] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:14] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:14] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:15] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:15] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:15] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:15] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:15] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:15] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:15] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:15] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:16] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:16] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:16] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:16] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:17] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:17] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:17] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:17] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
(node:12919) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 exit listeners added to [process]. Use emitter.setMaxListeners() to increase limit
(node:12919) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 SIGINT listeners added to [process]. Use emitter.setMaxListeners() to increase limit
(node:12919) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 SIGTERM listeners added to [process]. Use emitter.setMaxListeners() to increase limit
(node:12919) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 SIGHUP listeners added to [process]. Use emitter.setMaxListeners() to increase limit
4
5
6
7
[2020-09-09 10:52:17] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:17] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:18] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:18] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:18] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:18] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:18] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:18] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:19] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:19] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:19] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:19] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:19] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:19] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:19] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:19] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:20] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:20] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:20] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:20] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:20] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:20] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:21] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:21] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:21] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:21] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:21] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:21] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:22] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:22] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:22] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:22] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:22] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:22] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:23] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:23] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:23] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:23] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:23] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:23] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:24] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:24] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
4
5
6
7
[2020-09-09 10:52:24] - ------------------------------Process start for new url------------------------------
[2020-09-09 10:52:24] - The url being called is: http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1
2
3
[2020-09-09 10:52:24] - the following 'go to url action' error happened:  TimeoutError: Navigation timeout of 10000 ms exceeded
    at /Users/sebastienponcelet/Documents/3d-puppeteer/3d-puppeteer/node_modules/puppeteer/lib/cjs/puppeteer/common/LifecycleWatcher.js:106:111
    at async FrameManager.navigateFrame (/Users/sebastienponcelet/Documents/3d-puppeteer/3d-puppeteer/node_modules/puppeteer/lib/cjs/puppeteer/common/FrameManager.js:88:21)
    at async Frame.goto (/Users/sebastienponcelet/Documents/3d-puppeteer/3d-puppeteer/node_modules/puppeteer/lib/cjs/puppeteer/common/FrameManager.js:405:16)
    at async Page.goto (/Users/sebastienponcelet/Documents/3d-puppeteer/3d-puppeteer/node_modules/puppeteer/lib/cjs/puppeteer/common/Page.js:826:16)
    at async /Users/sebastienponcelet/Documents/3d-puppeteer/3d-puppeteer/loadPage.js:49:13
[2020-09-09 10:52:24] - ------------------------------Error 'go to action' end for new url------------------------------
error: Forever detected script exited with code: 0
error: Script restart attempt #1
1
error: restarting script because /Users/sebastienponcelet/Documents/3d-puppeteer/3d-puppeteer/stack-overflow.md changed
error: Forever detected script was killed by signal: SIGKILL
error: Script restart attempt #2
1


Solution

  • I have managed to solve the issue by simply deleting the try-catch on the go to action. Don't really know why but that stopped the program from looping indefinitely until a response was returned.

    The code there looks like that now:

    // ------------------------------START - GO TO URL PART------------------------------
        await page.goto(`${baseUrl}${parsedUrl.pathname}${parsedUrl.search}`, {
            waitUntil: 'networkidle2',
            timeout: 10000
        })
    
        let t2 = Date.now();
        console.log("[" + new Date().toISOString().replace('T', ' ').substr(0, 19) + "] - " +
            "The 'go to url action' took " + (t2 - t0) + " milliseconds."
        );
        // ------------------------------END - GO TO URL PART------------------------------
    

    Would be glad to have any comment explaining why this did the trick though.