Saturday, July 23, 2011

The Exerciser Monkey tool, ANR error and AsyncTask

Ok, today I'm going to run of test of my app with monkeyrunner. I saw somewhere that it was a one-line unix command, and recorded it somewhere in my blog. But, I don't think there's a global search, on this, so I'm just going to google it.

Ok, it's not monkeyrunner, it's monkey:

The monkeyrunner tool is not related to the UI/Application Exerciser Monkey, also known as the monkey tool. The monkey tool runs in an adb shell directly on the device or emulator and generates pseudo-random streams of user and system events. In comparison, the monkeyrunner tool controls devices and emulators from a workstation by sending specific commands and events from an API.

Here we go:

http://developer.android.com/guide/developing/tools/monkey.html

Overview

The Monkey is a command-line tool that that you can run on any emulator instance or on a device.

It sends a pseudo-random stream of user events into the system, which acts as a stress test on the application software you are developing.

The Monkey includes a number of options, but they break down into four primary categories:

Basic configuration options, such as setting the number of events to attempt.

// ok

Operational constraints, such as restricting the test to a single package.

//ok

Event types and frequencies.

// ok

Debugging options.

// ok. Lots of stuff.

When the Monkey runs, it generates events and sends them to the system.

// ok

It also watches the system under test and looks for three conditions, which it treats specially:


If you have constrained the Monkey to run in one or more specific packages, it watches for attempts to navigate to any other packages, and blocks them.

// ok

If your application crashes or receives any sort of unhandled exception, the Monkey will stop and report the error.

// ok

If your application generates an application not responding error, the Monkey will stop and report the error.

// ok

Depending on the verbosity level you have selected, you will also see reports on the progress of the Monkey and the events being generated.

// ok



Basic Use of the Monkey

You can launch the Monkey using a command line on your development machine or from a script.

// ok

Because the Monkey runs in the emulator/device environment, you must launch it from a shell in that environment.

// ok

You can do this by prefacing adb shell to each command, or by entering the shell and entering Monkey commands directly.

The basic syntax is:

$ adb shell monkey [options]

With no options specified, the Monkey will launch in a quiet (non-verbose) mode, and will send events to any (and all) packages installed on your target.


Here is a more typical command line, which will launch your application and send 500 pseudo-random events to it:


$ adb shell monkey -p your.package.name -v 500

Ok - let's give it a try and see what happens.

$ adb shell monkey -p com.kanjisoft.jlpt -v 500

:Monkey: seed=0 count=500
:AllowPackage: com.kanjisoft.jlpt
:IncludeCategory: android.intent.category.LAUNCHER
:IncludeCategory: android.intent.category.MONKEY
** No activities found to run, monkey aborted.


Do I have to start the app first? No difference. Let's google it.

Ok, I actually have it running in a different directory than the package name, which is com.jlptquiz.app

How did the package names get to be in variance? Is it in the manifest?

Ok, fixed the package name - I had been using a different package name for media storage - and got a bunch of output:

:IncludeCategory: android.intent.category.MONKEY
// Event percentages:
// 0: 15.0%
// 1: 10.0%
// 2: 15.0%
// 3: 25.0%
// 4: 15.0%
// 5: 2.0%
// 6: 2.0%
// 7: 1.0%
// 8: 15.0%
:Switch: #Intent;action=android.intent.action.MAIN;category=android.intent.category.LAUNCHER;launchFlags=0x10000000;component=com.jlptquiz.app/.StartActivity;end
// Allowing start of Intent { act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] cmp=com.jlptquiz.app/.StartActivity } in package com.jlptquiz.app
:Sending Pointer ACTION_DOWN x=234.0 y=197.0
:Sending Pointer ACTION_UP x=238.0 y=190.0
// Rejecting start of Intent { act=android.intent.action.CALL_BUTTON cmp=com.android.contacts/.DialtactsActivity } in package com.android.contacts
:Sending Pointer ACTION_DOWN x=56.0 y=280.0
etc...

Ok, I dunno. Should I try some more stuff? Let's try 5000 events.

Cool. It went in and out of all three displays, changed a lot of stuff, volume control, weird numbers keypads. It didn't crash. How about the data? Let's see if I can pull it in and find anything funky. Nothing obvious.

Let's try it with 50000 events.

Ah, crash. Ok where was it? Interesting, it also left the media player running. I should somehow turn it off in the case of a crash, or destroy. How do you turn it if? Well, turn off the phone, or maybe task killer. So, how did it get that null pointer?

// java.lang.NullPointerException
// at com.jlptquiz.app.QuestionActivity.onListItemClick(QuestionActivity.java:597)


Well, by the looks of the trace, it was some kind of npe on the select listview, obviously when the autoplay was working. That shouldn't have an impact, because in autoplay all the questions are automatically available. But it might be a good idea to sort of make sure they can't select anything while in autoplay mode. I should also make sure that autoplay gets turned off when they exit the program.

