typelevel / skunk

A data access library for Scala + Postgres.
https://typelevel.org/skunk/
MIT License
1.58k stars 161 forks source link

Stacktrace displayed in MUnit test that intercepts the exception #511

Open ohuu opened 3 years ago

ohuu commented 3 years ago

I'm running a few tests which I expect to fail with a Skunk exception. The tests pass but Skunk displays the exception in the console. This isn't a problem it's just mildly annoying.

Here's a snippet of my test

IO(dbWorker())
      .flatMap(sessionPool =>
        sessionPool.use(session =>
          val res = for
            service <- sciServiceFromSession(session)
            _       <- service.signup(sciWithPasswd1)
            _       <- service.signup(sciWithPasswd2)
          yield ()

          // check that the IO throws an exception
          res.intercept[skunk.exception.PostgresErrorException]
        )
      )

And here's a screenshot of the test being run:

image

Also as a side note, noticed the strange font of the stacktrace is this because I'm running it on Windows and the terminal can't render the font properly?

ohuu commented 3 years ago

I'm creating a site that stores users and I want to take advantage of row level security (RLS) to stop users from reading each others private data. The example below is simplified and somewhat contrived but it does illustrate the problem I'm having well. The migration script for the user table looks something like this:

BEGIN ;

DROP TABLE IF EXISTS user CASCADE;
CREATE TABLE user (
    id UUID PRIMARY KEY DEFAULT uuid_generate_v4()
    firstname TEXT DEFAULT NULL,

    ...blah blah blah
);
ALTER TABLE user ENABLE ROW LEVEL SECURITY;

GRANT INSERT, SELECT, UPDATE ON TABLE user TO db_user;

-- don't let user see other users stuff!
CREATE POLICY select_own ON user 
    FOR SELECT
    TO db_user
    USING (current_setting('auth.id')::UUID = id);

... blah blah blah

COMMIT;

I've written a simple test to check that scientist can only access their own private data.

package com.osi.main.http

import java.util.UUID

import cats.*
import cats.effect.IO
import cats.effect.MonadCancelThrow
import cats.effect.Resource
import cats.effect.implicits.*
import cats.implicits.*

import skunk.*
import skunk.exception.*
import skunk.codec.all.*
import skunk.implicits.*
import natchez.Trace.Implicits.noop

class MinimalExampleSuite extends munit.CatsEffectSuite {
  val dbFixture: Fixture[skunk.SessionPool[IO]] =
    new Fixture[skunk.SessionPool[IO]]("db_user") {
      val sessionPool = Session.pooled[IO](
        host = "localhost",
        port = 5432,
        user = "db_user",
        database = "my_db",
        password = "blahblahblah".some,
        max = 10,
        debug = false
      )

      def apply() = sessionPool
    }

  override def munitFixtures = List(dbFixture)

  val id1 = UUID.fromString("d719cc23-d97a-40b5-8813-72c687a40479")
  val id2 = UUID.fromString("c2d06800-a577-459d-baea-8cb8438c51a8")

  test("this works") {
    IO(dbFixture())
      .flatMap(sessionPool =>
        sessionPool.use(session =>
          session.use(db =>
            val test = for
              _    <- db.execute(sql"SET auth.id = '#${id1.toString}'".command)
              name <- db
                        .prepare(sql"SELECT firstname FROM user WHERE id = $uuid".query(text))
                        .use(_.unique(id2))  // fails because id2 != id1 
            yield name

            test.intercept[SkunkException] // expect the query to throw an exception
          )
        )
      )
  }
}

This works just fine. The test passes because the query throws an exception thanks to RLS and the output of the test looks like this:

com.example.MinimalExampleSuite:
  + this works 0.95s

I'm making pretty good use of RLS so I don't want to keep setting the auth.id session variable on every query that touches RLS so I abstract that bit out into a function using the loveliness of functional programing like this:

