thetwom / toc2

Metronome app
GNU General Public License v3.0
161 stars 23 forks source link

App Crashes and Doesn't Start #8

Closed ulville closed 4 years ago

ulville commented 4 years ago

When I try to open it, it only shows a blank white screen with a purple notification bar. Then it crashes after a few seconds. I installed it from f-droid app and I use an Xperia XZ running Android 8.0 Oreo.

I'm happy to see an open source metronome app, so I hope this issue helps.

thetwom commented 4 years ago

Thanks for taking the time and reporting your issue. Unfortunately, I would need some help from you to find the issue. As a start, can you tell me which version you installed from fdroid? We had a similar issue with version 1.6.1, but this was solved since version 1.6.2, maybe you could also try a 1.5.* version if it is still available in fdroid and let me know if any of the versions work.

ulville commented 4 years ago

I've been trying what fdroid currently offering as default, which is 1.6.3. It only lists 1.6.1, 1.6.2 and 1.6.3 right now. Now I tried all three of them. Latest one and 1.6.2 shows a white screen and after 7-8 seconds phone says its not responding. With 1.6.1 it immediately crashes and kicks me out to my apps menu and phone says "Metronome stopped - try to open again." Unfortunately fdroid doesn't list 1.5.x series so I couldn't try them. If you can provide me with its apk I would gladly test it.

thetwom commented 4 years ago

Thanks for testing this. 1.5.* is not really necessary, it would just have given a better overview over the situation. Since I cannot reproduce the error I am now dependent on additional input from your side. I would be glad if you could give me some more input:

You basically get them by enabling the developer options on your phone (Find the build number in "Settings > About Phone > Build Number" and tap on this number seven times, then you find the developer options under "Settings > System > Advanced > Developer Options", and there is the option "Take bug report" which is normally directly at the top). For the "bug report" your would choose the default option. For me I then get a notification, showing some progress bar. If tapping on the notification it asks me some details (none really needed), and when done you can share the result.

But before going into more details here and how to share this file (this shouldn't really be made public), let me know if you are willing to take the efforts.

ulville commented 4 years ago

I installed the DecoderTest (the latest release) but it also hangs at the blank white screen and doesn't respond. It seemed like a memory management problem to me but I'm not sure. I'll try to take the bug report. Since I do it for the first time and to be sure I'm doing it right; I will start the bug reporting, then try to open the Metronome app (it won't respond), then touch on the notification that shows the progress bar and touch on save. Is that right?

thetwom commented 4 years ago

You would do it the other way round: First start the metronome app, then wait until it crashes. And then you take the bug report. Android saves a lot of system information (and also crash infos) in the so called logcat. And one way to access this logcat is using the bug reporting functionality.

Anyway, before you take your time trying getting into this, your information about the DecoderTest already tells that there still seems to be an issue with the audio decoding. So lets first try something else. I uploaded a new version of DecoderTest (link), which hopefully gives you at least some output. Could you try again and (hopefully) post a screenshot of the result? This would be great. If we're lucky, I won't need the logcat info at all.

ulville commented 4 years ago

Unfortunately this version is still has the same issue. White screen and not responding...

thetwom commented 4 years ago

Thanks for testing, sorry to hear that we still don't get any output. Quite strange. Could you give it another try? Decoder test v5.0

ulville commented 4 years ago

Nope. No luck. It still waits with a white screen like forever. I will try to take a bug report if I can find time tomorrow. I did one but it was after a reboot and before opening the app. But I can see its a huge file. I can cut the relevant parts and share only those parts here if you wish. Or what are your suggestions?

thetwom commented 4 years ago

This is weird. There is nothing I can see which can block the test app from printing at least something to the screen. When I find some more time, I will strip down the test such that it only prints something random such that we can hopefully find out why nothing is happening on your phone.

Did you observe such behaviors with other apps, too?

I am not sure if the logcat will contain any relevant info in the current situation. But who knows maybe it gives any hints. I you want to have look by yourselves, unpack the zip-file and check the files which are not inside the folders. I currently don't recall the name of the file containing logcat info, but I am sure you will find the correct one (I guess it's one of the larger files). Alternatively, I can check for the namings, when I find some time. Inside the logcat info we are mainly looking for lines which contain the app names (Metronome, DecoderTest)

ulville commented 4 years ago

I haven't observed such behavior with other apps before. I think I know which one is the logcat file. I use Termux on my phone (it's a Linux terminal emulator app) and I piped the file to "grep decodertest" yesterday night. It gave some output but I couldn't give it a deeper look since it's hard on the phone screen. Unfortunately I'm at work now but I will take a fresh bug report today and try to investigate it on my laptop as soon as I go home.

thetwom commented 4 years ago

Thanks for investigating. Let's see, if we get any useful logcat info. Additionally I will try upload another test when I find some time. Shouldn't be too difficult to find the problem, since the DecoderTest is really not a complicated app ...

thetwom commented 4 years ago

So here are some tests, sorry that it is a zip file but thats all what github allows here. Maybe you could test them and tell me which one work. If any of the tests 04, 05, 06, 07 work it would be enough to post the result of the test of the highest number. I actually think that all will be working, so you could just test 07, and post the result :-).

release.zip

ulville commented 4 years ago

Screenshot_20200609-003247 7 did work. Here is the output

ulville commented 4 years ago

[ulvican@legion bugreport]$ cat bugreport-F8331-41.3.A.2.192-2020-06-08-12-41-07.txt | grep decodertest

