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.

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

Chat download task never finishes #354

Closed
russelg opened this issue Jan 13, 2024 · 15 comments
Closed

Chat download task never finishes #354

russelg opened this issue Jan 13, 2024 · 15 comments

Comments

@russelg
Copy link

russelg commented Jan 13, 2024

On most (not every) live archive that runs for me, the Chat Download task does not mark itself as finished. However, Chat Convert/Render/Move all occur and succeed afterwards. Due to this, the queue entry is never finished, and I've had to go and set the queue entry and the vod to not processing.

These lines are the most relevant:

{"level":"debug","ActivityID":{},"Attempt":1,"Namespace":"default","RunID":"1fb2d45b-0794-4cc8-9fdd-30f8cea4962c","TaskQueue":"archive","WorkerID":"f73ae91174e2","WorkflowID":"a3aae82e-6090-403b-ab6e-340b68c8a668_37","WorkflowType":"DownloadTwitchLiveChatWorkflow","time":"2024-01-13T15:22:31+08:00","message":"RequestCancelActivity"}
{"level":"debug","ActivityID":"15","ActivityType":"KillTwitchLiveChatDownload","Attempt":1,"Namespace":"default","RunID":"1fb2d45b-0794-4cc8-9fdd-30f8cea4962c","TaskQueue":"archive","WorkerID":"f73ae91174e2","WorkflowID":"a3aae82e-6090-403b-ab6e-340b68c8a668_37","WorkflowType":"DownloadTwitchLiveChatWorkflow","time":"2024-01-13T15:22:31+08:00","message":"ExecuteActivity"}
{"level":"error","ActivityType":"KillTwitchLiveChatDownload","Attempt":1,"Error":"exit status 1","Namespace":"default","RunID":"1fb2d45b-0794-4cc8-9fdd-30f8cea4962c","TaskQueue":"archive","WorkerID":"f73ae91174e2","WorkflowID":"a3aae82e-6090-403b-ab6e-340b68c8a668_37","time":"2024-01-13T15:22:31+08:00","message":"Activity error."}

From inside temporal:
image

Here is a full log for all mentions of a certain vod, and the chat download workflow that is "cancelled" as well.

