search

dosbox-staging / dosbox-staging

DOSBox Staging is a modern continuation of DOSBox with advanced features and current development practices.
https://www.dosbox-staging.org/
Other
1.27k stars 153 forks source link

Crystal Caves, Episode 1: After Restoring a Saved Game, If You Attempt to Save Again, Game Displays `File Error` Message #3262

Closed MasterO2 closed 8 months ago

MasterO2 commented 8 months ago

Windows 10, 64-bit https://github.com/dosbox-staging/dosbox-staging/releases/download/v0.81.0-rc1/dosbox-staging-windows-msys2-x86_64-v0.81.0-rc1.zip

Crystal Caves: Episode 1, CC1.EXE, has a save game bug where if you restore a saved game after saving it in slot 0, and then try to save again it in slot 0, Crystal Caves displays an error message FILE ERROR. It does not do that in Staging 0.80.1. The error occurred on the 0.81 RC Windows, 64-bit zip file release.

The game folder is not read-only. This problem also did not occur at all in Dosbox-Staging 0.80-1, Windows 10, 64-bit.

Yes, the mounted dosgames folder path has a space in it which is surrounded by single quotation marks.

Could it possibly have something to do with https://github.com/dosbox-staging/dosbox-staging/issues/2965?


dosbox.exe -noprimaryconf
date       time         |
2023-12-24 17:10:58.892 | arguments: dosbox.exe -noprimaryconf
2023-12-24 17:10:58.892 | Current dir: D:\stuff\dian war\emus\dosbox-staging-windows-msys2-x86_64-v0.81.0-rc1
2023-12-24 17:10:58.892 | stderr verbosity: 0
2023-12-24 17:10:58.892 | -----------------------------------
2023-12-24 17:10:58.893 | dosbox-staging version 0.81.0-rc1
2023-12-24 17:10:58.893 | ---
2023-12-24 17:10:58.893 | LOG: Loguru version 2.1.0 initialised
2023-12-24 17:10:58.893 | CONFIG: Using portable configuration layout in 'D:\stuff\dian war\emus\dosbox-staging-windows-msys2-x86_64-v0.81.0-rc1'
2023-12-24 17:10:58.894 | LANG: Using internal English language messages
2023-12-24 17:10:58.910 | SDL: version 2.28.5 initialised (windows video and wasapi audio)
2023-12-24 17:10:58.910 | DISPLAY: Initialised 1067x800 windowed mode using bilinear scaling on display-0
2023-12-24 17:10:59.162 | OPENGL: Vendor: NVIDIA Corporation
2023-12-24 17:10:59.162 | OPENGL: Version: 4.6.0 NVIDIA 462.75
2023-12-24 17:10:59.162 | OPENGL: GLSL version: 4.60 NVIDIA
2023-12-24 17:10:59.162 | OPENGL: NPOT textures supported
2023-12-24 17:10:59.162 | RENDER: Using adaptive CRT shader based on the graphics standard of the video mode
2023-12-24 17:10:59.188 | RENDER: Auto-switched to shader 'crt/hercules'
2023-12-24 17:10:59.188 | VGA: Pixel doubling enabled
2023-12-24 17:10:59.188 | VIDEO: Using the DOS video mode's frame rate
2023-12-24 17:10:59.195 | MEMORY: Using 4096 DOS memory pages (16 MB) at address: 000001AAEC51D040
2023-12-24 17:10:59.195 | VGA: Double scanning VGA video modes enabled
2023-12-24 17:10:59.196 | VIDEO: Initialised S3 Trio64 VESA 2.0 compatible with 4 MB of FP DRAM supporting 86 modes
2023-12-24 17:10:59.200 | VOODOO: Initialized with 4 MB of RAM, multithreading, and no bilinear filtering
2023-12-24 17:10:59.201 | CAPTURE: Image capturer started
2023-12-24 17:10:59.281 | MIXER: Negotiated 2-channel 48000 Hz audio of 1024-frame blocks
2023-12-24 17:10:59.281 | MIXER: Master compressor enabled
2023-12-24 17:10:59.532 | MIDI: Opened device: win32
2023-12-24 17:10:59.534 | MPU-401: Running in intelligent mode on ports 330h and 331h
2023-12-24 17:10:59.535 | OPL: Operating at 48000 Hz without resampling
2023-12-24 17:10:59.535 | OPL: Running OPL3 on ports 220h and 388h
2023-12-24 17:10:59.536 | SB16: Sound Blaster 16 OPL output filter enabled
2023-12-24 17:10:59.536 | DMA: Initialised primary controller
2023-12-24 17:10:59.536 | DMA: Initialised secondary controller
2023-12-24 17:10:59.537 | SB: Operating at 22050 Hz and upsampling to the output rate
2023-12-24 17:10:59.538 | SB16: Modern DAC output filter enabled
2023-12-24 17:10:59.538 | SB16: Setting 'BLASTER' environment variable to 'A220 I7 D1 H5 T6'
2023-12-24 17:10:59.538 | SB16: Running on port 220h, IRQ 7, DMA 1, and high DMA 5
2023-12-24 17:10:59.539 | PCSPEAKER: Operating at 48000 Hz without resampling
2023-12-24 17:10:59.539 | PCSPEAKER: Initialised discrete model
2023-12-24 17:10:59.539 | PCSPEAKER: Highpass filter enabled (18 dB/oct at 120 Hz)
2023-12-24 17:10:59.540 | PCSPEAKER: Lowpass filter enabled (12 dB/oct at 4800 Hz)
2023-12-24 17:10:59.541 | MOUSE: Will be captured after the first left or right button click
2023-12-24 17:10:59.541 | MOUSE: Middle button will capture/release the mouse (clicks not sent to the game/program)
2023-12-24 17:10:59.542 | MOUSE (PS/2): Standard, 3 buttons
2023-12-24 17:10:59.561 | DOS: Loaded modern locale for country 1, 'United States'
2023-12-24 17:10:59.561 | SLIRP: Slirp version: 4.7.0
2023-12-24 17:10:59.563 | SLIRP: Successfully initialized
2023-12-24 17:10:59.563 | NE2000: Initialised on port 300h and IRQ 3
2023-12-24 17:10:59.567 | CONFIG: Loaded auto-mounted drive config file 'resources\drives\y.conf'
2023-12-24 17:10:59.614 | MAPPER: No joysticks found
2023-12-24 17:10:59.614 | MAPPER: Loaded default key bindings
2023-12-24 17:10:59.623 | RENDER: Auto-switched to shader 'crt/vga-1080p'
2023-12-24 17:10:59.623 | SDL: Using standard SDI (auto) display refresh rate of 144 Hz
2023-12-24 17:10:59.650 | DISPLAY: VGA 720x400 16-colour text mode 03h at 70.087 Hz VFR, scaled to 1067x800 pixels with 1:1.35 (20:27) pixel aspect ratio
2023-12-24 17:10:59.652 | MOUNT: Path 'resources\drives\y' found
2023-12-24 17:11:18.607 | MOUNT: Path 'd:\stuff\dian war\emus\dosgames' found
2023-12-24 17:11:34.213 | RENDER: Auto-switched to shader 'crt/ega-1080p'
2023-12-24 17:11:34.213 | VGA: Forcing single scanning of double-scanned VGA video modes
2023-12-24 17:11:34.218 | DISPLAY: EGA 320x200 16-colour graphics mode 0Dh at 70.086 Hz VFR, scaled to 1067x800 pixels with 1:1.2 (5:6) pixel aspect ratio
2023-12-24 17:12:14.433 | SDL: Using VRR-adjusted (auto) display refresh rate of 141 Hz
2023-12-24 17:12:14.484 | RENDER: Auto-switched to shader 'crt/ega-1440p'
2023-12-24 17:12:14.486 | DISPLAY: EGA 320x200 16-colour graphics mode 0Dh at 70.086 Hz CFR, scaled to 1333x1000 pixels with 1:1.2 (5:6) pixel aspect ratio
2023-12-24 17:15:02.766 | Warning: file creation failed: d:\stuff\dian war\emus\dosgames\CAVES\CC1-11.SAV
2023-12-24 17:15:07.272 | SDL: Using standard SDI (auto) display refresh rate of 144 Hz
2023-12-24 17:15:07.274 | DISPLAY: EGA 320x200 16-colour graphics mode 0Dh at 70.086 Hz VFR, scaled to 1067x800 pixels with 1:1.2 (5:6) pixel aspect ratio
2023-12-24 17:15:07.319 | RENDER: Auto-switched to shader 'crt/ega-1080p'
2023-12-24 17:15:16.736 | RENDER: Auto-switched to shader 'crt/vga-1080p-fake-double-scan'
2023-12-24 17:15:16.748 | RENDER: Auto-switched to shader 'crt/vga-1080p'
2023-12-24 17:15:16.748 | VGA: Double scanning VGA video modes enabled
2023-12-24 17:15:16.751 | DISPLAY: VGA 720x400 16-colour text mode 03h at 70.087 Hz VFR, scaled to 1067x800 pixels with 1:1.35 (20:27) pixel aspect ratio```
johnnovak commented 8 months ago

Friendly reminder: please use the template next time @MasterO2 😄

kcgen commented 8 months ago

please use the template next time

(raises hand; blame is with me, @johnnovak - I suggested a quick copy-n-paste, thinking there was enough content to repro :sweat_smile: )

Working on a repro pack right now.

kcgen commented 8 months ago

@MasterO2 , I tried creating an identical directory tree:

.
└── stuff
    └── dian war
        └── emus
            └── dosgames
                └── CAVES
                    ├── CC1-11.SAV
                    ├── CC1-1.SND
                    ├── CC1-2.SND
                    ├── CC1-3.SND
                    ├── CC1.APG
                    ├── CC1.CDT
                    ├── CC1.CFG
                    ├── CC1.END
                    ├── CC1.EXE
                    ├── CC1-F1.MNI
                    ├── CC1-F2.MNI
                    ├── CC1.GFX
                    ├── CC1-SPL.MNI
                    ├── CC1.TTL
                    └── file_id.diz

6 directories, 16 files

And tried mounting C: and launching as follows:

[autoexec]
mount c "stuff\dian war\emus\dosgames"
c:
cd CAVES
CC1

However, I am able to save to slot 0, restore from slot 0, and re-save to slot 0 without errors or warnings:

https://github.com/dosbox-staging/dosbox-staging/assets/1557255/a280da16-ac24-4c1d-b90a-b4525b094cea

https://github.com/dosbox-staging/dosbox-staging/assets/1557255/9415371a-0c27-4220-afe7-d5aacd3f763e

Here's the pack: 3262-crystal_caves-save-game.zip, @MasterO2 , can you try it on your side?

Launch it like this from your windows command line:

cd 3262-crystal_caves-save-game
/path/to/v0.81.0-rc1/dosbox --noprimaryconf
MasterO2 commented 8 months ago

@kcgen, I've tried your repro package and it's still keeps giving me FILE ERROR. Strange...

D:\stuff\3262-crystal_caves-save-game>"D:\stuff\dian war\emus\dosbox-staging-windows-msys2-x86_64-v0.81.0-rc1\dosbox.exe" --noprimaryconf
date       time         |
2023-12-24 21:19:18.954 | arguments: D:\\stuff\\dian\ war\\emus\\dosbox-staging-windows-msys2-x86_64-v0.81.0-rc1\\dosbox.exe --noprimaryconf
2023-12-24 21:19:18.954 | Current dir: D:\stuff\3262-crystal_caves-save-game
2023-12-24 21:19:18.955 | stderr verbosity: 0
2023-12-24 21:19:18.955 | -----------------------------------
2023-12-24 21:19:18.955 | dosbox-staging version 0.81.0-rc1
2023-12-24 21:19:18.955 | ---
2023-12-24 21:19:18.955 | LOG: Loguru version 2.1.0 initialised
2023-12-24 21:19:18.955 | CONFIG: Using portable configuration layout in 'D:\stuff\dian war\emus\dosbox-staging-windows-msys2-x86_64-v0.81.0-rc1'
2023-12-24 21:19:18.956 | CONFIG: Loaded local config file 'dosbox.conf'
2023-12-24 21:19:18.957 | LANG: Using internal English language messages
2023-12-24 21:19:18.973 | SDL: version 2.28.5 initialised (windows video and wasapi audio)
2023-12-24 21:19:18.974 | DISPLAY: Initialised 1067x800 windowed mode using bilinear scaling on display-0
2023-12-24 21:19:19.336 | OPENGL: Vendor: NVIDIA Corporation
2023-12-24 21:19:19.337 | OPENGL: Version: 4.6.0 NVIDIA 462.75
2023-12-24 21:19:19.337 | OPENGL: GLSL version: 4.60 NVIDIA
2023-12-24 21:19:19.337 | OPENGL: NPOT textures supported
2023-12-24 21:19:19.339 | RENDER: Using adaptive CRT shader based on the graphics standard of the video mode
2023-12-24 21:19:19.368 | RENDER: Auto-switched to shader 'crt/hercules'
2023-12-24 21:19:19.368 | VGA: Pixel doubling enabled
2023-12-24 21:19:19.369 | VIDEO: Using the DOS video mode's frame rate
2023-12-24 21:19:19.377 | MEMORY: Using 4096 DOS memory pages (16 MB) at address: 0000021AE1F92040
2023-12-24 21:19:19.377 | VGA: Double scanning VGA video modes enabled
2023-12-24 21:19:19.378 | VIDEO: Initialised S3 Trio64 VESA 2.0 compatible with 4 MB of FP DRAM supporting 86 modes
2023-12-24 21:19:19.382 | VOODOO: Initialized with 4 MB of RAM, multithreading, and no bilinear filtering
2023-12-24 21:19:19.382 | CAPTURE: Image capturer started
2023-12-24 21:19:19.461 | MIXER: Negotiated 2-channel 48000 Hz audio of 1024-frame blocks
2023-12-24 21:19:19.461 | MIXER: Master compressor enabled
2023-12-24 21:19:19.712 | MIDI: Opened device: win32
2023-12-24 21:19:19.715 | MPU-401: Running in intelligent mode on ports 330h and 331h
2023-12-24 21:19:19.715 | OPL: Operating at 48000 Hz without resampling
2023-12-24 21:19:19.715 | OPL: Running OPL3 on ports 220h and 388h
2023-12-24 21:19:19.716 | SB16: Sound Blaster 16 OPL output filter enabled
2023-12-24 21:19:19.716 | DMA: Initialised primary controller
2023-12-24 21:19:19.717 | DMA: Initialised secondary controller
2023-12-24 21:19:19.717 | SB: Operating at 22050 Hz and upsampling to the output rate
2023-12-24 21:19:19.718 | SB16: Modern DAC output filter enabled
2023-12-24 21:19:19.718 | SB16: Setting 'BLASTER' environment variable to 'A220 I7 D1 H5 T6'
2023-12-24 21:19:19.719 | SB16: Running on port 220h, IRQ 7, DMA 1, and high DMA 5
2023-12-24 21:19:19.719 | PCSPEAKER: Operating at 48000 Hz without resampling
2023-12-24 21:19:19.720 | PCSPEAKER: Initialised discrete model
2023-12-24 21:19:19.720 | PCSPEAKER: Highpass filter enabled (18 dB/oct at 120 Hz)
2023-12-24 21:19:19.720 | PCSPEAKER: Lowpass filter enabled (12 dB/oct at 4800 Hz)
2023-12-24 21:19:19.721 | MOUSE: Will be captured after the first left or right button click
2023-12-24 21:19:19.721 | MOUSE: Middle button will capture/release the mouse (clicks not sent to the game/program)
2023-12-24 21:19:19.722 | MOUSE (PS/2): Standard, 3 buttons
2023-12-24 21:19:19.741 | DOS: Loaded modern locale for country 1, 'United States'
2023-12-24 21:19:19.741 | SLIRP: Slirp version: 4.7.0
2023-12-24 21:19:19.743 | SLIRP: Successfully initialized
2023-12-24 21:19:19.743 | NE2000: Initialised on port 300h and IRQ 3
2023-12-24 21:19:19.746 | CONFIG: Loaded auto-mounted drive config file 'D:\stuff\dian war\emus\dosbox-staging-windows-msys2-x86_64-v0.81.0-rc1\resources\drives\y.conf'
2023-12-24 21:19:19.747 | AUTOEXEC: Using autoexec from one or more joined sections
2023-12-24 21:19:19.798 | MAPPER: No joysticks found
2023-12-24 21:19:19.799 | MAPPER: Loaded default key bindings
2023-12-24 21:19:19.807 | RENDER: Auto-switched to shader 'crt/vga-1080p'
2023-12-24 21:19:19.807 | SDL: Using standard SDI (auto) display refresh rate of 144 Hz
2023-12-24 21:19:19.834 | DISPLAY: VGA 720x400 16-colour text mode 03h at 70.087 Hz VFR, scaled to 1067x800 pixels with 1:1.35 (20:27) pixel aspect ratio
2023-12-24 21:19:19.835 | MOUNT: Path '..\dian war\emus\dosbox-staging-windows-msys2-x86_64-v0.81.0-rc1\resources\drives\y' found
2023-12-24 21:19:19.837 | MOUNT: Path 'stuff\dian war\emus\dosgames' found
2023-12-24 21:19:20.381 | RENDER: Auto-switched to shader 'crt/ega-1080p'
2023-12-24 21:19:20.381 | VGA: Forcing single scanning of double-scanned VGA video modes
2023-12-24 21:19:20.385 | DISPLAY: EGA 320x200 16-colour graphics mode 0Dh at 70.086 Hz VFR, scaled to 1067x800 pixels with 1:1.2 (5:6) pixel aspect ratio
2023-12-24 21:19:50.845 | Warning: file creation failed: stuff\dian war\emus\dosgames\CAVES\CC1-11.SAV
2023-12-24 21:21:02.397 | Warning: file creation failed: stuff\dian war\emus\dosgames\CAVES\CC1-11.SAV
2023-12-24 21:21:08.007 | Warning: file creation failed: stuff\dian war\emus\dosgames\CAVES\CC1-11.SAV
kcgen commented 8 months ago

Thanks @MasterO2 -- your launch line looks perfect.

This must be a host filesystem handling issue or a bug in our cross-file IO handling code that's doing something slightly different on Windows vs. POSIX.

Hoping @shermp , @johnnovak , and @kklobe can investigate further when time permits, assuming you have an msys2 build environment on their Windows machines.

kklobe commented 8 months ago

have you tried it on a path with no spaces to rule that out?

MasterO2 commented 8 months ago

have you tried it on a path with no spaces to rule that out?

To answer your question, @kklobe:

D:\stuff\dosbox-staging-windows-msys2-x86_64-v0.81.0-rc1>dosbox.exe -noprimaryconf
date       time         |
2023-12-24 22:28:22.706 | arguments: dosbox.exe -noprimaryconf
2023-12-24 22:28:22.707 | Current dir: D:\stuff\dosbox-staging-windows-msys2-x86_64-v0.81.0-rc1
2023-12-24 22:28:22.707 | stderr verbosity: 0
2023-12-24 22:28:22.707 | -----------------------------------
2023-12-24 22:28:22.707 | dosbox-staging version 0.81.0-rc1
2023-12-24 22:28:22.707 | ---
2023-12-24 22:28:22.707 | LOG: Loguru version 2.1.0 initialised
2023-12-24 22:28:22.708 | CONFIG: Using portable configuration layout in 'D:\stuff\dosbox-staging-windows-msys2-x86_64-v0.81.0-rc1'
2023-12-24 22:28:22.709 | LANG: Using internal English language messages
2023-12-24 22:28:22.724 | SDL: version 2.28.5 initialised (windows video and wasapi audio)
2023-12-24 22:28:22.725 | DISPLAY: Initialised 1067x800 windowed mode using bilinear scaling on display-0
2023-12-24 22:28:22.976 | OPENGL: Vendor: NVIDIA Corporation
2023-12-24 22:28:22.976 | OPENGL: Version: 4.6.0 NVIDIA 462.75
2023-12-24 22:28:22.977 | OPENGL: GLSL version: 4.60 NVIDIA
2023-12-24 22:28:22.977 | OPENGL: NPOT textures supported
2023-12-24 22:28:22.977 | RENDER: Using adaptive CRT shader based on the graphics standard of the video mode
2023-12-24 22:28:23.005 | RENDER: Auto-switched to shader 'crt/hercules'
2023-12-24 22:28:23.006 | VGA: Pixel doubling enabled
2023-12-24 22:28:23.006 | VIDEO: Using the DOS video mode's frame rate
2023-12-24 22:28:23.013 | MEMORY: Using 4096 DOS memory pages (16 MB) at address: 000002921AE4C040
2023-12-24 22:28:23.013 | VGA: Double scanning VGA video modes enabled
2023-12-24 22:28:23.014 | VIDEO: Initialised S3 Trio64 VESA 2.0 compatible with 4 MB of FP DRAM supporting 86 modes
2023-12-24 22:28:23.018 | VOODOO: Initialized with 4 MB of RAM, multithreading, and no bilinear filtering
2023-12-24 22:28:23.018 | CAPTURE: Image capturer started
2023-12-24 22:28:23.055 | MIXER: Negotiated 2-channel 48000 Hz audio of 1024-frame blocks
2023-12-24 22:28:23.055 | MIXER: Master compressor enabled
2023-12-24 22:28:23.306 | MIDI: Opened device: win32
2023-12-24 22:28:23.309 | MPU-401: Running in intelligent mode on ports 330h and 331h
2023-12-24 22:28:23.309 | OPL: Operating at 48000 Hz without resampling
2023-12-24 22:28:23.309 | OPL: Running OPL3 on ports 220h and 388h
2023-12-24 22:28:23.310 | SB16: Sound Blaster 16 OPL output filter enabled
2023-12-24 22:28:23.310 | DMA: Initialised primary controller
2023-12-24 22:28:23.310 | DMA: Initialised secondary controller
2023-12-24 22:28:23.311 | SB: Operating at 22050 Hz and upsampling to the output rate
2023-12-24 22:28:23.312 | SB16: Modern DAC output filter enabled
2023-12-24 22:28:23.312 | SB16: Setting 'BLASTER' environment variable to 'A220 I7 D1 H5 T6'
2023-12-24 22:28:23.313 | SB16: Running on port 220h, IRQ 7, DMA 1, and high DMA 5
2023-12-24 22:28:23.313 | PCSPEAKER: Operating at 48000 Hz without resampling
2023-12-24 22:28:23.314 | PCSPEAKER: Initialised discrete model
2023-12-24 22:28:23.314 | PCSPEAKER: Highpass filter enabled (18 dB/oct at 120 Hz)
2023-12-24 22:28:23.314 | PCSPEAKER: Lowpass filter enabled (12 dB/oct at 4800 Hz)
2023-12-24 22:28:23.315 | MOUSE: Will be captured after the first left or right button click
2023-12-24 22:28:23.315 | MOUSE: Middle button will capture/release the mouse (clicks not sent to the game/program)
2023-12-24 22:28:23.316 | MOUSE (PS/2): Standard, 3 buttons
2023-12-24 22:28:23.335 | DOS: Loaded modern locale for country 1, 'United States'
2023-12-24 22:28:23.335 | SLIRP: Slirp version: 4.7.0
2023-12-24 22:28:23.337 | SLIRP: Successfully initialized
2023-12-24 22:28:23.337 | NE2000: Initialised on port 300h and IRQ 3
2023-12-24 22:28:23.341 | CONFIG: Loaded auto-mounted drive config file 'resources\drives\y.conf'
2023-12-24 22:28:23.395 | MAPPER: No joysticks found
2023-12-24 22:28:23.396 | MAPPER: Loaded default key bindings
2023-12-24 22:28:23.405 | RENDER: Auto-switched to shader 'crt/vga-1080p'
2023-12-24 22:28:23.406 | SDL: Using standard SDI (auto) display refresh rate of 144 Hz
2023-12-24 22:28:23.431 | DISPLAY: VGA 720x400 16-colour text mode 03h at 70.087 Hz VFR, scaled to 1067x800 pixels with 1:1.35 (20:27) pixel aspect ratio
2023-12-24 22:28:23.432 | MOUNT: Path 'resources\drives\y' found
2023-12-24 22:28:30.297 | MOUNT: Path 'd:\stuff\caves' found
2023-12-24 22:28:40.026 | RENDER: Auto-switched to shader 'crt/ega-1080p'
2023-12-24 22:28:40.026 | VGA: Forcing single scanning of double-scanned VGA video modes
2023-12-24 22:28:40.030 | DISPLAY: EGA 320x200 16-colour graphics mode 0Dh at 70.086 Hz VFR, scaled to 1067x800 pixels with 1:1.2 (5:6) pixel aspect ratio
2023-12-24 22:29:05.168 | Warning: file creation failed: d:\stuff\caves\CC1-11.SAV
LowLevelMahn commented 8 months ago

i can reproduce it - GetLastError + FormatMessage gives

Error 32, The process cannot access the file because it is being used by another process

and the error reappears even if you initialy delete the CC1-11.SAV start a new game/save/restore/save... could be a virus-scanner thing or the .sav is already opened somewhere else

FeralChild64 commented 8 months ago

I can reproduce it on Windows, but not on Linux. In fs_utils_win32.cpp, local_drive_create_file function CreateFileW fails; GetLastError() returns 0x20, which is ERROR_SHARING_VIOLATION - The process cannot access the file because it is being used by another process according to https://learn.microsoft.com/en-us/windows/win32/debug/system-error-codes--0-499-

Looks like there is a resource (file handle) leak somewhere.

kcgen commented 8 months ago

Is "the other process" Windows antivirus, or are we doing something wrong?

The fact 0.80.1 works OK, has me suspecting the latter.

Curious what bisect lands on! (If you guys go that route)🍿

LowLevelMahn commented 8 months ago

according to https://learn.microsoft.com/de-de/sysinternals/downloads/process-explorer "Find handler or DLL..." feature is dosbox itself holding the file open

image

sitting in breakpoint before the file creation - and process-explorer is already telling that the file is opened by dosbox

adding some printing to localDriver class shows this

[restore 0]
localDrive::FileOpen: CAVES\CC1-11.SAV
localDrive::FileOpen: CAVES\CC1-11.SAV
DOS_CloseFile
  DOS_CloseFile: CAVES\CC1-11.SAV
[save 0]
localDrive::FileCreate: CAVES\CC1-11.SAV
2023-12-25 17:04:17.124 | Warning: file creation failed: D:\temp\dos_stuff\tests\3262-crystal_caves-save-game\stuff\dian war\emus\dosgames\CAVES\CC1-11.SAV

my analyze so far: now its Grinch Movie time :)

UPDATE: https://www.vogons.org/viewtopic.php?t=37526

So I traced through the code and I discovered that Crystal Caves does an Open twice when 'r'eloading a save game. It closes the second file opened but leaves the first file open. Thus the cause of the issue. Looking through the dosbox code there is a section that "flushes" the buffer when an open is done on a file that has already been opened. So it is capable of detecting multiple opens on the same file.

kcgen commented 8 months ago

Wow - amazing find!

This rabbit hole got even more interesting (and challenging), because it's critical we duplicate how original MS-DOS deals with multiple open handles to the same file (as other applications and games might use this coding “technique”).

LowLevelMahn commented 8 months ago

some unit-test example - not fully tested, but thats all i can get with my virtual tab-keyboard while watching the Grinch :)

; nasm 3262.asm -fbin -o 3262.com

  org 100h 

section .text 

start:
  mov ah, 3Dh ; open
  mov al, 5 ; read|write
  mov dx, sav_file
  int 21h
  jc Step1Failed
  mov [handle1],ax

  mov ah, 3Dh ; open
  mov al, 5 ; read|write 
  mov dx, sav_file
  int 21h
  jc Step2Failed
  mov [handle2],ax

  mov ah,3Eh ; close
  mov bx,[handle2]
  int 21h
  jc Step3Failed

  mov ah,3Ch ; create
  mov cx,0
  mov dx, sav_file
  int 21h
  jc Step4Failed
  mov [handle3],ax

  ; set error-level

  mov al,0
  jmp end

Step1Failed:  
  mov al,1
  jmp end
Step2Failed:
  mov al,2
  jmp end
Step3Failed:
  mov al,3
  jmp end
Step4Failed:
  mov al,4

end:
  mov ah,4Ch
  int 21h

section .data
  sav_file db 'CC1-11.SAV',0
  handle1 dw 0
  handle2 dw 0
  handle3 dw 0
FeralChild64 commented 8 months ago

Last good commit was https://github.com/dosbox-staging/dosbox-staging/commit/bc4731fb7f2ff6b61b4f5890ca8839d93a5b74d9, https://github.com/dosbox-staging/dosbox-staging/commit/144783113f8f44a5c449ae7737b6ebb625104d84 is the first broken one. Now to check what's the difference in localDrive::FileCreate behavior...

[edit] Or, perhaps, it is somewhere else…

FeralChild64 commented 8 months ago

In localDrive::FileCreate, if I replace:

    FILE* file_pointer = local_drive_create_file(expanded_name, attributes);

    if (!file_pointer) {
        LOG_MSG("Warning: file creation failed: %s", expanded_name);
        DOS_SetError(DOSERR_ACCESS_DENIED);
        return false;

with (basically an old code):

    FILE* file_pointer = fopen_wrap(expanded_name, "wb+");
    if (!file_pointer) {
        LOG_MSG("Warning: file creation failed: %s", newname);
        return false;
    }

the bug is gone. But this will skip applying the attributes to the newly created file, which we don't want anymore. Now, how to fix it?

FeralChild64 commented 8 months ago

OK, initial fix is there, but it needs some more testing.

MasterO2 commented 8 months ago

@FeralChild64, your initial fix appears to have resolved the problem.

I saved a game in slot 0, restored the game from slot 0, and was successfully able to save to slot 0 again after restoring the game. No error message appeared.

I also saved to slot 0 after completing a level, quit to title screen, restored game from slot 0, then saved again to slot 0 without any issues.

If anyone else here is on Windows 10, 64-bit, please check if this has fixed the issue on your end as well.

D:\stuff\dosbox-staging-windows-msys2-x86_64-v0.81.0-alpha-2271-g0c7b1a>dosbox.exe -noprimaryconf
date       time         |
2023-12-25 14:17:18.810 | arguments: dosbox.exe -noprimaryconf
2023-12-25 14:17:18.811 | Current dir: D:\stuff\dosbox-staging-windows-msys2-x86_64-v0.81.0-alpha-2271-g0c7b1a
2023-12-25 14:17:18.811 | stderr verbosity: 0
2023-12-25 14:17:18.811 | -----------------------------------
2023-12-25 14:17:18.811 | dosbox-staging version 0.81.0-alpha-2271-g0c7b1a878
2023-12-25 14:17:18.811 | ---
2023-12-25 14:17:18.811 | LOG: Loguru version 2.1.0 initialised
2023-12-25 14:17:18.816 | LANG: Using internal English language messages
2023-12-25 14:17:18.832 | SDL: version 2.28.5 initialised (windows video and wasapi audio)
2023-12-25 14:17:18.833 | DISPLAY: Initialised 1067x800 windowed mode using bilinear scaling on display-0
2023-12-25 14:17:19.214 | OPENGL: Vendor: NVIDIA Corporation
2023-12-25 14:17:19.214 | OPENGL: Version: 4.6.0 NVIDIA 462.75
2023-12-25 14:17:19.214 | OPENGL: GLSL version: 4.60 NVIDIA
2023-12-25 14:17:19.214 | OPENGL: NPOT textures supported
2023-12-25 14:17:19.214 | RENDER: Using adaptive CRT shader based on the graphics standard of the video mode
2023-12-25 14:17:19.243 | RENDER: Auto-switched to shader 'crt/hercules'
2023-12-25 14:17:19.243 | VGA: Pixel doubling enabled
2023-12-25 14:17:19.244 | VIDEO: Using the DOS video mode's frame rate
2023-12-25 14:17:19.251 | MEMORY: Using 4096 DOS memory pages (16 MB) at address: 00000244FE15E040
2023-12-25 14:17:19.251 | VGA: Double scanning VGA video modes enabled
2023-12-25 14:17:19.251 | VIDEO: Initialised S3 Trio64 VESA 2.0 compatible with 4 MB of FP DRAM supporting 86 modes
2023-12-25 14:17:19.255 | VOODOO: Initialized with 4 MB of RAM, multithreading, and no bilinear filtering
2023-12-25 14:17:19.255 | CAPTURE: Image capturer started
2023-12-25 14:17:19.406 | MIXER: Negotiated 2-channel 48000 Hz audio of 1024-frame blocks
2023-12-25 14:17:19.406 | MIXER: Master compressor enabled
2023-12-25 14:17:19.655 | MIDI: Opened device: win32
2023-12-25 14:17:19.658 | MPU-401: Running in intelligent mode on ports 330h and 331h
2023-12-25 14:17:19.658 | OPL: Operating at 48000 Hz without resampling
2023-12-25 14:17:19.659 | OPL: Running OPL3 on ports 220h and 388h
2023-12-25 14:17:19.659 | SB16: Sound Blaster 16 OPL output filter enabled
2023-12-25 14:17:19.659 | DMA: Initialised primary controller
2023-12-25 14:17:19.660 | DMA: Initialised secondary controller
2023-12-25 14:17:19.660 | SB: Operating at 22050 Hz and upsampling to the output rate
2023-12-25 14:17:19.661 | SB16: Modern DAC output filter enabled
2023-12-25 14:17:19.662 | SB16: Setting 'BLASTER' environment variable to 'A220 I7 D1 H5 T6'
2023-12-25 14:17:19.662 | SB16: Running on port 220h, IRQ 7, DMA 1, and high DMA 5
2023-12-25 14:17:19.662 | PCSPEAKER: Operating at 48000 Hz without resampling
2023-12-25 14:17:19.663 | PCSPEAKER: Initialised discrete model
2023-12-25 14:17:19.663 | PCSPEAKER: Highpass filter enabled (18 dB/oct at 120 Hz)
2023-12-25 14:17:19.664 | PCSPEAKER: Lowpass filter enabled (12 dB/oct at 4800 Hz)
2023-12-25 14:17:19.666 | MOUSE: Will be captured after the first left or right button click
2023-12-25 14:17:19.666 | MOUSE: Middle button will capture/release the mouse (clicks not sent to the game/program)
2023-12-25 14:17:19.667 | MOUSE (PS/2): Standard, 3 buttons
2023-12-25 14:17:19.686 | DOS: Loaded modern locale for country 1, 'United States'
2023-12-25 14:17:19.686 | SLIRP: Slirp version: 4.7.0
2023-12-25 14:17:19.688 | SLIRP: Successfully initialized
2023-12-25 14:17:19.688 | NE2000: Initialised on port 300h and IRQ 3
2023-12-25 14:17:19.692 | CONFIG: Loaded auto-mounted drive config file 'resources\drives\y.conf'
2023-12-25 14:17:19.746 | MAPPER: No joysticks found
2023-12-25 14:17:19.747 | MAPPER: Loaded default key bindings
2023-12-25 14:17:19.755 | RENDER: Auto-switched to shader 'crt/vga-1080p'
2023-12-25 14:17:19.755 | SDL: Using standard SDI (auto) display refresh rate of 144 Hz
2023-12-25 14:17:19.790 | DISPLAY: VGA 720x400 16-colour text mode 03h at 70.087 Hz VFR, scaled to 1067x800 pixels with 1:1.35 (20:27) pixel aspect ratio
2023-12-25 14:17:19.792 | MOUNT: Path 'resources\drives\y' found
2023-12-25 14:17:25.222 | MOUNT: Path 'd:\stuff\caves' found
2023-12-25 14:17:28.613 | RENDER: Auto-switched to shader 'crt/ega-1080p'
2023-12-25 14:17:28.613 | VGA: Forcing single scanning of double-scanned VGA video modes
2023-12-25 14:17:28.617 | DISPLAY: EGA 320x200 16-colour graphics mode 0Dh at 70.086 Hz VFR, scaled to 1067x800 pixels with 1:1.2 (5:6) pixel aspect ratio
2023-12-25 14:19:12.455 | SDL: Using VRR-adjusted (auto) display refresh rate of 141 Hz
2023-12-25 14:19:12.492 | RENDER: Auto-switched to shader 'crt/ega-1440p'
2023-12-25 14:19:12.494 | DISPLAY: EGA 320x200 16-colour graphics mode 0Dh at 70.086 Hz CFR, scaled to 1333x1000 pixels with 1:1.2 (5:6) pixel aspect ratio
2023-12-25 14:22:13.023 | SDL: Using standard SDI (auto) display refresh rate of 144 Hz
2023-12-25 14:22:13.027 | DISPLAY: EGA 320x200 16-colour graphics mode 0Dh at 70.086 Hz VFR, scaled to 1067x800 pixels with 1:1.2 (5:6) pixel aspect ratio
2023-12-25 14:22:13.056 | RENDER: Auto-switched to shader 'crt/ega-1080p'
FeralChild64 commented 8 months ago

It seems that DOS function 0x3c (create file) does not react properly on invalid file attributes - but this is not a regression. I'll need to investigate this, but this is a separate topic, definitely not for 0.81.0. I'll switch the PR to review shortly.