simonradier / node-red-contrib-selenium-wd2

Selenium nodes for Node-Red
Apache License 2.0
9 stars 7 forks source link

Node-Red crashing if Chrome instance can not be launched #17

Closed FabioEight closed 1 year ago

FabioEight commented 2 years ago

Hello, first of all I thank you for the huge work for this node!

I made an automation using chrome-chromedriver on a Raspberry, to automate actions on a local webpage. I noticed that in some cases, when chromedriver/seleniumdriver is no longer running (or maybe crashed) and Node-Red ask to open a new instance, the flow cause a crash of the whole Node-Red environment. This is an issues since it stops all my other flows and make Node-Red unresponsive for a while.

I found the following logs on the Node-Red registry:

20 Jun 09:53:46 - [error] [open-web:XXXXXX] Can't open an instance of chrome
20 Jun 09:53:47 - [red] Uncaught Exception:
20 Jun 09:53:47 - [error] WebDriverError: unknown error: DevToolsActivePort file doesn't exist
    at Object.throwDecodedError (/config/node-red/node_modules/selenium-webdriver/lib/error.js:550:15)
    at parseHttpResponse (/config/node-red/node_modules/selenium-webdriver/lib/http.js:566:16)
    at Executor.execute (/config/node-red/node_modules/selenium-webdriver/lib/http.js:492:29)
    at runMicrotasks (<anonymous>)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
[09:53:47] WARNING: Node-RED crashed, halting add-on
s6-rc: info: service legacy-services: stopping
[09:53:47] INFO: Node-RED stoped, restarting...
[09:53:47] INFO: Node-RED stoped, restarting...
s6-svwait: fatal: supervisor died
s6-rc: info: service legacy-services successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped

Could you please check this? This kind of error should only stop the current flow and generate a flow error, not a Node-Red restart. For info: I have Node-Red on a host and the webdriver on another host on the same local network.

Thank you!

simonradier commented 1 year ago

Hi @FabioEight,

I updated my package with a new webdriver based on a simpler implementation of the webdriver standard (which does not require java and works well with chrome & co). Could you switch to the node-red-contrib-simple-driver and tell me if it still does not work?

Best regards

FabioEight commented 1 year ago

Hi @FabioEight,

I updated my package with a new webdriver based on a simpler implementation of the webdriver standard (which does not require java and works well with chrome & co). Could you switch to the node-red-contrib-simple-driver and tell me if it still does not work?

Best regards

Hello,

I was already testing it, but since the use of this new package, my NodeRed is crashing unexpectedly and not even restarting, despite the HA watchdog is set. Is there any way to collect logs in case of crashes? Thanks!

simonradier commented 1 year ago

Normally they should be written on standard/error output. Could you try to launch it manually and paste them here?

FabioEight commented 1 year ago

I was able to dump the messages via HA logs:


