1119838 - Error in ADBDevice when "adb" executable not in path isn't intuitive

Status: RESOLVED FIXED

(Testing :: Mozbase, defect)

Description

[William Lachance (:wlach)]

We emit a rather unintuitive OSError exception when we can't find the adb executable. I wonder if we should try to do something a bit more comprehensible for this at least somewhat common occurrence?

https://bugzilla.mozilla.org/show_bug.cgi?id=1118967#c2

Comment 1

[Bob Clary [:bc] (inactive)]

It probably make senses to check if the specified adb exists and is excecutable in the ADBCommand constructor and to raise a specific ADBError("adb executable %s not found" % adb) or something similar. It would happen quickly and be easily identifiable.

Comment 2

[Julien Pagès (:parkouss)]

I can work on this, if you are interested. I have some though about it:

Testing if an executable exists and is in PATH is *quite* complicated in python 2. Here is an example here:

http://stackoverflow.com/questions/377017/test-if-executable-exists-in-python

Instead, maybe just a try/except OSError around the subprocess.Popen call may be sufficient, but it will appears in the ADBProcess constructor instead I suppose.

Do you have a preference on this ? Also, if you prefer testing the executable presence before, I wonder if it could be useful to add this fonctionality to the mozfile module instead. Something like `mozfile.which`.

Comment 3

[Bob Clary [:bc] (inactive)]

Even if we did have a which capability, I'd rather not have to do this check every time we try to execute an adb command. With that said, implementing a mozfile.which might be useful for other use cases than this bug. If you would like to work on that, please file a new bug for it.

Trying to catch the exceptions thrown by Popen in ADBProcess also seems like overkill and tricky to get right. It seems that while we could catch the OSError 2 No such file or directory error if ADBCommand._adb_path does not exist or is not on the path or catch OSError 13 Permission denied error if it weren't executable, it isn't clear to me those are the only possibilities. It would be trickier to determine if subprocess.CalledProcessError was a result of the adb not being executable or due to some other non-zero return code. In addition, if adb isn't available, we should check earlier rather than later.

If we are soley concerned with adb not being executable then I would vote for a simple check in ADBCommand's constructor that tried to call adb and raised an ADBError if it wasn't available. Note that simply calling adb without arguments will result in a return code of 1, so we would need to do something like adb help which would be expected to succeed if adb were availabe.

try:
  (out,err) = subprocess.Popen([self._adb_path, 'help'],
                           stdout=subprocess.PIPE,
                           stderr=subprocess.PIPE).communicate()
except Exception:
  m = 'adb %s is not executable' % self._adb_path
  self.logger.exception(m)
  raise ADBError(m)

Comment 4

[William Lachance (:wlach)]

I think I'd prefer not to go in the direction of adding `mozfile.which`, as I suspect the behaviour would be difficult to get exactly right between Windows and UNIX and I don't think it would be that useful. For this particular problem, I think bc's solution sounds good.

Comment 5

[Bob Clary [:bc] (inactive)]

The (out,err) =  isn't necessary since they aren't used anywhere.

Comment 6

[Julien Pagès (:parkouss)]

Attachment: Raise exception early when there is no adb command available

Comment 7

[Bob Clary [:bc] (inactive)]

Comment on attachment 8549086 [details] [diff] [review]
Raise exception early when there is no adb command available

Review of attachment 8549086 [details] [diff] [review]:
-----------------------------------------------------------------

The use of |call| was interesting in that it doesn't raise exceptions, but having to deal with the output makes it less optimal I think.

Fix up the patch and I'll re-review it and check it in for you. Thanks!

::: testing/mozbase/mozdevice/mozdevice/adb.py
@@ +147,5 @@
>                                         self.__dict__))
>  
> +        # catch early a missing or non executable adb command
> +        try:
> +            subprocess.call([adb])

This will always dump the output of adb to stdout and stderr which will add unnecessary noise to the logs. call shouldn't be used with PIPEs so please use

subprocess.Popen([adb, 'help'],
                 stdout=subprocess.PIPE,
                 stderr=subprocess.PIPE).communicate()

@@ +152,5 @@
> +        except Exception, exc:
> +            msg = "Unable to find the adb executable `%s` (%s)"  % (adb, exc)
> +            self._logger.exception(msg)
> +            raise ADBError(msg)
> +

I'm not fond of the back tics and we log the exception and its stack via self._logger.exception(msg) there is no need to include the exception twice in the log message and I'm not clear as to the value for it in the ADBError. What was wrong with

except Exception:
  m = 'adb %s is not executable' % adb
  self.logger.exception(m)
  raise ADBError(m)

?

Comment 8

[Julien Pagès (:parkouss)]

(In reply to Bob Clary [:bc:] from comment #7)
> This will always dump the output of adb to stdout and stderr which will add
> unnecessary noise to the logs. call shouldn't be used with PIPEs so please
> use

Nice catch. :)


> I'm not fond of the back tics and we log the exception and its stack via
> self._logger.exception(msg) there is no need to include the exception twice
> in the log message and I'm not clear as to the value for it in the ADBError.

Well I thought that some consumers may find the information useful - but I am not aware of them,
and if there are all displaying log then it is fine. For mozregression it is fine as we use mozlogger.


In fact there is just a thing: I just tested "logger.exception" with mozlogger, and it appears that
the method does not exists - I will use "logger.error" instead, which works with both mozlog and
logging modules.


The whole thing is that I would have just raised the error, without logging at all - that is why I
put the real exception information in the new exception message. In mozregression (or any consumer)
we could then just do a try, then log on error if we want to - which will look like:

 0:00.00 LOG: MainThread ERROR adb executable adb not found (No such file or directory)

With this implementation we will have two error message, I suppose something like:

 0:00.00 LOG: MainThread adb ERROR No such file or directory
 0:00.00 LOG: MainThread ERROR adb executable adb not found

(my patch was bad because it mixed the two!) Well, that said, having two lines of
errors is also fine for me.

I will fix the patch as you recommended, then r? when done (probably tomorrow).

Comment 9

[Julien Pagès (:parkouss)]

Hum sorry, I made a mistake in my last comment, because we won't have

 0:00.00 LOG: MainThread adb ERROR No such file or directory
 0:00.00 LOG: MainThread ERROR adb executable adb not found

But rather

 0:00.00 LOG: MainThread adb ERROR db executable adb not found
 0:00.00 LOG: MainThread ERROR adb executable adb not found

Well I suppose in mozregression we will have to sys.exit on this error and not log since we will have the same error printed twice else. Hum that bother me a bit, because it will be a special case (every other exception we handle is just printed before exiting). William, do you have an opinion on this ?

Comment 10

[Bob Clary [:bc] (inactive)]

Mmm... Thanks for looking into the situation with logging. I hate that we've implemented an incompatible logger but oh well...

How about we not log in the except block and just raise the error and deal with it later. We can include the exception in the message for informational purposes.

except Exception, e:
  raise ADBError('%s: adb %s is not executable.' % (e, adb))

Comment 11

[Julien Pagès (:parkouss)]

Yup, fine for me. I will update the patch tomorrow.

Comment 12

[Julien Pagès (:parkouss)]

Attachment: Raise exception early when there is no adb command available

I updated the patch. One thing to note, I adjusted the error message to '%s: %s is not executable.' else on error with default args the message would have shown adb twice:

mozdevice.adb.ADBError: [Errno 2] No such file or directory: adb adb is not executable.

Comment 13

[Bob Clary [:bc] (inactive)]

Comment on attachment 8550704 [details] [diff] [review]
Raise exception early when there is no adb command available

Review of attachment 8550704 [details] [diff] [review]:
-----------------------------------------------------------------

Looks good, thanks!

Comment 14

[William Lachance (:wlach)]

Inbound: https://hg.mozilla.org/integration/mozilla-inbound/rev/5a4a637be054

Comment 15

[Phil Ringnalda (:philor)]

https://hg.mozilla.org/mozilla-central/rev/5a4a637be054

Comment 16

[Bob Clary [:bc] (inactive)]

https://github.com/mozilla/autophone/commit/73c2ea0de10009c2ffb77c446ac85ff3c43a7a28