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

Adapter does not work with nodejs 20 #449

Closed
Grothesk242 opened this issue Apr 21, 2023 · 25 comments
Closed

Adapter does not work with nodejs 20 #449

Grothesk242 opened this issue Apr 21, 2023 · 25 comments
Labels
bug Something isn't working

Comments

@Grothesk242
Copy link

With nodejs@20 the adapter won't start, with node-Versions <20 everything works just fine:

2023-04-21 18:31:25.875  - info: host.chet "system.adapter.tr-064.0" enabled
2023-04-21 18:31:26.039  - info: host.chet instance system.adapter.tr-064.0 started with pid 1085361
2023-04-21 18:31:28.881  - info: tr-064.0 (1085361) starting. Version 4.2.18 in /opt/iobroker/node_modules/iobroker.tr-064, node: v20.0.0, js-controller: 5.0.1-alpha.0-20230418-efa3e809
2023-04-21 18:31:29.150  - error: tr-064.0 (1085361) !device - "!device"
2023-04-21 18:31:29.151  - error: tr-064.0 (1085361) ~
2023-04-21 18:31:29.153  - error: tr-064.0 (1085361) ~~ Fatal error. Can not connect to your FritzBox.
2023-04-21 18:31:29.154  - error: tr-064.0 (1085361) ~~ If configuration, network, IP address, etc. ok, try to restart your FritzBox
2023-04-21 18:31:29.155  - error: tr-064.0 (1085361) ~
2023-04-21 18:31:29.157  - warn: tr-064.0 (1085361) Terminated (JS_CONTROLLER_STOPPED): Fatal error. Can not connect to your FritzBox.
2023-04-21 18:31:29.763  - error: host.chet instance system.adapter.tr-064.0 terminated with code 1 (JS_CONTROLLER_STOPPED)
2023-04-21 18:31:29.763  - info: host.chet Restart adapter system.adapter.tr-064.0 because enabled
2023-04-21 18:31:59.875  - info: host.chet instance system.adapter.tr-064.0 started with pid 1085376
2023-04-21 18:32:02.979  - info: tr-064.0 (1085376) starting. Version 4.2.18 in /opt/iobroker/node_modules/iobroker.tr-064, node: v20.0.0, js-controller: 5.0.1-alpha.0-20230418-efa3e809
2023-04-21 18:32:03.202  - error: tr-064.0 (1085376) !device - "!device"
2023-04-21 18:32:03.203  - error: tr-064.0 (1085376) ~
2023-04-21 18:32:03.204  - error: tr-064.0 (1085376) ~~ Fatal error. Can not connect to your FritzBox.
2023-04-21 18:32:03.205  - error: tr-064.0 (1085376) ~~ If configuration, network, IP address, etc. ok, try to restart your FritzBox
2023-04-21 18:32:03.206  - error: tr-064.0 (1085376) ~
2023-04-21 18:32:03.209  - warn: tr-064.0 (1085376) Terminated (JS_CONTROLLER_STOPPED): Fatal error. Can not connect to your FritzBox.
2023-04-21 18:32:03.833  - error: host.chet instance system.adapter.tr-064.0 terminated with code 1 (JS_CONTROLLER_STOPPED)
2023-04-21 18:32:03.834  - info: host.chet Restart adapter system.adapter.tr-064.0 because enabled
2023-04-21 18:32:33.942  - info: host.chet instance system.adapter.tr-064.0 started with pid 1085462
2023-04-21 18:32:36.581  - info: tr-064.0 (1085462) starting. Version 4.2.18 in /opt/iobroker/node_modules/iobroker.tr-064, node: v20.0.0, js-controller: 5.0.1-alpha.0-20230418-efa3e809
2023-04-21 18:32:36.831  - error: tr-064.0 (1085462) !device - "!device"
2023-04-21 18:32:36.832  - error: tr-064.0 (1085462) ~
2023-04-21 18:32:36.833  - error: tr-064.0 (1085462) ~~ Fatal error. Can not connect to your FritzBox.
2023-04-21 18:32:36.836  - error: tr-064.0 (1085462) ~~ If configuration, network, IP address, etc. ok, try to restart your FritzBox
2023-04-21 18:32:36.837  - error: tr-064.0 (1085462) ~
2023-04-21 18:32:36.840  - warn: tr-064.0 (1085462) Terminated (JS_CONTROLLER_STOPPED): Fatal error. Can not connect to your FritzBox.
2023-04-21 18:32:37.470  - error: host.chet instance system.adapter.tr-064.0 terminated with code 1 (JS_CONTROLLER_STOPPED)
2023-04-21 18:32:37.471  - info: host.chet Restart adapter system.adapter.tr-064.0 because enabled
2023-04-21 18:33:07.620  - info: host.chet instance system.adapter.tr-064.0 started with pid 1085492
2023-04-21 18:33:10.308  - info: tr-064.0 (1085492) starting. Version 4.2.18 in /opt/iobroker/node_modules/iobroker.tr-064, node: v20.0.0, js-controller: 5.0.1-alpha.0-20230418-efa3e809
2023-04-21 18:33:10.571  - error: tr-064.0 (1085492) !device - "!device"
2023-04-21 18:33:10.572  - error: tr-064.0 (1085492) ~
2023-04-21 18:33:10.573  - error: tr-064.0 (1085492) ~~ Fatal error. Can not connect to your FritzBox.
2023-04-21 18:33:10.574  - error: tr-064.0 (1085492) ~~ If configuration, network, IP address, etc. ok, try to restart your FritzBox
2023-04-21 18:33:10.575  - error: tr-064.0 (1085492) ~
2023-04-21 18:33:10.578  - warn: tr-064.0 (1085492) Terminated (JS_CONTROLLER_STOPPED): Fatal error. Can not connect to your FritzBox.
2023-04-21 18:33:11.186  - error: host.chet instance system.adapter.tr-064.0 terminated with code 1 (JS_CONTROLLER_STOPPED)
2023-04-21 18:33:11.186  - info: host.chet Restart adapter system.adapter.tr-064.0 because enabled
2023-04-21 18:33:41.334  - info: host.chet instance system.adapter.tr-064.0 started with pid 1085549
2023-04-21 18:33:43.983  - info: tr-064.0 (1085549) starting. Version 4.2.18 in /opt/iobroker/node_modules/iobroker.tr-064, node: v20.0.0, js-controller: 5.0.1-alpha.0-20230418-efa3e809
2023-04-21 18:33:44.234  - error: tr-064.0 (1085549) !device - "!device"
2023-04-21 18:33:44.235  - error: tr-064.0 (1085549) ~
2023-04-21 18:33:44.236  - error: tr-064.0 (1085549) ~~ Fatal error. Can not connect to your FritzBox.
2023-04-21 18:33:44.238  - error: tr-064.0 (1085549) ~~ If configuration, network, IP address, etc. ok, try to restart your FritzBox
2023-04-21 18:33:44.239  - error: tr-064.0 (1085549) ~
2023-04-21 18:33:44.242  - warn: tr-064.0 (1085549) Terminated (JS_CONTROLLER_STOPPED): Fatal error. Can not connect to your FritzBox.
2023-04-21 18:33:44.853  - error: host.chet instance system.adapter.tr-064.0 terminated with code 1 (JS_CONTROLLER_STOPPED)
2023-04-21 18:33:44.853  - info: host.chet Restart adapter system.adapter.tr-064.0 because enabled
2023-04-21 18:34:14.958  - info: host.chet instance system.adapter.tr-064.0 started with pid 1085606
2023-04-21 18:34:17.707  - info: tr-064.0 (1085606) starting. Version 4.2.18 in /opt/iobroker/node_modules/iobroker.tr-064, node: v20.0.0, js-controller: 5.0.1-alpha.0-20230418-efa3e809
2023-04-21 18:34:17.923  - error: tr-064.0 (1085606) !device - "!device"
2023-04-21 18:34:17.924  - error: tr-064.0 (1085606) ~
2023-04-21 18:34:17.925  - error: tr-064.0 (1085606) ~~ Fatal error. Can not connect to your FritzBox.
2023-04-21 18:34:17.926  - error: tr-064.0 (1085606) ~~ If configuration, network, IP address, etc. ok, try to restart your FritzBox
2023-04-21 18:34:17.927  - error: tr-064.0 (1085606) ~
2023-04-21 18:34:17.930  - warn: tr-064.0 (1085606) Terminated (JS_CONTROLLER_STOPPED): Fatal error. Can not connect to your FritzBox.
2023-04-21 18:34:18.540  - error: host.chet instance system.adapter.tr-064.0 terminated with code 1 (JS_CONTROLLER_STOPPED)
2023-04-21 18:34:18.540  - info: host.chet Restart adapter system.adapter.tr-064.0 because enabled

