[Dev] Tizen 3.0 : Optimizing applications launch time

Stéphane Desneux stephane.desneux at eurogiciel.fr
Tue Oct 22 11:10:41 GMT 2013


Hi Mikko, Patrick,

On 22/10/2013 10:39, Patrick Ohly wrote:
> On Tue, 2013-10-22 at 10:35 +0300, Ylinen, Mikko wrote:
>> Hi Stephane,
>>
>> On Mon, Oct 21, 2013 at 5:56 PM, Stéphane Desneux
>> <stephane.desneux at eurogiciel.fr> wrote:
>>          I saw in the launchpad code that the preloading uses dlopen()
>>          with the flag RTLD_NOW: this forces to load all unresolved
>>          symbols, thus the whole library tree.
>>
>>
>>          As the WRT launchpad executes this dlopen() for all binaries
>>          listed in /usr/share/aul/preload*.txt, this leads to loading
>>          nearly 200 libs:
>>          # for x in $( cat /usr/share/aul/preload*.txt); do ldd $x;
>>          done | awk '{print $1}' | sort | uniq | wc -l
>>          202
>>
>>          This is confirmed by reading the list of mapped files for the
>>          process:
>>          # readlink /proc/$(pgrep wrt_launchpad)/map_files/* | grep .so
>>          | sort | uniq | wc -l
>>          205
>>
>>
>> Just out of curiosity: will the WRT launchpad daemon startup time
>> improve if you disable libs dlopen()?
>>
>>
>> This is important for the system startup time.

Mikko: the 200+ libs are opened and mmaped but this doesn't take much 
time. On my target device (lenovo X230: core i5 IvyBridge), the first 
start of wrt_launchpad_daemon (cold boot) from command line takes less 
than 500ms.

A restart of the wrt launchpad takes ~130ms and no disk IO is observed 
=> the first time, 370ms are spent on disk IOs.

> Perhaps also worth investigating: is RTLD_NOW necessary or can RTLD_LAZY
> be used?
>
> Stéphane said that it causes loading "the while library tree", which is
> a bit misleading. The same set of libraries should be loaded with and
> without it. The difference is that symbol resolution happens for
> everything during loading when RTLD_NOW is used, while it gets deferred
> for functions until they are actually used with RTLD_LAZY.

Using ltrace (see attached log), I could see that all calls are made 
with RTLD_NOW (flag & 0x2 == 2 in dlopen calls)

This is a trace with explicit calls to dlopen() in the launchpad. To be 
compared with a strace, where all dependent libs are loaded in turn 
(this leads to the 200+ libs mapped).

> Symbol resolution can be expensive, so startup time might benefit from
> not doing it immediately. Functions that never get called don't need to
> be resolved at all.
>
> On the other hand, because functions get called in the forked processes,
> this work then needs to be done over and over again, which negates the
> purpose of preloading somewhat.

There's a process pool implemented in wrt launchpad, but it seems 
disabled on recent images (or I'm misunderstanding the signification of 
'process pool'). In package wrt=0.8.198.3-12.17, the 
/etc/profile.d/wrt_env.sh contains 'export WRT_PROCESS_POOL_DISABLE=ON'. 
Even by removing this export, the launchpad doesn't prefork any process. 
Strange... I'll check why it's disabled.

> There may be a way to get the best of both worlds: during startup, use
> RTLD_LAZY. Then sometime later, call dlopen() again for the same modules
> with RTLD_NOW. According to the dlopen() man page, that has the effect
> of retroactively resolving all symbols without actually loading the
> module again.
>
> Something else to watch our for is that switching between
> RTLD_LAZY/RTLD_NOW may also affect which symbols a function call is
> bound to. This is probably unlikely, but who knows...
>
> Another semantic difference is that a module fails to load with RTLD_NOW
> if any of its symbols cannot be resolved. With RTLD_LAZY, it gets loaded
> and a runtime error occurs when calling an unresolvable method.

This is definitely something to investigate.

