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

gnovm(bug): time.Time rendering causes Machine Panic #1588

Closed
leohhhn opened this issue Jan 25, 2024 · 2 comments · Fixed by #1606
Closed

gnovm(bug): time.Time rendering causes Machine Panic #1588

leohhhn opened this issue Jan 25, 2024 · 2 comments · Fixed by #1606
Assignees
Labels
🐞 bug Something isn't working 📦 🤖 gnovm Issues or PRs gnovm related

Comments

@leohhhn
Copy link
Contributor

leohhhn commented Jan 25, 2024

While working on the rendering of the blog realm, I came upon a possible Gno bug. Specifically, the bug happens when trying to return the value of a time.Time, formatted to the RFC3339 format using .Format().

Take a look at the following example realm.

package tt

import (
	"gno.land/p/demo/avl"
	"gno.land/p/demo/ufmt"
	"time"
)

var (
	storageTree avl.Tree
	index       = 0
)

type Post struct {
	CreatedAt time.Time
}

func Store(date string) {
	var parsedTime time.Time
	var err error

	if date != "" {
		parsedTime, err = time.Parse(time.RFC3339, date)

		if err != nil {
			panic(err)
		}
	} else {
		parsedTime = time.Now()
	}

	post := &Post{
		CreatedAt: parsedTime,
	}

	storageTree.Set(ufmt.Sprintf("%d", index), post)
	index++
}

func Read() string {
	out := ""

	for i := 0; i < index; i++ {
		rawPost, _ := storageTree.Get(ufmt.Sprintf("%d", i))
		post := rawPost.(*Post)

		out += post.CreatedAt.Format(time.RFC3339)
		out += "\n\n"
	}

	return out
} 
^^^ Error happens when calling Read() 

Calling the following commands:

// time.Now() as parsed time
❯ gnokey maketx call -pkgpath gno.land/r/demo/tt --func Store --args "" --gas-fee 10000000ugnot --gas-wanted 800000  --broadcast dev
Enter password.

OK!
GAS WANTED: 800000
GAS USED:   492640

// Rendering is OK, no error
❯ gnokey maketx call -pkgpath gno.land/r/demo/tt --func Read --gas-fee 10000000ugnot --gas-wanted 800000  --broadcast dev           
Enter password.
("2024-01-25T20:52:14Z\n\n" string)
OK!
GAS WANTED: 800000
GAS USED:   398033

// 2024-01-24T13:55:00Z as parsed time, a valid RFC3339 format
❯ gnokey maketx call -pkgpath gno.land/r/demo/tt --func Store --args "2024-01-24T13:55:00Z" --gas-fee 10000000ugnot --gas-wanted 800000  --broadcast dev
Enter password.

OK!
GAS WANTED: 800000
GAS USED:   555203

// Rendering is OK, no error
❯ gnokey maketx call -pkgpath gno.land/r/demo/tt --func Read --gas-fee 10000000ugnot --gas-wanted 800000  --broadcast dev                               
Enter password.
("2024-01-25T20:52:14Z\n\n2024-01-24T13:55:00Z\n\n" string)
OK!
GAS WANTED: 800000
GAS USED:   408777


// Finally, for 2024-01-25T21:28:15+01:00, also a valid RFC3339 fromat
❯ gnokey maketx call -pkgpath gno.land/r/demo/tt --func Store --args "2024-01-25T21:28:15+01:00" --gas-fee 10000000ugnot --gas-wanted 800000  --broadcast dev
Enter password.

OK!
GAS WANTED: 800000
GAS USED:   651010

❯ gnokey maketx call -pkgpath gno.land/r/demo/tt --func Read --gas-fee 10000000ugnot --gas-wanted 800000  --broadcast dev                                    
Enter password.
--= Error =--

Here is a gist of the error.
I am sure the formats passed in as strings are valid in Go: https://go.dev/play/p/IFMutN8aWGV