@Apollon77
Copy link
Member

Is debug showing more?

@Apollon77
Copy link
Member

pS: What is the setting? an ip or a name? what is set as dns order for conroller? ipv4 or ipv6?

@Apollon77
Copy link
Member

PPS: Please start adapter on cli with "iob debug tr-064.0" and post output. There could be more logs

@Grothesk242
Copy link
Author

Grothesk242 commented Apr 21, 2023

Settings: Hostname fritz.box or IP 192.168.178.1 makes no difference.

echad@chet:~ $ iob setup custom
Current configuration:
- Objects database:
  - Type: jsonl
  - Host/Unix Socket: 0.0.0.0
  - Port: 9001
- States database:
  - Type: jsonl
  - Host/Unix Socket: 0.0.0.0
  - Port: 9000
- Data Directory: ../../iobroker-data/

Debugger shows:

echad@chet:~ $ iob debug tr-064.0
Debugger listening on ws://127.0.0.1:9229/7e34cf16-27d3-49bd-a82d-9e75af17ea27
For help, see: https://nodejs.org/en/docs/inspector
2023-04-22 00:49:42.469  - debug: tr-064.0 (1120546) Redis Objects: Use Redis connection: 0.0.0.0:9001
2023-04-22 00:49:42.527  - debug: tr-064.0 (1120546) Objects client ready ... initialize now
2023-04-22 00:49:42.581  - debug: tr-064.0 (1120546) Objects create System PubSub Client
2023-04-22 00:49:42.584  - debug: tr-064.0 (1120546) Objects create User PubSub Client
2023-04-22 00:49:42.758  - debug: tr-064.0 (1120546) Objects client initialize lua scripts
2023-04-22 00:49:42.775  - debug: tr-064.0 (1120546) Objects connected to redis: 0.0.0.0:9001
2023-04-22 00:49:42.817  - debug: tr-064.0 (1120546) Redis States: Use Redis connection: 0.0.0.0:9000
2023-04-22 00:49:42.844  - debug: tr-064.0 (1120546) States create System PubSub Client
2023-04-22 00:49:42.846  - debug: tr-064.0 (1120546) States create User PubSub Client
2023-04-22 00:49:42.939  - debug: tr-064.0 (1120546) States connected to redis: 0.0.0.0:9000
2023-04-22 00:49:43.102  - debug: tr-064.0 (1120546) Plugin sentry Initialize Plugin (enabled=true)
2023-04-22 00:49:43.316  - error: tr-064.0 (1120546) adapter disabled
2023-04-22 00:49:43.511  - info: tr-064.0 (1120546) starting. Version 4.2.18 in /opt/iobroker/node_modules/iobroker.tr-064, node: v20.0.0, js-controller: 5.0.1-alpha.0-20230418-efa3e809
2023-04-22 00:49:43.589  - debug: tr-064.0 (1120546) Calllist Config after normalizing: {"all":{"generateJson":true,"generateHtml":true,"maxEntries":"10"},"missed":{"generateJson":true,"generateHtml":true,"maxEntries":"10"},"outbound":{"generateJson":true,"generateHtml":true,"maxEntries":"10"},"inbound":{"generateJson":true,"generateHtml":true,"maxEntries":"10"},"use":true}
2023-04-22 00:49:43.733  - debug: tr-064.0 (1120546) Set Template: "<!-- Variables: id, type, caller, called, callednumber, name, numbertype, device, port date, duration, count, path.to use with %() e.g. %(date) --><div>The last call was from %(name) at %(date) from %(caller)</div><div>%(type): %(count)<table><!!--Entry--><tr><td>%(date)</td><td>%(name)</td><td>%(caller)</td></tr><!!--EntryEnd--></table></div>"
null
<HTML><HEAD><TITLE>404 Not Found (ERR_NOT_FOUND)</TITLE></HEAD><BODY><H1>404 Not Found</H1><BR>ERR_NOT_FOUND<HR><B>Webserver</B> Fri, 21 Apr 2023 22:49:43 GMT</BODY></HTML>

