search

OpenEugene / openboard

An open source switchboard, written in Elm and Go.
MIT License
22 stars 7 forks source link

Create a logging policy using sync/atomic load and store value #153

Closed xipxape closed 3 years ago

xipxape commented 3 years ago

Added ability to log information to stdout, errors to stderr, and uses package-level variable debug logger for debugging.

Closes #123

codegold79 commented 3 years ago

@daved I've made the these updates:

codegold79 commented 3 years ago

@daved In this PR, I'm using the sync/atomic atomic.Value load/store methods. Please compare with the other two PRs I posted:

My next goal is to put the three branches through benchmark testing to compare their performance.

codegold79 commented 3 years ago

Benchmark test results

Range: 1.204s - 1.668s Average: 1.385s

TEST A

   10000            135192 ns/op
PASS
ok      github.com/OpenEugene/openboard/back/internal/dbg       1.358s

TEST B

   10000            119121 ns/op
PASS
ok      github.com/OpenEugene/openboard/back/internal/dbg       1.204s

TEST C

   10000            166115 ns/op
PASS
ok      github.com/OpenEugene/openboard/back/internal/dbg       1.668s

TEST D

   10000            127507 ns/op
PASS
ok      github.com/OpenEugene/openboard/back/internal/dbg       1.284s

TEST E

   10000            139454 ns/op
PASS
ok      github.com/OpenEugene/openboard/back/internal/dbg       1.413s
codegold79 commented 3 years ago

@daved The benchmark test results show (as you had predicted) that the sync/atomic uint32 implementation has the best performance. I'll label this PR [NOT FOR MERGE] and put #161 up for merge.

codegold79 commented 3 years ago

After improving benchmark test, I ran test again:

16580 85695 ns/op PASS ok github.com/OpenEugene/openboard/back/internal/dbg 2.157s

codegold79 commented 3 years ago

Sync atomic load and store using b.RunParallel

Results

$ go test -bench=. goos: linux goarch: amd64 pkg: github.com/OpenEugene/openboard/back/internal/dbg cpu: Intel(R) Core(TM) i5-4200U CPU @ 1.60GHz BenchmarkDbgUse-4 4808780 224.6 ns/op BenchmarkDbgUseNil-4 5095231 235.6 ns/op BenchmarkDbgSetAndUse-4 5512214 252.1 ns/op BenchmarkDbgSetAndUseNil-4 22432702 46.82 ns/op PASS ok github.com/OpenEugene/openboard/back/internal/dbg 5.500s

$ go test -bench=. goos: linux goarch: amd64 pkg: github.com/OpenEugene/openboard/back/internal/dbg cpu: Intel(R) Core(TM) i5-4200U CPU @ 1.60GHz BenchmarkDbgUse-4 4490373 251.5 ns/op BenchmarkDbgUseNil-4 4580872 251.7 ns/op BenchmarkDbgSetAndUse-4 5409266 207.7 ns/op BenchmarkDbgSetAndUseNil-4 24270432 46.74 ns/op PASS ok github.com/OpenEugene/openboard/back/internal/dbg 5.371s

$ go test -bench=. goos: linux goarch: amd64 pkg: github.com/OpenEugene/openboard/back/internal/dbg cpu: Intel(R) Core(TM) i5-4200U CPU @ 1.60GHz BenchmarkDbgUse-4 4613444 256.3 ns/op BenchmarkDbgUseNil-4 4652350 258.5 ns/op BenchmarkDbgSetAndUse-4 5156545 218.9 ns/op BenchmarkDbgSetAndUseNil-4 22653818 49.94 ns/op PASS ok github.com/OpenEugene/openboard/back/internal/dbg 5.493s

$ go test -bench=. goos: linux goarch: amd64 pkg: github.com/OpenEugene/openboard/back/internal/dbg cpu: Intel(R) Core(TM) i5-4200U CPU @ 1.60GHz BenchmarkDbgUse-4 4616432 241.4 ns/op BenchmarkDbgUseNil-4 5064988 233.3 ns/op BenchmarkDbgSetAndUse-4 5304114 207.6 ns/op BenchmarkDbgSetAndUseNil-4 24949291 49.70 ns/op PASS ok github.com/OpenEugene/openboard/back/internal/dbg 5.443s

Conclusion

Sync atomic store and load of values seems to beat out mutex locks and unlocks in parallel benchmark tests (PR #162) for the dbg package. I'm recommending this PR for merge.

codegold79 commented 3 years ago

During our last meeting, @daved found that this debug logger was racy. I fixed it so that race detector did not find a race when I ran go test -bench=. -race. The fix was not to store the status of the logger with toggle, but rather store the logger itself into an atomic/sync value variable. Here were the results from go test -bench=.:

goos: linux
goarch: amd64
pkg: github.com/OpenEugene/openboard/back/internal/dbg
cpu: Intel(R) Core(TM) i5-4200U CPU @ 1.60GHz
BenchmarkDbgUse-4                4487584               246.4 ns/op
BenchmarkDbgUseNil-4             4612100               248.8 ns/op
BenchmarkDbgSetAndUse-4          4194343               249.5 ns/op
BenchmarkDbgSetAndUseNil-4      22563385                47.44 ns/op
PASS
ok      github.com/OpenEugene/openboard/back/internal/dbg       5.301s

The performance using sync atomic still beats the mutex version in PR #162. I maintain my recommendation that this is the dbg logger version that gets merged.