mget

[Eugene Toropov]

Что это за mget такой?

vagrant@precise32:/tgo/src/proxy$ go tool pprof -text proxy /tmp/profile421316969/cpu.pprof
63s of 70.66s total (89.16%)
Dropped 193 nodes (cum <= 0.35s)
flat flat% sum% cum cum%
11.25s 15.92% 15.92% 14.24s 20.15% mget
4.63s 6.55% 22.47% 4.63s 6.55% unicode.init
4.33s 6.13% 28.60% 4.33s 6.13% encoding/json.marshalerEncoder
3.63s 5.14% 33.74% 9.17s 12.98% encoding/xml.(*Decoder).name
3.03s 4.29% 38.03% 5.02s 7.10% encoding/base64.(*Encoding).Decode
2.63s 3.72% 41.75% 2.63s 3.72% reflect.Kind.String
2.40s 3.40% 45.15% 2.43s 3.44% encoding/base64.(*encoder).Write
2.32s 3.28% 48.43% 2.77s 3.92% runtime.mallocgc
1.91s 2.70% 51.13% 1.91s 2.70% runtime.MSpan_Sweep
1.67s 2.36% 53.50% 42.48s 60.12% encoding/xml.(*Decoder).rawToken
1.52s 2.15% 55.65% 1.52s 2.15% gc

Евгений

[Eugene Toropov]

Который судя по всему запускает garbage collector: https://www.dropbox.com/s/rlnn081b9ouxc5e/Screenshot%202015-02-28%2011.08.38.png?dl=0

[Konstantin Kulikov]

m - это поток операционной системы.
Пробуйте ThreadCreateProfile

> --
> Вы получили это сообщение, поскольку подписаны на группу Golang Russian.
>
> Чтобы отменить подписку на эту группу и больше не получать от нее сообщения, отправьте письмо на электронный адрес golang-ru+...@googlegroups.com.
> Настройки подписки и доставки писем: https://groups.google.com/d/optout.

[Eugene Toropov]

Ммм.. В смысле попробуйте? У меня в коде его нет. Это как-то где-то конфигурируется?


> 28 февр. 2015 г., в 18:46, Konstantin Kulikov <k.kul...@gmail.com> написал(а):

[Dmitry Vyukov]

Я думаю, что вы дали pprof неправильный бинарник - весь профиль
выглядит неправильно. unicode.init выполняется один раз при старте и
занимат пару микросекунд. Аналогично reflect.Kind.String не должн быть
виден в профиле. Это так же объясняет, почему в профиле mget

[Eugene Toropov]

--
Вы получили это сообщение, поскольку подписаны на группу Golang Russian.

Чтобы отменить подписку на эту группу и больше не получать от нее сообщения, отправьте письмо на электронный адрес golang-ru+...@googlegroups.com.
Настройки подписки и доставки писем: https://groups.google.com/d/optout.

Бинго! А подскажите пожалуйста еще по профайлингу. Я использую "github.com/davecheney/profile” как описано здесь - https://medium.com/code-adventures/profiling-golang-851db2d9ae24 - вместо стандартного pprof, так как последний не удобен в том смысле, что ничего не пишет в файл, если я останавливаю http-демона по Ctrl+C. Может порекомендуете что-то еще более удобное?

Евгений

[Dmitry Vyukov]

2015-02-28 23:09 GMT+03:00 Eugene Toropov <eugene....@gmail.com>:
> Бинго! А подскажите пожалуйста еще по профайлингу. Я использую
> "github.com/davecheney/profile” как описано здесь -
> https://medium.com/code-adventures/profiling-golang-851db2d9ae24 - вместо
> стандартного pprof, так как последний не удобен в том смысле, что ничего не
> пишет в файл, если я останавливаю http-демона по Ctrl+C. Может
> порекомендуете что-то еще более удобное?

Если это вопрос ко мне, то я ничего тут не подскажу. Я использую go
test, net/http/pprof и perf на linux (но он не умеет удаленно).

[Eugene Toropov]

> --
> Вы получили это сообщение, поскольку подписаны на группу Golang Russian.
>
> Чтобы отменить подписку на эту группу и больше не получать от нее сообщения, отправьте письмо на электронный адрес golang-ru+...@googlegroups.com.
> Настройки подписки и доставки писем: https://groups.google.com/d/optout.

