[TIMOB-12376] Android Deployment: build takes a long time

GitHub Issue	n/a
Type	Bug
Priority	High
Status	Closed
Resolution	Cannot Reproduce
Resolution Date	2013-08-07T23:35:50.000+0000
Affected Version/s	n/a
Fix Version/s	n/a
Components	Android, Tooling
Labels	android, androidbuild, cb-verified, qe-3.0.2
Reporter	Shawn Lipscomb
Assignee	Chris Barber
Created	2013-01-22T21:29:01.000+0000
Updated	2017-03-21T21:35:10.000+0000

Description

User Story:

Most of the time when I'm running a freshly-cleaned project from Ti Studio, 
the Application Installer console gets to "" and then there's this long
pause, for about a minute, when there's no activity in the log and no CPU usage.
I'm running Windows 7 on a relatively new/fast machine. 
My CPU has 6 cores and none of them are showing any activity during that time.

It doesn't matter which SDK I use to build a project.
I'm using Windows 7 and building for Android 2.2 emulator (HVGA).

I'm pretty sure it always happens on the first build of the day (fresh run of Ti Studio, no previous emulator or ADB running). Happens on all projects.

QE Investigation:

I've tested this in Windows 7 using Titanium Studio 3.0.1 and
Titanium SDK 3.0.0GA and 2.1.4GA for the Android 2.2 Emulator. The
only pause I am seeing is for the compiling Android resources step
which warns the user it might take some time. I am unable to recreate
the issue as described. Could it be that his PC is too fast and that
something is waiting for a condition who's finish report came in
before the check? That's my only idea.

Comments

Shawn Lipscomb 2013-01-22

Response to QE Investigation: It could be that my PC is "too fast". I'm running a 3.47GHz Xeon processor with 6 cores. Windows 7 64-bit. The last lines I see in the Application Installer console window is: {panel}[INFO] Installing application on emulator [DEBUG] "C:\Program Files (x86)\Android\platform-tools\adb.exe" -e install -r C:\Titanium\blablaWorkspace\blablaProject\build\android\bin\app.apk{panel} then 1.5 minutes later it takes off with: {panel}[INFO] Launching application ... bla bla project name{panel}

Shawn Lipscomb 2013-01-23

