[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
    588
    216
    Home Country
    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.
     

    mm1352000

    Development Group
  • Team MediaPortal
  • September 1, 2008
    21,577
    8,222
    Home Country
    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
    588
    216
    Home Country
    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,577
    8,222
    Home Country
    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
    588
    216
    Home Country
    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,577
    8,222
    Home Country
    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,475
    4,645
    46
    ::1
    Home Country
    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,475
    4,645
    46
    ::1
    Home Country
    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

    Similar threads

    Thanks for that but it does seem to me that Madvr is the issue here, I guess it is not as robust as the EVR or does not get shut down as elegantly, I also suspect, though I have not tried it, that the result would be the same for playback of any video, i.e. not just TV. Given that German TV is now all transmitted as full HD, the need...
    Thanks for that but it does seem to me that Madvr is the issue here, I guess it is not as robust as the EVR or does not get shut...
    When I finish watching TV I always stop the playback and exit to the home gui before putting the HTPC to sleep and have no...
    Replies
    2
    Views
    3K
    For me not ;) -- Tapatalk | WBR, ajs
    For me not ;) -- Tapatalk | WBR, ajs
    Description: After a resume from sleep the Radio Time plugin will no longer play any radio stations and gives the error shown in...
    Replies
    10
    Views
    1K
    The new 2020 AMD graphics control app. "Radeon Settings" (Driver package ver. 19.12.2 &3) fails to start after a resume from hibernation but only if MP (1.23 final) was also running when the HTPC was put in standby. Nothing happens at all if the icon on the taskbar is double clicked and when I attempt to run the app from win10 start...
    The new 2020 AMD graphics control app. "Radeon Settings" (Driver package ver. 19.12.2 &3) fails to start after a resume from...
    The new 2020 AMD graphics control app. "Radeon Settings" (Driver package ver. 19.12.2 &3) fails to start after a resume from...
    Replies
    0
    Views
    684
    MP1 MP2 MP2 DLNA status? DE
    What I meant is that we have a MP2 plugin called UPnP Render that can play media from DLNA servers if I remember correctly. I don't know the current state of the plugin though. That's why MP2 probably never will be certified. ;) Yes, that was also the idea, but it is a big job as all TV's, software etc. seems to not do everything...
    What I meant is that we have a MP2 plugin called UPnP Render that can play media from DLNA servers if I remember correctly. I don't...
    So I'm wondering what the state of play is with MP2 and DLNA functionality? When I started this post, I did see some posts...
    Replies
    10
    Views
    564
    Ok, the importer also remembers the queue of items that are still needed to be processed in settings file. If there is something stuck, it will try again on next server start and probably stuck again. But removing the media source also removes the associated queue. The server's TV plugin automatically creates the media sources for...
    Ok, the importer also remembers the queue of items that are still needed to be processed in settings file. If there is something...
    Hi, I’ve been struggling with MP 2 now for several weeks. Initially all was fine. Then in the client, the listings of recorded TV...
    Replies
    8
    Views
    761
    Top Bottom