DewGew/Domoticz-Google-Assistant

DZGA working but returning an error in version 1.22.32 after each command

wimmme opened this issue · 11 comments

Describe the bug:

Executing any command works BUT ends with an error (which also spoken out by the google assistant)

Expected behavior:

no error like before (1.11.10, beta version on docker hub, works without this issue)

Desktop (please complete the following information):

  • Domoticz Version: 2022.2 (build 14863)
  • DZGA Version: 1.22.32 (docker dewgew/domoticz-google-assistant:latest)
  • Python Version : the one from the docker container

Smartphone (please complete the following information):

  • Device: any (Sonos google assistant, android google assistant, ...)

Logs.

--------------
BAD (1.22.32):
--------------

2022-12-20 14:45:08 - DEBUG - Host: xxx.ddns.net
X-Real-IP: xx.xx.xx.xx
X-Forwarded-For: xx.xx.xx.xx
X-Scheme: https
Connection: close
Content-Length: 308
Content-Type: application/json;charset=UTF-8
Google-Assistant-API-Version: v1
Authorization: Bearer xxxxxxxxxxxxxxxxxxxxxxx
User-Agent: Mozilla/5.0 (compatible; Google-Cloud-Functions/2.1; +http://www.google.com/bot.html)
Accept-Encoding: gzip, deflate, br


2022-12-20 14:45:08 - INFO - {
  "inputs": [
    {
      "context": {
        "locale_country": "BE",
        "locale_language": "nl"
      },
      "intent": "action.devices.EXECUTE",
      "payload": {
        "commands": [
          {
            "devices": [
              {
                "id": "ColorSwitch3717"
              },
              {
                "id": "ColorSwitch3711"
              }
            ],
            "execution": [
              {
                "command": "action.devices.commands.OnOff",
                "params": {
                  "on": true
                }
              }
            ]
          }
        ]
      }
    }
  ],
  "requestId": "17087538846971864840"
}
2022-12-20 14:45:08 - INFO - Google Assistant requests an action.devices.EXECUTE
2022-12-20 14:45:08 - DEBUG - Starting new HTTP connection (1): xx.xx.xx.xx:8080
2022-12-20 14:45:08 - DEBUG - http://xx.xx.xx.xx:8080 "GET /json.htm?type=command¶m=switchlight&idx=3717&switchcmd=On HTTP/1.1" 200 47
2022-12-20 14:45:08 - ERROR - Extra data: line 1 column 3 (char 2)
2022-12-20 14:45:08 - ERROR - Error handling message {'inputs': [{'context': {'locale_country': 'BE', 'locale_language': 'nl'}, 'intent': 'action.devices.EXECUTE', 'payload': {'commands': [{'devices': [{'id': 'ColorSwitch3717'}, {'id': 'ColorSwitch3711'}], 'execution': [{'command': 'action.devices.commands.OnOff', 'params': {'on': True, 'online': True}}]}]}}], 'requestId': '17087538846971864840'}: {'errorCode': 'unknownError'}

--------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------

---------------
GOOD (1.11.10):
---------------

2022-12-20 15:10:51 - DEBUG - Host: xxx.ddns.net
X-Real-IP: xx.xx.xx.xx
X-Forwarded-For: xx.xx.xx.xx
X-Scheme: https
Connection: close
Content-Length: 309
Content-Type: application/json;charset=UTF-8
Google-Assistant-API-Version: v1
Authorization: Bearer xxxxxxxxxxxxxxxxxxxxxxx
User-Agent: Mozilla/5.0 (compatible; Google-Cloud-Functions/2.1; +http://www.google.com/bot.html)
Accept-Encoding: gzip, deflate, br


2022-12-20 15:10:51 - INFO - Request {
  "inputs": [
    {
      "context": {
        "locale_country": "BE",
        "locale_language": "nl"
      },
      "intent": "action.devices.EXECUTE",
      "payload": {
        "commands": [
          {
            "devices": [
              {
                "id": "ColorSwitch3717"
              },
              {
                "id": "ColorSwitch3711"
              }
            ],
            "execution": [
              {
                "command": "action.devices.commands.OnOff",
                "params": {
                  "on": false
                }
              }
            ]
          }
        ]
      }
    }
  ],
  "requestId": "10946522902634247739"
}
2022-12-20 15:10:51 - DEBUG - Starting new HTTP connection (1): xx.xx.xx.xx:8080
2022-12-20 15:10:51 - DEBUG - http://xx.xx.xx.xx:8080 "GET /json.htm?type=command¶m=switchlight&idx=3717&switchcmd=Off HTTP/1.1" 200 47
2022-12-20 15:10:51 - DEBUG - Starting new HTTP connection (1): xx.xx.xx.xx:8080
2022-12-20 15:10:51 - DEBUG - http://xx.xx.xx.xx:8080 "GET /json.htm?type=command¶m=switchlight&idx=3711&switchcmd=Off HTTP/1.1" 200 47
2022-12-20 15:10:51 - DEBUG - Starting new HTTP connection (1): xx.xx.xx.xx:8080
2022-12-20 15:10:51 - DEBUG - http://xx.xx.xx.xx:8080 "GET /json.htm?type=devices&rid=3717 HTTP/1.1" 200 680
2022-12-20 15:10:51 - DEBUG - {
  "ShellyBureauLedKast": {
    "idx": 3717,
    "type": "ColorSwitch",
    "state": "On",
    "lastupdate": "2022-12-20 14:45:09",
    "willReportState": true
  }
}
2022-12-20 15:10:51 - DEBUG - Starting new HTTP connection (1): xx.xx.xx.xx:8080
2022-12-20 15:10:51 - DEBUG - http://xx.xx.xx.xx:8080 "GET /json.htm?type=devices&rid=3711 HTTP/1.1" 200 682
2022-12-20 15:10:51 - DEBUG - {
  "ShellyBureauLedRaam": {
    "idx": 3711,
    "type": "ColorSwitch",
    "state": "Off",
    "lastupdate": "2022-12-20 14:44:06",
    "willReportState": true
  }
}






Check your settng in voicecontrol tags or in device_config
You have this Error: Extra data: line 1 column 3 (char 2). I have never seen this

I don't have any special device config or voicecontrol settings. Had one device config, left that out but same result.

This is my config.yaml:

CheckForUpdates: false
ClientID: xxxxxxx
ClientSecret: xxxxxxxx
Domoticz:
  ip: http://192.168.0.xx
  password: xxx
  port: '8080'
  roomplan: '0'
  switchProtectionPass: 'false'
  username: xxx
Low_battery_limit: 9
PidFile: ''
auth_pass: xxx
auth_user: xxx
loglevel: Debug
logtofile: true
ngrok_auth_token: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
ngrok_tunnel: false
pathToLogFile: /config
port_number: 3030
ssl_cert: None
ssl_key: None
use_ssl: false
userinterface: true

I noticed that when editing the config via the webinterface , it adds linebreaks (^M), but that doesn't seem to bother dzga.
Occasionally, it adds an extra empty line at the end, which causes 'Connection to Domoticz lost'.

Could it be something in my nginx

I have to add that in V1.11.10 everything works, except for requesting the temperature from a device.
Already opened a bug report earlier but without response (no offense, love your work)
#271
It works for thermostat devices but not for temperature devices.
Seems like the same error i receive in the latest version for every device.
I use the docker-compose version, so pretty standard config i guess.
My domoticz is also the latest beta official docker version.

Error in 1.11.10 for returning temperature:

2022-12-21 21:01:00 - INFO - Request {
  "inputs": [
    {
      "intent": "action.devices.QUERY",
      "payload": {
        "devices": [
          {
            "id": "Temperature2495"
          }
        ]
      }
    }
  ],
  "requestId": "1431765284992416987"
}
2022-12-21 21:01:00 - INFO - Response {
  "devices": {
    "Temperature2495": {
      "descriptiveCapacityRemaining": "FULL",
      "online": true,
      "thermostatHumidityAmbient": 51,
      "thermostatMode": "heat",
      "thermostatTemperatureAmbient": 1.0,
      "thermostatTemperatureSetpoint": 1.0
    }
  }
}
2022-12-21 21:01:00 - ERROR - Extra data: line 1 column 3 (char 2)
2022-12-21 21:01:00 - ERROR - Error handling message {'inputs': [{'intent': 'action.devices.QUERY', 'payload': {'devices': [{'id': 'Temperature2495'}]}}], 'requestId': '1431765284992416987'}: {'errorCode': 'unknownError'}



Turn on HomeGraph API

Direct link to activate : https://console.cloud.google.com/apis/api/homegraph.googleapis.com/overview

It is already enabled. Don't see how this could be working without.
Like I said, got DZGA working since 03/2020, docker container was on 1.11.9.
1.11.10 works also.

Nothing to do with homegraph. Its a json error somewhere with json loads or dumps. I cant reproduce this error. I dont get this error. so its hard to track this issue
.

Only thing I could think off that's in between is NGINX.
This is my config, seems to be correct if I compare others configs on the interwebs:

location /assistant/ {
rewrite ^/assistant/?(.*) /$1 break;
proxy_pass http://192.168.0.xx:3030; 
proxy_set_header Host $host;
proxy_set_header X-Real-IP $remote_addr;
proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
proxy_set_header X-Scheme $scheme;
proxy_read_timeout  90;
}

One thing i have on all versions is that when using the sync button on the settings pages i receive the same error:
Page not found!: Extra data: line 1 column 3 (char 2)

Just went through my docker images and found the one i was running on for about 1.5year, 1.10.9, it has that too.
Initiating sync from sonos google assistant works fine

Since I updated dzga from a (very) old version yesterday, I also get error messages after the action was execute just fine. I have only noticed these error messages when activating scenes. I am not sure it has anything to do with the upgrade (see below)

In my case I have excluded nginx as a cause by configuring ssl on dzga itself and mapping the port on the router directly to dzga. The result was the same (so I reverted back tot using nginx)

I suspect is has something to do with homegraph. When I remove the smart-home-key.json file it works just fine and doesn't generate the error message. When I re-anable the file the error message returns.
I have created a new service-account and key (I am sure it is for the right project... I only have 1 ;-)
I have also re-saved the account linking and re-started the test on the google action console.

The Domoticz version is 2022.2. Both dzga and domoticz are running in (separate) docker containers on Debian (all recent versions)
My old version never had the smart-home-key.json file, so that's why I cannot be sure this is even caused by the update from very old to 1.23.2.

I hope this description will be helpful, but apologize if my problem turns out to be unrelated.

Here is the log:

2023-01-21 11:53:55 - DEBUG - Starting new HTTP connection (1): 192.168.19.222:8080
2023-01-21 11:53:56 - DEBUG - http://192.168.19.222:8080 "GET /json.htm?type=command¶m=switchscene&idx=2&switchcmd=On HTTP/1.1" 200 47
2023-01-21 11:53:56 - DEBUG - Starting new HTTPS connection (1): homegraph.googleapis.com:443
2023-01-21 11:53:56 - DEBUG - https://homegraph.googleapis.com:443 "POST /v1/devices:reportStateAndNotification HTTP/1.1" 400 None
2023-01-21 11:53:56 - ERROR - 400 Client Error: Bad Request for url: https://homegraph.googleapis.com/v1/devices:reportStateAndNotification
2023-01-21 11:53:56 - ERROR - Error handling message {'inputs': [{'context': {'locale_country': 'US', 'locale_language': 'en'}, 'intent': 'action.devices.EXECUTE', 'payload': {'commands': [{'devices': [{'id': 'Scene2'}], 'execution': [{'command': 'action.devices.commands.ActivateScene', 'params': {'deactivate': False, 'online': True}}]}]}}], 'requestId': '5032422287475997968'}: {'errorCode': 'unknownError'}

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 5 days

Up to avoid stale. Have a complete second installation of domoticz and dzga to test, will provide feedback