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

multiple last_called devices with one account #97

Closed
h4nc opened this issue Feb 26, 2019 · 17 comments · Fixed by #105
Closed

multiple last_called devices with one account #97

h4nc opened this issue Feb 26, 2019 · 17 comments · Fixed by #105
Assignees
Labels
bug Something isn't working

Comments

@h4nc
Copy link

h4nc commented Feb 26, 2019

Coming from here

If you only have one Alexa account, then there should only be one last_called echo. There is a polling thread to determine the last serial number, and all devices will read an event when a new one is discovered and should adjust themselves. If you see more than one returning true (for more than a split second, which is the time for HA to tell every component), that’s a bug. Please file an issue.

I only have one account, but as noticed in another issue I have echo buttons in my network.
For me it looked like they stay true (last_called) until I restart home assistant.
I don't get an error.

To make it better readable I also extracted the last_called attributes to binary sensor and added them to my UI. This way I was better able to see if when the one gets TRUE if the other ons gets FALSE. But that did not happen. Both stayed TRUE.

In the thread above one other user seems to have the same issue, so I might not be the only one.
See: https://community.home-assistant.io/t/echo-devices-alexa-as-media-player-testers-needed/58639/2000?u=h4nc

@alandtse
Copy link
Owner

This is probably resolved with this branch which also exposes the service to solve #83. Haven't tested it fully yet though.

@alandtse alandtse self-assigned this Feb 27, 2019
@alandtse alandtse added the bug Something isn't working label Feb 27, 2019
@h4nc
Copy link
Author

h4nc commented Feb 27, 2019

Unfortunately not. As you see in the attached pic, I can still have more than one entity last_called true (only one account).

sz_last is a device that also has echo buttons linked to it (which I use for routines).

Even calling the new service doesn't make it go false.

1

@h4nc
Copy link
Author

h4nc commented Feb 27, 2019

I want to add that it still gets the right values when I restart home assistant

@alandtse
Copy link
Owner

alandtse commented Feb 28, 2019

Can you please try the latest version in #100 and provide debugging logs for custom_components.alexa_media.media_player when you use the service. Specifically:

  1. Use the service.
  2. Speak to any Alexa device.
  3. Use the service again.

I only need the logs covering these three steps.

@h4nc
Copy link
Author

h4nc commented Feb 28, 2019

Ok so I added this to my configuration.yaml

logger:
  default: critical
  logs:
    custom_components.alexa_media: debug 

This is what I got:

1)
2019-02-28 12:23:22 DEBUG (SyncWorker_12) [custom_components.alexa_media] Service update_last_called for: []
2019-02-28 12:23:23 DEBUG (SyncWorker_12) [custom_components.alexa_media] ****@gmail.com: Updated last_called: {'serialNumber': 'G**************D', 'timestamp': 1551352751931}
2019-02-28 12:23:26 DEBUG (SyncWorker_18) [custom_components.alexa_media] ****@gmail.com: Found 7 devices, 1 bluetooth
2019-02-28 12:23:26 DEBUG (SyncWorker_18) [custom_components.alexa_media] ****@gmail.com: Existing: [<Entity Echo Dot 1: standby>, <Entity Echo Dot 2: standby>, <Entity Echo Dot 3: standby>] New: []; Filtered by: include_devices: ['Fire TV stick', 'Fire Tablet', 'This Device', "Alexa Apps"] exclude_devices:[]
2019-02-28 12:23:26 DEBUG (SyncWorker_18) [custom_components.alexa_media] ****@gmail.com: Updated last_called: {'serialNumber': 'G**************D', 'timestamp': 1551352751931}

2) 
2019-02-28 12:25:28 DEBUG (SyncWorker_0) [custom_components.alexa_media] ****@gmail.com: Found 7 devices, 1 bluetooth
2019-02-28 12:25:28 DEBUG (SyncWorker_0) [custom_components.alexa_media] ****@gmail.com: Existing: [<Entity Echo Dot 1: standby>, <Entity Echo Dot 2: standby>, <Entity Echo Dot 3: standby>] New: []; Filtered by: include_devices: ['Fire TV stick', 'Fire Tablet', 'This Device', "Alexa Apps"] exclude_devices:[]
2019-02-28 12:25:28 DEBUG (SyncWorker_0) [custom_components.alexa_media] ****@gmail.com: Updated last_called: {'serialNumber': 'G**************7', 'timestamp': 1551353095805}
2019-02-28 12:25:28 DEBUG (SyncWorker_0) [custom_components.alexa_media] ****@gmail.com: last_called changed: {'serialNumber': 'G**************D', 'timestamp': 1551352751931} to {'serialNumber': 'G**************7', 'timestamp': 1551353095805}
2019-02-28 12:25:28 DEBUG (SyncWorker_18) [custom_components.alexa_media.media_player] ****@gmail.com: Refreshing Echo Dot 1
2019-02-28 12:25:28 DEBUG (SyncWorker_3) [custom_components.alexa_media.media_player] ****@gmail.com: Refreshing Echo Dot 2
2019-02-28 12:25:28 DEBUG (SyncWorker_2) [custom_components.alexa_media.media_player] Echo Dot 3 is last_called: G**************7
2019-02-28 12:25:28 DEBUG (SyncWorker_2) [custom_components.alexa_media.media_player] ****@gmail.com: Refreshing Echo Dot 3

3)
2019-02-28 12:26:53 DEBUG (SyncWorker_14) [custom_components.alexa_media] Service update_last_called for: []
2019-02-28 12:26:53 DEBUG (SyncWorker_14) [custom_components.alexa_media] ****@gmail.com: Updated last_called: {'serialNumber': 'G**************7', 'timestamp': 1551353095805}

@alandtse
Copy link
Owner

You may need to turn off the other components if they're showing up.

