duplicity exits with status -1

Asked by Sammitch

We've got some automation built up around duplicity, but we're having some occasional trouble with duplicity exiting with code -1 during a restore. eg:

Writing foo/bar.jpg of type reg
Deleting /var/lib/tmp/duplicity-GYz7n0-tempdir/mktemp-yHEK5p-7
Processed volume 6 of 49
Ended with non-successful exit code (-1)

With the last line of output originating from our system.

I've looked at the pydoc for the ErrorCode class, and it explicitly states that negative return codes are not to be used. The best I've been able to turn up is that Python subprocesses will return a negative status reflecting the signal they were sent, -1 correlating to SIGHUP.

Investigating this further I've found that duplicity.pexpect.run() appears to be calling the close() function on child processes which issues a SIGHUP, and then returning the child's status.

Is this an expected behaviour? Can we safely assume that a -1 exit status is OK from duplicity?

This is pure inference, but is duplicity issuing an early close() on the subprocess handling the restore once it has restored the necessary files, and then the -1 return code gets passed up through the stack until duplicity exits?

Question information

Language:
English Edit question
Status:
Expired
For:
Duplicity Edit question
Assignee:
No assignee Edit question
Last query:
Last reply:
Revision history for this message
Launchpad Janitor (janitor) said :
#1

This question was expired because it remained in the 'Open' state without activity for the last 15 days.

Revision history for this message
Sammitch (fubes2000) said :
#2

Reopen
On Sun, Mar 1, 2015 at 12:17 AM Launchpad Janitor <
<email address hidden>> wrote:

> Your question #262087 on Duplicity changed:
> https://answers.launchpad.net/duplicity/+question/262087
>
> Status: Open => Expired
>
> Launchpad Janitor expired the question:
> This question was expired because it remained in the 'Open' state
> without activity for the last 15 days.
>
> --
> If you're still having this problem, you can reopen your question either
> by replying to this email or by going to the following page and
> entering more information about your problem:
> https://answers.launchpad.net/duplicity/+question/262087
>
> You received this question notification because you asked the question.
>

Revision history for this message
Kenneth Loafman (kenneth-loafman) said :
#3

What version of duplicity?

No, SIGHUP is not anticipated and not caught correctly. Have you tried running 'nohup duplicity ...' as a short term solution?

Revision history for this message
Sammitch (fubes2000) said :
#4

We are currently running 0.6.22

The issue is not that duplicity is responding oddly to an externally-issued HUP signal, there is nothing in our framework that uses a HUP at all. But it appears that duplicity is issuing this signal to its subprocesses and then allowing that return code to bubble out to the OS despite it being a successful run.

Revision history for this message
edso (ed.so) said :
#5

On 02.03.2015 22:31, Sammitch wrote:
> Question #262087 on Duplicity changed:
> https://answers.launchpad.net/duplicity/+question/262087
>
> Status: Answered => Open
>
> Sammitch is still having a problem:
> We are currently running 0.6.22
>
> The issue is not that duplicity is responding oddly to an externally-
> issued HUP signal, there is nothing in our framework that uses a HUP at
> all. But it appears that duplicity is issuing this signal to its
> subprocesses and then allowing that return code to bubble out to the OS
> despite it being a successful run.
>

you wrote you dug into the code.. could you please pinpoint the code for us to look at?

..ede/duply.net

Revision history for this message
Kenneth Loafman (kenneth-loafman) said :
#6

It's in the older pexpect module which uses SIGINT, SIGHUP, then finally SIGKILL to close the child process. I'm not sure what it would be trying to kill though. That's a bit of a mystery.

What command line are you using?

What OS? What version?

Revision history for this message
edso (ed.so) said :
#7

On 03.03.2015 14:21, Kenneth Loafman wrote:
> Question #262087 on Duplicity changed:
> https://answers.launchpad.net/duplicity/+question/262087
>
> Kenneth Loafman requested more information:
> It's in the older pexpect module which uses SIGINT, SIGHUP, then finally
> SIGKILL to close the child process. I'm not sure what it would be
> trying to kill though. That's a bit of a mystery.
>

still. if he's right and duplicity uses the last pexpect's return code as global return code, that smells buggy.

