Непонятное срабатывание rdtsc() в Linux ( Ubuntu 10.10 ) Опции

[Белый пони]

Здравствуйте!

Столкнулся с проблемой, в ходе вычисления временного интервала с помощью rdtsc().
Вот программа, которая считывает значения, приходящие на последовательный порт и засекающая временные промежутки между их считванием:

dumb3.cpp

#include <stdio.h>
#include <fcntl.h>
#include <unistd.h>
#include <termios.h>
#include <stdint.h>

extern __inline__ uint64_t rdtsc(); 

void SetSIO( int fd,
                  unsigned int BaudRate,   // B0 B50 ... B9600 B19200 B38400
                  unsigned int Parity,     // 1 ... 4 ( odd, even, mark, space)
                  unsigned int DataBits,     // CS5 ... CS8
                  unsigned int StopBits,     // 0 или 1 (1 или 2)
                  unsigned int FlowControl); // 0 .. 3 ( RTS/CTS,  XON/XOFF, both, none)

int main(void)
{
unsigned char R[50];  // read data
char key[1];

short bytesrd;
int fp;              // tty's descriptor

unsigned long ini, end;   // rdtsc() limits 


///////// keyboard settings, reserve copy of initial/////
 struct termios tp1;
 struct termios tp2;

  tcgetattr(0,&tp1);
  tp2=tp1;
  tp2.c_iflag&=~ICRNL;
  tp2.c_lflag&=~ICANON;
  tp2.c_lflag&=~ECHO;
  tp2.c_cc[VMIN ]=1;
  tp2.c_cc[VTIME]=0;
  tcsetattr(0,TCSANOW,&tp2);
////////////////////////////////////////////////////////

fp = open( "/dev/ttyS0", O_RDWR | O_NONBLOCK);
SetSIO( fp, B9600, 0, CS8, 0, 3);

fd_set set0, set;      // forming set of COM and keyboard descriptors
FD_ZERO( &set);
FD_SET( fp, &set);
FD_SET(  0, &set);
set0 = set;

ini = rdtsc();
while(1)
    {
    if ( select( fp+1, &set, NULL, NULL, NULL ) > 0)
        {
        if( FD_ISSET( fp, &set))
            { 
            bytesrd = read( fp, R, 1);            
                        if( bytesrd == -1){ printf("\ninit oi!!!"); break;}            
            end = rdtsc();
            printf("%2X %li \n", R[0], (end - ini)/3000 ); // примерная частота процессора в МГц
            ini = end;
            }

        if( FD_ISSET( 0, &set) )    
            { 
            bytesrd = read( 0, key, 1);
            if ( bytesrd != -1 )printf(" %c pressed. \n", key[0]);
            if( key[0] == 27){ break;}
            }
        }
    
    set = set0;    
    }
tcflush( fp, TCIOFLUSH);
tcsetattr(0,TCSANOW,&tp1);   // restore keyboard settings

close(fp);
printf("\n");
}


extern __inline__ uint64_t rdtsc() {
   uint64_t x;
   __asm__ volatile (".byte 0x0f, 0x31" : "=A" (x));
   return x;
 }

(процедура SetSIO - настраивает параметры com-порта, она громоздкая и мне кажется, к проблеме отношения не имеет. Но если что - могу и её запостить)

Cигналы принимаются от девайса с известными интервалами - 10 раз в секунду пачками по 9 байт. перед первый байтом пачки - большая пауза, примерно 95 мс.
Проблема в том, что эта самая программа, будучи запущения разными способами, выдаёт разные временные промежутки:

При запуск в терминале графической оболочки Gnome ("./dump3") в терминал выводится:

1

//пришедший байт, временной интервал после предыдущего байта в микросекундах
2 96434
4 22
F4 8
0 8
30 7
13 7
4 7
EF 7
0 3935
2 96471
4 23
F4 8
0 8
30 7
13 7
4 7
EF 7
0 3971
2 96436
4 22
F4 8
0 8
30 8
13 7
4 7
EF 7
0 3968
...

