Production only problem with Policy Injection, please help

Topics: Policy Injection Application Block
Jun 2, 2008 at 7:20 PM
Hi,

Yesterday we installed a new version of our web site with several new features and infrastructure changes. The most important change in the infrastructure was separating some functionality to Policy Injection Handlers from EL as well as a few custom ones of our own. In the previous release of our web site we had only a couple of those: the Logging Handler and the Performance Counters Handler just to try them out.

Until yesterday all was working well. In QA and staging the new release was pretty happy but when we installed it in production we started getting intermittent problems - see below. Here is the environment: Intel Xeon processors, Windows Server 2003, Bus.Logic services target x86 (required by some 3rd party libs), implemented as a set of WCF services communicating with the Web app over named pipe and hosted in Windows Service. All is compiled with VS2008 (the prev version was compiled with VS2005), EL 3.1, NHibernate, SQL Server. To implement the PIAB+WCF combination we implemented the Policy Injection Behaviors per Hugh Angh and David San Filippo article almost 1:1.

Other than that the systems are running OK. The app generally works OK and these exceptions are intermittent. The only big difference between QA and Prod is the processor architecture (x86 vs x64) but this was never a problem so far.

Thank you!
Val Melamed

Here are some of the exceptions:

    • Time: 2008-06-02 10:24:13.953
    • Machine: SMF-ZOPA-WEB-02
    • Application: BLWebAppSvc.exe
    • Severity: Information
    • Fmt.Message: HandlingInstance ID: - 09dc3ce8-ed0e-411c-a5a6-b3a2590c20df
    • Message: System.NullReferenceException: Object reference not set to an instance of an object.
    • at Microsoft.Practices.EnterpriseLibrary.PolicyInjection.RemotingInterception.InterceptingRealProxy.Invoke(IMessage msg)
    • at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
    • at Zopa.BusinessLogic.ISocialNetwork.GetFeaturedLoans(String sessionToken, SocialProfileElementPresent present, Int32 pageNumber, Int32 pageSize, Int32& totalRecords)
    • at SyncInvokeGetFeaturedLoans(Object , Object[] , Object[] )
    • at System.ServiceModel.Dispatcher.SyncMethodInvoker.Invoke(Object instance, Object[] inputs, Object[]& outputs)
    • at System.ServiceModel.Dispatcher.DispatchOperationRuntime.InvokeBegin(MessageRpc& rpc)
    • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage5(MessageRpc& rpc)
    • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage4(MessageRpc& rpc)
    • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage3(MessageRpc& rpc)
    • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage2(MessageRpc& rpc)
    • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage1(MessageRpc& rpc)
    • at System.ServiceModel.Dispatcher.MessageRpc.Process(Boolean isOperationContextSet)
    • Time: 2008-06-02 10:19:53.640
    • Machine: SMF-ZOPA-WEB-02
    • Application: BLWebAppSvc.exe
    • Severity: Information
    • Fmt.Message: HandlingInstance ID: - 70d3af36-9d81-4ac1-8b58-93bba41ccba7
    • Message: System.NullReferenceException: Object reference not set to an instance of an object.
    • at Microsoft.Practices.EnterpriseLibrary.PolicyInjection.RemotingInterception.InterceptingRealProxy.Invoke(IMessage msg)
    • at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
    • at Zopa.BusinessLogic.IMemberProfile.GetProfile(String sessionToken)
    • at SyncInvokeGetProfile(Object , Object[] , Object[] )
    • at System.ServiceModel.Dispatcher.SyncMethodInvoker.Invoke(Object instance, Object[] inputs, Object[]& outputs)
    • at System.ServiceModel.Dispatcher.DispatchOperationRuntime.InvokeBegin(MessageRpc& rpc)
    • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage5(MessageRpc& rpc)
    • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage4(MessageRpc& rpc)
    • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage3(MessageRpc& rpc)
    • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage2(MessageRpc& rpc)
    • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage1(MessageRpc& rpc)
    • at System.ServiceModel.Dispatcher.MessageRpc.Process(Boolean isOperationContextSet)
      • Time: 2008-06-02 10:19:50.813
      • Machine: SMF-ZOPA-WEB-01
      • Application: BLWebAppSvc.exe
      • Severity: Information
      • Fmt.Message: HandlingInstance ID: - 458207c2-390b-4bd5-a508-d53414c70d77
      • Message: System.InvalidCastException: Return argument has an invalid type.
      • at System.Runtime.Remoting.Proxies.RealProxy.ValidateReturnArg(Object arg, Type paramType)
      • at System.Runtime.Remoting.Proxies.RealProxy.PropagateOutParameters(IMessage msg, Object[] outArgs, Object returnValue)
      • at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
      • at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
      • at Zopa.BusinessLogic.ISocialNetwork.GetStatistics(String sessionToken)
      • at SyncInvokeGetStatistics(Object , Object[] , Object[] )
      • at System.ServiceModel.Dispatcher.SyncMethodInvoker.Invoke(Object instance, Object[] inputs, Object[]& outputs)
      • at System.ServiceModel.Dispatcher.DispatchOperationRuntime.InvokeBegin(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage5(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage4(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage3(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage2(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage1(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.MessageRpc.Process(Boolean isOperationContextSet)
      • Time: 2008-06-02 10:13:31.343
      • Machine: SMF-ZOPA-WEB-02
      • Application: BLWebAppSvc.exe
      • Severity: Information
      • Fmt.Message: HandlingInstance ID: - b16dec3b-0fab-4928-894c-80f919336611
      • Message: System.IndexOutOfRangeException: Index was outside the bounds of the array.
      • at System.Runtime.Remoting.Proxies.RealProxy.PropagateOutParameters(IMessage msg, Object[] outArgs, Object returnValue)
      • at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
      • at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
      • at Zopa.BusinessLogic.ISocialNetwork.GetFeaturedLoans(String sessionToken, SocialProfileElementPresent present, Int32 pageNumber, Int32 pageSize, Int32& totalRecords)
      • at SyncInvokeGetFeaturedLoans(Object , Object[] , Object[] )
      • at System.ServiceModel.Dispatcher.SyncMethodInvoker.Invoke(Object instance, Object[] inputs, Object[]& outputs)
      • at System.ServiceModel.Dispatcher.DispatchOperationRuntime.InvokeBegin(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage5(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage4(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage3(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage2(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage1(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.MessageRpc.Process(Boolean isOperationContextSet)
      • Time: 2008-06-02 10:07:10.500
      • Machine: SMF-ZOPA-WEB-02
      • Application: BLWebAppSvc.exe
      • Severity: Information
      • Fmt.Message: HandlingInstance ID: - ea4bd2a2-2aa7-434b-b683-f60ec7597284
      • Message: System.InvalidCastException: Return argument has an invalid type.
      • at System.Runtime.Remoting.Proxies.RealProxy.ValidateReturnArg(Object arg, Type paramType)
      • at System.Runtime.Remoting.Proxies.RealProxy.PropagateOutParameters(IMessage msg, Object[] outArgs, Object returnValue)
      • at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
      • at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
      • at Zopa.BusinessLogic.IMemberProfile.GetProfile(String sessionToken)
      • at SyncInvokeGetProfile(Object , Object[] , Object[] )
      • at System.ServiceModel.Dispatcher.SyncMethodInvoker.Invoke(Object instance, Object[] inputs, Object[]& outputs)
      • at System.ServiceModel.Dispatcher.DispatchOperationRuntime.InvokeBegin(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage5(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage4(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage3(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage2(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.ImmutableDispatchRuntime.ProcessMessage1(MessageRpc& rpc)
      • at System.ServiceModel.Dispatcher.MessageRpc.Process(Boolean isOperationContextSet)
Jun 25, 2008 at 7:19 PM


Well, it turned out that we'd missed an important point in the PIAB documentation: 

The application block reuses handler instances in different pipelines to minimize the number of objects it must create. Therefore, handlers should not store any per-call state in member variables. In multi-threaded applications, the action of multiple calls passing through the same handler instance is likely to corrupt the internal state.

We made our handlers thread safe and now all is normal.