Closed Bug 1398057 Opened 3 years ago Closed 3 years ago

Not all command arguments are printed to the log

Categories

(Testing :: geckodriver, enhancement, P1)

57 Branch
enhancement

Tracking

(firefox57 fixed)

RESOLVED FIXED
mozilla57
Tracking Status
firefox57 --- fixed

People

(Reporter: whimboo, Assigned: whimboo)

References

Details

Attachments

(1 file)

That is the output I see when running geckodriver:

> 1504859605253	geckodriver::marionette	INFO	Starting browser /data/code/gecko/obj/debug/dist/NightlyDebug.app/Contents/MacOS/firefox with args ["-marionette"]

So there is no output of the profile, because in rust_mozrunner it gets directly added to the command but not to `self.args`:

https://github.com/jgraham/rust_mozrunner/blob/master/src/runner.rs#L128-L130

So whether we have a chance to print the command itself in geckodriver, or we should really add all arguments to `self.args`. I really would vote for the second option.
Flags: needinfo?(james)
I don't know what the question is here. We add the profile at the end because we only add it if there isn't another one specified. So we can't directly add it to self.args. mozrunner will print the command at debug level, so the simplest solution would be to change that to info and remove the log from geckodriver.
Flags: needinfo?(james)
So any logging from mozrunner is currently not visible due to some filtering of crates as done here:

https://searchfox.org/mozilla-central/rev/44c693914255638d74bcf1ec3b0bcd448dfab2fd/testing/geckodriver/src/logging.rs#133

I can add mozrunner to the exclusion list, so that its log output will appear in the geckodriver log. I will create a PR for mozrunner, to change the logging from `debug!` to `info!`.
mozrunner changes got merged via https://github.com/jgraham/rust_mozrunner/pull/13.

I will put work on hold on this bug until a new version has been released.
Assignee: nobody → hskupin
Status: NEW → ASSIGNED
With bug 1388251 I'm going to upgrade mozrunner to 0.5. And as such I will update the necessary code pieces there.
Depends on: 1388251
Asking already for review given the simplicity of the changes. But it would need a rebase for the changes on bug 1388251 before I can push to try.
Comment on attachment 8907437 [details]
Bug 1398057 - Not all command arguments are printed to the log.

https://reviewboard.mozilla.org/r/179126/#review184238

::: testing/geckodriver/src/logging.rs:134
(Diff revision 1)
>      fn format(&self, io: &mut io::Write, record: &Record, _: &OwnedKeyValueList) -> io::Result<()> {
>          // TODO(ato): Quite sure this is the wrong way to filter records with slog,
>          // but I do not comprehend how slog works.
>          let module = record.module();
> -        if module.starts_with("geckodriver") || module.starts_with("webdriver") {
> +        if module.starts_with("geckodriver") || module.starts_with("webdriver") ||
> +                module.starts_with("mozrunner") {

Indentation is weird.
Attachment #8907437 - Flags: review?(james) → review+
Comment on attachment 8907437 [details]
Bug 1398057 - Not all command arguments are printed to the log.

https://reviewboard.mozilla.org/r/179126/#review184238

> Indentation is weird.

I used the 8 chars to avoid clashing with the first line inside the if condition. Maybe we should move the opening bracket to the next line instead?

        if module.starts_with("geckodriver") || module.starts_with("webdriver") ||
            module.starts_with("mozrunner")
        {
            let ts = format_ts(Local::now());
Comment on attachment 8907437 [details]
Bug 1398057 - Not all command arguments are printed to the log.

https://reviewboard.mozilla.org/r/179126/#review184238

> I used the 8 chars to avoid clashing with the first line inside the if condition. Maybe we should move the opening bracket to the next line instead?
> 
>         if module.starts_with("geckodriver") || module.starts_with("webdriver") ||
>             module.starts_with("mozrunner")
>         {
>             let ts = format_ts(Local::now());

This is a digression, but please could we just succumb to rustfmt?
I believe they recently added a new “default Rust style”
proposed in an RFC.  Discussions about indentation should be a thing
of the past.
Comment on attachment 8907437 [details]
Bug 1398057 - Not all command arguments are printed to the log.

https://reviewboard.mozilla.org/r/179126/#review184238

> This is a digression, but please could we just succumb to rustfmt?
> I believe they recently added a new “default Rust style”
> proposed in an RFC.  Discussions about indentation should be a thing
> of the past.

The problem with rustfmt at the moment is it's non-trivial to run. You have to install unstable rust and be sure not to try to build against stable, or build the ol version by mistake.

> I used the 8 chars to avoid clashing with the first line inside the if condition

It should line up with the condition on the first line.
Comment on attachment 8907437 [details]
Bug 1398057 - Not all command arguments are printed to the log.

https://reviewboard.mozilla.org/r/179126/#review184238

> The problem with rustfmt at the moment is it's non-trivial to run. You have to install unstable rust and be sure not to try to build against stable, or build the ol version by mistake.
> 
> > I used the 8 chars to avoid clashing with the first line inside the if condition
> 
> It should line up with the condition on the first line.

Better now?
We're sorry, Autoland could not rebase your commits for you automatically. Please manually rebase your commits and try again.

hg error in cmd: hg rebase -s 92c5377438f7 -d e392e524801b: rebasing 419809:92c5377438f7 "Bug 1398057 - Not all command arguments are printed to the log. r=jgraham" (tip)
merging testing/geckodriver/CHANGES.md
warning: conflicts while merging testing/geckodriver/CHANGES.md! (edit, then use 'hg resolve --mark')
unresolved conflicts (see hg resolve, then hg rebase --continue)
We're sorry, Autoland could not rebase your commits for you automatically. Please manually rebase your commits and try again.

hg error in cmd: hg rebase -s 92c5377438f7 -d 763af7d6686d: rebasing 419809:92c5377438f7 "Bug 1398057 - Not all command arguments are printed to the log. r=jgraham"
merging testing/geckodriver/CHANGES.md
warning: conflicts while merging testing/geckodriver/CHANGES.md! (edit, then use 'hg resolve --mark')
unresolved conflicts (see hg resolve, then hg rebase --continue)
Priority: -- → P1
Pushed by hskupin@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/e9b5426100ed
Not all command arguments are printed to the log. r=jgraham
https://hg.mozilla.org/mozilla-central/rev/e9b5426100ed
Status: ASSIGNED → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla57
You need to log in before you can comment on or make changes to this bug.