Contractor attempts to renew contracts prior to renewwindow

[mtlynch]

BUG REPORT

Stack Trace or error message

/renter shows the following:

{
    "currentperiod": 141743,
    "financialmetrics": {
        "contractspending": "2966666666666666666666666637",
        "downloadspending": "0",
        "storagespending": "829812797467921349445190510",
        "unspent": "1139328082921212303324167387",
        "uploadspending": "64192452944199680563975466"
    },
    "settings": {
        "allowance": {
            "funds": "5000000000000000000000000000",
            "hosts": 50,
            "period": 12960,
            "renewwindow": 6480
        }
    }
}

Expected behavior

My understanding is that the contract started at block 141743, ends at block 12960, and should attempt to renew contracts at block 141743 + 6480 = 148223.

Block 148223 is several weeks away, so my expectation is that the contract will not attempt to renew until that block occurs.

Actual behavior

contractor.log is filled with attempts to renew contracts:

2018/03/11 16:31:25.062784 contracts.go:479: WARN: failed to renew contract 2a49afa77dd37e59e5ab1c8c22de307e7eef517ed36d4b9218af842ea058abed: insufficient balance

Environment

• Sia version: 1.3.1
• OS: Win10 x64

Logs: https://gist.github.com/mtlynch/7726468eca7ffef0ff6ac9370b05024e

[Bojak4616]

I see errors on my host that appear to be related to this issue of renters trying to renew contracts with me too soon.

host log: https://gist.github.com/Bojak4616/6c0bba37c72650311269be01213a8222

[DavidVorick]

I do not believe that this a bug. Sia will renew a contract if it runs out of funds, which can happen before the renew window expires.

[DavidVorick]

@Bojak4616 the errors that you are seeing I think are something different. That error appears if the renter proposes a contract to the host that doesn't give the host enough time to submit the final revision of the contract safely. This can happen if you set the duration of your allowance really low, but it shouldn't happen if you are using the default settings.

[mtlynch]

I do not believe that this a bug. Sia will renew a contract if it runs out of funds, which can happen before the renew window expires.

It seems to be renewing them all at once, which is unexpected:

[DavidVorick]

Noted. Do you have the messages from the wallet.log around that time? I believe it should be logging the money it spends. If you can find the messages from the contractor.log around that time as well, we might be able to figure out what happened.

Can you also truncate the logs to the exact day of the big plummet in siacoins available to the wallet?

[mtlynch]

It started around 2018/03/03 02:30:00:

2018/03/03 02:21:44.823425 contracts.go:426: renewing 3 contracts
2018/03/03 02:31:45.328298 contracts.go:479: WARN: failed to renew contract 8eab21c168fe0263d20591747a33f36a211f4a8a0c987080b3ba51b31e07161d: host did not accept our signatures: read tcp 10.0.0.100:53159->45.51.175.46:9982: i/o timeout
2018/03/03 02:42:48.785436 contracts.go:479: WARN: failed to renew contract 01a5f6c8ddc77f72023de2ac0da66376a66e7c9f0d95529435f332266f253718: host did not accept our signatures: read tcp 10.0.0.100:58335->188.244.40.69:9986: i/o timeout
2018/03/03 02:43:49.859388 contracts.go:479: WARN: failed to renew contract e83fb123c96e99a1fede7146a59c74f1e26bdf587d436716b62ec9a5122267a1: dial tcp 47.17.201.131:9982: connectex: No connection could be made because the target machine actively refused it.

2018/03/03 02:21:40.829926 update.go:119: Wallet has lost a spendable siacoin output: d33e95ef030d97071e0b0c02b56979534a4079a62967e94c0b2e90b33e512b27 :: 1.767 KS
2018/03/03 02:21:40.830427 update.go:116: Wallet has gained a spendable siacoin output: 5051f58aa8271038f771128cccb3685a0ac9934d0190be6f68b99f0ffeb4aa55 :: 66.67 SC
2018/03/03 02:21:40.830427 update.go:116: Wallet has gained a spendable siacoin output: a8ede9a2b1f9a7bc6d276c4483e1661d0d7fa7930b336ee69016d4a4e1dc035b :: 1.7 KS
2018/03/03 02:21:40.830427 update.go:119: Wallet has lost a spendable siacoin output: 5051f58aa8271038f771128cccb3685a0ac9934d0190be6f68b99f0ffeb4aa55 :: 66.67 SC
2018/03/03 02:21:40.831427 update.go:285: A transaction has been confirmed on the blockchain: ebf3c12ad33c2a9afd0ec1d07cf8df496755ce80990b9cf4bb46ed1afd753e72

[MSevey]

@mtlynch a quick comment on your initial post

My understanding is that the contract started at block 141743, ends at block 12960, and should attempt to renew contracts at block 141743 + 6480 = 148223.

If the contract started at block 141743 and the period is 12960 then the contract should end at 141743 + 12960. In this case the renew window is half the period so you are right in saying that the contract should attempt to renew at 141743 + 6480 but it is more accurate to say that the contract will renew at startHeight + period - renewWindow, so in this case 141743 + 12960 - 6480.