Threading issues when using HttpClient for asynchronous file downloads

Question

This question is a follow-up to Using HttpClient for Asynchronous File downloads.

2015/01/15 Edited to add in accomodation for multithreading - still have a mystery,

using System;
using System.Collections.Generic;
using System.IO;
using System.Net.Http;
using System.Threading.Tasks;

namespace TestHttpClient2
{
  class Program
  {
    /* Use Yahoo portal to access quotes for stocks - perform asynchronous operations. */

    static string baseUrl = "http://real-chart.finance.yahoo.com/";
    static string requestUrlFormat = "/table.csv?s={0}&d=0&e=1&f=2016&g=d&a=0&b=1&c=1901&ignore=.csv";

    static void Main(string[] args)
    {
      var activeTaskList = new List<Task>();

      string outputDirectory = "StockQuotes";
      if (!Directory.Exists(outputDirectory))
      {
        Directory.CreateDirectory(outputDirectory);
      }

      while (true)
      {
        Console.WriteLine("Enter symbol or [ENTER] to exit:");
        string symbol = Console.ReadLine();
        if (string.IsNullOrEmpty(symbol))
        {
          break;
        }

        Task downloadTask = DownloadDataForStockAsync(outputDirectory, symbol);
        if (TaskIsActive(downloadTask))
        {
          // This is an asynchronous world - lock the list before updating it!
          lock (activeTaskList)
          {
            activeTaskList.Add(downloadTask);
          }

        }
        else
        {
          Console.WriteLine("task completed already?!??!?");
        }
        CleanupTasks(activeTaskList);
      }

      Console.WriteLine("Cleaning up");
      while (CleanupTasks(activeTaskList))
      {
        Task.Delay(1).Wait();
      }
    }

    private static bool CleanupTasks(List<Task> activeTaskList)
    {
      // reverse loop to allow list item deletions
      // This is an asynchronous world - lock the list before updating it!
      lock (activeTaskList)
      {
        for (int i = activeTaskList.Count - 1; i >= 0; i--)
        {
          if (!TaskIsActive(activeTaskList[i]))
          {
            activeTaskList.RemoveAt(i);
          }
        }
        return activeTaskList.Count > 0;
      }
    }

    private static bool TaskIsActive(Task task)
    {
      return task != null
          && task.Status != TaskStatus.Canceled
          && task.Status != TaskStatus.Faulted
          && task.Status != TaskStatus.RanToCompletion;
    }

    static async Task DownloadDataForStockAsync(string outputDirectory, string symbol)
    {
      try
      {
        using (var client = new HttpClient())
        {
          client.BaseAddress = new Uri(baseUrl);
          client.Timeout = TimeSpan.FromMinutes(5);
          string requestUrl = string.Format(requestUrlFormat, symbol);

          var request = new HttpRequestMessage(HttpMethod.Post, requestUrl);
          var sendTask = client.SendAsync(request, HttpCompletionOption.ResponseHeadersRead);
          var response = await sendTask;
          response.EnsureSuccessStatusCode();
          var httpStream = await response.Content.ReadAsStreamAsync();

          string timestampedName = FormatTimestampedString(symbol, true);
          var filePath = Path.Combine(outputDirectory, timestampedName + ".csv");
          using (var fileStream = File.Create(filePath))
          using (var reader = new StreamReader(httpStream))
          {
            await httpStream.CopyToAsync(fileStream);
            fileStream.Flush();
          }
        }
      }
      catch (Exception ex)
      {
        Console.WriteLine("Exception on thread: {0}: {1}\r\n",
          System.Threading.Thread.CurrentThread.ManagedThreadId,
          ex.Message,
          ex.StackTrace);
      }
    }

    static volatile string lastTimestampedString = string.Empty;
    static volatile string dummy = string.Empty;
    static HashSet<string> oldStrings = new HashSet<string>();

    static string FormatTimestampedString(string message, bool uniquify = false)
    {
      // This is an asynchronous world - lock the shared resource before using it!
      //lock (dummy)
      lock (lastTimestampedString)
      {
        Console.WriteLine("IN  - Thread: {0:D2} lastTimestampedString: {1}", 
            System.Threading.Thread.CurrentThread.ManagedThreadId,
            lastTimestampedString);

        string newTimestampedString;

        while (true)
        {
          DateTime lastDateTime = DateTime.Now;

          newTimestampedString = string.Format(
              "{1:D4}_{2:D2}_{3:D2}_{4:D2}_{5:D2}_{6:D2}_{7:D3}_{0}",
                message,
                lastDateTime.Year, lastDateTime.Month, lastDateTime.Day,
                lastDateTime.Hour, lastDateTime.Minute, lastDateTime.Second,
                lastDateTime.Millisecond
                );
          if (!uniquify)
          {
            break;
          }
          if (newTimestampedString != lastTimestampedString)
          {
            break;
          }

          //Task.Delay(1).Wait();
        };

        lastTimestampedString = newTimestampedString;
        Console.WriteLine("OUT - Thread: {0:D2} lastTimestampedString: {1}",
            System.Threading.Thread.CurrentThread.ManagedThreadId,
            lastTimestampedString);

        if (uniquify)
        {
          oldStrings.Add(lastTimestampedString);
        }
        return lastTimestampedString;
      }
    }
  }
}

Q) Why am I getting this intermittent error (at the end of this output.) (I am copying a long list of repeated lines of "NES" to the clipboard and pasting into the console in order to duplicate the problem):