2023-04-22 00:49:43.781  - error: tr-064.0 (1120546) !device - "!device"
2023-04-22 00:49:43.782  - error: tr-064.0 (1120546) ~
2023-04-22 00:49:43.783  - error: tr-064.0 (1120546) ~~ Fatal error. Can not connect to your FritzBox.
2023-04-22 00:49:43.784  - error: tr-064.0 (1120546) ~~ If configuration, network, IP address, etc. ok, try to restart your FritzBox
2023-04-22 00:49:43.785  - error: tr-064.0 (1120546) ~
2023-04-22 00:49:43.787  - debug: tr-064.0 (1120546) Plugin sentry destroyed
2023-04-22 00:49:43.789  - warn: tr-064.0 (1120546) Terminated (JS_CONTROLLER_STOPPED): Fatal error. Can not connect to your FritzBox.

@mcm1957 mcm1957 added the bug Something isn't working label Jun 2, 2023
@Grothesk242
Copy link
Author

As comparison a debug with nodejs 18.16.0

echad@chet:/opt/iobroker $ iob debug tr-064.0
Debugger listening on ws://127.0.0.1:9229/9869fb4d-a923-4a9d-8787-ea98378f565a
For help, see: https://nodejs.org/en/docs/inspector
2023-06-08 16:10:21.708  - debug: tr-064.0 (1170338) Redis Objects: Use Redis connection: 0.0.0.0:9001
2023-06-08 16:10:21.762  - debug: tr-064.0 (1170338) Objects client ready ... initialize now
2023-06-08 16:10:21.771  - debug: tr-064.0 (1170338) Objects create System PubSub Client
2023-06-08 16:10:21.774  - debug: tr-064.0 (1170338) Objects create User PubSub Client
2023-06-08 16:10:21.850  - debug: tr-064.0 (1170338) Objects client initialize lua scripts
2023-06-08 16:10:21.879  - debug: tr-064.0 (1170338) Objects connected to redis: 0.0.0.0:9001
2023-06-08 16:10:21.942  - debug: tr-064.0 (1170338) Redis States: Use Redis connection: 0.0.0.0:9000
2023-06-08 16:10:22.011  - debug: tr-064.0 (1170338) States create System PubSub Client
2023-06-08 16:10:22.013  - debug: tr-064.0 (1170338) States create User PubSub Client
2023-06-08 16:10:22.113  - debug: tr-064.0 (1170338) States connected to redis: 0.0.0.0:9000
2023-06-08 16:10:22.284  - debug: tr-064.0 (1170338) Plugin sentry Initialize Plugin (enabled=true)
2023-06-08 16:10:22.544  - error: tr-064.0 (1170338) adapter disabled
2023-06-08 16:10:22.726  - info: tr-064.0 (1170338) starting. Version 4.2.18 in /opt/iobroker/node_modules/iobroker.tr-064, node: v18.16.0, js-controller: 5.0.1-alpha.0-20230525-c580eb7e
2023-06-08 16:10:22.823  - debug: tr-064.0 (1170338) Calllist Config after normalizing: {"all":{"generateJson":true,"generateHtml":false,"maxEntries":"10"},"missed":{"generateJson":true,"generateHtml":false,"maxEntries":"10"},"outbound":{"generateJson":true,"generateHtml":false,"maxEntries":"10"},"inbound":{"generateJson":true,"generateHtml":false,"maxEntries":"10"},"use":true}
2023-06-08 16:10:23.020  - debug: tr-064.0 (1170338) Set Template: "<!-- Variables: id, type, caller, called, callednumber, name, numbertype, device, port date, duration, count, path.to use with %() e.g. %(date) --><div>The last call was from %(name) at %(date) from %(caller)</div><div>%(type): %(count)<table><!!--Entry--><tr><td>%(date)</td><td>%(name)</td><td>%(caller)</td></tr><!!--EntryEnd--></table></div>"


