|
|
|
This thread is locked; no one can reply to it.
|
| Timing Allegro program sometimes... fails... |
|
Chris Katko
Member #1,881
January 2002
 |
I wanted to benchmark blitting various size textures to the screen. Either I ran into an issue with the first method. Since Allegro is using an event structure but is "essentially" single-threaded, I could "fire off" an event that says "one second has passed" but the problem is... how do you TERMINATE an existing job? The job itself would run (say blitting for 1/2 second) and only when that job (a function, really) is finished its for loop, can the event actually be processed. I kept trying to get that to work but failing (perhaps I just have a mental block for the simple solution). So I fell back on the second method. Simply draw 30000 blits of a specific texture size and time it using Linux/bash's time command. But here's the problem, and I'm considering making a StackOverflow post about it but I couldn't find ANYONE with the problem. SOMETIMES, when I run: $ time ./myprogram It'll be 5-10 seconds. Other times with the same program it'll report close to .5 seconds which is FAR lower than it actually is. Almost like it's timing a thread other than the main thread, and that other thread is just idling. Here's the actual output: 1$ time ./speedtest
2
3[init] Start up.
4Maximum texture size reported to Allegro is 8192
5WARNING - Size 16384^2 is a MEMORY BITMAP!
6[init] End.
7[execute] Start up.
8[execute] End.
9[shutdown] Start up.
10[shutdown] End.
11
12real 0m0.919s //<------- WRONG
13user 0m0.544s
14sys 0m0.244s
15
16$ time ./speedtest
17[init] Start up.
18Maximum texture size reported to Allegro is 8192
19WARNING - Size 16384^2 is a MEMORY BITMAP!
20[init] End.
21[execute] Start up.
22[execute] End.
23[shutdown] Start up.
24[shutdown] End.
25
26real 0m20.332s //<-------- Actual
27user 0m0.564s
28sys 0m0.192s
And even then, when I had lower draw call numbers and it was faster, time still felt like it slightly under-reported every time. I would sit there, watch the command that I triggered, and I would feel like it was 5 seconds and it would tell me... ~2.3. And I am NOT that bad at counting seconds. But it's possible I just miscalculated something. What's NOT possible is my program magically goes from 20 seconds ... to .5 seconds. I have tried both bash's "time" ($ time ./myprogram) as well as the (POSIX?) /usr/bin/time . Both report the same values as far as I can tell. My only thought is that Allegro is running multiple threads and time is reporting the wrong one. -----sig: |
|
Peter Hull
Member #1,136
March 2001
|
As I understand it, time measures the process, so the number of threads should not give a false result. Pete
|
|
Edgar Reynaldo
Major Reynaldo
May 2007
 |
al_get_time. Don't know what the implementation is on linux, but it should have resolution on the order of milliseconds at least. My Website! | EAGLE GUI Library Demos | My Deviant Art Gallery | Spiraloid Preview | A4 FontMaker | Skyline! (Missile Defense) Eagle and Allegro 5 binaries | Older Allegro 4 and 5 binaries | Allegro 5 compile guide |
|
Chris Katko
Member #1,881
January 2002
|
I just timed it... on video... with my phone. 11 seconds, yet time reports 1.x seconds. Like it's off by a factor of 10x. Try it yourself! 1// Completely hobbled together code. It wasn't meant to be elegant, just to test some speeds.
2// You'll need the 'common.c' from the Allegro examples folder.
3
4#define ALLEGRO_STATICLINK
5
6#include <iostream>
7
8#include <allegro5/allegro.h>
9#include <allegro5/allegro_font.h>
10#include <allegro5/allegro_image.h>
11#include <allegro5/allegro_color.h>
12#include <allegro5/allegro_primitives.h>
13#include <allegro5/allegro_ttf.h>
14#include <stdio.h>
15#include <stdarg.h>
16#include <math.h>
17
18#include "common.c"
19
20#include <list>
21#include <vector>
22
23namespace g
24 {
25 const int SCREEN_W = 640;
26 const int SCREEN_H = 480;
27
28 ALLEGRO_DISPLAY *display;
29 ALLEGRO_TIMER *timer;
30 ALLEGRO_TIMER *fps_timer;
31 ALLEGRO_EVENT_QUEUE *queue;
32 ALLEGRO_FONT *font;
33 const float LOGIC_FPS = 60;
34
35 //framerate time keeping
36 int frames_passed = 0;
37 int fps = 0;
38
39
40 ALLEGRO_BITMAP *current_screen;
41 ALLEGRO_BITMAP *fake_map;
42 };
43
44using namespace g;
45using namespace std;
46
47//forward declarations
48class map_chunk_t;
49class guessing_algorithm_t;
50
51enum MYKEYS {
52 KEY_UP, KEY_DOWN, KEY_LEFT, KEY_RIGHT,
53 KEY_W, KEY_S, KEY_A, KEY_D, KEY_C, KEY_P
54};
55
56int number_of_draws_per_second = 0;
57int number_of_draws = 0;
58ALLEGRO_BITMAP *test_blit_512;
59ALLEGRO_BITMAP *test_blit_1024;
60ALLEGRO_BITMAP *test_blit_2048;
61ALLEGRO_BITMAP *test_blit_4096;
62ALLEGRO_BITMAP *test_blit_8192;
63ALLEGRO_BITMAP *test_blit_16384;
64
65void run_test(int size, int count)
66 {
67 ALLEGRO_BITMAP *source;
68
69 if(size == 512){source = test_blit_512;}
70 if(size == 1024){source = test_blit_1024;}
71 if(size == 2048){source = test_blit_2048;}
72 if(size == 4096){source = test_blit_4096;}
73 if(size == 8192){source = test_blit_8192;}
74 if(size == 16384){source = test_blit_16384;}
75
76 for(int i = 0; i < count; i++)
77 {
78 al_draw_bitmap(source, rand()%320, rand()%240, 0);
79 number_of_draws++;
80 }
81
82
83 }
84
85int initialize()
86 {
87
88 if (!al_init()) {
89 abort_example("Could not init Allegro.\n");
90 }
91
92 al_install_keyboard();
93 al_install_mouse();
94 al_init_image_addon();
95 al_init_font_addon();
96 al_init_ttf_addon();
97 init_platform_specific();
98
99 g::display = al_create_display(800, 600);
100 if (!g::display) {
101 abort_example("Error creating display\n");
102 }
103
104 timer = al_create_timer(1.0 / g::LOGIC_FPS);
105 fps_timer = al_create_timer(1.0);
106
107 g::queue = al_create_event_queue();
108 al_register_event_source(g::queue, al_get_keyboard_event_source());
109 al_register_event_source(g::queue, al_get_mouse_event_source());
110 al_register_event_source(g::queue, al_get_display_event_source(display));
111 al_register_event_source(g::queue, al_get_timer_event_source(timer));
112 al_register_event_source(g::queue, al_get_timer_event_source(fps_timer));
113
114 al_start_timer(g::timer);
115 al_start_timer(g::fps_timer);
116
117 g::font = al_load_font("DejaVuSans.ttf", 16, 0);
118 if(g::font == NULL)printf("OH SHIT FONT NOT FOUND OR FAILED TO LOAD.\n");
119
120// PNGS and JPEGS are tested to work.
121// fake_map = al_load_bitmap("./maps/SecretofMana_map_gaiasnavel.png");
122 fake_map = al_load_bitmap("./maps/EarthboundMapDustyDunesDesert.png");
123 current_screen = al_create_bitmap(320, 200); //= al_load_bitmap("screen_view.png");
124
125 test_blit_512 = al_create_bitmap(512, 512);
126 test_blit_1024 = al_create_bitmap(1024, 1024);
127 test_blit_2048 = al_create_bitmap(2048, 2048);
128 test_blit_4096 = al_create_bitmap(4096, 4096);
129 test_blit_8192 = al_create_bitmap(8192, 8192);
130 test_blit_16384 = al_create_bitmap(16384, 16384);
131
132
133 int MAX_TEX = al_get_display_option(g::display, ALLEGRO_MAX_BITMAP_SIZE);
134 printf("Maximum texture size reported to Allegro is %i\n", MAX_TEX);
135
136
137 if(test_blit_4096 == NULL){printf("Can't make a 4096x4096 bitmap.\n");}
138 if(test_blit_8192 == NULL){printf("Can't make a 8192x8192 bitmap.\n");}
139 if(test_blit_16384 == NULL){printf("Can't make a 16384x16384 bitmap.\n");}
140
141
142 int x;
143 if((x = al_get_bitmap_flags(test_blit_2048)) & ALLEGRO_MEMORY_BITMAP)
144 {
145 printf("WARNING - Size 2048^2 is a MEMORY BITMAP! \n");
146 }
147 if((x = al_get_bitmap_flags(test_blit_4096)) & ALLEGRO_MEMORY_BITMAP)
148 {
149 printf("WARNING - Size 4096^2 is a MEMORY BITMAP! \n");
150 }
151 if((x = al_get_bitmap_flags(test_blit_8192)) & ALLEGRO_MEMORY_BITMAP)
152 {
153 printf("WARNING - Size 8192^2 is a MEMORY BITMAP! \n");
154 }
155 if((x = al_get_bitmap_flags(test_blit_16384)) & ALLEGRO_MEMORY_BITMAP)
156 {
157 printf("WARNING - Size 16384^2 is a MEMORY BITMAP! \n");
158 }
159
160 return 0;
161 }
162
163void shutdown()
164 {
165 al_destroy_event_queue(g::queue);
166 }
167
168void execute2()
169 {
170 run_test(1024, 30000);
171 }
172
173int main(int argc, char **argv)
174 {
175 cout << "[init] Start up." << endl;
176 initialize();
177 cout << "[init] End." << endl;
178 cout << "[execute] Start up." << endl;
179
180
181 execute2();
182
183
184 cout << "[execute] End." << endl;
185 cout << "[shutdown] Start up." << endl;
186 shutdown();
187 cout << "[shutdown] End." << endl;
188 return 0;
189 }
And the build file--though yours should work fine. For some reason I've always had problems doing it the "proper" way with the package config utility on this laptop. 1clang++ speedtest.cpp -o speedtest -fcolor-diagnostics -O3 \
2-I/usr/local/include/** \
3-I/usr/local/include/allegro5/** \
4-lallegro_monolith-static \
5-lpthread \
6-lGL \
7-lGLU \
8-lXcursor \
9-lXi \
10-lXrandr \
11-lX11 \
12-lXinerama \
13-lz \
14-lpng \
15-ljpeg \
16-lfreetype
FYI, I imagine I can time it other ways like with the internal allegro timer. My question here is because I've only seen it do this with my Allegro program(s) and I couldn't find a SO answer even remotely describing the problem. Perhaps I'll ask on Stack Overflow after all... -----sig: |
|
|
