Dev help needed: Custom track loading hangs

Discussion in 'Technical Archives' started by Jorgen, Jul 1, 2014.

  1. Jorgen

    Jorgen Registered

    Joined:
    Oct 5, 2010
    Messages:
    558
    Likes Received:
    3
    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.
     
  2. Jorgen

    Jorgen Registered

    Joined:
    Oct 5, 2010
    Messages:
    558
    Likes Received:
    3
    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?
     
  3. Jorgen

    Jorgen Registered

    Joined:
    Oct 5, 2010
    Messages:
    558
    Likes Received:
    3
    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:

    [​IMG]

    Everything is extremely sluggish once this happens, even the mouse cursor movement is jerky.
     
    Last edited by a moderator: Jul 1, 2014
  4. Jorgen

    Jorgen Registered

    Joined:
    Oct 5, 2010
    Messages:
    558
    Likes Received:
    3
    One last post, same problems on build 770 as on 769.
     
  5. Jorgen

    Jorgen Registered

    Joined:
    Oct 5, 2010
    Messages:
    558
    Likes Received:
    3
    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.
     
  6. 88mphTim

    88mphTim Staff Member

    Joined:
    Sep 23, 2010
    Messages:
    10,724
    Likes Received:
    119
    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.
     
  7. Jeremy Miller

    Jeremy Miller Former ISI Senior Programmer

    Joined:
    Oct 5, 2010
    Messages:
    276
    Likes Received:
    3
    What track is causing the problem?
     
  8. Jorgen

    Jorgen Registered

    Joined:
    Oct 5, 2010
    Messages:
    558
    Likes Received:
    3
    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?
     
  9. Jorgen

    Jorgen Registered

    Joined:
    Oct 5, 2010
    Messages:
    558
    Likes Received:
    3
    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.
     
  10. Jorgen

    Jorgen Registered

    Joined:
    Oct 5, 2010
    Messages:
    558
    Likes Received:
    3
    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.
     
  11. Jorgen

    Jorgen Registered

    Joined:
    Oct 5, 2010
    Messages:
    558
    Likes Received:
    3
    Sorry, I forgot to reply to this one. Yes, I am running the 32-bit executable.
     
  12. Jeremy Miller

    Jeremy Miller Former ISI Senior Programmer

    Joined:
    Oct 5, 2010
    Messages:
    276
    Likes Received:
    3
    If you can pm me a link to your track we can possibly try to see what the problem is.
     
  13. Jorgen

    Jorgen Registered

    Joined:
    Oct 5, 2010
    Messages:
    558
    Likes Received:
    3
    Thanks for the offer Jeremy, I really appreciate it! Will upload and PM you a link shortly.
     
  14. Jorgen

    Jorgen Registered

    Joined:
    Oct 5, 2010
    Messages:
    558
    Likes Received:
    3
    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:

    I doubt it's one of those, right? Has there been any substantial shader changes between 660 and the 770 stable/7xx unstables?
     
  15. Joe Campana

    Joe Campana Member

    Joined:
    Jan 19, 2012
    Messages:
    129
    Likes Received:
    2
    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.
     
  16. Jorgen

    Jorgen Registered

    Joined:
    Oct 5, 2010
    Messages:
    558
    Likes Received:
    3
    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)
     
  17. Jorgen

    Jorgen Registered

    Joined:
    Oct 5, 2010
    Messages:
    558
    Likes Received:
    3
    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)

    [​IMG]

    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.
     
  18. Jorgen

    Jorgen Registered

    Joined:
    Oct 5, 2010
    Messages:
    558
    Likes Received:
    3
    I have now installed Windows 7 Professional 64-bit, so I will re-test this once I have rF2 installed. Will report back later.
     
  19. Jorgen

    Jorgen Registered

    Joined:
    Oct 5, 2010
    Messages:
    558
    Likes Received:
    3
    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: Jul 21, 2014

Share This Page