2023-06-08 16:10:23.892  - debug: tr-064.0 (1170338) Initialize HTML template: <!-- Variables: id, type, caller, called, callednumber, name, numbertype, device, port date, duration, count, path.to use with %() e.g. %(date) --><div>The last call was from %(name) at %(date) from %(caller)</div><div>%(type): %(count)<table><!!--Entry--><tr><td>%(date)</td><td>%(name)</td><td>%(caller)</td></tr><!!--EntryEnd--></table></div>
2023-06-08 16:10:23.895  - debug: tr-064.0 (1170338) createConfiguredDevices
2023-06-08 16:10:23.897  - debug: tr-064.0 (1170338) forEachConfiguredDevice
2023-06-08 16:10:23.940  - debug: tr-064.0 (1170338) Request Calllist JSON: url = http://192.168.178.1:49000/calllist.lua?sid=2975867d3dd6530a&timestamp=1633078063&id=319
2023-06-08 16:10:23.990  - debug: tr-064.0 (1170338) getVoIPCommonCountryCode: 0049
2023-06-08 16:10:24.006  - debug: tr-064.0 (1170338) Result Calllist JSON: {"root":{"timestamp":"1633078063"}}
2023-06-08 16:10:24.011  - debug: tr-064.0 (1170338) Calllist all regenerated
2023-06-08 16:10:24.013  - debug: tr-064.0 (1170338) Calllist inbound regenerated
2023-06-08 16:10:24.014  - debug: tr-064.0 (1170338) Calllist missed regenerated
2023-06-08 16:10:24.017  - debug: tr-064.0 (1170338) Calllist outbound regenerated
2023-06-08 16:10:24.021  - debug: tr-064.0 (1170338) Calllist states updated
2023-06-08 16:10:24.090  - debug: tr-064.0 (1170338) getVoIPCommonAreaCode: 0221
2023-06-08 16:10:24.093  - debug: tr-064.0 (1170338) Phonebook.read
in parseString callback
2023-06-08 16:10:24.134  - debug: tr-064.0 (1170338) Phonebook.read: NewPhonebookList=0
2023-06-08 16:10:24.178  - debug: tr-064.0 (1170338) Phonebook 0: {"NewPhonebookName":"Telefonbuch","NewPhonebookExtraID":"","NewPhonebookURL":"http://192.168.178.1:49000/phonebook.lua?sid=2333333d2dd6530a&pbid=0"} / err=null
2023-06-08 16:10:24.248  - debug: tr-064.0 (1170338) Phonebook 0 New Entry: {"name":"Alle (Rundruf)","normalizedName":"allerundruf","number":"0049221**9","id":"3","phonebookId":"0"}
2023-06-08 16:10:24.249  - debug: tr-064.0 (1170338) Phonebook 0 New Entry: {"name":"Anrufbeantworter","normalizedName":"anrufbeantworter","number":"0049221**600","id":"9","phonebookId":"0"}
2023-06-08 16:10:24.251  - debug: tr-064.0 (1170338) Phonebook 0 New Entry: {"name":"Anrufbeantworter","normalizedName":"anrufbeantworter","number":"0049221**605","id":"9","phonebookId":"0"}
2023-06-08 16:10:24.252  - debug: tr-064.0 (1170338) Phonebook 0 New Entry: {"name":"AVM Ansage (HD)","normalizedName":"avmansagehd","number":"0049221500","id":"0","phonebookId":"0"}
2023-06-08 16:10:24.254  - debug: tr-064.0 (1170338) Phonebook 0 New Entry: {"name":"DECT Rundruf","normalizedName":"dectrundruf","number":"0049221**50","id":"4","phonebookId":"0"}
2023-06-08 16:10:24.256  - debug: tr-064.0 (1170338) Phonebook 0 New Entry: {"name":"ERSETZT","normalizedName":"ERSETZT","number":"ERSETZT","id":"24","phonebookId":"0"}
2023-06-08 16:10:24.257  - debug: tr-064.0 (1170338) Phonebook 0 New Entry: {"name":"Mobilteil 1","normalizedName":"mobilteil","number":"0049221**610","id":"18","phonebookId":"0"}
2023-06-08 16:10:24.258  - debug: tr-064.0 (1170338) Phonebook 0 New Entry: {"name":"Mobilteil 2","normalizedName":"mobilteil","number":"0049221**612","id":"20","phonebookId":"0"}
2023-06-08 16:10:24.260  - debug: tr-064.0 (1170338) Phonebook 0 New Entry: {"name":"Telefon","normalizedName":"telefon","number":"0049221**1","id":"8","phonebookId":"0"}
2023-06-08 16:10:24.261  - debug: tr-064.0 (1170338) Phonebook 0 New Entry: {"name":"ERSETZT","normalizedName":"ERSETZT","number":"ERSETZT","id":"25","phonebookId":"0"}
2023-06-08 16:10:24.262  - debug: tr-064.0 (1170338) Phonebook 0 New Entry: {"name":"ERSETZT","normalizedName":"ERSETZT","number":"ERSETZT","id":"25","phonebookId":"0"}
2023-06-08 16:10:24.263  - debug: tr-064.0 (1170338) Phonebook 0 New Entry: {"name":"ERSETZT","normalizedName":"ERSETZT","number":"ERSETZT","id":"12","phonebookId":"0"}
2023-06-08 16:10:24.264  - debug: tr-064.0 (1170338) Phonebook 0 New Entry: {"name":"ERSETZT","normalizedName":"ERSETZT","number":"ERSETZT","id":"12","phonebookId":"0"}
2023-06-08 16:10:24.265  - debug: tr-064.0 (1170338) Phonebook 0 New Entry: {"name":"Wecker 1","normalizedName":"wecker","number":"0049221**41","id":"5","phonebookId":"0"}
2023-06-08 16:10:24.266  - debug: tr-064.0 (1170338) Phonebook 0 New Entry: {"name":"Wecker 2","normalizedName":"wecker","number":"0049221**42","id":"6","phonebookId":"0"}
2023-06-08 16:10:24.267  - debug: tr-064.0 (1170338) Phonebook 0 New Entry: {"name":"Wecker 3","normalizedName":"wecker","number":"0049221**43","id":"7","phonebookId":"0"}
2023-06-08 16:10:24.285  - debug: tr-064.0 (1170338) starting callmonitor
2023-06-08 16:10:24.292  - debug: tr-064.0 (1170338) callmonitor initialize ...
2023-06-08 16:10:24.303  - debug: tr-064.0 (1170338) callmonitor connected
2023-06-08 16:10:26.285  - debug: tr-064.0 (1170338) in updateAll
in parseString callback
2023-06-08 16:10:36.755  - debug: tr-064.0 (1170338) in updateAll
in parseString callback
2023-06-08 16:10:47.207  - debug: tr-064.0 (1170338) in updateAll
in parseString callback
2023-06-08 16:10:57.730  - debug: tr-064.0 (1170338) in updateAll
in parseString callback
2023-06-08 16:11:08.172  - debug: tr-064.0 (1170338) in updateAll
in parseString callback
2023-06-08 16:11:18.674  - debug: tr-064.0 (1170338) in updateAll
in parseString callback
2023-06-08 16:11:29.100  - debug: tr-064.0 (1170338) in updateAll
in parseString callback
2023-06-08 16:11:39.587  - debug: tr-064.0 (1170338) in updateAll
in parseString callback

