Client taking time to statup with Failed to execute remote TV server operation (IsAnyCardRecording) (1 Viewer)

[PCSentianl]

Desktop

 

[mm1352000]

Just timed it with Stopwatch,
from clicking Icon to Main menu appearing takes 58 seconds

I'm not sure what to say because like I said, that's not what I see in the log files.

then if you launch LiveTV, it takes 51 seconds before you start to hear some choppy audio and then another 27 seconds until you see video,

From your earlier log files:

[2013-11-26 14:40:02,162] [Log ] [MPMain ] [INFO ] - TVHome.ViewChannelAndCheck(): View channel=BBC One
[2013-11-26 14:40:05,672] [Log ] [MPMain ] [INFO ] - succeededucceeded TvControl.VirtualCard
[2013-11-26 14:40:27,512] [Log ] [TvClient-TvHome: HeartBeat transmitter thread] [ERROR] - TvServer: Failed to execute remote TV server operation (IsAnyCardRecording) The operation has timed out after 3000.
[2013-11-26 14:40:27,559] [Log ] [MPMain ] [INFO ] - tvhome:startplay

So, it takes ~3 seconds for the server to tune... but 22 seconds for MP to try to start playback... during which time it is doing... very little.

Some standard questions:

1. Have you disabled IPv6 on the client network adaptor? (IPv6 enabled can cause random delays like above.)
   
2. Are any firewalls present on the client or server?
3. Are any real-time scanners (anti virus/malware/spyware) running on the client?

Also, please describe the connection between the client and server. You said it is not wireless. Is it 100M or 1G wired... powerline...?

FYI during startup approx. 50% of time is spent displaying "initialising input devices" - not sre if that helps

That is probably plugins loading. What happens if you start MP in debug mode (ie. with the watchdog/debug-tool) and use option 1)?

I also note this error at around that time:

[2013-11-26 14:15:19,331] [Log ] [MPMain ] [ERROR] - Exception: System.InvalidOperationException: Operation is not valid due to the current state of the object.
at MediaPortal.Mixer.Mixer.Open(Int32 mixerIndex, Boolean isDigital)
at MediaPortal.Player.VolumeHandler..ctor(Int32[] volumeTable)
at MediaPortal.Player.VolumeHandler.CreateInstance()
at MediaPortal.Player.VolumeHandler.get_Instance()
at MediaPortalApp.OnStartup()
at MediaPortal.D3D.OnLoad(Object sender, EventArgs e)
at System.Windows.Forms.Form.OnLoad(EventArgs e)
at System.Windows.Forms.Form.OnCreateControl()
at System.Windows.Forms.Control.CreateControl(Boolean fIgnoreVisible)
at System.Windows.Forms.Control.CreateControl()
at System.Windows.Forms.Control.WmShowWindow(Message& m)
at System.Windows.Forms.Control.WndProc(Message& m)
at System.Windows.Forms.ScrollableControl.WndProc(Message& m)
at System.Windows.Forms.ContainerControl.WndProc(Message& m)
at System.Windows.Forms.Form.WmShowWindow(Message& m)
at System.Windows.Forms.Form.WndProc(Message& m)
at MediaPortalApp.WndProc(Message& msg) Message: Operation is not valid due to the current state of the object. Site : Void Open(Int32, Boolean)

 

[PCSentianl]

I've run it in debug with the top option (not remotely), but it doesn't seen right, when the main menu comes up it does not display any graphics just text, when its run from the normal icon you don't get that issue.

 

[Holzi]

when the main menu comes up it does not display any graphics just text,

That seems to be a Titan Extended Theme issue..

 

[mm1352000]

I've run it in debug with the top option (not remotely)...

Does loading seem faster to you? It seems to be taking 20 seconds in this log file. That
I'm also curious: are you running any kind of anti-virus or anti-spyware software? Sometimes these can slow down MP if they are set to scan the MP and/or TV Server program folders.

 

[PCSentianl]

As I say the button graphic issue is only when its run in debug mode.

The loading time is still much longer than 20 seconds (from clicking icon to menu appearing on screen, didn't put a stopwatch on this time but would guess around 60 secs

 

[mm1352000]

The loading time is still much longer than 20 seconds (from clicking icon to menu appearing on screen, didn't put a stopwatch on this time but would guess around 60 secs

Again, the logs tell a different story:

[2013-11-28 07:23:41,817] [Log ] [MPMain ] [INFO ] - Using alternate configuration file: C:\Users\All\AppData\Local\Temp\MPTemp\MediaPortalTemp.xml
...
[2013-11-28 07:24:02,878] [Log ] [MPMain ] [INFO ] - D3D: Stopping splash screen thread
[2013-11-28 07:24:02,925] [Log ] [MPMain ] [DEBUG] - D3D: Cursor state balanced from -2 to -1
[2013-11-28 07:24:02,925] [Log ] [MPMain ] [DEBUG] - D3D: MouseMoveEvent()
[2013-11-28 07:24:02,972] [Log ] [MPMain ] [DEBUG] - D3D FullRender: MP focus
[2013-11-28 07:24:02,972] [Log ] [MPMain ] [DEBUG] - D3D OnIdle: MP focus done
[2013-11-28 07:24:02,972] [Log ] [MPMain ] [DEBUG] - D3D: MouseMoveEvent()
...
[2013-11-28 07:24:16,279] [Log ] [MPMain ] [INFO ] - Main: Exit requested

So just a little over 20 seconds until the splash screen goes away and we can see you're moving your mouse etc. etc.
After about 35 seconds (total since first log entry) you ask to close MP.

An Atom CPU with ION graphics is always going to be a little slow. MP works much better with higher end hardware.

No comment about the real-time scanning?

 

[PCSentianl]

All scanning is turned of, and firewall is off for all except public, I know you keep quoting the log times, but what I am talking about is the actual visual time. Do you know what the error line
Failed to execute remote TV server operation (IsAnyCardRecording)
actually refers to?

 

[mm1352000]

All scanning is turned of, and firewall is off for all except public

What exactly do you mean by "public", and have you tried disabling it completely?
Also, what about the IPv6 question?

I know you keep quoting the log times, but what I am talking about is the actual visual time.

I realise that. Obviously I can't be there to see what you're actually seeing, but just because I can't see your screen doesn't mean that the log entries aren't accurate.
From the log quote in my last post we can see the first line in the log file which should be written almost immediately after you activate the MP shortcut.
We can also see the point in time where you asked MP to close.
There is no ambiguity about either of those times.
The time difference is approximately 35 seconds. If you're saying it took 60 seconds to load MP on that occasion, not even counting the time between when MP finished loaded and when you closed it down again... something is off. Either your estimate is wildly wrong or a lot of time is spent before the first log entry is written. In the first case, you can ensure your estimate is not wrong by using a stopwatch every time; in the second case, to me that would indicate an OS/system problem.

Does that make sense?

Do you know what the error line
Failed to execute remote TV server operation (IsAnyCardRecording)
actually refers to?

Yes, it means the client tried to ask the server whether any tuners were recording, and the request failed. Failures of that kind usually happen because the connection between the client and server dropped out. Again I'd like to point out that in my opinion the log entry is not directly relevant to the delay. I'm ignoring it.

Coming back to some comments you made previously...

When it does startup then TV works fine.

then if you launch LiveTV, it takes 51 seconds before you start to hear some choppy audio and then another 27 seconds until you see video

These two statements seem to contradict eachother. Can you please elaborate?

 

[edsche]

I'm digging out these 4 years old thread, because i've had the same error. MediaPortal startup times were ok, but the first tune of a tv channel took around 1 minute. So i searched in the logs and found the same error message as PCSentianl. Also the same 20 seconds of doing nothing before the error message.

[2017-01-02 14:07:56,246] [Log ] [MPMain ] [INFO ] - succeededucceeded TvControl.VirtualCard
[2017-01-02 14:08:17,904] [Log ] [TvClient-TvHome: HeartBeat transmitter thread] [ERROR] - TvServer: Failed to execute remote TV server operation (IsAnyCardRecording) The operation has timed out after 3000.
[2017-01-02 14:08:18,919] [Log ] [TvClient-TvHome: HeartBeat transmitter thread] [DEBUG] - RemoteControl: TCP connect took : 3
[2017-01-02 14:08:18,920] [Log ] [TvClient-TvHome: HeartBeat transmitter thread] [INFO ] - RemoteControl - Connected

Looks like my windows 10 system had problems with resolving my servers pc name. I discoverd this in the TV Settings of MediaPortal. If i tested the connection it took about 30 seconds till the "Connection succeded" message came up. So i used the ip address instead of the server name. But that didn't worked. MediaPortal still uses the server name .

[2017-01-02 14:08:32,665] [Log ] [MPMain ] [DEBUG] - PlayerFactory: Successfully created player instance for file - rtsp://BRAIN:554/stream3.0

Then i added a entry to the host file.

Spoiler

# Copyright (c) 1993-2009 Microsoft Corp.
#
# This is a sample HOSTS file used by Microsoft TCP/IP for Windows.
#
# This file contains the mappings of IP addresses to host names. Each
# entry should be kept on an individual line. The IP address should
# be placed in the first column followed by the corresponding host name.
# The IP address and the host name should be separated by at least one
# space.
#
# Additionally, comments (such as these) may be inserted on individual
# lines or following the machine name denoted by a '#' symbol.
#
# For example:
#
# 102.54.94.97 rhino.acme.com # source server
# 38.25.63.10 x.acme.com # x client host

# localhost name resolution is handled within DNS itself.
# 127.0.0.1 localhost
# ::1 localhost
192.168.0.10 BRAIN

Since then the error message in the log disappeared and the first tune is as fast as the others after

Hope i could help, if someone has the same problem.