def as[F[_], A](key: UUID)(f: => F[A])(using MonadCancelThrow[F])(implicit session: Session[F]) =
  session.transaction.use(xa =>
    for
      _ <- session.execute(sql"SET auth.id = '#${key.toString}'".command)
      a <- f
    yield a
  )

But now when I create a test using this function something prints out the stacktrace and message from Skunk even though the test passes just fine. The test looks like this:

test("this works BUT message and stack trace is printed!") {
    IO(dbWorker())
      .flatMap(sessionPool =>
        sessionPool.use(dbResource =>
          dbResource.use(implicit session =>
            val test = as(id1) {
              session
                .prepare(sql"SELECT firstname FROM user WHERE id = $uuid".query(text))
                .use(_.unique(id2))
            }

            test.intercept[SkunkException]
          )
        )
      )
  }

The test outputs:

com.example.MinimalExampleSuite:
skunk.exception.SkunkException:
­ƒöÑ   main_http4s / Test / testOnly 1s
­ƒöÑ  Skunk encountered a problem related to use of unique
­ƒöÑ    at ...\com\example\MinimalExampleSuite.scala:87
­ƒöÑ
­ƒöÑ    Problem: Exactly one row was expected, but none were returned.
­ƒöÑ       Hint: You used unique. Did you mean to use option?
­ƒöÑ
­ƒöÑ  The statement under consideration was defined
­ƒöÑ    at ...\com\example\MinimalExampleSuite.scala:86
­ƒöÑ
­ƒöÑ    SELECT firstname FROM user WHERE id = $1
­ƒöÑ
­ƒöÑ  and the arguments were provided
­ƒöÑ    at ...\com\example\MinimalExampleSuite.scala:87
­ƒöÑ
­ƒöÑ    $1 uuid       c2d06800-a577-459d-baea-8cb8438c51a8
­ƒöÑ

skunk.exception.SkunkException: Exactly one row was expected, but none were returned.
        at skunk.exception.SkunkException$.fromQueryAndArguments(SkunkException.scala:145)
        at skunk.PreparedQuery$$anon$1.fail(PreparedQuery.scala:134)
        at skunk.PreparedQuery$$anon$1.unique$$anonfun$1(PreparedQuery.scala:113)
        at cats.effect.IOFiber.flatMapK(IOFiber.scala:1213)
        at cats.effect.IOFiber.succeeded(IOFiber.scala:1013)
        at cats.effect.IOFiber.uncancelableSuccessK(IOFiber.scala:1302)
        at cats.effect.IOFiber.succeeded(IOFiber.scala:1023)
        at cats.effect.IOFiber.mapK(IOFiber.scala:1205)
        at cats.effect.IOFiber.succeeded(IOFiber.scala:1012)
        at cats.effect.IOFiber.uncancelableSuccessK(IOFiber.scala:1302)
        at cats.effect.IOFiber.succeeded(IOFiber.scala:1023)
        at cats.effect.IOFiber.uncancelableSuccessK(IOFiber.scala:1302)
        at cats.effect.IOFiber.succeeded(IOFiber.scala:1023)
        at cats.effect.IOFiber.uncancelableSuccessK(IOFiber.scala:1302)
        at cats.effect.IOFiber.succeeded(IOFiber.scala:1023)
        at cats.effect.IOFiber.mapK(IOFiber.scala:1205)
        at cats.effect.IOFiber.succeeded(IOFiber.scala:1012)
        at cats.effect.IOFiber.uncancelableSuccessK(IOFiber.scala:1302)
        at cats.effect.IOFiber.succeeded(IOFiber.scala:1023)
        at cats.effect.IOFiber.runLoop(IOFiber.scala:259)
        at cats.effect.IOFiber.asyncContinueSuccessfulR(IOFiber.scala:1132)
        at cats.effect.IOFiber.run(IOFiber.scala:126)
        at cats.effect.unsafe.WorkerThread.run(WorkerThread.scala:306)
  + this works BUT message and stack trace is printed!  0.13s

This may seem like a small issue but it's SUPER annoying!