In my introductory post about OpenGL programming in Python 3 we had no specific debugging or logging facilities enabled at all. The best we could then hope for was a raised exception. Maybe you even moved forward to this post to debug the first example.

Overview

We will discuss logging and debugging OpenGL here without any tools in addition to the original example file. So we will take a look at what the OpenGL subsystem itself and PyOpenGL have to offer us.

Debugging / Error Handling

All calls to the GL functions through PyOpenGL will raise an exception if an error occurs like explained in the relevant PyOpenGL documentation. However there are also some pitfalls. You could for example have a syntax error in the shader source, like a missing semicolon:

    ..

    vertexShaderProgramm = """#version 100
        in vec2 position // <- missing semicolon
        void main() {

    ..

This would not cause glCompileShader to raise an error. Instead the call to glUseProgram itself will fail like this:

OpenGL.error.GLError: GLError(
    err = 1282,
    description = b'invalid operation',
    baseOperation = glUseProgram,
    cArguments = (3,)
)

So you see there is some need to check for errors yourself occasionally. For this there are several OpenGL functions, that we will look into. Here for this specific error glGetShaderiv is the most interesting. If you have actually tried it fix the error again (i.e. add the semicolon). Also don't forget how easy it is to drop to the interactive python debugger prompt. Just put the following in your code at some point you wish to start debugging:

import pdb; pdb.set_trace()

I often fall back into the habit of throwing print calls around when something goes wrong and nobody is looking. So this also serves as a friendly reminder to myself to use the proper tool for the job :).

General Logging

Even if our program runs just fine we should keep an eye on what information the OpenGL subsystem offers us. These calls should be helpful:

Points 3 and 4 are more advanced and will not be covered here yet. As I understand it the output can vary depending on the vendor and the implementation of the OpenGL driver. Furthermore logs might be minimal in a non-debug context and much more extensive in a debug context. So keep in mind that we may have to switch our program to a special debug context to get detailed debug output.

Debug Code

We will now extend the code from my first example. The code can be downloaded here example1.py. The full blog post is here. Remember to activate your virtualenv.

Checking Shader Compilation

To check if the shaders compile fine we replace the following old code

    ..

    GL.glCompileShader(vertexShader)

    ..

with this:

    ..

    GL.glCompileShader(vertexShader)
    compilestatus = GL.glGetShaderiv(vertexShader, GL.GL_COMPILE_STATUS)
    if compilestatus != GL.GL_TRUE:
        raise RuntimeError(GL.glGetShaderInfoLog(vertexShader)
                           .decode('ASCII'))

    ..

There are convenience functions for this in PyOpenGL, namely compileShader and compileProgram (OpenGL.GL.shaders) but since they are not standard OpenGL and have some pitfalls of their own we will stick to this plain error checking version for now.

If we now introduce a bug into the shader source like already mentioned above

    ..

        in vec2 position // <- missing semicolon

    ..

The compilation will fail with a nice error like this:

..

RuntimeError: Vertex shader failed to compile with the following errors:
ERROR: 0:3: error(#132) Syntax error: "void" parse error
ERROR: error(#273) 1 compilation errors.  No code generated

It even says us that line 3 of our shader source generates the error. Which is exactly what happens when you forget the semicolon in the line before. Fix the error (i.e. add the semicolon) now. Also implement the same functionality for the fragment shader like this:

    ..

    GL.glCompileShader(fragmentShader)
    compilestatus = GL.glGetShaderiv(fragmentShader, GL.GL_COMPILE_STATUS)
    if compilestatus != GL.GL_TRUE:
        raise RuntimeError(GL.glGetShaderInfoLog(fragmentShader)
                           .decode('ASCII'))

    ..

Checking Shader Program Linking

Now that our shader sources compile fine we need to move on to the linking step and make sure nothing fails there. At this point in time it might be prudent to think of your shaders as object files, just like you would have ".o" files when dealing with C.

How can the linking step fail? I suppose there are more possible errors, but at this time two important ones come to mind.

The pipeline is incomplete (for example a fragment shader is attached but no vertex shader)
An attached shader has no main() function

The first point is quite clear. Without a vertex shader there is no way for the OpenGL subsystem to know where your vertex data will come from and how it is formatted.

The second point seems also obvious because just like in a C program the main() function defines the entry point of a program. Without it you cannot compile an executable. Each type of shader added to the pipeline needs to have one main() function.

For some other error condition examples see glLinkProgram.

Note: It is possible to have more than one shader of the same type in one program but just one main() function per shader type. This is interesting because you can split your shaders into several functions. The one shader with the main() function then just calls the others. This way you could for example split up the fragment shader in one part, that does the lighting and another part that does the material and so forth.

Let's simulate a linking error as well. Change the vertex shader source like this:

    ..

    in vec2 position;
    void notthemainfunction() {
        gl_Position = vec4(position, 0.0, 1.0);

    ..

Run the program and it should fail with a raised GLError. It is not very helpful so we add some error checking to the linking step.

Replace the old code:

    ..

    # link the program and activate it
    GL.glLinkProgram(shaderProgram)

    ..

with this:

    ..

    # link the program
    GL.glLinkProgram(shaderProgram)
    linkstatus = GL.glGetProgramiv(shaderProgram, GL.GL_LINK_STATUS)
    if linkstatus != GL.GL_TRUE:
        raise RuntimeError(GL.glGetProgramInfoLog(shaderProgram)
                           .decode('ASCII'))
    # validate program
    GL.glValidateProgram(shaderProgram)
    validatestatus = GL.glGetProgramiv(shaderProgram, GL.GL_VALIDATE_STATUS)
    if validatestatus != GL.GL_TRUE:
        raise RuntimeError(GL.glGetProgramInfoLog(shaderProgram)
                           .decode('ASCII'))
    # activate the program

    ..

Now run our broken program again and you should get a much more helpful error message like this:

    ..

    RuntimeError: Vertex shader(s) failed to link, fragment shader(s) failed to link.
    Vertex link error: INVALID_OPERATION.
    ERROR: error(#97) No program main found
    fragment link error: INVALID_OPERATION.
    ERROR: error(#97) No program main found

You can see this is a lot more helpful. The exact output however is dependent on the implementation in the OpenGL driver. Fix the error by resetting notthemainfunction to main.

Our program is already getting a bit convoluted. But for the sake of expressiveness we will leave it like this for now. It will be factored out in a later tutorial.

Logging Facilities

Now that we hopefully have found all the bugs that may have kept our program from running we can move on to logging what else is happening in our program. Maybe the OpenGL subsystem has some interesting hints to offer us.

General Tip

First of all a feature specific to PyOpenGL can be helpful. Switch on full logging by changing your imports like this:

..

import OpenGL
OpenGL.FULL_LOGGING = True

from OpenGL import GL

..

Debug Message Log

Another way to get some more logging especially for debug purposes is to use the OpenGL functions directly. The aforementioned glGetDebugMessageLog comes to mind. This did however not go well in my case. It first seemed the function was not there at all. But something was definitively there when I checked like this:

glxinfo | grep -i debug
GL_AMDX_debug_output, GL_AMDX_vertex_shader_tessellator, 
GL_AMD_conservative_depth, GL_AMD_debug_output,

The debug_output extension seems to implement the functions we are looking for. It is part of the OpenGL 4.3 core profile or available as an extension. Be sure your driver supports it if you want the following code to work.

Logging Code

We will define us a nice get_debug_output function so that we can possibly scatter it across this and future programs with great ease.

New Imports

At first we update our imports.

from OpenGL import GL, constant
from OpenGL.GL.ARB import debug_output

from OpenGL.extensions import alternate

debug_output is the extension we want. The glGetDebugMessageLog function may be available under different names so we have the little alternate helper select the first one.

glGetDebugMessageLog = alternate(
    'glGetDebugMessageLog', GL.glGetDebugMessageLog,
    debug_output.glGetDebugMessageLogARB)

Some Trickery

Unfortunately the return value sizes for some glGet tokens seem not to be available yet. So we manually add them to the GL_GET_SIZES dictionary.

# the size specifications of some debug_output tokens seem to be missing so
# we add them manually even though it does not seem to be a nice way to do it
GL.glget.GL_GET_SIZES[debug_output.GL_MAX_DEBUG_MESSAGE_LENGTH_ARB] = (1,)
GL.glget.GL_GET_SIZES[debug_output.GL_DEBUG_LOGGED_MESSAGES_ARB] = (1,)

If you don't do this the calls to glGetInteger further below will fail inside the PyOpenGL library.

Values to Constant Names

After some experimentation I came up with a little helper, that we will need further below to translate integer token values like 0x9146 back to their human readable string representation like DEBUG_SEVERITY_HIGH_ARB.

def get_constant(value, namespace):
    """Get symbolic constant.

    value - the (integer) token value to look for
    namespace - the module object to search in

    """

    for var in dir(namespace):
        attr = getattr(namespace, var)
        if isinstance(attr, constant.Constant) and attr == value:
            return var
    return value

It is just a little helper and does not to anything really OpenGL specific.

Getting the Log

Next we move on to actually retrieving and formatting the debug log.

def get_debug_output():
    """Get the contents of the OpenGL debug log as a string."""

    # details for the available log messages
    msgmaxlen = GL.glGetInteger(debug_output.GL_MAX_DEBUG_MESSAGE_LENGTH_ARB)
    msgcount = GL.glGetInteger(debug_output.GL_DEBUG_LOGGED_MESSAGES_ARB)

    # ctypes arrays to receive the log data
    msgsources = (ctypes.c_uint32 * msgcount)()
    msgtypes = (ctypes.c_uint32 * msgcount)()
    msgids = (ctypes.c_uint32 * msgcount)()
    msgseverities = (ctypes.c_uint32 * msgcount)()
    msglengths = (ctypes.c_uint32 * msgcount)()
    msglog = (ctypes.c_char * (msgmaxlen * msgcount))()

    glGetDebugMessageLog(msgcount, msgmaxlen, msgsources, msgtypes, msgids,
                         msgseverities, msglengths, msglog)

    offset = 0
    logdata = zip(msgsources, msgtypes, msgids, msgseverities, msglengths)
    for msgsource, msgtype, msgid, msgseverity, msglen in logdata:
        msgtext = msglog.raw[offset:offset + msglen].decode("ASCII")
        offset += msglen
        msgsource = get_constant(msgsource, debug_output)
        msgtype = get_constant(msgtype, debug_output)
        msgseverity = get_constant(msgseverity, debug_output)
        return("SOURCE: {0}\nTYPE: {1}\nID: {2}\nSEVERITY: {3}\n"
               "MESSAGE: {4}".format(msgsource, msgtype, msgid,
               msgseverity, msgtext))
    return ""

You can see it is divided into four logical parts.

check for the number of available message and the maximum possible length per message in bytes
prepare ctypes arrays to receive the log data
get the log data
format the log data nicely

There is quite a bit going on here but it should be pretty self explanatory.

Activating the Debug Context in SDL

The debug log will not work in a regular OpenGL context. So we have to instruct the provider of our context - the SDL library - to make it a debug context.

..

sdl2.SDL_GL_SetAttribute(sdl2.SDL_GL_CONTEXT_FLAGS,
                         sdl2.SDL_GL_CONTEXT_DEBUG_FLAG)

window = sdl2.SDL_CreateWindow(

..

Calling for the Debug Log

Finally we need to ask for the debug log at some point. Right before we activate our shader program seems as good a place as any.

..

# print the current debug log
print(get_debug_output())

# activate the program
GL.glUseProgram(shaderProgram)

..

You can drop this print(get_debug_output()) pretty much anywhere you like. Alright. Seems we are good to go now.

No Error?

If you run the program now - well, nothing has changed. Hopefully. There are simply no errors to list. That should be good news but now we want to see some errors. It is not that easy to come up with a simple error to test this whole program that is not already covered. One simple test would be to mess with the shader source again. Remove the semicolon just like at the beginning of this post.

    ..

    vertexShaderProgramm = """#version 100
        in vec2 position // <- missing semicolon
        void main() {

    ..

Because our compilestatus test will already catch this error we move the request to print the debug log right before it like this:

    ..

    GL.glCompileShader(vertexShader)

    # print the current debug log
    print(get_debug_output())

    compilestatus = GL.glGetShaderiv(vertexShader, GL.GL_COMPILE_STATUS)

    ..

If you run the program now you should get something like the following output right before the traceback from the raised exception:

TYPE: GL_DEBUG_TYPE_ERROR_ARB
ID: 2000
SEVERITY: GL_DEBUG_SEVERITY_HIGH_ARB
MESSAGE: glCompileShader failed to compile a GLSL shader with the following shader info log: 'Vertex shader failed to compile with the following errors:
ERROR: 0:3: error(#132) Syntax error: "void" parse error
ERROR: error(#273) 1 compilation errors.  No code generated

'

..

Looks pretty descent and even more informative than the regular compilation check we did. But remember: The exact text and ID are implementation dependent and may differ between vendors and driver suppliers.

Add the semicolon again.

In more complicated programs there surely will be quite some interesting information popping up. DEBUG_TYPE_PERFORMANCE_ARB is probably something to look out for.

Something Odd

During my experimentation I found something odd that produced a deprecation error of sorts. The glGetString cannot be called with GL_EXTENSIONS anymore. That behaviour has been deprecated in the OpenGL 3.2 core profile. You can compare the specifications here OpenGL API Specs. Check OpenGL core 3.1 page 350 and compare it to OpenGL core 3.2 page 254.

Let's make the following changes to our program:

    ..

    if sdl2.SDL_Init(sdl2.SDL_INIT_VIDEO) != 0:
        print(sdl2.SDL_GetError())
        return

    sdl2.SDL_GL_SetAttribute(sdl2.SDL_GL_CONTEXT_MAJOR_VERSION, 3)
    sdl2.SDL_GL_SetAttribute(sdl2.SDL_GL_CONTEXT_MINOR_VERSION, 2)
    sdl2.SDL_GL_SetAttribute(sdl2.SDL_GL_CONTEXT_FLAGS,
                             sdl2.SDL_GL_CONTEXT_DEBUG_FLAG)

    ..

Here we ask for at least OpenGL 3.2 to be used in our program. Run the program again. You should see:

SOURCE: GL_DEBUG_SOURCE_API_ARB
TYPE: GL_DEBUG_TYPE_ERROR_ARB
ID: 3200
SEVERITY: GL_DEBUG_SEVERITY_HIGH_ARB
MESSAGE: Using glGetString in a Core context with arameter <name> and enum '0x1f03' which was removed from Core OpenGL (GL_INVALID_ENUM)

Activated OpenGL.FULL_LOGGING = True will show a bit more. The reason for this error is that PyOpenGL (3.1.0a1) will check for extensions at the first opportunity (here at: vao = GL.glGenVertexArrays(1)). It then uses glGetString with GL_EXTENSIONS (0x1f03) to check for extensions, catches the exception and tries again with glGetStringi.

You could also manually induce this error by adding the following somewhere in the program:

    ..

    try:
        GL.glGetString(GL.GL_EXTENSIONS)
    except:
        pass
    print(get_debug_output())

    ..

Obviously it is not a good idea to consume and drop an exception like this. It is just for illustration purposes and to show that the debug output has nothing to do with the raised exception itself.

If you switch to a version lower than OpenGL 3.2 for example like this:

    ..

    sdl2.SDL_GL_SetAttribute(sdl2.SDL_GL_CONTEXT_MINOR_VERSION, 1)

    ..

The error will disappear, because at the time of OpenGL 3.1 glGetString(GL_EXTENSIONS) was not yet deprecated. Alternatively you could switch from the core profile to the compatible profile.

    ..

    sdl2.SDL_GL_SetAttribute(sdl2.SDL_GL_CONTEXT_MINOR_VERSION, 2)
    sdl2.SDL_GL_SetAttribute(sdl2.SDL_GL_CONTEXT_PROFILE_MASK,
                             sdl2.SDL_GL_CONTEXT_PROFILE_COMPATIBILITY)

    ..

However I do not recommend this. Stick to the core profile if possible. And you can then simply ignore the error, because it was already handled in PyOpenGL. If you have this issue, want to set OpenGL 3.2 core or above and the error really annoys you even at this early experimenting and testing stage you can purge it right after the first PyOpenGL call like this:

    ..

    vao = GL.glGenVertexArrays(1)
    # purge glGetString deprecation error from debug log
    get_debug_output()

    ..

The return value goes right into the nirvana. Just remember to remove this "fix" once you are really lost in your debugging efforts.

Thats it!

There is no point to show a screen shot here like in the last post since they are exactly the same. However you should have a lot of information at hand now to debug OpenGL programs in Python.

You can download the complete source here example2.py. Should you have not played through every step I encourage you to play with the error checking. Introduce some bugs, change the opengl version, context flags and profile and see what happens.

It was quite some work to figure it all out but I hope you will find it useful. Feel free to comment below.

Discussion / Next Topics ?

There is a lot of ways to go from here. I will not go directly go into extensive shader programming and 3D since my math is a bit rusty in this regard. However the following topics are on my mind:

Go a bit into SDL. Catch mouse clicks and adjust vertex locations accordingly.
Animate some vertex positions time-based. Look into ELEMENT_ARRAY_BUFFERs.

Stay tuned for more ..

Hivestream - Linux, Python, Bees ...

OpenGL Logging and Debugging

Overview

Debugging / Error Handling

General Logging

Debug Code

Checking Shader Compilation

Checking Shader Program Linking

Logging Facilities

General Tip

Debug Message Log

Logging Code

New Imports

Some Trickery

Values to Constant Names

Getting the Log

Activating the Debug Context in SDL

Calling for the Debug Log

No Error?

Something Odd

Thats it!

Discussion / Next Topics ?

Overview

Debugging / Error Handling

General Logging

Debug Code

Checking Shader Compilation

Checking Shader Program Linking

Logging Facilities

General Tip

Debug Message Log

Logging Code

New Imports

Some Trickery

Values to Constant Names

Getting the Log

Activating the Debug Context in SDL

Calling for the Debug Log

No Error?

Something Odd

Thats it!

Discussion / Next Topics ?

social