Yeah, it's a good idea.

Other things:

- Increase the width of the timeout line

check android:layout_height="8dp" android:paddingLeft="6dp"

- No delay on display if picture on the image screen

check

Turn off the audio on the exit of the app.

It does turn off when it exists normally.

- Disable the listview selection when it's in autoplay mode.

if (this.mAppState.autoPlay) {
getListView().setEnabled(false);
}
else {
getListView().setEnabled(true);
}

check

Ok, let's run monkey again. Pretty good, it caught that problem.

50000 events lasts a long time. But the cool thing is that the app isn't crashing.

Owch. I spoke to soon. It crashed again. Let's see why.

Well, it's in the same place, and it wasn't on timer mode. So, this is the code:

View selView = listView.getChildAt(lastViewPos - position);

// default to incorrect, override later if correct
selView.setBackgroundResource(R.drawable.hilight_gradient_incorrect_drawable);

displayCorrectAnswer(listView); <============ CRASH! npe

So, if the list view is null, how could a selView be gotten from it? It doesn't make any sense. The trace shows that the routine that selects the possible answers was called 4 times, as you might expect. It also shows the correct code was called.

Am I mistaken, or is Pandora definitely playing more commercials since the IPO?

I don't know what to make of this thing. Could it somehow be running two threads? It doesn't look that way from the trace.

Well, I could just put a check for null in and print out that's it's null, which would prove that it's the listView that's null, then let it crash again...

Interesting. When I put this code in:

if (null == listView) {
Log.d(TAG, "List view is null!!!!!!!!!!!!!!!");
}
It flags the last two lines as dead code!

Maybe I'll check for selView, which is more likely.

if (null == selView) {
Log.d(TAG, "selView is null!!!!!!!!!!!!!!!");
}


Yes - it crashed again, and showed the above message. Ok, let's display some more:

if (null == selView) {
Log.d(TAG, "selView is null!!!!!!!!!!!!!!!");
Log.d(TAG, "childCount is : " + childCount);
Log.d(TAG, "lastViewPos is : " + lastViewPos);
Log.d(TAG, "postion is : " + position);
int temp = lastViewPos - position;
Log.d(TAG, "lastViewPos - position) : " + temp);

}


Ok, here we go:

D/QuestionActivity( 1921): selView is null!!!!!!!!!!!!!!!
D/QuestionActivity( 1921): childCount is : 0
D/QuestionActivity( 1921): lastViewPos is : -1
D/QuestionActivity( 1921): postion is : 3
D/QuestionActivity( 1921): lastViewPos - position : -4

So, it might just be question of it's moving so fast that the child count doesn't get set on time or something. Because, how could it select position 3 if the list wasn't even populated? I dunno, could it? It seems far more likely that I'm just not setting the data in the list correctly.

Well, here's the code that fills it up:

int breakLoopCount = 0;

while (cntr < 4) {

breakLoopCount++;

// hack to break loop TODO check cause - looks like it
// keeps coming up with the same answer and can't get out
if (breakLoopCount > 100) {
Log.d(TAG,
"Count is 100; breaking!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!");
break;
}

// get a grouping of words that are as similar as possible
// to select possible answers from
grouping = getWordGrouping(question);

// get potential anwer or guess to list as one of the possible answers
String fullGuess = getRandomAnswer(grouping, startString);

// can't use a choice that's the same as the actual answer
if (fullGuess.equals(question.hiragana)) {
continue;
}

// check if this one is already in answer
if (answerHash.get(fullGuess) != null) {
Log.d(TAG, "possible answer already in hash - skipping! " + fullGuess);
continue;
}

answerHash.put(fullGuess, fullGuess);

mAppState.mAnswerArray[cntr] = fullGuess;

cntr++;

}


While it's a bit suspect with the hack for breaking out when it gets stuck on an answer is a bit suspect, there is not message indicating that occurred, nor any of the other conditions for that matter. Ok, what I'm going to do is check if the child count is zero, and if it is, display a message and write to the log and finish out of the activity.


Ok, here's some workaround code:

// Workaround on bug raised by monkey exerciser
if (0 == childCount){
Toast.makeText(this.mAppState, "System error, ListView is empty, exiting activity", Toast.LENGTH_LONG).show();
Log.d(TAG, "System error, ListView is empty, exiting activity");
finish();
}


Another bug this thing has raised is I think it managed to get the media player running parallel tracks. Well, I'm not sure - but it's supposed to cut short the previous one if a new one comes up, and it seems to be doing that, but then you hear the English coming up.

Ok, this last one crashed on this:

// Allowing start of Intent { cmp=com.jlptquiz.app/.QuestionActivity } in package com.jlptquiz.app
// NOT RESPONDING: com.jlptquiz.app (pid 2543)
ANR in com.jlptquiz.app (com.jlptquiz.app/.QuestionActivity)
Reason: keyDispatchingTimedOut
Load: 4.33 / 4.12 / 3.5


