Malfunction & Errors in logfile

Hello,
first of all many thanks for the great CoreELEC distribution. I have been using it for more than a year on my OdroidC4 without any (bigger) trouble. Installation and setup worked out of the box.

Nevertheless I updated to the newest CoreELEC / KODI Version a couple of days ago.
Kernel: Linux 4.9.113 #1 SMP PREEMPT Sun Oct 24 21:34:02 CEST 2021
Release: CoreELEC 19.3-Matrix

Since that I’m faced with the situation, that starting some ZDF content from MEDIATHEKVIEW plugin is not launching. There are different errors, and the team over there, expect that this is a kodi issue.
Unfortunately I’m not sure how I can localize that. At least some of them start with the ZDF Mediathek plugin.

Here’s the link to the information in MEDIATHEKVIEW Forum.
https://forum.mediathekview.de/topic/4505/zdf-fehler-beim-abspielen/1

On Top I have some failures showing up regularly in my Logs, unfortunately I can’t finally judge what is important and and what not, and how can I find the root cause:

2021-12-19 21:53:29.957 T:5693 ERROR : CUPnPDirectory::GetResource - unable to find object 2$15$1/folder.jpg → nothing found
2021-12-19 21:53:30.010 T:5692 ERROR : CUPnPDirectory::GetResource - unable to find object 3$16$0/folder.jpg → nothing found
2021-12-19 21:47:49.230 T:4897 ERROR : GetString: error reading /sys/class/amhdmitx/amhdmitx0/custom_mode → found, seems uncritical
2021-12-19 21:47:49.363 T:5550 ERROR : AddOnLog: pvr.iptvsimple: pvr.iptvsimple - LoadChannelEpgs - EPG channels not found. → nothing found
2021-12-19 21:47:49.382 T:4897 ERROR : Control 55 in window 10025 has been asked to focus, but it can’t → just found some fixing in 2018?

Any help is appreciated. I’ll try to get a Debug log, last time it seems I failed to find it :frowning:

Thanks
//hufnala

One could start here.

Thanks, exactly that I did, started from scratch to update the whole system. It is eMMC memory card, so no cf.
Logging is active, but upload takes very long and how to I get the short link from the device to the forum? Seems I need to use paper?
Is there a chance to upload logs manually there and share?

BR // hufnala

First I see you have some network issues because of this thing

2021-12-14 20:59:50.890 T:5249 ERROR <general>: CCurlFile::FillBuffer - Failed: Timeout was reached(28)
2021-12-14 20:59:50.890 T:5249 ERROR <general>: CCurlFile::Open failed with code 0 for https://rodlzdf-a.akamaihd.net/none/zdf/21/12/211210_2015_sendung_chf/5/211210_2015_sendung_chf_a1a2_3360k_p36v15.mp4:

When this post was written the link is working.

https://ix.io/3bIe < the only thing you really have to write down are the last 4 characters (3bIe). The rest of the URL is always the same: https://ix.io/

The link is case sensitive.

It’s still working…

Hi vpeter,
yes the link is strange, it is and was always working from many PCs also my Office PC (leap 15.2 / FireFox) but it is not (regularly!) from my KODI. Network is the same, but connected via copper to the WLAN router in an other room. Office is directly to the master router (GB switch in between). The problem is new, since I updated two weeks ago completely. There where no major issues before, just jumped to new major releases after one year.

I’m investigating together with somebody from the mediathekview team, there seems to be something more. If somebody is interested a logfile and description. In this case - and it seems different to the former one because there’s probably a stream still running while I switched to a new one) there seems to be some differences in the init routines. I control the KODI with YATSE, and if the back key is used (probably in this case) the remote is on top of the running stream. In the new log there’s a failing and a working attempt to the same stream at round about 21:08. & 21:09.

But what about the other issues? I deaktivated upnp yesterday as source, because the server could not be reached any more. nfs to the same share and UPNP from mobile in WLAN worked fine at the same time :-D. UPNP is a MiniDLNA on a Debian Banany-Pi installation.

Sorry I have to correct “was” not (regularly). After a couple of days when I tried again it was working out of the box.

Found one new topic on the new log: There seem to be two calls to open the download (same link) in the failing attempt.

2021-12-27 21:08:26.197 T:6052 DEBUG : CurlFile::Open(0xbccfd130)

2021-12-27 21:08:26.302 T:6052 DEBUG : CurlFile::Open(0xd0ccb730)
Didn’t check the old log by now :wink:

And what should show this 2 lines to anyone? Nothing. Because there is no context to it.

sorry, you are right, the context is in the logfile and description above, and the behavior is equal to the CURL error mentioned before - CURL Open File error (network).
So that there are 2 calls is new for me, and I’m not sure if it might be related to the issue.

I just started to check the old log to find if contains also 2 OpenCalls on the same link also.

2021-12-27 21:08:26.197 T:6052    DEBUG <general>: CurlFile::Open(0xbccfd130) .....
2021-12-27 21:08:56.337 T:6052    ERROR <general>: CCurlFile::FillBuffer - Failed: Timeout was reached(28)
2021-12-27 21:08:56.337 T:6052    ERROR <general>: CCurlFile::Open failed with code 0 for ....

indicates that there as no data received. I suspect that even TCP connection was not made because the http return code is 0.
And there are 2 simultaneous open connections and it’s not clear what belongs together.

I don’t think this services are not 100% perfect which means sometimes some streams just doesn’t work. And playing same stream again just works.

Thanks.

Yes, I always don’t understand about the 2nd open connection, it is opened roughly 100ms later, so I guess nothing I can do manually :slight_smile:
Or do we talk about 3 open connections now : one the still running stream in the background, the 1st and the 2nd open on the same link within 100ms? T: 6052 means they are from the same task/PID?

2021-12-27 21:08:26.197 T:6052    DEBUG <general>: CurlFile::Open(0xbccfd130) ...
2021-12-27 21:08:26.302 T:6052    DEBUG <general>: CurlFile::Open(0xd0ccb730) ...

BTW: The old log from 14th had no 2nd open conenction, I checked in parallel!
What means:

services are not 100% perfect

By now the “old” system turned out very stable before I updated, I have this issues now on 30-50% of the calls, and it seems with different root causes.

What about the other issues? Are they important and I need to take care about. They are still there in the new log as well.

I think you should do tests with restarting kodi between tests. Because looking 200MB kodi log is not nice. And use wireshark when testing to compare kodi log with network traffic.

OK I’ll try. By now, I have not made tests in this sense, but only check logs on Errors that occured during using it.
Is it OK to cut the logfiles > what is important then, only the last minutes or keep some init routine always?

I guess using wireshark is something for power users and debugging, but not for me at the moment :smiley:

How about the answer here?

No idea really. That’s why this tests should be done in controlled situation to exactly know what is going on.

About | FAQ | Terms of Service | Privacy Policy | Legal Notice