Daemon is very slow to start on Windows

[scakemyer]

I've been going over our commits multiple times, mistakenly thought it was the new translation support (my apologies @i96751414), and still can't pinpoint what caused the slow loading times. It might be from the libtorrent-go stack, but from the logs it just looks like it takes a lot of time for Kodi to even trigger starting the daemon, after which it starts in a very decent amount of time. So I suspect the issue really lies on the Python side.

[scakemyer]

So I went over commits and the whole python codebase, to finally just checking enabled Services and Program add-ons, disabling a few, notably "TvTunes" that was causing this warning while Quasar was launching:

CPythonInvoker(15): Script invoked without an addon. Adding all addon modules installed to python path as fallback. This behaviour will be removed in future version.

And what do you know, Quasar now launches in under 10 seconds consistently instead of 30-40s. When reinstalling Quasar, and Kodi isn't launching other stuff, it easily starts in under 5 seconds, and pretty much instantly on Intel CPUs.

So folks, please check your currently installed add-ons if you have this issue. Since Quasar launches as a service, the time it takes to do so can be greatly affected by other badly behaving add-ons.

[Magic815]

So I've tried to do some digging in my specific situation, but haven't been able to pinpoint badly behaving addons. I'm currently running Quasar v0.9.33 on a Windows 8.1 machine, and it takes about 50 seconds for the daemon to start.

Do you see any obvious culprits?
http://xbmclogs.com/pznyhvtsf

[ShlomiD83]

same here, 50 seconds. it used to be about 30 but after the trakt lists integration it became about 50.
even on a fresh copy of kodi. using win 7. should it be like this on windows?

http://xbmclogs.com/peepmnbog

[scakemyer]

This seems to affect Windows a lot more than other platforms, as it starts almost instantly on the few rpi3 I tried.

[ShlomiD83]

yeah, it's just windows. on my crappy galaxy s2 the daemon starts in 5 seconds.

[nix87]

For me it starts around 40-50 sec. but honestly I don't see where the problem is xDD

Quasar working damn good for me, it's my number 1 multimedia addon and I hope it will stays like that for years to come so a couple of seconds to wait for deamon to start is nothing as Quasar worth every second. The only thing I prays to finally get work is utilization of private trackers, that's all.

[m4xc4v413r4]

I don't know why but I have something telling me this might be caused by anti-virus software, but I'll try to test it when I have some time and am at home, which might not be for a couple of days since it's Easter...

If anyone want's to test it before then, it would be helpful.

