Very odd bug with 3.0.1 nightly build [test case]

Started by xsupermetroidx, September 27, 2016, 07:44:33

Previous topic - Next topic

xsupermetroidx

After updating to the 3.0.1 nightly build, I had no issues adapting to the new modular structure, but then I attempted to start my game demo. Everything loads and runs properly until I perform an action that triggers the compilation and linking of a geometry shader, at which point I get a link error along the lines of "error: Varying (named ︩ specified but not present in the program object." The specific varying it complains about potentially changes each time, as though it is pointing to a random point in memory. I reverted back to a previous (non-modular) version and the same shader compiles and runs without any issue. I am using the latest nvidia drivers.

The conclusion I came to is that there must be a bug in the newest version's OpenGL wrapper which sometimes results in failed shader compilation. I am not sure how to go about narrowing this down to something easily reproducible.

Kai

QuoteI am not sure how to go about narrowing this down to something easily reproducible.
Well, since the problem is linking the program, just provide the shader sources and all program-related GL calls you do before linking it, such as glTransformFeedbackVaryings.
No need to supply GLFW window, VBO/VAO, FBO or texture setup.

xsupermetroidx

I've replicated the bug with a small test case. This is the complete code:

package bugtest;
    
import static org.lwjgl.glfw.GLFW.glfwCreateWindow;
import static org.lwjgl.glfw.GLFW.glfwInit;
import static org.lwjgl.glfw.GLFW.glfwMakeContextCurrent;
import static org.lwjgl.glfw.GLFW.glfwShowWindow;
import org.lwjgl.opengl.GL;
import static org.lwjgl.opengl.GL11.GL_FALSE;
import static org.lwjgl.opengl.GL11.GL_TRUE;
import static org.lwjgl.opengl.GL20.GL_COMPILE_STATUS;
import static org.lwjgl.opengl.GL20.GL_INFO_LOG_LENGTH;
import static org.lwjgl.opengl.GL20.GL_LINK_STATUS;
import static org.lwjgl.opengl.GL20.GL_VALIDATE_STATUS;
import static org.lwjgl.opengl.GL20.GL_VERTEX_SHADER;
import static org.lwjgl.opengl.GL20.glAttachShader;
import static org.lwjgl.opengl.GL20.glCompileShader;
import static org.lwjgl.opengl.GL20.glCreateProgram;
import static org.lwjgl.opengl.GL20.glCreateShader;
import static org.lwjgl.opengl.GL20.glGetProgramInfoLog;
import static org.lwjgl.opengl.GL20.glGetProgrami;
import static org.lwjgl.opengl.GL20.glGetShaderInfoLog;
import static org.lwjgl.opengl.GL20.glGetShaderi;
import static org.lwjgl.opengl.GL20.glLinkProgram;
import static org.lwjgl.opengl.GL20.glShaderSource;
import static org.lwjgl.opengl.GL20.glValidateProgram;
import static org.lwjgl.opengl.GL30.GL_INTERLEAVED_ATTRIBS;
import static org.lwjgl.opengl.GL30.glTransformFeedbackVaryings;
import static org.lwjgl.opengl.GL32.GL_GEOMETRY_SHADER;
import org.lwjgl.system.Configuration;
import static org.lwjgl.system.MemoryUtil.NULL;

public class BugTest {
    static final String nativesPath = System.getProperty("user.dir") + "\\native";
    
    static final String[] varyings = new String[] {
        "out_Position",
        "out_Velocity",
        "out_Color",
        "out_Fade",
        "out_Anim",
    };
    
    static final String stage1Source = "#version 330\n" +
"\n" +
"layout(location = 0) in vec4 in_Position;\n" +
"layout(location = 1) in vec4 in_Velocity;\n" +
"layout(location = 2) in vec4 in_Color;\n" +
"layout(location = 3) in vec4 in_Fade;\n" +
"layout(location = 4) in vec4 in_Anim;\n" +
"\n" +
"out vec4 pass_Position;\n" +
"out vec4 pass_Velocity;\n" +
"out vec4 pass_Color;\n" +
"out vec4 pass_Fade;\n" +
"out vec4 pass_Anim;\n" +
"\n" +
"void main() {\n" +
"    pass_Position = in_Position;\n" +
"    pass_Velocity = in_Velocity;\n" +
"    pass_Color = in_Color;\n" +
"    pass_Fade = in_Fade;\n" +
"    pass_Anim = in_Anim;\n" +
"};";
    