net/http/prof я как-то пропустил, спасибо

Евгений

[Eugene Toropov]

Хм, я тут наткнулся вот на такое - https://groups.google.com/forum/#!msg/golang-nuts/5lxfW3cninU/LemgM21ImmgJ - даже процитирую:

Dave Cheney:

I don't believe that you can profile reliably inside a VM. Profiling 
requires the profiling signal to be delivered to the program at 
precise intervals, and precision and time is not something VMs do 
well. 

Nicolas Riesch:

Thank you for your explanation, Dave.
I have just installed exactly the same Linux environment on the same machine, but as dual boot.
The result is now normal :

nico@nico-dv7 ~/z_go/src/inut15 $ go tool pprof -text ./inut15 myprof.prof 
Total: 762 samples
     334  43.8%  43.8%      537  70.5% runtime.mallocgc
     132  17.3%  61.2%      138  18.1% runtime.MSpan_Sweep
     103  13.5%  74.7%      640  84.0% runtime.new
      50   6.6%  81.2%      690  90.6% main.main
      44   5.8%  87.0%       44   5.8% scanblock
      42   5.5%  92.5%       42   5.5% runtime.markspan
       8   1.0%  93.6%        8   1.0% runtime.usleep
       6   0.8%  94.4%        6   0.8% runtime.futex
       5   0.7%  95.0%       86  11.3% MCentral_Grow
       5   0.7%  95.7%        5   0.7% flushptrbuf
       3   0.4%  96.1%        3   0.4% ExternalCode
       3   0.4%  96.5%       35   4.6% MHeap_AllocLocked

So, the conclusion is that profiling cannot be done inside a Virtual Machine.

У меня такая же ситуация, как была у Николаса - ExternalCode жрет больше всех и получается, что профайлинг в виртуалке бесполезен? И никаких workaround-ов?

Евгений

[Dmitry Vyukov]

Не знаю. Может вы и правильный профиль видите.

[Eugene Toropov]

А как понять правильный или нет? у меня нет никакого Си кода, есть просто прокси, получающий XML файлы и конвертирующий в JSON - реально один файл, 200 строк Go кода

Евгений

[Daniel Podolsky]

> А как понять правильный или нет?

похоже - только запустить на железе и сравнить...

[Dmitry Vyukov]

2015-03-01 15:02 GMT+03:00 Daniel Podolsky <onok...@gmail.com>:
>> А как понять правильный или нет?
> похоже - только запустить на железе и сравнить...

Это - самый надежный вариант.
Ещё можно попробовать воспользоваться другим профайлером (на linux
perf-ом например).
Хотя конечно если нет нативного кода, то ExternalCode быть не должно.

[Eugene Toropov]

На маке тоже какая-то странная история:

howing top 10 nodes out of 66 (cum >= 690ms)

      flat  flat%   sum%        cum   cum%

   48950ms 64.43% 64.43%    48950ms 64.43%  runtime.mach_semaphore_wait

    4820ms  6.34% 70.78%     4820ms  6.34%  runtime.mach_semaphore_timedwait

    1750ms  2.30% 73.08%     2240ms  2.95%  runtime.mallocgc

    1450ms  1.91% 74.99%     2920ms  3.84%  encoding/xml.(*Decoder).getc

    1310ms  1.72% 76.71%     1310ms  1.72%  unicode.is16

    1000ms  1.32% 78.03%     1000ms  1.32%  bytes.(*Reader).ReadByte

     870ms  1.15% 79.18%     1560ms  2.05%  bytes.(*Buffer).WriteByte

     720ms  0.95% 80.12%      750ms  0.99%  bytes.(*Buffer).grow

     700ms  0.92% 81.05%     2190ms  2.88%  encoding/xml.(*Decoder).text

     690ms  0.91% 81.95%      690ms  0.91%  runtime.MSpan_Sweep

и похоже не у меня одного: https://groups.google.com/forum/#!topic/golang-nuts/0Sre9xE9l-Q

На родной убунте чуть позже запущу и покажу.

Евгений

[Eugene Toropov]

Но родной убунте ExternalCode в топ10 нету:

(pprof) top10

39.18s of 83.58s total (46.88%)

Dropped 194 nodes (cum <= 0.42s)

