Prisma deploy error in production but no data in the log

[alan345]

Today we deployed in production and we get an error

Error: P3009
migrate found failed migrations in the target database, new migrations will not be applied. Read more about how to resolve migration issues in a production database: https://pris.ly/d/migrate-resolve
The `20220414162927_prisma_upgrade` migration started at 2022-04-16 16:28:01.302 UTC failed with the following logs:

When we checked the logs in _prisma_migrations, no issued was found and the migration was successfully applied.

It looks like the NPM warning triggered this wrong error message. (NPM 8.7.0 was released 2 days ago) https://www.npmjs.com/package/npm

Full Log:

Prisma schema loaded from prisma/schema.prisma
--
Datasource "db": MySQL database "na" at "db-prod-principal-database.us-west-2.rds.amazonaws.com:3306"
60 migrations found in prisma/migrations
Applying migration `20220414162927_prisma_upgrade`
Done in 72.52s.
Prisma schema loaded from prisma/schema.prisma
Datasource "db": MySQL database "na" at "db-prod-principal-database.us-west-2.rds.amazonaws.com:3306"
60 migrations found in prisma/migrations
Error: P3009
migrate found failed migrations in the target database, new migrations will not be applied. Read more about how to resolve migration issues in a production database: https://pris.ly/d/migrate-resolve
The `20220414162927_prisma_upgrade` migration started at 2022-04-16 16:28:01.302 UTC failed with the following logs:
npm notice
npm notice New minor version of npm available! 8.5.5 -> 8.7.0
npm notice Changelog: <https://github.com/npm/cli/releases/tag/v8.7.0>
npm notice Run `npm install -g npm@8.7.0` to update!
npm notice
Prisma schema loaded from prisma/schema.prisma
✔ Generated Prisma Client (3.12.0 \| library) to ./node_modules/@prisma/client in 3.13s
You can now start using Prisma Client in your code. Reference: https://pris.ly/d/client

import { PrismaClient } from '@prisma/client'
const prisma = new PrismaClient()

Type "Node" is missing a "__resolveType" resolver. Pass false into "resolverValidationOptions.requireResolversForResolveType" to disable this warning.
🚀 Server ready at http://localhost:4000/ - Env: production

[janpio]

What commands exactly are you running there? The output is a bit unexpected to us.

[tak1n]

Not sure if related, but we were also getting errors with this specific code for a failed migration:

2022-04-27T10:14:17.553Z prisma:migrateEngine:rpc SENDING RPC CALL {"id":2,"jsonrpc":"2.0","method":"applyMigrations","params":{"migrationsDirectoryPath":"/home/node/app/prisma/migrations"}}
2022-04-27T10:14:17.687Z prisma:migrateEngine:rpc {
jsonrpc: '2.0',
error: {
code: 4466,
message: 'An error happened. Check the data field for details.',
data: {
is_panic: false,
message: 'migrate found failed migrations in the target database, new migrations will not be applied. Read more about how to resolve migration issues in a production database: https://pris.ly/d/migrate-resolve\n' +
'The `20220426103019_extend_invite_model` migration started at 2022-04-27 10:14:02.792767 UTC failed with the following logs:\n' +
'\n',
meta: [Object],
error_code: 'P3009'
}
},
id: 2
}
Error: Error: P3009
migrate found failed migrations in the target database, new migrations will not be applied. Read more about how to resolve migration issues in a production database: https://pris.ly/d/migrate-resolve
The `20220426103019_extend_invite_model` migration started at 2022-04-27 10:14:02.792767 UTC failed with the following logs:
at Object.<anonymous> (/home/node/app/node_modules/prisma/build/index.js:110362:25)
at Object.handleResponse (/home/node/app/node_modules/prisma/build/index.js:110230:36)
at LineStream3.<anonymous> (/home/node/app/node_modules/prisma/build/index.js:110322:16)
at LineStream3.emit (node:events:526:28)
at addChunk (node:internal/streams/readable:315:12)
at readableAddChunk (node:internal/streams/readable:289:9)
at LineStream3.Readable.push (node:internal/streams/readable:228:10)
at LineStream3._pushBuffer (/home/node/app/node_modules/prisma/build/index.js:110109:17)
at LineStream3._transform (/home/node/app/node_modules/prisma/build/index.js:110103:8)
at LineStream3.Transform._write (node:internal/streams/transform:184:23)

Not sure if we did anything wrong here, but I would have assumed the logs should indicate what exactly failed 🤔
For us the issue was adding foreign key constraints to columns, the existing data referenced non existing foreign keys though which obviously lets it fail. We figured that out quite fast, but I could imagine for bigger schema migrations it could get tricky to even grasp what went wrong?

