Hotloading failure while changing game scripts

[historic_bruno]

OS: Windows 7 64-bit

Release build [9477]

---

Assertion failed: "0 && (L"GetBuffer() called with no file loaded")"
Location: Filesystem.cpp:132 (CVFSFile::GetBuffer)

Call stack:

CVFSFile::GetBuffer (filesystem.cpp:132)
    this = (unavailable)

CComponentManager::LoadScript (componentmanager.cpp:138)
    this = (unavailable)
    filename = 0x0072F4B8 -> 
        path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
        separator = "/r굴퀜r)"

    hotload = true 
    content = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
    file = 
        m_Buffer = 
            px = 0x1DB73F38 -> [8] { 200 (0xC8), 238 (0xEE), 42 (0x2A), 0 (0x00), 1 (0x01), 0 (0x00), 0 (0x00), 0 (0x00) }
            pn = 
                pi_ = 0x00000000


        m_BufferSize = 0 (0x00000000)


CSimulation2Impl::ReloadChangedFile (simulation2.cpp:175)
    this = (unavailable)
    path = 0x165642F8 -> 
        path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
        separator = "js"


CSimulation2Impl::ReloadChangedFileCB (simulation2.cpp:119)
    param = 0x164DC060
    path = 0x0072F4B8 (see above)

ReloadChangedFiles (filesystem.cpp:90)
    notifications = (error -100500 while analyzing vector<DirWatchNotification >)
    pathname = 
        path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
        separator = 44404


Frame (main.cpp:296)
    need_update = (bool)0x9B
    TimeSinceLastFrame = -0.000000 (0x80000000)
    need_render = (bool)0x3C
    down = [3] { -0.866025 (0xBF5DB3D7), -0.500000 (0xBF000000), 0.000000 (0x0072F700) }

RunGameOrAtlas (main.cpp:492)
    argc = 1 (0x00000001)
    argv = 0x02AF8650 -> 0x02AB8DD8 -> "C:\Users\Ben\devel\ps\binaries\system\pyrogenesis.exe"
    args = 
        m_Args = (error -100500 while analyzing vector<pair<CStr8,CStr8> >)
        m_Arg0 = 
            path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
            separator = 28632


    paths = 
        m_root = 
            path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
            separator = 464

        m_rdata = 
            path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
            separator = 14458

        m_data = 
            path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
            separator = 63152

        m_config = 
            path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
            separator = 0

        m_cache = 
            path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
            separator = 14515

        m_logs = 
            path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
            separator = 44276


    replay = 
        m_Stream = 0xB40001B5 -> (error -100406 while analyzing basic_istream<char,char_traits<char> >)

    mod = 
        path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
        separator = 2

    zip = 
        path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
        separator = 128

    paths = 
        m_root = 
            path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
            separator = 464

        m_rdata = 
            path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
            separator = 14458

        m_data = 
            path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
            separator = 63152

        m_config = 
            path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
            separator = 0

        m_cache = 
            path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
            separator = 14515

        m_logs = 
            path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
            separator = 44276


    builder = 
        m_VFS = 
            px = 0x00000135
            pn = 
                pi_ = 0xB40001B5 (see above)


        m_Files = (error -100500 while analyzing vector<Path >)
        m_TempDir = 
            path = (error -100500 while analyzing basic_string<wchar_t,char_traits<wchar_t> >)
            separator = 53 ('5')



main (main.cpp:511)
    argc = 1 (0x00000001)
    argv = 0x02AF8650 (see above)

wmain (wseh.cpp:380)
    argc = 1 (0x00000001)
    argv = 0x02AB1400 -> 0x02AB1408 -> "C:\Users\Ben\devel\ps\binaries\system\pyrogenesis.exe"
    utf8_argv = (error -100500 while analyzing vector<char * >)
    ret = 2647718 (0x002866A6)
    utf8 = (error -100500 while analyzing string >)

__tmainCRTStartup (crtexe.c:583)
    nested = 0 (0x00000000)

CallStartupWithinTryBlock (wseh.cpp:397)
    ret = 3257310886 (0xC2269EA6)

BaseThreadInitThunk (:0)

RtlInitializeExceptionChain (:0)

RtlInitializeExceptionChain (:0)


errno = 0 (?)
OS error = 0 (no error code was set)

[Jan Wassenberg]

Unable to reproduce. I launched both debug and release builds with -autostart="We Are Legion", opened UnitAI.js in VS while it was running, and inserted/removed a space and saved. ReloadChangedFileCB was executed without issue.

How are you triggering this? Does it always happen?

[historic_bruno]

Replying to jan:

Unable to reproduce. I launched both debug and release builds with -autostart="We Are Legion", opened UnitAI.js in VS while it was running, and inserted/removed a space and saved. ReloadChangedFileCB was executed without issue.

How are you triggering this? Does it always happen?

It's a consistent error I'm afraid :/ I can reproduce it by adding a string of random characters, saving, then removing them and saving again. The map doesn't seem to make any difference (reproduced on both We Are Legion and Death Canyon).

[Jan Wassenberg]

