TypeError on deploy - Githubissues

gpongelli commented 1 year ago

Hi, first of all, thanks for this fantastic Telegram integration on nodered!

Yesterday I've upgraded my nodered docker installation to 3.0.2 and this package to latest version 14.1 .

After that moment, when I do Deploy I receive following messages on Debug panel:

Aborting: Token of <my_bot_name> is already in use by <my_bot_name>: {env.get("TELEGRAM_API")} first error message that points to bot configuration node
TypeError: this.config.registerCommand is not a function error message from ALL Command nodes
bot not initialized. warning message from ALL Sender nodes
(node:7) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 status listeners added to [TelegramBotNode]. Use emitter.setMaxListeners() to increase limit from docker log

Due to a message I sent via telegram at nodered startup, the CatchAll node also prints this stack (don't know if it's useful):

TypeError: Cannot read properties of null (reading 'sendMessage')
    at TelegramOutNode.processMessage (/data/node_modules/node-red-contrib-telegrambot/telegrambot/99-telegrambot.js:1914:42)
    at TelegramOutNode._inputCallback (/data/node_modules/node-red-contrib-telegrambot/telegrambot/99-telegrambot.js:2496:26)
    at /usr/src/node-red/node_modules/@node-red/runtime/lib/nodes/Node.js:210:26
    at Object.trigger (/usr/src/node-red/node_modules/@node-red/util/lib/hooks.js:166:13)
    at TelegramOutNode.Node._emitInput (/usr/src/node-red/node_modules/@node-red/runtime/lib/nodes/Node.js:202:11)
    at TelegramOutNode.Node.emit (/usr/src/node-red/node_modules/@node-red/runtime/lib/nodes/Node.js:186:25)
    at TelegramOutNode.Node.receive (/usr/src/node-red/node_modules/@node-red/runtime/lib/nodes/Node.js:485:10)
    at Immediate._onImmediate (/usr/src/node-red/node_modules/@node-red/runtime/lib/flows/Flow.js:831:52)
    at processImmediate (node:internal/timers:466:21)

If I do restart the nodered container, everything described above does not happen, docker log included.

Previously I did not have any issue, nodered was v2.x and this package was 11.x or 12.x .

Thanks.

windkh commented 1 year ago

Hi @gpongelli I will try to answer one by one:

Aborting: Token of is already in use by : {env.get("TELEGRAM_API")} first error message that points to bot configuration node --> this indicates that you are using the same token in two different configuration nodes. Please remove the duplicate to fix this.
TypeError: this.config.registerCommand is not a function error message from ALL Command nodes --> I guess that the bot was not created due to error 1. above and should vanish when the same token is not used twice. I will try to handle this in future correctly.
bot not initialized. warning message from ALL Sender nodes --> Same here: this is a result of error 1: initialization was aborted, bot not created: bot is not initialized
(node:7) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 status listeners added to [TelegramBotNode]. Use emitter.setMaxListeners() to increase limit from docker log --> You can ignore this. It is a warning which is issued by the EventEmitter from nodejs when you have a lot of listeners attached to one event. In this case you have 11 command nodes listening to one bot config node.
TypeError: Cannot read properties of null (reading 'sendMessage') --> I guess you are triggering a not initialized node (due to error 1 above). I will try to handle this in a better way in future.

And finally: If I do restart the nodered container, everything described above does not happen, docker log included. I don't understand this. You mean by simply restarting all error are gone???

windkh commented 1 year ago

should be better in 14.2.

gpongelli commented 1 year ago

Hi @windkh , thanks for the reply.

Aborting: Token of is already in use by : {env.get("TELEGRAM_API")} first error message that points to bot configuration node --> this indicates that you are using the same token in two different configuration nodes. Please remove the duplicate to fix this.

No, I have only one configuration node for Telegram bot and I do not get/set that environment variable in any other place. I don't know if removing and recreating the configuration node can solve, but I would be careful doing that because I've around 60 telegram command/reply nodes and reconfigure all of them could be time consuming .

And finally: If I do restart the nodered container, everything described above does not happen, docker log included. I don't understand this. You mean by simply restarting all error are gone???

I mean doing following steps:

on running nodered, clear nodered debug log panel
docker-compose restart nodered , nodered server restart , debug log panel is empty, Telegram bot get connected, I can interact with it sending/receiving messages.
Then, simply moving a node on the sheet, without changing anything, just to have the Deploy button clickable
click on full Deploy button, all the issue above are listed on debug panel, Telegram bot does not work, all telegram nodes have a red circle below indicating "bot not initialized"
clear nodered debug log panel
restart again the server with docker-compose restart nodered , nodered server restart , debug log panel remains empty , Telegram bot get connected, I can interact with it sending/receiving messages.
loop from point 3

