View Issue Details

IDProjectCategoryView StatusLast Update
0005042The Dark ModCodingpublic04.05.2020 06:00
Reporterstgatilov Assigned Tostgatilov  
PriorityurgentSeveritymajorReproducibilitysometimes
Status resolvedResolutionfixed 
Product VersionTDM 2.07 
Target VersionTDM 2.08Fixed in VersionTDM 2.08 
Summary0005042: Timestamps fiasco: Unix vs DOS, local vs UTC
DescriptionThe engine code heavily relies on file timestamps. They influence incremental reloading of assets, choosing how to resolve conflict when same asset is present in many places, etc. Moreover, if file timestamp cannot be determined properly, then the engine may decide that the file does not exist (but still read it at the same time). All of this causes terrible issues sometimes.

One problem about it was noticed in 2016 at TDM 2.05:
  http://forums.thedarkmod.com/index.php?/topic/18582-bogus-timestamps-in-tdm-update-files-cause-tdm-crashes-under-linux/&tab=comments#comment-399317
The next problem happened in 2019 at TDM 2.07 (confirmed):
  http://forums.thedarkmod.com/index.php?/topic/20050-proccpuinfo-cpu-frequency-200007-mhz-signal-caught-segmentation-fault-si_code-1/

The code stores timestamps as ID_TIME_T, which is a typedef for time_t from C. This type stores a Unix Timestamp, i.e. the number of seconds passed since Epoch, where Epoch is specified in UTC. Most importantly, Unix timestamp for an event is logically the same on every machine in every timezone. It is NOT a local time.

A major convention used in engine (e.g. by image loading code) is:
  If timestamp is -1, then the file was not loaded.
The same convention is used by mktime function, which computes Unit Timestamp from local time:
  If local time cannot be converted, then timestamp -1 is returned.
Adding these two conventions together: if some error happens when handling file timestamp, then the file is considered as "not loaded" (sort of... partially)

Now back to why we need local times at all.
The engine uses zip file format for all assets on the player side. Zip format is very old, and it stores last modification time of each file in DOS format. Which is just "year, month, day, hour, minute, second", without any timezone/DST info. By common convention, everyone treats DOS time as local time.
Since zip modification times are considered local, the engine converts them to Unix Timestamps on reading. This is done in function Sys_DosToUnixTime, and it calls aforementioned mktime standard function to convert from local time to Unit Timestamp.

Here are some problems:
1) mktime function works differently depending on locale/timezone/DST/whatever. It may fail due to some DST weirdness or due to random value stored in zip datetimes.
2) Sys_DosToUnixTime function does not initialize the field "dostm.tm_isdst" before calling mktime. Depending on the sign of this value, mktime considers input to be at non-DST/DST/uncertain moment, which may result in different output or even fail (depending on locale).
3) The pk4 files have somewhat imprecise timestamps. Because TDM server packages everything in one timezone, while players read these zips in another timezone.
TagsNo tags attached.

Relationships

related to 0004864 resolvedstgatilov Remove pk4 timestamps fixes from updater 
related to 0003732 closedgrayman Engine should take daylight savings into account when determining which DLL to load 
related to 0003224 resolvedgrayman TheDarkMod.exe crashes after updating a 1.07 installation to 1.08 

Activities

stgatilov

stgatilov

12.08.2019 17:54

administrator   ~0011816

I suggest hardening the handling of file/timestamps reading errors in several places, introducing a zillion of cvars in process. The cvars should have proper default values so that no one has to change them, but they should allow some freedom to fix issues if they happen.

Possible mitigations:
1) Somehow set tm.tm_isdst in Sys_DosToUnixTime. Perhaps to -1, perhaps to a value of some cvar. Also, maybe move this function to common Sys file, since now it is the same for Linux and Windows.
2) Treat file modification times from pk4 files as in UTC. Not a good thing, but why not.
3) Add more error checking in image loading code to avoid hard-to-debug crashes.
4) Print warning to game console when mktime fails.
5) Add handmade implementation of converting "year,month,day,hour,minute,second" into Unit Timestamp. Use this implementation a) always, b) when mktime fails, c) never (depending on cvar).
6) In case mktime fails, do something, Maybe just set some predefined valid timestamp.
7) Allow overriding timezone/dst/locale somehow. Maybe via locale function, maybe in conjunction with self-written date conversion.
stgatilov