Enter symbol or [ENTER] to exit:
NES
Enter symbol or [ENTER] to exit:
NES
Enter symbol or [ENTER] to exit:
NES
Enter symbol or [ENTER] to exit:
NES
Enter symbol or [ENTER] to exit:
NES
Enter symbol or [ENTER] to exit:
NES
Enter symbol or [ENTER] to exit:
NES
Enter symbol or [ENTER] to exit:
NES
Enter symbol or [ENTER] to exit:
NES
Enter symbol or [ENTER] to exit:
NES
Enter symbol or [ENTER] to exit:
NES
Enter symbol or [ENTER] to exit:
NES
Enter symbol or [ENTER] to exit:
NES
Enter symbol or [ENTER] to exit:
NES
Enter symbol or [ENTER] to exit:
NES
Enter symbol or [ENTER] to exit:
IN  - Thread: 18 lastTimestampedString:
OUT - Thread: 18 lastTimestampedString: 2015_01_15_11_19_44_472_NES
IN  - Thread: 17 lastTimestampedString: 2015_01_15_11_19_44_472_NES
OUT - Thread: 17 lastTimestampedString: 2015_01_15_11_19_44_473_NES
IN  - Thread: 19 lastTimestampedString: 2015_01_15_11_19_44_473_NES
OUT - Thread: 19 lastTimestampedString: 2015_01_15_11_19_44_493_NES
IN  - Thread: 16 lastTimestampedString: 2015_01_15_11_19_44_493_NES
OUT - Thread: 16 lastTimestampedString: 2015_01_15_11_19_44_494_NES
IN  - Thread: 18 lastTimestampedString: 2015_01_15_11_19_44_494_NES
OUT - Thread: 18 lastTimestampedString: 2015_01_15_11_19_44_495_NES
IN  - Thread: 17 lastTimestampedString: 2015_01_15_11_19_44_495_NES
IN  - Thread: 16 lastTimestampedString: 2015_01_15_11_19_44_495_NES
OUT - Thread: 17 lastTimestampedString: 2015_01_15_11_19_44_496_NES
IN  - Thread: 19 lastTimestampedString: 2015_01_15_11_19_44_495_NES
OUT - Thread: 19 lastTimestampedString: 2015_01_15_11_19_44_496_NES
IN  - Thread: 18 lastTimestampedString: 2015_01_15_11_19_44_496_NES
OUT - Thread: 16 lastTimestampedString: 2015_01_15_11_19_44_495_NES
OUT - Thread: 18 lastTimestampedString: 2015_01_15_11_19_44_497_NES
IN  - Thread: 19 lastTimestampedString: 2015_01_15_11_19_44_497_NES
OUT - Thread: 19 lastTimestampedString: 2015_01_15_11_19_44_523_NES
IN  - Thread: 18 lastTimestampedString: 2015_01_15_11_19_44_523_NES
OUT - Thread: 18 lastTimestampedString: 2015_01_15_11_19_44_532_NES
IN  - Thread: 19 lastTimestampedString: 2015_01_15_11_19_44_532_NES
OUT - Thread: 19 lastTimestampedString: 2015_01_15_11_19_44_533_NES
IN  - Thread: 18 lastTimestampedString: 2015_01_15_11_19_44_533_NES
Exception on thread: 17: The process cannot access the file 'C:\Users\drogers\_code\Tests\TestHttpClient\TestHttpClient2\bin\Debug\StockQuot
es\2015_01_15_11_19_44_495_NES.csv' because it is being used by another process.

Exception on thread: 16: The process cannot access the file 'C:\Users\drogers\_code\Tests\TestHttpClient\TestHttpClient2\bin\Debug\StockQuot
es\2015_01_15_11_19_44_496_NES.csv' because it is being used by another process.

OUT - Thread: 18 lastTimestampedString: 2015_01_15_11_19_44_540_NES
IN  - Thread: 17 lastTimestampedString: 2015_01_15_11_19_44_540_NES
IN  - Thread: 19 lastTimestampedString: 2015_01_15_11_19_44_540_NES
OUT - Thread: 17 lastTimestampedString: 2015_01_15_11_19_44_557_NES
OUT - Thread: 19 lastTimestampedString: 2015_01_15_11_19_44_560_NES
Exception on thread: 19: The process cannot access the file 'C:\Users\drogers\_code\Tests\TestHttpClient\TestHttpClient2\bin\Debug\StockQuot
es\2015_01_15_11_19_44_560_NES.csv' because it is being used by another process.

I can avoid the problem with the uncommenting of line 126 and commenting line 127, as in:

  // This is an asynchronous world - lock the shared resource before using it!
  lock (dummy)
  //lock (lastTimestampedString)

Looking at the il, the only difference in the code generated for FormatTimestampedString is

ldsfld     string modreq([mscorlib]System.Runtime.CompilerServices.IsVolatile)
            TestHttpClient2.Program::**lastTimestampedString**

versus

ldsfld     string modreq([mscorlib]System.Runtime.CompilerServices.IsVolatile) 
            TestHttpClient2.Program::**dummy**

Answer 1

Strings are immutable. So when I set my lock on the lastTimestampedString reference, and then changed it, I no longer had the lock I thought I had. The lock was on the old string. Anyone else coming along would be testing the lock on the new string, and would therefore be allowed in.

Mea culpa.

Answer 2

You have 2 tasks trying to write the stock data to the same file.

Change FormatTimestampedString to check for the existence of the generate filename and if exists generate a new one.