I've tested this loop many times yesterday before opening this issue.

Just for curiosity, when running deploy, does this package "release" the token (or the configuration node) before re-using it? Seems that it keeps token (or configuration nodes) "locked" , so then it find token locked and emit errors; meanwhile when server starts up from docker command, the token appear "correctly released" (I'm supposing, I don't know how this package nor nodered work).

Thanks.

windkh commented 1 year ago

Hi @windkh , thanks for the reply.

Aborting: Token of is already in use by : {env.get("TELEGRAM_API")} first error message that points to bot configuration node --> this indicates that you are using the same token in two different configuration nodes. Please remove the duplicate to fix this.

No, I have only one configuration node for Telegram bot and I do not get/set that environment variable in any other place. I don't know if removing and recreating the configuration node can solve, but I would be careful doing that because I've around 60 telegram command/reply nodes and reconfigure all of them could be time consuming .

I would like to have a look at your flows if you don't mind. In my theory you must have two config nodes using the same token. If not I would be interested to see where the problem comes from.

And finally: If I do restart the nodered container, everything described above does not happen, docker log included. I don't understand this. You mean by simply restarting all error are gone???

I mean doing following steps:

on running nodered, clear nodered debug log panel

docker-compose restart nodered , nodered server restart , debug log panel is empty, Telegram bot get connected, I can interact with it sending/receiving messages.

Then, simply moving a node on the sheet, without changing anything, just to have the Deploy button clickable

click on full Deploy button, all the issue above are listed on debug panel, Telegram bot does not work, all telegram nodes have a red circle below indicating "bot not initialized"

clear nodered debug log panel

restart again the server with docker-compose restart nodered , nodered server restart , debug log panel remains empty , Telegram bot get connected, I can interact with it sending/receiving messages.

loop from point 3

I've tested this loop many times yesterday before opening this issue.

Hm... I am doing this many times when developing. Never had an issue like that. There must be something that is different here.

Just for curiosity, when running deploy, does this package "release" the token (or the configuration node) before re-using it? Seems that it keeps token (or configuration nodes) "locked" , so then it find token locked and emit errors; meanwhile when server starts up from docker command, the token appear "correctly released" (I'm supposing, I don't know how this package nor nodered work).

Thanks. Well you do not have to "release" a token. You will have problems when two config nodes would poll messages from the TelegramServer at the same time. Some messages would be retrieved by the first node, some by the second. You would see a lot of random sideeffects. To avoid this it is checked during startup that all config nodes use different tokens. It is done inside the nodes and has nothing to do with Telegram API. Basically it is dictionary which is shared by all config nodes. On redeploy every config node removes its token from that dictionary. This can only happen if node-red does not call "close" correctly.

On what platform do you run docker? is there a way to attach a debugger?

gpongelli commented 1 year ago

Hi @windkh ,

I would like to have a look at your flows if you don't mind. In my theory you must have two config nodes using the same token. If not I would be interested to see where the problem comes from.

I’ve to check my flows, they contain many logic related to home assistant and other “private” parts.

Well you do not have to "release" a token. You will have problems when two config nodes would poll messages from the TelegramServer at the same time. Some messages would be retrieved by the first node, some by the second. You would see a lot of random sideeffects. To avoid this it is checked during startup that all config nodes use different tokens. It is done inside the nodes and has nothing to do with Telegram API. Basically it is dictionary which is shared by all config nodes. On redeploy every config node removes its token from that dictionary. This can only happen if node-red does not call "close" correctly. On what platform do you run docker? is there a way to attach a debugger?

on raspberry bookworm (testing). I’ve no idea how to attach a debugger on nodered , I’ll follow a guide any if exist.

actually I could recreate the docker container, if you think it’s something related to core nodered.

windkh commented 1 year ago

@gpongelli I will release a modified version 14.3 now... without knowing exactly what is going on I did some changes in the code. Maybe you can give it a try and report if something changed?

windkh commented 1 year ago

@gpongelli I respect that your flows are your privacy... no problem, then we need to find another way to solve it. I just wanted to offer help...

gpongelli commented 1 year ago

@gpongelli I will release a modified version 14.3 now... without knowing exactly what is going on I did some changes in the code. Maybe you can give it a try and report if something changed?

I've just tried recreating the container with modeled 3.0.2, the issue persist on package v14.1.0 .

I'm waiting the 14.3 and let update you.

