Kodi library window: First load after boot needs 10 seconds

Libre_Pat · March 25, 2018 at 3:34 PM

Hello,

I'm using LE 8.2.4 on a Raspberry Pi v1, with a 32GB Class10 SD-Card. Compared to a Pi v3 the system runs a little slower,

but still ok for occasionally use.

BUT:

After booting the system the first start of the (video) library is very slow. That means after pressing the menu button,

about 10 seconds nothing visibly happens, then the new window opens including all library entries.

Currently I am using Amber Skin, but the delay is identical on every other skin, even on default. The system is freshly installed,

just all unneccesary services (Updates, SAMBA, SSH, AirPlay, etc.) deactivated and the only addon, which I installed is keymap editor

and Amber skin.

After the library has beed entered the first time, on next opening there is no more uncommon delay any more - so just on first

start after booting.

I tried the same configuration on a Pi v3, due to the extended CPU power the delay on first start is just a couple of seconds,

but still a moment slower than on futher use. So maybe there could be an issue in my personal configuration...?

For better solution I activated error loging, the full file ist attached.

In my opinion the following lines should include the problem:

Code

---
09:33:40.338 T:1944936448   DEBUG: OnKey: up (0xf080) pressed, action is Up
09:33:40.491 T:1944936448   DEBUG: Keyboard: scancode: 0x67, sym: 0x0111, unicode: 0x0000, modifier: 0x0
09:33:42.921 T:1944936448   DEBUG: Keyboard: scancode: 0x1c, sym: 0x000d, unicode: 0x0000, modifier: 0x0
09:33:43.054 T:1944936448   DEBUG: OnKey: return (0xf00d) pressed, action is Select
09:33:43.063 T:1944936448   DEBUG: Activating window ID: 10025
09:33:43.063 T:1944936448   DEBUG: ------ Window Deinit (Home.xml) ------
09:33:43.315 T:1944936448   DEBUG: ------ Window Init (MyVideoNav.xml) ------
09:33:43.315 T:1944936448    INFO: Loading skin file: MyVideoNav.xml, load type: KEEP_IN_MEMORY
09:33:45.957 T:1944936448   ERROR: Misplaced [
09:33:45.957 T:1944936448   ERROR: Error parsing boolean expression [Window.IsActive(MyPVRChannels.xml) | Window.IsActive(MyPVRGuide.xml) | Window.IsActive(MyPVRRecordings.xml)] + !String.IsEmpty(ListItem.Plot) + !String.IsEqual($INFO[ListItem.EpisodeName],$INFO[ListItem.Plot])
09:33:47.497 T:1944936448   ERROR: Misplaced [
09:33:47.498 T:1944936448   ERROR: Error parsing boolean expression [Window.IsActive(MyPVRChannels.xml) | Window.IsActive(MyPVRGuide.xml) | Window.IsActive(MyPVRRecordings.xml)] + !String.IsEmpty(ListItem.Plot) + !String.IsEqual($INFO[ListItem.EpisodeName],$INFO[ListItem.Plot])
09:33:51.767 T:1944936448   DEBUG: CDirectoryProvider[]: refreshing..
09:33:51.770 T:1743377312   ERROR: GetDirectory - Error getting
09:33:51.771 T:1944936448   DEBUG: CDirectoryProvider[]: refreshing..
09:33:51.772 T:1734988704   ERROR: GetDirectory - Error getting
09:33:51.773 T:1944936448   DEBUG: CDirectoryProvider[]: refreshing..
09:33:51.773 T:1670656928   ERROR: GetDirectory - Error getting
09:33:51.774 T:1944936448   DEBUG: CDirectoryProvider[]: refreshing..
09:33:51.775 T:1857024928   ERROR: GetDirectory - Error getting
09:33:51.776 T:1944936448   DEBUG: CDirectoryProvider[]: refreshing..
09:33:51.777 T:1743377312   ERROR: GetDirectory - Error getting
09:33:51.777 T:1944936448   DEBUG: CDirectoryProvider[]: refreshing..
09:33:51.778 T:1734988704   ERROR: GetDirectory - Error getting
09:33:51.779 T:1944936448   DEBUG: CDirectoryProvider[]: refreshing..
09:33:51.780 T:1670656928   ERROR: GetDirectory - Error getting
09:33:51.781 T:1944936448   DEBUG: CDirectoryProvider[]: refreshing..
09:33:51.782 T:1857024928   ERROR: GetDirectory - Error getting
09:33:51.783 T:1944936448   DEBUG: CDirectoryProvider[]: refreshing..
09:33:51.783 T:1743377312   ERROR: GetDirectory - Error getting
09:33:51.784 T:1944936448   DEBUG: CDirectoryProvider[]: refreshing..
09:33:51.785 T:1734988704   ERROR: GetDirectory - Error getting
09:33:51.786 T:1944936448   DEBUG: CDirectoryProvider[]: refreshing..
09:33:51.787 T:1670656928   ERROR: GetDirectory - Error getting
09:33:51.787 T:1944936448   DEBUG: CDirectoryProvider[]: refreshing..
09:33:51.788 T:1857024928   ERROR: GetDirectory - Error getting
09:33:51.789 T:1944936448   DEBUG: CDirectoryProvider[]: refreshing..
09:33:51.790 T:1743377312   ERROR: GetDirectory - Error getting
09:33:51.790 T:1944936448   DEBUG: CDirectoryProvider[]: refreshing..
09:33:51.791 T:1734988704   ERROR: GetDirectory - Error getting
09:33:51.805 T:1944936448   DEBUG: CGUIMediaWindow::GetDirectory (videodb://movies/titles/)
09:33:51.805 T:1944936448   DEBUG:   ParentPath = [videodb://movies/titles/]
09:33:52.016 T:1944936448   DEBUG: RunQuery took 132 ms for 435 items query: select * from movie_view
09:33:52.751 T:1722979232   DEBUG: Thread BackgroundLoader start, auto delete: false
09:33:52.945 T:1722979232   DEBUG: Thread BackgroundLoader 1722979232 terminating
---

Display More

Sorry, I do not understand the code so far - but it seems to be a error by the PVR module...?

I do not use any PVR services on this device.

Thank you all for trying to help my issue

Best regards

Patrick

**milhouse** · March 26, 2018 at 3:40 AM

Kodi has a caching mechanism that will save slow queries to local storage for subsequent (in theory faster) re-use, which most likely explains why the initial query takes longer than subsequent queries. The cache folder is cleared when Kodi is restarted so the cache does not persist across restarts/reboots.

However there are problems with the FileItem cache - at least in latest Kodi 18, and probably 17.6 too - which may mean it doesn't quite work as intended, but this could be skin specific.

Also bear in mind that after booting the RPi1 will be busy for 1-2 minutes while it starts services in the background etc.

The PVR errors in your log ("Misplaced [") are most likely skin bugs and should be reported to the skin maintainer.

Libre_Pat · March 27, 2018 at 12:09 AM

Hello milhouse,

thank you for your reply - glad to hear that it seems to be a common behaviour on Kodi and no bad configuration on my device...

Quote from milhouse

The PVR errors in your log ("Misplaced [") are most likely skin bugs and should be reported to the skin maintainer.

When entering the video library the second time, there's no more PVR error. No chance that that skin error causes the delay?

Code

09:36:09.562 T:1944936448   DEBUG: OnKey: return (0xf00d) pressed, action is Select
09:36:09.563 T:1944936448   DEBUG: Activating window ID: 10025
09:36:09.563 T:1944936448   DEBUG: ------ Window Deinit (Home.xml) ------
09:36:09.619 T:1944936448   DEBUG: ------ Window Init (MyVideoNav.xml) ------
09:36:09.633 T:1944936448   DEBUG: CGUIMediaWindow::GetDirectory (videodb://movies/titles/)
09:36:09.634 T:1944936448   DEBUG:   ParentPath = [videodb://movies/titles/]
09:36:09.840 T:1944936448   DEBUG: RunQuery took 125 ms for 435 items query: select * from movie_view
09:36:10.566 T:1722979232   DEBUG: Thread BackgroundLoader start, auto delete: false
09:36:10.759 T:1722979232   DEBUG: Thread BackgroundLoader 1722979232 terminating

Query time is nearly the same on inital load or subsequent load:

09:33:52.016 T:1944936448 DEBUG: RunQuery took 132 ms for 435 items query: select * from movie_view

09:36:09.840 T:1944936448 DEBUG: RunQuery took 125 ms for 435 items query: select * from movie_view

So the only solution will be waiting ...

Best regards

Patrick

SkywalkerPD · April 3, 2018 at 8:30 AM

Running LibreELEC 8.2.4 on my shinny new Rpi 3B+ and I also have issues with my library. Browsing is incredibly slow. Moving back and forth through my files (local NAS storage through NFS) takes very long. This is a fresh install. My databases are on MySQL.

**Klojum** · April 3, 2018 at 9:36 AM Official Post

SkywalkerPD I'm not doubting your current slow RPi situation, but "incredibly slow" is not a bug report we can work with. Start by providing a full debug-enabled kodi.log via pastebin.com (or similar websites). Please do not paste it directly into the forum.

SkywalkerPD · April 3, 2018 at 11:39 AM

Quote from Klojum

SkywalkerPD I'm not doubting your current slow RPi situation, but "incredibly slow" is not a bug report we can work with. Start by providing a full debug-enabled kodi.log via pastebin.com (or similar websites). Please do not paste it directly into the forum.

I get your comment. Will try to post a debug log somewhere....

**Jocke.Sve** · April 4, 2018 at 12:25 PM

SkywalkerPD

Quote from Klojum

SkywalkerPDStart by providing a full debug-enabled kodi.log via pastebin.com (or similar websites). Please do not paste it directly into the forum.

That means: https://libreelec.wiki/how_to/provide_logfile?s[]=log

SkywalkerPD · April 4, 2018 at 2:31 PM

Used other alternative as Pastebin has a 512kb limit....

Paste.ee - Kodi debug log