При запуске в терминале без графической оболочки (Cntrl+Alt+F1 в Убунту) в терминал выводится:

2

2 96464
4 231
D0 240
0 239
30 227
13 227
4 227
CB 225
0 2398
2 96461
4 233
D2 238
0 238
30 225
13 225
4 224
CD 224
0 2406
...

При запуске в том же терминале без графической оболочки с направлением вывода не в консоль, а в файл ( "./dump3.cpp > yyy.txt"):

3

2 29861
4 49
54 5
0 4
30 4
13 4
4 4
50 4
0 3934
2 96454
4 5
54 4
0 4
30 4
13 4
4 4
50 4
0 3986
2 96463
4 5
54 4
0 4
30 4
13 4
4 4
50 4
0 3986

Откуда такие различия?
И где значения ближе к правде?

[Iron Bug]

сколько процессоров на машине? на многопроцессорных (многоядерных) процах эту функцию использовать нельзя. используй clock_gettime с CLOCK_MONOTONIC.

[Белый пони]

сколько процессоров на машине? на многопроцессорных (многоядерных) процах эту функцию использовать нельзя. используй clock_gettime с CLOCK_MONOTONIC.

Однопроцессорный одноядерный Pentium 4 (3 GHz).
Может быть Линукс так организует очередь выполнения процессов и мне нужна исключительно ОС реального времени?..
За clock_gettime спасибо, в будущем пригодиться

[Iron Bug]

на самом деле, просто система обработки и выполнения команд в конвейере процессора может быть такой, что эта функция будет возвращать неточные результаты. в общем, эту функцию применять не рекомендуют уже очень давно. в очень редких случаях её можно применять, но там куча условностей и особенностей применения. да, кстати, её наличие ещё зависит от настроек ядра. юзер её может вообще отключить.
обычно всё-таки для приложений функции clock_gettime хватает вполне. для десяти раз в секунду по 9 байт хватит за глаза. это не "риал-тайм" в полном смысле, это очень медленная скорость передачи. интервалы куда больше, чем наносекунды. а наносекунды линюкс считает очень даже неплохо даже на многопроцессорных архитектурах.

Сообщение отредактировал Iron Bug - 20.3.2011, 23:28

[Белый пони]

на самом деле, просто система обработки и выполнения команд в конвейере процессора может быть такой, что эта функция будет возвращать неточные результаты. в общем, эту функцию применять не рекомендуют уже очень давно. в очень редких случаях её можно применять, но там куча условностей и особенностей применения. да, кстати, её наличие ещё зависит от настроек ядра. юзер её может вообще отключить.
обычно всё-таки для приложений функции clock_gettime хватает вполне. для десяти раз в секунду по 9 байт хватит за глаза. это не "риал-тайм" в полном смысле, это очень медленная скорость передачи. интервалы куда больше, чем наносекунды. а наносекунды линюкс считает очень даже неплохо даже на многопроцессорных архитектурах.

Понятно. Спасибо!

[Белый пони]

на самом деле, просто система обработки и выполнения команд в конвейере процессора может быть такой, что эта функция будет возвращать неточные результаты. в общем, эту функцию применять не рекомендуют уже очень давно. в очень редких случаях её можно применять, но там куча условностей и особенностей применения. да, кстати, её наличие ещё зависит от настроек ядра. юзер её может вообще отключить.
обычно всё-таки для приложений функции clock_gettime хватает вполне. для десяти раз в секунду по 9 байт хватит за глаза. это не "риал-тайм" в полном смысле, это очень медленная скорость передачи. интервалы куда больше, чем наносекунды. а наносекунды линюкс считает очень даже неплохо даже на многопроцессорных архитектурах.

Понятно. Спасибо!

[Белый пони]

Попробовал. Не помогло

Добавил gettime:

gettime1.cpp

int main(void)
{
unsigned char R[50];  // read data
char key[1];

short bytesrd;
int fp;              // tty's descriptor

unsigned long ini, end;   // rdtsc() limits 

struct timespec Ini;
struct timespec End;

Ini.tv_sec = Ini.tv_nsec = End.tv_sec = End.tv_nsec = 0;

///////// keyboard settings, reserve copy of initial/////
 struct termios tp1;
 struct termios tp2;

  tcgetattr(0,&tp1);
  tp2=tp1;
  tp2.c_iflag&=~ICRNL;
  tp2.c_lflag&=~ICANON;
  tp2.c_lflag&=~ECHO;
  tp2.c_cc[VMIN ]=1;
  tp2.c_cc[VTIME]=0;
  tcsetattr(0,TCSANOW,&tp2);
////////////////////////////////////////////////////////

fp = open( "/dev/ttyS0", O_RDWR | O_NONBLOCK);
SetSIO( fp, B9600, 0, CS8, 0, 3);

fd_set set0, set;      // forming set of COM and keyboard descriptors
FD_ZERO( &set);
FD_SET( fp, &set);
FD_SET(  0, &set);
set0 = set;

ini = rdtsc();
clock_gettime( CLOCK_MONOTONIC, &Ini);
while(1)
    {
    if ( select( fp+1, &set, NULL, NULL, NULL ) > 0)
        {
        if( FD_ISSET( fp, &set))
            { 
            bytesrd = read( fp, R, 1);            
                        if( bytesrd == -1){ printf("\ninit oi!!!"); break;}            
            end = rdtsc();
            clock_gettime( CLOCK_MONOTONIC, &End);
            printf("%2X %li  %li\n", R[0], (end - ini)/3014, (End.tv_nsec - Ini.tv_nsec)/1000 );
            ini = end;
            Ini.tv_nsec = End.tv_nsec;
            }

        if( FD_ISSET( 0, &set) )    
            { 
            bytesrd = read( 0, key, 1);
            if ( bytesrd != -1 )printf(" %c pressed. \n", key[0]);
            if( key[0] == 27){ break;}
            }
        }
    
    set = set0;    
    }
tcflush( fp, TCIOFLUSH);
tcsetattr(0,TCSANOW,&tp1);   // restore keyboard settings

close(fp);
printf("\n");
}

С CLOCK_MONOTONIC выдаёт такие же интервалы как и rdtsc(). С другими часами - немного другие, но тоже неверные

Вот что получается (в таком же порядке: терминал Gnome, неграфический терминал, неграфический терминал с перенаправлением в файл):

CLOCK_MONOTONIC

2 96008 96000

2 92021 92012
6 25 24
6C 10 10
0 9 9
30 8 8
13 8 8
6 8 8
66 8 8
0 7908 7907
2 92021 92012
6 25 25
6C 10 10
0 9 9
30 8 8
13 8 8
6 8 8
66 8 8
0 7907 7906
2 92021 92013
6 24 24
6C 10 10
0 9 9
30 8 8
13 8 8
____________________________________
23 321 321
B0 325 325
0 317 317
30 316 316
14 317 317
23 314 314
8C 316 316
0 1770 1770
2 96013 96002
23 327 327
B0 332 332
0 320 320
30 321 321
14 320 320
23 318 318
8C 320 320
0 1738 1738
2 96022 96013
23 352 352
B0 325 325
0 315 315
30 313 313
14 314 314
23 319 319
8C 323 323
0 1722 1722
2 96006 95999
23 331 331
B0 336 336
______________________________________
7A 5 5
0 5 5
30 5 5
12 5 5
6 5 5
74 5 5
0 3959 3959
2 96013 96004
6 6 6
7A 5 5
0 5 5
30 5 5
13 5 5
6 5 5
74 5 5
0 3959 3958
2 96027 96018
6 17 17
7A 6 6
0 5 5
30 5 5
13 5 5
6 5 5
74 5 5
0 3929 3929
2 96011 -903997

CLOCK_REALTIME