Showing top 10 nodes out of 97 (cum >= 7.51s)

      flat  flat%   sum%        cum   cum%

     6.40s  7.66%  7.66%      7.90s  9.45%  runtime.mallocgc

     6.13s  7.33% 14.99%      6.13s  7.33%  runtime.MSpan_Sweep

     4.93s  5.90% 20.89%      9.73s 11.64%  encoding/xml.(*Decoder).getc

     4.18s  5.00% 25.89%      4.18s  5.00%  unicode.is16

     3.46s  4.14% 30.03%      3.46s  4.14%  scanblock

     3.44s  4.12% 34.15%      5.85s  7.00%  bytes.(*Buffer).WriteByte

     3.43s  4.10% 38.25%      3.43s  4.10%  bytes.(*Reader).ReadByte

     2.50s  2.99% 41.24%     63.16s 75.57%  encoding/xml.(*Decoder).unmarshal

     2.46s  2.94% 44.19%      2.48s  2.97%  bytes.(*Buffer).grow

     2.25s  2.69% 46.88%      7.51s  8.99%  encoding/xml.(*Decoder).text

Пичалька :( Я настолько привык к виртуалкам что даже не знаю, что и делать...

Евгений

[Dmitry Vyukov]

2015-03-02 21:58 GMT+03:00 Eugene Toropov <eugene....@gmail.com>:
> На маке тоже какая-то странная история:

На маке ппроф не работает из за ошибке в ядре. Где-то валяется патч
для ядра, который чинит ппроф.

> Чтобы настроить другие параметры, перейдите по ссылке
> https://groups.google.com/d/optout.

[Dmitry Vyukov]

2015-03-02 23:55 GMT+03:00 Eugene Toropov <eugene....@gmail.com>:
> Но родной убунте ExternalCode в топ10 нету:
>
> (pprof) top10
> 39.18s of 83.58s total (46.88%)
> Dropped 194 nodes (cum <= 0.42s)
> Showing top 10 nodes out of 97 (cum >= 7.51s)
> flat flat% sum% cum cum%
> 6.40s 7.66% 7.66% 7.90s 9.45% runtime.mallocgc
> 6.13s 7.33% 14.99% 6.13s 7.33% runtime.MSpan_Sweep
> 4.93s 5.90% 20.89% 9.73s 11.64% encoding/xml.(*Decoder).getc
> 4.18s 5.00% 25.89% 4.18s 5.00% unicode.is16
> 3.46s 4.14% 30.03% 3.46s 4.14% scanblock
> 3.44s 4.12% 34.15% 5.85s 7.00% bytes.(*Buffer).WriteByte
> 3.43s 4.10% 38.25% 3.43s 4.10% bytes.(*Reader).ReadByte
> 2.50s 2.99% 41.24% 63.16s 75.57%
> encoding/xml.(*Decoder).unmarshal
> 2.46s 2.94% 44.19% 2.48s 2.97% bytes.(*Buffer).grow
> 2.25s 2.69% 46.88% 7.51s 8.99% encoding/xml.(*Decoder).text
>
> Пичалька :( Я настолько привык к виртуалкам что даже не знаю, что и
> делать...

Зафайлить баг на виртуалку.
В идеале виртуалка не отличима от реальной машины. По крайней мере не
таким простым способом.

[Alexey Palazhchenko]

> На маке ппроф не работает из за ошибке в ядре. Где-то валяется патч

> для ядра, который чинит пор.

http://research.swtch.com/macpprof
http://rsc.io/pprof_mac_fix

–-–
Алексей «AlekSi» Палажченко

[Daniel Podolsky]

> В идеале виртуалка не отличима от реальной машины. По крайней мере не
> таким простым способом.

а это очень зависит от того, какая виртуалка, да на каком процессоре.

[Eugene Toropov]

Спасибо

[Eugene Toropov]

Да, спасибо. Попробую еще виртуозку проапгрейдить.

[Eugene Toropov]

У меня VirtualBox, если что

[Daniel Podolsky]

> У меня VirtualBox, если что

а проц? VTx в нем есть? VTi?

[Eugene Toropov]

Проц i5, iMac 27, не последний, модель не помню, дома гляну

> On Mar 3, 2015, at 12:31 PM, Daniel Podolsky <onok...@gmail.com> wrote:
>
>> У меня VirtualBox, если что
> а проц? VTx в нем есть? VTi?
>