MP crashes sometimes after resume from Standby (7 Viewers)

blub

MP Donator
  • Premium Supporter
  • October 1, 2013
    223
    82
    Giessen
    Home Country
    Germany Germany
    Hi

    Regarding MySQL:
    I have deleted the file from the MySQL data dir because there were still error messages despite the check which did not report any errors.


    I just had another crash, the log is attached. However I fear there will be no new clues here.

    I still cannot be sure whether MP crashes by resuming or while going into standby.
    However I have noticed that when my HTPC is "On" and I switch on my AVR it then provokes a HDMI reset, the resolution changes from 1920x1080 to something like 1024x768 and then back to 1920x1080 after a couple of seconds. At the same time the Audio device disappears and the re-appears. Maybe this also happens when switching it off and those changes lead to a MP crash somehow.

    I have now set the MP resume delay to 17s and disabled the setting "stop playback when audio renderer changes" - let's see if that helps.
     

    blub

    MP Donator
  • Premium Supporter
  • October 1, 2013
    223
    82
    Giessen
    Home Country
    Germany Germany
    And another one. There were nor errors in windows event log anymore, system seems to be clean.

    I do not think that it is the resolution change which crashes MP for the simple reason I can reproduce this by logging in via vnc and the turning on and off my AVR all day long (done about 20 times in a row) MP keeps happily resizing without crashing.

    Now I have bumped the MP startup delay to 10s - that's my last resort. I have no other ideas, despite buying a Gefen HDMI device that tells the HTPC that all components are always "on", meaning no resizing from Windows and no re-initializing of the audio renderers.
     

    mm1352000

    Retired Team Member
  • Premium Supporter
  • September 1, 2008
    21,577
    8,224
    Home Country
    New Zealand New Zealand
    Something seems funky to me in the events that MP is receiving.

    We have the suspend here:
    [collapse][2014-03-30 08:08:58,844] [Log ] [MPMain ] [DEBUG] - Main: WM_POWERBROADCAST (PBT_APMSUSPEND)
    [2014-03-30 08:08:59,071] [Log ] [MPMain ] [INFO ] - Main: OnSuspend - Done
    [2014-03-30 08:09:01,104] [Log ] [MPMain ] [INFO ] - SQLiteClient: Closing database: movingpictures.db3
    [2014-03-30 08:09:01,206] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:09:01,207] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: Teredo Tunneling Pseudo-Interface
    [2014-03-30 08:09:01,311] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:09:01,311] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: Microsoft-ISATAP-Adapter
    [2014-03-30 08:09:01,421] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:09:01,421] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: Teredo Tunneling Pseudo-Interface
    [2014-03-30 08:09:01,530] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:09:01,530] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: Microsoft-ISATAP-Adapter
    [2014-03-30 08:09:01,639] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:09:01,639] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: Realtek PCIe GBE Family Controller
    [2014-03-30 08:09:01,749] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:09:01,749] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: Realtek PCIe GBE Family Controller
    [/collapse]

    Then we have a resume:
    [collapse]
    [2014-03-30 08:28:23,567] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:23,567] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: SAMSUNG (SAM0510 EDID Override)
    [2014-03-30 08:28:23,567] [Log ] [MPMain ] [DEBUG] - Main: WM_POWERBROADCAST (PBT_APMRESUMESUSPEND)
    [2014-03-30 08:28:23,567] [Log ] [MPMain ] [INFO ] - Main: Resuming operation after a suspend
    [2014-03-30 08:28:23,567] [Log ] [MPMain ] [INFO ] - Main: OnResumeAutomatic - waiting on resume 7 secs
    [2014-03-30 08:28:30,574] [Log ] [MPMain ] [DEBUG] - Main: OnResumeAutomatic - reopen Database
    [2014-03-30 08:28:30,574] [Log ] [MPMain ] [INFO ] - Main: VideoDatabaseV5.db3 sqllite database disk cache activated.
    [2014-03-30 08:28:30,574] [Log ] [MPMain ] [INFO ] - Main: OnResumeAutomatic - Done[/collapse]

    At that time there are some resolution changes:
    [2014-03-30 08:28:30,591] [Log ] [MPMain ] [INFO ] - Main: OnDisplayChange Bounds of display changed from 1920x1080 to 1024x768

    Then we get a second resuming message:
    [2014-03-30 08:28:33,753] [Log ] [MPMain ] [DEBUG] - Main: WM_POWERBROADCAST (PBT_APMRESUMEAUTOMATIC)

    Seems a little odd to me, but anyhow MP seems not to mind.

    Another resolution change:
    [2014-03-30 08:28:40,757] [Log ] [MPMain ] [INFO ] - Main: OnDisplayChange Bounds of display changed from 1024x768 to 1920x1080

    And eventually:
    [2014-03-30 08:28:44,217] [Log ] [MPMain ] [DEBUG] - PS: RESUMESUSPEND
    [2014-03-30 08:28:44,218] [Log ] [MPMain ] [DEBUG] - PS: System has resumed from standby due to user activity - reset time of last user activity

    So we should be successfully resumed.

    A quick note at this point: you were saying that components should be detected as always on, and maybe that is true (I'm not an HDMI expert)... but the logs still show lots of disconnect/connect cycles:
    [collapse]
    [2014-03-30 08:28:44,219] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,220] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: SAMSUNG (SAM0509 EDID Override)
    [2014-03-30 08:28:44,220] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:44,221] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: 1 - SAMSUNG (2- AMD High Definition Audio Device)
    [2014-03-30 08:28:44,221] [Log ] [MPMain ] [INFO ] - Main: Audio Renderer 1 - SAMSUNG (2- AMD High Definition Audio Device) removed
    [2014-03-30 08:28:44,222] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:44,222] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,222] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:44,223] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,223] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:44,223] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,223] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:44,224] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,224] [Log ] [MPMain ] [INFO ] - Main: Audio Renderer AMD High Definition Audio Device removed
    [2014-03-30 08:28:44,225] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:44,225] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,226] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:44,226] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,226] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,226] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,227] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,227] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,227] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,227] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,228] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,228] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,228] [Log ] [MPMain ] [INFO ] - Main: Audio Renderer AMD High Definition Audio Device connected
    [2014-03-30 08:28:44,229] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,229] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,230] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,230] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,230] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,231] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: 1 - SAMSUNG (2- AMD High Definition Audio Device)
    [2014-03-30 08:28:44,231] [Log ] [MPMain ] [INFO ] - Main: Audio Renderer 1 - SAMSUNG (2- AMD High Definition Audio Device) connected
    [2014-03-30 08:28:44,232] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,232] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: Microsoft-ISATAP-Adapter
    [2014-03-30 08:28:44,233] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,233] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: Microsoft-ISATAP-Adapter
    [2014-03-30 08:28:44,233] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:44,234] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: SAMSUNG (SAM0509 EDID Override)
    [2014-03-30 08:28:44,234] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:44,234] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: SAMSUNG (SAM0509 EDID Override)
    [2014-03-30 08:28:44,235] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:44,235] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: 1 - SAMSUNG (2- AMD High Definition Audio Device)
    [2014-03-30 08:28:44,235] [Log ] [MPMain ] [INFO ] - Main: Audio Renderer 1 - SAMSUNG (2- AMD High Definition Audio Device) removed
    [2014-03-30 08:28:44,236] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,237] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: TX-NR3010
    [2014-03-30 08:28:44,237] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,237] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: TX-NR3010
    [2014-03-30 08:28:44,238] [Log ] [MPMain ] [INFO ] - ShortCut'er - Key not mapped: Key=<Return>
    [2014-03-30 08:28:44,238] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,238] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: TX-NR3010
    [2014-03-30 08:28:44,239] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,239] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: TX-NR3010
    [2014-03-30 08:28:44,239] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,240] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: TX-NR3010
    [2014-03-30 08:28:44,240] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,240] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: TX-NR3010
    [2014-03-30 08:28:44,241] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,241] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: SAMSUNG (SAM0510 EDID Override)
    [2014-03-30 08:28:44,241] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,242] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: SAMSUNG (SAM0510 EDID Override)
    [2014-03-30 08:28:44,242] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:44,242] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,242] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:44,243] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,243] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:44,243] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,295] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:44,295] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,295] [Log ] [MPMain ] [INFO ] - Main: Audio Renderer AMD High Definition Audio Device removed
    [2014-03-30 08:28:44,296] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:44,297] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,307] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:44,307] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,310] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,311] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,314] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,314] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,318] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,318] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,327] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,331] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,331] [Log ] [MPMain ] [INFO ] - Main: Audio Renderer AMD High Definition Audio Device connected
    [2014-03-30 08:28:44,344] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,344] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,344] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,345] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:44,345] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:44,345] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: 1 - SAMSUNG (2- AMD High Definition Audio Device)
    [2014-03-30 08:28:44,345] [Log ] [MPMain ] [INFO ] - Main: Audio Renderer 1 - SAMSUNG (2- AMD High Definition Audio Device) connected
    [2014-03-30 08:28:45,220] [Log ] [TvClient-TvHome: HeartBeat transmitter thread] [INFO ] - RemoteControl - Connected
    [2014-03-30 08:28:45,242] [Log ] [44 ] [DEBUG] - PS: Inspecting WakeableWakeupPlugins:
    [2014-03-30 08:28:45,245] [Log ] [PS StandbyWakeup] [DEBUG] - PS: Signal time of last user activity (08:28:44) to the local TvServer
    [2014-03-30 08:28:45,247] [Log ] [PS StandbyWakeup] [DEBUG] - PS: LoadSettings()
    [2014-03-30 08:28:45,261] [Log ] [44 ] [DEBUG] - PS: Inspecting WakeableStandbyPlugins:
    [2014-03-30 08:28:45,261] [Log ] [44 ] [DEBUG] - PS: Check if user interface is idle
    [2014-03-30 08:28:45,261] [Log ] [44 ] [DEBUG] - PS: User interface is idle
    [2014-03-30 08:28:46,221] [Log ] [TvClient-TvHome: HeartBeat transmitter thread] [INFO ] - RemoteControl - Connected
    [2014-03-30 08:28:47,223] [Log ] [TvClient-TvHome: HeartBeat transmitter thread] [INFO ] - RemoteControl - Connected
    [2014-03-30 08:28:48,225] [Log ] [TvClient-TvHome: HeartBeat transmitter thread] [INFO ] - RemoteControl - Connected
    [2014-03-30 08:28:54,926] [Log ] [MPMain ] [DEBUG] - Main: WM_DISPLAYCHANGE
    [2014-03-30 08:28:54,927] [Log ] [MPMain ] [DEBUG] - Main: WM_DISPLAYCHANGE
    [2014-03-30 08:28:54,928] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:54,928] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: SAMSUNG (SAM0510 EDID Override)
    [2014-03-30 08:28:54,928] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:54,929] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: SAMSUNG (SAM0510 EDID Override)
    [2014-03-30 08:28:54,929] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:54,929] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: SAMSUNG (SAM0510 EDID Override)
    [2014-03-30 08:28:54,930] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVNODES_CHANGED)
    [2014-03-30 08:28:54,930] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:54,930] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: SAMSUNG (SAM0510 EDID Override)
    [2014-03-30 08:28:54,930] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:54,931] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: SAMSUNG (SAM0510 EDID Override)
    [2014-03-30 08:28:54,931] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:54,931] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: SAMSUNG (SAM0510 EDID Override)
    [2014-03-30 08:28:54,932] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:54,932] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: SAMSUNG (SAM0509 EDID Override)
    [2014-03-30 08:28:54,933] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:54,933] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: SAMSUNG (SAM0509 EDID Override)
    [2014-03-30 08:28:54,934] [Log ] [MPMain ] [DEBUG] - Main: WM_GETMINMAXINFO Start (MaxSize: 1920x1080 - MaxPostion: 0,0 - MinTrackSize: 2x2 - MaxTrackSize: 1932x1092)
    [2014-03-30 08:28:54,935] [Log ] [MPMain ] [DEBUG] - Main: WM_GETMINMAXINFO End (MaxSize: 1920x1080 - MaxPostion: 0,0 - MinTrackSize: 1920x1080 - MaxTrackSize: 1920x1080)
    [2014-03-30 08:28:54,935] [Log ] [MPMain ] [DEBUG] - Main: WM_GETMINMAXINFO Start (MaxSize: 1920x1080 - MaxPostion: 0,0 - MinTrackSize: 2x2 - MaxTrackSize: 1932x1092)
    [2014-03-30 08:28:54,936] [Log ] [MPMain ] [DEBUG] - Main: WM_GETMINMAXINFO End (MaxSize: 1920x1080 - MaxPostion: 0,0 - MinTrackSize: 1920x1080 - MaxTrackSize: 1920x1080)
    [2014-03-30 08:28:54,936] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:54,937] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:54,937] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:54,938] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:54,941] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:54,941] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:54,944] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:54,944] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:54,944] [Log ] [MPMain ] [INFO ] - Main: Audio Renderer AMD High Definition Audio Device removed
    [2014-03-30 08:28:54,952] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:54,952] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:54,955] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEREMOVECOMPLETE)
    [2014-03-30 08:28:54,956] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:54,964] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:54,964] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:54,984] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:54,984] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:54,985] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:54,985] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:54,985] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:54,986] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:54,986] [Log ] [MPMain ] [INFO ] - Main: Audio Renderer AMD High Definition Audio Device connected
    [2014-03-30 08:28:54,987] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVNODES_CHANGED)
    [2014-03-30 08:28:54,988] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:54,988] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [2014-03-30 08:28:54,989] [Log ] [MPMain ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-03-30 08:28:54,989] [Log ] [MPMain ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: AMD High Definition Audio Device
    [/collapse]

    Amongst that is your receiver, TV and audio renderer disconnect/connect cycles.
    So, I would venture to say that your HDMI detective is not preventing reinitialisation of audio renderers and other things that you think it might be.

    Moving on...
    You try to view Das Erste HD and we have some exceptions:
    [2014-03-30 08:29:41,907] [Log ] [MPMain ] [INFO ] - TVHome.ViewChannelAndCheck(): View channel=Das Erste HD
    [2014-03-30 08:29:42,397] [Log ] [MPMain ] [DEBUG] - CiMenu: PrepareCiMenu
    [2014-03-30 08:29:44,134] [Log ] [MPMain ] [INFO ] - succeeded:confused:ucceeded TvControl.VirtualCard
    [2014-03-30 08:29:44,137] [Log ] [MPMain ] [INFO ] - tvhome:startplay
    ...

    [2014-03-30 08:29:45,474] [Log ] [MPMain ] [INFO ] - TexturePacker: fontengine add texure:1969
    [2014-03-30 08:29:45,482] [Error ] [43 ] [ERROR] - LoadSkin: Running on wrong thread - StackTrace: ' bei System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
    bei System.Environment.get_StackTrace()
    bei MediaPortal.GUI.Library.GUIWindow.LoadSkin()
    bei MediaPortal.GUI.Library.GUIWindow.OnMessage(GUIMessage message)
    bei TvPlugin.TvFullScreen.OnMessage(GUIMessage message)
    bei MediaPortal.GUI.Library.GUIWindowManager.ActivateWindow(Int32 newWindowId, Boolean replaceWindow, Boolean skipHistory, String loadParameter, Boolean skipAnimation, Int32 focusControlId)
    bei MediaPortal.Player.g_Player.ShowFullScreenWindowTVDefault()
    bei MediaPortal.Player.g_Player.ShowFullScreenWindow()
    bei TvPlugin.TVHome.TvDelayThread()
    bei System.Threading.ThreadHelper.ThreadStart_Context(Object state)
    bei System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
    bei System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
    bei System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
    bei System.Threading.ThreadHelper.ThreadStart()'

    Despite the exceptions it looks like TV starts okay. After that it looks like you're playing around for some minutes - recordings and program info and so on.

    I think after that the strange things start to happen after that.
    At ~08:42 we stop seeing PS standby/wakeup thread entries in the MP logs. These should normally be shown every 15 seconds.
    On the TV Server side we see that at this time the PC is going to suspend:
    [collapse]
    [2014-03-30 08:41:40,500] [Log ] [12 ] [DEBUG] - Detecting BDA/WDM devices...
    [2014-03-30 08:41:40,500] [Log ] [12 ] [DEBUG] - Detect legacy AM filter devices
    [2014-03-30 08:41:40,511] [Log ] [12 ] [DEBUG] - Detect AM KS crossbar devices
    [2014-03-30 08:41:40,512] [Log ] [12 ] [DEBUG] - Detect AM KS TV tuner devices
    [2014-03-30 08:41:40,513] [Log ] [12 ] [DEBUG] - Detect BDA source devices
    [2014-03-30 08:41:41,087] [Log ] [PowerEventThread] [DEBUG] - TV service PowerEventThread received WM_POWERBROADCAST 4
    [2014-03-30 08:41:41,088] [Log ] [PowerEventThread] [DEBUG] - OnPowerEvent: PowerStatus: Suspend
    [2014-03-30 08:41:41,088] [Log ] [PowerEventThread] [DEBUG] - OnPowerEventHandler: PowerStatus: Suspend
    [2014-03-30 08:41:41,088] [Log ] [PowerEventThread] [INFO ] - TvController.OnSuspend()
    [2014-03-30 08:41:41,099] [Log ] [PowerEventThread] [INFO ] - Scheduler: stopped
    [2014-03-30 08:41:41,107] [Log ] [PowerEventThread] [DEBUG] - Scheduler: thread stopped.
    [2014-03-30 08:41:41,108] [Log ] [PowerEventThread] [INFO ] - Stopcard
    [2014-03-30 08:41:41,110] [Log ] [PowerEventThread] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
    [2014-03-30 08:41:41,110] [Log ] [PowerEventThread] [INFO ] - tvcard:FreeSubChannel :0 - is timeshifting (skipped)
    [2014-03-30 08:41:41,110] [Log ] [PowerEventThread] [INFO ] - dvb:confused:topGraph called
    [2014-03-30 08:41:41,111] [Log ] [PowerEventThread] [INFO ] - tvcard:FreeAllSubChannels
    [2014-03-30 08:41:41,112] [Log ] [PowerEventThread] [INFO ] - DVB subch:0 Decompose()
    [2014-03-30 08:41:41,112] [Log ] [PowerEventThread] [INFO ] - subch:0-0 tswriter StopTimeshifting...
    [2014-03-30 08:41:41,113] [Log ] [PowerEventThread] [INFO ] - FreeSubChannel CA: freeing sub channel : 0
    [2014-03-30 08:41:41,114] [Log ] [PowerEventThread] [INFO ] - dvb:confused:topGraph
    [2014-03-30 08:41:41,262] [Log ] [PowerEventThread] [INFO ] - debug: IMediaControl stopped! hr = 0x0 :)
    [2014-03-30 08:41:41,263] [Log ] [PowerEventThread] [INFO ] - Stopcard
    [2014-03-30 08:41:41,263] [Log ] [PowerEventThread] [INFO ] - dvb:confused:topGraph called
    [2014-03-30 08:41:41,263] [Log ] [PowerEventThread] [INFO ] - tvcard:FreeAllSubChannels
    [2014-03-30 08:41:41,263] [Log ] [PowerEventThread] [DEBUG] - PS: SUSPEND
    [2014-03-30 08:41:41,263] [Log ] [PowerEventThread] [DEBUG] - PS: System is going to suspend
    [2014-03-30 08:41:41,264] [Log ] [PowerEventThread] [DEBUG] - PS: Signal "Suspend" to StandbyWakeupThread
    [2014-03-30 08:41:41,264] [Log ] [PowerEventThread] [DEBUG] - PS: Stop EPG grabbing and TV controller
    [2014-03-30 08:41:41,264] [Log ] [PS StandbyWakeup] [DEBUG] - PS: StandbyWakeupThread suspended
    [2014-03-30 08:41:41,265] [Log ] [PowerEventThread] [DEBUG] - PS: Run external command
    [2014-03-30 08:41:41,265] [Log ] [PowerEventThread] [DEBUG] - PS: Send "EnteringStandby" event[/collapse]

    ...but on the MP side no indication of that. Only a resolution change:
    [2014-03-30 08:41:41,286] [Log ] [MPMain ] [INFO ] - Main: OnDisplayChange Bounds of display changed from 1920x1080 to 1024x768

    This is very strange, and I would wager that this is part of the problem.

    I note that TV hasn't been stopped before standby (BAD!) so TS reader seems to be not happy as well:
    [collapse]
    [2014-03-30 08:41:47,471] [11ab4f50] [ c30] - CTsReaderFilter::pause() - IsTimeShifting = 1 - state = 2
    [2014-03-30 08:41:47,471] [11ab4f50] [ c30] - CTsReaderFilter::pause() - END - state = 1
    [2014-03-30 08:41:47,471] [11ab4f50] [ 7b8] - CTsReaderFilter:: ForcePosnUpdate: 722.343 s
    [2014-03-30 08:41:48,118] [11ab4f50] [ 7b8] - CTsReaderFilter::Duration - correction to predicted duration: 717223.000[/collapse]

    Then you try to resume and MP is borked. To me it seems not really a big surprise given that suspend on the MP side didn't seem to happen properly.

    So rather than only thinking about the resume part, I would suggest that you need to think about the suspend part as well...
     

    blub

    MP Donator
  • Premium Supporter
  • October 1, 2013
    223
    82
    Giessen
    Home Country
    Germany Germany
    Hi


    A quick note at this point: you were saying that components should be detected as always on, and maybe that is true (I'm not an HDMI expert)... but the logs still show lots of disconnect/connect cycles

    I do not have a HDMI detective yet! - you got that wrong. I think about buying one!



    The resolution changes are easy to explain:

    Every time my AVR receiver turns off it is off before the HTPC is in standby it is just faster :) . Most of the times the HTPC resumes faster than the Receiver because my Control4 system turns the receiver on at last (cannot change that).

    Every time the HTPC is on and the AVR receiver changes its status it will lead to a HDMI disconnect/connect cycle and Windows sets the resolution to 1024x768 (known as Windows 7 half screen mode I think) for a brief moment and then back to 1920x1080 - that's the way MS wants it, so it is not per definition a HDMI bug.
    Can be overcome by a) HDMI detective b) cover PIN 19 of HDMI

    There are some scenarios where my AVR is already on before the HTPS resume i.e. when I have listened to music before.


    Regarding your observations:

    I think after that the strange things start to happen after that.
    At ~08:42 we stop seeing PS standby/wakeup thread entries in the MP logs. These should normally be shown every 15 seconds.
    On the TV Server side we see that at this time the PC is going to suspend:
    Hide Spoiler
    [2014-03-30 08:41:40,500] [Log ] [12 ] [DEBUG] - Detecting BDA/WDM devices...
    [2014-03-30 08:41:40,500] [Log ] [12 ] [DEBUG] - Detect legacy AM filter devices
    [2014-03-30 08:41:40,511] [Log ] [12 ] [DEBUG] - Detect AM KS crossbar devices
    [2014-03-30 08:41:40,512] [Log ] [12 ] [DEBUG] - Detect AM KS TV tuner devices
    [2014-03-30 08:41:40,513] [Log ] [12 ] [DEBUG] - Detect BDA source devices
    [2014-03-30 08:41:41,087] [Log ] [PowerEventThread] [DEBUG] - TV service PowerEventThread received WM_POWERBROADCAST 4
    [2014-03-30 08:41:41,088] [Log ] [PowerEventThread] [DEBUG] - OnPowerEvent: PowerStatus: Suspend
    [2014-03-30 08:41:41,088] [Log ] [PowerEventThread] [DEBUG] - OnPowerEventHandler: PowerStatus: Suspend
    [2014-03-30 08:41:41,088] [Log ] [PowerEventThread] [INFO ] - TvController.OnSuspend()
    [2014-03-30 08:41:41,099] [Log ] [PowerEventThread] [INFO ] - Scheduler: stopped
    [2014-03-30 08:41:41,107] [Log ] [PowerEventThread] [DEBUG] - Scheduler: thread stopped.
    [2014-03-30 08:41:41,108] [Log ] [PowerEventThread] [INFO ] - Stopcard
    [2014-03-30 08:41:41,110] [Log ] [PowerEventThread] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
    [2014-03-30 08:41:41,110] [Log ] [PowerEventThread] [INFO ] - tvcard:FreeSubChannel :0 - is timeshifting (skipped)
    [2014-03-30 08:41:41,110] [Log ] [PowerEventThread] [INFO ] - dvb:confused:topGraph called
    [2014-03-30 08:41:41,111] [Log ] [PowerEventThread] [INFO ] - tvcard:FreeAllSubChannels
    [2014-03-30 08:41:41,112] [Log ] [PowerEventThread] [INFO ] - DVB subch:0 Decompose()
    [2014-03-30 08:41:41,112] [Log ] [PowerEventThread] [INFO ] - subch:0-0 tswriter StopTimeshifting...
    [2014-03-30 08:41:41,113] [Log ] [PowerEventThread] [INFO ] - FreeSubChannel CA: freeing sub channel : 0
    [2014-03-30 08:41:41,114] [Log ] [PowerEventThread] [INFO ] - dvb:confused:topGraph
    [2014-03-30 08:41:41,262] [Log ] [PowerEventThread] [INFO ] - debug: IMediaControl stopped! hr = 0x0 :)
    [2014-03-30 08:41:41,263] [Log ] [PowerEventThread] [INFO ] - Stopcard
    [2014-03-30 08:41:41,263] [Log ] [PowerEventThread] [INFO ] - dvb:confused:topGraph called
    [2014-03-30 08:41:41,263] [Log ] [PowerEventThread] [INFO ] - tvcard:FreeAllSubChannels
    [2014-03-30 08:41:41,263] [Log ] [PowerEventThread] [DEBUG] - PS: SUSPEND
    [2014-03-30 08:41:41,263] [Log ] [PowerEventThread] [DEBUG] - PS: System is going to suspend
    [2014-03-30 08:41:41,264] [Log ] [PowerEventThread] [DEBUG] - PS: Signal "Suspend" to StandbyWakeupThread
    [2014-03-30 08:41:41,264] [Log ] [PowerEventThread] [DEBUG] - PS: Stop EPG grabbing and TV controller
    [2014-03-30 08:41:41,264] [Log ] [PS StandbyWakeup] [DEBUG] - PS: StandbyWakeupThread suspended
    [2014-03-30 08:41:41,265] [Log ] [PowerEventThread] [DEBUG] - PS: Run external command
    [2014-03-30 08:41:41,265] [Log ] [PowerEventThread] [DEBUG] - PS: Send "EnteringStandby" event

    ...but on the MP side no indication of that. Only a resolution change:
    [2014-03-30 08:41:41,286] [Log ] [MPMain ] [INFO ] - Main: OnDisplayChange Bounds of display changed from 1920x1080 to 1024x768
    This is very strange, and I would wager that this is part of the problem.

    This sounds logical. The resolution change comes from the above explanation of mine and is "natural Windows behaviour" - I can trigger the resolution change everytime I want by manually turning my AVR on and off - MP just doesnt mind and justs chagnes resolution without a crash.


    I cannot say why it doesn't get the "Standby message" - So if that loosk to be the problem how can I narrow it down?



    I note that TV hasn't been stopped before standby (BAD!) so TS reader seems to be not happy as well:

    Mhh. Why doesn't MP stop live TV when "power off" command is received? I would expect that from MP if it can lead to problems because I would imagine most users just click "the off button" on the remote when they are going to bed rather than exiting/stoppping TV mode prior to doing that!?
     

    mm1352000

    Retired Team Member
  • Premium Supporter
  • September 1, 2008
    21,577
    8,224
    Home Country
    New Zealand New Zealand
    I do not have a HDMI detective yet! - you got that wrong. I think about buying one!
    Ahhh, the way you said "despite" confused me. Your English is very understandable, but that is one part which is not quite right. :D

    The resolution changes are easy to explain...
    Yep, that makes much more sense now that I understand there is no HDMI detective [ye].

    This sounds logical. The resolution change comes from the above explanation of mine and is "natural Windows behaviour" - I can trigger the resolution change everytime I want by manually turning my AVR on and off - MP just doesnt mind and justs chagnes resolution without a crash.
    So to be clear: the conclusion here is that it is not the resolution change that is the problem, but rather the problem is something which is causing a failure to suspend properly.

    I cannot say why it doesn't get the "Standby message" - So if that loosk to be the problem how can I narrow it down?
    Unfortunately I have absolutely no idea. I've never used a TV, AVR or STB with HDMI so I haven't got much experience with these problems. Just making the best interpretation I can of the log files.

    I note that TV hasn't been stopped before standby (BAD!) so TS reader seems to be not happy as well:
    Mhh. Why doesn't MP stop live TV when "power off" command is received? I would expect that from MP if it can lead to problems because I would imagine most users just click "the off button" on the remote when they are going to bed rather than exiting/stoppping TV mode prior to doing that!?
    [/quote]
    Your expectation is probably fair. The integration between MP and PS in this regard is not so good. Timeshifting is stopped on the server side; it is just the client side MP TV plugin that doesn't do the right thing. This topic has come up in other threads. The workaround is to make the off button stop playback before powering off.
     

    blub

    MP Donator
  • Premium Supporter
  • October 1, 2013
    223
    82
    Giessen
    Home Country
    Germany Germany
    Zitat von blub: ↑
    This sounds logical. The resolution change comes from the above explanation of mine and is "natural Windows behaviour" - I can trigger the resolution change everytime I want by manually turning my AVR on and off - MP just doesnt mind and justs chagnes resolution without a crash.
    So to be clear: the conclusion here is that it is not the resolution change that is the problem, but rather the problem is something which is causing a failure to suspend properly.
    Zitat von blub: ↑
    I cannot say why it doesn't get the "Standby message" - So if that loosk to be the problem how can I narrow it down?
    Unfortunately I have absolutely no idea. I've never used a TV, AVR or STB with HDMI so I haven't got much experience with these problems. Just making the best interpretation I can of the log files


    Ok the let's focus on that MP doesn't go to STB properly - as that would explain why the startup delay doesn't help.
    Is it possible that the cause maybe my receiver turning off so fast that MP gets confused while the Audio device is disappearing in windows (I have disabled

    This topic has come up in other threads. The workaround is to make the off button stop playback before powering off.

    If there is a workaround could you send me link to a thread how to do it? - thx

    onboard audio, so there is no device then)?
     

    Sebastiii

    Development Group
  • Team MediaPortal
  • November 12, 2007
    16,583
    10,403
    France
    Home Country
    France France
    There is an option to stop playback on audio device removal but i think you already test that ? :)
     

    blub

    MP Donator
  • Premium Supporter
  • October 1, 2013
    223
    82
    Giessen
    Home Country
    Germany Germany
    Then we get a second resuming message:
    [2014-03-30 08:28:33,753] [Log ] [MPMain ] [DEBUG] - Main: WM_POWERBROADCAST (PBT_APMRESUMEAUTOMATIC)
    Seems a little odd to me, but anyhow MP seems not to mind.

    I have an explanation for that:

    my Control4 system connect to my AVR via IP and the AVR draws 8w power in network mode.
    So when no motion has been detected in the living room my control4 system switches off the power plug the AVR is connected to to save power.
    When motion is detected it turns it back on.
    However my lazy AVR sometimes needs 40s or more to get the LAN IP up when in STB so it finally turn on waaay to late when TV and HTPC are already bored of wating all day - in those cases there will most likely be 2 resolution changes, one triggered from the TV and one triggered by the AVR some seconds later.

    You can see this in the attached log where I replicated this scenario.



    Some thoughts:

    Maybe MP doesn't suspend properly because some event/action is going on in windows and that "confuses MP to death".
    The most possible scenario I can think of is the one I posted above:
    Audio renderer reset/change when AVR is powered off before/while MP goes to suspend - and due to the IP connection the AVR is really powering off instantly leading to Windows maybe recognizing it in the wrong moment.

    There is an option to stop playback on audio device removal but i think you already test that ?

    Yea I did test that. Sadly however I cannot remember what the outcome was because I changed so many things - :mad: - At the moment "stop playback when audio renderer changes " is "ON"

    Therefore after the next crash I will set it to "OFF" and I will not make any other changes.
     

    blub

    MP Donator
  • Premium Supporter
  • October 1, 2013
    223
    82
    Giessen
    Home Country
    Germany Germany
    Hi

    Here is the current/last log file from a crash.
    Settings:
    Delay resume 10s
    Stop Playback when audio renderer changes - YES

    I have now set "Stop Playback when audio renderer changes" to "NO"

    From my notes I am pretty sure that this will fix the issue. I am wondering how I could have missed this.

    @skorz
    What is your setting regarding this option?
     

    Users who are viewing this thread

    Top Bottom