rachoon icon indicating copy to clipboard operation
rachoon copied to clipboard

ERROR: relation "templates" does not exist at character 15

Open sabbath88 opened this issue 1 month ago • 7 comments

I was playing with application trying to reproduce problem with PDF #45 Then preparing logs for submitting realized that my setup may be already bit messy and decided to make new one. Than I run into problems at very beginning while filling Company name at 1st possible step

Image

logs shows;

rachoon_postgres  | 2025-10-30 21:46:54.627 UTC [69] ERROR:  relation "templates" does not exist at character 15
rachoon_postgres  | 2025-10-30 21:46:54.627 UTC [69] STATEMENT:  select * from "templates" where "title" = $1 and "organization_id" is null and "templates"."deleted_at" is null limit $2
rachoon_postgres  | 2025-10-30 21:48:10.883 UTC [73] ERROR:  relation "organizations" does not exist at character 15
rachoon_postgres  | 2025-10-30 21:48:10.883 UTC [73] STATEMENT:  select * from "organizations" where "organizations"."deleted_at" is null order by "created_at" asc limit $1
rachoon           | {"level":50,"time":1761860890894,"pid":29,"hostname":"670454d6acf6","name":"backend","err":{"type":"DatabaseError","message":"select * from \"organizations\" where \"organizations\".\"deleted_at\" is null order by \"created_at\" asc limit $1 - relation \"organizations\" does not exist","stack":"error: select * from \"organizations\" where \"organizations\".\"deleted_at\" is null order by \"created_at\" asc limit $1 - relation \"organizations\" does not exist\n    at Parser.parseErrorMessage (/app/backend/node_modules/.pnpm/[email protected]/node_modules/pg-protocol/src/parser.ts:369:69)\n    at Parser.handlePacket (/app/backend/node_modules/.pnpm/[email protected]/node_modules/pg-protocol/src/parser.ts:187:21)\n    at Parser.parse (/app/backend/node_modules/.pnpm/[email protected]/node_modules/pg-protocol/src/parser.ts:102:30)\n    at Socket.<anonymous> (/app/backend/node_modules/.pnpm/[email protected]/node_modules/pg-protocol/src/index.ts:7:48)\n    at Socket.emit (node:events:507:28)\n    at addChunk (node:internal/streams/readable:559:12)\n    at readableAddChunkPushByteMode (node:internal/streams/readable:510:3)\n    at Socket.Readable.push (node:internal/streams/readable:390:5)\n    at TCP.onStreamRead (node:internal/stream_base_commons:189:23)","length":112,"name":"error","severity":"ERROR","code":"42P01","position":"15","file":"parse_relation.c","line":"1392","routine":"parserOpenTable","status":500},"msg":"select * from \"organizations\" where \"organizations\".\"deleted_at\" is null order by \"created_at\" asc limit $1 - relation \"organizations\" does not exist"}
rachoon_postgres  | 2025-10-30 21:48:10.897 UTC [73] ERROR:  relation "organizations" does not exist at character 15
rachoon_postgres  | 2025-10-30 21:48:10.897 UTC [73] STATEMENT:  select * from "organizations" where "organizations"."deleted_at" is null order by "created_at" asc limit $1
rachoon           | {"level":50,"time":1761860890898,"pid":29,"hostname":"670454d6acf6","name":"backend","err":{"type":"DatabaseError","message":"select * from \"organizations\" where \"organizations\".\"deleted_at\" is null order by \"created_at\" asc limit $1 - relation \"organizations\" does not exist","stack":"error: select * from \"organizations\" where \"organizations\".\"deleted_at\" is null order by \"created_at\" asc limit $1 - relation \"organizations\" does not exist\n    at Parser.parseErrorMessage (/app/backend/node_modules/.pnpm/[email protected]/node_modules/pg-protocol/src/parser.ts:369:69)\n    at Parser.handlePacket (/app/backend/node_modules/.pnpm/[email protected]/node_modules/pg-protocol/src/parser.ts:187:21)\n    at Parser.parse (/app/backend/node_modules/.pnpm/[email protected]/node_modules/pg-protocol/src/parser.ts:102:30)\n    at Socket.<anonymous> (/app/backend/node_modules/.pnpm/[email protected]/node_modules/pg-protocol/src/index.ts:7:48)\n    at Socket.emit (node:events:507:28)\n    at addChunk (node:internal/streams/readable:559:12)\n    at readableAddChunkPushByteMode (node:internal/streams/readable:510:3)\n    at Socket.Readable.push (node:internal/streams/readable:390:5)\n    at TCP.onStreamRead (node:internal/stream_base_commons:189:23)","length":112,"name":"error","severity":"ERROR","code":"42P01","position":"15","file":"parse_relation.c","line":"1392","routine":"parserOpenTable","status":500},"msg":"select * from \"organizations\" where \"organizations\".\"deleted_at\" is null order by \"created_at\" asc limit $1 - relation \"organizations\" does not exist"}

