Gentoo Websites Logo
Go to: Gentoo Home Documentation Forums Lists Bugs Planet Store Wiki Get Gentoo!
Bug 531724 - sys-apps/portage: PipeReaderPtyTestCase tests fail intermittently
Summary: sys-apps/portage: PipeReaderPtyTestCase tests fail intermittently
Status: RESOLVED FIXED
Alias: None
Product: Portage Development
Classification: Unclassified
Component: Core (show other bugs)
Hardware: All Linux
: Normal normal (vote)
Assignee: Portage team
URL:
Whiteboard:
Keywords: InVCS
: 497504 (view as bug list)
Depends on:
Blocks: 484436
  Show dependency tree
 
Reported: 2014-12-05 02:55 UTC by Patrick Lauer
Modified: 2015-03-04 21:30 UTC (History)
2 users (show)

See Also:
Package list:
Runtime testing required: ---


Attachments
standalone test case demonstrating that EPOLLHUP triggers the issue (test_read_pty.py,1.27 KB, text/x-python)
2014-12-26 07:25 UTC, Zac Medico
Details
standalone test case demonstrating that EPOLLHUP triggers the issue (test_read_pty.py,1.23 KB, text/x-python)
2014-12-26 07:34 UTC, Zac Medico
Details
standalone test case demonstrating that EPOLLHUP triggers the issue (test_read_pty.py,1.40 KB, text/x-python)
2014-12-26 08:06 UTC, Zac Medico
Details
standalone test case (read regardless of EPOLLIN like portage-2.2.17 does) (test_read_pty.py,1.52 KB, text/x-python)
2015-02-13 04:53 UTC, Zac Medico
Details
C equivalent standalone test case (read regardless of EPOLLIN like portage-2.2.17 does) (test_read_pty.c,3.45 KB, text/x-csrc)
2015-02-22 22:27 UTC, Zac Medico
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Patrick Lauer gentoo-dev 2014-12-05 02:55:54 UTC
======================================================================
FAIL: testPipeReader (portage.tests.process.test_poll.PipeReaderPtyTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/var/tmp/portage/sys-apps/portage-2.2.15/work/portage-2.2.15-python3_4/lib/portage/tests/__init__.py", line 222, in run
    testMethod()
  File "/var/tmp/portage/sys-apps/portage-2.2.15/work/portage-2.2.15-python3_4/lib/portage/tests/process/test_poll.py", line 68, in testPipeReader
    "x = %s, len(output) = %s" % (x, len(output)))
AssertionError: 'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa' != ''
- aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
+ 
 : x = 32, len(output) = 0

[snip]

Ran 222 tests in 568.685s

OK
Symlinking /var/tmp/portage/sys-apps/portage-2.2.15/work/portage-2.2.15-python3_3/cnf -> ../portage-2.2.15/cnf
Symlinking /var/tmp/portage/sys-apps/portage-2.2.15/work/portage-2.2.15-python3_4/cnf -> ../portage-2.2.15/cnf
Traceback (most recent call last):
  File "setup.py", line 665, in <module>
    'Topic :: System :: Installation/Setup'
  File "/usr/lib64/python3.4/distutils/core.py", line 148, in setup
    dist.run_commands()
  File "/usr/lib64/python3.4/distutils/dist.py", line 955, in run_commands
    self.run_command(cmd)
  File "/usr/lib64/python3.4/distutils/dist.py", line 974, in run_command
    cmd_obj.run()
  File "setup.py", line 579, in run
    os.path.join(self.build_lib, 'portage/tests/runTests.py')
  File "/usr/lib64/python3.4/subprocess.py", line 561, in check_call
    raise CalledProcessError(retcode, cmd)
subprocess.CalledProcessError: Command '['/usr/bin/python3.4', '-bWd', '/var/tmp/portage/sys-apps/portage-2.2.15/work/portage-2.2.15-python3_4/lib/portage/tests/runTests.py']' returned non-zero exit status 1
 * ERROR: sys-apps/portage-2.2.15::gentoo failed (test phase):
 *   (no error message)


