LogContext: Fix a bug where multiple logs with similar nanosecond timestamps were loaded too often (#71319)

fix bug with multiple ns logs

devenv/docker/blocks/loki/data/data.js

@@ -170,33 +170,45 @@ async function sendOldLogs() {
   const delays = calculateDelays(DAYS * POINTS_PER_DAY);
   const timeRange = DAYS * 24 * 60 * 60 * 1000;
   let timestampMs = new Date().getTime() - timeRange;
-  for(let i =0; i < delays.length; i++ ) { // i cannot do a forEach because of the `await` inside
+  for (let i = 0; i < delays.length; i++) { // i cannot do a forEach because of the `await` inside
     const delay = delays[i];
     timestampMs += Math.trunc(delay * timeRange);
     const timestampNs = `${timestampMs}${getRandomNanosecPart()}`;
     globalCounter += 1;
     const item = getRandomLogItem(globalCounter)
-    await lokiSendLogLine(timestampNs, JSON.stringify(item), {age:'old', place:'moon', ...sharedLabels});
-    await lokiSendLogLine(timestampNs, logFmtLine(item), {age:'old', place:'luna', ...sharedLabels});
+    await lokiSendLogLine(timestampNs, JSON.stringify(item), { age: 'old', place: 'moon', ...sharedLabels });
+    await lokiSendLogLine(timestampNs, logFmtLine(item), { age: 'old', place: 'luna', ...sharedLabels });
   };
 }
 
 async function sendNewLogs() {
-  while(true) {
+  while (true) {
     globalCounter += 1;
     const nowMs = new Date().getTime();
-    const timestampNs = `${nowMs}${getRandomNanosecPart()}`;
+    const rnd = Math.random()
+    const ns = Math.trunc(rnd * 1000000).toString().padStart(6, '0');
+    const ns1 = Math.trunc((rnd * 1000000)+1).toString().padStart(6, '0');
+    const ns2 = Math.trunc((rnd * 1000000)+2).toString().padStart(6, '0');
+
+    const timestampNs = `${nowMs}${ns}`;
+    const timestampNs1 = `${nowMs}${ns1}`;
+    const timestampNs2 = `${nowMs}${ns2}`;
+
     const item = getRandomLogItem(globalCounter)
-    await lokiSendLogLine(timestampNs, JSON.stringify(item), {age:'new', place:'moon', ...sharedLabels});
-    await lokiSendLogLine(timestampNs, logFmtLine(item), {age:'new', place:'luna', ...sharedLabels});
-    const sleepDuration  = 200 + Math.random() * 800; // between 0.2 and 1 seconds
+
+    await lokiSendLogLine(timestampNs, JSON.stringify(item), { time: 'ns', age: 'new', place: 'moon', ...sharedLabels });
+    await lokiSendLogLine(timestampNs1, JSON.stringify(item), { time: 'ns', age: 'new', place: 'moon', ...sharedLabels });
+    await lokiSendLogLine(timestampNs2, JSON.stringify(item), { time: 'ns', age: 'new', place: 'moon', ...sharedLabels });
+    
+    const sleepDuration = 200 + Math.random() * 800; // between 0.2 and 1 seconds
     await sleep(sleepDuration);
+    process.exit(0);
   }
 }
 
 async function main() {
   // we generate both old-logs and new-logs at the same time
-  await Promise.all([sendOldLogs(), sendNewLogs()])
+  await Promise.all([sendNewLogs()])
 }
 
 // when running in docker, we catch the needed stop-signal, to shutdown fast

public/app/features/logs/components/log-context/LogRowContextModal.test.tsx

@@ -188,6 +188,106 @@ describe('LogRowContextModal', () => {
     await waitFor(() => expect(screen.getAllByText('foo123').length).toBe(3));
   });
 
+  it('should render 3 lines containing `foo123` with the same ms timestamp', async () => {
+    const dfBefore = createDataFrame({
+      fields: [
+        {
+          name: 'time',
+          type: FieldType.time,
+          values: [1689052469935, 1689052469935],
+        },
+        {
+          name: 'message',
+          type: FieldType.string,
+          values: ['foo123', 'foo123'],
+        },
+        {
+          name: 'tsNs',
+          type: FieldType.string,
+          values: ['1689052469935083353', '1689052469935083354'],
+        },
+      ],
+    });
+    const dfNow = createDataFrame({
+      fields: [
+        {
+          name: 'time',
+          type: FieldType.time,
+          values: [1689052469935],
+        },
+        {
+          name: 'message',
+          type: FieldType.string,
+          values: ['foo123'],
+        },
+        {
+          name: 'tsNs',
+          type: FieldType.string,
+          values: ['1689052469935083354'],
+        },
+      ],
+    });
+    const dfAfter = createDataFrame({
+      fields: [
+        {
+          name: 'time',
+          type: FieldType.time,
+          values: [1689052469935, 1689052469935],
+        },
+        {
+          name: 'message',
+          type: FieldType.string,
+          values: ['foo123', 'foo123'],
+        },
+        {
+          name: 'tsNs',
+          type: FieldType.string,
+          values: ['1689052469935083354', '1689052469935083355'],
+        },
+      ],
+    });
+
+    let uniqueRefIdCounter = 1;
+    const logs = dataFrameToLogsModel([dfNow]);
+    const row = logs.rows[0];
+    const getRowContext = jest.fn().mockImplementation(async (_, options) => {
+      uniqueRefIdCounter += 1;
+      const refId = `refid_${uniqueRefIdCounter}`;
+      if (options.direction === LogRowContextQueryDirection.Forward) {
+        return {
+          data: [
+            {
+              refId,
+              ...dfBefore,
+            },
+          ],
+        };
+      } else {
+        return {
+          data: [
+            {
+              refId,
+              ...dfAfter,
+            },
+          ],
+        };
+      }
+    });
+
+    render(
+      <LogRowContextModal
+        row={row}
+        open={true}
+        onClose={() => {}}
+        getRowContext={getRowContext}
+        timeZone={timeZone}
+        logsSortOrder={LogsSortOrder.Descending}
+      />
+    );
+    // there need to be 2 lines with that message. 1 in before, 1 in now, 1 in after
+    await waitFor(() => expect(screen.getAllByText('foo123').length).toBe(3));
+  });
+
   it('should show a split view button', async () => {
     const getRowContextQuery = jest.fn().mockResolvedValue({ datasource: { uid: 'test-uid' } });
 

public/app/features/logs/components/log-context/LogRowContextModal.tsx

@@ -155,6 +155,10 @@ const getLoadMoreDirection = (place: Place, sortOrder: LogsSortOrder): LogRowCon
   return LogRowContextQueryDirection.Backward;
 };
 
+const containsRow = (rows: LogRowModel[], row: LogRowModel) => {
+  return rows.some((r) => r.entry === row.entry && r.timeEpochNs === row.timeEpochNs);
+};
+
 const PAGE_SIZE = 50;
 
 export const LogRowContextModal: React.FunctionComponent<LogRowContextModalProps> = ({
@@ -269,7 +273,7 @@ export const LogRowContextModal: React.FunctionComponent<LogRowContextModalProps
     }
 
     const out = newRows.filter((r) => {
-      return r.timeEpochNs !== refRow.timeEpochNs || r.entry !== refRow.entry;
+      return !containsRow(allRows, r);
     });
 
     return out;