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

fastward resume worker pool deadlock #298

Closed
plastikfan opened this issue Aug 23, 2023 · 5 comments · Fixed by #300
Closed

fastward resume worker pool deadlock #298

plastikfan opened this issue Aug 23, 2023 · 5 comments · Fixed by #300
Assignees
@plastikfan
Labels
bug Something isn't working

Comments

@plastikfan
Copy link
Contributor

plastikfan commented Aug 23, 2023 •
edited
Loading

Issue #292 (support concurrent traversal), implemented workload acceleration using the worker pool. However, the fastward resume scenario is the only one that causes a deadlock and wait ing on the waitgroup always blocks indefinitely.

One thing that should also be noted, which may be related is the fact that at no point within an accelerated navigation session do we call Done() on the waitgroup for all the other scenarios that do appear to work. This seems counter-intuitive, the wait should only ever get unblocked, when the correct number of Done()'s have been invoked, so this is fishy and may be the hidden cause of the deadlock in a fastward resume scenario. We need to rationalise this and fix so that we can safely invoke Done() in the normal manner.

The ensync method is invoked as part of walk. This is probably unwise and should be delegated to the session. Invoking from walk means that there a complication because what happens during fasward is different to what happens in spawn. We should get rid of these types of differences wherever possible.

For the fastward scenario, note this code (commit: f69db56):

func (s *fastwardStrategy) resume(info *strategyResumeInfo) (*TraverseResult, error) {
	resumeAt := info.ps.Active.NodePath
	s.nc.logger().Info("fastward resume",
		log.String("root-path", info.ps.Active.Root),
		log.String("resume-at-path", resumeAt),
	)

	if info.ai != nil {
		s.ensync(info.ai)
	}

	// fast-forward doesn't need to restore the entire state, eg, the
	// Depth can begin as per usual, without being restored.
	//
	return info.nc.walk(info.ps.Active.Root)
}

This looks wrong because we are invoking ensync inside resume, but walk also does this, which means we get an extra and invalid decoration. This is the reason why we should delegate to the session as by doing this we can be sure that the logic is correct and consistent between fastward and spawn.

Output that shows a fastward resume that timesout the unit test due to deadlock ... 
 ✘ plastikfan@Janus  ~/dev/github/go/snivilised/extendio λ   feat/concurrent-traversal ±  task t
ok      github.com/snivilised/extendio/collections      (cached)
ok      github.com/snivilised/extendio/i18n     (cached)
?       github.com/snivilised/extendio/internal/helpers [no test files]
?       github.com/snivilised/extendio/internal/log     [no test files]
Running Suite: Nav Suite - /home/plastikfan/dev/github/go/snivilised/extendio/xfs/nav
=====================================================================================
Random Seed: 1692784370

Will run 1 of 98 specs
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics'
===> 🧊 WorkerPool.run ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0004f06f0 cancel:0x50a1e0 suite:0xc000128000})
===> 🧊 (#workers: '0') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(❤️)WORKER-ID-1:6c39bc8c-28a3-46cf-a214-07d93fd59e59' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:6bac9462-fa72-441d-98b9-2778f4d720ad) [Seq: -999]
===> 🧊 (#workers: '1') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(💙)WORKER-ID-2:d97fc59d-5810-4b67-910e-0ecb9eddad93' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:0463facf-d98b-4d4f-a08d-c9e7738a7837) [Seq: -999]
        ---> 🚀worker.run((💙)WORKER-ID-2:d97fc59d-5810-4b67-910e-0ecb9eddad93) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0004f06f0 cancel:0x50a1e0 suite:0xc000128000})
        ---> 🚀 worker.run((💙)WORKER-ID-2:d97fc59d-5810-4b67-910e-0ecb9eddad93)(input:'{0xc0002e6000 0x7ccae0}')
        ---> 🚀 worker.run((💙)WORKER-ID-2:d97fc59d-5810-4b67-910e-0ecb9eddad93)(input:'{0xc0002e6070 0x7ccae0}')
        ---> 🚀worker.run((❤️)WORKER-ID-1:6c39bc8c-28a3-46cf-a214-07d93fd59e59) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0004f06f0 cancel:0x50a1e0 suite:0xc000128000})
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics/Night Drive'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics/Night Drive/A1 - The Telephone Call.flac'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics/Night Drive/A2 - Night Drive.flac'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics/Night Drive/cover.night-drive.jpg'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics/Night Drive/vinyl-info.night-drive.txt'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Northern Council'
===> 🧊 (#workers: '2') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(💚)WORKER-ID-3:7950ebde-d144-4bb9-a077-17cb20d79a55' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:ed3e66c8-c006-4f28-8597-bd8c4d00376f) [Seq: -999]
===> 🧊 (#workers: '3') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(💜)WORKER-ID-4:ce8d574c-8217-49cc-af87-7933a219be29' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:93cfd64f-ed67-42bc-8eca-89493b3ab97a) [Seq: -999]
===> 🧊 (#workers: '4') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(💛)WORKER-ID-5:d73f5eaa-408c-4013-8ef0-6de55a5022f2' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:ab040551-6027-48f7-901d-413818813e74) [Seq: -999]
===> 🧊 (#workers: '5') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(🤍)WORKER-ID-6:465cfe4e-eb2c-4559-8a4e-166de5c30cc0' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:9c4189f3-d37f-410b-aa2b-0ceceee74537) [Seq: -999]
===> 🧊 (#workers: '6') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(💖)WORKER-ID-7:a171f1d9-fe78-4cad-8a77-78399ea7f58f' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:fbae96d6-9e19-499f-a8b9-b08b1f9d4ca1) [Seq: -999]
===> 🧊 (#workers: '7') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(💗)WORKER-ID-8:18b78bba-51ed-401f-a39d-b32934bcdb5c' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:5a39ce40-0fa4-458a-bf97-bc52b6e4bb38) [Seq: -999]
        ---> 🚀worker.run((💚)WORKER-ID-3:7950ebde-d144-4bb9-a077-17cb20d79a55) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0004f06f0 cancel:0x50a1e0 suite:0xc000128000})
        ---> 🚀 worker.run((💚)WORKER-ID-3:7950ebde-d144-4bb9-a077-17cb20d79a55)(input:'{0xc0002e61c0 0x7ccae0}')
        ---> 🚀 worker.run((💚)WORKER-ID-3:7950ebde-d144-4bb9-a077-17cb20d79a55)(input:'{0xc0002e6230 0x7ccae0}')
        ---> 🚀 worker.run((💚)WORKER-ID-3:7950ebde-d144-4bb9-a077-17cb20d79a55)(input:'{0xc0002e62a0 0x7ccae0}')
        ---> 🚀 worker.run((💚)WORKER-ID-3:7950ebde-d144-4bb9-a077-17cb20d79a55)(input:'{0xc0002e6310 0x7ccae0}')
        ---> 🚀 worker.run((💙)WORKER-ID-2:d97fc59d-5810-4b67-910e-0ecb9eddad93)(input:'{0xc0002e6150 0x7ccae0}')
        ---> 🚀worker.run((💜)WORKER-ID-4:ce8d574c-8217-49cc-af87-7933a219be29) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0004f06f0 cancel:0x50a1e0 suite:0xc000128000})
        ---> 🚀 worker.run((❤️)WORKER-ID-1:6c39bc8c-28a3-46cf-a214-07d93fd59e59)(input:'{0xc00016c000 0x7ccae0}')
        ---> 🚀worker.run((💛)WORKER-ID-5:d73f5eaa-408c-4013-8ef0-6de55a5022f2) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0004f06f0 cancel:0x50a1e0 suite:0xc000128000})
        ---> 🚀worker.run((🤍)WORKER-ID-6:465cfe4e-eb2c-4559-8a4e-166de5c30cc0) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0004f06f0 cancel:0x50a1e0 suite:0xc000128000})
        ---> 🚀worker.run((💖)WORKER-ID-7:a171f1d9-fe78-4cad-8a77-78399ea7f58f) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0004f06f0 cancel:0x50a1e0 suite:0xc000128000})
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Northern Council/A1 - Incident.flac'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Northern Council/A2 - The Zemlya Expedition.flac'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Northern Council/cover.northern-council.jpg'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Northern Council/vinyl-info.northern-council.txt'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/A1 - Can You Kiss Me First.flac'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/A2 - Teenage Color.flac'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/vinyl-info.teenage-color.txt'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth'
        ---> 🚀worker.run((💗)WORKER-ID-8:18b78bba-51ed-401f-a39d-b32934bcdb5c) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0004f06f0 cancel:0x50a1e0 suite:0xc000128000})
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:b80e2789-5deb-4f37-83b4-a6291cbd959b) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:9b1863c3-e1f8-4474-adbb-3c32bf898ac0) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:5b15e62d-c281-4c4e-b96f-11362eb3505f) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:e7649f1c-0817-4d8b-afce-3d6b5a7efd0c) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:620ae82c-a5d2-48e0-bf8d-8f2f00584f7b) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:f1d9c959-4491-4435-8a37-15eda17690ae) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:6584932a-8101-4f3b-b525-4cd26da7f520) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:759b3442-d3db-45fa-97e0-ec9b97b1a83a) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:83e787cf-d452-4307-aa37-064e74bcef43) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:3cf68fc0-c969-46b5-b4f0-ef5bd8161fd7) [Seq: -999]
        ---> 🚀 worker.run((💗)WORKER-ID-8:18b78bba-51ed-401f-a39d-b32934bcdb5c)(input:'{0xc0002e6690 0x7ccae0}')
        ---> 🚀 worker.run((💗)WORKER-ID-8:18b78bba-51ed-401f-a39d-b32934bcdb5c)(input:'{0xc0002e6770 0x7ccae0}')
        ---> 🚀 worker.run((💗)WORKER-ID-8:18b78bba-51ed-401f-a39d-b32934bcdb5c)(input:'{0xc0002e67e0 0x7ccae0}')
        ---> 🚀 worker.run((💚)WORKER-ID-3:7950ebde-d144-4bb9-a077-17cb20d79a55)(input:'{0xc0002e6380 0x7ccae0}')
        ---> 🚀 worker.run((💙)WORKER-ID-2:d97fc59d-5810-4b67-910e-0ecb9eddad93)(input:'{0xc00016c070 0x7ccae0}')
        ---> 🚀 worker.run((💜)WORKER-ID-4:ce8d574c-8217-49cc-af87-7933a219be29)(input:'{0xc0002e63f0 0x7ccae0}')
        ---> 🚀 worker.run((💛)WORKER-ID-5:d73f5eaa-408c-4013-8ef0-6de55a5022f2)(input:'{0xc0002e64d0 0x7ccae0}')
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/A1 - Before Life.flac'
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:1c577465-634a-4854-8ac6-4dc856839681) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:bb269287-1291-4087-9374-fdcdbb0d1d44) [Seq: -999]
        ---> 🚀 worker.run((💚)WORKER-ID-3:7950ebde-d144-4bb9-a077-17cb20d79a55)(input:'{0xc0002e68c0 0x7ccae0}')
        ---> 🚀 worker.run((🤍)WORKER-ID-6:465cfe4e-eb2c-4559-8a4e-166de5c30cc0)(input:'{0xc0002e6540 0x7ccae0}')
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color'
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:c350c233-b049-4e89-b86b-355cd5410ceb) [Seq: -999]
        ---> 🚀 worker.run((💙)WORKER-ID-2:d97fc59d-5810-4b67-910e-0ecb9eddad93)(input:'{0xc0002e6540 0x7ccae0}')
