Dev help needed: Custom track loading hangs

J

Jorgen

Registered
I just tried again in unstable 769 and this time a track that loaded fine in unstable 767 won't load anymore. The loading bar goes all the way to 100% and after a while it is as if rF2 goes into a tight loop where lots of system calls are executed since the "System" process in the task manager jumps to around 10% and all other applications start to run very slow and sluggish. I have run the sysinternals process monitor (http://technet.microsoft.com/en-us/sysinternals/bb896645) during the track loading, and the last things that happen before the loading halts are that rF2 writes to a temporary file in the Replays folder, after which it reads from arialbd.ttf and then everything stops.

I saved the process monitor recording and uploaded it if anyone from the dev team wants to take a look. It's available here:
http://www.racehub.se/rf2/rf2-track-loading-hangs.zip

In case you wonder, the final CloseFile events are from right after I killed the process from the task manager, about two minutes after loading reached the 100% stage. If loading succeeds, it usually never takes more than a few seconds at that point.

I would really like to figure out if it's an issue with the tracks or if it's an issue with the unstable release, because all of these tracks load fine in build 660. Any help is much appreciated.
 
This is getting bizarre... After successfully loading ISI Malaysia 1.42 and restarting the game, the track that did not load earlier actually does load. (!) The task manager shows that almost all consumed CPU time is spent in the OS kernel once the loading bar has reached 100%. The tracks that do not load have .cbash files which are more than twice as large as the tracks that do load. Not sure if it's related, but anyway. What's a .cbash file by the way?
 
I just observed the track loading in build 660, and it's a LOT less time spent in the OS kernel with that build. Almost all time is spent in user mode, except for a short 100% burst after the loading bar reaches the end, after which it drops to around 20%. Going to give it a shot with the latest 770 stable too, but considering the short time period between 769 and 770 I guess very little was done between those builds.

Can this be an effect of the combined 32- and 64-bit builds and compiler settings that do not play well on a 32-bit OS?

This is what the task manager looks like when the kernel % shoots through the roof:

rf2-track-loading-hangs.png


Everything is extremely sluggish once this happens, even the mouse cursor movement is jerky.
 
Last edited by a moderator:
More input, here is the stack trace from the thread that gets stuck:

Code: 
ntdll.dll+0xe514
d3d9.dll+0x30a2c
d3d9.dll+0x52321
d3d9.dll+0x4cced
d3d9.dll+0x3c2a2
rFactor2.exe+0xc344e
rFactor2.exe+0xbf899
rFactor2.exe+0x984ec
rFactor2.exe+0xa20d4
rFactor2.exe+0xa21d4
rFactor2.exe+0x37ff1e
rFactor2.exe+0x34bd67
rFactor2.exe+0x2cea9f
kernel32.dll+0x16037

I will definitely need help from a developer to solve this mystery.
 
You only are running the 32bit build, right? the XP kernel is not supported at all. Just reply to that, in the meantime I will alert Jeremy.
 
It's a set of conversions I originally did for our F1 league back in 2012. The league is now defunct but I keep the tracks for personal use only due to the nature of the rFactor1 tracks they were made from. Given that, if you do have some time to test, I can upload one of those that give me problems to my web space and PM you a link. Does that sound OK?
 
Wow, I just discovered that with build 772, the tracks do load, it just takes a LOT longer than with build 660. After the loading bar reaches 100%, we're talking minutes (b7xx) compared to seconds (b660) before the session is entered. The track that creates the largest .cbash file causes rF2 to crash though:

Code: 
Faulting application rfactor2.exe, version 1.7.7.2, faulting module rfactor2.exe, version 1.7.7.2, fault address 0x000551af.

I will do some timing between b660 and b772 for comparison.
 
Ok, here are the track load times in build 660 vs build 772. It's the second time the track is loaded with a restart of rF2 in between, just to have all shaders pre-generated, and also the .rrshd and .cbash files, whatever they are. Pretty significant change for the worse, unfortunately...

Code: 
                   Loading 0-100%         100% to session start
Build 660              24 seconds                    11 seconds
Build 772              36 seconds                   312 seconds
I'd love to know what the 7xx builds are doing after the loading bar reaches 100% on this particular track.
 
PM was sent a few days ago. In the meantime, some more feedback. I have been trying to set up build 772 in the exact same way as I had build 660 set up (graphical options, replay recording off, etc), and while I can get a steady 60 fps almost everywhere (vsync on) with some intermittent drops to around 50, the track is almost undrivable on build 772. I get 9 (!) fps and a red CPU bar in many sections. Something must have been fundamentally changed to yield this drop. The release notes mentions only two graphical items:

Fixed sun block bug which caused inconsistent occluder values.
Fixed a bug where HUD textures refuse to load.
Click to expand...

I doubt it's one of those, right? Has there been any substantial shader changes between 660 and the 770 stable/7xx unstables?
 
Jorgen said:
I doubt it's one of those, right? Has there been any substantial shader changes between 660 and the 770 stable/7xx unstables?
Click to expand...

not really. a couple of us have loaded your track in the viewer and in-game, and aside from the fact that it has an astounding 5500 meshes, it loaded and ran fine for us.
 
Ok, thanks for the heads-up Joe. Follow up question if I may: Does anyone in the ISI dev team or the internal test team have access to a Windows XP machine on which this can be tested? I will soon get rid of XP on my machine, but since I believe it's still supported it would be useful to know if it's just on my machine this happens, or if it is a generic XP issue. (Or rather DirectX 9.0c, since I can see via the stack that the bulk work that causes the kernel to work really hard takes place in DX9 code)
 
I went through all the graphics settings and fiddled with them, and after a while I realized that it's four settings I have to back down on quite substantially to get the loading time back to the same speed as with build 660. Below is a comparison between the settings on build 789 (left) and 660 (right) which gives me almost identical loading times: (differences are marked in yellow)

ui-settings-789-660.png


As soon as I try to up one of them by only one click, the loading starts to bog down the whole machine. I will install Windows 7 fairly soon, but it would be nice to be able to tick this off as an XP related issue, if we can prove that it is.
 
I have now installed Windows 7 Professional 64-bit, so I will re-test this once I have rF2 installed. Will report back later.
 
I can now confirm that the track loading issues I had were purely XP related. On Win7 Professional 64 bit, it takes almost zero time to enter the session once the loading bar reaches 100%. (using the 64 bit executables and with even higher graphics settings than I ever tried before) Time to drop XP support real soon!

EDIT: And it's amazing how much better everything runs now, not a single stutter anywhere on the track. Same hardware, just a different OS and 64 bit executables. Wow... :)
 
Last edited by a moderator:
You must log in or register to reply here.
Back
Top