diff options
author | John Jannotti <jannotti@gmail.com> | 2024-01-17 14:20:29 -0500 |
---|---|---|
committer | GitHub <noreply@github.com> | 2024-01-17 14:20:29 -0500 |
commit | 434dca0f02d48d30af1d42eb223039d9e16f0bab (patch) | |
tree | 9356f44935c7c5a72305dbf7fa559e4e14edef39 | |
parent | 5e5c16a7b4e6c40c9e57dcce65b51118755592ba (diff) |
AVM: report structure txn failure info (#5875)
-rw-r--r-- | daemon/algod/api/client/restClient.go | 24 | ||||
-rw-r--r-- | daemon/algod/api/server/v2/utils.go | 8 | ||||
-rw-r--r-- | data/basics/serr.go | 132 | ||||
-rw-r--r-- | data/basics/serr_test.go | 135 | ||||
-rw-r--r-- | data/transactions/logic/eval.go | 131 | ||||
-rw-r--r-- | data/transactions/logic/evalAppTxn_test.go | 4 | ||||
-rw-r--r-- | data/transactions/logic/evalStateful_test.go | 222 | ||||
-rw-r--r-- | data/transactions/logic/eval_test.go | 130 | ||||
-rw-r--r-- | data/transactions/logic/export_test.go | 2 | ||||
-rw-r--r-- | data/transactions/logic/ledger_test.go | 2 | ||||
-rw-r--r-- | data/transactions/logic/resources_test.go | 2 | ||||
-rw-r--r-- | ledger/simulation/simulation_eval_test.go | 2 | ||||
-rwxr-xr-x[-rw-r--r--] | test/e2e-go/cli/goal/expect/goalAppAccountAddressTest.exp | 0 | ||||
-rw-r--r--[-rwxr-xr-x] | test/e2e-go/cli/goal/expect/statefulTealCreateAppTest.exp | 0 | ||||
-rw-r--r--[-rwxr-xr-x] | test/e2e-go/cli/goal/expect/tealConsensusTest.exp | 0 | ||||
-rw-r--r-- | test/e2e-go/restAPI/other/appsRestAPI_test.go | 14 | ||||
-rwxr-xr-x | test/scripts/e2e_subs/avm-failure-info.py | 78 | ||||
-rwxr-xr-x | test/scripts/e2e_subs/goal/goal.py | 13 |
18 files changed, 758 insertions, 141 deletions
diff --git a/daemon/algod/api/client/restClient.go b/daemon/algod/api/client/restClient.go index cf25773fd..f6494fa38 100644 --- a/daemon/algod/api/client/restClient.go +++ b/daemon/algod/api/client/restClient.go @@ -72,6 +72,7 @@ type HTTPError struct { StatusCode int Status string ErrorString string + Data map[string]any } // Error formats an error string. @@ -120,24 +121,11 @@ func extractError(resp *http.Response) error { decodeErr := json.Unmarshal(errorBuf, &errorJSON) var errorString string + var data map[string]any if decodeErr == nil { - if errorJSON.Data == nil { - // There's no additional data, so let's just use the message - errorString = errorJSON.Message - } else { - // There's additional data, so let's re-encode the JSON response to show everything. - // We do this because the original response is likely encoded with escapeHTML=true, but - // since this isn't a webpage that extra encoding is not preferred. - var buffer strings.Builder - enc := json.NewEncoder(&buffer) - enc.SetEscapeHTML(false) - encErr := enc.Encode(errorJSON) - if encErr != nil { - // This really shouldn't happen, but if it does let's default to errorBuff - errorString = string(errorBuf) - } else { - errorString = buffer.String() - } + errorString = errorJSON.Message + if errorJSON.Data != nil { + data = *errorJSON.Data } } else { errorString = string(errorBuf) @@ -149,7 +137,7 @@ func extractError(resp *http.Response) error { return unauthorizedRequestError{errorString, apiToken, resp.Request.URL.String()} } - return HTTPError{StatusCode: resp.StatusCode, Status: resp.Status, ErrorString: errorString} + return HTTPError{StatusCode: resp.StatusCode, Status: resp.Status, ErrorString: errorString, Data: data} } // stripTransaction gets a transaction of the form "tx-XXXXXXXX" and truncates the "tx-" part, if it starts with "tx-" diff --git a/daemon/algod/api/server/v2/utils.go b/daemon/algod/api/server/v2/utils.go index a16b11031..ee306a62b 100644 --- a/daemon/algod/api/server/v2/utils.go +++ b/daemon/algod/api/server/v2/utils.go @@ -18,6 +18,7 @@ package v2 import ( "encoding/base64" + "errors" "fmt" "net/http" "strings" @@ -44,7 +45,12 @@ import ( // returnError logs an internal message while returning the encoded response. func returnError(ctx echo.Context, code int, internal error, external string, logger logging.Logger) error { logger.Info(internal) - return ctx.JSON(code, model.ErrorResponse{Message: external}) + var data *map[string]any + var se *basics.SError + if errors.As(internal, &se) { + data = &se.Attrs + } + return ctx.JSON(code, model.ErrorResponse{Message: external, Data: data}) } func badRequest(ctx echo.Context, internal error, external string, log logging.Logger) error { diff --git a/data/basics/serr.go b/data/basics/serr.go new file mode 100644 index 000000000..229d800d7 --- /dev/null +++ b/data/basics/serr.go @@ -0,0 +1,132 @@ +// Copyright (C) 2019-2024 Algorand, Inc. +// This file is part of go-algorand +// +// go-algorand is free software: you can redistribute it and/or modify +// it under the terms of the GNU Affero General Public License as +// published by the Free Software Foundation, either version 3 of the +// License, or (at your option) any later version. +// +// go-algorand is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU Affero General Public License for more details. +// +// You should have received a copy of the GNU Affero General Public License +// along with go-algorand. If not, see <https://www.gnu.org/licenses/>. + +package basics + +import ( + "errors" + "strings" + + "golang.org/x/exp/slog" +) + +// SError is a structured error object. It contains a message and an arbitrary +// set of attributes. If the message contains "%A", it will be replaced by the +// attributes (in no guaranteed order), when SError() is called. +// +//msgp:ignore SError +type SError struct { + Msg string + Attrs map[string]any + Wrapped error +} + +// New creates a new structured error object using the supplied message and +// attributes. If the message contains "%A", it will be replaced by the +// attributes when Error() is called. +func New(msg string, pairs ...any) *SError { + attrs := make(map[string]any, len(pairs)/2) + for i := 0; i < len(pairs); i += 2 { + attrs[pairs[i].(string)] = pairs[i+1] + } + return &SError{Msg: msg, Attrs: attrs} +} + +// Error returns either the exact supplied message, or the serialized attributes if +// the supplied message was blank, or substituted for %A. +func (e *SError) Error() string { + if e.Msg == "" { + return e.AttributesAsString() + } + // imperfect because we replace \%A as well + if strings.Contains(e.Msg, "%A") { + return strings.Replace(e.Msg, "%A", e.AttributesAsString(), -1) + } + return e.Msg +} + +// AttributesAsString returns the attributes the same way that slog serializes +// attributes to text in a log message, in no guaranteed order. +func (e *SError) AttributesAsString() string { + var buf strings.Builder + args := make([]any, 0, 2*len(e.Attrs)) + for key, val := range e.Attrs { + args = append(args, key) + args = append(args, val) + } + l := slog.New(slog.NewTextHandler(&buf, nil)) + l.Info("", args...) + return strings.TrimSuffix(strings.SplitN(buf.String(), " ", 4)[3], "\n") +} + +// Annotate adds additional attributes to an existing error, even if the error +// is deep in the error chain. If the supplied error is nil, nil is returned so +// that callers can annotate errors without checking if they are non-nil. If +// the error is not a structured error, it is wrapped in one using its existing +// message and the new attributes. Just like append() for slices, callers should +// re-assign, like this `err = serr.Annotate(err, "x", 100)` +func Annotate(err error, pairs ...any) error { + if err == nil { + return nil + } + var serr *SError + if ok := errors.As(err, &serr); ok { + for i := 0; i < len(pairs); i += 2 { + serr.Attrs[pairs[i].(string)] = pairs[i+1] + } + return err + } + // Since we don't have a structured error, we wrap the existing error in one. + serr = New(err.Error(), pairs...) + serr.Wrapped = err + return serr +} + +// Wrap is used to "demote" an existing error to a field in a new structured +// error. The wrapped error message is added as $field-msg, and if the error is +// structured, the attributes are added under $field-attrs. +func Wrap(err error, msg string, field string, pairs ...any) error { + serr := New(msg, field+"-msg", err.Error()) + for i := 0; i < len(pairs); i += 2 { + serr.Attrs[pairs[i].(string)] = pairs[i+1] + } + serr.Wrapped = err + + var inner *SError + if ok := errors.As(err, &inner); ok { + attributes := make(map[string]any, len(inner.Attrs)) + for key, val := range inner.Attrs { + attributes[key] = val + } + serr.Attrs[field+"-attrs"] = attributes + } + + return serr +} + +// Unwrap returns the inner error, if it exists. +func (e *SError) Unwrap() error { + return e.Wrapped +} + +// Attributes returns the attributes of a structured error, or nil/empty. +func Attributes(err error) map[string]any { + var se *SError + if errors.As(err, &se) { + return se.Attrs + } + return nil +} diff --git a/data/basics/serr_test.go b/data/basics/serr_test.go new file mode 100644 index 000000000..4df6e2048 --- /dev/null +++ b/data/basics/serr_test.go @@ -0,0 +1,135 @@ +// Copyright (C) 2019-2024 Algorand, Inc. +// This file is part of go-algorand +// +// go-algorand is free software: you can redistribute it and/or modify +// it under the terms of the GNU Affero General Public License as +// published by the Free Software Foundation, either version 3 of the +// License, or (at your option) any later version. +// +// go-algorand is distributed in the hope that it will be useful, +// but WITHOUT ANY WARRANTY; without even the implied warranty of +// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +// GNU Affero General Public License for more details. +// +// You should have received a copy of the GNU Affero General Public License +// along with go-algorand. If not, see <https://www.gnu.org/licenses/>. + +package basics + +import ( + "errors" + "fmt" + "testing" + + "github.com/algorand/go-algorand/test/partitiontest" + "github.com/stretchr/testify/assert" +) + +func TestNew(t *testing.T) { + partitiontest.PartitionTest(t) + t.Parallel() + + err := New("test") + assert.Equal(t, "test", err.Error()) +} + +func TestNewWithPairs(t *testing.T) { + partitiontest.PartitionTest(t) + t.Parallel() + + err := New("test", "a", 7, "b", []byte{3, 4}) + assert.Equal(t, "test", err.Error()) + assert.Equal(t, 7, err.Attrs["a"]) + assert.Equal(t, []byte{3, 4}, err.Attrs["b"]) + + err.Msg = "" + assert.ErrorContains(t, err, `a=7`) + assert.ErrorContains(t, err, `b="\x03\x04"`) + + err.Msg = "check it: %A" + assert.ErrorContains(t, err, ` a=7`) + assert.ErrorContains(t, err, ` b="\x03\x04"`) + assert.Equal(t, `check it: `, err.Error()[:10]) + +} + +func TestAnnotate(t *testing.T) { + partitiontest.PartitionTest(t) + t.Parallel() + + err := New("test", "a", 7, "b", []byte{3, 4}) + assert.Equal(t, 7, err.Attrs["a"]) + assert.Equal(t, nil, err.Attrs["c"]) + Annotate(err, "c", true, "a", false) + assert.Equal(t, true, err.Attrs["c"]) + assert.Equal(t, false, err.Attrs["a"]) +} + +func attribute(err error, name string) any { + var serr *SError + if ok := errors.As(err, &serr); ok { + return serr.Attrs[name] + } + return nil +} + +func TestAnnotateUnstructured(t *testing.T) { + partitiontest.PartitionTest(t) + t.Parallel() + + err := errors.New("hello") + err = Annotate(err, "c", true, "a", false) + assert.Equal(t, true, attribute(err, "c")) +} + +func TestReannotateEmbedded(t *testing.T) { + partitiontest.PartitionTest(t) + t.Parallel() + + var err error + err = New("test", "a", 7, "b", []byte{3, 4}) + err = fmt.Errorf("embed the above here %w", err) + assert.Equal(t, 7, attribute(err, "a")) + assert.Equal(t, nil, attribute(err, "c")) + Annotate(err, "c", true, "a", false) + assert.Equal(t, true, attribute(err, "c")) + assert.Equal(t, false, attribute(err, "a")) + // "b" is still visible. It would not be is we had _wrapped_ the fmt.Error + assert.Equal(t, []byte{3, 4}, attribute(err, "b")) +} + +func TestWrapBare(t *testing.T) { + partitiontest.PartitionTest(t) + t.Parallel() + + var err error + err = errors.New("inner thingy") + err = Wrap(err, "outer stuff", "xxx") + assert.Equal(t, "inner thingy", attribute(err, "xxx-msg")) + assert.Equal(t, nil, attribute(err, "xxx-attrs")) +} + +func TestWrapStructured(t *testing.T) { + partitiontest.PartitionTest(t) + t.Parallel() + + var err error + err = New("test", "a", 7, "b", []byte{3, 4}) + err = Wrap(err, "outer stuff", "yyy") + assert.Equal(t, "test", attribute(err, "yyy-msg")) + assert.NotNil(t, attribute(err, "yyy-attrs")) + + // these are deeper now, not here + assert.Equal(t, nil, attribute(err, "a")) + assert.Equal(t, nil, attribute(err, "b")) + + // here they are + attrs := attribute(err, "yyy-attrs").(map[string]any) + assert.Equal(t, 7, attrs["a"]) + assert.Equal(t, []byte{3, 4}, attrs["b"]) + + // deeper, with a new attribute + err = Wrap(err, "further out", "again", "name", "jj") + assert.Nil(t, attribute(err, "yyy-msg")) + assert.Equal(t, "outer stuff", attribute(err, "again-msg")) +} diff --git a/data/transactions/logic/eval.go b/data/transactions/logic/eval.go index fe102086a..bd56b9b01 100644 --- a/data/transactions/logic/eval.go +++ b/data/transactions/logic/eval.go @@ -66,6 +66,11 @@ var maxAppCallDepth = 8 // maxStackDepth should not change unless controlled by an AVM version change const maxStackDepth = 1000 +// maxTxGroupSize is the same as config.MaxTxGroupSize, but is a constant so +// that we can declare an array of this size. A unit test confirms that they +// match. +const maxTxGroupSize = 16 + // stackValue is the type for the operand stack. // Each stackValue is either a valid []byte value or a uint64 value. // If (.Bytes != nil) the stackValue is a []byte value, otherwise uint64 value. @@ -102,6 +107,17 @@ func (sv stackValue) String() string { return fmt.Sprintf("%d 0x%x", sv.Uint, sv.Uint) } +func (sv stackValue) asAny() any { + if sv.Bytes != nil { + return sv.Bytes + } + return sv.Uint +} + +func (sv stackValue) isEmpty() bool { + return sv.Bytes == nil && sv.Uint == 0 +} + func (sv stackValue) address() (addr basics.Address, err error) { if len(sv.Bytes) != len(addr) { return basics.Address{}, errors.New("not an address") @@ -301,7 +317,7 @@ type EvalParams struct { TxnGroup []transactions.SignedTxnWithAD - pastScratch []*scratchSpace + pastScratch [maxTxGroupSize]*scratchSpace logger logging.Logger @@ -457,7 +473,6 @@ func NewAppEvalParams(txgroup []transactions.SignedTxnWithAD, proto *config.Cons TxnGroup: copyWithClearAD(txgroup), Proto: proto, Specials: specials, - pastScratch: make([]*scratchSpace, len(txgroup)), minAvmVersion: computeMinAvmVersion(txgroup), FeeCredit: credit, PooledApplicationBudget: pooledApplicationBudget, @@ -525,7 +540,6 @@ func NewInnerEvalParams(txg []transactions.SignedTxnWithAD, caller *EvalContext) Proto: caller.Proto, Trace: caller.Trace, TxnGroup: txg, - pastScratch: make([]*scratchSpace, len(txg)), logger: caller.logger, SigLedger: caller.SigLedger, Ledger: caller.Ledger, @@ -968,10 +982,9 @@ var errTooManyArgs = errors.New("LogicSig has too many arguments") // EvalError indicates AVM evaluation failure type EvalError struct { - Err error - details string - groupIndex int - logicsig bool + Err error + details string + logicsig bool } // Error satisfies builtin interface `error` @@ -992,6 +1005,78 @@ func (err EvalError) Unwrap() error { return err.Err } +func (cx *EvalContext) evalError(err error) error { + pc, det := cx.pcDetails() + details := fmt.Sprintf("pc=%d, opcodes=%s", pc, det) + + err = basics.Annotate(err, + "pc", pc, + "group-index", cx.groupIndex, + "eval-states", cx.evalStates()) + if cx.runMode == ModeApp { + details = fmt.Sprintf("app=%d, %s", cx.appID, details) + err = basics.Annotate(err, "app-index", cx.appID) + } + + return EvalError{err, details, cx.runMode == ModeSig} +} + +type evalState struct { + Scratch []any `json:"scratch,omitempty"` + Stack []any `json:"stack,omitempty"` + Logs [][]byte `json:"logs,omitempty"` +} + +func (cx *EvalContext) evalStates() []evalState { + states := make([]evalState, cx.groupIndex+1) + for i := 0; i <= cx.groupIndex; i++ { + var scratch []stackValue + if cx.pastScratch[i] != nil { + scratch = (*cx.pastScratch[i])[:] + } + lastNonZero := -1 + scratchAsAny := make([]any, len(scratch)) + for s, sv := range scratch { + if !sv.isEmpty() { + lastNonZero = s + } + scratchAsAny[s] = sv.asAny() + } + if lastNonZero == -1 { + scratchAsAny = nil + } else { + scratchAsAny = scratchAsAny[:lastNonZero+1] + } + + // Only the current program's stack is still available. So perhaps it + // should be located outside of the evalState, with the PC. + var stack []any + if cx.groupIndex == i { + stack = convertSlice(cx.Stack, func(sv stackValue) any { + return sv.asAny() + }) + } + + states[i] = evalState{ + Scratch: scratchAsAny, + Stack: stack, + Logs: convertSlice(cx.TxnGroup[i].EvalDelta.Logs, func(s string) []byte { return []byte(s) }), + } + } + return states +} + +func convertSlice[X any, Y any](input []X, fn func(X) Y) []Y { + if input == nil { + return nil + } + output := make([]Y, len(input)) + for i := range input { + output[i] = fn(input[i]) + } + return output +} + // EvalContract executes stateful program as the gi'th transaction in params func EvalContract(program []byte, gi int, aid basics.AppIndex, params *EvalParams) (bool, *EvalContext, error) { if params.Ledger == nil { @@ -1013,6 +1098,10 @@ func EvalContract(program []byte, gi int, aid basics.AppIndex, params *EvalParam txn: ¶ms.TxnGroup[gi], appID: aid, } + // Save scratch for `gload`. We used to copy, but cx.scratch is quite large, + // about 8k, and caused measurable CPU and memory demands. Of course, these + // should never be changed by later transactions. + cx.pastScratch[cx.groupIndex] = &cx.Scratch if cx.Proto.IsolateClearState && cx.txn.Txn.OnCompletion == transactions.ClearStateOC { if cx.PooledApplicationBudget != nil && *cx.PooledApplicationBudget < cx.Proto.MaxAppProgramCost { @@ -1070,7 +1159,13 @@ func EvalContract(program []byte, gi int, aid basics.AppIndex, params *EvalParam if used > cx.ioBudget { err = fmt.Errorf("box read budget (%d) exceeded", cx.ioBudget) if !cx.Proto.EnableBareBudgetError { - err = EvalError{err, "", gi, false} + // We return an EvalError here because we used to do + // that. It is wrong, and means that there could be a + // ClearState call in an old block that failed on read + // quota, but we allowed to execute anyway. If testnet and + // mainnet have no such transactions, we can remove + // EnableBareBudgetError and this code. + err = EvalError{err, "", false} } return false, nil, err } @@ -1084,20 +1179,13 @@ func EvalContract(program []byte, gi int, aid basics.AppIndex, params *EvalParam } pass, err := eval(program, &cx) if err != nil { - pc, det := cx.pcDetails() - details := fmt.Sprintf("pc=%d, opcodes=%s", pc, det) - err = EvalError{err, details, gi, false} + err = cx.evalError(err) } if cx.Trace != nil && cx.caller != nil { fmt.Fprintf(cx.Trace, "--- exit %d accept=%t\n", aid, pass) } - // Save scratch for `gload`. We used to copy, but cx.scratch is quite large, - // about 8k, and caused measurable CPU and memory demands. Of course, these - // should never be changed by later transactions. - cx.pastScratch[cx.groupIndex] = &cx.Scratch - return pass, &cx, err } @@ -1123,12 +1211,15 @@ func EvalSignatureFull(gi int, params *EvalParams) (bool, *EvalContext, error) { groupIndex: gi, txn: ¶ms.TxnGroup[gi], } + // Save scratch. `gload*` opcodes are not currently allowed in ModeSig + // (though it seems we could allow them, with access to LogicSig scratch + // values). But error returns and potentially debug code might like to + // return them. + cx.pastScratch[cx.groupIndex] = &cx.Scratch pass, err := eval(cx.txn.Lsig.Logic, &cx) if err != nil { - pc, det := cx.pcDetails() - details := fmt.Sprintf("pc=%d, opcodes=%s", pc, det) - err = EvalError{err, details, gi, true} + err = cx.evalError(err) } return pass, &cx, err @@ -5539,7 +5630,7 @@ func opItxnSubmit(cx *EvalContext) (err error) { } if err != nil { - return err + return basics.Wrap(err, fmt.Sprintf("inner tx %d failed: %s", i, err.Error()), "inner") } // This is mostly a no-op, because Perform does its work "in-place", but diff --git a/data/transactions/logic/evalAppTxn_test.go b/data/transactions/logic/evalAppTxn_test.go index 21ce259a7..9a6d0ebc4 100644 --- a/data/transactions/logic/evalAppTxn_test.go +++ b/data/transactions/logic/evalAppTxn_test.go @@ -2006,7 +2006,7 @@ int 1 ledger.NewApp(parentTx.Receiver, parentAppID, basics.AppParams{}) ledger.NewAccount(parentAppID.Address(), 50_000) - parentEd := TestApp(t, parentSource, ep) + parentEd, _ := TestApp(t, parentSource, ep) require.Len(t, parentEd.Logs, 2) require.Len(t, parentEd.InnerTxns, 2) @@ -2334,7 +2334,7 @@ int 1 ledger.NewApp(parentTx.Receiver, parentAppID, basics.AppParams{}) ledger.NewAccount(parentAppID.Address(), 50_000) - parentEd := TestApp(t, parentSource, ep) + parentEd, _ := TestApp(t, parentSource, ep) require.Len(t, parentEd.Logs, 2) require.Len(t, parentEd.InnerTxns, 2) diff --git a/data/transactions/logic/evalStateful_test.go b/data/transactions/logic/evalStateful_test.go index fe30d2594..12d1b8c28 100644 --- a/data/transactions/logic/evalStateful_test.go +++ b/data/transactions/logic/evalStateful_test.go @@ -422,7 +422,7 @@ func TestBalance(t *testing.T) { } func testApps(t *testing.T, programs []string, txgroup []transactions.SignedTxn, opt protoOpt, ledger *Ledger, - expected ...expect) *EvalParams { + expected ...expect) (*EvalParams, error) { t.Helper() proto := makeTestProto(opt) codes := make([][]byte, len(programs)) @@ -447,11 +447,10 @@ func testApps(t *testing.T, programs []string, txgroup []transactions.SignedTxn, ledger.Reset() ep.Ledger = ledger ep.SigLedger = ledger - testAppsBytes(t, codes, ep, expected...) - return ep + return ep, testAppsBytes(t, codes, ep, expected...) } -func testAppsBytes(t *testing.T, programs [][]byte, ep *EvalParams, expected ...expect) { +func testAppsBytes(t *testing.T, programs [][]byte, ep *EvalParams, expected ...expect) error { t.Helper() require.LessOrEqual(t, len(programs), len(ep.TxnGroup)) for i := range ep.TxnGroup { @@ -465,20 +464,21 @@ func testAppsBytes(t *testing.T, programs [][]byte, ep *EvalParams, expected ... appID = basics.AppIndex(888) } if len(expected) > 0 && expected[0].l == i { - testAppFull(t, program, i, appID, ep, expected[0].s) - break // Stop after first failure - } else { - testAppFull(t, program, i, appID, ep) + // Stop after first failure + _, err := testAppFull(t, program, i, appID, ep, expected[0].s) + return err } + testAppFull(t, program, i, appID, ep) } else { if len(expected) > 0 && expected[0].l == i { require.Failf(t, "testAppsBytes used incorrectly.", "No error can happen in txn %d. Not an app.", i) } } } + return nil } -func testApp(t *testing.T, program string, ep *EvalParams, problems ...string) transactions.EvalDelta { +func testApp(t *testing.T, program string, ep *EvalParams, problems ...string) (transactions.EvalDelta, error) { t.Helper() if ep == nil { ep = defaultAppParamsWithVersion(LogicVersion) @@ -487,7 +487,7 @@ func testApp(t *testing.T, program string, ep *EvalParams, problems ...string) t return testAppBytes(t, ops.Program, ep, problems...) } -func testAppBytes(t *testing.T, program []byte, ep *EvalParams, problems ...string) transactions.EvalDelta { +func testAppBytes(t *testing.T, program []byte, ep *EvalParams, problems ...string) (transactions.EvalDelta, error) { t.Helper() if ep == nil { ep = defaultAppParamsWithVersion(LogicVersion) @@ -505,7 +505,7 @@ func testAppBytes(t *testing.T, program []byte, ep *EvalParams, problems ...stri // ep.reset() is in testAppBytes, not here. This means that ADs in the ep are // not cleared, so repeated use of a single ep is probably not a good idea // unless you are *intending* to see how ep is modified as you go. -func testAppFull(t *testing.T, program []byte, gi int, aid basics.AppIndex, ep *EvalParams, problems ...string) transactions.EvalDelta { +func testAppFull(t *testing.T, program []byte, gi int, aid basics.AppIndex, ep *EvalParams, problems ...string) (transactions.EvalDelta, error) { t.Helper() var checkProblem string @@ -545,7 +545,7 @@ func testAppFull(t *testing.T, program []byte, gi int, aid basics.AppIndex, ep * if evalProblem == "" { require.NoError(t, err, "Eval\n%sExpected: PASS", ep.Trace) require.True(t, pass, "Eval\n%sExpected: PASS", ep.Trace) - return delta + return delta, nil } // There is an evalProblem to check. REJECT is special and only means that @@ -555,7 +555,7 @@ func testAppFull(t *testing.T, program []byte, gi int, aid basics.AppIndex, ep * } else { require.ErrorContains(t, err, evalProblem, "Wrong error in EvalContract %v", ep.Trace) } - return delta + return delta, err } // testLogicRange allows for running tests against a range of avm @@ -819,6 +819,122 @@ int 0 testApp(t, text, now) } +// TestAppErrorDetails confirms that the error returned from app failures +// has the right structured information. +func TestAppErrorDetails(t *testing.T) { + partitiontest.PartitionTest(t) + t.Parallel() + + badsource := notrack(` +byte 0x04040004; log // log +int 5; store 10 // store an int +byte 0x01020300; store 15 // store a bytes + +int 100; byte 0x0201; == // types mismatch so this will fail +`) + _, err := testApp(t, badsource, nil, "cannot compare") + attrs := basics.Attributes(err) + zeros := [256]int{} + scratch := convertSlice(zeros[:], func(i int) any { return uint64(i) }) + scratch[10] = uint64(5) + scratch[15] = []byte{0x01, 0x02, 0x03, 0x00} + require.Equal(t, map[string]any{ + "pc": 26, + "group-index": 0, + "app-index": basics.AppIndex(888), + "eval-states": []evalState{ + { + Logs: [][]byte{{0x04, 0x04, 0x00, 0x04}}, + Stack: []any{uint64(100), []byte{02, 01}}, + Scratch: scratch[:16], + }, + }, + }, attrs) + + goodsource := ` +byte 0x04040104; log // log +byte 0x04040204; log // log + +int 4; store 2 // store an int +byte "jj"; store 3 // store a bytes +int 1 +` + gscratch := convertSlice(zeros[:], func(i int) any { return uint64(i) }) + gscratch[2] = uint64(4) + gscratch[3] = []byte("jj") + + _, err = testApps(t, []string{goodsource, badsource}, nil, nil, nil, exp(1, "cannot compare")) + attrs = basics.Attributes(err) + require.Equal(t, map[string]any{ + "pc": 26, + "group-index": 1, + "app-index": basics.AppIndex(888), + "eval-states": []evalState{ + { + Logs: [][]byte{ + {0x04, 0x04, 0x01, 0x04}, + {0x04, 0x04, 0x02, 0x04}, + }, + Scratch: gscratch[:4], + }, + { + Logs: [][]byte{{0x04, 0x04, 0x00, 0x04}}, + Stack: []any{uint64(100), []byte{02, 01}}, + Scratch: scratch[:16], + }, + }, + }, attrs) + + _, _, ledger := makeSampleEnv() + ledger.NewAccount(appAddr(888), 100_000) + bad := testProg(t, badsource, 5) + innerFailSource := ` +int 777 +itxn_begin +int appl; itxn_field TypeEnum +byte 0x` + hex.EncodeToString(bad.Program) + ` // run the bad program by trying to create it +itxn_field ApprovalProgram + +byte 0x05 +itxn_field ClearStateProgram + +itxn_submit +` + _, err = testApps(t, []string{goodsource, innerFailSource}, nil, nil, ledger, exp(1, "inner tx 0 failed")) + attrs = basics.Attributes(err) + require.Equal(t, map[string]any{ + "pc": 45, + "group-index": 1, + "app-index": basics.AppIndex(888), + "eval-states": []evalState{ + { + Logs: [][]byte{ + {0x04, 0x04, 0x01, 0x04}, + {0x04, 0x04, 0x02, 0x04}, + }, + Scratch: gscratch[:4], + }, + { + Stack: []any{uint64(777)}, + }, + }, + "inner-msg": "logic eval error: cannot compare (uint64 to []byte). Details: app=5000, pc=26, opcodes=pushint 100; pushbytes 0x0201 // 0x0201; ==", + "inner-attrs": map[string]any{ + "pc": 26, + "group-index": 0, + "app-index": basics.AppIndex(firstTestID), + "eval-states": []evalState{ + { + Logs: [][]byte{{0x04, 0x04, 0x00, 0x04}}, + Stack: []any{uint64(100), []byte{02, 01}}, + Scratch: scratch[:16], + }, + }, + }, + }, attrs) + +} + func TestAppReadGlobalState(t *testing.T) { partitiontest.PartitionTest(t) t.Parallel() @@ -1493,7 +1609,7 @@ func TestGlobalNonDelete(t *testing.T) { testLogicRange(t, 2, 0, func(t *testing.T, ep *EvalParams, txn *transactions.Transaction, ledger *Ledger) { source := `byte "none"; app_global_del; int 1` ledger.NewApp(txn.Sender, 888, makeApp(0, 0, 1, 0)) - delta := testApp(t, source, ep) + delta, _ := testApp(t, source, ep) require.Empty(t, delta.GlobalDelta) require.Empty(t, delta.LocalDeltas) }) @@ -1509,7 +1625,7 @@ func TestLocalNonDelete(t *testing.T) { ledger.NewAccount(txn.Sender, 100000) ledger.NewApp(txn.Sender, 888, makeApp(0, 0, 1, 0)) ledger.NewLocals(txn.Sender, 888) - delta := testApp(t, source, ep) + delta, _ := testApp(t, source, ep) require.Empty(t, delta.GlobalDelta) require.Empty(t, delta.LocalDeltas) }) @@ -1660,7 +1776,7 @@ int 0x77 if ep.Proto.LogicSigVersion < directRefEnabledVersion { source = strings.ReplaceAll(source, "txn Sender", "int 0") } - delta := testApp(t, source, ep) + delta, _ := testApp(t, source, ep) require.Empty(t, delta.GlobalDelta) require.Len(t, delta.LocalDeltas, 1) @@ -1698,7 +1814,7 @@ int 0x77 algoValue := basics.TealValue{Type: basics.TealUintType, Uint: 0x77} ledger.NewLocal(txn.Sender, 100, "ALGO", algoValue) - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Empty(t, delta.GlobalDelta) require.Empty(t, delta.LocalDeltas) @@ -1730,7 +1846,7 @@ exist2: if ep.Proto.LogicSigVersion < directRefEnabledVersion { source = strings.ReplaceAll(source, "txn Sender", "int 0") } - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Empty(t, delta.GlobalDelta) require.Empty(t, delta.LocalDeltas) @@ -1748,7 +1864,7 @@ int 1 if ep.Proto.LogicSigVersion < directRefEnabledVersion { source = strings.ReplaceAll(source, "txn Sender", "int 0") } - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Empty(t, delta.GlobalDelta) require.Len(t, delta.LocalDeltas, 1) require.Len(t, delta.LocalDeltas[0], 1) @@ -1778,7 +1894,7 @@ int 0x78 if ep.Proto.LogicSigVersion < directRefEnabledVersion { source = strings.ReplaceAll(source, "txn Sender", "int 0") } - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Empty(t, delta.GlobalDelta) require.Len(t, delta.LocalDeltas, 1) require.Len(t, delta.LocalDeltas[0], 1) @@ -1806,7 +1922,7 @@ app_local_put if ep.Proto.LogicSigVersion < directRefEnabledVersion { source = strings.ReplaceAll(source, "txn Sender", "int 0") } - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Empty(t, delta.GlobalDelta) require.Len(t, delta.LocalDeltas, 1) require.Len(t, delta.LocalDeltas[0], 1) @@ -1844,7 +1960,7 @@ int 1 source = strings.ReplaceAll(source, "txn Sender", "int 0") source = strings.ReplaceAll(source, "txn Accounts 1", "int 1") } - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Empty(t, delta.GlobalDelta) require.Len(t, delta.LocalDeltas, 2) require.Len(t, delta.LocalDeltas[0], 2) @@ -1934,7 +2050,7 @@ int 0x77 ledger.Reset() - delta := testAppBytes(t, ops.Program, ep) + delta, _ := testAppBytes(t, ops.Program, ep) require.Empty(t, delta.LocalDeltas) } }) @@ -2023,7 +2139,7 @@ int 0x77 } source = strings.ReplaceAll(source, "THISAPP", "int 100") } - delta := testApp(t, source, ep) + delta, _ := testApp(t, source, ep) require.Len(t, delta.GlobalDelta, 2) require.Empty(t, delta.LocalDeltas) @@ -2052,7 +2168,7 @@ int 0x77 algoValue := basics.TealValue{Type: basics.TealUintType, Uint: 0x77} ledger.NewGlobal(100, "ALGO", algoValue) - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Empty(t, delta.GlobalDelta) require.Empty(t, delta.LocalDeltas) @@ -2076,7 +2192,7 @@ int 0x77 ledger.NoGlobal(100, "ALGOA") ledger.NewGlobal(100, "ALGO", algoValue) - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Empty(t, delta.GlobalDelta) require.Empty(t, delta.LocalDeltas) @@ -2116,7 +2232,7 @@ byte "ALGO" ledger.NoGlobal(100, "ALGOA") ledger.NewGlobal(100, "ALGO", algoValue) - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Len(t, delta.GlobalDelta, 2) require.Empty(t, delta.LocalDeltas) @@ -2172,7 +2288,7 @@ byte "myval" ledger.NewAccount(txn.Sender, 1) ledger.NewApp(txn.Sender, 100, basics.AppParams{}) - delta := testApp(t, source, ep, "no app 101") + delta, _ := testApp(t, source, ep, "no app 101") require.Empty(t, delta.GlobalDelta) require.Empty(t, delta.LocalDeltas) @@ -2181,7 +2297,7 @@ byte "myval" algoValue := basics.TealValue{Type: basics.TealBytesType, Bytes: "myval"} ledger.NewGlobal(101, "mykey", algoValue) - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Empty(t, delta.GlobalDelta) require.Empty(t, delta.LocalDeltas) }) @@ -2214,7 +2330,7 @@ int 7 ledger.NewAccount(txn.Sender, 1) ledger.NewApp(txn.Sender, 100, basics.AppParams{}) - delta := testApp(t, source, ep) + delta, _ := testApp(t, source, ep) require.Empty(t, delta.LocalDeltas) }) } @@ -2256,7 +2372,7 @@ int 1 txn.ApplicationID = 100 ledger.NewApp(txn.Sender, 100, basics.AppParams{}) - delta := testApp(t, source, ep) + delta, _ := testApp(t, source, ep) require.Len(t, delta.GlobalDelta, 2) require.Empty(t, delta.LocalDeltas) @@ -2287,7 +2403,7 @@ app_global_get_ex source = strings.ReplaceAll(source, "THISAPP", "int 100") } txn.ForeignApps = []basics.AppIndex{txn.ApplicationID} - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Len(t, delta.GlobalDelta, 1) vd := delta.GlobalDelta["ALGO"] require.Equal(t, basics.DeleteAction, vd.Action) @@ -2312,7 +2428,7 @@ byte "ALGOA" int 0x78 app_global_put ` - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Len(t, delta.GlobalDelta, 1) vd = delta.GlobalDelta["ALGOA"] require.Equal(t, basics.SetUintAction, vd.Action) @@ -2334,7 +2450,7 @@ int 0x78 app_global_put int 1 ` - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Len(t, delta.GlobalDelta, 1) vd = delta.GlobalDelta["ALGO"] require.Equal(t, basics.SetUintAction, vd.Action) @@ -2357,7 +2473,7 @@ byte "ALGO" app_global_del int 1 ` - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Len(t, delta.GlobalDelta, 1) vd = delta.GlobalDelta["ALGO"] require.Equal(t, basics.DeleteAction, vd.Action) @@ -2380,7 +2496,7 @@ byte "ALGOA" app_global_del int 1 ` - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Len(t, delta.GlobalDelta, 1) require.Len(t, delta.LocalDeltas, 0) }) @@ -2433,7 +2549,7 @@ int 1 ep.Trace = &strings.Builder{} - delta := testApp(t, source, ep) + delta, _ := testApp(t, source, ep) require.Equal(t, 0, len(delta.GlobalDelta)) require.Equal(t, 2, len(delta.LocalDeltas)) ledger.Reset() @@ -2442,7 +2558,7 @@ int 1 // test that app_local_put and _app_local_del can use byte addresses withBytes := strings.ReplaceAll(source, "int 0 // sender", "txn Sender") withBytes = strings.ReplaceAll(withBytes, "int 1 // other", "txn Accounts 1") - delta := testApp(t, withBytes, ep) + delta, _ := testApp(t, withBytes, ep) // But won't even compile in old teal testProg(t, withBytes, directRefEnabledVersion-1, exp(4, "app_local_put arg 0 wanted..."), exp(11, "app_local_del arg 0 wanted...")) @@ -2473,7 +2589,7 @@ app_local_get_ex if ep.Proto.LogicSigVersion < directRefEnabledVersion { source = strings.ReplaceAll(source, "txn Sender", "int 0") } - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Equal(t, 0, len(delta.GlobalDelta)) require.Equal(t, 1, len(delta.LocalDeltas)) vd := delta.LocalDeltas[0]["ALGO"] @@ -2504,7 +2620,7 @@ app_local_put if ep.Proto.LogicSigVersion < directRefEnabledVersion { source = strings.ReplaceAll(source, "txn Sender", "int 0") } - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Equal(t, 0, len(delta.GlobalDelta)) require.Equal(t, 1, len(delta.LocalDeltas)) vd = delta.LocalDeltas[0]["ALGOA"] @@ -2531,7 +2647,7 @@ int 1 if ep.Proto.LogicSigVersion < directRefEnabledVersion { source = strings.ReplaceAll(source, "txn Sender", "int 0") } - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Equal(t, 0, len(delta.GlobalDelta)) require.Equal(t, 1, len(delta.LocalDeltas)) vd = delta.LocalDeltas[0]["ALGO"] @@ -2561,7 +2677,7 @@ int 1 if ep.Proto.LogicSigVersion < directRefEnabledVersion { source = strings.ReplaceAll(source, "txn Sender", "int 0") } - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Equal(t, 0, len(delta.GlobalDelta)) require.Equal(t, 1, len(delta.LocalDeltas)) vd = delta.LocalDeltas[0]["ALGO"] @@ -2591,7 +2707,7 @@ int 1 if ep.Proto.LogicSigVersion < directRefEnabledVersion { source = strings.ReplaceAll(source, "txn Sender", "int 0") } - delta = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Equal(t, 0, len(delta.GlobalDelta)) require.Equal(t, 1, len(delta.LocalDeltas)) require.Equal(t, 1, len(delta.LocalDeltas[0])) @@ -3328,7 +3444,7 @@ func TestLog(t *testing.T) { //track expected number of logs in cx.EvalDelta.Logs for i, s := range testCases { - delta := testApp(t, s.source, ep) + delta, _ := testApp(t, s.source, ep) require.Len(t, delta.Logs, s.loglen) if i == len(testCases)-1 { require.Equal(t, strings.Repeat("a", maxLogSize), delta.Logs[0]) @@ -3653,7 +3769,7 @@ int 43 app_local_put int 1 ` - ed := testApp(t, source, ep) + delta, _ := testApp(t, source, ep) require.Len(t, tx.Accounts, 1) // Sender + 1 tx.Accounts means LocalDelta index should be 2 require.Equal(t, map[uint64]basics.StateDelta{ 1: { @@ -3668,8 +3784,8 @@ int 1 Uint: 42, }, }, - }, ed.LocalDeltas) - require.Equal(t, []basics.Address{tx.ApplicationID.Address()}, ed.SharedAccts) + }, delta.LocalDeltas) + require.Equal(t, []basics.Address{tx.ApplicationID.Address()}, delta.SharedAccts) /* Confirm it worked. */ source = ` @@ -3695,7 +3811,7 @@ int 7 app_local_put int 1 ` - ed = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Len(t, tx.Accounts, 1) // Sender + 1 tx.Accounts means LocalDelta index should be 2 require.Equal(t, map[uint64]basics.StateDelta{ 1: { @@ -3709,8 +3825,8 @@ int 1 Action: basics.DeleteAction, }, }, - }, ed.LocalDeltas) - require.Equal(t, []basics.Address{tx.ApplicationID.Address()}, ed.SharedAccts) + }, delta.LocalDeltas) + require.Equal(t, []basics.Address{tx.ApplicationID.Address()}, delta.SharedAccts) // Now, repeat the "put" test with multiple keys, to ensure only one // address is added to SharedAccts and we'll modify the Sender too, to @@ -3734,7 +3850,7 @@ int 21 app_local_put int 1 ` - ed = testApp(t, source, ep) + delta, _ = testApp(t, source, ep) require.Len(t, tx.Accounts, 1) // Sender + 1 tx.Accounts means LocalDelta index should be 2 require.Equal(t, map[uint64]basics.StateDelta{ 0: { @@ -3753,9 +3869,9 @@ int 1 Uint: 21, }, }, - }, ed.LocalDeltas) + }, delta.LocalDeltas) - require.Equal(t, []basics.Address{tx.ApplicationID.Address()}, ed.SharedAccts) + require.Equal(t, []basics.Address{tx.ApplicationID.Address()}, delta.SharedAccts) }) } diff --git a/data/transactions/logic/eval_test.go b/data/transactions/logic/eval_test.go index 0eceac9a3..b7c55faf8 100644 --- a/data/transactions/logic/eval_test.go +++ b/data/transactions/logic/eval_test.go @@ -217,7 +217,7 @@ func (ep *EvalParams) reset() { inners := ep.Proto.MaxTxGroupSize * ep.Proto.MaxInnerTransactions ep.pooledAllowedInners = &inners } - ep.pastScratch = make([]*scratchSpace, len(ep.TxnGroup)) + ep.pastScratch = [maxTxGroupSize]*scratchSpace{} for i := range ep.TxnGroup { ep.TxnGroup[i].ApplyData = transactions.ApplyData{} } @@ -2182,7 +2182,7 @@ func testLogicBytes(t *testing.T, program []byte, ep *EvalParams, problems ...st } // testLogicFull is the lowest-level so it does not create an ep or reset it. -func testLogicFull(t *testing.T, program []byte, gi int, ep *EvalParams, problems ...string) { +func testLogicFull(t *testing.T, program []byte, gi int, ep *EvalParams, problems ...string) error { t.Helper() var checkProblem string @@ -2217,7 +2217,7 @@ func testLogicFull(t *testing.T, program []byte, gi int, ep *EvalParams, problem if evalProblem == "" { require.NoError(t, err, "Eval\n%sExpected: PASS", ep.Trace) assert.True(t, pass, "Eval\n%sExpected: PASS", ep.Trace) - return + return nil } // There is an evalProblem to check. REJECT is special and only means that @@ -2227,9 +2227,10 @@ func testLogicFull(t *testing.T, program []byte, gi int, ep *EvalParams, problem } else { require.ErrorContains(t, err, evalProblem, "Wrong error in EvalSignature %v", ep.Trace) } + return err } -func testLogics(t *testing.T, programs []string, txgroup []transactions.SignedTxn, opt protoOpt, expected ...expect) *EvalParams { +func testLogics(t *testing.T, programs []string, txgroup []transactions.SignedTxn, opt protoOpt, expected ...expect) error { t.Helper() proto := makeTestProto(opt) @@ -2248,10 +2249,14 @@ func testLogics(t *testing.T, programs []string, txgroup []transactions.SignedTx ep := NewSigEvalParams(txgroup, proto, &NoHeaderLedger{}) for i, program := range programs { if program != "" { + if len(expected) > 0 && expected[0].l == i { + // Stop after first failure + return testLogicFull(t, txgroup[i].Lsig.Logic, i, ep, expected[0].s) + } testLogicFull(t, txgroup[i].Lsig.Logic, i, ep) } } - return ep + return nil } func TestTxna(t *testing.T) { @@ -2571,12 +2576,11 @@ substring3 len`, 2) // fails at runtime - err := testPanics(t, `byte 0xf000000000000000 + testPanics(t, `byte 0xf000000000000000 int 4 int 0xFFFFFFFFFFFFFFFE substring3 -len`, 2) - require.Contains(t, err.Error(), "substring range beyond length of string") +len`, 2, "substring range beyond length of string") } func TestSubstringRange(t *testing.T) { @@ -2629,44 +2633,37 @@ func TestExtractFlop(t *testing.T) { len`, 5, exp(4, "extract3 expects 0 immediate arguments")) // fails at runtime - err := testPanics(t, `byte 0xf000000000000000 + testPanics(t, `byte 0xf000000000000000 extract 1 8 - len`, 5) - require.Contains(t, err.Error(), "extraction end 9") + len`, 5, "extraction end 9") - err = testPanics(t, `byte 0xf000000000000000 + testPanics(t, `byte 0xf000000000000000 extract 9 0 - len`, 5) - require.Contains(t, err.Error(), "extraction start 9") + len`, 5, "extraction start 9") - err = testPanics(t, `byte 0xf000000000000000 + testPanics(t, `byte 0xf000000000000000 int 4 int 0xFFFFFFFFFFFFFFFE extract3 - len`, 5) - require.Contains(t, err.Error(), "extraction end exceeds uint64") + len`, 5, "extraction end exceeds uint64") - err = testPanics(t, `byte 0xf000000000000000 + testPanics(t, `byte 0xf000000000000000 int 100 int 2 extract3 - len`, 5) - require.Contains(t, err.Error(), "extraction start 100") + len`, 5, "extraction start 100") - err = testPanics(t, `byte 0xf000000000000000 + testPanics(t, `byte 0xf000000000000000 int 55 - extract_uint16`, 5) - require.Contains(t, err.Error(), "extraction start 55") + extract_uint16`, 5, "extraction start 55") - err = testPanics(t, `byte 0xf000000000000000 + testPanics(t, `byte 0xf000000000000000 int 9 - extract_uint32`, 5) - require.Contains(t, err.Error(), "extraction start 9") + extract_uint32`, 5, "extraction start 9") - err = testPanics(t, `byte 0xf000000000000000 + testPanics(t, `byte 0xf000000000000000 int 1 - extract_uint64`, 5) - require.Contains(t, err.Error(), "extraction end 9") + extract_uint64`, 5, "extraction end 9") } func TestReplace(t *testing.T) { @@ -2752,8 +2749,8 @@ loads func TestLoadStore2(t *testing.T) { partitiontest.PartitionTest(t) - t.Parallel() + progText := `int 2 int 3 byte 0xaa @@ -2768,6 +2765,61 @@ int 5 testAccepts(t, progText, 1) } +// TestLogicErrorDetails confirms that the error returned from logicsig failures +// has the right structured information. +func TestLogicErrorDetails(t *testing.T) { + partitiontest.PartitionTest(t) + t.Parallel() + + badsource := notrack(` +int 5; store 10 // store an int +byte 0x01020300; store 15 // store a bytes + +int 100; byte 0x0201; == // types mismatch so this will fail +`) + err := testPanics(t, badsource, 1, "cannot compare") + attrs := basics.Attributes(err) + zeros := [256]int{} + scratch := convertSlice(zeros[:], func(i int) any { return uint64(i) }) + scratch[10] = uint64(5) + scratch[15] = []byte{0x01, 0x02, 0x03, 0x00} + require.Equal(t, map[string]any{ + "pc": 19, + "group-index": 0, + "eval-states": []evalState{ + { + Stack: []any{uint64(100), []byte{02, 01}}, + Scratch: scratch[:16], + }, + }, + }, attrs) + + goodsource := ` +int 4; store 2 // store an int +byte "jj"; store 3 // store a bytes +int 1 +` + gscratch := convertSlice(zeros[:], func(i int) any { return uint64(i) }) + gscratch[2] = uint64(4) + gscratch[3] = []byte("jj") + + err = testLogics(t, []string{goodsource, badsource}, nil, nil, exp(1, "cannot compare")) + attrs = basics.Attributes(err) + require.Equal(t, map[string]any{ + "pc": 19, + "group-index": 1, + "eval-states": []evalState{ + { + Scratch: gscratch[:4], + }, + { + Stack: []any{uint64(100), []byte{02, 01}}, + Scratch: scratch[:16], + }, + }, + }, attrs) +} + func TestGload(t *testing.T) { partitiontest.PartitionTest(t) t.Parallel() @@ -4563,7 +4615,11 @@ func testEvaluation(t *testing.T, program string, introduced uint64, tester eval require.True(t, ok) isNotPanic(t, err) // Never want a Go level panic. if err != nil { - // Use wisely. This could probably return any of the concurrent runs' errors. + // Use `outer` wisely. It could return any of the concurrent runs' errors. + var se *basics.SError + require.ErrorAs(t, err, &se) + var ee EvalError + require.ErrorAs(t, err, &ee) outer = err } }) @@ -5278,9 +5334,7 @@ By Herman Melville`, "", if LogicVersion < fidoVersion { testProg(t, source, AssemblerMaxVersion, exp(0, "unknown opcode...")) } else { - err := testPanics(t, source, fidoVersion) - require.Error(t, err) - require.Contains(t, err.Error(), tc.error) + testPanics(t, source, fidoVersion, tc.error) } } } @@ -6122,9 +6176,17 @@ int 1 func TestNoHeaderLedger(t *testing.T) { partitiontest.PartitionTest(t) + t.Parallel() nhl := NoHeaderLedger{} _, err := nhl.BlockHdr(1) require.Error(t, err) require.Equal(t, err, fmt.Errorf("no block header access")) } + +func TestMaxTxGroup(t *testing.T) { + partitiontest.PartitionTest(t) + t.Parallel() + + require.Equal(t, config.MaxTxGroupSize, maxTxGroupSize) +} diff --git a/data/transactions/logic/export_test.go b/data/transactions/logic/export_test.go index 3ba93a87e..ed250acd8 100644 --- a/data/transactions/logic/export_test.go +++ b/data/transactions/logic/export_test.go @@ -60,7 +60,7 @@ var WithPanicOpcode = withPanicOpcode // TryApps exports "testApps" while accepting a simple uint64. Annoying, we // can't export call this "TestApps" because it looks like a Test function with // the wrong signature. But we can get that effect with the alias below. -func TryApps(t *testing.T, programs []string, txgroup []transactions.SignedTxn, ver uint64, ledger *Ledger, expected ...expect) *EvalParams { +func TryApps(t *testing.T, programs []string, txgroup []transactions.SignedTxn, ver uint64, ledger *Ledger, expected ...expect) (*EvalParams, error) { return testApps(t, programs, txgroup, protoVer(ver), ledger, expected...) } diff --git a/data/transactions/logic/ledger_test.go b/data/transactions/logic/ledger_test.go index 6c2d62c7f..0254a4467 100644 --- a/data/transactions/logic/ledger_test.go +++ b/data/transactions/logic/ledger_test.go @@ -625,7 +625,7 @@ func (l *Ledger) move(from basics.Address, to basics.Address, amount uint64) err tbr = newBalanceRecord(to, 0) } if fbr.balance < amount { - return fmt.Errorf("insufficient balance") + return fmt.Errorf("insufficient balance in %v. %d < %d", from, fbr.balance, amount) } fbr.balance -= amount tbr.balance += amount diff --git a/data/transactions/logic/resources_test.go b/data/transactions/logic/resources_test.go index 42ceee6d4..6458e081a 100644 --- a/data/transactions/logic/resources_test.go +++ b/data/transactions/logic/resources_test.go @@ -141,7 +141,7 @@ func TestAppSharing(t *testing.T) { TestApps(t, sources, txntest.Group(&appl0, &appl1), 9, ledger, Exp(1, "account "+appl0.Sender.String()+" is not opted into 901")) ledger.NewLocals(appl0.Sender, 901) // opt in - ep := TestApps(t, sources, txntest.Group(&appl0, &appl1), 9, ledger) + ep, _ := TestApps(t, sources, txntest.Group(&appl0, &appl1), 9, ledger) require.Len(t, ep.TxnGroup, 2) ed := ep.TxnGroup[1].ApplyData.EvalDelta require.Equal(t, map[uint64]basics.StateDelta{ diff --git a/ledger/simulation/simulation_eval_test.go b/ledger/simulation/simulation_eval_test.go index 100ea8b7f..41482e72e 100644 --- a/ledger/simulation/simulation_eval_test.go +++ b/ledger/simulation/simulation_eval_test.go @@ -6813,7 +6813,7 @@ int 1`, input: simulation.Request{ TxnGroups: [][]transactions.SignedTxn{txgroup}, }, - expectedError: "logic eval error: this transaction should be issued by the manager", + expectedError: "this transaction should be issued by the manager", expected: simulation.Result{ Version: simulation.ResultLatestVersion, LastRound: env.TxnInfo.LatestRound(), diff --git a/test/e2e-go/cli/goal/expect/goalAppAccountAddressTest.exp b/test/e2e-go/cli/goal/expect/goalAppAccountAddressTest.exp index 6146fa172..6146fa172 100644..100755 --- a/test/e2e-go/cli/goal/expect/goalAppAccountAddressTest.exp +++ b/test/e2e-go/cli/goal/expect/goalAppAccountAddressTest.exp diff --git a/test/e2e-go/cli/goal/expect/statefulTealCreateAppTest.exp b/test/e2e-go/cli/goal/expect/statefulTealCreateAppTest.exp index 0051d65cc..0051d65cc 100755..100644 --- a/test/e2e-go/cli/goal/expect/statefulTealCreateAppTest.exp +++ b/test/e2e-go/cli/goal/expect/statefulTealCreateAppTest.exp diff --git a/test/e2e-go/cli/goal/expect/tealConsensusTest.exp b/test/e2e-go/cli/goal/expect/tealConsensusTest.exp index cd2b81cfd..cd2b81cfd 100755..100644 --- a/test/e2e-go/cli/goal/expect/tealConsensusTest.exp +++ b/test/e2e-go/cli/goal/expect/tealConsensusTest.exp diff --git a/test/e2e-go/restAPI/other/appsRestAPI_test.go b/test/e2e-go/restAPI/other/appsRestAPI_test.go index 51d757af1..c4a4986ed 100644 --- a/test/e2e-go/restAPI/other/appsRestAPI_test.go +++ b/test/e2e-go/restAPI/other/appsRestAPI_test.go @@ -31,7 +31,6 @@ import ( "github.com/algorand/go-algorand/data/basics" "github.com/algorand/go-algorand/data/transactions" "github.com/algorand/go-algorand/data/transactions/logic" - "github.com/algorand/go-algorand/protocol" "github.com/algorand/go-algorand/test/framework/fixtures" "github.com/algorand/go-algorand/test/partitiontest" "github.com/stretchr/testify/require" @@ -319,15 +318,12 @@ end: e := err.(client.HTTPError) a.Equal(400, e.StatusCode) - var er *model.ErrorResponse - err = protocol.DecodeJSON([]byte(e.ErrorString), &er) - a.NoError(err) - a.Equal("Result limit exceeded", er.Message) - a.Equal(uint64(100000), ((*er.Data)["max-api-box-per-application"]).(uint64)) - a.Equal(requestedMax, ((*er.Data)["max"]).(uint64)) - a.Equal(expectedCount, ((*er.Data)["total-boxes"]).(uint64)) + a.Equal("Result limit exceeded", e.ErrorString) + a.EqualValues(100000, e.Data["max-api-box-per-application"]) + a.EqualValues(requestedMax, e.Data["max"]) + a.EqualValues(expectedCount, e.Data["total-boxes"]) - a.Len(*er.Data, 3, fmt.Sprintf("error response (%v) contains unverified fields. Extend test for new fields.", *er.Data)) + a.Len(e.Data, 3, fmt.Sprintf("error response (%v) contains unverified fields. Extend test for new fields.", e.Data)) } // `assertBoxCount` sanity checks that the REST API respects `expectedCount` through different queries against app ID = `createdAppID`. diff --git a/test/scripts/e2e_subs/avm-failure-info.py b/test/scripts/e2e_subs/avm-failure-info.py new file mode 100755 index 000000000..5f2adfab4 --- /dev/null +++ b/test/scripts/e2e_subs/avm-failure-info.py @@ -0,0 +1,78 @@ +#!/usr/bin/env python + +import os +import json +import subprocess +import sys +from goal import Goal + +from datetime import datetime + +stamp = datetime.now().strftime("%Y%m%d_%H%M%S") +print(f"{os.path.basename(sys.argv[0])} start {stamp}") + +goal = Goal(sys.argv[1], autosend=True) + +joe = goal.new_account() + +txinfo, err = goal.pay(goal.account, joe, amt=500_000) +assert not err, err + +teal = """ +#pragma version 6 + byte 0x1a00011afb // be sure to test non-ascii logs + byte 0x2a00012afc // be sure to test non-ascii logs + log + log + int 42 + byte 0x4a01004afa // be sure to test non-ascii stack + int 7 + store 10 + byte 0x4a00014afe // be sure to test non-ascii scratch + store 12 + int 1 + int 2 + - // Fail! +end: + int 1 +""" + +tx = goal.app_create(joe, goal.assemble(teal), send=False) +command = goal.curl_command(tx) +response = subprocess.check_output(command, shell=True) +j = json.loads(response) +print(j) +assert j['data']['pc'] == 45 +assert j['data']['group-index'] == 0 +assert j['data']['app-index'] > 1000 +assert j['data']['eval-states'][0]['scratch'][10] == 7 +assert j['data']['eval-states'][0]['scratch'][12] == 'SgABSv4=' +assert j['data']['eval-states'][0]['stack'] == [42, 'SgEASvo=', 1, 2] +assert j['data']['eval-states'][0]['logs'] == ['KgABKvw=', 'GgABGvs='] + +# Test some omit-empty behavior. That `scratch` simply doesn't appear, +# and that `logs` does appear, even if the only log entry is an empty +# message. +teal = """ +#pragma version 6 + byte 0x; log // Log (only) an empty msg + int 1 + int 2 + - // Fail! +end: + int 1 +""" + +tx = goal.app_create(joe, goal.assemble(teal), send=False) +command = goal.curl_command(tx) +response = subprocess.check_output(command, shell=True) +j = json.loads(response) +print(j) + +assert j['data']['group-index'] == 0 +assert 'scratch' not in j['data']['eval-states'][0] +assert j['data']['eval-states'][0]['logs'] == [''] +assert j['data']['pc'] == 10 + +stamp = datetime.now().strftime("%Y%m%d_%H%M%S") +print(f"{os.path.basename(sys.argv[0])} OK {stamp}") diff --git a/test/scripts/e2e_subs/goal/goal.py b/test/scripts/e2e_subs/goal/goal.py index 812afe897..5d0dd7db0 100755 --- a/test/scripts/e2e_subs/goal/goal.py +++ b/test/scripts/e2e_subs/goal/goal.py @@ -158,6 +158,19 @@ class Goal: except algosdk.error.AlgodHTTPError as e: return (None, e) + def send_details(self, tx): + stx = self.sign(tx) + headers = {"Content-Type": "application/x-binary", + "X-Algo-API-Token": self.algod.algod_token, + } + url = self.algod.algod_address + "/v2/transactions" + return (url, headers, enc.msgpack_encode(stx)) + + def curl_command(self, tx): + (url, headers, b64data) = self.send_details(tx) + H = " ".join(['-H "' + k + ':' + v + '"' for k,v in headers.items()]) + return f"echo {b64data} | base64 -d | curl -s {url} {H} --data-binary @-" + def send_group(self, txns, confirm=True): # Need unsigned transactions to calculate the group This pulls # out the unsigned tx if tx is sigged, logicsigged or |