Deploying to production (Angular, login hangs). #646 | Support

GregB created 4 years ago

ABP Framework version: v3.3.2
UI type: Angular
Tiered (MVC) or Identity Server Seperated (Angular): no
Exception message and stack trace: N/A
Steps to reproduce the issue:

I can't get login to work reliably after deploying to a server. It works sometimes, at a guess about 3% of the time, but I can't reproduce it reliably to get an accurate number. It only happens once deployed, but I've deployed to two separate environments, a VPS and Azure and ended up with the same situation. This suggests it's something I'm doing (or not doing) but the lack of deployment instructions makes it hard to know.

Here's what I'm doing:

I've got a pretty vanilla ABP Commercial 3.3.2 app. It's gota few entities and a few custom Angiular components. I haven't changed any configuration options (in ConfigureServices etc).
This all works fine locally.
I've added an environment.azure.ts file to the angular project like

import { Config } from '@abp/ng.core';

/* web URL */
const baseUrl = 'https://example.z33.web.core.windows.net';

export const environment = {
  production: true,
  application: {
    baseUrl,
    name: 'MyApp',
  },
  oAuthConfig: {
    issuer: 'https://example-api.azurewebsites.net',
    redirectUri: baseUrl,
    clientId: 'MyApp_App',
    responseType: 'code',
    scope: 'offline_access MyApp',
  },
  apis: {
    default: {
      url: 'https://example-api.azurewebsites.net',
      rootNamespace: 'MyApp',
    },
  },
} as Config.Environment;

I've added a corresponding configuration to the angular.json

"configurations": {
                        "production": {
                            ...
                        },
                        "azure": {
                            "fileReplacements": [
                                {
                                    "replace": "src/environments/environment.ts",
                                    "with": "src/environments/environment.azure.ts"
                                }
                            ],
                            "optimization": true,
                            ...
                        }
                }

I've build this with yarn build:azure and upload the output to Static Website in blob storage at https://example.z33.web.core.windows.net.
In the API project I've added an apsettings.Staging_2.json like so

{
  "App": {
    "SelfUrl": "https://example-api.azurewebsites.net",
    "ClientUrl": "https://example.z33.web.core.windows.net",
    "CorsOrigins": "https://example.z33.web.core.windows.net,http://example.z33.web.core.windows.net"
  },
  "ConnectionStrings": {
    "Default": "xxxx"
  },
  "AuthServer": {
    "Authority": "https://example-api.azurewebsites.net",
    "RequireHttpsMetadata": "true"
  },
 }

I've build and deployed this to an Azure AppService
Next I create a SQL Azure database and allow my client IP. Configure users and confirm I can connect via SSMS
I go to Example.DbMigrator\bin\Debug\netcoreapp3.1 and edit the appSettings.json and add in the connection string from step #7 above . I change the IdentityServer section to

      "ExcelErp_App": {
        "ClientId": "ExcelErp_App",
        "RootUrl": "https://example.z33.web.core.windows.net"
      },

(as per https://support.abp.io/QA/Questions/524/UNAUTHORIZEDCLIENT-after-deploying-to-test-server, no trailing slash) 9. I run the DbMigrator and confirm the tables have been created and the seed data added. The Admin user is there and if I check [IdentityServerClientRedirectUris] I can see a row for ClientId RedirectUri CDFEC9FC-51C9-A562-089C-39F953F0ECAB https://example.z33.web.core.windows.net

Now I visit https://example.z33.web.core.windows.net and get the login screeen fine.
If I visit https://example-api.azurewebsites.net/.well-known/openid-configuration I get what appears to be a valid configuration document wiht the correct URLs as per my config.
If I visit https://example.azurewebsites.net/swagger/index.html I get the swagger UI as expected.
Now, back in the Angular app at https://example.z33.web.core.windows.net, if I enter the default admin un/pw the form POSTs to /Account/Login, the broswer spins until it times out.
Now, here's the interesting bit, as mentioned at the top, some tiny percentage of the time, if you go back to the Angular UI and refresh, you are logged in, but that's probably <3% of the time. The other 97%+ you're just greeted with the Login screen again.

What's happening? What am I doing wrong?

10 Answer(s)

0

alper created 4 years ago
Support Team Director

I see that account/login returns An internal error occurred during your request!

so need to see the logs. can you provide us the logs?

this is most probably a configuration issue
0

GregB created 4 years ago

I've re-deployed the API and now get 200 OK on the login endpoint.

But he login UI still hangs nad eventually gives a 500 Request timed out.

My settings in dev vs on the server are :

In the database:

IdentityServerClientPostLogoutRedirectUris Dev: http://localhost:4200 Server: https://excelerpdevstorage2.z33.web.core.windows.net

IdentityServerClientRedirectUris Dev: http://localhost:4200 Server: https://excelerpdevstorage2.z33.web.core.windows.net

AppSettings.json app.SelfUrl Dev: https://localhost:44390 Server: https://excelerp-dev-appservice.azurewebsites.net

app.ClientUrl Dev: http://localhost:4200 Server: https://excelerpdevstorage2.z33.web.core.windows.net

app.CorsOrigins Dev: https://*.ExcelErp.com,http://localhost:4200,https://localhost:44307 Server: https://excelerpdevstorage2.z33.web.core.windows.net,https://excelerp-dev-appservice.azurewebsites.net

AuthServer.Authority Dev: https://localhost:44390 Server: https://excelerp-dev-appservice.azurewebsites.net

Angular environment.ts baseUrl Dev: http://localhost:4200 Server: https://excelerpdevstorage2.z33.web.core.windows.net

oAuthConfig.issuer Dev: https://localhost:44390 Server: https://excelerp-dev-appservice.azurewebsites.net

apis.default.url Dev: https://localhost:44390 Server: https://excelerp-dev-appservice.azurewebsites.net

Here's an exerpt from my log when I log in via the API

2020-12-24 10:38:32.039 +00:00 [Debug] (Volo.Abp.EntityFrameworkCore.AbpDbContext.) Added 0 entity changes to the current audit log 2020-12-24 10:46:20.396 +00:00 [Warning] (Volo.Abp.Account.Public.Web.Ldap.LdapExternalLoginProvider.) Ldap login feature is not enabled! 2020-12-24 10:46:20.452 +00:00 [Debug] (IdentityServer4.Hosting.IdentityServerAuthenticationService.) Augmenting SignInContext 2020-12-24 10:46:20.452 +00:00 [Debug] (IdentityServer4.Hosting.IdentityServerAuthenticationService.) Adding idp claim with value: "local" 2020-12-24 10:46:20.452 +00:00 [Debug] (IdentityServer4.Hosting.IdentityServerAuthenticationService.) Adding auth_time claim with value: "1608806780" 2020-12-24 10:46:20.567 +00:00 [Debug] (Volo.Abp.EntityFrameworkCore.AbpDbContext.) Added 0 entity changes to the current audit log 2020-12-24 10:46:20.567 +00:00 [Debug] (Volo.Abp.EntityFrameworkCore.AbpDbContext.) Added 0 entity changes to the current audit log 2020-12-24 10:46:20.568 +00:00 [Debug] (Volo.Abp.EntityFrameworkCore.AbpDbContext.) Added 0 entity changes to the current audit log 2020-12-24 10:46:20.593 +00:00 [Debug] (Volo.Abp.EntityFrameworkCore.AbpDbContext.) Added 0 entity changes to the current audit log 2020-12-24 10:46:20.593 +00:00 [Debug] (Volo.Abp.EntityFrameworkCore.AbpDbContext.) Added 0 entity changes to the current audit log

Here's an exerpt from the log when I try to log in via the UI

2020-12-24 11:11:09.199 +00:00 [Debug] (IdentityServer4.Hosting.EndpointRouter.) Request path "/connect/authorize" matched to endpoint type "Authorize" 2020-12-24 11:11:09.211 +00:00 [Debug] (IdentityServer4.Hosting.EndpointRouter.) Endpoint enabled: "Authorize", successfully created handler: "IdentityServer4.Endpoints.AuthorizeEndpoint" 2020-12-24 11:11:09.211 +00:00 [Information] (IdentityServer4.Hosting.IdentityServerMiddleware.) Invoking IdentityServer endpoint: "IdentityServer4.Endpoints.AuthorizeEndpoint" for "/connect/authorize" 2020-12-24 11:11:09.211 +00:00 [Debug] (IdentityServer4.Endpoints.AuthorizeEndpoint.) Start authorize request 2020-12-24 11:11:09.211 +00:00 [Debug] (IdentityServer4.Endpoints.AuthorizeEndpoint.) No user present in authorize request 2020-12-24 11:11:09.211 +00:00 [Debug] (IdentityServer4.Validation.AuthorizeRequestValidator.) Start authorize request protocol validation 2020-12-24 11:11:09.229 +00:00 [Debug] (IdentityServer4.Stores.ValidatingClientStore.) client configuration validation for client "ExcelErp_App" succeeded. 2020-12-24 11:11:09.229 +00:00 [Debug] (IdentityServer4.Validation.AuthorizeRequestValidator.) Checking for PKCE parameters 2020-12-24 11:11:09.249 +00:00 [Debug] (IdentityServer4.Validation.AuthorizeRequestValidator.) Calling into custom validator: "IdentityServer4.Validation.DefaultCustomAuthorizeRequestValidator" 2020-12-24 11:11:09.249 +00:00 [Debug] (IdentityServer4.Endpoints.AuthorizeEndpoint.) ValidatedAuthorizeRequest AuthorizeRequestValidationLog { ClientId: "ExcelErp_App", ClientName: "ExcelErp_App", RedirectUri: "https://excelerpdevstorage2.z33.web.core.windows.net", AllowedRedirectUris: ["https://excelerpdevstorage2.z33.web.core.windows.net"], SubjectId: "anonymous", ResponseType: "code", ResponseMode: "query", GrantType: "authorization_code", RequestedScopes: "openid offline_access ExcelErp", State: "OXh6RE9odlpBMDFDdTJ0SGp1d05sN2dXMFFjZ2xIS0F2RVhxMHpCVmktLnhE", UiLocales: null, Nonce: "OXh6RE9odlpBMDFDdTJ0SGp1d05sN2dXMFFjZ2xIS0F2RVhxMHpCVmktLnhE", AuthenticationContextReferenceClasses: null, DisplayMode: null, PromptMode: null, MaxAge: null, LoginHint: null, SessionId: "", Raw: [("response_type": "code"), ("client_id": "ExcelErp_App"), ("state": "OXh6RE9odlpBMDFDdTJ0SGp1d05sN2dXMFFjZ2xIS0F2RVhxMHpCVmktLnhE"), ("redirect_uri": "https://excelerpdevstorage2.z33.web.core.windows.net"), ("scope": "openid offline_access ExcelErp"), ("code_challenge": "D2uN7NXarCoUwRwmbw_mJFeHO4Kmtk2k6sksENztO7s"), ("code_challenge_method": "S256"), ("nonce": "OXh6RE9odlpBMDFDdTJ0SGp1d05sN2dXMFFjZ2xIS0F2RVhxMHpCVmktLnhE")] } 2020-12-24 11:11:09.250 +00:00 [Information] (IdentityServer4.ResponseHandling.AuthorizeInteractionResponseGenerator.) Showing login: User is not authenticated 2020-12-24 11:11:09.294 +00:00 [Information] (Volo.Abp.AspNetCore.Mvc.AntiForgery.AbpValidateAntiforgeryTokenAuthorizationFilter.) Skipping the execution of current filter as its not the most effective filter implementing the policy Microsoft.AspNetCore.Mvc.ViewFeatures.IAntiforgeryPolicy 2020-12-24 11:11:09.321 +00:00 [Debug] (IdentityServer4.Validation.AuthorizeRequestValidator.) Start authorize request protocol validation 2020-12-24 11:11:09.327 +00:00 [Debug] (IdentityServer4.Stores.ValidatingClientStore.) client configuration validation for client "ExcelErp_App" succeeded. 2020-12-24 11:11:09.327 +00:00 [Debug] (IdentityServer4.Validation.AuthorizeRequestValidator.) Checking for PKCE parameters 2020-12-24 11:11:09.342 +00:00 [Debug] (IdentityServer4.Validation.AuthorizeRequestValidator.) Calling into custom validator: "IdentityServer4.Validation.DefaultCustomAuthorizeRequestValidator" 2020-12-24 11:11:09.347 +00:00 [Debug] (IdentityServer4.Stores.ValidatingClientStore.) client configuration validation for client "ExcelErp_App" succeeded. 2020-12-24 11:11:09.352 +00:00 [Debug] (Volo.Abp.EntityFrameworkCore.AbpDbContext.) Added 0 entity changes to the current audit log 2020-12-24 11:11:09.466 +00:00 [Debug] (Volo.Abp.AspNetCore.Mvc.UI.Bundling.TagHelpers.AbpTagHelperResourceService.) Added bundle 'Lepton.Global' to the page in 1.51 ms. 2020-12-24 11:11:09.476 +00:00 [Debug] (Volo.Abp.AspNetCore.Mvc.UI.Bundling.TagHelpers.AbpTagHelperResourceService.) Added bundle 'Lepton.Global' to the page in 7.19 ms. 2020-12-24 11:11:09.727 +00:00 [Debug] (Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.AbpApplicationConfigurationAppService.) Executing AbpApplicationConfigurationAppService.GetAsync()... 2020-12-24 11:11:09.752 +00:00 [Debug] (Volo.Abp.AspNetCore.Mvc.ApplicationConfigurations.AbpApplicationConfigurationAppService.) Executed AbpApplicationConfigurationAppService.GetAsync(). 2020-12-24 11:15:06.274 +00:00 [Debug] (Volo.Abp.AspNetCore.Mvc.UI.Bundling.TagHelpers.AbpTagHelperResourceService.) Added bundle 'Lepton.Global' to the page in 1.01 ms. 2020-12-24 11:15:06.293 +00:00 [Debug] (Volo.Abp.AspNetCore.Mvc.UI.Bundling.TagHelpers.AbpTagHelperResourceService.) Added bundle 'Lepton.Global' to the page in 8.75 ms.

As you can see it hangs after the line at 11:11:09 Executed AbpApplicationConfigurationAppService.GetAsync(). before finally timing out at 11:15.

Why is it hanging? How can I get more information?
0

gterdem created 4 years ago
Senior .NET Developer

Hello,

Can it be related with your redis server? Can you check if redis is up and matches with your redis config?
0

GregB created 4 years ago

Hi @gterdem.

I don't have Redis. Locally or in the deployed environment.
0

alper created 4 years ago
Support Team Director

@gterdem he's project is not seperated IDS
0

gterdem created 4 years ago
Senior .NET Developer

AppConfig (39.4k) seems to be loaded in ~200 ms

Login request begins..

Timeout after 3.8 min..

Can you confirm that this problem only occurs on azure and not in local? Can you check azure web server logs if anything logged during this period?
0

GregB created 4 years ago

@gterdem I've tried deploying the app to Azure and a Windows VM with the same result.

Nothing else is logged in this time. The application is just hanging on that POST to /account/login .

The application runs fine locally.

I haven't changed any code related to CORS or IdentityServer configuration. Only the URLs stated above at deployment time.
0

GregB created 4 years ago

@gterdem @alper do you have any update on this? My project is blocked on this and if I can't resolve the issue soon I'm going to have to look at re-implementing the project without IDS and ABP.

Thanks, Greg
0

gterdem created 4 years ago
Senior .NET Developer

@GregB

It is not possible to re-produce nor diagnose without checking azure web-server logs to see what is happening during identityserver callback.

Can it be related with azure tiers?
0

alper created 4 years ago
Support Team Director

there's a 500 errror which means this request is handled and couldn't be executed nicely. there must be the log for it.

Have an answer to this question? Log in and write your answer.