[TIMOB-4612] Android: Reading and writing large files cause ANR / Exceptions in Fastdev
| GitHub Issue | n/a |
|---|---|
| Type | Bug |
| Priority | High |
| Status | Closed |
| Resolution | Fixed |
| Resolution Date | 2011-11-05T14:03:40.000+0000 |
| Affected Version/s | Release 1.7.1 |
| Fix Version/s | Sprint 2011-27, Release 1.7.2, Release 1.8.0 |
| Components | Android |
| Labels | n/a |
| Reporter | Paul Dowsett |
| Assignee | Natalie Huynh |
| Created | 2011-07-06T23:26:33.000+0000 |
| Updated | 2014-06-19T12:46:19.000+0000 |
Description
The following code demonstrates that after copying files between filesystems, an exception is generated, as shown below.
No further application launches are possible due to the process stalling with the output, also shown below.
Test files are attached, created using:
cat /dev/null > testfile-large.txt; for i in {1..1000}; do cat testfile.txt >> testfile-large.txt; done).
var testfile = [
'testfile-003KB.txt',
'testfile-006KB.txt',
'testfile-009KB.txt',
'testfile-010KB.txt',
'testfile-012KB.txt',
'testfile-018KB.txt',
'testfile-036KB.txt',
'testfile-046KB.txt',
'testfile-048KB.txt',
'testfile-050KB.txt',
'testfile-052KB.txt',
'testfile-060KB.txt',
'testfile-088KB.txt',
'testfile-176KB.txt',
'testfile-293KB.txt'
];
if(Titanium.Filesystem.isExternalStoragePresent){
var dstFilesystem = Ti.Filesystem.externalStorageDirectory;
Ti.API.info('Files will be copied to the SD Card');
} else {
var dstFilesystem = Ti.Filesystem.applicationDataDirectory;
Ti.API.info('Files will be copied to the Application Data Directory');
}
for (var i=0, ilen=testfile.length; i<ilen; i++){
Ti.API.info('------------------------------------------------');
var srcFile = Ti.Filesystem.getFile(Ti.Filesystem.resourcesDirectory,testfile[i]);
var dstFile = Ti.Filesystem.getFile(dstFilesystem, testfile[i]);
if(dstFile.exists()){
dstFile.deleteFile();
Ti.API.info('The testfile named ' + testfile[i] + ' has been deleted');
}
dstFile.write(srcFile.read());
if(dstFile.exists()){
Ti.API.info('The testfile named ' + testfile[i] + ' has been successfully copied to ' + dstFile.nativePath);
}
}
10925 AndroidRuntime D >>>>>>>>>>>>>> AndroidRuntime START <<<<<<<<<<<<<<
10925 AndroidRuntime D CheckJNI is ON
10925 AndroidRuntime D --- registering native functions ---
10925 jdwp I Ignoring second debugger -- accepting and dropping
61 ActivityManager I Starting activity: Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10000000 cmp=com.testing.testing7/.Testing7Activity }
10925 AndroidRuntime D Shutting down VM
10925 dalvikvm D Debugger has detached; object registry had 1 entries
10925 AndroidRuntime I NOTE: attach of thread 'Binder Thread #3' failed
61 ActivityManager I Start proc com.testing.testing7 for activity com.testing.testing7/.Testing7Activity: pid=10932 uid=10040 gids={1015, 3003}
10932 jdwp I Ignoring second debugger -- accepting and dropping
10932 TiApplication I (main) [0,0] checkpoint, app created.
10932 dalvikvm D GC_FOR_MALLOC freed 2759 objects / 312312 bytes in 99ms
10932 TiApplication I (main) [758,758] Titanium 1.7.1 (2011/06/17 00:13 293a6d...)
10932 TiDeployData D (main) [129,887] Read deploy data: {"debuggerPort":-1,"debuggerEnabled":false,"fastdevPort":55583}
10932 TiPlatformHelper E (main) [234,1121] renaming ID
10932 TiRootActivity I (main) [0,0] checkpoint, on root activity create, savedInstanceState: null
10932 TiApplication E (main) [590,590] APP PROXY: [Ti.App]
10932 TiCommonContactsApi D (main) [35,625] Using newer contacts api. Android SDK level: 8
10932 dalvikvm D GC_FOR_MALLOC freed 4758 objects / 342848 bytes in 67ms
10932 global I Default buffer size used in BufferedReader constructor. It would be better to be explicit if an 8k-char buffer is required.
10932 dalvikvm D GC_FOR_MALLOC freed 4735 objects / 331136 bytes in 159ms
38 qemud D fdhandler_accept_event: accepting on fd 10
38 qemud D created client 0x91908 listening on fd 15
38 qemud D client_fd_receive: attempting registration for service 'sensors'
38 qemud D client_fd_receive: -> received channel id 16
38 qemud D client_registration: registration succeeded for client 16
38 qemud D fdhandler_event: disconnect on fd 15
10932 TiFastDev D (kroll$1: app://app.js) [851,1476] Enabling Fastdev on port 55583
10932 TiFastDev D (kroll$1: app://app.js) [128,1604] sent tokens successfully
10932 TiFastDev D (kroll$1: app://app.js) [1,1605] Fastdev session handshake succesful.
10932 TiFastDev D (kroll$1: app://app.js) [58,1663] sent tokens successfully
10932 KrollContext D (kroll$1: app://app.js) [2,1665] Running evaluated script: file:///android_asset/Resources/app.js
10932 TiAPI I (kroll$1: app://app.js) [129,1794] Files will be copied to the SD Card
10932 TiAPI I (kroll$1: app://app.js) [1,1795] ------------------------------------------------
10932 TiAPI I (kroll$1: app://app.js) [89,1884] The testfile named testfile-003KB.txt has been deleted
10932 TiFastDev D (kroll$1: app://app.js) [50,1934] sent tokens successfully
10932 dalvikvm D GC_FOR_MALLOC freed 6850 objects / 479864 bytes in 64ms
10932 global I Default buffer size used in BufferedOutputStream constructor. It would be better to be explicit if an 8k buffer is required.
10932 TiAPI I (kroll$1: app://app.js) [177,2111] The testfile named testfile-003KB.txt has been successfully copied to file:///mnt/sdcard/com.testing.testing7/testfile-003KB.txt
10932 TiAPI I (kroll$1: app://app.js) [2,2113] ------------------------------------------------
10932 TiAPI I (kroll$1: app://app.js) [47,2160] The testfile named testfile-006KB.txt has been deleted
10932 TiFastDev D (kroll$1: app://app.js) [48,2208] sent tokens successfully
10932 global I Default buffer size used in BufferedOutputStream constructor. It would be better to be explicit if an 8k buffer is required.
10932 TiAPI I (kroll$1: app://app.js) [40,2248] The testfile named testfile-006KB.txt has been successfully copied to file:///mnt/sdcard/com.testing.testing7/testfile-006KB.txt
10932 TiAPI I (kroll$1: app://app.js) [13,2261] ------------------------------------------------
10932 TiAPI I (kroll$1: app://app.js) [24,2285] The testfile named testfile-009KB.txt has been deleted
10932 TiFastDev D (kroll$1: app://app.js) [38,2323] sent tokens successfully
10932 global I Default buffer size used in BufferedOutputStream constructor. It would be better to be explicit if an 8k buffer is required.
10932 TiAPI I (kroll$1: app://app.js) [33,2356] The testfile named testfile-009KB.txt has been successfully copied to file:///mnt/sdcard/com.testing.testing7/testfile-009KB.txt
10932 TiAPI I (kroll$1: app://app.js) [12,2368] ------------------------------------------------
10932 TiAPI I (kroll$1: app://app.js) [34,2402] The testfile named testfile-010KB.txt has been deleted
10932 TiFastDev D (kroll$1: app://app.js) [41,2443] sent tokens successfully
10932 dalvikvm D GC_FOR_MALLOC freed 1014 objects / 179648 bytes in 72ms
10932 global I Default buffer size used in BufferedOutputStream constructor. It would be better to be explicit if an 8k buffer is required.
10932 TiAPI I (kroll$1: app://app.js) [115,2558] The testfile named testfile-010KB.txt has been successfully copied to file:///mnt/sdcard/com.testing.testing7/testfile-010KB.txt
10932 TiAPI I (kroll$1: app://app.js) [17,2575] ------------------------------------------------
10932 TiAPI I (kroll$1: app://app.js) [36,2611] The testfile named testfile-012KB.txt has been deleted
10932 TiFastDev D (kroll$1: app://app.js) [43,2654] sent tokens successfully
10932 global I Default buffer size used in BufferedOutputStream constructor. It would be better to be explicit if an 8k buffer is required.
10932 TiAPI I (kroll$1: app://app.js) [37,2691] The testfile named testfile-012KB.txt has been successfully copied to file:///mnt/sdcard/com.testing.testing7/testfile-012KB.txt
10932 TiAPI I (kroll$1: app://app.js) [19,2710] ------------------------------------------------
10932 TiAPI I (kroll$1: app://app.js) [51,2761] The testfile named testfile-018KB.txt has been deleted
10932 TiFastDev D (kroll$1: app://app.js) [48,2809] sent tokens successfully
10932 dalvikvm D GC_FOR_MALLOC freed 747 objects / 219344 bytes in 79ms
10932 global I Default buffer size used in BufferedOutputStream constructor. It would be better to be explicit if an 8k buffer is required.
10932 TiAPI I (kroll$1: app://app.js) [118,2927] The testfile named testfile-018KB.txt has been successfully copied to file:///mnt/sdcard/com.testing.testing7/testfile-018KB.txt
10932 TiAPI I (kroll$1: app://app.js) [2,2929] ------------------------------------------------
10932 TiAPI I (kroll$1: app://app.js) [39,2968] The testfile named testfile-036KB.txt has been deleted
10932 TiFastDev D (kroll$1: app://app.js) [65,3033] sent tokens successfully
10932 dalvikvm D GC_FOR_MALLOC freed 385 objects / 81016 bytes in 74ms
10932 global I Default buffer size used in BufferedOutputStream constructor. It would be better to be explicit if an 8k buffer is required.
10932 TiAPI I (kroll$1: app://app.js) [126,3159] The testfile named testfile-036KB.txt has been successfully copied to file:///mnt/sdcard/com.testing.testing7/testfile-036KB.txt
10932 TiAPI I (kroll$1: app://app.js) [5,3164] ------------------------------------------------
10932 TiAPI I (kroll$1: app://app.js) [46,3210] The testfile named testfile-046KB.txt has been deleted
10932 TiFastDev D (kroll$1: app://app.js) [51,3261] sent tokens successfully
10932 dalvikvm D GC_FOR_MALLOC freed 378 objects / 172240 bytes in 65ms
10932 global I Default buffer size used in BufferedOutputStream constructor. It would be better to be explicit if an 8k buffer is required.
10932 TiAPI I (kroll$1: app://app.js) [118,3379] The testfile named testfile-046KB.txt has been successfully copied to file:///mnt/sdcard/com.testing.testing7/testfile-046KB.txt
10932 TiAPI I (kroll$1: app://app.js) [2,3381] ------------------------------------------------
10932 TiAPI I (kroll$1: app://app.js) [45,3426] The testfile named testfile-048KB.txt has been deleted
10932 dalvikvm D GC_FOR_MALLOC freed 337 objects / 207032 bytes in 64ms
10932 TiFastDev D (kroll$1: app://app.js) [111,3537] sent tokens successfully
10932 global I Default buffer size used in BufferedOutputStream constructor. It would be better to be explicit if an 8k buffer is required.
10932 TiAPI I (kroll$1: app://app.js) [37,3574] The testfile named testfile-048KB.txt has been successfully copied to file:///mnt/sdcard/com.testing.testing7/testfile-048KB.txt
10932 TiAPI I (kroll$1: app://app.js) [2,3576] ------------------------------------------------
10932 dalvikvm D GC_FOR_MALLOC freed 334 objects / 218688 bytes in 62ms
10932 TiFastDev D (kroll$1: app://app.js) [130,3706] sent tokens successfully
10932 global I Default buffer size used in BufferedOutputStream constructor. It would be better to be explicit if an 8k buffer is required.
10932 TiAPI I (kroll$1: app://app.js) [80,3786] The testfile named testfile-050KB.txt has been successfully copied to file:///mnt/sdcard/com.testing.testing7/testfile-050KB.txt
10932 TiAPI I (kroll$1: app://app.js) [2,3788] ------------------------------------------------
10932 dalvikvm D GC_FOR_MALLOC freed 335 objects / 222728 bytes in 59ms
10932 TiFastDev D (kroll$1: app://app.js) [124,3912] sent tokens successfully
10932 global I Default buffer size used in BufferedOutputStream constructor. It would be better to be explicit if an 8k buffer is required.
10932 TiAPI I (kroll$1: app://app.js) [32,3944] The testfile named testfile-052KB.txt has been successfully copied to file:///mnt/sdcard/com.testing.testing7/testfile-052KB.txt
10932 TiAPI I (kroll$1: app://app.js) [3,3947] ------------------------------------------------
10932 dalvikvm D GC_FOR_MALLOC freed 334 objects / 226784 bytes in 70ms
10932 TiFastDev D (kroll$1: app://app.js) [139,4086] sent tokens successfully
10932 dalvikvm D GC_FOR_MALLOC freed 62 objects / 36408 bytes in 71ms
10932 dalvikvm-heap I Grow heap (frag case) to 3.400MB for 122896-byte allocation
10932 dalvikvm D GC_FOR_MALLOC freed 1 objects / 32 bytes in 74ms
10932 global I Default buffer size used in BufferedOutputStream constructor. It would be better to be explicit if an 8k buffer is required.
10932 TiAPI I (kroll$1: app://app.js) [203,4289] The testfile named testfile-060KB.txt has been successfully copied to file:///mnt/sdcard/com.testing.testing7/testfile-060KB.txt
10932 TiAPI I (kroll$1: app://app.js) [2,4291] ------------------------------------------------
10932 dalvikvm D GC_FOR_MALLOC freed 310 objects / 332064 bytes in 67ms
10932 TiFastDev D (kroll$1: app://app.js) [146,4437] sent tokens successfully
10932 dalvikvm D GC_FOR_MALLOC freed 63 objects / 93776 bytes in 65ms
10932 dalvikvm-heap I Grow heap (frag case) to 3.457MB for 90016-byte allocation
10932 dalvikvm D GC_FOR_MALLOC freed 1 objects / 32 bytes in 75ms
10932 global I Default buffer size used in BufferedOutputStream constructor. It would be better to be explicit if an 8k buffer is required.
10932 TiAPI I (kroll$1: app://app.js) [204,4641] The testfile named testfile-088KB.txt has been successfully copied to file:///mnt/sdcard/com.testing.testing7/testfile-088KB.txt
10932 TiAPI I (kroll$1: app://app.js) [2,4643] ------------------------------------------------
10932 TiAPI I (kroll$1: app://app.js) [32,4675] The testfile named testfile-176KB.txt has been deleted
10932 dalvikvm D GC_FOR_MALLOC freed 295 objects / 331528 bytes in 62ms
10932 TiFastDev D (kroll$1: app://app.js) [124,4799] sent tokens successfully
10932 dalvikvm D GC_FOR_MALLOC freed 63 objects / 93784 bytes in 65ms
10932 dalvikvm-heap I Grow heap (frag case) to 3.700MB for 253968-byte allocation
10932 dalvikvm D GC_FOR_MALLOC freed 1 objects / 32 bytes in 71ms
10932 dalvikvm D GC_FOR_MALLOC freed 22 objects / 123784 bytes in 72ms
10932 global I Default buffer size used in BufferedOutputStream constructor. It would be better to be explicit if an 8k buffer is required.
10932 TiAPI I (kroll$1: app://app.js) [331,5130] The testfile named testfile-176KB.txt has been successfully copied to file:///mnt/sdcard/com.testing.testing7/testfile-176KB.txt
10932 TiAPI I (kroll$1: app://app.js) [2,5132] ------------------------------------------------
10932 dalvikvm D GC_FOR_MALLOC freed 279 objects / 640792 bytes in 61ms
61 ActivityManager W Launch timeout has expired, giving up wake lock!
61 ActivityManager W Activity idle timeout for HistoryRecord{45020fb8 com.testing.testing7/.Testing7Activity}
61 ActivityManager W Timeout of broadcast BroadcastRecord{450f8c18 android.intent.action.TIME_TICK} - receiver=android.app.ActivityThread$PackageInfo$ReceiverDispatcher$InnerReceiver@45019c68
61 ActivityManager W Receiver during timeout: BroadcastFilter{45019e80 ReceiverList{45019e08 61 system/1000 local:45019c68}}
61 ActivityManager W Timeout executing service: ServiceRecord{45172ec8 com.testing.testing7/org.appcelerator.titanium.analytics.TiAnalyticsService}
61 Process I Sending signal. PID: 10932 SIG: 3
10932 dalvikvm I threadid=3: reacting to signal 3
61 ActivityManager W finishReceiver called but none active
10932 dalvikvm I Wrote stack traces to '/data/anr/traces.txt'
61 Process I Sending signal. PID: 61 SIG: 3
61 dalvikvm I threadid=3: reacting to signal 3
61 dalvikvm I Wrote stack traces to '/data/anr/traces.txt'
61 Process I Sending signal. PID: 108 SIG: 3
108 dalvikvm I threadid=3: reacting to signal 3
108 dalvikvm I Wrote stack traces to '/data/anr/traces.txt'
61 Process I Sending signal. PID: 115 SIG: 3
115 dalvikvm I threadid=3: reacting to signal 3
115 dalvikvm I Wrote stack traces to '/data/anr/traces.txt'
61 Process I Sending signal. PID: 300 SIG: 3
300 dalvikvm I threadid=3: reacting to signal 3
300 dalvikvm I Wrote stack traces to '/data/anr/traces.txt'
61 Process I Sending signal. PID: 309 SIG: 3
309 dalvikvm I threadid=3: reacting to signal 3
309 dalvikvm I Wrote stack traces to '/data/anr/traces.txt'
61 Process I Sending signal. PID: 291 SIG: 3
291 dalvikvm I threadid=3: reacting to signal 3
291 dalvikvm I Wrote stack traces to '/data/anr/traces.txt'
61 Process I Sending signal. PID: 162 SIG: 3
162 dalvikvm I threadid=3: reacting to signal 3
162 dalvikvm I Wrote stack traces to '/data/anr/traces.txt'
61 Process I Sending signal. PID: 181 SIG: 3
181 dalvikvm I threadid=3: reacting to signal 3
181 dalvikvm I Wrote stack traces to '/data/anr/traces.txt'
61 Process I Sending signal. PID: 221 SIG: 3
221 dalvikvm I threadid=3: reacting to signal 3
221 dalvikvm I Wrote stack traces to '/data/anr/traces.txt'
61 Process I Sending signal. PID: 196 SIG: 3
196 dalvikvm I threadid=3: reacting to signal 3
196 dalvikvm I Wrote stack traces to '/data/anr/traces.txt'
61 Process I Sending signal. PID: 204 SIG: 3
204 dalvikvm I threadid=3: reacting to signal 3
204 dalvikvm I Wrote stack traces to '/data/anr/traces.txt'
61 Process I Sending signal. PID: 112 SIG: 3
112 dalvikvm I threadid=3: reacting to signal 3
112 dalvikvm I Wrote stack traces to '/data/anr/traces.txt'
61 ActivityManager E ANR in com.testing.testing7
61 ActivityManager E Reason: Executing service com.testing.testing7/org.appcelerator.titanium.analytics.TiAnalyticsService
61 ActivityManager E Load: 6.06 / 1.75 / 0.87
61 ActivityManager E CPU usage from 494572ms to 49ms ago:
61 ActivityManager E system_server: 2% = 2% user + 0% kernel / faults: 9933 minor 366 major
61 ActivityManager E adbd: 2% = 0% user + 2% kernel / faults: 8244 minor
61 ActivityManager E mmcqd: 0% = 0% user + 0% kernel
61 ActivityManager E id.defcontainer: 0% = 0% user + 0% kernel / faults: 1291 minor 17 major
61 ActivityManager E m.android.phone: 0% = 0% user + 0% kernel / faults: 951 minor 9 major
61 ActivityManager E ndroid.launcher: 0% = 0% user + 0% kernel / faults: 2429 minor 46 major
61 ActivityManager E logcat: 0% = 0% user + 0% kernel / faults: 162 minor
61 ActivityManager E logcat: 0% = 0% user + 0% kernel / faults: 162 minor
61 ActivityManager E logcat: 0% = 0% user + 0% kernel / faults: 162 minor
61 ActivityManager E s:FriendService: 0% = 0% user + 0% kernel / faults: 601 minor 6 major
61 ActivityManager E kswapd0: 0% = 0% user + 0% kernel
61 ActivityManager E e.process.gapps: 0% = 0% user + 0% kernel / faults: 338 minor 6 major
61 ActivityManager E putmethod.latin: 0% = 0% user + 0% kernel / faults: 314 minor
61 ActivityManager E zygote: 0% = 0% user + 0% kernel / faults: 259 minor
61 ActivityManager E events/0: 0% = 0% user + 0% kernel
61 ActivityManager E qemud: 0% = 0% user + 0% kernel / faults: 106 minor 2 major
61 ActivityManager E rild: 0% = 0% user + 0% kernel / faults: 194 minor 12 major
61 ActivityManager E zygote: 0% = 0% user + 0% kernel / faults: 179 minor 2 major
61 ActivityManager E roid.alarmclock: 0% = 0% user + 0% kernel / faults: 254 minor
61 ActivityManager E m.android.music: 0% = 0% user + 0% kernel / faults: 255 minor
61 ActivityManager E android.protips: 0% = 0% user + 0% kernel / faults: 255 minor
61 ActivityManager E com.svox.pico: 0% = 0% user + 0% kernel / faults: 311 minor
61 ActivityManager E pdflush: 0% = 0% user + 0% kernel
61 ActivityManager E installd: 0% = 0% user + 0% kernel / faults: 47 minor 2 major
61 ActivityManager E +esting.testing7: 0% = 0% user + 0% kernel
61 ActivityManager E +sh: 0% = 0% user + 0% kernel
61 ActivityManager E -esting.testing7: 0% = 0% user + 0% kernel
61 ActivityManager E TOTAL: 19% = 7% user + 10% kernel + 1% iowait + 0% irq + 0% softirq
300 dalvikvm D GC_EXPLICIT freed 45 objects / 2120 bytes in 60ms
309 dalvikvm D GC_EXPLICIT freed 114 objects / 7376 bytes in 96ms
115 dalvikvm D GC_EXPLICIT freed 700 objects / 39576 bytes in 73ms
11028 AndroidRuntime D >>>>>>>>>>>>>> AndroidRuntime START <<<<<<<<<<<<<<
11028 AndroidRuntime D CheckJNI is ON
11028 AndroidRuntime D --- registering native functions ---
11028 jdwp I Ignoring second debugger -- accepting and dropping
61 ActivityManager I Starting activity: Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10000000 cmp=com.testing.testing7/.Testing7Activity }
11028 AndroidRuntime D Shutting down VM
11028 dalvikvm D Debugger has detached; object registry had 1 entries
11028 AndroidRuntime I NOTE: attach of thread 'Binder Thread #3' failed
Attachments
| File | Date | Size |
|---|---|---|
| test-files.zip | 2011-07-07T10:43:15.000+0000 | 6136 |
| timob4612.zip | 2011-07-08T13:30:51.000+0000 | 761836 |
Test steps: * Run the attached timob4612.zip project with Fastdev enabled. You can either use Titanium Studio for this, or manually by running:
* Make sure the test loads, and says "Finished!". You should also double check that the file got copied successfully using ADB:* Run the filesystem and xml drillbit test suites for Android, and make sure they passNote that TIMOB-4633 and TIMOB-4632 may be related.
Merging.
Tested with 1.8.0.v20110909152148 on Win7, Linux 10.04 and Mac 10.6.8
Standardizing summary and labels.