"TimeSwitchModule" after "BatteryStatusChanged" triggering (Script issue) #787

wvzxn · 2023-10-13T19:12:00Z

Description

Sometimes, after BatteryStatusChanged, TimeSwitchModule is also triggered (with weird params), which leads to duplication of scripts.

Automatic theme switch: disabled
Device unplugged Dark Theme switch: enabled

2023-10-13 15:38:33 | Info | ThemeManager.UpdateTheme: dark theme switch performed, source: BatteryStatusChanged

2023-10-13 15:38:36 | Info | ThemeManager.UpdateTheme: dark theme switch performed, source: TimeSwitchModule, sunset: 01/01/0001 12:00:00 am

My script detected the duplicate and returned ## MULTI ##:

2023-10-13 15:38:38 | Info | ScriptHandler.Launch: ===== scripts_loader (ANY) ====='s output: ##### MULTI #####

How often does this happen?
It seems more like random thing. Maybe about once in ten times.

Expected Behavior

No response

Log Data

2023-10-13 15:38:28 | Info | SystemEventHandler.PowerManager_BatteryStatusChanged: battery discharging, enabling dark mode 
2023-10-13 15:38:28 | Info | ComponentManager.GetComponentsToUpdate: components queued for update: [ScriptSwitch] 
2023-10-13 15:38:28 | Info | ThemeManager.UpdateTheme: dwm management: full refresh requested by user 
2023-10-13 15:38:28 | Info | ScriptHandler.Launch: running ===== scripts_loader (ANY) =====: "powershell" "-ExecutionPolicy" "Bypass" "-File" ".\#scripts_loader.ps1" "Dark" 
2023-10-13 15:38:33 | Info | Tm2Handler.SetTheme: applied theme ADMUnmanagedDark, from origin: C:\Users\wz\AppData\Local\Microsoft\Windows\Themes\dark.theme directly via IThemeManager2 
2023-10-13 15:38:33 | Info | ThemeManager.UpdateTheme: dark theme switch performed, source: BatteryStatusChanged 
2023-10-13 15:38:36 | Info | ComponentManager.GetComponentsToUpdate: components queued for update: [ScriptSwitch] 
2023-10-13 15:38:36 | Info | ThemeManager.UpdateTheme: dwm management: no refresh required 
2023-10-13 15:38:36 | Info | ScriptHandler.Launch: running ===== scripts_loader (ANY) =====: "powershell" "-ExecutionPolicy" "Bypass" "-File" ".\#scripts_loader.ps1" "Dark" 
2023-10-13 15:38:36 | Info | ThemeManager.UpdateTheme: dark theme switch performed, source: TimeSwitchModule, sunset: 01/01/0001 12:00:00 am 
2023-10-13 15:38:38 | Info | ScriptHandler.Launch: ===== scripts_loader (ANY) ====='s output: ##### MULTI ##### 
2023-10-13 15:38:38 | Info | ScriptSwitch.HandleSwitch: update info - previous: Light, now: Dark 
2023-10-13 15:38:38 | Info | ScriptHandler.Launch: ===== scripts_loader (ANY) ====='s output: SUCCESS: The process "explorer.exe" with PID 4624 has been terminated.
2023-10-13 15:38:38 | Info | ScriptSwitch.HandleSwitch: update info - previous: Light, now: Dark

Commit Hash, Version and Windows Build

Commit: cf7a0fe
Service/App: 10.4.1.1
Updater: 3.1.4
Shell: 1.3.3.0
.Net: 7.0.5
Windows: 19045.3448

Screenshots / Videos

No response

The text was updated successfully, but these errors were encountered:

Spiritreader · 2023-10-23T20:24:20Z

Hm yes, that doesn't seem right. Disabling automatic theme switch should also disable the time switch module.

You mentioned this happens randomly?
The only location where we would produce such an event is here

Windows-Auto-Night-Mode/AutoDarkModeSvc/Governors/TimeSwitchGovernor.cs

Line 67 in cf7a0fe

    
           return new(isInSwitchWindow, new(SwitchSource.TimeSwitchModule, Theme.Automatic));

Which shouldn't be active on disabled automatic switch.

Could you please upload the entire log and your config file? I need to check if the time switch governor is active.

wvzxn · 2023-10-23T22:49:27Z

You mentioned this happens randomly?

As far as I understood, this happens when the BatteryStatusChanged is triggered and the theme switches to dark.

service.log
AllowedSources: [Any] - so my script was launched from any trigger

config.yaml

AutoThemeSwitchingEnabled: true
Governor: Default
Autostart:
  Validate: false
WindowsThemeMode:
  Enabled: true
  DarkThemePath: C:\Users\wz\AppData\Local\Microsoft\Windows\Themes\dark.theme
  LightThemePath: C:\Users\wz\AppData\Local\Microsoft\Windows\Themes\light.theme
  MonitorActiveTheme: false
  ApplyFlags: []