{"level":"debug","time":"2024-01-13T08:36:47+08:00","message":"workflow id d59ef217-b1ab-11ee-9576-0242ac12000f started for live stream 42209411369"}
{"level":"debug","Attempt":1,"ChildWorkflowID":"a3aae82e-6090-403b-ab6e-340b68c8a668_5","Namespace":"default","RunID":"a3aae82e-6090-403b-ab6e-340b68c8a668","TaskQueue":"archive","WorkerID":"f73ae91174e2","WorkflowID":"d59ef217-b1ab-11ee-9576-0242ac12000f","WorkflowType":"CreateDirectoryWorkflow","time":"2024-01-13T08:36:47+08:00","message":"ExecuteChildWorkflow"}
{"level":"debug","time":"2024-01-13T08:36:47+08:00","message":"creating folder: 420jenkins/2024-01-13 - absolute_downward_spiral_sort_of_day [42209411369][live][d59ef217-b1ab-11ee-9576-0242ac12000f]"}
{"level":"debug","Attempt":1,"ChildWorkflowID":"a3aae82e-6090-403b-ab6e-340b68c8a668_14","Namespace":"default","RunID":"a3aae82e-6090-403b-ab6e-340b68c8a668","TaskQueue":"archive","WorkerID":"f73ae91174e2","WorkflowID":"d59ef217-b1ab-11ee-9576-0242ac12000f","WorkflowType":"DownloadTwitchLiveThumbnailsWorkflow","time":"2024-01-13T08:36:47+08:00","message":"ExecuteChildWorkflow"}
{"level":"debug","Attempt":1,"ChildWorkflowID":"a3aae82e-6090-403b-ab6e-340b68c8a668_23","Namespace":"default","RunID":"a3aae82e-6090-403b-ab6e-340b68c8a668","TaskQueue":"archive","WorkerID":"f73ae91174e2","WorkflowID":"d59ef217-b1ab-11ee-9576-0242ac12000f","WorkflowType":"SaveTwitchLiveVideoInfoWorkflow","time":"2024-01-13T08:36:48+08:00","message":"ExecuteChildWorkflow"}
{"level":"debug","Attempt":1,"ChildWorkflowID":"a3aae82e-6090-403b-ab6e-340b68c8a668_32","Namespace":"default","RunID":"a3aae82e-6090-403b-ab6e-340b68c8a668","TaskQueue":"archive","WorkerID":"f73ae91174e2","WorkflowID":"d59ef217-b1ab-11ee-9576-0242ac12000f","WorkflowType":"ArchiveTwitchLiveChatWorkflow","time":"2024-01-13T08:36:48+08:00","message":"ExecuteChildWorkflow"}
{"level":"debug","Attempt":1,"ChildWorkflowID":"a3aae82e-6090-403b-ab6e-340b68c8a668_37","Namespace":"default","RunID":"a3aae82e-6090-403b-ab6e-340b68c8a668","TaskQueue":"archive","WorkerID":"f73ae91174e2","WorkflowID":"d59ef217-b1ab-11ee-9576-0242ac12000f","WorkflowType":"DownloadTwitchLiveChatWorkflow","time":"2024-01-13T08:36:48+08:00","message":"ExecuteChildWorkflow"}
{"level":"debug","time":"2024-01-13T08:36:48+08:00","message":"Live chat workflow ID: a3aae82e-6090-403b-ab6e-340b68c8a668_37"}
{"level":"debug","Attempt":1,"ChildWorkflowID":"a3aae82e-6090-403b-ab6e-340b68c8a668_42","Namespace":"default","RunID":"a3aae82e-6090-403b-ab6e-340b68c8a668","TaskQueue":"archive","WorkerID":"f73ae91174e2","WorkflowID":"d59ef217-b1ab-11ee-9576-0242ac12000f","WorkflowType":"ArchiveTwitchLiveVideoWorkflow","time":"2024-01-13T08:36:48+08:00","message":"ExecuteChildWorkflow"}
{"level":"debug","time":"2024-01-13T08:36:50+08:00","message":"streamlink live args: [--progress=force --force https://twitch.tv/420jenkins best,best --http-header Authorization=OAuth ... --twitch-low-latency --twitch-disable-hosting -o /tmp/42209411369_d59ef217-b1ab-11ee-9576-0242ac12000f-video.mp4]"}
{"level":"debug","time":"2024-01-13T08:36:50+08:00","message":"running: streamlink --progress=force --force https://twitch.tv/420jenkins best,best --http-header Authorization=OAuth ... --twitch-low-latency --twitch-disable-hosting -o /tmp/42209411369_d59ef217-b1ab-11ee-9576-0242ac12000f-video.mp4"}
{"level":"debug","ActivityID":"9","ActivityType":"DownloadTwitchLiveChat","Attempt":1,"Namespace":"default","RunID":"1fb2d45b-0794-4cc8-9fdd-30f8cea4962c","TaskQueue":"archive","WorkerID":"f73ae91174e2","WorkflowID":"a3aae82e-6090-403b-ab6e-340b68c8a668_37","WorkflowType":"DownloadTwitchLiveChatWorkflow","time":"2024-01-13T08:36:50+08:00","message":"ExecuteActivity"}
{"level":"debug","ActivityID":{},"Attempt":1,"Namespace":"default","RunID":"1fb2d45b-0794-4cc8-9fdd-30f8cea4962c","TaskQueue":"archive","WorkerID":"f73ae91174e2","WorkflowID":"a3aae82e-6090-403b-ab6e-340b68c8a668_37","WorkflowType":"DownloadTwitchLiveChatWorkflow","time":"2024-01-13T15:22:31+08:00","message":"RequestCancelActivity"}
{"level":"debug","ActivityID":"15","ActivityType":"KillTwitchLiveChatDownload","Attempt":1,"Namespace":"default","RunID":"1fb2d45b-0794-4cc8-9fdd-30f8cea4962c","TaskQueue":"archive","WorkerID":"f73ae91174e2","WorkflowID":"a3aae82e-6090-403b-ab6e-340b68c8a668_37","WorkflowType":"DownloadTwitchLiveChatWorkflow","time":"2024-01-13T15:22:31+08:00","message":"ExecuteActivity"}
{"level":"error","ActivityType":"KillTwitchLiveChatDownload","Attempt":1,"Error":"exit status 1","Namespace":"default","RunID":"1fb2d45b-0794-4cc8-9fdd-30f8cea4962c","TaskQueue":"archive","WorkerID":"f73ae91174e2","WorkflowID":"a3aae82e-6090-403b-ab6e-340b68c8a668_37","time":"2024-01-13T15:22:31+08:00","message":"Activity error."}
{"level":"debug","time":"2024-01-13T15:22:31+08:00","message":"video convert args: [-y -hide_banner -i /tmp/42209411369_d59ef217-b1ab-11ee-9576-0242ac12000f-video.mp4 -c:v copy -c:a copy /tmp/42209411369_d59ef217-b1ab-11ee-9576-0242ac12000f-video-convert.mp4]"}
{"level":"debug","time":"2024-01-13T15:22:39+08:00","message":"moving file: /tmp/42209411369_d59ef217-b1ab-11ee-9576-0242ac12000f-chat-convert.json to /vods/420jenkins/2024-01-13 - absolute_downward_spiral_sort_of_day [42209411369][live][d59ef217-b1ab-11ee-9576-0242ac12000f]/absolute_downward_spiral_sort_of_day [42209411369]-chat-convert.json"}
{"level":"debug","time":"2024-01-13T15:22:39+08:00","message":"moving file: /tmp/42209411369_d59ef217-b1ab-11ee-9576-0242ac12000f-chat.json to /vods/420jenkins/2024-01-13 - absolute_downward_spiral_sort_of_day [42209411369][live][d59ef217-b1ab-11ee-9576-0242ac12000f]/absolute_downward_spiral_sort_of_day [42209411369]-chat.json"}
{"level":"warn","ActivityID":"9","ActivityType":"DownloadTwitchLiveChat","Attempt":1,"Error":"workflow execution already completed","Namespace":"default","RunID":"1fb2d45b-0794-4cc8-9fdd-30f8cea4962c","TaskQueue":"archive","WorkerID":"f73ae91174e2","WorkflowID":"a3aae82e-6090-403b-ab6e-340b68c8a668_37","WorkflowType":"DownloadTwitchLiveChatWorkflow","time":"2024-01-13T15:22:54+08:00","message":"RecordActivityHeartbeat with error"}
{"level":"debug","time":"2024-01-13T15:25:30+08:00","message":"deleting file: /tmp/42209411369_d59ef217-b1ab-11ee-9576-0242ac12000f-video.mp4"}
{"level":"info","error":"error deleting file: remove /tmp/42209411369_d59ef217-b1ab-11ee-9576-0242ac12000f-video.mp4: no such file or directory","time":"2024-01-13T15:25:30+08:00","message":"error deleting source file for vod d59ef217-b1ab-11ee-9576-0242ac12000f"}

