check-neutron-dsvm-functional dies with Length too long

Bug #1382579 reported by Mate Lakat on 2014-10-17
22
This bug affects 3 people
Affects Status Importance Assigned to Milestone
Testrepository
Undecided
Unassigned
neutron
High
Numan Siddique

Bug Description

Could be seen on this job:
http://logs.openstack.org/08/129208/1/check/check-neutron-dsvm-functional/650dd00/console.html
dsvm-functional installdeps: -r/opt/stack/new/neutron/requirements.txt, -r/opt/stack/new/neutron/test-requirements.txt
dsvm-functional develop-inst: /opt/stack/new/neutron
dsvm-functional runtests: PYTHONHASHSEED='3217326230'
dsvm-functional runtests: commands[0] | python -m neutron.openstack.common.lockutils python setup.py testr --slowest --testr-args=
running testr
Length too long: 20339241
running=OS_STDOUT_CAPTURE=1 OS_STDERR_CAPTURE=1 OS_LOG_CAPTURE=1 ${PYTHON:-python} -m subunit.run discover -t ./ ${OS_TEST_PATH:-./neutron/tests/unit} --list
running=OS_STDOUT_CAPTURE=1 OS_STDERR_CAPTURE=1 OS_LOG_CAPTURE=1 ${PYTHON:-python} -m subunit.run discover -t ./ ${OS_TEST_PATH:-./neutron/tests/unit} --load-list /tmp/tmpRymoqb
running=OS_STDOUT_CAPTURE=1 OS_STDERR_CAPTURE=1 OS_LOG_CAPTURE=1 ${PYTHON:-python} -m subunit.run discover -t ./ ${OS_TEST_PATH:-./neutron/tests/unit} --load-list /tmp/tmpMeUYgP
running=OS_STDOUT_CAPTURE=1 OS_STDERR_CAPTURE=1 OS_LOG_CAPTURE=1 ${PYTHON:-python} -m subunit.run discover -t ./ ${OS_TEST_PATH:-./neutron/tests/unit} --load-list /tmp/tmp6xlXix
running=OS_STDOUT_CAPTURE=1 OS_STDERR_CAPTURE=1 OS_LOG_CAPTURE=1 ${PYTHON:-python} -m subunit.run discover -t ./ ${OS_TEST_PATH:-./neutron/tests/unit} --load-list /tmp/tmpV42F6X
running=OS_STDOUT_CAPTURE=1 OS_STDERR_CAPTURE=1 OS_LOG_CAPTURE=1 ${PYTHON:-python} -m subunit.run discover -t ./ ${OS_TEST_PATH:-./neutron/tests/unit} --load-list /tmp/tmppzphnl
running=OS_STDOUT_CAPTURE=1 OS_STDERR_CAPTURE=1 OS_LOG_CAPTURE=1 ${PYTHON:-python} -m subunit.run discover -t ./ ${OS_TEST_PATH:-./neutron/tests/unit} --load-list /tmp/tmpgoQS1K
running=OS_STDOUT_CAPTURE=1 OS_STDERR_CAPTURE=1 OS_LOG_CAPTURE=1 ${PYTHON:-python} -m subunit.run discover -t ./ ${OS_TEST_PATH:-./neutron/tests/unit} --load-list /tmp/tmpDwh5_K
running=OS_STDOUT_CAPTURE=1 OS_STDERR_CAPTURE=1 OS_LOG_CAPTURE=1 ${PYTHON:-python} -m subunit.run discover -t ./ ${OS_TEST_PATH:-./neutron/tests/unit} --load-list /tmp/tmpdPzTrB
error: testr failed (3)
ERROR: InvocationError: '/opt/stack/new/neutron/.tox/dsvm-functional/bin/python -m neutron.openstack.common.lockutils python setup.py testr --slowest --testr-args='
___________________________________ summary ____________________________________
ERROR: dsvm-functional: commands failed

Mate Lakat (mate-lakat) on 2014-10-17
description: updated
Clark Boylan (cboylan) wrote :

Moved this bug to neutron as it appears to be a valid test run failure with neutron's test suite.

no longer affects: openstack-ci
Changed in neutron:
assignee: nobody → Numan Siddique (numansiddique)
Changed in neutron:
importance: Undecided → High
Changed in neutron:
status: New → In Progress
Numan Siddique (numansiddique) wrote :

I see this issue in my local setup approx. 1 in 10 times.

"Length too long" exception message is coming from ./.tox/dsvm-functional/lib/python2.7/site-packages/subunit/v2.py (StreamResultToBytes.__write_packet() function - line no 206) - raise ValueError(Length too long: %r" % base_length)

The issue is seen when the size of the testr log file (eg. .testrepository/25 ) size goes into MBs.
Here is one log file when the failure is seen
http://paste.openstack.org/show/121895/

In the success cases the testr log file is approx . 6940 bytes

Numan Siddique (numansiddique) wrote :

When the issue is seen, the testr log file is filled with the below logs

2014-10-18 16:20:52.199 3173 DEBUG neutron.openstack.common.lockutils [req-e46c6952-ddbb-4e89-bf5d-65b5435e4f8f None] Got semaphore "_check_child_processes" lock neutron/openstack/common/lockutils.py:168
2014-10-18 16:20:52.199 3173 DEBUG neutron.openstack.common.lockutils [req-e46c6952-ddbb-4e89-bf5d-65b5435e4f8f None] Got semaphore / lock "_check_child_processes" inner neutron/openstack/common/lockutils.py:248
2014-10-18 16:20:52.200 3173 DEBUG neutron.openstack.common.lockutils [req-e46c6952-ddbb-4e89-bf5d-65b5435e4f8f None] Semaphore / lock released "_check_child_processes" inner neutron/openstack/common/lockutils.py:252

Numan Siddique (numansiddique) wrote :

testr log file when the issue is seen

Reviewed: https://review.openstack.org/130939
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=f0582e2cd12191baec6007803536d2fb63a1de58
Submitter: Jenkins
Branch: master

commit f0582e2cd12191baec6007803536d2fb63a1de58
Author: Numan Siddique <email address hidden>
Date: Sat Oct 25 16:29:52 2014 +0530

    Fix 'Length too long' error in neutron-dsvm-functional tests

    testr is occasionally failing with 'Length too long' for
    neutron-dsvm-functional test cases.

    The issue is seen when the size of the testr log file size goes into MBs.

    (Please see the bug comments for the details on the testr logs)

    This patch fixes the issue by disabling debug logs in the tests.

    Change-Id: I48fc9d14f6886f86761038ee4d106fbbe59b6890
    Closes-bug: #1382579

Changed in neutron:
status: In Progress → Fix Committed
Thierry Carrez (ttx) on 2014-12-18
Changed in neutron:
milestone: none → kilo-1
status: Fix Committed → Fix Released
Thierry Carrez (ttx) on 2015-04-30
Changed in neutron:
milestone: kilo-1 → 2015.1.0
Vasyl Saienko (vsaienko) wrote :

It has been reproduced on another job. Indeed if testr log size exceeds some value the issue is seen.
I'm opening this bug for testrepository since the root cause is there.

http://paste.openstack.org/show/492441/

Michael Johnson (johnsom) wrote :

Also seen in the octavia project:
http://paste.openstack.org/show/594911/

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Duplicates of this bug

Other bug subscribers