Portage 2.2.14 (python 2.7.8-final-0, default/linux/amd64/13.0/desktop/kde, gcc-4.9.2, glibc-2.20, 3.17.2-gentoo x86_64)
=================================================================
System uname: Linux-3.17.2-gentoo-x86_64-AMD_Phenom-tm-_II_X4_965_Processor-with-gentoo-2.2
KiB Mem:     7919412 total,   1228040 free
KiB Swap:   16777208 total,  16746892 free
Timestamp of tree: Unknown
ld GNU ld (Gentoo 2.24 p1.4) 2.24
app-shells/bash:          4.3_p30-r1
dev-lang/perl:            5.20.1-r3
dev-lang/python:          2.7.8, 3.3.5-r1, 3.4.2
dev-util/cmake:           3.0.2
dev-util/pkgconfig:       0.28-r2
sys-apps/baselayout:      2.2
sys-apps/openrc:          0.13.6
sys-apps/sandbox:         2.6-r1
sys-devel/autoconf:       2.69
sys-devel/automake:       1.14.1
sys-devel/binutils:       2.24-r3
sys-devel/gcc:            4.9.2
sys-devel/gcc-config:     1.8
sys-devel/libtool:        2.4.3-r2
sys-devel/make:           4.1-r1
sys-kernel/linux-headers: 3.17-r1 (virtual/os-headers)
sys-libs/glibc:           2.20
Repositories: gentoo x-overlay
ACCEPT_KEYWORDS="amd64 ~amd64"
ACCEPT_LICENSE="*"
CBUILD="x86_64-pc-linux-gnu"
CFLAGS="-O2 -pipe"
CHOST="x86_64-pc-linux-gnu"
CONFIG_PROTECT="/etc /usr/share/config /usr/share/gnupg/qualified.txt /usr/share/themes/oxygen-gtk/gtk-2.0 /var/lib/hsqldb"
CONFIG_PROTECT_MASK="/etc/ca-certificates.conf /etc/dconf /etc/env.d /etc/fonts/fonts.conf /etc/gconf /etc/gentoo-release /etc/revdep-rebuild /etc/sandbox.d /etc/terminfo /etc/texmf/language.dat.d /etc/texmf/language.def.d /etc/texmf/updmap.d /etc/texmf/web2c"
CXXFLAGS="-O2 -pipe"
DISTDIR="/usr/portage/distfiles"
FCFLAGS="-O2 -pipe"
FEATURES="assume-digests binpkg-logs buildpkg config-protect-if-modified distlocks ebuild-locks fixlafiles merge-sync news parallel-fetch preserve-libs protect-owned sandbox sfperms split-elog strict test unknown-features-warn unmerge-logs unmerge-orphans userfetch userpriv usersandbox usersync"
FFLAGS="-O2 -pipe"
GENTOO_MIRRORS="http://mirrors.sohu.com/gentoo/"
LANG="en_US.utf8"
LDFLAGS="-Wl,-O1 -Wl,--as-needed"
MAKEOPTS="-j4"
PKGDIR="/usr/portage/packages"
PORTAGE_CONFIGROOT="/"
PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --omit-dir-times --compress --force --whole-file --delete --stats --human-readable --timeout=180 --exclude=/distfiles --exclude=/local --exclude=/packages"
PORTAGE_TMPDIR="/var/tmp"
PORTDIR="/usr/portage"
PORTDIR_OVERLAY="/overlay"
USE="X a52 aac acl acpi alsa amd64 berkdb bluetooth branding bzip2 cairo cdda cdr cli consolekit cracklib crypt cups cxx dbus declarative dri dts dvd dvdr egl emboss encode exif fam firefox flac fortran gdbm gif glamor gpm gtk iconv ipv6 jpeg kde kipi lcms ldap libnotify mad mmx mng modules mp3 mp4 mpeg multilib ncurses nls nptl ogg opengl openmp openvg pam pango pcre pdf phonon plasma png policykit ppds python qt3support qt4 readline sdl semantic-desktop session spell sqlite sse sse2 ssl startup-notification svg tcl tcpd tiff truetype udev udisks unicode upower usb vorbis wxwidgets x264 xa xcb xcomposite xinerama xml xscreensaver xv xvfb xvid zlib" ABI_X86="64" ALSA_CARDS="ali5451 als4000 atiixp atiixp-modem bt87x ca0106 cmipci emu10k1x ens1370 ens1371 es1938 es1968 fm801 hda-intel intel8x0 intel8x0m maestro3 trident usb-audio via82xx via82xx-modem ymfpci" APACHE2_MODULES="authn_core authz_core socache_shmcb unixd actions alias auth_basic authn_alias authn_anon authn_dbm authn_default authn_file authz_dbm authz_default authz_groupfile authz_host authz_owner authz_user autoindex cache cgi cgid dav dav_fs dav_lock deflate dir disk_cache env expires ext_filter file_cache filter headers include info log_config logio mem_cache mime mime_magic negotiation rewrite setenvif speling status unique_id userdir usertrack vhost_alias" CALLIGRA_FEATURES="kexi words flow plan sheets stage tables krita karbon braindump author" CAMERAS="ptp2" COLLECTD_PLUGINS="df interface irq load memory rrdtool swap syslog" ELIBC="glibc" GPSD_PROTOCOLS="ashtech aivdm earthmate evermore fv18 garmin garmintxt gpsclock itrax mtk3301 nmea ntrip navcom oceanserver oldstyle oncore rtcm104v2 rtcm104v3 sirf superstar2 timing tsip tripmate tnt ublox ubx" INPUT_DEVICES="keyboard mouse evdev" KERNEL="linux" LCD_DEVICES="bayrad cfontz cfontz633 glk hd44780 lb216 lcdm001 mtxorb ncurses text" LIBREOFFICE_EXTENSIONS="presenter-console presenter-minimizer" OFFICE_IMPLEMENTATION="libreoffice" PHP_TARGETS="php5-5" PYTHON_SINGLE_TARGET="python2_7" PYTHON_TARGETS="python2_7 python3_3 python3_4" RUBY_TARGETS="ruby21" USERLAND="GNU" VIDEO_CARDS="vesa" XTABLES_ADDONS="quota2 psd pknock lscan length2 ipv4options ipset ipp2p iface geoip fuzzy condition tee tarpit sysrq steal rawnat logmark ipmark dhcpmac delude chaos account"
Unset:  CPPFLAGS, CTARGET, EMERGE_DEFAULT_OPTS, INSTALL_MASK, LC_ALL, PORTAGE_BUNZIP2_COMMAND, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS, PORTAGE_RSYNC_EXTRA_OPTS, SYNC, USE_PYTHON
Comment 1 Arfrever Frehtes Taifersar Arahesis 2014-12-05 04:12:12 UTC
portage.tests.process.test_poll.PipeReaderPtyTestCase.testPipeReader() has been failing sporadically for long time (over a year), so it is not a regression in Portage 2.2.15.
Comment 2 Zac Medico gentoo-dev 2014-12-05 15:07:04 UTC
I suspect that this is triggered when os.read raises errno.EIO or errno.EAGAIN inside AbstractPollTask._read_buf. It would be similar to http://bugs.python.org/issue5380, but involving os.read instead of array.fromfile.
Comment 3 Zac Medico gentoo-dev 2014-12-26 07:25:18 UTC
Created attachment 392412 [details]
standalone test case demonstrating that EPOLLHUP triggers the issue

