980427 - Panda logcat dump in test log double spaced (additional newline after every line)

Status: RESOLVED WONTFIX

(Release Engineering :: General, defect)

Description

[Ed Morley [:emorley]]

eg:
09:42:53     INFO -  Mochi-Remote INFO | Device info: {'uptime': ['0 days 0 hours 6 minutes 27 seconds 832 ms'], 'sutuserinfo': [], 'power': ['Power status:', ' AC power OFFLINE', ' Battery charge NO BATTERY', ' Remaining charge: 0%', ' Battery Temperature: 0.0 (c)'], 'process': [['10043', '1903', 'com.mozilla.SUTAgentAndroid'], ['10047', '2287', 'org.mozilla.fennec.UpdateService'], ['10036', '2022', 'com.android.quicksearchbox'], ['10017', '1993', 'com.android.gallery3d'], ['10028', '1979', 'com.svox.pico'], ['10008', '2007', 'com.android.musicfx'], ['10027', '1963', 'com.android.defcontainer'], ['10014', '1545', 'com.android.inputmethod.latin'], ['10045', '1536', 'net.rocboronat.android.wallpaper.npe'], ['10007', '1647', 'com.android.smspush'], ['1001', '1577', 'com.android.phone'], ['1000', '1402', 'system'], ['10001', '1631', 'android.process.acore'], ['10038', '1799', 'com.android.providers.calendar'], ['10021', '1859', 'com.android.calendar'], ['10030', '1817', 'com.android.deskclock'], ['10024', '1590', 'com.android.launcher'], ['10031', '1726', 'com.android.email'], ['10033', '1742', 'com.android.exchange'], ['10000', '1518', 'android.process.media'], ['1000', '1562', 'com.android.settings'], ['10044', '1833', 'com.mozilla.watcher'], ['1000', '1504', 'com.android.systemui'], ['10032', '1764', 'com.android.mms']], 'screen': ['X:1280 Y:672'], 'memory': ['PA:742322176, FREE: 549572608'], 'systime': ['2014/03/06 09:42:52:878'], 'rotation': ['ROTATION:0'], 'disk': ['/data: 534761472 total, 379224064 available', '/system: 534761472 total, 185085952 available', '/mnt/sdcard: 8573165568 total, 8541200384 available'], 'os': ['pandaboard-eng 4.0.4 IMM76I 5 test-keys'], 'id': ['2e:60:15:bd:49:01'], 'uptimemillis': ['387871'], 'temperature': ['Temperature: 40.6']}
09:42:53     INFO -  Mochi-Remote INFO | Test root: /mnt/sdcard/tests
09:42:53     INFO - Return code: 0
09:42:53     INFO - Output logcat...
09:42:54     INFO - Connecting to: panda-0188
09:42:54     INFO - *** STARTING LOGCAT ***
09:42:54     INFO - --------- beginning of /dev/log/main
09:42:54     INFO - 
09:42:54     INFO - 03-06 09:41:24.937 I/SUTAgentAndroid( 1903): 10.12.129.18 : isdir /mnt/sdcard/tests
09:42:54     INFO - 
09:42:54     INFO - 03-06 09:41:24.984 I/SUTAgentAndroid( 1903): 10.12.129.18 : isdir /mnt/sdcard/tests
09:42:54     INFO - 
09:42:54     INFO - 03-06 09:41:24.984 I/SUTAgentAndroid( 1903): 10.12.129.18 : cd /mnt/sdcard/tests
09:42:54     INFO - 
09:42:54     INFO - 03-06 09:41:25.054 I/SUTAgentAndroid( 1903): 10.12.129.18 : ls

https://tbpl.mozilla.org/php/getParsedLog.php?id=35731646&tree=Mozilla-Inbound

Android 4.0 Panda mozilla-inbound opt test mochitest-7 on 2014-03-06 09:30:36 PST for push d65a803d2b9a

slave: panda-0188

Comment 1

[Justin Wood (:Callek)]

Geoff/Armen could one of you throw this on your todo lists to peek at?

Comment 2

[Ed Morley [:emorley]]

iirc this started around the time we switched to mozharness for pandas?

The "*** STARTING LOGCAT ***" comes from:
https://hg.mozilla.org/build/mozharness/file/bf050bb8b3a0/scripts/android_panda.py#l264
   260                 if tbpl_status != TBPL_SUCCESS:
   261                     self.info("Output logcat...")
   262                     try:
   263                         lines = self.get_logcat()
   264                         self.info("*** STARTING LOGCAT ***")
   265                         for l in lines:
   266                             self.info(l)
   267                         self.info("*** END LOGCAT ***")

self.get_logcat():
https://hg.mozilla.org/build/mozharness/file/bf050bb8b3a0/mozharness/mozilla/testing/device.py#l658
   658     def get_logcat(self):
   659         dm = self.query_devicemanager()
   660         return dm.getLogcat()

dm.getLogcat():
https://hg.mozilla.org/build/tools/file/a059eca4973d/sut_tools/mozdevice/devicemanager.py#l563
   563     def getLogcat(self):
   564         """
   565         Returns the contents of the logcat file as a string
   566 
   567         returns:
   568           success: contents of logcat, string
   569           failure: None
   570         """
   571         buf = StringIO.StringIO()
   572         if self.shell(["/system/bin/logcat", "-d", "dalvikvm:S", "ConnectivityService:S", "WifiMonitor:S", "WifiStateTracker:S", "wpa_supplicant:S", "NetworkStateTracker:S"], buf, root=True) != 0:
   573             return None
   574 
   575         return str(buf.getvalue()[0:-1]).rstrip().split('\r')

Comment 3

[Ed Morley [:emorley]]

Note the in-tree mozdevice seems quite a bit newer & getLogcat() a bit more refined:
http://mxr.mozilla.org/mozilla-central/source/testing/mozbase/mozdevice/mozdevice/devicemanager.py#127

Comment 4

[Armen [:armenzg]]

I got no cycles to look into this.

I hope we're using the right version of mozdevice rather than the one under sut_tools.

Comment 5

[Justin Wood (:Callek)]

we pretty assuredly should be the in-tree one:

http://hg.mozilla.org/build/mozharness/filelog/bf050bb8b3a0/mozharness/mozilla/mozbase.py

perhaps we should rope dminor about this at the same time. Either way I presume this is low priority for all involved

Comment 6

[Ed Morley [:emorley]]

(In reply to Justin Wood (:Callek) from comment #5)
> we pretty assuredly should be the in-tree one:

Ah great :-)

> Either way I presume this is low priority for all involved

Yup

Comment 7

[Kim Moir [:kmoir] ET]

closing since we are decomming pandas in bug 1186615