New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 901322 link

Starred by 1 user

Issue metadata

Status: Duplicate
Merged: issue 900962
Owner:
User never visited
Closed: Nov 2
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 1
Type: Bug



Sign in to add a comment

crosvm failed to start after flash to 11219.0.0

Project Member Reported by cylee@chromium.org, Nov 2

Issue description

I could not start VM on the latest image (11219.0.0). The problem also happens on my local build of crosvm.

2018-11-02T04:05:58.375164-07:00 INFO vm_concierge[10408]: Received StartVm request
2018-11-02T04:05:58.376324-07:00 INFO seneschal[10410]: Received request to start new 9p server
2018-11-02T04:05:58.376865-07:00 WARNING seneschal[10410]: libminijail[1]: non-debug build: ignoring request to enable seccomp logging
2018-11-02T04:05:58.378035-07:00 INFO seneschal[10410]: Started server on /run/seneschal/scoped_dir_5XdBzv
2018-11-02T04:05:58.382371-07:00 INFO kernel: [  486.477092] tun: Universal TUN/TAP device driver, 1.6
2018-11-02T04:05:58.382396-07:00 INFO kernel: [  486.477104] tun: (C) 1999-2004 Max Krasnyansky <maxk@qualcomm.com>
2018-11-02T04:05:58.398615-07:00 INFO localhos[10441]: crosvm[4]: [src/linux.rs:770] crosvm entering multiprocess mode
2018-11-02T04:05:58.405552-07:00 INFO crash_reporter[10409]: Processing selinux violation: always collect from developer builds
2018-11-02T04:05:58.405952-07:00 INFO crash_reporter[10409]: Accessing crash dir '/var/spool/crash' via symlinked handle '/proc/self/fd/9'
2018-11-02T04:05:58.406104-07:00 WARNING crash_reporter[10409]: Failed to write audit message to /proc/self/fd/9/selinux_violation.20181102.110558.0.log: File exists
2018-11-02T04:05:58.419411-07:00 INFO crash_reporter[10443]: libminijail[32]: mount '/dev/log' -> '/dev/log' type '' flags 0x1001
2018-11-02T04:05:58.422756-07:00 INFO crosvm[10441]: libminijail[4]: mount 'none' -> '/' type 'tmpfs' flags 0xe
2018-11-02T04:05:58.422768-07:00 INFO crosvm[10441]: libminijail[4]: mount '/run/chrome' -> '/wayland' type '' flags 0x1000
2018-11-02T04:05:58.433809-07:00 WARNING localhos[10441]: crosvm[4]: [src/linux.rs:854] failed to add stdin to poll context: Error(1)
2018-11-02T04:05:58.516356-07:00 WARNING kernel: [  486.610772] Pid 1(crosvm) over core_pipe_limit
2018-11-02T04:05:58.516369-07:00 WARNING kernel: [  486.610776] Skipping core dump
2018-11-02T04:05:58.518247-07:00 INFO crash_reporter[10463]: libminijail[10463]: mount '/dev/log' -> '/dev/log' type '' flags 0x1001
2018-11-02T04:05:58.519367-07:00 WARNING kernel: [  486.613684] Pid 1(crosvm) over core_pipe_limit
2018-11-02T04:05:58.519375-07:00 WARNING kernel: [  486.613688] Skipping core dump
2018-11-02T04:05:58.520965-07:00 INFO crash_reporter[10464]: libminijail[10464]: mount '/dev/log' -> '/dev/log' type '' flags 0x1001
2018-11-02T04:05:58.520973-07:00 INFO crash_reporter[10465]: libminijail[10465]: mount '/dev/log' -> '/dev/log' type '' flags 0x1001
2018-11-02T04:05:58.521172-07:00 INFO crash_reporter[10466]: libminijail[10466]: mount '/dev/log' -> '/dev/log' type '' flags 0x1001
2018-11-02T04:05:58.521465-07:00 INFO crash_reporter[10443]: Processing selinux violation: always collect from developer builds
2018-11-02T04:05:58.521754-07:00 INFO crash_reporter[10443]: Accessing crash dir '/var/spool/crash' via symlinked handle '/proc/self/fd/9'
2018-11-02T04:05:58.521855-07:00 WARNING crash_reporter[10443]: Failed to write audit message to /proc/self/fd/9/selinux_violation.20181102.110558.0.log: File exists
2018-11-02T04:05:58.524419-07:00 ERR localhos[10441]: crosvm[4]: [src/linux.rs:954] child 9 died: signo 17, status 31, code 2
2018-11-02T04:05:58.529818-07:00 WARNING crash_reporter[10463]: [user] Received crash notification for crosvm[10445] sig 31, user 299 group 299 (developer build - not testing - always dumping)
2018-11-02T04:05:58.530742-07:00 INFO crash_reporter[10463]: State of crashed process [10445]: S (sleeping)
2018-11-02T04:05:58.530921-07:00 INFO crash_reporter[10463]: Accessing crash dir '/var/spool/crash' via symlinked handle '/proc/self/fd/6'
2018-11-02T04:05:58.530970-07:00 INFO crash_reporter[10470]: libminijail[33]: mount '/dev/log' -> '/dev/log' type '' flags 0x1001
2018-11-02T04:05:58.534082-07:00 WARNING crash_reporter[10466]: [user] Received crash notification for crosvm[10449] sig 31, user 299 group 299 (developer build - not testing - always dumping)
2018-11-02T04:05:58.534796-07:00 INFO crash_reporter[10466]: State of crashed process [10449]: S (sleeping)
2018-11-02T04:05:58.534811-07:00 WARNING crash_reporter[10464]: [user] Received crash notification for crosvm[10447] sig 31, user 299 group 299 (developer build - not testing - always dumping)
2018-11-02T04:05:58.535008-07:00 INFO crash_reporter[10466]: Accessing crash dir '/var/spool/crash' via symlinked handle '/proc/self/fd/6'
2018-11-02T04:05:58.535436-07:00 WARNING crash_reporter[10465]: [user] Received crash notification for crosvm[10446] sig 31, user 299 group 299 (developer build - not testing - always dumping)
2018-11-02T04:05:58.535786-07:00 INFO crash_reporter[10464]: State of crashed process [10447]: S (sleeping)
2018-11-02T04:05:58.536001-07:00 INFO crash_reporter[10464]: Accessing crash dir '/var/spool/crash' via symlinked handle '/proc/self/fd/6'
2018-11-02T04:05:58.536254-07:00 INFO crash_reporter[10465]: State of crashed process [10446]: S (sleeping)
2018-11-02T04:05:58.536475-07:00 INFO crash_reporter[10465]: Accessing crash dir '/var/spool/crash' via symlinked handle '/proc/self/fd/6'
2018-11-02T04:05:58.539773-07:00 INFO crash_reporter[10463]: Stored minidump to /var/spool/crash/crosvm.20181102.190558.10445.dmp
2018-11-02T04:05:58.539961-07:00 INFO crash_reporter[10463]: Leaving core file at /proc/self/fd/6/crosvm.20181102.190558.10445.core due to developer image
2018-11-02T04:05:58.542062-07:00 INFO crash_reporter[10466]: Stored minidump to /var/spool/crash/crosvm.20181102.190558.10449.dmp
2018-11-02T04:05:58.542317-07:00 INFO crash_reporter[10466]: Leaving core file at /proc/self/fd/6/crosvm.20181102.190558.10449.core due to developer image
2018-11-02T04:05:58.545376-07:00 INFO crash_reporter[10464]: Stored minidump to /var/spool/crash/crosvm.20181102.190558.10447.dmp
2018-11-02T04:05:58.545552-07:00 INFO crash_reporter[10464]: Leaving core file at /proc/self/fd/6/crosvm.20181102.190558.10447.core due to developer image
2018-11-02T04:05:58.546203-07:00 INFO crash_reporter[10465]: Stored minidump to /var/spool/crash/crosvm.20181102.190558.10446.dmp
2018-11-02T04:05:58.546376-07:00 INFO crash_reporter[10465]: Leaving core file at /proc/self/fd/6/crosvm.20181102.190558.10446.core due to developer image
2018-11-02T04:05:58.621618-07:00 INFO crash_reporter[10470]: Processing selinux violation: always collect from developer builds
2018-11-02T04:05:58.622058-07:00 INFO crash_reporter[10470]: Accessing crash dir '/var/spool/crash' via symlinked handle '/proc/self/fd/9'
2018-11-02T04:05:58.622247-07:00 WARNING crash_reporter[10470]: Failed to write audit message to /proc/self/fd/9/selinux_violation.20181102.110558.0.log: File exists
2018-11-02T04:05:58.648514-07:00 INFO crash_reporter[10485]: libminijail[34]: mount '/dev/log' -> '/dev/log' type '' flags 0x1001
2018-11-02T04:05:59.186828-07:00 INFO crash_reporter[10485]: Processing selinux violation: always collect from developer builds
2018-11-02T04:05:59.187647-07:00 INFO crash_reporter[10485]: Accessing crash dir '/var/spool/crash' via symlinked handle '/proc/self/fd/9'
2018-11-02T04:05:59.212985-07:00 INFO crash_reporter[10498]: libminijail[35]: mount '/dev/log' -> '/dev/log' type '' flags 0x1001
2018-11-02T04:05:59.312631-07:00 INFO crash_reporter[10498]: Processing selinux violation: always collect from developer builds
2018-11-02T04:05:59.313098-07:00 INFO crash_reporter[10498]: Accessing crash dir '/var/spool/crash' via symlinked handle '/proc/self/fd/9'
2018-11-02T04:05:59.313301-07:00 WARNING crash_reporter[10498]: Failed to write audit message to /proc/self/fd/9/selinux_violation.20181102.110559.0.log: File exists
2018-11-02T04:05:59.336752-07:00 INFO crash_reporter[10501]: libminijail[36]: mount '/dev/log' -> '/dev/log' type '' flags 0x1001
2018-11-02T04:05:59.437652-07:00 INFO crash_reporter[10501]: Processing selinux violation: always collect from developer builds
2018-11-02T04:05:59.438172-07:00 INFO crash_reporter[10501]: Accessing crash dir '/var/spool/crash' via symlinked handle '/proc/self/fd/9'
2018-11-02T04:05:59.438449-07:00 WARNING crash_reporter[10501]: Failed to write audit message to /proc/self/fd/9/selinux_violation.20181102.110559.0.log: File exists
2018-11-02T04:06:00.264050-07:00 NOTICE temp_logger[10530]: 00:60 02:47 03:46 04:49 05:55 06:60 07:47
2018-11-02T04:06:00.468566-07:00 ERR localhos[10441]: crosvm[4]: [devices/src/proxy.rs:177] failed read from child device process: Recv(Error(11))
2018-11-02T04:06:00.549236-07:00 ERR localhos[10441]: crosvm[4]: [devices/src/proxy.rs:173] failed write to child device process: Send(Error(111))
2018-11-02T04:06:02.548538-07:00 ERR localhos[10441]: crosvm[4]: [devices/src/proxy.rs:177] failed read from child device process: Recv(Error(11))
2018-11-02T04:06:02.548630-07:00 ERR localhos[10441]: crosvm[4]: [devices/src/proxy.rs:173] failed write to child device process: Send(Error(111))
2018-11-02T04:06:04.548931-07:00 ERR localhos[10441]: crosvm[4]: [devices/src/proxy.rs:177] failed read from child device process: Recv(Error(11))
2018-11-02T04:06:04.548991-07:00 ERR localhos[10441]: crosvm[4]: [devices/src/proxy.rs:173] failed write to child device process: Send(Error(111))
2018-11-02T04:06:06.548444-07:00 ERR localhos[10441]: crosvm[4]: [devices/src/proxy.rs:177] failed read from child device process: Recv(Error(11))
2018-11-02T04:06:06.548466-07:00 ERR localhos[10441]: crosvm[4]: [devices/src/proxy.rs:173] failed write to child device process: Send(Error(111))
2018-11-02T04:06:08.548943-07:00 ERR localhos[10441]: crosvm[4]: [devices/src/proxy.rs:177] failed read from child device process: Recv(Error(11))
2018-11-02T04:06:08.549000-07:00 ERR localhos[10441]: crosvm[4]: [devices/src/proxy.rs:173] failed write to child device process: Send(Error(111))
2018-11-02T04:06:10.548628-07:00 ERR localhos[10441]: crosvm[4]: [devices/src/proxy.rs:177] failed read from child device process: Recv(Error(11))
2018-11-02T04:06:10.549533-07:00 ERR localhos[10441]: crosvm[4]: [devices/src/proxy.rs:173] failed write to child device process: Send(Error(111))
2018-11-02T04:06:12.549533-07:00 ERR localhos[10441]: crosvm[4]: [devices/src/proxy.rs:177] failed read from child device process: Recv(Error(11))
2018-11-02T04:06:12.549560-07:00 INFO localhos[10441]: crosvm[4]: [src/main.rs:520] crosvm has exited normally


