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

[Mate Lakat]

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

[Clark Boylan (cboylan)]

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

[Numan Siddique (numansiddique)]

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)]

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)]

testr log file when the issue is seen

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/130939

[OpenStack Infra (hudson-openstack)]

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

[Vasyl Saienko (vsaienko)]

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)]

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