We wanted to understand how audit logging is produced, so we decided to first override the AuditLogMiddleware from ABP and disable the write of the audit log info. If we then refresh the page and check auditlog we still see information being written to data base:
Could you let us know where and how these are logged to audit log? Or how they are bypassing the middleware? Can we disable audit logging for only API controllers? Do we need to override the Interceptor too?
Yes, not being able to reproduce this behavior, you could immediately conclude that you cannot do anything. However, you wrote the entire infrastructure and plumbing of the background component and related functionality, so we ask you to just please help us figuring out what is happening, why it is happening and how this hopefully can be addressed, as we are hard stuck.
In order to do our part, I will explain what we did and perhaps we can figure out together why this behavior is happening. Also, judging by the previous threads created on similar issues related to IsAbandoned being set without any logging output, it could perhaps be something nested very deep within ABP. Without any logging output from the underlying components it's incredibly hard to debug this. So here is what we did/tried (and yes perhaps we did it terribly wrong, but we are not ABP experts...yet):
Configure<AbpBackgroundJobOptions>(options =>
{
options.IsJobExecutionEnabled = false; // Let's assume the configuration returned false
options.AddJob<SendGridMailerJob>(); // This processes the emails needing to be send by SendGrid
options.AddJob<UpdateTrackServiceJob>(); // This processes 'Tracking' information that needs to be forwarded to an external API
});
Justification: We need the ability to completely disable background job processing. One major factor here is being able to process the jobs locally with debugging enabled in order to verify or troubleshoot in case we see anything going wrong on Production. The assumption is that at this moment "we/our code" is the only process that is working on the (pending) background jobs.
Behavior: Jobs are set to IsAbandoned = true no logging is produced, no exceptions are seemingly captured. Enabling output logging on our DbContext also shows no SQL responsible for performing the UPDATE, yet refreshing the table you can see that RetryCount = 1 and IsAbandoned = true.
Analysis: When an exception does occur, we can immediately see output logging, and the job is retried several tries before IsAbandoned = true is set. However on "these special occasions" it is set immediately after the first try. NextTryTime is not adjusted and the RetryCount is never increased afterwards.
Hypothesis: Are there other DbContext at play that are querying and writing to the **AbpBackgroundJobs** table? How can we verify this? What could we overwrite or configure to visualize this behavior with logging?
Conclusion: We are stumped, we cannot explain this behavior. Luckily the source code is on GitHub, so we figured it is time to start overriding some code or classes to see if we can learn anything about background behavior in ABP.
This is being called in PostConfigureServices in our own module, which we believe is loaded and processed last in the chain. We are highly skeptical about having this code here, but we also are unable to verify if ReplaceServices and/or ReplaceContext is enough.
context.Services.RemoveAll[IBackgroundWorker]();
context.Services.RemoveAll[IBackgroundJobWorker]();
context.Services.RemoveAll[IBackgroundJobManager]();
context.Services.RemoveAll[BackgroundJobWorker]();
context.Services.RemoveAll[BackgroundEmailSendingJob]();
context.Services.RemoveAll[NullBackgroundJobManager]();
context.Services.RemoveAll[DefaultBackgroundJobManager]();
Justification: We want to intercept all the calls being made so we can add logging output and observe behavior about background jobs being picked up. We also want to make sure that "our" worker is the only process actually processing background jobs (see next section).
Behavior: Jobs are still set to IsAbandoned = true and again no logging is produced when this occurs.
Conclusion: We need to implement our own BackgroundWorker and add more logging to understand what is happening.
We created our own AcmeBackgroundWorker class and copied the BackgroundJobWorker class line by line to ensure we are compliant and also because I am not going to pretend to understand every bit of code in there (we do, but that's not the point). We've extended the ExecuteAsync method and added verbose logging.
This is how the class is currently defined:
[Dependency(ReplaceServices = true)]
public sealed class AcmeBackgroundWorker : AsyncPeriodicBackgroundWorkerBase, IBackgroundJobWorker, IBackgroundWorker
{
// Implementation
}
// In the same 'PostConfigureServices' block as shown above at the end we then added
context.Services.AddTransient<IBackgroundWorker, AcmeBackgroundWorker>(); // Not sure if both is needed but we saw both in the ServiceCollection
context.Services.AddTransient<IBackgroundJobWorker, AcmeBackgroundWorker>(); // Not sure if both is needed but we saw both in the ServiceCollection
context.Services.AddTransient<IBackgroundJobManager, DefaultBackgroundJobManager>(); // This just queues the messages, so can be restored originally
Justification: We intially thought that the ReplaceServices would be enough to override everything, but since the jobs are still being processed by a ghost worker, we left it despite the fact we are already manually calling RemoveAll.
These are the parts were we added our own logging just to see what is happening, both when everything goes right, but especially when things go wrong (i.e. an Exception is thrown).
var pendingJobs = await _acmeService.GetPendingBackgroundJobsAsync();
// Let's output how many jobs are pending
Logger.LogInformation("[AcmeBackgroundWorker] Retrieved '{jobCount}' pending background job(s).", pendingJobs.Count);
if (pendingJobs.IsNullOrEmpty()) return;
// <snip>
// We will log which Job is being called to process the message
Logger.LogInformation("[AcmeBackgroundWorker] Executing {jobType}.ExecuteAsync()...", currentJob.JobName);
// <Execute the registered Job instance to process the job>
// We will indicate when all is successful and thus the job will be removed from the table
Logger.LogInformation("[AcmeBackgroundWorker] Deleting successfully executed '{jobType}' job.", currentJob.JobName);
// <snip>
// This is code where the Exceptions are 'caught' and IsAbandoned is set to 'true' by the Worker (2 occurences)
Logger.LogWarning("[AcmeBackgroundWorker] Setting IsAbandoned = true for '{jobType}'.", currentJob.JobName);
Justification: We used LogInformation as we want to be able to see these messages on Production, normally this would be regarded as debug output. We also added these specific statements, almost to the point of over completeness, because we really wanted to have this verbose output whenever a job is being processed.
Behavior: When it "works normally" and if an exception is thrown logging output is shown as expected. But when the ghost worker has done something no output is produced, breakpoints inside our worker are never hit, but the result is still that IsAbandoned = true is written to the DB. Meanwhile in the logs we can see the following:
2024-04-10 11:59:43.856 +02:00 [INF] [AcmeBackgroundWorker] Retrieved '0' pending background job(s).
2024-04-10 11:59:48.869 +02:00 [INF] [AcmeBackgroundWorker] Retrieved '0' pending background job(s).
According to our worker instance there were no pending jobs, even when we set the BackgroundJob to IsAbandoned = 0 using SQL directly. When doing a SELECT right after the UPDATE we can see that IsAbandoned is 0. No breakpoints are triggered, and doing a SELECT right after shows that IsAbandoned is set to 1. All the while the logs are only showing our own custom added logging output, ABP by itself produces zero logging when background job processing seemingly fails.
Conclusion: We are completely flabbergasted what is processing the AbpBackgroundJobs table, considering we believe that we eliminated "everything" from the pipeline?
We currently have 272 failed BackgroundJobs stored in the database. So we figured, why not execute a SQL script that will effectively reset all the jobs back to their initial state so they can be reprocessed by our worker.
The SQL we executed is as follows:
UPDATE [AbpBackgroundJobs]
SET LastTryTime = NULL, TryCount = 0, NextTryTime = GETDATE(), IsAbandoned = 0
272 row(s) affected
Then we wait and observe what the logfiles are telling us:
2024-04-10 13:25:08.255 +02:00 [INF] [AcmeBackgroundWorker] Retrieved '172' pending background job(s).
If we then look in the database we can see that exactly 100 BackgroundJob rows are IsAbandoned = true with RetryCount = 1 and these records thus never made it to our AcmeBackgroundWorker. So what has picked up this data? Why were they flagged as unprocesable?
We repeated this process several times and each time only a portion of background jobs is processed, the rest is abandoned. After about 4 retries the queue is now fully depleted and all messages are seemingly processed, resulting in an empty AbpBackgroundJobs table.
What else can we do? Override the store? Create our own tables and completely disable ABP Background Job feature? We also did a ReplaceContext for the BackgroundJob module, but still we cannot see any SQL output in the console that involves doing an UPDATE on that table. Perhaps because we set that up wrong and our understanding of ABP plumbing is too underdeveloped at this stage.
I sincerely hope you are able to share some thoughts and insights to provide a direction for the next steps we can do to try to figure this out. We are probably going to make a small management page to see the current abandoned jobs and add a feature to retry them, so we can at least process the 'deadletter' queue this way, but we are still completely puzzled what part of ABP is querying this table, despite us believing that only our worker should be handling this table.
Hi,
We have been integrating ABP Commercial Business into our new project and so far it has been a good experience. Getting our domain and entity models added, we initially opted for using Suite to generate the UI components, but considering and realizing the more unique requirements, eventually settled on adding them manually after studying the generated code.
We opted to move these requirements to their own module where appropriate, and together with two additional modules, Metronic 8 and Multilingual, we have been able to get the authentication and dashboard integration working fine with our data models. The pages are not crazy fast, but consistent, and the 'user experience' is fine considering the current stages of development. It took some getting used to, to figure out where everything should go, especially with the localization and modules, but we feel we are at a good state none the less.
However, we came to the point where we wanted to try and figure out the 'modal' experience, which is also part of the default generated website and the pages generated with Suite. We generated the CRUD experience for 1 particular model, studied the generated code, removed what we didn't need, and added what we did need (mostly Metronic styling). The auto-generated HTTP/API and proxy classes gave an additional hurdle to fully understand the minimal requirements to get it all working together, but we did and the result was good, visually.
We decided on a more traditional approach for the models, whereas the 'index' and 'list' pages are using Knockout JS, but we are using razor pages for loading the modal content. These modals have been using the generated suite ABP tag helpers where applicable and regular (Microsoft) tag-helpers to get the desired output. We do have some script bound to provide an auto-complete experience, but it is with the form rendering where we are experiencing the first serious slowdown.
Loading the 'Create' modal of the model, that is showing your typical "Name, Address" fields takes 3-4 seconds to load. We double checked the API call and verified that it completed in 60ms, so it's not the ABP backend causing a slow-down. Since it is a Create modal, there are no additional DB queries involved, in fact we removed everything that could potentially slow it down, returning an empty new FooViewModel() as the result, but still the dialog loaded extremely slow.
However, this did sped up the initial experience (not having to load all navigation properties, like list of companies, list of users) it did not speed up the modal loading part. We analyzed all we could think of, removing tag-helpers, removing the modal body, enabling trace logging, double-checking no EF queries are being fired. Perhaps slow scripts that could prevent the dialog from showing, but nothing explained the slow-down. We installed AppInsights, but no additional insights into what caused the slow-down. Logging output also revealed no additional information as there are simply 2-3 lines visible where it matches the route and then 3-4secs later an indication that the content is being shown.
We then started to time the entire call, which is divided as follows:
We checked with F12 in Chrome/Edge to verify that the website was waiting for the server to render the modal, we also verified this by calling just the 'create-modal' route, and that is taking almost 4 seconds to render. We then removed all form/tag helpers on the modal, and it renders in ~100ms. Then every single form field, using a tag-helper adds 200-400ms delay, and as mentioned earlier, the two dropdowns containing localized Enum values, take upwards to 500ms each.
Checking the Network tab in Chrome reveals the total load time of the modal itself:
We then added a Stopwatch on the Razor page to show the rendering times of each control:
We tried quite a lot of things to determine what could, or should not be part of the issue:
@Html.DisplayFor and @Html.Input, dialog takes 200ms
We've partially executed and considered the following alternative approaches:
I realize that one of your first automated replies would probably be: Can you get us an isolated MVP project to showcase the issue? Well sadly, I cannot, our project is currently the smallest application to reproduce the problem.
However, we are more than willing to:
Any help and direction at this point will be appreciated, as we simply cannot figure out why the tag-helpers and localization are causing a slowdown. Did we perhaps make a fatal configuration error with regards to modules and inheritance? Is there another option to enable diagnostic logging to figure out what the "server" is doing for ~4secs?
We've banged our heads against this wall for about a full sprint now (2 weeks) and have reached a point where we need a solution, either hopefully with the expert assistance of your team, or by reaching a different conclusion on how to proceed further.
Thank you very much for your time and effort reading this very lengthy question.
Hi,
In our application we have the following structure: Main Application -> Our Custom Module -> ABP Module(s). Inside this custom module, we want to be able to link our data with a User and/or Organisation. So through ABP Suite we have setup the needed navigation properties:
This took some effort, and if we didn't have the Commercial source package, I am not sure how to have accomplished this properly from inside a module, but that is besides the issue I am raising. Looking at the provided sample code generated within the AcmeDbContext class, we can see that [ReplaceDbContext(typeof(IIdentityProDbContext))] is used to replace that implementation with that of our own AcmeDbContext class.
Assuming this is how it is done, we did the same in our ModuleDbContext class and added the [ReplaceDbContext(typeof(IIdentityProDbContext))] attribute. We added the required DbSet properties and made sure that builder.ConfigureIdentityPro(); is called. We then added [ReplaceDbContext(typeof(IAcmeDbContext))] attribute to the main application AcmeDbContext so we can also expose our new entities there for later use (a call to builder.ConfigureAcme(); was also added as we replicated that setup).
We have a Company entity that we wish to connect to a User and Organization and using the Suite configuration above it generates the following class:
public partial class Company : FullAuditedEntity<Guid>, IMultiTenant
{
public Guid OrganizationId { get; set; } // OrganizationUnit is referenced here as expected
public Guid UserId { get; set; } // IdentityUser is referenced here as expected
public Guid? TenantId { get; set; }
/* Snip! */
}
Subsequently, the WithNavigationProperties class is generated as expected (putting it here for reference and completeness sake):
public class CompanyWithNavigationProperties
{
public Company Company { get; set; }
public OrganizationUnit OrganizationUnit { get; set; }
public IdentityUser IdentityUser { get; set; }
}
And the necessary methods within the EfCoreCompanyRepository class is also available:
protected virtual async Task<IQueryable<CompanyWithNavigationProperties>> GetQueryForNavigationPropertiesAsync()
{
return from company in (await GetDbSetAsync())
join organizationUnit in (await GetDbContextAsync()).OrganizationUnits
on company.OrganizationId equals organizationUnit.Id into organizationUnits
from organizationUnit in organizationUnits.DefaultIfEmpty()
join identityUser in (await GetDbContextAsync()).Users
on company.UserId equals identityUser.Id into users
from identityUser in users.DefaultIfEmpty()
select new CompanyWithNavigationProperties
{
Company = company,
OrganizationUnit = organizationUnit,
IdentityUser = identityUser
};
}
We build and start the application and navigate to the 'Companies' menu item; here we are treated with the following:
Value cannot be null. (Parameter 'inner') message inside the EF Core logAfter a slight refactoring of this particular method (as I wanted to get more familiar with the generated code and why it looked like that) it looks like the following:
protected virtual async Task<IQueryable<CompanyWithNavigationProperties>> GetQueryForNavigationPropertiesAsync()
{
// Retrieve the current DbContext once (does it make a difference?)
var dbContext = await GetDbContextAsync();
// Add explicit references to the DbSet properties so we can easily inspect them during Debug
var companies = dbContext.Companies; // This is (await GetDbSetAsync()) in generated code
var organizations = dbContext.OrganizationUnits; // This DbSet<T> is null!
var identityUsers = dbContext.Users; // This DbSet<T> is null!
return from company in companies
// The generated join is an 'Outer Join' even though our navigations are 'Required', but irrelevant to the issue
join organizationUnit in organizations
on company.OrganizationId equals organizationUnit.Id into organizationUnits
from organizationUnit in organizationUnits.DefaultIfEmpty()
// The generated join is an 'Outer Join' even though our navigations are 'Required', but irrelevant to the issue
join identityUser in identityUsers
on company.UserId equals identityUser.Id into users
from identityUser in users.DefaultIfEmpty()
select new CompanyWithNavigationProperties
{
Company = company,
OrganizationUnit = organizationUnit,
IdentityUser = identityUser
};
}
Now I could see that the DbSet properties that we took from the IIdentityProDbContext interface are seemingly not properly referring, or mapped to the table on this particular context, even though by my current, and still very much growing understanding of ABP, was configured correctly using [ReplaceDbContext(typeof(IIdentityProDbContext))]?
TL;DR, after using ReplaceDbContext the implemented DbSet properties are null inside a module that the main application is using.
What am I missing here? Why is Users and Organization null? Did I miss some key configuration part to make this work? Did I totally misunderstand the intention here? All the wiring of this logic is happening inside the Module and not the Application. We will make and use different pages and logic there that does not belong to this module. I have also checked the various sources of the Commercial modules, but it seems nothing is making a reference to either a User or Organization.
To summarize:
nullI would like to create a computed property for the purpose of using this in the navigation dropdown as the display property. I think this scenario could be pretty common, especially with the desire to often add the IdentityUser as a navigation property to one of your own entities. So for that purpose I wanted to add a "FullName" property to IdentityUserDto, instead of now only being able to choose between Name and Surname that is available on this type (other properties are of course available, but not relevant to the question).
Having already been successful in adding multiple 'regular' properties to the IdentityUser entity and the IdentityUserDto class, I am thus familiar with the various options, and also what is currently available as information from the documentation. However, how could we achieve this type of extension property? I am unable to figure out how to access the Dto instance itself when providing the configuration, so I am confused how I can create my property.
As a reference, this is how I would declare the property if the Dto class was my own:
public string FullName => string.Join(" ", string.Empty, Name, Surname).Trim();
or as a common variation using interpolation:
public string FullName => $"{Name} {Surname}).Trim();
What do I need to provide to the configuration parameter to achieve the equivalent result?
user.AddOrUpdateProperty<string>(UserConsts.FullName, options => options.DefaultValue = <What should I use here?>);
I also looked at the DefaultValueFactory but this Func does not provide access to the referencing type.
Note: If this is currently not possible through the regular extension methods, is there any alternative or other work-around to achieve something similar?
Thanks for your time and effort.
If you're creating a bug/problem report, please include followings:
'/libs/datatables.net-bs5/css/dataTables.bootstrap5.css' for the bundle 'Lepton.Global'!abp suite update --preview then proceed to start it using abp suite once the browser is opened error 500 is displayed and the exception listed above is visible in the console window that launched ABP Suite.I have also updated the npm module of datatables.net-bs5 globally, but I presume the application is expecting this lib to be available from a local perspective.
If there is a more suited place to report v5 specific issues that would be great as the current support forum is less than accomodation filtering out the v5 specific issues.
PS. If this is a known issue, I'd like to request a credit refund of our question limit, tyvm :)
Update: I was able to add the library to the presumable path it is looking for: %USERPROFILE%\.dotnet\tools\.store\volo.abp.suite\5.0.0-beta.3\volo.abp.suite\5.0.0-beta.3\tools\net6.0\any\wwwroot\libs\ and added the bs5 package there copied from the npm folder, but it now refers to another missing library: Could not find the bundle file '/libs/bootstrap/js/bootstrap.enable.tooltips.everywhere.js' for the bundle 'Lepton.Global'!
Update 2: I've add an empty file called bootstrap.enable.tooltips.everywhere.js in that folder and abp suite now at least launches, seemingly without any console errors. So we can continue our day, hope this information can contribute to locating the issue, or perhaps if I missed something when upgrading.
Thanks a lot for your time and efforts!