Running a vm/qeval returns a 500 internal server error:

❯ gnokey query vm/qeval --data "gno.land/r/demo/tt Read()"                                                               
--= Error =--
Data: server at 'http://127.0.0.1:26657' returned 500 Internal Server Error
--= /Error =--

What might be causing this?

cc @thehowl

@leohhhn leohhhn added the 🐞 bug Something isn't working label Jan 25, 2024
@leohhhn leohhhn changed the title Bug: time.Time rendering causes Machine Panic gnovm(bug): time.Time rendering causes Machine Panic Jan 25, 2024
@thehowl
Copy link
Member

thehowl commented Jan 26, 2024

full trace result and txtar test: https://gist.github.com/thehowl/f0ca7715705998116c2c88a6811a692f

This seems to be related to realm storage of time.Time values which have a Location value of the timezone. Needs some more investigation.

Specifically, the machine info seems to point to the error happening somewhere here:

if l != &utcLoc {
if l.cacheZone != nil && l.cacheStart <= sec && sec < l.cacheEnd {

@thehowl thehowl added the 📦 🤖 gnovm Issues or PRs gnovm related label Jan 26, 2024
@thehowl thehowl added this to the 🚀 main.gno.land (required) milestone Jan 26, 2024
@deelawn
Copy link
Contributor

deelawn commented Jan 30, 2024

You're spot on with the line in question @thehowl. It's resolving the l.cacheZone selector that is causing the problem. For some reason, reading that object from storage is returning an array typed value rather than the expected struct. So far it's unclear to me if something got mucked up in how this data is being read or how the data was saved. I'll take a closer look at it.

@deelawn deelawn self-assigned this Jan 30, 2024
@deelawn deelawn linked a pull request Jan 31, 2024 that will close this issue
7 tasks
thehowl pushed a commit that referenced this issue Feb 22, 2024
…#1606)

<!-- please provide a detailed description of the changes made in this
pull request. -->
Addresses #1588.

The following explanation refers to the txtar test linked to in the
issue. [Here it
is](https://gist.github.com/thehowl/f0ca7715705998116c2c88a6811a692f)
for convenience.

### Why the panic?
This line in the txtar test's `Read()` function caused the panic: `out
+= post.CreatedAt.Format(time.RFC3339)`. The `Format` method results in
invoking the `Time.locabs` method, and this is the line inside that
method that caused the panic:
https://github.com/gnolang/gno/blob/master/gnovm/stdlibs/time/time.gno#L468

The panic occurs when trying to resolve the value of `l.cacheZone` as a
part of the selector operation. This is a panic caused by an invalid
type assertion. The invalid type assertion happens on the line that was
modified for this PR:
https://github.com/gnolang/gno/blob/master/gnovm/stdlibs/time/time.gno#L468

In the case of this particular txtar test, the target value's base value
is a struct value, not an array value. We can look at how the original
`cacheZone` value was persisted to understand why the base type is
different from what we'd expect.

### Original value persistence
The original time value is built as a result of this line in the txtar
test's `Store()` function: `parsedTime, err = time.Parse(time.RFC3339,
date)`.

The `cacheZone` value that is persisted either has a struct base value
or is nil for the majority of this operation. However, the time value's
`Location` field gets updated near the end of the `parse` operation and
assumes the value of the result of the `FixedZone` function:
https://github.com/gnolang/gno/blob/master/gnovm/stdlibs/time/format.gno#L1306

Taking a look at what `FixedZone` actually does, we can see that the
location's `cacheZone` is now a reference to a zone that exists as a
part of an array -- a struct with a base type of an array value:
https://github.com/gnolang/gno/blob/master/gnovm/stdlibs/time/timezoneinfo.gno#L114

This explains why the value we were seeing when trying to resolve the
`cacheZone` selector had an array base.

### The fix
It doesn't matter if the source value's parent is an array or struct; we
need the underlying value's type and value. That being said, I don't
think the array type assertion needs to happen since the type value is
accessible via the `Elem()` method defined as part of the `Type`
interface. Now the value is obtained without causing a panic.

<details><summary>Contributors' checklist...</summary>

- [x] Added new tests, or not needed, or not feasible
- [x] Provided an example (e.g. screenshot) to aid review or the PR is
self-explanatory
- [x] Updated the official documentation or not needed
- [x] No breaking changes were made, or a `BREAKING CHANGE: xxx` message
was included in the description
- [x] Added references to related issues and PRs
- [x] Provided any useful hints for running manual tests
- [x] Added new benchmarks to [generated
graphs](https://gnoland.github.io/benchmarks), if any. More info
[here](https://github.com/gnolang/gno/blob/master/.benchmarks/README.md).
</details>
leohhhn pushed a commit to leohhhn/gno that referenced this issue Feb 29, 2024
…gnolang#1606)

<!-- please provide a detailed description of the changes made in this
pull request. -->
Addresses gnolang#1588.

The following explanation refers to the txtar test linked to in the
issue. [Here it
is](https://gist.github.com/thehowl/f0ca7715705998116c2c88a6811a692f)
for convenience.

### Why the panic?
This line in the txtar test's `Read()` function caused the panic: `out
+= post.CreatedAt.Format(time.RFC3339)`. The `Format` method results in
invoking the `Time.locabs` method, and this is the line inside that
method that caused the panic:
https://github.com/gnolang/gno/blob/master/gnovm/stdlibs/time/time.gno#L468

The panic occurs when trying to resolve the value of `l.cacheZone` as a
part of the selector operation. This is a panic caused by an invalid
type assertion. The invalid type assertion happens on the line that was
modified for this PR:
https://github.com/gnolang/gno/blob/master/gnovm/stdlibs/time/time.gno#L468

In the case of this particular txtar test, the target value's base value
is a struct value, not an array value. We can look at how the original
`cacheZone` value was persisted to understand why the base type is
different from what we'd expect.

### Original value persistence
The original time value is built as a result of this line in the txtar
test's `Store()` function: `parsedTime, err = time.Parse(time.RFC3339,
date)`.

The `cacheZone` value that is persisted either has a struct base value
or is nil for the majority of this operation. However, the time value's
`Location` field gets updated near the end of the `parse` operation and
assumes the value of the result of the `FixedZone` function:
https://github.com/gnolang/gno/blob/master/gnovm/stdlibs/time/format.gno#L1306

Taking a look at what `FixedZone` actually does, we can see that the
location's `cacheZone` is now a reference to a zone that exists as a
part of an array -- a struct with a base type of an array value:
https://github.com/gnolang/gno/blob/master/gnovm/stdlibs/time/timezoneinfo.gno#L114

This explains why the value we were seeing when trying to resolve the
`cacheZone` selector had an array base.

### The fix
It doesn't matter if the source value's parent is an array or struct; we
need the underlying value's type and value. That being said, I don't
think the array type assertion needs to happen since the type value is
accessible via the `Elem()` method defined as part of the `Type`
interface. Now the value is obtained without causing a panic.

<details><summary>Contributors' checklist...</summary>

- [x] Added new tests, or not needed, or not feasible
- [x] Provided an example (e.g. screenshot) to aid review or the PR is
self-explanatory
- [x] Updated the official documentation or not needed
- [x] No breaking changes were made, or a `BREAKING CHANGE: xxx` message
was included in the description
- [x] Added references to related issues and PRs
- [x] Provided any useful hints for running manual tests
- [x] Added new benchmarks to [generated
graphs](https://gnoland.github.io/benchmarks), if any. More info
[here](https://github.com/gnolang/gno/blob/master/.benchmarks/README.md).
</details>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
🐞 bug Something isn't working 📦 🤖 gnovm Issues or PRs gnovm related
Projects
Development

Successfully merging a pull request may close this issue.

3 participants