github.com/koko1123/flow-go-1@v0.29.6/utils/binstat/binstat.go (about) 1 /* 2 Package binstat implements file based code statistics in bins. 3 4 Generate bin based statistics on code by wrapping it with binstat functions. 5 Every wallclock second, binstat will output bins to a text file if changed. 6 7 API: 8 9 bs := binstat.Enter[Time][Val]("<What>"[,<Val>]) 10 binstat.Leave[Val](bs, [<Val>]) 11 12 Bin (single text line in output file depends on .Enter*()/.Leave*() combo) anatomy: 13 14 /GOMAXPROCS=8,CPUS=8/what[~4whatExampleOne]/size[<num>-<num>]/time[<num>-<num>]=<num> <num> 15 ^^^^^ Total wallclock 16 ^^^^^ Number of samples 17 ^^^^^^^^^^^^^^^^^^ If .EnterTime*() used 18 ^^^^^^^^^^^^^^^^^^ If <Val> given in .Enter*Val() or .LeaveVal() 19 ^^^^^^^^^^^^^^^^^^^^^^^ <What> string from .Enter*() 20 ^^^^^ default <What> length to include in bin unless BINSTAT_LEN_WHAT 21 ^^^^^^^^^^^^^^^^^^^^ normally does not change 22 23 Size and time ranges are optional and auto generated from a single value or time. 24 E.g. time 0.012345 will be transformed to the range 0.010000 to 0.019999. 25 E.g. value 234 will be transformed to the range 200 to 299. 26 Note: Value can be optionally given with .Enter*Val() or .Leave*Val() as appropriate. 27 28 Using different API combinations then a varity of bin formats are possible: 29 30 /GOMAXPROCS=8,CPUS=8/what[~7formata]=<num> <num> 31 /GOMAXPROCS=8,CPUS=8/what[~7formatb]/size[<num>-<num>]=<num> <num> 32 /GOMAXPROCS=8,CPUS=8/what[~7formatc]/time[<num>-<num>]=<num> <num> 33 /GOMAXPROCS=8,CPUS=8/what[~7formatd]/size[<num>-<num>]/time[<num>-<num>]=<num> <num> 34 35 In this way, code can be called millions of times, but relatively few bins generated & updated. 36 37 The number of bins used at run-time & output can be modified at process start via env vars. 38 E.g. By default binstat is disabled and binstat function will just return, using little CPU. 39 E.g. BINSTAT_LEN_WHAT=~what=0 means disable this particular <What> stat. 40 E.g. BINSTAT_LEN_WHAT=~what=99 means create a longer <What> (therefore more bins) for this particular <What> stat. 41 42 Note: binstat also outputs bins for its internal function statistics. 43 44 Please see API examples below. 45 46 Please see README for examples of commenting and uncommenting. 47 48 Please see test for example of binstat versus pprof. 49 */ 50 package binstat 51 52 /* 53 #if defined(__linux__) 54 #include <stdint.h> 55 #include <unistd.h> 56 #include <sys/syscall.h> 57 #ifdef SYS_gettid 58 uint64_t gettid() { return syscall(SYS_gettid); } 59 #else 60 #error "SYS_gettid unavailable on this system" 61 #endif 62 #elif __APPLE__ // http://elliotth.blogspot.com/2012/04/gettid-on-mac-os.html 63 #include <stdint.h> 64 #include <pthread.h> 65 uint64_t gettid() { uint64_t tid; pthread_threadid_np(NULL, &tid); return tid; } 66 #else 67 # error "Unknown platform; __linux__ or __APPLE__ supported" 68 #endif 69 */ 70 import "C" 71 72 import ( 73 "fmt" 74 "os" 75 "path/filepath" 76 "runtime" 77 "runtime/debug" 78 "strconv" 79 "strings" 80 "sync" 81 "sync/atomic" 82 "time" 83 84 "github.com/rs/zerolog" 85 ) 86 87 // todo: consider using something faster than runtime.nano() e.g. [1] 88 // But is [1] maybe not safe with multiple CPUs? [2] 89 // "Another concern is that if a thread is migrated on a different 90 // processor between two measurements, the counter might skip too much 91 // or even 'go back'." [3] 92 // [1] https://github.com/templexxx/tsc/issues/8 93 // [2] https://stackoverflow.com/questions/3388134/rdtsc-accuracy-across-cpu-cores 94 // [3] https://coherent-labs.com/posts/timestamps-for-performance-measurements/ 95 96 type globalStruct struct { 97 rwMutex sync.RWMutex 98 log zerolog.Logger 99 dumps uint64 100 dmpName string 101 dmpPath string 102 cutPath string 103 processBaseName string 104 processPid int 105 index int 106 indexInternalMax int 107 key2index map[string]int 108 keysArray []string 109 keysEgLoc []string 110 frequency []uint64 111 frequencyShadow []uint64 112 accumMono []uint64 113 accumMonoShadow []uint64 114 verbose bool 115 enable bool 116 second uint64 117 startTime time.Time 118 startTimeMono time.Duration 119 lenWhat string // e.g. "~Code=99;~X=99" 120 what2len map[string]int // e.g. Code -> 99, X -> 99 121 } 122 123 type BinStat struct { 124 what string 125 enterTime time.Duration 126 callerFunc string 127 callerLine int 128 callerParams string 129 callerTime bool 130 callerSize int64 131 callerSizeWhen int 132 keySizeRange string 133 keyTimeRange string 134 } 135 136 const ( 137 sizeAtEnter = iota 138 sizeNotUsed 139 sizeAtLeave 140 ) 141 142 const ( 143 internalSec = iota 144 internalEnter 145 internalPoint 146 internalx_2_y 147 internalDebug 148 internalGC 149 ) 150 151 var global = globalStruct{} 152 153 //go:linkname runtimeNano runtime.nanotime 154 func runtimeNano() int64 155 156 func runtimeNanoAsTimeDuration() time.Duration { 157 return time.Duration(runtimeNano()) 158 } 159 160 func atoi(s string) int { 161 v, _ := strconv.Atoi(s) 162 return v 163 } 164 165 func init() { 166 t1 := runtimeNanoAsTimeDuration() 167 168 // inspired by https://github.com/koko1123/flow-go-1/blob/master/utils/unittest/logging.go 169 zerolog.TimestampFunc = func() time.Time { return time.Now().UTC() } 170 global.log = zerolog.New(os.Stderr).Level(zerolog.DebugLevel).With().Timestamp().Logger() 171 172 global.dumps = 0 173 global.startTime = time.Now() 174 global.startTimeMono = runtimeNanoAsTimeDuration() 175 global.processBaseName = filepath.Base(os.Args[0]) 176 global.processPid = os.Getpid() 177 _, global.verbose = os.LookupEnv("BINSTAT_VERBOSE") 178 _, global.enable = os.LookupEnv("BINSTAT_ENABLE") 179 global.dmpName, _ = os.LookupEnv("BINSTAT_DMP_NAME") 180 if global.dmpName == "" { 181 global.dmpName = fmt.Sprintf("%s.pid-%06d.binstat.txt", global.processBaseName, global.processPid) 182 } 183 global.dmpPath, _ = os.LookupEnv("BINSTAT_DMP_PATH") 184 if global.dmpPath == "" { 185 global.dmpPath = "." 186 } 187 global.cutPath, _ = os.LookupEnv("BINSTAT_CUT_PATH") 188 if global.cutPath == "" { 189 global.cutPath = "github.com/koko1123/flow-go-1/" 190 } 191 global.what2len = make(map[string]int) 192 global.lenWhat, _ = os.LookupEnv("BINSTAT_LEN_WHAT") 193 if len(global.lenWhat) > 0 { 194 parts := strings.Split(global.lenWhat, ";") 195 for n, part := range parts { // e.g. "~Code=99" 196 subParts := strings.Split(part, "=") 197 const leftAndRightParts = 2 198 if (len(subParts) != leftAndRightParts) || (subParts[0][0:1] != "~") || (0 == len(subParts[0][1:])) { 199 panic(fmt.Sprintf("ERROR: BINSTAT: BINSTAT_LEN_WHAT=%s <-- cannot parse <-- format should be ~<what prefix>=<max len>[;...], e.g. ~Code=99;~X=99\n", global.lenWhat)) 200 } 201 k := subParts[0][1:] 202 v := atoi(subParts[1]) 203 global.what2len[k] = v 204 if global.verbose { 205 elapsedThisProc := time.Duration(runtimeNanoAsTimeDuration() - global.startTimeMono).Seconds() 206 global.log.Debug().Msgf("%f %d=pid %d=tid init() // parsing .lenWhat=%s; extracted #%d k=%s v=%d", elapsedThisProc, os.Getpid(), int64(C.gettid()), global.lenWhat, n, k, v) 207 } 208 } 209 } 210 global.key2index = make(map[string]int) 211 212 appendInternalKey := func(keyIotaIndex int, name string) { 213 if keyIotaIndex != len(global.keysArray) { 214 panic(fmt.Sprintf("ERROR: BINSTAT: INTERNAL: %s", name)) 215 } 216 global.keysArray = append(global.keysArray, name) 217 global.keysEgLoc = append(global.keysEgLoc, "") 218 global.frequency = append(global.frequency, 0) 219 global.accumMono = append(global.accumMono, 0) 220 global.frequencyShadow = append(global.frequencyShadow, 0) 221 global.accumMonoShadow = append(global.accumMonoShadow, 0) 222 } 223 appendInternalKey(internalSec, "/internal/second") 224 appendInternalKey(internalEnter, "/internal/binstat.enter") 225 appendInternalKey(internalPoint, "/internal/binstat.point") 226 appendInternalKey(internalx_2_y, "/internal/binstat.x_2_y") 227 appendInternalKey(internalDebug, "/internal/binstat.debug") 228 appendInternalKey(internalGC, "/internal/GCStats") 229 230 global.index = len(global.keysArray) 231 global.indexInternalMax = len(global.keysArray) 232 go tick(100 * time.Millisecond) // every 0.1 seconds 233 234 if global.verbose { 235 elapsedThisProc := time.Duration(runtimeNanoAsTimeDuration() - global.startTimeMono).Seconds() 236 global.log.Debug().Msgf("%f %d=pid %d=tid init() // .enable=%t .verbose=%t .dmpPath=%s .dmpName=%s .cutPath=%s .lenWhat=%s", 237 elapsedThisProc, os.Getpid(), int64(C.gettid()), global.enable, global.verbose, global.dmpPath, global.dmpName, global.cutPath, global.lenWhat) 238 } 239 240 t2 := runtimeNanoAsTimeDuration() 241 if t2 <= t1 { 242 panic(fmt.Sprintf("ERROR: BINSTAT: INTERNAL: t1=%d but t2=%d\n", t1, t2)) 243 } 244 } 245 246 func enterGeneric(what string, callerTime bool, callerSize int64, callerSizeWhen int, verbose bool) *BinStat { 247 if !global.enable { 248 return &BinStat{} // so that chained functions can be called even if binstat globally disabled 249 } 250 251 t := runtimeNanoAsTimeDuration() 252 253 funcName := "" 254 fileLine := 0 255 if global.verbose { 256 // todo: is there a way to speed up runtime.Caller() and/or runtime.FuncForPC() somehow? cache pc value or something like that? 257 pc, _, lineNum, _ := runtime.Caller(2) // 2 assumes private binStat.newGeneric() called indirectly via public stub function; please see eof 258 fn := runtime.FuncForPC(pc) 259 funcName = fn.Name() 260 funcName = strings.ReplaceAll(funcName, global.cutPath, "") 261 fileLine = lineNum 262 } 263 264 whatLen := len(what) // e.g. what = "~3net:wire" 265 const tildaCharLen = 1 266 const lenCharLen = 1 267 const whatCharLenMin = 1 268 if (what[0:1] == "~") && (len(what) >= (tildaCharLen + lenCharLen + whatCharLenMin)) { 269 // come here if what is "~<default len><what>", meaning that BINSTAT_LEN_WHAT may override <default len> 270 // ^^^^^^ 1+ chars; alphanumeric what name which may be longer than default len 271 // ^^^^^^^^^^^^^ 1 char; digit means default what len 1-9 272 // ^ 1 char; tilda means use next digit as default len unless override len exists in .what2len map 273 whatLenDefault := atoi(what[1:2]) 274 whatLen = whatLenDefault + tildaCharLen + lenCharLen 275 if whatLenOverride, keyExists := global.what2len[what[tildaCharLen+lenCharLen:whatLen]]; keyExists { 276 whatLen = whatLenOverride + tildaCharLen + lenCharLen 277 } 278 if whatLen > len(what) { 279 whatLen = len(what) 280 } 281 } 282 283 callerParams := "" 284 bs := BinStat{what[0:whatLen], t, funcName, fileLine, callerParams, callerTime, callerSize, callerSizeWhen, "", ""} 285 286 t2 := runtimeNanoAsTimeDuration() 287 288 if verbose && global.verbose { 289 elapsedThisProc := time.Duration(t2 - global.startTimeMono).Seconds() 290 elapsedThisFunc := time.Duration(t2 - t).Seconds() 291 global.log.Debug().Msgf("%f %d=pid %d=tid %s:%d(%s) // enter in %f // what[%s] .NumCPU()=%d .GOMAXPROCS(0)=%d .NumGoroutine()=%d", 292 elapsedThisProc, os.Getpid(), int64(C.gettid()), bs.callerFunc, bs.callerLine, bs.callerParams, elapsedThisFunc, what, runtime.NumCPU(), runtime.GOMAXPROCS(0), runtime.NumGoroutine()) 293 } 294 295 // for internal accounting, atomically increment counters in (never appended to) shadow array; saving additional lock 296 atomic.AddUint64(&global.frequencyShadow[internalEnter], 1) 297 atomic.AddUint64(&global.accumMonoShadow[internalEnter], uint64(t2-t)) 298 299 return &bs 300 } 301 302 func pointGeneric(bs *BinStat, pointUnique string, callerSize int64, callerSizeWhen int, verbose bool) time.Duration { 303 // if binstat disabled, or <what> disabled; "~#" == "~<default len><what>" 304 if (!global.enable) || (2 == len(bs.what)) { 305 return time.Duration(0) 306 } 307 308 t := runtimeNanoAsTimeDuration() 309 310 elapsedNanoAsTimeDuration := t - bs.enterTime 311 if sizeAtLeave == callerSizeWhen { 312 bs.callerSizeWhen = callerSizeWhen 313 bs.callerSize = callerSize 314 } 315 var pointType string 316 switch pointUnique { 317 case "Leave": 318 pointType = "leave" 319 switch bs.callerSizeWhen { 320 case sizeAtEnter: 321 bs.keySizeRange = fmt.Sprintf("/size[%s]", x_2_y(float64(bs.callerSize), true)) 322 case sizeNotUsed: 323 bs.keySizeRange = "" 324 case sizeAtLeave: 325 bs.keySizeRange = fmt.Sprintf("/size[%s]", x_2_y(float64(bs.callerSize), true)) 326 } 327 case "": 328 default: 329 pointType = "point" 330 bs.keySizeRange = fmt.Sprintf("/size[%s]", pointUnique) 331 } 332 if bs.callerTime { 333 elapsedSeconds := elapsedNanoAsTimeDuration.Seconds() 334 bs.keyTimeRange = fmt.Sprintf("/time[%s]", x_2_y(elapsedSeconds, false)) 335 } 336 key := fmt.Sprintf("/GOMAXPROCS=%d,CPUS=%d/what[%s]%s%s", runtime.GOMAXPROCS(0), runtime.NumCPU(), bs.what, bs.keySizeRange, bs.keyTimeRange) 337 338 tryAgainRaceCondition: 339 var frequency uint64 340 var accumMono uint64 341 global.rwMutex.RLock() // lock for many readers v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v 342 index, keyExists := global.key2index[key] 343 if keyExists { 344 frequency = atomic.AddUint64(&global.frequency[index], 1) 345 accumMono = atomic.AddUint64(&global.accumMono[index], uint64(elapsedNanoAsTimeDuration)) 346 } 347 global.rwMutex.RUnlock() // unlock for many readers ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ 348 349 if !keyExists { 350 // come here to create new hash table bucket 351 keyEgLoc := "" 352 if global.verbose { 353 keyEgLoc = fmt.Sprintf(" // e.g. %s:%d", bs.callerFunc, bs.callerLine) 354 } 355 global.rwMutex.Lock() // lock for single writer v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v 356 _, keyExists = global.key2index[key] 357 if keyExists { // come here if another func beat us to key creation 358 global.rwMutex.Unlock() // unlock for single writer ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ 359 goto tryAgainRaceCondition 360 } 361 // come here to create key and associated counter array element 362 index = global.index 363 global.key2index[key] = index // https://stackoverflow.com/questions/36167200/how-safe-are-golang-maps-for-concurrent-read-write-operations 364 global.keysArray = append(global.keysArray, key) 365 global.keysEgLoc = append(global.keysEgLoc, keyEgLoc) 366 global.frequency = append(global.frequency, 1) 367 global.accumMono = append(global.accumMono, uint64(elapsedNanoAsTimeDuration)) 368 global.index++ 369 global.rwMutex.Unlock() // unlock for single writer ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ 370 frequency = 1 371 accumMono = uint64(elapsedNanoAsTimeDuration) 372 } 373 tOld := uint64(0) 374 tNew := uint64(0) 375 if verbose { // come here if NOT internal instrumentation, e.g. not binstat.dmp() etc 376 tNew = uint64(time.Duration(t - global.startTimeMono).Seconds()) 377 tOld = atomic.SwapUint64(&global.second, tNew) 378 } 379 t2 := runtimeNanoAsTimeDuration() 380 if verbose && global.verbose { 381 hint := "" 382 if tNew > tOld { 383 global.dumps++ 384 hint = fmt.Sprintf("; dump #%d", global.dumps) 385 } 386 elapsedThisProc := time.Duration(t2 - global.startTimeMono).Seconds() 387 elapsedSinceNew := elapsedNanoAsTimeDuration.Seconds() 388 global.log.Debug().Msgf("%f %d=pid %d=tid %s:%d(%s) // %s in %f // %s=[%d]=%d %f%s", 389 elapsedThisProc, os.Getpid(), int64(C.gettid()), bs.callerFunc, bs.callerLine, bs.callerParams, pointType, elapsedSinceNew, key, index, frequency, time.Duration(accumMono).Seconds(), hint) 390 } 391 392 // for internal accounting, atomically increment counters in (never appended to) shadow array; saving additional lock 393 atomic.AddUint64(&global.frequencyShadow[internalPoint], 1) 394 atomic.AddUint64(&global.accumMonoShadow[internalPoint], uint64(t2-t)) 395 396 if tNew > tOld { 397 // come here if won lottery to save binStats this second 398 const UseDefaultName = "" 399 Dump(UseDefaultName) 400 } 401 402 return elapsedNanoAsTimeDuration 403 } 404 405 // todo: there must be a better / faster way to do all the operations below :-) 406 // todo: allow configuration for more granular ranges, e.g. 1.100000-1.199999, or bigger ranges e.g. 0.200000-0.399999 ? 407 // todo: consider outputting int range in hex for 16 bins instead of 10 bins (at a particular magnitude)? 408 func x_2_y(v float64, isInt bool) string { // e.g. 12.345678 409 t := runtimeNanoAsTimeDuration() 410 411 var s string 412 if isInt { 413 s = fmt.Sprintf("%d", int64(v)) // e.g. "12" 414 } else { 415 s = fmt.Sprintf("%f", v) // e.g. "12.2345678" 416 } 417 // make lo & hi copy of strings 418 lo := []byte(s) 419 hi := []byte(s) 420 // find first non-zero digit 421 var z int 422 for z = 0; z < len(lo); z++ { 423 if (lo[z] != '0') && (lo[z] != '.') { 424 goto foundFirstNonZeroNonDot 425 } 426 } 427 foundFirstNonZeroNonDot: 428 // turn the remaining lo digits to '0' and hi digits to '1' 429 z++ 430 for i := z; i < len(lo); i++ { 431 if lo[i] != '.' { 432 lo[i] = '0' 433 hi[i] = '9' 434 } 435 } 436 returnString := fmt.Sprintf("%s-%s", lo, hi) 437 438 t2 := runtimeNanoAsTimeDuration() 439 440 // for internal accounting, atomically increment counters in (never appended to) shadow array; saving additional lock 441 atomic.AddUint64(&global.frequencyShadow[internalx_2_y], 1) 442 atomic.AddUint64(&global.accumMonoShadow[internalx_2_y], uint64(t2-t)) 443 444 return returnString 445 } 446 447 func debugGeneric(bs *BinStat, debugText string, verbose bool) { 448 if !global.enable { 449 return 450 } 451 452 t := runtimeNanoAsTimeDuration() 453 454 if verbose && global.verbose { 455 elapsedThisProc := time.Duration(t - global.startTimeMono).Seconds() 456 global.log.Debug().Msgf("%f %d=pid %d=tid %s:%d(%s) // debug %s", elapsedThisProc, os.Getpid(), int64(C.gettid()), bs.callerFunc, bs.callerLine, bs.callerParams, debugText) 457 } 458 459 t2 := runtimeNanoAsTimeDuration() 460 461 // for internal accounting, atomically increment counters in (never appended to) shadow array; saving additional lock 462 atomic.AddUint64(&global.frequencyShadow[internalDebug], 1) 463 atomic.AddUint64(&global.accumMonoShadow[internalDebug], uint64(t2-t)) 464 } 465 466 func tick(t time.Duration) { 467 if !global.enable { 468 return 469 } 470 471 ticker := time.NewTicker(t) 472 for range ticker.C { 473 bs := enter("internal-NumG") 474 leaveVal(bs, int64(runtime.NumGoroutine())) 475 } 476 } 477 478 func fatalPanic(err string) { 479 global.log.Fatal().Msg(err) 480 panic(err) 481 } 482 483 // todo: would a different format, like CSV or JSON, be useful and how would it be used? 484 // todo: consider env var for path to bin dump file (instead of just current folder)? 485 // todo: if bin dump file path is /dev/shm, add paranoid checking around filling up /dev/shm? 486 // todo: consider reporting on num active go-routines [1] and/or SchedStats API [2] if/when available. 487 // [1] https://github.com/golang/go/issues/17089 "runtime: expose number of running/runnable goroutines #17089" 488 // [2] https://github.com/golang/go/issues/15490 "proposal: runtime: add SchedStats API #15490" 489 490 // Dump binstat text file. 491 // Normally called automatically once per second if bins have changed. 492 // Consider calling explicity before exiting process. 493 // Called explicity in tests so as not to wait one second. 494 func Dump(dmpNonDefaultName string) { 495 bs := enterTime("internal-dump") 496 defer leave(bs) 497 498 var gcStats debug.GCStats 499 debug.ReadGCStats(&gcStats) 500 global.frequencyShadow[internalGC] = uint64(gcStats.NumGC) 501 global.accumMonoShadow[internalGC] = uint64(gcStats.PauseTotal) 502 503 global.rwMutex.RLock() // lock for many readers until function return 504 defer global.rwMutex.RUnlock() 505 506 // todo: copy into buffer and then write to file outside of reader lock? 507 508 t := time.Now() 509 seconds := uint64(t.Unix()) 510 global.frequencyShadow[internalSec] = seconds 511 global.accumMonoShadow[internalSec] = uint64(runtimeNanoAsTimeDuration() - global.startTimeMono) 512 513 // copy internal accounting from never-appending shadow to appending non-shadow counters 514 for i := 0; i < global.indexInternalMax; i++ { 515 v1 := atomic.LoadUint64(&global.frequencyShadow[i]) 516 atomic.StoreUint64(&global.frequency[i], v1) 517 v2 := atomic.LoadUint64(&global.accumMonoShadow[i]) 518 atomic.StoreUint64(&global.accumMono[i], v2) 519 } 520 521 fileTmp := fmt.Sprintf("%s/%s.%d.tmp%s", global.dmpPath, global.dmpName, seconds, dmpNonDefaultName) 522 fileNew := fmt.Sprintf("%s/%s%s", global.dmpPath, global.dmpName, dmpNonDefaultName) 523 f, err := os.Create(fileTmp) 524 if err != nil { 525 fatalPanic(fmt.Sprintf("ERROR: BINSTAT: .Create(%s)=%s", fileTmp, err)) 526 } 527 for i := range global.keysArray { 528 // grab these atomically (because they may be atomically updated in parallel) so as not to trigger Golang's "WARNING: DATA RACE" 529 u1 := atomic.LoadUint64(&global.frequency[i]) 530 u2 := atomic.LoadUint64(&global.accumMono[i]) 531 _, err := fmt.Fprintf(f, "%s=%d %f%s\n", global.keysArray[i], u1, time.Duration(u2).Seconds(), global.keysEgLoc[i]) 532 if err != nil { 533 fatalPanic(fmt.Sprintf("ERROR: BINSTAT: .Fprintf()=%s", err)) 534 } 535 } 536 err = f.Close() 537 if err != nil { 538 fatalPanic(fmt.Sprintf("ERROR: BINSTAT: .Close()=%s", err)) 539 } 540 err = os.Rename(fileTmp, fileNew) // atomically rename / move on Linux :-) 541 if err != nil { 542 // sometimes -- very infrequently -- we come here with the error: "no such file or directory" 543 // in theory only one go-routine should write this uniquely named per second file, so how can the file 'disappear' for renaming? 544 // therefore this error results in a warning and not an error / panic, and the next second we just write the file again hopefuly :-) 545 global.log.Warn().Msgf("WARN: .Rename(%s, %s)=%s\n", fileTmp, fileNew, err) 546 } 547 } 548 549 // functions for exposing binstat internals e.g. for running non-production experiments sampling data, etc 550 func (bs *BinStat) GetSizeRange() string { return bs.keySizeRange } 551 func (bs *BinStat) GetTimeRange() string { return bs.keyTimeRange } 552 func (bs *BinStat) GetWhat() string { return bs.what } 553 554 // functions BEFORE go fmt v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v v 555 556 /* 557 func Enter (what string, ) *BinStat { return enterGeneric(what, false , 0 , sizeNotUsed, true ) } 558 func enter (what string ) *BinStat { return enterGeneric(what, false , 0 , sizeNotUsed, false) } 559 func EnterVal (what string, callerSize int64 ) *BinStat { return enterGeneric(what, false , callerSize, sizeAtEnter, true ) } 560 func enterVal (what string, callerSize int64 ) *BinStat { return enterGeneric(what, false , callerSize, sizeAtEnter, false) } 561 func EnterTime (what string, ) *BinStat { return enterGeneric(what, true , 0 , sizeNotUsed, true ) } 562 func enterTime (what string ) *BinStat { return enterGeneric(what, true , 0 , sizeNotUsed, false) } 563 func EnterTimeVal(what string, callerSize int64 ) *BinStat { return enterGeneric(what, true , callerSize, sizeAtEnter, true ) } 564 func enterTimeVal(what string, callerSize int64 ) *BinStat { return enterGeneric(what, true , callerSize, sizeAtEnter, false) } 565 566 func DebugParams (bs *BinStat, callerParams string) *BinStat { bs.callerParams = callerParams; return bs } 567 func Debug (bs *BinStat, text string) { debugGeneric(bs , text , true ) } 568 569 func Point (bs *BinStat, pointUnique string) time.Duration { return pointGeneric(bs , pointUnique , 0 , sizeNotUsed, true ) } 570 func point (bs *BinStat, pointUnique string) time.Duration { return pointGeneric(bs , pointUnique , 0 , sizeNotUsed, false) } 571 func Leave (bs *BinStat ) time.Duration { return pointGeneric(bs , "Leave" , 0 , sizeNotUsed, true ) } 572 func leave (bs *BinStat ) time.Duration { return pointGeneric(bs , "Leave" , 0 , sizeNotUsed, false) } 573 func LeaveVal (bs *BinStat, callerSize int64 ) time.Duration { return pointGeneric(bs , "Leave" , callerSize, sizeAtLeave, true ) } 574 func leaveVal (bs *BinStat, callerSize int64 ) time.Duration { return pointGeneric(bs , "Leave" , callerSize, sizeAtLeave, false) } 575 */ 576 577 // functions W/&W/O go fmt ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ ~ 578 579 func Enter(what string) *BinStat { return enterGeneric(what, false, 0, sizeNotUsed, true) } 580 func enter(what string) *BinStat { return enterGeneric(what, false, 0, sizeNotUsed, false) } 581 func EnterVal(what string, callerSize int64) *BinStat { 582 return enterGeneric(what, false, callerSize, sizeAtEnter, true) 583 } 584 func enterVal(what string, callerSize int64) *BinStat { 585 return enterGeneric(what, false, callerSize, sizeAtEnter, false) 586 } 587 func EnterTime(what string) *BinStat { return enterGeneric(what, true, 0, sizeNotUsed, true) } 588 func enterTime(what string) *BinStat { return enterGeneric(what, true, 0, sizeNotUsed, false) } 589 func EnterTimeVal(what string, callerSize int64) *BinStat { 590 return enterGeneric(what, true, callerSize, sizeAtEnter, true) 591 } 592 func enterTimeVal(what string, callerSize int64) *BinStat { 593 return enterGeneric(what, true, callerSize, sizeAtEnter, false) 594 } 595 596 func DebugParams(bs *BinStat, callerParams string) *BinStat { 597 bs.callerParams = callerParams 598 return bs 599 } 600 func Debug(bs *BinStat, text string) { debugGeneric(bs, text, true) } 601 602 func Point(bs *BinStat, pointUnique string) time.Duration { 603 return pointGeneric(bs, pointUnique, 0, sizeNotUsed, true) 604 } 605 func point(bs *BinStat, pointUnique string) time.Duration { 606 return pointGeneric(bs, pointUnique, 0, sizeNotUsed, false) 607 } 608 func Leave(bs *BinStat) time.Duration { return pointGeneric(bs, "Leave", 0, sizeNotUsed, true) } 609 func leave(bs *BinStat) time.Duration { return pointGeneric(bs, "Leave", 0, sizeNotUsed, false) } 610 func LeaveVal(bs *BinStat, callerSize int64) time.Duration { 611 return pointGeneric(bs, "Leave", callerSize, sizeAtLeave, true) 612 } 613 func leaveVal(bs *BinStat, callerSize int64) time.Duration { 614 return pointGeneric(bs, "Leave", callerSize, sizeAtLeave, false) 615 } 616 617 // functions AFTER go fmt ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^ ^