ReportState: Google Home App always shows off / switches back to off

[fightforlife]

Hi i8beef,

I created a "testSwitch" which should report its state to homegraph. To simplify things I set the state topic to the standard delegate topic. Now everytime I set the device to ON via the Google Home App, the switch shows ON for a second an then switches back to OFF in the App. (the real state is still ON, no MQTT message with "on": false.) As far as I can see the MQTT payload is correct

[11:38:54 VRB] RX (55 bytes) <<< Publish: [Topic=google/home/execution/testSwitch/OnOff] [Payload.Length=11] [QoSLevel=AtLeastOnce] [Dup=False] [Retain=False] [PacketIdentifier=3]
[11:38:54 INF] MQTT message received for topic google/home/execution/testSwitch/OnOff: {"on":true}

Most likely this is a configuration error on my side. But I currently have no clue what to look for.

Device configuration of "testSwitch"

  "testSwitch": {
    "id": "testSwitch",
    "type": "action.devices.types.SWITCH",
    "disabled": false,
    "willReportState": true,
    "roomHint": "Home",
    "name": {
      "defaultNames": [],
      "name": "testSwitch",
      "nicknames": []
    },
    "deviceInfo": null,
    "traits": [
      {
        "trait": "action.devices.traits.OnOff",
        "attributes": {
          "commandOnlyOnOff": false,
          "queryOnlyOnOff": false
        },
        "commands": {
          "action.devices.commands.OnOff": {
            "on": ""
          }
        },
        "state": {
          "on": {
            "topic": "google/home/execution/testSwitch/OnOff",
            "valueMap": null
          }
        },
        "challenge": null
      }
    ],
    "customData": null
  },

LOG of switching "testSwitch" on via Google Home App.

