vescon / MethodBoundaryAspect.Fody

A Fody weaver which allows to decorate methods and hook into method start, method end and method exceptions.
MIT License
251 stars 75 forks source link

Common Language Runtime detected an invalid program #66

Open minhhungit opened 5 years ago

minhhungit commented 5 years ago

Hi team, last week I have a bug on production site This is a case that caused bug (I call it as "FAKE" code - short code to reproduce):

[TimeTakenTrackLog]
public class Demo
{
    public static async Task DoNothing()
    {

    }

    public static async Task DemoBugAsync(int value)
    {
        if (value > 0)
        {
            await DoNothing();
        }
    }
}

// My page
[TimeTakenTrackLog] // applied on class
protected void Page_Load(object sender, EventArgs e)
{
    Demo.DemoBugAsync(5).GetAwaiter().GetResult();
}

// My aspect attribute
public class TimeTakenTrackLogAttribute : OnMethodBoundaryAspect
{
    public const string MessageQueueKey = "ImMethodTimeTakenMsgQueue";

    public override void OnEntry(MethodExecutionArgs args)
    {

    }

    public override void OnException(MethodExecutionArgs args)
    {

    }

    public override void OnExit(MethodExecutionArgs args)
    {
        if (args.ReturnValue is Task t)
        {
            t.ContinueWith(task => {
                BuildTimeTakenData(EventType.OnExitAsync, args);
                EnqueueTrackMessage();
        });
        }
        else
        {
            BuildTimeTakenData(EventType.OnExit, args);
            EnqueueTrackMessage();
        }         
    }  
}

=> It's just a piece of "real" code I applied to production last week (but it can cause error) => Fake code cause error on both DEBUG and RELEASE, local site & production site => "Real" code worked on Local (Debug mode)/TEST (Release mode) site BUT DID NOT work on Production site (RELEASE mode)


Here is a mini version of real code:

Caller:

WriteDbAccess.InitOrderRequestAndParseSubTrackData(new OrderRequestItem
{
    OrderId = trackRequestData.OrderId,
    SupplierId = supplierId,
    OrderStatus = OrderStatus.New
}, NewPORequest, response).GetAwaiter().GetResult();

=> And here is method InitOrderRequestAndParseSubTrackData in class WriteDbAccess: I used Dapper btw

public static async Task InitOrderRequestAndParseSubTrackData(OrderRequestItem dto, NewPORequest xmlRequest, NewPOResponse xmlResponse)
{
    using (var conn = new SqlConnection(Settings.ConnectionString))
    {
        conn.Open();

        var poIdNumber = xmlRequest?.PurchaseOrder?.purchaseOrderId;
        if (poIdNumber != null && poIdNumber > 0)
        {
            var exists = conn.ExecuteScalar<bool>("select top 1 1 from dbo.YOUR_TABLE where PurchaseOrderId = @poId", new { poId = poIdNumber.ToString() });

            if (!exists)
            {
                var parms = new DynamicParameters();

                parms.Add("@orderId", dto.OrderId);
                parms.Add("@supplierId", dto.SupplierId);
                parms.Add("@orderStatus", dto.OrderStatus);

                await conn.ExecuteAsync("InsertOrderRequest", parms,
                            commandType: CommandType.StoredProcedure, commandTimeout: Settings.ConnectionTimeout);

                await ParseOrderRequestSubTrackDataAsync(dto.OrderId, xmlRequest, xmlResponse);
            }
        }
    }
}

