WCF Error: The message with Action cannot be proce

2019-04-02 14:30发布

问题:

I get famous error in web application, which is WCF client:

The message with Action cannot be processed at the receiver, due to a ContractFilter mismatch at the EndpointDispatcher. This may be because of either a contract mismatch (mismatched Actions between sender and receiver) or a binding/security mismatch between the sender and the receiver. Check that sender and receiver have the same contract and the same binding (including security requirements, e.g. Message, Transport, None).

Several interesting facts are:
- it happens sometimes and for some users. It's a part of trace from web application (user1 gets errors whereas user2 works fine):

19/04/2011 9:43:37|52ms2ebf25dj1x2ldk0gci55/user1|OperationQueueTasksStart|TaskCount:1|InvestigationId:f855786f-f06c-4b63-bd38-e1f414c0270b
19/04/2011 9:43:38|52ms2ebf25dj1x2ldk0gci55/user1|OperationQueueTasksStop|Elapsed:0.0045741|WithResult:True|InvestigationId:f855786f-f06c-4b63-bd38-e1f414c0270b
19/04/2011 9:43:38|52ms2ebf25dj1x2ldk0gci55/user1|AllocationEnd|Elapsed:0.2748583
19/04/2011 9:43:38|52ms2ebf25dj1x2ldk0gci55/user1|AllocationErrorTrace|Errors were encountered:- The message with Action 'http://tempuri.org/IAllocationProvider/OperationQueueTasks2' cannot be processed at the receiver, due to a ContractFilter mismatch at the EndpointDispatcher. This may be because of either a contract mismatch (mismatched Actions between sender and receiver) or a binding/security mismatch between the sender and the receiver.  Check that sender and receiver have the same contract and the same binding (including security requirements, e.g. Message, Transport, None).
19/04/2011 9:43:47|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:9.4693646|WithResult:False|InvestigationId:376f17e8-e969-4394-a6fc-2538632d2956
19/04/2011 9:43:47|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:5|InvestigationId:1083fe62-f31d-48b6-9f6b-d0a28a62912e
19/04/2011 9:43:53|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:6.0867429|WithResult:False|InvestigationId:1083fe62-f31d-48b6-9f6b-d0a28a62912e
19/04/2011 9:43:53|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:1|InvestigationId:159ccda4-f753-40f0-a0a7-e531e6826d67
19/04/2011 9:43:57|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:3.9732669|WithResult:False|InvestigationId:159ccda4-f753-40f0-a0a7-e531e6826d67
19/04/2011 9:43:57|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:1|InvestigationId:73493ade-c9cc-42e1-8be5-0869070c8542
19/04/2011 9:43:59|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:2.4491641|WithResult:False|InvestigationId:73493ade-c9cc-42e1-8be5-0869070c8542
19/04/2011 9:43:59|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:2|InvestigationId:60c0f224-558f-4f0b-977a-9c15e101a6a9
19/04/2011 9:44:03|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:3.1119381|WithResult:False|InvestigationId:60c0f224-558f-4f0b-977a-9c15e101a6a9
19/04/2011 9:44:03|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:2|InvestigationId:677fa342-ff38-49ae-bed1-3d2f8b843b17
19/04/2011 9:44:07|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:4.7489463|WithResult:False|InvestigationId:677fa342-ff38-49ae-bed1-3d2f8b843b17
19/04/2011 9:44:07|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:4|InvestigationId:c4cd34d6-3564-4a06-bc0b-f25fc37d86de
19/04/2011 9:44:12|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:4.41472|WithResult:False|InvestigationId:c4cd34d6-3564-4a06-bc0b-f25fc37d86de
19/04/2011 9:44:12|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:3|InvestigationId:b4e0a795-d4ba-42b8-8d21-3ffa2aa2a7fc
19/04/2011 9:44:16|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:4.0598829|WithResult:False|InvestigationId:b4e0a795-d4ba-42b8-8d21-3ffa2aa2a7fc
19/04/2011 9:44:16|o52wurr3kkx0pkj024dhjj55/user2|AllocationEnd|Elapsed:88.0465741
19/04/2011 9:44:47|52ms2ebf25dj1x2ldk0gci55/user1|AllocationStart|InvestigationCount:1|QueueId:98aebaa3-f507-4f3d-b919-1a95a5b1d2ea
19/04/2011 9:44:47|52ms2ebf25dj1x2ldk0gci55/user1|OperationQueueTasksStart|TaskCount:1|InvestigationId:f855786f-f06c-4b63-bd38-e1f414c0270b
19/04/2011 9:44:48|52ms2ebf25dj1x2ldk0gci55/user1|OperationQueueTasksStop|Elapsed:0.0043857|WithResult:True|InvestigationId:f855786f-f06c-4b63-bd38-e1f414c0270b
19/04/2011 9:44:48|52ms2ebf25dj1x2ldk0gci55/user1|AllocationEnd|Elapsed:0.3354014
19/04/2011 9:44:48|52ms2ebf25dj1x2ldk0gci55/user1|AllocationErrorTrace|Errors were encountered:- The message with Action 'http://tempuri.org/IAllocationProvider/OperationQueueTasks2' cannot be processed at the receiver, due to a ContractFilter mismatch at the EndpointDispatcher. This may be because of either a contract mismatch (mismatched Actions between sender and receiver) or a binding/security mismatch between the sender and the receiver.  Check that sender and receiver have the same contract and the same binding (including security requirements, e.g. Message, Transport, None).
19/04/2011 9:51:27|o52wurr3kkx0pkj024dhjj55/user2|AllocationStart|InvestigationCount:14|QueueId:98aebaa3-f507-4f3d-b919-1a95a5b1d2ea
19/04/2011 9:51:27|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:1|InvestigationId:a0c00957-c621-4f7a-a65d-1fa873b24afc
19/04/2011 9:51:29|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:2.6407058|WithResult:False|InvestigationId:a0c00957-c621-4f7a-a65d-1fa873b24afc
19/04/2011 9:51:29|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:1|InvestigationId:29989dfb-1f4a-4524-ac50-68cce1b373b0
19/04/2011 9:51:32|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:2.3559612|WithResult:False|InvestigationId:29989dfb-1f4a-4524-ac50-68cce1b373b0
19/04/2011 9:51:32|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:1|InvestigationId:f8978117-40b3-497e-baec-09ed0508e6d9
19/04/2011 9:51:34|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:2.736648|WithResult:False|InvestigationId:f8978117-40b3-497e-baec-09ed0508e6d9
19/04/2011 9:51:34|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:1|InvestigationId:aea25d48-48eb-4bc8-9347-b7d79267330e
19/04/2011 9:51:37|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:2.3584367|WithResult:False|InvestigationId:aea25d48-48eb-4bc8-9347-b7d79267330e
19/04/2011 9:51:37|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:1|InvestigationId:f983cc74-5e4e-438a-8083-dca3ab116d03
19/04/2011 9:51:39|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:2.3643481|WithResult:False|InvestigationId:f983cc74-5e4e-438a-8083-dca3ab116d03
19/04/2011 9:51:39|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:1|InvestigationId:4fc1febb-3495-46bc-b3df-814c88e2164c
19/04/2011 9:51:41|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:2.4341061|WithResult:False|InvestigationId:4fc1febb-3495-46bc-b3df-814c88e2164c
19/04/2011 9:51:41|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:1|InvestigationId:a7adf45e-2476-4478-b579-2eb58cb1b90e
19/04/2011 9:51:44|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:2.7966921|WithResult:False|InvestigationId:a7adf45e-2476-4478-b579-2eb58cb1b90e
19/04/2011 9:51:44|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:1|InvestigationId:937ee46d-61ed-477f-91df-876dc011b488
19/04/2011 9:51:47|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:2.3558742|WithResult:False|InvestigationId:937ee46d-61ed-477f-91df-876dc011b488
19/04/2011 9:51:47|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:1|InvestigationId:4f6c23d5-3082-4578-bc25-e1acaea3b944
19/04/2011 9:51:49|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:2.216947|WithResult:False|InvestigationId:4f6c23d5-3082-4578-bc25-e1acaea3b944
19/04/2011 9:51:49|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:1|InvestigationId:e4c4517e-f522-490a-9e5d-4244cf51efe0
19/04/2011 9:51:51|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:2.5495532|WithResult:False|InvestigationId:e4c4517e-f522-490a-9e5d-4244cf51efe0
19/04/2011 9:51:51|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:1|InvestigationId:8b7ecc3a-f234-45e7-8824-e39f0209d00b
19/04/2011 9:51:54|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:2.4506334|WithResult:False|InvestigationId:8b7ecc3a-f234-45e7-8824-e39f0209d00b
19/04/2011 9:51:54|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:1|InvestigationId:abac0e79-587d-407d-bdb6-63c6af3f4217
19/04/2011 9:51:56|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:2.2250336|WithResult:False|InvestigationId:abac0e79-587d-407d-bdb6-63c6af3f4217
19/04/2011 9:51:56|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:1|InvestigationId:0e11aea4-7cc8-4225-8ba1-c68487e38ad2
19/04/2011 9:52:00|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:3.9445225|WithResult:False|InvestigationId:0e11aea4-7cc8-4225-8ba1-c68487e38ad2
19/04/2011 9:52:00|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStart|TaskCount:1|InvestigationId:9c6557ed-843c-44d6-a6b0-bd2a702efcaf
19/04/2011 9:52:03|o52wurr3kkx0pkj024dhjj55/user2|OperationQueueTasksStop|Elapsed:2.6812607|WithResult:False|InvestigationId:9c6557ed-843c-44d6-a6b0-bd2a702efcaf
19/04/2011 9:52:03|o52wurr3kkx0pkj024dhjj55/user2|AllocationEnd|Elapsed:36.1138801
  • there's also a pattern (I don't know how reliable) that some particular user (in terms of asp .net session) get that error more often (if not all the time) ther other. On the other hand, I have users that didn't experienced that error at all.

