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/stdlibs/bytes: lots of time spent in runtime garbage collection than in running programs #3435

Open
odeke-em opened this issue Jan 2, 2025 · 2 comments
Labels
🐞 bug Something isn't working non-security

Comments

@odeke-em
Copy link
Contributor

odeke-em commented Jan 2, 2025

Investigating #3421, trying to run a single test takes close to 3 minutes. On profiling we can see more than 60 seconds spent in garbage collection

pprof003
profile001

We need to figure out how to reduce the memory bloat and all the garbage collection cycles. Even for the beefiest servers, it is very rare to see programs spending most of their time in runtime.scanobject. This issue is going to require some more design considerations.

Kindly cc-ing @moul @thehowl @notJoon @jaekwon

@thehowl
Copy link
Member

thehowl commented Jan 23, 2025

Is this not though ultimately the same problem as #3487?

@odeke-em
Copy link
Contributor Author

Nope, those are 2 different problems, there is so much more we can do for this issue like #3598; #3487 is specialized just for NewBlock and the other is just for ReadMemPackageFromList; this issue is the overarching call to action to make the GnoVM fast and much more efficient

odeke-em added a commit to odeke-em/gno that referenced this issue Jan 23, 2025
…lices from os.ReadFile

This change takes advantage of the fact that we can singly use the
byteslices that were already allocated from os.ReadFile, given that
the places that their string(bz) are invoked don't have any unsafe
usages that then would modify those strings.

This change shaves off considerable CPU and RAM and is in the spirit
of having a fast VM that can be relied on and not stymied per se by
garbage collection. With it, all the RAM contributions for:
PackageNameFromFile and gnovm.MemFile disappear shaving off 4+GB
and no longer even appearing as a direct RAM contributor in the top 10.

```shell
$ benchstat before.txt after.txt
name              old time/op    new time/op    delta
ReadMemPackage-8     101µs ± 8%      89µs ± 4%  -11.54%  (p=0.000 n=9+10)

name              old alloc/op   new alloc/op   delta
ReadMemPackage-8    64.1kB ± 0%    34.2kB ± 0%  -46.72%  (p=0.001 n=8+9)

name              old allocs/op  new allocs/op  delta
ReadMemPackage-8      59.0 ± 0%      56.0 ± 0%   -5.08%  (p=0.000 n=10+10)
```

and then now RAM usage profiles show

```shell
Total: 7.41GB
ROUTINE ======================== github.com/gnolang/gno/gnovm/pkg/gnolang.ReadMemPackageFromList in /Users/emmanuelodeke/go/src/github.com/gnolang/gno/gnovm/pkg/gnolang/nodes.go
      34MB     6.98GB (flat, cum) 94.14% of Total
         .          .   1310:func ReadMemPackageFromList(list []string, pkgPath string) (*gnovm.MemPackage, error) {
   14.50MB    14.50MB   1311:	memPkg := &gnovm.MemPackage{Path: pkgPath}
         .          .   1312:	var pkgName Name
         .          .   1313:	for _, fpath := range list {
         .          .   1314:		fname := filepath.Base(fpath)
         .     4.35GB   1315:		bz, err := os.ReadFile(fpath)
         .          .   1316:		if err != nil {
         .          .   1317:			return nil, err
         .          .   1318:		}
         .          .   1319:		// XXX: should check that all pkg names are the same (else package is invalid)
         .          .   1320:		if pkgName == "" && strings.HasSuffix(fname, ".gno") {
         .          .   1321:			// The string derived from bz is never modified inside PackageNameFromFileBody
         .          .   1322:			// hence shave these unnecessary allocations by an unsafe
         .          .   1323:			// byteslice->string conversion per gnolang#3598
         .     2.59GB   1324:			pkgName, err = PackageNameFromFileBody(fname, unsafeBytesliceToStr(bz))
         .          .   1325:			if err != nil {
         .          .   1326:				return nil, err
         .          .   1327:			}
         .          .   1328:			if strings.HasSuffix(string(pkgName), "_test") {
         .          .   1329:				pkgName = pkgName[:len(pkgName)-len("_test")]
         .          .   1330:			}
         .          .   1331:		}
    6.50MB     6.50MB   1332:		memPkg.Files = append(memPkg.Files,
      13MB       13MB   1333:			&gnovm.MemFile{
         .          .   1334:				Name: fname,
         .          .   1335:				// The string derived from bz is never modified, hence to shave
         .          .   1336:				// unnecessary allocations, perform this unsafe byteslice->string
         .          .   1337:				// conversion per gnolang#3598
         .          .   1338:				// and the Go garbage collector will knows to garbage collect
         .          .   1339:				// bz when no other object points to that memory.
         .          .   1340:				Body: unsafeBytesliceToStr(bz),
         .          .   1341:			})
         .          .   1342:	}
         .          .   1343:
         .          .   1344:	// If no .gno files are present, package simply does not exist.
         .          .   1345:	if !memPkg.IsEmpty() {
         .     7.01MB   1346:		if err := validatePkgName(string(pkgName)); err != nil {
         .          .   1347:			return nil, err
         .          .   1348:		}
         .          .   1349:		memPkg.Name = string(pkgName)
         .          .   1350:	}
```

