search

younglo / cyanogenmod4milestone

Automatically exported from code.google.com/p/cyanogenmod4milestone
0 stars 0 forks source link

Package installation fails and causes phone reboot #614

Open GoogleCodeExporter opened 8 years ago

GoogleCodeExporter commented 8 years ago 
What steps will reproduce the problem?
1. happens at random times while installing packages (from market or from 
eclipse).

What version of the product are you using?
CM7.1 rc10 but also happened with earlier versions.

Please provide any additional information below.

I'm using CM apps2sd, after install failure, the phone reboots itself, and then 
the sdext partitions are mounted read-only. A new reboot is required to mount 
apps2sd partition as read-write.
While sdext partition is read-only, attempts to install other packages will 
fail and cause reboots.

Original issue reported on code.google.com by yuri.da...@gmail.com on 22 Jun 2011 at 12:28

GoogleCodeExporter commented 8 years ago 
06-22 14:22:29.616: DEBUG/dalvikvm(5408): GC_EXPLICIT freed 257K, 48% free 
3512K/6663K, external 0K/0K, paused 98ms
06-22 14:22:34.593: DEBUG/dalvikvm(5423): GC_EXPLICIT freed 68K, 50% free 
2715K/5379K, external 0K/0K, paused 73ms
06-22 14:22:37.499: DEBUG/AndroidRuntime(5527): >>>>>> AndroidRuntime START 
com.android.internal.os.RuntimeInit <<<<<<
06-22 14:22:37.499: INFO/AndroidRuntime(5527): Heap size: -Xmx48m
06-22 14:22:37.499: DEBUG/AndroidRuntime(5527): CheckJNI is OFF
06-22 14:22:37.507: DEBUG/dalvikvm(5527): creating instr width table
06-22 14:22:38.264: DEBUG/AndroidRuntime(5527): Calling main entry 
com.android.commands.pm.Pm
06-22 14:22:38.389: ERROR/dalvikvm(5535): could not disable core file 
generation for pid 5535: Operation not permitted
06-22 14:22:38.389: INFO/ActivityManager(1770): Start proc 
com.android.defcontainer for service 
com.android.defcontainer/.DefaultContainerService: pid=5535 uid=10020 
gids={1015, 2001}
06-22 14:22:38.843: DEBUG/dalvikvm(5535): GC_EXPLICIT freed 51K, 51% free 
2672K/5379K, external 0K/0K, paused 54ms
06-22 14:22:38.858: WARN/ActivityManager(1770): No content provider found for: 
06-22 14:22:38.858: ERROR/PackageManager(1770): Couldn't create temp file for 
downloaded package file.
06-22 14:22:38.866: WARN/dalvikvm(1770): threadid=11: thread exiting with 
uncaught exception (group=0x40018560)
06-22 14:22:38.866: ERROR/AndroidRuntime(1770): *** FATAL EXCEPTION IN SYSTEM 
PROCESS: PackageManager
06-22 14:22:38.866: ERROR/AndroidRuntime(1770): java.lang.NullPointerException
06-22 14:22:38.866: ERROR/AndroidRuntime(1770):     at 
com.android.server.PackageManagerService$FileInstallArgs.createCopyFile(PackageM
anagerService.java:5166)
06-22 14:22:38.866: ERROR/AndroidRuntime(1770):     at 
com.android.server.PackageManagerService$FileInstallArgs.copyApk(PackageManagerS
ervice.java:5174)
06-22 14:22:38.866: ERROR/AndroidRuntime(1770):     at 
com.android.server.PackageManagerService$InstallParams.handleStartCopy(PackageMa
nagerService.java:4970)
06-22 14:22:38.866: ERROR/AndroidRuntime(1770):     at 
com.android.server.PackageManagerService$HandlerParams.startCopy(PackageManagerS
ervice.java:4821)
06-22 14:22:38.866: ERROR/AndroidRuntime(1770):     at 
com.android.server.PackageManagerService$PackageHandler.doHandleMessage(PackageM
anagerService.java:513)
06-22 14:22:38.866: ERROR/AndroidRuntime(1770):     at 
com.android.server.PackageManagerService$PackageHandler.handleMessage(PackageMan
agerService.java:458)
06-22 14:22:38.866: ERROR/AndroidRuntime(1770):     at 
android.os.Handler.dispatchMessage(Handler.java:99)
06-22 14:22:38.866: ERROR/AndroidRuntime(1770):     at 
android.os.Looper.loop(Looper.java:130)
06-22 14:22:38.866: ERROR/AndroidRuntime(1770):     at 
android.os.HandlerThread.run(HandlerThread.java:60)
06-22 14:22:38.889: INFO/Process(1770): Sending signal. PID: 1770 SIG: 9
06-22 14:22:38.929: INFO/ServiceManager(1415): service 'SurfaceFlinger' died
06-22 14:22:38.936: INFO/ActivityThread(5535): Removing dead content provider: 
settings
06-22 14:22:38.936: INFO/ActivityThread(2180): Removing dead content provider: 
settings
06-22 14:22:38.936: INFO/ActivityThread(1871): Removing dead content provider: 
settings
06-22 14:22:38.936: INFO/ActivityThread(1891): Removing dead content provider: 
settings
06-22 14:22:38.936: INFO/ActivityThread(1861): Removing dead content provider: 
settings
06-22 14:22:38.944: INFO/ActivityThread(1874): Removing dead content provider: 
settings
06-22 14:22:38.944: INFO/ActivityThread(1832): Removing dead content provider: 
settings
06-22 14:22:38.944: INFO/ActivityThread(5408): Removing dead content provider: 
settings