<6>[ 228.018804] adu.decodertest[12640]: unhandled level 2 translation fault (11) at 0x00000000, esr 0x92000006 <4>[ 228.018838] CPU: 0 PID: 12640 Comm: adu.decodertest Tainted: P W O 3.18.66-perf-gd5ec1d77090d #1 <6>[ 228.019499] adu.decodertest[12640]: unhandled level 2 translation fault (11) at 0x00000000, esr 0x92000006 <4>[ 228.019532] CPU: 0 PID: 12640 Comm: adu.decodertest Tainted: P W O 3.18.66-perf-gd5ec1d77090d #1 <6>[ 228.019887] adu.decodertest[12640]: unhandled level 2 translation fault (11) at 0x00000000, esr 0x92000006 <4>[ 228.019917] CPU: 0 PID: 12640 Comm: adu.decodertest Tainted: P W O 3.18.66-perf-gd5ec1d77090d #1 <6>[ 228.023283] adu.decodertest[12640]: unhandled level 2 translation fault (11) at 0x00000000, esr 0x92000006 <4>[ 228.023319] CPU: 0 PID: 12640 Comm: adu.decodertest Tainted: P W O 3.18.66-perf-gd5ec1d77090d #1 <6>[ 228.023739] adu.decodertest[12640]: unhandled level 2 translation fault (11) at 0x00000000, esr 0x92000006 <4>[ 228.023773] CPU: 0 PID: 12640 Comm: adu.decodertest Tainted: P W O 3.18.66-perf-gd5ec1d77090d #1 <6>[ 228.024069] adu.decodertest[12640]: unhandled level 2 translation fault (11) at 0x00000000, esr 0x92000006 <4>[ 228.024100] CPU: 0 PID: 12640 Comm: adu.decodertest Tainted: P W O 3.18.66-perf-gd5ec1d77090d #1 <6>[ 228.028170] adu.decodertest[12640]: unhandled level 2 translation fault (11) at 0x00000000, esr 0x92000006 <4>[ 228.028208] CPU: 0 PID: 12640 Comm: adu.decodertest Tainted: P W O 3.18.66-perf-gd5ec1d77090d #1 <6>[ 228.028607] adu.decodertest[12640]: unhandled level 2 translation fault (11) at 0x00000000, esr 0x92000006 <4>[ 228.028910] CPU: 0 PID: 12640 Comm: adu.decodertest Tainted: P W O 3.18.66-perf-gd5ec1d77090d #1 <6>[ 228.029241] adu.decodertest[12640]: unhandled level 2 translation fault (11) at 0x00000000, esr 0x92000006 <4>[ 228.029273] CPU: 0 PID: 12640 Comm: adu.decodertest Tainted: P W O 3.18.66-perf-gd5ec1d77090d #1 <6>[ 228.034270] adu.decodertest[12640]: unhandled level 2 translation fault (11) at 0x00000000, esr 0x92000006 <4>[ 228.034308] CPU: 0 PID: 12640 Comm: adu.decodertest Tainted: P W O 3.18.66-perf-gd5ec1d77090d #1 06-08 12:39:06.820 1000 1284 3041 I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=de.moekadu.decodertest/.MainActivity} from uid 10215 06-08 12:39:07.003 1000 1284 7805 I ActivityManager: Start proc 12640:de.moekadu.decodertest/u0a272 for activity de.moekadu.decodertest/.MainActivity 06-08 12:39:07.700 10272 12640 12640 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:21) 06-08 12:39:07.701 10272 12640 12640 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:21) 06-08 12:39:07.701 10272 12640 12640 I zygote64: Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/de.moekadu.decodertest-yYA4xBEfkXQhW-WIifPS4A==/base.apk"],nativeLibraryDirectories=[/data/app/de.moekadu.decodertest-yYA4xBEfkXQhW-WIifPS4A==/lib/arm64, /system/lib64, /system/vendor/lib64]] 06-08 12:39:07.701 10272 12640 12640 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:21) 06-08 12:40:26.513 1000 1284 1802 I WindowManager: Input event dispatching timed out sending to application AppWindowToken{bc35218 token=Token{fc65ee8 ActivityRecord{482100b u0 de.moekadu.decodertest/.MainActivity t3039}}}. Reason: Waiting because no window has focus but there is a focused application that may eventually add a window when it finishes starting up. 06-08 12:40:31.584 1000 1284 1802 I WindowManager: Input event dispatching timed out sending to application AppWindowToken{bc35218 token=Token{fc65ee8 ActivityRecord{482100b u0 de.moekadu.decodertest/.MainActivity t3039}}}. Reason: Waiting because no window has focus but there is a focused application that may eventually add a window when it finishes starting up. 06-08 12:40:43.185 1000 1284 1386 E ActivityManager: ANR in de.moekadu.decodertest (de.moekadu.decodertest/.MainActivity) 06-08 12:40:43.193 1000 1284 1386 D ActivityManager: New dropbox entry: de.moekadu.decodertest, data_app_anr, c1fc8c7d-71c8-4aef-b6b0-ece1f4ce5fe1 06-08 12:40:43.493 1000 1284 1386 I ActivityManager: Skipping duplicate ANR: ProcessRecord{4ba73f5 12640:de.moekadu.decodertest/u0a272} Input dispatching timed out (Waiting because no window has focus but there is a focused application that may eventually add a window when it finishes starting up.) 06-08 12:40:43.598 root 1023 1023 I JavaDumper:JavaDumperThread: addEvent: data_app_anr@1591609243470.txt.gz processName: de.moekadu.decodertest 06-08 12:40:49.062 1000 1284 1387 W ActivityManager: Force finishing activity de.moekadu.decodertest/.MainActivity 06-08 12:40:49.083 1000 1284 1387 I ActivityManager: Killing 12640:de.moekadu.decodertest/u0a272 (adj 0): user request after error 06-08 12:39:06.834 1000 1284 3041 I am_create_activity: [0,75632651,3039,de.moekadu.decodertest/.MainActivity,android.intent.action.MAIN,NULL,NULL,270532608] 06-08 12:39:07.003 1000 1284 7805 I am_proc_start: [0,12640,10272,de.moekadu.decodertest,activity,de.moekadu.decodertest/.MainActivity] 06-08 12:39:07.296 1000 1284 2459 I am_proc_bound: [0,12640,de.moekadu.decodertest] 06-08 12:39:07.315 1000 1284 2459 I am_restart_activity: [0,75632651,3039,de.moekadu.decodertest/.MainActivity] 06-08 12:39:07.327 1000 1284 2459 I am_set_resumed_activity: [0,de.moekadu.decodertest/.MainActivity,minimalResumeActivityLocked] 06-08 12:39:17.776 1000 1284 1385 I am_pss : [12640,10272,de.moekadu.decodertest,10758144,9142272,138240] 06-08 12:40:27.166 1000 1284 1386 I am_anr : [0,12640,de.moekadu.decodertest,684244548,Input dispatching timed out (Waiting because no window has focus but there is a focused application that may eventually add a window when it finishes starting up.)] 06-08 12:40:49.062 1000 1284 1387 I am_finish_activity: [0,75632651,3039,de.moekadu.decodertest/.MainActivity,user-terminated] 06-08 12:40:49.066 1000 1284 1387 I am_pause_activity: [0,75632651,de.moekadu.decodertest/.MainActivity] 06-08 12:40:49.083 1000 1284 1387 I am_kill : [0,12640,de.moekadu.decodertest,0,user request after error] 06-08 12:40:49.177 1000 1284 3069 I am_proc_died: [0,12640,de.moekadu.decodertest,0,2] Cmd line: de.moekadu.decodertest /data/app/de.moekadu.decodertest-yYA4xBEfkXQhW-WIifPS4A==/oat/arm64/base.odex: speed-profile at de.moekadu.decodertest.MainActivity.audioToPCM(MainActivity.kt:54) at de.moekadu.decodertest.MainActivity.onCreate(MainActivity.kt:33) de.moekadu.decodertest 1441810 74910 17010688 45056 0 0 0 0 2 0 packageName=de.moekadu.decodertest processName=de.moekadu.decodertest app=ProcessRecord{4ba73f5 12640:de.moekadu.decodertest/u0a272} Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=de.moekadu.decodertest/.MainActivity bnds=[437,669][643,905] } frontOfTask=true task=TaskRecord{736358a #3039 A=de.moekadu.decodertest U=0 StackId=1 sz=1} taskAffinity=de.moekadu.decodertest realActivity=de.moekadu.decodertest/.MainActivity baseDir=/data/app/de.moekadu.decodertest-yYA4xBEfkXQhW-WIifPS4A==/base.apk dataDir=/data/user/0/de.moekadu.decodertest packageName=de.moekadu.decodertest processName=de.moekadu.decodertest app=ProcessRecord{4ba73f5 12640:de.moekadu.decodertest/u0a272} Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=de.moekadu.decodertest/.MainActivity bnds=[437,669][643,905] } frontOfTask=true task=TaskRecord{736358a #3039 A=de.moekadu.decodertest U=0 StackId=1 sz=1} taskAffinity=de.moekadu.decodertest realActivity=de.moekadu.decodertest/.MainActivity baseDir=/data/app/de.moekadu.decodertest-yYA4xBEfkXQhW-WIifPS4A==/base.apk dataDir=/data/user/0/de.moekadu.decodertest mIntent=Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=de.moekadu.decodertest/.MainActivity bnds=[437,669][643,905] } * TaskRecord{736358a #3039 A=de.moekadu.decodertest U=0 StackId=1 sz=1} affinity=de.moekadu.decodertest intent={act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=de.moekadu.decodertest/.MainActivity bnds=[437,669][643,905]} realActivity=de.moekadu.decodertest/.MainActivity Activities=[ActivityRecord{482100b u0 de.moekadu.decodertest/.MainActivity t3039}] * Hist #0: ActivityRecord{482100b u0 de.moekadu.decodertest/.MainActivity t3039} packageName=de.moekadu.decodertest processName=de.moekadu.decodertest app=ProcessRecord{4ba73f5 12640:de.moekadu.decodertest/u0a272} Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=de.moekadu.decodertest/.MainActivity bnds=[437,669][643,905] } frontOfTask=true task=TaskRecord{736358a #3039 A=de.moekadu.decodertest U=0 StackId=1 sz=1} taskAffinity=de.moekadu.decodertest realActivity=de.moekadu.decodertest/.MainActivity baseDir=/data/app/de.moekadu.decodertest-yYA4xBEfkXQhW-WIifPS4A==/base.apk dataDir=/data/user/0/de.moekadu.decodertest TaskRecord{736358a #3039 A=de.moekadu.decodertest U=0 StackId=1 sz=1} Run #0: ActivityRecord{482100b u0 de.moekadu.decodertest/.MainActivity t3039} mResumedActivity: ActivityRecord{482100b u0 de.moekadu.decodertest/.MainActivity t3039} ResumedActivity: ActivityRecord{482100b u0 de.moekadu.decodertest/.MainActivity t3039} Process de.moekadu.decodertest uid 10272: last crashed +1m37s76ms ago

Also here is the bug report file but only the lines contain "decodertest"

06-08 12:39:07.701 10272 12640 12640 I zygote64: Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/de.moekadu.decodertest-yYA4xBEfkXQhW-WIifPS4A==/base.apk"],nativeLibraryDirectories=[/data/app/de.moekadu.decodertest-yYA4xBEfkXQhW-WIifPS4A==/lib/arm64, /system/lib64, /system/vendor/lib64]]

This line may be relevant but I'm not an android expert so...

thetwom commented 4 years ago

thanks for your further investigations and patience. I understand now that I cannot rely on the screen output, as I was hoping for. I still don't understand where this is hanging, but hopefully a further test will finally reveal more information. So if you could grant me some more of your time, could you install the next version of the decodertest link? Then follow the following steps:

thetwom commented 4 years ago

maybe you could then grep case-insensitive ... (cat bugreport....txt | grep -i decodertest) and also grep for "mediacodec" (cat bugreport....txt | grep -i mediacodec)

one more note, if you are under linux and have "adb" (Android Debug Bride) installed, you could connect your phone via usb and then call "adb logcat | grep -i decodertest" directly. This would save you from the extra step of taking the bug report.

ulville commented 4 years ago

OK the last page it could show was number 5. After 5th one pressing the button caused it to hang again.

grep -i decodertest gives this:

[ulvican@legion ~]$ adb logcat | grep -i decodertest 06-10 23:31:08.389 1399 2360 I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=de.moekadu.decodertest/.MainActivity} from uid 10215 06-10 23:31:08.416 1399 2360 D ActivityTrigger: activityStartTrigger: Activity is Triggerred in full screen ApplicationInfo{8f5f486 de.moekadu.decodertest} 06-10 23:31:08.416 1399 2360 E ActivityTrigger: activityStartTrigger: not whiteListedde.moekadu.decodertest/de.moekadu.decodertest.MainActivity/6 06-10 23:31:08.417 1399 2360 D ActivityTrigger: activityResumeTrigger: The activity in ApplicationInfo{8f5f486 de.moekadu.decodertest} is now in focus and seems to be in full-screen mode 06-10 23:31:08.417 1399 2360 E ActivityTrigger: activityResumeTrigger: not whiteListedde.moekadu.decodertest/de.moekadu.decodertest.MainActivity/6 06-10 23:31:08.921 1399 1449 D ActivityTrigger: activityResumeTrigger: The activity in ApplicationInfo{8f5f486 de.moekadu.decodertest} is now in focus and seems to be in full-screen mode 06-10 23:31:08.921 1399 1449 E ActivityTrigger: activityResumeTrigger: not whiteListedde.moekadu.decodertest/de.moekadu.decodertest.MainActivity/6 06-10 23:31:08.949 1399 1449 I ActivityManager: Start proc 9444:de.moekadu.decodertest/u0a274 for activity de.moekadu.decodertest/.MainActivity 06-10 23:31:09.490 9444 9444 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-10 23:31:09.490 9444 9444 I zygote64: Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/de.moekadu.decodertest-V64kVYPjr5TuckG1VppvQg==/base.apk"],nativeLibraryDirectories=[/data/app/de.moekadu.decodertest-V64kVYPjr5TuckG1VppvQg==/lib/arm64, /system/lib64, /system/vendor/lib64]] 06-10 23:31:09.491 9444 9444 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-10 23:31:09.492 9444 9444 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-10 23:31:09.493 9444 9444 I zygote64: Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/de.moekadu.decodertest-V64kVYPjr5TuckG1VppvQg==/base.apk"],nativeLibraryDirectories=[/data/app/de.moekadu.decodertest-V64kVYPjr5TuckG1VppvQg==/lib/arm64, /system/lib64, /system/vendor/lib64]] 06-10 23:31:09.493 9444 9444 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-10 23:31:09.495 9444 9444 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-10 23:31:09.495 9444 9444 I zygote64: Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/de.moekadu.decodertest-V64kVYPjr5TuckG1VppvQg==/base.apk"],nativeLibraryDirectories=[/data/app/de.moekadu.decodertest-V64kVYPjr5TuckG1VppvQg==/lib/arm64, /system/lib64, /system/vendor/lib64]] 06-10 23:31:09.495 9444 9444 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-10 23:31:09.751 1399 3358 I InputDispatcher: Focus entered window: Window{4541d7a u0 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity} 06-10 23:31:09.757 9444 9444 W RenderThread: type=1400 audit(0.0:1321): avc: denied { search } for name="proc" dev="debugfs" ino=13815 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:object_r:qti_debugfs:s0 tclass=dir permissive=0 ppid=1018 pcomm="main" pgid=9444 pgcomm="adu.decodertest" 06-10 23:31:10.010 1399 1465 I ActivityManager: Displayed de.moekadu.decodertest/.MainActivity: +1s77ms 06-10 23:31:10.023 1399 1465 I Timeline: Timeline: Activity_windows_visible id: ActivityRecord{c87dcc8 u0 de.moekadu.decodertest/.MainActivity t3186} time:151136 diff:1603 start:cold| batt:69|2 mw:off|1 mem:1202240|0|63|8|17 cpu:[1036800, 1036800, 1036800, 1036800] 06-10 23:31:14.308 9444 9444 V DecoderTest: dequeInputBuffer 06-10 23:31:14.309 9444 9444 V DecoderTest: Done 06-10 23:31:14.309 9444 9444 V DecoderTest: getInputBuffer 06-10 23:31:14.310 9444 9444 V DecoderTest: Done 06-10 23:31:14.310 9444 9444 V DecoderTest: read sample data 06-10 23:31:14.312 9444 9444 V DecoderTest: Done 06-10 23:31:14.312 9444 9444 V DecoderTest: queue input buffer 06-10 23:31:14.312 9444 9444 V DecoderTest: Done 06-10 23:31:14.313 9444 9444 V DecoderTest: advance media extractor 06-10 23:31:14.313 9444 9444 V DecoderTest: Done 06-10 23:31:14.313 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:14.314 9444 9444 V DecoderTest: Done 06-10 23:31:14.315 9444 9444 V DecoderTest: dequeInputBuffer 06-10 23:31:14.315 9444 9444 V DecoderTest: Done 06-10 23:31:14.315 9444 9444 V DecoderTest: getInputBuffer 06-10 23:31:14.315 9444 9444 V DecoderTest: Done 06-10 23:31:14.315 9444 9444 V DecoderTest: read sample data 06-10 23:31:14.332 9444 9444 V DecoderTest: Done 06-10 23:31:14.332 9444 9444 V DecoderTest: queue input buffer 06-10 23:31:14.333 9444 9444 V DecoderTest: Done 06-10 23:31:14.333 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:14.335 9444 9444 V DecoderTest: Done 06-10 23:31:14.335 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:14.335 9444 9444 V DecoderTest: Done 06-10 23:31:14.335 9444 9444 V DecoderTest: get output buffer 06-10 23:31:14.335 9444 9444 V DecoderTest: Done 06-10 23:31:14.335 9444 9444 V DecoderTest: create short buffer 06-10 23:31:14.335 9444 9444 V DecoderTest: Done 06-10 23:31:14.335 9444 9444 V DecoderTest: read short buffer from 0 to 8192 06-10 23:31:14.382 9444 9444 V DecoderTest: release output buffer 06-10 23:31:14.382 9444 9444 V DecoderTest: Done 06-10 23:31:14.382 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:14.383 9444 9444 V DecoderTest: Done 06-10 23:31:14.383 9444 9444 V DecoderTest: get output buffer 06-10 23:31:14.383 9444 9444 V DecoderTest: Done 06-10 23:31:14.383 9444 9444 V DecoderTest: create short buffer 06-10 23:31:14.383 9444 9444 V DecoderTest: Done 06-10 23:31:14.383 9444 9444 V DecoderTest: read short buffer from 0 to 8192 06-10 23:31:14.427 9444 9444 V DecoderTest: release output buffer 06-10 23:31:14.427 9444 9444 V DecoderTest: Done 06-10 23:31:14.427 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:14.428 9444 9444 V DecoderTest: Done 06-10 23:31:14.428 9444 9444 V DecoderTest: get output buffer 06-10 23:31:14.429 9444 9444 V DecoderTest: Done 06-10 23:31:14.429 9444 9444 V DecoderTest: create short buffer 06-10 23:31:14.429 9444 9444 V DecoderTest: Done 06-10 23:31:14.429 9444 9444 V DecoderTest: read short buffer from 0 to 8192 06-10 23:31:14.564 9444 9444 V DecoderTest: release output buffer 06-10 23:31:14.566 9444 9444 V DecoderTest: Done 06-10 23:31:14.567 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:14.568 9444 9444 V DecoderTest: Done 06-10 23:31:14.568 9444 9444 V DecoderTest: get output buffer 06-10 23:31:14.568 9444 9444 V DecoderTest: Done 06-10 23:31:14.568 9444 9444 V DecoderTest: create short buffer 06-10 23:31:14.568 9444 9444 V DecoderTest: Done 06-10 23:31:14.568 9444 9444 V DecoderTest: read short buffer from 0 to 2634 06-10 23:31:14.589 9444 9444 V DecoderTest: release output buffer 06-10 23:31:14.589 9444 9444 V DecoderTest: Done 06-10 23:31:14.590 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:14.590 9444 9444 V DecoderTest: Done 06-10 23:31:14.590 9444 9444 V DecoderTest: get output buffer 06-10 23:31:14.590 9444 9444 V DecoderTest: Done 06-10 23:31:14.590 9444 9444 V DecoderTest: create short buffer 06-10 23:31:14.592 9444 9444 V DecoderTest: Done 06-10 23:31:14.592 9444 9444 V DecoderTest: read short buffer from 0 to 0 06-10 23:31:14.592 9444 9444 V DecoderTest: release output buffer 06-10 23:31:14.593 9444 9444 V DecoderTest: Done 06-10 23:31:14.593 9444 9444 V DecoderTest: COUNTER: 7 06-10 23:31:14.632 9444 9444 V DecoderTest: scaling result 06-10 23:31:17.069 9444 9444 V DecoderTest: dequeInputBuffer 06-10 23:31:17.077 9444 9444 V DecoderTest: Done 06-10 23:31:17.077 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:17.082 9444 9444 V DecoderTest: Done 06-10 23:31:17.082 9444 9444 V DecoderTest: dequeInputBuffer 06-10 23:31:17.083 9444 9444 V DecoderTest: Done 06-10 23:31:17.083 9444 9444 V DecoderTest: getInputBuffer 06-10 23:31:17.083 9444 9444 V DecoderTest: Done 06-10 23:31:17.083 9444 9444 V DecoderTest: read sample data 06-10 23:31:17.084 9444 9444 V DecoderTest: Done 06-10 23:31:17.084 9444 9444 V DecoderTest: queue input buffer 06-10 23:31:17.085 9444 9444 V DecoderTest: Done 06-10 23:31:17.085 9444 9444 V DecoderTest: advance media extractor 06-10 23:31:17.085 9444 9444 V DecoderTest: Done 06-10 23:31:17.085 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:17.087 9444 9444 V DecoderTest: Done 06-10 23:31:17.087 9444 9444 V DecoderTest: dequeInputBuffer 06-10 23:31:17.087 9444 9444 V DecoderTest: Done 06-10 23:31:17.087 9444 9444 V DecoderTest: getInputBuffer 06-10 23:31:17.087 9444 9444 V DecoderTest: Done 06-10 23:31:17.087 9444 9444 V DecoderTest: read sample data 06-10 23:31:17.088 9444 9444 V DecoderTest: Done 06-10 23:31:17.088 9444 9444 V DecoderTest: queue input buffer 06-10 23:31:17.093 9444 9444 V DecoderTest: Done 06-10 23:31:17.093 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:17.094 9444 9444 V DecoderTest: Done 06-10 23:31:17.094 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:17.095 9444 9444 V DecoderTest: Done 06-10 23:31:17.095 9444 9444 V DecoderTest: get output buffer 06-10 23:31:17.095 9444 9444 V DecoderTest: Done 06-10 23:31:17.095 9444 9444 V DecoderTest: create short buffer 06-10 23:31:17.095 9444 9444 V DecoderTest: Done 06-10 23:31:17.095 9444 9444 V DecoderTest: read short buffer from 0 to 9216 06-10 23:31:17.096 9444 9444 V DecoderTest: release output buffer 06-10 23:31:17.097 9444 9444 V DecoderTest: Done 06-10 23:31:17.097 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:17.099 9444 9444 V DecoderTest: Done 06-10 23:31:17.099 9444 9444 V DecoderTest: get output buffer 06-10 23:31:17.099 9444 9444 V DecoderTest: Done 06-10 23:31:17.099 9444 9444 V DecoderTest: create short buffer 06-10 23:31:17.099 9444 9444 V DecoderTest: Done 06-10 23:31:17.099 9444 9444 V DecoderTest: read short buffer from 0 to 9216 06-10 23:31:17.100 9444 9444 V DecoderTest: release output buffer 06-10 23:31:17.100 9444 9444 V DecoderTest: Done 06-10 23:31:17.100 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:17.101 9444 9444 V DecoderTest: Done 06-10 23:31:17.102 9444 9444 V DecoderTest: get output buffer 06-10 23:31:17.102 9444 9444 V DecoderTest: Done 06-10 23:31:17.102 9444 9444 V DecoderTest: create short buffer 06-10 23:31:17.102 9444 9444 V DecoderTest: Done 06-10 23:31:17.102 9444 9444 V DecoderTest: read short buffer from 0 to 9216 06-10 23:31:17.102 9444 9444 V DecoderTest: release output buffer 06-10 23:31:17.103 9444 9444 V DecoderTest: Done 06-10 23:31:17.103 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:17.104 9444 9444 V DecoderTest: Done 06-10 23:31:17.104 9444 9444 V DecoderTest: get output buffer 06-10 23:31:17.104 9444 9444 V DecoderTest: Done 06-10 23:31:17.105 9444 9444 V DecoderTest: create short buffer 06-10 23:31:17.105 9444 9444 V DecoderTest: Done 06-10 23:31:17.105 9444 9444 V DecoderTest: read short buffer from 0 to 9216 06-10 23:31:17.105 9444 9444 V DecoderTest: release output buffer 06-10 23:31:17.106 9444 9444 V DecoderTest: Done 06-10 23:31:17.106 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:17.106 9444 9444 V DecoderTest: Done 06-10 23:31:17.106 9444 9444 V DecoderTest: get output buffer 06-10 23:31:17.106 9444 9444 V DecoderTest: Done 06-10 23:31:17.106 9444 9444 V DecoderTest: create short buffer 06-10 23:31:17.106 9444 9444 V DecoderTest: Done 06-10 23:31:17.107 9444 9444 V DecoderTest: read short buffer from 0 to 9216 06-10 23:31:17.107 9444 9444 V DecoderTest: release output buffer 06-10 23:31:17.108 9444 9444 V DecoderTest: Done 06-10 23:31:17.108 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:17.108 9444 9444 V DecoderTest: Done 06-10 23:31:17.108 9444 9444 V DecoderTest: get output buffer 06-10 23:31:17.108 9444 9444 V DecoderTest: Done 06-10 23:31:17.108 9444 9444 V DecoderTest: create short buffer 06-10 23:31:17.108 9444 9444 V DecoderTest: Done 06-10 23:31:17.108 9444 9444 V DecoderTest: read short buffer from 0 to 2538 06-10 23:31:17.108 9444 9444 V DecoderTest: release output buffer 06-10 23:31:17.109 9444 9444 V DecoderTest: Done 06-10 23:31:17.109 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:17.109 9444 9444 V DecoderTest: Done 06-10 23:31:17.110 9444 9444 V DecoderTest: get output buffer 06-10 23:31:17.110 9444 9444 V DecoderTest: Done 06-10 23:31:17.110 9444 9444 V DecoderTest: create short buffer 06-10 23:31:17.110 9444 9444 V DecoderTest: Done 06-10 23:31:17.110 9444 9444 V DecoderTest: read short buffer from 0 to 0 06-10 23:31:17.110 9444 9444 V DecoderTest: release output buffer 06-10 23:31:17.110 9444 9444 V DecoderTest: Done 06-10 23:31:17.110 9444 9444 V DecoderTest: COUNTER: 10 06-10 23:31:17.127 9444 9444 V DecoderTest: scaling result 06-10 23:31:20.108 9444 9444 V DecoderTest: dequeInputBuffer 06-10 23:31:20.111 9444 9444 V DecoderTest: Done 06-10 23:31:20.111 9444 9444 V DecoderTest: getInputBuffer 06-10 23:31:20.111 9444 9444 V DecoderTest: Done 06-10 23:31:20.112 9444 9444 V DecoderTest: read sample data 06-10 23:31:20.113 9444 9444 V DecoderTest: Done 06-10 23:31:20.113 9444 9444 V DecoderTest: queue input buffer 06-10 23:31:20.114 9444 9444 V DecoderTest: Done 06-10 23:31:20.114 9444 9444 V DecoderTest: advance media extractor 06-10 23:31:20.114 9444 9444 V DecoderTest: Done 06-10 23:31:20.114 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:20.124 9444 9444 V DecoderTest: Done 06-10 23:31:20.124 9444 9444 V DecoderTest: dequeInputBuffer 06-10 23:31:20.133 9444 9444 V DecoderTest: Done 06-10 23:31:20.133 9444 9444 V DecoderTest: getInputBuffer 06-10 23:31:20.133 9444 9444 V DecoderTest: Done 06-10 23:31:20.133 9444 9444 V DecoderTest: read sample data 06-10 23:31:20.134 9444 9444 V DecoderTest: Done 06-10 23:31:20.134 9444 9444 V DecoderTest: queue input buffer 06-10 23:31:20.135 9444 9444 V DecoderTest: Done 06-10 23:31:20.135 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:20.136 9444 9444 V DecoderTest: Done 06-10 23:31:20.136 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:20.137 9444 9444 V DecoderTest: Done 06-10 23:31:20.137 9444 9444 V DecoderTest: get output buffer 06-10 23:31:20.137 9444 9444 V DecoderTest: Done 06-10 23:31:20.137 9444 9444 V DecoderTest: create short buffer 06-10 23:31:20.137 9444 9444 V DecoderTest: Done 06-10 23:31:20.137 9444 9444 V DecoderTest: read short buffer from 0 to 9216 06-10 23:31:20.137 9444 9444 V DecoderTest: release output buffer 06-10 23:31:20.138 9444 9444 V DecoderTest: Done 06-10 23:31:20.138 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:20.139 9444 9444 V DecoderTest: Done 06-10 23:31:20.139 9444 9444 V DecoderTest: get output buffer 06-10 23:31:20.139 9444 9444 V DecoderTest: Done 06-10 23:31:20.139 9444 9444 V DecoderTest: create short buffer 06-10 23:31:20.139 9444 9444 V DecoderTest: Done 06-10 23:31:20.139 9444 9444 V DecoderTest: read short buffer from 0 to 9216 06-10 23:31:20.140 9444 9444 V DecoderTest: release output buffer 06-10 23:31:20.141 9444 9444 V DecoderTest: Done 06-10 23:31:20.141 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:20.141 9444 9444 V DecoderTest: Done 06-10 23:31:20.141 9444 9444 V DecoderTest: get output buffer 06-10 23:31:20.142 9444 9444 V DecoderTest: Done 06-10 23:31:20.142 9444 9444 V DecoderTest: create short buffer 06-10 23:31:20.142 9444 9444 V DecoderTest: Done 06-10 23:31:20.142 9444 9444 V DecoderTest: read short buffer from 0 to 9216 06-10 23:31:20.142 9444 9444 V DecoderTest: release output buffer 06-10 23:31:20.143 9444 9444 V DecoderTest: Done 06-10 23:31:20.143 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:20.143 9444 9444 V DecoderTest: Done 06-10 23:31:20.143 9444 9444 V DecoderTest: get output buffer 06-10 23:31:20.143 9444 9444 V DecoderTest: Done 06-10 23:31:20.143 9444 9444 V DecoderTest: create short buffer 06-10 23:31:20.143 9444 9444 V DecoderTest: Done 06-10 23:31:20.143 9444 9444 V DecoderTest: read short buffer from 0 to 6430 06-10 23:31:20.144 9444 9444 V DecoderTest: release output buffer 06-10 23:31:20.144 9444 9444 V DecoderTest: Done 06-10 23:31:20.144 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:20.144 9444 9444 V DecoderTest: Done 06-10 23:31:20.144 9444 9444 V DecoderTest: get output buffer 06-10 23:31:20.144 9444 9444 V DecoderTest: Done 06-10 23:31:20.144 9444 9444 V DecoderTest: create short buffer 06-10 23:31:20.144 9444 9444 V DecoderTest: Done 06-10 23:31:20.144 9444 9444 V DecoderTest: read short buffer from 0 to 0 06-10 23:31:20.144 9444 9444 V DecoderTest: release output buffer 06-10 23:31:20.145 9444 9444 V DecoderTest: Done 06-10 23:31:20.145 9444 9444 V DecoderTest: COUNTER: 7 06-10 23:31:20.168 9444 9444 V DecoderTest: scaling result 06-10 23:31:22.692 9444 9444 V DecoderTest: dequeInputBuffer 06-10 23:31:22.703 9444 9444 V DecoderTest: Done 06-10 23:31:22.703 9444 9444 V DecoderTest: getInputBuffer 06-10 23:31:22.704 9444 9444 V DecoderTest: Done 06-10 23:31:22.704 9444 9444 V DecoderTest: read sample data 06-10 23:31:22.706 9444 9444 V DecoderTest: Done 06-10 23:31:22.706 9444 9444 V DecoderTest: queue input buffer 06-10 23:31:22.706 9444 9444 V DecoderTest: Done 06-10 23:31:22.706 9444 9444 V DecoderTest: advance media extractor 06-10 23:31:22.706 9444 9444 V DecoderTest: Done 06-10 23:31:22.706 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:22.710 9444 9444 V DecoderTest: Done 06-10 23:31:22.710 9444 9444 V DecoderTest: dequeInputBuffer 06-10 23:31:22.710 9444 9444 V DecoderTest: Done 06-10 23:31:22.710 9444 9444 V DecoderTest: getInputBuffer 06-10 23:31:22.710 9444 9444 V DecoderTest: Done 06-10 23:31:22.710 9444 9444 V DecoderTest: read sample data 06-10 23:31:22.711 9444 9444 V DecoderTest: Done 06-10 23:31:22.711 9444 9444 V DecoderTest: queue input buffer 06-10 23:31:22.711 9444 9444 V DecoderTest: Done 06-10 23:31:22.711 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:22.716 9444 9444 V DecoderTest: Done 06-10 23:31:22.716 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:22.718 9444 9444 V DecoderTest: Done 06-10 23:31:22.718 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:22.718 9444 9444 V DecoderTest: Done 06-10 23:31:22.718 9444 9444 V DecoderTest: get output buffer 06-10 23:31:22.718 9444 9444 V DecoderTest: Done 06-10 23:31:22.718 9444 9444 V DecoderTest: create short buffer 06-10 23:31:22.718 9444 9444 V DecoderTest: Done 06-10 23:31:22.718 9444 9444 V DecoderTest: read short buffer from 0 to 9216 06-10 23:31:22.719 9444 9444 V DecoderTest: release output buffer 06-10 23:31:22.719 9444 9444 V DecoderTest: Done 06-10 23:31:22.719 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:22.719 9444 9444 V DecoderTest: Done 06-10 23:31:22.719 9444 9444 V DecoderTest: get output buffer 06-10 23:31:22.719 9444 9444 V DecoderTest: Done 06-10 23:31:22.719 9444 9444 V DecoderTest: create short buffer 06-10 23:31:22.719 9444 9444 V DecoderTest: Done 06-10 23:31:22.719 9444 9444 V DecoderTest: read short buffer from 0 to 2342 06-10 23:31:22.719 9444 9444 V DecoderTest: release output buffer 06-10 23:31:22.720 9444 9444 V DecoderTest: Done 06-10 23:31:22.720 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:22.720 9444 9444 V DecoderTest: Done 06-10 23:31:22.720 9444 9444 V DecoderTest: get output buffer 06-10 23:31:22.720 9444 9444 V DecoderTest: Done 06-10 23:31:22.720 9444 9444 V DecoderTest: create short buffer 06-10 23:31:22.720 9444 9444 V DecoderTest: Done 06-10 23:31:22.720 9444 9444 V DecoderTest: read short buffer from 0 to 0 06-10 23:31:22.720 9444 9444 V DecoderTest: release output buffer 06-10 23:31:22.720 9444 9444 V DecoderTest: Done 06-10 23:31:22.720 9444 9444 V DecoderTest: COUNTER: 6 06-10 23:31:22.737 9444 9444 V DecoderTest: scaling result 06-10 23:31:24.780 9444 9444 V DecoderTest: dequeInputBuffer 06-10 23:31:24.780 9444 9444 V DecoderTest: Done 06-10 23:31:24.780 9444 9444 V DecoderTest: getInputBuffer 06-10 23:31:24.780 9444 9444 V DecoderTest: Done 06-10 23:31:24.780 9444 9444 V DecoderTest: read sample data 06-10 23:31:24.781 9444 9444 V DecoderTest: Done 06-10 23:31:24.781 9444 9444 V DecoderTest: queue input buffer 06-10 23:31:24.781 9444 9444 V DecoderTest: Done 06-10 23:31:24.781 9444 9444 V DecoderTest: advance media extractor 06-10 23:31:24.781 9444 9444 V DecoderTest: Done 06-10 23:31:24.781 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:24.784 9444 9444 V DecoderTest: Done 06-10 23:31:24.784 9444 9444 V DecoderTest: dequeInputBuffer 06-10 23:31:24.784 9444 9444 V DecoderTest: Done 06-10 23:31:24.784 9444 9444 V DecoderTest: getInputBuffer 06-10 23:31:24.784 9444 9444 V DecoderTest: Done 06-10 23:31:24.784 9444 9444 V DecoderTest: read sample data 06-10 23:31:24.785 9444 9444 V DecoderTest: Done 06-10 23:31:24.785 9444 9444 V DecoderTest: queue input buffer 06-10 23:31:24.785 9444 9444 V DecoderTest: Done 06-10 23:31:24.785 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:24.787 9444 9444 V DecoderTest: Done 06-10 23:31:24.787 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:24.790 9444 9444 V DecoderTest: Done 06-10 23:31:24.790 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:24.793 9444 9444 V DecoderTest: Done 06-10 23:31:24.793 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:24.806 9444 9444 V DecoderTest: Done 06-10 23:31:24.806 9444 9444 V DecoderTest: get output buffer 06-10 23:31:24.806 9444 9444 V DecoderTest: Done 06-10 23:31:24.806 9444 9444 V DecoderTest: create short buffer 06-10 23:31:24.806 9444 9444 V DecoderTest: Done 06-10 23:31:24.806 9444 9444 V DecoderTest: read short buffer from 0 to 9216 06-10 23:31:24.807 9444 9444 V DecoderTest: release output buffer 06-10 23:31:24.807 9444 9444 V DecoderTest: Done 06-10 23:31:24.807 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:24.807 9444 9444 V DecoderTest: Done 06-10 23:31:24.807 9444 9444 V DecoderTest: get output buffer 06-10 23:31:24.807 9444 9444 V DecoderTest: Done 06-10 23:31:24.807 9444 9444 V DecoderTest: create short buffer 06-10 23:31:24.807 9444 9444 V DecoderTest: Done 06-10 23:31:24.807 9444 9444 V DecoderTest: read short buffer from 0 to 1282 06-10 23:31:24.808 9444 9444 V DecoderTest: release output buffer 06-10 23:31:24.808 9444 9444 V DecoderTest: Done 06-10 23:31:24.808 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:24.808 9444 9444 V DecoderTest: Done 06-10 23:31:24.808 9444 9444 V DecoderTest: get output buffer 06-10 23:31:24.808 9444 9444 V DecoderTest: Done 06-10 23:31:24.808 9444 9444 V DecoderTest: create short buffer 06-10 23:31:24.808 9444 9444 V DecoderTest: Done 06-10 23:31:24.808 9444 9444 V DecoderTest: read short buffer from 0 to 0 06-10 23:31:24.808 9444 9444 V DecoderTest: release output buffer 06-10 23:31:24.809 9444 9444 V DecoderTest: Done 06-10 23:31:24.809 9444 9444 V DecoderTest: COUNTER: 7 06-10 23:31:24.828 9444 9444 V DecoderTest: scaling result 06-10 23:31:26.961 9444 9444 V DecoderTest: dequeInputBuffer 06-10 23:31:26.961 9444 9444 V DecoderTest: Done 06-10 23:31:26.961 9444 9444 V DecoderTest: getInputBuffer 06-10 23:31:26.961 9444 9444 V DecoderTest: Done 06-10 23:31:26.961 9444 9444 V DecoderTest: read sample data 06-10 23:31:26.962 9444 9444 V DecoderTest: Done 06-10 23:31:26.962 9444 9444 V DecoderTest: queue input buffer 06-10 23:31:26.962 9444 9444 V DecoderTest: Done 06-10 23:31:26.962 9444 9444 V DecoderTest: advance media extractor 06-10 23:31:26.963 9444 9444 V DecoderTest: Done 06-10 23:31:26.963 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:26.966 9444 9444 V DecoderTest: Done 06-10 23:31:26.966 9444 9444 V DecoderTest: dequeInputBuffer 06-10 23:31:26.968 9444 9444 V DecoderTest: Done 06-10 23:31:26.968 9444 9444 V DecoderTest: getInputBuffer 06-10 23:31:26.968 9444 9444 V DecoderTest: Done 06-10 23:31:26.968 9444 9444 V DecoderTest: read sample data 06-10 23:31:26.969 9444 9444 V DecoderTest: Done 06-10 23:31:26.969 9444 9444 V DecoderTest: queue input buffer 06-10 23:31:26.969 9444 9444 V DecoderTest: Done 06-10 23:31:26.969 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:26.970 9444 9444 V DecoderTest: Done 06-10 23:31:26.970 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:26.970 9444 9444 V DecoderTest: Done 06-10 23:31:26.970 9444 9444 V DecoderTest: get output buffer 06-10 23:31:26.970 9444 9444 V DecoderTest: Done 06-10 23:31:26.971 9444 9444 V DecoderTest: create short buffer 06-10 23:31:26.971 9444 9444 V DecoderTest: Done 06-10 23:31:26.971 9444 9444 V DecoderTest: read short buffer from 0 to 9216 06-10 23:31:26.971 9444 9444 V DecoderTest: release output buffer 06-10 23:31:26.971 9444 9444 V DecoderTest: Done 06-10 23:31:26.971 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:26.972 9444 9444 V DecoderTest: Done 06-10 23:31:26.972 9444 9444 V DecoderTest: get output buffer 06-10 23:31:26.972 9444 9444 V DecoderTest: Done 06-10 23:31:26.972 9444 9444 V DecoderTest: create short buffer 06-10 23:31:26.972 9444 9444 V DecoderTest: Done 06-10 23:31:26.972 9444 9444 V DecoderTest: read short buffer from 0 to 9216 06-10 23:31:26.972 9444 9444 V DecoderTest: release output buffer 06-10 23:31:26.973 9444 9444 V DecoderTest: Done 06-10 23:31:26.973 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:26.973 9444 9444 V DecoderTest: Done 06-10 23:31:26.973 9444 9444 V DecoderTest: get output buffer 06-10 23:31:26.973 9444 9444 V DecoderTest: Done 06-10 23:31:26.973 9444 9444 V DecoderTest: create short buffer 06-10 23:31:26.973 9444 9444 V DecoderTest: Done 06-10 23:31:26.973 9444 9444 V DecoderTest: read short buffer from 0 to 3936 06-10 23:31:26.973 9444 9444 V DecoderTest: release output buffer 06-10 23:31:26.974 9444 9444 V DecoderTest: Done 06-10 23:31:26.974 9444 9444 V DecoderTest: deque output buffer 06-10 23:31:26.974 9444 9444 V DecoderTest: Done 06-10 23:31:26.974 9444 9444 V DecoderTest: get output buffer 06-10 23:31:26.974 9444 9444 V DecoderTest: Done 06-10 23:31:26.974 9444 9444 V DecoderTest: create short buffer 06-10 23:31:26.974 9444 9444 V DecoderTest: Done 06-10 23:31:26.974 9444 9444 V DecoderTest: read short buffer from 0 to 0 06-10 23:31:26.974 9444 9444 V DecoderTest: release output buffer 06-10 23:31:26.975 9444 9444 V DecoderTest: Done 06-10 23:31:26.975 9444 9444 V DecoderTest: COUNTER: 6 06-10 23:31:26.991 9444 9444 V DecoderTest: scaling result 06-10 23:32:04.356 1399 1812 I InputDispatcher: Application is not responding: Window{4541d7a u0 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity}. It has been 5006.3ms since event, 5005.7ms since wait started. Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 7. Wait queue head age: 6701.2ms. 06-10 23:32:04.361 1399 1812 I WindowManager: Input event dispatching timed out sending to de.moekadu.decodertest/de.moekadu.decodertest.MainActivity. Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 7. Wait queue head age: 6701.2ms. 06-10 23:32:09.394 1399 1812 I InputDispatcher: Application is not responding: Window{4541d7a u0 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity}. It has been 9419.4ms since event, 5005.7ms since wait started. Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 7. Wait queue head age: 11739.2ms. 06-10 23:32:09.397 1399 1812 I WindowManager: Input event dispatching timed out sending to de.moekadu.decodertest/de.moekadu.decodertest.MainActivity. Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 7. Wait queue head age: 11739.2ms. 06-10 23:32:12.976 1399 1449 E ActivityManager: ANR in de.moekadu.decodertest (de.moekadu.decodertest/.MainActivity) 06-10 23:32:12.976 1399 1449 E ActivityManager: 1.6% 9444/de.moekadu.decodertest: 1% user + 0.6% kernel / faults: 1134 minor 36 06-10 23:32:12.981 1399 1449 D ActivityManager: New dropbox entry: de.moekadu.decodertest, data_app_anr, fbeaf4c1-a24e-426b-8e8e-28564415d59f 06-10 23:32:13.086 1399 1449 I ActivityManager: Skipping duplicate ANR: ProcessRecord{87aa300 9444:de.moekadu.decodertest/u0a274} Input dispatching timed out (Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 7. Wait queue head age: 11739.2ms.) 06-10 23:32:13.154 1029 1029 I JavaDumper:JavaDumperThread: addEvent: data_app_anr@1591821133137.txt.gz processName: de.moekadu.decodertest 06-10 23:32:13.168 1399 1450 I InputDispatcher: Focus entered window: Window{5efb3a8 u0 Application Not Responding: de.moekadu.decodertest} 06-10 23:32:18.857 1399 1450 W ActivityManager: Force finishing activity de.moekadu.decodertest/.MainActivity 06-10 23:32:18.868 1399 1450 I ActivityManager: Killing 9444:de.moekadu.decodertest/u0a274 (adj 0): user request after error 06-10 23:32:19.015 1399 1838 I WindowManager: WIN DEATH: Window{4541d7a u0 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity}