but previously looked like

```shell
ROUTINE ======================== github.com/gnolang/gno/gnovm/pkg/gnolang.ReadMemPackageFromList in /Users/emmanuelodeke/go/src/github.com/gnolang/gno/gnovm/pkg/gnolang/nodes.go
    5.55GB    11.46GB (flat, cum) 97.01% of Total
         .          .   1309:func ReadMemPackageFromList(list []string, pkgPath string) (*gnovm.MemPackage, error) {
      13MB       13MB   1310:	memPkg := &gnovm.MemPackage{Path: pkgPath}
         .          .   1311:	var pkgName Name
         .          .   1312:	for _, fpath := range list {
         .          .   1313:		fname := filepath.Base(fpath)
         .     3.66GB   1314:		bz, err := os.ReadFile(fpath)
         .          .   1315:		if err != nil {
         .          .   1316:			return nil, err
         .          .   1317:		}
         .          .   1318:		// XXX: should check that all pkg names are the same (else package is invalid)
         .          .   1319:		if pkgName == "" && strings.HasSuffix(fname, ".gno") {
    2.02GB     4.27GB   1320:			pkgName, err = PackageNameFromFileBody(fname, string(bz))
         .          .   1321:			if err != nil {
         .          .   1322:				return nil, err
         .          .   1323:			}
         .          .   1324:			if strings.HasSuffix(string(pkgName), "_test") {
         .          .   1325:				pkgName = pkgName[:len(pkgName)-len("_test")]
         .          .   1326:			}
         .          .   1327:		}
    4.50MB     4.50MB   1328:		memPkg.Files = append(memPkg.Files,
    9.50MB     9.50MB   1329:			&gnovm.MemFile{
         .          .   1330:				Name: fname,
    3.50GB     3.50GB   1331:				Body: string(bz),
         .          .   1332:			})
         .          .   1333:	}
         .          .   1334:
         .          .   1335:	// If no .gno files are present, package simply does not exist.
         .          .   1336:	if !memPkg.IsEmpty() {
         .     6.51MB   1337:		if err := validatePkgName(string(pkgName)); err != nil {
         .          .   1338:			return nil, err
         .          .   1339:		}
         .          .   1340:		memPkg.Name = string(pkgName)
         .          .   1341:	}
```

Updates gnolang#3435
Fixes gnolang#3598
odeke-em added a commit to odeke-em/gno that referenced this issue Jan 23, 2025
…lices from os.ReadFile

This change takes advantage of the fact that we can singly use the
byteslices that were already allocated from os.ReadFile, given that
the places that their string(bz) are invoked don't have any unsafe
usages that then would modify those strings.

This change shaves off considerable CPU and RAM and is in the spirit
of having a fast VM that can be relied on and not stymied per se by
garbage collection. With it, all the RAM contributions for:
PackageNameFromFile and gnovm.MemFile disappear shaving off 4+GB
and no longer even appearing as a direct RAM contributor in the top 10.

