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 }