---> ⏩ ON-ASYNC-CALLBACK(Fastward Resume WithCPUPool(universal: listen pending(logged)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color'
        ---> 🚀 worker.run((💖)WORKER-ID-7:a171f1d9-fe78-4cad-8a77-78399ea7f58f)(input:'{0xc0002e65b0 0x7ccae0}')
---> ⏩ ON-ASYNC-CALLBACK(Fastward Resume WithCPUPool(universal: listen pending(logged)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/A1 - Can You Kiss Me First.flac'
        ---> 🚀 worker.run((💗)WORKER-ID-8:18b78bba-51ed-401f-a39d-b32934bcdb5c)(input:'{0xc0002e6850 0x7ccae0}')
---> ⏩ ON-ASYNC-CALLBACK(Fastward Resume WithCPUPool(universal: listen pending(logged)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld'
        ---> 🚀 worker.run((❤️)WORKER-ID-1:6c39bc8c-28a3-46cf-a214-07d93fd59e59)(input:'{0xc0002e6460 0x7ccae0}')
---> ⏩ ON-ASYNC-CALLBACK(Fastward Resume WithCPUPool(universal: listen pending(logged)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Northern Council/cover.northern-council.jpg'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/A2 - Runaway.flac'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/vinyl-info.innerworld.txt'
---> 😈😈😈 defer session.finish
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:409b8f55-ebac-4f8f-8bdc-cf2e01f02b4b) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:36d47b02-5899-4ab9-858f-4a7828bac5fd) [Seq: -999]
===> 🚀 WorkerPool.run(source jobs chan closed) 🟥🟥🟥
!!!! 🧊 WorkerPool.drain - waiting for remaining workers: 8 (#GRs: 15); 🧊🧊🧊
        ---> 🚀 worker.run((💚)WORKER-ID-3:7950ebde-d144-4bb9-a077-17cb20d79a55)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((💚)WORKER-ID-3:7950ebde-d144-4bb9-a077-17cb20d79a55) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((💚)WORKER-ID-3:7950ebde-d144-4bb9-a077-17cb20d79a55) finished, remaining: '7' 🟥
        ---> 🚀 worker.run((💜)WORKER-ID-4:ce8d574c-8217-49cc-af87-7933a219be29)(input:'{0xc0002e6930 0x7ccae0}')
---> ⏩ ON-ASYNC-CALLBACK(Fastward Resume WithCPUPool(universal: listen pending(logged)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/A2 - Runaway.flac'
        ---> 🚀 worker.run((💛)WORKER-ID-5:d73f5eaa-408c-4013-8ef0-6de55a5022f2)(input:'{0xc0002e69a0 0x7ccae0}')
---> ⏩ ON-ASYNC-CALLBACK(Fastward Resume WithCPUPool(universal: listen pending(logged)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/vinyl-info.innerworld.txt'
        ---> 🚀 worker.run((💗)WORKER-ID-8:18b78bba-51ed-401f-a39d-b32934bcdb5c)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((💗)WORKER-ID-8:18b78bba-51ed-401f-a39d-b32934bcdb5c) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((💗)WORKER-ID-8:18b78bba-51ed-401f-a39d-b32934bcdb5c) finished, remaining: '6' 🟥
        ---> 🚀 worker.run((💖)WORKER-ID-7:a171f1d9-fe78-4cad-8a77-78399ea7f58f)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((💖)WORKER-ID-7:a171f1d9-fe78-4cad-8a77-78399ea7f58f) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((💖)WORKER-ID-7:a171f1d9-fe78-4cad-8a77-78399ea7f58f) finished, remaining: '5' 🟥
        ---> 🚀 worker.run((💙)WORKER-ID-2:d97fc59d-5810-4b67-910e-0ecb9eddad93)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((💙)WORKER-ID-2:d97fc59d-5810-4b67-910e-0ecb9eddad93) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((💙)WORKER-ID-2:d97fc59d-5810-4b67-910e-0ecb9eddad93) finished, remaining: '4' 🟥
        ---> 🚀 worker.run((🤍)WORKER-ID-6:465cfe4e-eb2c-4559-8a4e-166de5c30cc0)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((🤍)WORKER-ID-6:465cfe4e-eb2c-4559-8a4e-166de5c30cc0) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((🤍)WORKER-ID-6:465cfe4e-eb2c-4559-8a4e-166de5c30cc0) finished, remaining: '3' 🟥
        ---> 🚀 worker.invoke((❤️)WORKER-ID-1:6c39bc8c-28a3-46cf-a214-07d93fd59e59)(cancel) - done received 💥💥💥
        ---> 🚀 worker.run((❤️)WORKER-ID-1:6c39bc8c-28a3-46cf-a214-07d93fd59e59)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((❤️)WORKER-ID-1:6c39bc8c-28a3-46cf-a214-07d93fd59e59) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((❤️)WORKER-ID-1:6c39bc8c-28a3-46cf-a214-07d93fd59e59) finished, remaining: '2' 🟥
        ---> 🚀 worker.invoke((💜)WORKER-ID-4:ce8d574c-8217-49cc-af87-7933a219be29)(cancel) - done received 💥💥💥
        ---> 🚀 worker.invoke((💛)WORKER-ID-5:d73f5eaa-408c-4013-8ef0-6de55a5022f2)(cancel) - done received 💥💥💥
        ---> 🚀 worker.run((💛)WORKER-ID-5:d73f5eaa-408c-4013-8ef0-6de55a5022f2)(finished) - done received 🔶🔶🔶
        <--- 🚀 worker.run((💛)WORKER-ID-5:d73f5eaa-408c-4013-8ef0-6de55a5022f2) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((💛)WORKER-ID-5:d73f5eaa-408c-4013-8ef0-6de55a5022f2) finished, remaining: '1' 🟥
        ---> 🚀 worker.run((💜)WORKER-ID-4:ce8d574c-8217-49cc-af87-7933a219be29)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((💜)WORKER-ID-4:ce8d574c-8217-49cc-af87-7933a219be29) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((💜)WORKER-ID-4:ce8d574c-8217-49cc-af87-7933a219be29) finished, remaining: '0' 🟥
===> 🧊 WorkerPool.run - drain complete (workers count: '0'). 🎃🎃🎃
<--- WorkerPool.run (QUIT). 🧊🧊🧊

------------------------------
• [TIMEDOUT] [2.003 seconds]
navigation async [It] 🧪 ===> given: 'Fastward Resume WithCPUPool(universal: listen pending(logged)', should: 'run with context'
/home/plastikfan/dev/github/go/snivilised/extendio/xfs/nav/traverse-navigator-async_test.go:158

  [TIMEDOUT] A spec timeout occurred
  In [It] at: /home/plastikfan/dev/github/go/snivilised/extendio/xfs/nav/traverse-navigator-async_test.go:158 @ 08/23/23 10:52:52.287

  This is the Progress Report generated when the spec timeout occurred:
    navigation async 🧪 ===> given: 'Fastward Resume WithCPUPool(universal: listen pending(logged)', should: 'run with context' (Spec Runtime: 2.001s)
      /home/plastikfan/dev/github/go/snivilised/extendio/xfs/nav/traverse-navigator-async_test.go:158
      In [It] (Node Runtime: 2s)
        /home/plastikfan/dev/github/go/snivilised/extendio/xfs/nav/traverse-navigator-async_test.go:158

      Spec Goroutine
      goroutine 11 [sleep]
        time.Sleep(0x2faf080)
          /usr/local/go/src/runtime/time.go:195
        github.com/fortytw2/leaktest.CheckContext.func1()
          /home/plastikfan/go/pkg/mod/github.com/fortytw2/[email protected]/leaktest.go:144
        github.com/fortytw2/leaktest.CheckTimeout.func1()
          /home/plastikfan/go/pkg/mod/github.com/fortytw2/[email protected]/leaktest.go:113
      > github.com/snivilised/extendio/xfs/nav_test.glob..func6.3({0xaf9320?, 0xc000542300}, 0xc000110ed0)
          /home/plastikfan/dev/github/go/snivilised/extendio/xfs/nav/traverse-navigator-async_test.go:137
            |   wg.Wait()
            |   Expect(err).To(BeNil())
            > },
            | func(entry *asyncTE) string {
            |   return fmt.Sprintf("🧪 ===> given: '%v', should: '%v'", entry.given, entry.should)
        reflect.Value.call({0x94c160?, 0xc000110e40?, 0x13?}, {0x9fdf17, 0x4}, {0xc000542390, 0x2, 0x2?})
          /usr/local/go/src/reflect/value.go:584
        reflect.Value.Call({0x94c160?, 0xc000110e40?, 0xafe2a8?}, {0xc000542390?, 0x0?, 0xc0000c2c80?})
          /usr/local/go/src/reflect/value.go:368
      > github.com/onsi/ginkgo/v2.invokeFunction({0x94c160?, 0xc000110e40}, {0xc000077aa0, 0x2, 0x1?})
          /home/plastikfan/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/table_dsl.go:262
            |   }
            |
            >   return reflect.ValueOf(function).Call(inValues)
            | }
            |
      > github.com/onsi/ginkgo/v2.generateTable.func2.1({0xaf9320?, 0xc000542300?})
          /home/plastikfan/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/table_dsl.go:224
            |                   panic(err)
            |           }
            >           invokeFunction(itBody, append([]interface{}{c}, entry.parameters...))
            |   })
            | } else {
      > github.com/onsi/ginkgo/v2/internal.(*Suite).runNode.func3()
          /home/plastikfan/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/suite.go:865
            |   }()
            |
            >   node.Body(sc)
            |   finished = true
            | }()
      > github.com/onsi/ginkgo/v2/internal.(*Suite).runNode
          /home/plastikfan/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/suite.go:852
            | failureC := make(chan types.Failure)
            |
            > go func() {
            |   finished := false
            |   defer func() {

      Goroutines of Interest
      goroutine 7 [select]
      > github.com/onsi/ginkgo/v2/internal/interrupt_handler.(*InterruptHandler).registerForInterrupts.func2(0x0?)
          /home/plastikfan/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/interrupt_handler/interrupt_handler.go:131
            | var interruptCause InterruptCause
            | for {
            >   select {
            |   case <-signalChannel:
            |           interruptCause = InterruptCauseSignal
      > github.com/onsi/ginkgo/v2/internal/interrupt_handler.(*InterruptHandler).registerForInterrupts
          /home/plastikfan/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/interrupt_handler/interrupt_handler.go:128
            | }
            |
            > go func(abortChannel chan interface{}) {
            |   var interruptCause InterruptCause
            |   for {

      goroutine 8 [select]
      > github.com/onsi/ginkgo/v2/internal.RegisterForProgressSignal.func1()
          /home/plastikfan/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/progress_report.go:32
            | go func() {
            |   for {
            >           select {
            |           case <-signalChannel:
            |                   handler()
      > github.com/onsi/ginkgo/v2/internal.RegisterForProgressSignal
          /home/plastikfan/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/progress_report.go:30
            | }
            | ctx, cancel := context.WithCancel(context.Background())
            > go func() {
            |   for {
            |           select {

      goroutine 37 [chan receive]
        github.com/snivilised/lorax/async.(*WorkerPool[...]).drain(0xc00030e000?, 0xa25436)
          /home/plastikfan/go/pkg/mod/github.com/snivilised/[email protected]/async/worker-pool.go:236
        github.com/snivilised/lorax/async.(*WorkerPool[...]).run(0xc00030e000, {0x7fca5d9e8160, 0xc000542300?}, 0xc00010e120, 0xc00053fce0)
          /home/plastikfan/go/pkg/mod/github.com/snivilised/[email protected]/async/worker-pool.go:159
        github.com/snivilised/lorax/async.(*WorkerPool[...]).Start(0x0?, {0x7fca5d9e8160?, 0xc000542300?}, 0x0?)
          /home/plastikfan/go/pkg/mod/github.com/snivilised/[email protected]/async/worker-pool.go:100
      > github.com/snivilised/extendio/xfs/nav.(*navigationAccelerator).start
          /home/plastikfan/dev/github/go/snivilised/extendio/xfs/nav/navigation-accelerator.go:23
            | // more data will be written to it and will close when complete.
            | //
            > go a.pool.Start(ai.Ctx, ai.OutputsChOut)
            |
            | ai.Wg.Add(1)
------------------------------
SSSSSSSSSSSSSSSSSSS

Summarizing 1 Failure:
  [TIMEDOUT] navigation async [It] 🧪 ===> given: 'Fastward Resume WithCPUPool(universal: listen pending(logged)', should: 'run with context'
  /home/plastikfan/dev/github/go/snivilised/extendio/xfs/nav/traverse-navigator-async_test.go:158

Ran 1 of 98 Specs in 2.006 seconds
FAIL! -- 0 Passed | 1 Failed | 0 Pending | 97 Skipped

<\details>
@plastikfan plastikfan added the bug Something isn't working label Aug 23, 2023
@plastikfan plastikfan self-assigned this Aug 23, 2023
@plastikfan plastikfan linked a pull request Aug 23, 2023 that will close this issue
feat(nav): use context for concurrent navigation (#292) #299
Merged
@plastikfan plastikfan removed a link to a pull request Aug 23, 2023
feat(nav): use context for concurrent navigation (#292) #299
Merged
@plastikfan
Copy link
Contributor Author

Output that shows a spawn resume that completes without deadlock (from the same code version as the failing case) ... 
===> 🧊 WorkerPool.run ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc000580000 cancel:0x50a1e0 suite:0xc00009a000})
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/A1 - Can You Kiss Me First.flac'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/A2 - Teenage Color.flac'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/vinyl-info.teenage-color.txt'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth'
===> 🧊 (#workers: '0') WorkerPool.run - new job received
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/A1 - Before Life.flac'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/A2 - Runaway.flac'
---> 🐬 ASYNC-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/vinyl-info.innerworld.txt'
---> 😈😈😈 defer session.finish
===> 🧊 WorkerPool.spawned new worker: '(❤️)WORKER-ID-1:93f58430-c58c-4bf0-a643-8f01cc9e1b1e' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:079bd8a1-35d0-43ae-b4d5-d3dc4cac91f6) [Seq: -999]
===> 🧊 (#workers: '1') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(💙)WORKER-ID-2:d4690a75-9022-4b67-a770-dfdf0ce57e37' 🎀🎀🎀
        ---> 🚀worker.run((❤️)WORKER-ID-1:93f58430-c58c-4bf0-a643-8f01cc9e1b1e) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc000580000 cancel:0x50a1e0 suite:0xc00009a000})
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:8342b92b-bcfc-49fc-8551-72c5880a9aaf) [Seq: -999]
===> 🧊 (#workers: '2') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(💚)WORKER-ID-3:81087520-da02-44d4-86c3-5e402060b653' 🎀🎀🎀
        ---> 🚀 worker.run((❤️)WORKER-ID-1:93f58430-c58c-4bf0-a643-8f01cc9e1b1e)(input:'{0xc000208230 0x7ccae0}')
---> ⏩ ON-ASYNC-CALLBACK(Spawn Resume WithPool(universal: listen not active/deaf)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color'
        ---> 🚀 worker.run((❤️)WORKER-ID-1:93f58430-c58c-4bf0-a643-8f01cc9e1b1e)(input:'{0xc0002082a0 0x7ccae0}')
---> ⏩ ON-ASYNC-CALLBACK(Spawn Resume WithPool(universal: listen not active/deaf)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/A1 - Can You Kiss Me First.flac'
        ---> 🚀 worker.run((❤️)WORKER-ID-1:93f58430-c58c-4bf0-a643-8f01cc9e1b1e)(input:'{0xc000208310 0x7ccae0}')
---> ⏩ ON-ASYNC-CALLBACK(Spawn Resume WithPool(universal: listen not active/deaf)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/A2 - Teenage Color.flac'
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:5af11d8d-0c0a-4427-b9dc-19ed89898902) [Seq: -999]
===> 🧊 (#workers: '3') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:e46faab8-bdee-4dcb-b355-728263220dbd) [Seq: -999]
===> 🧊 (#workers: '3') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:a51d3221-72cd-4178-8389-5e5e9e0066f8) [Seq: -999]
===> 🧊 (#workers: '3') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:1e40315b-df1c-4cb9-a6e4-884812ebe6df) [Seq: -999]
===> 🧊 (#workers: '3') WorkerPool.run - new job received
        ---> 🚀worker.run((💚)WORKER-ID-3:81087520-da02-44d4-86c3-5e402060b653) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc000580000 cancel:0x50a1e0 suite:0xc00009a000})
        ---> 🚀 worker.run((💚)WORKER-ID-3:81087520-da02-44d4-86c3-5e402060b653)(input:'{0xc0002083f0 0x7ccae0}')
---> ⏩ ON-ASYNC-CALLBACK(Spawn Resume WithPool(universal: listen not active/deaf)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth'
        ---> 🚀 worker.run((❤️)WORKER-ID-1:93f58430-c58c-4bf0-a643-8f01cc9e1b1e)(input:'{0xc000208380 0x7ccae0}')
        ---> 🚀 worker.run((💚)WORKER-ID-3:81087520-da02-44d4-86c3-5e402060b653)(input:'{0xc000208460 0x7ccae0}')
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:f83de701-89a0-4918-a603-65932cd53736) [Seq: -999]
===> 🧊 (#workers: '3') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:b5a3c733-925f-473c-a9de-924e80b08e79) [Seq: -999]
===> 🧊 (#workers: '3') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:6bd43c4e-ebae-4e3c-bd51-09de92e4dc3d) [Seq: -999]
===> 🚀 WorkerPool.run(source jobs chan closed) 🟥🟥🟥
!!!! 🧊 WorkerPool.drain - waiting for remaining workers: 3 (#GRs: 10); 🧊🧊🧊
---> ⏩ ON-ASYNC-CALLBACK(Spawn Resume WithPool(universal: listen not active/deaf)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld'
        ---> 🚀 worker.run((💚)WORKER-ID-3:81087520-da02-44d4-86c3-5e402060b653)(input:'{0xc0002084d0 0x7ccae0}')
---> ⏩ ON-ASYNC-CALLBACK(Spawn Resume WithPool(universal: listen not active/deaf)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/A1 - Before Life.flac'
        ---> 🚀 worker.run((💚)WORKER-ID-3:81087520-da02-44d4-86c3-5e402060b653)(input:'{0xc000208540 0x7ccae0}')
---> ⏩ ON-ASYNC-CALLBACK(Spawn Resume WithPool(universal: listen not active/deaf)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/A2 - Runaway.flac'
        ---> 🚀 worker.run((💚)WORKER-ID-3:81087520-da02-44d4-86c3-5e402060b653)(input:'{0xc0002085b0 0x7ccae0}')
---> ⏩ ON-ASYNC-CALLBACK(Spawn Resume WithPool(universal: listen not active/deaf)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/vinyl-info.innerworld.txt'
        ---> 🚀 worker.run((💚)WORKER-ID-3:81087520-da02-44d4-86c3-5e402060b653)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((💚)WORKER-ID-3:81087520-da02-44d4-86c3-5e402060b653) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((💚)WORKER-ID-3:81087520-da02-44d4-86c3-5e402060b653) finished, remaining: '2' 🟥
---> ⏩ ON-ASYNC-CALLBACK(Spawn Resume WithPool(universal: listen not active/deaf)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/vinyl-info.teenage-color.txt'
        ---> 🚀 worker.run((❤️)WORKER-ID-1:93f58430-c58c-4bf0-a643-8f01cc9e1b1e)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((❤️)WORKER-ID-1:93f58430-c58c-4bf0-a643-8f01cc9e1b1e) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((❤️)WORKER-ID-1:93f58430-c58c-4bf0-a643-8f01cc9e1b1e) finished, remaining: '1' 🟥
        ---> 🚀worker.run((💙)WORKER-ID-2:d4690a75-9022-4b67-a770-dfdf0ce57e37) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc000580000 cancel:0x50a1e0 suite:0xc00009a000})
        ---> 🚀 worker.run((💙)WORKER-ID-2:d4690a75-9022-4b67-a770-dfdf0ce57e37)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((💙)WORKER-ID-2:d4690a75-9022-4b67-a770-dfdf0ce57e37) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((💙)WORKER-ID-2:d4690a75-9022-4b67-a770-dfdf0ce57e37) finished, remaining: '0' 🟥
===> 🧊 WorkerPool.run - drain complete (workers count: '0'). 🎃🎃🎃
<--- WorkerPool.run (QUIT). 🧊🧊🧊
•SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS

Ran 1 of 98 Specs in 0.009 seconds
SUCCESS! -- 1 Passed | 0 Failed | 1 Pending | 96 Skipped

<\details>

@plastikfan
Copy link
Contributor Author

plastikfan commented Aug 24, 2023 •
edited
Loading

We need another object that wraps the wait group to help debug wait group issues (see issue #35).

@plastikfan
Copy link
Contributor Author

plastikfan commented Aug 26, 2023 •
edited
Loading

The deadlock is proving t be intermittent.

This is an example of fastward resume working ok 
           ➕➕➕ [[ WaitGroupAssister(🍂 traversal).Add ]] - gr-name: '✨ observable-navigator' (count: '1') (running: '✨ observable-navigator')
           ➕➕➕ [[ WaitGroupAssister(🍂 traversal).Add ]] - gr-name: '🧊 worker pool' (count: '2') (running: '✨ observable-navigator/🧊 worker pool')
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE'
===> 🧊 WorkerPool.run ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc00054c048 cancel:0x50a1e0 suite:0xc00009e000})
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics'
===> 🧊 (#workers: '0') WorkerPool.run - new job received
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics/Night Drive'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics/Night Drive/A1 - The Telephone Call.flac'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics/Night Drive/A2 - Night Drive.flac'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics/Night Drive/cover.night-drive.jpg'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics/Night Drive/vinyl-info.night-drive.txt'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Northern Council'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Northern Council/A1 - Incident.flac'
        ---> 🚀 worker.run((❤️)WORKER-ID-1:970c84b4-ff2d-4a1d-b535-1e4a8dd60764) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc00054c048 cancel:0x50a1e0 suite:0xc00009e000})
===> 🧊 WorkerPool.spawned new worker: '(❤️)WORKER-ID-1:970c84b4-ff2d-4a1d-b535-1e4a8dd60764' 🎀🎀🎀
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Northern Council/A2 - The Zemlya Expedition.flac'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Northern Council/cover.northern-council.jpg'
        ---> 🚀 worker.run((❤️)WORKER-ID-1:970c84b4-ff2d-4a1d-b535-1e4a8dd60764)(input:'{0xc0005520e0 0x7cd700}')
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Northern Council/vinyl-info.northern-council.txt'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/A1 - Can You Kiss Me First.flac'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/A2 - Teenage Color.flac'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/vinyl-info.teenage-color.txt'
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:9f20c197-4052-4f3f-8fee-af6daf1d1d00) [Seq: -999]
===> 🧊 (#workers: '1') WorkerPool.run - new job received
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth'
===> 🧊 WorkerPool.spawned new worker: '(💙)WORKER-ID-2:f8721219-611e-4128-a933-41a590ab7589' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:1418e6e3-0b59-4538-a4fa-f20b4a75d055) [Seq: -999]
===> 🧊 (#workers: '2') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(💚)WORKER-ID-3:260f42e5-8142-47a0-850d-d20a485bfeb2' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:6e6e6cb9-c7dc-4f6a-9a17-f9d4ec418a28) [Seq: -999]
===> 🧊 (#workers: '3') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(💜)WORKER-ID-4:ea460841-1b53-442b-a873-54fb613241b4' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:15ccb2e5-49e3-4201-8d5f-9f969c5c63fd) [Seq: -999]
===> 🧊 (#workers: '4') WorkerPool.run - new job received
        ---> 🚀 worker.run((💚)WORKER-ID-3:260f42e5-8142-47a0-850d-d20a485bfeb2) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc00054c048 cancel:0x50a1e0 suite:0xc00009e000})
===> 🧊 WorkerPool.spawned new worker: '(💛)WORKER-ID-5:ac3f5c50-7584-4844-bedf-67edacad0889' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:5f1461df-cc0b-45d5-8e5f-113406c428a1) [Seq: -999]
        ---> 🚀 worker.run((❤️)WORKER-ID-1:970c84b4-ff2d-4a1d-b535-1e4a8dd60764)(input:'{0xc000552150 0x7cd700}')
        ---> 🚀 worker.run((❤️)WORKER-ID-1:970c84b4-ff2d-4a1d-b535-1e4a8dd60764)(input:'{0xc000552230 0x7cd700}')
        ---> 🚀 worker.run((❤️)WORKER-ID-1:970c84b4-ff2d-4a1d-b535-1e4a8dd60764)(input:'{0xc0005522a0 0x7cd700}')
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld'
        ---> 🚀 worker.run((💛)WORKER-ID-5:ac3f5c50-7584-4844-bedf-67edacad0889) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc00054c048 cancel:0x50a1e0 suite:0xc00009e000})
===> 🧊 (#workers: '5') WorkerPool.run - new job received
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/A1 - Before Life.flac'
===> 🧊 WorkerPool.spawned new worker: '(🤍)WORKER-ID-6:3ca03cc4-8beb-4385-8012-c9550f25a3e2' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:efd8fa42-aa38-4608-a7e1-550c4489005c) [Seq: -999]
===> 🧊 (#workers: '6') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(💖)WORKER-ID-7:b90ce5b8-430c-4cab-b42f-fb3ce611d887' 🎀🎀🎀
        ---> 🚀 worker.run((🤍)WORKER-ID-6:3ca03cc4-8beb-4385-8012-c9550f25a3e2) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc00054c048 cancel:0x50a1e0 suite:0xc00009e000})
        ---> 🚀 worker.run((💛)WORKER-ID-5:ac3f5c50-7584-4844-bedf-67edacad0889)(input:'{0xc000552380 0x7cd700}')
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:4dc21f53-8fb0-45df-a9c7-f8f54df220a0) [Seq: -999]
        ---> 🚀 worker.run((💙)WORKER-ID-2:f8721219-611e-4128-a933-41a590ab7589) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc00054c048 cancel:0x50a1e0 suite:0xc00009e000})
        ---> 🚀 worker.run((❤️)WORKER-ID-1:970c84b4-ff2d-4a1d-b535-1e4a8dd60764)(input:'{0xc000552310 0x7cd700}')
===> 🧊 (#workers: '7') WorkerPool.run - new job received
        ---> 🚀 worker.run((💚)WORKER-ID-3:260f42e5-8142-47a0-850d-d20a485bfeb2)(input:'{0xc0005521c0 0x7cd700}')
===> 🧊 WorkerPool.spawned new worker: '(💗)WORKER-ID-8:eac7f8b8-15a6-41cf-b84c-d9a1424710fd' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:48dd5592-f959-4e58-84ae-2ac4199b8bb6) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:11464684-d739-49f4-9677-57924b4a5383) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:72d0580b-2161-4ce4-b112-82a68553828d) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
        ---> 🚀 worker.run((💖)WORKER-ID-7:b90ce5b8-430c-4cab-b42f-fb3ce611d887) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc00054c048 cancel:0x50a1e0 suite:0xc00009e000})
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:cf37739d-75e2-4a56-b818-310b20fd7a9e) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
        ---> 🚀 worker.run((💛)WORKER-ID-5:ac3f5c50-7584-4844-bedf-67edacad0889)(input:'{0xc000552460 0x7cd700}')
        ---> 🚀 worker.run((💚)WORKER-ID-3:260f42e5-8142-47a0-850d-d20a485bfeb2)(input:'{0xc0005525b0 0x7cd700}')
        ---> 🚀 worker.run((💜)WORKER-ID-4:ea460841-1b53-442b-a873-54fb613241b4) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc00054c048 cancel:0x50a1e0 suite:0xc00009e000})
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:0b8aa3fb-c626-49d1-b18d-4e51fd333359) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:a5e2c51e-f937-45b1-be6b-4b9549856b85) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:03484572-e422-4a57-881e-b2f2fd2ed893) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:2ce2a599-e5ee-4908-8414-c016e50bdaff) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:169f09d0-9512-4cec-b19a-506a8e39df3a) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:446efcdf-4858-4875-b13f-08967f05d635) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:fdc608ba-8c8b-4620-89f1-b14536a8e276) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:76a2b39b-8d34-40d0-95ea-358b46c30515) [Seq: -999]
        ---> 🚀 worker.run((💗)WORKER-ID-8:eac7f8b8-15a6-41cf-b84c-d9a1424710fd) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc00054c048 cancel:0x50a1e0 suite:0xc00009e000})
        ---> 🚀 worker.run((💜)WORKER-ID-4:ea460841-1b53-442b-a873-54fb613241b4)(input:'{0xc0005527e0 0x7cd700}')
        ---> 🚀 worker.run((💜)WORKER-ID-4:ea460841-1b53-442b-a873-54fb613241b4)(input:'{0xc0005528c0 0x7cd700}')
        ---> 🚀 worker.run((💜)WORKER-ID-4:ea460841-1b53-442b-a873-54fb613241b4)(input:'{0xc000552930 0x7cd700}')
        ---> 🚀 worker.run((❤️)WORKER-ID-1:970c84b4-ff2d-4a1d-b535-1e4a8dd60764)(input:'{0xc000552540 0x7cd700}')
        ---> 🚀 worker.run((🤍)WORKER-ID-6:3ca03cc4-8beb-4385-8012-c9550f25a3e2)(input:'{0xc0005523f0 0x7cd700}')
        ---> 🚀 worker.run((💙)WORKER-ID-2:f8721219-611e-4128-a933-41a590ab7589)(input:'{0xc0005524d0 0x7cd700}')
        ---> 🚀 worker.run((💛)WORKER-ID-5:ac3f5c50-7584-4844-bedf-67edacad0889)(input:'{0xc000552690 0x7cd700}')
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/A2 - Runaway.flac'
        ---> 🚀 worker.run((💖)WORKER-ID-7:b90ce5b8-430c-4cab-b42f-fb3ce611d887)(input:'{0xc000552620 0x7cd700}')