@Grothesk242
Copy link
Author

Looks to me as if

2023-06-08 16:10:23.020  - debug: tr-064.0 (1170338) Set Template: "<!-- Variables: id, type, caller, called, callednumber, name, numbertype, device, port date, duration, count, path.to use with %() e.g. %(date) --><div>The last call was from %(name) at %(date) from %(caller)</div><div>%(type): %(count)<table><!!--Entry--><tr><td>%(date)</td><td>%(name)</td><td>%(caller)</td></tr><!!--EntryEnd--></table></div>"


2023-06-08 16:10:23.892  - debug: tr-064.0 (1170338) Initialize HTML template: <!-- Variables: id, type, caller, called, callednumber, name, numbertype, device, port date, duration, count, path.to use with %() e.g. %(date) --><div>The last call was from %(name) at %(date) from %(caller)</div><div>%(type): %(count)<table><!!--Entry--><tr><td>%(date)</td><td>%(name)</td><td>%(caller)</td></tr><!!--EntryEnd--></table></div>
2023-06-08 16:10:23.895  - debug: tr-064.0 (1170338) createConfiguredDevices
2023-06-08 16:10:23.897  - debug: tr-064.0 (1170338) forEachConfiguredDevice
2023-06-08 16:10:23.940  - debug: tr-064.0 (1170338) Request Calllist JSON: url = http://192.168.178.1:49000/calllist.lua?sid=2975867d3dd6530a&timestamp=1633078063&id=319