stgatilov

13.08.2019 03:43

administrator   ~0011817

This is the commit which added usage of zip timestamps (yeah, that's TDM-specific):

Revision: 5723
Author: taaaki
Date: 26 марта 2013 г. 10:58:38
Message:
Added timestamp check when determining whether to use the existing game dll/so in the executable path or the dll/so in the game pak file. Refer to issue 0003224.
----
Modified : /trunk/TypeInfo/main.cpp
Modified : /trunk/framework/File.cpp
Modified : /trunk/framework/File.h
Modified : /trunk/framework/FileSystem.cpp
Modified : /trunk/sys/posix/posix_main.cpp
Modified : /trunk/sys/sys_public.h
Modified : /trunk/sys/win32/win_main.cpp
stgatilov

stgatilov

16.08.2019 07:03

administrator   ~0011818

Last edited: 16.08.2019 07:04

In the latest case:
  http://forums.thedarkmod.com/index.php?/topic/20050-proccpuinfo-cpu-frequency-200007-mhz-signal-caught-segmentation-fault-si_code-1
It happens as follows:
1) Uninitialized member dostm.tm_isdst turns out to be positive, which means "DST is in effect".
2) Function mktime consults records for the current timezone and sees that DST was never used for the current timezone. so it returns error (-1).
3) R_LoadImage considers that LoadTGA failed because timestamp is -1. It does not care that image buffer it not NULL.
4) LoadJPG is called. It clears the image buffer, but obviously fails to load jpg since there is no jpg.
5) The case "makeIntensity" in R_ParseImageProgram_r applies postprocessing to the image buffer without checking it for being NULL.
Note that mktime started returning -1 (step 2) only in recent versions of glibc (i.e. version 2.29). Previously it returned some positive result. Here is report about this change in glibc:
  https://bugzilla.redhat.com/show_bug.cgi?id=1653340

The workaround for TDM 2.07 (or earlier) is to set ANY timezone which has Daylight Saving Time (DST). For instance, Asia/Tehran is known to work.
I guess it is also possible to override timezone for TDM only by setting TZ environment variable:
  https://unix.stackexchange.com/questions/45803/run-an-application-with-different-timezone

stgatilov

stgatilov

02.09.2019 15:57

administrator   ~0011832

Regarding the latest issue, Duzenko has compiled a Linux x64 binary with workaround here:
  http://forums.thedarkmod.com/index.php?/topic/20050-proccpuinfo-cpu-frequency-200007-mhz-signal-caught-segmentation-fault-si_code-1/&do=findComment&comment=439028
stgatilov

stgatilov

16.11.2019 15:53

administrator   ~0011869

Last edited: 16.11.2019 15:54

Here is how engine finds the file.

In general, the file might be present on the filesystem (outside of paks), and be present in one or several pk4 files.
Most importantly, the file may be present in pk4 of the game itself, and in pk4 of the FM installed.

The file is loaded via method idFileSystemLocal::OpenFileReadFlags, which accepts search flags, consisting of:
  #define FSFLAG_SEARCH_DIRS ( 1 << 0 ) //if not set, then local unpacked files are completely ignored
  #define FSFLAG_SEARCH_PAKS ( 1 << 1 ) //if not set, then file inside pk4 archives are completely ignored
  #define FSFLAG_BINARY_ONLY ( 1 << 2 ) //if set, then pk4 without "binary.conf" file are ignored (note: remnant from game.dll days)
  #define FSFLAG_SEARCH_ADDONS ( 1 << 3 ) //if set, then addon pk4 are also considered in search (there are no addons in TDM)
