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

Issue 890844 link

Starred by 3 users
Status: Duplicate
Owner:
briannorris@chromium.org
Closed: Oct 9
Cc:
█ lhchavez@chromium.org
benchan@chromium.org
briannorris@chromium.org
snanda@chromium.org
abhishekbh@chromium.org
█ kbleicher@chromium.org
vapier@chromium.org
dgagnon@chromium.org
█ djmm@chromium.org
█ f...@chromium.org
█ kirtika@chromium.org
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug



Sign in to add a comment

Crash: 085bd65c-exit130-shill

Project Member Reported by kbleicher@google.com, Oct 1 
Large uptick in Chrome OS occurrences from DEV1 (11078.0.0) to DEV2 (11097.0.0).

#1 Chrome OS Crash in M71 Dev (40%)

Guessing at assignment per https://chromium-review.googlesource.com/c/chromiumos/platform2/+/1248324

Report ID6cf2154cc151bbf7
Product, versionChromeOS, 11097.0.0
Process typeservice-failure
Stable Signature085bd65c-exit130-shilledit bugs&comments
Report TimeMon, 01 Oct 2018 16:01:02 GMT
Upload TimeMon, 01 Oct 2018 16:01:02 GMT
Processed TimeMon, 01 Oct 2018 16:01:16 GMT
Client ID987b678bac3445609c7cc253565c0b1e
Filesupload_file_logDownloadView file


