libunwind-devel
[Top][All Lists]
Advanced

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

[Libunwind-devel] performance regression for v1.3 on aarch64


From: yangyongyong
Subject: [Libunwind-devel] performance regression for v1.3 on aarch64
Date: Tue, 13 Feb 2018 04:15:42 +0000

Hi all,

Recently I upgrade libunwind from 1.2 to 1.3 (until commit 26718da1713a5698070e702e68db1f995baeae07) mostly because commit 5a491cb2d889f03952182d611d2ac6e15c3c5845:

“arm64: Support for restore of ARM64 Neon callee-saved registers during unwind”

 

v1.3 works well except the performance regression of unw_get_proc_info.

I sampled the time consumed by unw_get_proc_info with clock_gettime(CLOCK_MONOTONIC, …)

Here is the results (Tests are performed on aarch64/linux with gcc 5.4, us means microsecond):

v1.3:

         -- unw_get_proc_info called 6603, time(us) consumed total 620254, time(us) consumed delta 68

         -- unw_get_proc_info called 6604, time(us) consumed total 620322, time(us) consumed delta 49

         -- unw_get_proc_info called 6605, time(us) consumed total 620371, time(us) consumed delta 60

         -- unw_get_proc_info called 6606, time(us) consumed total 620431, time(us) consumed delta 80

         -- unw_get_proc_info called 6607, time(us) consumed total 620511, time(us) consumed delta 77

         -- unw_get_proc_info called 6608, time(us) consumed total 620588, time(us) consumed delta 88

         -- unw_get_proc_info called 6609, time(us) consumed total 620676, time(us) consumed delta 201

         -- unw_get_proc_info called 6610, time(us) consumed total 620877, time(us) consumed delta 200

         -- unw_get_proc_info called 6611, time(us) consumed total 621077, time(us) consumed delta 185

         -- unw_get_proc_info called 6612, time(us) consumed total 621262, time(us) consumed delta 151

         -- unw_get_proc_info called 6613, time(us) consumed total 621413, time(us) consumed delta 136

         -- unw_get_proc_info called 6614, time(us) consumed total 621549, time(us) consumed delta 75

         -- unw_get_proc_info called 6615, time(us) consumed total 621624, time(us) consumed delta 66

         -- unw_get_proc_info called 6616, time(us) consumed total 621690, time(us) consumed delta 57

         -- unw_get_proc_info called 6617, time(us) consumed total 621747, time(us) consumed delta 78

         -- unw_get_proc_info called 6618, time(us) consumed total 621825, time(us) consumed delta 80

         -- unw_get_proc_info called 6619, time(us) consumed total 621905, time(us) consumed delta 79

         -- unw_get_proc_info called 6620, time(us) consumed total 621984, time(us) consumed delta 78

         -- unw_get_proc_info called 6621, time(us) consumed total 622062, time(us) consumed delta 78

         -- unw_get_proc_info called 6622, time(us) consumed total 622140, time(us) consumed delta 79

         -- unw_get_proc_info called 6623, time(us) consumed total 622219, time(us) consumed delta 78

         -- unw_get_proc_info called 6624, time(us) consumed total 622297, time(us) consumed delta 66

         -- unw_get_proc_info called 6625, time(us) consumed total 622363, time(us) consumed delta 49

         -- unw_get_proc_info called 6626, time(us) consumed total 622412, time(us) consumed delta 61

         -- unw_get_proc_info called 6627, time(us) consumed total 622473, time(us) consumed delta 81

 