Original comment by yuri.da...@gmail.com on 22 Jun 2011 at 1:04

GoogleCodeExporter commented 8 years ago 
I have more logging, but I can't attach files to this issue ticket.

Original comment by yuri.da...@gmail.com on 22 Jun 2011 at 1:05

GoogleCodeExporter commented 8 years ago 
Found something more in a later install:

06-22 15:17:59.114: DEBUG/PackageManager(1771): Scanning package eu.mHb.android
06-22 15:17:59.137: INFO/PackageManager(1771): Package eu.mHb.android codePath 
changed from /data/app/eu.mHb.android-2.apk to /data/app/eu.mHb.android-1.apk; 
Retaining data and using new
06-22 15:17:59.145: INFO/PackageManager(1771): Unpacking native libraries for 
/data/app/eu.mHb.android-1.apk
06-22 15:17:59.215: DEBUG/installd(1441): DexInv: --- BEGIN 
'/data/app/eu.mHb.android-1.apk' ---
06-22 15:17:59.317: DEBUG/dalvikvm(3972): creating instr width table
06-22 15:17:59.707: DEBUG/dalvikvm(3972): DexOpt: load 61ms, verify+opt 300ms
06-22 15:17:59.762: DEBUG/installd(1441): DexInv: --- END 
'/data/app/eu.mHb.android-1.apk' (success) ---
06-22 15:17:59.762: INFO/ActivityManager(1771): Force stopping package 
eu.mHb.android uid=10131
06-22 15:17:59.762: WARN/PackageManager(1771): Code path for pkg : 
eu.mHb.android changing from /data/app/eu.mHb.android-2.apk to 
/data/app/eu.mHb.android-1.apk
06-22 15:17:59.770: DEBUG/PackageManager(1771):   Activities: 
eu.mHb.android.Main eu.mHb.android.Login eu.mHb.android.Settings 
eu.mHb.android.Help eu.mHb.android.Profile eu.mHb.android.Map 
eu.mHb.android.Messages eu.mHb.android.MyMeds eu.mHb.android.Medicine 
eu.mHb.android.News eu.mHb.android.Leaflet
06-22 15:17:59.770: WARN/PackageManager(1771): Resource path for pkg : 
eu.mHb.android changing from /data/app/eu.mHb.android-2.apk to 
/data/app/eu.mHb.android-1.apk
06-22 15:18:00.286: INFO/installd(1441): move 
/data/dalvik-cache/data@app@eu.mHb.android-1.apk@classes.dex -> 
/data/dalvik-cache/data@app@eu.mHb.android-1.apk@classes.dex
06-22 15:18:00.286: DEBUG/PackageManager(1771): New package installed in 
/data/app/eu.mHb.android-1.apk
06-22 15:18:00.465: INFO/ActivityManager(1771): Force stopping package 
eu.mHb.android uid=10131
06-22 15:18:00.528: DEBUG/dalvikvm(1885): GC_EXPLICIT freed 132K, 51% free 
3454K/6919K, external 1495K/1847K, paused 53ms
06-22 15:18:00.559: DEBUG/HomeLoaders(1885): application intent received: 
android.intent.action.PACKAGE_REMOVED, replacing=true
06-22 15:18:00.559: DEBUG/HomeLoaders(1885):   --> package:eu.mHb.android
06-22 15:18:00.567: INFO/ActivityManager(1771): Start proc 
com.appspot.swisscodemonkeys.apps for broadcast 
com.appspot.swisscodemonkeys.apps/.PackageReceiver: pid=3973 uid=10073 
gids={3003}
06-22 15:18:00.575: ERROR/dalvikvm(3973): could not disable core file 
generation for pid 3973: Operation not permitted
06-22 15:18:00.590: DEBUG/szipinf(1771): Initializing inflate state
06-22 15:18:00.684: DEBUG/szipinf(1771): Initializing inflate state
06-22 15:18:00.747: DEBUG/HomeLoaders(1885): application intent received: 
android.intent.action.PACKAGE_ADDED, replacing=true
06-22 15:18:00.747: DEBUG/HomeLoaders(1885):   --> package:eu.mHb.android
06-22 15:18:00.747: DEBUG/HomeLoaders(1885):   --> update package eu.mHb.android
06-22 15:18:01.246: INFO/ActivityThread(3973): Pub appbrain.SuggestionProvider: 
com.appspot.swisscodemonkeys.apps.search.SearchSuggestionSampleProvider
06-22 15:18:01.426: DEBUG/dalvikvm(1771): GC_EXPLICIT freed 841K, 38% free 
6895K/10951K, external 1656K/2121K, paused 451ms
06-22 15:18:01.903: DEBUG/dalvikvm(3973): GC_CONCURRENT freed 358K, 51% free 
2811K/5639K, external 0K/0K, paused 3ms+4ms
06-22 15:18:02.520: INFO/installd(1441): unlink 
/data/dalvik-cache/data@app@eu.mHb.android-2.apk@classes.dex

Original comment by yuri.da...@gmail.com on 22 Jun 2011 at 1:26

GoogleCodeExporter commented 8 years ago 
this operation 

move /data/dalvik-cache/data@app@eu.mHb.android-1.apk@classes.dex -> 
/data/dalvik-cache/data@app@eu.mHb.android-1.apk@classes.dex

seems strange, I think first file name should say ...-2.apk... because now I 
have two files in my dalvik-cache directory, one -1 and one -2, same size and 
timestamp.

Original comment by yuri.da...@gmail.com on 22 Jun 2011 at 1:28