Failure while running through systemctl

[mobilutz]

When running through systemctl, I unfortunately get the following error:

 2020-1-4 22:59:58 - INFO: Starting free@home API
 2020-1-4 22:59:59 - DEBUG: Received new status:
 2020-1-4 22:59:59 - DEBUG: connecting
 2020-1-4 22:59:59 - DEBUG: Received new status:
 2020-1-4 22:59:59 - DEBUG: connect
 2020-1-4 22:59:59 - DEBUG: Received new status:
 2020-1-4 22:59:59 - DEBUG: opening
 2020-1-4 22:59:59 - DEBUG: Received new output data:
 2020-1-4 22:59:59 - DEBUG: <open version="1.0" xmlns="urn:ietf:params:xml:ns:xmpp-framing" to="busch-jaeger.de"/>
 2020-1-4 22:59:59 - DEBUG: Received new input data:
 2020-1-4 22:59:59 - DEBUG: <open id="tinyxmppd2151" from="busch-jaeger.de" xml:lang="en" version="1.0" xmlns="urn:ietf:params:xml:ns:xmpp-framing"/>
 2020-1-4 22:59:59 - DEBUG: Received new input data:
 2020-1-4 22:59:59 - DEBUG: <features xmlns="http://etherx.jabber.org/streams"><mechanisms xmlns="urn:ietf:params:xml:ns:xmpp-sasl"><mechanism>SCRAM-SHA-256</mechanism><mechanism>SCRAM-SHA-1</mechanism><mechanism>DIGEST-MD5</mechanism></mechanisms></features>
 2020-1-4 22:59:59 - DEBUG: Received new output data:
 2020-1-4 22:59:59 - DEBUG: <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-1">___XXX___</auth>
 2020-1-4 22:59:59 - DEBUG: Received new status:
 2020-1-4 22:59:59 - DEBUG: open
 2020-1-4 22:59:59 - DEBUG: Received new input data:
 2020-1-4 22:59:59 - DEBUG: <challenge xmlns="urn:ietf:params:xml:ns:xmpp-sasl">___XXX___</challenge>
 2020-1-4 23:00:01 - DEBUG: Received new output data:
 2020-1-4 23:00:01 - DEBUG: <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="SCRAM-SHA-1">___XXX___</response>
 2020-1-4 23:00:01 - DEBUG: Received new input data:
 2020-1-4 23:00:01 - DEBUG: <success xmlns="urn:ietf:params:xml:ns:xmpp-sasl">___XXX___</success>
 2020-1-4 23:00:01 - DEBUG: Received new status:
 2020-1-4 23:00:01 - DEBUG: opening
 2020-1-4 23:00:01 - DEBUG: Received new output data:
 2020-1-4 23:00:01 - DEBUG: <open version="1.0" xmlns="urn:ietf:params:xml:ns:xmpp-framing" to="busch-jaeger.de"/>
 2020-1-4 23:00:01 - DEBUG: Received new input data:
 2020-1-4 23:00:01 - DEBUG: <open id="tinyxmppd2152" from="busch-jaeger.de" xml:lang="en" version="1.0" xmlns="urn:ietf:params:xml:ns:xmpp-framing"/>
 2020-1-4 23:00:01 - DEBUG: Received new input data:
 2020-1-4 23:00:01 - DEBUG: <features xmlns="http://etherx.jabber.org/streams"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><required/></bind></features>
 2020-1-4 23:00:01 - DEBUG: Received new output data:
 2020-1-4 23:00:01 - DEBUG: <iq type="set" id="52a4r7a15z" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource>freeathome-api</resource></bind></iq>
 2020-1-4 23:00:01 - DEBUG: Received new status:
 2020-1-4 23:00:01 - DEBUG: open
 2020-1-4 23:00:01 - ERR: TypeError: promise.finally is not a function
 /home/pi/code/freeathome-api/node_modules/freeathome-api/dist/appRunner.js:33
         throw up;
         ^
 Error: Received error broadcast message, TypeError: promise.finally is not a function
     at Application.broadcastMessage (/home/pi/code/freeathome-api/node_modules/freeathome-api/dist/lib/Application.js:166:19)
     at Client.client.on.err (/home/pi/code/freeathome-api/node_modules/freeathome-api/dist/lib/SystemAccessPoint.js:78:29)
     at emitOne (events.js:121:20)
     at Client.emit (events.js:211:7)
     at next.then.catch.err (/home/pi/code/freeathome-api/node_modules/@xmpp/middleware/index.js:19:28)
     at <anonymous>
     at process._tickCallback (internal/process/next_tick.js:189:7)
freeathome-api.service: Main process exited, code=exited, status=1/FAILURE

It is very strange, because running it directly through console, there is no problem at all :(

It is different than #1 because I am already running

node -v
v13.1.0

When running the api through the console, this is the next output I see:

1/4/2020, 11:06:43 PM - DEBUG: Received new input data:
1/4/2020, 11:06:43 PM - DEBUG: <iq id="52a4r7a15z" type="result" xmlns="jabber:client"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><jid>__JID__@busch-jaeger.de/freeathome-api</jid></bind></iq>
1/4/2020, 11:06:43 PM - DEBUG: Received stanza:
1/4/2020, 11:06:43 PM - DEBUG: <ref *1> Element {
  name: 'iq',
  parent: null,
  children: [
    Element {
      name: 'bind',
      parent: [Circular *1],
      children: [Array],
      attrs: [Object]
    }
  ],
  attrs: { id: '52a4r7a15z', type: 'result', xmlns: 'jabber:client' }
}

[mobilutz]

Temporary fix I did was using a screen session.

I would really like to run the api through systemctl. Can you point me in a direction so I can look for the problem?

[henry-spanka]

You may have installed multiple node versions. Check with: dpkg -l | grep node

[mobilutz]

You may have installed multiple node versions. Check with: dpkg -l | grep node

Thanks for the hint. That was the case! And of course the problem was between the chair and screen 😉

In console, it used /usr/local/bin/node but through systemd it used /usr/bin/node.

/usr/bin/node --version
v8.16.2

One really always have to be careful when using nodejs. And even more when using npm 😉

PS: Vielen Dank fuer die Implementierung hier, ich arbeite gerade an einem ioBroker Adapter damit man free@home direkt dort einbinden kann.

[henry-spanka]

👍 Glad you could solve it.

PS: Sieht gut aus. Habe bei mir aber alles mit Homebridge + ein Grafana Panel mit Node-RED Anbindung gelöst, da dort viele unterschiedliche Daten zusammenkommen. Never change a running system, d.h. bleibt das jetzt erstmal alles so wie es ist ;) Eventuell schaue ich mir irgendwann mal ioBroker an wenn ich Zeit habe.