Azure Connection Issue

DocD · October 2, 2020, 4:52am

Hi, appreciate the work that’s gone into this plugin, thanks.

I’m coming back to this after quite a while and have upgraded to 2.0 but seem to be having trouble connecting to Azure. I’ve done the Azure account setup etc, selected Azure and entered the key and region (australiaeast) in the Sonos System config.
The endpoint URL seems to be different to the one quoted in the Azure setup guide. Mine is:
https://verasonostts.cognitiveservices.azure.com/

Is this a problem and do I need to enter this URL somewhere in the config?

I’m clearly missing something fundamental and would be very appreciative of some help. Thanks

Below is the luaupnp log output from a TTS attempt from the TTS tab in one of my Sonos devices:

02	10/02/20 13:57:53.785	Device_Basic::AddPoll 37 poll list full, deleting old one <0x77606520>
06	10/02/20 13:57:53.787	Device_Variable::m_szValue_set device: 37 service: urn:micasaverde-com:serviceId:HaDevice1 variable: PollRatings was: 5.00 now: 5.00 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x77606520>
06	10/02/20 13:57:53.787	Device_Variable::m_szValue_set device: 37 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastPollSuccess was: 1601610803 now: 1601611073 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x77606520>
06	10/02/20 13:57:53.788	Device_Variable::m_szValue_set device: 37 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: ConsecutivePollFails was: 0 now: 0 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x77606520>
01	10/02/20 13:58:04.162	FileUtils::ReadURL 28/resp:0 user: pass: size 1 http://192.168.1.134/util/query.cgi response: <0x77406520>
06	10/02/20 13:58:05.108	Device_Variable::m_szValue_set device: 15 service: urn:futzle-com:serviceId:UPnPProxy1 variable: Status was: 1 now: 1 #hooks: 0 upnp: 0 skip: 0 v:0x1026808/NONE duplicate:1 <0x76806520>
06	10/02/20 13:58:05.108	Device_Variable::m_szValue_set device: 15 service: urn:futzle-com:serviceId:UPnPProxy1 variable: StatusText was: Running now: Running #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x76806520>
06	10/02/20 13:58:05.109	Device_Variable::m_szValue_set device: 15 service: urn:futzle-com:serviceId:UPnPProxy1 variable: API was: 3 now: 3 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x76806520>
50	10/02/20 13:58:12.100	luup_log:361: Sonos: [debug] sonosTick(“2”) <0x76206520>
50	10/02/20 13:58:12.102	luup_log:361: Sonos: [debug] Task:runReadyTasks() ready “checkProxy” 1601611092(10/02/20.13:58:12) <0x76206520>
50	10/02/20 13:58:12.102	luup_log:361: Sonos: [debug] Task:runReadyTasks() running “checkProxy” <0x76206520>
50	10/02/20 13:58:12.103	luup_log:361: Sonos: [debug] checkProxy(“Task(checkProxy)”,361) <0x76206520>
50	10/02/20 13:58:12.109	luup_log:361: Sonos: UPnP Event Proxy identified - API version “3” <0x76206520>
50	10/02/20 13:58:12.110	luup_log:361: Sonos: [debug] Task:runReadyTasks() waiting “__sched” 0 <0x76206520>
50	10/02/20 13:58:12.111	luup_log:361: Sonos: [debug] Task:runReadyTasks() waiting “update19” 0 <0x76206520>
50	10/02/20 13:58:12.111	luup_log:361: Sonos: [debug] Task:runReadyTasks() waiting “master” 1601611755(10/02/20.14:09:15) <0x76206520>
50	10/02/20 13:58:12.113	luup_log:361: Sonos: [debug] Task:runReadyTasks() waiting “checkProxy” 1601611392(10/02/20.14:03:12) <0x76206520>
50	10/02/20 13:58:12.113	luup_log:361: Sonos: [debug] Task:runReadyTasks() waiting “update18” 0 <0x76206520>
50	10/02/20 13:58:12.114	luup_log:361: Sonos: [debug] Task:runReadyTasks() waiting “update17” 0 <0x76206520>
50	10/02/20 13:58:12.115	luup_log:361: Sonos: [debug] Task:runReadyTasks() next in 300 <0x76206520>
50	10/02/20 13:58:13.545	luup_log:361: Sonos: [debug] request(“SonosSystem”,{ action=“ttsengines” },“”) luup.device=361 <0x73be0520>
04	10/02/20 13:58:13.673	<0x77606520>
02	10/02/20 13:58:13.674	Device_Basic::AddPoll 283 poll list full, deleting old one <0x77606520>
06	10/02/20 13:58:13.675	Device_Variable::m_szValue_set device: 283 service: urn:micasaverde-com:serviceId:HaDevice1 variable: PollRatings was: 5.00 now: 5.00 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x77606520>
06	10/02/20 13:58:13.676	Device_Variable::m_szValue_set device: 283 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastPollSuccess was: 1601610823 now: 1601611093 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x77606520>
06	10/02/20 13:58:13.676	Device_Variable::m_szValue_set device: 283 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: ConsecutivePollFails was: 0 now: 0 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x77606520>
08	10/02/20 13:58:17.963	JobHandler_LuaUPnP::HandleActionRequest device: 19 service: urn:micasaverde-com:serviceId:Sonos1 action: Say <0x73e06520>
08	10/02/20 13:58:17.963	JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=19 <0x73e06520>
08	10/02/20 13:58:17.963	JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:micasaverde-com:serviceId:Sonos1 <0x73e06520>
08	10/02/20 13:58:17.964	JobHandler_LuaUPnP::HandleActionRequest argument action=Say <0x73e06520>
08	10/02/20 13:58:17.964	JobHandler_LuaUPnP::HandleActionRequest argument Text=hello <0x73e06520>
08	10/02/20 13:58:17.965	JobHandler_LuaUPnP::HandleActionRequest argument Engine=AZURE <0x73e06520>
08	10/02/20 13:58:17.965	JobHandler_LuaUPnP::HandleActionRequest argument rand=0.6882342188733281 <0x73e06520>
50	10/02/20 13:58:17.967	luup_log:361: Sonos: [debug] actionSonosSay(19,{ rand=“0.6882342188733281”, action=“Say”, DeviceNum=“19”, Text=“hello”, Engine=“AZURE”, serviceId=“urn:micasaverde-com:serviceId:Sonos1” }) <0x77e20000>
50	10/02/20 13:58:17.968	luup_log:361: Sonos: Say action on device 19 text “hello” <0x77e20000>
50	10/02/20 13:58:17.970	luup_log:361: Sonos: [debug] loadTTSCache(“AZURE”,“en-US-JessaRUS”,25) <0x77e20000>
50	10/02/20 13:58:17.971	luup_log:361: Sonos: [debug] makeTTSAlert() checking cache for “hello”: { nextfile=1, version=1, strings={ } } <0x77e20000>
50	10/02/20 13:58:17.971	luup_log:361: Sonos: [debug] makeTTSAlert() not cached, creating <0x77e20000>
02	10/02/20 13:58:19.030	luup_log:361: Sonos: AzureTTSEngine:say() authorization failed with Azure service <0x77e20000>
02	10/02/20 13:58:19.031	luup_log:361: Sonos: (tts) engine Azure Speech Service error: authorization failed <0x77e20000>
02	10/02/20 13:58:19.031	luup_log:361: Sonos: (tts) Engine “Azure Speech Service” produced no audio <0x77e20000>
04	10/02/20 13:58:19.033	<0x77e20000>

