How to diagnose Error.WaitForScopedServiceIsCreatedTimeoutExpired?

[yallie]

Hello Maksim!

Is there a way to diagnose the WaitForScopedServiceIsCreatedTimeoutExpired error? I sometimes get an error message like this:

DryIoc.ContainerException: code: Error.WaitForScopedServiceIsCreatedTimeoutExpired;
message: DryIoc has waited for the creation of the scoped or singleton service by the "other party" for the  ticks without the completion. 
You may call `exception.TryGetDetails(container)` to get the details of the problematic service registration.
The error means that either the "other party" is the parallel thread which has started but is unable to finish the creation of the service in the provided amount of time. 
Or more likely the "other party"  is the same thread and there is an undetected recursive dependency or 
the scoped service creation is failed with the exception and the exception was catched but you are trying to resolve the failed service again. 
For all those reasons DryIoc has a timeout to prevent the infinite waiting. 
You may change the default timeout via `Scope.WaitForScopedServiceIsCreatedTimeoutTicks=NewNumberOfTicks`
   в DryIoc.ContainerException.WithDetails(Object details, Int32 error, Object arg0, Object arg1, Object arg2, Object arg3)
   в DryIoc.Scope.WaitForItemIsSet(ImMapEntry`1 itemRef)
   в DryIoc.Factory.GetExpressionOrDefault(Request request)
   в DryIoc.Container.DryIoc.IContainer.GetDecoratorExpressionOrDefault(Request request)
   в DryIoc.Factory.GetExpressionOrDefault(Request request)
   в DryIoc.ReflectionFactory.TryGetMemberAssignments(Boolean& failedToGet, Request request, IContainer container, Rules rules)
   в DryIoc.ReflectionFactory.CreateExpressionOrDefault(Request request)
   в DryIoc.Factory.GetExpressionOrDefault(Request request)
   в DryIoc.Container.ResolveAndCacheKeyed(Int32 serviceTypeHash, Type serviceType, Object serviceKey, IfUnresolved ifUnresolved, Object scopeName, Type requiredServiceType, Request preResolveParent, Object[] args)
   в DryIoc.Container.DryIoc.IResolver.Resolve(Type serviceType, Object serviceKey, IfUnresolved ifUnresolved, Type requiredServiceType, Request preResolveParent, Object[] args)
   в DryIoc.Interpreter.InterpretResolveMethod(IResolverContext resolver, IList`1 callArgs, Object paramExprs, Object paramValues, ParentLambdaArgs parentArgs, Boolean useFec, Object& result)
   в DryIoc.Interpreter.TryInterpretMethodCall(IResolverContext r, Expression expr, Object paramExprs, Object paramValues, ParentLambdaArgs parentArgs, Boolean useFec, Object& result)
   в DryIoc.Interpreter.TryInterpret(IResolverContext r, Expression expr, Object paramExprs, Object paramValues, ParentLambdaArgs parentArgs, Boolean useFec, Object& result)
   в DryIoc.Interpreter.TryInterpretNestedLambdaBodyAndUnwrapException(IResolverContext r, Expression bodyExpr, Object paramExprs, Object paramValues, ParentLambdaArgs parentArgs, Boolean useFec)
   в DryIoc.Interpreter.<>c__DisplayClass3_0.<TryInterpretNestedLambda>b__0()
   в DryIoc.Interpreter.<>c__DisplayClass5_0`1.<ConvertFunc>b__0()
   в System.Lazy`1.CreateValue()
   в System.Lazy`1.LazyInitValue()
   в Ultima.Server.Composition.ServerCallImport`1.<>c.<get_Value>b__7_0() в D:\ProjectsNext\UNEXT\Server\UltimaServerImplementation\Composition\ServerCallImport.cs:строка 48
   в System.Lazy`1.CreateValue()
   в System.Lazy`1.LazyInitValue()
...

It happens when the app starts up and tries to execute a few scheduled tasks at once. The first task succeeds, and other tasks fail. But the next time they run — everything works fine. The issue doesn't reproduce every time the app starts up. Also, the message doesn't have the number of ticks it waited: for the ticks.

Looks like the container reaches the timeout the first time it tries to resolve my services, but manages to create and cache a part of the dependency tree. And the second time, after a minute or so, everything works fine without any errors.

Calling exception.TryGetDetails(container) returns this:

Unable to get the service registration for the problematic FactoryID=20713656

Is there an easy way to dump everything we know about this FactoryID at this point?

Cheers!

PS. It's DryIoc version 4.8.7, I'm going to update to the latest version as soon as I fix this issue.

PPS. Oops, I should have used Discussions tab, not Issues. My fault!

[dadhi]

@yallie First, hi again.

Unable to get the service registration for the problematic FactoryID=20713656

Given the FactoryID is greater than 16 bit, it means that it is actually a decorator with upper 16 bits corresponding to the Decorated FactoryID. And it's need to be fixed to account for this situation.

You may try to use this code until it's fixed:

        public static string TryGetDetails(IContainer container, ContainerException ex)
        {
            var e = ex.Error;
            if (e == DryIoc.Error.WaitForScopedServiceIsCreatedTimeoutExpired)
            {
                var factoryId = (int)ex.Details;

                // check `Request.CombineDecoratorWithDecoratedFactoryID()` for why is this logic
                // var decoratorFactoryId = 0; // todo: @wip #598 add search for the `decoratorFactoryId`
                if (factoryId > ushort.MaxValue)
                {
                    // decoratorFactoryId = factoryId & ushort.MaxValue;
                    factoryId = factoryId >> 16;
                }

                foreach (var reg in container.GetServiceRegistrations()) 
                {
                    var f = reg.Factory;
                    if (f.FactoryID == factoryId)
                        return $"The service registration related to the problem is:{Environment.NewLine}{reg}";
                    var genFactories = f.GeneratedFactories;
                    if (genFactories != null)
                        foreach (var genEntry in f.GeneratedFactories.Enumerate()) 
                        {
                            var generatedFactory = genEntry.Value;
                            if (generatedFactory.FactoryID == factoryId)
                                return $"The service registration related to the problem is:{Environment.NewLine}{reg}{Environment.NewLine}Specifically, its closed-generic factory is:{Environment.NewLine}{generatedFactory}";
                        }
                }
                return "Unable to find the service registration for the problematic factory with FactoryID={factoryId}";
            }
            return string.Empty;
        }

Also, the message doesn't have the number of ticks it waited: for the ticks.

It was fixed in #475

[yallie]

Hi Maksim, thanks a lot for the explanation and the code sample! 🚀