Closed Bug 754873 Opened 8 years ago Closed 7 years ago

fennec automated tests should capture logcat output while test is running

Categories

(Testing :: General, defect)

ARM
Android
defect
Not set

Tracking

(Not tracked)

RESOLVED FIXED
mozilla16

People

(Reporter: vlad, Assigned: jmaher)

References

Details

Attachments

(2 files, 3 obsolete files)

In a test result such as https://tbpl.mozilla.org/php/getParsedLog.php?id=11727341&tree=Try&full=1 , it would be very helpful to have the logcat output for the full run of the actual test (from app/test launch to finish).  The only logcat-y bits that I see are stuff that's dumped during reboot, but that seems to have the interesting bits already out of the buffer.
Looks like /system/bin/logcat exists on devices; something like:

First flush/clear the logcat output before running a test:
  /system/bin/logcat -c

Then after a test, dump to a file:
  /system/bin/logcat -d -f outfile.txt

and then pull outfile.txt over.

(/system/bin/logcat -? will show some other options)
this patch does two things:
1) allows for remote reftest to be used as a harness and not a script.  I found that if there was an exception, we were calling sys.exit(..).  Also passing in args was impossible.

2) what this bug is titled.  This is the logcat information and appears to work fairly reasonable.  This does not cover the entire history of logcat during the test run.  What this does is capture the relevant logcat information that it finds in the log buffer shortly before the app finished/quit.

This could use some cleanup, but it gets the ball rolling.
Assignee: nobody → jmaher
Attachment #628493 - Flags: feedback?(wlachance)
Comment on attachment 628493 [details] [diff] [review]
add logcat output to reftest (0.9)

In general looks ok. I have some architectural nits, but if it's urgent to get more information I would be ok with this going in as-is.

--

Nit #1:

I would prefer to add some commands to manipulate/save logcats at the devicemanager level. I've already written such code for Eideticker:

https://github.com/mozilla/eideticker/blob/49bf9cdb0f8ffe2295b5a5c20f62a34afb0fc0ef/src/eideticker/eideticker/device.py#L67

The fact that you've written very similar code is a sign that we should try and solve this problem at a higher level of abstraction. :) I think it should be possible to come up with a nice API for this.

Nit #2:

+    for line in data:
+        if not line.startswith("D/dalvikvm") and \
+           not line.startswith("V/WifiMonitor") and \
+           not line.startswith("V/WifiStateTracker") and \
+           not line.startswith("D/ConnectivityService") and \
+           not line.startswith("I/wpa_supplicant"):

I'd prefer if we could filter these out beforehand and I believe we can by doing something like:

<foo>:S

e.g.

logcat dalvikvm:S

See here for more info:

http://www.herongyang.com/Android/Debug-adb-logcat-Command-Argument-Output-Filter.html
Attachment #628493 - Flags: feedback?(wlachance) → feedback+
I have a similar need in B2G, which I've also solved with a one-off.  Note that logcat only stores some maximum amount of data in the log (on my device it is 2MB; but it may vary); if there is more data than that, it deletes lines at the top of the log.  So if there is > 2MB of data (which happens easily with mochitest), just doing logcat -d at the end of the test run won't give you everything.

For B2G I'm thinking of spinning a thread to read the realtime output of logcat (no arguments) to avoid this issue.
I am open to anything.  If we can do a thread or something similar in sutagent or thereabouts, I am very open to capturing the logcat output for the entire test run.  

:wlach, thanks for the tips, I will look at filtering out the biggest noisemakers via logcat commandline.
this patch is updated with some of the feedback.  This puts an api in devicemanager to record and retrieve logcat information.  I have tested this on try server and we get the appropriate logcat information in the logs!  Also this works well for local sut or adb usage.

What this doesn't do is spin it off in a thread, so we are limited by the buffer size.  I think for now that is acceptable, but with the way the API is designed we can replace the devicemanager bits to do that successfully.