I am using ubuntu 24.04.3 LTS docker -v Docker version 28.5.1, build e180ab8

cat docker-compose.yml
services:
  rachoon:
    image: ghcr.io/ad-on-is/rachoon:latest
    container_name: rachoon
    depends_on:
      - postgres
      - gotenberg
    ports:
      - 8080:8080
    environment:
      - HOST=0.0.0.0
      - APP_KEY=myappkey=
      - DRIVE_DISK=local
      - DB_CONNECTION=pg
      - GOTENBERG_URL=http://gotenberg
      - PG_HOST=postgres
      - PG_PORT=5432
      - PG_USER=rachoon
      - PG_PASSWORD=mydbpass
      - PG_DB_NAME=rachoon
      - BASE_URL=http://localhost:8080

  postgres:
    image: postgres:15
    container_name: rachoon_postgres
    restart: always
    environment:
      - POSTGRES_USER=rachoon
      - POSTGRES_PASSWORD=mydbpass
      - POSTGRES_DB=rachoon
    volumes:
      - ./pgdata:/var/lib/postgresql/data

  gotenberg:
    image: gotenberg/gotenberg:8
    container_name: gotenberg
    restart: always

sabbath88 avatar Oct 30 '25 21:10 sabbath88

Hmmm... did the migration run on startup?

The only difference between your setup and mine, is, I'm using postgres16. Don't know if that's the issue, though.

Oohh... I just realized from your screenshot, I still have the production-domain hardcoded in the organization check 😅

ad-on-is avatar Oct 30 '25 22:10 ad-on-is

before running I ve made:

docker compose down -v docker system prune -a --volumes rm -rf pgdata

recreating once more time with postgres16

sabbath88 avatar Oct 30 '25 22:10 sabbath88

there seems to be problem in db during initial step;

