DoCheckAnnouncementQueue is not working correctly

[Markcp]

The Sonos TTS speech has always worked for me. Then I may follow it with tuning to a Sonos radio station.
Recently I started running into the problem of the Sonos stopping and reverting after 100 seconds.
The "wait for speech to finish" never worked for me, so I would uncheck the box and add a WAIT step. This worked fine. I also unchecked for "Force Wait Flag" in the Sonos Config.

In any case from the logs I see that it is still going to the DoCheckAnnouncementQueue to get the status and there is none (this has never worked for me). When it gets to the 100 seconds it reverts as designed. As a workaround I changed the 100 seconds to 10 seconds, counting on the failure. Then execute Sonos commands thereafter.

I just updated the version of HSPRO and Sono PI last night.

Any way of getting this to work?

Thanks.

--Mark

Below are the logs I captured:

3/15/2013 1:52:48 PM Event Event Trigger "TTS Test"
3/15/2013 1:52:48 PM SonosController SpeakIn called for Device = 0, Text = This is a test of Homeseer and Sonos speech., Wait=False, Host = $SONOS$BEDROOM$HOMESEEREFAULT
3/15/2013 1:52:48 PM SonosController AddAnnouncementToQueue called for LinkGroupName = BEDROOM and Text = This is a test of Homeseer and Sonos speech.
3/15/2013 1:52:48 PM SonosController GetLinkgroupSourceZone called with LinkgroupName = BEDROOM
3/15/2013 1:52:48 PM SonosController GetMusicAPI (Integer) was called with Value: 1
3/15/2013 1:52:48 PM SonosController GetTailOfAnnouncementQueue called
3/15/2013 1:52:48 PM SonosController DoCheckAnnouncementQueue called for linkgroup BEDROOM and State = asIdle and isFile = True
3/15/2013 1:52:48 PM SonosController HandleLinkingOn called with LinkgroupName = BEDROOM
3/15/2013 1:52:48 PM SonosController GetLinkGroupInfo called with LinkgroupName = BEDROOM
3/15/2013 1:52:48 PM SonosController HandleLinkingOn found uuid:RINCON_000E587C80C801400 as source
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo called for zoneplayer - Bedroom
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom saved ZoneIsLinked = False
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom saved SourceLinkedZone =
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom with Track(0) =
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom with Track(1) =
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom with Track(2) =
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom with Track(3) = x-rincon-queue:RINCON_000E587C80C801400#0
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom with Track(4) = /SonosController/images/noart.jpeg
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom with Track(5) = 00:00:00
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom with Track(6) =
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom with Track(7) = 0
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom with Track(8) =
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom with Track(9) = Tracks
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom with Track(10) = False
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom with Track(11) =
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom with Track(12) =
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom saved Queue position = 0
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom saved Player State = STOPPED
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom saved Master Volume = 17
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom saved Mute State = False
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom saved PlayMode State = NORMAL
3/15/2013 1:52:48 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-KitchenNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionRadioStation: The PatriotNo Action
3/15/2013 1:52:48 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:48 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-Living RoomNo ActionLinkNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionKitchen
3/15/2013 1:52:48 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:48 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-Guest RoomNo ActionLinkNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionKitchen
3/15/2013 1:52:48 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:48 PM SonosController TracksInQueue called for ZonePlayer = Bedroom and found 0 tracks.
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom saved MyTargetZoneLinkedList =
3/15/2013 1:52:48 PM SonosController SaveCurrentTrackInfo for zoneplayer Bedroom saved ChannelMapSet =
3/15/2013 1:52:48 PM SonosController SearchZoneUDN called with SearchZoneUDN = RINCON_000E587C80C801400 and SourceZoneUDN = RINCON_000E587C80C801400 and DestinationZoneString =
3/15/2013 1:52:49 PM SonosController GetZoneDestination called for ZoneName Bedroom and TargetZones =
3/15/2013 1:52:49 PM SonosController SavedPlayerList.add called with PlayerIndex = 1
3/15/2013 1:52:49 PM SonosController SearchZoneUDN called with SearchZoneUDN = RINCON_000E587C80C801400 and SourceZoneUDN = RINCON_000E587C80C801400 and DestinationZoneString =
3/15/2013 1:52:49 PM SonosController GetZoneDestination called for ZoneName Bedroom and TargetZones =
3/15/2013 1:52:49 PM SonosController HandleLinkingOn: Done Saving LinkgroupZoneDestination = uuid:RINCON_000E587C80C801400
3/15/2013 1:52:49 PM SonosController SetTransportState called for zoneplayer - Bedroom with value = Stop
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-BedroomNo ActionLinkNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionKitchen
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:49 PM SonosController HandleLinkingOn: Start LinkgroupZoneDestination = uuid:RINCON_000E587C80C801400
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-KitchenNo ActionNo ActionNo Action20No ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:49 PM SonosController HandleLinkingOn: Done LinkgroupZoneDestination = uuid:RINCON_000E587C80C801400
3/15/2013 1:52:49 PM SonosController HandleLinkingOn done with LinkgroupName = BEDROOM
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-BedroomNo ActionUnlinkNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-KitchenNo ActionUnlinkNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-Family RoomNo ActionUnlinkNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-Living RoomNo ActionUnlinkNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-Guest RoomNo ActionUnlinkNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-Living RoomNo ActionNo ActionNo Action15No ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-BedroomNo ActionNo ActionNo Action10No ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-KitchenNo ActionNo ActionNo Action10No ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-Family RoomNo ActionNo ActionNo Action20No ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:49 PM SonosController DoCheckAnnouncementQueue activated with HostName = HOMESEEREFAULT Text = This is a test of Homeseer and Sonos speech. and LinkgroupName = BEDROOM
3/15/2013 1:52:49 PM SonosController DoCheckAnnouncementQueue adds file = C:\Program Files (x86)\HomeSeer HSPRO\html/SonosController/Announcements/Ann_BEDROOM_0 to Queue
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-Guest RoomNo ActionNo ActionNo Action10No ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:49 PM SonosController DoCheckAnnouncementQueue calling SpeakToFile with Text This is a test of Homeseer and Sonos speech. and File C:\Program Files (x86)\HomeSeer HSPRO\html/SonosController/Announcements/Ann_BEDROOM_0.wav
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-Living RoomNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionLearned - 'A' Net StationNo Action
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-KitchenNo ActionLinkNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionLiving Room
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-Family RoomNo ActionLinkNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionLiving Room
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-Guest RoomNo ActionLinkNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionLiving Room
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-BedroomNo ActionLinkNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionLiving Room
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-KitchenNo ActionStop PlayingNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:49 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-KitchenNo ActionNo ActionNo Action40No ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-KitchenNo ActionStop PlayingNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-KitchenNo ActionNo ActionNo Action40No ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-KitchenNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionRadioStation: KNOW-FMNo Action
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-BedroomNo ActionUnlinkNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-KitchenNo ActionUnlinkNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-Family RoomNo ActionUnlinkNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-Living RoomNo ActionUnlinkNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with action = SONOSCONTROLLER-Guest RoomNo ActionUnlinkNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo ActionNo Action
3/15/2013 1:52:50 PM SonosController ActionUIFormat called with 23 objects
3/15/2013 1:52:52 PM SonosController DoCheckChange Called
3/15/2013 1:52:52 PM SonosController DoCheckAnnouncementQueue finished SpeakToFile
3/15/2013 1:52:52 PM SonosController PlayURI called for zoneplayer Bedroom with strURI = http://192.168.1.200:80/SonosController/Announcements/Ann_BEDROOM_0.wav and MetaData = http://192.168.1.200:80/SonosController/Announcements/Ann_BEDROOM_0.wavhttp://192.168.1.200:80/SonosController/Announcements/Announcement.jpgHomeSeer Announcementobject.item.audioItem.musicTrackDirk CorsusSonosControllerDirk Corsus
3/15/2013 1:52:52 PM SonosController DoCheckAnnouncementQueue is calling PlayURI with http://192.168.1.200:80/SonosController/Announcements/Ann_BEDROOM_0.wav
3/15/2013 1:52:52 PM SonosController Waiting in DoCheckAnnouncementQueue before issues play for = 2 seconds
3/15/2013 1:52:54 PM SonosController SetTransportState called for zoneplayer - Bedroom with value = Play