AppsSwitch:
  Enabled: true
  Component:
    Mode: Switch
SystemSwitch:
  Enabled: true
  Component:
    Mode: Switch
    TaskbarSwitchDelay: 1200
    TaskbarColorOnAdaptive: false
    TaskbarColorWhenNonAdaptive: Light
    DWMPrevalenceSwitch: false
    DWMPrevalenceEnableTheme: Light
TouchKeyboardSwitch:
  Enabled: false
  Component: {}
ColorizationSwitch:
  Enabled: false
  Component:
    LightHex: ''
    DarkHex: ''
    LightAutoColorization: false
    DarkAutoColorization: false
ColorFilterSwitch:
  Enabled: false
  Component: {}
OfficeSwitch:
  Enabled: false
  Component:
    Mode: Switch
    LightTheme: 0
    DarkTheme: 4
CursorSwitch:
  Enabled: false
  Component:
    CursorsLight: 
    CursorsDark: 
Sunrise: 2023-10-20T08:30:00.0000000
Sunset: 2023-10-20T18:20:00.0000000
Location:
  PollingCooldownTimeSpan: 1.00:00:00
  Enabled: false
  UseGeolocatorService: true
  SunsetOffsetMin: 0
  SunriseOffsetMin: 0
  CustomLat: 0
  CustomLon: 0
Tunable:
  BatterySliderDefaultValue: 25
  DisableEnergySaverOnThemeSwitch: false
  UseLogonTask: false
  Debug: true
  Trace: false
  DebugTimerMessage: false
  ShowTrayIcon: true
  AlwaysFullDwmRefresh: true
  UICulture: en
GPUMonitoring:
  Enabled: false
  Threshold: 30
  Samples: 1
ProcessBlockList:
  ProcessNames: []
  Enabled: false
Events:
  DarkThemeOnBattery: true
  Win10AllowLockscreenSwitch: true
Notifications:
  OnAutoThemeSwitching: true
  OnSkipNextSwitch: true
AutoSwitchNotify:
  Enabled: false
  GracePeriodMinutes: 5
Hotkeys:
  Enabled: false
  ForceLight: 
  ForceDark: 
  NoForce: 
  ToggleTheme: 
  TogglePostpone: 
  ToggleAutoThemeSwitch: 
IdleChecker:
  Enabled: false
  Threshold: 5
WallpaperSwitch:
  Enabled: false
  Component:
    TypeLight: Individual
    TypeDark: Individual
    Position: Fill
    GlobalWallpaper:
      Light: 
      Dark: 
    SolidColors:
      Light: '#FFFFFF'
      Dark: '#000000'
    Monitors: []
Updater:
  AutoInstall: false
  Enabled: true
  Silent: false
  DaysBetweenUpdateCheck: 7
  CheckOnStart: false
  VersionQueryUrl: https://raw.githubusercontent.com/AutoDarkMode/AutoDarkModeVersion/master/version-beta.yaml
  DownloadBaseUrl: 
  ZipCustomUrl: 
  HashCustomUrl:

Here's a part where I tested AC plug-unplug and it worked as it should:

