Not getting a "gassistantFHEM.loginURL"

[Zaleo]

Hello all,

It has been some time that I worked with FHEM, and my Pi3 with CCD (v1.1) really needed an update.
My German is not great, as I am Dutch, however I have tried to follow the instructions on: https://wiki.fhem.de/wiki/Google_Assistant_FHEM_Connect#Installation

Ca. 30s warten bis ein Reading gassistantFHEM.loginURL erscheint. Wenn der Link nicht erscheint, dann bitte in der Konsole einmal "gassistant-fhem" ausführen und die Fehlermeldung beachten. Gerne diese im Forum posten.

So here I am with my problem, I do not get a google login URL, and I did notice an error in the gassistant log file.

Code (gassistant log) Auswählen Erweitern

/usr/local/lib/node_modules/gassistant-fhem/node_modules/sync-rpc/lib/index.js:80
    throw new Error(
    ^

Error: Timed out waiting for sync-rpc server to start (it should respond with "pong" when sent "ping"):

events.js:174
      throw er; // Unhandled 'error' event
      ^

Error: connect ECONNREFUSED 127.0.0.1:40723
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1104:14)
Emitted 'error' event at:
    at emitErrorNT (internal/streams/destroy.js:82:8)
    at emitErrorAndCloseNT (internal/streams/destroy.js:50:3)
    at process._tickCallback (internal/process/next_tick.js:63:19)


    at waitForAlive (/usr/local/lib/node_modules/gassistant-fhem/node_modules/sync-rpc/lib/index.js:80:11)
    at start (/usr/local/lib/node_modules/gassistant-fhem/node_modules/sync-rpc/lib/index.js:40:3)
    at sendMessage (/usr/local/lib/node_modules/gassistant-fhem/node_modules/sync-rpc/lib/index.js:117:17)
    at createClient (/usr/local/lib/node_modules/gassistant-fhem/node_modules/sync-rpc/lib/index.js:157:27)
    at Object.<anonymous> (/usr/local/lib/node_modules/gassistant-fhem/node_modules/sync-request/lib/index.js:16:14)
    at Module._compile (internal/modules/cjs/loader.js:689:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:700:10)
    at Module.load (internal/modules/cjs/loader.js:599:32)
    at tryModuleLoad (internal/modules/cjs/loader.js:538:12)
    at Function.Module._load (internal/modules/cjs/loader.js:530:3)
Loading cli.js...
Loading version.js...
Loading server.js...
Loading user.js...
Loading logger.js...
Loading fhem.js...
Loading database.js...

OS:Raspbian GNU/Linux 10 (buster)

# npm -v
6.10.1

# node -v
v10.15.2

Fhem version 5.9.19853

gassistant-fhem@2.0.0
sync-rpc@1.3.4

Did check netstat too see if node was lisseinging on ports in the higher ranges, and yes this seems the case, but on different ports numbers.

root@Domotica:/opt/fhem/log# netstat -tulpn | grep LISTEN
tcp        0      0 0.0.0.0:7072            0.0.0.0:*               LISTEN      390/perl
tcp        0      0 0.0.0.0:8083            0.0.0.0:*               LISTEN      390/perl
tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      389/sshd
tcp6       0      0 :::36127                :::*                    LISTEN      663/node
tcp6       0      0 :::46729                :::*                    LISTEN      976/node
tcp6       0      0 :::22                   :::*                    LISTEN      389/sshd

Please do you have any advice?

With kind regards,
Zeo

[dominik]

Hi,
do you have any special security settings on your system? It looks like the internal rpc communication isn't working.

Cheers

[Zaleo]

Thanks dominik for the effort.

do you have any special security settings on your system?

Not that I am aware, basic Raspbian Buster Lite image and followed the instructions on the busware.de (ccdv1) and FHEM website to get things running.

[amenomade]

What does

Code Auswählen Erweitern

ip asay?

[Zaleo]

What does
ip a
say?

Code (ip a) Auswählen Erweitern

1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host
       valid_lft forever preferred_lft forever
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default qlen 1000
    link/ether b8:27:eb:ba:b0:68 brd ff:ff:ff:ff:ff:ff
    inet 192.168.1.175/24 brd 192.168.1.255 scope global noprefixroute eth0
       valid_lft forever preferred_lft forever
    inet6 fe80::f6fe:57df:320f:6262/64 scope link
       valid_lft forever preferred_lft forever


[Zaleo]

The answer from dominik got me thinking 
I installed the light image of Raspbian, so thing I needed to start the portmapper.