13 Aug 16:26:59 - [info] [open browser:Apri Silentron] http://192.168.1.31:9515/ is reacheable by Node-red
13 Aug 16:26:59 - [info] [open browser:Apri Silentron] http://192.168.1.31:9515/ is reacheable by Node-red
13 Aug 16:26:59 - [info] [open browser:Apri Silentron] http://192.168.1.31:9515/ is reacheable by Node-red
13 Aug 16:26:59 - [info] [open browser:Apri Silentron] http://192.168.1.31:9515/ is reacheable by Node-red
13 Aug 16:27:03 - [info] [server:Home Assistant] Connecting to http://supervisor/core
13 Aug 16:27:03 - [info] [server:Home Assistant] Connecting to http://supervisor/core
13 Aug 16:27:03 - [info] [server:Home Assistant] Connected to http://supervisor/core
13 Aug 16:27:03 - [info] [server:Home Assistant] Connected to http://supervisor/core
[TRACE][2022-08-13T14:30:21.144Z][Object.<anonymous>|api.js:40] Calling : POST http://192.168.1.31:9515/session
[DEBUG][2022-08-13T14:30:21.493Z][Object.<anonymous>|api.js:43] : 
WebDriverRequest {
  data: { capabilities: { alwaysMatch: [Object] } },
  requestOptions: {
    headers: {
      'Content-Type': 'application/json;charset=utf-8',
      'Cache-Control': 'no-cache',
      'Content-Length': 100
    },
    method: 'POST',
    timeout: 10000
  },
  path: 'session'
}
[DEBUG][2022-08-13T14:30:21.509Z][Object.<anonymous>|api.js:44] : 
HttpResponse {
  statusCode: 500,
  statusMessage: 'Internal Server Error',
  body: {
    value: {
      error: 'unknown error',
      message: 'unknown error: Chrome failed to start: crashed.\n' +
        "  (unknown error: DevToolsActivePort file doesn't exist)\n" +
        '  (The process started from chrome location /usr/bin/chromium-browser is no longer running, so ChromeDriver is assuming that Chrome has crashed.)',
      stacktrace: '#0 0x0055790e8e54 <unknown>\n' +
        '#1 0x005578e6b9bc <unknown>\n' +
        '#2 0x005578e8b280 <unknown>\n' +
        '#3 0x005578e877e8 <unknown>\n' +
        '#4 0x005578eb91f8 <unknown>\n' +
        '#5 0x005578e90658 <unknown>\n' +
        '#6 0x005579128cdc <unknown>\n' +
        '#7 0x00557912bc54 <unknown>\n' +
        '#8 0x005579116bb0 <unknown>\n' +
        '#9 0x00557912c540 <unknown>\n' +
        '#10 0x00557910bcec <unknown>\n' +
        '#11 0x0055791456a0 <unknown>\n' +
        '#12 0x0055791457ec <unknown>\n' +
        '#13 0x00557915dbc0 <unknown>\n' +
        '#14 0x007f904e3628 <unknown>\n' +
        '#15 0x007f9001001c <unknown>\n'
    }
  },
  url: 'http://192.168.1.31:9515/session'
}
[ERROR][2022-08-13T14:30:21.519Z][Object.<anonymous>|api.js:46] : 
{
  value: {
    error: 'unknown error',
    message: 'unknown error: Chrome failed to start: crashed.\n' +
      "  (unknown error: DevToolsActivePort file doesn't exist)\n" +
      '  (The process started from chrome location /usr/bin/chromium-browser is no longer running, so ChromeDriver is assuming that Chrome has crashed.)',
    stacktrace: '#0 0x0055790e8e54 <unknown>\n' +
      '#1 0x005578e6b9bc <unknown>\n' +
      '#2 0x005578e8b280 <unknown>\n' +
      '#3 0x005578e877e8 <unknown>\n' +
      '#4 0x005578eb91f8 <unknown>\n' +
      '#5 0x005578e90658 <unknown>\n' +
      '#6 0x005579128cdc <unknown>\n' +
      '#7 0x00557912bc54 <unknown>\n' +
      '#8 0x005579116bb0 <unknown>\n' +
      '#9 0x00557912c540 <unknown>\n' +
      '#10 0x00557910bcec <unknown>\n' +
      '#11 0x0055791456a0 <unknown>\n' +
      '#12 0x0055791457ec <unknown>\n' +
      '#13 0x00557915dbc0 <unknown>\n' +
      '#14 0x007f904e3628 <unknown>\n' +
      '#15 0x007f9001001c <unknown>\n'
  }
}
13 Aug 16:30:21 - [red] Uncaught Exception:
13 Aug 16:30:21 - [error] WebDriverResponseError: unknown error : unknown error: Chrome failed to start: crashed.
  (unknown error: DevToolsActivePort file doesn't exist)
  (The process started from chrome location /usr/bin/chromium-browser is no longer running, so ChromeDriver is assuming that Chrome has crashed.)
    at Object.<anonymous> (/config/node-red/node_modules/@critik/simple-webdriver/dist/api.js:47:23)
    at Generator.next (<anonymous>)
    at fulfilled (/config/node-red/node_modules/@critik/simple-webdriver/dist/api.js:27:58)
    at runMicrotasks (<anonymous>)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
[16:30:21] WARNING: Node-RED crashed, halting add-on
[16:30:21] INFO: Node-RED stoped, restarting...
s6-rc: info: service legacy-services: stopping
[16:30:21] INFO: Node-RED stoped, restarting...
s6-svwait: fatal: supervisor died
s6-rc: info: service legacy-services successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped ```

it is strange because using the old we driver version, it was stuck in a crash loop, while now it doesn’t restart anymore.
For completeness, I have a flow that send an SSH command to run chrome driver on a secondary host, then execute some clicks and then another ssh command to kill the chrome driver. 
every command has a delay of 2-3 seconds to avoid to be executed early.
The flow is now crashing on the first open browser node.
Thanks!
simonradier commented 1 year ago

Hi @FabioEight , could you give me your chromedriver logs as well? (By the way, can you try with the new alpha5?)

Thanks,

FabioEight commented 1 year ago

Hi @FabioEight , could you give me your chromedriver logs as well? (By the way, can you try with the new alpha5?)

Thanks,

Hello,

For completeness, here is my flow: image Basically, the "Avvia WebDriver" execute the following cmd on my Pi with chromedriver:

ssh -i /config/id_rsa -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null root@192.168.x.x 'chromedriver --whitelisted-ips="" --url-base /'

Then it open a webpage and scrape some data. I detect the crash just during the execution of the node open browser ("Apri"). At the time being I'm not able to capture the chromedriver as if I start manually chromedriver and then execute the flow, it works. This flow automatically starts and stops the chromedriver on the remote host, as I don't know if it's whether is running or not when executed, with: `'chromedriver --whitelisted-ips="" --url-base /'`` And


#!/bin/bash
pkill -f chromedriver
pkill -f chromium-browser

I suppose (as I had the same issue with wd2) that sometimes there are more concurrent chromedrivers or chromedriver is not executed yet, this seems to cause the crash of the whole Node-Red platform. In this case I would expect just a flow stop or a error exit node. The weirdest thing is that using wd2, I was stuck in a NodeRed crash loop, instead now NodeRed just crashes and doesn't restart on HA! Hope this clarify further.

Here's the chromedriver log:


[1660660735,501][INFO]: Starting ChromeDriver 101.0.4951.57 (352920124de66f14c4af140139f61c798937eda9-refs/branch-heads/4951@{#1148}) on port 9515
[1660660735,501][INFO]: Please see https://chromedriver.chromium.org/security-considerations for suggestions on keeping ChromeDriver safe.
[1660660735,504][SEVERE]: bind() failed: Impossibile assegnare l'indirizzo richiesto (99)
[1660660735,504][INFO]: listen on IPv6 failed with error ERR_ADDRESS_INVALID
[1660661015,156][INFO]: Starting ChromeDriver 101.0.4951.57 (352920124de66f14c4af140139f61c798937eda9-refs/branch-heads/4951@{#1148}) on port 9515
[1660661015,156][INFO]: Please see https://chromedriver.chromium.org/security-considerations for suggestions on keeping ChromeDriver safe.
[1660661025,845][INFO]: [9c1063c80277e8f37f7910dc58ca20a7] COMMAND InitSession {
   "capabilities": {
      "alwaysMatch": {
         "browserName": "chromium",
         "goog:chromeOptions": {
            "args": [ "headless" ]
         }
      }
   }
}
[1660661025,851][INFO]: [9c1063c80277e8f37f7910dc58ca20a7] RESPONSE InitSession ERROR session not created: No matching capabilities found
[1660661025,852][DEBUG]: Log type 'driver' lost 1 entries on destruction
root@PI2:~# cat chromedriver.log 
[1660660735,501][INFO]: Starting ChromeDriver 101.0.4951.57 (352920124de66f14c4af140139f61c798937eda9-refs/branch-heads/4951@{#1148}) on port 9515
[1660660735,501][INFO]: Please see https://chromedriver.chromium.org/security-considerations for suggestions on keeping ChromeDriver safe.
[1660660735,504][SEVERE]: bind() failed: Impossibile assegnare l'indirizzo richiesto (99)
[1660660735,504][INFO]: listen on IPv6 failed with error ERR_ADDRESS_INVALID
[1660661015,156][INFO]: Starting ChromeDriver 101.0.4951.57 (352920124de66f14c4af140139f61c798937eda9-refs/branch-heads/4951@{#1148}) on port 9515
[1660661015,156][INFO]: Please see https://chromedriver.chromium.org/security-considerations for suggestions on keeping ChromeDriver safe.
[1660661025,845][INFO]: [9c1063c80277e8f37f7910dc58ca20a7] COMMAND InitSession {
   "capabilities": {
      "alwaysMatch": {
         "browserName": "chromium",
         "goog:chromeOptions": {
            "args": [ "headless" ]
         }
      }
   }
}
[1660661025,851][INFO]: [9c1063c80277e8f37f7910dc58ca20a7] RESPONSE InitSession ERROR session not created: No matching capabilities found
[1660661025,852][DEBUG]: Log type 'driver' lost 1 entries on destruction
root@PI2:~# cat chromedriver.log 
[1660660735,501][INFO]: Starting ChromeDriver 101.0.4951.57 (352920124de66f14c4af140139f61c798937eda9-refs/branch-heads/4951@{#1148}) on port 9515
[1660660735,501][INFO]: Please see https://chromedriver.chromium.org/security-considerations for suggestions on keeping ChromeDriver safe.
[1660660735,504][SEVERE]: bind() failed: Impossibile assegnare l'indirizzo richiesto (99)
[1660660735,504][INFO]: listen on IPv6 failed with error ERR_ADDRESS_INVALID
[1660661015,156][INFO]: Starting ChromeDriver 101.0.4951.57 (352920124de66f14c4af140139f61c798937eda9-refs/branch-heads/4951@{#1148}) on port 9515
[1660661015,156][INFO]: Please see https://chromedriver.chromium.org/security-considerations for suggestions on keeping ChromeDriver safe.
[1660661025,845][INFO]: [9c1063c80277e8f37f7910dc58ca20a7] COMMAND InitSession {
   "capabilities": {
      "alwaysMatch": {
         "browserName": "chromium",
         "goog:chromeOptions": {
            "args": [ "headless" ]
         }
      }
   }
}
[1660661025,851][INFO]: [9c1063c80277e8f37f7910dc58ca20a7] RESPONSE InitSession ERROR session not created: No matching capabilities found
[1660661025,852][DEBUG]: Log type 'driver' lost 1 entries on destruction

Edit2:

Ok nevermind: it seems it was using Chromium and not Chrome. Anyway, I think that this should be addressed: in case of any error, the flow should just stop and not affect all the Node-Red platform, by crashing it or preventing the restart.

Thanks!

simonradier commented 1 year ago

Hi @FabioEight,

I'm glad you found the root cause. On my side I patched the issues which may cause the node-red crash. Have you tested the @alpha-5 (i.e. the latest release?)

Best regards,

FabioEight commented 1 year ago

Hello, I haven't detected any further crash. I'll let you know if I detect something! Thanks!