..ede/duply.net

Revision history for this message
Kenneth Loafman (kenneth-loafman) said :
#8

Possibly. Read up on Python's signal handling. We have to know the path
before we handle this, thus the questions.

On Tue, Mar 3, 2015 at 9:56 AM, edso <email address hidden>
wrote:

> Question #262087 on Duplicity changed:
> https://answers.launchpad.net/duplicity/+question/262087
>
> edso proposed the following answer:
> On 03.03.2015 14:21, Kenneth Loafman wrote:
> > Question #262087 on Duplicity changed:
> > https://answers.launchpad.net/duplicity/+question/262087
> >
> > Kenneth Loafman requested more information:
> > It's in the older pexpect module which uses SIGINT, SIGHUP, then finally
> > SIGKILL to close the child process. I'm not sure what it would be
> > trying to kill though. That's a bit of a mystery.
> >
>
> still. if he's right and duplicity uses the last pexpect's return code
> as global return code, that smells buggy.
>
> ..ede/duply.net
>
> --
> You received this question notification because you are a member of
> duplicity-team, which is an answer contact for Duplicity.
>
> _______________________________________________
> Mailing list: https://launchpad.net/~duplicity-team
> Post to : <email address hidden>
> Unsubscribe : https://launchpad.net/~duplicity-team
> More help : https://help.launchpad.net/ListHelp
>

Revision history for this message
edso (ed.so) said :
#9

already asked him, where in the code we reuse the return signal. he claimed to have looked it up earlier.

..ede/duply.net

On 03.03.2015 17:26, Kenneth Loafman wrote:
> Question #262087 on Duplicity changed:
> https://answers.launchpad.net/duplicity/+question/262087
>
> Kenneth Loafman proposed the following answer:
> Possibly. Read up on Python's signal handling. We have to know the path
> before we handle this, thus the questions.
>
>
> On Tue, Mar 3, 2015 at 9:56 AM, edso <email address hidden>
> wrote:
>
>> Question #262087 on Duplicity changed:
>> https://answers.launchpad.net/duplicity/+question/262087
>>
>> edso proposed the following answer:
>> On 03.03.2015 14:21, Kenneth Loafman wrote:
>>> Question #262087 on Duplicity changed:
>>> https://answers.launchpad.net/duplicity/+question/262087
>>>
>>> Kenneth Loafman requested more information:
>>> It's in the older pexpect module which uses SIGINT, SIGHUP, then finally
>>> SIGKILL to close the child process. I'm not sure what it would be
>>> trying to kill though. That's a bit of a mystery.
>>>
>>
>> still. if he's right and duplicity uses the last pexpect's return code
>> as global return code, that smells buggy.
>>
>> ..ede/duply.net
>>
>> --
>> You received this question notification because you are a member of
>> duplicity-team, which is an answer contact for Duplicity.
>>
>> _______________________________________________
>> Mailing list: https://launchpad.net/~duplicity-team
>> Post to : <email address hidden>
>> Unsubscribe : https://launchpad.net/~duplicity-team
>> More help : https://help.launchpad.net/ListHelp
>>
>

Revision history for this message
Kenneth Loafman (kenneth-loafman) said :
#10

OK, I just filled in the blanks so we could recreate the problem locally. It has to be ending up at line #1516 if it's going through sys.exit(), so it's just a matter of recreating something close to the original.

Revision history for this message
Sammitch (fubes2000) said :
#11

The lines in question are pexpect.py:256-258

    if withexitstatus:
        child.close()
        return (child_result, child.exitstatus)

Where under certain conditions the child process is terminated with SIGHUP. As far as I can follow the code if closing the child's tty fd doesn't work it drops into terminate() which will issue a SIGHUP as its first attempt to stop the process.

We are currently running duplicity 0.6.22 on Centos 6.5, and the restore commands are like:

/usr/bin/duplicity -v info restore --tempdir /var/lib/tmp --file-to-restore foo.bar -t 2015-03-03T04:12:02 --s3-use-new-style --no-encryption s3+http://foo-backup/foobar /foo.bar

Revision history for this message
Launchpad Janitor (janitor) said :
#12

This question was expired because it remained in the 'Open' state without activity for the last 15 days.