Files
Etienne Perot 0cd10e4a36 runsc boot: Add startup timer instrumentation.
Example output:

```
I0807 10:27:23.158030       1 timing.go:866] ---- runsc boot timing information ----
[10:27:22.991938]                               ╭─ runsc boot
[10:27:22.995285]        +3 346µs ▋             ├─ Go code running: 3 346µs
[10:27:22.996191]          +906µs ▏             ├─ boot subcommand dispatched: 906µs
[10:27:22.996643]          +451µs               ├─ CPUID initialized: 451µs
[10:27:22.996645]            +2µs               ├─ ring0 initialized: 2µs
[10:27:22.997012]          +367µs               ├─ host info read: 367µs
[10:27:22.998024]        +1 011µs ▏             ├─ spec read: 1 011µs
[10:27:22.998555]          +530µs               ├─ chroot base mounted: 530µs
[10:27:22.998822]          +267µs               ├─ chroot proc mounted: 267µs
[10:27:23.000271]        +1 449µs ▎             ├─ chroot procfs set up: 1 449µs
[10:27:23.000369]           +97µs               ├─ chroot sealed read-only: 97µs
[10:27:23.002635]        +2 266µs ▍             ├─ chroot set up: 2 266µs
[10:27:23.003523]          +887µs ▏             ├─ sandbox capabilities computed: 887µs
[10:27:23.003693]          +170µs               ├─ current capabilities read: 170µs
[10:27:23.012905]        +9 211µs ▉▊            ├─ bounding set trimmed on all threads: 9 211µs
[10:27:23.013139]          +233µs               ├─ capset applied on all threads: 233µs
[10:27:23.013449]          +310µs               ├─ capabilities applied: 310µs
[10:27:23.024366]       +10 916µs ▉▉            ├─ resolved mounts read: 10 916µs
[10:27:23.029416]        +5 049µs ▉             ├─ seccheck initialized: 5 049µs
[10:27:23.029419]            +3µs               ├─ RNG initialized: 3µs
[10:27:23.029571]          +152µs               ├─ memory usage initialized: 152µs
[10:27:23.029619]           +47µs               ├─ GOMAXPROCS set: 47µs
[10:27:23.057560]       +27 941µs ▉▉▉▉▉▍        ├─ stdio FDs remapped: 27 941µs
[10:27:23.057563]            +2µs               ├─ donated FDs ingested: 2µs
[10:27:23.057889]          +326µs               ├─ systrap memory file created: 326µs
[10:27:23.058714]          +825µs ▏             ├─ systrap stub initialized: 825µs
[10:27:23.063232]        +4 517µs █             ├─ systrap source process created: 4 517µs
[10:27:23.063244]           +12µs               ├─ waiting for membarrier: 12µs
[10:27:23.063246]            +1µs               ├─ host membarrier probed: 1µs
[10:27:23.063251]            +4µs               ├─ platform created: 4µs
[10:27:23.063390]          +138µs               ├─ memory file created: 138µs
[10:27:23.063438]           +48µs               ├─ VDSO prepared: 48µs
[10:27:23.063473]           +34µs               ├─ timekeeper configured: 34µs
[10:27:23.063675]          +201µs               ├─ network stack created: 201µs
[10:27:23.063854]          +179µs               ├─ kernel initialized: 179µs
[10:27:23.063859]            +4µs               ├─ filesystems registered: 4µs
[10:27:23.063943]           +84µs               ├─ process args created: 84µs
[10:27:23.063947]            +3µs               ├─ compat logs initialized: 3µs
[10:27:23.063948]            +0µs               ├─ mount hints parsed: 0µs
[10:27:23.063949]            +1µs               ├─ host FS mount created: 1µs
[10:27:23.064142]          +192µs               ├─ control server started: 192µs
[10:27:23.064142]            +0µs               ├─ loader created: 0µs
[10:27:23.064152]            +9µs               ├─ metrics initialized: 9µs
[10:27:23.064152]            +0µs               ├─ notifying parent: 0µs
[10:27:23.126745]       +62 592µs ▉▉▉▉▉▉▉▉▉▉▉▉  ├─ network args received: 62 592µs
[10:27:23.126972]          +227µs               ├─ start RPC received: 227µs
[10:27:23.126982]           +10µs               ├─ start signal received: 10µs
[10:27:23.127852]          +869µs ▏             ├─ network configured: 869µs
[10:27:23.128646]          +794µs ▏             ├─ open FDs validated: 794µs
[10:27:23.131274]        +2 628µs ▌             ├─ pre-seccomp callback done: 2 628µs
[10:27:23.132513]        +1 238µs ▎             ├─ seccomp rules computed: 1 238µs
[10:27:23.146898]       +14 384µs ▉▉▊           ├─ seccomp program compiled: 14 384µs
[10:27:23.148596]        +1 698µs ▎             ├─ seccomp program installed: 1 698µs
[10:27:23.148655]           +58µs               ├─ seccomp filters installed: 58µs
[10:27:23.148655]            +0µs               ├─ forked: 0µs                          ╭─ root container
[10:27:23.148876]          +220µs               │ ... 220µs ...                         ├─ FD table created: 220µs
[10:27:23.149125]          +249µs               │ ... 469µs ...                         ├─ cgroups mounted: 249µs
[10:27:23.149798]          +673µs ▏             │ ... 1 143µs ...                       ├─ rootfs mounted: 673µs
[10:27:23.149804]            +5µs               │ ... 1 148µs ...                       ├─ submounts prepared: 5µs
[10:27:23.150009]          +205µs               │ ... 1 353µs ...                       ├─ mounted "/dev": 205µs
[10:27:23.150362]          +352µs               │ ... 1 706µs ...                       ├─ mounted "/sys": 352µs
[10:27:23.150822]          +459µs               │ ... 2 166µs ...                       ├─ mounted "/proc": 459µs
[10:27:23.150886]           +63µs               │ ... 2 230µs ...                       ├─ mounted "/dev/pts": 63µs
[10:27:23.150915]           +29µs               │ ... 2 259µs ...                       ├─ mounted "/dev/shm": 29µs
[10:27:23.151200]          +285µs               │ ... 2 544µs ...                       ├─ mounted "/etc/hosts": 285µs
[10:27:23.151212]           +12µs               │ ... 2 557µs ...                       ├─ mounted "/dev/mqueue": 12µs
[10:27:23.151539]          +326µs               │ ... 2 883µs ...                       ├─ mounted "/etc/hostname": 326µs
[10:27:23.151660]          +121µs               │ ... 3 004µs ...                       ├─ mounted "/sys/fs/cgroup": 121µs
[10:27:23.151846]          +186µs               │ ... 3 190µs ...                       ├─ mounted "/etc/resolv.conf": 186µs
[10:27:23.151974]          +128µs               │ ... 3 319µs ...                       ├─ submounts mounted: 128µs
[10:27:23.151981]            +6µs               │ ... 3 325µs ...                       ├─ device files created: 6µs
[10:27:23.151981]            +0µs               │ ... 3 326µs ...                       ├─ executable path resolved: 0µs
[10:27:23.152057]           +75µs               │ ... 3 401µs ...                       ├─ exec user home resolved: 75µs
[10:27:23.152085]           +28µs               │ ... 3 429µs ...                       ├─ FS context created: 28µs
[10:27:23.153742]        +1 656µs ▎             │ ... 5 086µs ...                       ├─ memory manager created: 1 656µs
[10:27:23.156409]        +2 667µs ▌             │ ... 7 753µs ...                       ├─ executable loaded: 2 667µs
[10:27:23.156419]           +10µs               │ ... 7 763µs ...                       ├─ VDSO mapped: 10µs
[10:27:23.156425]            +5µs               │ ... 7 769µs ...                       ├─ stack allocated: 5µs
[10:27:23.156491]           +65µs               │ ... 7 835µs ...                       ├─ stack contents loaded: 65µs
[10:27:23.156497]            +5µs               │ ... 7 841µs ...                       ├─ task image loaded: 5µs
[10:27:23.156543]           +46µs               │ ... 7 887µs ...                       ├─ init task created: 46µs
[10:27:23.156599]           +56µs               ├─ root container created: 7 943µs      │ ... 56µs ...
[10:27:23.157146]          +547µs               ├─ signal forwarding started: 547µs     │ ... 603µs ...
[10:27:23.157575]          +428µs               ├─ kernel started: 428µs                │ ... 1 031µs ...
[10:27:23.157575]            +0µs               │ ... 0µs ...                           ╰─ END 1 032µs, total 8 919µs
[10:27:23.157576]            +1µs               ╰─ END 1µs, total 165 638µs
---- End of runsc boot timing information ----
```
2026-08-07 10:26:34 -07:00