Note: it played the voice fine --Mark.

3/15/2013 1:52:59 PM SonosController Warning in DoCheckAnnouncementQueue. Announcement hasn't started after 6 seconds
3/15/2013 1:53:24 PM SonosController Warning in DoCheckAnnouncementQueue. Announcement hasn't started after 31 seconds
3/15/2013 1:53:31 PM SonosController ActionUI called with action string =
3/15/2013 1:53:31 PM SonosController ActionUI called with 0 objects
3/15/2013 1:53:31 PM SonosController NumInstances called. Instances is 5
3/15/2013 1:53:36 PM SonosController ActionUI called with action string =
3/15/2013 1:53:36 PM SonosController ActionUI called with 0 objects
3/15/2013 1:53:36 PM SonosController NumInstances called. Instances is 5
3/15/2013 1:54:36 PM SonosController Error in DoCheckAnnouncementQueue. 100 seconds expired since the announcement started and no end was received.
3/15/2013 1:54:36 PM SonosController DoCheckAnnouncementQueue called for linkgroup BEDROOM and State = asFilePlayed and isFile = True
3/15/2013 1:54:36 PM SonosController HandleLinkingOff called with LinkgroupName = BEDROOM
3/15/2013 1:54:36 PM SonosController GetLinkGroupInfo called with LinkgroupName = BEDROOM
3/15/2013 1:54:36 PM SonosController PlayURI called for zoneplayer Bedroom with strURI = x-rincon-queue:RINCON_000E587C80C801400#0 and MetaData =
3/15/2013 1:54:37 PM SonosController SavedPlayerList.GetLastIndex called
3/15/2013 1:54:37 PM SonosController SavedPlayerList.GetLastIndex called and returned Index = 1
3/15/2013 1:54:37 PM SonosController RestoreCurrentTrackInfo for Zonename = Bedroom and MySavedTrackinfo = x-rincon-queue:RINCON_000E587C80C801400#0
3/15/2013 1:54:37 PM SonosController PlayURI called for zoneplayer Bedroom with strURI = x-rincon-queue:RINCON_000E587C80C801400#0 and MetaData =
3/15/2013 1:54:37 PM SonosController SetVolumeLevel called for ZonePlayer = Bedroom with values Channel=Master Value=17
3/15/2013 1:54:38 PM SonosController SetPlayMode called for ZoneName Bedroom with value = NORMAL
3/15/2013 1:54:38 PM SonosController SetTransportState called for zoneplayer - Bedroom with value = STOPPED
3/15/2013 1:54:38 PM SonosController PlayChangeNotifyCallback called for Zone - Bedroom with ChangeType = PlayStatusChanged and Changevalue = stopped
3/15/2013 1:54:38 PM SonosController CheckTrigger called in DeviceTrigger for Zone - Bedroom with Trigger = SONOSCONTROLLERSonos Player TriggerPlayer Stop
3/15/2013 1:54:38 PM SonosController RestoreCurrentTrackInfo updated HS DeviceValue for zonePlayer Bedroom. HS Code = [2 and value = stopped
3/15/2013 1:54:38 PM SonosController RestoreCurrentTrackInfo is done for zonePlayer Bedroom
3/15/2013 1:54:38 PM SonosController SavedPlayerList.GetLastIndex called
3/15/2013 1:54:38 PM SonosController HandleLinkingOff done with LinkgroupName = BEDROOM
3/15/2013 1:54:38 PM SonosController DeleteHeadOfAnnouncementQueue called
3/15/2013 1:54:38 PM SonosController DoCheckAnnouncementQueue called and all announcements were processed
3/15/2013 1:54:38 PM SonosController DeletePreviousSavedQueues called for ZonePlayer = Bedroom with QueueName = SCQueue-Bedroom-BEDROOM
3/15/2013 1:54:39 PM SonosController DeletePreviousSavedQueues found 0 playlists for ZonePlayer - Bedroom
3/15/2013 1:55:00 PM SonosController GenPage called with Link= /SonosController_config and LinkIndex= 0 and page_title=Sonos Controller Configuration and Linktext= Sonos Config and Link= SonosController_config
3/15/2013 1:55:00 PM SonosController GetIniSection called with Section = TTSSpeakDevice
3/15/2013 1:55:00 PM SonosController GetIniSection called with Section = TTSSpeakDevice
3/15/2013 1:55:01 PM SonosController GetIniSection called with Section = TTSSpeakDevice
3/15/2013 1:55:10 PM SonosController BackUpIniFile called with IniFileName = C:\Program Files (x86)\HomeSeer HSPRO\Config\HSPI_SONOSCONTROLLER.ini
3/15/2013 1:55:10 PM SonosController BackUpIniFile file copied = C:\Program Files (x86)\HomeSeer HSPRO\Config\HSPI_SONOSCONTROLLER_ini_Saved_3_15_2013_1_55_1 0_PM.ini
3/15/2013 1:55:10 PM SonosController DeleteIniSection called with Section = LinkgroupZoneSource
3/15/2013 1:55:10 PM SonosController DeleteIniSection called with Section = LinkgroupZoneDestination
3/15/2013 1:55:10 PM SonosController DeleteIniSection called with Section = TTSSpeakDevice
3/15/2013 1:55:10 PM SonosController DeleteIniSection called with Section = LinkgroupNames

[dcorsus]

The Sonos TTS speech has always worked for me. Then I may follow it with tuning to a Sonos radio station.
Recently I started running into the problem of the Sonos stopping and reverting after 100 seconds.
The "wait for speech to finish" never worked for me, so I would uncheck the box and add a WAIT step. This worked fine. I also unchecked for "Force Wait Flag" in the Sonos Config.

In any case from the logs I see that it is still going to the DoCheckAnnouncementQueue to get the status and there is none (this has never worked for me). When it gets to the 100 seconds it reverts as designed. As a workaround I changed the 100 seconds to 10 seconds, counting on the failure. Then execute Sonos commands thereafter.

I just updated the version of HSPRO and Sono PI last night.

Any way of getting this to work?

Thanks.

--Mark

Two things to try: just for the heck, can you power cycle the bedroom player (pull out power :-) and see if that makes a difference. The problem is with Sonos not issuing a play event. Is this always failing or intermittent? I'm interested to see if this made a difference.

Second thing to try is to locate the following line in the HSPI_Sonoscontroller.ini file:

AnnouncementWaitforPlayTime=2

and change the value to 3 or 4 or 6 until it works. When you edit the value, you need to restart HS for the change to take effect. If you don't like to restart HS, after you've edited and saved the new value, go to the Sonos Config page and just click the Save button, that might do it. Just look for this line in your log file to see if the value was properly picked up:

SonosController Waiting in DoCheckAnnouncementQueue before issues play for = 2 seconds

You wrote about inserting a wait, where exactly are you inserting a wait?

Dirk

[Markcp]

Tried other things

- I had inserted the WAIT in the rule since 'wait for speech to finish' never worked.
- I tried powering down
- I also tried increasing AnnouncementWaitForPlay all the way up to 8 seconds.

I tried a couple other things:
-Temporarily disabled my firewall in case that was blocking
- I opened Sonos on iPhone, iPad, and HS Devices page
When I started/stopped, etc on iPhone or iPad it reflected on the other, right away. Did not reflect in HS. Looks like the speakers are transmitting status changes.
- This is very curious. If I started or stopped in HS devices page, it worked on the speaker but did not reflect on the status even though I made that change in HS. Upon closer inspection, the content on the speakers (song name, playart) is all mine but way out of date. This for sure is not updating real-time.
- it looks like commands going TO the speakers works fine.
- Status updates FROM the speakers is not registering.

[dcorsus]

- I had inserted the WAIT in the rule since 'wait for speech to finish' never worked.
- I tried powering down
- I also tried increasing AnnouncementWaitForPlay all the way up to 8 seconds.

I tried a couple other things:
-Temporarily disabled my firewall in case that was blocking
- I opened Sonos on iPhone, iPad, and HS Devices page
When I started/stopped, etc on iPhone or iPad it reflected on the other, right away. Did not reflect in HS. Looks like the speakers are transmitting status changes.
- This is very curious. If I started or stopped in HS devices page, it worked on the speaker but did not reflect on the status even though I made that change in HS. Upon closer inspection, the content on the speakers (song name, playart) is all mine but way out of date. This for sure is not updating real-time.
- it looks like commands going TO the speakers works fine.
- Status updates FROM the speakers is not registering.

hmm, something has to come from the players else I wouldn't even find them.

Can you do the following: turn the Sonos PI debug flag on (don't forget to save). Make sure HS logging to disk is turned on. Restart HS, let it come up, do an announcement, send me the log file starting with the log of HS coming up.

I'm still not tracking on where you inserted a wait? What rule? Do you mean action? Could you do some screen shots of how you have set up the announcements (that is the Sonos config page) and any events/actions or where this "rule" is applied.

Thanks

Dirk

[Markcp]

Sure, I can do that. In what directory is the log file stored?

Thanks.

--Mark

[dcorsus]

Sure, I can do that. In what directory is the log file stored?

Thanks.

--Mark

.... depends on your setting in HS setup page. Typically the <hs root>\logs subdirectory.

What about my question on your "wait rule"? Can you post a screen shot where and how you inserted that.

Thanks

Dirk

[Markcp]

Do you have an email address I can send this to? The text is too long to paste here and I don't see how you can paste image files.

All done. I copied screenshots of the Sonos Config as well as the rule (with the 'wait' in the action). The reason I use the 'wait' is because if I check the box 'wait for message to complete', without an explicit wait statement it tries to move forward to the next step right away.

I copied the logs from the start-up with Sonos verbose logging turned on. I noted in green for where the actions place.

Thanks Dirk!

--Mark

[Markcp]

I found your email address on your profile and sent the attachment there. You should have it now.

---Mark

[dcorsus]

I bought two new Sonos and downloaded the plugin yesterday. I have the same exact error. Tried the changes Dirk talked about in this post and it did not help. The radios have the latest firmware download.

Error in DoCheckAnnouncementQueue. 100 seconds expired since the announcement started and no end was received.

Which Windows version are you running HS on?

Dirk

[dcorsus]

Windows 7 64bit.

I'm also try setting the host for a different linkgroup in your config file and both speakers are always playing. Maybe this is not correct to use linkgroup in this way with only one speaker?

Any chance to post some screen shots (both of the Sonos Config page and your action/event page) and some debug log with debug flag of the SonosController PI active.

Thanks

Dirk

[dcorsus]

Windows 7 64bit.

Marc appears to be on Win8 and has no events what so ever. Could be a Win8 setting/issue. Yours might be something else as many users use announcements w/o issues on Win7

Dirk

[dcorsus]

I have not posted much so I am still trying to figure out how to post the screen shot. I will send the config file info for now..

Just hit ctrl-print screen, open up paint, do a paste, save it and upload as attachment to your post here.
The .ini file is good.

From the log, I can see events, so that is different from Marc but I see responses being slower than molasses. Is this on a very slow PC or a very busy PC or a very slow or very busy network? Perhaps Anti-virus/Firewall too slow inspecting incoming/outgoing messages/transfers?

One of the things you can try to change in your .ini file is this line:

AnnouncementWaitforPlayTime=6

See if that helps.

For example:

3/25/2013 6:38:55 PM SonosController SetVolumeLevel called for ZonePlayer = Living Room with values Channel=Master Value=6
3/25/2013 6:39:21 PM SonosController Living Room : Rendering (Master Volume) = 60

A WHOPPING 27 SECONDS to respond to a volume change ??????

Are you using the latest Sonos SW version? Do you actually hear the announcement almost instantaneously or very much delayed?

Which version of HS are you using and which version of the plug-in?

Dirk

[dcorsus]

I have restarted HS a few times during debug. Currently sonos did start to sync and unsync. Still getting the no end statement after the timer in the config expires.

One more thing, in the log you provided, the Living room player is grouped with the bedroom player. If you ungroup them first, do you still have this problem?

Dirk

[dcorsus]

It is a fan less shuttle computer 1.6GHZ with a ssd and 3 gig memory. Memory and cpu run about 50% usage. Network is dual band and I do not notice any lag on the internet, all wireless computers. It is dedicated to HS. I do have about 8 plugins in use with HS version 2.5.0.60, none give me any problems. The plugin was downloaded today again from the updater on a backup HS that has not had the plugin installed. I have used sonos control software for testing with out a flaw but it was loaded on my desktop and not my HS computer.

What I might do is install a fresh HS trial on another computer this weekend if I get sometime and use the sonos plugin and see what happens. I will let you know the results.

50% is actually quite high if just for HS. Would recommend to download HS v.79, because .60 had a number of issues although none that would affect what you experience.

If after you reinstall, the problem is still the same, there is something I would like you to try. Set the max announcement time to let's say 100 seconds. Then set in the .ini file the

AnnouncementWaitforPlayTime=xxx

with xxx to something high, maybe set it to 30, see if there is a point where it actually works.

This is the first time I have somebody that has it not working at all. I've seen it on occasion but can't simulate it if I set the AnnouncementWaitForPlayTime higher then 4 seconds.

Dirk

[Markcp]

Hi Dirk, I found the problem. I did as you suggested and dug into the firewall.
My McAfee Total Protection had my wifi router listed as "Public" (so higher level of scrutiny).
After I changed it to "Home" (traffic trusted), Sonos plugin started to behave as expected.

Announcements work fine, that cool " save and restore" pre/post announcement works and the status page with the Sonos devices is now updating.

Thanks for all your help.

--Mark