Issue 891842  has been merged into this issue.

http://g/chromeos-chatty-eng/YAAkxrVjxe8 may be relevant.

In the meantime, are you okay with updating the test to (also?) match the truncated version, James?

we're tracking the rework in issue 887875.  might be worth spending time in addressing that rather than pushing the hacks around some more.

+sky

fwiw, i bisected to https://chromium-review.googlesource.com/c/chromium/src/+/1239371, though from the comments it seems the real bug lies somewhere else.

It seems to fail pretty consistently on caroline, tricky and minnie now.

As James says, this is likely because of  issue 772099 .

I'm OK with modifying the test to look for "--mash*". I spent a while last year trying to sort out a similar problem and failed to figure it out.

sammiequon Re #4 - is it possible that CL changed the command line length, which might affect where truncations happened?

Workaround CL: https://chromium-review.googlesource.com/c/chromiumos/platform/tast-tests/+/1260054

My patch shouldn't have impacted CommandLine at all.

Re #7: I was in the middle of a bisect before the other bug got merged, so i thought i finish it and post my findings in case it helps. I didn't dig too deeper since it seemed like this was under control, but happy to take a closer look if needed!

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/platform/tast-tests/+/f95075b921b5041b81dc53cdae911c5bfb83239e

commit f95075b921b5041b81dc53cdae911c5bfb83239e
Author: James Cook <jamescook@chromium.org>
Date: Fri Oct 05 06:00:17 2018

tast-tests: Use arg prefix for mash processes in ui.MashLogin

Chrome sometimes truncates arguments in its command line.
Instead of looking for "mash-service-name", just look for
"mash-". The command line problem is issue 887875

BUG= chromium:891470 ,chromium:887875
TEST=this is the test

Change-Id: I812ffd147ec36148cd6185b73510dfef40b70135
Reviewed-on: https://chromium-review.googlesource.com/c/1260054
Tested-by: James Cook <jamescook@chromium.org>
Trybot-Ready: James Cook <jamescook@chromium.org>
Reviewed-by: Dan Erat <derat@chromium.org>
Reviewed-by: James Cook <jamescook@chromium.org>

[modify] https://crrev.com/f95075b921b5041b81dc53cdae911c5bfb83239e/src/chromiumos/tast/local/bundles/cros/ui/mash_login.go

One of the runs after this landed passed, but a couple runs have been failing, just showing missing "--mash-s" instead of "--mash-service-name"

Yeah, I think this is still a real problem. Here's a recent failure:

https://stainless.corp.google.com/search?exclude_retried=true&first_date=2018-10-03&master_builder_name=&builder_name_number=&shard=&exclude_acts=true&builder_name=-tot-chrom.*-pfq-informational%24&master_builder_name_number=&owner=&retry=&exclude_cts=false&exclude_non_production=false&hostname=&board=%5Etricky%24&test=%5Etast%5C..*Mash&suite=&build=%5ER71%5C-11129%5C.0%5C.0%5C-b3009867%24&status=FAIL&status=ERROR&status=ABORT&reason=&waterfall=&exclude_not_run=false&last_date=2018-10-05&exclude_non_release=false&exclude_au=true&model=&view=list

There are a variety of .dmp files here, including:

     │   ├── chromium-ash-minidump-1c1d1f24b5b199f4.dmp.txt [0 Bytes]
     │   ├── cryptohome.14135.dmp.txt [6.6 kB]
     │   ├── cryptohomed.871.dmp.txt [41.4 kB]
     │   └── tcsd.834.dmp.txt [9.1 kB]

I don't know what chromium-ash-minidump is, nor tcsd.