    static final String stage2Source = "#version 330 core\n" +
"\n" +
"layout(points) in;\n" +
"layout(points, max_vertices = 1) out;\n" +
"\n" +
"in vec4 pass_Position[];\n" +
"in vec4 pass_Velocity[];\n" +
"in vec4 pass_Color[];\n" +
"in vec4 pass_Fade[];\n" +
"in vec4 pass_Anim[];\n" +
"\n" +
"out vec4 out_Position;\n" +
"out vec4 out_Velocity;\n" +
"out vec4 out_Color;\n" +
"out vec4 out_Fade;\n" +
"out vec4 out_Anim;\n" +
"\n" +
"void main() {\n" +
"    out_Position = pass_Position[0];\n" +
"    out_Velocity = pass_Velocity[0];\n" +
"    out_Color = pass_Color[0];\n" +
"    out_Fade = pass_Fade[0];\n" +
"    out_Anim = pass_Anim[0];\n" +
"};";
    
    public static void main(String[] args) {
        openWindow();
        GL.createCapabilities();
        compile();
    }
    
    static void openWindow() {
        Configuration.LIBRARY_PATH.set(nativesPath);
        glfwInit();
        long window = glfwCreateWindow(800, 600, "", NULL, NULL);
        glfwMakeContextCurrent(window);
        glfwShowWindow(window);
    }
    
    static void compile() {
        int program = glCreateProgram();
        int stage1 = generateShader(GL_VERTEX_SHADER, stage1Source);
        int stage2 = generateShader(GL_GEOMETRY_SHADER, stage2Source);
        
        link(program, stage1, stage2);
        
        validate(program);
    }
    
    private static int generateShader(int type, String source) {
        int id = glCreateShader(type);
        glShaderSource(id, source);
		glCompileShader(id);
        
        String log = glGetShaderInfoLog(id, glGetShaderi(id, GL_INFO_LOG_LENGTH));
        if (log.equals("")) { log = "No error"; }
        System.out.println("Compiling: \n" + log);
        System.out.println();
        
        if (glGetShaderi(id, GL_COMPILE_STATUS) == GL_FALSE) {
            throw new IllegalStateException("Unable to compile");
        }
        
        return id;
    }
    
    private static void link(int program, int stage1, int stage2) {
        glAttachShader(program, stage1);
        glAttachShader(program, stage2);
        glTransformFeedbackVaryings(program, varyings, GL_INTERLEAVED_ATTRIBS);
        glLinkProgram(program);
        
        String linkStatus = glGetProgramInfoLog(program, glGetProgrami(program, GL_INFO_LOG_LENGTH));
        if (linkStatus.equals("")) { linkStatus = "No error"; }
        System.out.println("Link status: \n" + linkStatus);
        System.out.println("");
        
        if (glGetProgrami(program, GL_LINK_STATUS) != GL_TRUE) {
            throw new IllegalStateException("Unable to link");
        }
    }
    
    private static void validate(int program) {
        glValidateProgram(program);
        
        String validateStatus = glGetProgramInfoLog(program, glGetProgrami(program, GL_INFO_LOG_LENGTH));
        if (validateStatus.equals("")) { validateStatus = "No error"; }
        System.out.println("Validation status: \n" + validateStatus);
        System.out.println("");
        
        if (glGetProgrami(program, GL_VALIDATE_STATUS) != GL_TRUE) {
            throw new RuntimeException("Unable to validate");
        }
    }
    
}


The above code compiles a vertex+geometry shader, specifying a few varyings. Under LWJGL 3.0.0, the output is:

Compiling: 
No error

Compiling: 
No error

Link status: 
No error

Validation status: 
No error


Under version 3.0.1, the output is:
Compiling: 
No error

