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

TransactionScope enlistment regression in 1.20.2 #331

Closed
KernelCrap opened this issue Oct 18, 2023 · 6 comments · Fixed by #332
Closed

TransactionScope enlistment regression in 1.20.2 #331

KernelCrap opened this issue Oct 18, 2023 · 6 comments · Fixed by #332

Comments

@KernelCrap
Copy link

Enqueuing a job inside a transaction scope no longer runs as expected after updating from 1.20.1 to 1.20.2.

It might be related to the following change:
Fixing Enqueued Job Trigger for Multiple Queues

Runnable example code:

using Hangfire;
using Hangfire.PostgreSql;

using Microsoft.EntityFrameworkCore;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Hosting;

using System.Transactions;

var host = new HostBuilder()
    .ConfigureServices((context, services) =>
    {
        const string ConnectionString = "Host=localhost;Port=5432;Database=test;Username=postgres";

        services.AddDbContext<TestContext>(optionsBuilder 
            => optionsBuilder.UseNpgsql(ConnectionString));

        var options = new PostgreSqlStorageOptions
        {
            EnableTransactionScopeEnlistment = true
        };

        services.AddHangfire((provider, config)
            => config.UsePostgreSqlStorage(ConnectionString, options));

        services.AddHangfireServer();
        services.AddTransient<ItemAddJob>();
    })
    .Build();

using (var scope = host.Services.CreateScope())
{
    var context = scope.ServiceProvider
        .GetRequiredService<TestContext>();

    await context.Database.EnsureDeletedAsync();
    await context.Database.EnsureCreatedAsync();
}

await host.StartAsync();

using (var scope = host.Services.CreateScope())
{
    var context = scope.ServiceProvider
        .GetRequiredService<TestContext>();

    var options = new TransactionOptions
    {
        IsolationLevel = IsolationLevel.Serializable
    };

    using (var ts = new TransactionScope(
        TransactionScopeOption.Required, options, TransactionScopeAsyncFlowOption.Enabled))
    {
        Console.WriteLine($"[{DateTime.UtcNow:O}]: TransactionScope: Started");

        context.Items.Add(new Item(1, "A"));

        await context.SaveChangesAsync();

        BackgroundJob.Enqueue<ItemAddJob>(e => e.Add(2, "B"));
        BackgroundJob.Enqueue<ItemAddJob>(e => e.Add(3, "B"));

        await context.SaveChangesAsync();

        ts.Complete();

        Console.WriteLine($"[{DateTime.UtcNow:O}]: TransactionScope: Completed");
    }

    Console.WriteLine($"[{DateTime.UtcNow:O}]: TransactionScope: Disposed. Waiting 5 seconds...");

    await Task.Delay(5000);

    var items = await context.Items.ToArrayAsync();

    Console.WriteLine($"[{DateTime.UtcNow:O}]: Items:");

    foreach (var item in items)
        Console.WriteLine($" - Item: {item.Id} - {item.Value}");

    await host.WaitForShutdownAsync();
}

public class ItemAddJob
{
    private readonly TestContext _context;

    public ItemAddJob(TestContext context)
    {
        _context = context;
    }

    public async Task Add(int id, string value)
    {
        Console.WriteLine($"[{DateTime.UtcNow:O}]: Hangfire task: Started #{id}");

        _context.Add(new Item(id, value));

        await _context.SaveChangesAsync();

        Console.WriteLine($"[{DateTime.UtcNow:O}]: Hangfire task: Completed #{id}");
    }
}

public class TestContext : DbContext
{
    public TestContext(DbContextOptions<TestContext> options) : base(options) { }
    public DbSet<Item> Items => Set<Item>();
}

public record Item(int Id, string Value);

Output with Hangfire.PostgreSql 1.20.2:

[2023-10-18T11:14:25.9833839Z]: TransactionScope: Started
[2023-10-18T11:14:26.6804603Z]: TransactionScope: Completed
[2023-10-18T11:14:26.6836808Z]: TransactionScope: Disposed. Waiting 5 seconds...
[2023-10-18T11:14:31.8639173Z]: Items:
 - Item: 1 - A
[2023-10-18T11:14:41.7238726Z]: Hangfire task: Started #3
[2023-10-18T11:14:41.7239170Z]: Hangfire task: Started #2
[2023-10-18T11:14:41.7723883Z]: Hangfire task: Completed #2
[2023-10-18T11:14:41.7754600Z]: Hangfire task: Completed #3

Output with Hangfire.PostgreSql 1.20.1 (runs as expected):

[2023-10-18T11:15:08.8346271Z]: TransactionScope: Started
[2023-10-18T11:15:09.4545437Z]: TransactionScope: Completed
[2023-10-18T11:15:09.4590676Z]: TransactionScope: Disposed. Waiting 5 seconds...
[2023-10-18T11:15:09.5326520Z]: Hangfire task: Started #3
[2023-10-18T11:15:09.5326558Z]: Hangfire task: Started #2
[2023-10-18T11:15:09.5794835Z]: Hangfire task: Completed #3
[2023-10-18T11:15:09.5794860Z]: Hangfire task: Completed #2
[2023-10-18T11:15:14.6145290Z]: Items:
 - Item: 1 - A
 - Item: 2 - B
 - Item: 3 - B
@Tinyakov
Copy link
Contributor

I didn't dig deep yet, but it appears that the issue is in version 1.20.2 and it's my fault.
There is no signal of new jobs after the transaction has been committed.

@Tinyakov
Copy link
Contributor

I've made draft PR #332

The example code runs as expected, jobs execute immediately.

[2023-10-18T12:42:06.9614230Z]: TransactionScope: Started
[2023-10-18T12:42:07.1539390Z]: TransactionScope: Completed
[2023-10-18T12:42:07.1576300Z]: TransactionScope: Disposed. Waiting 5 seconds...
[2023-10-18T12:42:07.2001600Z]: Hangfire task: Started #3
[2023-10-18T12:42:07.2001970Z]: Hangfire task: Started #2
[2023-10-18T12:42:07.2246870Z]: Hangfire task: Completed #3
[2023-10-18T12:42:07.2246890Z]: Hangfire task: Completed #2
[2023-10-18T12:42:12.2758860Z]: Items:
 - Item: 1 - A
 - Item: 3 - B
 - Item: 2 - B

I haven't checked it properly yet, unfortunately I don't have time right now. If someone could check, I would appreciate it.
Sorry for bug.

@azygis
Copy link
Collaborator

azygis commented Oct 18, 2023

I don't think there's anything else to check. Code looks fine, tests are green, your own test shows the expected behavior like it was before the issue started.

Unless you have some extra stuff planned for your draft, I'd say we merge it and publish.

@Tinyakov
Copy link
Contributor

I will check the case with several workers now, because of which I initially made the changes.

@Tinyakov
Copy link
Contributor

@azygis , quick tests in my multi-worker, multi-queue environment were successful as well: jobs executed immediately, and the count of fetching queries did not increase.

I've removed the Draft label.

azygis added a commit that referenced this issue Oct 18, 2023
Fix new jobs signalling in case of ambient transaction #331
@azygis
Copy link
Collaborator

azygis commented Oct 18, 2023

@Tinyakov thanks for super quick resolution!

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

Successfully merging a pull request may close this issue.

3 participants