[11:38:54 INF] Request starting HTTP/1.1 POST http://home.domain.com/smarthome application/json;charset=UTF-8 277
[11:38:54 VRB] All hosts are allowed.
[11:38:54 DBG] Connection id "0HM5F2710FESO", Request id "0HM5F2710FESO:00000008": started reading request body.
[11:38:54 DBG] Connection id "0HM5F2710FESO", Request id "0HM5F2710FESO:00000008": done reading request body.
[11:38:54 VRB] Http Request Body: {"inputs":[{"context":{"locale_country":"US","locale_language":"en"},"intent":"action.devices.EXECUTE","payload":{"commands":[{"devices":[{"id":"testSwitch"}],"execution":[{"command":"action.devices.commands.OnOff","params":{"on":true}}]}]}],"requestId":"7929634488463653273"}
[11:38:54 DBG] POST requests are not supported
[11:38:54 DBG] 1 candidate(s) found for the request path '/smarthome'
[11:38:54 DBG] Endpoint 'HomeAutio.Mqtt.GoogleHome.Controllers.GoogleHomeController.Post (HomeAutio.Mqtt.GoogleHome)' with route pattern 'smarthome' is valid for the request path '/smarthome'
[11:38:54 DBG] Request matched endpoint 'HomeAutio.Mqtt.GoogleHome.Controllers.GoogleHomeController.Post (HomeAutio.Mqtt.GoogleHome)'
[11:38:54 DBG] AuthenticationScheme: Cookies was not authenticated.
[11:38:54 INF] Successfully validated the token.
[11:38:54 DBG] AuthenticationScheme: Bearer was successfully authenticated.
[11:38:54 INF] Authorization was successful.
[11:38:54 INF] Executing endpoint 'HomeAutio.Mqtt.GoogleHome.Controllers.GoogleHomeController.Post (HomeAutio.Mqtt.GoogleHome)'
[11:38:54 INF] Route matched with {action = "Post", controller = "GoogleHome"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.IActionResult Post(HomeAutio.Mqtt.GoogleHome.Models.Request.Request) on controller HomeAutio.Mqtt.GoogleHome.Controllers.GoogleHomeController (HomeAutio.Mqtt.GoogleHome).
[11:38:54 DBG] Execution plan of authorization filters (in the following order): ["None"]
[11:38:54 DBG] Execution plan of resource filters (in the following order): ["Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter"]
[11:38:54 DBG] Execution plan of action filters (in the following order): ["Microsoft.AspNetCore.Mvc.Filters.ControllerActionFilter (Order: -2147483648)", "Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter (Order: -3000)"]
[11:38:54 DBG] Execution plan of exception filters (in the following order): ["None"]
[11:38:54 DBG] Execution plan of result filters (in the following order): ["Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter"]
[11:38:54 VRB] Resource Filter: Before executing OnResourceExecuting on filter Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter.
[11:38:54 VRB] Resource Filter: After executing OnResourceExecuting on filter Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter.
[11:38:54 DBG] Executing controller factory for controller HomeAutio.Mqtt.GoogleHome.Controllers.GoogleHomeController (HomeAutio.Mqtt.GoogleHome)
[11:38:54 DBG] Executed controller factory for controller HomeAutio.Mqtt.GoogleHome.Controllers.GoogleHomeController (HomeAutio.Mqtt.GoogleHome)
[11:38:54 DBG] Attempting to bind parameter 'request' of type 'HomeAutio.Mqtt.GoogleHome.Models.Request.Request' ...
[11:38:54 DBG] Attempting to bind parameter 'request' of type 'HomeAutio.Mqtt.GoogleHome.Models.Request.Request' using the name '' in request data ...
[11:38:54 DBG] Rejected input formatter 'Microsoft.AspNetCore.Mvc.Formatters.NewtonsoftJsonPatchInputFormatter' for content type 'application/json;charset=UTF-8'.
[11:38:54 DBG] Selected input formatter 'Microsoft.AspNetCore.Mvc.Formatters.NewtonsoftJsonInputFormatter' for content type 'application/json;charset=UTF-8'.
[11:38:54 DBG] Done attempting to bind parameter 'request' of type 'HomeAutio.Mqtt.GoogleHome.Models.Request.Request'.
[11:38:54 DBG] Done attempting to bind parameter 'request' of type 'HomeAutio.Mqtt.GoogleHome.Models.Request.Request'.
[11:38:54 DBG] Attempting to validate the bound parameter 'request' of type 'HomeAutio.Mqtt.GoogleHome.Models.Request.Request' ...
[11:38:54 DBG] Done attempting to validate the bound parameter 'request' of type 'HomeAutio.Mqtt.GoogleHome.Models.Request.Request'.
[11:38:54 VRB] Action Filter: Before executing OnActionExecutionAsync on filter Microsoft.AspNetCore.Mvc.Filters.ControllerActionFilter.
[11:38:54 VRB] Action Filter: Before executing OnActionExecuting on filter Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter.
[11:38:54 VRB] Action Filter: After executing OnActionExecuting on filter Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter.
[11:38:54 INF] Executing action method HomeAutio.Mqtt.GoogleHome.Controllers.GoogleHomeController.Post (HomeAutio.Mqtt.GoogleHome) - Validation state: Valid
[11:38:54 VRB] Executing action method HomeAutio.Mqtt.GoogleHome.Controllers.GoogleHomeController.Post (HomeAutio.Mqtt.GoogleHome) with arguments (["HomeAutio.Mqtt.GoogleHome.Models.Request.Request"])
[11:38:54 INF] Received EXECUTE intent for commands: action.devices.commands.OnOff
[11:38:54 VRB] TX (55 bytes) >>> Publish: [Topic=google/home/execution/testSwitch/OnOff] [Payload.Length=11] [QoSLevel=AtLeastOnce] [Dup=False] [Retain=False] [PacketIdentifier=6]
[11:38:54 INF] Executed action method HomeAutio.Mqtt.GoogleHome.Controllers.GoogleHomeController.Post (HomeAutio.Mqtt.GoogleHome), returned result Microsoft.AspNetCore.Mvc.OkObjectResult in 1.3412ms.
[11:38:54 VRB] Action Filter: Before executing OnActionExecuted on filter Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter.
[11:38:54 VRB] Action Filter: After executing OnActionExecuted on filter Microsoft.AspNetCore.Mvc.ModelBinding.UnsupportedContentTypeFilter.
[11:38:54 VRB] Action Filter: After executing OnActionExecutionAsync on filter Microsoft.AspNetCore.Mvc.Filters.ControllerActionFilter.
[11:38:54 VRB] Result Filter: Before executing OnResultExecuting on filter Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter.
[11:38:54 VRB] Result Filter: After executing OnResultExecuting on filter Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter.
[11:38:54 VRB] Before executing action result Microsoft.AspNetCore.Mvc.OkObjectResult.
[11:38:54 DBG] List of registered output formatters, in the following order: ["Microsoft.AspNetCore.Mvc.Formatters.HttpNoContentOutputFormatter", "Microsoft.AspNetCore.Mvc.Formatters.StringOutputFormatter", "Microsoft.AspNetCore.Mvc.Formatters.StreamOutputFormatter", "Microsoft.AspNetCore.Mvc.Formatters.NewtonsoftJsonOutputFormatter"]
[11:38:54 DBG] No information found on request to perform content negotiation.
[11:38:54 DBG] Attempting to select an output formatter without using a content type as no explicit content types were specified for the response.
[11:38:54 DBG] Attempting to select the first formatter in the output formatters list which can write the result.
[11:38:54 DBG] Selected output formatter 'Microsoft.AspNetCore.Mvc.Formatters.NewtonsoftJsonOutputFormatter' and content type 'application/json' to write the response.
[11:38:54 INF] Executing OkObjectResult, writing value of type 'HomeAutio.Mqtt.GoogleHome.Models.Response.Response'.
[11:38:54 VRB] After executing action result Microsoft.AspNetCore.Mvc.OkObjectResult.
[11:38:54 VRB] Result Filter: Before executing OnResultExecuted on filter Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter.
[11:38:54 VRB] Result Filter: After executing OnResultExecuted on filter Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter.
[11:38:54 VRB] Resource Filter: Before executing OnResourceExecuted on filter Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter.
[11:38:54 VRB] RX (4 bytes) <<< PubAck: [PacketIdentifier=6] [ReasonCode=]
[11:38:54 VRB] Resource Filter: After executing OnResourceExecuted on filter Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter.
[11:38:54 INF] Executed action HomeAutio.Mqtt.GoogleHome.Controllers.GoogleHomeController.Post (HomeAutio.Mqtt.GoogleHome) in 3.6969ms
[11:38:54 INF] Executed endpoint 'HomeAutio.Mqtt.GoogleHome.Controllers.GoogleHomeController.Post (HomeAutio.Mqtt.GoogleHome)'
[11:38:54 VRB] Http Response: {"requestId":"7929634488463653273","payload":{"commands":[{"ids":["testSwitch"],"status":"SUCCESS","states":{"on":true,"online":true}}]}
[11:38:54 DBG] Connection id "0HM5F2710FESO" completed keep alive response.
[11:38:54 INF] Request finished HTTP/1.1 POST http://home.domain.com/smarthome application/json;charset=UTF-8 277 - 200 137 application/json;+charset=utf-8 6.2816ms
[11:38:54 VRB] RX (55 bytes) <<< Publish: [Topic=google/home/execution/testSwitch/OnOff] [Payload.Length=11] [QoSLevel=AtLeastOnce] [Dup=False] [Retain=False] [PacketIdentifier=3]
[11:38:54 INF] MQTT message received for topic google/home/execution/testSwitch/OnOff: {"on":true}
[11:38:54 DBG] Get/Refresh access token
[11:38:54 DBG] Built JWT request: XXX_VALID_TOKEN_XXX
[11:38:54 INF] Start processing HTTP request POST https://oauth2.googleapis.com/token
[11:38:54 VRB] Request Headers:
Content-Type: application/x-www-form-urlencoded
[11:38:54 INF] Sending HTTP request POST https://oauth2.googleapis.com/token
[11:38:54 VRB] Request Headers:
Content-Type: application/x-www-form-urlencoded
[11:38:54 INF] Received HTTP response headers after 44.6963ms - 200
[11:38:54 VRB] Response Headers:
Vary: X-Origin, Referer, Origin, Accept-Encoding
Date: Sat, 02 Jan 2021 11:38:54 GMT
Server: scaffolding, on, HTTPServer2
Cache-Control: private
X-XSS-Protection: 0
X-Frame-Options: SAMEORIGIN
X-Content-Type-Options: nosniff
Alt-Svc: h3-29=":443"; ma=2592000, h3-T051=":443"; ma=2592000, h3-Q050=":443"; ma=2592000, h3-Q046=":443"; ma=2592000, h3-Q043=":443"; ma=2592000, quic=":443"; ma=2592000
Accept-Ranges: none
Transfer-Encoding: chunked
Content-Type: application/json; charset=utf-8
[11:38:54 INF] End processing HTTP request after 45.505ms - 200
[11:38:54 VRB] Response Headers:
Vary: X-Origin, Referer, Origin, Accept-Encoding
Date: Sat, 02 Jan 2021 11:38:54 GMT
Server: scaffolding, on, HTTPServer2
Cache-Control: private
X-XSS-Protection: 0
X-Frame-Options: SAMEORIGIN
X-Content-Type-Options: nosniff
Alt-Svc: h3-29=":443"; ma=2592000, h3-T051=":443"; ma=2592000, h3-Q050=":443"; ma=2592000, h3-Q046=":443"; ma=2592000, h3-Q043=":443"; ma=2592000, quic=":443"; ma=2592000
Accept-Ranges: none
Transfer-Encoding: chunked
Content-Type: application/json; charset=utf-8
[11:38:54 DBG] Received access token: HomeAutio.Mqtt.GoogleHome.Models.GoogleHomeGraph.AccessTokenResponse
[11:38:54 INF] Start processing HTTP request POST https://homegraph.googleapis.com/v1/devices:reportStateAndNotification
[11:38:54 VRB] Request Headers:
Authorization: Bearer XXXX
Content-Type: application/json; charset=utf-8
[11:38:54 INF] Sending HTTP request POST https://homegraph.googleapis.com/v1/devices:reportStateAndNotification
[11:38:54 VRB] Request Headers:
Authorization: Bearer XXXX
Content-Type: application/json; charset=utf-8
[11:38:54 VRB] TX (4 bytes) >>> PubAck: [PacketIdentifier=3] [ReasonCode=Success]
[11:38:54 INF] Received HTTP response headers after 275.1117ms - 200
[11:38:54 VRB] Response Headers:
Vary: X-Origin, Referer, Origin, Accept-Encoding
Date: Sat, 02 Jan 2021 11:38:54 GMT
Server: ESF
Cache-Control: private
X-XSS-Protection: 0
X-Frame-Options: SAMEORIGIN
X-Content-Type-Options: nosniff
Alt-Svc: h3-29=":443"; ma=2592000, h3-T051=":443"; ma=2592000, h3-Q050=":443"; ma=2592000, h3-Q046=":443"; ma=2592000, h3-Q043=":443"; ma=2592000, quic=":443"; ma=2592000
Accept-Ranges: none
Transfer-Encoding: chunked
Content-Type: application/json; charset=utf-8
[11:38:54 INF] End processing HTTP request after 275.9027ms - 200
[11:38:54 VRB] Response Headers:
Vary: X-Origin, Referer, Origin, Accept-Encoding
Date: Sat, 02 Jan 2021 11:38:54 GMT
Server: ESF
Cache-Control: private
X-XSS-Protection: 0
X-Frame-Options: SAMEORIGIN
X-Content-Type-Options: nosniff
Alt-Svc: h3-29=":443"; ma=2592000, h3-T051=":443"; ma=2592000, h3-Q050=":443"; ma=2592000, h3-Q046=":443"; ma=2592000, h3-Q043=":443"; ma=2592000, quic=":443"; ma=2592000
Accept-Ranges: none
Transfer-Encoding: chunked
Content-Type: application/json; charset=utf-8
[11:38:54 INF] Google Home Graph updated for devices: testSwitch

[i8beef]

First, if you are using command delegation, you should be able to do this with your command config as it only uses the config there to attempt to map command params to individual MQTT topic notifications. If you aren't USING those notifications, you should just set the command to null so you ONLY get the automatic command topic publish, and it doesn't try and publish additional messages per-parameter. I know this isn't spelled out real clearly:

        "commands": {
          "action.devices.commands.OnOff": null
        },

As for your issue, I think you are sending the wrong value to "google/home/execution/testSwitch/OnOff" on changes."Command delegation" only applies to piping through the incoming command "as is", the state topics are still single value mappings. That is, it LOOKS like you were sending {"on":true}, when you SHOULD have send true.

[fightforlife]

Thank you very much! It is working now. 68fbc4deaa8ff1933f097d1484a50911386af61b helped to understand the examples.

Maybe in the future there could be a "delegation mode" for states?

[i8beef]

This app is a bridge between Google's API (request-response) and MQTT (pub-sub / asynchronous fire and forget); that difference limits my options. The alternative is to act as a bridge to arbitrary WebHooks instead and make someone do the JSON building themselves in something like node-red. That actually has a lot of advantages because Google implements different traits in a pure request-response manner that I CAN'T accommodate with a pub-sub model... but obviously would REQUIRE something like node-red in the picture... at which point I've basically recreated NORA, but with the OAuth / Google API handling moved locally.

That said, Google has added several traits that I can't handle with this model. I handle CameraStream for instance because... well because I wanted it... but there is a portion of it I can't support: auth tokens. That is a pure request-response action, where the request would require generating a new token and returning it, which I can't do without delegating the entire command AND getting a response from outside which MQTT is not suited for.

Having a "WebHook" option would actually solve that, while maintaining the rest of the MQTT bridging for basic pure-state traits... but on the other hand, you'll find a comment in the code around the "response faking" I do that I consider my approach there pretty ill conceived anyway. There's an inherent race condition in a pub-sub protocol where I have to wait for the state to come back to be able to generate a response, so I FAKE it by taking current state at the time, overlaying the command param values (transformed), and returning that, and hoping ReportState cleans up any discrepancies. That DOESN'T completely handle pure request-response traits...

But having a WebHook option for those situations could give an alternative without throwing out the whole model and going to something like a pure NORA node-red model. I have actually considered the possibility of dropping the MQTT binding in favor of competing with NORA like this, but frankly if he just distributed the server side piece for you to run locally, its BASICALLY the same thing.

Sorry this is mostly me brainstorming. I don't think your case (OnOff) makes a case for this, but some of the other traits COULD. I will keep this option in the back of my head as we go forward as a possibly addition in the future.

[i8beef]

As your original issue is resolved, I'm going to close this.