Hemiptera Bugtracker at bugs.linux-forks.de

advtrains

Creating advtrains files gives repeated stacktrace, trains do not save

Send replies to 142@bugs.linux-forks.de or using the Form below.
avatar From: OP
Sun, 15 Dec 2019 15:04:02 -0000

In windows 7 (may be platform-specific), minetest 5.1.0 OR minetest

0.4.17.1 and all commits since a3c4680. i.e. I ran git bisect and found

that this bug was introduced by commit 7f4f8c606 with message "lines: Add

rwt adapt mode to adapt to real time".

1. Create a new world or select a new world to add advtrains to

2. Enable advtrains in that world

3. Launch the world

Result: A stack trace shows. Relevant lines from debug.txt:

2019-12-16 01:05:52: ACTION[Main]: World at

[[redacted]\worlds\ThereIsNoTrain]

2019-12-16 01:05:52: ACTION[Main]: Server for gameid="minetest" listening

on 0.0.0.0:60297.

2019-12-16 01:05:52: ACTION[Server]: [advtrains] loading

[redacted]\minetest-5.1.0-win64\bin\..\worlds\ThereIsNoTrain/advtrains_version

2019-12-16 01:05:52: WARNING[Server]: Failed to read advtrains save data

from file

[redacted]\minetest-5.1.0-win64\bin\..\worlds\ThereIsNoTrain/advtrains_version:

[redacted]\minetest-5.1.0-win64\bin\..\worlds\ThereIsNoTrain/advtrains_version:

No such file or directory

2019-12-16 01:05:52: WARNING[Server]: (this is normal when first enabling

advtrains on this world)

2019-12-16 01:05:52: WARNING[Server]: Failed to read advtrains save data

from file

[redacted]\minetest-5.1.0-win64\bin\..\worlds\ThereIsNoTrain/advtrains:

[redacted]\minetest-5.1.0-win64\bin\..\worlds\ThereIsNoTrain/advtrains: No

such file or directory

2019-12-16 01:05:52: WARNING[Server]: (this is normal when first enabling

advtrains on this world)

2019-12-16 01:05:52: ERROR[Server]: Failed to read advtrains_luaautomation

save data from file

[redacted]\minetest-5.1.0-win64\bin\..\worlds\ThereIsNoTrain/advtrains_luaautomation:

[redacted]\minetest-5.1.0-win64\bin\..\worlds\ThereIsNoTrain/advtrains_luaautomation:

No such file or directory

2019-12-16 01:05:52: ACTION[Server]: [advtrains][load_all]Loaded advtrains

save files

2019-12-16 01:05:52: WARNING[Server]: [advtrains]Lua Error occured:

...mods\advtrains\advtrains_line_automation\railwaytime.lua:86: attempt to

perform arithmetic on upvalue 'e_last_epoch' (a nil value)

2019-12-16 01:05:52: WARNING[Server]: [advtrains]stack traceback:

...est-5.1.0-win64\bin\..\mods\advtrains\advtrains\init.lua:47: in function

'__sub'

...mods\advtrains\advtrains_line_automation\railwaytime.lua:86: in function

'step'

...bin\..\mods\advtrains\advtrains_line_automation\init.lua:45: in function

'step'

...est-5.1.0-win64\bin\..\mods\advtrains\advtrains\init.lua:488: in

function <...est-5.1.0-win64\bin\..\mods\advtrains\advtrains\init.lua:454>

[C]: in function 'xpcall'

...est-5.1.0-win64\bin\..\mods\advtrains\advtrains\init.lua:45: in function

<...est-5.1.0-win64\bin\..\mods\advtrains\advtrains\init.lua:42>

...ls\minetest-5.1.0-win64\bin\..\builtin\game\register.lua:429: in

function <...ls\minetest-5.1.0-win64\bin\..\builtin\game\register.lua:413>

2019-12-16 01:05:52: WARNING[Server]: [advtrains]Restoring saved state in 1

second...

The stack trace then repeats from lines 3 onwards every second, after the

restore finishes. During this time, you are not able to place any track.

It may or may not be a red herring that 'e_last_epoch' is not available on

the windows platform (I have no idea of its relevance to the unix epoch and

its possible availability or unavailabilty on windows).

4. Exit to menu and then open the world again

The stack traces will no longer occur, and the files appear in the world

folder.

5. Place any kind of train in the world

6. Place a TCB, assign it to a rail and make interlocked sections

7. Exit to menu

8. Reload the world

The train will not be saved and the TCB will have its text set to "Assigned

to (x,y,z)" but not have any interlocking data attached.

avatar From: Someone else
Tue, 17 Dec 2019 22:00:01 -0000

This is indeed a bug introduced by the changes in the mentioned commit... git bisect was right. The bug should be platform independent.

e_last_epoch is just a local variable in rwt.lua. It seems like it somehow isn't initialized when no save files are loaded, thus triggering a crash.

