Problem with PCAN-USB speed

[Fojtik]

I erased post "Fri 9. Feb 2018, 13:34" to prevent confusing anybody from public. Another post Fri 9. Feb 2018, 11:55 demonstrates, that true CAN message rate >6000msgs/s can be achieved.

The control loop would completely break when there is delays in [ms] not seconds. I will attempt to realise completelly different measuring test program. I think about something like "CAN ping" and trully evaluate response time. Without this code, the measurements are not reliable. When I get interesting results, I will publish it here.

[Fojtik]

I apologize for my bad previous measurement.
New measurements ready:

Code: Select all

 CAN_Init(CAN_SPEED,CAN_INIT_TYPE_ST);
  if(hEvent==NULL) hEvent = CreateEvent(NULL, FALSE, FALSE, "");	
  CAN_SetRcvEvent(hEvent);		//Set Event Handle for CANReadExt

  SetThreadPriority(GetCurrentThread(), THREAD_PRIORITY_HIGHEST);

  while(toupper(ch)!='Q')
  {	
    if(_kbhit()) 
    {
      ch = _getch();	/* Use _getch to get key pressed. */
      printf("\nKey struck was '%c'\n", ch);
      //if(toupper(ch)=='H') PrintHelp();
    }      
  

    MsgBuffSnd.ID = 0x601;
    MsgBuffSnd.MSGTYPE = 0;
    MsgBuffSnd.LEN = 6;    
    MsgBuffSnd.DATA[0] = 0x23;
    MsgBuffSnd.DATA[1] = 0x09;
    MsgBuffSnd.DATA[2] = 0x20;
    MsgBuffSnd.DATA[3] = 0x07;
    MsgBuffSnd.DATA[4] = 0x16;
    MsgBuffSnd.DATA[5] = 0x00;
    MsgBuffSnd.DATA[6] = 0x00;
    MsgBuffSnd.DATA[7] = 0x00;
    CAN_Write(&MsgBuffSnd);

    DWORD tck = GetTickCount();

WaitAgain:
    DWORD tck2 = 80 - (GetTickCount() - tck);
    if(tck2>80) tck2 = 0;
    
    WaitForSingleObject(hEvent, tck2);
    if(CAN_Read(&MsgBuff) == CAN_ERR_OK)
    {
      if(MsgBuff.ID<=0x80) goto WaitAgain;
     
      tck2 = GetTickCount();
      printf("%4X %d[B], time %d[ms]\n", MsgBuff.ID, MsgBuff.LEN, tck2-tck);
    }

    tck2 = 100 - (GetTickCount() - tck);
    if(tck2>100) tck2 = 10;
    Sleep(tck2);
    while(CAN_Read(&MsgBuff)==CAN_ERR_OK)
    {		// Get a garbage from a queue.
    }
  }

  CAN_Close();

I am not interested in receive timemark, but the real time when message is extracted from a queue.

For near zero CAN bus load, the delays are usually 0, but sometimes 16 ms.

Code: Select all

581 8[B], time 16[ms]
581 8[B], time 0[ms]
581 8[B], time 0[ms]
581 8[B], time 0[ms]
581 8[B], time 0[ms]
581 8[B], time 0[ms]
581 8[B], time 0[ms]
581 8[B], time 0[ms]
581 8[B], time 0[ms]
581 8[B], time 0[ms]
581 8[B], time 0[ms]
581 8[B], time 0[ms]
581 8[B], time 15[ms]
581 8[B], time 0[ms]
581 8[B], time 0[ms]
581 8[B], time 0[ms]
581 8[B], time 0[ms]
581 8[B], time 16[ms]
581 8[B], time 0[ms]
581 8[B], time 0[ms]
581 8[B], time 0[ms]
581 8[B], time 0[ms]
581 8[B], time 0[ms]

When transfer rate is 4000 msgs/s, average transfer rate is 16ms.

Code: Select all

 581 8[B], time 15[ms]
 581 8[B], time 15[ms]
 581 8[B], time 16[ms]
 581 8[B], time 32[ms]
 581 8[B], time 15[ms]
 581 8[B], time 15[ms]
 581 8[B], time 16[ms]
 581 8[B], time 32[ms]
 581 8[B], time 15[ms]
 581 8[B], time 32[ms]
 581 8[B], time 16[ms]
 581 8[B], time 15[ms]
 581 8[B], time 15[ms]
 581 8[B], time 15[ms]
 581 8[B], time 16[ms]
 581 8[B], time 15[ms]
 581 8[B], time 16[ms]
 581 8[B], time 16[ms]
 581 8[B], time 15[ms]
 581 8[B], time 16[ms]
 581 8[B], time 16[ms]
 581 8[B], time 16[ms]
 581 8[B], time 15[ms]

For 6000 msgs/s the transfer delay grows to 46ms.

Even when this is not a defect of PCAN-USB hardware, it would be better to try to buy PCIe card. May be that it will be more faster or have smaller delays.