v1.2

         -- unw_get_proc_info called 6289, time(us) consumed total 45070, time(us) consumed delta 10

         -- unw_get_proc_info called 6290, time(us) consumed total 45080, time(us) consumed delta 4

         -- unw_get_proc_info called 6291, time(us) consumed total 45084, time(us) consumed delta 3

         -- unw_get_proc_info called 6292, time(us) consumed total 45087, time(us) consumed delta 5

         -- unw_get_proc_info called 6293, time(us) consumed total 45092, time(us) consumed delta 3

         -- unw_get_proc_info called 6294, time(us) consumed total 45095, time(us) consumed delta 7

         -- unw_get_proc_info called 6295, time(us) consumed total 45102, time(us) consumed delta 4

         -- unw_get_proc_info called 6296, time(us) consumed total 45106, time(us) consumed delta 6

         -- unw_get_proc_info called 6297, time(us) consumed total 45112, time(us) consumed delta 8

         -- unw_get_proc_info called 6298, time(us) consumed total 45120, time(us) consumed delta 7

         -- unw_get_proc_info called 6299, time(us) consumed total 45127, time(us) consumed delta 8

         -- unw_get_proc_info called 6300, time(us) consumed total 45135, time(us) consumed delta 8

         -- unw_get_proc_info called 6301, time(us) consumed total 45143, time(us) consumed delta 8

         -- unw_get_proc_info called 6302, time(us) consumed total 45151, time(us) consumed delta 9

         -- unw_get_proc_info called 6303, time(us) consumed total 45160, time(us) consumed delta 8

         -- unw_get_proc_info called 6304, time(us) consumed total 45168, time(us) consumed delta 9

         -- unw_get_proc_info called 6305, time(us) consumed total 45177, time(us) consumed delta 7

         -- unw_get_proc_info called 6306, time(us) consumed total 45184, time(us) consumed delta 6

         -- unw_get_proc_info called 6307, time(us) consumed total 45190, time(us) consumed delta 7

         -- unw_get_proc_info called 6308, time(us) consumed total 45197, time(us) consumed delta 7

         -- unw_get_proc_info called 6309, time(us) consumed total 45204, time(us) consumed delta 7

         -- unw_get_proc_info called 6310, time(us) consumed total 45211, time(us) consumed delta 4

         -- unw_get_proc_info called 6311, time(us) consumed total 45215, time(us) consumed delta 3

         -- unw_get_proc_info called 6312, time(us) consumed total 45218, time(us) consumed delta 5

         -- unw_get_proc_info called 6313, time(us) consumed total 45223, time(us) consumed delta 3

         -- unw_get_proc_info called 6314, time(us) consumed total 45226, time(us) consumed delta 8

         -- unw_get_proc_info called 6315, time(us) consumed total 45234, time(us) consumed delta 5

         -- unw_get_proc_info called 6316, time(us) consumed total 45239, time(us) consumed delta 6

         -- unw_get_proc_info called 6317, time(us) consumed total 45245, time(us) consumed delta 8

         -- unw_get_proc_info called 6318, time(us) consumed total 45253, time(us) consumed delta 8

         -- unw_get_proc_info called 6319, time(us) consumed total 45261, time(us) consumed delta 8

         -- unw_get_proc_info called 6320, time(us) consumed total 45269, time(us) consumed delta 9

         -- unw_get_proc_info called 6321, time(us) consumed total 45278, time(us) consumed delta 10

         -- unw_get_proc_info called 6322, time(us) consumed total 45288, time(us) consumed delta 8

         -- unw_get_proc_info called 6323, time(us) consumed total 45296, time(us) consumed delta 8

         -- unw_get_proc_info called 6324, time(us) consumed total 45304, time(us) consumed delta 9

         -- unw_get_proc_info called 6325, time(us) consumed total 45313, time(us) consumed delta 6

         -- unw_get_proc_info called 6326, time(us) consumed total 45319, time(us) consumed delta 6

 

It seems v1.3 costs 10 times more. And things are getting even worse on qemu. I do not have any clue for this problem, please some one enlights me.

 

By the way, v1.3 can not be built on Android NDK r16b (https://dl.google.com/android/repository/android-ndk-r16b-linux-x86_64.zip ) with configure :  “configure   --host=aarch64-linux-android  --prefix=xxx_install_yyy     --enable-debug”.  Following are some potential problems:

1.       test-coredump-unwind  includes execinfo.h  which does not exist on android.

2.       HAVE_STRUCT_ELF_PRSTATUS is not defined during configuration.

3.       struct elf_prstatus is defined in linux/elfcore.h which is not included.

 

Best regards.

 


reply via email to

[Prev in Thread] Current Thread [Next in Thread]