The error is caught by a mechanism that I added about 2 years ago called "nocrash", that was meant to prevent errors in advtrains to crash the whole Minetest server. This mechanism stops anything advtrains-related for 1 second and then reloads the save files, which makes the whole thing start from the beginning.

The second part of your report makes me wonder though. I'll try to reproduce this behavior.

avatar From: Developer
Wed, 18 Dec 2019 09:26:02 -0000

I fixed the first part. Can you try to reproduce the second part of your report? Thanks.

Am 17. Dezember 2019 23:02:01 MEZ schrieb 142@bugs.linux-forks.de:

>This is indeed a bug introduced by the changes in the mentioned

>commit... git bisect was right. The bug should be platform independent.

>

>e_last_epoch is just a local variable in rwt.lua. It seems like it

>somehow isn't initialized when no save files are loaded, thus

>triggering a crash.

>

>The error is caught by a mechanism that I added about 2 years ago

>called "nocrash", that was meant to prevent errors in advtrains to

>crash the whole Minetest server. This mechanism stops anything

>advtrains-related for 1 second and then reloads the save files, which

>makes the whole thing start from the beginning.

>

>The second part of your report makes me wonder though. I'll try to

>reproduce this behavior.

--

Diese Nachricht wurde von meinem Android-Gerät mit K-9 Mail gesendet.

avatar From: OP
Thu, 19 Dec 2019 00:19:02 -0000

I can confirm commit 50a81dd removes the stack traces coming from nocrash.

However, trains and TCBs still will not save. From what I can tell, the

issue applies to all database files. However, it applies in the following

order:

1. On first advtrains init, all the database files that end with ~ have the

correct contents saved into them during play.

2. On exit, the ~ files are unchanged and still contain the correct

contents, but the main files do not have any data saved into them

3. On second load of the world, no changes occur. The ~ files still contain

the correct contents, but the main files still have no data. Thus, all the

trains, TCBs, rs locks, etc. disappear.

4. During play, the ~ files will continue have to correct data for what you

place in the world. However, as load occurs on the main files, the

5. So the cycle repeats: Any data saved is only done during play to the ~

files, and no writeback to the main files occurs. However, load occurs only

from the main files. While playing, the ~ files be updated with any data

you create. After save, any data left in the ~ files is only what you had

added back to the game during play. and any old data that you do not add

back during play will not be saved in to the ~ files.

An additional weird result: Some station/stop tracks, ATC tracks, unloading

tracks, loading tracks or point speed restriction rails placed became

ordinary tracks for me. This was with a certain weird straight track

section made of uninitialized components. I'm not sure how to reproduce at

the moment and hopefully that is just a weird side effect that should not

return when saving is fixed.

It is curious that saving to the ~ files works but the main files does not.

I hope this gives an important clue as to what is wrong with the save

system.

avatar From: OP
Fri, 20 Dec 2019 03:56:02 -0000

The offending code is init.lua:354: function advtrains.save_component

os.rename(temppath, advtrains.fpath.."_"..name)

Which makes the assumption that the operating system is POSIX, where rename

is atomic and will clobber the target file if it exists. This method for

saving was introduced in 7a6740e by gabriel after the second great train

service breakdown.

Windows will refuse to clobber existing files with os.rename. Lua will

return <nil, "File exists", 17>. In order to support windows you will have

to delete the old file first then rename the just-saved file. I don't think

this is any less safe than atomically clobbering the file.

Let this be a lesson in always checking file I/O operations. I will send a

patch in the next message.

avatar From: OP
Fri, 20 Dec 2019 03:57:01 -0000

Unlike POSIX, win32 does not allow rename to clobber the target file.

Instead, remove the old file before performing the rename.

---

advtrains/init.lua | 15 +++++++++++++--

1 file changed, 13 insertions(+), 2 deletions(-)

diff --git a/advtrains/init.lua b/advtrains/init.lua

index c5604fd..fe77870 100644

--- a/advtrains/init.lua

+++ b/advtrains/init.lua

@@ -351,8 +351,19 @@ advtrains.save_component = function (tbl, name)

end

file:write(datastr)

file:close()

- os.rename(temppath, advtrains.fpath.."_"..name)

-

+ local oldfname = advtrains.fpath.."_"..name

+ local succ, msg

+

+ succ, msg = os.remove(oldfname)

+ if (succ == nil and (not string.find(msg, "No such file or directory")))

then

+ minetest.log("error", string.format(" Failed to remove %s during save:

'%s'", oldfname, msg))

+ return

+ end

+

+ succ,msg = os.rename(temppath, oldfname)

+ if succ == nill then

+ minetest.log("error", string.format(" Failed to rename %s -> %s during

save: %s", temppath, oldfname, msg))

+ end

end

advtrains.avt_save = function(remove_players_from_wagons)

--

2.21.0.windows.1

Reply