neutron

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

Bug #1382579 reported by Mate Lakat on 2014-10-17

This bug affects 3 people

Affects		Status	Importance	Assigned to	Milestone
	Testrepository	New	Undecided	Unassigned
	neutron	Fix Released	High	Numan Siddique	neutron 2015.1.0 "kilo"

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

See original description

Mate Lakat (mate-lakat) on 2014-10-17

description:

updated

Revision history for this message

Clark Boylan (cboylan) wrote on 2014-10-17:

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

Numan Siddique (numansiddique) on 2014-10-17

Changed in neutron:
assignee:	nobody → Numan Siddique (numansiddique)

Eugene Nikanorov (enikanorov) on 2014-10-18

Changed in neutron:
importance:	Undecided → High

Numan Siddique (numansiddique) on 2014-10-18

Changed in neutron:
status:	New → In Progress

Revision history for this message

Numan Siddique (numansiddique) wrote on 2014-10-19:

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

Revision history for this message

Numan Siddique (numansiddique) wrote on 2014-10-25:

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

Revision history for this message

Numan Siddique (numansiddique) wrote on 2014-10-25:

neutron_dsvm_functionals_logs.txt Edit (11.1 MiB, text/plain)

testr log file when the issue is seen

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2014-10-25: Fix proposed to neutron (master)

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

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2014-10-28: Fix merged to neutron (master)

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

Revision history for this message

Vasyl Saienko (vsaienko) wrote on 2016-03-30:

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/

Revision history for this message

Michael Johnson (johnsom) wrote on 2017-01-14:

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