Is this the expected output for failed migrations, or did I miss something? We are using version 3.12.0. Could it be that I missed the initial try of applying the migrations which shows a more helpful error and the logs from above are just emitted when you "retry" to apply the schema migrations through npx prisma migrate deploy (we are using k8s in prod like envs - so it could be the k8s job which applies the migration has automatically been retried).

[janpio]

No, obviously a failing migration should output the actual failure message.

Do you still have the failing migration (SQL), and maybe the state of the tables (SQL) before that? It would be optimal for us if we can reproduce running the same migrate deploy that failed for you but did not output any information.

[tak1n]

No, obviously a failing migration should output the actual failure message.
Do you still have the failing migration (SQL), and maybe the state of the tables (SQL) before that? It would be optimal for us if we can reproduce running the same migrate deploy that failed for you but did not output any information.

Great to hear that my expectations aren't too off here. I will try to come up with a reproduction the next few days ✌️

[tak1n]

@janpio it seems to work like expected, I tried to setup a reproduction at https://github.com/Onlim/prisma-repro and it outputs a more useful error message the first time:

prisma-repro on  add-foreign-key-constraint [?] is 📦 v1.0.0 via ⬢ v16.14.2                                                                                                                  
➜ npx prisma migrate deploy                                                                                                                                                                   
Environment variables loaded from .env                                                                                                                                                        
Prisma schema loaded from prisma/schema.prisma                                                                                                                                                
Datasource "db": PostgreSQL database "prisma-repro", schema "public" at "localhost:5432"                                                                                                      
                                                                                                                                                                                              
2 migrations found in prisma/migrations                                                                                                                                                       
                                                                                                                                                                                              
Applying migration `20220430142956_add_foreign_key_constraint`                                                                                                                                
Error: P3018                                                                                                                                                                                  
                                                                                                                                                                                              
A migration failed to apply. New migrations cannot be applied before the error is recovered from. Read more about how to resolve migration issues in a production database: https://pris.ly/d/
migrate-resolve                                                                                                                                                                               
                                                                                                                                                                                              
Migration name: 20220430142956_add_foreign_key_constraint                                                                                                                                     
                                                                                                                                                                                              
Database error code: 23503                                                                                                                                                                    
                                                                                                                                                                                              
Database error:                                                                                                                                                                               
ERROR: insert or update on table "Post" violates foreign key constraint "Post_authorId_fkey"                                                                                                  
DETAIL: Key (authorId)=(99999) is not present in table "User".                                                                                                                                
                                                                                                                                                                                              
DbError { severity: "ERROR", parsed_severity: Some(Error), code: SqlState("23503"), message: "insert or update on table \"Post\" violates foreign key constraint \"Post_authorId_fkey\"", deta
il: Some("Key (authorId)=(99999) is not present in table \"User\"."), hint: None, position: None, where_: None, schema: Some("public"), table: Some("Post"), column: None, datatype: None, con
straint: Some("Post_authorId_fkey"), file: Some("ri_triggers.c"), line: Some(2465), routine: Some("ri_ReportViolation") }

When retrying npx prisma migrate deploy a second time it outputs what I've observed for our application above:

➜ npx prisma migrate deploy                                                   
Environment variables loaded from .env
Prisma schema loaded from prisma/schema.prisma
Datasource "db": PostgreSQL database "prisma-repro", schema "public" at "localhost:5432"

2 migrations found in prisma/migrations

Error: P3009

migrate found failed migrations in the target database, new migrations will not be applied. Read more about how to resolve migration issues in a production database: https://pris.ly/d/migrate-resolve
The `20220430142956_add_foreign_key_constraint` migration started at 2022-04-30 14:30:35.283825 UTC failed with the following logs:

So like I assumed I just missed the logs for the first run of npx prisma migrate deploy due to our kubernetes setup. Sorry for the noise 😄

[janpio]

Not noise at all, we need to fix this! You should never end up in a situation where the CLI tells you with the following logs: and then nothing follows, it's that easy. We'' have to check how deploy is supposed to work and know the previous log output, and what we can do to fix that. (Also it seems we might benefit from making it clearer that an old migrate run failed, not the current one - I did definitely not catch that when reading the output you posted before.)

[tak1n]

Also it seems we might benefit from making it clearer that an old migrate run failed, not the current one - I did definitely not catch that when reading the output you posted before

To be honest that's also something which surprised me. Coming from rails world when a migration fails it is not recorded in the migrations table and therefore you don't have to rollback a failed migration. By default, a migration either succeeded completely or not at all (as it is per default run in a transaction, you have to explicitly opt out of the "save" behavior). This is out of the scope of this issue though as I've read various other tickets which talk about this.