0

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

  • website not reachable -> timeout to be reached
  • tag looked for in the "waitSelector" does not exist -> timeout to be reached

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
Improve this question
2
  • What happens if you start the server directly without forever and only fetch the first url? Apart from that, it seems like networkidle0 is the culprit, are you sure no network connections are kept open? What if you replace that with networkidle2? Commented Sep 10, 2020 at 11:32
  • So when I execute the script directly like $node loadPage.js I get the same behaviour. Replaced networkidle0 by networkidle2 but still have the same issue. Not sure about open network connections, but when inspecting the page I don't see anything else happening but the call to the url. Still baffled by the code's behaviour, I don't have any while or for loop, really dont' get why the code repeats itself while waiting for the try-catch to return a response. This does not happen however when there is no error in any try-catch. Commented Sep 11, 2020 at 5:09

3 Answers 3

Reset to default
1

The problem is that you are calling the same HTTP server again and again, without returning a response.

The HTTP server is listening on port 88:

http.createServer(function (req, res) {
  ...
}).listen(88)

Then you make the first HTTP request so that the process starts. After 2-7, the process reaches the line:

await page.goto(`${baseUrl}${parsedUrl.pathname}${parsedUrl.search}`, {

This instructs puppeteer to go to the page http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1, which is also on localhost:88, hitting the same HTTP server again.

When this second request comes, it goes through the same process, starting the browser, extracting the URL, then making a request to http://localhost:88/..., that spawns another browser, makes another request, and so on. That's why you are seeing 2-7 over and over, it's a textbook example of an infinite recursion.

Since all browsers are waiting for a response but that never comes, they eventually timeout and that's why you are seeing an error.

Improve this answer
Sign up to request clarification or add additional context in comments.

5 Comments

I expected the timeout but the rest is insightful. I did not expect the process to be like this. Thought that it would listen to the port 88 and would only start the process when I entered the localhost:88/... url. Then it'd reach the first try-catch for the page.goto action and actually wait for a response or an error. But still not sure I understand, does it mean that in this case it will make several requests to that same url? Because I only enter it once.
The goto is making a new request (http://localhost:88/demo/love_down.php?clean=0&line1=1,8,0,0-125&orderid=ORDIB2B-9000105953_1) to the localhost:88 server
Ok, I understand that. However how come the program doesn't wait for the try-catch answer but goes back to the beginning of the code only when an error is expected and is received later, never when a response is received?
The answer is: it never goes back. Think about it this way: Request 1 comes, does 2-7 then fires off a request to localhost:88. Request 2 starts, does 2-7, then fires off a request to localhost:88. Request 3 starts, ...., this goes until Request 1 timeouts and you see the error
Sorry to insist but something still bothers me. This just happens when an error occurs during the try-catch. When I enter a wrong url on purpose just for the sake of trying it out then what you describe happens. However if everything goes well then in the logs I only see one request, the big url not just the call to port 88 and the response is not instantaneous. So why when an error will happen it will take all the request 1 by 1 but when it all goes well then it waits at the try-catch?
0

Your catch block has process.exit() in it, which is closing your server. Forever than sees the process was killed and restarts it. Just remove that line.

Improve this answer

3 Comments

I understand and that is the expected behaviour, if the process stops then Forever is supposed to launch it again. However it seems that when reaching the try-catch it doesn't wait for the response (success or error) but goes back to the beginning of the script (up to console.log(2)) and repeats it indefinitely until the try-catch returns a response (in my case I expected an error because I gave a wrong url on purpose). So this behaviour is not critical because in the end it does what it's supposed to, but this behaviour is very weird.
Have you tried running this in VS Code and attached a debugger? You should be able to follow the flow by setting breakpoints at various points in the script. I'm also not sure why you have an immediately executing function inside the main handler. Why not just make the main callback function async? i.e. http.createServer(async function (req, res) {
So I have tried making the main callback function async as suggested. However it did not change the behaviour. Still don't get why it repeats the requests indefinitely instead of waiting for the first try catch response. Using a debugger doesn't provide more information than what is shown in the logs in the question. While waiting for the response for the same url it still repeat the same lines but doesn't change anything else.
0

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.

Improve this answer

Comments

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.