New issue
Advanced search Search tips

Issue 668497 link

Starred by 2 users

Issue metadata

Status: Fixed
Owner:
Closed: Nov 2016
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 3
Type: Bug



Sign in to add a comment

Two strange tree closings

Project Member Reported by kolos@chromium.org, Nov 24 2016

Issue description


* The build didn't find message_filter.o, but single CL in blamelist didn't affect on that file. http://build.chromium.org/p/chromium.linux/builders/Linux%20Builder%20%28dbg%29%2832%29/builds/60417 

* A lot of messages like "ninja explain: *.o dirty". The build has failed. https://build.chromium.org/p/chromium/builders/Linux%20x64/builds/29050

Infra guys recommended to file a bug to GOMA team.
 
If this is related to https://bugs.chromium.org/p/chromium/issues/detail?id=668548, we might see errors saying cannot write to /tmp or so?
http://build.chromium.org/p/chromium.linux/builders/Linux%20Builder%20%28dbg%29%2832%29/builds/60417:
https://luci-logdog.appspot.com/v/?s=chromium%2Fbb%2Fchromium.linux%2FLinux_Builder__dbg__32_%2F60417%2F%2B%2Frecipes%2Fsteps%2Fcompile%2F0%2Fstdout

zgrep Task:18773 compiler_proxy.build45-m1.chrome-bot.log.INFO.20161124-040520.16310.gz 
I1124 04:41:16.843917 16329 compile_task.cc:988] Task:18773 Start ../../ipc/message_filter.cc gomacc_pid=3307 build_dir=/b/c/b/linux/src/out/Debug
I1124 04:41:17.009543 16319 multi_http_rpc.cc:137] Task:18773 rpc multi: Task:18773 Task:18776 Task:18775 Task:18774
I1124 04:41:23.868113 16331 subprocess_task.cc:240] Task:18773 started pid=3838 state=RUN
I1124 04:41:26.129853 16319 multi_http_rpc.cc:189] Task:18773 rpc multi done: Task:18773 Task:18776 Task:18775 Task:18774
I1124 04:41:26.131141 16329 compile_task.cc:2013] Task:18773 goma finished, killing subproc pid=3838
I1124 04:41:26.142369 16331 subprocess_task.cc:251] Task:18773 terminated pid=3838 status=137
I1124 04:41:26.142488 16329 compile_task.cc:4939] Task:18773 finished subprocess. pid=3838 status=137 pending_ms=1352 run_ms=2274 mem_kb=0 local_killed=1
I1124 04:41:26.142688 16329 compile_task.cc:2416] Task:18773 CommitOutput num=2: message_filter.o message_filter.o.d
I1124 04:41:26.142717 16329 compile_task.cc:2426] Task:18773 ReplyResponse: goma success (cache hit)

$ zgrep id=7054 compiler_proxy-subproc.build45-m1.chrome-bot.log.INFO.20161124-040521.16312.gz 
I1124 04:41:22.514458 16312 subprocess_controller_server.cc:184] id=7054 Register Task:18773
I1124 04:41:23.867044 16312 subprocess_impl.cc:38] id=7054 spawn Task:18773
I1124 04:41:23.867871 16312 subprocess_controller_server.cc:273] id=7054 Started pid=3838
I1124 04:41:26.131348 16312 subprocess_impl.cc:98] id=7054 kill Task:18773 pid=3838 child_signaled=0 running=1
I1124 04:41:26.132580 16312 subprocess_impl.cc:111] id=7054 Signaled Task:18773 pid=3838 status=137
I1124 04:41:26.142257 16312 subprocess_controller_server.cc:279] id=7054 Terminated status=137

