Page 1 of 2

execute plugin fails intermittently

Posted: Wed Jun 27, 2012 1:40 am
by voltaicsca
sometimes the execute plugin fails to execute with the following error in the log file:

Code: Select all

[DEBUG   ] 04:35:56 alertmanager:123 torrent_finished_alert: << torrent name >> torrent finished downloading
[DEBUG   ] 04:35:56 alertmanager:123 state_changed_alert: << torrent name >>: state changed to: finished
[DEBUG   ] 04:35:56 alertmanager:123 state_changed_alert: << torrent name >>: state changed to: seeding
[DEBUG   ] 04:35:56 alertmanager:123 tracker_announce_alert: << torrent name >> (udp:// sending announce (completed)
[DEBUG   ] 04:35:56 torrentmanager:869 on_alert_torrent_finished
[DEBUG   ] 04:35:56 torrentmanager:875 << torrent id >> is finished..
[DEBUG   ] 04:35:56 rpcserver:466 intevents: {4426: ['TorrentRemovedEvent', 'PluginEnabledEvent', 'TorrentAddedEvent', 'PluginDisabledEvent', 'TorrentStateChangedEvent', 'ConfigValueChangedEvent']}
[DEBUG   ] 04:35:56 core:111 [execute] Running commands for complete
[DEBUG   ] 04:35:56 core:127 [execute] running /home/deluge/
[ERROR   ] 04:35:56 eventmanager:59 Event handler TorrentFinishedEvent failed in <function event_handler at 0x1f976e0>

The script that is supposed to run when a torrent completes never gets touched. ie, the failure occurs before ever actually invoking the script.
Also, I have tested my script, and it works always when invoked from the command line, and sometimes when run from deluge.

I'm running deluge 1.3.5 on ubuntu server 10.04 LTS

anyone have any ideas?

PS, I don't think it's relevant, but here's the script i'm running:

Code: Select all




scpresume="rsync --partial --progress --inplace --rsh=ssh"


echo "\"${torrentfullpath}\""
#remove the /home/deluge part of the full path.
#now add the remote path to the torrentdest
#get the directory name only for the destination
torrentdest=`dirname "${torrentdest}"`
#escape spaces.
torrentdest="${torrentdest// /\ }"
#torrentfullpath="${torrentfullpath// /asdfasdf}"

echo "log for $torrentname, $torrentid" >> /home/deluge/lastxfer.txt

starttime=`date +%s`
echo starttime: $starttime

until (( retries>60 || result==0 ))
        #wait a little longer each time.
        sleep $((retries/2))m
        (( retries += 1 ))
        echo "try #${retries}" >> /home/deluge/lastxfer.txt
        echo $scpresume -r "'${torrentfullpath}'" user@sshserver:"${torrentdest}/" >> /home/deluge/lastxfer.$
        eval $scpresume -r "\"$torrentfullpath\"" user@sshserver:"${torrentdest}/"

if (( result != 0 ))
        echo "scp never completed sucesssfully" >> /home/deluge/lastxfer.txt
        endtime=`date +%s`
        echo entime: $endtime

        echo totaltime: $totaltime
        size=`du -s "$torrentfullpath"`
        set -- $size
        echo "removing $torrentname" >> /home/deluge/lastxfer.txt
        echo $torrentid
        echo $? >> /home/deluge/lastxfer.txt
        echo -e "Subject: $torrentname finished\nTo:\nDate: `date`\nFrom:\n\nfile $
echo "" >> /home/deluge/lastxfer.txt

Re: execute plugin fails intermittently

Posted: Wed Jun 27, 2012 4:55 am
by johnnyg
Hmm that doesn't give us much info to go off.
Something is going wrong when trying to run the script (which is weird).

Is that the only script that's running?
As of Deluge 1.3.4 scripts are run asynchronously (i.e. deluge doesn't block when running scripts), so it's possible to have two scripts running at the same time.

If your script produces an error then that should get caught though (and it will print so).
The only thing that doesn't get caught at the moment is if your script raises a signal (which your script doesn't do unless it's somehow being killed).

How do you know it's not being touched at all? By inspecting your lastxfer.txt file?
Your echos won't get printed unless your script exits with a non-zero status code.
You could modify your script to do so however I suspect that won't help as it's not getting to the part where it can print things.

The best way to debug this would be to modify the source to print what the exception was (+ a traceback), however I'm guessing you installed Deluge from the PPA?

Re: execute plugin fails intermittently

Posted: Wed Jun 27, 2012 2:54 pm
by voltaicsca
I realize that is pretty scant information to go on.
It is the only script that is running when it is invoked.
I did install from the PPA, but I don't have any qualms about rolling my own with more debugging info. Also, deluge is written in Python, isn't it? shouldn't I be able to modify my source in-place on the running system?
I'll give that a try, and see what I can find out. I'm guessing from the log file that the source file to modify would be eventmanager, somewhere around line 59?

Re: execute plugin fails intermittently

Posted: Wed Jun 27, 2012 3:14 pm
by johnnyg
Yes Deluge is written in Python so you could do that.

Obviously it's slightly easier to patch if you've installed from source.

Yes you would need to modify

Simplest way to debug would be to log the exception:

Code: Select all

diff --git a/deluge/core/ b/deluge/core/
index c663491..424f111 100644
--- a/deluge/core/
+++ b/deluge/core/
@@ -55,8 +55,9 @@ def emit(self, event):
                 #log.debug("Running handler %s for event %s with args: %s",, handler, event.args)
-                except:
+                except Exception, e:
                     log.error("Event handler %s failed in %s",, handler)
+                    log.exception(e)
     def register_event_handler(self, event, handler):

Re: execute plugin fails intermittently

Posted: Wed Jun 27, 2012 3:38 pm
by voltaicsca
Awesome! Very helpful. Thanks!

I'll give that a try and report back.

Re: execute plugin fails intermittently

Posted: Fri Jul 13, 2012 1:18 pm
by voltaicsca
I haven't forgotten about this, but since I added that code to the file, the thing hasn't failed once, which is odd since it used to fail about once a week.

I keep hoping it will fail so I can have some concrete idea of what is actually happening, rather than having some mysterious "fix" that resulted from changing something unrelated in the code... Anyway, I'm still watching.

Re: execute plugin fails intermittently

Posted: Wed Jul 18, 2012 1:30 am
by terrukallan
I was experiencing what is presumably the same problem, but unlike voltaicsca I've been able to reproduce it consistently. It's caused by unicode characters in the torrent name.

Here's the stack trace:

Code: Select all

[ERROR   ] 19:01:52 eventmanager:60 Arguments contain a non-string value
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/deluge/core/", line 57, in emit
  File "/usr/lib/python2.7/dist-packages/deluge/plugins/Execute-1.2.egg/execute/", line 90, in event_handler
    self.execute_commands(torrent_id, event)
  File "/usr/lib/python2.7/dist-packages/deluge/plugins/Execute-1.2.egg/execute/", line 130, in execute_commands
    d = getProcessOutputAndValue(command, (torrent_id, torrent_name, save_path), env=os.environ)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/", line 169, in getProcessOutputAndValue
  File "/usr/lib/python2.7/dist-packages/twisted/internet/", line 25, in _callProtocolWithDeferred
    reactor.spawnProcess(p, executable, (executable,)+tuple(args), env, path)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/", line 328, in spawnProcess
    args, env = self._checkProcessArgs(args, env)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/", line 886, in _checkProcessArgs
    raise TypeError("Arguments contain a non-string value")
TypeError: Arguments contain a non-string value

Twisted (getProcessOutputAndValue) is throwing the TypeError because it's attempting to turn any arguments of type unicode to strings by using the python system encoding (sys.getdefaultencoding()). On my system, this is ascii by default so any unicode strings fail to decode and throw the error.

Just as a quick hack to get things working for me, I've made the following addition in execute/

Code: Select all

        # Go through and execute all the commands
        for command in self.config["commands"]:
            if command[EXECUTE_EVENT] == event:
                command = os.path.expandvars(command[EXECUTE_COMMAND])
                command = os.path.expanduser(command)
                log.debug("[execute] running %s", command)
+               if isinstance(torrent_name, unicode):
+                   torrent_name = torrent_name.encode('utf-8')
                d = getProcessOutputAndValue(command, (torrent_id, torrent_name, save_path), env=os.environ)
                d.addCallback(log_error, command)

With this in place, the previously failing torrents are getting passed to my execute scripts.

Edit: forgot to mention that this is 1.3.5 on Ubuntu 12.04

Re: execute plugin fails intermittently

Posted: Tue Aug 21, 2012 12:15 pm
by chimpy
This error is also causing my script to fail intermittently too. Trying out terrukalian's solution, but it's not working :(

This is indeed the file I need to edit, right? /usr/share/pyshared/deluge/plugins/Execute-1.2.egg/execute/


Re: execute plugin fails intermittently

Posted: Tue Aug 21, 2012 12:22 pm
by chimpy
Just restarted Deluge and the fix works magnificently! Thank you so much terrukalian + others! :)

That change should probably be committed into 1.3.6, no?

Re: execute plugin fails intermittently

Posted: Tue Aug 21, 2012 12:52 pm
by Cas
If you create a ticket and mark it for 1.3.6 milestone then it will be dealt with.