Furthermore, the below is being logged every second, 1 line per each stuck chat downloading task.

{"ActivityID":"9","ActivityType":"DownloadTwitchLiveChat","Attempt":1,"Error":"context canceled","Namespace":"default","RunID":"1fb2d45b-0794-4cc8-9fdd-30f8cea4962c","TaskQueue":"archive","WorkerID":"f73ae91174e2","WorkflowID":"a3aae82e-6090-403b-ab6e-340b68c8a668_37","WorkflowType":"DownloadTwitchLiveChatWorkflow","level":"warn","message":"RecordActivityHeartbeat with error","time":"2024-01-13T18:12:54+08:00"}
@Zibbp
Copy link
Owner

Zibbp commented Jan 14, 2024

Looks like it's failing to kill the chat download for some reason. Do you see the "found pid for chat_downloader" in any logs (debug only)?

log.Debug().Msgf("found pid %s for chat_downloader", string(out))

@russelg
Copy link
Author

russelg commented Jan 14, 2024

Yep

{"level":"debug","time":"2024-01-09T15:33:51+08:00","message":"found pid 53\n for chat_downloader"}
{"level":"debug","time":"2024-01-09T22:02:04+08:00","message":"found pid 104\n for chat_downloader"}
{"level":"debug","time":"2024-01-09T23:02:12+08:00","message":"found pid 111\n for chat_downloader"}
{"level":"debug","time":"2024-01-10T15:07:17+08:00","message":"found pid 179\n for chat_downloader"}
{"level":"debug","time":"2024-01-11T07:23:05+08:00","message":"found pid 53\n216\n for chat_downloader"}
{"level":"debug","time":"2024-01-11T22:02:18+08:00","message":"found pid 104\n254\n for chat_downloader"}
{"level":"debug","time":"2024-01-12T13:24:55+08:00","message":"found pid 53\n216\n291\n for chat_downloader"}
{"level":"debug","time":"2024-01-12T15:57:38+08:00","message":"found pid 53\n216\n291\n329\n for chat_downloader"}
{"level":"debug","time":"2024-01-13T15:22:31+08:00","message":"found pid 53\n216\n291\n329\n368\n for chat_downloader"}

