alexa / avs-device-sdk

An SDK for commercial device makers to integrate Alexa directly into connected products.
https://developer.amazon.com/alexa/alexa-voice-service
Apache License 2.0
1.26k stars 604 forks source link

Alarm list in AVS cloud does not match local copy #2023

Open brett-lynnes opened 2 years ago

brett-lynnes commented 2 years ago

IMPORTANT: Before you create an issue, please take a look at our Issue Reporting Guide.

Briefly summarize your issue:

Using a LOCAL_STOP on an snoozing AVS alert (set using "Alexa set alarm at [time]", then when it goes off say "Alexa snooze") the alarm is removed locally (will not trigger at the end of 9 minutes of snooze) and is no longer in the local databases (alerts.db and offline_alerts.db). However, if you say "Alexa what are my alarms", the answer will be "You have one alarm set for [time] currently snoozing until [time+9mins]"

basically, the local version of what alarms are pending differs from the online version

What is the expected behavior?

When asking AVS cloud what pending alarms are set, the ones stopped with a LOCAL_STOP should not be in the list.

What behavior are you observing?

pushing our LOCAL_STOP button (sending a LOCAL_STOP to the server) is not removing the alarm from the cloud's list of alarms (it is also still visible in the Alexa App).

logs in reply where I snoozed an ongoing alarm, then pushed the local "stop" button. i added a DEBUG: line to the output so you can see that the LOCAL_STOP was sent to the server via certifiedSender [W](140003510314752) 14:51:09.6121 DEBUG: send using certified: {"event":{"header":{"namespace":"Alerts","name":"AlertStopped","messageId":"250dc3bf-6f9f-4e05-92b2-5dc613c309d4"},"payload":{"token":"amzn1.as-ct.v1.Domain:Application:Alarms#DNID#d71ce0f3-49d7-3bef-ad6c-98bb199bdf61","scheduledTime":"LOCAL_STOP","eventTime":"2022-04-05T21:51:09Z"}}}

Provide the steps to reproduce the issue, if applicable:

Set an alarm and snooze it with your voice. While it is snoozing, stop it with a LOCAL_STOP command (in our case a button). Say "Alexa what are my alarms" (or check the Alexa App to see the alarm appears to still be pending).

Tell us about your environment:

What version of the AVS Device SDK are you using?

  <1.26.0>

Tell us what hardware you're using:

Tell us about your OS (Type & version):

brett-lynnes commented 2 years ago

