search

dotnet-architecture / eShopOnContainers

Cross-platform .NET sample microservices and container based application that runs on Linux Windows and macOS. Powered by .NET 7, Docker Containers and Azure Kubernetes Services. Supports Visual Studio, VS for Mac and CLI based environments with Docker CLI, dotnet CLI, VS Code or any other code editor. Moved to https://github.com/dotnet/eShop.
https://dot.net/architecture
24.53k stars 10.35k forks source link

Getting db error login failed for user "sa" #1239

Closed babula38 closed 4 years ago

babula38 commented 4 years ago

Issue:- application are not connecting to DB Error:- Cannot open database "db name" requested by the login. The login failed. Login failed for user 'sa'.

Steps to reproduce:-

  1. Clone the dev branch to the local system.
  2. Follow the steps provided on https://github.com/dotnet-architecture/eShopOnContainers/wiki/Windows-setup.

Expected:- Application should show the home page without any issue.

nagiramadan commented 4 years ago

I have the same issue image

Mouzou commented 4 years ago

Same here Capture

Cannot open database "Microsoft.eShopOnContainers.Services.xxxxxxxDb" requested by the login. The login failed. Login failed for user 'sa'.

sriharshatechi commented 4 years ago

Same here image

loxx123 commented 4 years ago

run it from Visual Studio and errors don't show up, but you'll still have to contend with the log in errors. At least microservices will show working and healthy when running from VS2019.

mvelosop commented 4 years ago

Hi @babula38

Did you assign the 6 GB required by Docker, as per the setup page?

Could also check this line?:

https://github.com/dotnet-architecture/eShopOnContainers/blob/20238d536f9175ed3358ffbcf0b6d85a00e713e2/src/docker-compose.override.yml#L18

You could also check the container logs:

docker container logs src_sqldata_1

And, finally, you could also try connecting to directly to the SQL container from SQL Server Management Studio (SSMS) to database at localhost,5433

Hope this helps.

Roland1975 commented 4 years ago

I was running into the same issue. I must have messed things up somewhere. What I did:

Hope this helps.

R.

sriharshatechi commented 4 years ago

@Roland1975 I followed you steps . it worked, thank you. I think running as admin is the key. @babula38 you can close this bug.

d0pare commented 4 years ago

Hi,

I have similar issue, When I'm running docker-compose from Visual Studio services cannot authenticate with SQL but the password is correct because I can connect to SQL using SSMS. I don't have this issue when images are created from CLI. Another thing to mention is that even I do docker system prune -a building images from Visual Studio still uses docker cache.

d0pare commented 4 years ago

Seems like after several exception like these :

2020-02-26 14:37:07.28 Logon       Login failed for user 'sa'. Reason: Failed to open the explicitly specified database 'Microsoft.eShopOnContainers.Services.IdentityDb'. [CLIENT: 172.28.0.18]
2020-02-26 14:37:07.68 Logon       Error: 18456, Severity: 14, State: 38.

SQL server redoes databases

2020-02-26 14:37:08.67 spid51      Parallel redo is started for database 'Microsoft.eShopOnContainers.Service.IdentityDb' with worker pool size [1].
2020-02-26 14:37:08.71 spid51      Parallel redo is shutdown for database 'Microsoft.eShopOnContainers.Service.IdentityDb' with worker pool size [1].

which fixes the issue

babula38 commented 4 years ago

My system does not have sufficient RAM. May be that might be creating this issue. I will soon upgrade my system, if during that time i will face issue i will reopen this. but for now closing this.

baijdzm commented 4 years ago

Having the same issue. I did the following steps to resolve the issue.

  1. restart docker
  2. run docker-compose build in ADMIN. for my case, i ran PowerShell in Admin mode.
  3. run docker-compose up
  4. all db are created and issues resolved.
YuriyTigiev commented 4 years ago

I don't have a menu for RAM and CPU settings How can I reserve memory and cpu for docker?

image

image

sughosneo commented 4 years ago

Hi @YuriyTigiev, This is because WSL 2 backend. Please refer Memory And CPU Configuration

Thank you.

alikrc commented 3 years ago

i've started via visual studio, I had same error, after waiting 2-3 minutes and checking again problem solved. If it helps here are my sql server logs:


SQL Server 2019 will run as non-root by default.

This container is running as user root.

To learn more visit https://go.microsoft.com/fwlink/?linkid=2099216.

2021-01-29 03:06:22.41 Server Setup step is copying system data file 'C:\templatedata\master.mdf' to '/var/opt/mssql/data/master.mdf'.

2021-01-29 03:06:23.00 Server Did not find an existing master data file /var/opt/mssql/data/master.mdf, copying the missing default master and other system database files. If you have moved the database location, but not moved the database files, startup may fail. To repair: shutdown SQL Server, move the master database to configured location, and restart.

2021-01-29 03:06:23.06 Server Setup step is copying system data file 'C:\templatedata\mastlog.ldf' to '/var/opt/mssql/data/mastlog.ldf'.

2021-01-29 03:06:23.22 Server Setup step is copying system data file 'C:\templatedata\model.mdf' to '/var/opt/mssql/data/model.mdf'.

2021-01-29 03:06:23.44 Server Setup step is copying system data file 'C:\templatedata\modellog.ldf' to '/var/opt/mssql/data/modellog.ldf'.

2021-01-29 03:06:23.78 Server Setup step is copying system data file 'C:\templatedata\msdbdata.mdf' to '/var/opt/mssql/data/msdbdata.mdf'.

2021-01-29 03:06:24.16 Server Setup step is copying system data file 'C:\templatedata\msdblog.ldf' to '/var/opt/mssql/data/msdblog.ldf'.

2021-01-29 03:06:25.09 Server Microsoft SQL Server 2017 (RTM-CU22-GDR) (KB4583457) - 14.0.3370.1 (X64)

Nov 6 2020 18:19:52

Copyright (C) 2017 Microsoft Corporation

Developer Edition (64-bit) on Linux (Ubuntu 16.04.7 LTS)

2021-01-29 03:06:25.13 Server UTC adjustment: 0:00

2021-01-29 03:06:25.14 Server (c) Microsoft Corporation.

2021-01-29 03:06:25.15 Server All rights reserved.

2021-01-29 03:06:25.16 Server Server process ID is 40.

2021-01-29 03:06:25.18 Server Logging SQL Server messages in file '/var/opt/mssql/log/errorlog'.

2021-01-29 03:06:25.19 Server Registry startup parameters:

-d /var/opt/mssql/data/master.mdf

-l /var/opt/mssql/data/mastlog.ldf

-e /var/opt/mssql/log/errorlog

2021-01-29 03:06:25.43 Server SQL Server detected 1 sockets with 4 cores per socket and 8 logical processors per socket, 8 total logical processors; using 8 logical processors based on SQL Server licensing. This is an informational message; no user action is required.

2021-01-29 03:06:25.47 Server SQL Server is starting at normal priority base (=7). This is an informational message only. No user action is required.

2021-01-29 03:06:25.49 Server Detected 10160 MB of RAM. This is an informational message; no user action is required.

2021-01-29 03:06:25.51 Server Using conventional memory in the memory manager.

2021-01-29 03:06:25.57 Server Large Page Allocated: 32MB

2021-01-29 03:06:25.58 Server Page exclusion bitmap is enabled.

2021-01-29 03:06:26.26 Server Buffer pool extension is already disabled. No action is necessary.

2021-01-29 03:06:28.31 Server InitializeExternalUserGroupSid failed. Implied authentication will be disabled.

2021-01-29 03:06:28.33 Server Implied authentication manager initialization failed. Implied authentication will be disabled.

2021-01-29 03:06:28.36 Server Successfully initialized the TLS configuration. Allowed TLS protocol versions are ['1.0 1.1 1.2']. Allowed TLS ciphers are ['ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA:ECDHE-ECDSA-AES128-SHA:AES256-GCM-SHA384:AES128-GCM-SHA256:AES256-SHA256:AES128-SHA256:AES256-SHA:AES128-SHA:!DHE-RSA-AES256-GCM-SHA384:!DHE-RSA-AES128-GCM-SHA256:!DHE-RSA-AES256-SHA:!DHE-RSA-AES128-SHA'].

2021-01-29 03:06:28.54 Server Query Store settings initialized with enabled = 1,

2021-01-29 03:06:28.60 Server Node configuration: node 0: CPU mask: 0x00000000000000ff:0 Active CPU mask: 0x00000000000000ff:0. This message provides a description of the NUMA configuration for this computer. This is an informational message only. No user action is required.

2021-01-29 03:06:28.60 Server The maximum number of dedicated administrator connections for this instance is '1'

2021-01-29 03:06:28.66 Server Using dynamic lock allocation. Initial allocation of 2500 Lock blocks and 5000 Lock Owner blocks per node. This is an informational message only. No user action is required.

2021-01-29 03:06:28.71 Server In-Memory OLTP initialized on standard machine.

2021-01-29 03:06:28.84 Server Database Instant File Initialization: enabled. For security and performance considerations see the topic 'Database Instant File Initialization' in SQL Server Books Online. This is an informational message only. No user action is required.

ForceFlush is enabled for this instance.

2021-01-29 03:06:28.92 spid6s Starting up database 'master'.

2021-01-29 03:06:28.93 Server Software Usage Metrics is disabled.

ForceFlush feature is enabled for log durability.

2021-01-29 03:06:29.41 spid6s The tail of the log for database master is being rewritten to match the new sector size of 4096 bytes. 3072 bytes at offset 418816 in file /var/opt/mssql/data/mastlog.ldf will be written.

2021-01-29 03:06:30.22 spid6s Converting database 'master' from version 862 to the current version 869.

2021-01-29 03:06:30.24 spid6s Database 'master' running the upgrade step from version 862 to version 863.

2021-01-29 03:06:30.52 spid6s Database 'master' running the upgrade step from version 863 to version 864.

2021-01-29 03:06:31.23 spid6s Database 'master' running the upgrade step from version 864 to version 865.

2021-01-29 03:06:31.63 spid6s Database 'master' running the upgrade step from version 865 to version 866.

2021-01-29 03:06:31.95 spid6s Database 'master' running the upgrade step from version 866 to version 867.

2021-01-29 03:06:32.23 spid6s Database 'master' running the upgrade step from version 867 to version 868.

2021-01-29 03:06:32.65 spid6s Database 'master' running the upgrade step from version 868 to version 869.

2021-01-29 03:06:34.54 spid6s Resource governor reconfiguration succeeded.

2021-01-29 03:06:34.55 spid6s SQL Server Audit is starting the audits. This is an informational message. No user action is required.

2021-01-29 03:06:34.59 spid6s SQL Server Audit has started the audits. This is an informational message. No user action is required.

2021-01-29 03:06:35.17 spid6s SQL Trace ID 1 was started by login "sa".

2021-01-29 03:06:35.87 spid6s Server name is '07d98e2c07e3'. This is an informational message only. No user action is required.

2021-01-29 03:06:35.93 spid6s Starting up database 'msdb'.

2021-01-29 03:06:35.93 spid23s Always On: The availability replica manager is starting. This is an informational message only. No user action is required.

2021-01-29 03:06:35.97 spid7s Starting up database 'mssqlsystemresource'.

2021-01-29 03:06:35.99 spid23s Always On: The availability replica manager is waiting for the instance of SQL Server to allow client connections. This is an informational message only. No user action is required.

2021-01-29 03:06:36.03 spid7s The resource database build version is 14.00.3370. This is an informational message only. No user action is required.

2021-01-29 03:06:36.14 spid7s Starting up database 'model'.

2021-01-29 03:06:36.37 spid19s Password policy update was successful.

2021-01-29 03:06:36.38 spid6s The tail of the log for database msdb is being rewritten to match the new sector size of 4096 bytes. 512 bytes at offset 306688 in file /var/opt/mssql/data/MSDBLog.ldf will be written.

2021-01-29 03:06:36.80 spid7s The tail of the log for database model is being rewritten to match the new sector size of 4096 bytes. 2048 bytes at offset 75776 in file /var/opt/mssql/data/modellog.ldf will be written.

2021-01-29 03:06:37.28 spid6s Converting database 'msdb' from version 862 to the current version 869.

2021-01-29 03:06:37.30 spid6s Database 'msdb' running the upgrade step from version 862 to version 863.

2021-01-29 03:06:37.53 spid7s Converting database 'model' from version 862 to the current version 869.

2021-01-29 03:06:37.55 spid7s Database 'model' running the upgrade step from version 862 to version 863.

2021-01-29 03:06:38.24 spid19s A self-generated certificate was successfully loaded for encryption.

2021-01-29 03:06:38.27 spid19s Server is listening on [ 'any' <ipv6> 1433].

2021-01-29 03:06:38.32 spid19s Server is listening on [ 'any' <ipv4> 1433].

2021-01-29 03:06:38.35 Server Server is listening on [ ::1 <ipv6> 1434].

2021-01-29 03:06:38.36 Server Server is listening on [ 127.0.0.1 <ipv4> 1434].

2021-01-29 03:06:38.37 Server Dedicated admin connection support was established for listening locally on port 1434.

2021-01-29 03:06:38.40 spid19s SQL Server is now ready for client connections. This is an informational message; no user action is required.

2021-01-29 03:06:38.69 spid7s Database 'model' running the upgrade step from version 863 to version 864.

2021-01-29 03:06:38.69 spid6s Database 'msdb' running the upgrade step from version 863 to version 864.

2021-01-29 03:06:39.17 Logon Error: 18456, Severity: 14, State: 38.

2021-01-29 03:06:39.17 Logon Login failed for user 'sa'. Reason: Failed to open the explicitly specified database 'Microsoft.eShopOnContainers.Service.IdentityDb'. [CLIENT: 172.18.0.9]

2021-01-29 03:06:39.20 Logon Error: 18456, Severity: 14, State: 38.

2021-01-29 03:06:39.20 Logon Login failed for user 'sa'. Reason: Failed to open the explicitly specified database 'Microsoft.eShopOnContainers.Services.OrderingDb'. [CLIENT: 172.18.0.12]

2021-01-29 03:06:39.91 spid7s Database 'model' running the upgrade step from version 864 to version 865.

2021-01-29 03:06:40.18 spid6s Database 'msdb' running the upgrade step from version 864 to version 865.

2021-01-29 03:06:40.92 spid7s Database 'model' running the upgrade step from version 865 to version 866.

2021-01-29 03:06:41.04 spid6s Database 'msdb' running the upgrade step from version 865 to version 866.

2021-01-29 03:06:41.34 Logon Error: 18456, Severity: 14, State: 38.

2021-01-29 03:06:41.34 Logon Login failed for user 'sa'. Reason: Failed to open the explicitly specified database 'Microsoft.eShopOnContainers.Services.CatalogDb'. [CLIENT: 172.18.0.11]

2021-01-29 03:06:41.34 spid7s Database 'model' running the upgrade step from version 866 to version 867.

2021-01-29 03:06:41.44 spid6s Database 'msdb' running the upgrade step from version 866 to version 867.

2021-01-29 03:06:41.82 spid7s Database 'model' running the upgrade step from version 867 to version 868.

2021-01-29 03:06:41.82 spid6s Database 'msdb' running the upgrade step from version 867 to version 868.

2021-01-29 03:06:42.61 Logon Error: 18456, Severity: 14, State: 38.

2021-01-29 03:06:42.61 Logon Login failed for user 'sa'. Reason: Failed to open the explicitly specified database 'Microsoft.eShopOnContainers.Services.CatalogDb'. [CLIENT: 172.18.0.11]

2021-01-29 03:06:42.66 spid6s Database 'msdb' running the upgrade step from version 868 to version 869.

2021-01-29 03:06:42.91 spid7s Database 'model' running the upgrade step from version 868 to version 869.

2021-01-29 03:06:43.98 spid7s Polybase feature disabled.

2021-01-29 03:06:43.99 spid7s Clearing tempdb database.

2021-01-29 03:06:46.70 spid7s Starting up database 'tempdb'.

2021-01-29 03:06:47.61 spid7s The tempdb database has 1 data file(s).

2021-01-29 03:06:47.79 spid23s The Service Broker endpoint is in disabled or stopped state.

2021-01-29 03:06:47.81 spid23s The Database Mirroring endpoint is in disabled or stopped state.

2021-01-29 03:06:48.16 spid23s Service Broker manager has started.

2021-01-29 03:06:48.52 spid51 Starting up database 'Microsoft.eShopOnContainers.Services.OrderingDb'.

2021-01-29 03:06:48.91 spid51 Parallel redo is started for database 'Microsoft.eShopOnContainers.Services.OrderingDb' with worker pool size [4].

DBSTARTUP (msdb, 4): FileMgrPreRecoveryTime took 195 ms

DBSTARTUP (msdb, 4): PhysicalCompletionTime took 239 ms

DBSTARTUP (msdb, 4): RecoveryCompletionTime took 372 ms

DBSTARTUP (msdb, 4): UpgradeTime took 5917 ms

DBSTARTUP (msdb, 4): StartupInDatabaseTime took 11034 ms

DBSTARTUP (msdb, 4): RemapSysfiles1Time took 512 ms

2021-01-29 03:06:49.14 spid51 Parallel redo is shutdown for database 'Microsoft.eShopOnContainers.Services.OrderingDb' with worker pool size [4].

2021-01-29 03:06:50.45 spid52 Starting up database 'Microsoft.eShopOnContainers.Service.IdentityDb'.

2021-01-29 03:06:50.87 spid52 Parallel redo is started for database 'Microsoft.eShopOnContainers.Service.IdentityDb' with worker pool size [4].

2021-01-29 03:06:51.81 spid52 Parallel redo is shutdown for database 'Microsoft.eShopOnContainers.Service.IdentityDb' with worker pool size [4].

2021-01-29 03:06:52.99 Logon Error: 18456, Severity: 14, State: 38.

2021-01-29 03:06:52.99 Logon Login failed for user 'sa'. Reason: Failed to open the explicitly specified database 'Microsoft.eShopOnContainers.Services.CatalogDb'. [CLIENT: 172.18.0.11]

2021-01-29 03:06:53.30 spid51 Setting database option READ_COMMITTED_SNAPSHOT to ON for database 'Microsoft.eShopOnContainers.Services.OrderingDb'.

2021-01-29 03:06:54.79 spid6s Recovery is complete. This is an informational message only. No user action is required.

2021-01-29 03:06:54.91 spid52 Setting database option READ_COMMITTED_SNAPSHOT to ON for database 'Microsoft.eShopOnContainers.Service.IdentityDb'.

2021-01-29 03:06:55.02 spid16s The default language (LCID 0) has been set for engine and full-text services.

2021-01-29 03:06:57.13 spid51 Starting up database 'Microsoft.eShopOnContainers.Services.OrderingDb'.

2021-01-29 03:06:57.62 spid51 Parallel redo is started for database 'Microsoft.eShopOnContainers.Services.OrderingDb' with worker pool size [4].

2021-01-29 03:06:58.15 spid51 Parallel redo is shutdown for database 'Microsoft.eShopOnContainers.Services.OrderingDb' with worker pool size [4].

2021-01-29 03:06:59.27 spid52 Starting up database 'Microsoft.eShopOnContainers.Service.IdentityDb'.

2021-01-29 03:06:59.75 spid52 Parallel redo is started for database 'Microsoft.eShopOnContainers.Service.IdentityDb' with worker pool size [4].

2021-01-29 03:07:00.46 spid52 Parallel redo is shutdown for database 'Microsoft.eShopOnContainers.Service.IdentityDb' with worker pool size [4].

2021-01-29 03:07:02.37 Logon Error: 18456, Severity: 14, State: 38.

2021-01-29 03:07:02.37 Logon Login failed for user 'sa'. Reason: Failed to open the explicitly specified database 'Microsoft.eShopOnContainers.Services.CatalogDb'. [CLIENT: 172.18.0.11]

2021-01-29 03:07:19.38 Logon Error: 18456, Severity: 14, State: 38.

2021-01-29 03:07:19.38 Logon Login failed for user 'sa'. Reason: Failed to open the explicitly specified database 'Microsoft.eShopOnContainers.Services.CatalogDb'. [CLIENT: 172.18.0.11]

2021-01-29 03:07:53.23 Logon Error: 18456, Severity: 14, State: 38.

2021-01-29 03:07:53.23 Logon Login failed for user 'sa'. Reason: Failed to open the explicitly specified database 'Microsoft.eShopOnContainers.Services.CatalogDb'. [CLIENT: 172.18.0.11]

2021-01-29 03:08:57.18 Logon Error: 18456, Severity: 14, State: 38.

2021-01-29 03:08:57.18 Logon Login failed for user 'sa'. Reason: Failed to open the explicitly specified database 'Microsoft.eShopOnContainers.Services.CatalogDb'. [CLIENT: 172.18.0.11]

2021-01-29 03:10:06.67 Logon Error: 18456, Severity: 14, State: 38.

2021-01-29 03:10:06.67 Logon Login failed for user 'sa'. Reason: Failed to open the explicitly specified database 'Microsoft.eShopOnContainers.Services.CatalogDb'. [CLIENT: 172.18.0.11]

2021-01-29 03:10:16.77 Logon Error: 18456, Severity: 14, State: 38.

2021-01-29 03:10:16.77 Logon Login failed for user 'sa'. Reason: Failed to open the explicitly specified database 'Microsoft.eShopOnContainers.Services.CatalogDb'. [CLIENT: 172.18.0.11]

2021-01-29 03:10:18.91 spid55 Starting up database 'Microsoft.eShopOnContainers.Services.CatalogDb'.

2021-01-29 03:10:19.14 spid55 Parallel redo is started for database 'Microsoft.eShopOnContainers.Services.CatalogDb' with worker pool size [4].

2021-01-29 03:10:19.25 spid55 Parallel redo is shutdown for database 'Microsoft.eShopOnContainers.Services.CatalogDb' with worker pool size [4].

2021-01-29 03:10:20.57 spid55 Setting database option READ_COMMITTED_SNAPSHOT to ON for database 'Microsoft.eShopOnContainers.Services.CatalogDb'.

2021-01-29 03:10:23.21 spid55 Starting up database 'Microsoft.eShopOnContainers.Services.CatalogDb'.

2021-01-29 03:10:23.50 spid55 Parallel redo is started for database 'Microsoft.eShopOnContainers.Services.CatalogDb' with worker pool size [4].

2021-01-29 03:10:23.63 spid55 Parallel redo is shutdown for database 'Microsoft.eShopOnContainers.Services.CatalogDb' with worker pool size [4].
UvacaTechnologies commented 3 years ago

Checking the docker container logs helped me big time. I had a spelling error. 1 character missing on the database name in the scaffold command connection string.

Hamels commented 3 years ago

Hi @babula38

Did you assign the 6 GB required by Docker, as per the setup page?

Could also check this line?:

https://github.com/dotnet-architecture/eShopOnContainers/blob/20238d536f9175ed3358ffbcf0b6d85a00e713e2/src/docker-compose.override.yml#L18

You could also check the container logs:

docker container logs src_sqldata_1

And, finally, you could also try connecting to directly to the SQL container from SQL Server Management Studio (SSMS) to database at localhost,5433

Hope this helps.

Assigning 6GB helped for me. I read somehwere 4GB but 6GB works

bobowinca commented 1 year ago

I was running into the same issue. I must have messed things up somewhere. What I did:

  • Docker RAM: I have allocated 7GB
  • ensure any VPN is disabled (mine was on)
  • run the following: docker stop $(docker ps -a -q) #stop all
  • execute both scripts as admin: \eShopOnContainers-dev\deploy\windows\ (it was required in my case)
  • run again docker-compose build & docker-compose up
  • health-check: all is green

Hope this helps.

R.

For me it was the VPN. Disconnect it, and it worked perfectly. @Roland1975 Thanks a bunch!