There are corresponding success logs for some of them

{"level":"info","time":"2024-01-09T15:33:51+08:00","message":"killed chat downloader for channel 420jenkins"}
{"level":"info","time":"2024-01-09T22:02:04+08:00","message":"killed chat downloader for channel mogra"}
{"level":"info","time":"2024-01-09T23:02:12+08:00","message":"killed chat downloader for channel otographic"}
{"level":"info","time":"2024-01-10T15:07:17+08:00","message":"killed chat downloader for channel midnightsnacksfm"}

@Zibbp
Copy link
Owner

Zibbp commented Jan 14, 2024

I was able to reproduce locally, only when the stream ended. Does this seem to occur only when the stream ends for you?

@russelg
Copy link
Author

russelg commented Jan 14, 2024

Does this seem to occur only when the stream ends for you?

That seems to be the case, but I haven't been watching the logs while a stream ends so can't say for sure.

@c-hri-s
Copy link

c-hri-s commented Jan 14, 2024

Agree - I see this here too:

image

@Zibbp
Copy link
Owner

Zibbp commented Jan 15, 2024

I believe I have found the issue. The chat download task was getting cancelled but the post-tasks were never running. I have some changes in #357 if anyone is able to test these changes. I did some testing and the context and chat download processing is fixed but would like to get some others to test as well.

@russelg
Copy link
Author

russelg commented Jan 15, 2024

I would like to test it, how can I pull it in docker? I tried ghcr.io/zibbp/ganymede:pr-357 as shown in the action logs, but that doesn't work.

@Zibbp
Copy link
Owner

Zibbp commented Jan 15, 2024

Pull requests don't publish the images to save on storage. You'll need to clone the repository and checkout the branch and build the image locally.

@russelg
Copy link
Author

russelg commented Jan 15, 2024

Alright, got it running locally. I've added a bunch of random live archives, will report back after a couple of them end.

@russelg
Copy link
Author

russelg commented Jan 15, 2024

Almost certainly a different issue, but while testing this, my internet went out :/. Anyway, that caused the live video downloads to end, which is expected. But even though the video download task in the queue is marked complete, it's not moving on to video convert/move. And chat download is stuck in progress still.

Looks like the video download workflow failed due to the fetch VOD ID failing. Perhaps we can just ignore that failure?
Granted, this isn't the normal flow. Once my internet returns I'll test with a normal stream ending, not due to the internet going out :P

