Strange deviations in effective framerate

[void]

So, this is something I've observed off and on in a few of my prototype projects, but I always assumed it was something I was doing wrong with my logic.

When I was recently working on a project where I was trying to measure performance of something else while displaying visuals, I realized something strange is going on.

After about ten seconds of execution, there is a noticable drop in the rate of certain kinds of graphics operations.

In this case, I'm drawing a lot of filled circles on the screen, switching buffers ten times a second. For the first ten seconds my machine manages ~4300 circles per 100ms frame, thereafter only managing around 2700 circles per frame. (This is without debug enabled, although the behavior is present and similar with debug enabled albeit with smaller counts)

I'm able to replicate this result whether or not I have #PB_Screen_NoSynchronization set for the window, and regardless of the timestep I use per frame (every 100ms, every 500ms, every 1000ms).

Strangely, this does NOT occur with lineXY(), but it does occur with box() (the below commented-out instruction for boxes goes about 76 per 100ms frame for the first 10 seconds, then about 44 per 100ms frame thereafter.

If I change which graphics operation I am performing after 10 seconds, I get results commensurate with just using that operation only from start to past 10 seconds. If I switch from boxes or circles for ~11-12 seconds to lines, lines perform just as normal with no apparent slowdown.

This particular set of tests was done on windows PB5 x86 (final), but in the past I've seen it on windows PB 4.x x64.

Can anyone help me track this down?

Code: Select all

OpenWindow(0,50,50,640,480,"test")
InitSprite()
InitKeyboard()
OpenWindowedScreen(WindowID(0),0,0,640,480,0,0,0)

starttime.i=ElapsedMilliseconds()
time = starttime
circlecount = 0
totalcount = 0
framecount = 0
Repeat 
  Gosub processevents
  
  oldtime = time
  circlecount = 0
  FlipBuffers()
  framecount + 1
  ClearScreen(0)
  
  StartDrawing(ScreenOutput())
  Repeat  
  time = ElapsedMilliseconds() - starttime
  
  Circle(400, 400, 5)
  ;LineXY(0, 400, 400, 0)
  ;Box(0,0, 400, 400)

;  If time - startime < 12000
;    Box(0,0, 400, 400)
;  Else
;  LineXY(0, 400, 400, 0)
;    Circle(400, 400, 5)
;  EndIf

  circlecount + 1
  totalcount + 1
  ExamineKeyboard()
  If KeyboardPushed(#PB_Key_Escape)
    exit = 1
  EndIf
  
  Until time > oldtime + 100 Or exit
  DrawText(0,0,Str(time) + " : " + Str(circlecount) + " , " + Str(totalcount) + " ( " + Str(framecount)+")")
  StopDrawing()
  
  ExamineKeyboard()
  If KeyboardPushed(#PB_Key_Escape)
    exit = 1
  EndIf
  
Until exit ; time >= 3.5 Or 

Repeat
  
  ExamineKeyboard()
  
Until KeyboardPushed(#PB_Key_Escape) Or exit

End

processevents:
  Event = WindowEvent() 
  Select Event
    Case #PB_Event_CloseWindow
      exit = 1
  EndSelect
Return

[infratec]

Hi,

since your code was not working, I modified it a bit:

Code: Select all

InitSprite()
InitKeyboard()

OpenWindow(0,50,50,640,480,"test")
OpenWindowedScreen(WindowID(0),0,0,640,480,0,0,0)

starttime.i = ElapsedMilliseconds()
time = starttime
circlecount = 0
totalcount = 0
framecount = 0
oldtime = 0

Repeat
  
  If WindowEvent() = #PB_Event_CloseWindow : exit = 1 : EndIf
  
  circlecount = 0
  framecount + 1
  ClearScreen(0)
 
  StartDrawing(ScreenOutput())
  Repeat 
    time = ElapsedMilliseconds() - starttime
    
    Circle(400, 400, 5, $FFFFFF)

    circlecount + 1
    Totalcount + 1
    ExamineKeyboard()
    If KeyboardPushed(#PB_Key_Escape) : exit = 1 : EndIf
  Until time > oldtime + 100 Or exit
  oldtime = time
  
  DrawText(0, 0, Str(time) + " : " + Str(circlecount) + " , " + Str(totalcount) + " (" + Str(framecount) + ")")
  StopDrawing()
  
  FlipBuffers()
 
Until exit

It runs without any problems.

PB 5.00 WinXP 32

Bernd

[void]

It runs without any problems.

PB 5.00 WinXP 32

Bernd

If by "runs without any problems" you mean "does not crash or produce unexpected visual effects", then yes.

Unfortunately, neither of those were the problem I was experiencing; your version of the code still has the exact same behavior on my computer, which is a significant drop in throughput on graphics operations after approximately ten seconds.

[IdeasVacuum]

void, your code literally does nothing on my PC (WinXP 32bit, PB5 final). It just hangs until escaped.

infratec's code works fine, but what is need of course is some output that compares the first 10 seconds of drawing with the next 10 seconds worth.

[void]

void, your code literally does nothing on my PC (WinXP 32bit, PB5 final). It just hangs until escaped.

I'm not sure how that can be. I just C&P'd what I posted back into PB, and it runs exactly as it did on my machine, and performs the same as what infratec posted.

infratec's code works fine, but what is need of course is some output that compares the first 10 seconds of drawing with the next 10 seconds worth.

I'm sorry, I didn't make this clear. the row of numbers at the top is: the number of milliseconds since program start, the number of drawing operations completed in the previous frame, the number of drawing operations completed so far, and the number of frames completed so far.

The second number drastically drops for me after about ten seconds, on both my version of the code posted and infratec's version. This happens with circle() and box(), but not with lineXY().

[IdeasVacuum]

Ah, seeing the light now

OK, tried your code again, same issue, nothing drawn.

The next bit of interest though is that the output from infratec's version is too fast to discern the slightest slow-down.

Now infratec and I are both testing on WinXP 32bit. You haven't actually stated what your Windows version is. If it's Vista, then the issue could be Windows itself.

[BasicallyPure]

Confirmed code from first post does not run on Windows 7 (x64).
If you move this line:

Code: Select all

oldtime = time

after the counting loop then it runs.
Also, notice how I changed your processevents subroutine.
It is imoprtant to remove 'all' events from the event queue before you return.

Code: Select all

OpenWindow(0,50,50,640,480,"test")
InitSprite()
InitKeyboard()
OpenWindowedScreen(WindowID(0),0,0,640,480,0,0,0)

starttime.i=ElapsedMilliseconds()
time = starttime
circlecount = 0
totalcount = 0
framecount = 0
Repeat 
   Gosub processevents
   
   circlecount = 0
   FlipBuffers()
   framecount + 1
   ClearScreen(0)
   
   StartDrawing(ScreenOutput())
   Repeat  
      time = ElapsedMilliseconds() - starttime
      
      Circle(400, 400, 5)
      ;LineXY(0, 400, 400, 0)
      ;Box(0,0, 400, 400)
      
      ;  If time - startime < 12000
      ;    Box(0,0, 400, 400)
      ;  Else
      ;  LineXY(0, 400, 400, 0)
      ;    Circle(400, 400, 5)
      ;  EndIf
      
      circlecount + 1
      totalcount + 1
      ExamineKeyboard()
      If KeyboardPushed(#PB_Key_Escape)
         exit = 1
      EndIf
      
   Until time > oldtime + 100 Or exit
   
   oldtime = time
   
   DrawText(0,0,Str(time) + " : " + Str(circlecount) + " , " + Str(totalcount) + " ( " + Str(framecount)+")")
   StopDrawing()
   
   ExamineKeyboard()
   If KeyboardPushed(#PB_Key_Escape)
      exit = 1
   EndIf
   
Until exit ; time >= 3.5 Or 

Repeat
   
   ExamineKeyboard()
   
Until KeyboardPushed(#PB_Key_Escape) Or exit

End

processevents:
Repeat
   Event = WindowEvent() 
   If Event = #PB_Event_CloseWindow
      exit = 1
   EndIf
Until Event = #False ; it is important to process 'ALL' events
Return

I detect no slowdown as the program continues to run on my system.

Here is a shorter and a little faster version:

Code: Select all

InitSprite()
InitKeyboard()

OpenWindow(0,50,150,640,480,"test")
OpenWindowedScreen(WindowID(0),0,0,640,480,0,0,0)

Repeat
   
   ExamineKeyboard()
   If KeyboardPushed(#PB_Key_Escape)
      exit = 1
   EndIf
   
   Repeat ; process all events until queue is empty
      Event = WindowEvent()
      If Event = #PB_Event_CloseWindow
         exit = 1
      EndIf
   Until Event = #False
   
   circlecount = 0
   
   ClearScreen(0)
   StartDrawing(ScreenOutput())
   
   stopTime = ElapsedMilliseconds() + 100
   
   Repeat
      Circle(Random(639), Random(449)+30, 5)
      circlecount + 1
   Until ElapsedMilliseconds() > stopTime
   
   DrawText(0, 0, Str(circlecount))
   
   StopDrawing()
   FlipBuffers()
   
Until exit

[void]

Okay. I'm running on windows 7, 64-bit.

I never tried my original post in PB 5 x64, because when I encountered the performance quirk I had been working on a 32-bit project (dealing with a 32bit external library that I haven't produced a 64-bit version yet).

When I try it in PB 5 x64, I see the issue reported that it doesn't work. Mysteriously, it /still/ works for me in PB 5 x86. I don't understand why it would work for me in PB x86 but not the others in PB x86 or for anyone in PB x64, but it's completely tangential to my actual issue anyway.

Both of BasicallyPure's postings continue to exhibit the same results in both PB 5 x86 and PB 5 x64 on my machine, so it's not clearing the event queue per frame that's the problem (and I just checked my original project where I very first encountered the issue, and it is clearing the queue; I just forgot for this quickly assembled test case).

I'm at a loss as to how to narrow down what's actually happening here, but first I need to demonstrate what I'm seeing to everyone else.

I know benchmarks in debug mode are not to be relied on heavily, but the behavior I perceive exists in both debug and non-debug mode in roughly the same timeframe. So using BasicallyPure's smaller modification of my original post, I added this line after the StopDrawing() call:

Code: Select all

  Debug StrD(time / 1000,1) + " : " + Str(circlecount)

Most of the output is uninteresting, until I hit this point:

Code: Select all

9.8 : 3615
10.0 : 3863
10.1 : 3688
10.2 : 3830
10.3 : 3671
10.4 : 2751
10.5 : 2593
10.6 : 2423
10.7 : 2575
10.8 : 2464
10.9 : 2600
11.0 : 2523

This is my sharp reduction in throughput. All data points before 10.3 are over 3500. All data points after 10.3 are below 2800.

With boxes instead of circles, the transition point seems to be 10.9 instead of 10.3.

(this pair of tests was run on PB 5 x64)

[infratec]

Hi,

I tested now my code on a Win7 64 with PB 5.00 32:

No slowdown.

Bernd

[djes]

Given that code

Code: Select all

InitSprite()
InitKeyboard()

OpenWindow(0,50,150,640,480,"test")
OpenWindowedScreen(WindowID(0),0,0,640,480,0,0,0)

starttime = ElapsedMilliseconds()

Repeat
   
   ExamineKeyboard()
   If KeyboardPushed(#PB_Key_Escape)
      exit = 1
   EndIf
   
   Repeat ; process all events until queue is empty
      Event = WindowEvent()
      If Event = #PB_Event_CloseWindow
         exit = 1
      EndIf
   Until Event = #False
   
   circlecount = 0
   
   ClearScreen(0)
   StartDrawing(ScreenOutput())
   
   stopTime = ElapsedMilliseconds() - starttime + 100
   
   Repeat
      time = ElapsedMilliseconds() - starttime
      Circle(Random(639), Random(449)+30, 5, Random($ffffff))
      circlecount + 1
   Until time > stopTime
   
   DrawText(0, 0, Str(circlecount))
   
   StopDrawing()
   Debug StrD(time / 1000,1) + " : " + Str(circlecount)
   FlipBuffers()
   
Until exit

No slowdown on XP-SP3. Please note that for me OpenGL is -a lot- faster than DirectX.

[buddymatkona]

Win 7 PB64 using OpenGL Circle Count = 200,000 with no slowdowns over time.

Win 7 PB64 using DirectX

• Start Circle Count = 3700
  + 9 Sec 2600
  + 16 Sec 2250
  + 22 Sec 1250

Like void, I wish I understood the DirectX slowdowns over time.

[void]

It never occurred to me to try opengl. That's very interesting.

Once I tried opengl, I got results similar to (but lower volume) to buddymatkona, no visible slowdowns.

[Zach]

Could this be related to GPU settings on your machine, perhaps?

I think that's another thing that needs to be explored.. In addition to operating system, you should know what everyone who is testing, is using for hardware.

[void]

I'm not sure what kind of "GPU settings" might be relevant for regular 2D drawing like we're looking at here. What all hardware steps actually go into the 2d-only startdrawing() .. stopdrawing() .. flipbuffers() cyle, anyway? How do they differ between openGL and DirectX, in the PureBasic implementation side of things?

But as far as hardware, I'm using an Nvidia Geforce GTX 560. I suppose I /could/ try some different driver versions, but I'd be really surprised if that'd have a tangible effect on the behavior I'm witnessing here.

[buddymatkona]

The numbers I reported also involved Nvidia Geforce GTX 560. The Nvidia driver signed by Microsoft was Version 9.18.13.697, 02-Oct-12.
When I repeated the test on a Win 7/64 PC using an ATI Radeon card, there were no slowdowns. Maybe Nvidia owes void and me a driver fix.