gpongelli commented 1 year ago

this is the log of the update from into nodered:

2022-09-20T20:53:52.611Z Install : node-red-contrib-telegrambot 14.3.0

2022-09-20T20:53:54.692Z npm install --no-audit --no-update-notifier --no-fund --save --save-prefix=~ --production --engine-strict node-red-contrib-telegrambot@14.3.0
2022-09-20T20:53:57.161Z [err] npm
2022-09-20T20:53:57.165Z [err]  WARN 
2022-09-20T20:53:57.167Z [err] config production Use `--omit=dev` instead.
2022-09-20T20:54:00.692Z [err] npm WARN
2022-09-20T20:54:00.699Z [err]  old lockfile 
2022-09-20T20:54:00.699Z [err] npm WARN old lockfile The package-lock.json file was created with an old version of npm,
2022-09-20T20:54:00.699Z [err] npm WARN old lockfile so supplemental metadata must be fetched from the registry.
2022-09-20T20:54:00.699Z [err] npm WARN old lockfile 
2022-09-20T20:54:00.699Z [err] npm WARN old lockfile This is a one-time fix-up, please be patient...
2022-09-20T20:54:00.707Z [err] npm WARN old lockfile 
2022-09-20T20:54:19.428Z [err] npm 
2022-09-20T20:54:19.431Z [err] WARN old lockfile TypeError: Cannot convert undefined or null to object
2022-09-20T20:54:19.431Z [err] npm WARN old lockfile     at Function.keys (<anonymous>)
2022-09-20T20:54:19.431Z [err] npm WARN old lockfile     at module.exports (/usr/local/lib/node_modules/npm/node_modules/npm-pick-manifest/lib/index.js:213:22)
2022-09-20T20:54:19.431Z [err] npm WARN old lockfile     at RegistryFetcher.manifest (/usr/local/lib/node_modules/npm/node_modules/pacote/lib/registry.js:125:24)
2022-09-20T20:54:19.431Z [err] npm WARN old lockfile     at async Array.<anonymous> (/usr/local/lib/node_modules/npm/node_modules/@npmcli/arborist/lib/arborist/build-ideal-tree.js:784:9)
2022-09-20T20:54:19.431Z [err] npm WARN old lockfile  Could not fetch metadata for node-red-contrib-date@0.0.2 TypeError: Cannot convert undefined or null to object
2022-09-20T20:54:19.431Z [err] npm WARN old lockfile     at Function.keys (<anonymous>)
2022-09-20T20:54:19.431Z [err] npm WARN old lockfile     at module.exports (/usr/local/lib/node_modules/npm/node_modules/npm-pick-manifest/lib/index.js:213:22)
2022-09-20T20:54:19.431Z [err] npm WARN old lockfile     at RegistryFetcher.manifest (/usr/local/lib/node_modules/npm/node_modules/pacote/lib/registry.js:125:24)
2022-09-20T20:54:19.431Z [err] npm WARN old lockfile     at async Array.<anonymous> (/usr/local/lib/node_modules/npm/node_modules/@npmcli/arborist/lib/arborist/build-ideal-tree.js:784:9)
2022-09-20T20:54:33.884Z [out] 
2022-09-20T20:54:33.884Z [out] changed 1 package in 37s
2022-09-20T20:54:34.021Z rc=0

also those warning could be useful for you when doing update directly Into container's console:

bash-5.1# npm install --location=global node-red-contrib-telegrambot
npm WARN deprecated har-validator@5.1.5: this library is no longer supported
npm WARN deprecated request-promise@4.2.6: request-promise has been deprecated because it extends the now deprecated request package, see https://github.com/request/request/issues/3142
npm WARN deprecated uuid@3.4.0: Please upgrade  to version 7 or higher.  Older versions may use Math.random() in certain circumstances, which is known to be problematic.  See https://v8.dev/blog/math-random for details.
npm WARN deprecated request@2.88.2: request has been deprecated, see https://github.com/request/request/issues/3142

added 120 packages, and audited 121 packages in 38s

33 packages are looking for funding
  run `npm fund` for details

found 0 vulnerabilities

after such changes, I cannot login into nodered anymore :(

gpongelli commented 1 year ago

@gpongelli I respect that your flows are your privacy... no problem, then we need to find another way to solve it. I just wanted to offer help...

Yes I know that you're offering your help to fix the issue, I'm sorry.

Anyway, good news, 14.3.0 fixes the issue 🎉

Thank you!

windkh commented 1 year ago

Ok nice thanks for reporting

windkh / node-red-contrib-telegrambot

TypeError on deploy #272