{"level":"debug","time":"2024-01-15T09:37:55+08:00","message":"workflow id b45d1f90-b346-11ee-a650-0242ac12000f started for live stream 43418657787"}
{"level":"debug","Attempt":1,"ChildWorkflowID":"148902df-f5e8-4456-bcdd-3e78cf9936dc_5","Namespace":"default","RunID":"148902df-f5e8-4456-bcdd-3e78cf9936dc","TaskQueue":"archive","WorkerID":"b183487d2851","WorkflowID":"b45d1f90-b346-11ee-a650-0242ac12000f","WorkflowType":"CreateDirectoryWorkflow","time":"2024-01-15T09:37:55+08:00","message":"ExecuteChildWorkflow"}
{"level":"debug","ActivityID":"5","ActivityType":"CreateDirectory","Attempt":1,"Namespace":"default","RunID":"99d578de-03b1-41e4-8830-5a6d05017d66","TaskQueue":"archive","WorkerID":"b183487d2851","WorkflowID":"148902df-f5e8-4456-bcdd-3e78cf9936dc_5","WorkflowType":"CreateDirectoryWorkflow","time":"2024-01-15T09:37:55+08:00","message":"ExecuteActivity"}
{"level":"debug","time":"2024-01-15T09:37:55+08:00","message":"creating folder: lyricaldota/2024-01-15 - (LIVE)_Nouns_vs_BammySoy [43418657787][live][b45d1f90-b346-11ee-a650-0242ac12000f]"}
{"level":"debug","Attempt":1,"ChildWorkflowID":"148902df-f5e8-4456-bcdd-3e78cf9936dc_14","Namespace":"default","RunID":"148902df-f5e8-4456-bcdd-3e78cf9936dc","TaskQueue":"archive","WorkerID":"b183487d2851","WorkflowID":"b45d1f90-b346-11ee-a650-0242ac12000f","WorkflowType":"DownloadTwitchLiveThumbnailsWorkflow","time":"2024-01-15T09:37:55+08:00","message":"ExecuteChildWorkflow"}
{"level":"debug","ActivityID":"5","ActivityType":"DownloadTwitchLiveThumbnails","Attempt":1,"Namespace":"default","RunID":"3386fbbf-4186-42ec-8fd8-135da3bacf5e","TaskQueue":"archive","WorkerID":"b183487d2851","WorkflowID":"148902df-f5e8-4456-bcdd-3e78cf9936dc_14","WorkflowType":"DownloadTwitchLiveThumbnailsWorkflow","time":"2024-01-15T09:37:55+08:00","message":"ExecuteActivity"}
{"level":"debug","time":"2024-01-15T09:37:57+08:00","message":"checking if tasks are done for video 43418657787"}
{"level":"debug","Attempt":1,"ChildWorkflowID":"148902df-f5e8-4456-bcdd-3e78cf9936dc_23","Namespace":"default","RunID":"148902df-f5e8-4456-bcdd-3e78cf9936dc","TaskQueue":"archive","WorkerID":"b183487d2851","WorkflowID":"b45d1f90-b346-11ee-a650-0242ac12000f","WorkflowType":"SaveTwitchLiveVideoInfoWorkflow","time":"2024-01-15T09:37:57+08:00","message":"ExecuteChildWorkflow"}
{"level":"debug","ActivityID":"5","ActivityType":"SaveTwitchLiveVideoInfo","Attempt":1,"Namespace":"default","RunID":"b9b520dd-703d-40ab-9697-3751e87de7f2","TaskQueue":"archive","WorkerID":"b183487d2851","WorkflowID":"148902df-f5e8-4456-bcdd-3e78cf9936dc_23","WorkflowType":"SaveTwitchLiveVideoInfoWorkflow","time":"2024-01-15T09:37:57+08:00","message":"ExecuteActivity"}
{"level":"debug","time":"2024-01-15T09:37:57+08:00","message":"checking if tasks are done for video 43418657787"}
{"level":"debug","Attempt":1,"ChildWorkflowID":"148902df-f5e8-4456-bcdd-3e78cf9936dc_32","Namespace":"default","RunID":"148902df-f5e8-4456-bcdd-3e78cf9936dc","TaskQueue":"archive","WorkerID":"b183487d2851","WorkflowID":"b45d1f90-b346-11ee-a650-0242ac12000f","WorkflowType":"ArchiveTwitchLiveChatWorkflow","time":"2024-01-15T09:37:57+08:00","message":"ExecuteChildWorkflow"}
{"level":"debug","time":"2024-01-15T09:37:57+08:00","message":"Live chat archive workflow ID: 148902df-f5e8-4456-bcdd-3e78cf9936dc_32"}
{"level":"debug","Attempt":1,"ChildWorkflowID":"148902df-f5e8-4456-bcdd-3e78cf9936dc_37","Namespace":"default","RunID":"148902df-f5e8-4456-bcdd-3e78cf9936dc","TaskQueue":"archive","WorkerID":"b183487d2851","WorkflowID":"b45d1f90-b346-11ee-a650-0242ac12000f","WorkflowType":"DownloadTwitchLiveChatWorkflow","time":"2024-01-15T09:37:57+08:00","message":"ExecuteChildWorkflow"}
{"level":"debug","time":"2024-01-15T09:37:57+08:00","message":"Live chat workflow ID: 148902df-f5e8-4456-bcdd-3e78cf9936dc_37"}
{"level":"debug","Attempt":1,"ChildWorkflowID":"148902df-f5e8-4456-bcdd-3e78cf9936dc_42","Namespace":"default","RunID":"148902df-f5e8-4456-bcdd-3e78cf9936dc","TaskQueue":"archive","WorkerID":"b183487d2851","WorkflowID":"b45d1f90-b346-11ee-a650-0242ac12000f","WorkflowType":"ArchiveTwitchLiveVideoWorkflow","time":"2024-01-15T09:37:57+08:00","message":"ExecuteChildWorkflow"}
{"level":"debug","Attempt":1,"ChildWorkflowID":"6a89acb8-12eb-4b80-a595-8155f9fcde77_5","Namespace":"default","RunID":"6a89acb8-12eb-4b80-a595-8155f9fcde77","TaskQueue":"archive","WorkerID":"b183487d2851","WorkflowID":"148902df-f5e8-4456-bcdd-3e78cf9936dc_42","WorkflowType":"DownloadTwitchLiveVideoWorkflow","time":"2024-01-15T09:37:57+08:00","message":"ExecuteChildWorkflow"}
{"level":"debug","time":"2024-01-15T09:37:57+08:00","message":"starting heartbeat download-livevideo-43418657787"}
{"level":"debug","time":"2024-01-15T09:37:58+08:00","message":"streamlink live args: [--progress=force --force https://twitch.tv/lyricaldota best,best --http-header Authorization=OAuth ... --twitch-low-latency --twitch-disable-hosting -o /tmp/43418657787_b45d1f90-b346-11ee-a650-0242ac12000f-video.mp4]"}
{"level":"debug","time":"2024-01-15T09:37:58+08:00","message":"running: streamlink --progress=force --force https://twitch.tv/lyricaldota best,best --http-header Authorization=OAuth ... --twitch-low-latency --twitch-disable-hosting -o /tmp/43418657787_b45d1f90-b346-11ee-a650-0242ac12000f-video.mp4"}
{"level":"debug","ActivityID":"9","ActivityType":"DownloadTwitchLiveChat","Attempt":1,"Namespace":"default","RunID":"560112a8-0ea4-4357-9e0f-82c74d712328","TaskQueue":"archive","WorkerID":"b183487d2851","WorkflowID":"148902df-f5e8-4456-bcdd-3e78cf9936dc_37","WorkflowType":"DownloadTwitchLiveChatWorkflow","time":"2024-01-15T09:37:58+08:00","message":"ExecuteActivity"}
{"level":"debug","time":"2024-01-15T09:37:58+08:00","message":"starting heartbeat download-livechat-43418657787"}
{"level":"debug","time":"2024-01-15T09:44:59+08:00","message":"finished downloading live video for 43418657787"}
{"level":"error","ActivityType":"DownloadTwitchLiveVideo","Attempt":1,"Error":"failed to get twitch videos: Get \"https://api.twitch.tv/helix/videos?user_id=90937535&type=archive&first=100\": dial tcp: lookup api.twitch.tv on 127.0.0.11:53: read udp 127.0.0.1:41249->127.0.0.11:53: i/o timeout","Namespace":"default","RunID":"d9e1e6ad-08aa-4efe-b883-e76a30fa4d86","TaskQueue":"archive","WorkerID":"b183487d2851","WorkflowID":"6a89acb8-12eb-4b80-a595-8155f9fcde77_5","time":"2024-01-15T09:45:09+08:00","message":"Activity error."}
{"level":"debug","time":"2024-01-15T09:45:09+08:00","message":"stopping heartbeat download-livevideo-43418657787"}
{"level":"warn","ActivityID":"9","ActivityType":"DownloadTwitchLiveChat","Attempt":1,"Error":"workflow execution already completed","Namespace":"default","RunID":"560112a8-0ea4-4357-9e0f-82c74d712328","TaskQueue":"archive","WorkerID":"b183487d2851","WorkflowID":"148902df-f5e8-4456-bcdd-3e78cf9936dc_37","WorkflowType":"DownloadTwitchLiveChatWorkflow","time":"2024-01-15T09:45:19+08:00","message":"RecordActivityHeartbeat with error"}
{"level":"warn","ActivityID":"9","ActivityType":"DownloadTwitchLiveChat","Attempt":1,"Error":"context canceled","Namespace":"default","RunID":"560112a8-0ea4-4357-9e0f-82c74d712328","TaskQueue":"archive","WorkerID":"b183487d2851","WorkflowID":"148902df-f5e8-4456-bcdd-3e78cf9936dc_37","WorkflowType":"DownloadTwitchLiveChatWorkflow","time":"2024-01-15T09:46:19+08:00","message":"RecordActivityHeartbeat with error"}
{"level":"warn","ActivityID":"9","ActivityType":"DownloadTwitchLiveChat","Attempt":1,"Error":"context canceled","Namespace":"default","RunID":"560112a8-0ea4-4357-9e0f-82c74d712328","TaskQueue":"archive","WorkerID":"b183487d2851","WorkflowID":"148902df-f5e8-4456-bcdd-3e78cf9936dc_37","WorkflowType":"DownloadTwitchLiveChatWorkflow","time":"2024-01-15T09:47:19+08:00","message":"RecordActivityHeartbeat with error"}
<above repeated every minute>

