Compare commits

...
Author SHA1 Message Date
spoopyghosty0 3ba49708aa FrameBridge: answer xrGetDisplayRefreshRateFB with the real rate (PreyVR black menu, #306)
The Frame's runtime has no XR_FB_display_refresh_rate (-7); OVRPort's dispatcher still
offers it and answered 0 Hz. Team Beef's idTech 4 ports run USERCMD_MSEC = 1000 / refresh,
so PreyVR had 0 ms tics: the async thread spun (~1.9M tics/s), com_frameTime stayed 0 and
the main menu's timeline never got past its first step (black backdrop + cursor only).
FrameBridge now always answers with 1 / predictedDisplayPeriod (else the refresh_rate
setting, else 72 Hz). Headless: menu drawn (snapshot mean 68 vs 0.1 before), clocks advance.

- glmv: gl_mv_debug=2 traces draws (state, GL errors per framebuffer), failed texture
  uploads/copies/compiles and idTech 4 clocks; how this was found
- triage: a single xrEndFrame -16 is info, not the black-menu error it was blamed for
- PLAYBOOK row, CLAUDE.md fact, host test for the fallback rate
2026-10-16 01:34:33 -04:00
spoopyghosty0 57f70dc63d adapter: snapshots fall back to a quad/cylinder layer and log brightness
Frames without a projection layer (e.g. PreyVR's menu, a cylinder layer only) gave no snapshot. The snapshot now
takes the first quad/cylinder layer's image instead and logs the layer type, image area, array index and the mean/max
brightness of the submitted area, so a black image shows in the log without fetching the file (#306).
2026-10-15 19:24:26 -04:00
17 changed files with 428 additions and 21 deletions

No files matched your search

+3
View File
@@ -459,6 +459,9 @@ Repo is on an NTFS drive (`core.fileMode=false`); line endings are LF (`.gitattr
XR_KHR_composition_layer_equirect2/cylinder, XR_FB_composition_layer_image_layout (flip emulated by Vulkan blit).
- `xrConvertTimespecTimeToTimeKHR`/`xrConvertTimeToTimespecTimeKHR` return FUNCTION_UNSUPPORTED → adapter emulates
(offset = predictedDisplayTime − period − CLOCK_MONOTONIC, sampled in xrWaitFrame).
- No XR_FB_display_refresh_rate (`xrGetDisplayRefreshRateFB` -7), yet OVRPort's dispatcher offers it and answered 0 Hz
→ FrameBridge always answers with the measured rate (1/predictedDisplayPeriod, else 72). PreyVR (#306, idTech 4:
`USERCMD_MSEC = 1000 / GetRefresh()`) had 0 ms tics: async thread spinning, `com_frameTime` stuck at 0, menu black.
- Guardian STAGE bounds report 1×1 m (scene emulation uses ≥1.5 m).
- GL goes through **Zink** (Mesa GL on Vulkan). Mesa GLSL is strict: `#pragma` before `#extension` fails, implicit
int/float conversions fail (enable `GL_EXT_shader_implicit_conversions`), num_views=2 shaders on single-view FBOs
+3 -3
View File
@@ -10,14 +10,14 @@ d6337034fb0bdcca7ef9b7063d85b7586b8508b63b435959e8fffaba0691091c ./arm64-v8a/li
0167c2fde5dfde62897f9d85afc4fc8e97784e988b5b8df6cea8c407240b3424 ./arm64-v8a/libfp_tkeys.so
e8c0965c188665a4e565e4a3af983ef1866d1cf9225665cc90d8df286bc96ef3 ./arm64-v8a/libfp_vk.so
383054f8b3b41dde76d062c71856cd3163655e50009c08454bc1793f393ead65 ./arm64-v8a/libfpg.so
5432674a59d02f411cd853a5dc57e3fa547d1ac518f25bf433fc54c43677177a ./arm64-v8a/libfpglmv.so
4a13a33e112c9e4e3c5ff4337ed6e988a9e5b3602f48d654df148ef5fafbf426 ./arm64-v8a/libfpglmv.so
8a8f6b1da8952cb3933a5b53558424a5fc56043b2527a16bb6dd62a00d2de01a ./arm64-v8a/libframe_xrshim.so
19ba5ed3c4b780f5ae46251f6958f552acfc5f13c8bb39f995579593fa8990c6 ./arm64-v8a/libglshim.so
0f058921e9c1f5b9ef5847cc9e6b80a23e75028c76c1d3bb02d1610b535f81c9 ./arm64-v8a/libopenxr_loader_generic.so
86261c4d7c4b78af5e182b81ae172f6d5fd5b12d8dc6194a876eee08b589d3ce ./arm64-v8a/libopenxr_loader_generic.so
1feaeafad467c4cafdf2b018a4d84b0bee200c3f711697b4ce97e66a3ba256ca ./arm64-v8a/libovrplatformcompat.so
a4ed80ae45ca90758239f152ea5a2e8c127d491e1e697ea5680db6fd7f72db07 ./arm64-v8a/libvrapi.so
a4ed80ae45ca90758239f152ea5a2e8c127d491e1e697ea5680db6fd7f72db07 ./arm64-v8a/libvrapi_foveation.so
9e8a7ce599b62a7c607b0d3637e4ec1b1ea1974c3373a7af3f5920ad2adc5e00 ./armeabi-v7a/libopenxr_loader_generic.so
1a3b250835798f46049f527a6b32f9d0b33a2a976006d08f5997bfccc215ee89 ./armeabi-v7a/libopenxr_loader_generic.so
1871eae093432d277da4bc751bf5f3269dfcf11f9168260b0c3caadb0dedb19d ./dex/oculusos-stubs.dex
b634ab5640e258563c536e658cad87080553df6f34f62269a21d554844e58bfe ./hevc/COPYING.FFmpeg
141de01f0d40b97d4f9a720db5ab8ea442f6aa35db5272048899292884994a1c ./hevc/libstagefrighthw.so
Binary file not shown.
Binary file not shown.
Binary file not shown.
+7 -2
View File
@@ -101,8 +101,13 @@ signatures:
suggest: [frame.adapter]
- id: cylinder-menu-layers-rejected
pattern: 'xrEndFrame failed -16\b'
severity: error
diagnosis: The game draws a curved (cylinder) screen to each eye separately (for example the Doom3Quest / PreyVR menu). The Frame's runtime has no cylinder layers, so FrameBridge shows each as flat quad strips; a per-eye pair makes too many quad layers for one frame and the runtime rejects the whole frame (XR_ERROR_LAYER_INVALID), leaving the menu black while the game runs. FrameBridge from this build shows the left eye's strips to both eyes to halve the count; rebuild and reinstall the game to try it.
severity: info
# PreyVR (GitHub #306): one rejected frame at the start of every session (its space isn't locatable yet); the black
# menu there had another cause (a 0 Hz refresh rate stopped the game clock), so this alone is no error
diagnosis: The runtime rejected a frame's layers once (XR_ERROR_LAYER_INVALID). At the start of a session that is
harmless. If it repeats every frame the picture stays black; FrameBridge shows a curved (cylinder) screen drawn
to each eye separately (for example the Doom3Quest / PreyVR menu) as one set of flat strips for both eyes to stay
within the runtime's layer limit, so rebuild and reinstall the game with the current FrameBridge.
suggest: [frame.adapter]
- id: missing-ovr-symbol
pattern: '(UnsatisfiedLinkError|cannot locate symbol) .*"?(ovr_[A-Za-z0-9_]+|ovr[A-Z][A-Za-z0-9]*_ToString)'
+2 -2
View File
@@ -511,7 +511,7 @@ FramePort's layer between the game and the Steam Frame: fills in what the Frame
- **Suggested (on):** Required for every OpenXR/overport build on the Frame.
- **Suggested by launch-test signatures:**
- `cube-swapchain-refused` (fatal): The game asked for a cube-map swapchain (for example an OVROverlay skybox or loading cube), which the Frame's runtime doesn't have.
- `cylinder-menu-layers-rejected` (error): The game draws a curved (cylinder) screen to each eye separately (for example the Doom3Quest / PreyVR menu).
- `cylinder-menu-layers-rejected` (info): The runtime rejected a frame's layers once (XR_ERROR_LAYER_INVALID).
- `graphics-requirements-missing` (fatal): The game can't start VR on the Frame; rebuild it with the current FramePort.
- `swapchain-rect-invalid` (fatal): The runtime rejects the game's frames, so it stops drawing (for example stuck at a "Waiting" box).
- `time-conversion` (warning): The Frame's runtime lacks timespec time conversion; the current adapter build emulates it.
@@ -1621,7 +1621,7 @@ Logs details when flat panels stay black. No effect on the game.
- Game settings → Troubleshooting → "Flat panel diagnostics (log)" (advanced).
- **Source:** [patches/settings.py](../src/frameport/patches/settings.py)
> Diagnostics for frame.gl_multiview_fbo: checks for GL errors after every single-view draw of a multiview shader and logs counters every 5 seconds (tag GLMV in launch.log).
> Diagnostics for frame.gl_multiview_fbo: checks for GL errors after every single-view draw of a multiview shader and logs counters every 5 seconds (tag GLMV in launch.log). 2 (frameport settings) also checks every draw and logs the draw state, failed texture uploads and shader compiles and, for idTech 4 engines, the game clock.
### <a id="adapter-haptic_fix"></a>Fix freezes when controllers vibrate
+1
View File
@@ -168,6 +168,7 @@ version is `catalog/triage.yaml` (used by `frameport test` / the Job screen); ke
| Black screen, audio works, log `Unsupported VrApi layer type N` | bridge drops frames containing that layer | extend the bridge (cylinder=3 is converted to a quad already) |
| Only some draws visible (for example controllers) + `glGetError 0x502` | multiview shaders used on single-view FBOs | GL shim `gl_hide_multiview=1` (default) |
| Own GLES engine (OpenXR, not VrApi): eye view fine, but HUD / menu / PDA panels black (for example Doom3Quest, GitHub #77; no error in the log) | every shader declares `layout(num_views=2) in;`, also the ones drawn into the engine's single-layer offscreen framebuffers (2D textures/renderbuffers); OVR_multiview makes such draws INVALID_OPERATION and Mesa drops them (`draw_validate.c`), Quest's driver doesn't | `frame.gl_multiview_fbo` (opt-in, experimental: `libfpglmv.so` interposes GLES and draws those cases with a single-view twin of the program; logs `GLMV: twin built: program N -> M`, per-5-s `single-view draws` counters; `gl_mv_debug=1` adds glGetError checks; triage `gl-multiview-twin-failed`). Alternative: the game's own fix (two-layer multiview pool, Xandrix's patch in #77) |
| Team Beef idTech 4 port (PreyVR, GitHub #306): main menu black except the mouse cursor, loading screen fine, 72 fps, no GL error; one game thread at 100 % CPU | the game clock runs 1000 / refresh ms per tic (`USERCMD_MSEC`, from xrGetDisplayRefreshRateFB). The Frame's runtime lacks XR_FB_display_refresh_rate and OVRPort's dispatcher answered 0 Hz: 0 ms tics, the async thread spins (millions of tics/s) and `com_frameTime` stays 0, so the menu GUI stays at its first animation step (everything hidden) | FrameBridge (default, no setting) answers xrGetDisplayRefreshRateFB with the measured rate (1 / predictedDisplayPeriod, else 72 Hz); log `refresh rate: runtime reported 0.0 Hz (result -7), reporting 72.0 Hz`. Found with `gl_mv_debug=2` (`frameport settings <pkg> gl_mv_debug=2`, needs `frame.gl_multiview_fbo`): only 2 draws per frame (backdrop + cursor) and `trace clocks: com_frameTime=0` |
| Upside-down image in a GL bridge game | GL images start at the bottom row | fixed in the bridge (swap angleUp/Down for GL chains) |
| UI panels upside down (AC Nexus) | XrCompositionLayerImageLayoutFB VERTICAL_FLIP unsupported | adapter `flip_emul=1` (default); rotating quads makes them vanish |
| Passthrough black (BAM) | XR_FB_passthrough missing | adapter `passthrough_emul=1` (default) + `patch_force_passthrough` for MR-only games |
+5
View File
@@ -15,6 +15,8 @@
// * drops requested instance extensions the runtime lacks (e.g. XR_FB_passthrough);
// * retries rejected swapchains with 1 sample / a supported format (swapchain_fix, overport #71);
// * drops composition layers that reference swapchains that failed to create (layer_fix);
// * answers xrGetDisplayRefreshRateFB with the measured display rate when the runtime lacks it or reports 0 Hz
// (session_fixes.c);
// * serves cube swapchains the runtime refuses as GL/Vulkan cube maps and drops their layers (cube_standin, cube_standin.c);
// * optionally requests mutable-format swapchain images (mutable_fix, off by default);
// * optionally swaps left/right images of stereo projection layers (swap_eyes, off by default);
@@ -2177,6 +2179,9 @@ XRAPI_ATTR XrResult XRAPI_CALL xrGetInstanceProcAddr(XrInstance instance, const
if (layer_debug || refresh_rate > 0) {
HOOK_AS(xrRequestDisplayRefreshRateFB, hook_request_refresh_rate)
}
// The Frame's runtime has no XR_FB_display_refresh_rate, but OVRPort's dispatcher offers it to the game and answers
// 0 Hz without it: the measured rate instead (the runtime's own answer when it has one).
if (instance != XR_NULL_HANDLE) HOOK_AS(xrGetDisplayRefreshRateFB, hook_get_refresh_rate)
if (surface_emul) HOOK_AS(xrCreateSwapchainAndroidSurfaceKHR, hook_xrCreateSwapchainAndroidSurfaceKHR)
if (eye_debug || release_wait) HOOK_AS(xrReleaseSwapchainImage, eye_hook_xrReleaseSwapchainImage)
if (layer_debug || cube_standin) { // counters + cube stand-ins; every other wait/release hook above takes precedence
+15
View File
@@ -0,0 +1,15 @@
// SPDX-License-Identifier: GPL-3.0-only
// Display refresh rate for xrGetDisplayRefreshRateFB when the runtime doesn't give one (session_fixes.c). Pure, so the
// host test (tests/fixtures/src/refresh_rate_test.c) can check it.
#pragma once
#include <stdint.h>
// The rate the frame timing shows (1 / predictedDisplayPeriod of the last xrWaitFrame, whole Hz), else the
// refresh_rate setting, else 72 Hz (the Frame's rate for Android apps).
static inline float fb_refresh_rate(int64_t display_period_ns, float setting) {
if (display_period_ns > 0) {
double hz = 1e9 / (double)display_period_ns;
if (hz >= 30.0 && hz <= 240.0) return (float)(int)(hz + 0.5);
}
return setting > 0 ? setting : 72.0f;
}
+21
View File
@@ -9,6 +9,7 @@
// * aim_pitch / aim_yaw / aim_forward: correct the aim pose of controllers (pointer rays) by a fixed offset;
// * refresh_rate: display refresh rate requested at session start (and instead of the app's own requests).
#include "layer_math.h"
#include "refresh_rate.h"
static void emul_on_begin_session(const XrSessionBeginInfo *info); // layer_emul_gl.c
@@ -552,6 +553,26 @@ static XRAPI_ATTR XrResult XRAPI_CALL hook_request_refresh_rate(XrSession sessio
return XR_FAILED(result) && refresh_rate > 0 ? XR_SUCCESS : result;
}
// Always on: the Frame's runtime has no XR_FB_display_refresh_rate; OVRPort's dispatcher still offers the extension and
// its xrGetDisplayRefreshRateFB then answers 0 Hz. idTech 4 VR ports (Team Beef's Doom3Quest engine: PreyVR, GitHub
// #306) run their game clock at 1000 / refresh ms per tic: with 0 Hz the tic length is 0, the async thread spins and
// the frame/GUI time never advances (main menu stuck at its first animation step: black, only the cursor). A rate the
// runtime doesn't give is replaced by the one the frame timing shows (refresh_rate.h).
static XRAPI_ATTR XrResult XRAPI_CALL hook_get_refresh_rate(XrSession session, float *rate) {
if (!rate) return XR_ERROR_VALIDATION_FAILURE;
PFN_xrGetDisplayRefreshRateFB fn = (PFN_xrGetDisplayRefreshRateFB)lookup(active_instance, "xrGetDisplayRefreshRateFB");
XrResult result = fn ? fn(session, rate) : XR_ERROR_FUNCTION_UNSUPPORTED;
if ((XR_SUCCEEDED(result) && *rate > 0.0f) || result == XR_ERROR_HANDLE_INVALID) return result;
float runtime = XR_SUCCEEDED(result) ? *rate : 0.0f;
*rate = fb_refresh_rate((int64_t)last_display_period, refresh_rate);
static int logs;
if (logs < 4) {
++logs;
LOG("refresh rate: runtime reported %.1f Hz (result %d), reporting %.1f Hz", runtime, result, *rate);
}
return XR_SUCCESS;
}
static XRAPI_ATTR XrResult XRAPI_CALL hook_xrBeginSession(XrSession session, const XrSessionBeginInfo *info) {
PFN_xrBeginSession fn = (PFN_xrBeginSession)lookup(active_instance, "xrBeginSession");
if (!fn) return XR_ERROR_FUNCTION_UNSUPPORTED;
+30 -6
View File
@@ -1,6 +1,6 @@
// FramePort FrameBridge: eye-image snapshots for headless diagnostics (setting snapshot=<seconds>, GLES games only).
// Every <seconds>, at xrEndFrame, the left-eye image the game just submitted (projection layer, view 0: its swapchain
// image and array layer) is read back on the game's own GL context and written at a quarter of its size as
// image and array layer; without a projection layer the first quad/cylinder layer's) is read back on the game's own GL context and written at a quarter of its size as
// /sdcard/Android/data/<package>/files/fb_snap_<n>.ppm (n = 0-7, the oldest is overwritten). Nobody wears the headset
// in a launch test, so the headset view stays black: this shows what the game itself draws (e.g. which screen it is
// stuck on). The game's framebuffer, pack-buffer and pack-alignment bindings are restored afterwards.
@@ -118,18 +118,27 @@ static void snap_end_frame(const XrFrameEndInfo *info) {
int64_t t = (int64_t)now.tv_sec * 1000000000ll + now.tv_nsec;
if (t < next_ns) return;
next_ns = t + (int64_t)snapshot * 1000000000ll;
const XrCompositionLayerProjection *proj = NULL;
for (uint32_t i = 0; i < info->layerCount && !proj; ++i)
// The projection layer's left eye; a frame without one (e.g. a menu shown only as a quad or cylinder layer) gives
// its first quad/cylinder layer's image instead.
const XrSwapchainSubImage *sub = NULL;
int type = 0;
for (uint32_t i = 0; i < info->layerCount && !sub; ++i)
if (info->layers[i] && info->layers[i]->type == XR_TYPE_COMPOSITION_LAYER_PROJECTION &&
((const XrCompositionLayerProjection *)info->layers[i])->viewCount)
proj = (const XrCompositionLayerProjection *)info->layers[i];
if (!proj || !snap_load_gl()) return;
sub = &((const XrCompositionLayerProjection *)info->layers[i])->views[0].subImage, type = info->layers[i]->type;
for (uint32_t i = 0; i < info->layerCount && !sub; ++i) {
const XrCompositionLayerBaseHeader *layer = info->layers[i];
if (layer && layer->type == XR_TYPE_COMPOSITION_LAYER_QUAD)
sub = &((const XrCompositionLayerQuad *)layer)->subImage, type = layer->type;
else if (layer && layer->type == XR_TYPE_COMPOSITION_LAYER_CYLINDER_KHR)
sub = &((const XrCompositionLayerCylinderKHR *)layer)->subImage, type = layer->type;
}
if (!sub || !snap_load_gl()) return;
if (!s_eglGetCurrentContext()) {
static int logged;
if (!logged++) LOG("snapshot: no GL context current in xrEndFrame, no snapshot");
return;
}
const XrSwapchainSubImage *sub = &proj->views[0].subImage;
pthread_mutex_lock(&snap_lock);
int i = snap_find(sub->swapchain, 0);
GLuint tex = 0;
@@ -167,6 +176,21 @@ static void snap_end_frame(const XrFrameEndInfo *info) {
s_glDeleteFramebuffers(1, &fb);
while (s_glGetError() != GL_NO_ERROR) {} // our calls must not leave errors for the game to find
if (rgba) {
// brightness of the submitted area: tells a black image from a drawn one without fetching the file
uint64_t sum = 0, n = 0;
unsigned max = 0;
const XrRect2Di *r = &sub->imageRect;
for (int32_t y = r->offset.y; y < r->offset.y + r->extent.height; y += 4)
for (int32_t x = r->offset.x; x < r->offset.x + r->extent.width; x += 4) {
if (x < 0 || y < 0 || (uint32_t)x >= w || (uint32_t)y >= h) continue;
const unsigned char *p = rgba + ((size_t)y * w + (size_t)x) * 4;
unsigned v = p[0] > p[1] ? (p[0] > p[2] ? p[0] : p[2]) : (p[1] > p[2] ? p[1] : p[2]);
sum += v, ++n;
if (v > max) max = v;
}
LOG("snapshot: layer type=%d image %u array=%u rect=%d,%d %dx%d of %ux%u: mean %.1f max %u",
type, tex, sub->imageArrayIndex, r->offset.x, r->offset.y, r->extent.width, r->extent.height, w, h,
n ? (double)sum / (double)n : 0.0, max);
snap_write(rgba, w, h, taken++ % 8);
free(rgba);
}
+277 -6
View File
@@ -16,7 +16,8 @@
// block bindings and default-block uniform values (copied before every such draw), then the original is bound again.
//
// Logcat tag GLMV. Setting gl_mv_debug=1 (libframe_settings.so / framebridge.conf / FRAMEBRIDGE_CONFIG, as the GL
// shim): glGetError after every twin draw, and per-5-s counters.
// shim): glGetError after every twin draw, and per-5-s counters. gl_mv_debug=2 (trace) also checks every draw and
// logs the state of the first draws of each 5 s window, failed texture uploads/copies and shader compiles.
#define _GNU_SOURCE
#include <EGL/egl.h>
#include <GLES3/gl32.h>
@@ -111,7 +112,27 @@
X(void, UniformMatrix2x4fv, (GLint, GLsizei, GLboolean, const GLfloat *)) \
X(void, UniformMatrix4x2fv, (GLint, GLsizei, GLboolean, const GLfloat *)) \
X(void, UniformMatrix3x4fv, (GLint, GLsizei, GLboolean, const GLfloat *)) \
X(void, UniformMatrix4x3fv, (GLint, GLsizei, GLboolean, const GLfloat *))
X(void, UniformMatrix4x3fv, (GLint, GLsizei, GLboolean, const GLfloat *)) \
TRACE_LIST(X)
// gl_mv_debug=2 (trace): the draw state and texture/shader calls behind black output
#define TRACE_LIST(X) \
X(GLboolean, IsEnabled, (GLenum)) \
X(void, GetBooleanv, (GLenum, GLboolean *)) \
X(GLenum, CheckFramebufferStatus, (GLenum)) \
X(void, GetTexLevelParameteriv, (GLenum, GLint, GLenum, GLint *)) \
X(void, GetTexParameteriv, (GLenum, GLenum, GLint *)) \
X(void, Clear, (GLbitfield)) \
X(void, Viewport, (GLint, GLint, GLsizei, GLsizei)) \
X(void, TexImage2D, (GLenum, GLint, GLint, GLsizei, GLsizei, GLint, GLenum, GLenum, const void *)) \
X(void, TexSubImage2D, (GLenum, GLint, GLint, GLint, GLsizei, GLsizei, GLenum, GLenum, const void *)) \
X(void, CompressedTexImage2D, (GLenum, GLint, GLenum, GLsizei, GLsizei, GLint, GLsizei, const void *)) \
X(void, TexStorage2D, (GLenum, GLsizei, GLenum, GLsizei, GLsizei)) \
X(void, CopyTexImage2D, (GLenum, GLint, GLenum, GLint, GLint, GLsizei, GLsizei, GLint)) \
X(void, CopyTexSubImage2D, (GLenum, GLint, GLint, GLint, GLint, GLint, GLsizei, GLsizei)) \
X(void, GenerateMipmap, (GLenum)) \
X(void, BindTexture, (GLenum, GLuint)) \
X(void, TexParameteri, (GLenum, GLenum, GLint))
#define DECL(ret, name, args) static ret(*r_##name) args;
REAL_LIST(DECL)
@@ -515,6 +536,147 @@ static void stats(void) {
twin_draws = mv_draws = uniform_sets = 0;
}
// ---------------------------------------------------------------- trace (gl_mv_debug=2, diagnostics)
// Every draw is checked with glGetError (this also consumes errors the game would read), counted per draw
// framebuffer, and the first draws of every 5 s window are logged with the state that decides whether they write
// anything: framebuffer status and views, program, viewport/scissor, colour/depth/stencil/blend state and the texture
// on the active unit. Texture uploads, copies and shader compiles that fail are logged too.
#define TRACE_DETAIL 12 // detailed draws per window
#define TRACE_WINDOWS 40 // windows with detail
#define NTFB 16
struct tfb { GLint fb; unsigned long draws, errors, clears; };
static int trace_detail, trace_windows;
static unsigned long trace_draws, trace_errors, trace_clears;
static GLenum trace_first_error;
static struct tfb tfb[NTFB];
static struct timespec trace_last;
static pthread_mutex_t trace_lock = PTHREAD_MUTEX_INITIALIZER;
static struct tfb *tfb_slot(GLint fb) {
for (int i = 0; i < NTFB; ++i)
if (tfb[i].fb == fb && (tfb[i].draws || tfb[i].clears)) return &tfb[i];
for (int i = 0; i < NTFB; ++i)
if (!tfb[i].draws && !tfb[i].clears) { tfb[i].fb = fb; return &tfb[i]; }
return NULL;
}
static void trace_window(void) { // under trace_lock
struct timespec now;
clock_gettime(CLOCK_MONOTONIC, &now);
if (!trace_last.tv_sec) trace_last = now;
if (now.tv_sec - trace_last.tv_sec < 5) return;
trace_last = now;
char buf[700];
int n = 0;
for (int i = 0; i < NTFB && n < (int)sizeof(buf) - 60; ++i)
if (tfb[i].draws || tfb[i].clears)
n += snprintf(buf + n, sizeof(buf) - n, " fb%d:d%lu/e%lu/c%lu", tfb[i].fb, tfb[i].draws, tfb[i].errors,
tfb[i].clears);
LOG("trace 5s: %lu draws, %lu with a GL error (first 0x%x), %lu clears;%s", trace_draws, trace_errors,
trace_first_error, trace_clears, n ? buf : " none");
{ // idTech 4 engines (Doom3Quest, PreyVR) export their clocks; GUI animations run on com_frameTime, so one that
// stands still leaves menus at their first step (PreyVR, GitHub #306: 0 Hz refresh rate -> 0 ms per tic)
static int *frame_time, *tic_number, *frame_number, looked;
if (!looked) {
looked = 1;
frame_time = dlsym(RTLD_DEFAULT, "com_frameTime");
tic_number = dlsym(RTLD_DEFAULT, "com_ticNumber");
frame_number = dlsym(RTLD_DEFAULT, "com_frameNumber");
}
if (frame_time && tic_number && frame_number)
LOG("trace clocks: com_frameTime=%d com_ticNumber=%d com_frameNumber=%d", *frame_time, *tic_number,
*frame_number);
}
memset(tfb, 0, sizeof(tfb));
trace_draws = trace_errors = trace_clears = 0;
trace_first_error = 0;
if (trace_windows < TRACE_WINDOWS) {
++trace_windows;
trace_detail = 0;
}
}
static void trace_state(const char *what, GLenum mode, GLsizei count, GLenum err) {
GLint fb = 0, prog = 0, vp[4] = {0}, sc[4] = {0}, unit = 0, tex = 0, dfunc = 0, bsrc = 0, bdst = 0, bsrca = 0,
bdsta = 0, cullmode = 0;
GLboolean cmask[4] = {0}, dmask = 0;
r_GetIntegerv(GL_DRAW_FRAMEBUFFER_BINDING, &fb);
r_GetIntegerv(GL_CURRENT_PROGRAM, &prog);
r_GetIntegerv(GL_VIEWPORT, vp);
r_GetIntegerv(GL_SCISSOR_BOX, sc);
r_GetIntegerv(GL_ACTIVE_TEXTURE, &unit);
r_GetIntegerv(GL_DEPTH_FUNC, &dfunc);
r_GetIntegerv(GL_BLEND_SRC_RGB, &bsrc);
r_GetIntegerv(GL_BLEND_DST_RGB, &bdst);
r_GetIntegerv(GL_BLEND_SRC_ALPHA, &bsrca);
r_GetIntegerv(GL_BLEND_DST_ALPHA, &bdsta);
r_GetIntegerv(GL_CULL_FACE_MODE, &cullmode);
r_GetBooleanv(GL_COLOR_WRITEMASK, cmask);
r_GetBooleanv(GL_DEPTH_WRITEMASK, &dmask);
GLenum status = r_CheckFramebufferStatus(GL_DRAW_FRAMEBUFFER);
GLint linked = 0;
if (prog) r_GetProgramiv((GLuint)prog, GL_LINK_STATUS, &linked);
struct prog *p = prog ? find_prog((GLuint)prog, 0) : NULL;
r_GetIntegerv(GL_TEXTURE_BINDING_2D, &tex); // (on the active unit)
GLint tw = 0, th = 0, tfmt = 0, minf = 0, maxl = 0, imm = 0;
if (tex) {
r_GetTexLevelParameteriv(GL_TEXTURE_2D, 0, GL_TEXTURE_WIDTH, &tw);
r_GetTexLevelParameteriv(GL_TEXTURE_2D, 0, GL_TEXTURE_HEIGHT, &th);
r_GetTexLevelParameteriv(GL_TEXTURE_2D, 0, GL_TEXTURE_INTERNAL_FORMAT, &tfmt);
r_GetTexParameteriv(GL_TEXTURE_2D, GL_TEXTURE_MIN_FILTER, &minf);
r_GetTexParameteriv(GL_TEXTURE_2D, GL_TEXTURE_MAX_LEVEL, &maxl);
r_GetTexParameteriv(GL_TEXTURE_2D, GL_TEXTURE_IMMUTABLE_LEVELS, &imm);
}
r_GetError(); // (the queries above must not count as the game's)
LOG("trace %s(mode=0x%x n=%d) err=0x%x fb=%d status=0x%x views=%d prog=%d linked=%d mv=%d vp=%d,%d %dx%d "
"scissor=%d %d,%d %dx%d cmask=%d%d%d%d blend=%d 0x%x/0x%x,0x%x/0x%x depth=%d f=0x%x w=%d stencil=%d cull=%d "
"0x%x unit=0x%x tex2d=%d %dx%d fmt=0x%x min=0x%x maxl=%d imm=%d",
what, mode, count, err, fb, status, draw_fb_views(), prog, linked, p ? p->multiview : -1, vp[0], vp[1], vp[2],
vp[3], r_IsEnabled(GL_SCISSOR_TEST), sc[0], sc[1], sc[2], sc[3], cmask[0], cmask[1], cmask[2], cmask[3],
r_IsEnabled(GL_BLEND), bsrc, bdst, bsrca, bdsta, r_IsEnabled(GL_DEPTH_TEST), dfunc, dmask,
r_IsEnabled(GL_STENCIL_TEST), r_IsEnabled(GL_CULL_FACE), cullmode, unit, tex, tw, th, tfmt, minf, maxl, imm);
}
static void trace_before(void) {
if (debug >= 2) r_GetError();
}
static void trace_after(const char *what, GLenum mode, GLsizei count) {
if (debug < 2) return;
GLenum err = r_GetError();
GLint fb = 0;
r_GetIntegerv(GL_DRAW_FRAMEBUFFER_BINDING, &fb);
int detail;
pthread_mutex_lock(&trace_lock);
++trace_draws;
if (err) {
++trace_errors;
if (!trace_first_error) trace_first_error = err;
}
struct tfb *e = tfb_slot(fb);
if (e) {
++e->draws;
if (err) ++e->errors;
}
detail = trace_windows < TRACE_WINDOWS && trace_detail < TRACE_DETAIL;
if (detail) ++trace_detail;
trace_window();
pthread_mutex_unlock(&trace_lock);
if (detail) trace_state(what, mode, count, err);
}
static int trace_logs;
#define TRACE_CALL(fmt, ...) \
do { \
if (debug >= 2) { \
GLenum e_ = r_GetError(); \
if ((e_ || trace_logs < 40) && trace_logs < 400) { \
++trace_logs; \
LOG("trace " fmt " err=0x%x", __VA_ARGS__, e_); \
} \
} \
} while (0)
// Before a draw: bind the twin when the program is multiview and the framebuffer has no views. 1 = twin bound.
static int begin_draw(void) {
struct prog *p = cur_prog;
@@ -558,6 +720,14 @@ EXPORT void glLinkProgram(GLuint program) {
INIT();
note_program(program);
r_LinkProgram(program);
if (debug >= 2) {
GLint ok = 0;
r_GetProgramiv(program, GL_LINK_STATUS, &ok);
char log[700] = {0};
r_GetProgramInfoLog(program, sizeof(log) - 1, NULL, log);
struct prog *p = find_prog(program, 0);
LOG("trace glLinkProgram(%u) ok=%d multiview=%d log: %s", program, ok, p ? p->multiview : -1, log);
}
}
EXPORT void glDeleteProgram(GLuint program) {
@@ -626,43 +796,143 @@ static void w_ftmsmv(GLenum target, GLenum attachment, GLuint texture, GLint lev
#define DRAW(name, call) \
INIT(); \
if (!r_##name) return; \
trace_before(); \
if (begin_draw()) { \
r_##name call; \
end_draw("gl" #name); \
} else { \
r_##name call; \
}
} \
trace_after("gl" #name, call_mode, call_count);
EXPORT void glDrawArrays(GLenum mode, GLint first, GLsizei count) { DRAW(DrawArrays, (mode, first, count)) }
EXPORT void glDrawArrays(GLenum mode, GLint first, GLsizei count) {
GLenum call_mode = mode; GLsizei call_count = count;
DRAW(DrawArrays, (mode, first, count))
}
EXPORT void glDrawElements(GLenum mode, GLsizei count, GLenum type, const void *indices) {
GLenum call_mode = mode; GLsizei call_count = count;
DRAW(DrawElements, (mode, count, type, indices))
}
EXPORT void glDrawArraysInstanced(GLenum mode, GLint first, GLsizei count, GLsizei instances) {
GLenum call_mode = mode; GLsizei call_count = count;
DRAW(DrawArraysInstanced, (mode, first, count, instances))
}
EXPORT void glDrawElementsInstanced(GLenum mode, GLsizei count, GLenum type, const void *indices, GLsizei instances) {
GLenum call_mode = mode; GLsizei call_count = count;
DRAW(DrawElementsInstanced, (mode, count, type, indices, instances))
}
EXPORT void glDrawRangeElements(GLenum mode, GLuint start, GLuint end, GLsizei count, GLenum type,
const void *indices) {
GLenum call_mode = mode; GLsizei call_count = count;
DRAW(DrawRangeElements, (mode, start, end, count, type, indices))
}
EXPORT void glDrawArraysIndirect(GLenum mode, const void *indirect) { DRAW(DrawArraysIndirect, (mode, indirect)) }
EXPORT void glDrawArraysIndirect(GLenum mode, const void *indirect) {
GLenum call_mode = mode; GLsizei call_count = -1;
DRAW(DrawArraysIndirect, (mode, indirect))
}
EXPORT void glDrawElementsIndirect(GLenum mode, GLenum type, const void *indirect) {
GLenum call_mode = mode; GLsizei call_count = -1;
DRAW(DrawElementsIndirect, (mode, type, indirect))
}
EXPORT void glDrawElementsBaseVertex(GLenum mode, GLsizei count, GLenum type, const void *indices, GLint base) {
GLenum call_mode = mode; GLsizei call_count = count;
DRAW(DrawElementsBaseVertex, (mode, count, type, indices, base))
}
EXPORT void glDrawRangeElementsBaseVertex(GLenum mode, GLuint start, GLuint end, GLsizei count, GLenum type,
const void *indices, GLint base) {
GLenum call_mode = mode; GLsizei call_count = count;
DRAW(DrawRangeElementsBaseVertex, (mode, start, end, count, type, indices, base))
}
EXPORT void glDrawElementsInstancedBaseVertex(GLenum mode, GLsizei count, GLenum type, const void *indices,
GLsizei instances, GLint base) {
GLenum call_mode = mode; GLsizei call_count = count;
DRAW(DrawElementsInstancedBaseVertex, (mode, count, type, indices, instances, base))
}
// ---------------------------------------------------------------- traced calls (pass-through unless gl_mv_debug=2)
EXPORT void glClear(GLbitfield mask) {
INIT();
if (debug >= 2) r_GetError();
r_Clear(mask);
if (debug >= 2) {
GLenum err = r_GetError();
GLint fb = 0;
r_GetIntegerv(GL_DRAW_FRAMEBUFFER_BINDING, &fb);
pthread_mutex_lock(&trace_lock);
++trace_clears;
struct tfb *e = tfb_slot(fb);
if (e) ++e->clears;
pthread_mutex_unlock(&trace_lock);
if (err) LOG("trace glClear(0x%x) fb=%d err=0x%x", mask, fb, err);
}
}
EXPORT void glTexImage2D(GLenum t, GLint l, GLint ifmt, GLsizei w, GLsizei h, GLint b, GLenum f, GLenum ty,
const void *px) {
INIT();
if (debug >= 2) r_GetError();
r_TexImage2D(t, l, ifmt, w, h, b, f, ty, px);
GLint tex = 0;
if (debug >= 2) r_GetIntegerv(GL_TEXTURE_BINDING_2D, &tex);
TRACE_CALL("glTexImage2D(target=0x%x tex=%d level=%d ifmt=0x%x %dx%d fmt=0x%x type=0x%x data=%d)", t, tex, l, ifmt,
w, h, f, ty, px != NULL);
}
EXPORT void glTexSubImage2D(GLenum t, GLint l, GLint x, GLint y, GLsizei w, GLsizei h, GLenum f, GLenum ty,
const void *px) {
INIT();
if (debug >= 2) r_GetError();
r_TexSubImage2D(t, l, x, y, w, h, f, ty, px);
TRACE_CALL("glTexSubImage2D(target=0x%x level=%d %d,%d %dx%d fmt=0x%x type=0x%x)", t, l, x, y, w, h, f, ty);
}
EXPORT void glCompressedTexImage2D(GLenum t, GLint l, GLenum ifmt, GLsizei w, GLsizei h, GLint b, GLsizei size,
const void *data) {
INIT();
if (debug >= 2) r_GetError();
r_CompressedTexImage2D(t, l, ifmt, w, h, b, size, data);
TRACE_CALL("glCompressedTexImage2D(target=0x%x level=%d ifmt=0x%x %dx%d size=%d)", t, l, ifmt, w, h, size);
}
EXPORT void glTexStorage2D(GLenum t, GLsizei levels, GLenum ifmt, GLsizei w, GLsizei h) {
INIT();
if (debug >= 2) r_GetError();
r_TexStorage2D(t, levels, ifmt, w, h);
TRACE_CALL("glTexStorage2D(target=0x%x levels=%d ifmt=0x%x %dx%d)", t, levels, ifmt, w, h);
}
EXPORT void glCopyTexImage2D(GLenum t, GLint l, GLenum ifmt, GLint x, GLint y, GLsizei w, GLsizei h, GLint b) {
INIT();
if (debug >= 2) r_GetError();
r_CopyTexImage2D(t, l, ifmt, x, y, w, h, b);
GLint rfb = 0;
if (debug >= 2) r_GetIntegerv(GL_READ_FRAMEBUFFER_BINDING, &rfb);
TRACE_CALL("glCopyTexImage2D(target=0x%x level=%d ifmt=0x%x %d,%d %dx%d read fb=%d)", t, l, ifmt, x, y, w, h, rfb);
}
EXPORT void glCopyTexSubImage2D(GLenum t, GLint l, GLint xo, GLint yo, GLint x, GLint y, GLsizei w, GLsizei h) {
INIT();
if (debug >= 2) r_GetError();
r_CopyTexSubImage2D(t, l, xo, yo, x, y, w, h);
GLint rfb = 0;
if (debug >= 2) r_GetIntegerv(GL_READ_FRAMEBUFFER_BINDING, &rfb);
TRACE_CALL("glCopyTexSubImage2D(target=0x%x level=%d %d,%d from %d,%d %dx%d read fb=%d)", t, l, xo, yo, x, y, w, h,
rfb);
}
EXPORT void glGenerateMipmap(GLenum t) {
INIT();
if (debug >= 2) r_GetError();
r_GenerateMipmap(t);
TRACE_CALL("glGenerateMipmap(target=0x%x)", t);
}
EXPORT void glCompileShader(GLuint sh) {
INIT();
r_CompileShader(sh);
if (debug < 2) return;
GLint ok = 0;
r_GetShaderiv(sh, GL_COMPILE_STATUS, &ok);
char log[700] = {0};
r_GetShaderInfoLog(sh, sizeof(log) - 1, NULL, log);
if (!ok || (log[0] && trace_logs < 400)) {
++trace_logs;
LOG("trace glCompileShader(%u) ok=%d log: %s", sh, ok, log);
}
}
// A context made current on this thread (engines with a render thread move theirs between threads, e.g. Doom3Quest's
// GLimp_ActivateContext): what this thread knew about the bound program and framebuffer may be another context's.
EXPORT EGLBoolean eglMakeCurrent(EGLDisplay dpy, EGLSurface draw, EGLSurface read, EGLContext ctx) {
@@ -698,7 +968,8 @@ EXPORT __eglMustCastToProperFunctionPointerType eglGetProcAddress(const char *na
OWN(glFramebufferTexture) OWN(glDrawBuffers) OWN(glDrawArrays) OWN(glDrawElements) OWN(glDrawArraysInstanced)
OWN(glDrawElementsInstanced) OWN(glDrawRangeElements) OWN(glDrawArraysIndirect) OWN(glDrawElementsIndirect)
OWN(glDrawElementsBaseVertex) OWN(glDrawRangeElementsBaseVertex) OWN(glDrawElementsInstancedBaseVertex)
OWN(eglMakeCurrent)
OWN(eglMakeCurrent) OWN(glClear) OWN(glTexImage2D) OWN(glTexSubImage2D) OWN(glCompressedTexImage2D)
OWN(glTexStorage2D) OWN(glCopyTexImage2D) OWN(glCopyTexSubImage2D) OWN(glGenerateMipmap) OWN(glCompileShader)
#undef OWN
return fn;
}
+1 -1
View File
@@ -377,7 +377,7 @@
"dev build": "",
"Dev builds are early, less tested versions and may have bugs. You still get the next release as a normal update (you have {version}).": "",
"Developer Mode lets FramePort find and connect to the Frame; the setup turns it on for you. With it on, you can also open Settings → Developer → Pair new host on the Frame and approve FramePort there.": "",
"Diagnostics for frame.gl_multiview_fbo: checks for GL errors after every single-view draw of a multiview shader and logs counters every 5 seconds (tag GLMV in launch.log).": "",
"Diagnostics for frame.gl_multiview_fbo: checks for GL errors after every single-view draw of a multiview shader and logs counters every 5 seconds (tag GLMV in launch.log). 2 (frameport settings) also checks every draw and logs the draw state, failed texture uploads and shader compiles and, for idTech 4 engines, the game clock.": "",
"Diagnostics: removes layer color fades. Some fades no longer show.": "",
"Diagnostics: the Vulkan shim (frame.vk_sanitize) adds Khronos' validation layer to the game's instance; its findings go to launch.log. The layer library (libVkLayer_khronos_validation.so) must be in the APK.": "",
"Disable application space warp if used": "",
+3 -1
View File
@@ -215,7 +215,9 @@ SETTINGS = [
"findings go to launch.log. The layer library (libVkLayer_khronos_validation.so) must be in the APK."),
("gl_mv_debug", "int", 0, "Multiview interposer: diagnostics",
"Diagnostics for frame.gl_multiview_fbo: checks for GL errors after every single-view draw of a multiview "
"shader and logs counters every 5 seconds (tag GLMV in launch.log)."),
"shader and logs counters every 5 seconds (tag GLMV in launch.log). 2 (frameport settings) also checks every "
"draw and logs the draw state, failed texture uploads and shader compiles and, for idTech 4 engines, the game "
"clock."),
("gl_hide_msrtt", "int", 1, "GL shim: hide multisampled render-to-texture",
"GL shim only: hide GL_EXT_multisampled_render_to_texture(2) (Zink crashes rendering Unity's runtime MSAA eye "
"buffer through it, for example The Room VR)."),
+17
View File
@@ -0,0 +1,17 @@
// SPDX-License-Identifier: GPL-3.0-only
// FrameBridge's xrGetDisplayRefreshRateFB fallback (native/adapter/refresh_rate.h, GitHub #306).
#include <assert.h>
#include "refresh_rate.h"
int main(void) {
assert(fb_refresh_rate(13888888, 0) == 72.0f); // 72 Hz frame timing
assert(fb_refresh_rate(11111111, 0) == 90.0f); // 90 Hz
assert(fb_refresh_rate(8333333, 0) == 120.0f); // 120 Hz
assert(fb_refresh_rate(6944444, 0) == 144.0f); // 144 Hz
assert(fb_refresh_rate(0, 0) == 72.0f); // no xrWaitFrame yet: never 0 Hz (PreyVR: 1000 / 0 ms per tic)
assert(fb_refresh_rate(0, 90.0f) == 90.0f); // ... else the refresh_rate setting
assert(fb_refresh_rate(-5, 0) == 72.0f);
assert(fb_refresh_rate(1000, 0) == 72.0f); // nonsense periods (1 MHz, 1 Hz) aren't believed
assert(fb_refresh_rate(1000000000, 80.0f) == 80.0f);
return 0;
}
+43
View File
@@ -0,0 +1,43 @@
"""FrameBridge answers xrGetDisplayRefreshRateFB with a real rate (GitHub #306, PreyVR's black main menu).
The Frame's runtime has no XR_FB_display_refresh_rate; OVRPort's dispatcher still offers it and answered 0 Hz. Team
Beef's idTech 4 ports (PreyVR, the Doom3Quest engine) run 1000 / refresh ms per tic, so 0 Hz stopped their game and
GUI clock: the main menu stayed at its first animation step (black, only the cursor)."""
import os
import re
import shutil
import subprocess
from pathlib import Path
import pytest
import yaml
from frameport.validate import triage
ROOT = Path(__file__).resolve().parents[1]
def test_fallback_rate_is_never_zero(tmp_path):
cc = shutil.which("cc") or shutil.which("gcc") or shutil.which("clang")
if not cc or os.name == "nt":
pytest.skip("needs a POSIX host C compiler")
binary = tmp_path / "refresh-rate-test"
subprocess.run([cc, "-std=c11", "-Wall", "-Wextra", "-Werror", "-I", str(ROOT / "native/adapter"),
str(ROOT / "tests/fixtures/src/refresh_rate_test.c"), "-o", str(binary)], check=True)
subprocess.run([str(binary)], check=True)
def test_the_hook_is_always_installed():
src = (ROOT / "native/adapter/frame_adapter.c").read_text()
# not behind a per-game setting: every game that asks gets a rate, also where the runtime lacks the function
assert re.search(r"\n if \(instance != XR_NULL_HANDLE\) HOOK_AS\(xrGetDisplayRefreshRateFB, hook_get_refresh_rate\)",
src)
assert "fb_refresh_rate(" in (ROOT / "native/adapter/session_fixes.c").read_text()
def test_a_single_rejected_frame_is_not_an_error():
entries = {e["id"]: e for e in yaml.safe_load((ROOT / "catalog/triage.yaml").read_text())["signatures"]}
assert entries["cylinder-menu-layers-rejected"]["severity"] == "info"
log = "10-16 05:06:16.011 1188 1248 I FrameBridge: xrEndFrame failed -16: blend=1 layers=7\n"
found = [f for f in triage.triage(log).findings if f.id == "cylinder-menu-layers-rejected"]
assert found and found[0].severity == "info"