docker compose logs gotenberg | gotenberg | _____ __ __
gotenberg | / / / /___ ___ / / ___ _______ _ gotenberg | / (_ / _ / / -) _ / _ / -) / _ '/ gotenberg | _/_/_/_////.__/_// _, / gotenberg | /__/ gotenberg | gotenberg | A containerized API for seamless PDF conversion. gotenberg | Version: 8.24.0 gotenberg | ------------------------------------------------------- gotenberg | [SYSTEM] modules: api chromium exiftool libreoffice libreoffice-api libreoffice-pdfengine logging pdfcpu pdfengines pdftk prometheus qpdf webhook gotenberg | [SYSTEM] chromium: Chromium ready to start gotenberg | [SYSTEM] libreoffice-api: LibreOffice ready to start gotenberg | [SYSTEM] api: server started on [::]:3000 gotenberg | [SYSTEM] prometheus: collecting metrics gotenberg | [SYSTEM] pdfengines: merge engines - qpdf pdfcpu pdftk gotenberg | [SYSTEM] pdfengines: split engines - pdfcpu qpdf pdftk gotenberg | [SYSTEM] pdfengines: flatten engines - qpdf gotenberg | [SYSTEM] pdfengines: convert engines - libreoffice-pdfengine gotenberg | [SYSTEM] pdfengines: read metadata engines - exiftool gotenberg | [SYSTEM] pdfengines: write metadata engines - exiftool gotenberg | [SYSTEM] pdfengines: encrypt engines - qpdf pdftk pdfcpu rachoon | Error: connect ECONNREFUSED 172.18.0.3:5432 rachoon | at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1636:16) rachoon | ❯ error database/seeders/Template rachoon | select * from "templates" where "title" = $1 and "organization_id" is null and "templates"."deleted_at" is null limit $2 - relation "templates" does not exist rachoon | {"level":"info","ts":1761862120.1642747,"msg":"maxprocs: Leaving GOMAXPROCS=16: CPU quota undefined"} rachoon | {"level":"info","ts":1761862120.1644962,"msg":"GOMEMLIMIT is updated","package":"github.com/KimMachineGun/automemlimit/memlimit","GOMEMLIMIT":60598473523,"previous":9223372036854775807} rachoon | {"level":"info","ts":1761862120.1645594,"msg":"using config from file","file":"/app/Caddyfile"} rachoon | {"level":"info","ts":1761862120.1654088,"msg":"adapted config to JSON","adapter":"caddyfile"} rachoon | {"level":"warn","ts":1761862120.1654153,"msg":"Caddyfile input is not formatted; run 'caddy fmt --overwrite' to fix inconsistencies","adapter":"caddyfile","file":"/app/Caddyfile","line":2} rachoon | {"level":"info","ts":1761862120.1660376,"logger":"admin","msg":"admin endpoint started","address":"localhost:2019","enforce_origin":false,"origins":["//localhost:2019","//[::1]:2019","//127.0.0.1:2019"]} rachoon_postgres | The files belonging to this database system will be owned by user "postgres". rachoon_postgres | This user must also own the server process. rachoon_postgres | rachoon_postgres | The database cluster will be initialized with locale "en_US.utf8". rachoon_postgres | The default database encoding has accordingly been set to "UTF8". rachoon_postgres | The default text search configuration will be set to "english". rachoon_postgres | rachoon_postgres | Data page checksums are disabled. rachoon_postgres | rachoon_postgres | fixing permissions on existing directory /var/lib/postgresql/data ... ok rachoon_postgres | creating subdirectories ... ok rachoon_postgres | selecting dynamic shared memory implementation ... posix rachoon_postgres | selecting default max_connections ... 100 rachoon_postgres | selecting default shared_buffers ... 128MB rachoon_postgres | selecting default time zone ... Etc/UTC rachoon_postgres | creating configuration files ... ok rachoon_postgres | running bootstrap script ... ok rachoon_postgres | performing post-bootstrap initialization ... ok rachoon_postgres | syncing data to disk ... ok rachoon_postgres | rachoon_postgres | rachoon_postgres | Success. You can now start the database server using: rachoon_postgres | rachoon_postgres | initdb: warning: enabling "trust" authentication for local connections rachoon_postgres | initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb. rachoon_postgres | pg_ctl -D /var/lib/postgresql/data -l logfile start rachoon_postgres | rachoon_postgres | waiting for server to start....2025-10-30 22:08:39.206 UTC [49] LOG: starting PostgreSQL 16.10 (Debian 16.10-1.pgdg13+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 14.2.0-19) 14.2.0, 64-bit rachoon_postgres | 2025-10-30 22:08:39.207 UTC [49] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432" rachoon_postgres | 2025-10-30 22:08:39.211 UTC [52] LOG: database system was shut down at 2025-10-30 22:08:39 UTC rachoon_postgres | 2025-10-30 22:08:39.215 UTC [49] LOG: database system is ready to accept connections rachoon_postgres | done rachoon_postgres | server started rachoon_postgres | CREATE DATABASE rachoon_postgres | rachoon_postgres | rachoon_postgres | /usr/local/bin/docker-entrypoint.sh: ignoring /docker-entrypoint-initdb.d/* rachoon_postgres | rachoon_postgres | 2025-10-30 22:08:39.388 UTC [49] LOG: received fast shutdown request rachoon_postgres | waiting for server to shut down....2025-10-30 22:08:39.390 UTC [49] LOG: aborting any active transactions rachoon_postgres | 2025-10-30 22:08:39.391 UTC [49] LOG: background worker "logical replication launcher" (PID 55) exited with exit code 1 rachoon_postgres | 2025-10-30 22:08:39.391 UTC [50] LOG: shutting down rachoon_postgres | 2025-10-30 22:08:39.392 UTC [50] LOG: checkpoint starting: shutdown immediate rachoon_postgres | 2025-10-30 22:08:39.446 UTC [50] LOG: checkpoint complete: wrote 926 buffers (5.7%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.015 s, sync=0.036 s, total=0.055 s; sync files=301, longest=0.002 s, average=0.001 s; distance=4273 kB, estimate=4273 kB; lsn=0/191F0D0, redo lsn=0/191F0D0 rachoon_postgres | 2025-10-30 22:08:39.452 UTC [49] LOG: database system is shut down rachoon_postgres | done rachoon_postgres | server stopped rachoon_postgres | rachoon_postgres | PostgreSQL init process complete; ready for start up. rachoon_postgres | rachoon_postgres | 2025-10-30 22:08:39.507 UTC [1] LOG: starting PostgreSQL 16.10 (Debian 16.10-1.pgdg13+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 14.2.0-19) 14.2.0, 64-bit rachoon_postgres | 2025-10-30 22:08:39.507 UTC [1] LOG: listening on IPv4 address "0.0.0.0", port 5432 rachoon_postgres | 2025-10-30 22:08:39.507 UTC [1] LOG: listening on IPv6 address "::", port 5432 rachoon | {"level":"info","ts":1761862120.166203,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0xc00015dc00"} rachoon | {"level":"warn","ts":1761862120.1664507,"logger":"http","msg":"HTTP/2 skipped because it requires TLS","network":"tcp","addr":":8080"} rachoon | {"level":"warn","ts":1761862120.1664555,"logger":"http","msg":"HTTP/3 skipped because it requires TLS","network":"tcp","addr":":8080"} rachoon | {"level":"info","ts":1761862120.1664574,"logger":"http.log","msg":"server running","name":"srv0","protocols":["h1","h2","h3"]} rachoon | {"level":"info","ts":1761862120.1685193,"msg":"autosaved config (load with --resume flag)","file":"/root/.config/caddy/autosave.json"} rachoon | {"level":"info","ts":1761862120.1685262,"msg":"serving initial configuration"} rachoon | {"level":"info","ts":1761862120.1713738,"logger":"tls","msg":"cleaning storage unit","storage":"FileStorage:/root/.local/share/caddy"} rachoon | {"level":"info","ts":1761862120.1722724,"logger":"tls","msg":"finished cleaning storage units"} rachoon | Listening on http://0.0.0.0:3000 rachoon | {"level":30,"time":1761862120593,"pid":29,"hostname":"1c21f09e67f8","name":"backend","msg":"started server on 0.0.0.0:3333"} rachoon_postgres | 2025-10-30 22:08:39.509 UTC [1] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432" rachoon_postgres | 2025-10-30 22:08:39.513 UTC [65] LOG: database system was shut down at 2025-10-30 22:08:39 UTC rachoon_postgres | 2025-10-30 22:08:39.518 UTC [1] LOG: database system is ready to accept connections rachoon_postgres | 2025-10-30 22:08:40.111 UTC [69] ERROR: relation "templates" does not exist at character 15 rachoon_postgres | 2025-10-30 22:08:40.111 UTC [69] STATEMENT: select * from "templates" where "title" = $1 and "organization_id" is null and "templates"."deleted_at" is null limit $2