2023-10-22 10:34:36 | Info | SystemEventHandler.PowerManager_BatteryStatusChanged: battery discharging, enabling dark mode 
2023-10-22 10:34:36 | Info | ComponentManager.GetComponentsToUpdate: components queued for update: [SystemSwitchThemeFile, ScriptSwitch] 
2023-10-22 10:34:36 | Info | SystemSwitchThemeFile.SwitchSystemTheme: update info - previous: Light/NoAccent, pending: Dark/NoAccent, mode: Switch, accent: no 
2023-10-22 10:34:36 | Info | ThemeManager.UpdateTheme: dwm management: full refresh requested by user 
2023-10-22 10:34:36 | Info | ScriptHandler.Launch: running scripts_loader: "powershell" "-ExecutionPolicy" "Bypass" "-File" ".\#scripts_loader.ps1" "Dark" 
2023-10-22 10:34:36 | Info | Tm2Handler.SetTheme: applied theme ADMUnmanagedDark, from origin: C:\Users\wz\AppData\Local\Microsoft\Windows\Themes\dark.theme directly via IThemeManager2
2023-10-22 10:34:36 | Info | ThemeManager.UpdateTheme: dark theme switch performed, source: BatteryStatusChanged
2023-10-22 10:34:39 | Info | ScriptSwitch.HandleSwitch: update info - previous: Light, now: Dark 
2023-10-22 10:38:23 | Info | ComponentManager.GetComponentsToUpdate: components queued for update: [SystemSwitchThemeFile, ScriptSwitch] 
2023-10-22 10:38:23 | Info | SystemSwitchThemeFile.SwitchSystemTheme: update info - previous: Dark/NoAccent, pending: Light/NoAccent, mode: Switch, accent: no
2023-10-22 10:38:23 | Info | ThemeManager.UpdateTheme: dwm management: full refresh requested by user 
2023-10-22 10:38:23 | Info | ScriptHandler.Launch: running scripts_loader: "powershell" "-ExecutionPolicy" "Bypass" "-File" ".\#scripts_loader.ps1" "Light" 
2023-10-22 10:38:25 | Info | Tm2Handler.SetTheme: applied theme ADMUnmanagedLight, from origin: C:\Users\wz\AppData\Local\Microsoft\Windows\Themes\light.theme directly via IThemeManager2 
2023-10-22 10:38:25 | Info | ThemeManager.UpdateTheme: light theme switch performed, source: BatteryStatusChanged 
2023-10-22 10:38:27 | Info | ScriptSwitch.HandleSwitch: update info - previous: Dark, now: Light 
2023-10-22 10:38:50 | Info | SystemEventHandler.PowerManager_BatteryStatusChanged: battery discharging, enabling dark mode 
2023-10-22 10:38:50 | Info | ComponentManager.GetComponentsToUpdate: components queued for update: [SystemSwitchThemeFile, ScriptSwitch] 
2023-10-22 10:38:50 | Info | SystemSwitchThemeFile.SwitchSystemTheme: update info - previous: Light/NoAccent, pending: Dark/NoAccent, mode: Switch, accent: no 
2023-10-22 10:38:50 | Info | ThemeManager.UpdateTheme: dwm management: full refresh requested by user 
2023-10-22 10:38:50 | Info | ScriptHandler.Launch: running scripts_loader: "powershell" "-ExecutionPolicy" "Bypass" "-File" ".\#scripts_loader.ps1" "Dark" 
2023-10-22 10:38:52 | Info | Tm2Handler.SetTheme: applied theme ADMUnmanagedDark, from origin: C:\Users\wz\AppData\Local\Microsoft\Windows\Themes\dark.theme directly via IThemeManager2 
2023-10-22 10:38:52 | Info | ThemeManager.UpdateTheme: dark theme switch performed, source: BatteryStatusChanged 
2023-10-22 10:38:54 | Info | ScriptSwitch.HandleSwitch: update info - previous: Light, now: Dark

Spiritreader · 2023-10-24T11:14:22Z

Automatic theme switch: disabled

Your config and the logs say otherwise:

AutoThemeSwitchingEnabled: true

2023-10-23 02:50:43 | Info | TimeSwitchGovernor.EnableHook: time switch governor selected

Your auto switch is enabled. Which means that the time switch module and the battery event can overlap, causing the behavior you observed.

The duplicate trigger is most likely a race condition where ADM hasn't updated the internal state yet after the battery event triggers, and the timer events fire just so.

I've introduced a guard on the battery event that should prevent the governor modules from invoking a switch when a battery trigger event happens.

wvzxn · 2023-10-25T08:21:51Z

Your auto switch is enabled

Yes, yes, it's my bad.
I forgot that I had enabled AutoThemeSwitchingEnabled, and this log was displaying information with AutoThemeSwitchingEnabled: true.

But this does not cancel the fact that the bug exists, and perhaps this will fix the situation:

The duplicate trigger is most likely a race condition where ADM hasn't updated the internal state yet after the battery event triggers, and the timer events fire just so.
I've introduced a guard on the battery event that should prevent the governor modules from invoking a switch when a battery trigger event happens.

Spiritreader · 2024-04-24T20:46:12Z

Is the guard working?

wvzxn added the needs triage label Oct 13, 2023

Spiritreader added bug Something isn't working and removed needs triage labels Oct 23, 2023

Spiritreader added a commit that referenced this issue Oct 24, 2023

introduce guard to battery event if auto theme switch is enabled (#787)

09af2b9

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

"TimeSwitchModule" after "BatteryStatusChanged" triggering (Script issue) #787

"TimeSwitchModule" after "BatteryStatusChanged" triggering (Script issue) #787

wvzxn commented Oct 13, 2023

Spiritreader commented Oct 23, 2023 •

edited

wvzxn commented Oct 23, 2023

Spiritreader commented Oct 24, 2023 •

edited

wvzxn commented Oct 25, 2023

Spiritreader commented Apr 24, 2024

"TimeSwitchModule" after "BatteryStatusChanged" triggering (Script issue) #787

"TimeSwitchModule" after "BatteryStatusChanged" triggering (Script issue) #787

Comments

wvzxn commented Oct 13, 2023

Description

Expected Behavior

Log Data

Commit Hash, Version and Windows Build

Screenshots / Videos

Spiritreader commented Oct 23, 2023 • edited

wvzxn commented Oct 23, 2023

Spiritreader commented Oct 24, 2023 • edited

wvzxn commented Oct 25, 2023

Spiritreader commented Apr 24, 2024

Spiritreader commented Oct 23, 2023 •

edited

Spiritreader commented Oct 24, 2023 •

edited