Remember that Real code work on local and test site, but it did not work on Production site :(

More images:

image

image

!!! FYI: My Aspect attribute work good, I have some web services and aspect worked for those services, only one of them did not work

This can be a bug of Fody , not MethodBoundaryAspect.Fody but I don't know So anyone can explain why please

minhhungit commented 5 years ago

I also created a simple project for testing here DemoBug.zip

Ralf1108 commented 5 years ago

Hi, thx for the bug report. The async support was implemented by @keith-anders so maybe he has time to check this out?

mantas-masidlauskas commented 5 years ago

Hi,

We used this library first time, and I got same CLR exception running existing tests.

Not getting exception with 2.0.111 version. Appeared only in 2.0.113 version.

ndrwrbgs commented 5 years ago

Seems like this is still present, the min-repro I could make was:

public class NoopAspect : OnMethodBoundaryAspect
{
    public override void OnException(MethodExecutionArgs arg)
    {
        base.OnException(arg);
    }
}
[NoopAspect]
internal class Program
{
    private static async Task Main(string[] args)
    {
        try
        {
            await new Program().DoNothing();
        }
        finally
        {
            Console.WriteLine("hi");
        }
    }

    private async Task DoNothing()
    {
    }
}
DamirAinullin commented 4 years ago

I also got such error. Can you fix it please?

ndrwrbgs commented 4 years ago

Could you provide a repro?

On Tue, May 19, 2020, 3:26 PM Damir Ainullin notifications@github.com wrote:

I also got such error. Can you fix it please?

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/vescon/MethodBoundaryAspect.Fody/issues/66#issuecomment-631116594, or unsubscribe https://github.com/notifications/unsubscribe-auth/ACSHCOQ6OSBX6TJDHD5666LRSMBSXANCNFSM4H6UN6MA .

DamirAinullin commented 4 years ago

@ndrwrbgs It is the same as previous ones. Async method with non-generic Task as return value.

Murphybro2 commented 3 years ago

I came across this too, but in a slightly different fashion, I'll post the code needed to reproduce below. Weirdly enough it only happens when both the async call AND the if statement are included. If I remove either of them, the other part will run will fine. So it looks to be a combination of the two in this case.

class Program
{
    [MethodBoundary]
    static async Task Main(string[] args)
    {
        bool uselessValue = true;
        if (uselessValue) // comment out the if statement and it will run fine
        {
            await Task.Delay(10); // OR comment out this and it will run fine
        }
        // but if both are in, it throws - "System.InvalidProgramException: 'Common Language Runtime detected an invalid program.'"
    }

    public class MethodBoundary : OnMethodBoundaryAspect
    {
        public override void OnException(MethodExecutionArgs args)
        {
        }
    }
}
kou-h commented 3 years ago

Hello, I have this problem. Is there any way to solve it.

class Program { [TraceLog] public async Task Invoke(HttpContext httpContext) {

}

public class TraceLogAttribute: OnMethodBoundaryAspect
{
    public override void OnException(MethodExecutionArgs args)
    {
    }
}

}

minhhungit commented 3 years ago

Hello, I have this problem. Is there any way to solve it.

I am sorry I know this advise is rude but I used Postsharp and it works fine This issue was created near 2 years but no solution also @keith-anders who wrote the code (as @Ralf1108 said) didn't have any response :(

I can not wait, you might not wait too LOL

kou-h commented 3 years ago

Hello, I have this problem. Is there any way to solve it.

I am sorry I know this advise is rude but I used Postsharp and it works fine This issue was created near 2 years but no solution also @keith-anders who wrote the code (as @Ralf1108 said) didn't have any response :(

I can not wait, you might not wait too LOL

thank you

psaxton commented 2 years ago

I've created a set of tests to reproduce this defect. It is important to note that the exception happens at runtime when the affected method is called: It is not caught using the "VerifyAssembly" directive (PEVerify). It does not throw when the assembly is first loaded.

Commit with the tests is here: https://github.com/vescon/MethodBoundaryAspect.Fody/commit/2517a551ac330687f2f8e2bc86b62916b1ec9c1d

Ralf1108 commented 2 years ago

@psaxton can you create a fork with your commit? Somehow GitHub tells me that about your commit: "This commit does not belong to any branch on this repository, and may belong to a fork outside of the repository." How did you do this?

psaxton commented 2 years ago

@Ralf1108 That commit is on my fork and is currently the head of this branch: https://github.com/psaxton/MethodBoundaryAspect.Fody/tree/issue66/invalid-program-exception -- I'm not certain why github shows it as a commit on the vescon repository. I referenced the commit hash because I will be changing this branch and the commit should be immutable. I've pushed a branch https://github.com/psaxton/MethodBoundaryAspect.Fody/tree/issue66/test-to-prove-defect which I'll leave pointed at this commit.

psaxton commented 2 years ago

I've been able to fix the InvalidProgramException in the case of a method ending with an if block. Changes can be found in my branch https://github.com/psaxton/MethodBoundaryAspect.Fody/tree/issue66/invalid-program-exception at commit ea7060e.

The problem caused by the try-catch block is not related. It seems to be that the outer try label is getting lost somewhere. I've stepped through the weaving process and the ExceptionHandlers seem to be defined correctly at the end of AsyncMethodWeaver.WeaveOnException: image but the completed assembly IL is missing the outer try block: image Outer try block should start at IL_0007 -- because it doesn't, the catches get nested inside-out: image

I'm really not sure where to go next. Ideas are welcome.

psaxton commented 2 years ago

@Ralf1108 I'm not certain if you've seen the updates to this issue, so I'll try @ing you.. A fork is available at my fork

psaxton commented 2 years ago

@Ralf1108 @ndrwrbgs I believe I have fully solved this issue in PR #100 if I could get some reviews and approval or criticism.

Ralf1108 commented 2 years ago

@psaxton Thank you very much for your contribution !

Ralf1108 commented 2 years ago

please checkout nuget packeage 2.0.147-pre if issues are solved

alewmt commented 2 years ago

It does not solve the bug for me method image cil image

Ralf1108 commented 2 years ago

@alewmt thx for the feedback @psaxton can you review this feedback?

psaxton commented 2 years ago

@alewmt @Ralf1108 I'm unable to repro this defect. If I can get a minimum reproducible code snippet I'll see what I can do.

image

I used the following code to attempt to repro. The IL looks correct and the method can be called and behaves as expected. Targets/AsyncEmptyMethodBoundaryAspectMethods.cs


        [EmptyMethodBoundaryAspect]
        public async Task<int> Handle(object command, CancellationToken cancellationToken)
        {
            int idOfANewPayment = -1;
            await TakesAClosure(command, id => idOfANewPayment = id);

            return idOfANewPayment;
        }

        private async Task TakesAClosure(object commands, Action<int> callbackWithANewPaymentId)
        {
            await Task.CompletedTask;
            callbackWithANewPaymentId(-99);
        }

AsyncMethodCausesInvalidProgramExceptonTests.cs:

        [Fact]
        public async Task AsyncHandleShouldNotThrow()
        {
            var target = new Targets.AsyncEmptyMethodBoundaryAspectMethods();

            Func<Task<int>> handleAction = () => target.Handle(new object(), CancellationToken.None);

            await handleAction.Should().NotThrowAsync();
        }
psaxton commented 2 years ago

Also, @alewmt code does not use any if, if-else or try blocks which seem to be the common thread in these issues.

alewmt commented 2 years ago

unfortunately I couldn't make a min repro. I can't understand why this bug occurs in some places and does not occur in other similar places.

psaxton commented 2 years ago

@alewmt It can be the most frustrating, I agree. I had one method where this issue appeared in "Release" configuration but not in "Debug" (I did try to repro in both configurations, btw). I don't think this issue of the br.s address seeming to overflow is related to this defect though. This issue was being caused when fixing up the leave instructions.

If you're able to find code that can be used to repro the br.s address, create an issue, tag me and I'll take a look at it if I get time.

Ralf1108 commented 2 years ago

Yes this could make a difference as the IL code is more optimized in Release than in Debug builds. I remember now that I had similar issues at the very beginning of the implementation of the MBA

psaxton commented 2 years ago

It's currently the head commit on my issue66 branch on my fork ( https://github.com/psaxton/MethodBoundaryAspect.Fody/tree/issue66/invalid-program-exception ). I posted the commit URL so that it would always show the changes I was referring to. ... I'm not sure why GitHub shows it this way, it was quite surprising to me too.

On Tue, Sep 20, 2022, 15:15 Ralf @.***> wrote:

@psaxton https://github.com/psaxton can you create a fork with your commit? Somehow GitHub tells me that about your commit: "This commit does not belong to any branch on this repository, and may belong to a fork outside of the repository." How did you do this?

— Reply to this email directly, view it on GitHub https://github.com/vescon/MethodBoundaryAspect.Fody/issues/66#issuecomment-1252921084, or unsubscribe https://github.com/notifications/unsubscribe-auth/ADXEKYTT5HHLYULPXCAKXOLV7ISPBANCNFSM4H6UN6MA . You are receiving this because you were mentioned.Message ID: @.***>

vmandic commented 2 years ago

Getting the issue still withv2.0.143-pre, aspect is:

public sealed class LogTimeAttribute : OnMethodBoundaryAspect
    {
        public override void OnEntry(MethodExecutionArgs args)
        {
            Console.WriteLine("Starting");
            var timer = new Stopwatch();
            timer.Restart();
            args.MethodExecutionTag = timer;

            Console.WriteLine(
                $"\n>> LOG MethodTimer: [{DateTime.Now:HH:mm:ss.fffff}]\n (START) {args.Method.GetMethodContextName()} {timer.Elapsed} ({timer.ElapsedMilliseconds}ms)");
        }

        public override void OnExit(MethodExecutionArgs args)
        {
            Console.WriteLine("Exiting");
            var timer = (Stopwatch)args.MethodExecutionTag;

            if (args.ReturnValue is Task t)
            {
                t.ContinueWith(_ =>
                {
                    Console.WriteLine(
                        $"\n>> LOG MethodTimer: [{DateTime.Now:HH:mm:ss.fffff}]\n (EXIT ASYNC) {args.Method.GetMethodContextName()} {timer.Elapsed} ({timer.ElapsedMilliseconds}ms)");
                });
            }
            else
            {
                Console.WriteLine(
                    $"\n>> LOG MethodTimer: [{DateTime.Now:HH:mm:ss.fffff}]\n (EXIT) {args.Method.GetMethodContextName()} {timer.Elapsed} ({timer.ElapsedMilliseconds}ms)");
            }
        }

        public override void OnException(MethodExecutionArgs args)
        {
            Console.WriteLine("Excp");
            var timer = (Stopwatch)args.MethodExecutionTag;
            Console.WriteLine(
                $"\n>> LOG MethodTimer: [{DateTime.Now:HH:mm:ss.fffff}]\n (EXCEPTION!!!) {args.Method.GetMethodContextName()} {timer.Elapsed} ({timer.ElapsedMilliseconds}ms)");
        }
    }

The target method returns a Task eg. [LogTime] private async Task ExecuteIteration(CancellationToken ct) { ... }

I get the (START) printed and then it fails:

>> LOG MethodTimer: [12:53:49.45213]
 (START) Redacted.ExecuteIteration 00:00:00.0080320 (8ms)

Unhandled exception. System.InvalidProgramException: Common Language Runtime detected an invalid program.
   at Redacted.ExecuteIteration(CancellationToken ct)
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
vmandic commented 2 years ago

Also, I noticed I do not need the OnException override so removing it resolves my issue.

psaxton commented 2 years ago

@Vedran can you please verify which version of MethodBoundaryAspect.Fody you're using which is producing this error with OnException?

On Thu, Oct 20, 2022, 06:29 Vedran Mandić @.***> wrote:

Also, I noticed I do not need the OnException override so removing it resolves my issue.

— Reply to this email directly, view it on GitHub https://github.com/vescon/MethodBoundaryAspect.Fody/issues/66#issuecomment-1285461052, or unsubscribe https://github.com/notifications/unsubscribe-auth/ADXEKYSE5P326THC24P2JQDWEE3KBANCNFSM4H6UN6MA . You are receiving this because you were mentioned.Message ID: @.***>

vmandic commented 2 years ago

@psaxton pardon, made a typo initially, latest:
<PackageReference Include="MethodBoundaryAspect.Fody" Version="2.0.147-pre" />

psaxton commented 2 years ago

@vmandic Thank you for following up. I suspected it was a typo, but it's always best to confirm. I'm unable to repro in netcoreapp3.1 or net6.0.

I don't have a GetMethodContextName() method like you had in your exception handler so I just made an extension method public static string GetMethodContextName(this MethodBase method) => method.Name;

You've already mentioned you're able to work around by just removing OnException, so I understand if you don't wish to chase this any further. In case you do if you can provide a minimal code repro with the OnMethodBoundaryAspect, the target class, and any needed external references (like GetMethodContextName) I'll be happy to continue looking into this.

vmandic commented 2 years ago

@psaxton unfortunately dropped that code already, but it was the OnException from above (that code should be used for a minimal repro). Thanks and good luck.

The method is a Reflection extension to dig out the method name:

#nullable enable

using System.Linq;
using System.Reflection;
using System.Runtime.CompilerServices;

public static class ReflectionExtensions
    {
        public static string GetMethodContextName(this MethodBase method)
        {
            if (method?.DeclaringType?.GetInterfaces().Any(i => i == typeof(IAsyncStateMachine)) != true)
            {
                return $"{method?.DeclaringType?.Name ?? "UnknownType"}.{method?.Name ?? "UnknownMethod"}";
            }

            var generatedType = method.DeclaringType;
            var originalType = generatedType.DeclaringType;

            var foundMethod = originalType?.GetMethods(
                    BindingFlags.Instance
                    | BindingFlags.Static
                    | BindingFlags.Public
                    | BindingFlags.NonPublic
                    | BindingFlags.DeclaredOnly)
                ?.SingleOrDefault(m =>
                    m.GetCustomAttribute<AsyncStateMachineAttribute>()?.StateMachineType == generatedType);

            return $"{foundMethod?.DeclaringType?.Name ?? "UnknownAsyncType"}.{foundMethod?.Name ?? "UnknownAsyncMethod"}";
        }
    }
psaxton commented 2 years ago

@vmandic I've tried every direction to repro this issue locally. If this is still a problem for you could you try ensuring your build environment has been cleaned and rebuilding (dotnet clean; dotnet build)? If it is then still a problem, could you provide the content of dotnet --info ?

antonre commented 11 months ago

Perhaps it will be useful to someone. I have encountered this error. Solution - check out other Fody extensions. In my case https://github.com/Fody/NullGuard referred to the Fody version 6.6.4 . This broke compatibility with 6.7.0