vsonnier / vkQuake-vso

My own personnal fork of vkQuake.
GNU General Public License v2.0
7 stars 0 forks source link

error when trying to save/load a savegame #7

Closed j4reporting closed 2 months ago

j4reporting commented 3 months ago

This happens sometimes, although very rarely, during a longer session ie playing a big map and several save/load cycles. Not really sure how to replicate this and I have to admit this time I realized too late, what was going on and did not investigate more. Quit and Re-start cycle fixes this.

Map was ad_magna and the quick save game was NOT overwritten. The previous savegame was still intact. Was able to load the old savegame after restart. Unfortunately I haven't try to load other savegames, but I would guess it would have failed as well.

any idea what the reason might be for this?

vkquake-vso_error

Macil commented 3 months ago

I wonder if the process could be running out of open file handles and unable to open any more. There could be a file handle leak in loading the map data or saves.

j4reporting commented 3 months ago

out of file handles was also my first idea. It seems I can recreate this simply by playing ad_magna. Towards the end of the map, it's quite likely that this situation will occur. Today I built a debug executable and started playing. I've uploaded binary and the dump (VStudio 2022 Community).

It's very likely that some debug settings are missing... Interesting fact, the load and save screens show no available savegames. Every slot is empty.

vsonnier commented 3 months ago

Hello @j4reporting, I assume you have something like that in either your autoexec.cfg or vkQuake.cfg to enable quicksaving:

bind "F5" "echo Quicksaving...; wait; save quick"
bind "F6" "echo Quickloading...; wait; load quick"

also what are your values for the following Cvars:

cvar_t autoload = {"autoload", "1", CVAR_ARCHIVE};
cvar_t autofastload = {"autofastload", "0", CVAR_ARCHIVE};

I'll try to follow the corresponding code paths trying to see if we lost file handles along the way.

j4reporting commented 3 months ago

Hi vsonnier,

quicksave/load are default but re-assigned to F6 / F9

autoload 0 autofastload 0

in case this is important... this is the content of C:\games\vkquake\

$ ls -F /c/Games/vkquake/
_BAK/            alk_maps/     dopa/               honey/          libmikmod-3.dll*      q25limit/   rubicon2/   spiritworld/              wicked/
_FEDORA/         alk1.1/       dwellv1p2/          hwjam/          libmpg123-0.dll*      qbj2/       SDL2.dll*   tainted/                  xmasjam2018/
_OLD_BIN/        alk1.2/       dwellv2p2/          hwjam2/         libogg-0.dll*         quoffee2/   sewerjam2/  terra/                    xmasjam2019/
_TMP/            alkaline/     eod/                hwjam3/         libopus-0.dll*        quoth/      sf/         vkQuake.dmp               xmasjam2020/
_vkquake.bat     backstein/    eoe/                hwjam4/         libopusfile-0.dll*    ravenkeep/  sm190/      vkQuake.exe*              xmasjam2021/
1000cuts/        bak/          explorejam3_v1/     id1/            libvorbis-0.dll*      reload/     sm218/      vkQuake_debug.exe*
ad/              bv/           explorejam3_v1.15/  jam2/           libvorbisfile-3.dll*  rm1.0/      sm219/      vkQuake_Novum.exe*
ad_gibtropolis/  copper/       fbj/                jjj2/           libxmp.dll*           rm1.1/      sm221/      vkQuake_Novum_debug.exe*
ad_heresp1/      copper_120/   fear/               jpqm12/         LICENSE.txt           rmj1/       sm222/      vkQuake_prev.exe*
ad_heresp2/      copper_maps/  get_git.bat         jpqm4/          m_aur1_amuse/         rogue/      sm225/      vkQuake_prev2.exe*
ad_maps/         ctsj2/        get_msys2.bat       jpqm9/          m_azuremoon/          rotj/       sm226/      vkQuake_release.exe*
ad_replicon11/   custom_maps/  hipnotic/           libFLAC-8.dll*  pun/                  rrp/        smej/       vkQuake_w64devkit.exe*
ad_TEST/         dmd/          history.txt         libmad-0.dll*   purifier/             rubicon/    smej2/      vkQuake-vso_debug.exe*

I also use F2/F3 to save/load from the default savegame slots s[0-19].sav .

vsonnier commented 3 months ago