grep -i mediacodec didn't give any output.

thetwom commented 4 years ago

Thanks for running and evaluating this test. It looks like there is a problem with one sound file, which is stored as mono instead of stereo. I will see that I reformat the track, such that it will hopefully be working.

However, I still wonder where the actual problem is and unfortunately the logcat doesn't tell yet. So, here is what I propose to be a way forward:

Thanks for the great support so far.

ulville commented 4 years ago

You're welcome! I'll gladly help. Hope we'll figure it out this time.

thetwom commented 4 years ago

As promised, here a test version of the metronome: link Can you try and report?

And here another decoder test printing more logs. I changed the track order, so it should now hang for the first track. Would be great if you could send me the logs again: link Hopefully, this finally tells where the problem is.

ulville commented 4 years ago

Metronome works like a charm with this version! I tried every feature and nothing caused an error. By the way I just remembered that my phone has stereo speakers. I'm not sure but that may be the thing that caused the issue in the first place.

Here is the logcat lines which contain metronome:

[ulvican@legion ~]$ adb logcat | grep -i metronome 06-11 22:24:36.511 1422 3131 I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=de.moekadu.metronome/.MainActivity} from uid 10215 06-11 22:24:36.541 1422 3131 D ActivityTrigger: activityStartTrigger: Activity is Triggerred in full screen ApplicationInfo{456371d de.moekadu.metronome} 06-11 22:24:36.541 1422 3131 E ActivityTrigger: activityStartTrigger: not whiteListedde.moekadu.metronome/de.moekadu.metronome.MainActivity/18 06-11 22:24:36.544 1422 3131 D ActivityTrigger: activityResumeTrigger: The activity in ApplicationInfo{456371d de.moekadu.metronome} is now in focus and seems to be in full-screen mode 06-11 22:24:36.544 1422 3131 E ActivityTrigger: activityResumeTrigger: not whiteListedde.moekadu.metronome/de.moekadu.metronome.MainActivity/18 06-11 22:24:36.640 1422 2904 I ActivityManager: Start proc 5809:de.moekadu.metronome/u0a275 for activity de.moekadu.metronome/.MainActivity 06-11 22:24:36.730 1422 2904 D ActivityTrigger: activityResumeTrigger: The activity in ApplicationInfo{456371d de.moekadu.metronome} is now in focus and seems to be in full-screen mode 06-11 22:24:36.730 1422 2904 E ActivityTrigger: activityResumeTrigger: not whiteListedde.moekadu.metronome/de.moekadu.metronome.MainActivity/18 06-11 22:24:36.962 5809 5809 I zygote64: at void de.moekadu.metronome.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:85) 06-11 22:24:36.963 5809 5809 I zygote64: Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/de.moekadu.metronome-GbIiT6gvPU-W_2sluY0QIA==/base.apk"],nativeLibraryDirectories=[/data/app/de.moekadu.metronome-GbIiT6gvPU-W_2sluY0QIA==/lib/arm64, /system/lib64, /system/vendor/lib64]] 06-11 22:24:36.963 5809 5809 I zygote64: at void de.moekadu.metronome.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:85) 06-11 22:24:36.964 5809 5809 I zygote64: at void de.moekadu.metronome.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:85) 06-11 22:24:36.964 5809 5809 I zygote64: Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/de.moekadu.metronome-GbIiT6gvPU-W_2sluY0QIA==/base.apk"],nativeLibraryDirectories=[/data/app/de.moekadu.metronome-GbIiT6gvPU-W_2sluY0QIA==/lib/arm64, /system/lib64, /system/vendor/lib64]] 06-11 22:24:36.964 5809 5809 I zygote64: at void de.moekadu.metronome.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:85) 06-11 22:24:36.965 5809 5809 I zygote64: at void de.moekadu.metronome.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:85) 06-11 22:24:36.966 5809 5809 I zygote64: Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/de.moekadu.metronome-GbIiT6gvPU-W_2sluY0QIA==/base.apk"],nativeLibraryDirectories=[/data/app/de.moekadu.metronome-GbIiT6gvPU-W_2sluY0QIA==/lib/arm64, /system/lib64, /system/vendor/lib64]] 06-11 22:24:36.966 5809 5809 I zygote64: at void de.moekadu.metronome.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:85) 06-11 22:24:38.822 5809 5809 W RenderThread: type=1400 audit(0.0:1275): avc: denied { search } for name="proc" dev="debugfs" ino=13808 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:object_r:qti_debugfs:s0 tclass=dir permissive=0 ppid=1016 pcomm="main" pgid=5809 pgcomm="ekadu.metronome" 06-11 22:24:38.822 5809 5809 W RenderThread: type=1400 audit(0.0:1275): avc: denied { search } for name="proc" dev="debugfs" ino=13808 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:object_r:qti_debugfs:s0 tclass=dir permissive=0 ppid=1016 pcomm="main" pgid=5809 pgcomm="ekadu.metronome" 06-11 22:24:39.314 1422 1475 I ActivityManager: Displayed de.moekadu.metronome/.MainActivity: +2s652ms 06-11 22:24:39.320 1422 1475 I Timeline: Timeline: Activity_windows_visible id: ActivityRecord{39631c7 u0 de.moekadu.metronome/.MainActivity t3279} time:88502 diff:2774 start:lukewarm|cch-empty batt:89|2 mw:off|1 mem:1025276|0|58|6|17 cpu:[1036800, 1036800, 1036800, 1036800] 06-11 22:24:42.559 1971 2499 V Avrcp : ActiveSession: MediaController (de.moekadu.metronome@c533533) 3 1.0 3 0.39115644 , null, null 06-11 22:24:42.562 1971 2499 V Avrcp : isBrowseSupported for de.moekadu.metronome: false 06-11 22:24:42.574 1971 2499 D Avrcp : update #4:MediaPlayerInfo de.moekadu.metronome (as 'Metronome') Type = 1, SubType = 0, Status = 2 Feature Bits [40 41 42 44 45 47 48 58] Controller: MediaController (de.moekadu.metronome@c533533) 3 1.0 3 0.39115644 , null, null 06-11 22:24:43.329 1971 2499 V Avrcp : ActiveSession: MediaController (de.moekadu.metronome@439669) 3 1.0 3 0.39115644 , null, null 06-11 22:24:43.331 1971 2499 V Avrcp : isBrowseSupported for de.moekadu.metronome: false 06-11 22:24:43.333 1971 2499 D Avrcp : update #4:MediaPlayerInfo de.moekadu.metronome (as 'Metronome') Type = 1, SubType = 0, Status = 2 Feature Bits [40 41 42 44 45 47 48 58] Controller: MediaController (de.moekadu.metronome@439669) 3 1.0 3 0.39115644 , null, null 06-11 22:24:45.350 1971 2499 V Avrcp : ActiveSession: MediaController (de.moekadu.metronome@2d138ee) 3 1.0 3 0.39115644 , null, null 06-11 22:24:45.350 1971 2499 V Avrcp : isBrowseSupported for de.moekadu.metronome: false 06-11 22:24:45.354 1971 2499 D Avrcp : update #4:MediaPlayerInfo de.moekadu.metronome (as 'Metronome') Type = 1, SubType = 0, Status = 2 Feature Bits [40 41 42 44 45 47 48 58] Controller: MediaController (de.moekadu.metronome@2d138ee) 3 1.0 3 0.39115644 , null, null 06-11 22:24:45.656 1971 2499 V Avrcp : ActiveSession: MediaController (de.moekadu.metronome@a879c1c) 3 1.0 3 0.39115644 , null, null 06-11 22:24:45.657 1971 2499 V Avrcp : isBrowseSupported for de.moekadu.metronome: false 06-11 22:24:45.658 1971 2499 D Avrcp : update #4:MediaPlayerInfo de.moekadu.metronome (as 'Metronome') Type = 1, SubType = 0, Status = 2 Feature Bits [40 41 42 44 45 47 48 58] Controller: MediaController (de.moekadu.metronome@a879c1c) 3 1.0 3 0.39115644 , null, null 06-11 22:24:52.861 1422 1437 D MediaSessionService: Media button session is changed to de.moekadu.metronome/toc2 (userId=0) 06-11 22:24:52.877 1971 1971 V Avrcp : Set active media session de.moekadu.metronome 06-11 22:24:52.879 1971 2499 V Avrcp : ActiveSession: MediaController (de.moekadu.metronome@6f63025) 3 1.0 3 0.39115644 , null, null 06-11 22:24:52.880 1971 2499 V Avrcp : isBrowseSupported for de.moekadu.metronome: false 06-11 22:24:52.881 1971 1971 V Avrcp : isBrowseSupported for de.moekadu.metronome: false 06-11 22:24:52.883 1971 2499 D Avrcp : update #4:MediaPlayerInfo de.moekadu.metronome (as 'Metronome') Type = 1, SubType = 0, Status = 1 Feature Bits [40 41 42 44 45 47 48 58] Controller: MediaController (de.moekadu.metronome@6f63025) 3 1.0 3 0.39115644 , null, null 06-11 22:24:52.888 1971 1971 D Avrcp : update #4:MediaPlayerInfo de.moekadu.metronome (as 'Metronome') Type = 1, SubType = 0, Status = 1 Feature Bits [40 41 42 44 45 47 48 58] Controller: MediaController (de.moekadu.metronome@b1bf5fa) 3 1.0 3 0.39115644 , null, null 06-11 22:24:52.888 1971 1971 V Avrcp : Changing addressed media session to de.moekadu.metronome 06-11 22:24:52.888 1971 1971 V Avrcp : getMediaPlayerInfo: Found de.moekadu.metronome 06-11 22:24:52.889 1971 1971 V Avrcp : Set addressed #4 MediaPlayerInfo de.moekadu.metronome (as 'Metronome') Type = 1, SubType = 0, Status = 1 Feature Bits [40 41 42 44 45 47 48 58] Controller: MediaController (de.moekadu.metronome@b1bf5fa) 3 1.0 3 0.39115644 , null, null 06-11 22:24:52.890 1971 1971 D Avrcp : updateCurrentController: null to MediaController (de.moekadu.metronome@b1bf5fa) 3 1.0 3 0.39115644 , null, null 06-11 22:24:52.911 1971 1971 I AddressedMediaPlayer: null queue from de.moekadu.metronome, constructing single-item list 06-11 22:24:58.163 1971 2499 V Avrcp : ActiveSession: MediaController (de.moekadu.metronome@93617ab) 3 1.0 3 0.39115644 , null, null 06-11 22:24:58.166 1971 2499 V Avrcp : isBrowseSupported for de.moekadu.metronome: false 06-11 22:24:58.176 1971 2499 D Avrcp : update #4:MediaPlayerInfo de.moekadu.metronome (as 'Metronome') Type = 1, SubType = 0, Status = 2 Feature Bits [40 41 42 44 45 47 48 58] Controller: MediaController (de.moekadu.metronome@93617ab) 3 1.0 3 0.39115644 , null, null 06-11 22:24:58.179 1971 2499 D Avrcp : updateCurrentController: MediaController (de.moekadu.metronome@b1bf5fa) 3 1.0 3 0.39115644 , null, null to MediaController (de.moekadu.metronome@93617ab) 3 1.0 3 0.39115644 , null, null 06-11 22:24:58.182 1971 2499 I AddressedMediaPlayer: null queue from de.moekadu.metronome, constructing single-item list 06-11 22:24:58.663 1971 2499 V Avrcp : ActiveSession: MediaController (de.moekadu.metronome@805e08) 3 1.0 3 0.39115644 , null, null 06-11 22:24:58.663 1971 2499 V Avrcp : isBrowseSupported for de.moekadu.metronome: false 06-11 22:24:58.666 1971 2499 D Avrcp : update #4:MediaPlayerInfo de.moekadu.metronome (as 'Metronome') Type = 1, SubType = 0, Status = 2 Feature Bits [40 41 42 44 45 47 48 58] Controller: MediaController (de.moekadu.metronome@805e08) 3 1.0 3 0.39115644 , null, null 06-11 22:24:58.670 1971 2499 D Avrcp : updateCurrentController: MediaController (de.moekadu.metronome@93617ab) 3 1.0 3 0.39115644 , null, null to MediaController (de.moekadu.metronome@805e08) 3 1.0 3 0.39115644 , null, null 06-11 22:24:58.673 1971 2499 I AddressedMediaPlayer: null queue from de.moekadu.metronome, constructing single-item list 06-11 22:24:59.316 1971 2499 V Avrcp : ActiveSession: MediaController (de.moekadu.metronome@57ea9a1) 3 1.0 3 0.39115644 , null, null 06-11 22:24:59.317 1971 2499 V Avrcp : isBrowseSupported for de.moekadu.metronome: false 06-11 22:24:59.319 1971 2499 D Avrcp : update #4:MediaPlayerInfo de.moekadu.metronome (as 'Metronome') Type = 1, SubType = 0, Status = 2 Feature Bits [40 41 42 44 45 47 48 58] Controller: MediaController (de.moekadu.metronome@57ea9a1) 3 1.0 3 0.39115644 , null, null 06-11 22:24:59.321 1971 2499 D Avrcp : updateCurrentController: MediaController (de.moekadu.metronome@805e08) 3 1.0 3 0.39115644 , null, null to MediaController (de.moekadu.metronome@57ea9a1) 3 1.0 3 0.39115644 , null, null 06-11 22:24:59.324 1971 2499 I AddressedMediaPlayer: null queue from de.moekadu.metronome, constructing single-item list

