Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

test failures #100

Open
Alessandro-Barbieri opened this issue Jun 28, 2021 · 4 comments
Open

test failures #100

Alessandro-Barbieri opened this issue Jun 28, 2021 · 4 comments

Comments

@Alessandro-Barbieri
Copy link

While packaging this for gentoo overlay guru I got the errors below:

=================================== FAILURES ===================================
_________________________________ test_manhole _________________________________
tests/test_remote.py:29: in test_manhole
    wait_for_strings(target.read, TIMEOUT, 'Broken pipe', 'Stopping tracer.')
        target     = TestProcess(pid=96, is_alive=False)
        tracer     = TestProcess(pid=100, is_alive=False)
/usr/lib/python3.8/site-packages/process_tests.py:247: in wait_for_strings
    raise AssertionError("Waited %0.2fsecs but %s did not appear in output in the given order !" % (
E   AssertionError: Waited 10.00secs but ['Stopping tracer.', 'Broken pipe'] did not appear in output in the given order !
        buff       = ('Manhole[96:1624881702.5855]: Not patching os.fork and os.forkpty. Oneshot '
 'activation is done by signal Signals.SIGURG\n'
 'Manhole[96:1624881702.7540]: Manhole UDS path: /tmp/manhole-96\n'
 'Manhole[96:1624881702.7540]: Waiting for new connection (in pid:96) ...\n'
 'Manhole[96:1624881702.7541]: Accepted connection on fd:4 from PID:100 '
 'UID:250 GID:250\n'
 'Manhole[96:1624881702.7543]: Running: "from hunter import remote; '
 "remote.activate('/tmp/hunter-100', False, 'utf-8', "
 '\'stdlib=False\')\\n".\n'
 "Manhole[96:1624881702.7559]: Running: 'exit()\\n'.\n"
 'Manhole[96:1624881702.7573]: Exiting exec loop.\n')
        cb         = <bound method BufferingBase.read of TestProcess(pid=96, is_alive=False)>
        check_strings = ['Stopping tracer.', 'Broken pipe']
        line       = 'Manhole[96:1624881702.7573]: Exiting exec loop.'
        seconds    = 10
        start      = 1624881705.8134274
        strings    = ('Broken pipe', 'Stopping tracer.')
----------------------------- Captured stdout call -----------------------------
*********** OUTPUT ***********
Manhole[96:1624881702.5855]: Not patching os.fork and os.forkpty. Oneshot activation is done by signal Signals.SIGURG
Manhole[96:1624881702.7540]: Manhole UDS path: /tmp/manhole-96
Manhole[96:1624881702.7540]: Waiting for new connection (in pid:96) ...
Manhole[96:1624881702.7541]: Accepted connection on fd:4 from PID:100 UID:250 GID:250
Manhole[96:1624881702.7543]: Running: "from hunter import remote; remote.activate('/tmp/hunter-100', False, 'utf-8', 'stdlib=False')\n".
Manhole[96:1624881702.7559]: Running: 'exit()\n'.
Manhole[96:1624881702.7573]: Exiting exec loop.

******************************
___________________________ test_manhole_clean_exit ____________________________
tests/test_remote.py:47: in test_manhole_clean_exit
    wait_for_strings(target.read, TIMEOUT,
        target     = TestProcess(pid=104, is_alive=False)
        tracer     = TestProcess(pid=108, is_alive=False)
/usr/lib/python3.8/site-packages/process_tests.py:247: in wait_for_strings
    raise AssertionError("Waited %0.2fsecs but %s did not appear in output in the given order !" % (
E   AssertionError: Waited 10.00secs but ['Doing stuff', 'Doing stuff', 'Doing stuff'] did not appear in output in the given order !
        buff       = ('Manhole[104:1624881717.4568]: Manhole UDS path: /tmp/manhole-104\n'
 'Manhole[104:1624881717.4568]: Waiting for new connection (in pid:104) ...\n'
 'Manhole[104:1624881717.4570]: Accepted connection on fd:4 from PID:108 '
 'UID:250 GID:250\n'
 'Manhole[104:1624881717.4572]: Running: "from hunter import remote; '
 "remote.activate('/tmp/hunter-108', False, 'utf-8', "
 '\'stdlib=False\')\\n".\n'
 "Manhole[104:1624881717.4594]: Running: 'exit()\\n'.\n"
 'Manhole[104:1624881717.4611]: Exiting exec loop.\n'
 'Manhole[104:1624881719.3209]: Manhole UDS path: /tmp/manhole-104\n'
 'Manhole[104:1624881719.3216]: Waiting for new connection (in pid:104) ...\n'
 'Manhole[104:1624881719.3239]: Accepted connection on fd:4 from PID:108 '
 'UID:250 GID:250\n'
 "Manhole[104:1624881719.3261]: Running: 'from hunter import remote; "
 "remote.deactivate()\\n'.\n"
 "Manhole[104:1624881719.3273]: Running: 'exit()\\n'.\n"
 'Manhole[104:1624881719.3274]: Exiting exec loop.\n')
        cb         = <bound method BufferingBase.read of TestProcess(pid=104, is_alive=False)>
        check_strings = ['Doing stuff', 'Doing stuff', 'Doing stuff']
        line       = 'Manhole[104:1624881719.3274]: Exiting exec loop.'
        seconds    = 10
        start      = 1624881719.5192776
        strings    = ('remote.deactivate()', 'Doing stuff', 'Doing stuff', 'Doing stuff')
----------------------------- Captured stdout call -----------------------------
*********** OUTPUT ***********
Manhole[104:1624881717.4568]: Manhole UDS path: /tmp/manhole-104
Manhole[104:1624881717.4568]: Waiting for new connection (in pid:104) ...
Manhole[104:1624881717.4570]: Accepted connection on fd:4 from PID:108 UID:250 GID:250
Manhole[104:1624881717.4572]: Running: "from hunter import remote; remote.activate('/tmp/hunter-108', False, 'utf-8', 'stdlib=False')\n".
Manhole[104:1624881717.4594]: Running: 'exit()\n'.
Manhole[104:1624881717.4611]: Exiting exec loop.
Manhole[104:1624881719.3209]: Manhole UDS path: /tmp/manhole-104
Manhole[104:1624881719.3216]: Waiting for new connection (in pid:104) ...
Manhole[104:1624881719.3239]: Accepted connection on fd:4 from PID:108 UID:250 GID:250
Manhole[104:1624881719.3261]: Running: 'from hunter import remote; remote.deactivate()\n'.
Manhole[104:1624881719.3273]: Running: 'exit()\n'.
Manhole[104:1624881719.3274]: Exiting exec loop.

******************************

------------------------------------------------------------------------------------------------------ benchmark: 6 tests -----------------------------------------------------------------------------------------------------
Name (time in us)                      Min                     Max                    Mean                 StdDev                  Median                    IQR            Outliers          OPS            Rounds  Iterations
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
test_probe[no_probe]               15.1298 (1.0)          760.6531 (1.0)           15.3464 (1.0)           3.4970 (1.0)           15.3184 (1.0)           0.0694 (1.0)        53;786  65,161.7396 (1.0)       45619           1
test_probe[fast_probe]            143.9727 (9.52)         929.3230 (1.22)         157.5877 (10.27)        18.7469 (5.36)         161.5318 (10.54)        17.2644 (248.83)      22;10   6,345.6727 (0.10)       4351           1
test_probe[brief_probe]           232.6570 (15.38)      1,041.8324 (1.37)         246.5197 (16.06)        23.2296 (6.64)         237.8458 (15.53)        23.3571 (336.64)      29;11   4,056.4703 (0.06)       3528           1
test_perf_filter[cython]      274,501.9039 (>1000.0)  354,294.5948 (465.78)   304,883.3194 (>1000.0)  32,353.0886 (>1000.0)  301,420.9466 (>1000.0)  47,793.7540 (>1000.0)       1;0       3.2799 (0.00)          5           1
test_perf_actions[cython]     455,421.3379 (>1000.0)  488,003.5832 (641.56)   467,119.1530 (>1000.0)  12,828.7531 (>1000.0)  463,430.7548 (>1000.0)  16,124.5076 (>1000.0)       1;0       2.1408 (0.00)          5           1
test_perf_stdlib[cython]      902,216.5239 (>1000.0)  920,643.3422 (>1000.0)  909,875.8356 (>1000.0)   7,485.2808 (>1000.0)  909,887.4042 (>1000.0)  11,693.8566 (>1000.0)       2;0       1.0991 (0.00)          5           1
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Legend:
  Outliers: 1 Standard Deviation from Mean; 1.5 IQR (InterQuartile Range) from 1st Quartile and 3rd Quartile.
  OPS: Operations Per Second, computed as 1 / Mean
=========================== short test summary info ============================
SKIPPED [1] tests/test_remote.py:54: condition: not distutils.spawn.find_executable("gdb")
SKIPPED [1] tests/test_remote.py:73: condition: not distutils.spawn.find_executable("gdb")
SKIPPED [3] tests/test_tracer.py:658: <class 'hunter.tracer.Tracer'> is not <class 'hunter._tracer.Tracer'> in this environment
SKIPPED [1] tests/test_tracer.py:1120: condition: not os.environ.get('PUREPYTHONHUNTER')
SKIPPED [1] tests/test_tracer.py:1194: condition: not os.environ.get('PUREPYTHONHUNTER')
SKIPPED [1] tests/test_tracer.py:1323: condition: not os.environ.get('PUREPYTHONHUNTER')
SKIPPED [1] tests/test_tracer.py:1470: condition: PY3
FAILED tests/test_remote.py::test_manhole - AssertionError: Waited 10.00secs ...
FAILED tests/test_remote.py::test_manhole_clean_exit - AssertionError: Waited...
============= 2 failed, 750 passed, 9 skipped in 69.94s (0:01:09) ==============
Traceback (most recent call last):
  File "src/hunter/_tracer.pyx", line 49, in hunter._tracer.trace_func
    fast_call(handler, event)
  File "src/hunter/_predicates.pyx", line 585, in hunter._predicates.fast_call
    return fast_When_call(<When> callable, event)
  File "src/hunter/_predicates.pyx", line 354, in hunter._predicates.fast_When_call
    result = fast_call(self.condition, event)
  File "src/hunter/_predicates.pyx", line 591, in hunter._predicates.fast_call
    return callable(event)
TypeError: <lambda>() takes 0 positional arguments but 1 was given
Disabling tracer because handler <hunter._predicates.When: condition=<function test_tracer_autostop.<locals>.<lambda> at 0x7fbebed7f550>, actions=(CallPrinter(stream=<_io.TextIOWrapper name='<stderr>' mode='w' encoding='utf-8'>, force_colors=False, filename_alignment=40, thread_alignment=12, pid_alignment=9 repr_limit=1024, repr_func=<function safe_repr at 0x7fbec060c700>),)> failed (TypeError('<lambda>() takes 0 positional arguments but 1 was given')) at <Event kind='return' function='trace' module='hunter' filename='/var/tmp/portage/dev-python/hunter-3.3.8/work/python-hunter-3.3.8-python3_8/lib/hunter/__init__.py' lineno=384>.

[...]ter-3.3.8/tests/test_integration.py:304   line                  node += 'x'
[...]ython-hunter-3.3.8/tests/sample7.py:27    call      => five()
[...]ython-hunter-3.3.8/tests/sample7.py:28    line         in_five = 1
[...]ython-hunter-3.3.8/tests/sample7.py:29    line         for i in range(1):  # five
[...]ython-hunter-3.3.8/tests/sample7.py:30    line         return i
[...]ython-hunter-3.3.8/tests/sample7.py:30    return    <= five: 0
[...]ython-hunter-3.3.8/tests/sample7.py:27    call      => five()
[...]ython-hunter-3.3.8/tests/sample7.py:28    line         in_five = 1
[...]ython-hunter-3.3.8/tests/sample7.py:29    line         for i in range(1):  # five
[...]ython-hunter-3.3.8/tests/sample7.py:30    line         return i
[...]ython-hunter-3.3.8/tests/sample7.py:30    return    <= five: 0
[...].8-python3_8/lib/hunter/__init__.py:384   return    def trace(*predicates, **options):
                                               ...       return value: <hunter._tracer.Tracer object at 0x7fbebec10e20>
[...]n-hunter-3.3.8/tests/test_tracer.py:635   line              def a():
[...]n-hunter-3.3.8/tests/test_tracer.py:638   line              a()
[...]n-hunter-3.3.8/tests/test_tracer.py:635   call              def a():
[...]n-hunter-3.3.8/tests/test_tracer.py:636   line                  pass
[...]n-hunter-3.3.8/tests/test_tracer.py:636   return                pass
                                               ...       return value: None
[...]ython-hunter-3.3.8/tests/sample7.py:27    call      => five()
[...]ython-hunter-3.3.8/tests/sample7.py:28    line         in_five = 1
[...]ython-hunter-3.3.8/tests/sample7.py:29    line         for i in range(1):  # five
[...]ython-hunter-3.3.8/tests/sample7.py:30    line         return i
[...]ython-hunter-3.3.8/tests/sample7.py:30    return    <= five: 0
[...]ython-hunter-3.3.8/tests/sample7.py:27    call      => five()
[...]ython-hunter-3.3.8/tests/sample7.py:28    line         in_five = 1
[...]ython-hunter-3.3.8/tests/sample7.py:29    line         for i in range(1):  # five
[...]ython-hunter-3.3.8/tests/sample7.py:30    line         return i
[...]ython-hunter-3.3.8/tests/sample7.py:30    return    <= five: 0
 * ERROR: dev-python/hunter-3.3.8::guru failed (test phase):
 *   pytest failed with python3.8

Full log here: https://799026.bugs.gentoo.org/attachment.cgi?id=719727
https://bugs.gentoo.org/799026
@ionelmc
Copy link
Owner

ionelmc commented Jul 2, 2021

Well it would appear that for those tests the tracing works but the target process is hosed (AssertionError: Waited 10.00secs but ['Doing stuff', 'Doing stuff', 'Doing stuff'] did not appear in output in the given order !). IOW the process doesn't resume normally and output Doing stuff after the tracer de-attaches. Well actually ... I'm not sure if the process works normally anyway since I don't have any assertion of that about before tracer attaches. Is there an easy way I can reproduce the problem you had there - like a docker container thing to run your build system?

@guettli
Copy link

guettli commented Jul 26, 2021

@Alessandro-Barbieri the issue is closed in gentoo. Maybe you want to close this issue, too?

@Alessandro-Barbieri
Copy link
Author

@Alessandro-Barbieri the issue is closed in gentoo. Maybe you want to close this issue, too?

No, I've only deselected the failing tests

@abitrolly
Copy link
Contributor

@Alessandro-Barbieri does that mean manhole is broken in Gentoo?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@ionelmc @guettli @abitrolly @Alessandro-Barbieri