sabbath88 avatar Oct 30 '25 22:10 sabbath88

rachoon | Error: connect ECONNREFUSED 172.18.0.3:5432

Looks like rachoon is starting to do it's thing before the DB is up and running.

What happens if you restart rachoon only, after everything is up and running?

ad-on-is avatar Oct 30 '25 22:10 ad-on-is

that might be right. after restarting just a rachoon its quite good; docker compose restart rachoon docker compose logs |less

rachoon_postgres  | 2025-10-30 22:08:39.452 UTC [49] LOG:  database system is shut down
rachoon_postgres  |  done
rachoon_postgres  | server stopped
rachoon_postgres  | 
rachoon_postgres  | PostgreSQL init process complete; ready for start up.
rachoon_postgres  | 
rachoon_postgres  | 2025-10-30 22:08:39.507 UTC [1] LOG:  starting PostgreSQL 16.10 (Debian 16.10-1.pgdg13+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 14.2.0-19) 14.2.0, 64-bit
rachoon_postgres  | 2025-10-30 22:08:39.507 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
rachoon_postgres  | 2025-10-30 22:08:39.507 UTC [1] LOG:  listening on IPv6 address "::", port 5432
rachoon_postgres  | 2025-10-30 22:08:39.509 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
rachoon_postgres  | 2025-10-30 22:08:39.513 UTC [65] LOG:  database system was shut down at 2025-10-30 22:08:39 UTC
rachoon_postgres  | 2025-10-30 22:08:39.518 UTC [1] LOG:  database system is ready to accept connections
rachoon_postgres  | 2025-10-30 22:08:40.111 UTC [69] ERROR:  relation "templates" does not exist at character 15
rachoon_postgres  | 2025-10-30 22:08:40.111 UTC [69] STATEMENT:  select * from "templates" where "title" = $1 and "organization_id" is null and "templates"."deleted_at" is null limit $2
rachoon_postgres  | 2025-10-30 22:13:39.553 UTC [63] LOG:  checkpoint starting: time
rachoon_postgres  | 2025-10-30 22:13:43.802 UTC [63] LOG:  checkpoint complete: wrote 45 buffers (0.3%); 0 WAL file(s) added, 0 removed, 0 recycled; write=4.221 s, sync=0.007 s, total=4.250 s; sync files=12, longest=0.004 s, average=0.001 s; distance=260 kB, estimate=260 kB; lsn=0/19604D0, redo lsn=0/1960498
rachoon_postgres  | 2025-10-30 22:38:40.069 UTC [63] LOG:  checkpoint starting: time

