Hey folks, with latest Cerbos image I'm getting

SQL logic error: no such table: policy

, it should never happen when in-memory sqlite is used, right?

conf.yaml

storage:
  driver: "sqlite3"
  sqlite3:
    dsn: ":memory:"

I'm using testcontainers for some integration tests, here is log from container

2024-09-13 13:05:30 {"log.level":"error","@timestamp":"2024-09-13T11:05:30.045Z","log.logger":"cerbos","message":"Failed to add/update policies","protocol":"grpc","grpc.component":"server","grpc.service":"cerbos.svc.v1.CerbosAdminService","grpc.method":"AddOrUpdatePolicy","grpc.method_type":"unary","cerbos":{"call_id":"01J7NGYF3GNHQ5FYNVFRA6NY55"},"peer.address":"192.168.65.1:28747","peer.address":"192.168.65.1:28747","error":"failed to upsert cerbos.resource.RECORD.vdefault: failed to insert policy cerbos.resource.RECORD.vdefault: SQL logic error: no such table: policy (1)"}

from changelog did not see any conf breaking changes did I miss something?

Hi @Danylo Vivchar, I am not sure why the

policy

table doesn't exist, could you share the rest of the logs for the cerbos container?

@oguzhan sure

{"log.level":"warn","@timestamp":"2024-09-13T11:27:20.972Z","log.logger":"cerbos.otel","message":"Disabling OTLP traces because neither OTEL_EXPORTER_OTLP_ENDPOINT nor OTEL_EXPORTER_OTLP_TRACES_ENDPOINT is defined"}

{"log.level":"error","@timestamp":"2024-09-13T11:27:25.354Z","log.logger":"cerbos","message":"Failed to add/update policies","protocol":"grpc","grpc.component":"server","grpc.service":"cerbos.svc.v1.CerbosAdminService","grpc.method":"AddOrUpdatePolicy","grpc.method_type":"unary","cerbos":{"call_id":"01J7NJ6KK4YGMBHT8H2EKFE4Q6"},"peer.address":"192.168.65.1:23779","peer.address":"192.168.65.1:23779","error":"failed to upsert cerbos.resource.RECORD.vdefault: failed to insert policy cerbos.resource.RECORD.vdefault: SQL logic error: no such table: policy (1)"}

{"log.level":"error","@timestamp":"2024-09-13T11:27:25.354Z","log.logger":"cerbos.grpc","message":"Handled request","protocol":"grpc","grpc.component":"server","grpc.service":"cerbos.svc.v1.CerbosAdminService","grpc.method":"AddOrUpdatePolicy","grpc.method_type":"unary","cerbos":{"call_id":"01J7NJ6KK4YGMBHT8H2EKFE4Q6"},"peer.address":"192.168.65.1:23779","grpc.start_time":"2024-09-13T11:27:25Z","grpc.request.deadline":"2024-09-13T11:27:26Z","grpc.code":"Internal","grpc.error":"rpc error: code = Internal desc = Failed to add/update policies","grpc.time_ms":"69.775"}

{"log.level":"warn","@timestamp":"2024-09-13T11:27:25.354Z","log.logger":"cerbos.compiler","message":"Error while processing storage event","event":"ADD/UPDATE [789736770103430606]","error":"failed to find dependents: SQL logic error: no such table: policy_dependency (1)"}

{"log.level":"warn","@timestamp":"2024-09-13T11:27:25.354Z","log.logger":"cerbos.compiler","message":"Error while processing storage event","event":"ADD/UPDATE [14399243654329287359]","error":"failed to find dependents: SQL logic error: no such table: policy_dependency (1)"}

{"log.level":"warn","@timestamp":"2024-09-13T11:27:25.354Z","log.logger":"cerbos.compiler","message":"Error while processing storage event","event":"ADD/UPDATE [14091712466151272979]","error":"failed to find dependents: SQL logic error: no such table: policy_dependency (1)"}

Is there any line consisting of the

Initializing sqlite3 storage

message perhaps? In addition, next few lines after the message