0 3942 3941
2 95988 95979
6 26 25
A5 10 10
0 9 9
30 8 8
12 8 8
6 8 8
9E 8 8
0 3952 3952
2 95975 95966
6 25 25
A5 10 10
0 8 8
30 8 8
12 8 8
6 8 8
9E 8 8
0 3943 3943
2 95987 95978
6 25 24
A5 10 10
0 8 8
30 8 8
12 8 8
6 8 8
_____________________________________
2A 291 291
50 273 273
0 274 274
30 275 275
14 279 279
2A 286 286
26 288 287
0 2017 2016
2 96010 96000
2A 309 309
50 309 309
0 312 312
30 313 313
14 320 320
2A 328 328
26 331 331
0 1774 1774
2 96010 96000
2A 340 340
50 331 331
0 327 327
30 321 321
14 312 312
2A 313 313
26 312 312
0 1739 1739
____________________________________

2 91725 91711
6 59 59
AF 6 6
0 5 5
30 5 5
12 5 5
6 5 5
A8 5 5
0 3895 3895
2 96004 95999
6 6 6
AF 5 5
0 5 5
30 5 5
13 5 5
6 5 5
A8 5 5
0 3961 3961
2 96015 96001
6 6 6
AF 5 5
0 5 5

CLOCK_PROCESS_CPUTIME_ID

1D 9 9
0 3938 13
2 95989 26
7 28 26
24 10 10
0 9 9
30 9 9
12 9 9
7 8 8
1D 9 9
0 3936 13
2 95985 26
7 27 26
24 11 10
0 9 9
30 9 9
13 9 9
7 8 8
1D 8 8
0 3938 13
2 95985 25
_________________________________
2 92031 284
1E 311 310
64 280 279
0 282 281
30 283 283
14 287 287
1E 294 293
46 303 302
0 5938 306
2 92024 328
1E 351 348
64 320 320
0 322 321
30 328 327
14 333 332
1E 340 339
46 347 346
0 5640 353
2 92005 350
1E 334 333
64 328 328
0 318 317
30 319 318
14 316 315
1E 310 309
46 312 312
0 5761 323
2 92010 321
1E 320 319
64 326 325
0 324 323
30 326 325
14 323 323
1E 315 315
46 316 315
0 5747 324
2 92027 331
___________________________________
2 88693 25
7 60 60
30 6 6
0 5 5
30 5 5
13 5 5
7 5 5
29 5 5
0 3892 9
2 96010 10
7 7 6
30 5 5
0 5 5
30 5 5
12 5 5
7 5 5
29 5 5
0 3959 9
2 96008 10
7 6 6
30 5 5

CLOCK_THREAD_CPUTIME_ID

13 9 9
7 8 8
75 9 9
0 3937 13
2 95987 25
7 27 26
7C 10 10
0 9 9
30 9 9
13 8 8
7 8 8
75 8 8
0 3904 12
2 96022 26
7 27 25
7C 10 10
0 9 9
30 9 9
13 8 8
7 8 8
75 8 8
0 3938 13
2 95987 26
7 27 26
7C 10 10
0 9 9
30 9 9
13 8 8
7 8 8
75 8 8
0 3939 13
2 95986 26
7 26 24
7C 10 10
________________________________________
0 280 280
30 285 284
14 289 288
1C 293 292
30 299 298
0 1984 303
2 96006 313
1C 317 316
4C 316 315
0 321 320
30 329 329
14 333 332
1C 336 335
30 342 341
0 1703 343
2 96009 345
1C 329 328
4C 324 323
0 313 313
30 305 304
14 306 305
1C 304 303
30 303 303
0 1813 304
2 96030 321
1C 346 344
4C 303 303
0 301 300
30 303 302
14 303 302
1C 304 304
30 309 309
0 1809 312
2 96025 324
1C 348 346
4C 313 312
0 311 310
_________________________________
2 92009 11
7 8 8
A0 5 5
0 5 5
30 5 5
13 5 5
7 5 5
98 5 5
0 7959 9
2 92012 10
7 6 6
A0 5 5
0 5 5
30 5 5
13 5 5
7 5 5
98 5 5
0 7961 9
2 92002 10
7 6 6
A0 5 5
0 5 5
30 5 5
13 5 5
7 5 5