In addition, I clean up the remotereftest script so that we can treat it as a module rather than a shell script.
Attachment #628493 - Attachment is obsolete: true
Attachment #630972 - Flags: review?(wlachance)
Comment on attachment 630972 [details] [diff] [review]
collect logcat information on mochitest + reftest (2.0)

Thanks for following up on this. Looks good. I have just one serious problem with this patch. In this function in dmADB/dmSUT:

+  def getLogcat(self, filename):
+    #TODO: when recordLogcat spawns off, this will just terminate the collector
+    self.checkCmdAs(["shell", "/system/bin/logcat", "-d", "-f", "%s/logcat.log" % self.getDeviceRoot(), "dalvikvm:S ConnectivityService:S WifiMonitor:S WifiStateTracker:S wpa_supplicant:S NetworkStateTracker:S"])
+
+    self.getFile('%s/logcat.log' % self.getDeviceRoot(), 'logcat.log')
+    fHandle = open('logcat.log')
+    data = fHandle.readlines()
+    fHandle.close()
+    return data

You don't clean up either the local or remote version of logcat.log after using it. Also, you're not using the filename parameter AFAICT. This is a bit messy. I think we can do better.

I think we can replace both these functions with a simpler version in devicemanager. Something like:

def getLogCat(self):
  buf = StringIO.StringIO()
  if self.shell(["/system/bin/logcat", "-d", "dalvikvm:S ConnectivityService:S WifiMonitor:S WifiStateTracker:S wpa_supplicant:S NetworkStateTracker:S"], buf) != 0:
    return None
  return str(buf.getvalue()[0:-1]).rstrip()

I also would recommend putting all this logcat stuff in droid.py's DroidSUT or DroidADB classes (and then modifying mochitest to use those), as this is VERY android-specific.
Attachment #630972 - Flags: review?(wlachance) → review-
(In reply to William Lachance (:wlach) from comment #7)
> Comment on attachment 630972 [details] [diff] [review]

> I also would recommend putting all this logcat stuff in droid.py's DroidSUT
> or DroidADB classes (and then modifying mochitest to use those), as this is
> VERY android-specific.

Actually I guess this stuff would be usable by B2G as well. Disregard that comment, probably best to just put this in devicemanager for now.
to do this via self.shell(), won't work without modifying devicemanagerSUT shell to add a su -c.
See bug 754873 on making execute-as-root the default inside the agent.
Sorry, seems like I have a case of the Mondays. I mean bug 763497.
updated and tested on try server.
Attachment #630972 - Attachment is obsolete: true
Attachment #632677 - Flags: review?(wlachance)
Comment on attachment 632677 [details] [diff] [review]
collect logcat information on mochitest + reftest (3.0)

Looks good now, thanks. We may eventually want to make the logging settings configurable, but we can do that later.
Attachment #632677 - Flags: review?(wlachance) → review+
https://hg.mozilla.org/mozilla-central/rev/3bffe02b6223
Status: NEW → RESOLVED
Closed: 8 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla16
Is this only for reftests? It would be nice to have this for all android tests (such as to diagnose the talos redness currently happening on inbound)
I have a patch for talos, but it creates red jobs due to the log parsing stuff.  I think it finds strings in the logcat output and marks the job red.
Is the patch on a bug somewhere? It would still be useful for me if I can push it to try and get logcat output.
and the bugs eventually get resolved
Attachment #669679 - Flags: review?(jhammel)
not sure why this was resolved, it is reopened now.
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
thanks to :wlach for reminding me about the devicemanager api for doing this.  Simplified code, tested locally == WIN!
Attachment #669679 - Attachment is obsolete: true
Attachment #669679 - Flags: review?(jhammel)
Attachment #669693 - Flags: review?(jhammel)
Comment on attachment 669693 [details] [diff] [review]
talos should output logcat information (2.0)

lgtm
Attachment #669693 - Flags: review?(jhammel) → review+
http://hg.mozilla.org/build/talos/rev/066af6a96478
Status: REOPENED → RESOLVED
Closed: 8 years ago7 years ago
Resolution: --- → FIXED
Depends on: 801633
Depends on: 1048836
You need to log in before you can comment on or make changes to this bug.