And as you said decodertest hanged at the first button-press. Here is it's logcat:

[ulvican@legion ~]$ adb logcat | grep -i decodertest 06-11 22:46:52.827 1438 2376 I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=de.moekadu.decodertest/.MainActivity} from uid 10215 06-11 22:46:52.880 1438 2376 D ActivityTrigger: activityStartTrigger: Activity is Triggerred in full screen ApplicationInfo{f89bd8a de.moekadu.decodertest} 06-11 22:46:52.880 1438 2376 E ActivityTrigger: activityStartTrigger: not whiteListedde.moekadu.decodertest/de.moekadu.decodertest.MainActivity/7 06-11 22:46:52.890 1438 2376 D ActivityTrigger: activityResumeTrigger: The activity in ApplicationInfo{f89bd8a de.moekadu.decodertest} is now in focus and seems to be in full-screen mode 06-11 22:46:52.890 1438 2376 E ActivityTrigger: activityResumeTrigger: not whiteListedde.moekadu.decodertest/de.moekadu.decodertest.MainActivity/7 06-11 22:46:52.967 1438 2376 D ActivityTrigger: activityResumeTrigger: The activity in ApplicationInfo{f89bd8a de.moekadu.decodertest} is now in focus and seems to be in full-screen mode 06-11 22:46:52.968 1438 2376 E ActivityTrigger: activityResumeTrigger: not whiteListedde.moekadu.decodertest/de.moekadu.decodertest.MainActivity/7 06-11 22:46:53.012 1438 2376 I ActivityManager: Start proc 6304:de.moekadu.decodertest/u0a276 for activity de.moekadu.decodertest/.MainActivity 06-11 22:46:53.333 6304 6304 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-11 22:46:53.333 6304 6304 I zygote64: Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/de.moekadu.decodertest-EPfRrBu4YRO9O1hTt7fa-Q==/base.apk"],nativeLibraryDirectories=[/data/app/de.moekadu.decodertest-EPfRrBu4YRO9O1hTt7fa-Q==/lib/arm64, /system/lib64, /system/vendor/lib64]] 06-11 22:46:53.334 6304 6304 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-11 22:46:53.337 6304 6304 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-11 22:46:53.337 6304 6304 I zygote64: Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/de.moekadu.decodertest-EPfRrBu4YRO9O1hTt7fa-Q==/base.apk"],nativeLibraryDirectories=[/data/app/de.moekadu.decodertest-EPfRrBu4YRO9O1hTt7fa-Q==/lib/arm64, /system/lib64, /system/vendor/lib64]] 06-11 22:46:53.338 6304 6304 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-11 22:46:53.341 6304 6304 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-11 22:46:53.342 6304 6304 I zygote64: Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/de.moekadu.decodertest-EPfRrBu4YRO9O1hTt7fa-Q==/base.apk"],nativeLibraryDirectories=[/data/app/de.moekadu.decodertest-EPfRrBu4YRO9O1hTt7fa-Q==/lib/arm64, /system/lib64, /system/vendor/lib64]] 06-11 22:46:53.342 6304 6304 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-11 22:46:53.603 1438 3017 I InputDispatcher: Focus entered window: Window{c578145 u0 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity} 06-11 22:46:53.610 6304 6304 W RenderThread: type=1400 audit(0.0:1271): avc: denied { search } for name="proc" dev="debugfs" ino=8073 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:object_r:qti_debugfs:s0 tclass=dir permissive=0 ppid=1018 pcomm="main" pgid=6304 pgcomm="adu.decodertest" 06-11 22:46:54.050 1438 1502 I ActivityManager: Displayed de.moekadu.decodertest/.MainActivity: +1s67ms 06-11 22:46:54.053 1438 1502 I Timeline: Timeline: Activity_windows_visible id: ActivityRecord{17c952c u0 de.moekadu.decodertest/.MainActivity t3101} time:86807 diff:1162 start:cold| batt:87|2 mw:off|1 mem:976796|0|59|7|17 cpu:[1113600, 1113600, 1113600, 1113600] 06-11 22:46:58.694 6304 6304 V DecoderTest: openRawRessource 06-11 22:46:58.695 6304 6304 V DecoderTest: Done 06-11 22:46:58.695 6304 6304 V DecoderTest: setDataSource 06-11 22:47:16.336 1438 1808 I InputDispatcher: Application is not responding: Window{c578145 u0 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity}. It has been 5001.0ms since event, 5000.5ms since wait started. Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 2. Wait queue head age: 5891.8ms. 06-11 22:47:16.338 1438 1808 I WindowManager: Input event dispatching timed out sending to de.moekadu.decodertest/de.moekadu.decodertest.MainActivity. Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 2. Wait queue head age: 5891.8ms. 06-11 22:47:21.359 1438 1808 I InputDispatcher: Application is not responding: Window{c578145 u0 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity}. It has been 9368.6ms since event, 5001.2ms since wait started. Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 2. Wait queue head age: 10916.9ms. 06-11 22:47:21.362 1438 1808 I WindowManager: Input event dispatching timed out sending to de.moekadu.decodertest/de.moekadu.decodertest.MainActivity. Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 2. Wait queue head age: 10916.9ms. 06-11 22:47:29.020 1438 1470 E ActivityManager: ANR in de.moekadu.decodertest (de.moekadu.decodertest/.MainActivity) 06-11 22:47:29.023 1438 1470 D ActivityManager: New dropbox entry: de.moekadu.decodertest, data_app_anr, a9843406-dcda-4409-8738-a0cfe88453e8 06-11 22:47:29.104 1024 1024 I JavaDumper:JavaDumperThread: addEvent: data_app_anr@1591904849091.txt.gz processName: de.moekadu.decodertest 06-11 22:47:29.335 1438 1471 I InputDispatcher: Focus entered window: Window{3515a91 u0 Application Not Responding: de.moekadu.decodertest} 06-11 22:47:29.409 1438 1470 I ActivityManager: Skipping duplicate ANR: ProcessRecord{3d76038 6304:de.moekadu.decodertest/u0a276} Input dispatching timed out (Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 2. Wait queue head age: 10916.9ms.) 06-11 22:47:37.064 1438 1471 W ActivityManager: Force finishing activity de.moekadu.decodertest/.MainActivity 06-11 22:47:37.079 1438 1471 I ActivityManager: Killing 6304:de.moekadu.decodertest/u0a276 (adj 0): user request after error 06-11 22:47:37.117 1438 1808 W InputDispatcher: channel 'c578145 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity (server)' ~ Consumer closed input channel or an error occurred. events=0xd 06-11 22:47:37.117 1438 1808 E InputDispatcher: channel 'c578145 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity (server)' ~ Channel is unrecoverably broken and will be disposed! 06-11 22:47:37.118 1438 7081 I WindowManager: WIN DEATH: Window{c578145 u0 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity} 06-11 22:47:37.118 1438 7081 W InputDispatcher: Attempted to unregister already unregistered input channel 'c578145 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity (server)'