This test case shows that the problem is always triggered by an EPOLLHUP event. If I change the test case to ignore EPOLLHUP, then the test always succeeds.
Comment 4 Zac Medico gentoo-dev 2014-12-26 07:34:02 UTC
Created attachment 392414 [details]
standalone test case demonstrating that EPOLLHUP triggers the issue

This updated test case fixes faulty fork/pid logic.
Comment 5 Zac Medico gentoo-dev 2014-12-26 07:37:16 UTC
(In reply to Zac Medico from comment #3)
> This test case shows that the problem is always triggered by an EPOLLHUP
> event. If I change the test case to ignore EPOLLHUP, then the test always
> succeeds.

After the pid logic fix, making it ignore EPOLLHUP causes the test case to hang in the epoll loop.
Comment 6 Zac Medico gentoo-dev 2014-12-26 08:06:30 UTC
Created attachment 392416 [details]
standalone test case demonstrating that EPOLLHUP triggers the issue

This updated test case adds a non-blocking read loop, to read until EAGAIN is raised.
Comment 7 Zac Medico gentoo-dev 2014-12-26 08:23:30 UTC
If I modify the test case so that the read loop executes even if the EPOLLIN flag is not set, then the test succeeds reliably!
Comment 8 Zac Medico gentoo-dev 2014-12-26 08:34:15 UTC
Also, if I try to swap the inner read loop for a single read, the test fails.
Comment 9 Zac Medico gentoo-dev 2014-12-26 09:05:23 UTC
I have a patch in the following branch:

	https://github.com/zmedico/portage/tree/bug_531724

I've posted it here for review:

	http://thread.gmane.org/gmane.linux.gentoo.portage.devel/5042
Comment 10 Zac Medico gentoo-dev 2015-01-05 19:37:18 UTC
This is in the master branch now:

https://github.com/gentoo/portage/commit/b3bba4dc8f4f93adeaeaf662870bb00a09bb1de7
Comment 11 Patrick Lauer gentoo-dev 2015-02-13 04:10:23 UTC
======================================================================
FAIL: testPipeReader (portage.tests.process.test_poll.PipeReaderPtyTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/var/tmp/portage/sys-apps/portage-2.2.17/work/portage-2.2.17-pypy/lib/portage/tests/__init__.py", line 222, in run
    testMethod()
  File "/var/tmp/portage/sys-apps/portage-2.2.17/work/portage-2.2.17-pypy/lib/portage/tests/process/test_poll.py", line 68, in testPipeReader
    "x = %s, len(output) = %s" % (x, len(output)))
AssertionError: x = 8192, len(output) = 4095

======================================================================
TODO: testAutounmaskMultilibUse (portage.tests.resolver.test_autounmask_multilib_use.AutounmaskMultilibUseTestCase)
----------------------------------------------------------------------
<bound method AutounmaskMultilibUseTestCase.testAutounmaskMultilibUse of <portage.tests.resolver.test_autounmask_multilib_use.AutounmaskMultilibUseTestCase testMethod=testAutounmaskMultilibUse>>: TODO
======================================================================
TODO: testDirectVirtualCircularDependency (portage.tests.resolver.test_circular_choices.VirtualCircularChoicesTestCase)
----------------------------------------------------------------------
<bound method VirtualCircularChoicesTestCase.testDirectVirtualCircularDependency of <portage.tests.resolver.test_circular_choices.VirtualCircularChoicesTestCase testMethod=testDirectVirtualCircularDependency>>: TODO
======================================================================
TODO: testBacktrackingGoodVersionFirst (portage.tests.resolver.test_slot_conflict_mask_update.SlotConflictMaskUpdateTestCase)
----------------------------------------------------------------------
<bound method SlotConflictMaskUpdateTestCase.testBacktrackingGoodVersionFirst of <portage.tests.resolver.test_slot_conflict_mask_update.SlotConflictMaskUpdateTestCase testMethod=testBacktrackingGoodVersionFirst>>: TODO
----------------------------------------------------------------------
Ran 226 tests in 340.179s

FAILED (failures=1)
Symlinking /var/tmp/portage/sys-apps/portage-2.2.17/work/portage-2.2.17-pypy/cnf -> ../portage-2.2.17/cnf
Traceback (most recent call last):
  File "app_main.py", line 75, in run_toplevel
  File "setup.py", line 708, in <module>
    'Topic :: System :: Installation/Setup'
  File "/usr/lib64/pypy/lib-python/2.7/distutils/core.py", line 151, in setup
    dist.run_commands()
  File "/usr/lib64/pypy/lib-python/2.7/distutils/dist.py", line 953, in run_commands
    self.run_command(cmd)
  File "/usr/lib64/pypy/lib-python/2.7/distutils/dist.py", line 972, in run_command
    cmd_obj.run()
  File "setup.py", line 579, in run
    os.path.join(self.build_lib, 'portage/tests/runTests.py')
  File "/usr/lib64/pypy/lib-python/2.7/subprocess.py", line 540, in check_call
    raise CalledProcessError(retcode, cmd)
CalledProcessError: Command '['/usr/bin/pypy', '-bWd', '/var/tmp/portage/sys-apps/portage-2.2.17/work/portage-2.2.17-pypy/lib/portage/tests/runTests.py']' returned non-zero exit status 1
 * ERROR: sys-apps/portage-2.2.17::gentoo failed (test phase):
 *   (no error message)


Similar but slightly different failure with pypy
Comment 12 Zac Medico gentoo-dev 2015-02-13 04:39:07 UTC
(In reply to Patrick Lauer from comment #11)

Can you also reproduce it with the attached standalone test case? I think we should report an upstream python bug with that test case.
Comment 13 Zac Medico gentoo-dev 2015-02-13 04:53:15 UTC
Created attachment 396310 [details]
standalone test case (read regardless of EPOLLIN like portage-2.2.17 does)

Please use this version for testing.
Comment 14 Brian Dolbec gentoo-dev 2015-02-15 05:40:35 UTC
Released in portage-2.2.16.


Is this one still a problem?
Comment 15 Zac Medico gentoo-dev 2015-02-17 04:09:29 UTC
If it's still reproducible with portage-2.2.17, as reported in comment #11, then we've still got a problem.

I supposed we could write an equivalent test case in C, in order to show whether or not python is at fault.
Comment 16 Zac Medico gentoo-dev 2015-02-22 06:14:59 UTC
*** Bug 497504 has been marked as a duplicate of this bug. ***
Comment 17 Zac Medico gentoo-dev 2015-02-22 22:27:09 UTC
Created attachment 397280 [details]
C equivalent standalone test case (read regardless of EPOLLIN like portage-2.2.17 does)

build: gcc -lutil test_read_pty.c -o test_read_pty
usage: for x in {1..100} ; do ./test_read_pty || break ; done

If the C implementation succeeds while the equivalent python implementation (from comment #13) fails, then we can report it as an upstream python issue.
Comment 18 Brian Dolbec gentoo-dev 2015-03-04 21:30:05 UTC
Released in portage-2.2.16