Skip to content

Commit 1778db2

Browse files
kylecarbsAbhineetJain
kylecarbs
and
AbhineetJain
authored
fix: Use WebSockets to stream workspace build logs (#2569)
* fix: Use WebSockets to stream workspace build logs This was using a streaming HTTP request before, which didn't work on my version of Chrome. This method seemed less reliable and standard than a WebSocket, so figured switching would be best. * Update site/src/xServices/workspaceBuild/workspaceBuildXService.ts Co-authored-by: Abhineet Jain <AbhineetJain@users.noreply.github.com> * Update site/src/pages/WorkspaceBuildPage/WorkspaceBuildPage.test.tsx Co-authored-by: Abhineet Jain <AbhineetJain@users.noreply.github.com> * Update site/src/api/api.ts Co-authored-by: Abhineet Jain <AbhineetJain@users.noreply.github.com> * Remove unused prop Co-authored-by: Abhineet Jain <AbhineetJain@users.noreply.github.com>
1 parent dc7d6de commit 1778db2

File tree

12 files changed

+130
-108
lines changed

12 files changed

+130
-108
lines changed

‎coderd/provisionerjobs.go

+21-16
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@ import (
1111
"time"
1212

1313
"github.com/google/uuid"
14+
"nhooyr.io/websocket"
1415

1516
"cdr.dev/slog"
1617

@@ -98,12 +99,28 @@ func (api *API) provisionerJobLogs(rw http.ResponseWriter, r *http.Request, job
9899
return
99100
}
100101

102+
api.websocketWaitMutex.Lock()
103+
api.websocketWaitGroup.Add(1)
104+
api.websocketWaitMutex.Unlock()
105+
defer api.websocketWaitGroup.Done()
106+
conn, err := websocket.Accept(rw, r, nil)
107+
if err != nil {
108+
httpapi.Write(rw, http.StatusBadRequest, httpapi.Response{
109+
Message: "Failed to accept websocket.",
110+
Detail: err.Error(),
111+
})
112+
return
113+
}
114+
115+
ctx, wsNetConn := websocketNetConn(r.Context(), conn, websocket.MessageText)
116+
defer wsNetConn.Close() // Also closes conn.
117+
101118
bufferedLogs := make(chan database.ProvisionerJobLog, 128)
102119
closeSubscribe, err := api.Pubsub.Subscribe(provisionerJobLogsChannel(job.ID), func(ctx context.Context, message []byte) {
103120
var logs []database.ProvisionerJobLog
104121
err := json.Unmarshal(message, &logs)
105122
if err != nil {
106-
api.Logger.Warn(r.Context(), fmt.Sprintf("invalid provisioner job log on channel %q: %s", provisionerJobLogsChannel(job.ID), err.Error()))
123+
api.Logger.Warn(ctx, fmt.Sprintf("invalid provisioner job log on channel %q: %s", provisionerJobLogsChannel(job.ID), err.Error()))
107124
return
108125
}
109126

@@ -113,7 +130,7 @@ func (api *API) provisionerJobLogs(rw http.ResponseWriter, r *http.Request, job
113130
default:
114131
// If this overflows users could miss logs streaming. This can happen
115132
// if a database request takes a long amount of time, and we get a lot of logs.
116-
api.Logger.Warn(r.Context(), "provisioner job log overflowing channel")
133+
api.Logger.Warn(ctx, "provisioner job log overflowing channel")
117134
}
118135
}
119136
})
@@ -126,7 +143,7 @@ func (api *API) provisionerJobLogs(rw http.ResponseWriter, r *http.Request, job
126143
}
127144
defer closeSubscribe()
128145

129-
provisionerJobLogs, err := api.Database.GetProvisionerLogsByIDBetween(r.Context(), database.GetProvisionerLogsByIDBetweenParams{
146+
provisionerJobLogs, err := api.Database.GetProvisionerLogsByIDBetween(ctx, database.GetProvisionerLogsByIDBetweenParams{
130147
JobID: job.ID,
131148
CreatedAfter: after,
132149
CreatedBefore: before,
@@ -142,17 +159,8 @@ func (api *API) provisionerJobLogs(rw http.ResponseWriter, r *http.Request, job
142159
return
143160
}
144161

145-
// "follow" uses the ndjson format to stream data.
146-
// See: https://canjs.com/doc/can-ndjson-stream.html
147-
rw.Header().Set("Content-Type", "application/stream+json")
148-
rw.WriteHeader(http.StatusOK)
149-
if flusher, ok := rw.(http.Flusher); ok {
150-
flusher.Flush()
151-
}
152-
153162
// The Go stdlib JSON encoder appends a newline character after message write.
154-
encoder := json.NewEncoder(rw)
155-
163+
encoder := json.NewEncoder(wsNetConn)
156164
for _, provisionerJobLog := range provisionerJobLogs {
157165
err = encoder.Encode(convertProvisionerJobLog(provisionerJobLog))
158166
if err != nil {
@@ -171,9 +179,6 @@ func (api *API) provisionerJobLogs(rw http.ResponseWriter, r *http.Request, job
171179
if err != nil {
172180
return
173181
}
174-
if flusher, ok := rw.(http.Flusher); ok {
175-
flusher.Flush()
176-
}
177182
case <-ticker.C:
178183
job, err := api.Database.GetProvisionerJobByID(r.Context(), job.ID)
179184
if err != nil {

‎codersdk/provisionerdaemons.go

+23-5
Original file line numberDiff line numberDiff line change
@@ -6,11 +6,16 @@ import (
66
"encoding/json"
77
"fmt"
88
"net/http"
9+
"net/http/cookiejar"
910
"net/url"
1011
"strconv"
1112
"time"
1213

1314
"github.com/google/uuid"
15+
"golang.org/x/xerrors"
16+
"nhooyr.io/websocket"
17+
18+
"github.com/coder/coder/coderd/httpmw"
1419
)
1520

1621
type LogSource string
@@ -106,17 +111,30 @@ func (c *Client) provisionerJobLogsAfter(ctx context.Context, path string, after
106111
if !after.IsZero() {
107112
afterQuery = fmt.Sprintf("&after=%d", after.UTC().UnixMilli())
108113
}
109-
res, err := c.Request(ctx, http.MethodGet, fmt.Sprintf("%s?follow%s", path, afterQuery), nil)
114+
followURL, err := c.URL.Parse(fmt.Sprintf("%s?follow%s", path, afterQuery))
110115
if err != nil {
111116
return nil, err
112117
}
113-
if res.StatusCode != http.StatusOK {
114-
defer res.Body.Close()
118+
jar, err := cookiejar.New(nil)
119+
if err != nil {
120+
return nil, xerrors.Errorf("create cookie jar: %w", err)
121+
}
122+
jar.SetCookies(followURL, []*http.Cookie{{
123+
Name: httpmw.SessionTokenKey,
124+
Value: c.SessionToken,
125+
}})
126+
httpClient := &http.Client{
127+
Jar: jar,
128+
}
129+
conn, res, err := websocket.Dial(ctx, followURL.String(), &websocket.DialOptions{
130+
HTTPClient: httpClient,
131+
CompressionMode: websocket.CompressionDisabled,
132+
})
133+
if err != nil {
115134
return nil, readBodyAsError(res)
116135
}
117-
118136
logs := make(chan ProvisionerJobLog)
119-
decoder := json.NewDecoder(res.Body)
137+
decoder := json.NewDecoder(websocket.NetConn(ctx, conn, websocket.MessageText))
120138
go func() {
121139
defer close(logs)
122140
var log ProvisionerJobLog

‎scripts/build_go_matrix.sh

+3-1
Original file line numberDiff line numberDiff line change
@@ -193,7 +193,7 @@ for spec in "${specs[@]}"; do
193193
--os "$spec_os" \
194194
--arch "$spec_arch" \
195195
--output "$spec_output_binary" \
196-
"${build_args[@]}"
196+
"${build_args[@]}" &
197197
log
198198
log
199199

@@ -227,3 +227,5 @@ for spec in "${specs[@]}"; do
227227
log
228228
fi
229229
done
230+
231+
wait

‎site/src/api/api.ts

+4-17
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,4 @@
11
import axios, { AxiosRequestHeaders } from "axios"
2-
import ndjsonStream from "can-ndjson-stream"
32
import * as Types from "./types"
43
import { WorkspaceBuildTransition } from "./types"
54
import * as TypesGen from "./typesGenerated"
@@ -280,25 +279,13 @@ export const getWorkspaceBuildByNumber = async (
280279
return response.data
281280
}
282281

283-
export const getWorkspaceBuildLogs = async (buildname: string): Promise<TypesGen.ProvisionerJobLog[]> => {
284-
const response = await axios.get<TypesGen.ProvisionerJobLog[]>(`/api/v2/workspacebuilds/${buildname}/logs`)
282+
export const getWorkspaceBuildLogs = async (buildname: string, before: Date): Promise<TypesGen.ProvisionerJobLog[]> => {
283+
const response = await axios.get<TypesGen.ProvisionerJobLog[]>(
284+
`/api/v2/workspacebuilds/${buildname}/logs?before=${before.getTime()}`,
285+
)
285286
return response.data
286287
}
287288

288-
export const streamWorkspaceBuildLogs = async (
289-
buildname: string,
290-
): Promise<ReadableStreamDefaultReader<TypesGen.ProvisionerJobLog>> => {
291-
// Axios does not support HTTP stream in the browser
292-
// https://github.com/axios/axios/issues/1474
293-
// So we are going to use window.fetch and return a "stream" reader
294-
const reader = await window
295-
.fetch(`/api/v2/workspacebuilds/${buildname}/logs?follow=true`)
296-
.then((res) => ndjsonStream<TypesGen.ProvisionerJobLog>(res.body))
297-
.then((stream) => stream.getReader())
298-
299-
return reader
300-
}
301-
302289
export const putWorkspaceExtension = async (
303290
workspaceId: string,
304291
extendWorkspaceRequest: TypesGen.PutExtendWorkspaceRequest,

‎site/src/api/typesGenerated.ts

+6-6
Original file line numberDiff line numberDiff line change
@@ -201,7 +201,7 @@ export interface ParameterSchema {
201201
readonly validation_contains?: string[]
202202
}
203203

204-
// From codersdk/provisionerdaemons.go:33:6
204+
// From codersdk/provisionerdaemons.go:38:6
205205
export interface ProvisionerDaemon {
206206
readonly id: string
207207
readonly created_at: string
@@ -210,7 +210,7 @@ export interface ProvisionerDaemon {
210210
readonly provisioners: ProvisionerType[]
211211
}
212212

213-
// From codersdk/provisionerdaemons.go:62:6
213+
// From codersdk/provisionerdaemons.go:67:6
214214
export interface ProvisionerJob {
215215
readonly id: string
216216
readonly created_at: string
@@ -222,7 +222,7 @@ export interface ProvisionerJob {
222222
readonly storage_source: string
223223
}
224224

225-
// From codersdk/provisionerdaemons.go:73:6
225+
// From codersdk/provisionerdaemons.go:78:6
226226
export interface ProvisionerJobLog {
227227
readonly id: string
228228
readonly created_at: string
@@ -485,10 +485,10 @@ export interface WorkspaceResource {
485485
// From codersdk/workspacebuilds.go:22:6
486486
export type BuildReason = "autostart" | "autostop" | "initiator"
487487

488-
// From codersdk/provisionerdaemons.go:23:6
488+
// From codersdk/provisionerdaemons.go:28:6
489489
export type LogLevel = "debug" | "error" | "info" | "trace" | "warn"
490490

491-
// From codersdk/provisionerdaemons.go:16:6
491+
// From codersdk/provisionerdaemons.go:21:6
492492
export type LogSource = "provisioner" | "provisioner_daemon"
493493

494494
// From codersdk/parameters.go:29:6
@@ -503,7 +503,7 @@ export type ParameterSourceScheme = "data" | "none"
503503
// From codersdk/parameters.go:37:6
504504
export type ParameterTypeSystem = "hcl" | "none"
505505

506-
// From codersdk/provisionerdaemons.go:42:6
506+
// From codersdk/provisionerdaemons.go:47:6
507507
export type ProvisionerJobStatus = "canceled" | "canceling" | "failed" | "pending" | "running" | "succeeded"
508508

509509
// From codersdk/organizations.go:14:6

‎site/src/components/WorkspaceBuildLogs/WorkspaceBuildLogs.stories.tsx

-6
Original file line numberDiff line numberDiff line change
@@ -13,9 +13,3 @@ export const Example = Template.bind({})
1313
Example.args = {
1414
logs: MockWorkspaceBuildLogs,
1515
}
16-
17-
export const Loading = Template.bind({})
18-
Loading.args = {
19-
logs: MockWorkspaceBuildLogs,
20-
isWaitingForLogs: true,
21-
}

‎site/src/components/WorkspaceBuildLogs/WorkspaceBuildLogs.tsx

+3-12
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,3 @@
1-
import CircularProgress from "@material-ui/core/CircularProgress"
21
import { makeStyles } from "@material-ui/core/styles"
32
import dayjs from "dayjs"
43
import { FC } from "react"
@@ -40,33 +39,29 @@ const getStageDurationInSeconds = (logs: ProvisionerJobLog[]) => {
4039

4140
export interface WorkspaceBuildLogsProps {
4241
logs: ProvisionerJobLog[]
43-
isWaitingForLogs: boolean
4442
}
4543

46-
export const WorkspaceBuildLogs: FC<WorkspaceBuildLogsProps> = ({ logs, isWaitingForLogs }) => {
44+
export const WorkspaceBuildLogs: FC<WorkspaceBuildLogsProps> = ({ logs }) => {
4745
const groupedLogsByStage = groupLogsByStage(logs)
4846
const stages = Object.keys(groupedLogsByStage)
4947
const styles = useStyles()
5048

5149
return (
5250
<div className={styles.logs}>
53-
{stages.map((stage, stageIndex) => {
51+
{stages.map((stage) => {
5452
const logs = groupedLogsByStage[stage]
5553
const isEmpty = logs.every((log) => log.output === "")
5654
const lines = logs.map((log) => ({
5755
time: log.created_at,
5856
output: log.output,
5957
}))
6058
const duration = getStageDurationInSeconds(logs)
61-
const isLastStage = stageIndex === stages.length - 1
62-
const shouldDisplaySpinner = isWaitingForLogs && isLastStage
63-
const shouldDisplayDuration = !isWaitingForLogs && duration
59+
const shouldDisplayDuration = duration !== undefined
6460

6561
return (
6662
<div key={stage}>
6763
<div className={styles.header}>
6864
<div>{stage}</div>
69-
{shouldDisplaySpinner && <CircularProgress size={14} className={styles.spinner} />}
7065
{shouldDisplayDuration && (
7166
<div className={styles.duration}>
7267
{duration} {Language.seconds}
@@ -109,8 +104,4 @@ const useStyles = makeStyles((theme) => ({
109104
padding: theme.spacing(2),
110105
paddingLeft: theme.spacing(4),
111106
},
112-
113-
spinner: {
114-
marginLeft: "auto",
115-
},
116107
}))

‎site/src/pages/WorkspaceBuildPage/WorkspaceBuildPage.test.tsx

+14-13
Original file line numberDiff line numberDiff line change
@@ -1,26 +1,27 @@
11
import { screen } from "@testing-library/react"
2-
import * as API from "../../api/api"
2+
import WS from "jest-websocket-mock"
33
import { MockWorkspace, MockWorkspaceBuild, renderWithAuth } from "../../testHelpers/renderHelpers"
44
import { WorkspaceBuildPage } from "./WorkspaceBuildPage"
55

66
describe("WorkspaceBuildPage", () => {
77
it("renders the stats and logs", async () => {
8-
jest.spyOn(API, "streamWorkspaceBuildLogs").mockResolvedValueOnce({
9-
read() {
10-
return Promise.resolve({
11-
value: undefined,
12-
done: true,
13-
})
14-
},
15-
releaseLock: jest.fn(),
16-
closed: Promise.resolve(undefined),
17-
cancel: jest.fn(),
18-
})
8+
const server = new WS(`ws://localhost/api/v2/workspacebuilds/${MockWorkspaceBuild.id}/logs`)
199
renderWithAuth(<WorkspaceBuildPage />, {
2010
route: `/@${MockWorkspace.owner_name}/${MockWorkspace.name}/builds/${MockWorkspace.latest_build.build_number}`,
2111
path: "/@:username/:workspace/builds/:buildNumber",
2212
})
23-
13+
await server.connected
14+
const log = {
15+
id: "70459334-4878-4bda-a546-98eee166c4c6",
16+
created_at: "2022-05-19T16:46:02.283Z",
17+
log_source: "provisioner_daemon",
18+
log_level: "info",
19+
stage: "Another stage",
20+
output: "",
21+
}
22+
server.send(JSON.stringify(log))
2423
await screen.findByText(MockWorkspaceBuild.workspace_name)
24+
await screen.findByText(log.stage)
25+
server.close()
2526
})
2627
})

‎site/src/pages/WorkspaceBuildPage/WorkspaceBuildPage.tsx

+4-3
Original file line numberDiff line numberDiff line change
@@ -8,17 +8,18 @@ import { WorkspaceBuildPageView } from "./WorkspaceBuildPageView"
88

99
export const WorkspaceBuildPage: FC = () => {
1010
const { username, workspace: workspaceName, buildNumber } = useParams()
11-
const [buildState] = useMachine(workspaceBuildMachine, { context: { username, workspaceName, buildNumber } })
11+
const [buildState] = useMachine(workspaceBuildMachine, {
12+
context: { username, workspaceName, buildNumber, timeCursor: new Date() },
13+
})
1214
const { logs, build } = buildState.context
13-
const isWaitingForLogs = !buildState.matches("logs.loaded")
1415

1516
return (
1617
<>
1718
<Helmet>
1819
<title>{build ? pageTitle(`Build #${build.build_number} · ${build.workspace_name}`) : ""}</title>
1920
</Helmet>
2021

21-
<WorkspaceBuildPageView logs={logs} build={build} isWaitingForLogs={isWaitingForLogs} />
22+
<WorkspaceBuildPageView logs={logs} build={build} />
2223
</>
2324
)
2425
}

‎site/src/pages/WorkspaceBuildPage/WorkspaceBuildPageView.tsx

+2-3
Original file line numberDiff line numberDiff line change
@@ -14,10 +14,9 @@ const sortLogsByCreatedAt = (logs: ProvisionerJobLog[]) => {
1414
export interface WorkspaceBuildPageViewProps {
1515
logs: ProvisionerJobLog[] | undefined
1616
build: WorkspaceBuild | undefined
17-
isWaitingForLogs: boolean
1817
}
1918

20-
export const WorkspaceBuildPageView: FC<WorkspaceBuildPageViewProps> = ({ logs, build, isWaitingForLogs }) => {
19+
export const WorkspaceBuildPageView: FC<WorkspaceBuildPageViewProps> = ({ logs, build }) => {
2120
return (
2221
<Margins>
2322
<PageHeader>
@@ -27,7 +26,7 @@ export const WorkspaceBuildPageView: FC<WorkspaceBuildPageViewProps> = ({ logs,
2726
<Stack>
2827
{build && <WorkspaceBuildStats build={build} />}
2928
{!logs && <Loader />}
30-
{logs && <WorkspaceBuildLogs logs={sortLogsByCreatedAt(logs)} isWaitingForLogs={isWaitingForLogs} />}
29+
{logs && <WorkspaceBuildLogs logs={sortLogsByCreatedAt(logs)} />}
3130
</Stack>
3231
</Margins>
3332
)

‎site/src/testHelpers/handlers.ts

+3
Original file line numberDiff line numberDiff line change
@@ -124,4 +124,7 @@ export const handlers = [
124124
rest.patch("/api/v2/workspacebuilds/:workspaceBuildId/cancel", (req, res, ctx) => {
125125
return res(ctx.status(200), ctx.json(M.MockCancellationMessage))
126126
}),
127+
rest.get("/api/v2/workspacebuilds/:workspaceBuildId/logs", (req, res, ctx) => {
128+
return res(ctx.status(200), ctx.json(M.MockWorkspaceBuildLogs))
129+
}),
127130
]

0 commit comments

Comments
 (0)