I'm not just saying this out of nowhere btw. I've seen people on windows that had a ton of delay between choosing the source and actually starting the buffering that was resolved by whitelisting quasar.exe and/or kodi.exe (don't remember which one it was that worked at the time). It literally went from choosing the movie, waiting 2+ minutes (some times it was way more) and starting buffering, to choosing the movie, waiting 2 seconds and starting buffering.

At first I tested it by actually disabling the anti-virus because I saw it was using the HDD a lot which makes sense, it want's to check the file you're downloading. Disabling it fixed the problem, so I tried whitelisting and it was enough.

At the time I didn't test for startup time because I didn't know there was a problem with it. When I used the system it would already be on for a few minutes.

[scakemyer]

Last I checked in a VM there was no anti-virus software, and the daemon still took 40-50 seconds to start.

[incredulity]

Maybe quasar should throw an error other than 10061 instead indicating the daemon has not yet started. I wait for the onscreen notification that the daemon has started before clicking the quasar shortcut.

#456

[metate]

From the log it seems like one of these calls is causing the delay (in main.go):

conf := config.Reload()
ensureSingleInstance()
Migrate()

My (blind) guess would be that the http.Head call in ensureSingleInstance results in a timeout on windows (in contrast to some immediate connection refused error on unix). Adding debug prints here could help.

EDIT: using fiddler it seems like that wasn't the case and config.Reload() is causing the delay. Each call takes a second:

Line 758: 01:35:56 T:8748   DEBUG: [plugin.video.quasar] issue12: {"jsonrpc":"2.0","method":"GetSetting","params":["socks_host"],"id":0}
Line 764: 01:35:57 T:8748   DEBUG: [plugin.video.quasar] issue12: {"jsonrpc":"2.0","method":"GetSetting","params":["socks_port"],"id":0}
Line 770: 01:35:58 T:8748   DEBUG: [plugin.video.quasar] issue12: {"jsonrpc":"2.0","method":"GetSetting","params":["socks_login"],"id":0}
Line 771: 01:35:59 T:8748   DEBUG: [plugin.video.quasar] issue12: {"jsonrpc":"2.0","method":"GetSetting","params":["socks_password"],"id":0}

[scakemyer]

Thanks, that's a good start and useful debugging info. I don't have a lot of time lately so it will be while until I can look into this but this should help narrowing it down.

[tzickel]

I've found the issue. it's basically this line:
https://github.com/scakemyer/quasar/blob/master/xbmc/jsonrpc.go#L29
When it tries the IPV6 connection in windows:
https://github.com/scakemyer/quasar/blob/master/xbmc/jsonrpc.go#L20
It takes one second to fail before turning to the IPV4 option.
Thus all this code:
https://github.com/scakemyer/quasar/blob/master/config/config.go#L102
which tries to do a new JSON RPC to KODI each time, actually takes more than 1 second.....
and in total it takes quasar about a minute to go through the configuration before it can start running :(

[tzickel]

Looking into the issue more (why isn't there an ipv6 server), the bug is in the bjsonrpc package being used, it's hardcoded to use ipv4, so I assume this bug is in all OS, just that on windows, connect has a longer delay.

I guess long-term a PR should be submitted to @deavid :
https://github.com/deavid/bjsonrpc/blob/master/bjsonrpc/main.py

But if someone wants a temporary fix on the python side, here it is:
https://github.com/scakemyer/plugin.video.quasar/blob/master/resources/site-packages/bjsonrpc/main.py#L22
replacing that function with this one, seems to make everything work faster on windows:

def createserver(host="localhost", port=10123, handler_factory=bjsonrpc.handlers.NullHandler):
    for res in socket.getaddrinfo(host, port, socket.AF_UNSPEC, socket.SOCK_STREAM, 0, socket.AI_PASSIVE):
      af, socktype, proto, canonname, sa = res
      try:
        sck = socket.socket(af, socktype, proto)
      except socket.error as msg:
        sck = None
        continue
      try:
        sck.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)

        sck.bind(sa)
        sck.listen(3)
      except socket.error as msg:
        sck.close()
        sck = None
        continue
      break
    return bjsonrpc.server.Server(sck, handler_factory=handler_factory)

[ShlomiD83]

@tzickel 5-6 seconds till daemon starts, cache cleared instantly after settings changes, great work.

[tzickel]

Toda, you can still skim 2-3 more seconds (maybe, haven't checked) from startup if the go json-rpc code would re-use the same socket, instead of opening 50 sockets, to read 50 configuration items :) but maybe @scakemyer had a reason for doing it like this ?

[deavid]

@tzickel thanks for the mention. I'm glad to see you're using bjsonrpc.

First of all, feel free to submit any PR to bjsonrpc. I accept almost everything that enhances anything and doesn't have any fallback for old code.

There are things that I don't understand here. "createserver" is a helper function, and is perfect to create your own in your project fullfilling your needs. "bjsonrpc.server.Server" constructor should remain compatible.

The problem to me, appears to your client and server doesn't agree on which interface to use. And createserver doesn't have IPv4 hardcoded, it has as a default a listen address, which may fit your needs or not, but that doesn't mean the function isn't capable of IPv6, right?

Your personalization of createserver is doing a local dns resolution and is relying on what the OS says for localhost. Then you bind to the first socket available in the list. Isee this approach better than the old one in my library, but I would like to comment several things on that:

• The client tries first IPv6, then IPv4. I didn't see any DNS resolution on that code. You're relying on the OS to give first ::1, then 127.0.0.1
• If you're connecting to localhost, why bother with IPv6? If the client and server used 127.0.0.1 direclty, it would worked out of the box. Does any OS have IPv4 disabled by default or there's any plan to disable it? (Sorry, I don't see the point on using IPv6 for localhost connections)
• Your modified version of createserver eats all the errors raised. If none of the sockets are usable, you will try to create a bjsonrpc server with a "sck" which isn't defined. Maybe this is fixable, and you could create "sck = None" at first, record the last error, and raise it if sck was still none at the end.
• With your modified version you could end with unexpected results if the port is still being used on IPv6. One issue that happened at first with bjsonrpc is that after the server was closed, the port was still used. If this issue happens to you with that code, instead of failing, you would end with an IPv4 server. Maybe this is good, at least for your use case seems better an IPv4 server than none at all. For me, in a more general use case, seems unpredictable behaviour. At least an error should be printed to stderr or something to tell the user that something wrong is happening, why, and what solution is being taken.

The correct solution would be to bind on localhost on IPv4 and IPv6 at the same time. But that isn't possible in bjsonrpc as it has only a single listen socket, and a listen socket seems to be tied to IPv4 or IPV6, not both. I don't use IPv6 anywhere so this isn't useful for me, but I think we will need that sooner or later.

@tzickel notes the client is using 50 sockets (depending config) to read the configuration. Bjsonrpc was meant to use a single connection for all. Maximum say 2 or 3 for redundancy or other reasons. Each time you open a connection, you need to transmit the SYN and ACK packets, and it takes time. If TCP connections weren't expensive, probably I would ended using other of json-rpc libraries instead of doing my own. Probably on localhost doesn't add time, I never checked.

Most important on using lots of connections is to reduce parallel connections to bjsonrpc at a minimum. Close them if you're done with them. I had a serious issue because a C# application on a handheld keep reconnecting to the server and let the sockets open. When the list reaches to 1024 sockets, in Linux you hit the maximum open FD's. And then the server stops serving to new connections.

Hope this is helpful for you.

[tzickel]

Hi @deavid ,

This is the first time I've seen this project (quasar) and bjsonrpc, so I would hardly call myself a direct user of bjsonrpc. I have just seen a bad use-case of quasar on Windows which caused me annoyance and decided to look into it.

I admit that the code I've written here is just a quick patch to fix the annoyance, it is not PR quality, and this is why it's not a PR, but a quick band-aid for anybody who wants to use it. (It's also much easier to change python code, instead of recompiling go code).

While I don't agree with all your comments regarding the code, it doesn't matter, I too think that @scakemyer should just nix (or make it a fallback) the ipv6 code, as I've stated in the previous comment here.

Also, there is something called dual-stack, which mean you can auto listen with one single socket to both ipv6 and ipv4:
http://code.activestate.com/recipes/578504-server-supporting-ipv4-and-ipv6/

Reading the go code, it does seem to take care of at least closing the socket when the RPC call is finished.

[scakemyer]

@tzickel Nice work here. Keep in mind I didn't code all of this; I also think using a single socket would be much better, same for just removing the ipv6 lookups altogether. I'd be fine with patching bjsonrpc too but just removing ipv6 is probably the best solution.

Thanks for the feedback @deavid!

[leandrotsampa]

Hi @scakemyer, Instead of removing ipv6, just change places and you will have the same result.

From:
var ( XBMCJSONRPCHosts = []string{ net.JoinHostPort("::1", "9090"), net.JoinHostPort("127.0.0.1", "9090"), } XBMCExJSONRPCHosts = []string{ net.JoinHostPort("::1", "65252"), net.JoinHostPort("127.0.0.1", "65252"), } )

To:
var ( XBMCJSONRPCHosts = []string{ net.JoinHostPort("127.0.0.1", "9090"), net.JoinHostPort("::1", "9090"), } XBMCExJSONRPCHosts = []string{ net.JoinHostPort("127.0.0.1", "65252"), net.JoinHostPort("::1", "65252"), } )