I ran a clean build with Preferences > Titanium Studio > Troubleshooting > Debug > All, and got this log file (Help > Titanium Studio > View Log File):

   !ENTRY com.aptana.core 1 0 2013-01-23 08:54:23.480
   !MESSAGE (Build 3.0.1.201212181159) [INFO] com.aptana.core/debug/shell Running process:
   Process: "C:\Titanium\plugins\com.appcelerator.titanium.python.win32_1.0.0.1338515509\python\python.exe" "C:\Users\Shawn\AppData\Roaming\Titanium\mobilesdk\win32\3.1.0.v20130109175536\android\builder.py" "emulator" "TestProject" "C:\Program Files (x86)\Android" "C:\Titanium\GameWorkspace\TestProject" "com.EWRInc.TestProject" "1" "HVGA" "armeabi" ""
   Working directory: null
   Environment: {ALLUSERSPROFILE=C:\ProgramData, ANALYTICS_SOURCE=studio, APPDATA=C:\Users\Shawn\AppData\Roaming, BURN_AUTOPLAY=C:\Program Files (x86)\Roxio\OEM\Roxio Burn\, COMPUTERNAME=SHAWNS-T3500, ComSpec=C:\Windows\system32\cmd.exe, CommonProgramFiles=C:\Program Files (x86)\Common Files, CommonProgramFiles(x86)=C:\Program Files (x86)\Common Files, CommonProgramW6432=C:\Program Files\Common Files, DellClientSystemUpdatePath=C:\Program Files (x86)\Dell\ClientSystemUpdate\, EMC_AUTOPLAY=C:\Program Files (x86)\Common Files\Roxio Shared\OEM\, FP_NO_HOST_CHECK=NO, HOMEDRIVE=C:, HOMEPATH=\Users\Shawn, JAVA_HOME=C:\Progra~2\Java\jdk1.6.0_38, LOCALAPPDATA=C:\Users\Shawn\AppData\Local, LOGONSERVER=\\SHAWNS-T3500, NUMBER_OF_PROCESSORS=6, OS=Windows_NT, PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC, PROCESSOR_ARCHITECTURE=x86, PROCESSOR_ARCHITEW6432=AMD64, PROCESSOR_IDENTIFIER=Intel64 Family 6 Model 44 Stepping 2, GenuineIntel, PROCESSOR_LEVEL=6, PROCESSOR_REVISION=2c02, PSModulePath=C:\Windows\system32\WindowsPowerShell\v1.0\Modules\, PUBLIC=C:\Users\Public, Path=C:/Titanium/jre/bin/client;C:/Titanium/jre/bin;C:/Titanium/jre/lib/i386;C:\Progra~2\Java\jdk1.6.0_38;%android_sdk%;C:\Progra~2\Java\jdk1.6.0_38\bin;C:\Delphi\bin;C:\Users\Public\Documents\RAD Studio\9.0\Bpl;C:\Delphi\bin64;C:\Users\Public\Documents\RAD Studio\9.0\Bpl\Win64;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Program Files (x86)\Android\platform-tools\;C:\Program Files (x86)\Android\tools\;C:\Program Files (x86)\Borland\StarTeam SDK 11.0\Lib;C:\Program Files (x86)\Borland\StarTeam SDK 11.0\Bin;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files (x86)\NTRU Cryptosystems\NTRU TCG Software Stack\bin\;C:\Program Files\NTRU Cryptosystems\NTRU TCG Software Stack\bin\;C:\Program Files\Dell\Dell Data Protection\Access\Advanced\Wave\Gemalto\Access Client\v5\;C:\Program Files (x86)\Common Files\Roxio Shared\DLLShared\;C:\Program Files (x86)\Common Files\Roxio Shared\OEM\DLLShared\;C:\Program Files (x86)\Common Files\Roxio Shared\OEM\DLLShared\;C:\Program Files (x86)\Common Files\Roxio Shared\OEM\12.0\DLLShared\;C:\Program Files (x86)\Roxio\OEM\AudioCore\;C:\Program Files\Symantec.cloud\PlatformAgent\;C:\ClipperDevelopment\FOXBASE;C:\Program Files (x86)\QuickTime\QTSystem\;C:\Program Files (x86)\nodejs\;C:\Users\Shawn\AppData\Roaming\npm\;C:\Titanium;, ProgramData=C:\ProgramData, ProgramFiles=C:\Program Files (x86), ProgramFiles(x86)=C:\Program Files (x86), ProgramW6432=C:\Program Files, QTJAVA=C:\Program Files (x86)\Java\jre6\lib\ext\QTJava.zip, RCAUTOPLAY=C:\Program Files (x86)\Roxio\OEM\Roxio Central 5\, SESSIONNAME=Console, SystemDrive=C:, SystemRoot=C:\Windows, TEMP=C:\Users\Shawn\AppData\Local\Temp, TMP=C:\Users\Shawn\AppData\Local\Temp, USERDOMAIN=Shawns-T3500, USERNAME=Shawn, USERPROFILE=C:\Users\Shawn, eCotton_Developer=Shawn, windir=C:\Windows}
   
   !ENTRY com.aptana.core 1 0 2013-01-23 08:54:33.535
   !MESSAGE (Build 3.0.1.201212181159) [INFO] com.aptana.core/debug/shell Running process:
   Process: "C:\Titanium\plugins\com.appcelerator.titanium.python.win32_1.0.0.1338515509\python\python.exe" "C:\Users\Shawn\AppData\Roaming\Titanium\mobilesdk\win32\3.1.0.v20130109175536\android\fastdev.py" "start" "C:\Titanium\GameWorkspace\TestProject"
   Working directory: null
   Environment: {ALLUSERSPROFILE=C:\ProgramData, ANALYTICS_SOURCE=studio, APPDATA=C:\Users\Shawn\AppData\Roaming, BURN_AUTOPLAY=C:\Program Files (x86)\Roxio\OEM\Roxio Burn\, COMPUTERNAME=SHAWNS-T3500, ComSpec=C:\Windows\system32\cmd.exe, CommonProgramFiles=C:\Program Files (x86)\Common Files, CommonProgramFiles(x86)=C:\Program Files (x86)\Common Files, CommonProgramW6432=C:\Program Files\Common Files, DellClientSystemUpdatePath=C:\Program Files (x86)\Dell\ClientSystemUpdate\, EMC_AUTOPLAY=C:\Program Files (x86)\Common Files\Roxio Shared\OEM\, FP_NO_HOST_CHECK=NO, HOMEDRIVE=C:, HOMEPATH=\Users\Shawn, JAVA_HOME=C:\Progra~2\Java\jdk1.6.0_38, LOCALAPPDATA=C:\Users\Shawn\AppData\Local, LOGONSERVER=\\SHAWNS-T3500, NUMBER_OF_PROCESSORS=6, OS=Windows_NT, PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC, PROCESSOR_ARCHITECTURE=x86, PROCESSOR_ARCHITEW6432=AMD64, PROCESSOR_IDENTIFIER=Intel64 Family 6 Model 44 Stepping 2, GenuineIntel, PROCESSOR_LEVEL=6, PROCESSOR_REVISION=2c02, PSModulePath=C:\Windows\system32\WindowsPowerShell\v1.0\Modules\, PUBLIC=C:\Users\Public, Path=C:/Titanium/jre/bin/client;C:/Titanium/jre/bin;C:/Titanium/jre/lib/i386;C:\Progra~2\Java\jdk1.6.0_38;%android_sdk%;C:\Progra~2\Java\jdk1.6.0_38\bin;C:\Delphi\bin;C:\Users\Public\Documents\RAD Studio\9.0\Bpl;C:\Delphi\bin64;C:\Users\Public\Documents\RAD Studio\9.0\Bpl\Win64;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Program Files (x86)\Android\platform-tools\;C:\Program Files (x86)\Android\tools\;C:\Program Files (x86)\Borland\StarTeam SDK 11.0\Lib;C:\Program Files (x86)\Borland\StarTeam SDK 11.0\Bin;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files (x86)\NTRU Cryptosystems\NTRU TCG Software Stack\bin\;C:\Program Files\NTRU Cryptosystems\NTRU TCG Software Stack\bin\;C:\Program Files\Dell\Dell Data Protection\Access\Advanced\Wave\Gemalto\Access Client\v5\;C:\Program Files (x86)\Common Files\Roxio Shared\DLLShared\;C:\Program Files (x86)\Common Files\Roxio Shared\OEM\DLLShared\;C:\Program Files (x86)\Common Files\Roxio Shared\OEM\DLLShared\;C:\Program Files (x86)\Common Files\Roxio Shared\OEM\12.0\DLLShared\;C:\Program Files (x86)\Roxio\OEM\AudioCore\;C:\Program Files\Symantec.cloud\PlatformAgent\;C:\ClipperDevelopment\FOXBASE;C:\Program Files (x86)\QuickTime\QTSystem\;C:\Program Files (x86)\nodejs\;C:\Users\Shawn\AppData\Roaming\npm\;C:\Titanium;, ProgramData=C:\ProgramData, ProgramFiles=C:\Program Files (x86), ProgramFiles(x86)=C:\Program Files (x86), ProgramW6432=C:\Program Files, QTJAVA=C:\Program Files (x86)\Java\jre6\lib\ext\QTJava.zip, RCAUTOPLAY=C:\Program Files (x86)\Roxio\OEM\Roxio Central 5\, SESSIONNAME=Console, SystemDrive=C:, SystemRoot=C:\Windows, TEMP=C:\Users\Shawn\AppData\Local\Temp, TMP=C:\Users\Shawn\AppData\Local\Temp, USERDOMAIN=Shawns-T3500, USERNAME=Shawn, USERPROFILE=C:\Users\Shawn, eCotton_Developer=Shawn, windir=C:\Windows}
   
   !ENTRY com.aptana.core 1 0 2013-01-23 08:54:33.542
   !MESSAGE (Build 3.0.1.201212181159) [INFO] com.aptana.core/debug/shell Running process:
   Process: "C:\Titanium\plugins\com.appcelerator.titanium.python.win32_1.0.0.1338515509\python\python.exe" "C:\Users\Shawn\AppData\Roaming\Titanium\mobilesdk\win32\3.1.0.v20130109175536\android\builder.py" "simulator" "TestProject" "C:\Program Files (x86)\Android" "C:\Titanium\GameWorkspace\TestProject" "com.EWRInc.TestProject" "1" "HVGA" ""
   Working directory: null
   Environment: {ALLUSERSPROFILE=C:\ProgramData, ANALYTICS_SOURCE=studio, APPDATA=C:\Users\Shawn\AppData\Roaming, BURN_AUTOPLAY=C:\Program Files (x86)\Roxio\OEM\Roxio Burn\, COMPUTERNAME=SHAWNS-T3500, ComSpec=C:\Windows\system32\cmd.exe, CommonProgramFiles=C:\Program Files (x86)\Common Files, CommonProgramFiles(x86)=C:\Program Files (x86)\Common Files, CommonProgramW6432=C:\Program Files\Common Files, DellClientSystemUpdatePath=C:\Program Files (x86)\Dell\ClientSystemUpdate\, EMC_AUTOPLAY=C:\Program Files (x86)\Common Files\Roxio Shared\OEM\, FP_NO_HOST_CHECK=NO, HOMEDRIVE=C:, HOMEPATH=\Users\Shawn, JAVA_HOME=C:\Progra~2\Java\jdk1.6.0_38, LOCALAPPDATA=C:\Users\Shawn\AppData\Local, LOGONSERVER=\\SHAWNS-T3500, NUMBER_OF_PROCESSORS=6, OS=Windows_NT, PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC, PROCESSOR_ARCHITECTURE=x86, PROCESSOR_ARCHITEW6432=AMD64, PROCESSOR_IDENTIFIER=Intel64 Family 6 Model 44 Stepping 2, GenuineIntel, PROCESSOR_LEVEL=6, PROCESSOR_REVISION=2c02, PSModulePath=C:\Windows\system32\WindowsPowerShell\v1.0\Modules\, PUBLIC=C:\Users\Public, Path=C:/Titanium/jre/bin/client;C:/Titanium/jre/bin;C:/Titanium/jre/lib/i386;C:\Progra~2\Java\jdk1.6.0_38;%android_sdk%;C:\Progra~2\Java\jdk1.6.0_38\bin;C:\Delphi\bin;C:\Users\Public\Documents\RAD Studio\9.0\Bpl;C:\Delphi\bin64;C:\Users\Public\Documents\RAD Studio\9.0\Bpl\Win64;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Program Files (x86)\Android\platform-tools\;C:\Program Files (x86)\Android\tools\;C:\Program Files (x86)\Borland\StarTeam SDK 11.0\Lib;C:\Program Files (x86)\Borland\StarTeam SDK 11.0\Bin;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files (x86)\NTRU Cryptosystems\NTRU TCG Software Stack\bin\;C:\Program Files\NTRU Cryptosystems\NTRU TCG Software Stack\bin\;C:\Program Files\Dell\Dell Data Protection\Access\Advanced\Wave\Gemalto\Access Client\v5\;C:\Program Files (x86)\Common Files\Roxio Shared\DLLShared\;C:\Program Files (x86)\Common Files\Roxio Shared\OEM\DLLShared\;C:\Program Files (x86)\Common Files\Roxio Shared\OEM\DLLShared\;C:\Program Files (x86)\Common Files\Roxio Shared\OEM\12.0\DLLShared\;C:\Program Files (x86)\Roxio\OEM\AudioCore\;C:\Program Files\Symantec.cloud\PlatformAgent\;C:\ClipperDevelopment\FOXBASE;C:\Program Files (x86)\QuickTime\QTSystem\;C:\Program Files (x86)\nodejs\;C:\Users\Shawn\AppData\Roaming\npm\;C:\Titanium;, ProgramData=C:\ProgramData, ProgramFiles=C:\Program Files (x86), ProgramFiles(x86)=C:\Program Files (x86), ProgramW6432=C:\Program Files, QTJAVA=C:\Program Files (x86)\Java\jre6\lib\ext\QTJava.zip, RCAUTOPLAY=C:\Program Files (x86)\Roxio\OEM\Roxio Central 5\, SESSIONNAME=Console, SystemDrive=C:, SystemRoot=C:\Windows, TEMP=C:\Users\Shawn\AppData\Local\Temp, TMP=C:\Users\Shawn\AppData\Local\Temp, USERDOMAIN=Shawns-T3500, USERNAME=Shawn, USERPROFILE=C:\Users\Shawn, eCotton_Developer=Shawn, windir=C:\Windows}
   
   !ENTRY com.appcelerator.titanium.mobile.ui 1 0 2013-01-23 08:56:51.746
   !MESSAGE (Build 3.0.1.201212181159) [INFO] com.appcelerator.titanium.mobile/debug Android application installation terminated
   
   !ENTRY com.appcelerator.titanium.mobile.ui 1 0 2013-01-23 08:56:51.746
   !MESSAGE (Build 3.0.1.201212181159) [INFO] com.appcelerator.titanium.mobile/debug Android application installation exit value was 0
   
   !ENTRY com.aptana.editor.common 1 0 2013-01-23 08:57:43.555
   !MESSAGE (Build 3.0.1.201212181159) [INFO] com.aptana.editor.common/debug/presentation Initiating presentation reconciling for region at offset 0, length 10,560 in document of length 10,560

You can see the time gap between the running of builder.py and "Android application installation terminated", although it's 2 minutes and 18 seconds long, of that, 1 minute 15 seconds was the 0% CPU usage pause between the console messagess "Installing application on emulator" and "Launching application" (as shown in my previous comment, above). Nothing else happened in the console log during that 1 minute 15 second pause.

Chris Barber 2013-02-26

@Shawn, I don't think your computer is too fast, though that could be possible. Android's build system has flaws with launching the emulator. Things are broken in Titanium SDK 3 and newer. I recommend manually building using the CLI to call the "titanium" command or directly call the old Android builder.py. First run "android list target". Find the SDK that you want to use. I recommend selecting one that includes the Google APIs. Take note of the numeric ID. The ID is machine specific. Also, notice what "skins" are supported by that SDK. The default skin is HVGA, but that's not necessarily supported by all platforms. I personally cheat the system by making my own AVD from the Android AVD manager called "titanium_10_800x1280_armeabi-v7a" based on the Android 4.2 SDK, Intel Atom (x86) CPU, and a screen size of a Nexus 7. So, when I call the build command, I need to specify --avd-id 10 and --avd-skin 800x1280. Note that the AVD name must end with "_armeabi-v7a" even if the AVD's CPU is not "ARM". Then from the project's directory, run: titanium build -p android --log-level trace --output-dir . --avd-id <NUMERIC ID FROM ABOVE> --avd-skin <SKIN FROM ABOVE>
Chris Barber 2013-08-07