Mmm, CommitOutput did not fail?
https://luci-logdog.appspot.com/v/?s=chromium%2Fbb%2Fchromium%2FLinux_x64%2F29050%2F%2B%2Frecipes%2Fsteps%2Fcompile%2F0%2Fstdout
$ zgrep Task:6202 compiler_proxy.build48-m1.chrome-bot.log.INFO.20161124-043902.12601.gz 
I1124 04:40:20.631865 12615 compile_task.cc:988] Task:6202 Start ../../third_party/libvpx/source/libvpx/vp9/encoder/x86/vp9_dct_intrin_sse2.c gomacc_pid=5779 build_dir=/b/c/b/linux_clobber/src/out/Release
I1124 04:40:20.633568 12615 compile_task.cc:3856] Task:6202 use deps cache. required_files=55
I1124 04:40:20.659983 12615 multi_http_rpc.cc:137] Task:6187 rpc multi: Task:6187 Task:6188 Task:6189 Task:6190 Task:6191 Task:6192 Task:6193 Task:6194 Task:6195 Task:6196 Task:6197 Task:6198 Task:6199 Task:6200 Task:6201 Task:6202
I1124 04:40:20.919113 12621 subprocess_task.cc:240] Task:6202 started pid=5896 state=RUN
I1124 04:40:20.921484 12615 multi_http_rpc.cc:189] Task:6187 rpc multi done: Task:6187 Task:6188 Task:6189 Task:6190 Task:6191 Task:6192 Task:6193 Task:6194 Task:6195 Task:6196 Task:6197 Task:6198 Task:6199 Task:6200 Task:6201 Task:6202
I1124 04:40:20.924777 12615 compile_task.cc:2013] Task:6202 goma finished, killing subproc pid=5896
I1124 04:40:20.957995 12621 subprocess_task.cc:251] Task:6202 terminated pid=5896 status=0
I1124 04:40:20.960268 12615 compile_task.cc:4939] Task:6202 finished subprocess. pid=5896 status=0 pending_ms=281 run_ms=30 mem_kb=0 local_killed=1
I1124 04:40:20.960474 12615 compile_task.cc:2416] Task:6202 CommitOutput num=2: vp9_dct_intrin_sse2.o vp9_dct_intrin_sse2.o.d
I1124 04:40:20.960517 12615 compile_task.cc:2426] Task:6202 ReplyResponse: goma success (cache hit)

$ zgrep 'id=1337 ' compiler_proxy-subproc.build48-m1.chrome-bot.log.INFO.20161124-043903.12603.gz
I1124 04:40:20.633869 12603 subprocess_controller_server.cc:184] id=1337 Register Task:6202
I1124 04:40:20.915096 12603 subprocess_impl.cc:38] id=1337 spawn Task:6202
I1124 04:40:20.918881 12603 subprocess_controller_server.cc:273] id=1337 Started pid=5896
I1124 04:40:20.938184 12603 subprocess_impl.cc:98] id=1337 kill Task:6202 pid=5896 child_signaled=0 running=1
I1124 04:40:20.943905 12603 subprocess_impl.cc:111] id=1337 Signaled Task:6202 pid=5896 status=0
I1124 04:40:20.949018 12603 subprocess_controller_server.cc:279] id=1337 Terminated status=0

In both cases, local process has been killed.   Mmm, did local process actually keep on working and did something bad???

Comment 4 by ukai@chromium.org, Nov 25 2016

I suspect nacl toolchain is python wrapper, so wrapper was terminated before terminating real compiler toolchain, so goma thinks local process terminated, but keep running local compiler for a while.

workaround would be GOMA_DONT_KILL_SUBPROCESS=true (or set GOMA_DON_KILL_COMMANDS as windows?)
Project Member

Comment 5 by bugdroid1@chromium.org, Nov 25 2016

The following revision refers to this bug:
  https://chrome-internal.googlesource.com/goma/client/+/93cc946da386562ca249f887498abed937ed6c74

commit 93cc946da386562ca249f887498abed937ed6c74
Author: Fumitoshi Ukai <ukai@google.com>
Date: Fri Nov 25 02:34:46 2016

Comment 6 by ukai@chromium.org, Nov 25 2016

Owner: ukai@chromium.org
Status: Fixed (was: Available)
VERSION=119 sets GOMA_DONT_KILL_SUBPROCESS=true by default

Comment 7 by joedy....@gmail.com, Nov 25 2016

Pada 25 Nov 2016 13:43, "u… via monorail" <
monorail+v2.992337184@chromium.org> menulis:

Sign in to add a comment