Canvas integration test for chained groups that currently fails

[pencil]

Description

I have been investigating task duplication that was documented in #8180. That bug report was closed but I can still reproduce the erroneous behavior. Unfortunately I haven't been able to pinpoint the bug exactly but I think it might be related to how chains/groups are converted to chords.

If someone can help me debug further, I would be happy to spend some more time coming up with a fix. Or maybe this failing test is a useful starting point for someone else to figure out what's going on. If this is not useful, feel free to close the PR.

[codecov]

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 77.81%. Comparing base (780d3b5) to head (88ef2f1).
Report is 1 commits behind head on main.

Additional details and impacted files

@@           Coverage Diff           @@
##             main    #9013   +/-   ##
=======================================
  Coverage   77.81%   77.81%           
=======================================
  Files         150      150           
  Lines       18689    18689           
  Branches     3194     3194           
=======================================
  Hits        14543    14543           
  Misses       3854     3854           
  Partials      292      292           

Flag	Coverage Δ
unittests	77.79% <ø> (ø)

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

[Nusnus]

2024-05-09T05:38:29.4576030Z =================================== FAILURES ===================================
2024-05-09T05:38:29.4577452Z _ test_chain.test_chained_groups_within_chain_ending_with_group_inside_chain [All tasks are executed once] _
2024-05-09T05:38:29.4582441Z 
2024-05-09T05:38:29.4583198Z self = <t.integration.test_canvas.test_chain object at 0x7f609812a2d0>
2024-05-09T05:38:29.4588249Z manager = <celery.contrib.testing.manager.Manager object at 0x7f6097d06a50>
2024-05-09T05:38:29.4591657Z subtests = SubTests(ihook=<_pytest.config.compat.PathAwareHookProxy object at 0x7f609b44ef90>, suspend_capture_ctx=<bound method ...None>>, request=<SubRequest 'subtests' for <Function test_chained_groups_within_chain_ending_with_group_inside_chain>>)
2024-05-09T05:38:29.4594176Z 
2024-05-09T05:38:29.4595169Z     def test_chained_groups_within_chain_ending_with_group_inside_chain(self, manager, subtests):
2024-05-09T05:38:29.4597169Z         try:
2024-05-09T05:38:29.4597881Z             manager.app.backend.ensure_chords_allowed()
2024-05-09T05:38:29.4598715Z         except NotImplementedError as e:
2024-05-09T05:38:29.4599651Z             raise pytest.skip(e.args[0])
2024-05-09T05:38:29.4600333Z     
2024-05-09T05:38:29.4601288Z         if not manager.app.conf.result_backend.startswith('redis'):
2024-05-09T05:38:29.4602405Z             raise pytest.skip('Requires redis result backend.')
2024-05-09T05:38:29.4603141Z     
2024-05-09T05:38:29.4605103Z         redis_connection = get_redis_connection()
2024-05-09T05:38:29.4605998Z         redis_key = 'echo_chamber'
2024-05-09T05:38:29.4606647Z     
2024-05-09T05:38:29.4607268Z         c = chain(
2024-05-09T05:38:29.4607741Z             chain(
2024-05-09T05:38:29.4608268Z                 group(
2024-05-09T05:38:29.4609148Z                     redis_echo.si('1', redis_key=redis_key),
2024-05-09T05:38:29.4610051Z                     redis_echo.si('2', redis_key=redis_key),
2024-05-09T05:38:29.4611053Z                     redis_echo.si('3', redis_key=redis_key)
2024-05-09T05:38:29.4611718Z                 ),
2024-05-09T05:38:29.4612237Z                 group(
2024-05-09T05:38:29.4613017Z                     redis_echo.si('4', redis_key=redis_key),
2024-05-09T05:38:29.4613907Z                     redis_echo.si('5', redis_key=redis_key)
2024-05-09T05:38:29.4614626Z                 ),
2024-05-09T05:38:29.4615146Z             ),
2024-05-09T05:38:29.4615988Z             chain(
2024-05-09T05:38:29.4616551Z                 group(
2024-05-09T05:38:29.4617358Z                     redis_echo.si('6', redis_key=redis_key),
2024-05-09T05:38:29.4618280Z                     redis_echo.si('7', redis_key=redis_key),
2024-05-09T05:38:29.4619126Z                     redis_echo.si('8', redis_key=redis_key),
2024-05-09T05:38:29.4619922Z                 ),
2024-05-09T05:38:29.4620427Z             ),
2024-05-09T05:38:29.4621106Z             chain(redis_echo.si('Done', redis_key='Done')),
2024-05-09T05:38:29.4622214Z         )
2024-05-09T05:38:29.4622622Z     
2024-05-09T05:38:29.4623407Z         with subtests.test(msg='Run the chain and wait for completion'):
2024-05-09T05:38:29.4624555Z             redis_connection.delete(redis_key, 'Done')
2024-05-09T05:38:29.4625373Z             c.delay().get(timeout=TIMEOUT)
2024-05-09T05:38:29.4626451Z             await_redis_list_message_length(1, redis_key='Done', timeout=10)
2024-05-09T05:38:29.4627240Z     
2024-05-09T05:38:29.4627942Z         with subtests.test(msg='All tasks are executed once'):
2024-05-09T05:38:29.4628831Z             actual = [
2024-05-09T05:38:29.4629450Z                 sig.decode('utf-8')
2024-05-09T05:38:29.4630317Z                 for sig in redis_connection.lrange(redis_key, 0, -1)
2024-05-09T05:38:29.4631150Z             ]
2024-05-09T05:38:29.4634491Z             expected = [str(i) for i in range(1, 9)]
2024-05-09T05:38:29.4638557Z             with subtests.test(msg='All tasks are executed once'):
2024-05-09T05:38:29.4639352Z >               assert sorted(actual) == sorted(expected)
2024-05-09T05:38:29.4640144Z E               AssertionError: assert ['1', '2', '3...'5', '6', ...] == ['1', '2', '3...'5', '6', ...]
2024-05-09T05:38:29.4640798Z E                 
2024-05-09T05:38:29.4641187Z E                 At index 6 diff: '6' != '7'
2024-05-09T05:38:29.4641778Z E                 Left contains 3 more items, first extra item: '7'
2024-05-09T05:38:29.4642346Z E                 
2024-05-09T05:38:29.4642710Z E                 Full diff:
2024-05-09T05:38:29.4643081Z E                   [
2024-05-09T05:38:29.4643502Z E                       '1',...
2024-05-09T05:38:29.4643888Z E                 
2024-05-09T05:38:29.4644417Z E                 ...Full output truncated (11 lines hidden), use '-vv' to show
2024-05-09T05:38:29.4644796Z 
2024-05-09T05:38:29.4645101Z t/integration/test_canvas.py:1157: AssertionError

Nice one!
Though I was sure I fixed it last time hmmm…

Logging the error for now. I will also add the -vv to tox.ini maybe..

If this is not useful, feel free to close the PR.

Very useful! Thank you, much appreciated!

I’ll try to get to it around the next week or two - there are a lot of open issues for me to review so I need to reprioritize some stuff to make sense of everything.

[DorSSS]

Hi, I think that my PR also solves your problem: #9021