---> ⏩ ON-ASYNC-CALLBACK(Fastward Resume WithCPUPool(universal: listen pending(logged)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Northern Council/vinyl-info.northern-council.txt'
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:7e14cf46-476d-4bb0-86a1-fce0ed969312) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:16020899-55c1-4826-914e-dc048c67657a) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:d7871c5b-e85f-4531-9dd9-2b9782e54914) [Seq: -999]
        ---> 🚀 worker.run((🤍)WORKER-ID-6:3ca03cc4-8beb-4385-8012-c9550f25a3e2)(input:'{0xc0002d00e0 0x7cd700}')
---> ⏩ ON-ASYNC-CALLBACK(Fastward Resume WithCPUPool(universal: listen pending(logged)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/A2 - Runaway.flac'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/vinyl-info.innerworld.txt'
        ---> 🚀 worker.run((💗)WORKER-ID-8:eac7f8b8-15a6-41cf-b84c-d9a1424710fd)(input:'{0xc000552850 0x7cd700}')
---> ⏩ ON-ASYNC-CALLBACK(Fastward Resume WithCPUPool(universal: listen pending(logged)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/vinyl-info.teenage-color.txt'
        ---> 🚀 worker.run((💚)WORKER-ID-3:260f42e5-8142-47a0-850d-d20a485bfeb2)(input:'{0xc000552770 0x7cd700}')
---> ⏩ ON-ASYNC-CALLBACK(Fastward Resume WithCPUPool(universal: listen pending(logged)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/A1 - Can You Kiss Me First.flac'
        ---> 🚀 worker.run((❤️)WORKER-ID-1:970c84b4-ff2d-4a1d-b535-1e4a8dd60764)(input:'{0xc000552690 0x7cd700}')
        ---> 🚀 worker.run((💜)WORKER-ID-4:ea460841-1b53-442b-a873-54fb613241b4)(input:'{0xc0002d0000 0x7cd700}')
---> ⏩ ON-ASYNC-CALLBACK(Fastward Resume WithCPUPool(universal: listen pending(logged)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color'
---> observable navigator 😈😈😈 defer session.finish (CLOSE(JobsChanOut)/QUIT)
                🚩🚩🚩 [[ WaitGroupAssister(🍂 traversal).Done ]] - gr-name: '✨ observable-navigator' (count: '1') (running: '🧊 worker pool')
                🧭🧭🧭 [[ WaitGroupAssister(🍂 traversal).Wait ]] - gr-name: '👾 test-main' (count: '1') (running: '🧊 worker pool')
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:f563afe5-e5ea-4f78-a2b0-eb0deab90ce7) [Seq: -999]
===> 🚀 WorkerPool.run(source jobs chan closed) 🟥🟥🟥
!!!! 🧊 WorkerPool.drain - waiting for remaining workers: 8 (#GRs: 15); 🧊🧊🧊
        ---> 🚀 worker.run((💚)WORKER-ID-3:260f42e5-8142-47a0-850d-d20a485bfeb2)(jobs chan closed) 🟥🟥🟥
        ---> 🚀 worker.run((💖)WORKER-ID-7:b90ce5b8-430c-4cab-b42f-fb3ce611d887)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((💚)WORKER-ID-3:260f42e5-8142-47a0-850d-d20a485bfeb2) (SENT FINISHED). 🚀🚀🚀
        ---> 🚀 worker.run((❤️)WORKER-ID-1:970c84b4-ff2d-4a1d-b535-1e4a8dd60764)(jobs chan closed) 🟥🟥🟥
        ---> 🚀 worker.run((💛)WORKER-ID-5:ac3f5c50-7584-4844-bedf-67edacad0889)(jobs chan closed) 🟥🟥🟥
        ---> 🚀 worker.run((💙)WORKER-ID-2:f8721219-611e-4128-a933-41a590ab7589)(input:'{0xc0000d2000 0x7cd700}')
---> ⏩ ON-ASYNC-CALLBACK(Fastward Resume WithCPUPool(universal: listen pending(logged)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/vinyl-info.innerworld.txt'
!!!! 🧊 WorkerPool.drain - worker((💚)WORKER-ID-3:260f42e5-8142-47a0-850d-d20a485bfeb2) finished, remaining: '7' 🟥
        <--- 🚀 worker.run((❤️)WORKER-ID-1:970c84b4-ff2d-4a1d-b535-1e4a8dd60764) (SENT FINISHED). 🚀🚀🚀
        <--- 🚀 worker.run((💖)WORKER-ID-7:b90ce5b8-430c-4cab-b42f-fb3ce611d887) (SENT FINISHED). 🚀🚀🚀
---> ⏩ ON-ASYNC-CALLBACK(Fastward Resume WithCPUPool(universal: listen pending(logged)/run with context) '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/A1 - Before Life.flac'
        ---> 🚀 worker.run((💜)WORKER-ID-4:ea460841-1b53-442b-a873-54fb613241b4)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((💜)WORKER-ID-4:ea460841-1b53-442b-a873-54fb613241b4) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((💖)WORKER-ID-7:b90ce5b8-430c-4cab-b42f-fb3ce611d887) finished, remaining: '6' 🟥
!!!! 🧊 WorkerPool.drain - worker((❤️)WORKER-ID-1:970c84b4-ff2d-4a1d-b535-1e4a8dd60764) finished, remaining: '5' 🟥
!!!! 🧊 WorkerPool.drain - worker((💛)WORKER-ID-5:ac3f5c50-7584-4844-bedf-67edacad0889) finished, remaining: '4' 🟥
!!!! 🧊 WorkerPool.drain - worker((💜)WORKER-ID-4:ea460841-1b53-442b-a873-54fb613241b4) finished, remaining: '3' 🟥
        ---> 🚀 worker.run((🤍)WORKER-ID-6:3ca03cc4-8beb-4385-8012-c9550f25a3e2)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((🤍)WORKER-ID-6:3ca03cc4-8beb-4385-8012-c9550f25a3e2) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((🤍)WORKER-ID-6:3ca03cc4-8beb-4385-8012-c9550f25a3e2) finished, remaining: '2' 🟥
        ---> 🚀 worker.run((💗)WORKER-ID-8:eac7f8b8-15a6-41cf-b84c-d9a1424710fd)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((💗)WORKER-ID-8:eac7f8b8-15a6-41cf-b84c-d9a1424710fd) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((💗)WORKER-ID-8:eac7f8b8-15a6-41cf-b84c-d9a1424710fd) finished, remaining: '1' 🟥
        ---> 🚀 worker.run((💙)WORKER-ID-2:f8721219-611e-4128-a933-41a590ab7589)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((💙)WORKER-ID-2:f8721219-611e-4128-a933-41a590ab7589) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((💙)WORKER-ID-2:f8721219-611e-4128-a933-41a590ab7589) finished, remaining: '0' 🟥
===> 🧊 WorkerPool.run - drain complete (workers count: '0'). 🎃🎃🎃
        <--- 🚀 worker.run((💛)WORKER-ID-5:ac3f5c50-7584-4844-bedf-67edacad0889) (SENT FINISHED). 🚀🚀🚀
                🚩🚩🚩 [[ WaitGroupAssister(🍂 traversal).Done ]] - gr-name: '🧊 worker pool' (count: '0') (running: '')
<--- WorkerPool.run (QUIT). 🧊🧊🧊
•SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS

Ran 1 of 98 Specs in 0.022 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 97 Skipped

@plastikfan
Copy link
Contributor Author

plastikfan commented Aug 26, 2023 •
edited
Loading

... and here is an example of the fastward failing due to panic caused by sending on closed channel:

panic: send on closed channel 
               ➕➕➕ [[ WaitGroupAssister(🍂 traversal).Add ]] - gr-name: '✨ observable-navigator' (count: '1') (running: '✨ observable-navigator')
                ➕➕➕ [[ WaitGroupAssister(🍂 traversal).Add ]] - gr-name: '🧊 worker pool' (count: '2') (running: '✨ observable-navigator/🧊 worker pool')
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE'
===> 🧊 WorkerPool.run ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0000132c0 cancel:0x50a1e0 suite:0xc00012a000})
===> 🧊 (#workers: '0') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(❤️)WORKER-ID-1:269794d1-34a4-41e8-9ee8-8895a7871c3a' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:9989fa94-2966-4d4e-a1a3-c1a252a2422c) [Seq: -999]
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics'
        ---> 🚀 worker.run((❤️)WORKER-ID-1:269794d1-34a4-41e8-9ee8-8895a7871c3a) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0000132c0 cancel:0x50a1e0 suite:0xc00012a000})
        ---> 🚀 worker.run((❤️)WORKER-ID-1:269794d1-34a4-41e8-9ee8-8895a7871c3a)(input:'{0xc0000f2230 0x7cd700}')
===> 🧊 (#workers: '1') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(💙)WORKER-ID-2:a125907b-6d77-4360-a442-c7337c59324a' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:5338845a-0caa-45f2-bfc6-e4cfd8fbaa71) [Seq: -999]
        ---> 🚀 worker.run((❤️)WORKER-ID-1:269794d1-34a4-41e8-9ee8-8895a7871c3a)(input:'{0xc0000f22a0 0x7cd700}')
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics/Night Drive'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics/Night Drive/A1 - The Telephone Call.flac'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics/Night Drive/A2 - Night Drive.flac'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics/Night Drive/cover.night-drive.jpg'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Chromatics/Night Drive/vinyl-info.night-drive.txt'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Northern Council'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Northern Council/A1 - Incident.flac'
        ---> 🚀 worker.run((💙)WORKER-ID-2:a125907b-6d77-4360-a442-c7337c59324a) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0000132c0 cancel:0x50a1e0 suite:0xc00012a000})
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Northern Council/A2 - The Zemlya Expedition.flac'
===> 🧊 (#workers: '2') WorkerPool.run - new job received
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Northern Council/cover.northern-council.jpg'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Northern Council/vinyl-info.northern-council.txt'
===> 🧊 WorkerPool.spawned new worker: '(💚)WORKER-ID-3:42429057-7a3b-4171-88aa-be7dc2ffccb0' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:75e752f8-c2d7-404e-a2ee-1f0090ea1f35) [Seq: -999]
===> 🧊 (#workers: '3') WorkerPool.run - new job received
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/A1 - Can You Kiss Me First.flac'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/A2 - Teenage Color.flac'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color/vinyl-info.teenage-color.txt'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth'
===> 🧊 WorkerPool.spawned new worker: '(💜)WORKER-ID-4:dc8f8db4-f77f-4b09-b120-81f8f97e7f48' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:9d87bd12-7c17-4136-8e79-c2a9b867a540) [Seq: -999]
===> 🧊 (#workers: '4') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(💛)WORKER-ID-5:191fb876-f70b-4c7e-86ef-a9dda4734e1c' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:498bc3e3-ed04-4f95-b2c0-603415b80e83) [Seq: -999]
===> 🧊 (#workers: '5') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(🤍)WORKER-ID-6:05fcf3ef-f941-42a9-915a-c436e4db7f8b' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:805da2d5-9688-48eb-bec2-10877201240a) [Seq: -999]
===> 🧊 (#workers: '6') WorkerPool.run - new job received
===> 🧊 WorkerPool.spawned new worker: '(💖)WORKER-ID-7:807cd49e-1a64-4bf5-8883-684c489932af' 🎀🎀🎀
        ---> 🚀 worker.run((💜)WORKER-ID-4:dc8f8db4-f77f-4b09-b120-81f8f97e7f48) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0000132c0 cancel:0x50a1e0 suite:0xc00012a000})
        ---> 🚀 worker.run((💜)WORKER-ID-4:dc8f8db4-f77f-4b09-b120-81f8f97e7f48)(input:'{0xc00016a0e0 0x7cd700}')
        ---> 🚀 worker.run((💜)WORKER-ID-4:dc8f8db4-f77f-4b09-b120-81f8f97e7f48)(input:'{0xc00016a150 0x7cd700}')
        ---> 🚀 worker.run((💜)WORKER-ID-4:dc8f8db4-f77f-4b09-b120-81f8f97e7f48)(input:'{0xc00016a1c0 0x7cd700}')
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld'
        ---> 🚀 worker.run((💙)WORKER-ID-2:a125907b-6d77-4360-a442-c7337c59324a)(input:'{0xc00016a070 0x7cd700}')
        ---> 🚀 worker.run((❤️)WORKER-ID-1:269794d1-34a4-41e8-9ee8-8895a7871c3a)(input:'{0xc00016a000 0x7cd700}')
        ---> 🚀 worker.run((💚)WORKER-ID-3:42429057-7a3b-4171-88aa-be7dc2ffccb0) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0000132c0 cancel:0x50a1e0 suite:0xc00012a000})
        ---> 🚀 worker.run((🤍)WORKER-ID-6:05fcf3ef-f941-42a9-915a-c436e4db7f8b) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0000132c0 cancel:0x50a1e0 suite:0xc00012a000})
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:c509418a-0231-44d4-af4c-611f9f9bb54a) [Seq: -999]
        ---> 🚀 worker.run((💖)WORKER-ID-7:807cd49e-1a64-4bf5-8883-684c489932af) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0000132c0 cancel:0x50a1e0 suite:0xc00012a000})
        ---> 🚀 worker.run((💛)WORKER-ID-5:191fb876-f70b-4c7e-86ef-a9dda4734e1c) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0000132c0 cancel:0x50a1e0 suite:0xc00012a000})
