Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

chore(gnovm): instrument debug tracing to display the caller site. #3702

Merged
merged 6 commits into from
Feb 11, 2025

Conversation

mvertes
Copy link
Contributor

@mvertes mvertes commented Feb 7, 2025

Running the gnovm with the debug traces enabled (build tag debug) allows to display the details of preprocessing and opcodes operations.

This PR adds the caller location in source (file + line) to each trace, allowing to identify the calling context of opcodes, to ease understanding the gnovm behavior.

No change when debug is disabled (the default mode).

Tracing can be activated by: go run -tags debug ./cmd/gno run args

Before:

DEBUG: |||| -v (true <untyped> bool)
DEBUG: EXEC: (const (println func(xs ...interface{})()))((const ("i:" string)), i<VPBlock(1,0)>)
DEBUG: |||| -s bodyStmt[0/0/1]=(end)
DEBUG: |||| +o OpPopResults
DEBUG: ||||| +x (const (println func(xs ...interface{})()))((const ("i:" string)), i<VPBlock(1,0)>)
DEBUG: ||||| +o OpEval
DEBUG: |||||| -o OpEval
DEBUG: EVAL: (*gnolang.CallExpr) (const (println func(xs ...interface{})()))((const ("i:" string)), i<VPBlock(1,0)>)
DEBUG: ||||| +o OpPrecall
DEBUG: |||||| +x i<VPBlock(1,0)>
DEBUG: |||||| +o OpEval
DEBUG: ||||||| +x (const ("i:" string))
DEBUG: ||||||| +o OpEval
DEBUG: |||||||| +x (const (println func(xs ...interface{})()))
DEBUG: |||||||| +o OpEval
DEBUG: ||||||||| -o OpEval
DEBUG: EVAL: (*gnolang.ConstExpr) (const (println func(xs ...interface{})()))
DEBUG: |||||||| -x (const (println func(xs ...interface{})()))
DEBUG: |||||||| +v (println func(xs ...interface{})())
DEBUG: |||||||| -o OpEval
DEBUG: EVAL: (*gnolang.ConstExpr) (const ("i:" string))
DEBUG: ||||||| -x (const ("i:" string))
DEBUG: ||||||| +v ("i:" string)
DEBUG: ||||||| -o OpEval

After:

DEBUG:   op_exec.go:99  : |||| -v (true <untyped> bool)
DEBUG:   machine.go:1535: EXEC: (const (println func(xs ...interface{})()))((const ("i:" string)), i<VPBlock(1,0)>)
DEBUG:   op_exec.go:484 : |||| -s bodyStmt[0/0/1]=(end)
DEBUG:   op_exec.go:488 : |||| +o OpPopResults
DEBUG:   op_exec.go:493 : ||||| +x (const (println func(xs ...interface{})()))((const ("i:" string)), i<VPBlock(1,0)>)
DEBUG:   op_exec.go:494 : ||||| +o OpEval
DEBUG:   machine.go:1218: |||||| -o OpEval
DEBUG:   machine.go:1380: EVAL: (*gnolang.CallExpr) (const (println func(xs ...interface{})()))((const ("i:" string)), i<VPBlock(1,0)>)
DEBUG:   op_eval.go:243 : ||||| +o OpPrecall
DEBUG:   op_eval.go:247 : |||||| +x i<VPBlock(1,0)>
DEBUG:   op_eval.go:248 : |||||| +o OpEval
DEBUG:   op_eval.go:247 : ||||||| +x (const ("i:" string))
DEBUG:   op_eval.go:248 : ||||||| +o OpEval
DEBUG:   op_eval.go:251 : |||||||| +x (const (println func(xs ...interface{})()))
DEBUG:   op_eval.go:252 : |||||||| +o OpEval
DEBUG:   machine.go:1218: ||||||||| -o OpEval
DEBUG:   machine.go:1380: EVAL: (*gnolang.ConstExpr) (const (println func(xs ...interface{})()))
DEBUG:   op_eval.go:317 : |||||||| -x (const (println func(xs ...interface{})()))
DEBUG:   op_eval.go:319 : |||||||| +v (println func(xs ...interface{})())
DEBUG:   machine.go:1218: |||||||| -o OpEval
DEBUG:   machine.go:1380: EVAL: (*gnolang.ConstExpr) (const ("i:" string))
DEBUG:   op_eval.go:317 : ||||||| -x (const ("i:" string))
DEBUG:   op_eval.go:319 : ||||||| +v ("i:" string)
DEBUG:   machine.go:1218: ||||||| -o OpEval

Running the gnovm with the debug traces acivated (build tag `debug`)
allows to display the details of preprocessing and opcodes operations.

This PR adds the caller location in source (file + line) to each trace,
allowing to identify the calling context of opcodes, to ease
understanding the gnovm behavior.

No change when debug is disabled (the default mode).

Tracing can be activated by: `go run -tags debug ./cmd/gno run args`

Before:

```console
DEBUG: |||| -v (true <untyped> bool)
DEBUG: EXEC: (const (println func(xs ...interface{})()))((const ("i:" string)), i<VPBlock(1,0)>)
DEBUG: |||| -s bodyStmt[0/0/1]=(end)
DEBUG: |||| +o OpPopResults
DEBUG: ||||| +x (const (println func(xs ...interface{})()))((const ("i:" string)), i<VPBlock(1,0)>)
DEBUG: ||||| +o OpEval
DEBUG: |||||| -o OpEval
DEBUG: EVAL: (*gnolang.CallExpr) (const (println func(xs ...interface{})()))((const ("i:" string)), i<VPBlock(1,0)>)
DEBUG: ||||| +o OpPrecall
DEBUG: |||||| +x i<VPBlock(1,0)>
DEBUG: |||||| +o OpEval
DEBUG: ||||||| +x (const ("i:" string))
DEBUG: ||||||| +o OpEval
DEBUG: |||||||| +x (const (println func(xs ...interface{})()))
DEBUG: |||||||| +o OpEval
DEBUG: ||||||||| -o OpEval
DEBUG: EVAL: (*gnolang.ConstExpr) (const (println func(xs ...interface{})()))
DEBUG: |||||||| -x (const (println func(xs ...interface{})()))
DEBUG: |||||||| +v (println func(xs ...interface{})())
DEBUG: |||||||| -o OpEval
DEBUG: EVAL: (*gnolang.ConstExpr) (const ("i:" string))
DEBUG: ||||||| -x (const ("i:" string))
DEBUG: ||||||| +v ("i:" string)
DEBUG: ||||||| -o OpEval
```

After:
```console
DEBUG: op_exec.go:99:|||| -v (true <untyped> bool)
DEBUG: machine.go:1535:EXEC: (const (println func(xs ...interface{})()))((const ("i:" string)), i<VPBlock(1,0)>)
DEBUG: op_exec.go:484:|||| -s bodyStmt[0/0/1]=(end)
DEBUG: op_exec.go:488:|||| +o OpPopResults
DEBUG: op_exec.go:493:||||| +x (const (println func(xs ...interface{})()))((const ("i:" string)), i<VPBlock(1,0)>)
DEBUG: op_exec.go:494:||||| +o OpEval
DEBUG: machine.go:1218:|||||| -o OpEval
DEBUG: machine.go:1380:EVAL: (*gnolang.CallExpr) (const (println func(xs ...interface{})()))((const ("i:" string)), i<VPBlock(1,0)>)
DEBUG: op_eval.go:243:||||| +o OpPrecall
DEBUG: op_eval.go:247:|||||| +x i<VPBlock(1,0)>
DEBUG: op_eval.go:248:|||||| +o OpEval
DEBUG: op_eval.go:247:||||||| +x (const ("i:" string))
DEBUG: op_eval.go:248:||||||| +o OpEval
DEBUG: op_eval.go:251:|||||||| +x (const (println func(xs ...interface{})()))
DEBUG: op_eval.go:252:|||||||| +o OpEval
DEBUG: machine.go:1218:||||||||| -o OpEval
DEBUG: machine.go:1380:EVAL: (*gnolang.ConstExpr) (const (println func(xs ...interface{})()))
DEBUG: op_eval.go:317:|||||||| -x (const (println func(xs ...interface{})()))
DEBUG: op_eval.go:319:|||||||| +v (println func(xs ...interface{})())
DEBUG: machine.go:1218:|||||||| -o OpEval
DEBUG: machine.go:1380:EVAL: (*gnolang.ConstExpr) (const ("i:" string))
DEBUG: op_eval.go:317:||||||| -x (const ("i:" string))
DEBUG: op_eval.go:319:||||||| +v ("i:" string)
DEBUG: machine.go:1218:||||||| -o OpEval
```
@github-actions github-actions bot added the 📦 🤖 gnovm Issues or PRs gnovm related label Feb 7, 2025
@Gno2D2
Copy link
Collaborator

Gno2D2 commented Feb 7, 2025

🛠 PR Checks Summary

All Automated Checks passed. ✅

Manual Checks (for Reviewers):
  • IGNORE the bot requirements for this PR (force green CI check)
Read More

🤖 This bot helps streamline PR reviews by verifying automated checks and providing guidance for contributors and reviewers.

✅ Automated Checks (for Contributors):

🟢 Maintainers must be able to edit this pull request (more info)

☑️ Contributor Actions:
  1. Fix any issues flagged by automated checks.
  2. Follow the Contributor Checklist to ensure your PR is ready for review.
    • Add new tests, or document why they are unnecessary.
    • Provide clear examples/screenshots, if necessary.
    • Update documentation, if required.
    • Ensure no breaking changes, or include BREAKING CHANGE notes.
    • Link related issues/PRs, where applicable.
☑️ Reviewer Actions:
  1. Complete manual checks for the PR, including the guidelines and additional checks if applicable.
📚 Resources:
Debug
Automated Checks
Maintainers must be able to edit this pull request (more info)

If

🟢 Condition met
└── 🟢 And
    ├── 🟢 The base branch matches this pattern: ^master$
    └── 🟢 The pull request was created from a fork (head branch repo: mvertes/gno)

Then

🟢 Requirement satisfied
└── 🟢 Maintainer can modify this pull request

Manual Checks
**IGNORE** the bot requirements for this PR (force green CI check)

If

🟢 Condition met
└── 🟢 On every pull request

Can be checked by

  • Any user with comment edit permission

Copy link

codecov bot commented Feb 7, 2025

Codecov Report

Attention: Patch coverage is 0% with 18 lines in your changes missing coverage. Please review.

Files with missing lines Patch % Lines
gnovm/pkg/gnolang/machine.go 0.00% 10 Missing ⚠️
gnovm/pkg/gnolang/debug.go 0.00% 8 Missing ⚠️

📢 Thoughts on this report? Let us know!

@thehowl
Copy link
Member

thehowl commented Feb 7, 2025

But this makes the visual cue of the pipes on the left useless, as you can't line them up. Could this not go after the pipes, at least?

@github-actions github-actions bot added the 📦 ⛰️ gno.land Issues or PRs gno.land package related label Feb 11, 2025
@thehowl thehowl merged commit 4f03669 into gnolang:master Feb 11, 2025
58 of 59 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
📦 ⛰️ gno.land Issues or PRs gno.land package related 📦 🤖 gnovm Issues or PRs gnovm related
Projects
Development

Successfully merging this pull request may close these issues.

3 participants