DATA RACE in log.GoogleEmitter.Emit (4)

Status: fixed on 2024/08/03 02:02
Fix commit: 742b914fcb82 Don't log mount.root because it leads to racy access.
First crash: 756d, last: 756d
▶ ▼ Similar bugs (3)
Kernel Title Rank 🛈 Repro Cause bisect Fix bisect Count Last Reported Patched Status
gvisor DATA RACE in log.GoogleEmitter.Emit (3) -1 1 774d 774d 26/26 fixed on 2024/07/17 10:25
gvisor DATA RACE in log.GoogleEmitter.Emit -1 syz, C 34 2108d 2113d 0/26 fixed on 2020/11/21 02:21
gvisor DATA RACE in log.GoogleEmitter.Emit (2) -1 3 1195d 1197d 26/26 fixed on 2023/05/25 09:13

Sample crash report:
WARNING: DATA RACE
Read at 0x00c111d063f0 by goroutine 27884:
  reflect.typedmemmove()
      GOROOT/src/runtime/mbarrier.go:203 +0x0
  reflect.packEface()
      GOROOT/src/reflect/value.go:135 +0xc5
  reflect.valueInterface()
      GOROOT/src/reflect/value.go:1526 +0x179
  reflect.Value.Interface()
      GOROOT/src/reflect/value.go:1496 +0xb4
  fmt.(*pp).printValue()
      GOROOT/src/fmt/print.go:769 +0xc5
  fmt.(*pp).printValue()
      GOROOT/src/fmt/print.go:921 +0x132a
  fmt.(*pp).printArg()
      GOROOT/src/fmt/print.go:759 +0xb84
  fmt.(*pp).doPrintf()
      GOROOT/src/fmt/print.go:1075 +0x592
  fmt.Sprintf()
      GOROOT/src/fmt/print.go:239 +0x5c
  gvisor.dev/gvisor/pkg/log.GoogleEmitter.Emit()
      pkg/log/glog.go:82 +0x2b1
  gvisor.dev/gvisor/pkg/log.(*BasicLogger).WarningfAtDepth()
      pkg/log/log.go:234 +0x121
  gvisor.dev/gvisor/pkg/log.WarningfAtDepth()
      pkg/log/log.go:305 +0x71
  gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).Warningf()
      pkg/sentry/kernel/task_log.go:47 +0xcc
  gvisor.dev/gvisor/pkg/sentry/vfs.(*VirtualFilesystem).GenerateProcMountInfo()
      pkg/sentry/vfs/mount.go:1467 +0xaad
  gvisor.dev/gvisor/pkg/sentry/fsimpl/proc.(*mountInfoData).Generate()
      pkg/sentry/fsimpl/proc/task_files.go:1199 +0x328
  gvisor.dev/gvisor/pkg/sentry/vfs.(*DynamicBytesFileDescriptionImpl).preadLocked()
      pkg/sentry/vfs/file_description_impl_util.go:310 +0x1de
  gvisor.dev/gvisor/pkg/sentry/vfs.(*DynamicBytesFileDescriptionImpl).Read()
      pkg/sentry/vfs/file_description_impl_util.go:337 +0x12d
  gvisor.dev/gvisor/pkg/sentry/fsimpl/kernfs.(*DynamicBytesFD).Read()
      pkg/sentry/fsimpl/kernfs/dynamic_bytes_file.go:127 +0xa4
  gvisor.dev/gvisor/pkg/sentry/vfs.(*FileDescription).Read()
      pkg/sentry/vfs/file_description.go:648 +0x159
  gvisor.dev/gvisor/pkg/sentry/syscalls/linux.read()
      pkg/sentry/syscalls/linux/sys_read_write.go:93 +0xa4
  gvisor.dev/gvisor/pkg/sentry/syscalls/linux.Read()
      pkg/sentry/syscalls/linux/sys_read_write.go:62 +0x38e
  gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).executeSyscall()
      pkg/sentry/kernel/task_syscall.go:143 +0xb9e
  gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallInvoke()
      pkg/sentry/kernel/task_syscall.go:323 +0x84
  gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallEnter()
      pkg/sentry/kernel/task_syscall.go:283 +0xc6
  gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscall()
      pkg/sentry/kernel/task_syscall.go:258 +0x549
  gvisor.dev/gvisor/pkg/sentry/kernel.(*runApp).execute()
      pkg/sentry/kernel/task_run.go:263 +0x22f4
  gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run()
      pkg/sentry/kernel/task_run.go:98 +0x39a
  gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).Start.gowrap1()
      pkg/sentry/kernel/task_start.go:393 +0x44

Previous write at 0x00c111d063f0 by goroutine 27886:
  sync/atomic.AddInt32()
      src/runtime/race_amd64.s:281 +0xb
  sync/atomic.AddInt32()
      <autogenerated>:1 +0x14
  gvisor.dev/gvisor/pkg/sync.(*CrossGoroutineMutex).Unlock()
      pkg/sync/mutex_unsafe.go:28 +0xa35
  gvisor.dev/gvisor/pkg/sync.(*Mutex).Unlock()
      pkg/sync/mutex_unsafe.go:65 +0xa30
  gvisor.dev/gvisor/pkg/sentry/vfs.(*VirtualFilesystem).attachTreeLocked()
      pkg/sentry/vfs/mount.go:330 +0xa26
  gvisor.dev/gvisor/pkg/sentry/vfs.(*VirtualFilesystem).ConnectMountAt()
      pkg/sentry/vfs/mount.go:392 +0x446
  gvisor.dev/gvisor/pkg/sentry/vfs.(*VirtualFilesystem).MountAt()
      pkg/sentry/vfs/mount.go:637 +0x1dc
  gvisor.dev/gvisor/pkg/sentry/syscalls/linux.Mount()
      pkg/sentry/syscalls/linux/sys_mount.go:130 +0x7f0
  gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).executeSyscall()
      pkg/sentry/kernel/task_syscall.go:143 +0xb9e
  gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallInvoke()
      pkg/sentry/kernel/task_syscall.go:323 +0x84
  gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscallEnter()
      pkg/sentry/kernel/task_syscall.go:283 +0xc6
  gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).doSyscall()
      pkg/sentry/kernel/task_syscall.go:258 +0x549
  gvisor.dev/gvisor/pkg/sentry/kernel.(*runApp).execute()
      pkg/sentry/kernel/task_run.go:263 +0x22f4
  gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).run()
      pkg/sentry/kernel/task_run.go:98 +0x39a
  gvisor.dev/gvisor/pkg/sentry/kernel.(*Task).Start.gowrap1()
      pkg/sentry/kernel/task_start.go:393 +0x44

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/08/02 12:16 gvisor ef1ca17e5842 1e9c4cf3 .config console log report info ci-gvisor-ptrace-1-race-cover DATA RACE in log.GoogleEmitter.Emit
* Struck through repros no longer work on HEAD.