3. Logcat
Granted, the errors we debugged in the last section were pretty
straightforward—no different from debugging in any other environment.
But most applications are not as simple as DebugTest, and many problems
are much harder to isolate and solve. Android provides a general-purpose
logging facility that can help with many of those more difficult
problems.
As mentioned before, there’s a logcat pane on the Debug perspective (it’s also in the DDMS perspective). The log for DebugTest isn’t very
interesting, so instead start MJAndroid in Debug mode and we’ll take a
look at its log.
After the application comes up in the emulator, Eclipse switches to the Debug Perspective and shows the
logcat pane on the lower right, as it looks in Figure 10.
To make the pane large enough to be useful for reading the
log, click on the “full screen” symbol at the upper right of
the pane, and it will expand to fill the Eclipse window. You will then
see that there are hundreds of log messages in the file, going back to
when Eclipse first started the instantiation of the emulator that you
are using, continuing through the boot process for Android, loading all
the applications, and finally loading and executing MJAndroid. How are
you supposed to find anything useful in all of that?
Luckily, Android provides you with some handy filters to apply to
the logfile. See the V, D, I, W, and E symbols in the toolbar? These
filters successively narrow the scope of messages displayed, as
follows:
V (Verbose)
Show everything
D (Debug)
Show Debug, Information, Warning, and Error messages
(equivalent to V for now)
I (Information)
Show Information, Warning, and Error messages
W (Warning)
Show Warning and Error messages
E (Error)
Show only Error messages
The columns displayed for the log are:
Time
The time the log entry was made
Priority (the column is not actually labeled)
One of the log entry types from the previous list (D, I, W,
or E)
pid
The Linux process ID of the process making the entry
tag
A short tag describing the source of the entry
Message
The log entry itself
About two-thirds of the way through the log (if you started a new
emulator when you brought up MJAndroid), you’ll see a message entry
something like:
11-28 12:10:31.475: INFO/ActivityManager(52): Start proc com.microjobsinc.mjandroid
for activity com.microjobsinc.mjandroid/.MicroJobs:
pid=163 uid=10017 gids={3003}
which actually appears all on one line; we’ve broken it here so it
will fit on a printed page.
This is a log message from the Activity Manager telling us that it
started MicroJobs with process ID 163 (it will probably be different as
you run it). If you click on the green cross at the top of the logcat
pane, it will let you define a custom filter. Fill in a random name and
the pid number that you saw in the log. Now the log is filtered to show
only the messages that apply to this instance of MicroJobs. There are
likely still a lot of messages, which you can filter further (using the
D, I, W, and E buttons) or just scan.
If you ask other people for help debugging an error in your own
program, one of the first things you’ll likely be asked for is a copy
of the logcat output. You can easily extract the content of the
logfile to a text file by selecting what you’d like to preserve and
clicking on the little down arrow at the upper right of the logcat
pane, which brings down a pull-down menu. One of the selections on the
menu is “Export Selection as Text...”, which takes you to a dialog
where you can name an output file for the log text. |
|
3.1. Looking at logcat to solve runtime errors
Logcat gives you a lot of information about what happened as Android tried to run your program. It
is very useful when you get a generic error message from Android that
doesn’t tell you much. Let’s demonstrate one of my (least)
favorites.
In Eclipse, go to main.xml
for MJAndroid and remove the apiKey line under the MapView declaration (save it in a text
file or somewhere, so you can restore it; we’re doing this just to
generate an error). The apiKey is
needed to access mapping information, so removing it brings the
program to a screeching halt. When you run the program, the emulator
screen looks like Figure 11.
Although it’s good to know that the application stopped, the
message tells us very little about why. If you now look at the logcat
output in the Debug perspective (or the DDMS perspective), you’ll find
something like this after MicroJobs starts up, all in red type (we’ve
left off the first few columns so it will fit):
java.lang.RuntimeException: Unable to start activity
ComponentInfo{com.microjobsinc.mjandroid/com.microjobsinc.mjandroid.MicroJobs}:
android.view.InflateException: Binary XML file line #8: Error
inflating class java.lang.reflect.Constructor
at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2140)
at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:2156)
at android.app.ActivityThread.access$1800(ActivityThread.java:112)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1580)
at android.os.Handler.dispatchMessage(Handler.java:88)
at android.os.Looper.loop(Looper.java:123)
at android.app.ActivityThread.main(ActivityThread.java:3742)
at java.lang.reflect.Method.invokeNative(Native Method)
at java.lang.reflect.Method.invoke(Method.java:515)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:739)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:497)
at dalvik.system.NativeStart.main(Native Method)
Caused by: android.view.InflateException: Binary XML file line #8: Error
inflating class
java.lang.reflect.Constructor
at android.view.LayoutInflater.createView(LayoutInflater.java:512)
at android.view.LayoutInflater.createViewFromTag(LayoutInflater.java:564)
at android.view.LayoutInflater.rInflate(LayoutInflater.java:617)
at android.view.LayoutInflater.inflate(LayoutInflater.java:407)
at android.view.LayoutInflater.inflate(LayoutInflater.java:320)
at android.view.LayoutInflater.inflate(LayoutInflater.java:276)
at
com.android.internal.policy.impl.PhoneWindow.setContentView(PhoneWindow.java:227)
at android.app.Activity.setContentView(Activity.java:1569)
at com.microjobsinc.mjandroid.MicroJobs.onCreate(MicroJobs.java:132)
at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1122)
at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2103)
... 11 more
Caused by: java.lang.reflect.InvocationTargetException
at com.google.android.maps.MapView.<init>(MapView.java:227)
at java.lang.reflect.Constructor.constructNative(Native Method)
at java.lang.reflect.Constructor.newInstance(Constructor.java:424)
at android.view.LayoutInflater.createView(LayoutInflater.java:499)
... 21 more
Caused by: java.lang.IllegalArgumentException: You need to specify an API Key for
each MapView.
See the MapView documentation
for details.
at com.google.android.maps.MapView.<init>(MapView.java:263)
at com.google.android.maps.MapView.<init>(MapView.java:244)
... 25 more
The first three errors basically tell us that Android could not
start our application because it could not inflate the Views it found
in our layout file. The last error block we showed in the output
clearly tells us we need an API Key for each MapView. Logcat is often
the best way to get insight into errors where there isn’t specific
information otherwise.
3.2. Writing your own logcat entries
To write your own entries from your application into logcat,
Android provides methods corresponding to the different entry
priorities. The methods are all of the form:
Log.x(String tag, String message, [Throwable exception])
where x can be v, d,
i, w, or e,
and the optional exception makes it easy to report exceptions that you
didn’t anticipate in your code but encounter within a try/catch block.
For example, look at the onItemSelected method for
the Spinner in
MicroJobs.java:
try {
mc.animateTo(mMyLocationOverlay.getMyLocation());
}
catch (Exception e) {
Log.i("MicroJobs", "Unable to animate map", e);
}
mvMap.invalidate();
