I found https://github.com/davecheney/gcvis from +Dave Cheney <d...@cheney.net> is it a good choice for inspecting the gc logs?
tis 5 dec. 2017 kl 07:57 skrev Henrik Johansson <dahankz...@gmail.com>: > I have just added the gc tracing and it looks like this more or less all > the time: > > gc 78 @253.095s 0%: 0.032+3.3+0.46 ms clock, 0.26+0.24/2.6/2.4+3.6 ms cpu, > 11->12->4 MB, 12 MB goal, 8 P > gc 79 @253.109s 0%: 0.021+2.1+0.17 ms clock, 0.16+0.19/3.6/1.2+1.3 ms cpu, > 9->9->4 MB, 10 MB goal, 8 P > gc 80 @253.120s 0%: 0.022+2.8+2.2 ms clock, 0.17+0.27/4.8/0.006+18 ms cpu, > 8->8->4 MB, 9 MB goal, 8 P > gc 81 @253.138s 0%: 0.019+2.3+0.10 ms clock, 0.15+0.73/3.9/3.1+0.81 ms > cpu, 9->9->5 MB, 10 MB goal, 8 P > > Heroku already reports a SW of 343 ms but I can't find it by manual > inspection. I will download the logs later today and try to generate > realistic load. > What is the overhead of running like this, aside from the obvious extra > logging? > Are there any automatic tools to analyze these logs? > > lör 2 dec. 2017 kl 22:36 skrev Henrik Johansson <dahankz...@gmail.com>: > >> I am sorry, I was unclear. The app uses very little ram but the >> provisioned available memory is 512 MB. >> >> I will try to experiment with GC toggles as you suggest and report back. >> >> Thx! >> >> On Sat, Dec 2, 2017, 22:18 rlh via golang-nuts < >> golang-nuts@googlegroups.com> wrote: >> >>> Hard telling what it going on. 35MB, even for 1 CPU, seems very small. >>> Most modern system provision more than 1GB per HW thread though I've seen >>> some provision as little as 512MB. GOGC (SetGCPercent) can be adjust so >>> that the application uses more of the available RAM. Running with >>> GODEBUG=gctrace=1 will give you a sense of the GC's view of the application. >>> >>> In any case these kinds of numbers, running on a real systems, and >>> duplicatable on tip are worth filing an issue. >>> >>> On Saturday, December 2, 2017 at 3:02:30 AM UTC-5, Henrik Johansson >>> wrote: >>>> >>>> Hi, >>>> >>>> I am befuddled by GC SW times on several seconds (seen 20s once) in the >>>> metrics page for our app. There are several things that are strange but >>>> perhaps I am misreading it. The same metrics page reports Max Total 35 MB >>>> out of which 1 MB s swap the rest RSS. The response times on the service is >>>> has 99% ~400 ms which is not good but 95% is ~120 ms usually. >>>> The app reloads an in memory cache as needed using atomic,Value as a >>>> holder and the size is no more than a few thousand at any given time. >>>> Basically a map with pointers to simple structs and lists with pointers >>>> to the same structs to allow for some simple access scenarios. >>>> >>>> Now I haven't profiled the app yet but even in a very pathologial case >>>> it seems as though the GC would be able to keep up easily with such little >>>> amount of memory being used. Granted this is a Standard 1x dyno but even so >>>> once the machiine is stopped the GC should be able to complete it's work in >>>> a very short time given the low used memory. >>>> >>>> Has anyone seen this as well? Could the Go metrics on Heroku simply >>>> report erroneously? Perhaps a couple of orders of magnitide? >>>> >>>> Cheers, >>>> >>>> -- >>> You received this message because you are subscribed to the Google >>> Groups "golang-nuts" group. >>> To unsubscribe from this group and stop receiving emails from it, send >>> an email to golang-nuts+unsubscr...@googlegroups.com. >>> For more options, visit https://groups.google.com/d/optout. >>> >> -- You received this message because you are subscribed to the Google Groups "golang-nuts" group. To unsubscribe from this group and stop receiving emails from it, send an email to golang-nuts+unsubscr...@googlegroups.com. For more options, visit https://groups.google.com/d/optout.