[K.Wagner]

Hello,

I can see in the snippet code you posted, that you are using GetTickCount to do time measurement. Note that this is not accurate enough for measurements under 16 milliseconds. You should use a high-resolution timer instead, otherwise you will get wrong results.

Here an extract of the remarks on GetTickCount function from the Microsoft help:

GetTickCount remarks

GetTickCount.PNG (35.77 KiB) Viewed 23686 times

That is why you are seeing such time jumps of 16 milliseconds...

More information about GetTickCount and other timers can be found within the microsoft online documentation:

• GetTickCount
• High-resolution timers
• Multimedia timers

[Fojtik]

Yes, you are completelly right that my measurements are not precise enough. My task is not to measure delay precisely, but to evaluate whether closed loop control will work or not.
I can use rdtsc instruction to get CPU timing. I did not forget to turn off CPU frequency optimiser.

Code: Select all

  CAN_Init(CAN_SPEED,CAN_INIT_TYPE_ST);

  LARGE_INTEGER pFrequency;
  QueryPerformanceFrequency(&pFrequency);

  if(hEvent==NULL) hEvent = CreateEvent(NULL, FALSE, FALSE, "");		
  CAN_SetRcvEvent(hEvent);		//Set Event Handle for CANReadExt

  SetThreadPriority(GetCurrentThread(), THREAD_PRIORITY_HIGHEST);

  while(toupper(ch)!='Q')
  {	
    if(_kbhit()) 
    {
      ch = _getch();	/* Use _getch to get key pressed. */
      printf("\nKey struck was '%c'\n", ch);
      //if(toupper(ch)=='H') PrintHelp();
    }      
  

    MsgBuffSnd.ID = 0x601;
    MsgBuffSnd.MSGTYPE = 0;
    MsgBuffSnd.LEN = 6;    
    MsgBuffSnd.DATA[0] = 0x23;
    MsgBuffSnd.DATA[1] = 0x09;
    MsgBuffSnd.DATA[2] = 0x20;
    MsgBuffSnd.DATA[3] = 0x07;
    MsgBuffSnd.DATA[4] = 0x16;
    MsgBuffSnd.DATA[5] = 0x00;
    MsgBuffSnd.DATA[6] = 0x00;
    MsgBuffSnd.DATA[7] = 0x00;
    CAN_Write(&MsgBuffSnd);

    DWORD tck = GetTickCount();
    LARGE_INTEGER li1;
    QueryPerformanceCounter(&li1);

    unsigned __int64 I1 = __rdtsc();

WaitAgain:
    DWORD tck2 = 80 - (GetTickCount() - tck);
    if(tck2>80) tck2 = 0;
    
    WaitForSingleObject(hEvent, tck2);
    if(CAN_Read(&MsgBuff) == CAN_ERR_OK)
    {
      if(MsgBuff.ID<=0x80) goto WaitAgain;
     
      unsigned __int64 I2 = __rdtsc();
      LARGE_INTEGER li2;
      QueryPerformanceCounter(&li2);
      tck2 = GetTickCount();
      float f = (1000*(li2.LowPart-li1.LowPart))/(float)pFrequency.LowPart;
      printf("%4X %d[B], time %d[ms], RDTSC time %.2f, Perf timer %.2f[ms]\n", 
          MsgBuff.ID, MsgBuff.LEN, tck2-tck, (float)(I2-I1)/CPU_CLOCK, f);
    }

    tck2 = 100 - (GetTickCount() - tck);
    if(tck2>100) tck2 = 10;
    Sleep(tck2);
    while(CAN_Read(&MsgBuff)==CAN_ERR_OK)
    {		// Get a garbage from a queue.
    }
  }

  CAN_Close();

Code: Select all

 581 8[B], time 32[ms], RDTSC time 38.679809
 581 8[B], time 16[ms], RDTSC time 2.899182
 581 8[B], time 15[ms], RDTSC time 2.934446
 581 8[B], time 0[ms], RDTSC time 2.969755
 581 8[B], time 0[ms], RDTSC time 7.789376
 581 8[B], time 0[ms], RDTSC time 7.831396
    // CAN load increased from here