Kind regards,
-- 
Stéphane Desneux
Intel OTC - Vannes/FR
-------------- next part --------------
__libc_start_main(0x403230, 2, 0x7fffb7029d28, 0x408c90 <unfinished ...>
   getenv("WRT_PROCESS_POOL_DISABLE")                                                        = nil <0.000141>
   signal(0, 0)                                                                              = 0xffffffffffffffff <0.000110>
   signal(SIGHUP, 0)                                                                         = 0 <0.000078>
   signal(SIGINT, 0)                                                                         = 0 <0.000075>
   signal(SIGTRAP, 0)                                                                        = 0 <0.000075>
   signal(SIGKILL, 0)                                                                        = 0xffffffffffffffff <0.000076>
   signal(SIGUSR1, 0)                                                                        = 0 <0.000075>
   signal(SIGUSR2, 0)                                                                        = 0 <0.000099>
   signal(SIGALRM, 0)                                                                        = 0 <0.000094>
   signal(SIGTERM, 0)                                                                        = 0 <0.000088>
   signal(SIGSTKFLT, 0)                                                                      = 0 <0.000087>
   signal(SIGCHLD, 0)                                                                        = 0 <0.000087>
   signal(SIGCONT, 0)                                                                        = 0 <0.000088>
   signal(SIGSTOP, 0)                                                                        = 0xffffffffffffffff <0.000087>
   signal(SIGTSTP, 0)                                                                        = 0 <0.000087>
   signal(SIGTTIN, 0)                                                                        = 0 <0.000087>
   signal(SIGTTOU, 0)                                                                        = 0 <0.000096>
   signal(SIGURG, 0)                                                                         = 0 <0.000088>
   signal(SIGXCPU, 0)                                                                        = 0 <0.000088>
   signal(SIGXFSZ, 0)                                                                        = 0 <0.000088>
   signal(SIGVTALRM, 0)                                                                      = 0 <0.000087>
   signal(SIGPROF, 0)                                                                        = 0 <0.000087>
   signal(SIGWINCH, 0)                                                                       = 0 <0.000087>
   signal(SIGIO, 0)                                                                          = 0 <0.000087>
   signal(SIGPWR, 0)                                                                         = 0 <0.000087>
   signal(SIGSYS, 0)                                                                         = 0 <0.000092>
   signal(SIGRTMIN_0, 0)                                                                     = 0xffffffffffffffff <0.000070>
   signal(SIGRTMIN_1, 0)                                                                     = 0xffffffffffffffff <0.000070>
   signal(SIGRTMIN_2, 0)                                                                     = 0 <0.000087>
   signal(SIGRTMIN_3, 0)                                                                     = 0 <0.000087>
   signal(SIGRTMIN_4, 0)                                                                     = 0 <0.000087>
   signal(SIGRTMIN_5, 0)                                                                     = 0 <0.000087>
   signal(SIGRTMIN_6, 0)                                                                     = 0 <0.000087>
   signal(SIGRTMIN_7, 0)                                                                     = 0 <0.000088>
   signal(SIGRTMIN_8, 0)                                                                     = 0 <0.000095>
   signal(SIGRTMIN_9, 0)                                                                     = 0 <0.000088>
   signal(SIGRTMIN_10, 0)                                                                    = 0 <0.000087>
   signal(SIGRTMIN_11, 0)                                                                    = 0 <0.000089>
   signal(SIGRTMIN_12, 0)                                                                    = 0 <0.000088>
   signal(SIGRTMIN_13, 0)                                                                    = 0 <0.000088>
   signal(SIGRTMIN_14, 0)                                                                    = 0 <0.000087>
   signal(SIGRTMIN_15, 0)                                                                    = 0 <0.000088>
   signal(SIGRTMIN_16, 0)                                                                    = 0 <0.000087>
   signal(SIGRTMIN_17, 0)                                                                    = 0 <0.000092>
   signal(SIGRTMIN_18, 0)                                                                    = 0 <0.000088>
   signal(SIGRTMIN_19, 0)                                                                    = 0 <0.000087>
   signal(SIGRTMIN_20, 0)                                                                    = 0 <0.000089>
   signal(SIGRTMIN_21, 0)                                                                    = 0 <0.000088>
   signal(SIGRTMIN_22, 0)                                                                    = 0 <0.000087>
   signal(SIGRTMIN_23, 0)                                                                    = 0 <0.000089>
   signal(SIGRTMIN_24, 0)                                                                    = 0 <0.000088>
   signal(SIGRTMIN_25, 0)                                                                    = 0 <0.000088>
   signal(SIGRTMIN_26, 0)                                                                    = 0 <0.000089>
   signal(SIGRTMIN_27, 0)                                                                    = 0 <0.000088>
   signal(SIGRTMIN_28, 0)                                                                    = 0 <0.000088>
   signal(SIGRTMIN_29, 0)                                                                    = 0 <0.000088>
   signal(SIGRTMIN_30, 0)                                                                    = 0 <0.000089>
   signal(SIGRTMIN_31, 0)                                                                    = 0 <0.000088>
   signal(64, 0)                                                                             = 0 <0.000088>
   getpid()                                                                                  = 24316 <0.000068>
   __snprintf_chk(0x7fffb70299a0, 128, 1, 128)                                               = 19 <0.000093>
   open("/proc/24316/cmdline", 0, 026700514663)                                              = 3 <0.000125>
   read(3, "/usr/bin/wrt_launchpad_daemon", 127)                                             = 127 <0.000094>
   close(3)                                                                                  = 0 <0.000086>
   __strdup(0x7fffb70299a0, 0x7fffb70299a2, 127, 5)                                          = 0x1632030 <0.000076>
   __dlog_print(0, 3, 0x40a014, 0x409b30)                                                    = 0 <0.000187>
   umask(00)                                                                                 = 022 <0.000084>
   mkdir("/tmp/alaunch", 01777)                                                              = -1 <0.000103>
   umask(022)                                                                                = 00 <0.000082>
   socket(1, 524289, 0)                                                                      = 6 <0.000095>
   __snprintf_chk(0x7fffb7029932, 108, 1, 108)                                               = 15 <0.000076>
   unlink("/tmp/alaunch/-3")                                                                 = 0 <0.000110>
   getuid()                                                                                  = 0 <0.000080>
   smack_fsetlabel(6, 0x408d75, 5, -1)                                                       = 0 <0.000096>
   smack_fsetlabel(6, 0x408d77, 4, -1)                                                       = 0 <0.000090>
   bind(6, 0x7fffb7029930, 110, -1)                                                          = 0 <0.000100>
   chmod("/tmp/alaunch/-3", 0777)                                                            = 0 <0.000114>
   setsockopt(6, 1, 7, 0x7fffb702992c)                                                       = 0 <0.000091>
   setsockopt(6, 1, 8, 0x7fffb702992c)                                                       = 0 <0.000088>
   listen(6, 10, 8, -1)                                                                      = 0 <0.000089>
   strlen("/usr/bin/wrt_launchpad_daemon")                                                   = 29 <0.000102>
   strlen("                                "...)                                             = 201 <0.000178>
   __dlog_print(0, 3, 0x40a014, 0x409b78)                                                    = 0 <0.000070>
   fopen("/usr/share/aul/preload_list.txt", "rt")                                            = 0x1632060 <0.000135>
   fgets("/usr/lib64/libappcore-efl.so.1\n", 128, 0x1632060)                                 = 0x7fffb7029b70 <0.000145>
   strnlen(0x7fffb7029b70, 128, 0x1632140, 0)                                                = 31 <0.000072>
   calloc(1, 24)                                                                             = 0x16322a0 <0.000068>
   dlopen("/usr/lib64/libappcore-efl.so.1", 2)                                               = 0x1632320 <0.059413>
   __dlog_print(0, 3, 0x40a014, 0x409bc0)                                                    = 0 <0.000104>
   dlsym(0x1632320, "elm_quicklaunch_init")                                                  = 0x7fbc88d4d150 <0.000100>
   __dlog_print(0, 3, 0x40a014, 0x409be8)                                                    = 0 <0.000060>
   dlsym(0x1632320, "elm_quicklaunch_shutdown")                                              = 0x7fbc88d4db70 <0.000085>
   __dlog_print(0, 3, 0x40a014, 0x409c18)                                                    = 0 <0.000059>
   g_slist_prepend(0, 0x16322a0, 0, 0x409c18)                                                = 0x165a920 <0.000061>
   fgets("/usr/lib64/libappcore-common.so."..., 128, 0x1632060)                              = 0x7fffb7029b70 <0.000055>
   strnlen(0x7fffb7029b70, 128, 0x1632140, 0)                                                = 34 <0.000060>
   calloc(1, 24)                                                                             = 0x165c4c0 <0.000056>
   dlopen("/usr/lib64/libappcore-common.so."..., 2)                                          = 0x1634130 <0.000324>
   __dlog_print(0, 3, 0x40a014, 0x409bc0)                                                    = 0 <0.000059>
   dlsym(0x1634130, "elm_quicklaunch_init")                                                  = 0 <0.000082>
   g_slist_prepend(0x165a920, 0x165c4c0, 0x7fbc8bc0e908, 1)                                  = 0x165a930 <0.000060>
   fgets("/usr/lib64/ecore/immodules/libis"..., 128, 0x1632060)                              = 0x7fffb7029b70 <0.000055>
   strnlen(0x7fffb7029b70, 128, 0x1632140, 0)                                                = 48 <0.000059>
   calloc(1, 24)                                                                             = 0x163e660 <0.000056>
   dlopen("/usr/lib64/ecore/immodules/libis"..., 2)                                          = 0 <0.000120>
   free(0x163e660)                                                                           = <void> <0.000056>
   fgets("/usr/lib64/osp/libosp-appfw.so\n", 128, 0x1632060)                                 = 0x7fffb7029b70 <0.000053>
   strnlen(0x7fffb7029b70, 128, 0x1632140, 0)                                                = 31 <0.000059>
   calloc(1, 24)                                                                             = 0x163e660 <0.000056>
   dlopen("/usr/lib64/osp/libosp-appfw.so", 2)                                               = 0 <0.000108>
   free(0x163e660)                                                                           = <void> <0.000054>
   fgets("/usr/lib64/osp/libosp-uifw.so\n", 128, 0x1632060)                                  = 0x7fffb7029b70 <0.000055>
   strnlen(0x7fffb7029b70, 128, 0x1632140, 0)                                                = 30 <0.000060>
   calloc(1, 24)                                                                             = 0x163e660 <0.000056>
   dlopen("/usr/lib64/osp/libosp-uifw.so", 2)                                                = 0 <0.000106>
   free(0x163e660)                                                                           = <void> <0.000054>
   fgets("/usr/lib64/osp/libosp-uifw.so", 128, 0x1632060)                                    = 0 <0.000066>
   fclose(0x1632060)                                                                         = 0 <0.000087>
   __cxa_atexit(0x405b50, 0, 0, 0xfbad000c)                                                  = 0 <0.000065>
   fopen("/usr/share/aul/preload_list_wrt."..., "rt")                                        = 0x1632060 <0.000111>
   fgets("/usr/bin/wrt-client\n", 128, 0x1632060)                                            = 0x7fffb7029b70 <0.000093>
   strnlen(0x7fffb7029b70, 128, 0x1632140, 0)                                                = 20 <0.000059>
   dlopen("/usr/bin/wrt-client", 258)                                                        = 0x165c860 <0.174964>
   realloc(0, 80)                                                                            = 0x169f120 <0.000071>
   __dlog_print(0, 3, 0x40a014, 0x409bc0)                                                    = 0 <0.000065>
   fgets("/usr/lib64/libwrt-injected-bundl"..., 128, 0x1632060)                              = 0x7fffb7029b70 <0.000058>
   strnlen(0x7fffb7029b70, 128, 0x1632140, 0)                                                = 37 <0.000063>
   dlopen("/usr/lib64/libwrt-injected-bundl"..., 258)                                        = 0x169f1b0 <0.077871>
   __dlog_print(0, 3, 0x40a014, 0x409bc0)                                                    = 0 <0.000077>
   fgets("/usr/lib64/wrt-plugins/w3c-widge"..., 128, 0x1632060)                              = 0x7fffb7029b70 <0.000058>
   strnlen(0x7fffb7029b70, 128, 0x1632140, 0)                                                = 83 <0.000112>
   dlopen("/usr/lib64/wrt-plugins/w3c-widge"..., 258)                                        = 0x16a83c0 <0.072298>
   __dlog_print(0, 3, 0x40a014, 0x409bc0)                                                    = 0 <0.000089>
   fgets("/usr/lib64/wrt-plugins/tizen-tiz"..., 128, 0x1632060)                              = 0x7fffb7029b70 <0.000060>
   strnlen(0x7fffb7029b70, 128, 0x1632140, 0)                                                = 65 <0.000065>
   dlopen("/usr/lib64/wrt-plugins/tizen-tiz"..., 258)                                        = 0x169eb20 <0.075723>
   __dlog_print(0, 3, 0x40a014, 0x409bc0)                                                    = 0 <0.000084>
   fgets("/usr/lib64/wrt-plugins/tizen-tiz"..., 128, 0x1632060)                              = 0 <0.000071>
   fclose(0x1632060)                                                                         = 0 <0.000085>
   fopen("/usr/share/aul/preexec_list.txt", "rt")                                            = 0x1632060 <0.000118>
   __dlog_print(0, 3, 0x40a014, 0x40a369)                                                    = 0 <0.000060>
   fgets("#preexec configuration\n", 128, 0x1632060)                                         = 0x7fffb7029b70 <0.000094>
   fgets("##usage##\n", 128, 0x1632060)                                                      = 0x7fffb7029b70 <0.000055>
   fgets("#[type]: [preexec so path], [pre"..., 128, 0x1632060)                              = 0x7fffb7029b70 <0.000054>
   fgets("tpk: /usr/lib64/libosp-env-confi"..., 128, 0x1632060)                              = 0x7fffb7029b70 <0.000055>
   __strtok_r(0x7fffb7029b70, 0x40a385, 0x7fffb7029ad0, 0)                                   = 0x7fffb7029b70 <0.000062>
   __strtok_r(0, 0x40a38d, 0x7fffb7029ad0, 0x7fffb7029b74)                                   = 0x7fffb7029b75 <0.000059>
   __strtok_r(0, 0x40a38d, 0x7fffb7029ad0, 0x7fffb7029b95)                                   = 0x7fffb7029b96 <0.000059>
   calloc(1, 32)                                                                             = 0x16b4270 <0.000056>
   dlopen("/usr/lib64/libosp-env-config.so", 2)                                              = 0 <0.000145>
   free(0x16b4270)                                                                           = <void> <0.000055>
   fgets("tpk", 128, 0x1632060)                                                              = 0 <0.000066>
   fclose(0x1632060)                                                                         = 0 <0.000082>
   socket(1, 524289, 0)                                                                      = 7 <0.000078>
   __snprintf_chk(0x7fffb70299a2, 108, 1, 108)                                               = 28 <0.000060>
   unlink("/tmp/wrt_process_pool_server")                                                    = 0 <0.000103>
   __dlog_print(0, 3, 0x408d51, 0x40aa45)                                                    = 0 <0.000059>
   bind(7, 0x7fffb70299a0, 110, 0x40aa45)                                                    = 0 <0.000088>
   __dlog_print(0, 3, 0x408d51, 0x40aa5d)                                                    = 0 <0.000065>
   chmod("/tmp/wrt_process_pool_server", 0777)                                               = 0 <0.000120>
   __dlog_print(0, 3, 0x408d51, 0x40aa8f)                                                    = 0 <0.000063>
   listen(7, 10, 0, 0x40aa8f)                                                                = 0 <0.000075>
   __dlog_print(0, 3, 0x408d51, 0x40a930)                                                    = 0 <0.000059>
   time(0)                                                                                   = 1382437786 <0.000056>
   time(0)                                                                                   = 1382437786 <0.000053>
   time(0)                                                                                   = 1382437786 <0.000052>


More information about the Dev mailing list