thetwom commented 4 years ago

This is great to hear! Thanks again for your support in finding the problem. I would have had no change finding this issue without having a device showing this behavior, meaning I was fully dependent on you. Hopefully, the app keeps its promises, so it was worth your efforts. I will shortly make the new version ready for fdroid.

Thanks also for running the decoder test. It now really shows me where it is hanging and it is something I didn't expect. Somehow the monofile can't be read correctly by your phone. I don't think that it is because of being a stereo device, it seems more as an Android bug. If you have the patience you could repeat the procedure one more time link. This might reveal some last details why your phone does not like the file. But this is not so important though. So feel free to ignore my request.

ulville commented 4 years ago

I did nothing but testing some pre-created apps and running some commands. You did the great job for the community by creating and sharing this app. Thank you for your determination, big efforts and the good work!

I am happy to be able to use the app finally and I really liked it! It looks and feels nice and professional and it does the job well for me. I liked helping.

I did run the procedure with the latest decodertest. Here it is:

[ulvican@legion ~]$ adb logcat | grep -i decodertest 06-12 20:48:42.729 1432 2220 I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=de.moekadu.decodertest/.MainActivity} from uid 10215 06-12 20:48:42.753 1432 2220 D ActivityTrigger: activityStartTrigger: Activity is Triggerred in full screen ApplicationInfo{96225b2 de.moekadu.decodertest} 06-12 20:48:42.753 1432 2220 E ActivityTrigger: activityStartTrigger: not whiteListedde.moekadu.decodertest/de.moekadu.decodertest.MainActivity/8 06-12 20:48:42.763 1432 2220 D ActivityTrigger: activityResumeTrigger: The activity in ApplicationInfo{96225b2 de.moekadu.decodertest} is now in focus and seems to be in full-screen mode 06-12 20:48:42.763 1432 2220 E ActivityTrigger: activityResumeTrigger: not whiteListedde.moekadu.decodertest/de.moekadu.decodertest.MainActivity/8 06-12 20:48:42.875 1432 4988 D ActivityTrigger: activityResumeTrigger: The activity in ApplicationInfo{96225b2 de.moekadu.decodertest} is now in focus and seems to be in full-screen mode 06-12 20:48:42.875 1432 4988 E ActivityTrigger: activityResumeTrigger: not whiteListedde.moekadu.decodertest/de.moekadu.decodertest.MainActivity/8 06-12 20:48:42.903 1432 4988 I ActivityManager: Start proc 12042:de.moekadu.decodertest/u0a277 for activity de.moekadu.decodertest/.MainActivity 06-12 20:48:43.201 12042 12042 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-12 20:48:43.201 12042 12042 I zygote64: Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/de.moekadu.decodertest-nh0mXT8N4Q93Z-8EBTHbbg==/base.apk"],nativeLibraryDirectories=[/data/app/de.moekadu.decodertest-nh0mXT8N4Q93Z-8EBTHbbg==/lib/arm64, /system/lib64, /system/vendor/lib64]] 06-12 20:48:43.201 12042 12042 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-12 20:48:43.202 12042 12042 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-12 20:48:43.202 12042 12042 I zygote64: Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/de.moekadu.decodertest-nh0mXT8N4Q93Z-8EBTHbbg==/base.apk"],nativeLibraryDirectories=[/data/app/de.moekadu.decodertest-nh0mXT8N4Q93Z-8EBTHbbg==/lib/arm64, /system/lib64, /system/vendor/lib64]] 06-12 20:48:43.203 12042 12042 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-12 20:48:43.204 12042 12042 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-12 20:48:43.204 12042 12042 I zygote64: Caused by: java.lang.ClassNotFoundException: Didn't find class "android.view.View$OnUnhandledKeyEventListener" on path: DexPathList[[zip file "/data/app/de.moekadu.decodertest-nh0mXT8N4Q93Z-8EBTHbbg==/base.apk"],nativeLibraryDirectories=[/data/app/de.moekadu.decodertest-nh0mXT8N4Q93Z-8EBTHbbg==/lib/arm64, /system/lib64, /system/vendor/lib64]] 06-12 20:48:43.204 12042 12042 I zygote64: at void de.moekadu.decodertest.MainActivity.onCreate(android.os.Bundle) (MainActivity.kt:24) 06-12 20:48:43.473 1432 4988 I InputDispatcher: Focus entered window: Window{58e6512 u0 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity} 06-12 20:48:43.477 12042 12042 W RenderThread: type=1400 audit(0.0:1327): avc: denied { search } for name="proc" dev="debugfs" ino=13724 scontext=u:r:untrusted_app:s0:c512,c768 tcontext=u:object_r:qti_debugfs:s0 tclass=dir permissive=0 ppid=1013 pcomm="main" pgid=12042 pgcomm="adu.decodertest" 06-12 20:48:43.822 1432 1499 I ActivityManager: Displayed de.moekadu.decodertest/.MainActivity: +938ms 06-12 20:48:43.825 1432 1499 I Timeline: Timeline: Activity_windows_visible id: ActivityRecord{f6c2714 u0 de.moekadu.decodertest/.MainActivity t3139} time:154611 diff:1060 start:cold| batt:78|2 mw:off|1 mem:1140968|0|64|9|16 cpu:[1324800, 1324800, 1324800, 1324800] 06-12 20:48:47.440 12042 12042 V DecoderTest: openRawRessource 06-12 20:48:47.440 12042 12042 V DecoderTest: Done 06-12 20:48:47.443 12042 12042 V DecoderTest: setDataSource with fileDescriptor=java.io.FileDescriptor@429949f, startOffset=1912308, length=100 06-12 20:49:22.669 1432 1801 I InputDispatcher: Application is not responding: Window{58e6512 u0 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity}. It has been 5001.6ms since event, 5001.1ms since wait started. Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 9. Wait queue head age: 5647.9ms. 06-12 20:49:22.673 1432 1801 I WindowManager: Input event dispatching timed out sending to de.moekadu.decodertest/de.moekadu.decodertest.MainActivity. Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 9. Wait queue head age: 5647.9ms. 06-12 20:49:27.700 1432 1801 I InputDispatcher: Application is not responding: Window{58e6512 u0 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity}. It has been 9467.5ms since event, 5001.5ms since wait started. Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 9. Wait queue head age: 10679.2ms. 06-12 20:49:27.703 1432 1801 I WindowManager: Input event dispatching timed out sending to de.moekadu.decodertest/de.moekadu.decodertest.MainActivity. Reason: Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 9. Wait queue head age: 10679.2ms. 06-12 20:49:31.885 1432 1467 E ActivityManager: ANR in de.moekadu.decodertest (de.moekadu.decodertest/.MainActivity) 06-12 20:49:31.891 1432 1467 D ActivityManager: New dropbox entry: de.moekadu.decodertest, data_app_anr, bfce1d9b-07c2-4e36-a95e-1c230f58b7f7 06-12 20:49:31.944 1020 1020 I JavaDumper:JavaDumperThread: addEvent: data_app_anr@1591984171937.txt.gz processName: de.moekadu.decodertest 06-12 20:49:31.992 1432 1467 I ActivityManager: Skipping duplicate ANR: ProcessRecord{59c7431 12042:de.moekadu.decodertest/u0a277} Input dispatching timed out (Waiting to send non-key event because the touched window has not finished processing certain input events that were delivered to it over 500.0ms ago. Wait queue length: 9. Wait queue head age: 10679.2ms.) 06-12 20:49:32.043 1432 1468 I InputDispatcher: Focus entered window: Window{7788253 u0 Application Not Responding: de.moekadu.decodertest} 06-12 20:49:35.624 1432 1468 W ActivityManager: Force finishing activity de.moekadu.decodertest/.MainActivity 06-12 20:49:35.645 1432 1468 I ActivityManager: Killing 12042:de.moekadu.decodertest/u0a277 (adj 0): user request after error 06-12 20:49:35.693 1432 1801 W InputDispatcher: channel '58e6512 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity (server)' ~ Consumer closed input channel or an error occurred. events=0xd 06-12 20:49:35.694 1432 4878 I WindowManager: WIN DEATH: Window{58e6512 u0 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity} 06-12 20:49:35.695 1432 1801 E InputDispatcher: channel '58e6512 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity (server)' ~ Channel is unrecoverably broken and will be disposed! 06-12 20:49:35.695 1432 4878 W InputDispatcher: Attempted to unregister already unregistered input channel '58e6512 de.moekadu.decodertest/de.moekadu.decodertest.MainActivity (server)'

thetwom commented 4 years ago

Thanks for the posting the latest info. For now I will leave things as they are, since it really seems to be an Android but and we found a workaround which fixes the issue for you. However, if new similar reports will pop up, this will be a great reference. I tagged the fixed version as official release, so it should become available in fdroid and google play during the next days. I am glad you like that app. Thanks again for your support for fixing this problem!