Initializing sqlite3 storage

could be most useful.

no, these are all the logs from the Cerbos container

That's odd 🤔 Could you share the code snippet relevant to the creation of the test container?

sure, but it's scala code, suing java's testcontainer lib

trait CerbosContainer extends TestContainerForAll {
    this : Suite =>
    
    override val containerDef =
        DockerComposeContainer.Def(
            new File(resolvePathFromProjectRoot("cerbos-test/docker-compose.yml")),
            exposedServices = Seq(
                ExposedService("cerbos", 3593, Wait.forListeningPort())
            ),
            logConsumers = Seq(ServiceLogConsumer("cerbos", (t : OutputFrame) => println(s"cerboslog ${t.getUtf8String}")))
        )
}

Can't see something wrong. Though I wonder if using the

CerbosContainer

class (which we use for our sdk integration tests) from

cerbos/cerbos-sdk-java

would result in the same problem. (CerbosContainer, config used in our tests, creation of an object from CerbosContainer).

thanx, will try to check it later

I think some of the logs are not visible to due to log level being set to

warn

. As an alternative to doing the modifications I've suggested, you could also try to: 1. set the log level to something like

info

2. run the docker compose manually 3. use

cerbosctl put

(link) command to put required policies into store (ensure Admin API is enabled before this step) 4. execute the tests

here are more logs

