search

wackerl91 / luna

Moonlight Launcher for Kodi
GNU General Public License v3.0
100 stars 22 forks source link

Crash even before it loads anything #133

Closed Kiina closed 7 years ago

Kiina commented 7 years ago

So first I don't use OSMC but ubuntu. But when I try to start luna it crashes before loading anything. The logs show the following:

19:07:59 T:547834380064  NOTICE: [script.luna.kernel]: Bootstrapping DI ...
19:07:59 T:547834380064  NOTICE: [script.luna.kernel]: Bootstrapping Router ...
19:08:00 T:547834380064  NOTICE: [script.luna.router]: Registering route for class: HostController
19:08:00 T:547834380064  NOTICE: [script.luna.router]: Registering route for class: GameListController
19:08:00 T:547834380064  NOTICE: [script.luna.router]: Registering route for class: MainController
19:08:00 T:547834380064  NOTICE: [script.luna.router]: Registering route for class: GameContextMenuController
19:08:00 T:547834380064  NOTICE: [script.luna.router]: Registering route for class: ControllerConfigurationController
19:08:00 T:547834380064  NOTICE: [script.luna.router]: Registering route for class: AudioController
19:08:00 T:547834380064  NOTICE: [script.luna.router]: Registering route for class: GameInfoController
19:08:00 T:547834380064  NOTICE: [script.luna.router]: Registering route for class: SettingsController
19:08:00 T:547834380064  NOTICE: [script.luna.router]: Registering route for class: CacheController
19:08:07 T:547834380064  NOTICE: [script.luna.core]: Loaded storage "host" from disk
19:08:07 T:547834380064  NOTICE: [script.luna.core]: Loaded storage "game_storage" from disk
19:08:08 T:547834380064   ERROR: [script.luna.kernel]: Failed to start Luna: 'NoneType' object has no attribute 'replace'
19:08:09 T:547834380064   ERROR: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<--
                                             - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS!
                                            Error Type: <type 'exceptions.AttributeError'>
                                            Error Contents: 'NoneType' object has no attribute 'replace'
                                            Traceback (most recent call last):
                                              File "/home/kodi/.kodi/addons/script.luna/addon.py", line 24, in <module>
                                                XBMCApplicationKernel().bootstrap(callback)
                                              File "/home/kodi/.kodi/addons/script.luna/resources/lib/kernel/xbmcapplicationkernel.py", line 24, in bootstrap
                                                sys.excepthook(exc_type, exc_value, exc_tb)
                                              File "/home/kodi/.kodi/addons/script.luna/resources/lib/kernel/__init__.py", line 7, in log_exception
                                                eos_helper = RequiredFeature('eos-helper').request()
                                              File "/home/kodi/.kodi/addons/script.luna/resources/lib/di/requiredfeature.py", line 76, in request
                                                instance = class_(**arguments)
                                              File "/home/kodi/.kodi/addons/script.luna/resources/lib/eos/eoshelper.py", line 39, in __init__
                                                self._load_or_get_uid()
                                              File "/home/kodi/.kodi/addons/script.luna/resources/lib/eos/eoshelper.py", line 156, in _load_or_get_uid
                                                self.uid = uid.replace('"', '')
                                            AttributeError: 'NoneType' object has no attribute 'replace'
                                            -->End of Python script error report<--
wackerl91 commented 7 years ago

Seems there is an issue with getting a UID ... which is either Eos not returning one or the UID file already exists, but is empty.

Can you check if you can find a .eos_uid in Luna's .storage dir? (Yes, both of them are hidden ... you can use ls -a to list all files and folders, just in case you're not too familiar with *nix) The storage dir should be at /home/kodi/.kodi/userdata/addon_data/script.luna/.storage ... If you do have this file, please check if it's empty - if it is then just delete it, it will be auto-generated once Eos has returned a new ID.

If the file doesn't even exist I need to think of something, as that part should always work ...

Kiina commented 7 years ago

The .storage directory is empty

wackerl91 commented 7 years ago

That's really hard to believe, given that a) I had no issues generating a UID using an arbitrary HWID from my phone just now, so new UIDs can be requested and are properly generated b) there's not much that happens at this stage: either the ID file exists or it doesn't. If not, a HW ID String is generated and used to get a UID from Eos. If Eos isn't reachable (I.e. the request timed out, as the app goes to sleep after some time), the request is re-tried. If it still times out then None is returned and the timeout is logged (which it isn't, at least not in the log you posted -plus the timestamps don't really speak for two subsequent timeouts either). Otherwise (if the file exists), the contents are read.

In short, there are only two ways how you could get a None value for UID at this point:

Fishy, right?

I'll try again at home from OSX, but I'd bet that'll work just fine.

Kiina commented 7 years ago

So to be sure I just rm -rf the content of the .storage directory. Doesn't change. So just for testing I tried it on my Windows testing installation of kodi:

10:58:31.518 T:18044  NOTICE: [script.luna.core]: Loaded storage "host" from disk
10:58:31.520 T:18044  NOTICE: [script.luna.core]: Loaded storage "game_storage" from disk
10:58:44.085 T:18044   ERROR: [script.luna.kernel]: Failed to start Luna: 'NoneType' object has no attribute 'replace'
10:58:44.565 T:18044   ERROR: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<--
                                             - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS!
                                            Error Type: <type 'exceptions.AttributeError'>
                                            Error Contents: 'NoneType' object has no attribute 'replace'
                                            Traceback (most recent call last):
                                              File "C:\Users\Kiina\AppData\Roaming\Kodi\addons\script.luna\addon.py", line 24, in <module>
                                                XBMCApplicationKernel().bootstrap(callback)
                                              File "C:\Users\Kiina\AppData\Roaming\Kodi\addons\script.luna\resources\lib\kernel\xbmcapplicationkernel.py", line 24, in bootstrap
                                                sys.excepthook(exc_type, exc_value, exc_tb)
                                              File "C:\Users\Kiina\AppData\Roaming\Kodi\addons\script.luna\resources\lib\kernel\__init__.py", line 7, in log_exception
                                                eos_helper = RequiredFeature('eos-helper').request()
                                              File "C:\Users\Kiina\AppData\Roaming\Kodi\addons\script.luna\resources\lib\di\requiredfeature.py", line 76, in request
                                                instance = class_(**arguments)
                                              File "C:\Users\Kiina\AppData\Roaming\Kodi\addons\script.luna\resources\lib\eos\eoshelper.py", line 39, in __init__
                                                self._load_or_get_uid()
                                              File "C:\Users\Kiina\AppData\Roaming\Kodi\addons\script.luna\resources\lib\eos\eoshelper.py", line 156, in _load_or_get_uid
                                                self.uid = uid.replace('"', '')
                                            AttributeError: 'NoneType' object has no attribute 'replace'
                                            -->End of Python script error report<--

The exact same error, even though moonlight isn't even installed on my Windows. So could it be possible that it has trouble finding moonlight on my device but just doesn't log right?

wackerl91 commented 7 years ago

Nope, if moonlight can't be found it crashes early, but later than when your installations do.

From a fresh Kodi / Luna install on OSX:

12:17:03.024 T:123145332654080  NOTICE: [script.luna.core]: Loaded storage "host" from disk
12:17:03.024 T:123145332654080  NOTICE: [script.luna.core]: Loaded storage "game_storage" from disk
12:17:04.485 T:123145332654080  NOTICE: [script.luna.core]: Loaded storage "input_storage" from disk
12:17:04.486 T:123145351426048  NOTICE: [script.luna.core]: {"id":1,"jsonrpc":"2.0","result":{"name":"Kodi","version":{"major":17,"minor":0,"revision":"20170201-a10c504","tag":"stable"}}}
12:17:04.490 T:123145359839232  NOTICE: [script.luna.context]: Initialized
12:17:04.495 T:123145351426048   ERROR: Exception in thread Thread-3:
                                            [redacted]
                                                kodi_version['tagversion'], kodi_version['tag'])
                                            KeyError: 'tagversion'
12:17:04.506 T:123145359839232   ERROR: Exception in thread Thread-6:
                                            Traceback (most recent call last):
                                             [redacted]
                                                raise ValueError('Moonlight binary could not be found.')
                                            ValueError: Moonlight binary could not be found.
12:17:04.515 T:123145351426048  NOTICE: [script.luna.core]: Loaded storage "update" from disk
12:17:04.518 T:123145332654080 WARNING: CSkinInfo: failed to load skin settings
12:17:04.519 T:123145359839232  NOTICE: [script.luna.controller]: Getting Host Status
12:17:04.531 T:123145359839232  NOTICE: [script.luna.controller]: Getting Host Status ... Done

(The key error happens because the return value of a JSON RPC call seems to be different under OSX, never seen this under Linux).

By looking at the database, a UID was generated for this installation - server logs for Eos confirm this.

There's something really wonky here ... Do you have any special network setup in place, like system-wide proxies, own DNS servers, strict firewall rules, ... ? Alternatively: Can you try to curl this URL from the machine you're running Kodi on: https://www-eos.herokuapp.com/request/123456789? Response should be "24327924313024746441394e344b5578716c555536675964446f37454f6c564f464d516e75336d543233764d66685a3574657948506d6b6d31475736" (which is the string I'm using as user ID - in this case it's not assigned to any user, that's from the quick test I did from my phone last night).

Yet another alternative: if you enter the settings before opening Luna (via the context menu) and disable Eos (under the 'Experimental' tab in the settings) you should be able to open Luna.

Still, I'd like to know the root cause for what's happening on your end ...

Kiina commented 7 years ago

Oh okay so Eos was the telemetry service. Thats funny because one of the first things I disabled was this service, so it's actually disabled and still throwing this error. Tried to re-enable it, same logs. curl to the heroku site works fine.

Settings.xml say <setting id="enable_telemetry" value="false" /> so it should definitely be disabled

wackerl91 commented 7 years ago

Ouh, ouch ... Well, by design it shouldn't even get there if you disable it, as that kind of decision has to be up to the user (and transparent) in my opinion - even though the logs and exceptions it's gathering really help a lot, in the last week since this has been deployed I stumbled over at least 3 major issues which haven't been reported by users. So in the end it's there for a reason and while I can trace issues back to individual users, I do not know who they are or where they live. If you're interested in details about what kind of information is gathered, I'm happy to provide the information generated for my installations ;)

Enough of the preface, though: So, as I said - it's designed to disable itself completely during instantiation if the 'enable_telemetry' setting is false

However, a typo prevents it from effectively doing so entirely - the 'startswith' shouldn't check for '_' but for '__' to prevent overwriting of magic methods. In the end this means that neither the _load_or_get_uid nor the _get_uid method are replaced, thus still trying to generate a UID when it shouldn't (and still throwing the error you reported). All other methods are still overwritten, so even if it would start up properly no further information would be sent.

I'm deeply sorry about this and will provide a fix for this asap. While I'm at it, I'll probably also disable it entirely if no UID can be loaded and / or generated to prevent issues such as yours.