add debug logging

autopilot/contractor/contractor.go

@@ -180,10 +180,16 @@ func (c *Contractor) formContract(ctx *mCtx, hs HostScanner, host api.Host, minI
 		contractPrice = scan.V2Settings.Prices.ContractPrice
 		collateral = scan.V2Settings.Prices.Collateral
 		maxCollateral = scan.V2Settings.MaxCollateral
+		if contractPrice.IsZero() {
+			fmt.Println("contractprice2", contractPrice, scan.V2Settings)
+		}
 	} else {
 		contractPrice = scan.Settings.ContractPrice
 		collateral = scan.Settings.Collateral
 		maxCollateral = scan.Settings.MaxCollateral
+		if contractPrice.IsZero() {
+			fmt.Println("contractprice1", contractPrice, scan.Settings)
+		}
 	}
 
 	// check our budget
@@ -203,12 +209,14 @@ func (c *Contractor) formContract(ctx *mCtx, hs HostScanner, host api.Host, minI
 	hostCollateral := collateral.Mul64(expectedStorage).Mul64(ctx.Period())
 	if hostCollateral.Cmp(maxCollateral) > 0 {
 		hostCollateral = maxCollateral
+		fmt.Println("set to max", maxCollateral)
 	}
 
 	// shouldn't go below the minimum immediately so we add some buffer
 	minCollateral := MinCollateral.Mul64(2).Add(contractPrice)
 	if hostCollateral.Cmp(minCollateral) < 0 {
 		hostCollateral = minCollateral
+		fmt.Println("set to min", minCollateral, contractPrice, scan.V2Settings.Prices.ContractPrice, scan.Settings.ContractPrice)
 	}
 
 	// form contract
@@ -217,6 +225,7 @@ func (c *Contractor) formContract(ctx *mCtx, hs HostScanner, host api.Host, minI
 		logger.Errorw(fmt.Sprintf("contract formation failed, err: %v", err), "hk", hk)
 		return api.ContractMetadata{}, !utils.IsErr(err, wallet.ErrNotEnoughFunds), err
 	}
+	fmt.Printf("formed contract %v: contract price %v, hostcollateral %v, collateral %v\n", contract.ID, contract.ContractPrice, hostCollateral, collateral)
 
 	logger.Infow("formation succeeded",
 		"fcid", contract.ID,

autopilot/contractor/hostfilter.go

@@ -103,18 +103,21 @@ func (c *Contractor) isUsableContract(cfg api.AutopilotConfig, contract contract
 		renew = false
 	} else {
 		if contract.IsOutOfCollateral() {
+			fmt.Printf("%v should refresh (ooc): remaining: %v - %v, min: %v\n", contract.ID, MinCollateral, contract.Revision.MissedHostValue, contract.ContractPrice)
 			reasons = append(reasons, errContractOutOfCollateral.Error())
 			usable = usable && contract.IsGood() && c.shouldForgiveFailedRefresh(contract.ID)
 			refresh = true
 			renew = false
 		}
 		if contract.IsOutOfFunds() {
+			fmt.Printf("%v should refresh (oof)\n", contract.ID)
 			reasons = append(reasons, errContractOutOfFunds.Error())
 			usable = usable && contract.IsGood() && c.shouldForgiveFailedRefresh(contract.ID)
 			refresh = true
 			renew = false
 		}
 		if shouldRenew, secondHalf := isUpForRenewal(cfg, contract.EndHeight(), bh); shouldRenew {
+			fmt.Printf("%v should renew bh: %v, eh: %v, renewWindow: %v\n", contract.ID, bh, contract.EndHeight(), cfg.Contracts.RenewWindow)
 			reasons = append(reasons, fmt.Errorf("%w; second half: %t", errContractUpForRenewal, secondHalf).Error())
 			usable = usable && !secondHalf // only unusable if in second half of renew window
 			refresh = false

internal/test/e2e/cluster_test.go

@@ -3048,7 +3048,12 @@ func TestV1ToV2Transition(t *testing.T) {
 		archivedContracts, err = cluster.Bus.Contracts(context.Background(), api.ContractsOpts{FilterMode: api.ContractFilterModeArchived})
 		tt.OK(err)
 		if len(archivedContracts) != nHosts-1 {
-			return fmt.Errorf("expected %v archived contracts, got %v", nHosts-1, len(archivedContracts))
+			var info string
+			all, _ := cluster.Bus.Contracts(context.Background(), api.ContractsOpts{FilterMode: api.ContractFilterModeAll})
+			for _, c := range all {
+				info += fmt.Sprintf("%v: %v -> %v -> %v (%v)\n", c.HostKey, c.RenewedFrom, c.ID, c.RenewedTo, c.ArchivalReason)
+			}
+			return fmt.Errorf("expected %v archived contracts, got %v \n %s", nHosts-1, len(archivedContracts), info)
 		}
 		return nil
 	})