feat: log user identifier and user plugin version in write event table

This commit is contained in:
Maxime Cannoodt 2022-08-18 13:21:18 +02:00
parent 14e4b37418
commit 5dbdf8d1d2
17 changed files with 462 additions and 52 deletions

2
plugin

@ -1 +1 @@
Subproject commit 46e53a6d662988c9b8461d41ec4ec3e4f3085dff
Subproject commit 27f978720ff5a7ac7039a2fef8f0c44df54ea324

108
server/package-lock.json generated
View File

@ -1,11 +1,11 @@
{
"name": "obsidian-note-sharing-server",
"name": "obsidian-quickshare-server",
"version": "0.0.1",
"lockfileVersion": 2,
"requires": true,
"packages": {
"": {
"name": "obsidian-note-sharing-server",
"name": "obsidian-quickshare-server",
"version": "0.0.1",
"license": "MIT",
"dependencies": {
@ -13,6 +13,7 @@
"bloom-filters": "^3.0.0",
"body-parser": "^1.20.0",
"class-validator": "^0.13.2",
"crc": "^4.1.1",
"dotenv": "^16.0.1",
"express": "^4.18.1",
"express-rate-limit": "^6.4.0",
@ -649,6 +650,26 @@
"node": ">= 0.6.0"
}
},
"node_modules/base64-js": {
"version": "1.5.1",
"resolved": "https://registry.npmjs.org/base64-js/-/base64-js-1.5.1.tgz",
"integrity": "sha512-AKpaYlHn8t4SVbOHCy+b5+KKgvR4vrsD8vbvrbiQJps7fKDTkjkDry6ji0rUJjC0kzbNePLwzxq8iypo41qeWA==",
"funding": [
{
"type": "github",
"url": "https://github.com/sponsors/feross"
},
{
"type": "patreon",
"url": "https://www.patreon.com/feross"
},
{
"type": "consulting",
"url": "https://feross.org/support"
}
],
"peer": true
},
"node_modules/binary-extensions": {
"version": "2.2.0",
"resolved": "https://registry.npmjs.org/binary-extensions/-/binary-extensions-2.2.0.tgz",
@ -721,6 +742,30 @@
"node": ">=8"
}
},
"node_modules/buffer": {
"version": "6.0.3",
"resolved": "https://registry.npmjs.org/buffer/-/buffer-6.0.3.tgz",
"integrity": "sha512-FTiCpNxtwiZZHEZbcbTIcZjERVICn9yq/pDFkTl95/AxzD1naBctN7YO68riM/gLSDY7sdrMby8hofADYuuqOA==",
"funding": [
{
"type": "github",
"url": "https://github.com/sponsors/feross"
},
{
"type": "patreon",
"url": "https://www.patreon.com/feross"
},
{
"type": "consulting",
"url": "https://feross.org/support"
}
],
"peer": true,
"dependencies": {
"base64-js": "^1.3.1",
"ieee754": "^1.2.1"
}
},
"node_modules/bytes": {
"version": "3.1.2",
"resolved": "https://registry.npmjs.org/bytes/-/bytes-3.1.2.tgz",
@ -1026,6 +1071,17 @@
"integrity": "sha512-JxbCBUdrfr6AQjOXrxoTvAMJO4HBTUIlBzslcJPAz+/KT8yk53fXun51u+RenNYvad/+Vc2DIz5o9UxlCDymFQ==",
"dev": true
},
"node_modules/crc": {
"version": "4.1.1",
"resolved": "https://registry.npmjs.org/crc/-/crc-4.1.1.tgz",
"integrity": "sha512-2U3ZqJ2phJl9ANuP2q5VS53LMpNmYU9vcpmh6nutJmsqUREhtWpTRh9yYxG7sDg3xkwaEEXytSeffTxw4cgwPg==",
"engines": {
"node": ">=12"
},
"peerDependencies": {
"buffer": ">=6.0.3"
}
},
"node_modules/create-require": {
"version": "1.1.1",
"resolved": "https://registry.npmjs.org/create-require/-/create-require-1.1.1.tgz",
@ -2272,6 +2328,26 @@
"node": ">=0.10.0"
}
},
"node_modules/ieee754": {
"version": "1.2.1",
"resolved": "https://registry.npmjs.org/ieee754/-/ieee754-1.2.1.tgz",
"integrity": "sha512-dcyqhDvX1C46lXZcVqCpK+FtMRQVdIMN6/Df5js2zouUsqG7I6sFxitIC+7KYK29KdXOLHdu9zL4sFnoVQnqaA==",
"funding": [
{
"type": "github",
"url": "https://github.com/sponsors/feross"
},
{
"type": "patreon",
"url": "https://www.patreon.com/feross"
},
{
"type": "consulting",
"url": "https://feross.org/support"
}
],
"peer": true
},
"node_modules/ignore-by-default": {
"version": "1.0.1",
"resolved": "https://registry.npmjs.org/ignore-by-default/-/ignore-by-default-1.0.1.tgz",
@ -5696,6 +5772,12 @@
"resolved": "https://registry.npmjs.org/base64-arraybuffer/-/base64-arraybuffer-1.0.2.tgz",
"integrity": "sha512-I3yl4r9QB5ZRY3XuJVEPfc2XhZO6YweFPI+UovAzn+8/hb3oJ6lnysaFcjVpkCPfVWFUDvoZ8kmVDP7WyRtYtQ=="
},
"base64-js": {
"version": "1.5.1",
"resolved": "https://registry.npmjs.org/base64-js/-/base64-js-1.5.1.tgz",
"integrity": "sha512-AKpaYlHn8t4SVbOHCy+b5+KKgvR4vrsD8vbvrbiQJps7fKDTkjkDry6ji0rUJjC0kzbNePLwzxq8iypo41qeWA==",
"peer": true
},
"binary-extensions": {
"version": "2.2.0",
"resolved": "https://registry.npmjs.org/binary-extensions/-/binary-extensions-2.2.0.tgz",
@ -5755,6 +5837,16 @@
"fill-range": "^7.0.1"
}
},
"buffer": {
"version": "6.0.3",
"resolved": "https://registry.npmjs.org/buffer/-/buffer-6.0.3.tgz",
"integrity": "sha512-FTiCpNxtwiZZHEZbcbTIcZjERVICn9yq/pDFkTl95/AxzD1naBctN7YO68riM/gLSDY7sdrMby8hofADYuuqOA==",
"peer": true,
"requires": {
"base64-js": "^1.3.1",
"ieee754": "^1.2.1"
}
},
"bytes": {
"version": "3.1.2",
"resolved": "https://registry.npmjs.org/bytes/-/bytes-3.1.2.tgz",
@ -6002,6 +6094,12 @@
"integrity": "sha512-JxbCBUdrfr6AQjOXrxoTvAMJO4HBTUIlBzslcJPAz+/KT8yk53fXun51u+RenNYvad/+Vc2DIz5o9UxlCDymFQ==",
"dev": true
},
"crc": {
"version": "4.1.1",
"resolved": "https://registry.npmjs.org/crc/-/crc-4.1.1.tgz",
"integrity": "sha512-2U3ZqJ2phJl9ANuP2q5VS53LMpNmYU9vcpmh6nutJmsqUREhtWpTRh9yYxG7sDg3xkwaEEXytSeffTxw4cgwPg==",
"requires": {}
},
"create-require": {
"version": "1.1.1",
"resolved": "https://registry.npmjs.org/create-require/-/create-require-1.1.1.tgz",
@ -6851,6 +6949,12 @@
"safer-buffer": ">= 2.1.2 < 3"
}
},
"ieee754": {
"version": "1.2.1",
"resolved": "https://registry.npmjs.org/ieee754/-/ieee754-1.2.1.tgz",
"integrity": "sha512-dcyqhDvX1C46lXZcVqCpK+FtMRQVdIMN6/Df5js2zouUsqG7I6sFxitIC+7KYK29KdXOLHdu9zL4sFnoVQnqaA==",
"peer": true
},
"ignore-by-default": {
"version": "1.0.1",
"resolved": "https://registry.npmjs.org/ignore-by-default/-/ignore-by-default-1.0.1.tgz",

View File

@ -20,6 +20,7 @@
"bloom-filters": "^3.0.0",
"body-parser": "^1.20.0",
"class-validator": "^0.13.2",
"crc": "^4.1.1",
"dotenv": "^16.0.1",
"express": "^4.18.1",
"express-rate-limit": "^6.4.0",

View File

@ -0,0 +1,3 @@
-- AlterTable
ALTER TABLE "event" ADD COLUMN "user_id" TEXT;
ALTER TABLE "event" ADD COLUMN "user_plugin_version" TEXT;

View File

@ -19,15 +19,17 @@ model EncryptedNote {
}
model event {
id Int @id @default(autoincrement())
time DateTime @default(now())
type String
success Boolean
size_bytes Int?
note_id String?
host String?
error String?
expire_window_days Int?
id Int @id @default(autoincrement())
time DateTime @default(now())
type String
success Boolean
size_bytes Int?
note_id String?
host String?
error String?
expire_window_days Int?
user_id String?
user_plugin_version String?
}
model BloomFilter {

View File

@ -4,8 +4,6 @@ import { describe, it, expect } from "vitest";
import prisma from "./db/client";
import { deleteExpiredNotes } from "./tasks/deleteExpiredNotes";
import { EventType } from "./logging/EventLogger";
import { getFilter } from "./db/bloomFilter.dao";
import { getExpiredNoteFilter } from "./lib/expiredNoteFilter";
// const testNote with base64 ciphertext and hmac
const testNote = {
@ -83,8 +81,12 @@ describe("GET /api/note", () => {
});
describe("POST /api/note", () => {
it("returns a view_url on correct POST body", async () => {
it("returns a view_url on correct POST body (without plugin version and user id)", async () => {
const res = await supertest(app).post("/api/note").send(testNote);
if (res.statusCode !== 200) {
console.log(res.body);
}
expect(res.statusCode).toBe(200);
// Returned body has correct fields
@ -162,8 +164,14 @@ describe("POST /api/note", () => {
const responseCodes = responses.map((res) => res.statusCode);
// at least one response should be 429
expect(responseCodes).toContain(200);
expect(responseCodes).toContain(429);
// No other response codes should be present
expect(
responseCodes.map((code) => code === 429 || code === 200)
).not.toContain(false);
// sleep for 100 ms to allow rate limiter to reset
await new Promise((resolve) => setTimeout(resolve, 250));
});

View File

@ -2,7 +2,7 @@ import { NextFunction, Request, Response } from "express";
import { getExpiredNoteFilter } from "../../lib/expiredNoteFilter";
import EventLogger from "../../logging/EventLogger";
import { getConnectingIp } from "../../util";
import { getNote } from "./note.dao";
import { getNote } from "../../db/note.dao";
export async function getNoteController(
req: Request,
res: Response,

View File

@ -1,20 +1,38 @@
import { EncryptedNote } from "@prisma/client";
import { validateOrReject } from "class-validator";
import { NextFunction, Request, Response } from "express";
import { IsBase64 } from "class-validator";
import { createNote } from "./note.dao";
import { crc16 as crc } from "crc";
import { createNote } from "../../db/note.dao";
import { addDays, getConnectingIp } from "../../util";
import EventLogger from "../../logging/EventLogger";
import EventLogger, { WriteEvent } from "../../logging/EventLogger";
import {
validateOrReject,
IsBase64,
IsHexadecimal,
IsNotEmpty,
ValidateIf,
ValidationError,
Matches,
} from "class-validator";
/**
* Request body for creating a note
*/
export class NotePostRequest {
@IsBase64()
@IsNotEmpty()
ciphertext: string | undefined;
@IsBase64()
@IsNotEmpty()
hmac: string | undefined;
@ValidateIf((o) => o.user_id != null)
@IsHexadecimal()
user_id: string | undefined;
@ValidateIf((o) => o.plugin_version != null)
@Matches("^[0-9]+\\.[0-9]+\\.[0-9]+$")
plugin_version: string | undefined;
}
export async function postNoteController(
@ -22,38 +40,79 @@ export async function postNoteController(
res: Response,
next: NextFunction
): Promise<void> {
const ip = getConnectingIp(req);
const event: WriteEvent = {
success: false,
host: getConnectingIp(req),
user_id: req.body.user_id,
user_plugin_version: req.body.plugin_version,
};
// Validate request body
const notePostRequest = new NotePostRequest();
Object.assign(notePostRequest, req.body);
validateOrReject(notePostRequest).catch((err) => {
res.status(400).send(err.message);
});
const note = notePostRequest as EncryptedNote;
try {
await validateOrReject(notePostRequest);
} catch (_err: any) {
const err = _err as ValidationError;
res.status(400).send(err.toString());
event.error = err.toString();
EventLogger.writeEvent(event);
return;
}
// Validate user ID, if present
if (notePostRequest.user_id && !checkId(notePostRequest.user_id)) {
console.log("invalid user id");
res.status(400).send("Invalid user id (checksum failed)");
event.error = "Invalid user id (checksum failed)";
EventLogger.writeEvent(event);
return;
}
// Create note object
const EXPIRE_WINDOW_DAYS = 30;
createNote({
...note,
const note = {
ciphertext: notePostRequest.ciphertext as string,
hmac: notePostRequest.hmac as string,
expire_time: addDays(new Date(), EXPIRE_WINDOW_DAYS),
})
} as EncryptedNote;
// Store note object
createNote(note)
.then(async (savedNote) => {
await EventLogger.writeEvent({
success: true,
host: ip,
note_id: savedNote.id,
size_bytes: savedNote.ciphertext.length + savedNote.hmac.length,
expire_window_days: EXPIRE_WINDOW_DAYS,
});
event.success = true;
event.note_id = savedNote.id;
event.size_bytes = savedNote.ciphertext.length + savedNote.hmac.length;
event.expire_window_days = EXPIRE_WINDOW_DAYS;
await EventLogger.writeEvent(event);
res.json({
view_url: `${process.env.FRONTEND_URL}/note/${savedNote.id}`,
expire_time: savedNote.expire_time,
});
})
.catch(async (err) => {
await EventLogger.writeEvent({
success: false,
host: ip,
error: err.message,
});
event.error = err.toString();
await EventLogger.writeEvent(event);
next(err);
});
}
/**
* @param id {string} a 16 character base16 string with 12 random characters and 4 CRC characters
* @returns {boolean} true if the id is valid, false otherwise
*/
function checkId(id: string): boolean {
// check length
if (id.length !== 16) {
return false;
}
// extract the random number and the checksum
const random = id.slice(0, 12);
const checksum = id.slice(12, 16);
// compute the CRC of the random number
const computedChecksum = crc(random).toString(16).padStart(4, "0");
// compare the computed checksum with the one in the id
return computedChecksum === checksum;
}

View File

@ -0,0 +1,221 @@
import express from "express";
import supertest from "supertest";
import { vi, describe, it, beforeEach, afterEach, expect } from "vitest";
import * as noteDao from "../../db/note.dao";
import EventLogger from "../../logging/EventLogger";
import { NotePostRequest, postNoteController } from "./note.post.controller";
vi.mock("../../db/note.dao");
vi.mock("../../logging/EventLogger");
const VALID_CIPHERTEXT = Buffer.from("sample_ciphertext").toString("base64");
const VALID_HMAC = Buffer.from("sample_hmac").toString("base64");
const VALID_VERSION = "1.0.0";
const MALFORMED_VERSION = "v1.0.0";
const VALID_USER_ID = "f06536e7df6857fc";
const MALFORMED_ID_WRONG_CRC = "f06536e7df6857fd";
const MALFORMED_ID_WRONG_LENGTH = "0";
const MOCK_NOTE_ID = "1234";
type TestParams = {
payload: Partial<NotePostRequest>;
expectedStatus: number;
};
const TEST_PAYLOADS: TestParams[] = [
// Request with valid ciphertext and hmac
{
payload: {
ciphertext: VALID_CIPHERTEXT,
hmac: VALID_HMAC,
},
expectedStatus: 200,
},
// Request with valid ciphertext, hmac, user id, and plugin version
{
payload: {
ciphertext: VALID_CIPHERTEXT,
hmac: VALID_HMAC,
user_id: VALID_USER_ID,
plugin_version: VALID_VERSION,
},
expectedStatus: 200,
},
// Request with non-base64 ciphertext
{
payload: {
ciphertext: "not_base64",
hmac: VALID_HMAC,
},
expectedStatus: 400,
},
// Request with non-base64 hmac
{
payload: {
ciphertext: VALID_CIPHERTEXT,
hmac: "not_base64",
},
expectedStatus: 400,
},
// Request with empty ciphertext
{
payload: {
ciphertext: "",
hmac: VALID_HMAC,
},
expectedStatus: 400,
},
// Request with empty hmac
{
payload: {
ciphertext: VALID_CIPHERTEXT,
hmac: "",
},
expectedStatus: 400,
},
// Request with valid user id
{
payload: {
ciphertext: VALID_CIPHERTEXT,
hmac: VALID_HMAC,
user_id: VALID_USER_ID,
},
expectedStatus: 200,
},
// Request with malformed user id (wrong crc)
{
payload: {
ciphertext: VALID_CIPHERTEXT,
hmac: VALID_HMAC,
user_id: MALFORMED_ID_WRONG_CRC,
},
expectedStatus: 400,
},
// Request with malformed user id (wrong length)
{
payload: {
ciphertext: VALID_CIPHERTEXT,
hmac: VALID_HMAC,
user_id: MALFORMED_ID_WRONG_LENGTH,
},
expectedStatus: 400,
},
// Request with valid plugin version
{
payload: {
ciphertext: VALID_CIPHERTEXT,
hmac: VALID_HMAC,
plugin_version: VALID_VERSION,
},
expectedStatus: 200,
},
// Request with malformed plugin version
{
payload: {
ciphertext: VALID_CIPHERTEXT,
hmac: VALID_HMAC,
plugin_version: MALFORMED_VERSION,
},
expectedStatus: 400,
},
];
describe("note.post.controller", () => {
let mockNoteDao = vi.mocked(noteDao);
let mockEventLogger = vi.mocked(EventLogger);
const test_app = express().use(express.json()).post("/", postNoteController);
beforeEach(() => {
// database writes always succeed
mockNoteDao.createNote.mockImplementation(async (note) => ({
...note,
id: MOCK_NOTE_ID,
insert_time: new Date(),
}));
});
afterEach(() => {
vi.resetAllMocks();
});
it.each(TEST_PAYLOADS)("test payloads", async (params) => {
const { payload, expectedStatus } = params;
// make request
const res = await supertest(test_app).post("/").send(payload);
expect(res.status).toBe(expectedStatus);
// Validate reponse body
if (expectedStatus === 200) {
// validate view_url
expect(res.body).toHaveProperty("view_url");
expect(res.body.view_url).toMatch(/^http[s]?:\/\//);
expect(res.body.view_url).toMatch(MOCK_NOTE_ID);
// validate_expire_time
expect(res.body).toHaveProperty("expire_time");
expect(new Date(res.body.expire_time).getTime()).toBeGreaterThan(
new Date().getTime()
);
}
// Validate Write events
expect(mockEventLogger.writeEvent).toHaveBeenCalledOnce();
if (expectedStatus === 200) {
expect(mockEventLogger.writeEvent).toHaveBeenCalledWith(
expect.objectContaining({
success: true,
host: expect.any(String),
note_id: MOCK_NOTE_ID,
size_bytes: expect.any(Number),
expire_window_days: expect.any(Number),
user_id: params.payload.user_id,
user_plugin_version: params.payload.plugin_version,
})
);
} else {
expect(mockEventLogger.writeEvent).toHaveBeenCalledWith(
expect.objectContaining({
success: false,
host: expect.any(String),
error: expect.any(String),
user_id: params.payload.user_id,
user_plugin_version: params.payload.plugin_version,
})
);
}
});
it("test database write failure", async () => {
// Mock database writes always fail
mockNoteDao.createNote.mockImplementation(async (note) => {
throw new Error("Database write failed");
});
// Payload
const payload = {
ciphertext: VALID_CIPHERTEXT,
hmac: VALID_HMAC,
user_id: VALID_USER_ID,
plugin_version: VALID_VERSION,
};
// make request
const res = await supertest(test_app).post("/").send(payload);
expect(res.status).toBe(500);
// Validate Write events
expect(mockEventLogger.writeEvent).toHaveBeenCalledOnce();
expect(mockEventLogger.writeEvent).toHaveBeenCalledWith(
expect.objectContaining({
success: false,
host: expect.any(String),
error: "Error: Database write failed",
user_id: payload.user_id,
user_plugin_version: payload.plugin_version,
})
);
});
});

View File

@ -0,0 +1,4 @@
import { vi } from "vitest";
export const getFilter = vi.fn();
export const upsertFilter = vi.fn();

View File

@ -0,0 +1,6 @@
import { vi } from "vitest";
export const getNote = vi.fn();
export const createNote = vi.fn();
export const getExpiredNotes = vi.fn();
export const deleteNotes = vi.fn();

View File

@ -1,5 +1,5 @@
import { EncryptedNote } from "@prisma/client";
import prisma from "../../db/client";
import prisma from "./client";
export async function getNote(noteId: string): Promise<EncryptedNote | null> {
return prisma.encryptedNote.findUnique({

View File

@ -3,10 +3,7 @@ import { ExpiredNoteFilter } from "./expiredNoteFilter";
import { ScalableBloomFilter } from "bloom-filters";
import * as dao from "../db/bloomFilter.dao";
vi.mock("../db/bloomFilter.dao", () => ({
getFilter: vi.fn(),
upsertFilter: vi.fn(),
}));
vi.mock("../db/bloomFilter.dao");
describe("Deserialization from database", () => {
afterEach(() => {

View File

@ -10,6 +10,8 @@ describe("Logging write events", () => {
size_bytes: 100,
success: true,
expire_window_days: 30,
user_id: "test_user",
user_plugin_version: "1.0.0",
};
// Is event written successfully?

View File

@ -17,9 +17,11 @@ interface ClientEvent extends Event {
success: boolean;
note_id?: string;
size_bytes?: number;
user_id?: string;
user_plugin_version?: string;
}
interface WriteEvent extends ClientEvent {
export interface WriteEvent extends ClientEvent {
expire_window_days?: number;
}

View File

@ -1,4 +1,4 @@
import { deleteNotes, getExpiredNotes } from "../controllers/note/note.dao";
import { deleteNotes, getExpiredNotes } from "../db/note.dao";
import { getExpiredNoteFilter } from "../lib/expiredNoteFilter";
import EventLogger from "../logging/EventLogger";
import logger from "../logging/logger";

View File

@ -1,14 +1,14 @@
import { describe, it, expect, vi, beforeEach, afterEach } from "vitest";
import { deleteExpiredNotes } from "./deleteExpiredNotes";
import * as noteDao from "../controllers/note/note.dao";
import * as noteDao from "../db/note.dao";
import EventLogger from "../logging/EventLogger";
import logger from "../logging/logger";
import * as filter from "../lib/expiredNoteFilter";
vi.mock("../controllers/note/note.dao", () => ({
getExpiredNotes: vi.fn(),
deleteNotes: vi.fn(),
}));
// vi.mock("../db/note.dao", () => ({
// getExpiredNotes: vi.fn(),
// deleteNotes: vi.fn(),
// }));
vi.mock("../lib/expiredNoteFilter", () => {
const instance = {
@ -17,6 +17,7 @@ vi.mock("../lib/expiredNoteFilter", () => {
return { getExpiredNoteFilter: () => instance };
});
vi.mock("../db/note.dao");
vi.mock("../logging/EventLogger");
vi.spyOn(logger, "error");