Various prebuild fixes #20057

filiptronicek · 2024-07-22T15:57:53Z

Description

This PR fixes a couple of prebuilds-related issues. It originally was set out to fix incomplete endings of logs, but it ended up being about so a couple of other fixes, just not about this one 🤷.

Related Issue(s)

Fixes ENT-445
Fixes the NetworkError when attempting to fetch resource bug

How to test

Try executing some prebuild
Optionally, also try to run a failed prebuild (for instance https://github.com/mustard-mh/test/tree/prebuild/image-build-failed) and observe it in real time for ENT-445.

https://ft-fix-suc3e31a702ac.preview.gitpod-dev.com

filiptronicek · 2024-07-23T11:37:15Z

components/dashboard/src/data/prebuilds/prebuild-logs-emitter.ts

            console.debug("fetching from streamUrl: " + streamUrl);
            response = await fetch(streamUrl, {
                method: "GET",
-                cache: "no-cache",


using no-cache here might've been problematic, because the browser makes a conditional request in the case there is a cache entry present for this request. The problem is that no-cache actually does cache 🙃

filiptronicek · 2024-07-23T11:37:58Z

components/dashboard/src/data/prebuilds/prebuild-logs-emitter.ts


            const decoder = new TextDecoder("utf-8");
            let chunk = await reader.read();
            while (!chunk.done) {
+                if (disposables.disposed) {
+                    // stop reading when disposed


this means we don't have to read the whole body anymore if we dispose in the midst of it.

filiptronicek · 2024-07-23T11:38:39Z

components/server/src/workspace/workspace-starter.ts

@@ -860,6 +860,12 @@ export class WorkspaceStarter {
                        type: HeadlessWorkspaceEventType.Failed,
                        workspaceID: workspace.id,
                    });
+                    await this.publisher.publishPrebuildUpdate({


This fixes ENT-445

filiptronicek · 2024-07-23T11:39:17Z

components/supervisor/pkg/supervisor/tasks.go

 		go func(t *task, term *terminal.Term) {
 			state, err := term.Wait()
+			taskLog.Info("task terminal has been closed. Waiting for watch() to finish...")
+			taskWatchWg.Wait()


this makes sure that we append the 🍊 line before actually stopping the task.

This reverts commit fdc3183.

filiptronicek · 2024-07-23T11:58:06Z

components/supervisor/pkg/supervisor/services.go

There might be a case we're missing here:

gitpod/components/supervisor/pkg/supervisor/services.go

Lines 1132 to 1139 in c275510

n, err := reader.Read(buf)

if err == io.EOF {

if isClosed.Load() {

// We are done

log.Println("[prebuildlog]: closing because task state is done and we are done reading")

return nil

}

}

Imagine that the task was just closed, and we have also just encountered the end of the file, but in the meantime by finishing it has written the last 🍊 line to the output, which we now didn't catch.

From the logs, the difference in a sample prebuild I did between setting the task state to closed and us closing the stream off is about 0.3 milliseconds, but I do not know on which timescale the file watcher operates.

Edit: from a quick test, it turns out that between writing to a file and getting a notification for it, it takes approximately 0.2ms, so maybe we're just too slow with the final notification.

I think you are spot on. I tried to come up with a patch for it. @filiptronicek Is it fine if I add that on top of your PR?

Make sure we wait for the line to be written first

filiptronicek · 2024-07-23T13:11:56Z

Here are the logs from my latest experiment with 4 clients: (could come in handy in the future)

{
  "alias": "505309c5-e312-4544-aa90-1bbcb319ecf8",
  "file": "terminal.go:139",
  "func": "doClose",
  "level": "info",
  "message": "closing terminal",
  "serviceContext": {
    "service": "supervisor",
    "version": "commit-c275510fe58b6865ae5f5b10b85cd00a06ffc908-632948a1a049dce65aa5e2f57ce4cd64b2cb36be"
  },
  "severity": "INFO",
  "time": "2024-07-23T12:55:12.790276055Z"
}
{
  "file": "export.go:84",
  "func": "Error",
  "level": "error",
  "message": "Added kumquat line to prebuild log",
  "serviceContext": {
    "service": "supervisor",
    "version": "commit-c275510fe58b6865ae5f5b10b85cd00a06ffc908-632948a1a049dce65aa5e2f57ce4cd64b2cb36be"
  },
  "severity": "ERROR",
  "time": "2024-07-23T12:55:12.790467795Z"
}
{
  "command": "{\n./mvnw clean install -U -DskipTests\n}; exit",
  "file": "tasks.go:330",
  "func": "func2",
  "level": "info",
  "message": "task terminal has been closed. Waiting for watch() to finish...",
  "pid": 58,
  "serviceContext": {
    "service": "supervisor",
    "version": "commit-c275510fe58b6865ae5f5b10b85cd00a06ffc908-632948a1a049dce65aa5e2f57ce4cd64b2cb36be"
  },
  "severity": "INFO",
  "terminal": "505309c5-e312-4544-aa90-1bbcb319ecf8",
  "time": "2024-07-23T12:55:12.790385835Z"
}
{
  "command": "{\n./mvnw clean install -U -DskipTests\n}; exit",
  "file": "tasks.go:332",
  "func": "func2",
  "level": "info",
  "message": "watch() has finished, setting task state to closed",
  "pid": 58,
  "serviceContext": {
    "service": "supervisor",
    "version": "commit-c275510fe58b6865ae5f5b10b85cd00a06ffc908-632948a1a049dce65aa5e2f57ce4cd64b2cb36be"
  },
  "severity": "INFO",
  "terminal": "505309c5-e312-4544-aa90-1bbcb319ecf8",
  "time": "2024-07-23T12:55:12.790609845Z"
}
{
  "file": "export.go:154",
  "func": "Println",
  "level": "info",
  "message": "[prebuildlog]: closing because task state is done and we are done reading",
  "serviceContext": {
    "service": "supervisor",
    "version": "commit-c275510fe58b6865ae5f5b10b85cd00a06ffc908-632948a1a049dce65aa5e2f57ce4cd64b2cb36be"
  },
  "severity": "INFO",
  "time": "2024-07-23T12:55:12.790782805Z"
}
{
  "file": "export.go:154",
  "func": "Println",
  "level": "info",
  "message": "[prebuildlog]: closing because task state is done and we are done reading",
  "serviceContext": {
    "service": "supervisor",
    "version": "commit-c275510fe58b6865ae5f5b10b85cd00a06ffc908-632948a1a049dce65aa5e2f57ce4cd64b2cb36be"
  },
  "severity": "INFO",
  "time": "2024-07-23T12:55:12.790780865Z"
}
{
  "file": "export.go:154",
  "func": "Println",
  "level": "info",
  "message": "[prebuildlog]: closing because task state is done and we are done reading",
  "serviceContext": {
    "service": "supervisor",
    "version": "commit-c275510fe58b6865ae5f5b10b85cd00a06ffc908-632948a1a049dce65aa5e2f57ce4cd64b2cb36be"
  },
  "severity": "INFO",
  "time": "2024-07-23T12:55:12.790816395Z"
}
{
  "file": "export.go:154",
  "func": "Println",
  "level": "info",
  "message": "[prebuildlog]: closing because task state is done and we are done reading",
  "serviceContext": {
    "service": "supervisor",
    "version": "commit-c275510fe58b6865ae5f5b10b85cd00a06ffc908-632948a1a049dce65aa5e2f57ce4cd64b2cb36be"
  },
  "severity": "INFO",
  "time": "2024-07-23T12:55:12.790802255Z"
}

components/dashboard/src/data/prebuilds/prebuild-logs-emitter.ts

components/supervisor/pkg/supervisor/services.go

components/supervisor/pkg/supervisor/tasks.go

filiptronicek · 2024-07-24T06:47:49Z

I'm going to re-create the preview environment, as it's been GC'd over night.

geropl · 2024-07-24T07:48:22Z

@filiptronicek Taking a closer look now.

geropl · 2024-07-24T12:07:57Z

❤️

geropl

Code LGTM, tested and works nicely, thanks! 🙏 ✔️

filiptronicek added 3 commits July 22, 2024 12:27

log it all

18e18b9

fix failing image logs prebuild updates

bec110b

make sure we dispose of requests properly

6521f8b

roboquat added do-not-merge/work-in-progress do-not-merge/hold size/L labels Jul 22, 2024

filiptronicek added 4 commits July 23, 2024 07:44

minor cleanup

504debb

handle aborts gracefully

c35d8a1

Try using a tailing library for reading supervisor task logs

fdc3183

Fix caching requests on Firefox

bed19e4

filiptronicek commented Jul 23, 2024

View reviewed changes

Revert "Try using a tailing library for reading supervisor task logs"

c275510

This reverts commit fdc3183.

filiptronicek commented Jul 23, 2024

View reviewed changes

Change log order

3fe78aa

Make sure we wait for the line to be written first

filiptronicek changed the title ~~Fix incomplete prebuild logs~~ Various prebuild fixes Jul 23, 2024

filiptronicek self-assigned this Jul 23, 2024

filiptronicek marked this pull request as ready for review July 23, 2024 13:14

filiptronicek requested review from a team as code owners July 23, 2024 13:14

roboquat removed the do-not-merge/work-in-progress label Jul 23, 2024

github-actions bot added team: team-experience team: team-enterprise labels Jul 23, 2024

geropl reviewed Jul 23, 2024

View reviewed changes

components/dashboard/src/data/prebuilds/prebuild-logs-emitter.ts Outdated Show resolved Hide resolved

geropl reviewed Jul 23, 2024

View reviewed changes

components/supervisor/pkg/supervisor/services.go Show resolved Hide resolved

geropl reviewed Jul 23, 2024

View reviewed changes

components/supervisor/pkg/supervisor/tasks.go Outdated Show resolved Hide resolved

filiptronicek added 2 commits July 23, 2024 15:26

Tweak abortion error message

29fca3d

Remove extra log line

fe7e98b

geropl approved these changes Jul 24, 2024

View reviewed changes

filiptronicek removed the do-not-merge/hold label Jul 24, 2024

roboquat merged commit 10810ce into main Jul 24, 2024
19 checks passed

roboquat deleted the ft/fix-success-message-races branch July 24, 2024 13:48

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Various prebuild fixes #20057

Various prebuild fixes #20057

Uh oh!

filiptronicek commented Jul 22, 2024 •

edited

Loading

Uh oh!

filiptronicek Jul 23, 2024

Uh oh!

filiptronicek Jul 23, 2024

Uh oh!

filiptronicek Jul 23, 2024

Uh oh!

filiptronicek Jul 23, 2024

Uh oh!

filiptronicek Jul 23, 2024 •

edited

Loading

Uh oh!

geropl Jul 24, 2024

Uh oh!

filiptronicek commented Jul 23, 2024

Uh oh!

Uh oh!

Uh oh!

Uh oh!

filiptronicek commented Jul 24, 2024

Uh oh!

geropl commented Jul 24, 2024

Uh oh!

geropl commented Jul 24, 2024

Uh oh!

geropl left a comment

Uh oh!

Uh oh!

Uh oh!

	n, err := reader.Read(buf)
	if err == io.EOF {
	if isClosed.Load() {
	// We are done
	log.Println("[prebuildlog]: closing because task state is done and we are done reading")
	return nil
	}
	}

Various prebuild fixes #20057

Various prebuild fixes #20057

Uh oh!

Conversation

filiptronicek commented Jul 22, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Description

Related Issue(s)

How to test

Uh oh!

filiptronicek Jul 23, 2024

Choose a reason for hiding this comment

Uh oh!

filiptronicek Jul 23, 2024

Choose a reason for hiding this comment

Uh oh!

filiptronicek Jul 23, 2024

Choose a reason for hiding this comment

Uh oh!

filiptronicek Jul 23, 2024

Choose a reason for hiding this comment

Uh oh!

filiptronicek Jul 23, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

geropl Jul 24, 2024

Choose a reason for hiding this comment

Uh oh!

filiptronicek commented Jul 23, 2024

Uh oh!

Uh oh!

Uh oh!

Uh oh!

filiptronicek commented Jul 24, 2024

Uh oh!

geropl commented Jul 24, 2024

Uh oh!

geropl commented Jul 24, 2024

Uh oh!

geropl left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

filiptronicek commented Jul 22, 2024 •

edited

Loading

filiptronicek Jul 23, 2024 •

edited

Loading