===/var/log/messages===
2018-09-28T13:18:06.309623-04:00 INFO kernel: [ 2451.191063] Bluetooth: hci_core.c:skip_conditional_cmd() COND call queue_work.
2018-09-28T13:18:06.342294-04:00 INFO bluetoothd[1982]: adapter /org/bluez/hci0 has been disabled
2018-09-28T13:18:06.429133-04:00 INFO session_manager[8420]: [INFO:android_oci_wrapper.cc(124)] run_oci PID: 8657
2018-09-28T13:18:06.445223-04:00 INFO minijail0[8656]: libminijail[8656]: mount '/' -> '/' type '' flags 0x1001
2018-09-28T13:18:06.445251-04:00 INFO minijail0[8656]: libminijail[8656]: mount '/dev' -> '/dev' type '' flags 0x1001
2018-09-28T13:18:06.445266-04:00 INFO minijail0[8656]: libminijail[8656]: mount '/proc' -> '/proc' type '' flags 0x1001
2018-09-28T13:18:06.445345-04:00 INFO minijail0[8656]: libminijail[8656]: mount 'tmpfs' -> '/run' type 'tmpfs' flags 0xe
2018-09-28T13:18:06.445361-04:00 INFO minijail0[8656]: libminijail[8656]: mount '/run/dbus' -> '/run/dbus' type '' flags 0x1001
2018-09-28T13:18:06.448708-04:00 DEBUG kernel: [ 2451.330129] SELinux: initialized (dev proc, type proc), uses genfs_contexts
2018-09-28T13:18:06.448925-04:00 INFO minijail0[8656]: libminijail[8656]: not running init loop, exiting immediately
2018-09-28T13:18:06.501047-04:00 INFO minijail0[8667]: libminijail[8667]: mount '/' -> '/' type '' flags 0x1001
2018-09-28T13:18:06.501073-04:00 INFO minijail0[8667]: libminijail[8667]: mount '/proc' -> '/proc' type '' flags 0x1001
2018-09-28T13:18:06.501836-04:00 INFO minijail0[8667]: libminijail[8667]: mount '/sys' -> '/sys' type '' flags 0x1001
2018-09-28T13:18:06.501992-04:00 INFO minijail0[8667]: libminijail[8667]: mount 'tmpfs' -> '/run' type 'tmpfs' flags 0xe
2018-09-28T13:18:06.502013-04:00 INFO minijail0[8667]: libminijail[8667]: mount '/run/dbus' -> '/run/dbus' type '' flags 0x1001
2018-09-28T13:18:06.502028-04:00 INFO minijail0[8667]: libminijail[8667]: mount '/run/shill' -> '/run/shill' type '' flags 0x1001
2018-09-28T13:18:06.502082-04:00 INFO minijail0[8667]: libminijail[8667]: mount 'tmpfs' -> '/var' type 'tmpfs' flags 0xe
2018-09-28T13:18:06.502097-04:00 INFO minijail0[8667]: libminijail[8667]: mount '/var/lib/oemcrypto' -> '/var/lib/oemcrypto' type '' flags 0x1000
2018-09-28T13:18:06.503716-04:00 DEBUG kernel: [ 2451.385970] SELinux: initialized (dev proc, type proc), uses genfs_contexts
2018-09-28T13:18:06.508453-04:00 INFO midis[8666]: libminijail[2]: mount '/' -> '/' type '' flags 0x1001
2018-09-28T13:18:06.517106-04:00 INFO midis[8666]: libminijail[2]: mount '/dev' -> '/dev' type '' flags 0x1001
2018-09-28T13:18:06.517236-04:00 INFO midis[8666]: libminijail[2]: mount '/proc' -> '/proc' type '' flags 0x1001
2018-09-28T13:18:06.517278-04:00 INFO midis[8666]: libminijail[2]: mount 'tmpfs' -> '/run' type 'tmpfs' flags 0xe
2018-09-28T13:18:06.517318-04:00 INFO midis[8666]: libminijail[2]: mount '/run/dbus' -> '/run/dbus' type '' flags 0x1001
2018-09-28T13:18:06.518702-04:00 DEBUG kernel: [ 2451.400128] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
2018-09-28T13:18:06.525709-04:00 DEBUG kernel: [ 2451.407285] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
2018-09-28T13:18:06.580697-04:00 DEBUG kernel: [ 2451.462056] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
2018-09-28T13:18:06.580720-04:00 DEBUG kernel: [ 2451.462417] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
2018-09-28T13:18:06.580725-04:00 DEBUG kernel: [ 2451.462622] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
2018-09-28T13:18:06.628238-04:00 DEBUG kernel: [ 2451.509261] SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
2018-09-28T13:18:07.147850-04:00 DEBUG kernel: [ 2452.029521] SELinux: initialized (dev loop5, type squashfs), uses xattr
2018-09-28T13:18:07.159710-04:00 DEBUG kernel: [ 2452.041945] SELinux: initialized (dev loop6, type squashfs), uses xattr
2018-09-28T13:18:07.166843-04:00 DEBUG kernel: [ 2452.048665] SELinux: initialized (dev loop7, type squashfs), uses xattr
2018-09-28T13:18:07.193692-04:00 DEBUG kernel: [ 2452.075239] SELinux: initialized (dev proc, type proc), uses genfs_contexts
2018-09-28T13:18:07.330721-04:00 DEBUG kernel: [ 2452.212584] SELinux: initialized (dev proc, type proc), uses genfs_contexts
2018-09-28T13:18:07.676700-04:00 DEBUG kernel: [ 2452.558145] SELinux: initialized (dev proc, type proc), uses genfs_contexts
2018-09-28T13:18:07.780726-04:00 DEBUG kernel: [ 2452.662811] SELinux: initialized (dev proc, type proc), uses genfs_contexts
2018-09-28T13:18:07.871095-04:00 INFO chrome[8445]: [8445:8445:0928/131807.870904:INFO:remote_commands_invalidator.cc(32)] Initialize RemoteCommandsInvalidator.
2018-09-28T13:18:08.428890-04:00 WARNING minijail0[1091]: libminijail[1091]: child process 1097 received signal 2
2018-09-28T13:18:08.437720-04:00 WARNING kernel: [ 2453.319345] audit_printk_skb: 138 callbacks suppressed
2018-09-28T13:18:08.437756-04:00 NOTICE kernel: [ 2453.319363] audit: type=1400 audit(1538155088.436:402): avc: granted { execute } for pid=8709 comm="init" name="ui-respawn" dev="dm-0" ino=72313 scontext=u:r:cros_init:s0 tcontext=u:object_r:cros_init_shell_scripts:s0 tclass=file
2018-09-28T13:18:08.437762-04:00 NOTICE kernel: [ 2453.319539] audit: type=1400 audit(1538155088.436:403): avc: granted { execute } for pid=8709 comm="init" name="dash" dev="dm-0" ino=92247 scontext=u:r:cros_init:s0 tcontext=u:object_r:sh_exec:s0 tclass=file
2018-09-28T13:18:08.437765-04:00 NOTICE kernel: [ 2453.319832] audit: type=1400 audit(1538155088.436:404): avc: granted { execute } for pid=8709 comm="ui-respawn" path="/bin/dash" dev="dm-0" ino=92247 scontext=u:r:cros_init:s0 tcontext=u:object_r:sh_exec:s0 tclass=file
2018-09-28T13:18:08.446704-04:00 NOTICE kernel: [ 2453.328335] audit: type=1400 audit(1538155088.445:405): avc: granted { execute } for pid=8710 comm="init" name="dash" dev="dm-0" ino=92247 scontext=u:r:cros_init:s0 tcontext=u:object_r:sh_exec:s0 tclass=file
2018-09-28T13:18:08.446738-04:00 NOTICE kernel: [ 2453.328691] audit: type=1400 audit(1538155088.445:406): avc: granted { execute } for pid=8710 comm="sh" path="/bin/dash" dev="dm-0" ino=92247 scontext=u:r:cros_init:s0 tcontext=u:object_r:sh_exec:s0 tclass=file
2018-09-28T13:18:08.457711-04:00 NOTICE kernel: [ 2453.339762] audit: type=1400 audit(1538155088.456:407): avc: granted { execute } for pid=8712 comm="init" name="dash" dev="dm-0" ino=92247 scontext=u:r:cros_init:s0 tcontext=u:object_r:sh_exec:s0 tclass=file
2018-09-28T13:18:08.460962-04:00 NOTICE kernel: [ 2453.342334] audit: type=1400 audit(1538155088.459:408): avc: granted { execute } for pid=8712 comm="shill_logout_us" path="/bin/dash" dev="dm-0" ino=92247 scontext=u:r:cros_init:s0 tcontext=u:object_r:sh_exec:s0 tclass=file
2018-09-28T13:18:08.465773-04:00 NOTICE kernel: [ 2453.347270] audit: type=1400 audit(1538155088.464:409): avc: granted { execute } for pid=8714 comm="init" name="dash" dev="dm-0" ino=92247 scontext=u:r:cros_init:s0 tcontext=u:object_r:sh_exec:s0 tclass=file
2018-09-28T13:18:08.465809-04:00 NOTICE kernel: [ 2453.347563] audit: type=1400 audit(1538155088.464:410): avc: granted { execute } for pid=8714 comm="sh" path="/bin/dash" dev="dm-0" ino=92247 scontext=u:r:cros_init:s0 tcontext=u:object_r:sh_exec:s0 tclass=file
2018-09-28T13:18:08.473704-04:00 WARNING kernel: [ 2453.355311] init: shill main process (1091) terminated with status 130
EOF

