Firefox OS/Performance/Boot Sequence Optimization: Difference between revisions

m
Lakrits moved page FirefoxOS/Performance/Boot Sequence Optimization to Firefox OS/Performance/Boot Sequence Optimization: The official spelling of "Firefox OS" leaves a space between the two parts of the name. It's easier to find a page if the...
m (Lakrits moved page FirefoxOS/Performance/Boot Sequence Optimization to Firefox OS/Performance/Boot Sequence Optimization: The official spelling of "Firefox OS" leaves a space between the two parts of the name. It's easier to find a page if the...)
 
(16 intermediate revisions by 2 users not shown)
Line 24: Line 24:


==The Plan==
==The Plan==
[[FirefoxOS/Performance/Boot_Profiling]]
* [[FirefoxOS/Performance/Boot_Profiling|Boot Profiling]]
* [[FirefoxOS/Performance/Boot_Timing_Automation|Boot Timing Automation]]


==Bootchart==
==Bootchart==
Some example preliminary data collected via [http://www.bootchart.org/ bootchart] [http://people.mozilla.org/~jbailey/fxos_bootchart/ here].
[http://www.bootchart.org/ Bootchart] is a tool for collecting data on OS boot, and then processing it into easily digestible charts. Some example preliminary data collected via bootchart [http://people.mozilla.org/~jbailey/fxos_bootchart/ here].


To enable the collection of bootchart data in FireFox OS one must build '''init''' with the following environment variable set.
To enable the collection of bootchart data in FireFox OS one must build '''init''' with the following environment variable set.
Line 34: Line 35:
</pre>
</pre>


Once init on the device has been replaced with the bootchart-enabled version [[FirefoxOS/Performance/Modifying boot.img|(see process here)]], to begin logging one simply creates a file <code>|/data/bootchart-start|</code> on the device containing an integer representing the number of seconds for which bootchart should collect data, and then reboots the device.


Once init has been replaced on the device [[FirefoxOS/Performance/Modifying boot.img|(see process here)]], to enable logging one simply creates a file '''|'''/data/bootchart-start'''|''' on the device containing an integer representing the number of seconds for which bootchart should collect data, and then reboot the device.
Bootchart data is pulled from the device with the <code>system/core/grab-bootchart.sh</code> script, and presented in the form of a bootchart.tgz file. With the data collected one can then generate graphs by invoking:
 
 
Bootchart data is pulled from the device with the system/core/grab-bootchart.sh script, and presented in the form of a bootchart.tgz file. With the data collected one can then generate graphs by invoking:
<pre>
<pre>
java -jar bootchart.jar -f eps bootchart.tgz
java -jar bootchart.jar -f eps bootchart.tgz
</pre>
</pre>


Without the |-f eps| parameters, the default is for a PNG to be generated. The SVG format is also supported.
Without the <code>|-f eps|</code> parameters, the default is for a PNG to be generated. The SVG format is also supported.
 
Note that the charts generated by the stock bootchart.jar do not seem to include disk stats. This is because it does not recognize the mmcblk'''N'''p'''M''' format of partition names, and this can easily be fixed in the bootchart source code ( in particular, at |bootchart-0.9/src/org/bootchart/parser/linux/ProcDiskStatParser.java| ).


Another bootchart related change I made was in regards to how it records collected data. By default the process name is discarded and replaced by the cmdline invokation. This is not very useful considering b2g apps are then all shown as "Plugin-container". I things such that both names are recorded.
Note that the charts generated by the stock bootchart.jar do not seem to include disk stats. This is because it does not recognize the <code>mmcblk'''N'''p'''M'''</code> format of disk partition names, and this can easily be fixed in the bootchart source code (in particular, in <code>|bootchart-0.9/src/org/bootchart/parser/linux/ProcDiskStatParser.java|</code>).


Another bootchart related change made was in regards to how it records collected data. By default the process name is discarded and replaced by the 'cmdline' invocation (found in proc/PID/cmdline). This is not very useful considering b2g apps are then all shown as "Plugin-container". Init was [http://people.mozilla.org/~jbailey/bchart.patch modified] such that both names are recorded.


=== Data ===  
=== Data ===  
Line 80: Line 78:


[http://people.mozilla.org/~jbailey/v10G-first-baselines/ Old Baseline statistics]
[http://people.mozilla.org/~jbailey/v10G-first-baselines/ Old Baseline statistics]
These results were collected but then i decided to base my experiments on a slightly newer baseimage
These results were collected but I then decided to base my experiments on the newer v121 baseimage.


Note that all data collected applies to the Flame reference device.
Note that all data collected applies to the Flame reference device.
Line 89: Line 87:
For this and future data collection, at least 30 trials will be recorded. Also in the root directory there are a few randomly selected trials for which charts were generated for quick reference.
For this and future data collection, at least 30 trials will be recorded. Also in the root directory there are a few randomly selected trials for which charts were generated for quick reference.


A rough idea of what we are seeing currently, as well as empirical hypotheses:
A rough idea of what was seen, as well as empirical hypotheses:
* B2G starts after roughly 8s of mysterious "stuff"
* B2G starts after roughly 8s of mysterious "stuff", impenetrable to bootchart
* It has been noted that time between 5s and 8s is likely script execution up until |class_start main| in the init.rc
* Based on kmsg, it is likely that time between 5s and 8s is init script execution up until <code>|class_start main|</code> in the init.rc (which launches B2G service)
* Vertical comes up around 16s, however it does not seem to actually do anything until several seconds after that.
* Vertical is shown as coming up around 16s, however it is actually just the preallocated process at this point, which later becomes vertical (around 22s-23s).
<!-- although I feel like some time as been lost... (by stopwatch it seems longer than that) | is what i thought earlier, but it could just be idle
* As well it seems we are only at the init entry point around 4 seconds in anyway (based on inserted kernel log output)
      I should stopwatch time beginning of vertical again -->
* As well it seems init is only really alive at 4 seconds anyway (based on inserted kernel log output)


* As such it is likely that
* As such it is likely that
<code>
** -3.5s = bootloader + Early kernel
** -3.5s = bootloader + Early kernel
**   0s = kernel timing initialized
** &nbsp;&nbsp; 0s = kernel timing initialized
** ~4.5s = init main
** ~4.5s = init main
**  7-8s = B2G
**  &nbsp;7-8s = B2G
**  ~14s = (Nuwa)
**  &nbsp;~14s = (Nuwa)
**  ~16s = Vertical
**  &nbsp;~16s = Preallocated
**  ~25s = UI presented to user
**  &nbsp;~22s = Homescreen app?
**  &nbsp;~25s = UI presented to user
</code>


Of note is that there exists a pronounced black screen between the T2mobile and the "Mozilla Developer Network" logos, that was introduced at some point. Dave Huseby has noted in the past that such a noticeable black screen exists in other devices. This was less visible in past versions.
Of note is that there exists a pronounced black screen between the T2mobile and the "Mozilla Developer Network" logos, that was introduced at some point. Dave Huseby has noted in the past that such a noticeable black screen exists in other devices. This was less visible in past versions.


Of course, more concrete data will be explored later, but that is the general gist of things.
Of course, there is more concrete data, but that is the general trend of things.
 
Note the discrepancy between the vertical process coming up and actual availability, that will be the focus of a future investigation.


[http://people.mozilla.org/~jbailey/v121-2-premainb2g/ Experiment #1]
[http://people.mozilla.org/~jbailey/v121-2-premainb2g/ Experiment #1]
Line 121: Line 118:
In these images, each horizontal bar represents the lifetime of a process. A processes children are below it, and parent child relationships are indicated by a dotted line from the parent going into the beginning of the child's bar. The process bars are in order of launch time (earliest first). Blue segments of the bar represent CPU activity while pink segments indicate IO.
In these images, each horizontal bar represents the lifetime of a process. A processes children are below it, and parent child relationships are indicated by a dotted line from the parent going into the beginning of the child's bar. The process bars are in order of launch time (earliest first). Blue segments of the bar represent CPU activity while pink segments indicate IO.


Based on the current code, the earliest it is conceivably possible to run B2G would be in the early-init stage of init.rc. This stage was observed to be executing at around 4.8s of uptime. Realistically a lot of things would need to be changed for this to work (that is to say, a lot of things break when this is attempted). A more logical stage would be early-boot (which is not used in the default init script, however is a supported stage that occurs between post-fs-data and boot). What is notable about this stage is that, A.) if done here, B2G launches at around 5.8s and B.) It successfully runs. Sometimes. There are clearly some dependencies that are not quite guaranteed to be ready if one attempts to launch B2G this early, which could be the subject of a future investigation to see if those dependencies could be moved earlier as well. However as it stands, this only launches B2G around 2 seconds earlier. and there actually was no decrease in overall boot time observed (again dependencies not being respected comes to mind as an explanation).  
Based on the current code, the earliest it is conceivably possible to run B2G would be in the early-init stage of init.rc. This stage was observed to be executing at around 4.8s of uptime. Realistically a lot of things would need to be changed for this to work (that is to say, a lot of things break when this is attempted). A more logical stage would be early-boot (which is not used in the default init script, however is a supported stage that occurs between post-fs-data and boot). What is notable about this stage is that, A.) if done here, B2G launches at around 5.8s and B.) It successfully runs. Sometimes. There are clearly some dependencies that are not quite guaranteed to be ready if one attempts to launch B2G this early, which could be the subject of a future investigation to see if those dependencies could be moved earlier as well. However as it stands, this only launches B2G around 2 seconds earlier. and there actually was no decrease in overall boot time observed (again dependencies not being respected comes to mind as an explanation, or gaia/gecko depending on some other service being initialized).  


[http://people.mozilla.org/~jbailey/v121-2-lesswreckless/ Related Data]. Fewer trials were done because these were just cursory feasibility tests.
[http://people.mozilla.org/~jbailey/v121-2-lesswreckless/ Related Data]. Fewer trials were done because these were just cursory feasibility tests.
3,860

edits