581 8[B], time 16[ms], RDTSC time 21.51, Perf timer 21.51[ms]
581 8[B], time 16[ms], RDTSC time 15.63, Perf timer 15.63[ms]
581 8[B], time 16[ms], RDTSC time 15.63, Perf timer 15.63[ms]
581 8[B], time 16[ms], RDTSC time 14.72, Perf timer 14.72[ms]
581 8[B], time 0[ms], RDTSC time 7.84, Perf timer 7.84[ms]
581 8[B], time 16[ms], RDTSC time 6.56, Perf timer 6.56[ms]
581 8[B], time 16[ms], RDTSC time 13.61, Perf timer 13.61[ms]
581 8[B], time 16[ms], RDTSC time 15.64, Perf timer 15.64[ms]
581 8[B], time 15[ms], RDTSC time 6.04, Perf timer 6.04[ms]
581 8[B], time 15[ms], RDTSC time 15.64, Perf timer 15.65[ms]
581 8[B], time 16[ms], RDTSC time 13.69, Perf timer 13.69[ms]
581 8[B], time 15[ms], RDTSC time 14.79, Perf timer 14.79[ms]
581 8[B], time 0[ms], RDTSC time 7.02, Perf timer 7.02[ms]
581 8[B], time 16[ms], RDTSC time 13.67, Perf timer 13.67[ms]
581 8[B], time 16[ms], RDTSC time 13.66, Perf timer 13.66[ms]
581 8[B], time 31[ms], RDTSC time 27.35, Perf timer 27.35[ms]
581 8[B], time 32[ms], RDTSC time 18.27, Perf timer 18.27[ms]
581 8[B], time 16[ms], RDTSC time 18.35, Perf timer 18.35[ms]
581 8[B], time 31[ms], RDTSC time 27.32, Perf timer 27.32[ms]
581 8[B], time 16[ms], RDTSC time 18.29, Perf timer 18.29[ms]
581 8[B], time 31[ms], RDTSC time 27.32, Perf timer 27.32[ms]
581 8[B], time 15[ms], RDTSC time 18.32, Perf timer 18.32[ms]
581 8[B], time 15[ms], RDTSC time 19.24, Perf timer 19.24[ms]
581 8[B], time 15[ms], RDTSC time 19.20, Perf timer 19.20[ms]
581 8[B], time 31[ms], RDTSC time 27.32, Perf timer 27.32[ms]
581 8[B], time 16[ms], RDTSC time 17.61, Perf timer 17.61[ms]

When I measure delay 48ms in previous case, I am pretty sure that the real delay is not good for our application. I am doing here only proof of concept. I am aware how to write code to eliminate wrapping timer substraction - but this is only demo snippet. Basically force unsigned arithmetics will do this. 0x01 - 0xFF -> 2 (mod 256).

My real developped application does not measure CAN ping time. It is closed loop control. The only observation is that controlled system become unstable when transport delay increases. I am mainly interested whether PCI or PCIe device will perform signifficantly better or not?

[M.Maidhof]

Hi,

even with a PCI solution, you will measure the same, as long as you will not accept that you are working in a Windows enviroment, and you don't accept our tipps regarding the use of multimedia timer for such purposes.

regards

Michael

[Fojtik]

The time critical section is:

Code: Select all

   CAN_Write(&MsgBuffSnd);       // Message is sent to responder
   WaitForSingleObject(hEvent, tck2);  // Waitinig for message to receive and to be signalled
   CAN_Read(&MsgBuff);                      // Get message from queue.

I has been really used QueryPerformanceCounter() inside my code in the last example as you suggested. It is not sufficient enough? No other multimedia timer would help for this case. Timer ensures only precise event timing.
The responder has no Peak, it is one chip device.

For the final application e.g. the Matlab could be used. I have really experiences with real time toolbox and 1ms timing is attainable even for Windows - tested without Peak before 10years.

[Fojtik]

Only for public:

Code: Select all

D:\...k\CAN_LIB\src\PeakTiming\Release>PeakMonitor.exe -S 1M
 581 8[B], time 94[ms], RDTSC time 85.88, Perf timer 85.87[ms]
 581 8[B], time 0[ms], RDTSC time 0.67, Perf timer 0.67[ms]
 581 8[B], time 0[ms], RDTSC time 0.72, Perf timer 0.73[ms]
 581 8[B], time 0[ms], RDTSC time 0.77, Perf timer 0.77[ms]
 581 8[B], time 0[ms], RDTSC time 0.83, Perf timer 0.83[ms]
 581 8[B], time 0[ms], RDTSC time 0.74, Perf timer 0.74[ms]
 581 8[B], time 15[ms], RDTSC time 0.77, Perf timer 0.77[ms]
 581 8[B], time 0[ms], RDTSC time 0.80, Perf timer 0.83[ms]
 581 8[B], time 0[ms], RDTSC time 0.78, Perf timer 0.78[ms]
 581 8[B], time 0[ms], RDTSC time 0.79, Perf timer 0.79[ms]

even with a PCI solution, you will measure the same .......

The time measured cca 800us is for both sending and receiving. PCIe device seems to be 4x faster than USB when no load. On load the transport delay also deteriorates, but not so dramatically like for USB.
There are several criteria, PCAN-USB apparently can push the traffic, but we are interested in short response cycle.

[M.Maidhof]

Hello,

yes, very good solution to diss other people in a puplic forum! Your own failure in some posts before were deleted by you!

Honestly, it looks like you are a very nice guy! It was a great pleasure to help you!

will be helpfull to know, when you need some more support in the future.

regards

Michael