```shell
$ benchstat before.txt after.txt
name              old time/op    new time/op    delta
ReadMemPackage-8     101µs ± 8%      89µs ± 4%  -11.54%  (p=0.000 n=9+10)

name              old alloc/op   new alloc/op   delta
ReadMemPackage-8    64.1kB ± 0%    34.2kB ± 0%  -46.72%  (p=0.001 n=8+9)

name              old allocs/op  new allocs/op  delta
ReadMemPackage-8      59.0 ± 0%      56.0 ± 0%   -5.08%  (p=0.000 n=10+10)
```

and then now RAM usage profiles show

```shell
Total: 7.41GB
ROUTINE ======================== github.com/gnolang/gno/gnovm/pkg/gnolang.ReadMemPackageFromList in /Users/emmanuelodeke/go/src/github.com/gnolang/gno/gnovm/pkg/gnolang/nodes.go
      34MB     6.98GB (flat, cum) 94.14% of Total
         .          .   1310:func ReadMemPackageFromList(list []string, pkgPath string) (*gnovm.MemPackage, error) {
   14.50MB    14.50MB   1311:	memPkg := &gnovm.MemPackage{Path: pkgPath}
         .          .   1312:	var pkgName Name
         .          .   1313:	for _, fpath := range list {
         .          .   1314:		fname := filepath.Base(fpath)
         .     4.35GB   1315:		bz, err := os.ReadFile(fpath)
         .          .   1316:		if err != nil {
         .          .   1317:			return nil, err
         .          .   1318:		}
         .          .   1319:		// XXX: should check that all pkg names are the same (else package is invalid)
         .          .   1320:		if pkgName == "" && strings.HasSuffix(fname, ".gno") {
         .          .   1321:			// The string derived from bz is never modified inside PackageNameFromFileBody
         .          .   1322:			// hence shave these unnecessary allocations by an unsafe
         .          .   1323:			// byteslice->string conversion per gnolang#3598
         .     2.59GB   1324:			pkgName, err = PackageNameFromFileBody(fname, unsafeBytesliceToStr(bz))
         .          .   1325:			if err != nil {
         .          .   1326:				return nil, err
         .          .   1327:			}
         .          .   1328:			if strings.HasSuffix(string(pkgName), "_test") {
         .          .   1329:				pkgName = pkgName[:len(pkgName)-len("_test")]
         .          .   1330:			}
         .          .   1331:		}
    6.50MB     6.50MB   1332:		memPkg.Files = append(memPkg.Files,
      13MB       13MB   1333:			&gnovm.MemFile{
         .          .   1334:				Name: fname,
         .          .   1335:				// The string derived from bz is never modified, hence to shave
         .          .   1336:				// unnecessary allocations, perform this unsafe byteslice->string
         .          .   1337:				// conversion per gnolang#3598
         .          .   1338:				// and the Go garbage collector will knows to garbage collect
         .          .   1339:				// bz when no other object points to that memory.
         .          .   1340:				Body: unsafeBytesliceToStr(bz),
         .          .   1341:			})
         .          .   1342:	}
         .          .   1343:
         .          .   1344:	// If no .gno files are present, package simply does not exist.
         .          .   1345:	if !memPkg.IsEmpty() {
         .     7.01MB   1346:		if err := validatePkgName(string(pkgName)); err != nil {
         .          .   1347:			return nil, err
         .          .   1348:		}
         .          .   1349:		memPkg.Name = string(pkgName)
         .          .   1350:	}
```

but previously looked like

