Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Random Fail Message on Microsoft.EntityFrameworkCore.Database.Connection[20004] #3402

Open
BenBurge opened this issue Dec 8, 2024 · 2 comments

Comments

@BenBurge
Copy link

BenBurge commented Dec 8, 2024

General Information

Dotnet Version: 9.0.0

NuGet Packages:
Microsoft.EntityFrameworkCore.Tools 9.0.0
Microsoft.EntityFrameworkCore.Design 9.0.0
Npgsql.EntityFrameworkCore.PostgreSQL 9.0.2

CLI Tools:
dotnet-ef 9.0.0

** PostgresDb **
PostgreSQL 17.2 (Debian 17.2-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit


Problem Details

Whenever I try to wipe out and restore my database for development purposes I get a random error

fail: Microsoft.EntityFrameworkCore.Database.Connection[20004]
An error occurred using the connection to database 'dev_database' on server 'tcp://localhost:5432'.

I run the following command to wipe out and restore my database.

dotnet ef database drop -f && dotnet ef database update

I get the error on the second command dotnet ef database update and not on the first command.

This happens whether I am running the database locally in Docker or if I run it on my development servers. The strange part is that even with the error my database gets created like it should. I've include a snippet of the before and after logs.

I have done the following to troubleshoot the message:

  1. Cleaned and Rebuilt Project
  2. Delete project and re-cloned
  3. Used different variations on the the connection string for SSL settings, port, and other options
"PostgresDb": "Host=localhost;Port=5432;Database=dev_database;Username=dummy;Password=dummy;"
  1. Used docker and development instances of PostgresDb
  2. Updated NuGet Packages, and tried different versions
  3. Changed logging levels for more detail and tried verbose on the ef-core cli commands

Detailed Logs

dbug: Microsoft.EntityFrameworkCore.Infrastructure[10403]
      Entity Framework Core 9.0.0 initialized 'ExampleDbContext' using provider 'Npgsql.EntityFrameworkCore.PostgreSQL:9.0.2+697dd7182173ff3450eddc63b44837fba76331df' with options: None
Finding design-time services referenced by assembly 'Example.WebClient'...
Finding design-time services referenced by assembly 'Example.WebClient'...
No referenced design-time services were found.
Finding design-time services for provider 'Npgsql.EntityFrameworkCore.PostgreSQL'...
Using design-time services from provider 'Npgsql.EntityFrameworkCore.PostgreSQL'.
Finding IDesignTimeServices implementations in assembly 'Example.WebClient'...
No design-time services were found.
dbug: Microsoft.EntityFrameworkCore.Database.Connection[20005]
      Creating DbConnection.
Creating DbConnection.
dbug: Microsoft.EntityFrameworkCore.Database.Connection[20006]
      Created DbConnection. (14ms).
Created DbConnection. (14ms).
dbug: Microsoft.EntityFrameworkCore.Database.Connection[20000]
      Opening connection to database 'dev_database' on server 'tcp://localhost:5432'.
Opening connection to database 'dev_database' on server 'tcp://localhost:5432'.
fail: Microsoft.EntityFrameworkCore.Database.Connection[20004]
      An error occurred using the connection to database 'dev_database' on server 'tcp://localhost:5432'.
An error occurred using the connection to database 'dev_database' on server 'tcp://localhost:5432'.
dbug: Microsoft.EntityFrameworkCore.Migrations[20400]
      Migrating using database 'dev_database' on server 'tcp://localhost:5432'.
Migrating using database 'dev_database' on server 'tcp://localhost:5432'.
dbug: Microsoft.EntityFrameworkCore.Database.Connection[20000]
      Opening connection to database 'dev_database' on server 'tcp://localhost:5432'.
Opening connection to database 'dev_database' on server 'tcp://localhost:5432'.
dbug: Microsoft.EntityFrameworkCore.Database.Connection[20000]
      Opening connection to database 'dev_database' on server 'tcp://localhost:5432'.
Opening connection to database 'dev_database' on server 'tcp://localhost:5432'.
dbug: Microsoft.EntityFrameworkCore.Database.Connection[20004]
      An error occurred using the connection to database 'dev_database' on server 'tcp://localhost:5432'.
An error occurred using the connection to database 'dev_database' on server 'tcp://localhost:5432'.
dbug: Microsoft.EntityFrameworkCore.Database.Connection[20005]
      Creating DbConnection.
Creating DbConnection.
dbug: Microsoft.EntityFrameworkCore.Database.Connection[20006]
      Created DbConnection. (0ms).
Created DbConnection. (0ms).
dbug: Microsoft.EntityFrameworkCore.Database.Connection[20000]
      Opening connection to database 'postgres' on server 'tcp://localhost:5432'.
Opening connection to database 'postgres' on server 'tcp://localhost:5432'.
dbug: Microsoft.EntityFrameworkCore.Database.Connection[20001]
      Opened connection to database 'postgres' on server 'tcp://localhost:5432'.
Opened connection to database 'postgres' on server 'tcp://localhost:5432'.
dbug: Microsoft.EntityFrameworkCore.Database.Command[20103]
      Creating DbCommand for 'ExecuteNonQuery'.
Creating DbCommand for 'ExecuteNonQuery'.
dbug: Microsoft.EntityFrameworkCore.Database.Command[20104]
      Created DbCommand for 'ExecuteNonQuery' (3ms).
Created DbCommand for 'ExecuteNonQuery' (3ms).
dbug: Microsoft.EntityFrameworkCore.Database.Command[20106]
      Initialized DbCommand for 'ExecuteNonQuery' (6ms).
Initialized DbCommand for 'ExecuteNonQuery' (6ms).
dbug: Microsoft.EntityFrameworkCore.Database.Command[20100]
      Executing DbCommand [Parameters=[], CommandType='Text', CommandTimeout='30']
      CREATE DATABASE dev_database;
Executing DbCommand [Parameters=[], CommandType='Text', CommandTimeout='30']
CREATE DATABASE dev_database;
@BenBurge
Copy link
Author

BenBurge commented Dec 8, 2024

I decided to look at my Postgres logs to see if anything appears as I run those commands. I see three fatal messages indicating the database doesn't exist.

Perhaps this message is the cause of the error on the Postgres EFCore side? If so, I don't know if this is desired behavior because on previous versions of Postgres EFCore this didn't cause any errors as far as I can remember currently.

2024-12-07 17:52:51 2024-12-08 00:52:51.854 UTC [27] LOG:  checkpoint starting: immediate force wait
2024-12-07 17:52:51 2024-12-08 00:52:51.862 UTC [27] LOG:  checkpoint complete: wrote 1 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.002 s, total=0.008 s; sync files=1, longest=0.002 s, average=0.002 s; distance=17 kB, estimate=4258 kB; lsn=0/5FF9ED0, redo lsn=0/5FF9E78
2024-12-07 17:52:55 2024-12-08 00:52:55.990 UTC [263] FATAL:  database "dev_database" does not exist
2024-12-07 17:53:11 2024-12-08 00:53:11.636 UTC [264] FATAL:  database "dev_database" does not exist
2024-12-07 17:53:11 2024-12-08 00:53:11.660 UTC [265] FATAL:  database "dev_database" does not exist

@BenBurge
Copy link
Author

BenBurge commented Dec 8, 2024

It also happens when I run dotnet ef migrations remove when no database exists in postgres. Which is unexpected because I believe migrations remove shouldn't attempt to change or update the database.

Update
After looking it up, it must reach out to check if the migration has been rolled back. So this may actually make sense why it's getting the error if the database doesn't exist. However I'm still not sure if the desired behavior for both of these is too show an error.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant