[Bug 1558236] Re: /usr/bin/script freezes and eats all CPU, has to be killed, which kills shell and programs inside

Tue Apr 5 14:58:55 UTC 2016

## Status

Bug still occurs every few days, when I use Ubuntu 16.04, not when using
others.

## Trying to get more precise info

### Location in source code

Following https://wiki.ubuntu.com/DebuggingProgramCrash I could get an
interactive gdb prompt showing that it's blocked in the while loop
below:

term-utils/script.c lines 278-287:

static void wait_for_empty_fd(int fd)
{
	struct pollfd fds[] = {
	           { .fd = fd, .events = POLLIN }
	};

	while (poll(fds, 1, 10) == 1) {
		DBG(IO, ul_debug("  data to read"));
	}
}

### Activity at debugger level

Here's the gdb log of the loop when pressing return key at each prompt
repeats "step" gdb command:

wait_for_empty_fd (fd=<optimized out>) at term-utils/script.c:284
284		while (poll(fds, 1, 10) == 1) {
(gdb)
285			DBG(IO, ul_debug("  data to read"));
(gdb)
284		while (poll(fds, 1, 10) == 1) {
(gdb)
poll (__timeout=10, __nfds=1, __fds=0x7fffd0eff840) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46
46	  return __poll_alias (__fds, __nfds, __timeout);
(gdb)
poll () at ../sysdeps/unix/syscall-template.S:84
84	../sysdeps/unix/syscall-template.S: Aucun fichier ou dossier de ce type.
(gdb)

(gdb) bt
#0  poll (__timeout=10, __nfds=1, __fds=0x7fffd0eff840) at /usr/include/x86_64-linux-gnu/bits/poll2.h:46
#1  wait_for_empty_fd (fd=<optimized out>) at term-utils/script.c:284
#2  write_to_shell (ctl=ctl at entry=0x7fffd0f019c0, buf=buf at entry=0x7fffd0eff890 "sometext"..., bufsz=bufsz at entry=1) at term-utils/script.c:303
#3  0x0000000000402e6d in handle_io (ctl=ctl at entry=0x7fffd0f019c0, fd=0, eof=eof at entry=0x7fffd0f01904) at term-utils/script.c:346
#4  0x00000000004023fb in do_io (ctl=0x7fffd0f019c0) at term-utils/script.c:475
#5  main (argc=<optimized out>, argv=<optimized out>) at term-utils/script.c:781

(gdb) print __fds
$1 = (struct pollfd *) 0x7fffd0eff840
(gdb) print *__fds
$2 = {fd = 4, events = 1, revents = 1}

lrwx------ 1 stephane stephane 64 Apr  5 16:38 0 -> /dev/pts/6
lrwx------ 1 stephane stephane 64 Apr  5 16:38 1 -> /dev/pts/6
lrwx------ 1 stephane stephane 64 Apr  5 16:38 2 -> /dev/pts/6
lrwx------ 1 stephane stephane 64 Apr  5 16:38 3 -> /dev/ptmx
lrwx------ 1 stephane stephane 64 Apr  5 16:38 4 -> /dev/pts/21
lrwx------ 1 stephane stephane 64 Apr  5 16:38 5 -> anon_inode:[signalfd]
l-wx------ 1 stephane stephane 64 Apr  5 16:38 6 -> /tmp/myscriptfile.txt
l-wx------ 1 stephane stephane 64 Apr  5 16:38 7 -> /tmp/myscriptfile.timings

## Summary

* "script" polls slave pts at high speed consuming 100% CPU, assuming this won't last. But sometimes it does last forever.
* Polling code was introduced in commit below:

commit 54c6611d6f7b73609a5331f4d0bcf63c4af6429e
Author: Karel Zak <kzak at redhat.com>
Date:   Wed Jun 17 15:48:50 2015 +0200

    script: fix EOF problems

    * remove STDIN from poll() if:

      * STDIN already closed -- poll returns POLLHUP, for example:

                echo "date" | script

      * detect EOF as returned by read(), for example:

                script -c "echo Hello" < /dev/null

    * don't write to master when there is still something to read from
      slave (it means shell is not initialized yet or busy)

    Signed-off-by: Karel Zak <kzak at redhat.com>

## Now what ?

What should be changed?

It script to blame or is is the shell?   Additional info: exact same
operation (shell, etc) have been performed for years, no problem. Even
on this distro (Ubuntu 16.04) it usually works. It *always* works on
Ubuntu <=15.10, Debian 8.3, Fedora 23.

How to debug further?

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to util-linux in Ubuntu.
https://bugs.launchpad.net/bugs/1558236

Title:
  /usr/bin/script freezes and eats all CPU, has to be killed, which
  kills shell and programs inside

Status in util-linux package in Ubuntu:
  New

Bug description:
  # Context

  I've been using /usr/bin/script quite a lot for about 4 years (since
  about Ubuntu 12.04, maybe before). It always worked without problem.

  I'm using several script instance most of the time, in several
  terminals.

  Reproducible: randomly, once every few days.

  Problem happens since Ubuntu 16.04. Never seen before (12.04 12.10
  13.04 13.10 14.04 14.10 15.04 15.10).

  # Expected

  Continued operation, terminal running programs normally, little CPU
  used.

  # Observed

  Suddenly, terminal freezes. 
  Other tabs of same terminal window not affected.
  Top shows script consumes 100% CPU.

  Strace shows an endless stream of this line:

  poll([{fd=4, events=POLLIN}], 1, 10)    = 1 ([{fd=4, revents=POLLIN}])

  /proc/*/fd shows what file descriptor it is:

  total 0
  dr-x------ 2 stephane stephane  0 mars  16 20:03 .
  dr-xr-xr-x 9 stephane stephane  0 mars  16 20:03 ..
  lrwx------ 1 stephane stephane 64 mars  16 20:15 0 -> /dev/pts/17 (deleted)
  lrwx------ 1 stephane stephane 64 mars  16 20:15 1 -> /dev/pts/17 (deleted)
  lrwx------ 1 stephane stephane 64 mars  16 20:03 2 -> /dev/pts/17 (deleted)
  lrwx------ 1 stephane stephane 64 mars  16 20:15 3 -> /dev/ptmx
  lrwx------ 1 stephane stephane 64 mars  16 20:15 4 -> /dev/pts/21
  lrwx------ 1 stephane stephane 64 mars  16 20:15 5 -> anon_inode:[signalfd]
  l-wx------ 1 stephane stephane 64 mars  16 20:15 6 -> /somewhere/mylogfile.txt
  l-wx------ 1 stephane stephane 64 mars  16 20:15 7 -> /somewhere/mylogfile_timings.txt

  What can we do?

  ProblemType: Bug
  DistroRelease: Ubuntu 16.04
  Package: bsdutils 1:2.27.1-6ubuntu1
  ProcVersionSignature: Ubuntu 4.4.0-13.29-generic 4.4.5
  Uname: Linux 4.4.0-13-generic x86_64
  ApportVersion: 2.20-0ubuntu3
  Architecture: amd64
  CurrentDesktop: XFCE
  Date: Wed Mar 16 20:04:02 2016
  ExecutablePath: /usr/bin/script
  InstallationDate: Installed on 2016-02-03 (41 days ago)
  InstallationMedia: Xubuntu 16.04 LTS "Xenial Xerus" - Alpha amd64 (20160203)
  SourcePackage: util-linux
  UpgradeStatus: No upgrade log present (probably fresh install)

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/util-linux/+bug/1558236/+subscriptions