Compiling: 
No error

Link status: 
Link info
---------
error: Varying (named ) specified but not present in the program object.


Exception in thread "main" java.lang.IllegalStateException: Unable to link
	at bugtest.BugTest.link(BugTest.java:143)
	at bugtest.BugTest.compile(BugTest.java:109)
	at bugtest.BugTest.main(BugTest.java:93)
Java Result: 1

spasi

I cannot reproduce this (Windows 10, Nvidia GTX 970 with latest drivers).

Could you please post the output with -Dorg.lwjgl.util.Debug=true and -Dorg.lwjgl.util.DebugLoader=true?

Kai

Cannot reproduce this either (Win 7, Nvidia Quadro K2000M, driver 368.69 & 369.26)

CoDi

Wild guess: what if some driver does not copy the varying name strings until glLinkProgram() is called?

The JNI wrapper allocates memory, copies the strings, then frees the memory again inside GL30.glTransformFeedbackVaryings(). It is probably very common in C programs to a) call both functions one after another in the same routine, and b) store varying names as static constant strings, or at least not free them before calling glLinkProgram().

xsupermetroidx: You should be able to test this theory with GL30.glTransformFeedbackVaryings(int, PointerBuffer, int), essentially wrapping the calls yourself the same way as the (int, CharSequence[], int) variant does.

xsupermetroidx

It seems your suspicion was correct CoDi. In the above example, I replaced this call:

glTransformFeedbackVaryings(program, varyings, GL_INTERLEAVED_ATTRIBS);


with this code, which is copy-and-pasted from the source of the same method, but with the apiArrayFree call commented out:

MemoryStack stack = stackGet(); int stackPointer = stack.getPointer();
try {
    long varyingsAddress = org.lwjgl.system.APIUtil.apiArray(stack, MemoryUtil::memASCII, varyings);
    nglTransformFeedbackVaryings(program, varyings.length, varyingsAddress, GL_INTERLEAVED_ATTRIBS);
    //org.lwjgl.system.APIUtil.apiArrayFree(varyingsAddress, varyings.length);
} finally {
    stack.setPointer(stackPointer);
}


Removing the apiArrayFree call resolved the issue. I then went back and tested it in my game, and got the same result.

I'm using a GeForce GTX 770.

Observations:

Calling calling glLinkProgram just before apiArrayFree is not safe. The same bug occurs.
Inserting a sleep(1000) has no effect, so it's not a timing issue.

Linking and checking the link status before freeing the strings prevents the bug.
If the link status is not checked, it will fail at validation instead.
If neither link nor validation status is checked, the program will fail to work properly.

Theory: checking the link status causes the driver to make an internal copy of the strings. Otherwise, it's reliant on them not being freed.


spasi

I was able to reproduce this with the system allocator. Definitely a bug in the Nvidia driver.

Found two workarounds:

1) Disable threaded optimizations in the driver settings, or
2) Use the following code:

private static void link(int program, int stage1, int stage2) {
	glAttachShader(program, stage1);
	glAttachShader(program, stage2);

	int status;
	try ( MemoryStack stack = stackPush() ) {
		PointerBuffer varyingsEncoded = stack.mallocPointer(varyings.length);
		for ( int i = 0; i < varyings.length; i++ )
			varyingsEncoded.put(i, memASCII(varyings[i]));

		glTransformFeedbackVaryings(program, varyingsEncoded, GL_INTERLEAVED_ATTRIBS);
		glLinkProgram(program);

		status = glGetProgrami(program, GL_LINK_STATUS); // block until program is linked

		for ( int i = 0; i < varyings.length; i++ )
			nmemFree(varyingsEncoded.get(i));
	}

	String linkStatus = glGetProgramInfoLog(program, glGetProgrami(program, GL_INFO_LOG_LENGTH));
	if ( linkStatus.equals("") ) { linkStatus = "No error"; }
	System.err.println("Link status: \n" + linkStatus);
	System.err.println("");

	if ( status != GL_TRUE ) {
		throw new IllegalStateException("Unable to link");
	}
}


A glFinish after glLinkProgram also fixes it.