Web API controller action called twice

Question

My controller actions are getting called twice, and I can't figure out why!!

This is a typical controller:

[Authorize]
public abstract class BaseController : ApiController
{
    protected readonly ILogService logService;
    protected HttpResponseMessage response = null;

    protected BaseController(ILogService logService)
    {
        this.logService = logService;
    }

    protected override void Initialize(HttpControllerContext controllerContext)
    {
        base.Initialize(controllerContext);

        //check authorization here
    }
}

public abstract class EntityController<T> : BaseController
{
    public EntityController(ILogService logService) : base(logService) { }

    [HttpGet]
    public abstract IHttpActionResult Get(int id);

    [ActionName("Find")]
    [HttpGet]
    public virtual IHttpActionResult Find(string param)
    {
        return null;
    }

    [HttpPost]
    [ValidateModel]
    public abstract IHttpActionResult Create(T dto);

    [HttpPut]
    [ValidateModel]
    public abstract IHttpActionResult Update(T dto);

    [HttpDelete]
    public abstract IHttpActionResult Delete(int id);
}

public class CustomerTypeController : EntityController<CustomerTypeDTO>
{
    private readonly ICustomerTypeService customerTypeService;

    public CustomerTypeController(ILogService logService,
                                  ICustomerTypeService customerTypeService)
        : base(logService)
    {
        this.customerTypeService = customerTypeService;
    }

    public override IHttpActionResult Get(int id)
    {
        var item = Mapper.Map<CustomerTypeDTO>(customerTypeService.Get(id));
        return Ok<CustomerTypeDTO>(item);
    }

    public override IHttpActionResult Find(string param)
    {
        CustomerType modelItem = customerTypeService.Get(x => x.Abbr == param);

        CustomerTypeDTO item = Mapper.Map<CustomerTypeDTO>(modelItem);
        return Ok<CustomerTypeDTO>(item);
    }
}

Using tracing, I find this in my log files:

Request;;;"httpurlhere"/MyWebAPI/CustomerType/Find?param=100
MessageHandlers;ServerCompressionHandler;SendAsync;
Controllers;DefaultHttpControllerSelector;SelectController;Route='controller:CustomerType,action:Find'
Controllers;DefaultHttpControllerSelector;SelectController;CustomerType
Controllers;HttpControllerDescriptor;CreateController;
Controllers;HttpControllerDescriptor;CreateController;MyWebAPI.API.Controllers.Reference.CustomerTypeController
Controllers;CustomerTypeController;ExecuteAsync;
Action;ApiControllerActionSelector;SelectAction;
Action;ApiControllerActionSelector;SelectAction;Selected action 'Find(String param)'
Filters;AuthorizeAttribute;OnAuthorizationAsync;
Filters;AuthorizeAttribute;OnAuthorizationAsync;
ModelBinding;HttpActionBinding;ExecuteBindingAsync;
ModelBinding;ModelBinderParameterBinding;ExecuteBindingAsync;Binding parameter 'param'
ModelBinding;ModelBinderParameterBinding;ExecuteBindingAsync;Parameter 'param' bound to the value '100'
ModelBinding;HttpActionBinding;ExecuteBindingAsync;Model state is valid. Values: param=100
Filters;ValidateModelAttribute;OnActionExecutingAsync;Action filter for 'Find(String param)'
Filters;ValidateModelAttribute;OnActionExecutingAsync;
Action;ApiControllerActionInvoker;InvokeActionAsync;Action='Find(param=100)'
Action;ReflectedHttpActionDescriptor;ExecuteAsync;Invoking action 'Find(param=100)'
Action;ReflectedHttpActionDescriptor;ExecuteAsync;Action returned 'System.Web.Http.Results.OkNegotiatedContentResult`1[MyWebAPI.CustomerTypeDTO]'
Formatting;DefaultContentNegotiator;Negotiate;Type='CustomerType', formatters=[JsonMediaTypeFormatterTracer, XmlMediaTypeFormatterTracer, FormUrlEncodedMediaTypeFormatterTracer, FormUrlEncodedMediaTypeFormatterTracer]
 Formatting;JsonMediaTypeFormatter;GetPerRequestFormatterInstance;Obtaining formatter of type 'JsonMediaTypeFormatter' for type='CustomerType', mediaType='application/json; charset=utf-8'
Formatting;JsonMediaTypeFormatter;GetPerRequestFormatterInstance;Will use same 'JsonMediaTypeFormatter' formatter
Formatting;DefaultContentNegotiator;Negotiate;Selected formatter='JsonMediaTypeFormatter', content-type='application/json; charset=utf-8'
Action;ApiControllerActionInvoker;InvokeActionAsync;
Filters;ValidateModelAttribute;OnActionExecutedAsync;Action filter for 'Find(String param)'
Filters;ValidateModelAttribute;OnActionExecutedAsync;
Controllers;CustomerTypeController;ExecuteAsync;
Formatting;JsonMediaTypeFormatter;WriteToStreamAsync;Value='MyWebAPI.CustomerTypeDTO', type='CustomerType', content-type='application/json; charset=utf-8'
Formatting;JsonMediaTypeFormatter;WriteToStreamAsync;
MessageHandlers;ServerCompressionHandler;SendAsync;
Request;;;Content-type='application/json; charset=utf-8', content-length=93
Controllers;CustomerTypeController;Dispose;
Controllers;CustomerTypeController;Dispose;

I've checked the client side, and I can confirm that the action is only requested once by the client.

EDIT: I checked how many times the database is being hit on that particular action (Find), and it's only once.

So, the action is being called once, however, the constructor, other base class methods and the dispose methods are always called twice.

Why is this happening?

Answer 1

I had the exact same problem that some of my controller actions were called twice. I found that the only difference between these actions and other actions was that these ones took a bit more time to execute than the others.

I realized that my client code was the reason of this problem. In my case, I used Volley to make my networking calls. Volley has some policies to retry calling web service methods. It means that if the server responds too late, Volley can retry the call. By default, Volley retries the call if it doesn't get any respond in 1.5 seconds. I change my client code (Volley retry policy) and my problem solved. This is the changes I have done:

req.setRetryPolicy(new DefaultRetryPolicy(
                   (int) TimeUnit.SECONDS.toMillis(7), //time out before retry
                   0, //number of retries
                   DefaultRetryPolicy.DEFAULT_BACKOFF_MULT));

I hope this could help.