itwinjs-core icon indicating copy to clipboard operation
itwinjs-core copied to clipboard

Viewport's `waitForSceneCompletion` hangs, no elements displayed

Open tomas-kvaraciejus-bentley opened this issue 6 months ago • 18 comments

The Viewport component intermittently fails to render any elements for a model. The Viewport can still be interacted with - the camera can be moved, the background can be changed, we can even zoom into the elements by their ids (the position of the camera shifts to the right location but the elements are not rendered).

Additionally, the Promise in viewport.waitForSceneCompletion hangs when this happens. After some debugging, I've discovered that it could be related to some Tile requests failing to resolve. From what I understand, they're queued up and dispatched, but either never resolve or fail in a way that doesn't raise any exceptions.

We also often get these warnings in our logs, although they also sometimes appear on without the Tile requests having failed:

2025-09-11 16:37:32.170 [warn] |SQLite| rc=17, statement aborts at 33: database schema has changed; [INSERT OR REPLACE INTO be_Prop (Namespace,Name,Id,SubId,TxnMode,RawSize,Data,StrData) VALUES(?,?,?,?,?,?,?,?)] 
2025-09-11 16:37:32.171 [info] |BeSQLite| Created file 'C:\Users\[USER]\AppData\Local\iModelJs\exchangeUiTests\ChangeManagementWorkflow\test.bim.Tiles' 
2025-09-11 16:37:32.171 [warn] |SQLite| rc=1, no such table: TileTree3 in "DROP TABLE TileTree3" 
2025-09-11 16:37:32.172 [warn] |SQLite| rc=1, no such table: TileTree4 in "DROP TABLE TileTree4" 
2025-09-11 16:37:32.172 [warn] |SQLite| rc=1, no such table: TileTreeCreateTime2 in "DROP TABLE TileTreeCreateTime2" 
2025-09-11 16:37:32.172 [warn] |SQLite| rc=1, no such table: TileTreeCreateTime3 in "DROP TABLE TileTreeCreateTime3" 
2025-09-11 16:37:32.172 [warn] |SQLite| rc=1, no such table: TileTreeCreateTime4 in "DROP TABLE TileTreeCreateTime4" 
2025-09-11 16:37:32.172 [warn] |SQLite| rc=17, statement aborts at 11: database schema has changed; [SELECT 1 FROM sqlite_master where type='table' AND name=?] 
2025-09-11 16:37:32.172 [warn] |SQLite| rc=1, no such table: BRepMeta in "DROP TABLE BRepMeta" 
2025-09-11 16:37:32.172 [warn] |SQLite| rc=1, no such table: BRepData in "DROP TABLE BRepData" 
2025-09-11 16:37:38.561 [info] |DgnCore| [BisCore].[SubCategory].Rank - missing accessors for custom-handled property 

We haven't figured out how to reproduce this consistently, but once the rendering issue happens once it persists until we restart VSCode.

We've had this issue for months across many core-frontend versions (currently on 5.1.4).

The errors about "no such table" are harmless and unrelated. We're going to need some more information to try and figure out why tile requests are failing.

pmconne avatar Sep 11 '25 16:09 pmconne

Unfortunately that's all the information I could gather. I didn't hit any caught or uncaught exception breakpoints while debugging. Is there anything else I could do to provide you more information? If it helps, we have an item for this in our backlog with an example log file of when this occurred, maybe there could be something useful there too - https://dev.azure.com/bentleycs/EngSim/_workitems/edit/1704137.

The item you linked to doesn't mention or attach any logs as far as I can tell. What are you doing when this problem occurs? Is it an electron app or web app? How frequently does it occur? What kind of tiles (reality model? map? iModel)? Does it happen with all iModels/reality models, or only specific one(s)? If iModel tiles, are you using "experimental" tiles supplied by mesh export service, or the default backend-generated tiles? Etc etc.

pmconne avatar Sep 12 '25 09:09 pmconne