Может clock_gettime пользуется теми же регистрами что и rdtsc()? Мне и точность большая не нужна, десятков микросекунд с головой хватит( а тут такие расхождения

[Iron Bug]

ну, значит у тебя программа сама тормозит. попробуй сделать два потока и в одном (с высоким приоритетом) читать данные и складывать в какой-то буфер(чтобы было быстро), а в другом (с более низким приоритетом) считывать буфер и переносить куда угодно - в консоль или в файл. ну или если девайс работает недолго, то накапливать данные и потом в конце программы их выводить.
у тебя ini = end; после printf идёт, а это не есть гут. ибо printf может тормозить.

[Белый пони]

ну, значит у тебя программа сама тормозит. попробуй сделать два потока и в одном (с высоким приоритетом) читать данные и складывать в какой-то буфер(чтобы было быстро), а в другом (с более низким

приоритетом) считывать буфер и переносить куда угодно - в консоль или в файл. ну или если девайс работает недолго, то накапливать данные и потом в конце программы их выводить.
у тебя ini = end; после printf идёт, а это не есть гут. ибо printf может тормозить.

Для проверки считываю 90 значений сначала в массив и только после закрытия порта - вывожу в консоль:

gettime2.cpp

...
int main(void)
{
unsigned char R[50];  // read data
for( int i = 0; i < 50; i++ ) R[i] = 0xFF;
char key[1];

short bytesrd;
int fp;              // tty's descriptor

unsigned long ini, end;   // rdtsc() limits 

unsigned char    byteArray[90];
unsigned long   rdtscArray[90];
unsigned long gettimeArray[90];

struct timespec Ini;
struct timespec End;

Ini.tv_sec = Ini.tv_nsec = End.tv_sec = End.tv_nsec = 0;

///////// keyboard settings, reserve copy of initial/////
 struct termios tp1;
 struct termios tp2;

  tcgetattr(0,&tp1);
  tp2=tp1;
  tp2.c_iflag&=~ICRNL;
  tp2.c_lflag&=~ICANON;
  tp2.c_lflag&=~ECHO;
  tp2.c_cc[VMIN ]=1;
  tp2.c_cc[VTIME]=0;
  tcsetattr(0,TCSANOW,&tp2);
////////////////////////////////////////////////////////

fp = open( "/dev/ttyS0", O_RDWR | O_NONBLOCK);
SetSIO( fp, B9600, 0, CS8, 0, 3);

fd_set set0, set;      // forming set of COM and keyboard descriptors
FD_ZERO( &set);
FD_SET( fp, &set);
FD_SET(  0, &set);
set0 = set;

ini = rdtsc();
clock_gettime( CLOCK_MONOTONIC, &Ini);
unsigned short i = 0;
tcflush( fp, TCIOFLUSH);
while( i < 90)
    {
    if ( select( fp+1, &set, NULL, NULL, NULL ) > 0)
        {

        if( FD_ISSET( fp, &set))
            { 
            bytesrd = read( fp, R, 1);            
                if( bytesrd == -1){ printf("\ninit oi!!!"); break;}
                if( R[1] != 0xFF ){ printf("\nbuffer stuck: %2x %2X %2X", R[1], R[2], R[3]);}                                            
            end = rdtsc();
            clock_gettime( CLOCK_MONOTONIC, &End);
            //printf("%2X %li  %li\n", R[0], (end - ini)/3014, (End.tv_nsec - Ini.tv_nsec)/1000 );
            
               byteArray[i] = R[0];            
              rdtscArray[i] = (end - ini) / 3014;
            gettimeArray[i] = (End.tv_nsec - Ini.tv_nsec) / 1000;
            
            ini = end;
            Ini.tv_nsec = End.tv_nsec;
            i++;
            }

        if( FD_ISSET( 0, &set) )    
            { 
            bytesrd = read( 0, key, 1);
            if ( bytesrd != -1 )printf(" %c pressed. \n", key[0]);
            if( key[0] == 27){ break;}
            }
        }
    
    set = set0;    
    }
tcflush( fp, TCIOFLUSH);
tcsetattr(0,TCSANOW,&tp1);   // restore keyboard settings
close(fp);

for( i = 0; i < 90; i++) printf("%2X\t%li\t%li\t%X\t%X\n", byteArray[i], rdtscArray[i], gettimeArray[i], rdtscArray[i], gettimeArray[i]);
printf("\n");
}
...

При всех трёх вариантах запуска выдаются примерно одинаковые интервалы ( в этот раз распечатал значения интервалов ещё и в hex):

Раскрывающийся текст

 2    77903    77890    1304F    13042
 5    6    5    6    5
AF    4    4    4    4
 0    4    4    4    4
30    4    4    4    4
13    4    4    4    4
 5    4    4    4    4
A9    4    4    4    4
 0    7948    7948    1F0C    1F0C
 2    92007    92001    16767    16761
 5    5    4    5    4
AF    4    4    4    4
 0    4    4    4    4
30    4    4    4    4
13    4    4    4    4
 5    4    4    4    4
A9    4    4    4    4
 0    7965    7965    1F1D    1F1D
 2    92006    92000    16766    16760
 5    4    4    4    4
AF    4    4    4    4
 0    4    4    4    4
30    4    4    4    4
12    4    4    4    4
 5    4    4    4    4
A9    4    4    4    4
 0    7967    7966    1F1F    1F1E
 2    92010    92000    1676A    16760
 5    4    4    4    4
AF    4    4    4    4
 0    4    4    4    4
30    4    4    4    4
13    4    4    4    4
 5    4    4    4    4
A9    4    4    4    4
 0    7968    7968    1F20    1F20
 2    92002    92000    16762    16760
 5    4    4    4    4
AF    4    4    4    4
 0    4    4    4    4
30    4    4    4    4
13    4    4    4    4
 5    4    4    4    4
A9    4    4    4    4
 0    7969    7967    1F21    1F1F
 2    92014    92000    1676E    16760
 5    4    4    4    4
AF    4    4    4    4
 0    4    4    4    4
30    4    4    4    4
13    4    4    4    4
 5    4    4    4    4
A9    4    4    4    4
 0    8015    8016    1F4F    1F50
 2    91969    91970    16741    16742
 5    6    6    6    6
AF    4    4    4    4
 0    4    4    4    4
30    4    4    4    4
13    4    4    4    4
 5    4    4    4    4
A9    4    4    4    4
 0    7948    7946    1F0C    1F0A
 2    92011    -908001    1676B    FFF2251F
 5    5    5    5    5
AF    4    4    4    4
 0    4    4    4    4
30    4    4    4    4
13    4    4    4    4
 5    4    4    4    4
A9    4    4    4    4
 0    7968    7968    1F20    1F20
 2    92007    92002    16767    16762
 5    4    4    4    4
AF    4    4    4    4
 0    4    4    4    4
30    4    4    4    4
13    4    4    4    4
 5    4    4    4    4
A9    4    4    4    4
 0    7966    7965    1F1E    1F1D
 2    92009    92000    16769    16760
 5    4    4    4    4
AF    4    4    4    4
 0    4    4    4    4
30    4    4    4    4
12    4    4    4    4
 5    4    4    4    4
A9    4    4    4    4
 0    7968    7968    1F20    1F20

Видимо именно printf, действительно, всё задерживал. Причём в текстовой консоли он тормозил больше. И это мне не понятно Я думал без графической оболочки всё должно работать быстрее наоброт.

А ещё непонятно, откуда в gettime вылезло отрицательно значение ( см. вывод выше):

13 4 4 4 4
5 4 4 4 4
A9 4 4 4 4
0 7948 7946 1F0C 1F0A
2 92011 -908001 1676B FFF2251F
5 5 5 5 5
AF 4 4 4 4

вроде бы до переполнения переменной ещё полтора старших байта осталось .

[Iron Bug]

А ещё непонятно, откуда в gettime вылезло отрицательно значение

пауза была большая и счётчик переполнился.