===> 🧊 (#workers: '7') WorkerPool.run - new job received
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/A1 - Before Life.flac'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/A2 - Runaway.flac'
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/Electric Youth/Innerworld/vinyl-info.innerworld.txt'
---> observable navigator 😈😈😈 defer session.finish (CLOSE(JobsChanOut)/QUIT)
                🚩🚩🚩 [[ WaitGroupAssister(🍂 traversal).Done ]] - gr-name: '✨ observable-navigator' (count: '1') (running: '🧊 worker pool')
                🧭🧭🧭 [[ WaitGroupAssister(🍂 traversal).Wait ]] - gr-name: '👾 test-main' (count: '1') (running: '🧊 worker pool')
        ---> 🚀 worker.run((💗)WORKER-ID-8:8f346dd2-2d02-4f6e-9414-ea4fd5bc58cf) ...(ctx:&{Context:context.Background.WithCancel.WithValue(type string, val <not Stringer>) ProgressReporterManager:0xc0000132c0 cancel:0x50a1e0 suite:0xc00012a000})
===> 🧊 WorkerPool.spawned new worker: '(💗)WORKER-ID-8:8f346dd2-2d02-4f6e-9414-ea4fd5bc58cf' 🎀🎀🎀
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:4cf07519-38f6-4a30-a998-af029f1dc7c7) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:436027e4-2fb2-4fa2-a7a8-db9825c3bec9) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:6c1235d9-5818-4fb4-bbb0-a33c27452bef) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:ea220be5-8a25-4d33-93b2-d8e059b3df29) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:c2673c61-4525-4d36-b18c-dff1d2241d2f) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:d01892bb-ef24-4f2d-baa1-791229874c66) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:1ade1416-27a8-417c-8599-12eb2f1865a1) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:53e8ae1b-cadc-4793-bd80-eeb668e5c3ee) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:8ccf140e-4716-405d-b030-21d329c90c89) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:25d63e27-85fb-4bc2-ba88-2be845aac194) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:a6d0ccd2-cc97-4099-8965-2fe12bcb3bd3) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:0ad5c028-2eda-4bb1-8f22-03529fbf17d7) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:453a2eb8-3729-4c5f-824d-fe1c64905841) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:cb6be59b-fb86-436d-86e6-a5f1e899dc65) [Seq: -999]
===> 🧊 (#workers: '8') WorkerPool.run - new job received
===> 🧊 WorkerPool.run - forwarded job 🧿🧿🧿(JOB-ID:c8ca053e-67cd-4757-a8ec-746c1639f316) [Seq: -999]
===> 🚀 WorkerPool.run(source jobs chan closed) 🟥🟥🟥
!!!! 🧊 WorkerPool.drain - waiting for remaining workers: 8 (#GRs: 15); 🧊🧊🧊
        ---> 🚀 worker.run((💗)WORKER-ID-8:8f346dd2-2d02-4f6e-9414-ea4fd5bc58cf)(input:'{0xc00016a5b0 0x7cd700}')
        ---> 🚀 worker.run((💗)WORKER-ID-8:8f346dd2-2d02-4f6e-9414-ea4fd5bc58cf)(input:'{0xc00016a620 0x7cd700}')
        ---> 🚀 worker.run((💗)WORKER-ID-8:8f346dd2-2d02-4f6e-9414-ea4fd5bc58cf)(input:'{0xc00016a690 0x7cd700}')
        ---> 🚀 worker.run((💗)WORKER-ID-8:8f346dd2-2d02-4f6e-9414-ea4fd5bc58cf)(input:'{0xc00016a700 0x7cd700}')
        ---> 🚀 worker.run((💗)WORKER-ID-8:8f346dd2-2d02-4f6e-9414-ea4fd5bc58cf)(input:'{0xc00016a770 0x7cd700}')
        ---> 🚀 worker.run((💗)WORKER-ID-8:8f346dd2-2d02-4f6e-9414-ea4fd5bc58cf)(input:'{0xc0000f2310 0x7cd700}')
        ---> 🚀 worker.run((💗)WORKER-ID-8:8f346dd2-2d02-4f6e-9414-ea4fd5bc58cf)(input:'{0xc0000f2380 0x7cd700}')
        ---> 🚀 worker.run((💗)WORKER-ID-8:8f346dd2-2d02-4f6e-9414-ea4fd5bc58cf)(input:'{0xc0000f23f0 0x7cd700}')
        ---> 🚀 worker.run((💗)WORKER-ID-8:8f346dd2-2d02-4f6e-9414-ea4fd5bc58cf)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((💗)WORKER-ID-8:8f346dd2-2d02-4f6e-9414-ea4fd5bc58cf) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((💗)WORKER-ID-8:8f346dd2-2d02-4f6e-9414-ea4fd5bc58cf) finished, remaining: '7' 🟥
        ---> 🚀 worker.run((💜)WORKER-ID-4:dc8f8db4-f77f-4b09-b120-81f8f97e7f48)(input:'{0xc00016a230 0x7cd700}')
        ---> 🚀 worker.run((💜)WORKER-ID-4:dc8f8db4-f77f-4b09-b120-81f8f97e7f48)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((💜)WORKER-ID-4:dc8f8db4-f77f-4b09-b120-81f8f97e7f48) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((💜)WORKER-ID-4:dc8f8db4-f77f-4b09-b120-81f8f97e7f48) finished, remaining: '6' 🟥
        ---> 🚀 worker.run((💙)WORKER-ID-2:a125907b-6d77-4360-a442-c7337c59324a)(input:'{0xc00016a2a0 0x7cd700}')
        ---> 🚀 worker.run((💙)WORKER-ID-2:a125907b-6d77-4360-a442-c7337c59324a)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((💙)WORKER-ID-2:a125907b-6d77-4360-a442-c7337c59324a) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((💙)WORKER-ID-2:a125907b-6d77-4360-a442-c7337c59324a) finished, remaining: '5' 🟥
        ---> 🚀 worker.run((❤️)WORKER-ID-1:269794d1-34a4-41e8-9ee8-8895a7871c3a)(input:'{0xc00016a310 0x7cd700}')
        ---> 🚀 worker.run((❤️)WORKER-ID-1:269794d1-34a4-41e8-9ee8-8895a7871c3a)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((❤️)WORKER-ID-1:269794d1-34a4-41e8-9ee8-8895a7871c3a) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((❤️)WORKER-ID-1:269794d1-34a4-41e8-9ee8-8895a7871c3a) finished, remaining: '4' 🟥
        ---> 🚀 worker.run((💖)WORKER-ID-7:807cd49e-1a64-4bf5-8883-684c489932af)(input:'{0xc00016a4d0 0x7cd700}')
        ---> 🚀 worker.run((💖)WORKER-ID-7:807cd49e-1a64-4bf5-8883-684c489932af)(jobs chan closed) 🟥🟥🟥
        <--- 🚀 worker.run((💖)WORKER-ID-7:807cd49e-1a64-4bf5-8883-684c489932af) (SENT FINISHED). 🚀🚀🚀
!!!! 🧊 WorkerPool.drain - worker((💖)WORKER-ID-7:807cd49e-1a64-4bf5-8883-684c489932af) finished, remaining: '3' 🟥
        ---> 🚀 worker.run((💛)WORKER-ID-5:191fb876-f70b-4c7e-86ef-a9dda4734e1c)(input:'{0xc00016a540 0x7cd700}')
---> 🐬 ENSYNC-NAV-CALLBACK: '/home/plastikfan/dev/github/go/snivilised/extendio/Test/data/MUSICO/RETRO-WAVE/College/Teenage Color'
        <--- 🚀 worker.run((💛)WORKER-ID-5:191fb876-f70b-4c7e-86ef-a9dda4734e1c) (SENT FINISHED). 🚀🚀🚀
panic: send on closed channel

goroutine 38 [running]:
github.com/snivilised/extendio/xfs/nav.(*navigator).ensync.func1(0xc00016a540)
        /home/plastikfan/dev/github/go/snivilised/extendio/xfs/nav/navigator-abstract.go:44 +0x1ef
github.com/snivilised/extendio/xfs/nav.(*navigationListener).makeStates.func1(0xc00016a540)
        /home/plastikfan/dev/github/go/snivilised/extendio/xfs/nav/navigation-listener.go:91 +0x7d
github.com/snivilised/extendio/xfs/nav.(*navigationListener).decorate.func1(0xc0000820c0?)
        /home/plastikfan/dev/github/go/snivilised/extendio/xfs/nav/navigation-listener.go:164 +0x22
github.com/snivilised/extendio/xfs/nav.traverseExecutive({{0xc000032810, 0x2b}, {0xc00016a540, 0xc000114730}, 0xfffffffffffffc19})
        /home/plastikfan/dev/github/go/snivilised/extendio/xfs/nav/navigation-accelerator.go:31 +0x38
github.com/snivilised/lorax/async.(*worker[...]).invoke(0xc0002040c0?, {0x7f826c5dc438, 0xc0001935c0}, {{0xc000032810, 0x2b}, {0xc00016a540, 0xc000114730}, 0xfffffffffffffc19})
        /home/plastikfan/go/pkg/mod/github.com/snivilised/[email protected]/async/worker.go:47 +0xb0
github.com/snivilised/lorax/async.(*worker[...]).run(0xc0002040c0, {0x7f826c5dc438, 0xc0001935c0?})
        /home/plastikfan/go/pkg/mod/github.com/snivilised/[email protected]/async/worker.go:36 +0x316
created by github.com/snivilised/lorax/async.(*WorkerPool[...]).spawn
        /home/plastikfan/go/pkg/mod/github.com/snivilised/[email protected]/async/worker-pool.go:188 +0x271
FAIL    github.com/snivilised/extendio/xfs/nav  0.017s
ok      github.com/snivilised/extendio/xfs/utils        (cached)
FAIL

The intermittency means we have a race condition.

@plastikfan
Copy link
Contributor Author

It looks like the wrong go routine is closing the jobs channel. The workers send to the jobs channel, but none of them can close the channel as there are multiple writers. Therefore, the workers send their own finished notification to the worker pool. Whilst the pool is in its drain phase, it will countdown until there are no workers left (determined by the number of entries in the worker collection). When the worker collection is empty, it will close the jobs channel on behalf of the workers. However, this seems to create a race condition that only manifests in the fastward scenario.

plastikfan added a commit that referenced this issue Aug 26, 2023
@plastikfan
fix(nav): make resume strategies use of work pool consistent (#298)
1051138
plastikfan added a commit that referenced this issue Aug 26, 2023
@plastikfan
fix(nav): integrate annotated work group into navigator worker pool (#…
228cb83 
…298)
@plastikfan plastikfan linked a pull request Aug 26, 2023 that will close this issue
fix(nav): make resume strategies use of work pool consistent (#298) #300
Merged
plastikfan added a commit that referenced this issue Aug 26, 2023
@plastikfan
fix(nav): make resume strategies use of work pool consistent (#298)
b874f5e
plastikfan added a commit that referenced this issue Aug 26, 2023
@plastikfan
fix(nav): integrate annotated work group into navigator worker pool (#…
e09d3ee 
…298)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@plastikfan plastikfan

Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

fix(nav): make resume strategies use of work pool consistent (#298) snivilised/extendio
1 participant
@plastikfan