@russelg
Copy link
Author

russelg commented Jan 15, 2024

Ok, a stream ended naturally now. Failed at ending the chat downloader, multiple PIDs again. Could likely be due to the previous failures mentioned above. I didn't restart any of the containers after my internet came back.

Queue got stuck like so:
image

Now the video convert/move steps are still not running. Before, when the chat download failed to finish, the other steps would still continue.

{"level":"debug","time":"2024-01-15T11:22:15+08:00","message":"finished downloading live video for 50168626509"}
{"level":"debug","time":"2024-01-15T11:22:15+08:00","message":"getting video duration"}
{"level":"debug","time":"2024-01-15T11:22:16+08:00","message":"video duration: 4378"}
{"level":"info","time":"2024-01-15T11:22:16+08:00","message":"no vod found for livestream 50168626509, keeping live stream ID as external id"}
{"level":"debug","time":"2024-01-15T11:22:16+08:00","message":"stopping heartbeat download-livevideo-50168626509"}
{"level":"debug","ActivityID":"11","ActivityType":"KillTwitchLiveChatDownload","Attempt":1,"Namespace":"default","RunID":"86576e28-a6e3-485e-b111-a5ef41792282","TaskQueue":"archive","WorkerID":"b183487d2851","WorkflowID":"8c7b60c5-2205-4218-a296-f42aef18ba0e_5","WorkflowType":"DownloadTwitchLiveVideoWorkflow","time":"2024-01-15T11:22:16+08:00","message":"ExecuteActivity"}
{"level":"info","time":"2024-01-15T11:22:16+08:00","message":"killing chat downloader for channel idubbbz"}
{"level":"debug","time":"2024-01-15T11:22:16+08:00","message":"found pid 100\n132\n for chat_downloader"}
{"level":"error","ActivityType":"KillTwitchLiveChatDownload","Attempt":1,"Error":"exit status 1","Namespace":"default","RunID":"86576e28-a6e3-485e-b111-a5ef41792282","TaskQueue":"archive","WorkerID":"b183487d2851","WorkflowID":"8c7b60c5-2205-4218-a296-f42aef18ba0e_5","time":"2024-01-15T11:22:16+08:00","message":"Activity error."}
{"level":"debug","time":"2024-01-15T11:22:16+08:00","message":"Error notification is disabled"}

I will start testing again with a fresh temporal db and restarted containers.

@russelg
Copy link
Author

russelg commented Jan 15, 2024

After fresh temporal and restarting, seems the queue is progressing as expected now. I went live with a test stream, while also recording another stream.

The correct chat downloader was killed, and the queue item for my test stream finished as expected. The other livestream was unaffected, also as expected.

Ending the other livestream on the queue page (the X button): ended the capture, killed the chat download, and completed the queue, as expected.

Seems like the fixes work for me!

I'll make another issue for the issue that came up when my internet dropped, i.e. queue fails due to VOD ID not being retrievable after stream ends.

@Zibbp
Copy link
Owner

Zibbp commented Jan 15, 2024

I believe the multiple PID issue is that the chat downloader never got killed before (before the changes in the PR) so the processes just stuck around. Restarting the container clears those up for proper testing with the PR.

@Zibbp
Copy link
Owner

Zibbp commented Jan 16, 2024

If anyone else wants to test the fixes, they are now available using the :main image tag for the API container.

@Zibbp
Copy link
Owner

Zibbp commented Feb 19, 2024

These fixes have been released in v2.1.0.

@Zibbp Zibbp closed this as completed Feb 19, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants