Почему этот код выполняется быстрее, чем ожидалось?

Question

У меня есть этот код:

    public void replay() {
        long previous = DateTime.Now.Ticks;
        for (int i = 0; i < 1000; i++) {
            Thread.Sleep(300);
            long cur = DateTime.Now.Ticks;
            Console.WriteLine(cur - previous);
            previous = cur;
        }
    }

Который вызывается как отдельный поток, например:

        MethodInvoker replayer = new MethodInvoker(replay);
        replayer.BeginInvoke(null, null);

Однако, если я смотрю вывод, он действует странно. Он выводит i парами. Например, он будет ждать полного ожидания, затем вывести i, затем быстро вывести и следующую i, затем снова ждать. Почему он это делает и как я могу это исправить?

Это выводит это:

3125040
2968788
2968788
2968788
3125040
2968788
2968788
2968788
3125040
2968788
2968788
2968788
3125040

Если я увеличу сон более чем на секунду, этого не произойдет.

Answer 1

Измените код, чтобы исключить задержку отображения в вашем анализе:

public void replay() 
{        
    Thread.Sleep(5000);
    DateTime start = DateTime.Now;      
    for (int i = 0; i < 1000; i++) 
    {            
          Console.WriteLine(string.Format("Exec:{0} - {1} ms",
                i, DateTime.Now - start));
          start = DateTime.Now;
          Thread.Sleep(300);        
    }
}

Если посмотреть на ваш модифицированный выход, то разница в петле будет меньше 5% (15 мс из 300). Это нормально из-за неопределенности, связанной с тем, когда ОС фактически назначает временные интервалы потоку ... (Если я правильно помню, в ОС Windows это обычно происходит только каждые 20 мс!)

Большее расхождение, которое вы ощущаете в выводе на консоль, почти наверняка связано с задержками отображения.

Answer 2

Невозможно воспроизвести. Интересно, если это что-то локальное для вашей машины; возможно буферизация.

Answer 3

Я не могу воспроизвести это, но вы можете рассмотреть таймер. Это было бы более надежным.

public class Counter
{
    private readonly TimeSpan initialDelay, incrementDelay;
    private readonly int maxCount;
    private Timer timer;
    private int count;

    public Counter(TimeSpan initialDelay, TimeSpan incrementDelay, int maxCount)
    {
        this.maxCount = maxCount;
        this.initialDelay = initialDelay;
        this.incrementDelay = incrementDelay;
    }

    public void Start(Action<int> tickBehavior)
    {
        if (timer != null)
        {
            Timer temp = timer;
            timer = null;
            temp.Dispose();
        }
        timer = new Timer(() =>
            {
                tickBehavior(count++);
                if (count > maxCount) timer.Dispose();
            }, null, initialDelay, incrementDelay);
    }
}

Используйте это:

Counter counter = new Counter(TimeSpan.FromSeconds(5), TimeSpan.FromSeconds(.3), 1000);
counter.Start((count) => Console.WriteLine(count););

EDIT

Я использую System.Threading.Timer, но Counter можно легко изменить на System.Timers.Timer или System.Windows.Forms.Timer в зависимости от ваших потребностей. См. эту ссылку для описания того, когда и какие таймеры использовать.

Answer 4

Ваш сон внутри цикла составляет всего 300 мс, что не очень долго. Ваша заявка будет делать следующее:

• Сон 5 секунд
• печать 0
• Сон 300 мс
• печать 1
• Сон 300мс
• печать 2

и т.д.