Logs should be linked now, forgot that I had to click save to attach. It's a Studio app, so Electron. This usually happens on startup. We don't know how to consistently reproduce it, but generally once it happens once it persists on every subsequent startup until we re-open VSCode with a different set of permissions, for example if we're running VSCode with administrator privileges it persists even if we close it and open it as administrator again. If we open it without elevated privileges the Viewport starts rendering elements again. Vice-versa for running it as a regular user first.
We only display the iModel, and I believe we only use the default backend-generated tiles.

Thanks.

Can you clarify what you mean by "on startup"? I assume it can't be observed until you open an iModel. Does it only ever occur with the first iModel you open, or can it begin occurring only after you open a second (or more) iModel?

Does it ever occur if you run iTwin Studio normally - not via VSCode?

The fact that it persists until you change permissions suggests there might be a problem with the tile cache file (a SQLite database with a ".Tiles" extension). Have you determined if Studio puts the .Tiles files in a different directory based on user permissions? If you delete the .Tiles files after the issue occurs, does the issue resolve when rerunning VSCode with the same permissions?

pmconne avatar Sep 12 '25 11:09 pmconne

Currently the lifetime of the Viewport is tied directly to the lifetime of our application - the model is opened for viewing on startup and only closes on application exit, so startup in this case just means opening a model to view it.

After some testing I think I've found a way to reproduce it. Force-stopping the VSCode debugging session while the frontend process is halted on a breakpoint seems to do the trick - the model fails to load in the subsequent session. I'm not sure if we've managed to reproduce it running it without VSCode.

The .Tiles files are cleaned up and freshly generated every time the model loads, deleting them after closing the application has no effect. They are generated in the same folder under AppData/local for both regular and elevated permission sessions. Strangely, the generated "{modelName}.bim.Tiles" file starts out at about 60kb, then grows to 160kb when the Viewport works, and only 84kb when the rendering fails.

The .Tiles files are cleaned up and freshly generated every time the model loads

By whom, and why?

Strangely, the generated "{modelName}.bim.Tiles" file starts out at about 60kb, then grows to 160kb when the Viewport works, and only 84kb when the rendering fails.

Can you provide an example of a .Tiles file from when the Viewport worked and another from when rendering failed?

pmconne avatar Sep 12 '25 13:09 pmconne

Here's the Tiles.zip file with both the working (160kb) and broken (84kb) Tiles files. Cleanup is performed by us, generation I'd assume is performed automatically when the iModel is opened, since we don't seem to have any code explicitly related to this on our end.

The broken .Tiles file contains 2 tiles; the working one contains 3 more tiles in addition to those 2. That's the only difference I can see. I suspect that when you force-kill the process from the debugger, you leave behind a .wal file next to the .Tiles database. Can you confirm that hypothesis? What does your "cleanup" code look like?

pmconne avatar Sep 25 '25 11:09 pmconne

I can confirm that a {name}.bim-wal file is present in the directory, but it's presence doesn't seem to be related to the issue - it's always left behind when the process closes, both naturally and by killing the debugging session. Our cleanup code is simply to rmdir the entire directory before loading the iModel.

Does this ever occur outside of the context of force-killing the process in the debugger? Does it ever occur outside of debugger?

pmconne avatar Sep 25 '25 12:09 pmconne

Yes, this has happened outside of the debugger too, but we haven't figured out how to reproduce it consistently outside of force-killing a debugged instance.

Hey, any updates on this? I recently noticed this log too: Image I don't know if it's related, but the error only seems to fire when force closing the application with the display bug present, and at no other time.

@tomas-kvaraciejus-bentley No updates. Have you managed to find repro steps outside of force-closing an application?

markschlosseratbentley avatar Oct 10 '25 11:10 markschlosseratbentley

No, nothing else seems to cause this consistently.

Hi, once again asking if there's any updates on this issue.

Hi @tomas-kvaraciejus-bentley - is this issue continuing to occur, even on later versions of iTwin.js? Just checking. Have any specific consistent reproduction steps been narrowed down (preferably in a simple app or example)?

markschlosseratbentley avatar Dec 01 '25 13:12 markschlosseratbentley

Hey, this is happening with iTwin.js version 5.0.0. As I've mentioned, we can consistently reproduce this issue by force-closing the application while the frontend is halted during a debug session (i.e. frozen on a breakpoint).