0

I have a WSDualHttpBinding WCF Client which works perfectly except when hosted in IIS. After a reboot of the machine it will sporadically fail ca. 1/70 times after a reboot with an 403.4 (SSL Required) which manifests like this at the client:

    internal class TestWCFClient :
    DuplexClientBase<ITestWCFClient>, ITestWCFClient, ITestWCFClient
{
    public TestWCFClient(ICallback callback) :
        base(new InstanceContext(callback),
            new WSDualHttpBinding
            {
                SendTimeout = new TimeSpan(0, 5, 0),
                ReceiveTimeout = new TimeSpan(0, 5, 0)
            },
            new EndpointAddress("http://localhost/Content/TestWcfClient.svc")
        )
    {
    }


        System.Net.WebException
                1    The remote server returned an error: (403) Forbidden.
                
System.Net.HttpWebRequest.GetResponse()
System.ServiceModel.Channels.HttpChannelFactory`1+HttpRequestChannel+HttpChannelRequest[System.__Canon].WaitForReply(System.TimeSpan)
System.ServiceModel.Channels.RequestChannel.Request(System.ServiceModel.Channels.Message, System.TimeSpan)
System.ServiceModel.Security.IssuanceTokenProviderBase`1[System.__Canon].DoNegotiation(System.TimeSpan)
System.ServiceModel.Security.SspiNegotiationTokenProvider.OnOpen(System.TimeSpan)
System.ServiceModel.Security.WrapperSecurityCommunicationObject.OnOpen(System.TimeSpan)
System.ServiceModel.Channels.CommunicationObject.Open(System.TimeSpan)
System.ServiceModel.Security.CommunicationObjectSecurityTokenProvider.Open(System.TimeSpan)
System.ServiceModel.Security.SymmetricSecurityProtocol.OnOpen(System.TimeSpan)
System.ServiceModel.Security.WrapperSecurityCommunicationObject.OnOpen(System.TimeSpan)
System.ServiceModel.Channels.CommunicationObject.Open(System.TimeSpan)
System.ServiceModel.Channels.SecurityChannelFactory`1+ClientSecurityChannel`1[System.__Canon,System.__Canon].OnOpen(System.TimeSpan)
System.ServiceModel.Channels.CommunicationObject.Open(System.TimeSpan)
System.ServiceModel.Security.SecuritySessionSecurityTokenProvider.DoOperation(System.ServiceModel.Security.SecuritySessionOperation, System.ServiceModel.EndpointAddress, System.Uri, System.IdentityModel.Tokens.SecurityToken, System.TimeSpan)
System.ServiceModel.Security.SecuritySessionSecurityTokenProvider.GetTokenCore(System.TimeSpan)
System.IdentityModel.Selectors.SecurityTokenProvider.GetToken
System.ServiceModel.Security.SecuritySessionClientSettings`1+ClientSecuritySessionChannel[System.__Canon].OnOpen(System.TimeSpan)
System.ServiceModel.Channels.CommunicationObject.Open(System.TimeSpan)
System.ServiceModel.Channels.ReliableChannelBinder`1+ChannelSynchronizer+SyncWaiter[System.__Canon].TryGetChannel()
System.ServiceModel.Channels.ReliableChannelBinder`1+ChannelSynchronizer+SyncWaiter[System.__Canon].TryWait(System.__Canon ByRef)
System.ServiceModel.Channels.ReliableChannelBinder`1+ChannelSynchronizer[System.__Canon].TryGetChannel(Boolean, Boolean, System.TimeSpan, System.ServiceModel.Channels.MaskingMode, System.__Canon ByRef)
System.ServiceModel.Channels.ReliableChannelBinder`1[System.__Canon].Send(System.ServiceModel.Channels.Message, System.TimeSpan, System.ServiceModel.Channels.MaskingMode)
System.ServiceModel.Channels.SendReceiveReliableRequestor.OnRequest(System.ServiceModel.Channels.Message, System.TimeSpan, Boolean)
System.ServiceModel.Channels.ReliableRequestor.Request(System.TimeSpan)
System.ServiceModel.Channels.ClientReliableSession.Open(System.TimeSpan)
System.ServiceModel.Channels.ClientReliableDuplexSessionChannel.OnOpen(System.TimeSpan)
System.ServiceModel.Channels.CommunicationObject.Open(System.TimeSpan)
System.ServiceModel.Channels.ServiceChannel.OnOpen(System.TimeSpan)
System.ServiceModel.Channels.CommunicationObject.Open(System.TimeSpan)
System.ServiceModel.Channels.ServiceChannel+CallOpenOnce.System.ServiceModel.Channels.ServiceChannel.ICallOnce.Call(System.ServiceModel.Channels.ServiceChannel, System.TimeSpan)
System.ServiceModel.Channels.ServiceChannel+CallOnceManager.CallOnce(System.TimeSpan, CallOnceManager)
System.ServiceModel.Channels.ServiceChannel.EnsureOpened(System.TimeSpan)
System.ServiceModel.Channels.ServiceChannel.Call(System.String, Boolean, System.ServiceModel.Dispatcher.ProxyOperationRuntime, System.Object[], System.Object[], System.TimeSpan)
System.ServiceModel.Channels.ServiceChannelProxy.InvokeService(System.Runtime.Remoting.Messaging.IMethodCallMessage, System.ServiceModel.Dispatcher.ProxyOperationRuntime)
System.ServiceModel.Channels.ServiceChannelProxy.Invoke(System.Runtime.Remoting.Messaging.IMessage)
System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(System.Runtime.Remoting.Proxies.MessageData ByRef, Int32)

The interesting thing is that sometimes it recovers and 1-2 minutes later it continues to work again without any IIS restart. With failed request tracing I have found that shortly before the 404 the only difference in the traces is this event from the ETW provider WWW Server for the event GENERAL_GET_URL_METADATA

    <Event xmlns="http://schemas.microsoft.com/win/2004/08/events/event">
     <System>
      <Provider Name="WWW Server" Guid="{3A2A4E84-4C21-4981-AE10-3FDA0D9B0F83}"/>
      <EventID>0</EventID>
      <Version>1</Version>
      <Level>4</Level>
      <Opcode>30</Opcode>
      <Keywords>0x0</Keywords>
      <TimeCreated SystemTime="2021-06-14T09:46:08.170Z"/>
      <Correlation ActivityID="{80000003-0014-FF00-B63F-84710C7967BB}"/>
      <Execution ProcessID="21656" ThreadID="21860"/>
     </System>
     <EventData>
      <Data Name="ContextId">{80000003-0014-FF00-B63F-84710C7967BB}</Data>
      <Data Name="PhysicalPath"></Data>
      <Data Name="AccessPerms">521</Data>
     </EventData>
     <RenderingInfo Culture="en-US">
      <Opcode>GENERAL_GET_URL_METADATA</Opcode>
     </RenderingInfo>
     <ExtendedTracingInfo xmlns="http://schemas.microsoft.com/win/2004/08/events/trace">
      <EventGuid>{D42CF7EF-DE92-473E-8B6C-621EA663113A}</EventGuid>
     </ExtendedTracingInfo>
</Event>

This event has in the good case

<Data Name="AccessPerms">513</Data>

and in the bad case

<Data Name="AccessPerms">521</Data>

I am not sure if this is a permission issue but what is the AccessPerms telling me and what input is causing it to be set to 521?

The merged config file has sslFlags set to None

C:\inetpub\TEMP\appPools\AppPool\WCFPool.config
    <security>
      <access sslFlags="None" />

and it looks ok to me. Is IIS sometimes demanding SSL although it is configured that for this web service it should not use it?

Alois Kraus
  • 13,229
  • 1
  • 38
  • 64
  • You can refer to: https://stackoverflow.com/questions/19311832/http-error-403-4-forbidden – Theobald Du Jun 21 '21 at 07:36
  • @TheobaldDu: As I said this is not a configuration issue. After boot waiting for something around 5 minutes it works. This looks like some user name lookup issue or DNS not responding issue to verify e.g. host names in a certificate. But without debugging IIS I cannot tell. I have captured a Time Travel Trace of the faulting request of w3wp.exe. This will hopefully give MS Support a chance to debug through it. – Alois Kraus Jun 21 '21 at 07:52
  • If you do not enable SSL and you visit a website without a security certificate, the browser will remind you. If you cannot find significant IIS problems or server-side problems, it may be related to the browser settings. – Theobald Du Jun 22 '21 at 09:04
  • @TheobaldDu: This is a web service called via API. No browser is involved. Since it happens only after boot and 2-3 minutes later the same web service call works I can rule out WCF client configuration because this did not change. It is therefore some state issue inside IIS. – Alois Kraus Jun 22 '21 at 12:27
  • You can refer to: https://stackoverflow.com/questions/19311832/http-error-403-4-forbidden – Theobald Du Jul 16 '21 at 02:39
  • @TheobaldDU: I have a call at MS running. It is not a simple config issue. – Alois Kraus Jul 16 '21 at 13:14

0 Answers0