It seems I can recreate this simply by playing ad_magna.

Interesting fact, the load and save screens show no available savegames. Every slot is empty.

quicksave/load are default but re-assigned to F6 / F9

I also use F2/F3 to save/load from the default savegame slots s[0-19].sav .

in case this is important... this is the content of C:\games\vkquake\

Thanks @j4reporting, however I need to be the closest to you configutation. Thankfully there is a simpler way than detailing everything : attach a zip of your ad and id1 dir without the content of course, that should contain have someting like:

id1/autoexec.cfg
id1/vkQuake.cfg
ad/vkQuake.cfg
ad/save*.sav
ad/quake.rc

and describe your way to launch and run ad_magna and such.

vsonnier commented 3 months ago

BTW are you the 'j4r' that helped me about GCC 14 on https://www.slipseer.com/ site ? I goes by 'vso' there.

j4reporting commented 3 months ago

here we go. I made some changes just a few days ago. I moved the old config.cfg file to _config.cfg (ad and id1) and replaced with a new file with just a comment in ad. Did also comment out some settings in quake.rc that are not available in vkquake.

there are also screenshots (not imcl;uded) vkquake0000.png to vkquake0078.png, I should probably remove some ;)

startup procedure. windows terminal -> power shell

cd c:\games\vkquake  
.\vkquake.exe -game ad  
   (  ./vkquake -game ad    works also)

load s0.sav via F3 and proceed to the level. (in case of ad_magna via ad_chapters )

j4r@slipseer positive! vkq_configs.zip

vsonnier commented 3 months ago

Thanks @j4reporting, I've installed your setup, and of course , did not manage to reproduce the problem for the (relatively short) time I toyed with it.

Still, there is something I don't like the way the saves are loaded in the current Quakespasm and changed the method in the tentative fix you can see above.

I've never played AD beyond the test maps before so now I'm going to play ad_magna and save a lot, for science.

If you have the time, please try this fix and tell me if the problem is gone or not for you.

j4reporting commented 3 months ago

AD is really great. It's better to play the smaller maps first before tacklingt the really big maps like ad_sepulcher. The test maps are indeed a great way to start.

Too bad that I've found a quick and easy way to reproduce, ;) The issue seems to be the handling of pak files, in case of AD for the ad/pak0,pak file. My guess is that FDs are not released after files were extracted/read from this pak file.

how to reproduce

map ad_magna ( in fact any AD map).   
save quick 

