From 920acf4256ca3671abdf39a02047813f2b91b89c Mon Sep 17 00:00:00 2001 From: Amir Raminfar Date: Wed, 26 May 2021 12:05:55 -0700 Subject: [PATCH] Fixes reconnection bugs (#1256) * Fixes reconnect by sending lastEventId see #1246 * Cleans up colors and spacing * Fixes tests --- assets/components/LogContainer.vue | 2 +- assets/components/LogEventSource.spec.js | 70 +++++++++++++----------- assets/components/LogEventSource.vue | 46 ++++++++++------ assets/components/LogViewer.vue | 12 ++-- web/logs.go | 11 ++-- 5 files changed, 81 insertions(+), 60 deletions(-) diff --git a/assets/components/LogContainer.vue b/assets/components/LogContainer.vue index 064aca91..1368fb84 100644 --- a/assets/components/LogContainer.vue +++ b/assets/components/LogContainer.vue @@ -27,7 +27,7 @@ diff --git a/assets/components/LogEventSource.spec.js b/assets/components/LogEventSource.spec.js index 3409c995..899f7c59 100644 --- a/assets/components/LogEventSource.spec.js +++ b/assets/components/LogEventSource.spec.js @@ -66,22 +66,24 @@ describe("", () => { test("should connect to EventSource", async () => { const wrapper = createLogEventSource(); - sources["/api/logs/stream?id=abc"].emitOpen(); - expect(sources["/api/logs/stream?id=abc"].readyState).toBe(1); + sources["/api/logs/stream?id=abc&lastEventId="].emitOpen(); + expect(sources["/api/logs/stream?id=abc&lastEventId="].readyState).toBe(1); wrapper.destroy(); }); test("should close EventSource", async () => { const wrapper = createLogEventSource(); - sources["/api/logs/stream?id=abc"].emitOpen(); + sources["/api/logs/stream?id=abc&lastEventId="].emitOpen(); wrapper.destroy(); - expect(sources["/api/logs/stream?id=abc"].readyState).toBe(2); + expect(sources["/api/logs/stream?id=abc&lastEventId="].readyState).toBe(2); }); test("should parse messages", async () => { const wrapper = createLogEventSource(); - sources["/api/logs/stream?id=abc"].emitOpen(); - sources["/api/logs/stream?id=abc"].emitMessage({ data: `2019-06-12T10:55:42.459034602Z "This is a message."` }); + sources["/api/logs/stream?id=abc&lastEventId="].emitOpen(); + sources["/api/logs/stream?id=abc&lastEventId="].emitMessage({ + data: `2019-06-12T10:55:42.459034602Z "This is a message."`, + }); const [message, _] = wrapper.vm.messages; const { key, ...messageWithoutKey } = message; @@ -90,15 +92,15 @@ describe("", () => { expect(messageWithoutKey).toMatchInlineSnapshot(` Object { "date": 2019-06-12T10:55:42.459Z, - "message": " \\"This is a message.\\"", + "message": "\\"This is a message.\\"", } `); }); test("should parse messages with loki's timestamp format", async () => { const wrapper = createLogEventSource(); - sources["/api/logs/stream?id=abc"].emitOpen(); - sources["/api/logs/stream?id=abc"].emitMessage({ data: `2020-04-27T12:35:43.272974324+02:00 xxxxx` }); + sources["/api/logs/stream?id=abc&lastEventId="].emitOpen(); + sources["/api/logs/stream?id=abc&lastEventId="].emitMessage({ data: `2020-04-27T12:35:43.272974324+02:00 xxxxx` }); const [message, _] = wrapper.vm.messages; const { key, ...messageWithoutKey } = message; @@ -107,15 +109,17 @@ describe("", () => { expect(messageWithoutKey).toMatchInlineSnapshot(` Object { "date": 2020-04-27T10:35:43.272Z, - "message": " xxxxx", + "message": "xxxxx", } `); }); test("should pass messages to slot", async () => { const wrapper = createLogEventSource(); - sources["/api/logs/stream?id=abc"].emitOpen(); - sources["/api/logs/stream?id=abc"].emitMessage({ data: `2019-06-12T10:55:42.459034602Z "This is a message."` }); + sources["/api/logs/stream?id=abc&lastEventId="].emitOpen(); + sources["/api/logs/stream?id=abc&lastEventId="].emitMessage({ + data: `2019-06-12T10:55:42.459034602Z "This is a message."`, + }); const [message, _] = wrapper.findComponent(LogViewer).vm.messages; const { key, ...messageWithoutKey } = message; @@ -125,7 +129,7 @@ describe("", () => { expect(messageWithoutKey).toMatchInlineSnapshot(` Object { "date": 2019-06-12T10:55:42.459Z, - "message": " \\"This is a message.\\"", + "message": "\\"This is a message.\\"", } `); }); @@ -147,91 +151,93 @@ describe("", () => { test("should render messages", async () => { const wrapper = createLogEventSource(); - sources["/api/logs/stream?id=abc"].emitOpen(); - sources["/api/logs/stream?id=abc"].emitMessage({ data: `2019-06-12T10:55:42.459034602Z "This is a message."` }); + sources["/api/logs/stream?id=abc&lastEventId="].emitOpen(); + sources["/api/logs/stream?id=abc&lastEventId="].emitMessage({ + data: `2019-06-12T10:55:42.459034602Z "This is a message."`, + }); await wrapper.vm.$nextTick(); expect(wrapper.find("ul.events")).toMatchInlineSnapshot(`
    -
  • "This is a message."
    • +
  • "This is a message."
`); }); test("should render messages with color", async () => { const wrapper = createLogEventSource(); - sources["/api/logs/stream?id=abc"].emitOpen(); - sources["/api/logs/stream?id=abc"].emitMessage({ + sources["/api/logs/stream?id=abc&lastEventId="].emitOpen(); + sources["/api/logs/stream?id=abc&lastEventId="].emitMessage({ data: `2019-06-12T10:55:42.459034602Z \x1b[30mblack\x1b[37mwhite`, }); await wrapper.vm.$nextTick(); expect(wrapper.find("ul.events")).toMatchInlineSnapshot(`
    -
  • blackwhite
    • +
  • blackwhite
`); }); test("should render messages with html entities", async () => { const wrapper = createLogEventSource(); - sources["/api/logs/stream?id=abc"].emitOpen(); - sources["/api/logs/stream?id=abc"].emitMessage({ + sources["/api/logs/stream?id=abc&lastEventId="].emitOpen(); + sources["/api/logs/stream?id=abc&lastEventId="].emitMessage({ data: `2019-06-12T10:55:42.459034602Z foo bar`, }); await wrapper.vm.$nextTick(); expect(wrapper.find("ul.events")).toMatchInlineSnapshot(`
    -
  • <test>foo bar</test>
    • +
  • <test>foo bar</test>
`); }); test("should render dates with 12 hour style", async () => { const wrapper = createLogEventSource({ hourStyle: "12" }); - sources["/api/logs/stream?id=abc"].emitOpen(); - sources["/api/logs/stream?id=abc"].emitMessage({ + sources["/api/logs/stream?id=abc&lastEventId="].emitOpen(); + sources["/api/logs/stream?id=abc&lastEventId="].emitMessage({ data: `2019-06-12T23:55:42.459034602Z foo bar`, }); await wrapper.vm.$nextTick(); expect(wrapper.find("ul.events")).toMatchInlineSnapshot(`
    -
  • <test>foo bar</test>
    • +
  • <test>foo bar</test>
`); }); test("should render dates with 24 hour style", async () => { const wrapper = createLogEventSource({ hourStyle: "24" }); - sources["/api/logs/stream?id=abc"].emitOpen(); - sources["/api/logs/stream?id=abc"].emitMessage({ + sources["/api/logs/stream?id=abc&lastEventId="].emitOpen(); + sources["/api/logs/stream?id=abc&lastEventId="].emitMessage({ data: `2019-06-12T23:55:42.459034602Z foo bar`, }); await wrapper.vm.$nextTick(); expect(wrapper.find("ul.events")).toMatchInlineSnapshot(`
    -
  • <test>foo bar</test>
    • +
  • <test>foo bar</test>
`); }); test("should render messages with filter", async () => { const wrapper = createLogEventSource({ searchFilter: "test" }); - sources["/api/logs/stream?id=abc"].emitOpen(); - sources["/api/logs/stream?id=abc"].emitMessage({ + sources["/api/logs/stream?id=abc&lastEventId="].emitOpen(); + sources["/api/logs/stream?id=abc&lastEventId="].emitMessage({ data: `2019-06-11T10:55:42.459034602Z Foo bar`, }); - sources["/api/logs/stream?id=abc"].emitMessage({ + sources["/api/logs/stream?id=abc&lastEventId="].emitMessage({ data: `2019-06-12T10:55:42.459034602Z This is a test `, }); await wrapper.vm.$nextTick(); expect(wrapper.find("ul.events")).toMatchInlineSnapshot(`
    -
  • This is a test <hi></hi>
    • +
  • This is a test <hi></hi>
`); }); diff --git a/assets/components/LogEventSource.vue b/assets/components/LogEventSource.vue index a5bd8687..9e2c0f51 100644 --- a/assets/components/LogEventSource.vue +++ b/assets/components/LogEventSource.vue @@ -22,10 +22,11 @@ export default { return { messages: [], buffer: [], + es: null, + lastEventId: null, }; }, created() { - this.es = null; this.loadLogs(); this.flushBuffer = debounce(this.flushNow, 250, { maxWait: 1000 }); }, @@ -33,28 +34,37 @@ export default { this.es.close(); }, methods: { - onContainerStateChange(newValue, oldValue) { - if (newValue == "running" && newValue != oldValue) { - this.connect(); - } - }, loadLogs() { this.reset(); this.connect(); }, + onContainerStopped() { + this.es.close(); + this.buffer.push({ event: "container-stopped", message: "Container stopped", date: new Date(), key: new Date() }); + this.flushBuffer(); + this.flushBuffer.flush(); + }, + onMessage(e) { + this.lastEventId = e.lastEventId; + this.buffer.push(this.parseMessage(e.data)); + this.flushBuffer(); + }, + onContainerStateChange(newValue, oldValue) { + if (newValue == "running" && newValue != oldValue) { + this.buffer.push({ + event: "container-started", + message: "Container started", + date: new Date(), + key: new Date(), + }); + this.connect(); + } + }, connect() { - this.es = new EventSource(`${config.base}/api/logs/stream?id=${this.id}`); - this.es.addEventListener("container-stopped", (e) => { - this.es.close(); - this.buffer.push({ event: "container-stopped", message: "Container stopped", date: new Date() }); - this.flushBuffer(); - this.flushBuffer.flush(); - }); + this.es = new EventSource(`${config.base}/api/logs/stream?id=${this.id}&lastEventId=${this.lastEventId ?? ""}`); + this.es.addEventListener("container-stopped", (e) => this.onContainerStopped()); this.es.addEventListener("error", (e) => console.error("EventSource failed: " + JSON.stringify(e))); - this.es.onmessage = (e) => { - this.buffer.push(this.parseMessage(e.data)); - this.flushBuffer(); - }; + this.es.onmessage = (e) => this.onMessage(e); }, flushNow() { this.messages.push(...this.buffer); @@ -96,7 +106,7 @@ export default { } const key = data.substring(0, i); const date = new Date(key); - const message = data.substring(i); + const message = data.substring(i + 1); return { key, date, message }; }, }, diff --git a/assets/components/LogViewer.vue b/assets/components/LogViewer.vue index fc668110..d2ce75b3 100644 --- a/assets/components/LogViewer.vue +++ b/assets/components/LogViewer.vue @@ -1,6 +1,6 @@