Wrong intervals between the packets being sent

[maxsharabayko]

This issue affects network load, packet losses, receive speed and maximum bandwidth calculations, and congestion control for SRT file transfer mode. Time intervals between the packets are likely to be very short, even though the packet sending interval is set to much higher values. E.g. for 500 Mbps the interval between the packets should be approximately 20 us, while the actual time will be even 1 us on certain periods of sending.

Description

The sending thread function CSndQueue::worker() adjusts sending pace by calling to CTimer::sleepto(ts). The function is expected to make this working thread sleep until the timestamp of the next packet to be delivered comes, using:

pthread_cond_timedwait(&m_TickCond, &m_TickLock, &timeout);

where timeout is current time plus 10 ms (see + 10000 below).

timeout.tv_nsec = (now.tv_usec + 10000) * 1000;

Therefore, the implementation of this function makes the minimum sleep interval identical to 10 ms.

The sleep can be interrupted earlier by CRcvQueue::worker_RetrieveUnit() function, that calls m_pTimer->tick(); in the very beginning, and thus signals the conditional variable:

void CTimer::tick()
{
    pthread_cond_signal(&m_TickCond);
}

However, the CRcvQueue::worker_RetrieveUnit() will also wait for 10 ms on a socket in case there are no incoming packets:

tv.tv_usec = 10000;
const int select_ret = ::select((int) m_iSocket + 1, &set, NULL, &set, &tv);

When the waiting time is longer that expected, the CUDT::packData(…) function adds the delay to the m_ullTimeDiff_tk += entertime_tk - m_ullTargetTime_tk;. The target sending time of the next packet will be current time (entertime_tk) plus inter-packet interval (m_ullInterval_t) minus time difference (m_ullTimeDiff_tk):

ts_tk = entertime_tk + m_ullInterval_tk - m_ullTimeDiff_tk;

or just the current time if the difference is higher than the interval value:

ts_tk = entertime_tk;

Therefore further packets will be sent immediately after the previous one.
All these makes the sending pace very inaccurate, especially on Windows. The image below shows the number of bits sent in 10 ms interval. Average sending speed is 500 Mbps, while the deviation is almost +/-100%.

This affects network load, packet losses, receive speed and maximum bandwidth calculations, and congestion control for SRT file transfer mode.

[maxsharabayko]

The following test measures the accuracy of CTimer::sleepto(...) function on different intervals.

TEST(CSndQueue, SleeptoAccuracy)
{
    const int num_samples = 1000;
    uint64_t tk_vals[num_samples] = { };

    const uint64_t freq = CTimer::getCPUFrequency();
    std::cerr << "CPU Frequency: " << freq << "\n";

    const uint64_t sleep_intervals_us[] = { 1, 5, 10, 15, 20, 50, 100, 500, 1000, 5000 };

    CTimer timer;

    for (uint64_t interval_us : sleep_intervals_us)
    {
        uint64_t start_time;
        CTimer::rdtsc(start_time);

        for (int i = 0; i < num_samples; i++)
        {
            uint64_t currtime;
            CTimer::rdtsc(currtime);
            tk_vals[i] = currtime;
            timer.sleepto(currtime + interval_us * freq);
        }

        uint64_t stop_time;
        CTimer::rdtsc(stop_time);
        cerr << "Target sleep interval: " << interval_us << " us\n";
        const uint64_t delta_us = (stop_time - start_time) / freq;
        cerr << "rdtsc time interval: " << delta_us << " us\n";
        cerr << "sleepto avg time penalty: " << delta_us / num_samples << " us\n";
    }
}

[maxsharabayko]

The following measurements show that the minimum waiting time on Linux desktop would be ~60 μs, although only starting from 1 ms waiting time the accuracy is good enough (error < 10%).
CPU frequency for Windows test system is 10 (0.1 μs), for Linux 1 μs.

Note. Commenting out the while loop does not make any difference.

Wait, μs	Win 10	CentOS 7	MacBook Pro	iOS	Android
1	64	49	1
5	209	58	10
10	354	62	17
50	1181	99	68
100	1536	150	140
250	1559	315	389
500	1469	582	738
1000	1593	1080	1346
5000	5506	5110	6118
10000	10717	10112	11963

void CTimer::sleepto(uint64_t nexttime)
{
   // Use class member such that the method can be interrupted by others
   m_ullSchedTime = nexttime;

   uint64_t t;
   rdtsc(t);
   if (t >= m_ullSchedTime)
       return;

   const uint64_t freq = CTimer::getCPUFrequency();
   timeval now;
   gettimeofday(&now, 0);
   const uint64_t time_us = now.tv_sec * uint64_t(1000000) 
                                       + now.tv_usec + (m_ullSchedTime - t) / freq;
   timespec timeout;
   timeout.tv_sec  = time_us / 1000000;
   timeout.tv_nsec = (time_us % 1000000) * 1000;

   while (t < m_ullSchedTime)
   {
       THREAD_PAUSED();
       pthread_mutex_lock(&m_TickLock);
       pthread_cond_timedwait(&m_TickCond, &m_TickLock, &timeout);
       pthread_mutex_unlock(&m_TickLock);
       THREAD_RESUMED();

       rdtsc(t);
   }
}

[maxsharabayko]

Using this_thread::sleep_for().

	Waiting time, μs
sleepto()	1	5	10	15	20	50	100	500	1000	5000
Linux	65	70	76	96	85	116	169	591	1097	5140
Windows	1707	1748	1831	1850	1780	1828	1799	1899	1806	5633

TEST(CSndQueue, SleeptoAccuracy)
{
    const int num_samples = 1000;
    uint64_t tk_vals[num_samples] = { };

    const uint64_t freq = CTimer::getCPUFrequency();
    std::cerr << "CPU Frequency: " << freq << "\n";

    const uint64_t sleep_intervals_us[] = { 1, 5, 10, 15, 20, 50, 100, 500, 1000, 5000 };

    CTimer timer;

    for (uint64_t interval_us : sleep_intervals_us)
    {
        uint64_t start_time;
        CTimer::rdtsc(start_time);

        for (int i = 0; i < num_samples; i++)
        {
            this_thread::sleep_for(chrono::microseconds(interval_us));
        }

        uint64_t stop_time;
        CTimer::rdtsc(stop_time);
        cerr << "Target sleep interval: " << interval_us << " us\n";
        const uint64_t delta_us = (stop_time - start_time) / freq;
        cerr << "rdtsc time interval: " << delta_us << " us\n";
        cerr << "sleepto avg time penalty: " << delta_us / num_samples << " us\n";
    }
}

[maxsharabayko]

The Windows Timestamp Project. Microsecond Resolution Time Services for Windows.
Also not accurate enough.

G_Sleep for:  0.100000 ms
Elapsed time: 0.142100 ms, late by 42.100000 us
G_Sleep for:  0.200000 ms
Elapsed time: 0.145200 ms, late by -54.800000 us
G_Sleep for:  0.300000 ms
Elapsed time: 0.086000 ms, late by -214.000000 us
G_Sleep for:  0.400000 ms
Elapsed time: 0.096100 ms, late by -303.900000 us
G_Sleep for:  0.500000 ms
Elapsed time: 0.096600 ms, late by -403.400000 us
G_Sleep for:  0.010000 ms
Elapsed time: 0.063100 ms, late by 53.100000 us
G_Sleep for:  0.020000 ms
Elapsed time: 0.087200 ms, late by 67.200000 us
G_Sleep for:  0.030000 ms
Elapsed time: 0.087800 ms, late by 57.800000 us
G_Sleep for:  0.040000 ms
Elapsed time: 0.065300 ms, late by 25.300000 us
G_Sleep for:  0.050000 ms
Elapsed time: 0.062600 ms, late by 12.600000 us

[oviano]

I did a comparison on my Windows 10 PC with pthread_cond_timedwait vs std:::condition_variable::wait_for.

Interestingly, I didn't get the same results as you posted earlier where the Windows resolution seemed to be 15ms granularity in your pthread test. I wonder if you would get the same results for std::condition_variable though, your std::this_thread::sleep results suggest you would.

Switching SRT to use std::thread/mutex/condition_variable might be a good idea at some point, it would remove the Windows pthread dependency for a start.

CPU Frequency: 10

Using std::condition_variable:
Target sleep interval: 1
Actual time interval: 1790
Target sleep interval: 5
Actual time interval: 1762
Target sleep interval: 10
Actual time interval: 1767
Target sleep interval: 15
Actual time interval: 1756
Target sleep interval: 20
Actual time interval: 1778
Target sleep interval: 50
Actual time interval: 1754
Target sleep interval: 100
Actual time interval: 1780
Target sleep interval: 500
Actual time interval: 1764
Target sleep interval: 1000
Actual time interval: 1741
Target sleep interval: 5000
Actual time interval: 5651
Target sleep interval: 10000
Actual time interval: 10534
Target sleep interval: 50000
Actual time interval: 50478

Using pthread_cond_var:
Target sleep interval: 1
Actual time interval: 74
Target sleep interval: 5
Actual time interval: 13
Target sleep interval: 10
Actual time interval: 12
Target sleep interval: 15
Actual time interval: 42
Target sleep interval: 20
Actual time interval: 12
Target sleep interval: 50
Actual time interval: 45
Target sleep interval: 100
Actual time interval: 74
Target sleep interval: 500
Actual time interval: 2122
Target sleep interval: 1000
Actual time interval: 2413
Target sleep interval: 5000
Actual time interval: 6226
Target sleep interval: 10000
Actual time interval: 11191
Target sleep interval: 50000
Actual time interval: 51166

I think with the pthread one, the overhead for gettimeofday() and the calculations relating to that explain the low values for the sub 500us tests.

Here is the code, for reference.

void run_timer_test(void)
{
	uint64_t freq;
	LARGE_INTEGER counts_per_sec;
	if (QueryPerformanceFrequency(&counts_per_sec))
	{
		freq = counts_per_sec.QuadPart / 1000000;
		printf("CPU Frequency: %llu\n", freq);
	}
	else
	{
		printf("Error querying performance frequency\n");
		return;
	}

	const int num_samples = 1000;
	uint64_t tk_vals[num_samples] = { };

	const uint64_t sleep_intervals_us[] = { 1, 5, 10, 15, 20, 50, 100, 500, 1000, 5000, 10000, 50000 };

	{
		printf("Using std::condition_variable\n");

		std::condition_variable cv;
		std::mutex m;

		for (uint64_t interval_us : sleep_intervals_us)
		{
			uint64_t start_time;
			rdtsc(start_time);

			for (int i = 0; i < num_samples; i++)
			{
				std::unique_lock<std::mutex> ul(m);
				cv.wait_for(ul, std::chrono::microseconds(interval_us));
				ul.unlock();
			}

			uint64_t stop_time;
			rdtsc(stop_time);

			printf("Target sleep interval: %llu\n", interval_us);
			const uint64_t delta_us = (stop_time - start_time) / freq;
			printf("Actual time interval: %llu\n", delta_us / num_samples);
		}
	}

	{
		printf("Using pthread_cond_var\n");

		pthread_cond_t cv;
		pthread_mutex_t m;
		pthread_mutex_init(&m, NULL);
		pthread_cond_init(&cv, NULL);

		for (uint64_t interval_us : sleep_intervals_us)
		{
			uint64_t start_time;
			rdtsc(start_time);

			for (int i = 0; i < num_samples; i++)
			{
				timeval now;
				timespec timeout;
				gettimeofday(&now, 0);
				if (now.tv_usec < 990000)
				{
					timeout.tv_sec = now.tv_sec;
					timeout.tv_nsec = (now.tv_usec + interval_us) * 1000;
				}
				else
				{
					timeout.tv_sec = now.tv_sec + 1;
					timeout.tv_nsec = (now.tv_usec + interval_us - 1000000) * 1000;
				}
				pthread_mutex_lock(&m);
				pthread_cond_timedwait(&cv, &m, &timeout);
				pthread_mutex_unlock(&m);
			}

			uint64_t stop_time;
			rdtsc(stop_time);

			printf("Target sleep interval: %llu\n", interval_us);
			const uint64_t delta_us = (stop_time - start_time) / freq;
			printf("Actual time interval: %llu\n", delta_us / num_samples);
		}

		pthread_mutex_destroy(&m);
		pthread_cond_destroy(&cv);
	}
}

[maxsharabayko]

Windows 10 using waitable timer

void SleepInUs(uint32_t us)
{
    ::LARGE_INTEGER ft;
    // in 100 nanosecond intervals
    ft.QuadPart = -static_cast<int64_t>(us * 10);  // Negative values indicate relative time.

    ::HANDLE timer = ::CreateWaitableTimer(NULL, TRUE, NULL);
    ::SetWaitableTimer(timer, &ft, 0, NULL, NULL, 0);
    ::WaitForSingleObject(timer, INFINITE);
    ::CloseHandle(timer);
}

CPU Frequency: 10
Target sleep duration: 1 us
avg sleep duration: 15219 us
min sleep duration: 209 us
max sleep duration: 28257 us

Target sleep duration: 5 us
avg sleep duration: 15985 us
min sleep duration: 154 us
max sleep duration: 28298 us

Target sleep duration: 10 us
avg sleep duration: 14915 us
min sleep duration: 604 us
max sleep duration: 29628 us

Target sleep duration: 50 us
avg sleep duration: 14974 us
min sleep duration: 910 us
max sleep duration: 28375 us

Target sleep duration: 100 us
avg sleep duration: 15753 us
min sleep duration: 398 us
max sleep duration: 30591 us

Target sleep duration: 250 us
avg sleep duration: 14559 us
min sleep duration: 912 us
max sleep duration: 28314 us

Target sleep duration: 500 us
avg sleep duration: 15940 us
min sleep duration: 953 us
max sleep duration: 27708 us

Target sleep duration: 1000 us
avg sleep duration: 16045 us
min sleep duration: 981 us
max sleep duration: 30677 us

Target sleep duration: 5000 us
avg sleep duration: 16471 us
min sleep duration: 5020 us
max sleep duration: 30273 us

Target sleep duration: 10000 us
avg sleep duration: 14642 us
min sleep duration: 9902 us
max sleep duration: 40268 us