DocD · October 2, 2020, 5:41am

Further log info:

08 10/02/20 15:37:41.720 JobHandler_LuaUPnP::HandleActionRequest device: 0 service: urn:micasaverde-com:serviceId:HomeAutomationGateway1 action: RunLua <0x74206520>
08 10/02/20 15:37:41.720 JobHandler_LuaUPnP::HandleActionRequest argument id=lu_action <0x74206520>
08 10/02/20 15:37:41.721 JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:micasaverde-com:serviceId:HomeAutomationGateway1 <0x74206520>
08 10/02/20 15:37:41.721 JobHandler_LuaUPnP::HandleActionRequest argument action=RunLua <0x74206520>
08 10/02/20 15:37:41.722 JobHandler_LuaUPnP::HandleActionRequest argument Code=luup.call_action(“urn:micasaverde-com:serviceId:Sonos1”, “Say”,
{Text=“The sun shines outside”},
19) <0x74206520>
08 10/02/20 15:37:41.723 JobHandler_LuaUPnP::HandleActionRequest device: 19 service: urn:micasaverde-com:serviceId:Sonos1 action: Say <0x74206520>
08 10/02/20 15:37:41.724 JobHandler_LuaUPnP::HandleActionRequest argument Text=The sun shines outside <0x74206520>
50 10/02/20 15:37:41.725 luup_log:361: Sonos: [debug] actionSonosSay(19,{ Text=“The sun shines outside” }) <0x77e20000>
50 10/02/20 15:37:41.726 luup_log:361: Sonos: Say action on device 19 text “The sun shines outside” <0x77e20000>
50 10/02/20 15:37:41.728 luup_log:361: Sonos: [debug] loadTTSCache(“AZURE”,“en-US-JessaRUS”,52) <0x77e20000>
50 10/02/20 15:37:41.729 luup_log:361: Sonos: [debug] makeTTSAlert() checking cache for “The sun shines outside”: { nextfile=1, version=1, strings={ } } <0x77e20000>
50 10/02/20 15:37:41.729 luup_log:361: Sonos: [debug] makeTTSAlert() not cached, creating <0x77e20000>
50 10/02/20 15:37:41.730 luup_log:361: Sonos: (tts debug) generate() engine Azure Speech Service text The sun shines outside file /www/sonos/Say.19.mp3 <0x77e20000>
50 10/02/20 15:37:41.736 luup_log:361: Sonos: (tts debug) AzureTTSEngine:say() token is expired, fetching new <0x77e20000>
50 10/02/20 15:37:42.050 luup_log:361: Sonos: (tts debug) AzureTTSEngine:say() host “australiaeast.tts.speech.microsoft.com” payload “<speak version="1.0" xml:lang="en-US"><voice name="en-US-JessaRUS">The sun shines outside” <0x77e20000>
50 10/02/20 15:37:42.051 luup_log:361: Sonos: (tts debug) AzureTTSEngine:say() LuaSec “0.5.PR”, using protocol “tlsv1_2” for request <0x77e20000>
50 10/02/20 15:37:42.650 luup_log:361: Sonos: (tts debug) AzureTTSEngine:say() auth fail, arming for retry <0x77e20000>
50 10/02/20 15:37:42.650 luup_log:361: Sonos: (tts debug) AzureTTSEngine:say() token is expired, fetching new <0x77e20000>

DocD · October 2, 2020, 6:12am

I applied the hotfix. Different, but no cigar:

50 10/02/20 16:02:45.089 luup_log:361: Sonos: [debug] request(“SonosSystem”,{ action=“ttsengines” },“”) luup.device=361 <0x739e6520>
50 10/02/20 16:02:45.122 luup_log:361: Sonos: [debug] sonosTick(“2”) <0x75de6520>
50 10/02/20 16:02:45.123 luup_log:361: Sonos: [debug] Task:runReadyTasks() ready “master” 1601618565(10/02/20.16:02:45) <0x75de6520>
50 10/02/20 16:02:45.124 luup_log:361: Sonos: [debug] Task:runReadyTasks() running “master” <0x75de6520>
50 10/02/20 16:02:45.125 luup_log:361: Sonos: [debug] runMasterTick({ name=“361”, args={ 1=361 }, when=0, owner=361, func=function: 0x1231270, id=“master” }) <0x75de6520>
50 10/02/20 16:02:45.153 luup_log:361: Sonos: [debug] runMasterTick() “/etc/cmh-ludl/” has 3224K free at 66%% <0x75de6520>
50 10/02/20 16:02:45.176 luup_log:361: Sonos: [debug] runMasterTick() /www/sonos has 3224K free at 66%% <0x75de6520>
50 10/02/20 16:02:45.177 luup_log:361: Sonos: [debug] Task:runReadyTasks() waiting “__sched” 0 <0x75de6520>
50 10/02/20 16:02:45.178 luup_log:361: Sonos: [debug] Task:runReadyTasks() waiting “update19” 0 <0x75de6520>
50 10/02/20 16:02:45.179 luup_log:361: Sonos: [debug] Task:runReadyTasks() waiting “master” 1601619465(10/02/20.16:17:45) <0x75de6520>
50 10/02/20 16:02:45.180 luup_log:361: Sonos: [debug] Task:runReadyTasks() waiting “checkProxy” 1601618801(10/02/20.16:06:41) <0x75de6520>
50 10/02/20 16:02:45.181 luup_log:361: Sonos: [debug] Task:runReadyTasks() waiting “update18” 0 <0x75de6520>
50 10/02/20 16:02:45.182 luup_log:361: Sonos: [debug] Task:runReadyTasks() waiting “update17” 0 <0x75de6520>
50 10/02/20 16:02:45.183 luup_log:361: Sonos: [debug] Task:runReadyTasks() next in 236 <0x75de6520>
08 10/02/20 16:02:54.946 JobHandler_LuaUPnP::HandleActionRequest device: 19 service: urn:micasaverde-com:serviceId:Sonos1 action: Say <0x739e6520>
08 10/02/20 16:02:54.947 JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=19 <0x739e6520>
08 10/02/20 16:02:54.947 JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:micasaverde-com:serviceId:Sonos1 <0x739e6520>
08 10/02/20 16:02:54.948 JobHandler_LuaUPnP::HandleActionRequest argument action=Say <0x739e6520>
08 10/02/20 16:02:54.948 JobHandler_LuaUPnP::HandleActionRequest argument Text=speak damn you <0x739e6520>
08 10/02/20 16:02:54.949 JobHandler_LuaUPnP::HandleActionRequest argument Engine=AZURE <0x739e6520>
08 10/02/20 16:02:54.949 JobHandler_LuaUPnP::HandleActionRequest argument rand=0.29094672514178654 <0x739e6520>
50 10/02/20 16:02:54.952 luup_log:361: Sonos: [debug] actionSonosSay(19,{ rand=“0.29094672514178654”, action=“Say”, DeviceNum=“19”, Text=“speak damn you”, Engine=“AZURE”, serviceId=“urn:micasaverde-com:serviceId:Sonos1” }) <0x77a01000>
50 10/02/20 16:02:54.953 luup_log:361: Sonos: Say action on device 19 text “speak damn you” <0x77a01000>
50 10/02/20 16:02:54.956 luup_log:361: Sonos: [debug] loadTTSCache(“AZURE”,“en-US-JessaRUS”,31) <0x77a01000>
50 10/02/20 16:02:54.957 luup_log:361: Sonos: [debug] makeTTSAlert() checking cache for “speak damn you”: { nextfile=1, version=1, strings={ } } <0x77a01000>
50 10/02/20 16:02:54.958 luup_log:361: Sonos: [debug] makeTTSAlert() not cached, creating <0x77a01000>
50 10/02/20 16:02:54.959 luup_log:361: Sonos: (tts debug) generate() engine Azure Speech Service text speak damn you file /www/sonos/Say.19.mp3 <0x77a01000>
50 10/02/20 16:02:54.959 luup_log:361: Sonos: (tts debug) AzureTTSEngine:say() token is expired, fetching new <0x77a01000>
50 10/02/20 16:02:54.960 luup_log:361: Sonos: (tts debug) AzureTTSEngine:say() “curl -s -k -o - -m 15 -X POST -H ‘Content-length: 0’ \
-H ‘Content-type: application/x-www-form-urlencoded’ -H ‘Ocp-Apim-Subscription-Key: cdb89704e3fe408194331cb747627d5f’ ‘https://australiaeast.api.cognitive.microsoft.com/sts/v1.0/issueToken’” <0x77a01000>
50 10/02/20 16:02:55.597 luup_log:361: Sonos: (tts debug) AzureTTSEngine:say() response “eyJhbGciOiJodHRwOi8vd3d3LnczLm9yZy8yMDAxLzA0L3htbGRzaWctbW9yZSNobWFjLXNoYTI1NiIsInR5cCI6IkpXVCJ9.eyJyZWdpb24iOiJhdXN0cmFsaWFlYXN0Iiwic3Vic2NyaXB0aW9uLWlkIjoiZDhjYTNjYTUzYjZmNGM4MTg5Nzc2NTk2NzIyYzYzYjEiLCJwcm9kdWN0LWlkIjoiQ29nbml0aXZlU2VydmljZXMuUzAiLCJjb2duaXRpdmUtc2VydmljZXMtZW5kcG9pbnQiOiJodHRwczovL2FwaS5jb2duaXRpdmUubWljcm9zb2Z0LmNvbS9pbnRlcm5hbC92MS4wLyIsImF6dXJlLXJlc291cmNlLWlkIjoiL3N1YnNjcmlwdGlvbnMvNzljMmJlOTEtZWY1NC00Njg2LWJlMGEtNTZmYzk1YWIwNDUzL3Jlc291cmNlR3JvdXBzL1ZlcmFTb25vc1RUUy9wcm92aWRlcnMvTWljcm9zb2Z0LkNvZ25pdGl2ZVNlcnZpY2VzL2FjY291bnRzL1ZlcmFTb25vc1RUUyIsInNjb3BlIjpbInNwZWVjaHRvaW50ZW50cyIsImh0dHBzOi8vYXBpLm1pY3Jvc29mdHRyYW5zbGF0b3IuY29tLyIsInNwZWVjaHNlcnZpY2VzIl0sImF1ZCI6WyJ1cm46bXMuc3BlZWNoIiwidXJuOm1zLmx1aXMuYXVzdHJhbGlhZWFzdCIsInVybjptcy5taWNyb3NvZnR0cmFuc2xhdG9yIiwidXJuOm1zLnNwZWVjaHNlcnZpY2VzLmF1c3RyYWxpYWVhc3QiXSwiZXhwIjoxNjAxNjE5MTc1LCJpc3MiOiJ1cm46bXMuY29nbml0aXZlc2VydmljZXMifQ.hnjJeAxSPl-S7BD7_M3DzZHdyLGNHOsZks5ZllxgDtQ” <0x77a01000>
50 10/02/20 16:02:55.598 luup_log:361: Sonos: (tts debug) AzureTTSEngine:say() acquired new token “eyJhbGciOiJodHRwOi8vd3d3LnczLm9yZy8yMDAxLzA0L3htbGRzaWctbW9yZSNobWFjLXNoYTI1NiIsInR5cCI6IkpXVCJ9.eyJyZWdpb24iOiJhdXN0cmFsaWFlYXN0Iiwic3Vic2NyaXB0aW9uLWlkIjoiZDhjYTNjYTUzYjZmNGM4MTg5Nzc2NTk2NzIyYzYzYjEiLCJwcm9kdWN0LWlkIjoiQ29nbml0aXZlU2VydmljZXMuUzAiLCJjb2duaXRpdmUtc2VydmljZXMtZW5kcG9pbnQiOiJodHRwczovL2FwaS5jb2duaXRpdmUubWljcm9zb2Z0LmNvbS9pbnRlcm5hbC92MS4wLyIsImF6dXJlLXJlc291cmNlLWlkIjoiL3N1YnNjcmlwdGlvbnMvNzljMmJlOTEtZWY1NC00Njg2LWJlMGEtNTZmYzk1YWIwNDUzL3Jlc291cmNlR3JvdXBzL1ZlcmFTb25vc1RUUy9wcm92aWRlcnMvTWljcm9zb2Z0LkNvZ25pdGl2ZVNlcnZpY2VzL2FjY291bnRzL1ZlcmFTb25vc1RUUyIsInNjb3BlIjpbInNwZWVjaHRvaW50ZW50cyIsImh0dHBzOi8vYXBpLm1pY3Jvc29mdHRyYW5zbGF0b3IuY29tLyIsInNwZWVjaHNlcnZpY2VzIl0sImF1ZCI6WyJ1cm46bXMuc3BlZWNoIiwidXJuOm1zLmx1aXMuYXVzdHJhbGlhZWFzdCIsInVybjptcy5taWNyb3NvZnR0cmFuc2xhdG9yIiwidXJuOm1zLnNwZWVjaHNlcnZpY2VzLmF1c3RyYWxpYWVhc3QiXSwiZXhwIjoxNjAxNjE5MTc1LCJpc3MiOiJ1cm46bXMuY29nbml0aXZlc2VydmljZXMifQ.hnjJeAxSPl-S7BD7_M3DzZHdyLGNHOsZks5ZllxgDtQ” <0x77a01000>
50 10/02/20 16:02:55.599 luup_log:361: Sonos: (tts debug) AzureTTSEngine:say() host “australiaeast.tts.speech.microsoft.com” payload “<speak version="1.0" xml:lang="en-US"><voice name="en-US-JessaRUS">” <0x77a01000>
50 10/02/20 16:02:55.600 luup_log:361: Sonos: (tts debug) AzureTTSEngine:say() system LuaSec version is “0.5.PR” <0x77a01000>
02 10/02/20 16:02:55.749 luup_log:361: Sonos: AzureTTSEngine:say() conversion request failed, invalid protocol (any) <0x77a01000>
02 10/02/20 16:02:55.750 luup_log:361: Sonos: (tts) engine Azure Speech Service error: request failed invalid protocol (any) <0x77a01000>
02 10/02/20 16:02:55.751 luup_log:361: Sonos: (tts) Engine “Azure Speech Service” produced no audio <0x77a01000>

