Laharah / deluge-FileBotTool

A plugin to integrate simple FileBot functionality into Deluge
GNU General Public License v3.0
114 stars 10 forks source link

Filebottool Dialog not opening #50

Closed VladGrant closed 3 years ago

VladGrant commented 3 years ago

I am testing out FileBotTool with deluge 2.0, since I saw you released some support for it, however the dialog does not seem to show up from the right-click menu. The "Debug Info" button also doesn't display anything and only stays greyed out when clicked. I turned on some logging and nothing seems out of the ordinary (included at the bottom with slight redactions).

I'm running on arch linux with LXDE (not sure if that would matter). If there's any other logs that might help, let me know, it's pretty easy to reproduce.

08:08:34.054 [DEBUG ][deluge.core.rpcserver :310 ] RPC dispatch filebottool.get_rename_dialog_info 08:08:34.054 [DEBUG ][filebottool.common :847 ] [FileBotTool] dialog info requested, packing dialog info. 08:08:34.055 [DEBUG ][filebottool.common :863 ] [FileBotTool] sending dialog info to client: {'torrent_ids': ('0fb273b1b512609c0ed23e2d14c05e066db52d43',), 'torrent_save_path': "**", 'files': [{'index': 0, 'path': "", 'size': 1149316487, 'offset': 0}], 'filebot_version': b'FileBot 4.7.9 (r4984) / OpenJDK Runtime Environment 1.8.0_292 / Linux 5.12.1-arch1-1 (amd64)', 'rename_dialog_last_settings': {'database': 'TheMovieDB', 'download_subs': False, 'encoding': 'UTF-8', 'episode_order': None, 'format_string': "{ny}/{ny}{' CD'+pi}", 'handler_name': None, 'language_code': '', 'on_conflict': None, 'output': '**', 'query_override': None, 'rename_action': 'move', 'show_advanced': True, 'subs_language': ''}, 'saved_handlers': {'Anime': {'database': 'AniDB', 'download_subs': False, 'encoding': 'UTF-8', 'episode_order': None, 'format_string': "{n}/{'Season '+s}/{n} - {e00} - {t}", 'language_code': 'EN', 'on_conflict': None, 'output': '***', 'query_override': '', 'rename_action': 'move', 'show_advanced': True, 'subs_language': ''}, 'Movies': {'database': 'TheMovieDB', 'download_subs': False, 'encoding': 'UTF-8', 'episode_order': None, 'format_string': "{ny}/{ny}{' CD'+pi}", 'language_code': '', 'on_conflict': None, 'output': '', 'query_override': '', 'rename_action': 'move', 'show_advanced': True, 'subs_language': ''}, 'TV': {'database': 'TheTVDB', 'download_subs': False, 'encoding': 'UTF-8', 'episode_order': None, 'format_string': "{n}/{'Season '+s}/{n} - {s00e00} - {t}", 'language_code': '', 'on_conflict': None, 'output': '', 'query_override': '', 'rename_action': 'move', 'show_advanced': True, 'subs_language': ''}}, 'valid_databases': [None, 'TheTVDB', 'Tvmaze', 'AniDB', 'OpenSubtitles', 'TheMovieDB', 'TheMovieDB::TV', 'OMDb', 'AcoustID', 'ID3 Tags'], 'valid_rename_actions': [None, 'move', 'copy', 'duplicate', 'keeplink', 'symlink', 'reflink', 'hardlink', 'test'], 'valid_on_conflicts': [None, 'override', 'skip', 'auto', 'index', 'fail'], 'valid_episode_orders': [None, 'dvd', 'airdate', 'absolute']} 08:08:34.075 [DEBUG ][deluge.core.rpcserver :310 ] RPC dispatch filebottool.get_filebot_valid_values

The logs for the "Debug Info" button also seem to be perfectly fine:

08:16:53.289 [DEBUG ][deluge.core.rpcserver :310 ] RPC dispatch filebottool.get_filebot_debug 08:16:53.289 [DEBUG ][filebottool.common :903 ] [FileBotTool] Received request for FileBot debug info... 08:16:55.865 [DEBUG ][filebottool.common :909 ] [FileBotTool] FileBot debug info retrieved.

Laharah commented 3 years ago

That's annoying. Could you get me the logs for the GTK client? these debug logs are for the server portion of the plugin. I believe there is a separate flag for the GTK log in deluge 2.0. If that doesn't work you can put deluge into "classic mode" where I think everything is logged into one place. It's under settings>interface>classic mode.

I'll do some more testing tomorrow to see if I can replicate the issue somehow.

VladGrant commented 3 years ago

Found it:

07:30:41.511 [DEBUG ][deluge.ui.gtk3.torrentview :794 ] on_button_press_event 07:30:42.700 [DEBUG ][deluge.ui.gtk3.gtkui :294 ] RPC: Sent 243.3 KiB (15.1 KiB/s) Recv 332.4 KiB (16.2 KiB/s) Unhandled error in Deferred: 07:30:47.164 [CRITICAL][twisted :147 ] Unhandled error in Deferred:

Traceback (most recent call last): File "/usr/lib/python3.9/site-packages/deluge/transfer.py", line 129, in _handle_complete_message self.message_received( File "/usr/lib/python3.9/site-packages/deluge/ui/client.py", line 133, in message_received d.callback(request[2]) File "/usr/lib/python3.9/site-packages/twisted/internet/defer.py", line 477, in callback self._startRunCallbacks(result) File "/usr/lib/python3.9/site-packages/twisted/internet/defer.py", line 580, in _startRunCallbacks self._runCallbacks() --- --- File "/usr/lib/python3.9/site-packages/twisted/internet/defer.py", line 662, in _runCallbacks current.result = callback(current.result, *args, kw) File "/home/**/.config/deluge/plugins/FileBotTool-2.0.0-py3.9.egg/filebottool/gtkui/gtk3ui.py", line 104, in build_rename_dialog

File "/home/***/.config/deluge/plugins/FileBotTool-2.0.0-py3.9.egg/filebottool/gtkui/rename_dialog_gtk3.py", line 104, in init

builtins.AttributeError: 'str' object has no attribute 'decode'

07:30:47.180 [CRITICAL][deluge.log :90 ] twisted.internet.defer [Failure instance: Traceback: <class 'AttributeError'>: 'str' object has no attribute 'decode' /usr/lib/python3.9/site-packages/deluge/transfer.py:129:_handle_complete_message /usr/lib/python3.9/site-packages/deluge/ui/client.py:133:message_received /usr/lib/python3.9/site-packages/twisted/internet/defer.py:477:callback /usr/lib/python3.9/site-packages/twisted/internet/defer.py:580:_startRunCallbacks --- --- /usr/lib/python3.9/site-packages/twisted/internet/defer.py:662:_runCallbacks /home/*/.config/deluge/plugins/FileBotTool-2.0.0-py3.9.egg/filebottool/gtkui/gtk3ui.py:104:build_rename_dialog /home/**/.config/deluge/plugins/FileBotTool-2.0.0-py3.9.egg/filebottool/gtkui/rename_dialog_gtk3.py:104:init ] 07:30:47.194 [DEBUG ][filebottool.common :73 ] [FileBotTool] building database combo box 07:30:47.195 [DEBUG ][filebottool.common :77 ] [FileBotTool] building rename action combo box 07:30:47.195 [DEBUG ][filebottool.common :81 ] [FileBotTool] building on conflict combo box 07:30:47.196 [DEBUG ][filebottool.common :85 ] [FileBotTool] building episode order combo box 07:30:47.196 [DEBUG ][filebottool.common :106 ] [FileBotTool] Setting combo boxes 07:30:47.196 [DEBUG ][filebottool.common :130 ] [FileBotTool] Setting entry widgets 07:30:52.700 [DEBUG ][deluge.ui.gtk3.gtkui :294 ] RPC: Sent 424.4 KiB (18.1 KiB/s) Recv 526.8 KiB (19.4 KiB/s) 07:31:02.700 [DEBUG ][deluge.ui.gtk3.gtkui :294 ] RPC: Sent 575.4 KiB (15.1 KiB/s) Recv 688.6 KiB (16.2 KiB/s) 07:31:12.700 [DEBUG ][deluge.ui.gtk3.gtkui :294 ] RPC: Sent 726.7 KiB (15.1 KiB/s) Recv 850.5 KiB (16.2 KiB/s) ^C07:31:20.700 [DEBUG ][deluge.ui.gtk3.gtkui :240 ] SIGINT signal caught, firing event: gtkui_close 07:31:20.702 [DEBUG ][deluge.ui.gtk3.common :321 ] Creating backup of torrentview.state at: /home//.config/deluge/gtk3ui_state/torrentview.state.bak 07:31:20.703 [INFO ][deluge.ui.gtk3.common :326 ] Saving the torrentview.state at: /home//.config/deluge/gtk3ui_state/torrentview.state 07:31:20.741 [DEBUG ][deluge.ui.gtk3.gtkui :252 ] GTKUI shutting down... 07:31:20.741 [DEBUG ][deluge.ui.gtk3.torrentview :820 ] on_selection_changed 07:31:20.743 [DEBUG ][deluge.ui.gtk3.common :321 ] Creating backup of torrentview.state at: /home/**/.config/deluge/gtk3ui_state/torrentview.state.bak 07:31:20.743 [INFO ][deluge.ui.gtk3.common :326 ] Saving the torrentview.state at: /home//.config/deluge/gtk3ui_state/torrentview.state

Laharah commented 3 years ago

Looks like linux handles unicode from called subprocesses differently than osx.

I've pushed a new release with some bug fixes that I think should fix the issue: https://github.com/Laharah/deluge-FileBotTool/releases/tag/2.0.1

let me know if that fixes it. If not I'll have to spin up a VM and see if I can track down the issue.

VladGrant commented 3 years ago

A different error, does look like progress though!

19:15:07.507 [DEBUG ][deluge.ui.gtk3.gtkui :294 ] RPC: Sent 424.9 KiB (15.1 KiB/s) Recv 527.1 KiB (16.2 KiB/s) 19:15:08.780 [DEBUG ][deluge.ui.gtk3.torrentview :794 ] on_button_press_event 19:15:10.073 [DEBUG ][deluge_label.gtkui.submenu :47 ] label-on-show Unhandled error in Deferred: 19:15:11.416 [CRITICAL][twisted :147 ] Unhandled error in Deferred:

Traceback (most recent call last): File "/usr/lib/python3.9/site-packages/deluge/transfer.py", line 129, in _handle_complete_message self.message_received( File "/usr/lib/python3.9/site-packages/deluge/ui/client.py", line 133, in message_received d.callback(request[2]) File "/usr/lib/python3.9/site-packages/twisted/internet/defer.py", line 477, in callback self._startRunCallbacks(result) File "/usr/lib/python3.9/site-packages/twisted/internet/defer.py", line 580, in _startRunCallbacks self._runCallbacks() --- --- File "/usr/lib/python3.9/site-packages/twisted/internet/defer.py", line 662, in _runCallbacks current.result = callback(current.result, *args, **kw) File "/home/*****/.config/deluge/plugins/FileBotTool-2.0.1-py3.9.egg/filebottool/gtkui/gtk3ui.py", line 104, in build_rename_dialog

File "/home/*****/.config/deluge/plugins/FileBotTool-2.0.1-py3.9.egg/filebottool/gtkui/rename_dialog_gtk3.py", line 134, in init

File "/home/*****/.config/deluge/plugins/FileBotTool-2.0.1-py3.9.egg/filebottool/gtkui/rename_dialog_gtk3.py", line 212, in load_treestore

File "/usr/lib/python3.9/site-packages/gi/overrides/Gtk.py", line 1276, in append return self._do_insert(parent, -1, row) File "/usr/lib/python3.9/site-packages/gi/overrides/Gtk.py", line 1268, in _do_insert row, columns = self._convert_row(row) File "/usr/lib/python3.9/site-packages/gi/overrides/Gtk.py", line 907, in _convert_row result.append(self._convert_value(cur_col, value)) File "/usr/lib/python3.9/site-packages/gi/overrides/Gtk.py", line 921, in _convert_value return GObject.Value(self.get_column_type(column), value) File "/usr/lib/python3.9/site-packages/gi/overrides/GObject.py", line 208, in init self.set_value(py_value) File "/usr/lib/python3.9/site-packages/gi/overrides/GObject.py", line 240, in set_value raise TypeError("Expected string but got %s%s" % builtins.TypeError: Expected string but got 0<class 'int'>

19:15:11.418 [CRITICAL][deluge.log :90 ] twisted.internet.defer [Failure instance: Traceback: <class 'TypeError'>: Expected string but got 0<class 'int'> /usr/lib/python3.9/site-packages/deluge/transfer.py:129:_handle_complete_message /usr/lib/python3.9/site-packages/deluge/ui/client.py:133:message_received /usr/lib/python3.9/site-packages/twisted/internet/defer.py:477:callback /usr/lib/python3.9/site-packages/twisted/internet/defer.py:580:_startRunCallbacks --- --- /usr/lib/python3.9/site-packages/twisted/internet/defer.py:662:_runCallbacks /home//.config/deluge/plugins/FileBotTool-2.0.1-py3.9.egg/filebottool/gtkui/gtk3ui.py:104:build_rename_dialog /home//.config/deluge/plugins/FileBotTool-2.0.1-py3.9.egg/filebottool/gtkui/rename_dialog_gtk3.py:134:init /home/*****/.config/deluge/plugins/FileBotTool-2.0.1-py3.9.egg/filebottool/gtkui/rename_dialog_gtk3.py:212:load_treestore /usr/lib/python3.9/site-packages/gi/overrides/Gtk.py:1276:append /usr/lib/python3.9/site-packages/gi/overrides/Gtk.py:1268:_do_insert /usr/lib/python3.9/site-packages/gi/overrides/Gtk.py:907:_convert_row /usr/lib/python3.9/site-packages/gi/overrides/Gtk.py:921:_convert_value /usr/lib/python3.9/site-packages/gi/overrides/GObject.py:208:init /usr/lib/python3.9/site-packages/gi/overrides/GObject.py:240:set_value ] 19:15:11.420 [DEBUG ][filebottool.common :73 ] [FileBotTool] building database combo box 19:15:11.421 [DEBUG ][filebottool.common :77 ] [FileBotTool] building rename action combo box 19:15:11.422 [DEBUG ][filebottool.common :81 ] [FileBotTool] building on conflict combo box 19:15:11.423 [DEBUG ][filebottool.common :85 ] [FileBotTool] building episode order combo box 19:15:11.423 [DEBUG ][filebottool.common :106 ] [FileBotTool] Setting combo boxes 19:15:11.424 [DEBUG ][filebottool.common :130 ] [FileBotTool] Setting entry widgets

Laharah commented 3 years ago

Alright, that one's weird. It looks like the call structure for that GTK function has changed somewhere, but I have no idea when or why. Even looking at the gtk documentation it looks like that's still the correct signature.

Can you figure out what version of GTK you're running deluge with?

If you can open a python prompt with whatever python version you're running deluge with these commands should get you the version:

$>python3
Python 3.9.4 (default, Dec 20 2019, 16:48:12)
[GCC 8.3.0] on linux
Type "help", "copyright", "credits" or "license" for more information.

>>> from gi.repository import Gtk
>>> Gtk.MAJOR_VERSION, Gtk.MINOR_VERSION, Gtk.MICRO_VERSION
(3, 24, 29)

I can probably put out a fix for this error, but given that the signatures have changed at some point I'll probably instantly run into another. I'll try and spin up a vm with your GTK version and see if I can figure out why it's different from the versions of GTK I'm testing on.

VladGrant commented 3 years ago

So you're going to hate me for this:

Python 3.9.5 (default, May  9 2021, 14:00:28)
[GCC 10.2.0] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> from gi.repository import Gtk
Unable to init server: Could not connect: Connection refused
Unable to init server: Could not connect: Connection refused
<stdin>:1: PyGIWarning: Gtk was imported without specifying a version first. Use gi.require_version('Gtk', '3.0') before import to ensure that the right version gets loaded.
>>> Gtk.MAJOR_VERSION, Gtk.MINOR_VERSION, Gtk.MICRO_VERSION
(3, 24, 29)
>>> exit()

Now I checked the deluge GTK logs again and I am fairly sure it's using GTK3 not 2 since I see ton of deluge.ui.gtk3.* flagged items.

Laharah commented 3 years ago

No worries, I'm spinning up a VM now and I'll see if I can replicate the issue to see if I can figure out what's going on.

Laharah commented 3 years ago

I've got even worse news:

debug rename

I couldn't replicate the issue with a fresh arch VM. It's slow as hell, not sure if that's just the vm or something to do with the filebot install, but fully working as far as I can tell.

Info on how I built the VM etc:

All I can think is that maybe if you installed deluge with pip install deluge that could explain the Gtk issue? But honestly that error is so out of left field that I don't really have much to go on; as far as I know that function signature has always been valid for the gtk python bindings.

Can you check the python-gtk bindings version by opening a python prompt and running this?:

>>> import gi; gi.version_info

If it's the same as mine, I think I'm pretty stumped unless you can dig up some more info. Could deluge be running under a different python?

Can you peek at the deluge command and make sure you're using the same python to get both of your gtk version infos?

$> head -n 1 $(which deluge)
#!/usr/bin/python
$> /usr/bin/python
...
>>> import gi; gi.version_info
(3, 40, 1)
brad1ie commented 3 years ago

Hi, I am also seeing similar behaviour. I can get the dialog on all torrents in my list except for two. Not sure if this is a coincidence or not but the torrents that are affected both have a name that ends with .mkv and they are the only torrents i have that are single file torrents with the torrent name matching the filename, that all i can see that these torrents have in common. other than that it seems to work for me. hope this helps. Thanks!

Laharah commented 3 years ago

@brad1ie I'll take a look, can you tell me what OS you're on and how you installed deluge?

brad1ie commented 3 years ago

I am using Ubuntu 20.04 and just installed Deluge using the PPA

Laharah commented 3 years ago

Okay, looks like I found the issue. I was finally able to replicate and find the bug.

The fix is in the new release

Thanks so much for your help @brad1ie, and for your patience and bringing it to my attention @VladGrant.

VladGrant commented 3 years ago

Thank you so much, that got it!