Code Auswählen Erweitern

# sudo service portmap start

This did supress the error in the gassistant log...

Made it permanent

Code Auswählen Erweitern

# sudo systemctl enable portmap

But after a quick reboot, still I get an errormessage (Never got a loginURL).

[dominik]

Can you post the output from the gassistant-fhem log after the portmapper change?

[Zaleo]

Yes I can.

After a reboot, or a "set gassistant restart" I get an errors....

/usr/local/lib/node_modules/gassistant-fhem/node_modules/sync-rpc/lib/index.js:80
    throw new Error(
    ^

Error: Timed out waiting for sync-rpc server to start (it should respond with "pong" when sent "ping"):

events.js:174
      throw er; // Unhandled 'error' event
      ^

Error: connect ECONNREFUSED 127.0.0.1:45327
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1106:14)
Emitted 'error' event at:
    at emitErrorNT (internal/streams/destroy.js:91:
    at emitErrorAndCloseNT (internal/streams/destroy.js:59:3)
    at process._tickCallback (internal/process/next_tick.js:63:19)


    at waitForAlive (/usr/local/lib/node_modules/gassistant-fhem/node_modules/sync-rpc/lib/index.js:80:11)
    at start (/usr/local/lib/node_modules/gassistant-fhem/node_modules/sync-rpc/lib/index.js:40:3)
    at sendMessage (/usr/local/lib/node_modules/gassistant-fhem/node_modules/sync-rpc/lib/index.js:117:17)
    at createClient (/usr/local/lib/node_modules/gassistant-fhem/node_modules/sync-rpc/lib/index.js:157:27)
    at Object.<anonymous> (/usr/local/lib/node_modules/gassistant-fhem/node_modules/sync-request/lib/index.js:16:14)
    at Module._compile (internal/modules/cjs/loader.js:776:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:787:10)
    at Module.load (internal/modules/cjs/loader.js:653:32)
    at tryModuleLoad (internal/modules/cjs/loader.js:593:12)
    at Function.Module._load (internal/modules/cjs/loader.js:585:3)
Loading cli.js...
Loading version.js...
Loading server.js...
Loading user.js...
Loading logger.js...
Loading fhem.js...
Loading database.js...

When I do "sudo service portmap start" in the console and then a "set gassistant restart" the logging looks like:

Loading cli.js...
Loading version.js...
Loading server.js...
Loading user.js...
Loading logger.js...
Loading fhem.js...
Loading database.js...

No error....

So I think the portmap service is started at boot or after FHEM, or is not related.

Code Auswählen Erweitern

# sudo systemctl is-active portmap
active


However in both situations I do not get a loginURL. 

Hope this is clear?

[dominik]

Even after a minute or so nothing more appears in the log after the restart? Can you please check FHEM log as well in that case.

[Zaleo]

Waited 10 minutes now... Still no URL

Code (FHEM log) Auswählen Erweitern

2019.07.21 21:24:56 1: Including fhem.cfg
2019.07.21 21:24:59 3: WEB: port 8083 opened
2019.07.21 21:24:59 3: telnetPort: port 7072 opened
2019.07.21 21:25:00 3: Opening CCD device /dev/ttyAMA0
2019.07.21 21:25:00 3: Setting CCD serial parameters to 38400,8,N,1
2019.07.21 21:25:00 3: CCD: Possible commands: mbCFiAZGMRTVWXefltux
2019.07.21 21:25:00 3: CCD device opened
2019.07.21 21:25:02 2: eventTypes: loaded 32 events from ./log/eventTypes.txt
2019.07.21 21:25:02 1: Including ./log/fhem.save
2019.07.21 21:25:02 2: gassistant: starting gassistant-fhem: /usr/local/bin/gassistant-fhem -c ./gassistant-fhem.cfg
2019.07.21 21:25:02 3: gassistant: starting
2019.07.21 21:25:02 3: gassistant: using logfile: ./log/gassistant-2019-07-21.log
2019.07.21 21:25:02 0: Featurelevel: 5.9
2019.07.21 21:25:02 0: Server started with 27 defined entities (fhem.pl:19805/2019-07-09 perl:5.028001 os:linux user:fhem pid:374)
2019.07.21 21:25:41 3: gassistant: read: end of file reached while sysread


Here I got the error, and restarted gassistant - No more error.

Code (FHEM log) Auswählen Erweitern


2019.07.21 21:26:49 3: gassistant: stopped
2019.07.21 21:26:49 2: gassistant: starting gassistant-fhem: /usr/local/bin/gassistant-fhem -c ./gassistant-fhem.cfg
2019.07.21 21:26:49 3: gassistant: starting
2019.07.21 21:26:49 3: gassistant: using logfile: ./log/gassistant-2019-07-21.log

[dominik]

Stop gassistant again and try to start it in the console. Just type gassistant-fhem, nothing more. I hope you get some more log messages there.

[Zaleo]

Code (console) Auswählen Erweitern

root@Domotica:/opt/fhem# /usr/local/bin/gassistant-fhem -c ./gassistant-fhem.cfg
Loading cli.js...
Loading version.js...
Loading server.js...
Loading user.js...
Loading logger.js...
Loading fhem.js...
Loading database.js...
Illegal instruction
root@Domotica:/opt/fhem#


Illegal instruction 

[dominik]

Looks like a grpc issue.
Try
npm rebuild --build-from-source --unsafe-perm grpc
It can take 2 hours to compile.

[Zaleo]

Cooking 

Code (console) Auswählen Erweitern

root@Domotica:/usr/local/lib/node_modules/gassistant-fhem#  npm rebuild --build-from-source --unsafe-perm grpc

> grpc@1.20.0 install /usr/local/lib/node_modules/gassistant-fhem/node_modules/grpc
> node-pre-gyp install --fallback-to-build --library=static_library

node-pre-gyp WARN Using request for node-pre-gyp https download
make: Entering directory '/usr/local/lib/node_modules/gassistant-fhem/node_modules/grpc/build'
  CXX(target) Release/obj.target/grpc/deps/grpc/src/core/lib/surface/init.o
etc. etc.



@dominik thanks for all the help this far!!!! It is appreciated.

Will come back when finished.

[Zaleo]

The rebuild failed.... 

<-- snip-->
CXX(target) Release/obj.target/grpc/deps/grpc/src/core/ext/filters/client_channel/lb_policy/grpclb/load_balancer_api.o
../deps/grpc/src/core/ext/filters/client_channel/lb_policy/grpclb/load_balancer_api.cc: In function 'grpc_grpclb_request* grpc_grpclb_request_create(const char*)':
../deps/grpc/src/core/ext/filters/client_channel/lb_policy/grpclb/load_balancer_api.cc:70:10: error: 'char* strncpy(char*, const char*, size_t)' specified bound 128 equals destination size [-Werror=stringop-truncation]
   strncpy(req->initial_request.name, lb_service_name,
   ~~~~~~~^~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
           GRPC_GRPCLB_SERVICE_NAME_MAX_LENGTH);
           ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
cc1plus: all warnings being treated as errors
make: *** [grpc.target.mk:482: Release/obj.target/grpc/deps/grpc/src/core/ext/filters/client_channel/lb_policy/grpclb/load_balancer_api.o] Error 1
make: Leaving directory '/usr/local/lib/node_modules/gassistant-fhem/node_modules/grpc/build'
gyp ERR! build error
gyp ERR! stack Error: `make` failed with exit code: 2
gyp ERR! stack     at ChildProcess.onExit (/usr/local/lib/node_modules/npm/node_modules/node-gyp/lib/build.js:262:23)
gyp ERR! stack     at ChildProcess.emit (events.js:198:13)
gyp ERR! stack     at Process.ChildProcess._handle.onexit (internal/child_process.js:248:12)
gyp ERR! System Linux 4.19.57+
gyp ERR! command "/usr/local/bin/node" "/usr/local/lib/node_modules/npm/node_modules/node-gyp/bin/node-gyp.js" "build" "--fallback-to-build" "--library=static_library" "--module=/usr/local/lib/node_modules/gassistant-fhem/node_modules/grpc/src/node/extension_binary/node-v64-linux-arm-glibc/grpc_node.node" "--module_name=grpc_node" "--module_path=/usr/local/lib/node_modules/gassistant-fhem/node_modules/grpc/src/node/extension_binary/node-v64-linux-arm-glibc" "--napi_version=4" "--node_abi_napi=napi" "--napi_build_version=0" "--node_napi_label=node-v64"
gyp ERR! cwd /usr/local/lib/node_modules/gassistant-fhem/node_modules/grpc
gyp ERR! node -v v10.16.0
gyp ERR! node-gyp -v v3.8.0
gyp ERR! not ok
node-pre-gyp ERR! build error
node-pre-gyp ERR! stack Error: Failed to execute '/usr/local/bin/node /usr/local/lib/node_modules/npm/node_modules/node-gyp/bin/node-gyp.js build --fallback-to-build --library=static_library --module=/usr/local/lib/node_modules/gassistant-fhem/node_modules/grpc/src/node/extension_binary/node-v64-linux-arm-glibc/grpc_node.node --module_name=grpc_node --module_path=/usr/local/lib/node_modules/gassistant-fhem/node_modules/grpc/src/node/extension_binary/node-v64-linux-arm-glibc --napi_version=4 --node_abi_napi=napi --napi_build_version=0 --node_napi_label=node-v64' (1)
node-pre-gyp ERR! stack     at ChildProcess.<anonymous> (/usr/local/lib/node_modules/gassistant-fhem/node_modules/grpc/node_modules/node-pre-gyp/lib/util/compile.js:83:29)
node-pre-gyp ERR! stack     at ChildProcess.emit (events.js:198:13)
node-pre-gyp ERR! stack     at maybeClose (internal/child_process.js:982:16)
node-pre-gyp ERR! stack     at Process.ChildProcess._handle.onexit (internal/child_process.js:259:5)
node-pre-gyp ERR! System Linux 4.19.57+
node-pre-gyp ERR! command "/usr/local/bin/node" "/usr/local/lib/node_modules/gassistant-fhem/node_modules/grpc/node_modules/.bin/node-pre-gyp" "install" "--fallback-to-build" "--library=static_library"
node-pre-gyp ERR! cwd /usr/local/lib/node_modules/gassistant-fhem/node_modules/grpc
node-pre-gyp ERR! node -v v10.16.0
node-pre-gyp ERR! node-pre-gyp -v v0.12.0
node-pre-gyp ERR! not ok
Failed to execute '/usr/local/bin/node /usr/local/lib/node_modules/npm/node_modules/node-gyp/bin/node-gyp.js build --fallback-to-build --library=static_library --module=/usr/local/lib/node_modules/gassistant-fhem/node_modules/grpc/src/node/extension_binary/node-v64-linux-arm-glibc/grpc_node.node --module_name=grpc_node --module_path=/usr/local/lib/node_modules/gassistant-fhem/node_modules/grpc/src/node/extension_binary/node-v64-linux-arm-glibc --napi_version=4 --node_abi_napi=napi --napi_build_version=0 --node_napi_label=node-v64' (1)
npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! grpc@1.20.0 install: `node-pre-gyp install --fallback-to-build --library=static_library`
npm ERR! Exit status 1
npm ERR!
npm ERR! Failed at the grpc@1.20.0 install script.
npm ERR! This is probably not a problem with npm. There is likely additional logging output above.

npm ERR! A complete log of this run can be found in:
npm ERR!     /root/.npm/_logs/2019-07-21T21_01_37_769Z-debug.log

<-- snip-->
75 info lifecycle grpc@1.20.0~install: Failed to exec install script
476 verbose stack Error: grpc@1.20.0 install: `node-pre-gyp install --fallback-to-build --library=static_library`
476 verbose stack Exit status 1
476 verbose stack     at EventEmitter.<anonymous> (/usr/local/lib/node_modules/npm/node_modules/npm-lifecycle/index.js:301:16)
476 verbose stack     at EventEmitter.emit (events.js:198:13)
476 verbose stack     at ChildProcess.<anonymous> (/usr/local/lib/node_modules/npm/node_modules/npm-lifecycle/lib/spawn.js:55:14)
476 verbose stack     at ChildProcess.emit (events.js:198:13)
476 verbose stack     at maybeClose (internal/child_process.js:982:16)
476 verbose stack     at Process.ChildProcess._handle.onexit (internal/child_process.js:259:5)
477 verbose pkgid grpc@1.20.0
478 verbose cwd /usr/local/lib/node_modules/gassistant-fhem
479 verbose Linux 4.19.57+
480 verbose argv "/usr/local/bin/node" "/usr/local/bin/npm" "rebuild" "--build-from-source" "--unsafe-perm" "grpc"
481 verbose node v10.16.0
482 verbose npm  v6.9.0
483 error code ELIFECYCLE
484 error errno 1
485 error grpc@1.20.0 install: `node-pre-gyp install --fallback-to-build --library=static_library`
485 error Exit status 1
486 error Failed at the grpc@1.20.0 install script.
486 error This is probably not a problem with npm. There is likely additional logging output above.
487 verbose exit [ 1, true ]