Ticket #848 (new defect)

Opened 13 months ago

Last modified 4 months ago

Hotloading failure while changing game scripts

Reported by: historic_bruno Owned by: jan
Priority: If Time Permits Milestone: Backlog
Component: Core engine Keywords:
Cc: jan

Description (last modified by historic_bruno) (diff)

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)

Change History

comment:1 follow-up: ↓ 2 Changed 13 months ago by 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?

comment:2 in reply to: ↑ 1 Changed 13 months ago by 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).

comment:3 Changed 13 months ago by historic_bruno

  • Description modified (diff)

comment:4 Changed 13 months ago by historic_bruno

  • Description modified (diff)

comment:5 Changed 13 months ago by jan

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.

comment:7 Changed 13 months ago by 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?

comment:8 Changed 13 months ago by jan

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?

comment:9 Changed 13 months ago by 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?

comment:10 Changed 13 months ago by jan

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.

comment:11 Changed 13 months ago by k776

  • Milestone changed from Alpha 5 to Alpha 6

comment:12 Changed 13 months ago by Philip

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.

comment:13 Changed 11 months ago by historic_bruno

  • Summary changed from Hotloading failure while changing UnitAI.js to Hotloading failure while changing game scripts

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

comment:14 Changed 11 months ago by k776

  • Owner set to jan
  • Priority changed from Must Have to Should Have
  • Milestone changed from Alpha 6 to Alpha 7

comment:15 Changed 9 months ago by k776

  • Priority changed from Should Have to If Time Permits
  • Milestone changed from Alpha 7 to Alpha 8

comment:16 Changed 7 months ago by historic_bruno

  • Milestone changed from Alpha 8 to Backlog

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

comment:17 Changed 7 months ago by jan

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

comment:18 Changed 4 months ago by Philip

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?

comment:18 Changed 4 months ago by philip

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

comment:19 Changed 4 months ago by jan

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.

comment:20 Changed 4 months ago by historic_bruno

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

Note: See TracTickets for help on using tickets.