huh. Which editor are you using? Again, I can successfully change the file with VS 2010. Maybe it was detecting that my add/remove space action didn't actually change the file; but if I insert text such as "blub" after the "function" keyword, then save, it says "syntax error: expected ( after.." in game, thus confirming the successful hotload. So what else are we doing different? I'm starting the debug build from within VS with autostart as mentioned above. This is on the D: drive in a path that doesn't contain any special characters nor spaces.

[historic_bruno]

I'm using Notepad++ to change the file. I built the game in VC++ 2008 Express. My C: drive is an SSD, could this possibly make a difference?

[Jan Wassenberg]

Well, let's continue ruling things out. It works here when running pyrogenesis.exe from SVN, which I believe is still built by VC2008. Can you confirm that one also works for you? (It's dated 2011-05-05, which is before some hotloading changes, but at least after the major IO changes.)

I can also use Notepad++ to successfully change+hotload the file, as per the above experiment. (This might have made a difference - some tools create a temp file and rename it to the destination, others just truncate and start writing directly to the file.) My drive is also an SSD, and I note that your path doesn't contain special characters nor spaces, either. My OS is also Win7 x64, just upgraded to SP1 today, so I'm running out of ideas - except maybe for the compiler. Any chance of getting your hands on VC2010 EE?

[historic_bruno]

I tried the autobuild, and it took a bit longer to reproduce the error (maybe 10 or so attempts at adding and removing text before it finally failed). Can you try editing the file multiple times like that?

[Jan Wassenberg]

huh. Seems my luck ran out today. The exact same test (autobuild, open death canyon, change UnitAI.js in notepad) now fails as you describe. This doesn't happen even after ~20 attempts when only the main menu is running. I'm still not able to reproduce this in a self-built VC2010 debug EXE, even on the death canyon map and after dozens of hotloads.

[Philip Taylor]

If I remember correctly, the "GetBuffer() called with no file loaded" error happens when successfully loading a 0-byte file, which is probably a bug (but not the real problem here).

I think the problem is probably with editors that truncate then rewrite the file, instead of atomically renaming a temporary file, if the game is running fast enough that it catches the first file change notification and reloads before the writing has finished. There's also problems with tools that delete the file entirely then rewrite it (I forget which but I'm fairly sure I've encountered that problem occasionally) where the game tries to reload the file in the period where it doesn't exist.

Maybe the hotloading code should have some kind of added delay, so it doesn't report file X has changed until the latest change notification for X is >200ms old or something. (If there's multiple notifications within 200ms of each other (e.g. the file is huge and being written very slowly) then wait until 200ms after the last one, not the first). That should make it more tolerant of temporarily invalid filesystem states.

[historic_bruno]

Adjusting the title because I get this while editing other files, too.

[historic_bruno]

Hmm I think this is unlikely to be addressed soon, so I'll just put it on backlog.

[Jan Wassenberg]

Ooh, indeed this fell off the end of my todo list. Sorry, no progress will be possible until I'm back mid-November.

[Philip Taylor]

I'm not sure this is necessarily the same problem reported here, but it appears to be a problem that often makes hotloading not work at all with the current implementation, so it may be:

• I change a file like C:\0ad\binaries\data\mods\public\art\actors\whatever.xml
• dir_watch_Poll returns a path like C:\0ad\build\workspaces\vc2010\..\..\..\binaries\data\mods\public\art\actors\whatever.xml
• ReloadChangedFiles calls g_VFS->GetVirtualPath with that path.
• GetVirtualPath recurses over the VFS tree checking equality with AssociatedDirectory(), which returns paths like C:\Users\Philip\AppData\Roaming\0ad\cache\mods\internal\ (for the VFS root) and C:\0ad\build\workspaces\vc2010\..\..\..\binaries\data\mods\internal\art\actors\ etc, which doesn't match the changed path because of public vs internal.
• If GetVirtualPath does manage to find the right path, then g_VFS->RepopulateDirectory(pathname.Parent()) is called, where Parent() will return ...\art\actors, which seems to get looked up as the directory ...\art\, so the repopulation occurs one level too high. Presumably it needs to be RepopulateDirectory(pathname.Parent()/"") instead.

I think GetVirtualPath is the biggest problem. Using AssociatedDirectory seems fundamentally broken in the presence of mods, because many directories may be associated with one virtual path. (We only need one associated directory for writing, but many for reading.)

Possible solution: Make vfs::Mount append to a list of (mountPoint, path) pairs. GetVirtualPath(realPathname, ...) can then simply iterate over that list, look for any previous mountPoint that is a prefix of realPathname, and return the mounted path plus suffix. (We can safely assume a single physical path won't be mounted into two different virtual paths, because that would be weird). That sounds to me like it'll correctly identify the virtual path for any (non-archived) physical path under a mount, which is what we need. Are there any reasons that can't work?

[philip]

(In [10977]) Partially fix hotloading (see #848)

[Jan Wassenberg]

The fix looks good - RepopulateDirectory should have been ensuring its argument is a directory. In fact it might be good to assert Path::IsDirectory in all vfs functions that take a "path" (not pathname).

We have long been thinking of using a list of mountings, not just the associated directory. I know we discussed it at least twice, but some workaround was always found that allowed the associated directory thingy to creak along. I think a vector would be the more proper solution (albeit a bit more heavyweight), it definitely should work better.

[historic_bruno]

Thanks for taking a look into this Philip, I knew there was more wrong than just a misbehaving text editor :)