Well, I pressed a few buttons, and it went to this:

/QuestionActivity( 2543): System error, ListView is empty, exiting activity
D/QuestionActivity( 2543): selView is null!!!!!!!!!!!!!!!
D/QuestionActivity( 2543): childCount is : 0
D/QuestionActivity( 2543): lastViewPos is : -1
D/QuestionActivity( 2543): postion is : 2
D/QuestionActivity( 2543): lastViewPos - position) : -3
D/

Apparently blowing right through the finish. What is it finishing, anyway?

Let's try this:

// Workaround on bug raised by monkey exerciser
if (0 == childCount){
Toast.makeText(this.mAppState, "System error, ListView is empty, exiting activity", Toast.LENGTH_LONG).show();
Log.d(TAG, "System error, ListView is empty, exiting activity");
QuestionActivity.this.finish();
}


Let's try again.


Again this:

/dalvikvm( 96): GC_EXPLICIT freed 114K, 39% free 5827K/9479K, external 1646K/2137K, paused 71ms
E/ActivityManager( 96): ANR in com.jlptquiz.app (com.jlptquiz.app/.QuestionActivity)
E/ActivityManager( 96): Reason: keyDispatchingTimedOut
E/Act


Here's a good link on why this might happen:

http://www.randomtools.net/android-anr-keydispatchingtimedout-178.html


"This ANR, or Application Not Responding, error occurs when a process on the main thread takes too long (something like 5 seconds). Android kills that process and any related by design to spare the device's resources.

The solution is to run resource-expensive tasks on another thread, and then post, or update the main thread accordingly. A common use for this is network calls (and this was what my problem was). The following is an example of how to implement this logic, in my case to check if an update is needed:"


So, in my case, it's probably the database update. I'm wondering if it's worth putting it in as a separate thread?

Here's how he does it:

private void checkUpdate() {
SharedPreferences prefs = getPreferences(0);
SharedPreferences.Editor editor = prefs.edit();


// get last and current time
long lastUpdateTime = prefs.getLong("lastUpdateTime", 0);
long time = System.currentTimeMillis() / 1000;

// interval needs to be gt 3600 * 24 since last check
if (lastUpdateTime + 3600 * 24 < time) {
checkNetworkUpdate();
editor.putLong("lastUpdateTime", time);
editor.commit();
}
}



protected void checkNetworkUpdate() {

// Start a thread to do the update
Thread t = new Thread() {
public void run() {

// make the connection
try {
URL updateURL = new URL("http://www.updateurl.com/");
URLConnection conn = updateURL.openConnection();
conn.setConnectTimeout(3000);
Scanner scanner = new Scanner(conn.getInputStream());
scanner.useDelimiter("\\n");

int curVersion = getPackageManager().getPackageInfo("your.package.name", 0).versionCode;
int newVersion = 0;
if (scanner.hasNext())
newVersion = Integer.valueOf(scanner.next());

final boolean displayUpdate = newVersion > curVersion;

// This will run back on the UI thread once it's completed
runOnUiThread(new Runnable() {
public void run() {
handleNetworkReply(displayUpdate);
}
});
} catch (Exception e) {}
}
};
t.start();
}


// this is called when the time-consuming task is completed
private void handleNetworkReply(boolean displayUpdate) {


if (displayUpdate) {
(new AlertDialog.Builder(this)).setMessage("An update is available!\n\nOpen Android Market to see the details?")
.setTitle("Update Available")
.setPositiveButton("Yes", new DialogInterface.OnClickListener() {
public void onClick(DialogInterface dialog, int whichButton) {
Intent intent = new Intent(Intent.ACTION_VIEW, Uri.parse("market://details?id=your.package.name"));
startActivity(intent);
}
})
.setNegativeButton("No", null)
.create()
.show();
}
}



Well, I'm interested in this. I'd like to speed up the response time, more so than worrying about the monkey error.


Ok, I've added that logic. Basically the same, except I made it a runnable in order to pass parameters so that the run method could access.

Ok, there is nothing in the schedules right now. Let's try.


AudioFlinger( 68): write blocked for 166 msecs, 47 delayed writes, thread 0xea50
I/Process ( 3868): Sending signal. PID: 3868 SIG: 9
I/ActivityManager( 96): Process com.jlptquiz.app (pid 3868) has died.
I/WindowManager( 96): WIN DEATH: Window{40781470 com.jlptquiz.app/com.jlptquiz.app.StartActivity paused=false}
W/InputManagerService( 96): Got RemoteException sending setActive(false) notification to pid 3868 uid 10061

Interesting. The process manager sent a sig 9. Actually, why am I not doing this as an AsyncThread?

Ok, converting it to an AsyncTask works. Sweet. And the update is sooo much faster - instantaneous. And the data checks out. Next I'll run monkey exerciser. But, for now, it's a wrap!

No comments:

Post a Comment