now keep reloading  with load quick  (keep pressing the F key   until process reaches the  limit of max allowed number of open files.

Process Monitor (sysinternals) with this filter:

image

ending process shows this:
with https://github.com/vsonnier/vkQuake-vso/commit/19d76588037977f59506c18aa3d307f8f5124d0f


01:31:09,1477950    vkQuake_Novum.exe   31212   28552   ReadFile    C:\Games\vkquake\id1\music\track09.ogg  SUCCESS Offset: 299.484, Length: 2.048
01:31:09,1478013    vkQuake_Novum.exe   31212   28552   ReadFile    C:\Games\vkquake\id1\music\track09.ogg  SUCCESS Offset: 301.532, Length: 2.048
01:31:09,1478082    vkQuake_Novum.exe   31212   28552   ReadFile    C:\Games\vkquake\id1\music\track09.ogg  SUCCESS Offset: 303.580, Length: 2.048
01:31:09,8949621    vkQuake_Novum.exe   31212   28552   CloseFile   C:\Games\vkquake\id1\music\track09.ogg  SUCCESS 
01:31:09,8952102    vkQuake_Novum.exe   31212   28552   CreateFile  C:\Games\vkquake\ad\vkQuake.cfg SUCCESS Desired Access: Generic Write, Read Attributes, Disposition: OverwriteIf, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 0, OpenResult: Overwritten
01:31:09,8954825    vkQuake_Novum.exe   31212   28552   CloseFile   C:\Games\vkquake\ad\vkQuake.cfg SUCCESS 
01:31:09,8959620    vkQuake_Novum.exe   31212   28552   CreateFile  C:\Games\vkquake\history.txt    SUCCESS Desired Access: Generic Write, Read Attributes, Disposition: OverwriteIf, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 0, OpenResult: Overwritten
01:31:09,8961126    vkQuake_Novum.exe   31212   28552   CloseFile   C:\Games\vkquake\history.txt    SUCCESS 
01:31:10,1135627    vkQuake_Novum.exe   31212   28552   CloseFile   C:\Games\vkquake\id1\pak0.pak   SUCCESS 
01:31:10,1135801    vkQuake_Novum.exe   31212   28552   CloseFile   C:\Games\vkquake\id1\pak1.pak   SUCCESS 
01:31:10,1136113    vkQuake_Novum.exe   31212   28552   CloseFile   C:\Games\vkquake\id1\pak2.pak   SUCCESS 
01:31:10,1136259    vkQuake_Novum.exe   31212   28552   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:31:10,1136341    vkQuake_Novum.exe   31212   28552   CloseFile   C:\Games\vkquake\ad\pak1.pak    SUCCESS 
01:31:10,1136418    vkQuake_Novum.exe   31212   28552   CloseFile   C:\Games\vkquake\ad\pak2.pak    SUCCESS 

ReadFile music\tracj09.ogg plays the ext. music track

one CloseFile line for each pak file in ID1 and AD

this is how it looks like in current master after loading man ad_magna + quit we get 21 additional CloseFile lines


01:42:54,5518648    vkQuake.exe 15260   16872   ReadFile    C:\Games\vkquake\id1\pak2.pak   SUCCESS Offset: 5.718.614, Length: 40.960
01:42:54,5518962    vkQuake.exe 15260   16872   ReadFile    C:\Games\vkquake\id1\pak2.pak   SUCCESS Offset: 5.759.574, Length: 4.096
01:42:54,8916312    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\id1\music\track09.ogg  SUCCESS 
01:42:54,8920443    vkQuake.exe 15260   16872   CreateFile  C:\Games\vkquake\ad\vkQuake.cfg SUCCESS Desired Access: Generic Write, Read Attributes, Disposition: OverwriteIf, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 0, OpenResult: Overwritten
01:42:54,8923446    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\vkQuake.cfg SUCCESS 
01:42:54,8928208    vkQuake.exe 15260   16872   CreateFile  C:\Games\vkquake\history.txt    SUCCESS Desired Access: Generic Write, Read Attributes, Disposition: OverwriteIf, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 0, OpenResult: Overwritten
01:42:54,8929716    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\history.txt    SUCCESS 
01:42:55,1023959    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\id1\pak0.pak   SUCCESS 
01:42:55,1024301    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\id1\pak1.pak   SUCCESS 
01:42:55,1024377    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\id1\pak2.pak   SUCCESS 
01:42:55,1024466    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1024640    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak1.pak    SUCCESS 
01:42:55,1024984    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak2.pak    SUCCESS 

01:42:55,1114158    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1114396    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1114528    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1114658    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1114813    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1114937    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1115060    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1115230    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1115550    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1115662    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1115787    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1115920    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1116022    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1116133    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1116281    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1116507    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1116671    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1116838    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1116999    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1117183    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 
01:42:55,1117347    vkQuake.exe 15260   16872   CloseFile   C:\Games\vkquake\ad\pak0.pak    SUCCESS 

We add 20 more CloseFIle lines with each load quick.

Ironwail has the same issue....

vsonnier commented 2 months ago

Great catch @j4reporting ! Ironwail has the same problem because this is where I cherry-picked the code in the first place :)

Indeed with that fix, I no longer see an Handle count increase in Process Explorer, while it was 20 more or so at each load like you noticed.

I've pushed that fix on the vkQuake master. My tentative (non)-fix will stay on vkQuake-vso for now.

Since you are a fan of quicksaves, consider using autofastload 1 to have near-instantaneous loadings.

Of course, with such a setting the handle leak would have been non-existent since no resources are reloaded if the current map is the same as the save. I good thing you didn't use that before !

j4reporting commented 2 months ago

I think under Unix/Linux I could have found it more easily with trace and lsof. I kind of tricked myself using process explorer on Windows. I always double-clicked on the process to open the process information window. But it shows only the number of handles and no specific handle details. Instead I needed to activate the lower pane in the main window to display the files referenced by the handles... not very intuitive

I kind of always suspected that ironwail might have the same issue. I rember someone already mentioned something similar in an ironwail issue. Of course, once you find a quick and easy way to reproduce...