```shell
ROUTINE ======================== github.com/gnolang/gno/gnovm/pkg/gnolang.ReadMemPackageFromList in /Users/emmanuelodeke/go/src/github.com/gnolang/gno/gnovm/pkg/gnolang/nodes.go
    5.55GB    11.46GB (flat, cum) 97.01% of Total
         .          .   1309:func ReadMemPackageFromList(list []string, pkgPath string) (*gnovm.MemPackage, error) {
      13MB       13MB   1310:	memPkg := &gnovm.MemPackage{Path: pkgPath}
         .          .   1311:	var pkgName Name
         .          .   1312:	for _, fpath := range list {
         .          .   1313:		fname := filepath.Base(fpath)
         .     3.66GB   1314:		bz, err := os.ReadFile(fpath)
         .          .   1315:		if err != nil {
         .          .   1316:			return nil, err
         .          .   1317:		}
         .          .   1318:		// XXX: should check that all pkg names are the same (else package is invalid)
         .          .   1319:		if pkgName == "" && strings.HasSuffix(fname, ".gno") {
    2.02GB     4.27GB   1320:			pkgName, err = PackageNameFromFileBody(fname, string(bz))
         .          .   1321:			if err != nil {
         .          .   1322:				return nil, err
         .          .   1323:			}
         .          .   1324:			if strings.HasSuffix(string(pkgName), "_test") {
         .          .   1325:				pkgName = pkgName[:len(pkgName)-len("_test")]
         .          .   1326:			}
         .          .   1327:		}
    4.50MB     4.50MB   1328:		memPkg.Files = append(memPkg.Files,
    9.50MB     9.50MB   1329:			&gnovm.MemFile{
         .          .   1330:				Name: fname,
    3.50GB     3.50GB   1331:				Body: string(bz),
         .          .   1332:			})
         .          .   1333:	}
         .          .   1334:
         .          .   1335:	// If no .gno files are present, package simply does not exist.
         .          .   1336:	if !memPkg.IsEmpty() {
         .     6.51MB   1337:		if err := validatePkgName(string(pkgName)); err != nil {
         .          .   1338:			return nil, err
         .          .   1339:		}
         .          .   1340:		memPkg.Name = string(pkgName)
         .          .   1341:	}
```

Updates gnolang#3435
Fixes gnolang#3598
odeke-em added a commit to odeke-em/gno that referenced this issue Jan 24, 2025
…lices from os.ReadFile

This change takes advantage of the fact that we can singly use the
byteslices that were already allocated from os.ReadFile, given that
the places that their string(bz) are invoked don't have any unsafe
usages that then would modify those strings.

This change shaves off considerable CPU and RAM and is in the spirit
of having a fast VM that can be relied on and not stymied per se by
garbage collection. With it, all the RAM contributions for:
PackageNameFromFile and gnovm.MemFile disappear shaving off 4+GB
and no longer even appearing as a direct RAM contributor in the top 10.

```shell
$ benchstat before.txt after.txt
name              old time/op    new time/op    delta
ReadMemPackage-8     101µs ± 8%      89µs ± 4%  -11.54%  (p=0.000 n=9+10)

name              old alloc/op   new alloc/op   delta
ReadMemPackage-8    64.1kB ± 0%    34.2kB ± 0%  -46.72%  (p=0.001 n=8+9)

name              old allocs/op  new allocs/op  delta
ReadMemPackage-8      59.0 ± 0%      56.0 ± 0%   -5.08%  (p=0.000 n=10+10)
```

and then now RAM usage profiles show