Comment 1 by dgagnon@chromium.org, Oct 1

Labels: XAct

Comment 3 by kbleicher@google.com, Oct 2

Labels: -Pri-2 Pri-1

Comment 4 by f...@chromium.org, Oct 2 

crrev.com/c/1248324 shouldn't be related. It only controls how rsyslogd is being run.

2018-09-28T13:18:08.428890-04:00 WARNING minijail0[1091]: libminijail[1091]: child process 1097 received signal 2

It's weird the process receives SIGINT. Currently I have no clue why this happens.

Comment 5 by dtapu...@chromium.org, Oct 3 

Issue 889314 has been merged into this issue.

Comment 6 by f...@chromium.org, Oct 9 

vapier@, do you have any clues?
kbleicher@, why do you guess crrev.com/c/1248324 being related?

Comment 8 by vapier@chromium.org, Oct 9

Cc: briannorris@chromium.org kirtika@chromium.org benchan@chromium.org
Components: OS>Systems>Network
Owner: briannorris@chromium.org
yeah this should have no relationship to syslog behavior.  if syslog failed to start, the whole system would be broken.

over to the networking team to triage.

Comment 9 by briannorris@chromium.org, Oct 9

Cc: abhishekbh@chromium.org
Mergedinto: 865442
Status: Duplicate (was: Untriaged)
This is basically the same as bug 865442. As a side effect of this:
https://chromium-review.googlesource.com/c/chromiumos/platform2/+/1227387
we shifted the signal code from SIGTERM to SIGINT (which changes the exit code from 143 to 130). We're still unsure why exactly we're seeing more of these alleged "failures", but IIUC, they're all actually benign (daemon is terminating during logout and/or shutdown). At least one thing is clear: it's upstart shutting us down, and not some other odd termination condition...

At any rate, we can handle that in bug 865442.

Comment 10 by vapier@chromium.org, Oct 10

Labels: -Restrict-View-EditIssue
►

Sign in to add a comment