mycroft playing of music using spotify requires specification of spotify?

[fermulator]

Hi @forslund , wanted to report this issue "as is" in the current state (looking for guidance on debug/isolation - can provide quick turnaround)

So my last "working state" was roughly the situation described in #135 (comment).

For about a week now, starting early last week, suddenly when I asked mycroft to play some music using spotify, it says it is not configured to do so. A contradiction is that if I ask it to list the available devices, it still knows about the "some_other_device" in my spotify network.

 hey mycroft, list available spotify devices                                                                                                                
 >> [AV] back den soundbar                                                                                                                                              

Here is some clarity I've found. (summarizing)

1. If I just ask to play some music, it doesn't work;
2. If I specify to do it on or using spotify, it works;

(1)

hey Mycroft, play some classical music
 >> Just a second                                                                                                                                            >> It sounds like you are trying to listen to some music, but you have not yet set                                                                        up any music skills. Please go to market.mycroft.ai to install and configure a                                                                             
    music service skill.                                                                                                                                                

, logs:

2020-04-26 08:23:07.173 | INFO     |   546 | mycroft.audio.speech:mute_and_speak:127 | Speak: Excuse me, I wasn't able to find "classical".
2020-04-26 08:23:37.237 | INFO     |   546 | mycroft.audio.speech:mute_and_speak:127 | Speak: Just a second
2020-04-26 08:23:40.879 | INFO     |   546 | mycroft.audio.speech:mute_and_speak:127 | Speak: I'm not configured to play music yet.
2020-04-26 08:23:40.897 | INFO     |   546 | mycroft.audio.speech:mute_and_speak:127 | Speak: You can setup music services such as Pandora and Spotify at home dot mycroft dot ai.

OK darn, that didn't work? Confusing. If we are more specific to use "spotify", then it does key off it properly

(2)

 play classical music on spotify                                                                                                                                          
 >> Just a second                                                                                                                                            
 >> Playing songs by <random classical artist>                                                                                                                                      

2020-04-26 11:15:58.053 | INFO     |   546 | mycroft.audio.speech:mute_and_speak:127 | Speak: Give me a moment to check for that
2020-04-26 11:16:06.939 | INFO     |   546 | mycroft.audio.speech:mute_and_speak:127 | Speak: Listening to Some Classical Music by Various Artists.

2020-04-26 11:16:01.673 | INFO     |   543 | SpotifySkill | Handling "some classical music" as a genric query...
2020-04-26 11:16:01.673 | INFO     |   543 | SpotifySkill | Checking users playlists
Removing event mycroft-spotify.forslund:launch_librespot
2020-04-26 11:16:01.852 | INFO     |   543 | SpotifySkill | Checking artists
2020-04-26 11:16:02.030 | INFO     |   543 | SpotifySkill | Checking tracks
2020-04-26 11:16:02.319 | INFO     |   543 | SpotifySkill | Checking albums
2020-04-26 11:16:02.576 | INFO     |   543 | SpotifySkill | ('some classical music', 'some classical music', 1.0)
2020-04-26 11:16:02.577 | INFO     |   543 | SpotifySkill | Spotify confidence: 1.0
2020-04-26 11:16:06.197 | INFO     |   543 | Playback Control Skill | Playing with: mycroft-spotify.forslund
2020-04-26 11:16:06.717 | INFO     |   543 | Playback Control Skill | Audio service status: {}
2020-04-26 11:16:06.913 | INFO     |   543 | SpotifySkill | Device detected: DeviceType.FIRSTBEST
2020-04-26 11:16:06.914 | INFO     |   543 | SpotifySkill | playing album

Is it normal to have to specify "spotify" as the playback service/skill?
I cannot remember if I've always (previously) specified "on spotify" or if this behaviour changed on me ...

[forslund]

It shouldn't (TM) require on spotify but it will increase the score of the match if "on spotify" is used.

It is not normal to have to specify "on spotify", it should be able to match even without it (and does on my reference devices).

where is the "music service skill" output coming from? Could you have another Common playback skill that is returning a higher score than Spotify and using "on spotify".

There could also be a playback control skill issue at play here, I've seen it once or twice that it gives up waiting for the CPS skills to reply too soon in some cases (the "I've not been configured..." could indicate some such issue)

[fermulator]

This is a default install mostly, I've not added any other "music" or "playback" skills other than this spotify skill itself.

Here's my best attempt at proof:

mycroftai@mycroftai ~/mycroft-core/bin $ ./mycroft-msm list -i
INFO - building SkillEntry objects for all skills
INFO - building SkillEntry objects for all skills
INFO - invalidating skills cache
fallback-wolfram-alpha	[installed]
mycroft-pairing	[installed]
mycroft-support-helper	[installed]
mycroft-spelling	[installed]
mycroft-stop	[installed]
mycroft-configuration	[installed]
mycroft-playback-control	[installed]
mycroft-wiki	[installed]
mycroft-stock	[installed]
fallback-unknown	[installed]
mycroft-version-checker	[installed]
mycroft-timer	[installed]
mycroft-hello-world	[installed]
mycroft-personal	[installed]
homeassistant	[installed]
mycroft-audio-record	[installed]
mycroft-singing	[installed]
mycroft-reminder	[installed]
mycroft-joke	[installed]
mycroft-spotify	[installed]
mycroft-speak	[installed]
mycroft-alarm	[installed]
mycroft-ip	[installed]
mycroft-npr-news	[installed]
mycroft-date-time	[installed]
mycroft-volume	[installed]
mycroft-naptime	[installed]
mycroft-installer	[installed]
mycroft-weather	[installed]
fallback-query	[installed]
mycroft-fallback-duck-duck-go	[installed]
dismissal-skill	[installed]

There is no such "music service skill". hm.

mycroftai@mycroftai ~/mycroft-core/bin $ ./mycroft-msm list -i | egrep "music|play|spotify"
INFO - building SkillEntry objects for all skills
INFO - building SkillEntry objects for all skills
INFO - invalidating skills cache
mycroft-playback-control	[installed]
mycroft-spotify	[installed]

I am using old Dell hardware (this is a PoC/playground for me before moving to a Pi).
The CPU is fairly pegged all the time. It's ~25% idle (1.4-1.5x BUSY on a dual core system).

[forslund]

Thanks for verifying, I'll do some more experiments and see if I can trigger the behaviour.

A few comments and general ponderings over the report and my code:

The skills.log looks a bit weird for the second attempt... like it got the first request and played that:

2020-04-26 11:16:01.673 | INFO | 543 | SpotifySkill | Handling "some classical music" as a genric query...

Since it's a generic query quite far down on the check list it could be a timeout thing the first time around... Going to see if I can handle that in a more async way.

[fermulator]

Since switching over to picroft, I'd say this has improved; but on occasion I noticed a few instances where it didn't automatically attempt to use Spotify (same skill/installation as last time, there are no other playback skills installed) - I'll continue to use and monitor - next time it happens will try to snap some more logs.

[forslund]

To note is that the issue in the news skill overmatching was resolved by @krisgesling so that can be part of the improvement.