Vero 4K+ v19 - Many Problems

Help and Support
21

Not much info what happens in that 20 seconds but have you tried with the OSMC skin if you have the same delay?

2021-08-20 22:58:37.345 T:2642    DEBUG <general>: HandleKey: return (0xf00d) pressed, action is Select
2021-08-20 22:58:37.345 T:2943    DEBUG <general>: Thread Timer 3551006928 terminating
2021-08-20 22:58:37.346 T:2642    DEBUG <general>: ------ Window Deinit (DialogVideoInfo.xml) ------
2021-08-20 22:58:46.576 T:2707    DEBUG <general>: [ script.embuary.helper ] Force widgets to refresh (VideoLibrary.OnUpdate)
2021-08-20 22:58:46.577 T:2707    DEBUG <general>: [ script.embuary.helper ] Execute: AlarmClock(WidgetRefresh,SetProperty(EmbuaryWidgetUpdate,20210821025846,home),00:10,silent)
2021-08-20 22:58:56.001 T:2642    DEBUG <general>: CPlayerCoreFactory::GetPlayers(smb://192.168.1.11/Volume_1/dns345-v1-tv/Happy.Days.(1974)/Happy.Days.(1974).s03e10.A.Date.With.Fonzie.mkv)
22

I’ve been using Confluence for years with no issues until updating to v19.1 and changing paths to IP address. I tried Confluence, Embuary, and one other and the delay is identical (> 20 seconds).

I don’t know what else to do.

23

Use OSMC Skin and upload new logs to show the issue

24

Here you go… (updated log)
** LINK REMOVED **

@fzinken thanks for your help… Also can you please remove the log link url you copied on your earlier reply to me? I don’t like that personal info floating around. Thx

25

  1. It might just be a coincidence, but the log shows that connman took over 30 seconds to confirm the presence of an Internet connection. It could be a problem with the LAN, WAN or DNS, but I’d normally expect to see it taking 1 or 2 seconds:

    Aug 21 13:14:49 OSMC connmand[2358]: eth0 {add} route 82.165.8.211 gw 192.168.1.1 scope 0 <UNIVERSE>
Aug 21 13:15:21 OSMC connmand[2358]: eth0 {del} route 82.165.8.211 gw 192.168.1.1 scope 0 <UNIVERSE>

  2. It took almost 10 seconds to check for the existence of a subtitle file on the server.

    2021-08-21 13:18:46.479 T:2836    DEBUG <general>: ScanForExternalSubtitles: Searching for subtitles...
2021-08-21 13:18:46.560 T:2564    DEBUG <general>: ------ Window Init (DialogBusy.xml) ------
2021-08-21 13:18:53.832 T:2837    DEBUG <general>: Thread BackgroundLoader 3938123984 terminating
2021-08-21 13:18:56.262 T:2836     INFO <general>: ScanPathsForAssociatedItems: found associated file smb://192.168.1.11/Volume_2/dns345-v2-movies/One.For.The.Money.(2012)/One.For.The.Money.(2012).srt
2021-08-21 13:18:56.262 T:2836    DEBUG <general>: ScanForExternalSubtitles: END (total time: 9779 ms)

It could be network- or server-related or, at a stretch, a very inefficient search algorithm. Have you checked the network performance to/from the server, using iperf3?

Edit: One other thing. The log is also showing that network flow control is switched on. If true, this can potentially cause networking problems.

Aug 21 13:14:49 OSMC kernel: meson6-dwmac c9410000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx

26

I’m not familiar with iperf3. FYI, the storage are dedicated NAS units, not managed servers that support third-party applications. The Vero 4k+ is directly wired to the router. The NAS are attached to an unmanaged switch wired to the router. Again, the network configuration hasn’t changed in ~4 years. The only change is the upgrade to Kodi v19 and switching to mapped IP rather than samba.

Is this a setting in Kodi to disable?

27

Maybe something changed in the network, we suggest to check your network with iperf3. Please read this howto

28

And it still seems that there is a embuary script that causes the delay.
Maybe try to remove the script.

2021-08-21 13:18:28.683 T:2830    DEBUG <general>: DatabaseUtils::GetSortFieldList: unknown field 40
2021-08-21 13:18:28.683 T:2830    DEBUG <general>: DatabaseUtils::GetSortFieldList: unknown field 68
2021-08-21 13:18:31.894 T:2698    DEBUG <general>: [ script.embuary.helper ] Force widgets to refresh (VideoLibrary.OnScanFinished)
2021-08-21 13:18:46.406 T:2564    DEBUG <general>: CPlayerCoreFactory::GetPlayers(smb://192.168.1.11/Volume_2/dns345-v2-movies/One.For.The.Money.(2012)/One.For.The.Money.(2012).mp4)
2021-08-21 13:18:46.407 T:2564    DEBUG <general>: CPlayerSelectionRule::GetPlayers: considering rule: system rules
29

That message is from the kernel. It’s likely a setting that you need to configure on your router. Generally, it’s better to set it off.

30

I disabled the Embuary script and it looks like the library update scanning completes more quickly, but no impact to the original play-delay I originally reported.

I now understand how iperf3 works, but it can’t be installed on my NAS, which precludes the testing the instructions refer to.

There’s nothing in my router settings that would implement flow control. I iterated through every setting and there’s nothing called “flow control” nor are there any settings enabled that look related to that functionality.

31

Can you upload new logs and say which movie you started?
Wonder what now is mentioned in the 10 seconds in the log

32

New log: https://paste.osmc.tv/upebavavof

EDIT The film is “One.For.The.Money”

Please note that I started the film and realized I forgot to switch the skin to OSMC, so I changed the skin to OSMC and then restarted the film. So the last play instance will be under the OSMC skin.

Also, after reboot, the automatic library update takes a long time. I didn’t time anything, but the system hangs for what felt like minutes before starting to scan the LAN data sources for new content.

33

In my experience, flow control is usually something that is enabled or disabled on the Ethernet adapter on the device, not on the network switch.

34

The check for Internet took 2 seconds this time (good) and the check for subtitles just a few milliseconds (also good).

The library scan takes 3 mins 41 seconds, but is scanning over 5,300 files, so that doesn’t sound unreasonable.

So, AFAICT, the latest parameters I’ve listed seem to be quite healthy, Are you still reporting a problem?

35

TBH, I’m unsure what’s happening on the V4K+. I can point to logs where it’s showing as disabled after the link negotiation has occurred:

Aug 19 08:08:23 xxxxxx kernel: meson6-dwmac c9410000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off

and, as in this case, where it’s enabled. Other than running ethtool once the link has come up, I don’t know how to configure it at boot time on the V4K+.

It’s certainly an option on my managed switch and the V4K+ driver seems to support it.

36

I just ran more tests. Using a stopwatch, the time from pressing play till a film starts is ~20 to 22 seconds. For the past 3 years, the time from press-play to start ranged from instantly to ~4 seconds.

This is very disconcerting especially when trying to browse short home movie clips that are only 15 seconds long. We have to wait 20 seconds to start watching a 15-second video. Iterating through a directory of 30+ short clips is intolerably long.

I don’t think my NAS supports this and it’s not something I would feel comfortable installing (if it were possible).

37

Noted.

It’s probably just a setting somewhere. And probably also a distraction, so best ignored for now.

38

I can say with 100% certainty that this is issue is not a NAS setting. My LAN includes four 4-bay NAS, one of which is a different model from the rest. After configuring the units many ago and I haven’t touched them since. Also, one of the first things I did was spot-check videos on several of the units and the results all show the same delay, regardless of data source. The other NAS are not set for scanning on the Vero 4K+, so they won’t show on the log file.

39

Yep 20 seconds and there a strange things like an exception and a folder not found error happening in that time.

2021-08-22 12:08:18.422 T:2590    DEBUG <general>: HandleKey: return (0xf00d) pressed, action is Select
2021-08-22 12:08:18.424 T:2590    DEBUG <general>: ------ Window Deinit (DialogVideoInfo.xml) ------
2021-08-22 12:08:18.443 T:2871    DEBUG <general>: Thread BackgroundLoader 3337425104 terminating
2021-08-22 12:08:38.222 T:2590    ERROR <general>: GetDirectory - Unhandled exception
2021-08-22 12:08:38.222 T:2590    ERROR <general>: GetDirectory - Error getting /home/osmc/.kodi/temp/
2021-08-22 12:08:38.222 T:2590    ERROR <general>: GetDirectory - Error getting special://temp/
2021-08-22 12:08:38.239 T:2590    DEBUG <general>: CPlayerCoreFactory::GetPlayers(smb://192.168.1.11/Volume_2/dns345-v2-movies/One.For.The.Money.(2012)/One.For.The.Money.(2012).mp4)

At this moment I would suggest to try a clean Kodi folder with than a baseline config to try if that solves the issue. Alternative or additionally you still can check network with iperf3. Doesn’t need to be with your NAS can be e.g. between the PC and the Vero.

For a clean start (you can refer back afterwards, here are the commands.

Let’s test with Kodi default settings. Enter the following commands with an SSH connection.

systemctl stop mediacenter
mv ~/.kodi ~/kodi.bak
systemctl start mediacenter

If needed you can restore:

systemctl stop mediacenter
mv ~/.kodi ~/kodi.bk2
mv ~/kodi.bak ~/.kodi
systemctl start mediacenter

If your original setup was restored as expected and you want get rid of the unneeded clean install you can delete that with the following command.

rm -r ~/kodi.bk2

40

Thanks. It will be a few days before I can commit to the time it will take to go through this process. Thanks and I’ll circle back with results.