2024-09-16 14:04:35 cerbos-1  | {"log.level":"info","@timestamp":"2024-09-16T12:04:35.866Z","log.logger":"cerbos.server","message":"maxprocs: Leaving GOMAXPROCS=8: CPU quota undefined"}
2024-09-16 14:04:35 cerbos-1  | {"log.level":"info","@timestamp":"2024-09-16T12:04:35.866Z","log.logger":"cerbos.server","message":"Loading configuration from /config/conf.yaml"}
2024-09-16 14:04:35 cerbos-1  | {"log.level":"warn","@timestamp":"2024-09-16T12:04:35.867Z","log.logger":"cerbos.otel","message":"Disabling OTLP traces because neither OTEL_EXPORTER_OTLP_ENDPOINT nor OTEL_EXPORTER_OTLP_TRACES_ENDPOINT is defined"}
2024-09-16 14:04:35 cerbos-1  | {"log.level":"info","@timestamp":"2024-09-16T12:04:35.867Z","log.logger":"cerbos.auditlog","message":"Initializing audit log","backend":"local","path":"/auditlogs"}
2024-09-16 14:04:35 cerbos-1  | {"log.level":"info","@timestamp":"2024-09-16T12:04:35.889Z","log.logger":"cerbos.sqlite3","message":"Initializing sqlite3 storage","DSN":":memory:"}
2024-09-16 14:04:35 cerbos-1  | {"log.level":"info","@timestamp":"2024-09-16T12:04:35.894Z","log.logger":"cerbos.telemetry","message":"Anonymous telemetry enabled. Disable via the config file or by setting the CERBOS_NO_TELEMETRY=1 environment variable"}
2024-09-16 14:04:35 cerbos-1  | {"log.level":"info","@timestamp":"2024-09-16T12:04:35.894Z","log.logger":"cerbos.grpc","message":"Starting admin service"}
2024-09-16 14:04:35 cerbos-1  | {"log.level":"info","@timestamp":"2024-09-16T12:04:35.894Z","log.logger":"cerbos.grpc","message":"Starting gRPC server at :3593"}
2024-09-16 14:04:35 cerbos-1  | {"log.level":"info","@timestamp":"2024-09-16T12:04:35.896Z","log.logger":"cerbos.http","message":"Starting HTTP server at :3592"}
2024-09-16 14:04:38 cerbos-1  | {"log.level":"info","@timestamp":"2024-09-16T12:04:38.141Z","log.logger":"cerbos.grpc","message":"Handled request","protocol":"grpc","grpc.component":"server","grpc.service":"cerbos.svc.v1.CerbosAdminService","grpc.method":"AddOrUpdatePolicy","grpc.method_type":"unary","cerbos":{"call_id":"01J7XBGX3X150FJ7QW6Y91SDPE"},"peer.address":"192.168.65.1:64239","grpc.start_time":"2024-09-16T12:04:38Z","grpc.request.deadline":"2024-09-16T12:04:39Z","grpc.time_ms":"0.011"}
2024-09-16 14:04:38 cerbos-1  | {"log.level":"info","@timestamp":"2024-09-16T12:04:38.141Z","log.logger":"cerbos.grpc","message":"Handled request","protocol":"grpc","grpc.component":"server","grpc.service":"cerbos.svc.v1.CerbosAdminService","grpc.method":"AddOrUpdatePolicy","grpc.method_type":"unary","cerbos":{"call_id":"01J7XBGX3XPK7Q6VGQMMDQBDC6"},"peer.address":"192.168.65.1:64239","grpc.start_time":"2024-09-16T12:04:38Z","grpc.request.deadline":"2024-09-16T12:04:39Z","grpc.time_ms":"0.011"}
2024-09-16 14:04:38 cerbos-1  | {"log.level":"info","@timestamp":"2024-09-16T12:04:38.209Z","log.logger":"cerbos.grpc","message":"Handled request","protocol":"grpc","grpc.component":"server","grpc.service":"cerbos.svc.v1.CerbosAdminService","grpc.method":"AddOrUpdatePolicy","grpc.method_type":"unary","cerbos":{"call_id":"01J7XBGX3X150FJ7QW6Y91SDPE"},"peer.address":"192.168.65.1:64239","grpc.start_time":"2024-09-16T12:04:38Z","grpc.request.deadline":"2024-09-16T12:04:39Z","grpc.code":"OK","grpc.time_ms":"68.639"}
2024-09-16 14:04:38 cerbos-1  | {"log.level":"error","@timestamp":"2024-09-16T12:04:38.210Z","log.logger":"cerbos","message":"Failed to add/update policies","protocol":"grpc","grpc.component":"server","grpc.service":"cerbos.svc.v1.CerbosAdminService","grpc.method":"AddOrUpdatePolicy","grpc.method_type":"unary","cerbos":{"call_id":"01J7XBGX3XPK7Q6VGQMMDQBDC6"},"peer.address":"192.168.65.1:64239","peer.address":"192.168.65.1:64239","error":"failed to upsert cerbos.resource.RECORD.vdefault: failed to insert policy cerbos.resource.RECORD.vdefault: SQL logic error: no such table: policy (1)"}
2024-09-16 14:04:38 cerbos-1  | {"log.level":"error","@timestamp":"2024-09-16T12:04:38.210Z","log.logger":"cerbos.grpc","message":"Handled request","protocol":"grpc","grpc.component":"server","grpc.service":"cerbos.svc.v1.CerbosAdminService","grpc.method":"AddOrUpdatePolicy","grpc.method_type":"unary","cerbos":{"call_id":"01J7XBGX3XPK7Q6VGQMMDQBDC6"},"peer.address":"192.168.65.1:64239","grpc.start_time":"2024-09-16T12:04:38Z","grpc.request.deadline":"2024-09-16T12:04:39Z","grpc.code":"Internal","grpc.error":"rpc error: code = Internal desc = Failed to add/update policies","grpc.time_ms":"69.166"}
2024-09-16 14:04:38 cerbos-1  | {"log.level":"info","@timestamp":"2024-09-16T12:04:38.395Z","log.logger":"cerbos.grpc","message":"Handled request","protocol":"grpc","grpc.component":"server","grpc.service":"cerbos.svc.v1.CerbosAdminService","grpc.method":"AddOrUpdatePolicy","grpc.method_type":"unary","cerbos":{"call_id":"01J7XBGXBVQ0KKP12B01V2JQ20"},"peer.address":"192.168.65.1:64239","grpc.start_time":"2024-09-16T12:04:38Z","grpc.request.deadline":"2024-09-16T12:04:39Z","grpc.time_ms":"0.006"}
2024-09-16 14:04:38 cerbos-1  | {"log.level":"info","@timestamp":"2024-09-16T12:04:38.395Z","log.logger":"cerbos.grpc","message":"Handled request","protocol":"grpc","grpc.component":"server","grpc.service":"cerbos.svc.v1.CerbosAdminService","grpc.method":"AddOrUpdatePolicy","grpc.method_type":"unary","cerbos":{"call_id":"01J7XBGXBTG7QRFX4XP3TBVBNR"},"peer.address":"192.168.65.1:64239","grpc.start_time":"2024-09-16T12:04:38Z","grpc.request.deadline":"2024-09-16T12:04:39Z","grpc.time_ms":"0.008"}
2024-09-16 14:04:38 cerbos-1  | {"log.level":"error","@timestamp":"2024-09-16T12:04:38.489Z","log.logger":"cerbos","message":"Failed to add/update policies","protocol":"grpc","grpc.component":"server","grpc.service":"cerbos.svc.v1.CerbosAdminService","grpc.method":"AddOrUpdatePolicy","grpc.method_type":"unary","cerbos":{"call_id":"01J7XBGXBTG7QRFX4XP3TBVBNR"},"peer.address":"192.168.65.1:64239","peer.address":"192.168.65.1:64239","error":"failed to upsert cerbos.resource.RECORD.vdefault: failed to insert policy cerbos.resource.RECORD.vdefault: SQL logic error: no such table: policy (1)"}
2024-09-16 14:04:38 cerbos-1  | {"log.level":"error","@timestamp":"2024-09-16T12:04:38.489Z","log.logger":"cerbos.grpc","message":"Handled request","protocol":"grpc","grpc.component":"server","grpc.service":"cerbos.svc.v1.CerbosAdminService","grpc.method":"AddOrUpdatePolicy","grpc.method_type":"unary","cerbos":{"call_id":"01J7XBGXBTG7QRFX4XP3TBVBNR"},"peer.address":"192.168.65.1:64239","grpc.start_time":"2024-09-16T12:04:38Z","grpc.request.deadline":"2024-09-16T12:04:39Z","grpc.code":"Internal","grpc.error":"rpc error: code = Internal desc = Failed to add/update policies","grpc.time_ms":"94.139"}
2024-09-16 14:04:38 cerbos-1  | {"log.level":"info","@timestamp":"2024-09-16T12:04:38.489Z","log.logger":"cerbos.grpc","message":"Handled request","protocol":"grpc","grpc.component":"server","grpc.service":"cerbos.svc.v1.CerbosAdminService","grpc.method":"AddOrUpdatePolicy","grpc.method_type":"unary","cerbos":{"call_id":"01J7XBGXBVQ0KKP12B01V2JQ20"},"peer.address":"192.168.65.1:64239","grpc.start_time":"2024-09-16T12:04:38Z","grpc.request.deadline":"2024-09-16T12:04:39Z","grpc.code":"OK","grpc.time_ms":"94.068"}
2024-09-16 14:04:38 cerbos-1  | {"log.level":"warn","@timestamp":"2024-09-16T12:04:38.489Z","log.logger":"cerbos.compiler","message":"Error while processing storage event","event":"ADD/UPDATE [789736770103430606]","error":"failed to find dependents: SQL logic error: no such table: policy_dependency (1)"}
2024-09-16 14:04:38 cerbos-1  | {"log.level":"warn","@timestamp":"2024-09-16T12:04:38.490Z","log.logger":"cerbos.compiler","message":"Error while processing storage event","event":"ADD/UPDATE [14399243654329287359]","error":"failed to find dependents: SQL logic error: no such table: policy_dependency (1)"}
2024-09-16 14:04:38 cerbos-1  | {"log.level":"warn","@timestamp":"2024-09-16T12:04:38.490Z","log.logger":"cerbos.compiler","message":"Error while processing storage event","event":"ADD/UPDATE [14091712466151272979]","error":"failed to find dependents: SQL logic error: no such table: policy_dependency (1)"}

Thanks for reporting, I will dig deeper