Any ideas what can cause that mysterious behaviour?

Thanks,Pawel

EDIT 1: Adding configuration info

<endpoint address="net.tcp://10.80.12.25:8400/Hire.Application.Services/AllocationService" behaviorConfiguration="endpointBehavior" binding="netTcpBinding" bindingConfiguration="netTcpBinding" contract="Hire.Application.Contracts.IAllocationProvider" name="AllocationProvider" />

<endpointBehaviors>
    <behavior name="endpointBehavior">
        <customBehavior />
    </behavior>
</endpointBehaviors>

<extensions>
    <behaviorExtensions>
        <add name="customBehavior" type="Hire.Application.Contracts.CustomBehaviorExtensionElement, Hire.Application.Contracts, Version=5.2.7.0, Culture=neutral, PublicKeyToken=null" />
    </behaviorExtensions>
</extensions>

<bindings>
    <netTcpBinding>
        <binding name="netTcpBinding" closeTimeout="00:05:00" openTimeout="00:05:00" sendTimeout="00:05:00" receiveTimeout="00:15:00" hostNameComparisonMode="StrongWildcard" maxBufferSize="6553600" maxBufferPoolSize="524288" maxReceivedMessageSize="6553600">
            <readerQuotas maxDepth="64" maxStringContentLength="2147483647" maxArrayLength="2147483647" maxBytesPerRead="4096" maxNameTableCharCount="16384" />
            <security mode="None" />
        </binding>
    </netTcpBinding>
</bindings>

EDIT 2: netTcpBinding uses default configuration (sessions are enabled, no SessionMode properties are set on service. Also session timeouts use default values. Also InstanceContextMode is set to default PerSession value.

回答1:

issue resolved. It turned out that web server (WCF Client) was connecting with one out of four application servers (nodes) using sth like round-robin, when making requests. One node for some reason had old service contract assembly with old operation contract and old method signature (thank you Reflector!).

Thanks,Pawel