```shell
Total: 7.41GB
ROUTINE ======================== github.com/gnolang/gno/gnovm/pkg/gnolang.ReadMemPackageFromList in /Users/emmanuelodeke/go/src/github.com/gnolang/gno/gnovm/pkg/gnolang/nodes.go
      34MB     6.98GB (flat, cum) 94.14% of Total
         .          .   1310:func ReadMemPackageFromList(list []string, pkgPath string) (*gnovm.MemPackage, error) {
   14.50MB    14.50MB   1311:	memPkg := &gnovm.MemPackage{Path: pkgPath}
         .          .   1312:	var pkgName Name
         .          .   1313:	for _, fpath := range list {
         .          .   1314:		fname := filepath.Base(fpath)
         .     4.35GB   1315:		bz, err := os.ReadFile(fpath)
         .          .   1316:		if err != nil {
         .          .   1317:			return nil, err
         .          .   1318:		}
         .          .   1319:		// XXX: should check that all pkg names are the same (else package is invalid)
         .          .   1320:		if pkgName == "" && strings.HasSuffix(fname, ".gno") {
         .          .   1321:			// The string derived from bz is never modified inside PackageNameFromFileBody
         .          .   1322:			// hence shave these unnecessary allocations by an unsafe
         .          .   1323:			// byteslice->string conversion per gnolang#3598
         .     2.59GB   1324:			pkgName, err = PackageNameFromFileBody(fname, unsafeBytesliceToStr(bz))
         .          .   1325:			if err != nil {
         .          .   1326:				return nil, err
         .          .   1327:			}
         .          .   1328:			if strings.HasSuffix(string(pkgName), "_test") {
         .          .   1329:				pkgName = pkgName[:len(pkgName)-len("_test")]
         .          .   1330:			}
         .          .   1331:		}
    6.50MB     6.50MB   1332:		memPkg.Files = append(memPkg.Files,
      13MB       13MB   1333:			&gnovm.MemFile{
         .          .   1334:				Name: fname,
         .          .   1335:				// The string derived from bz is never modified, hence to shave
         .          .   1336:				// unnecessary allocations, perform this unsafe byteslice->string
         .          .   1337:				// conversion per gnolang#3598
         .          .   1338:				// and the Go garbage collector will knows to garbage collect
         .          .   1339:				// bz when no other object points to that memory.
         .          .   1340:				Body: unsafeBytesliceToStr(bz),
         .          .   1341:			})
         .          .   1342:	}
         .          .   1343:
         .          .   1344:	// If no .gno files are present, package simply does not exist.
         .          .   1345:	if !memPkg.IsEmpty() {
         .     7.01MB   1346:		if err := validatePkgName(string(pkgName)); err != nil {
         .          .   1347:			return nil, err
         .          .   1348:		}
         .          .   1349:		memPkg.Name = string(pkgName)
         .          .   1350:	}
```

but previously looked like

```shell
ROUTINE ======================== github.com/gnolang/gno/gnovm/pkg/gnolang.ReadMemPackageFromList in /Users/emmanuelodeke/go/src/github.com/gnolang/gno/gnovm/pkg/gnolang/nodes.go
    5.55GB    11.46GB (flat, cum) 97.01% of Total
         .          .   1309:func ReadMemPackageFromList(list []string, pkgPath string) (*gnovm.MemPackage, error) {
      13MB       13MB   1310:	memPkg := &gnovm.MemPackage{Path: pkgPath}
         .          .   1311:	var pkgName Name
         .          .   1312:	for _, fpath := range list {
         .          .   1313:		fname := filepath.Base(fpath)
         .     3.66GB   1314:		bz, err := os.ReadFile(fpath)
         .          .   1315:		if err != nil {
         .          .   1316:			return nil, err
         .          .   1317:		}
         .          .   1318:		// XXX: should check that all pkg names are the same (else package is invalid)
         .          .   1319:		if pkgName == "" && strings.HasSuffix(fname, ".gno") {
    2.02GB     4.27GB   1320:			pkgName, err = PackageNameFromFileBody(fname, string(bz))
         .          .   1321:			if err != nil {
         .          .   1322:				return nil, err
         .          .   1323:			}
         .          .   1324:			if strings.HasSuffix(string(pkgName), "_test") {
         .          .   1325:				pkgName = pkgName[:len(pkgName)-len("_test")]
         .          .   1326:			}
         .          .   1327:		}
    4.50MB     4.50MB   1328:		memPkg.Files = append(memPkg.Files,
    9.50MB     9.50MB   1329:			&gnovm.MemFile{
         .          .   1330:				Name: fname,
    3.50GB     3.50GB   1331:				Body: string(bz),
         .          .   1332:			})
         .          .   1333:	}
         .          .   1334:
         .          .   1335:	// If no .gno files are present, package simply does not exist.
         .          .   1336:	if !memPkg.IsEmpty() {
         .     6.51MB   1337:		if err := validatePkgName(string(pkgName)); err != nil {
         .          .   1338:			return nil, err
         .          .   1339:		}
         .          .   1340:		memPkg.Name = string(pkgName)
         .          .   1341:	}
```

Updates gnolang#3435
Fixes gnolang#3598
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
🐞 bug Something isn't working non-security
Projects
Status: Triage
Development

No branches or pull requests

3 participants