excerpt of the dump file:

MDRawContextAMD64
  p1_home       = 0x0
  p2_home       = 0x0
  p3_home       = 0x0
  p4_home       = 0x0
  p5_home       = 0x0
  p6_home       = 0x0
  context_flags = 0x10000f
  mx_csr        = 0x0
  cs            = 0x33
  ds            = 0x0
  es            = 0x0
  fs            = 0x0
  gs            = 0x0
  ss            = 0x2b
  eflags        = 0x246
  dr0           = 0x0
  dr1           = 0x0
  dr2           = 0x0
  dr3           = 0x0
  dr6           = 0x0
  dr7           = 0x0
  rax           = 0x2f
  rcx           = 0x792739ae3f20
  rdx           = 0x0
  rbx           = 0x17
  rsp           = 0x7ffca9ddbda8
  rbp           = 0x10
  rsi           = 0x7ffca9ddbdc8
  rdi           = 0x17
  r8            = 0x4
  r9            = 0x0
  r10           = 0x20
  r11           = 0x246
  r12           = 0x5965b5b40800
  r13           = 0x0
  r14           = 0x0
  r15           = 0x7ffca9ddbef0
  rip           = 0x792739ae3f20

0x2f is a "sys_recvmsg" syscall.

Reverting https://chromium-review.googlesource.com/c/chromiumos/platform/crosvm/+/1260259/ solved the problem on my local build.
 
Mergedinto: 900962
Status: Duplicate (was: Untriaged)
We have a fix, but the CQ is making things slow to apply to master.

Sign in to add a comment