rigpapa · October 2, 2020, 2:48pm

The bad news is, you’re on a system (Edge? Lite? 3?) with an outdated LuaSec that can’t handle the SSL/TLS encryption required by Azure.

The good news is, if you’re on the latest hotfix version of the Sonos plugin, there’s a new setting for TTS in the Sonos master device settings to let you switch to using curl as the requestor, which bypasses LuaSec. If you’re not on the hotfix version, just follow the instructions in the pinned hotfix post in this category.

DocD · October 3, 2020, 3:04am

Thanks Patrick. Yes, I’m on a Vera Edge and running the hotfix version.

I changed that setting in the Sonos master device settings and it now seems to be communicating with Azure. However, when I try to get it to say something via the TTS tab in one of my Sonos devices it seems to pause the current track, start playing a different track briefly (no chime), then resume the original track. I’m not hearing any TTS through the Sonos. There seems to be a different error related to playing the TTS shown in bold below.

Many thanks for your help.

</s:Envelope>" <0x77d7c000>
50 10/03/20 12:40:06.183 luup_log:361: Sonos: (UPnP) UPnP_request() status=1 statusMsg=200 result=“<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/\” s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/\“><s:Body><u:PauseResponse xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"></u:PauseResponse></s:Body></s:Envelope>” <0x77d7c000>
50 10/03/20 12:40:06.184 luup_log:361: Sonos: [debug] playURI(“RINCON_000E58282D0801400”,“0”,“"https://verasonostts.cognitiveservices.azure.com/\“Sonos_chime.mp3”,“1”,nil,{ 1=“RINCON_000E58282D0801400” },nil,nil,true,true) <0x77d7c000>
50 10/03/20 12:40:06.196 luup_log:361: Sonos: [debug] controlByCoordinator(“RINCON_000E58282D0801400”) <0x77d7c000>
50 10/03/20 12:40:06.197 luup_log:361: Sonos: [debug] getZoneGroup() group info for “RINCON_000E58282D0801400:23” is { members={ 1=“RINCON_000E58282D0801400” }, UUID=“RINCON_000E58282D0801400:23”, Coordinator=“RINCON_000E58282D0801400” } <0x77d7c000>
50 10/03/20 12:40:06.198 luup_log:361: Sonos: [debug] controlByCoordinator() coordinator “RINCON_000E58282D0801400” dev 19 <0x77d7c000>
50 10/03/20 12:40:06.199 luup_log:361: Sonos: [debug] decodeURI(“RINCON_000E58282D0801400”,“RINCON_000E58282D0801400”,”"https://verasonostts.cognitiveservices.azure.com/\“Sonos_chime.mp3”) <0x77d7c000>
50 10/03/20 12:40:06.200 luup_log:361: Sonos: [debug] decodeURI() uri now “"https://verasonostts.cognitiveservices.azure.com/\“Sonos_chime.mp3” title nil track nil serviceId nil <0x77d7c000>
50 10/03/20 12:40:06.200 luup_log:361: Sonos: [debug] decodeURI() url “"https://verasonostts.cognitiveservices.azure.com/\“Sonos_chime.mp3” serviceId nil title nil <0x77d7c000>
50 10/03/20 12:40:06.201 luup_log:361: Sonos: [debug] decodeURI() result uri=”"https://verasonostts.cognitiveservices.azure.com/\“Sonos_chime.mp3”, meta=”“, track=nil, groupControl=true, queueing=false <0x77d7c000>
50 10/03/20 12:40:06.202 luup_log:361: Sonos: [debug] playURI() creating new group <0x77d7c000>
50 10/03/20 12:40:06.203 luup_log:361: Sonos: (UPnP) service.__index: accessing non-existing function “BecomeCoordinatorOfStandaloneGroup” <0x77d7c000>
50 10/03/20 12:40:06.203 luup_log:361: Sonos: (UPnP) service.__index: “BecomeCoordinatorOfStandaloneGroup”(“http://192.168.1.138:1400/MediaRenderer/AVTransport/Control”, “urn:schemas-upnp-org:service:AVTransport:1”) called with parameter count=1 <0x77d7c000>
50 10/03/20 12:40:06.204 luup_log:361: Sonos: (UPnP) UPnP_request(“http://192.168.1.138:1400/MediaRenderer/AVTransport/Control",“BecomeCoordinatorOfStandaloneGroup”,"urn:schemas-upnp-org:service:AVTransport:1”,{ InstanceID=“0” }) <0x77d7c000>
50 10/03/20 12:40:06.215 luup_log:361: Sonos: (UPnP) UPnP_request() url=“http://192.168.1.138:1400/MediaRenderer/AVTransport/Control”, body=”<?xml version=\"1.0\" encoding=\"utf-8\"?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/\" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/\“>
<s:Body>
<u:BecomeCoordinatorOfStandaloneGroup xmlns:u="urn:schemas-upnp-org:service:AVTransport:1">0</u:BecomeCoordinatorOfStandaloneGroup>
</s:Body>
</s:Envelope>” <0x77d7c000>
50 10/03/20 12:40:06.328 luup_log:361: Sonos: (UPnP) UPnP_request() status=1 statusMsg=200 result=“<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/\” s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/\“><s:Body><u:BecomeCoordinatorOfStandaloneGroupResponse xmlns:u="urn:schemas-upnp-org:service:AVTransport:1">RINCON_000E58282D0801400:24</u:BecomeCoordinatorOfStandaloneGroupResponse></s:Body></s:Envelope>” <0x77d7c000>
50 10/03/20 12:40:06.329 luup_log:361: Sonos: [debug] playURI() setting URI to “"https://verasonostts.cognitiveservices.azure.com/\“Sonos_chime.mp3” meta “” <0x77d7c000>
50 10/03/20 12:40:06.330 luup_log:361: Sonos: (UPnP) service.__index: accessing non-existing function “SetAVTransportURI” <0x77d7c000>
50 10/03/20 12:40:06.331 luup_log:361: Sonos: (UPnP) service.__index: “SetAVTransportURI”(“http://192.168.1.138:1400/MediaRenderer/AVTransport/Control”, “urn:schemas-upnp-org:service:AVTransport:1”) called with parameter count=1 <0x77d7c000>
50 10/03/20 12:40:06.332 luup_log:361: Sonos: (UPnP) UPnP_request(“http://192.168.1.138:1400/MediaRenderer/AVTransport/Control",“SetAVTransportURI”,"urn:schemas-upnp-org:service:AVTransport:1”,{ OrderedArgs={ 1=“InstanceID=0”, 2=“CurrentURI="https://verasonostts.cognitiveservices.azure.com/\“Sonos_chime.mp3”, 3=“CurrentURIMetaData=” } }) <0x77d7c000>
50 10/03/20 12:40:06.333 luup_log:361: Sonos: (UPnP) UPnP_request() url=“http://192.168.1.138:1400/MediaRenderer/AVTransport/Control”, body=”<?xml version=\"1.0\" encoding=\"utf-8\"?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/\” s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/\“>
<s:Body>
<u:SetAVTransportURI xmlns:u="urn:schemas-upnp-org:service:AVTransport:1">0“https://verasonostts.cognitiveservices.azure.com/“Sonos_chime.mp3</u:SetAVTransportURI>
</s:Body>
</s:Envelope>" <0x77d7c000>
01 10/03/20 12:40:06.404 luup_log:361: Sonos: UPnP_request (SetAVTransportURI, urn:schemas-upnp-org:service:AVTransport:1): status=1 statusMsg=500 result=[<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”><s:Body><s:Fault>s:ClientUPnPError714</s:Fault></s:Body></s:Envelope>] <0x77d7c000>
02 10/03/20 12:40:06.425 luup_log:361: stack traceback:
** [string “–[[…”]:265: in function ‘error’**
** [string “–[[…”]:289: in function <[string “–[[…”]:169>**
** (tail call): ?**
** [string “–[[…”]:1720: in function ‘playURI’**
** [string “–[[…”]:3419: in function ‘sayOrAlert’**
** [string “–[[…”]:3460: in function ‘queueAlert’**
** [string “–[[…”]:3769: in function <[string “–[[…”]:3743>**
** (tail call): ? <0x77d7c000>**
50 10/03/20 12:40:06.426 luup_log:361: Sonos: [debug] playURI() starting play on “RINCON_000E58282D0801400” at speed 1 <0x77d7c000>
50 10/03/20 12:40:06.427 luup_log:361: Sonos: (UPnP) service.__index: accessing non-existing function “Play” <0x77d7c000>
50 10/03/20 12:40:06.428 luup_log:361: Sonos: (UPnP) service.__index: “Play”(“http://192.168.1.138:1400/MediaRenderer/AVTransport/Control”, “urn:schemas-upnp-org:service:AVTransport:1”) called with parameter count=1 <0x77d7c000>
50 10/03/20 12:40:06.429 luup_log:361: Sonos: (UPnP) UPnP_request(“http://192.168.1.138:1400/MediaRenderer/AVTransport/Control",“Play”,"urn:schemas-upnp-org:service:AVTransport:1”,{ OrderedArgs={ 1=“InstanceID=0”, 2=“Speed=1” } }) <0x77d7c000>
50 10/03/20 12:40:06.429 luup_log:361: Sonos: (UPnP) UPnP_request() url=“http://192.168.1.138:1400/MediaRenderer/AVTransport/Control”, body=”<?xml version=\"1.0\" encoding=\"utf-8\"?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/\” s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/\”>
<s:Body>
50 10/03/20 12:40:06.426 luup_log:361: Sonos: [debug] playURI() starting play on “RINCON_000E58282D0801400” at speed 1 <0x77d7c000>
50 10/03/20 12:40:06.427 luup_log:361: Sonos: (UPnP) service.__index: accessing non-existing function “Play” <0x77d7c000>
50 10/03/20 12:40:06.428 luup_log:361: Sonos: (UPnP) service._index: “Play”(“http://192.168.1.138:1400/MediaRenderer/AVTransport/Control”, “urn:schemas-upnp-org:service:AVTransport:1”) called with parameter count=1 <0x77d7c000>
50 10/03/20 12:40:06.429 luup_log:361: Sonos: (UPnP) UPnP_request(“http://192.168.1.138:1400/MediaRenderer/AVTransport/Control",“Play”,"urn:schemas-upnp-org:service:AVTransport:1”,{ OrderedArgs={ 1=“InstanceID=0”, 2=“Speed=1” } }) <0x77d7c000>
50 10/03/20 12:40:06.429 luup_log:361: Sonos: (UPnP) UPnP_request() url=“http://192.168.1.138:1400/MediaRenderer/AVTransport/Control”, body=“<?xml version=\"1.0\" encoding=\"utf-8\"?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/\” s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/\“>
<s:Body>
<u:Play xmlns:u="urn:schemas-upnp-org:service:AVTransport:1">01</u:Play>
</s:Body>
</s:Envelope>” <0x77d7c000>
08 10/03/20 12:40:06.488 JobHandler_LuaUPnP::HandleActionRequest device: 19 service: urn:micasaverde-com:serviceId:Sonos1 action: NotifyAVTransportChange <0x733d0520>
08 10/03/20 12:40:06.489 JobHandler_LuaUPnP::HandleActionRequest argument DeviceNum=19 <0x733d0520>
08 10/03/20 12:40:06.489 JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:micasaverde-com:serviceId:Sonos1 <0x733d0520>
08 10/03/20 12:40:06.489 JobHandler_LuaUPnP::HandleActionRequest argument action=NotifyAVTransportChange <0x733d0520>
08 10/03/20 12:40:06.490 JobHandler_LuaUPnP::HandleActionRequest argument LastChange=<CurrentTrackMetaData val=“x-sonos-spotify:spotify%3atrack%3a3JzlizIWmMyj4eIfoiIVfM?sid=12&flags=8224&sn=1<r:streamContent></r:streamContent><r:radioShowMd></r:radioShowMd>upnp:albumArtURI/getaa?s=1&u=x-sonos-spotify%3aspotify%253atrack%253a3JzlizIWmMyj4eIfoiIVfM%3fsid%3d12%26flags%3d8224%26sn%3d1</upnp:albumArtURI>dc:titleBetter - Remastered</dc:title>upnp:classobject.item.audioItem.musicTrack</upnp:class>dc:creatorThe Screaming Jets</dc:creator>upnp:albumDirty Thirty</upnp:album>”/><r:NextTrackURI val=“x-sonos-spotify:spotify%3atrack%3a4ESoCv0wlIsv7cEScCmqWW?sid=12&flags=8224&sn=1”/><r:NextTrackMetaData val=“x-sonos-spotify:spotify%3atrack%3a4ESoCv0wlIsv7cEScCmqWW?sid=12&flags=8224&sn=1upnp:albumArtURI/getaa?s=1&u=x-sonos-spotify%3aspotify%253atrack%253a4ESoCv0wlIsv7cEScCmqWW%3fsid%3d12%26flags%3d8224%26sn%3d1</upnp:albumArtURI>dc:titleC'mon - Remastered</dc:title>upnp:classobject.item.audioItem.musicTrack</upnp:class>dc:creatorThe Screaming Jets</dc:creator>upnp:albumDirty Thirty</upnp:album>”/><r:EnqueuedTransportURI val=“x-rincon-cpcontainer:1004206cspotify%3aalbum%3a6RcqFtDApqtxWThGGlZDOx?sid=12&flags=8300&sn=1”/><r:EnqueuedTransportURIMetaData val="dc:titleDirty Thirty</dc:title>upnp:classobject.container.album.musicAlbum</upnp:class>upnp:albumDirty Thirty</upnp:album>dc:creatorThe Screaming Jets</dc:creator>upnp:albumArtURI https://i.scdn.co/image/ab67616d0000b2736c18414e192c2e7ec7961ada</upnp:albumArtURI><r:description>The Screaming Jets</r:description>SA_RINCON3079_X#Svc3079-58c632fa-Token“/><
AVTransportURIMetaData val=”“/><r:CurrentValidPlayModes val=“SHUFFLE,REPEAT,REPEATONE,CROSSFADE”/> <0x733d0520>
08 10/03/20 12:40:06.491 JobHandler_LuaUPnP::HandleActionRequest argument sid=uuid:RINCON_000E58282D0801400_sub0000000114 <0x733d0520>
50 10/03/20 12:40:06.553 luup_log:361: Sonos: (UPnP) UPnP_request() status=1 statusMsg=200 result=”<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/\" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/\“><s:Body><u:PlayResponse xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"></u:PlayResponse></s:Body></s:Envelope>” <0x77d7c000>
50 10/03/20 12:40:06.554 luup_log:361: Sonos: [debug] sayOrAlert() delaying for duration 3 <0x77d7c000>
50 10/03/20 12:40:06.565 luup_log:361: Sonos: [debug] updateNow(19) <0x77d7c000>
50 10/03/20 12:40:06.567 luup_log:361: Sonos: [debug] queueAlert(19,{ rand=“0.9507924252840989”, action=“Say”, GroupZones=“CURRENT”, serviceId=“urn:micasaverde-com:serviceId:Sonos1”, Text=“good morning”, Engine=“AZURE”, URIMetadata=“<DIDL-Lite xmlns="urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/" xmlns:dc="http://purl.org/dc/elements/1.1/\” xmlns:upnp="urn:schemas-upnp-org:metadata-1-0/upnp/">
<item id="VERA_TTS" parentID="-1" restricted="1">
dc:titleAzure Speech Service</dc:title>
<res protocolInfo="http-get::audio/mpeg:">"https://verasonostts.cognitiveservices.azure.com/\“Say.19.mp3
upnp:classobject.item.audioItem.musicTrack</upnp:class>

”, URI=“"https://verasonostts.cognitiveservices.azure.com/\“Say.19.mp3”, Duration=3, TempFile=”/www/sonos/Say.19.mp3", DeviceNum=“19” }) <0x77d7c000>
04 10/03/20 12:40:06.568 <0x77d7c000>
50 10/03/20 12:40:06.569 luup_log:361: Sonos: [debug] actionSonosNotifyAVTransportChange(19, lul_settings) zone “RINCON_000E58282D0801400” <0x77d7c000>
50 10/03/20 12:40:06.570 luup_log:361: Sonos: [debug] handleAVTransportChange(“RINCON_000E58282D0801400”, event) <0x77d7c000>
06 10/03/20 12:40:06.571 Device_Variable::m_szValue_set device: 19 service: urn:upnp-org:serviceId:AVTransport variable: TransportState was: PAUSED_PLAYBACK now: STOPPED #hooks: 0 upnp: 0 skip: 0 v:0xd07b58/NONE duplicate:0 <0x77d7c000>
06 10/03/20 12:40:06.573 Device_Variable::m_szValue_set device: 19 service: urn:upnp-org:serviceId:AVTransport variable: CurrentTrack was: 8 now: 1 #hooks: 0 upnp: 0 skip: 0 v:0xd18988/NONE duplicate:0 <0x77d7c000>
06 10/03/20 12:40:06.574 Device_Variable::m_szValue_set device: 19 service: urn:upnp-org:serviceId:AVTransport variable: CurrentTrackURI was: x-sonos-spotify:spotify%3atrack%3a2Pfzum4JXjHWE9oi2F6dQ8?sid=12&flags=8224&sn=1 now: x-sonos-spotify:spotify%3atrack%3a3JzlizIWmMyj4eIfoiIVfM?sid=12&flags=8224&sn=1 #hooks: 0 upnp: 0 skip: 0 v:0xd199a8/NONE duplicate:0 <0x77d7c000>
06 10/03/20 12:40:06.586 Device_Variable::m_szValue_set device: 19 service: urn:upnp-org:serviceId:AVTransport variable: CurrentTrackDuration was: 0:04:26 now: 0:04:36 #hooks: 0 upnp: 0 skip: 0 v:0xd18eb8/NONE duplicate:0 <0x77d7c000>
06 10/03/20 12:40:06.597 Device_Variable::m_szValue_set device: 19 service: urn:upnp-org:serviceId:AVTransport variable: CurrentTrackMetaData was: x-sonos-spotify:spotify%3atrack%3a2Pfzum4JXjHWE9oi2F6dQ8?sid=12&flags=8224&sn=1<r:streamContent></r:streamContent>upnp:albumArtURI/getaa?s=1&u=x-sonos-spotify%3aspotify%253atrack%253a2Pfzum4JXjHWE9oi2F6dQ8%3fsid%3d12%26flags%3d8224%26sn%3d1</upnp:albumArtURI>dc:titleShivers - Remastered</dc:title>upnp:classobject.item.audioItem.musicTrack</upnp:class>dc:creatorThe Screaming Jets</dc:creator>upnp:albumDirty Thirty</upnp:album> now: x-sonos-spotify:spotify%3atrack%3a3JzlizIWmMyj4eIfoiIVfM?sid=12&flags=8224&sn=1<r:streamContent></r:streamContent><r:radioShowMd></r:radioShowMd>upnp:albumArtURI/getaa?s=1&u=x-sonos-spotify%3aspotify%253atrack%253a3JzlizIWmMyj4eIfoiIVfM%3fsid%3d12%26flags%3d8224%26sn%3d1</upnp:albumArtURI>dc:titleBetter - Remastered</dc:title>upnp:classobject.item.audioItem.musicTrack</upnp:class>dc:creatorThe Screaming Jets</dc:creator>upnp:albumDirty Thirty</upnp:album> #hooks: 0 upnp: 0 skip: 0 v:0xd196a8/NONE duplicate:0 <0x77d7c000>
06 10/03/20 12:40:06.611 Device_Variable::m_szValue_set device: 19 service: urn:upnp-org:serviceId:AVTransport variable: CurrentTransportActions was: Set, Stop, Pause, Play, X_DLNA_SeekTime, Next, Previous, X_DLNA_SeekTrackNr now: Set, Stop, Pause, Play, X_DLNA_SeekTime, Next, X_DLNA_SeekTrackNr #hooks: 0 upnp: 0 skip: 0 v:0xd19c68/NONE duplicate:0 <0x77d7c000>
06 10/03/20 12:40:06.630 Device_Variable::m_szValue_set device: 19 service: urn:upnp-org:serviceId:AVTransport variable: CurrentStatus was: Shivers - Remastered: (The Screaming Jets, Dirty Thirty) now: Better - Remastered: (The Screaming Jets, Dirty Thirty) #hooks: 0 upnp: 0 skip: 0 v:0xc69588/NONE duplicate:0 <0x77d7c000>
06 10/03/20 12:40:06.631 Device_Variable::m_szValue_set device: 19 service: urn:upnp-org:serviceId:AVTransport variable: CurrentTitle was: Shivers - Remastered now: Better - Remastered #hooks: 0 upnp: 0 skip: 0 v:0xd171c8/NONE duplicate:0 <0x77d7c000>
06 10/03/20 12:40:06.632 Device_Variable::m_szValue_set device: 19 service: urn:upnp-org:serviceId:AVTransport variable: CurrentAlbumArt was: http://192.168.1.138:1400/getaa?s=1&u=x-sonos-spotify%3Aspotify%253atrack%253a2Pfzum4JXjHWE9oi2F6dQ8%3Fsid%3D12%26flags%3D8224%26sn%3D1 now: http://192.168.1.138:1400/getaa?s=1&u=x-sonos-spotify%3Aspotify%253atrack%253a3JzlizIWmMyj4eIfoiIVfM%3Fsid%3D12%26flags%3D8224%26sn%3D1 #hooks: 0 upnp: 0 skip: 0 v:0xd18398/NONE duplicate:0 <0x77d7c000>
50 10/03/20 12:40:06.633 luup_log:361: Sonos: (UPnP) service.__index: “GetPositionInfo”(“http://192.168.1.138:1400/MediaRenderer/AVTransport/Control”, “urn:schemas-upnp-org:service:AVTransport:1”) called with parameter count=1 <0x77d7c000>
50 10/03/20 12:40:06.634 luup_log:361: Sonos: (UPnP) UPnP_request(“http://192.168.1.138:1400/MediaRenderer/AVTransport/Control",“GetPositionInfo”,"urn:schemas-upnp-org:service:AVTransport:1”,{ InstanceID=“0” }) <0x77d7c000>
50 10/03/20 12:40:06.647 luup_log:361: Sonos: (UPnP) UPnP_request() url=“http://192.168.1.138:1400/MediaRenderer/AVTransport/Control”, body=“<?xml version=\"1.0\" encoding=\"utf-8\"?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/\” s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/\">
<s:Body>\

rigpapa · October 3, 2020, 3:43pm

Looks like you might have played with some of the configuration state variables. Did you modify TTSBasePath and/or TTSBaseURL?

DocD · October 3, 2020, 4:26pm

Yes, you’re right. I did put something in the TTSBaseURL field when I was playing with it initially. It won’t let me save it with a null/blank value though.
How can I remove it?

Apologies, I should have mentioned that earlier.

rigpapa · October 3, 2020, 4:39pm

Just for reference (yourself and other readers in future), those settings (TTSBaseURL and TTSBasePath) are really intended for openLuup systems, where it can be installed in any directory, and the TTS scratch files and cache can be located where openLuup is installed or anywhere else in the filesystem. On Vera, those are established, well-known locations so these settings should not be modified. They have nothing to do with the URLs used by individual text engines for access to conversion services.

To clear them:

luup.variable_set( "urn:toggledbits-com:serviceId:SonosSystem1", "TTSBaseURL", "", sonos_master_device_num )
luup.variable_set( "urn:toggledbits-com:serviceId:SonosSystem1", "TTSBasePath", "", sonos_master_device_num )

DocD · October 3, 2020, 11:37pm

Thanks, appreciate the assistance. Updated the variable successfully:

08	10/04/20 10:19:20.621	JobHandler_LuaUPnP::HandleActionRequest device: 0 service: urn:micasaverde-com:serviceId:HomeAutomationGateway1 action: RunLua <0x74d06520>
08	10/04/20 10:19:20.621	JobHandler_LuaUPnP::HandleActionRequest argument id=lu_action <0x74d06520>
08	10/04/20 10:19:20.622	JobHandler_LuaUPnP::HandleActionRequest argument serviceId=urn:micasaverde-com:serviceId:HomeAutomationGateway1 <0x74d06520>
08	10/04/20 10:19:20.622	JobHandler_LuaUPnP::HandleActionRequest argument action=RunLua <0x74d06520>
08	10/04/20 10:19:20.622	JobHandler_LuaUPnP::HandleActionRequest argument Code=luup.variable_set( “urn:toggledbits-com:serviceId:SonosSystem1”, “TTSBaseURL”, “”, 361 ) <0x74d06520>
06	10/04/20 10:19:20.623	Device_Variable::m_szValue_set device: 361 service: urn:toggledbits-com:serviceId:SonosSystem1 variable: TTSBaseURL was: “” now: #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x74d06520>
04	10/04/20 10:19:30.631	<0x77506520>

It still seems to be having trouble playing the chime and the TTS file though. Behaviour the same as before (plays a few seconds of the last queued track). I haven’t touched any other variables.

01 10/04/20 10:21:46.226 luup_log:361: Sonos: UPnP_request (Pause, urn:schemas-upnp-org:service:AVTransport:1): status=1 statusMsg=500 result=[<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”><s:Body><s:Fault>s:ClientUPnPError701</s:Fault></s:Body></s:Envelope>] <0x77b20000>
02 10/04/20 10:21:46.227 luup_log:361: stack traceback:
[string “–[[…”]:265: in function ‘error’
[string “–[[…”]:289: in function <[string “–[[…”]:169>
(tail call): ?
[string “–[[…”]:3398: in function ‘sayOrAlert’
[string “–[[…”]:3460: in function ‘queueAlert’
[string “–[[…”]:3769: in function <[string “–[[…”]:3743>
(tail call): ? <0x77b20000>
50 10/04/20 10:21:46.228 luup_log:361: Sonos: [debug] playURI(“RINCON_000E5833008001400”,“0”,“"https://verasonostts.cognitiveservices.azure.com/\“Sonos_chime.mp3”,“1”,nil,{ 1=“RINCON_000E5833008001400” },nil,nil,true,true) <0x77b20000>
50 10/04/20 10:21:46.229 luup_log:361: Sonos: [debug] controlByCoordinator(“RINCON_000E5833008001400”) <0x77b20000>
50 10/04/20 10:21:46.230 luup_log:361: Sonos: [debug] getZoneGroup() group info for “RINCON_000E5833008001400:41” is { members={ 1=“RINCON_000E5833008001400” }, UUID=“RINCON_000E5833008001400:41”, Coordinator=“RINCON_000E5833008001400” } <0x77b20000>
50 10/04/20 10:21:46.231 luup_log:361: Sonos: [debug] controlByCoordinator() coordinator “RINCON_000E5833008001400” dev 17 <0x77b20000>
50 10/04/20 10:21:46.231 luup_log:361: Sonos: [debug] decodeURI(“RINCON_000E5833008001400”,“RINCON_000E5833008001400”,”"https://verasonostts.cognitiveservices.azure.com/\“Sonos_chime.mp3”) <0x77b20000>
50 10/04/20 10:21:46.232 luup_log:361: Sonos: [debug] decodeURI() uri now “"https://verasonostts.cognitiveservices.azure.com/\“Sonos_chime.mp3” title nil track nil serviceId nil <0x77b20000>
50 10/04/20 10:21:46.233 luup_log:361: Sonos: [debug] decodeURI() url “"https://verasonostts.cognitiveservices.azure.com/\“Sonos_chime.mp3” serviceId nil title nil <0x77b20000>
50 10/04/20 10:21:46.234 luup_log:361: Sonos: [debug] decodeURI() result uri=”"https://verasonostts.cognitiveservices.azure.com/\“Sonos_chime.mp3”, meta=”“, track=nil, groupControl=true, queueing=false <0x77b20000>
50 10/04/20 10:21:46.235 luup_log:361: Sonos: [debug] playURI() creating new group <0x77b20000>
50 10/04/20 10:21:46.236 luup_log:361: Sonos: (UPnP) service.__index: “BecomeCoordinatorOfStandaloneGroup”(“http://192.168.1.127:1400/MediaRenderer/AVTransport/Control”, “urn:schemas-upnp-org:service:AVTransport:1”) called with parameter count=1 <0x77b20000>
50 10/04/20 10:21:46.236 luup_log:361: Sonos: (UPnP) UPnP_request(“http://192.168.1.127:1400/MediaRenderer/AVTransport/Control",“BecomeCoordinatorOfStandaloneGroup”,"urn:schemas-upnp-org:service:AVTransport:1”,{ InstanceID=“0” }) <0x77b20000>
50 10/04/20 10:21:46.237 luup_log:361: Sonos: (UPnP) UPnP_request() url=“http://192.168.1.127:1400/MediaRenderer/AVTransport/Control”, body=”<?xml version=\"1.0\" encoding=\"utf-8\"?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/\" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/\“>
<s:Body>
<u:BecomeCoordinatorOfStandaloneGroup xmlns:u="urn:schemas-upnp-org:service:AVTransport:1">0</u:BecomeCoordinatorOfStandaloneGroup>
</s:Body>
</s:Envelope>” <0x77b20000>
50 10/04/20 10:21:46.415 luup_log:361: Sonos: (UPnP) UPnP_request() status=1 statusMsg=200 result=“<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/\” s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/\“><s:Body><u:BecomeCoordinatorOfStandaloneGroupResponse xmlns:u="urn:schemas-upnp-org:service:AVTransport:1">RINCON_000E5833008001400:42</u:BecomeCoordinatorOfStandaloneGroupResponse></s:Body></s:Envelope>” <0x77b20000>
50 10/04/20 10:21:46.416 luup_log:361: Sonos: [debug] playURI() setting URI to “"https://verasonostts.cognitiveservices.azure.com/\“Sonos_chime.mp3” meta “” <0x77b20000>
50 10/04/20 10:21:46.418 luup_log:361: Sonos: (UPnP) service.__index: “SetAVTransportURI”(“http://192.168.1.127:1400/MediaRenderer/AVTransport/Control”, “urn:schemas-upnp-org:service:AVTransport:1”) called with parameter count=1 <0x77b20000>
50 10/04/20 10:21:46.418 luup_log:361: Sonos: (UPnP) UPnP_request(“http://192.168.1.127:1400/MediaRenderer/AVTransport/Control",“SetAVTransportURI”,"urn:schemas-upnp-org:service:AVTransport:1”,{ OrderedArgs={ 1=“InstanceID=0”, 2=“CurrentURI="https://verasonostts.cognitiveservices.azure.com/\“Sonos_chime.mp3”, 3=“CurrentURIMetaData=” } }) <0x77b20000>
50 10/04/20 10:21:46.420 luup_log:361: Sonos: (UPnP) UPnP_request() url=“http://192.168.1.127:1400/MediaRenderer/AVTransport/Control”, body=”<?xml version=\"1.0\" encoding=\"utf-8\"?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/\” s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/\“>
<s:Body>
<u:SetAVTransportURI xmlns:u="urn:schemas-upnp-org:service:AVTransport:1">0“https://verasonostts.cognitiveservices.azure.com/“Sonos_chime.mp3</u:SetAVTransportURI>
</s:Body>
</s:Envelope>” <0x77b20000>
01 10/04/20 10:21:46.428 luup_log:361: Sonos: UPnP_request (SetAVTransportURI, urn:schemas-upnp-org:service:AVTransport:1): status=1 statusMsg=500 result=[<s:Envelope xmlns:s=“http://schemas.xmlsoap.org/soap/envelope/” s:encodingStyle=“http://schemas.xmlsoap.org/soap/encoding/”><s:Body><s:Fault>s:ClientUPnPError714</s:Fault></s:Body></s:Envelope>] <0x77b20000>
02 10/04/20 10:21:46.429 luup_log:361: stack traceback:
[string “–[[…”]:265: in function ‘error’
[string “–[[…”]:289: in function <[string “–[[…”]:169>
(tail call): ?
[string “–[[…”]:1720: in function ‘playURI’
[string “–[[…”]:3419: in function ‘sayOrAlert’
[string “–[[…”]:3460: in function ‘queueAlert’
[string “–[[…”]:3769: in function <[string “–[[…”]:3743>
(tail call): ? <0x77b20000>
50 10/04/20 10:21:46.430 luup_log:361: Sonos: [debug] playURI() starting play on “RINCON_000E5833008001400” at speed 1 <0x77b20000>
50 10/04/20 10:21:46.430 luup_log:361: Sonos: (UPnP) service.__index: “Play”(“http://192.168.1.127:1400/MediaRenderer/AVTransport/Control”, “urn:schemas-upnp-org:service:AVTransport:1”) called with parameter count=1 <0x77b20000>
50 10/04/20 10:21:46.431 luup_log:361: Sonos: (UPnP) UPnP_request(“http://192.168.1.127:1400/MediaRenderer/AVTransport/Control",“Play”,"urn:schemas-upnp-org:service:AVTransport:1”,{ OrderedArgs={ 1=“InstanceID=0”, 2=“Speed=1” } }) <0x77b20000>
50 10/04/20 10:21:46.432 luup_log:361: Sonos: (UPnP) UPnP_request() url=“http://192.168.1.127:1400/MediaRenderer/AVTransport/Control”, body=”<?xml version=\"1.0\" encoding=\"utf-8\"?>
<s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/\” s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/\">
<s:Body>
<u:Play xmlns:u="urn:schemas-upnp-org:service:AVTransport:1">01</u:Play>
</s:Body>\

rigpapa · October 4, 2020, 2:56pm

Probably just need to reload luup so it picks up the new setting

DocD · October 4, 2020, 10:03pm

Yep, that was it. All working now.

Many thanks for your help. This updated Sonos and the Reactor plug in are excellent. Thanks for putting the time into them.