works in nodejs@18 while it fails with nodejs@20:

2023-04-22 00:49:43.733  - debug: tr-064.0 (1120546) Set Template: "<!-- Variables: id, type, caller, called, callednumber, name, numbertype, device, port date, duration, count, path.to use with %() e.g. %(date) --><div>The last call was from %(name) at %(date) from %(caller)</div><div>%(type): %(count)<table><!!--Entry--><tr><td>%(date)</td><td>%(name)</td><td>%(caller)</td></tr><!!--EntryEnd--></table></div>"
null
<HTML><HEAD><TITLE>404 Not Found (ERR_NOT_FOUND)</TITLE></HEAD><BODY><H1>404 Not Found</H1><BR>ERR_NOT_FOUND<HR><B>Webserver</B> Fri, 21 Apr 2023 22:49:43 GMT</BODY></HTML>

2023-04-22 00:49:43.781  - error: tr-064.0 (1120546) !device - "!device"
```

@Apollon77
Copy link
Member

That "set template" is just an internal thing, so is notthe same. The call that fails is the call to get the TR0654 dewcription URL ... so (even if not 100% same lib becaus ethe soef sources disappeared from github but like https://github.com/hendrikw01/tr-064/blob/master/lib/TR064.js#L17 ... means that the request to http://IP:PORT/tr64desc.xml is returning no error but also no body ... I would strat ading maybe a bit more debug there to find out what happens.

In fact nodejs 20 changelog did not directly report such topics as deprecations ... https://nodejs.org/en/blog/announcements/v20-release-announce

@Grothesk242
Copy link
Author

Even on 'silly' there is nothing interesting to see, afaics

2023-06-08 21:53:52.341  - info: host.chet Restart adapter system.adapter.tr-064.0 because enabled
2023-06-08 21:54:22.456  - info: host.chet instance system.adapter.tr-064.0 started with pid 1198742
2023-06-08 21:54:24.227  - debug: tr-064.0 (1198742) Redis Objects: Use Redis connection: 0.0.0.0:9001
2023-06-08 21:54:24.279  - debug: tr-064.0 (1198742) Objects client ready ... initialize now
2023-06-08 21:54:24.282  - debug: tr-064.0 (1198742) Objects create System PubSub Client
2023-06-08 21:54:24.285  - debug: tr-064.0 (1198742) Objects create User PubSub Client
2023-06-08 21:54:24.362  - debug: tr-064.0 (1198742) Objects client initialize lua scripts
2023-06-08 21:54:24.373  - debug: tr-064.0 (1198742) Objects connected to redis: 0.0.0.0:9001
2023-06-08 21:54:24.378  - silly: tr-064.0 (1198742) redis psubscribe cfg.o.system.user.*
2023-06-08 21:54:24.421  - silly: tr-064.0 (1198742) redis psubscribe cfg.o.enum.*
2023-06-08 21:54:24.425  - silly: tr-064.0 (1198742) objectDB connected
2023-06-08 21:54:24.429  - debug: tr-064.0 (1198742) Redis States: Use Redis connection: 0.0.0.0:9000
2023-06-08 21:54:24.453  - debug: tr-064.0 (1198742) States create System PubSub Client
2023-06-08 21:54:24.454  - debug: tr-064.0 (1198742) States create User PubSub Client
2023-06-08 21:54:24.537  - debug: tr-064.0 (1198742) States connected to redis: 0.0.0.0:9000
2023-06-08 21:54:24.539  - silly: tr-064.0 (1198742) statesDB connected
2023-06-08 21:54:24.702  - debug: tr-064.0 (1198742) Plugin sentry Initialize Plugin (enabled=true)
2023-06-08 21:54:25.083  - info: tr-064.0 (1198742) starting. Version 4.2.18 in /opt/iobroker/node_modules/iobroker.tr-064, node: v20.2.0, js-controller: 5.0.1-alpha.0-20230525-c580eb7e
2023-06-08 21:54:25.143  - silly: tr-064.0 (1198742) States system redis pmessage system.adapter.tr-064.0.logLevel/system.adapter.tr-064.0.logLevel:{"val":"silly","ack":true,"ts":1686254065126,"q":0,"from":"system.adapter.tr-064.0","lc":1686253693955}
2023-06-08 21:54:25.163  - debug: tr-064.0 (1198742) Calllist Config after normalizing: {"all":{"generateJson":true,"generateHtml":false,"maxEntries":"10"},"missed":{"generateJson":true,"generateHtml":false,"maxEntries":"10"},"outbound":{"generateJson":true,"generateHtml":false,"maxEntries":"10"},"inbound":{"generateJson":true,"generateHtml":false,"maxEntries":"10"},"use":true}
2023-06-08 21:54:25.289  - debug: tr-064.0 (1198742) Set Template: "<!-- Variables: id, type, caller, called, callednumber, name, numbertype, device, port date, duration, count, path.to use with %() e.g. %(date) --><div>The last call was from %(name) at %(date) from %(caller)</div><div>%(type): %(count)<table><!!--Entry--><tr><td>%(date)</td><td>%(name)</td><td>%(caller)</td></tr><!!--EntryEnd--></table></div>"
2023-06-08 21:54:25.345  - error: tr-064.0 (1198742) !device - "!device"
2023-06-08 21:54:25.346  - error: tr-064.0 (1198742) ~
2023-06-08 21:54:25.347  - error: tr-064.0 (1198742) ~~ Fatal error. Can not connect to your FritzBox.
2023-06-08 21:54:25.348  - error: tr-064.0 (1198742) ~~ If configuration, network, IP address, etc. ok, try to restart your FritzBox
2023-06-08 21:54:25.349  - error: tr-064.0 (1198742) ~
2023-06-08 21:54:25.350  - debug: tr-064.0 (1198742) Plugin sentry destroyed
2023-06-08 21:54:25.352  - warn: tr-064.0 (1198742) Terminated (JS_CONTROLLER_STOPPED): Fatal error. Can not connect to your FritzBox.
2023-06-08 21:54:26.033  - error: host.chet instance system.adapter.tr-064.0 terminated with code 1 (JS_CONTROLLER_STOPPED)
2023-06-08 21:54:26.034  - info: host.chet Restart adapter system.adapter.tr-064.0 because enabled

@Grothesk242
Copy link
Author

Grothesk242 commented Jun 14, 2023

Maybe the parsing via xml2js is broken. Push dep to [email protected]. ?

#460

@mcm1957 mcm1957 assigned mcm1957 and unassigned mcm1957 Jun 14, 2023
@Apollon77
Copy link
Member

you could try locally ... we could start toadd logging to see where it breaks

@Grothesk242
Copy link
Author

Sorry, I have no idea on how to do that.

@Grothesk242
Copy link
Author

Grothesk242 commented Jul 5, 2023

Just tested nodejs 20.4.0
The issue still persists.

@Apollon77
Copy link
Member

Ok with now 3 adapters with these symptoms we assume it is because of the library "request" that is used ... we will deeper research

@Apollon77
Copy link
Member

@Grothesk242 welches OS nutzt du?

@winnyschuster
Copy link

winnyschuster commented Jul 9, 2023

@Grothesk242 nutzt du bookworm? Da bekomme ich die gleichen Fehler, mit bullseye gibt es keine Probleme mit node20. Mit node18 und bookworm gibt es keine Probleme mit dem Adapter

@Grothesk242
Copy link
Author

Grothesk242 commented Jul 9, 2023

Ja, bookworm 64bit auf einem Rpi4 8GB

Model           : Raspberry Pi 4 Model B Rev 1.4
Architecture    : aarch64
Docker          : false
Virtualization  : none
Distributor ID: Debian
Description:    Debian GNU/Linux 12 (bookworm)
Release:        12
Codename:       bookworm

Beim nuki-extended habe ich ein ähnliches Verhalten:

iobroker-community-adapters/ioBroker.nuki-extended#281

Beide Adapter kommen mit [email protected] daher. Andere Adapter, die auch 'request' in den Deps haben laufen allerdings, soweit ich das sehe.

@winnyschuster
Copy link

winnyschuster commented Jul 10, 2023

``Request
Hier sieht man den Netzwerktraffic, in der ersten Zeile ist ein Versuch vom JS-Adapter mit Fehler weil tr64desc.xml fehlt, Zeile 3 ist das gleiche Skript von der Konsole. Warum das abgeschnitten wird weiss ich noch nicht. Wie man den Adapter unter Linux debuggt weiss ich leider nicht, im Windows gibts keine Fehler

Hier das Skript, der zweite Teil mit exec() funktioniert, der erste nicht

const url='http://192.168.178.1:49000/tr64desc.xml';
request.get(url,(err,response,body)=>{
    if(err)log(JSON.stringify(err))
    log(response)
    //log(body)
})

//Im test.js ist der erste Teil, oberhalb von hier drinne
exec('node /opt/iobroker/test.js',(e,o,ee)=>{
   log(o)
})```

@winnyschuster
Copy link

@Grothesk242 habe dir ne patch Anleitung im Forum gesendet, bitte mal testen und berichten

@Grothesk242
Copy link
Author

Funktioniert!

@winnyschuster
Copy link

Funktioniert!

Bitte mal den Patch rückgängig machen und Sentry in der Instanz ausschalten, das sollte es tun

@Grothesk242
Copy link
Author

Grothesk242 commented Jul 22, 2023

Disabling Sentry makes the adapter start without the errors.
Need to check more detailed if it is fully working.

Edit: Works!

@Apollon77
Copy link
Member

related getsentry/sentry-javascript#8552

@winnyschuster
Copy link

node 20.6.0 solved the issue for me, sentry can be activated again :-)

@Grothesk242
Copy link
Author

Working with nodejs 20.6.0
Closing issue.

@winnyschuster
Copy link

Working with nodejs 20.6.0 Closing issue.

thanks for reporting back!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

4 participants