Measuring render time.

If you have any questions on programming, this is the place to ask them, whether you're a newbie or an experienced programmer. Discussion on programming in general is also welcome. We will help you with programming homework, but we will not do your work for you! Any porting requests must be made in Developmental Ideas.
Post Reply
Jae686
Insane DCEmu
Insane DCEmu
Posts: 112
https://www.artistsworkshop.eu/meble-kuchenne-na-wymiar-warszawa-gdzie-zamowic/
Joined: Sat Sep 22, 2007 9:43 pm
Location: Braga - Portugal
Has thanked: 0
Been thanked: 0

Measuring render time.

Post by Jae686 »

Good morning.

I've been trying to measure the time I take to render each frame on KOS, but sometimes I get odd results such as the start time being bigger than the end time, when using the timer_ms_gettime(); function.

My render look is written as follows :

Code: Select all

void new_draw(pDemoAssetList a)
{
    // measures the time it took to render in order to keep the animation time dependent instead of frame rate dependent.
    // the scene descriptor WILL get modified during the demo execution
    

    // delete ?
    struct timespec start; 
    struct timespec end;
    struct timespec elapsed;

    struct timeval start_val;
    struct timeval end_val;

    //
    //double elapsed_val;

    uint32 elapsed_time;

    uint32 ms_start;
    uint32 ms_end;
    uint32 ms_elapsed ;


    uint32 s_start;
    uint32 s_end;
    uint32 s_elapsed ;


    timer_ms_gettime(&s_start, &ms_start);

   // clock_gettime(CLOCK_REALTIME, &start);

    //gettimeofday(&start_val, NULL);
    //clock_t start = clock();

    unsigned long total_render_time_ms ;
    pDemoAssetList iter ;
    p3DModelList m;
    pTextureList t;
    pSceneDescription d;
    pCameraList c ;

    pmesh curr_model ;
    int curr_texture ;
    int curr_texture_pos ;

    iter = a ;

    m = iter->m ; // model list
    t = iter->t ; // texture list
    d = iter->d ; // scene descriptor
    c = iter->c ; // camera descriptor

    float curr_transf = 0.0 ;
    
    
    while(isCameraInTime(c, iter->milisec_elapsed) == 0)
    {
        c = c->next ; // seeks the camera in the current time frame
        
    }

    gluLookAt( c->start_pos.x,
               c->start_pos.y,
               c->start_pos.z,
               c->start_looking_direction.x,
               c->start_looking_direction.y,
               c->start_looking_direction.z,
               0.0,
               1.0,
               0.0 );

    while (d != NULL) // goes trough all the meshes on the asset list
    {
        
    glPushMatrix();
    

    glKosBeginFrame();

    if(d->render_effects & DRAW_WIREFRAME)
    {
       // glPolygonMode(GL_FRONT_AND_BACK, GL_LINE);
    }

    if(d->render_effects & DRAW_FLAT)
    {
        //glPolygonMode(GL_FRONT_AND_BACK, GL_FILL);
    }

    glRotatef(d->angle, d->rotation.x, d->rotation.y, d->rotation.z );
    glTranslatef(d->pos.x, d->pos.y, d->pos.z);
    glScalef(d->scale.x, d->scale.y , d->scale.z );
    //glRotatef(d->angle, d->rotation.x, d->rotation.y, d->rotation.z );
    curr_texture_pos = getTexturePos(t, d->texture_name);
    printf("texture_pos : %d \ntexture name : %s" , curr_texture_pos, d->texture_name);
    curr_texture = retrieveTextureHandle(t, curr_texture_pos);
    //printf("texture handle %d\n", curr_texture); 
    glBindTexture(GL_TEXTURE_2D, curr_texture);

    curr_model = retrieveMesh (m, getMeshPos(m, d->mesh_name));
    printf("mesh name \t %s\n" , d->mesh_name);
   
    

    draw_p(curr_model) ;
    //glKosFinishList();


    glPopMatrix();

    d = d -> next ; // goes to the next element

    }

    //printf("all meshes drawn\n");

    glKosFinishFrame();


    //clock_gettime(CLOCK_REALTIME, &end);
    timer_ms_gettime(&s_end, &ms_end);

    elapsed_time = diff_msec(ms_start, ms_end);
    
    
    
    
    //printf("elapsed_t : %d ns \n", iter->milisec_elapsed);

    
    iter->milisec_elapsed += elapsed_time;
    printf("elapsed : %u ms \nstart : %u\nend : %u\n", elapsed_time, ms_start, ms_end );
    printf("elapsed  TOTAL: %u ms \n", iter->milisec_elapsed );
    CameraListPosUpdate(iter->c, (iter->milisec_elapsed));

}


void demo_render(pDemoAssetList a)
{
    while(1)
    {
        new_draw(a);
    }
}

And I'm measuring the time elapsed using :

Code: Select all

inline unsigned long diff_msec(uint32 start,uint32 end)
{
    if(end > start)
    {
        return (end - start);    
    }
    else
    {
        return (start - end);
    }
    
}
User avatar
BlueCrab
The Crabby Overlord
The Crabby Overlord
Posts: 5652
Joined: Mon May 27, 2002 11:31 am
Location: Sailing the Skies of Arcadia
Has thanked: 9 times
Been thanked: 69 times
Contact:

Re: Measuring render time.

Post by BlueCrab »

You probably want to use the timer_ms_gettime64() function, which combines the number of seconds and milliseconds into one value. The way you're doing things, you're losing part of the value because you're ignoring the seconds value. If you want to continue using timer_ms_gettime(), make sure to add the number of seconds * 1000 to your milliseconds value, then you won't have such wonky results (of course, that's basically what the timer_ms_gettime64() function does, in the end).
Jae686
Insane DCEmu
Insane DCEmu
Posts: 112
Joined: Sat Sep 22, 2007 9:43 pm
Location: Braga - Portugal
Has thanked: 0
Been thanked: 0

Re: Measuring render time.

Post by Jae686 »

Thank you Bluecbrab, it worked :)

I dont recall reading about that function on KOS.pdf file. :)
User avatar
BlueCrab
The Crabby Overlord
The Crabby Overlord
Posts: 5652
Joined: Mon May 27, 2002 11:31 am
Location: Sailing the Skies of Arcadia
Has thanked: 9 times
Been thanked: 69 times
Contact:

Re: Measuring render time.

Post by BlueCrab »

PDF‽ I have a feeling you're looking at some REALLY outdated documentation, unless you generated it yourself from the KOS source code. You might want to take a look here for much more up-to-date documentation (that link is for v2.0.0, if you want the current version that has been following the Git repository, check here instead).
Jae686
Insane DCEmu
Insane DCEmu
Posts: 112
Joined: Sat Sep 22, 2007 9:43 pm
Location: Braga - Portugal
Has thanked: 0
Been thanked: 0

Re: Measuring render time.

Post by Jae686 »

Sorry for dig up an old thread, but how I measure the render time on the new gl API ?

I believe that it was explained somewhere on this forum, but I'm unable to find this information.

Best Regards.
User avatar
bogglez
Moderator
Moderator
Posts: 578
Joined: Sun Apr 20, 2014 9:45 am
Has thanked: 0
Been thanked: 0

Re: Measuring render time.

Post by bogglez »

What is it you want to profile? The GL libraries are synchronous and run on the same thread, so you should be able to just time each function.
If you architect your code in such a way that the drawing code is separate from stuff such as physics you should be able to just get the time before glClear() and before glutSwapBuffers (glutSwapBuffers will wait for vsync, so profiling it is not that useful)
Wiki & tutorials: http://dcemulation.org/?title=Development
Wiki feedback: viewtopic.php?f=29&t=103940
My libgl playground (not for production): https://bitbucket.org/bogglez/libgl15
My lxdream fork (with small fixes): https://bitbucket.org/bogglez/lxdream
User avatar
PH3NOM
DC Developer
DC Developer
Posts: 576
Joined: Fri Jun 18, 2010 9:29 pm
Has thanked: 0
Been thanked: 5 times

Re: Measuring render time.

Post by PH3NOM »

As bogglez mentioned, it should be pretty straight forward.

The only thing to consider is that all functions in the API besides glutSwapBuffers operate on the SH4 CPU and main RAM.
glutSwapBuffers handles all GPU interactions, meaning waiting for a vsync, and then actually transfer all vertex data from SH4 RAM to the PVR.

This fact means that we can effectively measure CPU time and GPU time independently.
Post Reply