however templates still missing :)

sabbath88 avatar Oct 30 '25 22:10 sabbath88

Interesting. I cloned github repo, build app myself. No issues with database, also no problems with PDF preview and opening downloaded file.

cat docker-compose.yml 
services:
  rachoon:
    build:
      context: .
      dockerfile: Dockerfile
    container_name: rachoon
    ports:
      - 8080:8080
    environment:
      - HOST=0.0.0.0
      - APP_KEY=T4ldZDU74wy4e6-D_wHmFxu9tEOdiXb6
      - DRIVE_DISK=local
      - DB_CONNECTION=pg
      - GOTENBERG_URL=http://gotenberg:3000
      - PG_HOST=postgres
      - PG_PORT=5432
      - PG_USER=rachoon
      - PG_PASSWORD=mydbpass
      - PG_DB_NAME=rachoon
      - BASE_URL=http://localhost:8080
    depends_on:
      - postgres
      - gotenberg
  gotenberg:
    image: gotenberg/gotenberg:8
    container_name: rachoon_gotenberg
    ports:
      - 3000:3000
    restart: always
  postgres:
    image: postgres:15
    container_name: rachoon_postgres
    restart: always
    environment:
      - POSTGRES_USER=rachoon
      - POSTGRES_PASSWORD=mydbpass
      - POSTGRES_DB=rachoon
    volumes:
      - ./pgdata:/var/lib/postgresql/data

I can give some more details if needed for further debugging. one more concern. Does the APP_KEY need some specific format/lengh?

sabbath88 avatar Oct 31 '25 10:10 sabbath88