[Usability] Restart on resume (1 Viewer)

The_Stig

Retired Team Member
  • Premium Supporter
  • April 5, 2005
    2,176
    428
    Country flag
    As I have a blocked MP from version 1.7 on after a resume from standby unregularly, I will try to provide logs too, when I run into this problem again.

    For the last days I have changed the wait time for MP after a resume to 10 seconds and haven't seen this problem anymore for quite a few days. So maybe indeed a plugin problem?!?
     

    Requiem

    MP Donator
  • Premium Supporter
  • January 1, 2012
    586
    214
    Germany Germany
    Country flag
    @HomeY @mm1352000 These are the logs with MPSync disabled.
    MP was frozen after resume.
    Only thiing is that my 1 yeaar old daughter caught the remote control and switched on the HTPC withput switching on the TV and I got a displayport arror which I usually never get, so please ignore any errors related to that. If this makes the logs invalid I'll reproduce this with my remote in a safer place ;-)

    @The_Stig Okay, I have increased wait time after resume from 5 to 10 seconds and see what happens.
     

    The_Stig

    Retired Team Member
  • Premium Supporter
  • April 5, 2005
    2,176
    428
    Country flag
    MP was frozen after resume.
    Didn't look at your logs, but please provide us with the relevant times, when did HTPC go to standby and when was the resume? Should make things easier to spot.
     

    mm1352000

    Development Group
  • Team MediaPortal
  • September 1, 2008
    21,571
    8,218
    New Zealand New Zealand
    Country flag
    Could you get much more complicated?!? :)
    HDMI + AudioSwitcher + multi-seat + auto-start TV + IFC + refresh rate changing... very complex.
    Nothing stands out immediately, except this:
    [2014-06-11 10:58:09,421] [Log ] [MPMain ] [INFO ] - CycleRefreshRate: unable to change refresh rate 50Hz for monitor 0
    ...and I'm not sure that could cause a freeze. There is so much room for things to go wrong. My suggestion would be to simplify to basics. Assuming HDMI + no AudioSwitcher + no auto-start + IFC disabled + refresh rate changing disabled works, you could enable them one by one to find the problem. If even the basic configuration causes problems then at least we will have simpler logs to work with.

    [edit: Spoke too soon. There are a bunch of playback issues in the TsReader log...]
     

    Requiem

    MP Donator
  • Premium Supporter
  • January 1, 2012
    586
    214
    Germany Germany
    Country flag
    MP was frozen after resume.
    Didn't look at your logs, but please provide us with the relevant times, when did HTPC go to standby and when was the resume? Should make things easier to spot.
    Standby was at 22:07 yesterday evening, resume on 10:57 today.

    Could you get much more complicated?!? :)
    HDMI + AudioSwitcher + multi-seat + auto-start TV + IFC + refresh rate changing... very complex.
    Yes, indeed, but everything is needed :-P Sure there are simpler setups than mine.
    Maybe this makes clear why I favor to have a restart oin resume ;-)


    Nothing stands out immediately, except this:
    [2014-06-11 10:58:09,421] [Log ] [MPMain ] [INFO ] - CycleRefreshRate: unable to change refresh rate 50Hz for monitor 0
    Might be due the TV being switched off,a s I said, my daughter switched it on. I am gathering new logs with MPSync enabled at the moment.

    As for error hunt, yes, I can disable options and switch them on again one by one.
    I am seeing issues after resume in tsreader.log, yesterday evening everything seemed to be fine.
    Maybe reinitialisation of the server really takes longer than 5 seconds to come available, so if this was the case, the startup delay increase should show an effect.
     

    mm1352000

    Development Group
  • Team MediaPortal
  • September 1, 2008
    21,571
    8,218
    New Zealand New Zealand
    Country flag
    Yes, indeed, but everything is needed :-P
    Sure, fine - I'm not saying you can't use them... but for now disabling them will make debugging a lot easier.

    Maybe reinitialisation of the server really takes longer than 5 seconds to come available, so if this was the case, the startup delay increase should show an effect.
    Without the server logs its impossible to be sure ;) ... but at least it looked like timeshifting started successfully.
     

    Requiem

    MP Donator
  • Premium Supporter
  • January 1, 2012
    586
    214
    Germany Germany
    Country flag
    Yes, indeed, but everything is needed :-P
    Sure, fine - I'm not saying you can't use them... but for now disabling them will make debugging a lot easier.
    Oh, I didnt mean to say that I am not willing to disable everything to track down issues. I just meant that in the end, I'd be glad if everything worked with everything enabled. And I am really thankful for your time and effort in helping me.

    Okay, new logs. What has changed?
    1. Resume delay upo to 10 from 5 seconds
    2. MPSync reenabled
    3. this time, everýthing switched on properly andf not by my daughter ;)

    Behaviour: Went to standby when running live TV. On resume, took notably longer to come back, than it came back with audio only live TV running and a black screen. Was able to exit with ALt+F4. Logs attached.
    I have deleted my old (lenghty) server logs and will attach server logs in future posts.

    I will now run a third watchdog round and disable all plugins/options mentioned by you,

    edit: i cannot switch off HDMI, this is my only connection from HTPC to audio and TV output.
    So I disabled: FritzBox plugin, MPsync, Dynamic Refrash Rate and IFC and switched the audio device from WASAPI to BASS player (this is what you meant by audio changer?)
     
    Last edited:

    mm1352000

    Development Group
  • Team MediaPortal
  • September 1, 2008
    21,571
    8,218
    New Zealand New Zealand
    Country flag
    Hmmmm, in both of these sets of logs I've seen something odd in the TsReader log. It is like PMT is received and streaming should start... but then the RTSP session is torn down... but it looks like streaming carries on anyway. I'm not so experienced with multi-seat setups so I'm not sure whether it is normal, but it doesn't look normal to me.

    Just out of interest, have you ever tried UNC paths instead of RTSP (and if so what was the result)?
     

    HomeY

    Test Group
  • Team MediaPortal
  • February 23, 2008
    6,466
    4,634
    45
    ::1
    Netherlands Netherlands
    Country flag
    @Requiem Just to be clear: Does the freeze happen directly after you resume from S3?

    I've looked @ the first logset. It seems the system was suspended last night @ 22:07
    Code:
    [2014-06-10 22:07:42,188] [Log    ] [MPMain   ] [INFO ] - Main: OnSuspend - Done
    And resumed this morning @ 10:57
    Code:
    [2014-06-11 10:57:06,482] [Log    ] [MPMain   ] [DEBUG] - Main: WM_DEVICECHANGE (Event: DBT_DEVICEARRIVAL)
    [2014-06-11 10:57:06,496] [Log    ] [MPMain   ] [DEBUG] - Main: Device type is DBT_DEVTYP_DEVICEINTERFACE - Name: Realtek PCIe GBE Family Controller
    Which was finished about 30 seconds later:
    Code:
    [2014-06-11 10:57:37,915] [Log    ] [MPMain   ] [INFO ] - Main: OnResumeAutomatic - Done
    I see a 20 seconds delay at this point:
    Code:
    [2014-06-11 10:57:10,477] [Log    ] [MPMain   ] [DEBUG] - Window: TvPlugin.TvFullScreen init
    [2014-06-11 10:57:10,487] [Log    ] [MPMain   ] [DEBUG] - TvFullScreen:init->OSD:Off
    [2014-06-11 10:57:31,507] [Log    ] [MPMain   ] [DEBUG] - TvFullScreen: init, playing False, player.CurrentFile , TVHome.Card.TimeShiftFileName .tsbuffer
    So when examining the logs after the 'OnResumeAutomatic - Done' part, the Fritz!BoxManager plugin gets started, and then this weird timestamp shows up:
    Code:
    [2014-06-11 10:57:54,141] [Log    ] [8        ] [DEBUG] - FRITZ!Box Manager: BackGroundWorker: Running refresh view task
    [2014-06-11 10:57:37,944] [Log    ] [MPMain   ] [DEBUG] - Main: WM_POWERBROADCAST (PBT_APMRESUMESUSPEND)
    [2014-06-11 10:58:00,221] [Log    ] [MPMain   ] [INFO ] - Main: OnResume - Switch to basic home screen
    I've seen a 30 seconds delay in the reconnection:
    Code:
    [2014-06-11 10:58:22,140] [Log    ] [43       ] [INFO ] - FRITZ!Box Manager: FritzBox: Waiting 30 seconds before reconnecting
    [2014-06-11 10:58:52,151] [Log    ] [43       ] [INFO ] - FRITZ!Box Manager: FritzBox: Connecting
    And if this is a treading issue, that could explain the freeze. So besides the issues that mm spotted, i would suggest to disable the Fritz!Box Manager plugin first, and test again.
     

    HomeY

    Test Group
  • Team MediaPortal
  • February 23, 2008
    6,466
    4,634
    45
    ::1
    Netherlands Netherlands
    Country flag
    Now the 2nd logs (MediaPortalLogs_11_06_14__12_29). The MediaPortal-Error.log already gives some hints on potential causes, which are the MPSync plugin:
    Code:
    [2014-06-11 11:16:15,292] [Error  ] [5        ] [ERROR] - MPSync: [Createtable] CREATE TABLE Image (Id TEXT PRIMARY KEY, Category TEXT, Provider TEXT, Key1 TEXT, Key2 TEXT, FullPath TEXT, SourcePath TEXT, AvailableRandom TEXT, Enabled TEXT, DummyItem TEXT, Time_Stamp TEXT) error with exception: database disk image is malformed
    database disk image is malformed
    [2014-06-11 11:16:15,354] [Error  ] [5        ] [ERROR] - MPSync: [Createtable] CREATE TABLE Version (Id INTEGER PRIMARY KEY, Version TEXT, Time_Stamp TEXT) error with exception: database disk image is malformed
    database disk image is malformed
    [2014-06-11 11:16:15,401] [Error  ] [5        ] [ERROR] - MPSync: [Createtable] CREATE TABLE mpsync_trigger (id INTEGER PRIMARY KEY AUTOINCREMENT, tablename TEXT, lastupdated TEXT) error with exception: database disk image is malformed
    database disk image is malformed
    And the Fritz!Box Manager:
    Code:
    [2014-06-11 11:16:28,739] [Error  ] [10       ] [ERROR] - FRITZ!Box Manager: FritzBox: Receiving callback failed: Object Disposed Exeption
    [2014-06-11 12:17:55,489] [Error  ] [16       ] [ERROR] - FRITZ!Box Manager: FritzBox: Connecting failed: FRITZ!Box DNS name could not be resolved
    [2014-06-11 12:27:52,025] [Error  ] [54       ] [ERROR] - FRITZ!Box Manager: FritzBox: Connecting failed: FRITZ!Box DNS name could not be resolved
    In general, suspended @ 12:17:
    Code:
    [2014-06-11 12:17:31,695] [Log    ] [MPMain   ] [INFO ] - Main: OnSuspend - Done
    and resumed about 10 minutes later @ 12:27:
    Code:
    [2014-06-11 12:27:47,514] [Log    ] [54       ] [INFO ] - FRITZ!Box Manager: FritzBox: Connecting
    And done resuming @ 12:28:
    Code:
    [2014-06-11 12:28:20,024] [Log    ] [MPMain   ] [INFO ] - Main: OnResumeAutomatic - Done
    Now let's look @ the delays that are there.
    Code:
    [2014-06-11 12:27:52,025] [Error  ] [54       ] [ERROR] - FRITZ!Box Manager: FritzBox: Connecting failed: FRITZ!Box DNS name could not be resolved
    [2014-06-11 12:27:52,033] [Log    ] [52       ] [INFO ] - FRITZ!Box Manager: FritzBox: Waiting 29 seconds before reconnecting
    [2014-06-11 12:28:10,003] [Log    ] [MPMain   ] [DEBUG] - Main: WM_POWERBROADCAST (PBT_APMRESUMEAUTOMATIC)
    So again the Fritz!Box Manager failed to connect and waits 30 seconds. If you can confirm that the system was completely unresponsive during this time, this also points towards a threading issue with the plugin.
    Off course the 10 seconds wait time (which you set) is in there:
    Code:
    [2014-06-11 12:28:10,011] [Log    ] [MPMain   ] [INFO ] - Main: OnResumeAutomatic - waiting on resume 10 secs
    [2014-06-11 12:28:20,014] [Log    ] [MPMain   ] [DEBUG] - Main: OnResumeAutomatic - reopen Database
    And about 18 seconds later the TV Stream is started:
    Code:
    [2014-06-11 12:28:38,231] [Log    ] [MPMain   ] [INFO ] - g_Player.OnStarted() rtsp://SERVER:554/stream3.0 media:TV
    Overall this doesn't look that bad. From the first log entry after resume @ 12:27:52, till the TV stream was started @ 12:28:38 there are about 48 seconds. 10 seconds are defined wait time, so means it takes 38 seconds from the time you resume the system, till the TV stream isn't started.

    Now i'm very curious about the test results from the WatchDog option #1. You don't need to manually disable the plugin, just start the WatchDog, select option 1 and put the system into standby as you always do.

    Are you putting the system into standby with the remote button? And do you do so while LiveTV is still running?
     

    Users Who Are Viewing This Thread (Users: 0, Guests: 1)

    OP Similar threads Forum Replies Date
    Dark Eyes TVService locks up or fails to restart on resuming from sleep, and crashes when grabbing EPG Installation, configuration support 7
    horned_reaper [solved] 5012: Restart current music track General Support 13
    RoChess Random GPU crash leads to MePo restart, but works fine afterwards MediaPortal 1 14
    HTPCSourcer [Finished] [MP2-793] 'Restart MP2' as additional option in shutdown menu Archive 6
    N [will not fix] Changed settings do not take effect until MP2-Client is stopped and restarted. Submit: Bug Reports 4
    R Mp restarts when scrolling down list of films Moving Pictures 8
    B [further infos missing] Install failed Exit code: 0xfff7, restarting: No 2.2 Archive 1
    D Windows tasks to restart TV Server General 2
    S MP restarts after 10-30 sec - how to read error logs General Support 1
    K MP2 - V2.1 [MP2-763] Interface configuration for RTSP streaming server lost on every restart Older releases 6
    S Resume Playback Annoyance Newcomers Forum 4
    joecrow MP 1 Hangs on resume fro sleep (TV) Watch / Listen Media 2
    joecrow 1.25.0 Radio Time plugin fails after Resume from Sleep with MP 1.25 Bugreports 4
    F After resume, TV Server connection screen is shown General Support 4
    P MP2 Client Screen Flickering on Resume General 2
    HTPCSourcer [fixed] [MP2-815] User not logged in when resuming from standby MediaPortal 2 17
    J Resume from Standby Last Module TV Showing TV Server Settings Television (MyTV frontend and TV-Server) 2
    R Media portal resumes with wrong screen resolution General Support 3
    B resume from within a folder Watch / Listen Media 0
    joecrow No Audio after MP Start/Resume from Sleep General Support 0
    R Weird sleep/resume loop General Support 4
    joecrow Further problem on resume from sleep (MP Crash) 1.21 5
    joecrow Loss of Navigation Sounds on Resume from Sleep Mp 1.21 General Support 10
    D [further infos missing] Problems switching to live tv channel after resume 2.2 Archive 1
    stirlinghart [duplicate] Mp not focused on after resuming from sleep 2.2 Archive 7
    Similar threads

























    Top Bottom