W 14:51:02.7206 RSBS createAnimation: [blinkCycle|min 0|max 1|500000000] W 14:51:03.7242 RSBS createAnimation: [blinkCycle|min 0|max 1|500000000] 2022-04-05 21:51:04.059 [ 1c] 9 KeywordObserver:computeStartOfSpeechTimestamp:timeSinceStartOfWW=720 I 14:51:04.0598 2022-04-05 21:51:04.059 [ 6] I AudioInputProcessor:Create audio attachment reader success:resolveKey=DEFAULT_RESOLVE_KEY,format=AUDIO_L16_RATE_16000_CHANNELS_1 I 14:51:04.0601 2022-04-05 21:51:04.060 [ 6] I MessageRouter:onWakeConnectionRetry I 14:51:04.0601 2022-04-05 21:51:04.060 [ 6] I MessageRouter:onWakeConnectionRetry:m_activeTransport=0x55c00fd2c4b0 I 14:51:04.0602 2022-04-05 21:51:04.060 [ 6] I HTTP2Transport:onWakeConnectionRetry:this=0x55c00fd2c4b0 W 14:51:04.0604 Calling stop animation on [pri_alexa_speaking_animation|min -2147483648|max -2147483648|40000000] I 14:51:04.0605 2022-04-05 21:51:04.060 [ 9] I ContextManager:updateCapabilityState I 14:51:04.0606 2022-04-05 21:51:04.060 [ 9] I ContextManager:updateCapabilityState I 14:51:04.0608 2022-04-05 21:51:04.060 [ 9] I ContextManager:updateCapabilityState I 14:51:04.0609 2022-04-05 21:51:04.060 [ 9] I ContextManager:updateCapabilityState I 14:51:04.0613 2022-04-05 21:51:04.061 [ 6] I DirectiveProcessor:setDialogRequestIdLocked:oldValue=108feecf-2eb2-441c-b6f7-8630530066f6,newValue=1b237734-a390-48c8-9781-04f9622e9565 I 14:51:04.0616 2022-04-05 21:51:04.061 [ d] I InterruptModel:getMixingBehavior:lowPriochannel=Alert,lowPrioContentType=MIXABLE,highPrioChannel=Dialog,highPrioContentType=MIXABLE D 14:51:04.0617 void alexaClientSDK::dopplerAlerts::DopplerAlertScheduler::updateFocus(alexaClientSDK::avsCommon::avs::FocusState, alexaClientSDK::avsCommon::avs::MixingBehavior) (/home/lynnes/workspace/doppler/src/AVS/Alerts/DopplerAlertScheduler.cpp:972) calling updateFocus with behavior: MAY_DUCK D 14:51:04.0618 virtual void alexaClientSDK::dopplerAlerts::renderer::DopplerRenderer::stop() (/home/lynnes/workspace/doppler/src/AVS/Alerts/DopplerRenderer.cpp:196) Doppler renderer stop called. W 14:51:04.0620 DEBUG: sendEvent AlertEnteredBackground with token amzn1.as-ct.v1.Domain:Application:Alarms#DNID#d71ce0f3-49d7-3bef-ad6c-98bb199bdf61 W 14:51:04.0622 DEBUG: send using messageSender: {"event":{"header":{"namespace":"Alerts","name":"AlertEnteredBackground","messageId":"7539cdb3-b070-47f5-a173-210966af0ca6"},"payload":{"token":"amzn1.as-ct.v1.Domain:Application:Alarms#DNID#d71ce0f3-49d7-3bef-ad6c-98bb199bdf61"}}} D 14:51:04.0624 virtual void ModeService::onAlertStateChange(const alexaClientSDK::acsdkAlertsInterfaces::AlertObserverInterface::AlertInfo&) (/home/lynnes/workspace/doppler/src/ModeService.cpp:97) Executing ModeService::onAlertStateChange W 14:51:04.0624 ALERT amzn1.as-ct.v1.Domain:Application:Alarms#DNID#d71ce0f3-49d7-3bef-ad6c-98bb199bdf61 STATE CHANGED TO SOMETHING WE DONT CARE ABOUT: FOCUS_ENTERED_BACKGROUND D 14:51:04.0633 void alexaClientSDK::dopplerAlerts::renderer::DopplerRenderer::executeOnPlaybackStopped(alexaClientSDK::dopplerAlerts::renderer::DopplerRenderer::SourceId) (/home/lynnes/workspace/doppler/src/AVS/Alerts/DopplerRenderer.cpp:530) DopplerRenderer: onPlaybackStopped of 2 W 14:51:04.0755 RSBS createAnimation: [pri_alexa_listening_animation|min 0|max 14|40000000] T 14:51:04.0755 ############################

Listening...

############################