The default flags (used by simpler idFileSystemLocal::OpenFileRead wrapper) are FSFLAG_SEARCH_DIRS and FSFLAG_SEARCH_PAKS.
Also, both functions allow passing "gamedir" parameter: if it is passed, then either only local files from FM directory are used, or only the local files from root directory are used (by default, both are used).

When game is started, the list of all "search paths" is created. A search path is either a directory or a whole pk4 archive.
When file is loaded, every search path is checked in order of their appearance in the list. The first found match is immediately returned.
The only exception is that addons are searched in the very last step, but TDM does not use them anyway.
So everything boils down to the order of search paths.
You can always see it in console by executing "path" command, or just looking at the beginning of console log. Also, use "fs_debug" to see which files was loaded from where.

The typical order of search paths in TDM is (earlier paths take precedence):
1. The directory of currently installed FM, e.g. "fms/alberic3".
2. The internationalization pack of the installed FM, e.g. "fms/alberic3/alberic3_l10n.pk4" (if present)
3. The main pack of the installed FM, e.g. "fms/alberic3/alberic3.pk4".
4. The base/root installation directory of TDM.
5. The base pk4 archives, ordered lexicographically decreasing, i.e. "tdm_textures_wood01.pk4", "tdm_textures_window01.pk4", ..., "tdm_ai_animals01.pk4".

This order is ensured in idFileSystemLocal::Startup.
Note that reverse lexicographical sort happens only between pk4 files in same directory (i.e. in FM dir or in base dir), the order of other things is fixed.

Timestamps are never used when searching for a file, so removing them will have no effect on how conflicts between packages/directories are resolved.

stgatilov

stgatilov

16.11.2019 16:30

administrator   ~0011870

Timestamps of in-zip files reverted to zero in svn rev 8400.
stgatilov

stgatilov

04.05.2020 06:00

administrator   ~0012454

These changes has caused one inconvenient consequence:
  https://forums.thedarkmod.com/index.php?/topic/20291-beta-testing-208/&do=findComment&comment=446683

Among many reloadXXX commands which check for timestamps, reloadDecls is the only one which explicitly checks for a zero timestamp.
If timestamp is zero, then it always reloads.
As far as I understand, zero timestamp can only appear from idFile_InZip. In 2.07 and before, it was returning some actual timestamp from zip file, but now it returns zero again as in D3.
Therefore, this is a change in behavior from 2.07.

I removed the explicit check for zero timestamp in svn rev 8705 on release2.08 branch.
I guess it will get into trunk soon too.

Issue History

Date Modified Username Field Change
12.08.2019 17:46 stgatilov New Issue
12.08.2019 17:46 stgatilov Status new => assigned
12.08.2019 17:46 stgatilov Assigned To => stgatilov
12.08.2019 17:47 stgatilov Relationship added related to 0004864
12.08.2019 17:47 stgatilov Relationship added related to 0003732
12.08.2019 17:54 stgatilov Note Added: 0011816
13.08.2019 03:43 stgatilov Note Added: 0011817
13.08.2019 03:45 stgatilov Relationship added related to 0003224
15.08.2019 16:25 stgatilov Description Updated
15.08.2019 16:25 stgatilov Description Updated
16.08.2019 07:03 stgatilov Note Added: 0011818
16.08.2019 07:04 stgatilov Note Edited: 0011818
16.08.2019 07:04 stgatilov Note Edited: 0011818
02.09.2019 15:57 stgatilov Note Added: 0011832
16.11.2019 15:53 stgatilov Note Added: 0011869
16.11.2019 15:54 stgatilov Note Edited: 0011869
16.11.2019 16:30 stgatilov Note Added: 0011870
16.11.2019 16:31 stgatilov Status assigned => resolved
16.11.2019 16:31 stgatilov Resolution open => fixed
16.11.2019 16:31 stgatilov Fixed in Version => TDM 2.08
04.05.2020 06:00 stgatilov Note Added: 0012454