src/internal/trace/v2/order.go

   1 // Copyright 2023 The Go Authors. All rights reserved.
   2 // Use of this source code is governed by a BSD-style
   3 // license that can be found in the LICENSE file.
   4
   5 package trace
   6
   7 import (
   8         "fmt"
   9         "strings"
  10
  11         "internal/trace/v2/event"
  12         "internal/trace/v2/event/go122"
  13         "internal/trace/v2/version"
  14 )
  15
  16 // ordering emulates Go scheduler state for both validation and
  17 // for putting events in the right order.
  18 type ordering struct {
  19         gStates     map[GoID]*gState
  20         pStates     map[ProcID]*pState // TODO: The keys are dense, so this can be a slice.
  21         mStates     map[ThreadID]*mState
  22         activeTasks map[TaskID]taskState
  23         gcSeq       uint64
  24         gcState     gcState
  25         initialGen  uint64
  26 }
  27
  28 // advance checks if it's valid to proceed with ev which came from thread m.
  29 //
  30 // Returns the schedCtx at the point of the event, whether it's OK to advance
  31 // with this event, and any error encountered in validation.
  32 //
  33 // It assumes the gen value passed to it is monotonically increasing across calls.
  34 //
  35 // If any error is returned, then the trace is broken and trace parsing must cease.
  36 // If it's not valid to advance with ev, but no error was encountered, the caller
  37 // should attempt to advance with other candidate events from other threads. If the
  38 // caller runs out of candidates, the trace is invalid.
  39 func (o *ordering) advance(ev *baseEvent, evt *evTable, m ThreadID, gen uint64) (schedCtx, bool, error) {
  40         if o.initialGen == 0 {
  41                 // Set the initial gen if necessary.
  42                 o.initialGen = gen
  43         }
  44
  45         var curCtx, newCtx schedCtx
  46         curCtx.M = m
  47         newCtx.M = m
  48
  49         if m == NoThread {
  50                 curCtx.P = NoProc
  51                 curCtx.G = NoGoroutine
  52                 newCtx = curCtx
  53         } else {
  54                 // Pull out or create the mState for this event.
  55                 ms, ok := o.mStates[m]
  56                 if !ok {
  57                         ms = &mState{
  58                                 g: NoGoroutine,
  59                                 p: NoProc,
  60                         }
  61                         o.mStates[m] = ms
  62                 }
  63                 curCtx.P = ms.p
  64                 curCtx.G = ms.g
  65                 newCtx = curCtx
  66                 defer func() {
  67                         // Update the mState for this event.
  68                         ms.p = newCtx.P
  69                         ms.g = newCtx.G
  70                 }()
  71         }
  72
  73         switch typ := ev.typ; typ {
  74         // Handle procs.
  75         case go122.EvProcStatus:
  76                 pid := ProcID(ev.args[0])
  77                 status := go122.ProcStatus(ev.args[1])
  78                 oldState := go122ProcStatus2ProcState[status]
  79                 if s, ok := o.pStates[pid]; ok {
  80                         if status == go122.ProcSyscallAbandoned && s.status == go122.ProcSyscall {
  81                                 // ProcSyscallAbandoned is a special case of ProcSyscall. It indicates a
  82                                 // potential loss of information, but if we're already in ProcSyscall,
  83                                 // we haven't lost the relevant information. Promote the status and advance.
  84                                 oldState = ProcRunning
  85                                 ev.args[1] = uint64(go122.ProcSyscall)
  86                         } else if s.status != status {
  87                                 return curCtx, false, fmt.Errorf("inconsistent status for proc %d: old %v vs. new %v", pid, s.status, status)
  88                         }
  89                         s.seq = makeSeq(gen, 0) // Reset seq.
  90                 } else {
  91                         o.pStates[pid] = &pState{id: pid, status: status, seq: makeSeq(gen, 0)}
  92                         if gen == o.initialGen {
  93                                 oldState = ProcUndetermined
  94                         } else {
  95                                 oldState = ProcNotExist
  96                         }
  97                 }
  98                 ev.extra(version.Go122)[0] = uint64(oldState) // Smuggle in the old state for StateTransition.
  99
 100                 // Bind the proc to the new context, if it's running.
 101                 if status == go122.ProcRunning || status == go122.ProcSyscall {
 102                         newCtx.P = pid
 103                 }
 104                 // Set the current context to the state of the M current running this G. Otherwise
 105                 // we'll emit a Running -> Running event that doesn't correspond to the right M.
 106                 if status == go122.ProcSyscallAbandoned && oldState != ProcUndetermined {
 107                         // N.B. This is slow but it should be fairly rare.
 108                         found := false
 109                         for mid, ms := range o.mStates {
 110                                 if ms.p == pid {
 111                                         curCtx.M = mid
 112                                         curCtx.P = pid
 113                                         curCtx.G = ms.g
 114                                         found = true
 115                                 }
 116                         }
 117                         if !found {
 118                                 return curCtx, false, fmt.Errorf("failed to find sched context for proc %d that's about to be stolen", pid)
 119                         }
 120                 }
 121                 return curCtx, true, nil
 122         case go122.EvProcStart:
 123                 pid := ProcID(ev.args[0])
 124                 seq := makeSeq(gen, ev.args[1])
 125
 126                 // Try to advance. We might fail here due to sequencing, because the P hasn't
 127                 // had a status emitted, or because we already have a P and we're in a syscall,
 128                 // and we haven't observed that it was stolen from us yet.
 129                 state, ok := o.pStates[pid]
 130                 if !ok || state.status != go122.ProcIdle || !seq.succeeds(state.seq) || curCtx.P != NoProc {
 131                         // We can't make an inference as to whether this is bad. We could just be seeing
 132                         // a ProcStart on a different M before the proc's state was emitted, or before we
 133                         // got to the right point in the trace.
 134                         //
 135                         // Note that we also don't advance here if we have a P and we're in a syscall.
 136                         return curCtx, false, nil
 137                 }
 138                 // We can advance this P. Check some invariants.
 139                 //
 140                 // We might have a goroutine if a goroutine is exiting a syscall.
 141                 reqs := event.SchedReqs{Thread: event.MustHave, Proc: event.MustNotHave, Goroutine: event.MayHave}
 142                 if err := validateCtx(curCtx, reqs); err != nil {
 143                         return curCtx, false, err
 144                 }
 145                 state.status = go122.ProcRunning
 146                 state.seq = seq
 147                 newCtx.P = pid
 148                 return curCtx, true, nil
 149         case go122.EvProcStop:
 150                 // We must be able to advance this P.
 151                 //
 152                 // There are 2 ways a P can stop: ProcStop and ProcSteal. ProcStop is used when the P
 153                 // is stopped by the same M that started it, while ProcSteal is used when another M
 154                 // steals the P by stopping it from a distance.
 155                 //
 156                 // Since a P is bound to an M, and we're stopping on the same M we started, it must
 157                 // always be possible to advance the current M's P from a ProcStop. This is also why
 158                 // ProcStop doesn't need a sequence number.
 159                 state, ok := o.pStates[curCtx.P]
 160                 if !ok {
 161                         return curCtx, false, fmt.Errorf("event %s for proc (%v) that doesn't exist", go122.EventString(typ), curCtx.P)
 162                 }
 163                 if state.status != go122.ProcRunning && state.status != go122.ProcSyscall {
 164                         return curCtx, false, fmt.Errorf("%s event for proc that's not %s or %s", go122.EventString(typ), go122.ProcRunning, go122.ProcSyscall)
 165                 }
 166                 reqs := event.SchedReqs{Thread: event.MustHave, Proc: event.MustHave, Goroutine: event.MayHave}
 167                 if err := validateCtx(curCtx, reqs); err != nil {
 168                         return curCtx, false, err
 169                 }
 170                 state.status = go122.ProcIdle
 171                 newCtx.P = NoProc
 172                 return curCtx, true, nil
 173         case go122.EvProcSteal:
 174                 pid := ProcID(ev.args[0])
 175                 seq := makeSeq(gen, ev.args[1])
 176                 state, ok := o.pStates[pid]
 177                 if !ok || (state.status != go122.ProcSyscall && state.status != go122.ProcSyscallAbandoned) || !seq.succeeds(state.seq) {
 178                         // We can't make an inference as to whether this is bad. We could just be seeing
 179                         // a ProcStart on a different M before the proc's state was emitted, or before we
 180                         // got to the right point in the trace.
 181                         return curCtx, false, nil
 182                 }
 183                 // We can advance this P. Check some invariants.
 184                 reqs := event.SchedReqs{Thread: event.MustHave, Proc: event.MayHave, Goroutine: event.MayHave}
 185                 if err := validateCtx(curCtx, reqs); err != nil {
 186                         return curCtx, false, err
 187                 }
 188                 // Smuggle in the P state that let us advance so we can surface information to the event.
 189                 // Specifically, we need to make sure that the event is interpreted not as a transition of
 190                 // ProcRunning -> ProcIdle but ProcIdle -> ProcIdle instead.
 191                 //
 192                 // ProcRunning is binding, but we may be running with a P on the current M and we can't
 193                 // bind another P. This P is about to go ProcIdle anyway.
 194                 oldStatus := state.status
 195                 ev.extra(version.Go122)[0] = uint64(oldStatus)
 196
 197                 // Update the P's status and sequence number.
 198                 state.status = go122.ProcIdle
 199                 state.seq = seq
 200
 201                 // If we've lost information then don't try to do anything with the M.
 202                 // It may have moved on and we can't be sure.
 203                 if oldStatus == go122.ProcSyscallAbandoned {
 204                         return curCtx, true, nil
 205                 }
 206
 207                 // Validate that the M we're stealing from is what we expect.
 208                 mid := ThreadID(ev.args[2]) // The M we're stealing from.
 209                 mState, ok := o.mStates[mid]
 210                 if !ok {
 211                         return curCtx, false, fmt.Errorf("stole proc from non-existent thread %d", mid)
 212                 }
 213
 214                 // Make sure we're actually stealing the right P.
 215                 if mState.p != pid {
 216                         return curCtx, false, fmt.Errorf("tried to steal proc %d from thread %d, but got proc %d instead", pid, mid, mState.p)
 217                 }
 218
 219                 // Tell the M it has no P so it can proceed.
 220                 //
 221                 // This is safe because we know the P was in a syscall and
 222                 // the other M must be trying to get out of the syscall.
 223                 // GoSyscallEndBlocked cannot advance until the corresponding
 224                 // M loses its P.
 225                 mState.p = NoProc
 226                 return curCtx, true, nil
 227
 228         // Handle goroutines.
 229         case go122.EvGoStatus:
 230                 gid := GoID(ev.args[0])
 231                 mid := ThreadID(ev.args[1])
 232                 status := go122.GoStatus(ev.args[2])
 233                 oldState := go122GoStatus2GoState[status]
 234                 if s, ok := o.gStates[gid]; ok {
 235                         if s.status != status {
 236                                 return curCtx, false, fmt.Errorf("inconsistent status for goroutine %d: old %v vs. new %v", gid, s.status, status)
 237                         }
 238                         s.seq = makeSeq(gen, 0) // Reset seq.
 239                 } else if gen == o.initialGen {
 240                         // Set the state.
 241                         o.gStates[gid] = &gState{id: gid, status: status, seq: makeSeq(gen, 0)}
 242                         oldState = GoUndetermined
 243                 } else {
 244                         return curCtx, false, fmt.Errorf("found goroutine status for new goroutine after the first generation: id=%v status=%v", gid, status)
 245                 }
 246                 ev.extra(version.Go122)[0] = uint64(oldState) // Smuggle in the old state for StateTransition.
 247
 248                 switch status {
 249                 case go122.GoRunning:
 250                         // Bind the goroutine to the new context, since it's running.
 251                         newCtx.G = gid
 252                 case go122.GoSyscall:
 253                         if mid == NoThread {
 254                                 return curCtx, false, fmt.Errorf("found goroutine %d in syscall without a thread", gid)
 255                         }
 256                         // Is the syscall on this thread? If so, bind it to the context.
 257                         // Otherwise, we're talking about a G sitting in a syscall on an M.
 258                         // Validate the named M.
 259                         if mid == curCtx.M {
 260                                 newCtx.G = gid
 261                                 break
 262                         }
 263                         // Now we're talking about a thread and goroutine that have been
 264                         // blocked on a syscall for the entire generation. This case must
 265                         // not have a P; the runtime makes sure that all Ps are traced at
 266                         // the beginning of a generation, which involves taking a P back
 267                         // from every thread.
 268                         ms, ok := o.mStates[mid]
 269                         if ok {
 270                                 // This M has been seen. That means we must have seen this
 271                                 // goroutine go into a syscall on this thread at some point.
 272                                 if ms.g != gid {
 273                                         // But the G on the M doesn't match. Something's wrong.
 274                                         return curCtx, false, fmt.Errorf("inconsistent thread for syscalling goroutine %d: thread has goroutine %d", gid, ms.g)
 275                                 }
 276                                 // This case is just a Syscall->Syscall event, which needs to
 277                                 // appear as having the G currently bound to this M.
 278                                 curCtx.G = ms.g
 279                         } else if !ok {
 280                                 // The M hasn't been seen yet. That means this goroutine
 281                                 // has just been sitting in a syscall on this M. Create
 282                                 // a state for it.
 283                                 o.mStates[mid] = &mState{g: gid, p: NoProc}
 284                                 // Don't set curCtx.G in this case because this event is the
 285                                 // binding event (and curCtx represents the "before" state).
 286                         }
 287                         // Update the current context to the M we're talking about.
 288                         curCtx.M = mid
 289                 }
 290                 return curCtx, true, nil
 291         case go122.EvGoCreate:
 292                 // Goroutines must be created on a running P, but may or may not be created
 293                 // by a running goroutine.
 294                 reqs := event.SchedReqs{Thread: event.MustHave, Proc: event.MustHave, Goroutine: event.MayHave}
 295                 if err := validateCtx(curCtx, reqs); err != nil {
 296                         return curCtx, false, err
 297                 }
 298                 // If we have a goroutine, it must be running.
 299                 if state, ok := o.gStates[curCtx.G]; ok && state.status != go122.GoRunning {
 300                         return curCtx, false, fmt.Errorf("%s event for goroutine that's not %s", go122.EventString(typ), GoRunning)
 301                 }
 302                 // This goroutine created another. Add a state for it.
 303                 newgid := GoID(ev.args[0])
 304                 if _, ok := o.gStates[newgid]; ok {
 305                         return curCtx, false, fmt.Errorf("tried to create goroutine (%v) that already exists", newgid)
 306                 }
 307                 o.gStates[newgid] = &gState{id: newgid, status: go122.GoRunnable, seq: makeSeq(gen, 0)}
 308                 return curCtx, true, nil
 309         case go122.EvGoDestroy, go122.EvGoStop, go122.EvGoBlock:
 310                 // These are goroutine events that all require an active running
 311                 // goroutine on some thread. They must *always* be advance-able,
 312                 // since running goroutines are bound to their M.
 313                 if err := validateCtx(curCtx, event.UserGoReqs); err != nil {
 314                         return curCtx, false, err
 315                 }
 316                 state, ok := o.gStates[curCtx.G]
 317                 if !ok {
 318                         return curCtx, false, fmt.Errorf("event %s for goroutine (%v) that doesn't exist", go122.EventString(typ), curCtx.G)
 319                 }
 320                 if state.status != go122.GoRunning {
 321                         return curCtx, false, fmt.Errorf("%s event for goroutine that's not %s", go122.EventString(typ), GoRunning)
 322                 }
 323                 // Handle each case slightly differently; we just group them together
 324                 // because they have shared preconditions.
 325                 switch typ {
 326                 case go122.EvGoDestroy:
 327                         // This goroutine is exiting itself.
 328                         delete(o.gStates, curCtx.G)
 329                         newCtx.G = NoGoroutine
 330                 case go122.EvGoStop:
 331                         // Goroutine stopped (yielded). It's runnable but not running on this M.
 332                         state.status = go122.GoRunnable
 333                         newCtx.G = NoGoroutine
 334                 case go122.EvGoBlock:
 335                         // Goroutine blocked. It's waiting now and not running on this M.
 336                         state.status = go122.GoWaiting
 337                         newCtx.G = NoGoroutine
 338                 }
 339                 return curCtx, true, nil
 340         case go122.EvGoStart:
 341                 gid := GoID(ev.args[0])
 342                 seq := makeSeq(gen, ev.args[1])
 343                 state, ok := o.gStates[gid]
 344                 if !ok || state.status != go122.GoRunnable || !seq.succeeds(state.seq) {
 345                         // We can't make an inference as to whether this is bad. We could just be seeing
 346                         // a GoStart on a different M before the goroutine was created, before it had its
 347                         // state emitted, or before we got to the right point in the trace yet.
 348                         return curCtx, false, nil
 349                 }
 350                 // We can advance this goroutine. Check some invariants.
 351                 reqs := event.SchedReqs{Thread: event.MustHave, Proc: event.MustHave, Goroutine: event.MustNotHave}
 352                 if err := validateCtx(curCtx, reqs); err != nil {
 353                         return curCtx, false, err
 354                 }
 355                 state.status = go122.GoRunning
 356                 state.seq = seq
 357                 newCtx.G = gid
 358                 return curCtx, true, nil
 359         case go122.EvGoUnblock:
 360                 // N.B. These both reference the goroutine to unblock, not the current goroutine.
 361                 gid := GoID(ev.args[0])
 362                 seq := makeSeq(gen, ev.args[1])
 363                 state, ok := o.gStates[gid]
 364                 if !ok || state.status != go122.GoWaiting || !seq.succeeds(state.seq) {
 365                         // We can't make an inference as to whether this is bad. We could just be seeing
 366                         // a GoUnblock on a different M before the goroutine was created and blocked itself,
 367                         // before it had its state emitted, or before we got to the right point in the trace yet.
 368                         return curCtx, false, nil
 369                 }
 370                 state.status = go122.GoRunnable
 371                 state.seq = seq
 372                 // N.B. No context to validate. Basically anything can unblock
 373                 // a goroutine (e.g. sysmon).
 374                 return curCtx, true, nil
 375         case go122.EvGoSyscallBegin:
 376                 // Entering a syscall requires an active running goroutine with a
 377                 // proc on some thread. It is always advancable.
 378                 if err := validateCtx(curCtx, event.UserGoReqs); err != nil {
 379                         return curCtx, false, err
 380                 }
 381                 state, ok := o.gStates[curCtx.G]
 382                 if !ok {
 383                         return curCtx, false, fmt.Errorf("event %s for goroutine (%v) that doesn't exist", go122.EventString(typ), curCtx.G)
 384                 }
 385                 if state.status != go122.GoRunning {
 386                         return curCtx, false, fmt.Errorf("%s event for goroutine that's not %s", go122.EventString(typ), GoRunning)
 387                 }
 388                 // Goroutine entered a syscall. It's still running on this P and M.
 389                 state.status = go122.GoSyscall
 390                 pState, ok := o.pStates[curCtx.P]
 391                 if !ok {
 392                         return curCtx, false, fmt.Errorf("uninitialized proc %d found during %s", curCtx.P, go122.EventString(typ))
 393                 }
 394                 pState.status = go122.ProcSyscall
 395                 // Validate the P sequence number on the event and advance it.
 396                 //
 397                 // We have a P sequence number for what is supposed to be a goroutine event
 398                 // so that we can correctly model P stealing. Without this sequence number here,
 399                 // the syscall from which a ProcSteal event is stealing can be ambiguous in the
 400                 // face of broken timestamps. See the go122-syscall-steal-proc-ambiguous test for
 401                 // more details.
 402                 //
 403                 // Note that because this sequence number only exists as a tool for disambiguation,
 404                 // we can enforce that we have the right sequence number at this point; we don't need
 405                 // to back off and see if any other events will advance. This is a running P.
 406                 pSeq := makeSeq(gen, ev.args[0])
 407                 if !pSeq.succeeds(pState.seq) {
 408                         return curCtx, false, fmt.Errorf("failed to advance %s: can't make sequence: %s -> %s", go122.EventString(typ), pState.seq, pSeq)
 409                 }
 410                 pState.seq = pSeq
 411                 return curCtx, true, nil
 412         case go122.EvGoSyscallEnd:
 413                 // This event is always advance-able because it happens on the same
 414                 // thread that EvGoSyscallStart happened, and the goroutine can't leave
 415                 // that thread until its done.
 416                 if err := validateCtx(curCtx, event.UserGoReqs); err != nil {
 417                         return curCtx, false, err
 418                 }
 419                 state, ok := o.gStates[curCtx.G]
 420                 if !ok {
 421                         return curCtx, false, fmt.Errorf("event %s for goroutine (%v) that doesn't exist", go122.EventString(typ), curCtx.G)
 422                 }
 423                 if state.status != go122.GoSyscall {
 424                         return curCtx, false, fmt.Errorf("%s event for goroutine that's not %s", go122.EventString(typ), GoRunning)
 425                 }
 426                 state.status = go122.GoRunning
 427
 428                 // Transfer the P back to running from syscall.
 429                 pState, ok := o.pStates[curCtx.P]
 430                 if !ok {
 431                         return curCtx, false, fmt.Errorf("uninitialized proc %d found during %s", curCtx.P, go122.EventString(typ))
 432                 }
 433                 if pState.status != go122.ProcSyscall {
 434                         return curCtx, false, fmt.Errorf("expected proc %d in state %v, but got %v instead", curCtx.P, go122.ProcSyscall, pState.status)
 435                 }
 436                 pState.status = go122.ProcRunning
 437                 return curCtx, true, nil
 438         case go122.EvGoSyscallEndBlocked:
 439                 // This event becomes advanceable when its P is not in a syscall state
 440                 // (lack of a P altogether is also acceptable for advancing).
 441                 // The transfer out of ProcSyscall can happen either voluntarily via
 442                 // ProcStop or involuntarily via ProcSteal. We may also acquire a new P
 443                 // before we get here (after the transfer out) but that's OK: that new
 444                 // P won't be in the ProcSyscall state anymore.
 445                 //
 446                 // Basically: while we have a preemptible P, don't advance, because we
 447                 // *know* from the event that we're going to lose it at some point during
 448                 // the syscall. We shouldn't advance until that happens.
 449                 if curCtx.P != NoProc {
 450                         pState, ok := o.pStates[curCtx.P]
 451                         if !ok {
 452                                 return curCtx, false, fmt.Errorf("uninitialized proc %d found during %s", curCtx.P, go122.EventString(typ))
 453                         }
 454                         if pState.status == go122.ProcSyscall {
 455                                 return curCtx, false, nil
 456                         }
 457                 }
 458                 // As mentioned above, we may have a P here if we ProcStart
 459                 // before this event.
 460                 if err := validateCtx(curCtx, event.SchedReqs{Thread: event.MustHave, Proc: event.MayHave, Goroutine: event.MustHave}); err != nil {
 461                         return curCtx, false, err
 462                 }
 463                 state, ok := o.gStates[curCtx.G]
 464                 if !ok {
 465                         return curCtx, false, fmt.Errorf("event %s for goroutine (%v) that doesn't exist", go122.EventString(typ), curCtx.G)
 466                 }
 467                 if state.status != go122.GoSyscall {
 468                         return curCtx, false, fmt.Errorf("%s event for goroutine that's not %s", go122.EventString(typ), GoRunning)
 469                 }
 470                 newCtx.G = NoGoroutine
 471                 state.status = go122.GoRunnable
 472                 return curCtx, true, nil
 473         case go122.EvGoCreateSyscall:
 474                 // This event indicates that a goroutine is effectively
 475                 // being created out of a cgo callback. Such a goroutine
 476                 // is 'created' in the syscall state.
 477                 if err := validateCtx(curCtx, event.SchedReqs{Thread: event.MustHave, Proc: event.MustNotHave, Goroutine: event.MustNotHave}); err != nil {
 478                         return curCtx, false, err
 479                 }
 480                 // This goroutine is effectively being created. Add a state for it.
 481                 newgid := GoID(ev.args[0])
 482                 if _, ok := o.gStates[newgid]; ok {
 483                         return curCtx, false, fmt.Errorf("tried to create goroutine (%v) in syscall that already exists", newgid)
 484                 }
 485                 o.gStates[newgid] = &gState{id: newgid, status: go122.GoSyscall, seq: makeSeq(gen, 0)}
 486                 // Goroutine is executing. Bind it to the context.
 487                 newCtx.G = newgid
 488                 return curCtx, true, nil
 489         case go122.EvGoDestroySyscall:
 490                 // This event indicates that a goroutine created for a
 491                 // cgo callback is disappearing, either because the callback
 492                 // ending or the C thread that called it is being destroyed.
 493                 //
 494                 // Note: we might have a P here. The P might not be released
 495                 // eagerly by the runtime, and it might get stolen back later
 496                 // (or never again, if the program is going to exit).
 497                 if err := validateCtx(curCtx, event.SchedReqs{Thread: event.MustHave, Proc: event.MayHave, Goroutine: event.MustHave}); err != nil {
 498                         return curCtx, false, err
 499                 }
 500                 // Check to make sure the goroutine exists in the right state.
 501                 state, ok := o.gStates[curCtx.G]
 502                 if !ok {
 503                         return curCtx, false, fmt.Errorf("event %s for goroutine (%v) that doesn't exist", go122.EventString(typ), curCtx.G)
 504                 }
 505                 if state.status != go122.GoSyscall {
 506                         return curCtx, false, fmt.Errorf("%s event for goroutine that's not %v", go122.EventString(typ), GoSyscall)
 507                 }
 508                 // This goroutine is exiting itself.
 509                 delete(o.gStates, curCtx.G)
 510                 newCtx.G = NoGoroutine
 511                 return curCtx, true, nil
 512
 513         // Handle tasks. Tasks are interesting because:
 514         // - There's no Begin event required to reference a task.
 515         // - End for a particular task ID can appear multiple times.
 516         // As a result, there's very little to validate. The only
 517         // thing we have to be sure of is that a task didn't begin
 518         // after it had already begun. Task IDs are allowed to be
 519         // reused, so we don't care about a Begin after an End.
 520         case go122.EvUserTaskBegin:
 521                 id := TaskID(ev.args[0])
 522                 if _, ok := o.activeTasks[id]; ok {
 523                         return curCtx, false, fmt.Errorf("task ID conflict: %d", id)
 524                 }
 525                 // Get the parent ID, but don't validate it. There's no guarantee
 526                 // we actually have information on whether it's active.
 527                 parentID := TaskID(ev.args[1])
 528
 529                 // Validate the name and record it. We'll need to pass it through to
 530                 // EvUserTaskEnd.
 531                 nameID := stringID(ev.args[2])
 532                 name, ok := evt.strings.get(nameID)
 533                 if !ok {
 534                         return curCtx, false, fmt.Errorf("invalid string ID %v for %v event", nameID, typ)
 535                 }
 536                 o.activeTasks[id] = taskState{name: name, parentID: parentID}
 537                 return curCtx, true, validateCtx(curCtx, event.UserGoReqs)
 538         case go122.EvUserTaskEnd:
 539                 id := TaskID(ev.args[0])
 540                 if ts, ok := o.activeTasks[id]; ok {
 541                         // Smuggle the task info. This may happen in a different generation,
 542                         // which may not have the name in its string table. Add it to the extra
 543                         // strings table so we can look it up later.
 544                         ev.extra(version.Go122)[0] = uint64(ts.parentID)
 545                         ev.extra(version.Go122)[1] = uint64(evt.addExtraString(ts.name))
 546                         delete(o.activeTasks, id)
 547                 } else {
 548                         // Explicitly clear the task info.
 549                         ev.extra(version.Go122)[0] = uint64(NoTask)
 550                         ev.extra(version.Go122)[1] = uint64(evt.addExtraString(""))
 551                 }
 552                 return curCtx, true, validateCtx(curCtx, event.UserGoReqs)
 553
 554         // Handle user regions.
 555         case go122.EvUserRegionBegin:
 556                 if err := validateCtx(curCtx, event.UserGoReqs); err != nil {
 557                         return curCtx, false, err
 558                 }
 559                 tid := TaskID(ev.args[0])
 560                 nameID := stringID(ev.args[1])
 561                 name, ok := evt.strings.get(nameID)
 562                 if !ok {
 563                         return curCtx, false, fmt.Errorf("invalid string ID %v for %v event", nameID, typ)
 564                 }
 565                 if err := o.gStates[curCtx.G].beginRegion(userRegion{tid, name}); err != nil {
 566                         return curCtx, false, err
 567                 }
 568                 return curCtx, true, nil
 569         case go122.EvUserRegionEnd:
 570                 if err := validateCtx(curCtx, event.UserGoReqs); err != nil {
 571                         return curCtx, false, err
 572                 }
 573                 tid := TaskID(ev.args[0])
 574                 nameID := stringID(ev.args[1])
 575                 name, ok := evt.strings.get(nameID)
 576                 if !ok {
 577                         return curCtx, false, fmt.Errorf("invalid string ID %v for %v event", nameID, typ)
 578                 }
 579                 if err := o.gStates[curCtx.G].endRegion(userRegion{tid, name}); err != nil {
 580                         return curCtx, false, err
 581                 }
 582                 return curCtx, true, nil
 583
 584         // Handle the GC mark phase.
 585         //
 586         // We have sequence numbers for both start and end because they
 587         // can happen on completely different threads. We want an explicit
 588         // partial order edge between start and end here, otherwise we're
 589         // relying entirely on timestamps to make sure we don't advance a
 590         // GCEnd for a _different_ GC cycle if timestamps are wildly broken.
 591         case go122.EvGCActive:
 592                 seq := ev.args[0]
 593                 if gen == o.initialGen {
 594                         if o.gcState != gcUndetermined {
 595                                 return curCtx, false, fmt.Errorf("GCActive in the first generation isn't first GC event")
 596                         }
 597                         o.gcSeq = seq
 598                         o.gcState = gcRunning
 599                         return curCtx, true, nil
 600                 }
 601                 if seq != o.gcSeq+1 {
 602                         // This is not the right GC cycle.
 603                         return curCtx, false, nil
 604                 }
 605                 if o.gcState != gcRunning {
 606                         return curCtx, false, fmt.Errorf("encountered GCActive while GC was not in progress")
 607                 }
 608                 o.gcSeq = seq
 609                 if err := validateCtx(curCtx, event.UserGoReqs); err != nil {
 610                         return curCtx, false, err
 611                 }
 612                 return curCtx, true, nil
 613         case go122.EvGCBegin:
 614                 seq := ev.args[0]
 615                 if o.gcState == gcUndetermined {
 616                         o.gcSeq = seq
 617                         o.gcState = gcRunning
 618                         return curCtx, true, nil
 619                 }
 620                 if seq != o.gcSeq+1 {
 621                         // This is not the right GC cycle.
 622                         return curCtx, false, nil
 623                 }
 624                 if o.gcState == gcRunning {
 625                         return curCtx, false, fmt.Errorf("encountered GCBegin while GC was already in progress")
 626                 }
 627                 o.gcSeq = seq
 628                 o.gcState = gcRunning
 629                 if err := validateCtx(curCtx, event.UserGoReqs); err != nil {
 630                         return curCtx, false, err
 631                 }
 632                 return curCtx, true, nil
 633         case go122.EvGCEnd:
 634                 seq := ev.args[0]
 635                 if seq != o.gcSeq+1 {
 636                         // This is not the right GC cycle.
 637                         return curCtx, false, nil
 638                 }
 639                 if o.gcState == gcNotRunning {
 640                         return curCtx, false, fmt.Errorf("encountered GCEnd when GC was not in progress")
 641                 }
 642                 if o.gcState == gcUndetermined {
 643                         return curCtx, false, fmt.Errorf("encountered GCEnd when GC was in an undetermined state")
 644                 }
 645                 o.gcSeq = seq
 646                 o.gcState = gcNotRunning
 647                 if err := validateCtx(curCtx, event.UserGoReqs); err != nil {
 648                         return curCtx, false, err
 649                 }
 650                 return curCtx, true, nil
 651
 652         // Handle simple instantaneous events that require a G.
 653         case go122.EvGoLabel, go122.EvProcsChange, go122.EvUserLog:
 654                 if err := validateCtx(curCtx, event.UserGoReqs); err != nil {
 655                         return curCtx, false, err
 656                 }
 657                 return curCtx, true, nil
 658
 659         // Handle allocation states, which don't require a G.
 660         case go122.EvHeapAlloc, go122.EvHeapGoal:
 661                 if err := validateCtx(curCtx, event.SchedReqs{Thread: event.MustHave, Proc: event.MustHave, Goroutine: event.MayHave}); err != nil {
 662                         return curCtx, false, err
 663                 }
 664                 return curCtx, true, nil
 665
 666         // Handle sweep, which is bound to a P and doesn't require a G.
 667         case go122.EvGCSweepBegin:
 668                 if err := validateCtx(curCtx, event.SchedReqs{Thread: event.MustHave, Proc: event.MustHave, Goroutine: event.MayHave}); err != nil {
 669                         return curCtx, false, err
 670                 }
 671                 if err := o.pStates[curCtx.P].beginRange(makeRangeType(typ, 0)); err != nil {
 672                         return curCtx, false, err
 673                 }
 674                 return curCtx, true, nil
 675         case go122.EvGCSweepActive:
 676                 pid := ProcID(ev.args[0])
 677                 // N.B. In practice Ps can't block while they're sweeping, so this can only
 678                 // ever reference curCtx.P. However, be lenient about this like we are with
 679                 // GCMarkAssistActive; there's no reason the runtime couldn't change to block
 680                 // in the middle of a sweep.
 681                 if err := o.pStates[pid].activeRange(makeRangeType(typ, 0), gen == o.initialGen); err != nil {
 682                         return curCtx, false, err
 683                 }
 684                 return curCtx, true, nil
 685         case go122.EvGCSweepEnd:
 686                 if err := validateCtx(curCtx, event.SchedReqs{Thread: event.MustHave, Proc: event.MustHave, Goroutine: event.MayHave}); err != nil {
 687                         return curCtx, false, err
 688                 }
 689                 _, err := o.pStates[curCtx.P].endRange(typ)
 690                 if err != nil {
 691                         return curCtx, false, err
 692                 }
 693                 return curCtx, true, nil
 694
 695         // Handle special goroutine-bound event ranges.
 696         case go122.EvSTWBegin, go122.EvGCMarkAssistBegin:
 697                 if err := validateCtx(curCtx, event.UserGoReqs); err != nil {
 698                         return curCtx, false, err
 699                 }
 700                 desc := stringID(0)
 701                 if typ == go122.EvSTWBegin {
 702                         desc = stringID(ev.args[0])
 703                 }
 704                 if err := o.gStates[curCtx.G].beginRange(makeRangeType(typ, desc)); err != nil {
 705                         return curCtx, false, err
 706                 }
 707                 return curCtx, true, nil
 708         case go122.EvGCMarkAssistActive:
 709                 gid := GoID(ev.args[0])
 710                 // N.B. Like GoStatus, this can happen at any time, because it can
 711                 // reference a non-running goroutine. Don't check anything about the
 712                 // current scheduler context.
 713                 if err := o.gStates[gid].activeRange(makeRangeType(typ, 0), gen == o.initialGen); err != nil {
 714                         return curCtx, false, err
 715                 }
 716                 return curCtx, true, nil
 717         case go122.EvSTWEnd, go122.EvGCMarkAssistEnd:
 718                 if err := validateCtx(curCtx, event.UserGoReqs); err != nil {
 719                         return curCtx, false, err
 720                 }
 721                 desc, err := o.gStates[curCtx.G].endRange(typ)
 722                 if err != nil {
 723                         return curCtx, false, err
 724                 }
 725                 if typ == go122.EvSTWEnd {
 726                         // Smuggle the kind into the event.
 727                         // Don't use ev.extra here so we have symmetry with STWBegin.
 728                         ev.args[0] = uint64(desc)
 729                 }
 730                 return curCtx, true, nil
 731         }
 732         return curCtx, false, fmt.Errorf("bad event type found while ordering: %v", ev.typ)
 733 }
 734
 735 // schedCtx represents the scheduling resources associated with an event.
 736 type schedCtx struct {
 737         G GoID
 738         P ProcID
 739         M ThreadID
 740 }
 741
 742 // validateCtx ensures that ctx conforms to some reqs, returning an error if
 743 // it doesn't.
 744 func validateCtx(ctx schedCtx, reqs event.SchedReqs) error {
 745         // Check thread requirements.
 746         if reqs.Thread == event.MustHave && ctx.M == NoThread {
 747                 return fmt.Errorf("expected a thread but didn't have one")
 748         } else if reqs.Thread == event.MustNotHave && ctx.M != NoThread {
 749                 return fmt.Errorf("expected no thread but had one")
 750         }
 751
 752         // Check proc requirements.
 753         if reqs.Proc == event.MustHave && ctx.P == NoProc {
 754                 return fmt.Errorf("expected a proc but didn't have one")
 755         } else if reqs.Proc == event.MustNotHave && ctx.P != NoProc {
 756                 return fmt.Errorf("expected no proc but had one")
 757         }
 758
 759         // Check goroutine requirements.
 760         if reqs.Goroutine == event.MustHave && ctx.G == NoGoroutine {
 761                 return fmt.Errorf("expected a goroutine but didn't have one")
 762         } else if reqs.Goroutine == event.MustNotHave && ctx.G != NoGoroutine {
 763                 return fmt.Errorf("expected no goroutine but had one")
 764         }
 765         return nil
 766 }
 767
 768 // gcState is a trinary variable for the current state of the GC.
 769 //
 770 // The third state besides "enabled" and "disabled" is "undetermined."
 771 type gcState uint8
 772
 773 const (
 774         gcUndetermined gcState = iota
 775         gcNotRunning
 776         gcRunning
 777 )
 778
 779 // String returns a human-readable string for the GC state.
 780 func (s gcState) String() string {
 781         switch s {
 782         case gcUndetermined:
 783                 return "Undetermined"
 784         case gcNotRunning:
 785                 return "NotRunning"
 786         case gcRunning:
 787                 return "Running"
 788         }
 789         return "Bad"
 790 }
 791
 792 // userRegion represents a unique user region when attached to some gState.
 793 type userRegion struct {
 794         // name must be a resolved string because the string ID for the same
 795         // string may change across generations, but we care about checking
 796         // the value itself.
 797         taskID TaskID
 798         name   string
 799 }
 800
 801 // rangeType is a way to classify special ranges of time.
 802 //
 803 // These typically correspond 1:1 with "Begin" events, but
 804 // they may have an optional subtype that describes the range
 805 // in more detail.
 806 type rangeType struct {
 807         typ  event.Type // "Begin" event.
 808         desc stringID   // Optional subtype.
 809 }
 810
 811 // makeRangeType constructs a new rangeType.
 812 func makeRangeType(typ event.Type, desc stringID) rangeType {
 813         if styp := go122.Specs()[typ].StartEv; styp != go122.EvNone {
 814                 typ = styp
 815         }
 816         return rangeType{typ, desc}
 817 }
 818
 819 // gState is the state of a goroutine at a point in the trace.
 820 type gState struct {
 821         id     GoID
 822         status go122.GoStatus
 823         seq    seqCounter
 824
 825         // regions are the active user regions for this goroutine.
 826         regions []userRegion
 827
 828         // rangeState is the state of special time ranges bound to this goroutine.
 829         rangeState
 830 }
 831
 832 // beginRegion starts a user region on the goroutine.
 833 func (s *gState) beginRegion(r userRegion) error {
 834         s.regions = append(s.regions, r)
 835         return nil
 836 }
 837
 838 // endRegion ends a user region on the goroutine.
 839 func (s *gState) endRegion(r userRegion) error {
 840         if next := s.regions[len(s.regions)-1]; next != r {
 841                 return fmt.Errorf("misuse of region in goroutine %v: region end %v when the inner-most active region start event is %v", s.id, r, next)
 842         }
 843         s.regions = s.regions[:len(s.regions)-1]
 844         return nil
 845 }
 846
 847 // pState is the state of a proc at a point in the trace.
 848 type pState struct {
 849         id     ProcID
 850         status go122.ProcStatus
 851         seq    seqCounter
 852
 853         // rangeState is the state of special time ranges bound to this proc.
 854         rangeState
 855 }
 856
 857 // mState is the state of a thread at a point in the trace.
 858 type mState struct {
 859         g GoID   // Goroutine bound to this M. (The goroutine's state is Executing.)
 860         p ProcID // Proc bound to this M. (The proc's state is Executing.)
 861 }
 862
 863 // rangeState represents the state of special time ranges.
 864 type rangeState struct {
 865         // inFlight contains the rangeTypes of any ranges bound to a resource.
 866         inFlight []rangeType
 867 }
 868
 869 // beginRange begins a special range in time on the goroutine.
 870 //
 871 // Returns an error if the range is already in progress.
 872 func (s *rangeState) beginRange(typ rangeType) error {
 873         if s.hasRange(typ) {
 874                 return fmt.Errorf("discovered event already in-flight for when starting event %v", go122.Specs()[typ.typ].Name)
 875         }
 876         s.inFlight = append(s.inFlight, typ)
 877         return nil
 878 }
 879
 880 // activeRange marks special range in time on the goroutine as active in the
 881 // initial generation, or confirms that it is indeed active in later generations.
 882 func (s *rangeState) activeRange(typ rangeType, isInitialGen bool) error {
 883         if isInitialGen {
 884                 if s.hasRange(typ) {
 885                         return fmt.Errorf("found named active range already in first gen: %v", typ)
 886                 }
 887                 s.inFlight = append(s.inFlight, typ)
 888         } else if !s.hasRange(typ) {
 889                 return fmt.Errorf("resource is missing active range: %v %v", go122.Specs()[typ.typ].Name, s.inFlight)
 890         }
 891         return nil
 892 }
 893
 894 // hasRange returns true if a special time range on the goroutine as in progress.
 895 func (s *rangeState) hasRange(typ rangeType) bool {
 896         for _, ftyp := range s.inFlight {
 897                 if ftyp == typ {
 898                         return true
 899                 }
 900         }
 901         return false
 902 }
 903
 904 // endsRange ends a special range in time on the goroutine.
 905 //
 906 // This must line up with the start event type  of the range the goroutine is currently in.
 907 func (s *rangeState) endRange(typ event.Type) (stringID, error) {
 908         st := go122.Specs()[typ].StartEv
 909         idx := -1
 910         for i, r := range s.inFlight {
 911                 if r.typ == st {
 912                         idx = i
 913                         break
 914                 }
 915         }
 916         if idx < 0 {
 917                 return 0, fmt.Errorf("tried to end event %v, but not in-flight", go122.Specs()[st].Name)
 918         }
 919         // Swap remove.
 920         desc := s.inFlight[idx].desc
 921         s.inFlight[idx], s.inFlight[len(s.inFlight)-1] = s.inFlight[len(s.inFlight)-1], s.inFlight[idx]
 922         s.inFlight = s.inFlight[:len(s.inFlight)-1]
 923         return desc, nil
 924 }
 925
 926 // seqCounter represents a global sequence counter for a resource.
 927 type seqCounter struct {
 928         gen uint64 // The generation for the local sequence counter seq.
 929         seq uint64 // The sequence number local to the generation.
 930 }
 931
 932 // makeSeq creates a new seqCounter.
 933 func makeSeq(gen, seq uint64) seqCounter {
 934         return seqCounter{gen: gen, seq: seq}
 935 }
 936
 937 // succeeds returns true if a is the immediate successor of b.
 938 func (a seqCounter) succeeds(b seqCounter) bool {
 939         return a.gen == b.gen && a.seq == b.seq+1
 940 }
 941
 942 // String returns a debug string representation of the seqCounter.
 943 func (c seqCounter) String() string {
 944         return fmt.Sprintf("%d (gen=%d)", c.seq, c.gen)
 945 }
 946
 947 func dumpOrdering(order *ordering) string {
 948         var sb strings.Builder
 949         for id, state := range order.gStates {
 950                 fmt.Fprintf(&sb, "G %d [status=%s seq=%s]\n", id, state.status, state.seq)
 951         }
 952         fmt.Fprintln(&sb)
 953         for id, state := range order.pStates {
 954                 fmt.Fprintf(&sb, "P %d [status=%s seq=%s]\n", id, state.status, state.seq)
 955         }
 956         fmt.Fprintln(&sb)
 957         for id, state := range order.mStates {
 958                 fmt.Fprintf(&sb, "M %d [g=%d p=%d]\n", id, state.g, state.p)
 959         }
 960         fmt.Fprintln(&sb)
 961         fmt.Fprintf(&sb, "GC %d %s\n", order.gcSeq, order.gcState)
 962         return sb.String()
 963 }
 964
 965 // taskState represents an active task.
 966 type taskState struct {
 967         // name is the type of the active task.
 968         name string
 969
 970         // parentID is the parent ID of the active task.
 971         parentID TaskID
 972 }