14:51:04.075 ALEXA_LISTENING: W 14:51:04.1385 ATTEMPTING TO CLEAR ASSET DATA BUFFER W 14:51:04.1386 DEBUG DEBUG: shouldPlayLocal set to 0 W 14:51:04.1386 DEBUG DEBUG: shouldPlayLocal now set to 0 W 14:51:04.6778 RSBS createAnimation: [pri_alexa_listening_active_animation|min 0|max 2147483647|40000000] W 14:51:04.7280 RSBS createAnimation: [blinkCycle|min 0|max 1|500000000] W 14:51:05.7317 RSBS createAnimation: [blinkCycle|min 0|max 1|500000000] I 14:51:05.7882 2022-04-05 21:51:05.788 [ 13] I DirectiveSequencer:onDirective:directive=namespace\:SpeechRecognizer\,name\:StopCapture\,messageId\:9228495a-69ef-4fef-84dc-ad9dfa651b7e\,dialogRequestId\:1b237734-a390-48c8-9781-04f9622e9565\,correlationToken\:\,eventCorrelationToken\:\,payloadVersion\:\,instance\: I 14:51:05.7884 2022-04-05 21:51:05.788 [ 1d] I DirectiveRouter:preHandleDirective:messageId=9228495a-69ef-4fef-84dc-ad9dfa651b7e,action=calling I 14:51:05.7886 2022-04-05 21:51:05.788 [ 1e] I DirectiveRouter:handleDirective:messageId=9228495a-69ef-4fef-84dc-ad9dfa651b7e,action=calling I 14:51:05.7983 2022-04-05 21:51:05.798 [ 13] I DirectiveSequencer:onDirective:directive=namespace\:SpeechRecognizer\,name\:SetEndOfSpeechOffset\,messageId\:adccb55d-75f5-43cf-a4da-0a1e5c1a5425\,dialogRequestId\:1b237734-a390-48c8-9781-04f9622e9565\,correlationToken\:\,eventCorrelationToken\:\,payloadVersion\:\,instance\: I 14:51:05.7984 2022-04-05 21:51:05.798 [ 1d] I DirectiveRouter:preHandleDirective:messageId=adccb55d-75f5-43cf-a4da-0a1e5c1a5425,action=calling I 14:51:05.7985 2022-04-05 21:51:05.798 [ 13] I DirectiveSequencer:onDirective:directive=namespace\:InteractionModel\,name\:RequestProcessingStarted\,messageId\:ec12a6b2-57f9-4e82-a1cd-ec8b4cd7eed9\,dialogRequestId\:1b237734-a390-48c8-9781-04f9622e9565\,correlationToken\:\,eventCorrelationToken\:\,payloadVersion\:\,instance\: I 14:51:05.7985 2022-04-05 21:51:05.798 [ 1e] I DirectiveRouter:handleDirective:messageId=adccb55d-75f5-43cf-a4da-0a1e5c1a5425,action=calling I 14:51:05.7986 2022-04-05 21:51:05.798 [ 1d] I DirectiveRouter:preHandleDirective:messageId=ec12a6b2-57f9-4e82-a1cd-ec8b4cd7eed9,action=calling I 14:51:05.7988 2022-04-05 21:51:05.798 [ 1e] I DirectiveRouter:handleDirective:messageId=ec12a6b2-57f9-4e82-a1cd-ec8b4cd7eed9,action=calling W 14:51:05.7990 Calling stop animation on [pri_alexa_listening_active_animation|min 0|max 2147483647|40000000] W 14:51:05.8153 RSBS createAnimation: [pri_alexa_thinking_animation|min 0|max 20|40000000] T 14:51:05.8154 ###########################

Thinking...

###########################

14:51:05.815 ALEXA_THINKING: I 14:51:05.9947 2022-04-05 21:51:05.994 [ 13] I DirectiveSequencer:onDirective:directive=namespace\:SpeechSynthesizer\,name\:Speak\,messageId\:d9299530-470d-4f6b-b45a-78a99fb9a9fc\,dialogRequestId\:1b237734-a390-48c8-9781-04f9622e9565\,correlationToken\:\,eventCorrelationToken\:\,payloadVersion\:\,instance\: I 14:51:05.9949 2022-04-05 21:51:05.994 [ 1d] I DirectiveRouter:preHandleDirective:messageId=d9299530-470d-4f6b-b45a-78a99fb9a9fc,action=calling I 14:51:05.9952 2022-04-05 21:51:05.995 [ 1e] I DirectiveRouter:handleDirective:messageId=d9299530-470d-4f6b-b45a-78a99fb9a9fc,action=calling W 14:51:05.9987 2022-04-05 21:51:05.998 [ 1f] W MediaPlayer:getCurrentStreamOffsetError:name=SpeakMediaPlayer,reason=getElementGetStateUnsuccessful,stateChangeReturn=ASYNC W 14:51:06.0647 2022-04-05 21:51:06.064 [ 1f] W MediaPlayer:getCurrentStreamOffsetError:name=SpeakMediaPlayer,reason=getElementGetStateUnsuccessful,stateChangeReturn=ASYNC W 14:51:06.0648 2022-04-05 21:51:06.064 [ 1f] W MediaPlayer:getCurrentStreamOffsetError:name=SpeakMediaPlayer,reason=getElementGetStateUnsuccessful,stateChangeReturn=ASYNC I 14:51:06.0652 2022-04-05 21:51:06.065 [ 1a] I ContextManager:updateCapabilityState W 14:51:06.0654 Calling stop animation on [pri_alexa_thinking_animation|min 0|max 20|40000000] W 14:51:06.0662 RSBS createAnimation: [pri_alexa_speaking_animation|min 0|max 77|40000000] T 14:51:06.0663 ###########################