176 lines
5.4 KiB
Go

// Copyright 2018 The gVisor Authors.
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
package kernel
import (
"gvisor.dev/gvisor/pkg/abi/linux/errno"
"gvisor.dev/gvisor/pkg/context"
"gvisor.dev/gvisor/pkg/hostarch"
"gvisor.dev/gvisor/pkg/log"
"gvisor.dev/gvisor/pkg/sentry/arch"
"gvisor.dev/gvisor/pkg/sentry/kernel/auth"
"gvisor.dev/gvisor/pkg/sentry/kernel/futex"
"gvisor.dev/gvisor/pkg/sentry/loader"
"gvisor.dev/gvisor/pkg/sentry/mm"
"gvisor.dev/gvisor/pkg/syserr"
)
var errNoSyscalls = syserr.New("no syscall table found", errno.ENOEXEC)
// Auxmap contains miscellaneous data for the task.
type Auxmap map[string]any
// TaskImage is the subset of a task's data that is provided by the loader.
//
// +stateify savable
type TaskImage struct {
// Name is the thread name set by the prctl(PR_SET_NAME) system call.
Name string
// Arch is the architecture-specific context (registers, etc.)
Arch *arch.Context64
// MemoryManager is the task's address space.
MemoryManager *mm.MemoryManager
// fu implements futexes in the address space.
fu *futex.Manager
// st is the task's syscall table.
st *SyscallTable `state:".(syscallTableInfo)"`
}
// release releases all resources held by the TaskImage. release is called by
// the task when it execs into a new TaskImage.
func (image *TaskImage) release(ctx context.Context) {
// Nil out pointers so that if the task is saved after release, it doesn't
// follow the pointers to possibly now-invalid objects.
if image.MemoryManager != nil {
image.MemoryManager.DecUsers(ctx)
image.MemoryManager = nil
}
image.fu = nil
}
// Fork returns a duplicate of image. The copied TaskImage always has an
// independent arch.Context64. If shareAddressSpace is true, the copied
// TaskImage shares an address space with the original; otherwise, the copied
// TaskImage has an independent address space that is initially a duplicate
// of the original's.
func (image *TaskImage) Fork(ctx context.Context, k *Kernel, shareAddressSpace bool) (*TaskImage, error) {
newImage := &TaskImage{
Name: image.Name,
Arch: image.Arch.Fork(),
st: image.st,
}
if shareAddressSpace {
newImage.MemoryManager = image.MemoryManager
if newImage.MemoryManager != nil {
if !newImage.MemoryManager.IncUsers() {
// Shouldn't be possible since image.MemoryManager should be a
// counted user.
panic("TaskImage.Fork called with userless TaskImage.MemoryManager")
}
}
newImage.fu = image.fu
} else {
newMM, err := image.MemoryManager.Fork(ctx)
if err != nil {
return nil, err
}
newImage.MemoryManager = newMM
newImage.fu = k.futexes.Fork()
}
return newImage, nil
}
// Arch returns t's arch.Context64.
//
// Preconditions: The caller must be running on the task goroutine, or t.mu
// must be locked.
func (t *Task) Arch() *arch.Context64 {
return t.image.Arch
}
// MemoryManager returns t's MemoryManager. MemoryManager does not take an
// additional reference on the returned MM.
//
// Preconditions: The caller must be running on the task goroutine, or t.mu
// must be locked.
func (t *Task) MemoryManager() *mm.MemoryManager {
return t.image.MemoryManager
}
// SyscallTable returns t's syscall table.
//
// Preconditions: The caller must be running on the task goroutine, or t.mu
// must be locked.
func (t *Task) SyscallTable() *SyscallTable {
return t.image.st
}
// Stack returns the userspace stack.
//
// Preconditions: The caller must be running on the task goroutine, or t.mu
// must be locked.
func (t *Task) Stack() *arch.Stack {
return &arch.Stack{
Arch: t.Arch(),
IO: t.MemoryManager(),
Bottom: hostarch.Addr(t.Arch().Stack()),
}
}
// LoadTaskImage loads a specified file into a new TaskImage. It also returns
// the new credentials for the task after execve and a bool indicating whether
// the task is executing with elevated privileges.
//
// args.MemoryManager does not need to be set by the caller.
func (k *Kernel) LoadTaskImage(ctx context.Context, args loader.LoadArgs) (*TaskImage, *auth.Credentials, bool, *syserr.Error) {
// Prepare a new user address space to load into.
m, merr := mm.NewMemoryManager(k, k.mf)
if merr != nil {
log.Warningf("Failed to create new memory manager: %v", merr)
return nil, nil, false, syserr.ErrNoMemory
}
defer m.DecUsers(ctx)
args.MemoryManager = m
args.StartupTimeline.Reached("memory manager created")
info, creds, secureExec, err := loader.Load(ctx, args, k.extraAuxv, k.vdso)
if err != nil {
return nil, nil, false, err
}
// Lookup our new syscall table.
st, ok := LookupSyscallTable(info.OS, info.Arch.Arch())
if !ok {
// No syscall table found. This means that the ELF binary does not match
// the architecture.
return nil, nil, false, errNoSyscalls
}
if !m.IncUsers() {
panic("Failed to increment users count on new MM")
}
return &TaskImage{
Name: info.Name,
Arch: info.Arch,
MemoryManager: m,
fu: k.futexes.Fork(),
st: st,
}, creds, secureExec, nil
}