github.com/zhyoulun/cilium@v1.6.12/pkg/lock/lock_debug.go (about)

     1  // Copyright 2017-2019 Authors of Cilium
     2  //
     3  // Licensed under the Apache License, Version 2.0 (the "License");
     4  // you may not use this file except in compliance with the License.
     5  // You may obtain a copy of the License at
     6  //
     7  //     http://www.apache.org/licenses/LICENSE-2.0
     8  //
     9  // Unless required by applicable law or agreed to in writing, software
    10  // distributed under the License is distributed on an "AS IS" BASIS,
    11  // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
    12  // See the License for the specific language governing permissions and
    13  // limitations under the License.
    14  
    15  // +build lockdebug
    16  
    17  package lock
    18  
    19  import (
    20  	"bytes"
    21  	"fmt"
    22  	"io"
    23  	"os"
    24  	"runtime/debug"
    25  	"time"
    26  
    27  	"github.com/cilium/cilium/pkg/logging"
    28  	"github.com/cilium/cilium/pkg/logging/logfields"
    29  
    30  	"github.com/sasha-s/go-deadlock"
    31  	"github.com/sirupsen/logrus"
    32  )
    33  
    34  const (
    35  	// selfishThresholdSec is the number of seconds that should be used when
    36  	// detecting if a lock was held for more than the specified time.
    37  	selfishThresholdSec = 0.1
    38  
    39  	// Waiting for a lock for longer than DeadlockTimeout is considered a deadlock.
    40  	// Ignored is DeadlockTimeout <= 0.
    41  	deadLockTimeout = 310 * time.Second
    42  )
    43  
    44  var (
    45  	log = logging.DefaultLogger.WithField(logfields.LogSubsys, "lock-lib")
    46  
    47  	// selfishThresholdMsg is the message that will be printed when a lock was
    48  	// held for more than selfishThresholdSec.
    49  	selfishThresholdMsg = fmt.Sprintf("Goroutine took lock for more than %.2f seconds", selfishThresholdSec)
    50  )
    51  
    52  func init() {
    53  	deadlock.Opts.DeadlockTimeout = deadLockTimeout
    54  }
    55  
    56  type internalRWMutex struct {
    57  	deadlock.RWMutex
    58  	t time.Time
    59  }
    60  
    61  func (i *internalRWMutex) Lock() {
    62  	i.RWMutex.Lock()
    63  	i.t = time.Now()
    64  }
    65  
    66  func (i *internalRWMutex) Unlock() {
    67  	if sec := time.Since(i.t).Seconds(); sec >= selfishThresholdSec {
    68  		printStackTo(sec, debug.Stack(), os.Stderr)
    69  	}
    70  	i.RWMutex.Unlock()
    71  }
    72  
    73  func (i *internalRWMutex) UnlockIgnoreTime() {
    74  	i.RWMutex.Unlock()
    75  }
    76  
    77  func (i *internalRWMutex) RLock() {
    78  	i.RWMutex.RLock()
    79  }
    80  
    81  func (i *internalRWMutex) RUnlock() {
    82  	i.RWMutex.RUnlock()
    83  }
    84  
    85  type internalMutex struct {
    86  	deadlock.Mutex
    87  	time.Time
    88  }
    89  
    90  func (i *internalMutex) Lock() {
    91  	i.Mutex.Lock()
    92  	i.Time = time.Now()
    93  }
    94  
    95  func (i *internalMutex) Unlock() {
    96  	if sec := time.Since(i.Time).Seconds(); sec >= selfishThresholdSec {
    97  		printStackTo(sec, debug.Stack(), os.Stderr)
    98  	}
    99  	i.Mutex.Unlock()
   100  }
   101  
   102  func (i *internalMutex) UnlockIgnoreTime() {
   103  	i.Mutex.Unlock()
   104  }
   105  
   106  func printStackTo(sec float64, stack []byte, writer io.Writer) {
   107  	goRoutineNumber := []byte("0")
   108  	newLines := 0
   109  
   110  	if bytes.Equal([]byte("goroutine"), stack[:len("goroutine")]) {
   111  		newLines = bytes.Count(stack, []byte{'\n'})
   112  		goroutineLine := bytes.IndexRune(stack, '[')
   113  		goRoutineNumber = stack[:goroutineLine]
   114  	}
   115  
   116  	log.WithFields(logrus.Fields{
   117  		"seconds":   sec,
   118  		"goroutine": string(goRoutineNumber[len("goroutine") : len(goRoutineNumber)-1]),
   119  	}).Debug(selfishThresholdMsg)
   120  
   121  	// A stack trace is usually in the following format:
   122  	// goroutine 1432 [running]:
   123  	// runtime/debug.Stack(0xc424c4a370, 0xc421f7f750, 0x1)
   124  	//   /usr/local/go/src/runtime/debug/stack.go:24 +0xa7
   125  	//   ...
   126  	// To know which trace belongs to which go routine we will append the
   127  	// go routine number to every line of the stack trace.
   128  	writer.Write(bytes.Replace(
   129  		stack,
   130  		[]byte{'\n'},
   131  		append([]byte{'\n'}, goRoutineNumber...),
   132  		// Don't replace the last '\n'
   133  		newLines-1),
   134  	)
   135  }