See, at begining. Probabaly dumping of profile info can wait let's say a second more, so those "ignore calls" will not broke table ?
Also see at top there some W3DN_DrawElements() call noted like if it come from tracing (while only profiling was enabled).
But after that all looks clean, ogles2 profile table also clean, and on very exit it before "Waiting over" words it says :
Shell Process '02.Quake3Map': OGLES2_glActiveTexture: texture 33985 Shell Process '02.Quake3Map': ActiveTexture function pointer is NULL (call ignored).
And then exit. No crash, so all fine.
Through probabaly you right issue was here before, just we didn't face it before because not many ogl functions was added. But now when all of them added probabaly time was in need to be increased.
Also tested "starttime/duration" now again, its indeed good and was worth of adding ! Because if run without it, then in profile log i have a looot of functions for both w3d and ogles2 (i.e. those calls which happens only on begining, before things stabilized). And you may think that there is a lot used, but when you run it with "starttime/duration", then profile logs is much more clear and much better show whole picture of only calls which is used indeed in process.
Also have another suggestion if you doesn't mind (but dunno how good is it and worth or not of adding) : maybe group "agl*" functions as other little table at end of the "gl" ogles2 table ? Because they are amigaos4 specific, and not related to rendering itself mostly. Just as idea of course..
If you run glsnoop in profile mode, and then run gl app, but then firstly close not app, but glsnoop, then in the log we have a lot of words about resotring all w3d functions and ogles2 functinos.
While if we close opengl app first, and then glsnoop, then there is no such massive output about restoring.
Is it possible to hide it also in that case ?
Maybe create some "level" of glsnoop's output, where we can hide glsnoop's internal outputs ? From another side if it already hided when we close opengl app first, then maybe just hide it and in case when glsnoop closed first, without any mambo-jambo with levels, etc ?
Tested new one , all fine now in terms of dumping info : no broken tables, and no tracing logs. Also new verbose=false works now too : if i use profile (with or without starttime/duratin) it is now dump on serial all clean and verbose-logs clean (does not matter if i close glsnoop first, or close gl app first : all fine).
So, thanks !
Are you about to release v0.3 then ? If so i can also update .guide a bit , as well as do some good stress-testing.
ps. the only thing that i notice now, is that when i run glsnoop like just "glsnoop PROFILE", in output it says:
What you think ? And all those 4 states can be taken in matter of what switches are used. If let's say we disable warp3d fully, then it can be "WARP3DNOVA mode: [fully disabled]" , or the same "WARP3DNOVA mode: [tracing: disabled, profiling: disabled]".
Plz check english in. Also have a look at PROFILE description in the "Command-line parameters" tab. I didn't explain 2 tables (as didn't know well what they mean still), and descriptions of other may be in some wonky english :)
- guide fine - filters fine (have all functions from both ogles2 and nova) - gui mode works (icnofication, about, pause/resume of all sorts, exit firstly from glsnoop, exit firstly from gl apps, etc) - can't make it crash (tried hard in different conditions)
OpenGL ES 2.0 profiling results for Background CLI 'reborn-sp':
Function calls used 0.000000 ms, 0.00 % of context life-time 18216.209243 ms
Frames/s 0.0
function | call count | errors | duration (ms) | avg. call dur. (us) | % of 0.000000 ms | % of CPU time
*) Please note that the above time measurements include time spent inside Warp3D Nova functions
Primitive statistics:
Nothing was drawn, vertex count 0
OpenGL ES 2.0 profiling results for Background CLI 'reborn-sp':
Function calls used 0.000000 ms, 0.00 % of context life-time 18257.766977 ms
Frames/s 0.0
function | call count | errors | duration (ms) | avg. call dur. (us) | % of 0.000000 ms | % of CPU time
*) Please note that the above time measurements include time spent inside Warp3D Nova functions
Primitive statistics:
Nothing was drawn, vertex count 0
See, between 2 tables something wrong happens: 2 times empty opengles2 profiling results writen, and only 3st one are correct table, while for warp3dnova 1 time (how it should be).
Second issue, it is small DSI crash. I got that when trying to debug RCTW Reboorn: just enough to run glsnoop (i do test via "glsnoop GUI PROFILE"), and run RCTW Reborn over it, it then will crash with nullpointer's DSI (DAR are 0x00000000). And stack trace point out on glSnoop:
Also have suggestion to add to release archive also glsnoop.debug binary (which is with those gstabs). So those users/devs who can't build it by some reassons from github, can use debug version when things going wrong and have a proper stack traces.
Regarding DSI, I thought that OS4 would have caught zero page writes but does it actually need some magic configuration? Is X5000 kernel different from the others? Need to experiment with debug kernel later.
@Capehill Tested new version : DSI fixed, yeah. But something with profile output notice again : i just run "glsnoop GUI PROFILE", then i just run RTCW Reboorn (no crash, so DSI gone) , play a bit, and exit from. Then close glsnoop.
OpenGL ES 2.0 profiling results for Shell Process 'reborn-sp':
Function calls used 0.000000 ms, 0.00 % of context life-time 110066.450967 ms
Frames/s 0.0
function | call count | errors | duration (ms) | avg. call dur. (us) | % of 0.000000 ms | % of CPU time
*) Please note that the above time measurements include time spent inside Warp3D Nova functions
Primitive statistics:
Nothing was drawn, vertex count 0
OpenGL ES 2.0 profiling results for Shell Process 'reborn-sp':
Function calls used 0.000000 ms, 0.00 % of context life-time 113003.726115 ms
Frames/s 0.0
function | call count | errors | duration (ms) | avg. call dur. (us) | % of 0.000000 ms | % of CPU time
*) Please note that the above time measurements include time spent inside Warp3D Nova functions
Primitive statistics:
Nothing was drawn, vertex count 0
glSnoop: tracing resumed
warp3dnova_free
ogles2_free
ITimer user count 0, dropping it
glSnoop exiting
See, Ogles2 output dumps as first (not as second as all the time), also in the middle between two tables some sort of begining of ogles2 table can be seen, and at end of output again another begining of ogles2 table.
I.e. the same issue as in previous post, just in previous post 2 begining of ogles2 results was in the middle.
Another time i tried to just run "glsnoop PROFILE STARTTIME 15", and on exit it also have in the middle between 2 tables, those ogles2 table-headers.
And i give a go for better test of STARTTIME/DURATION thing, if you doesn't mind there my findings:
1. If i just use "STARTTIME 10" , without "DURATION" , so to want only start after 10 seconds, but to have unlimited duration, i have duration automatically set to "1" second.
Will be imho good, if when you set only "starttime", then duration will be unlimited, as by default when you don't use starttime/duration combo.
2. If i use just "DURATION 10" , without "STARTTIME", so to have 10 seconds record from very begining, then i also can't. Even if i just do "STARTTIME 0 DURATION 10" it also didn't works. The only time when it works when i do "STARTTIME 1 DURATION 10", then it works.
So, in other words, will be good to use STARTTIME and DURATION independent of each others too.
And , both starttime/duration have some cosmetic issue in output:
1. When we run without starttime/duration, we have in output that:
Start time: [0] seconds Duration: [0] seconds
While, "Duration" this time are "unlimited". So in that case will be good to have something like:
Start time: [0] seconds Duration: [unlimited]
2. When we use only "starttime", then will be good to have it like:
Start time: [x] seconds Duration: [unlimited]
3. And when we use only "duration" , then:
Start time: [0] seconds Duration: [x] seconds
But that already the case, so only first and second cases can be adapter for output.
Edited by kas1e on 2019/10/2 4:47:12 Edited by kas1e on 2019/10/2 5:04:13
@Capehill I am mostly about Nova apps which not under our control and to which we have no sources, but that not big deal anyway, Drawcalls/s is fine to to compare.
If you see the strange profiling output tables only with a certain application, then maybe it got IOGLES2 twice. Duplicate patching could prove this theory, so you could make the logging verbose ( https://github.com/capehill/glsnoop/blob/master/logger.c#L9 ) and collect traces.
@Capehill You are right. Tested with verbose on , and find out that it doing patching for ogles2 2 times.
And i think i know the reassons why it happens in RTCW_Reboorn: probabaly Huno for sake of being safe, open ogles2.library from RTCW code too (while, ogles2.library opens from the gl4es , and there no needs to open it from the code).
So we have 2 times opening of ogles2.library , so 2 times patching , and then have that empty table.
Then there is come question : is it possible to disallow 2 (or more) times patching for single app ? Or there will be problem with choicing the "right" one to patch ? (probably last one will be the "right one" all the time ?).
Anyway that mostly theoretical question , as its probabaly have no needs to make workarouds for apps which want to open ogles2.library many times for now reassons :)
RTCW should be fixed. I will see what I can do to improve glSnoop logging but in my opinion it is working correctly and pointing out some issue in a real app ;)