Volume remains @ muted/10% after 'Wake Up'

[Olzeke51]

Describe the bug
after the "Wake Up' command, volume is at a '1 or 10%' - can hardly hear it

Expected behavior
Volume to return to previous value.

Log files
condensed log of my testing and @gez-mycroft test per his closing of ticket #58

muted_audio_after_sleep-wakeup.log
***first 50 lines(or so) are setup/modifications of the combined log files, & a copy of @gez test
*****@gez test starts at about line 167

Environment (please complete the following information):

• Device type: [Mark II - Dev kit - on network cable
  -Ubuntu default
• Mycroft-core version: ##### not sure
• ###!!#!#!#!!#!# this is olzeke51's latest build info
  I seem to be missing some 'latest' updates to this "stable"
  MarkII_arm-rpi64_Prod_005-stable_2021-04-08.img.g
  '
  /.logs - based primarily on "two-voices logs"
  turned on the 'Stable' 04-30 02:39 UTC - fresh copy to USB-stick
  turned on "latest' at home.mycroft.ai / Device - (possibly 04-30 09:24 UTC- finished 09:27)
  another update/restart at 04-30 09:34 UTC
  logs./
  '
  these seem to be missing - [based on 04-08 stable img.gz]
  .....unless the 'latest' incorporate the previous patches???
  '
  04-10 - appears to be a BSP
  '? another something or two
  04-23 05:52:06 latest
  04-26 12:54:06 latest
  {fwi..04-28 server disk full}
  [but now back online]
  04-28 07:58:10 latest **this is on the 'Standby Face currently
  ###!!#!#!#!!#!#

Additional context **************prolly a seperate issue, but wanted to FWIW
@gez and I might have different software versions, - him being a 'dev' vs. me/'user'
{I noticed my initial weather request used mimic2 , then mimic1 -- BUT on 05-01 {with V04-28} it is all mimic2 !!!!
AND I didn't do anything}

[Olzeke51]

system updated itself to 04-28 latest @05-03 04:16 UTC [mentioned in my chat/skill this morning]
STILL have issue with muted volume
'
FWIW - only had two intermediate updates between the Prod_005[04-08] and the 04-28 'latest'
per enclosure log :: main:create_enclosure:51 | Creating Mark II Enclosure
'
enclosure log (portion) for this evening's test of "sleep/wake up" volume
2021-05-03 22:24:47.912 | INFO | 271 | mycroft.client.enclosure.mark2.interface:on_volume_get:326 | Mark2:interface.py get and emit volume 0.1
2021-05-03 22:24:47.961 | WARNING | 271 | mycroft.client.enclosure.mark2.interface:on_volume_duck:302 | Mark2 volume duck deprecated! use volume set instead.
2021-05-03 22:24:50.225 | WARNING | 271 | mycroft.client.enclosure.mark2.interface:on_volume_unduck:307 | Mark2 volume unduck deprecated! use volume set instead.
2021-05-03 22:24:50.446 | ERROR | 271 | mycroft.client.enclosure.mark2.interface:run:140 | chase thread 1
2021-05-03 22:24:50.956 | ERROR | 271 | mycroft.client.enclosure.mark2.interface:async_volume_handler:253 | ASYNC SET VOL PASSED IN 2
2021-05-03 22:24:50.957 | ERROR | 271 | mycroft.client.enclosure.mark2.interface:async_volume_handler:257 | ASYNC SET VOL TO 0.2
2021-05-03 22:24:51.245 | ERROR | 271 | mycroft.client.enclosure.mark2.interface:async_volume_handler:253 | ASYNC SET VOL PASSED IN 3
2021-05-03 22:24:51.390 | ERROR | 271 | mycroft.client.enclosure.mark2.interface:async_volume_handler:257 | ASYNC SET VOL TO 0.3
2021-05-03 22:24:51.546 | ERROR | 271 | mycroft.client.enclosure.mark2.interface:run:140 | chase thread 2
2021-05-03 22:24:51.988 | ERROR | 271 | mycroft.client.enclosure.mark2.interface:async_volume_handler:253 | ASYNC SET VOL PASSED IN 4
2021-05-03 22:24:51.989 | ERROR | 271 | mycroft.client.enclosure.mark2.interface:async_volume_handler:257 | ASYNC SET VOL TO 0.4
2021-05-03 22:24:52.168 | ERROR | 271 | mycroft.client.enclosure.mark2.interface:async_volume_handler:253 | ASYNC SET VOL PASSED IN 5
2021-05-03 22:24:52.169 | ERROR | 271 | mycroft.client.enclosure.mark2.interface:async_volume_handler:257 | ASYNC SET VOL TO 0.5

[krisgesling]

Hey I did a little testing and did replicate this however only got it to happen once, which is one of the more annoying types of bugs :(

The volume "ERROR" logs appear to be standard logging, possibly made "ERROR" just to make them easier to see during development. I've reverted those to INFO level to be less confusing.

[Olzeke51]

the last two 'latestest' updates; 05-09 & 05-11 - it is working !!!
It used to be 10% consistently - so sumptin' happened
never changed any configs manually - just whatever "latest" @ home would do ....

[krisgesling]

I think it might be still there, just very rare, so potentially there's some race condition or other interruption that only causes the bug to happen in very specific circumstances.

Glad it's working for you now though, we'll keep an eye out for it.

[Olzeke51]

it has occured again on the 18th of May : put to sleep this morning, woke it up [15:30ish]>> to a low volume
just did it again 16:30-ish and still low volume {all times are EDT / east coast US/NY time zone
mycroft_wake_up-muted-0518.tar.gz
BIG FILES