logger:
  default: info
  logs:
    custom_components.alexa_media: debug

When you use the service you should get something like this:

Feb 28 11:29:16 contrib-stretch hass[16148]: 2019-02-28 11:29:16 DEBUG (Thread-9) [custom_components.alexa_media] Service update_last_called for: []
Feb 28 11:29:17 contrib-stretch hass[16148]: 2019-02-28 11:29:17 DEBUG (Thread-9) [custom_components.alexa_media] a******[email protected]: Updated last_called: {'serialNumber': 'G************9WE', 'timestamp': 1551351265883}

You'll want to find the first time you see Service update_last_called for: [] and copy between those two sections.

@h4nc
Copy link
Author

h4nc commented Feb 28, 2019

I updated my post above with the log.

@alandtse
Copy link
Owner

Thanks. Echo Dot 3 is the only one reporting that it's the last called one. Is last_called true for the other dots?

@h4nc
Copy link
Author

h4nc commented Feb 28, 2019

No currently not, because I restartet when I added logger.

Should I trigger another alexa to get more than one true and post again?

@alandtse
Copy link
Owner

Yes, as soon as you see the problem, please do the logging steps.

@h4nc
Copy link
Author

h4nc commented Feb 28, 2019

Ok so now I have two last_called true again, logs:

2019-02-28 13:03:51 DEBUG (SyncWorker_1) [custom_components.alexa_media] ****@gmail.com: Found 7 devices, 1 bluetooth
2019-02-28 13:03:51 DEBUG (SyncWorker_1) [custom_components.alexa_media] ****@gmail.com: Existing: [<Entity Echo Dot 1: paused>, <Entity Echo Dot 2: standby>, <Entity Echo Dot 3: standby>] New: []; Filtered by: include_devices: ['Fire TV stick', 'Fire Tablet', 'This Device', "Alexa Apps"] exclude_devices:[]
2019-02-28 13:03:52 DEBUG (SyncWorker_1) [custom_components.alexa_media] ****@gmail.com: Updated last_called: {'serialNumber': 'G**************D', 'timestamp': 1551354908133}
2019-02-28 13:03:55 DEBUG (SyncWorker_15) [custom_components.alexa_media] Service update_last_called for: []
2019-02-28 13:03:55 DEBUG (SyncWorker_15) [custom_components.alexa_media] ****@gmail.com: Updated last_called: {'serialNumber': 'G**************D', 'timestamp': 1551354908133}

2019-02-28 13:06:59 DEBUG (SyncWorker_13) [custom_components.alexa_media] Service update_last_called for: []
2019-02-28 13:07:00 DEBUG (SyncWorker_13) [custom_components.alexa_media] ****@gmail.com: Updated last_called: {'serialNumber': 'G**************P', 'timestamp': 1551355613410}
2019-02-28 13:07:00 DEBUG (SyncWorker_13) [custom_components.alexa_media] ****@gmail.com: last_called changed: {'serialNumber': 'G**************D', 'timestamp': 1551354908133} to {'serialNumber': 'G**************P', 'timestamp': 1551355613410}
2019-02-28 13:07:00 DEBUG (SyncWorker_4) [custom_components.alexa_media.media_player] ****@gmail.com: Refreshing Echo Dot 1
2019-02-28 13:07:00 DEBUG (SyncWorker_7) [custom_components.alexa_media.media_player] Echo Dot 2 is last_called: G**************P
2019-02-28 13:07:00 DEBUG (SyncWorker_15) [custom_components.alexa_media.media_player] ****@gmail.com: Refreshing Echo Dot 3
2019-02-28 13:07:00 DEBUG (SyncWorker_7) [custom_components.alexa_media.media_player] ****@gmail.com: Refreshing Echo Dot 2

It also takes some seconds until the second one gets true. After some minutes the wrong one got false again. The logs seem to only report one alexa last called. So is this an ha issue?

2

And here you can see that both are true and just to be sure I show you the binarysensor config that reads that state also:

- platform: template
  sensors:
    wz_last: 
      value_template: "{{ states.media_player.echo_dot_1.attributes.last_called }}"
    

@alandtse
Copy link
Owner

alandtse commented Mar 1, 2019

I think I might have found the cause. Looks like we have to separately force HA to update. I'm close to releasing a new release, so I didn't push it to the one you're testing yet. I'll let you know when we release it so you can confirm.

@h4nc
Copy link
Author

h4nc commented Mar 1, 2019

Ok, I'd like to mention that I tried this in a script in the meantime. But that also did not help

    - service: homeassistant.update_entity
      data:
        entity_id: sensor.last_alexa  

@alandtse
Copy link
Owner

alandtse commented Mar 1, 2019

That's not the correct service if you're calling the last_called service.

    - service: alexa_media.update_last_called

If you're referring to manually triggering the HA update, you'd have to do it to the media_players which are the source of you're binary_sensor (guessing at syntax for multiple entities).

    - service: homeassistant.update_entity
      data:
        entity_id: media_player.echo_dot_1, media_player.echo_dot_2, media_player.echo_dot_3

@h4nc
Copy link
Author

h4nc commented Mar 1, 2019

I tried this additionally to the alexa_media.update_last_called service.

But yes you are right, if I do this I have to update the meiaplayers.
Should I try this or what for the new version?

@alandtse
Copy link
Owner

alandtse commented Mar 1, 2019

New version is out. It should resolve all the issues you referred to. After I confirm it's working in my production I'll make a post on the thread.

@h4nc
Copy link
Author

h4nc commented Mar 1, 2019

Ok, I'd like to confirm that it works now, the last_called update instantly. Thanks!

I have another question about using delays, but I will ask that in the thread, because it will interessant more people.

Great work!

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

Successfully merging a pull request may close this issue.

2 participants