[~bitshftr] Have you figured out what's going on with this yet? Was this happening on an x86 Android emulator or an ARM Android emulator? If you do a simple "adb -e install yourapp.apk", does that take a long time? Is it intermittent?
Shawn Lipscomb 2013-08-07

Chris, when I do "adb -e install yourapp.apk" with a fresh emulator (ARM), I get this: * daemon not running. starting it now on port 5037 * * daemon started successfully * 70 KB/s (6027258 bytes in 83.916s) pkg: /data/local/tmp/yourapp.apk Success Note that it took 83 seconds. During that time, I saw 0% CPU usage, and nothing else in the command prompt window. The 83 second delay started after the line "* daemon started successfully *" appeared. The emulator I started was one that Titanium generated (HVGA, Google APIs, Android 2.2). The APK is 5.8MB. I see that adb reported "70 KB/s". This is on my hard drive, so why is it only getting 70k per second transfer rate? I can copy that file anywhere else that I want to in the blink of an eye.
Chris Barber 2013-08-07

[~bitshftr] If a simple "adb install" takes 83 seconds, that seems to line up with your earlier finds of "about a minute" and "1.5 minutes later". If adb is taking that long to install, I don't think that's a Titanium thing. Is your Android SDK up-to-date including the Build Tools and Platform Tools? Have you tried installing HAXM and running a x86 emulator?
Shawn Lipscomb 2013-08-07

Agreed, at this point I don't think it's a Titanium issue...unless for some reason the AVD image that Titanium created has some kind of flaw that is causing a throttling of throughput or an overactive (or crippled) emulator CPU. Stack Overflow has some posts that indicate that clicking around on the emulator (stimulating the emulator?) speeds up the app install, and my quick non-scientific tests confirm this. My Android SDK is up to date. I have not tried the HAXM/x86 emulator yet.
Chris Barber 2013-08-07

[~bitshftr] cool. I'll mark this issue as resolved. For more info about getting up and running with HAXM and the Android x86 emulator, check out this blog post: http://developer.appcelerator.com/blog/2013/07/speed-up-your-android-emulator.html. Also, we are in the process of adding support for Genymotion and it's gonna be sweet! TIMOB-14637
Lee Morris 2017-03-21

Closing ticket as the issue cannot be reproduced and due to the above comments.

JSON Source