977589 - Android sutAgent truncates environment variables (like NSPR_LOG_MODULES) that contain commas

Status: RESOLVED WONTFIX

(Firefox for Android Graveyard :: General, defect)

Description

[(no longer active)]

Over in bug 968200, we're trying to use the NSPR_LOG_MODULES environment variable to get NSPR logs for several modules.  Setting that environment variable to "nsSocketTransport:5,DocLoader:5,URILoader:5,HelperAppService:5" only gives us the socket transport logs.  We're thinking that perhaps Android is messing up the environment variable string because of its size of something.  Removing the "nsSocketTransport:5," from that string gives us the full log for the other three.

Comment 1

[Geoff Brown [:gbrown]]

From http://mozilla-releng-blobs.s3.amazonaws.com/blobs/try/sha512/72a6599308cf32556167b1ba9a183b80e0e9f9d66cf182adc7d93677a8112dd3103c3aa2c738a4184b92c013926e36fec8b6d6e838de3ae5cfe82e3c7534af63:

02-25 14:20:36.671 I/SUTAgentAndroid( 1897): 10.12.131.23 : exec "MOZ_CRASHREPORTER=1,XPCOM_DEBUG_BREAK=stack,MOZ_HIDE_RESULTS_TABLE=1,XPCOM_MEM_BLOAT_LOG=/tmp/tmpPngbXP/runtests_leaks.log,MOZ_CRASHREPORTER_NO_REPORT=1,NO_EM_RESTART=1,NSPR_LOG_FILE=/mnt/sdcard/tests/nspr.log,NSPR_LOG_MODULES=nsSocketTransport:5,DocLoader:5,URILoader:5,HelperAppService:5,MOZ_PROCESS_LOG=/tmp/tmpEE6U1upidlog" org.mozilla.fennec -no-remote -profile /mnt/sdcard/tests/profile/ http://mochi.test:8888/tests/?autorun=1&closeWhenDone=1&logFile=%2Fmnt%2Fsdcard%2Ftests%2Flogs%2Fmochitest.log&fileLevel=INFO&consoleLevel=INFO&totalChunks=8&thisChunk=8&hideResultsTable=1&testManifest=android.json&runOnly=true&dumpOutputDirectory=%2Fmnt%2Fsdcard%2Ftests
...
02-25 14:20:37.890 D/GeckoLoader( 2222): env20: NSPR_LOG_MODULES=nsSocketTransport:5

Maybe a short-coming in the sutagent's exec command?

Comment 2

[Geoff Brown [:gbrown]]

The sutagent's exec command allows for an environment argument preceding the command. The format of that space-delimited argument is <env1>,<env2>,...,<envN>, where <envN> is <name>=<value>. There is no escaping or quoting allowed -- no way to include a comma (or a space or equal sign) in either <name> or <value>.

I think we would need to update sutagent to allow commas in Android environment variables -- time to fix + at least a couple of weeks for testing and distribution to test slaves.


Obviously NSPR_LOG_MODULES=all:5 would be painful, but perhaps that would provide a workaround for the time being.

Comment 3

[(no longer active)]

Nice find Geoff, thanks for working on this! :-)

Comment 4

[(no longer active)]

FWIW the all:5 workaround didn't work, see bug 968200 comment 148.

Comment 5

[Geoff Brown [:gbrown]]

This looks like it might be very useful here: http://stackoverflow.com/questions/19241010/string-tokenizer-split-string-by-comma-and-ignore-comma-in-double-quotes?rq=1

Comment 6

[Geoff Brown [:gbrown]]

Here are some promising results using strings copied from logcats and:

input.split("\"?(,|$)(?=(([^\"]*\"){2})*[^\"]*$) *\"?")


MOZ_CRASHREPORTER=1,XPCOM_DEBUG_BREAK=stack,MOZ_HIDE_RESULTS_TABLE=1,MOZ_CRASHREPORTER_NO_REPORT=1,NO_EM_RESTART=1,MOZ_PROCESS_LOG=/tmp/tmpYjeNH6pidlog,XPCOM_MEM_BLOAT_LOG=/tmp/tmpn0FJ7i/runtests_leaks.log
-------------
MOZ_CRASHREPORTER=1
XPCOM_DEBUG_BREAK=stack
MOZ_HIDE_RESULTS_TABLE=1
MOZ_CRASHREPORTER_NO_REPORT=1
NO_EM_RESTART=1
MOZ_PROCESS_LOG=/tmp/tmpYjeNH6pidlog
XPCOM_MEM_BLOAT_LOG=/tmp/tmpn0FJ7i/runtests_leaks.log
=============
MOZ_CRASHREPORTER=1,XPCOM_DEBUG_BREAK=stack,MOZ_HIDE_RESULTS_TABLE=1,MOZ_CRASHREPORTER_NO_REPORT=1,NO_EM_RESTART=1,MOZ_PROCESS_LOG=/tmp/tmpYjeNH6pidlog,XPCOM_MEM_BLOAT_LOG=/tmp/tmpn0FJ7i/runtests_leaks.log,NSPR_LOG_MODULES=nsSocketTransport:5
-------------
MOZ_CRASHREPORTER=1
XPCOM_DEBUG_BREAK=stack
MOZ_HIDE_RESULTS_TABLE=1
MOZ_CRASHREPORTER_NO_REPORT=1
NO_EM_RESTART=1
MOZ_PROCESS_LOG=/tmp/tmpYjeNH6pidlog
XPCOM_MEM_BLOAT_LOG=/tmp/tmpn0FJ7i/runtests_leaks.log
NSPR_LOG_MODULES=nsSocketTransport:5
=============
MOZ_CRASHREPORTER=1,XPCOM_DEBUG_BREAK=stack,MOZ_HIDE_RESULTS_TABLE=1,MOZ_CRASHREPORTER_NO_REPORT=1,NO_EM_RESTART=1,MOZ_PROCESS_LOG=/tmp/tmpYjeNH6pidlog,XPCOM_MEM_BLOAT_LOG=/tmp/tmpn0FJ7i/runtests_leaks.log,"NSPR_LOG_MODULES=nsSocketTransport:5,DocLoader:5"
-------------
MOZ_CRASHREPORTER=1
XPCOM_DEBUG_BREAK=stack
MOZ_HIDE_RESULTS_TABLE=1
MOZ_CRASHREPORTER_NO_REPORT=1
NO_EM_RESTART=1
MOZ_PROCESS_LOG=/tmp/tmpYjeNH6pidlog
XPCOM_MEM_BLOAT_LOG=/tmp/tmpn0FJ7i/runtests_leaks.log
NSPR_LOG_MODULES=nsSocketTransport:5,DocLoader:5
=============

Note that the entire "x=y" is quoted in the above example. I would prefer to support x="y", which seems more natural for our application, but that does not quite work with this regex:

MOZ_CRASHREPORTER=1,XPCOM_DEBUG_BREAK=stack,MOZ_HIDE_RESULTS_TABLE=1,MOZ_CRASHREPORTER_NO_REPORT=1,NO_EM_RESTART=1,MOZ_PROCESS_LOG=/tmp/tmpYjeNH6pidlog,XPCOM_MEM_BLOAT_LOG=/tmp/tmpn0FJ7i/runtests_leaks.log,NSPR_LOG_MODULES="nsSocketTransport:5,DocLoader:5"
-------------
MOZ_CRASHREPORTER=1
XPCOM_DEBUG_BREAK=stack
MOZ_HIDE_RESULTS_TABLE=1
MOZ_CRASHREPORTER_NO_REPORT=1
NO_EM_RESTART=1
MOZ_PROCESS_LOG=/tmp/tmpYjeNH6pidlog
XPCOM_MEM_BLOAT_LOG=/tmp/tmpn0FJ7i/runtests_leaks.log
NSPR_LOG_MODULES="nsSocketTransport:5,DocLoader:5
===========
(Note the " in the NSPR_LOG_MODULES value.)

I tried to find a regex that supports x="y", but my approach became unreasonably complex. I expect we would only exercise this feature (sutagent exec command with quoted environment string) from a small number of python scripts, and perhaps only for NSPR_LOG_MODULES, so I'm not too concerned about requiring the less-natural "x=y" form.

Comment 7

[Geoff Brown [:gbrown]]

I can never seem to find time for this bug - sorry.

It seems less pressing now, because Android 4.3 does not use sutagent and Android 4.0 is being retired, so this is really only a problem for Android 2.3.

fwiw, I thought of another approach for resolving this: Generate a shell script and execute the browser from that script, like we do for remote xpcshell tests:

#!/bin/sh
NSPR_LOG_MODULES=a,b,c,...
MOZ_CRASHREPORTER=1
XPCOM_DEBUG_BREAK=stack
...
am start ... org.mozilla.fennec -no-remote -profile /mnt/sdcard/tests/profile/ http://mochi.test:8888/tests/?autorun=1&closeWhenDone=1&logFile=%2Fmnt%2Fsdcard%2Ftests%2Flogs%2Fmochitest.log&fileLevel=INFO&consoleLevel=INFO&totalChunks=8&thisChunk=8&hideResultsTable=1&testManifest=android.json&runOnly=true&dumpOutputDirectory=%2Fmnt%2Fsdcard%2Ftests

I'm sure that "am start" needs work and equally sure that there would be complications with url encoding, etc.

Comment 8

[Geoff Brown [:gbrown]]

The Android/Java version of sutagent is being removed in bug 1255527. (Negatus remains in use at this time.)