Speaking...

###########################

14:51:06.066 ALEXA_SPEAKING: I 14:51:06.1107 2022-04-05 21:51:06.110 [ 13] I DirectiveSequencer:onDirective:directive=namespace\:Alerts\,name\:SetAlert\,messageId\:28f7822f-172c-4a0e-a1d7-79dadbcc68eb\,dialogRequestId\:\,correlationToken\:\,eventCorrelationToken\:\,payloadVersion\:\,instance\: I 14:51:06.1108 2022-04-05 21:51:06.110 [ 1d] I DirectiveRouter:preHandleDirective:messageId=28f7822f-172c-4a0e-a1d7-79dadbcc68eb,action=calling I 14:51:06.1110 2022-04-05 21:51:06.110 [ 1e] I DirectiveRouter:handleDirective:messageId=28f7822f-172c-4a0e-a1d7-79dadbcc68eb,action=calling 14:51:06.111 ALERT_SNOOZED:2 ALARM 14 51 D 14:51:06.1116 virtual void alexaClientSDK::dopplerAlerts::renderer::DopplerRenderer::stop() (/home/lynnes/workspace/doppler/src/AVS/Alerts/DopplerRenderer.cpp:196) Doppler renderer stop called. W 14:51:06.1117 DEBUG DEBUG: should be playing sounds now I 14:51:06.1118 {"alarms":[{"color":{"blue":0,"green":0,"red":255},"id":0,"name":"Doppler System Alarm","repeat":"0","sound":"Harp.mp3","src":0,"status":10,"time_hr":17,"time_min":32,"volume":100},{"color":{"blue":254,"green":237,"red":0},"id":1,"name":"","repeat":"","sound":"","src":2,"status":5,"time_hr":14,"time_min":51,"volume":100}]} D 14:51:06.1119 virtual void ModeService::onAlertStateChange(const alexaClientSDK::acsdkAlertsInterfaces::AlertObserverInterface::AlertInfo&) (/home/lynnes/workspace/doppler/src/ModeService.cpp:97) Executing ModeService::onAlertStateChange W 14:51:06.1119 ALERT amzn1.as-ct.v1.Domain:Application:Alarms#DNID#d71ce0f3-49d7-3bef-ad6c-98bb199bdf61 STATE CHANGED TO SOMETHING WE DONT CARE ABOUT: SCHEDULED_FOR_LATER W 14:51:06.1120 DEBUG: sendEvent SetAlertSucceeded with token amzn1.as-ct.v1.Domain:Application:Alarms#DNID#d71ce0f3-49d7-3bef-ad6c-98bb199bdf61 W 14:51:06.1122 DEBUG: send using certified: {"event":{"header":{"namespace":"Alerts","name":"SetAlertSucceeded","messageId":"e799cd00-fd69-41ff-a19c-205950d6db0e"},"payload":{"token":"amzn1.as-ct.v1.Domain:Application:Alarms#DNID#d71ce0f3-49d7-3bef-ad6c-98bb199bdf61"}}} D 14:51:06.1128 void alexaClientSDK::dopplerAlerts::renderer::DopplerRenderer::executeOnPlaybackStopped(alexaClientSDK::dopplerAlerts::renderer::DopplerRenderer::SourceId) (/home/lynnes/workspace/doppler/src/AVS/Alerts/DopplerRenderer.cpp:530) DopplerRenderer: onPlaybackStopped of 3 W 14:51:06.1129 ATTEMPTING TO CLEAR ASSET DATA BUFFER I 14:51:06.1130 executeOnAlertStateChange alertToken amzn1.as-ct.v1.Domain:Application:Alarms#DNID#d71ce0f3-49d7-3bef-ad6c-98bb199bdf61 state SNOOZED reason D 14:51:06.1130 void alexaClientSDK::dopplerAlerts::DopplerAlertScheduler::executeOnAlertStateChange(const alexaClientSDK::acsdkAlertsInterfaces::AlertObserverInterface::AlertInfo&) (/home/lynnes/workspace/doppler/src/AVS/Alerts/DopplerAlertScheduler.cpp:1219) Entering the Snoozed State D 14:51:06.2151 void alexaClientSDK::dopplerAlerts::DopplerAlertScheduler::executeOnAlertStateChange(const alexaClientSDK::acsdkAlertsInterfaces::AlertObserverInterface::AlertInfo&) (/home/lynnes/workspace/doppler/src/AVS/Alerts/DopplerAlertScheduler.cpp:1222) m_activeAlert.reset called I 14:51:06.2154 {"alarms":[{"color":{"blue":254,"green":237,"red":0},"id":1,"name":"","repeat":"","sound":"","src":2,"status":6,"time_hr":14,"time_min":51,"volume":100},{"color":{"blue":0,"green":0,"red":255},"id":0,"name":"Doppler System Alarm","repeat":"0","sound":"Harp.mp3","src":0,"status":10,"time_hr":17,"time_min":32,"volume":100}]} D 14:51:06.2158 void alexaClientSDK::dopplerAlerts::DopplerAlertScheduler::updateFocus(alexaClientSDK::avsCommon::avs::FocusState, alexaClientSDK::avsCommon::avs::MixingBehavior) (/home/lynnes/workspace/doppler/src/AVS/Alerts/DopplerAlertScheduler.cpp:972) calling updateFocus with behavior: MUST_STOP I 14:51:06.2159 2022-04-05 21:51:06.215 [ 1a] I ContextManager:updateCapabilityState D 14:51:06.2160 virtual void ModeService::onAlertStateChange(const alexaClientSDK::acsdkAlertsInterfaces::AlertObserverInterface::AlertInfo&) (/home/lynnes/workspace/doppler/src/ModeService.cpp:97) Executing ModeService::onAlertStateChange W 14:51:06.2160 ALERT amzn1.as-ct.v1.Domain:Application:Alarms#DNID#d71ce0f3-49d7-3bef-ad6c-98bb199bdf61 STATE CHANGED TO SNOOZED D 14:51:06.2161 bool alexaClientSDK::dopplerAlerts::DopplerAlertScheduler::deactivateActiveAlertHelperLocked(alexaClientSDK::dopplerAlerts::DopplerAlert::StopReason) (/home/lynnes/workspace/doppler/src/AVS/Alerts/DopplerAlertScheduler.cpp:1312) call deactivateActiveAlertHelperLocked D 14:51:06.2161 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:267) Deregistering Handlers D 14:51:06.2162 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:269) Shutting down Graphics D 14:51:06.2162 void AlarmExecutingService::deregisterHandlersInternal() (/home/lynnes/workspace/doppler/src/AlarmExecutingService.cpp:83) Unregistering Handlers in Alarm Executing Mode W 14:51:06.2163 2022-04-05 21:51:06.216 [ 9] W Channel:notifyActivitiesFailed::No Associated Activities Found D 14:51:06.2164 bool AlarmExecutingService::shutdownGraphicsInternal() (/home/lynnes/workspace/doppler/src/AlarmExecutingService.cpp:95) Shutting Down Graphics in Alarm Executing Mode W 14:51:06.2164 Calling stop animation on [blinkCycle|min 0|max 1|500000000] D 14:51:06.2167 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:271) Stopping the service thread I 14:51:06.2168 DopplerIOService waiting on CV before stopwork. I 14:51:06.2168 DopplerIOService after cv wait calling stopWork. D 14:51:06.2168 void DopplerIOService::stopWork() (/home/lynnes/workspace/libpai/DopplerIOService.cpp:99) Stopping DopplerIOService D 14:51:06.2169 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:275) Shared ptr use count is 1 I 14:51:06.2169 Destroying Display Permission Factory alarmingBlank D 14:51:06.2170 void DopplerIOService::stopWork() (/home/lynnes/workspace/libpai/DopplerIOService.cpp:99) Stopping DopplerIOService I 14:51:06.2171 State retrieved successfully D 14:51:06.2171 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:280) Spinning up mode SNOOZING I 14:51:06.2173 s.getLowBrightness() = 20 D 14:51:06.2173 void DopplerIOService::start() (/home/lynnes/workspace/libpai/DopplerIOService.cpp:82) Started Thread SnoozeSrvc D 14:51:06.2174 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:282) Registering Handlers I 14:51:06.2174 Calling Snooze service registerHandlers in snooze mode D 14:51:06.2174 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:284) Setting up Graphics I 14:51:06.2174 Calling Snooze service setupGraphics in snooze mode I 14:51:06.2175 newMode is SNOOZING I 14:51:06.2175 Registering handlers in snooze mode D 14:51:06.2176 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:991) Searching observerlist in internaldataparser D 14:51:06.2176 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:996) Added Button observer in internaldataparser I 14:51:06.2177 Registering SnoozeService button observer in idp in snooze mode D 14:51:06.2177 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:991) Searching observerlist in internaldataparser D 14:51:06.2177 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:996) Added Button observer in internaldataparser I 14:51:06.2178 Registering VolumeService button observer in idp in snooze mode I 14:51:06.2178 Calling Snooze service setupGraphicsInternal in snooze mode W 14:51:06.2180 RSBS createAnimation: [colorTransition|min 0|max 12|104166666] W 14:51:06.2181 RSBS createAnimation: [colorTransition|min 13|max 25|104166666] I 14:51:06.4308 2022-04-05 21:51:06.430 [ 13] I DirectiveSequencer:onDirective:directive=namespace\:InteractionModel\,name\:RequestProcessingCompleted\,messageId\:278a4d9b-70a1-41b4-b114-bbd22f407b18\,dialogRequestId\:1b237734-a390-48c8-9781-04f9622e9565\,correlationToken\:\,eventCorrelationToken\:\,payloadVersion\:\,instance\: I 14:51:06.4309 2022-04-05 21:51:06.430 [ 1d] I DirectiveRouter:preHandleDirective:messageId=278a4d9b-70a1-41b4-b114-bbd22f407b18,action=calling I 14:51:06.4312 2022-04-05 21:51:06.431 [ 1e] I DirectiveRouter:handleDirective:messageId=278a4d9b-70a1-41b4-b114-bbd22f407b18,action=calling I 14:51:06.9596 2022-04-05 21:51:06.959 [ 1a] I ContextManager:updateCapabilityState W 14:51:07.1598 Calling stop animation on [pri_alexa_speaking_animation|min 0|max 77|40000000] W 14:51:07.1600 2022-04-05 21:51:07.159 [ 9] W Channel:notifyActivitiesFailed::No Associated Activities Found W 14:51:07.1703 RSBS createAnimation: [pri_alexa_ending_animation|min 0|max 42|40000000] T 14:51:07.1704 ########################################