Hypothesis: Some other regression came in while dealing with the truncated cmd line problem, and the ash process is crashing. The weird thing is the ash process should show as a chrome crash (it's a chrome utility process.)

Dan, do you know what any of those other processes are?

/var/log/messages shows a chrome crash:

2018-10-05T15:08:26.797141+00:00 WARNING crash_reporter[17047]: [user] Received crash notification for chrome[16579] sig 11, user 1000 group 1000 (ignoring call by kernel - chrome crash; waiting for chrome to call us directly)

Tast logs show a failure at roughly the same time:

2018/10/05 08:08:11 Started test ui.MashLogin
2018/10/05 08:08:11 [08:08:10.241] Restarting ui job
2018/10/05 08:08:13 [08:08:12.175] Waiting for org.chromium.SessionManager D-Bus service
2018/10/05 08:08:13 [08:08:12.210] Asking session_manager to enable Chrome testing
2018/10/05 08:08:13 [08:08:12.216] Waiting for Chrome to write its debugging port to /home/chronos/DevToolsActivePort
2018/10/05 08:08:15 [08:08:14.479] Checking cryptohomed service
2018/10/05 08:08:15 [08:08:14.480] Removing cryptohome for testuser@gmail.com
2018/10/05 08:08:15 [08:08:14.580] Finding OOBE DevTools target
2018/10/05 08:08:15 [08:08:14.733] Connecting to Chrome at ws://127.0.0.1:37769/devtools/page/9990A5696EF6134F3263BD1F6464367E
2018/10/05 08:08:16 [08:08:15.005] Waiting for OOBE
2018/10/05 08:08:21 [08:08:19.987] Logging in as user "testuser@gmail.com"
2018/10/05 08:08:21 [08:08:20.129] Waiting for cryptohome for user "testuser@gmail.com"
2018/10/05 08:08:22 [08:08:21.125] Waiting for OOBE to be dismissed
2018/10/05 08:08:30 [08:08:28.296] Error at mash_login.go:66: No chrome process containing "mash-s"

I see a surprising number of renderers running (22), but no utility processes, which makes me think the ash+ws process isn't running.

tast symbolize on the chromium-ash-minidump shows:

Crash reason:  SIGSEGV /SEGV_MAPERR
Crash address: 0x2b8
Process uptime: not available

Thread 0 (crashed)
 0  chrome!cc::SurfaceLayer::SetFallbackSurfaceId(viz::SurfaceId const&) [optional.h : 612 + 0x0]
    rax = 0x1638a1f361277500   rdx = 0x00003ee409a3ca00
    rcx = 0x0000000000000000   rbx = 0x00003ee409941770
    rsi = 0x00007ffd3c3d8d20   rdi = 0x0000000000000000
    rbp = 0x00007ffd3c3d8c40   rsp = 0x00007ffd3c3d8b40
     r8 = 0x00003ee4099f5380    r9 = 0x0000000000000000
    r10 = 0x0000000000000003   r11 = 0x00003ee40b3661e0
    r12 = 0x00003ee408c335a0   r13 = 0x0000000000000000
    r14 = 0x00007ffd3c3d8d20   r15 = 0x00007ffd3c3d8d20
    rip = 0x00007f79269a1707
    Found by: given as instruction pointer in context
 1  chrome!ui::Layer::SetFallbackSurfaceId(viz::SurfaceId const&) [layer.cc : 805 + 0x5]
    rbx = 0x00003ee409941770   rbp = 0x00007ffd3c3d8c70
    rsp = 0x00007ffd3c3d8c50   r12 = 0x00003ee408c335a0
    r13 = 0x00003ee408c97180   r14 = 0x00003ee40931a500
    r15 = 0x00007ffd3c3d8d20   rip = 0x00007f7923b5552c
    Found by: call frame info
 2  chrome!ws::ClientRoot::OnFirstSurfaceActivation(viz::SurfaceInfo const&) [client_surface_embedder.cc : 49 + 0x8]
    rbx = 0x00003ee409941770   rbp = 0x00007ffd3c3d8ca0
    rsp = 0x00007ffd3c3d8c80   r12 = 0x00003ee408c335a0
    r13 = 0x00003ee408c97180   r14 = 0x00003ee409941700
    r15 = 0x00007ffd3c3d8d20   rip = 0x00007f7924d2352a
    Found by: call frame info
 3  chrome!viz::mojom::FrameSinkManagerClientStubDispatch::Accept(viz::mojom::FrameSinkManagerClient*, mojo::Message*) [frame_sink_manager.mojom.cc : 2205 + 0x6]
    rbx = 0x00003ee40a821368   rbp = 0x00007ffd3c3d8eb0
    rsp = 0x00007ffd3c3d8cb0   r12 = 0x00003ee408c335a0
    r13 = 0x00003ee408c97180   r14 = 0x00007ffd3c3d8f20
    r15 = 0x00007ffd3c3d8f20   rip = 0x00007f79201dcd7d
    Found by: call frame info
 4  chrome!mojo::InterfaceEndpointClient::HandleIncomingMessageThunk::Accept(mojo::Message*) [interface_endpoint_client.cc : 423 + 0x6]
    rbx = 0x0000000000000000   rbp = 0x00007ffd3c3d8f00
    rsp = 0x00007ffd3c3d8ec0   r12 = 0x00003ee408c97140
    r13 = 0x00003ee408c97180   r14 = 0x00007ffd3c3d8f20
    r15 = 0x00007ffd3c3d90d8   rip = 0x00007f79224a95e0
    Found by: call frame info
 5  chrome!mojo::internal::MultiplexRouter::ProcessIncomingMessage(mojo::internal::MultiplexRouter::MessageWrapper*, mojo::internal::MultiplexRouter::ClientCallBehavior, base::SequencedTaskRunner*) [interface_endpoint_client.cc : 306 + 0xb]
...

sky has already landed a fix in https://chromium.googlesource.com/chromium/src/+/12ef71460252b042f52da8eddc26adf641e2d50b so this should go away shortly

Thank you for looking into this James!

#13: I don't understand Autotest's logic for determining which crashes and logs to collect. The files under tast/results/crashes are the ones that the tast process collects, and they're just the ones that appeared between when testing started and ended.

Test is green on the builders now.

I still see a few "No chrome process containing "mash-s" among [...]" failures, oddly both on scarlet-arcnext:

http://stainless/browse/chromeos-autotest-results/247580820-chromeos-test/
http://stainless/browse/chromeos-autotest-results/247795193-chromeos-test/

James, any ideas?

@derat - This is the same command-line truncation problem. For example, one process contains "--message-loop-type-ui --mash e=ash". I think that should be "--mash-service-name=ash" but the middle got eaten.

Maybe scarlet-arcnext has additional command-line switches that cause truncation to happen more.

We really need a fix for the command-line issue 887875, which is currently unassigned. I tried to fix it a few months ago, but my low-level POSIX-fu is weak.

In the mean time, do you think I should just skip the part of the test that looks for the command line switch?

Skipping the check seems like the only approach for now until the command line is fixed.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/platform/tast-tests/+/ae7903f4abf6c3e4eb554f11effb282e00e3e466

commit ae7903f4abf6c3e4eb554f11effb282e00e3e466
Author: James Cook <jamescook@chromium.org>
Date: Wed Oct 17 16:07:14 2018

tast-tests: Don't parse command line in ui.MashLogin

This avoids flaky failures due to command line arguments sometimes
being truncated by Chrome's implementation of setproctitle().

BUG= chromium:891470 
TEST=Tast ui.MashLogin

Change-Id: I911961ea09a4a8c48db70c1d25d8f6449948f26f
Reviewed-on: https://chromium-review.googlesource.com/c/1281682
Reviewed-by: Dan Erat <derat@chromium.org>
Tested-by: James Cook <jamescook@chromium.org>

[modify] https://crrev.com/ae7903f4abf6c3e4eb554f11effb282e00e3e466/src/chromiumos/tast/local/bundles/cros/ui/mash_login.go