Alexa is currently idle!

########################################

W 14:51:08.9270 RSBS createAnimation: [colorTransition|min 0|max 12|104166666] W 14:51:08.9271 RSBS createAnimation: [colorTransition|min 13|max 25|104166666] I 14:51:09.3918 State retrieved successfully D 14:51:09.3919 void InternalDataParser::cancelPreviousSet(std::set) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:887) Cancelling the empty set D 14:51:09.3920 void InternalDataParser::preparseButtons(int, int) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:404) count of buttons_now_down 1 D 14:51:09.3920 void InternalDataParser::preparseButtons(int, int) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:409) buttons depressed (is/are) 11,DOPPLER_BUTTON_ALARMBTN I 14:51:09.3922 State retrieved successfully I 14:51:09.3923 onAlarmButton Press in snooze mode D 14:51:09.3924 void alexaClientSDK::dopplerAlerts::DopplerAlertScheduler::doAlarmButtonPress() (/home/lynnes/workspace/doppler/src/AVS/Alerts/DopplerAlertScheduler.cpp:419) Calling doAlarmButtonPress in DopplerAlert.cpp D 14:51:09.3924 bool alexaClientSDK::dopplerAlerts::DopplerAlertScheduler::deactivateActiveAlertHelperLocked(alexaClientSDK::dopplerAlerts::DopplerAlert::StopReason) (/home/lynnes/workspace/doppler/src/AVS/Alerts/DopplerAlertScheduler.cpp:1312) call deactivateActiveAlertHelperLocked W 14:51:09.6119 DEBUG: sendEvent AlertStopped with token amzn1.as-ct.v1.Domain:Application:Alarms#DNID#d71ce0f3-49d7-3bef-ad6c-98bb199bdf61 I 14:51:09.6120 {"alarms":[{"color":{"blue":0,"green":0,"red":255},"id":0,"name":"Doppler System Alarm","repeat":"0","sound":"Harp.mp3","src":0,"status":10,"time_hr":17,"time_min":32,"volume":100}]} W 14:51:09.6121 DEBUG: send using certified: {"event":{"header":{"namespace":"Alerts","name":"AlertStopped","messageId":"250dc3bf-6f9f-4e05-92b2-5dc613c309d4"},"payload":{"token":"amzn1.as-ct.v1.Domain:Application:Alarms#DNID#d71ce0f3-49d7-3bef-ad6c-98bb199bdf61","scheduledTime":"LOCAL_STOP","eventTime":"2022-04-05T21:51:09Z"}}} 14:51:09.612 SNOOZE_CANCEL: D 14:51:09.6123 virtual void ModeService::onAlertStateChange(const alexaClientSDK::acsdkAlertsInterfaces::AlertObserverInterface::AlertInfo&) (/home/lynnes/workspace/doppler/src/ModeService.cpp:97) Executing ModeService::onAlertStateChange W 14:51:09.6123 ALERT amzn1.as-ct.v1.Domain:Application:Alarms#DNID#d71ce0f3-49d7-3bef-ad6c-98bb199bdf61 STATE CHANGED TO SOMETHING WE DONT CARE ABOUT: DELETED D 14:51:09.6124 void InternalDataParser::preparseButtons(int, int) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:404) count of buttons_now_down 0 D 14:51:09.6125 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:267) Deregistering Handlers I 14:51:09.6125 Calling Snooze service deregisterHandlers in snooze mode D 14:51:09.6125 virtual void ModeService::onAlertStateChange(const alexaClientSDK::acsdkAlertsInterfaces::AlertObserverInterface::AlertInfo&) (/home/lynnes/workspace/doppler/src/ModeService.cpp:97) Executing ModeService::onAlertStateChange W 14:51:09.6126 ALERT amzn1.as-ct.v1.Domain:Application:Alarms#DNID#d71ce0f3-49d7-3bef-ad6c-98bb199bdf61 STATE CHANGED TO SOMETHING WE DONT CARE ABOUT: COMPLETED I 14:51:09.6126 2022-04-05 21:51:09.612 [ 7] I ContextManager:updateCapabilityState D 14:51:09.6127 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:269) Shutting down Graphics I 14:51:09.6127 Calling Snooze service shutdownGraphics in snooze mode D 14:51:09.6128 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:271) Stopping the service thread I 14:51:09.6128 Calling Snooze service deregisterHandlersInternal in snooze mode D 14:51:09.6129 void InternalDataParser::preparseButtons(int, int) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:418) buttons_released 11,DOPPLER_BUTTON_ALARMBTN I 14:51:09.6130 DopplerIOService waiting on CV before stopwork. I 14:51:09.6130 Unregistering SnoozeService button observer in idp in snooze mode I 14:51:09.6130 Unregistering VolumeService button observer in idp in snooze mode I 14:51:09.6131 Calling Snooze service shutdownGraphicsInternal in snooze mode I 14:51:09.6132 DopplerIOService after cv wait calling stopWork. D 14:51:09.6132 void DopplerIOService::stopWork() (/home/lynnes/workspace/libpai/DopplerIOService.cpp:99) Stopping DopplerIOService D 14:51:09.6133 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:275) Shared ptr use count is 1 I 14:51:09.6133 Destroying Display Permission Factory snoozeDraw I 14:51:09.6134 State retrieved successfully I 14:51:09.6134 Destroying Display Permission Factory snoozeBlank D 14:51:09.6134 void DopplerIOService::stopWork() (/home/lynnes/workspace/libpai/DopplerIOService.cpp:99) Stopping DopplerIOService D 14:51:09.6135 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:280) Spinning up mode NORMAL I 14:51:09.6135 s.getLowBrightness() = 20 D 14:51:09.6136 void DopplerIOService::start() (/home/lynnes/workspace/libpai/DopplerIOService.cpp:82) Started Thread NormalMode(Srvc) D 14:51:09.6136 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:282) Registering Handlers D 14:51:09.6137 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:284) Setting up Graphics I 14:51:09.6137 newMode is NORMAL I 14:51:09.6138 registering handlers in normalmode service D 14:51:09.6138 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:991) Searching observerlist in internaldataparser D 14:51:09.6139 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:996) Added Button observer in internaldataparser I 14:51:09.6139 registering handlers idp postaddbuttonobserver normalmodeservice D 14:51:09.6139 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:991) Searching observerlist in internaldataparser D 14:51:09.6140 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:996) Added Button observer in internaldataparser I 14:51:09.6140 registering handlers idp postaddbuttonobserver timeservice D 14:51:09.6140 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:991) Searching observerlist in internaldataparser D 14:51:09.6141 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:996) Added Button observer in internaldataparser I 14:51:09.6141 registering handlers idp postaddbuttonobserver volumeservice I 14:51:09.6141 registering handlers quickbuttons D 14:51:09.6141 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:991) Searching observerlist in internaldataparser D 14:51:09.6142 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:996) Added Button observer in internaldataparser CALLING LOG ROLLING HANDLER: doppler.log Moving logfile doppler.log to old-doppler.logI 14:51:09.6211 running setup graphics in normalmodeservice W 14:51:09.6212 SETUP GRAPHICS FOR NORMAL MODE WAS BOGUS... WHAT IS BROKEN HERE NOW??? E 14:51:09.6296 do_blit SKIPPING setColor (26|3|0|snoozeDraw) E 14:51:09.6297 do_blit SKIPPING setColor (26|3|0|snoozeDraw) E 14:51:09.6298 do_blit SKIPPING setColor (26|3|0|snoozeDraw) E 14:51:09.6298 do_blit SKIPPING setColor (26|3|0|snoozeDraw) E 14:51:09.6298 do_blit SKIPPING setColor (26|3|0|snoozeDraw) E 14:51:09.6299 do_blit SKIPPING setColor (26|3|0|snoozeDraw) E 14:51:09.6299 do_blit SKIPPING setColor (26|3|0|snoozeDraw) E 14:51:09.6461 do_blit SKIPPING colorTransition (26|3|0|snoozeDraw) E 14:51:09.6462 do_blit SKIPPING colorTransition (26|3|0|snoozeDraw)

wryley-amzn commented 2 years ago

Thanks for bringing this to attention @brett-lynnes, we'll take a look into this