stujones11 / minetest-3d_armor

Visible player armor & wielded items for minetest
Other
56 stars 98 forks source link

A new crash #61

Closed Cat5TV closed 7 years ago

Cat5TV commented 8 years ago

Hey stujones11, Another server crashed cropped up in the past few days...

ServerError: Lua: Runtime error from mod '3d_armor' in callback on_dieplayer(): ...ie/.minetest/mods/minetest-3d_armor/3d_armor/api.lua:115: attempt to index field '?' (a nil value)

Cheers, Robbie

stujones11 commented 8 years ago

That code should never be reached in on_dieplayer() if you have disabled armor dropping. Any chance you can provide the full traceback? I can only guess that some other mod is calling set_player_armor and I've somehow broken the compatibility.

btw, this is really a duplicate of #60 so I will close that one now.

stujones11 commented 8 years ago

Try as I might, I cannot seem to reproduce this by any means of dying. I will need to update my minetest installation to see if it could be an engine problem but I doubt that. I have added some additional validation code around the problem area that should, if nothing else, provide a little more insight.

Cat5TV commented 8 years ago

~/.minetest/mods/minetest-3d_armor$ cat armor.conf ARMOR_DROP = false

Because of this issue I have players emailing me to tell me they can't connect to the server (the server crashes with the above error the moment they try to connect).

stujones11 commented 8 years ago

Have you updated the mod since my last few commits. The logs should now provide a little more info. Also, please try to capture the full traceback if it still causes a crash.

Cat5TV commented 8 years ago

Alright will do. I disabled the daily build yesterday just because we've had so many problems lately with instability... everyone's trying to keep up :) I'll update now and see what we see over the next few days.

Thanks!

stujones11 commented 8 years ago

No problem, fbdc68df5153592b5d22720911a668ff6bcc771e should now hopefully fix this regardless of the actual cause.

Cat5TV commented 8 years ago

Thanks man. Had a long weekend here so I've been AFK, but just did a new pull and will see how it shapes up.

stujones11 commented 8 years ago

You are very welcome, please let me know the outcome either way because I would like to get 0.5.0 released sometime over the coming weekend.

Cat5TV commented 8 years ago

Sure thing. I've updated all, including your mods and a new compile on minetest just to make sure everything is as current as can be.

If you need me, ping me here or pop on #ThePixelShadow on Freenode.

Cheers.

Cat5TV commented 8 years ago

Non-trivial, he marks it ;)

This morning after yesterday's updates:

2016-05-26 08:53:27: ACTION[Server]: Junebug leaves game. List of players: 2016-05-26 08:53:28: ERROR[Main]: ServerError: Lua: Runtime error from mod '3d_armor' in callback on_dieplayer(): .../.minetest/mods/minetest-3d_armor/multiskin/init.lua:53: attempt to index field '?' (a nil value) 2016-05-26 08:53:28: ERROR[Main]: stack traceback: 2016-05-26 08:53:28: ERROR[Main]: .../.minetest/mods/minetest-3d_armor/multiskin/init.lua:53: in function 'set_player_textures' 2016-05-26 08:53:28: ERROR[Main]: ...ie/.minetest/mods/minetest-3d_armor/3d_armor/api.lua:127: in function 'set_player_armor' 2016-05-26 08:53:28: ERROR[Main]: ...e/.minetest/mods/minetest-3d_armor/3d_armor/init.lua:284: in function '?' 2016-05-26 08:53:28: ERROR[Main]: ...ome/robbie/minetest/bin/../builtin/game/register.lua:369: in function <...ome/robbie/minetest/bin/../builtin/game/register.lua:349> Minetest Stopped. List of players:

numberZero commented 8 years ago

It seems that player:get_player_name() returned a literal "?" instead of nil or the player name. That looks very strange but may be caused by some another mod.

BTW, what do is expected to happen if there is a player named e.g. get_player_skin?

multiskin[name][layer] = textures[layer] or multiskin[name][layer]

The server crashes, of course:

2016-05-26 19:41:35: ACTION[Server]: get_player_skin [127.0.0.1] joins game. 
2016-05-26 19:41:35: ACTION[Server]: get_player_skin joins game. List of players: set_player_skin get_player_skin
...
2016-05-26 19:42:19: ACTION[Server]: set_player_textures [127.0.0.1] joins game. 
2016-05-26 19:42:19: ACTION[Server]: set_player_textures joins game. List of players: set_player_skin set_player_textures
2016-05-26 19:42:19: ERROR[Main]: ServerError: Lua: Runtime error from mod 'multiskin' in callback on_joinplayer(): ...layable-minetest/bin/../mods/3d_armor/multiskin/init.lua:84: attempt to call method 'get_player_skin' (a table value)
2016-05-26 19:42:19: ERROR[Main]: stack traceback:
2016-05-26 19:42:19: ERROR[Main]:       ...layable-minetest/bin/../mods/3d_armor/multiskin/init.lua:84: in function <...layable-minetest/bin/../mods/3d_armor/multiskin/init.lua:81>
2016-05-26 19:42:19: ERROR[Main]:       ...etest/playable-minetest/bin/../builtin/game/register.lua:369: in function <...etest/playable-minetest/bin/../builtin/game/register.lua:349>
2016-05-26 19:42:19: ACTION[Server]: set_player_skin leaves game. List of players: 
2016-05-26 19:42:19: ACTION[Server]: set_player_textures leaves game. List of players: 
stujones11 commented 8 years ago

@Cat5TV something definitely seems to be corrupting the player name. All I can do is add more checks to prevent a crash but the problem is likely to re-emerge somewhere else. Can you give me a list of all other installed mods.

BTW, what do is expected to happen if there is a player named e.g. get_player_skin?

That is a good point, well spotted. Will fix that asap.

stujones11 commented 8 years ago

fb2ff3a217b0156dd412b9b5a38937e8ed0ae477 should now fix the potential issue reported by @numberZero and at least prevent the crash from re-occurring there.

Cat5TV commented 8 years ago

I've done a new pull. Will let you know the outcome.

stujones11 commented 8 years ago

Thanks, though I would still like to know what other mods you have activated as something is very wrong when the api is returning garbage player names. It has to be a mod problem because I have updated my mt/mtg installation and I am still unable to reproduce this error.

Cat5TV commented 8 years ago

https://minetest.tv/server-specs.php - the server we had crash the other day was the "Survival" server.

stujones11 commented 8 years ago

Wow, that's a lot of mods. I am now wondering if it is only your survival server that is crashing, that would narrow things down considerably.

Cat5TV commented 8 years ago

It's really tough to know because it's only when certain players login. That said, it has happened on both Survival and Xtreme.

stujones11 commented 8 years ago

I wonder if it be something in the player name then, eg. do they contain any non-english characters?

Cat5TV commented 8 years ago

2016-05-26 08:53:27: ACTION[Server]: Junebug leaves game. List of players:

Player name was Junebug.

stujones11 commented 8 years ago

Yeah, it was in the logs, derp, been one of them days...I still don't understand how it could happen when a player leaves. I guess we'll just have to see were it goes from here.

Raughnbo commented 8 years ago

Two of the characters that this is happening to are mine. One of the character's name is Junebug the others name is Fred. Both players died while AFK and now everytime I try to log either character into the server the server resets. I have two other characters on the server that login to the server without issue. If you have any specific questions please ask and I will answer them to the best of my ability. Thank you.

stujones11 commented 8 years ago

@Raughnbo Thank you for this information, it has given me a clue as to what might be happening. If I am correct then it is really an engine bug, although mods should try avoid server crash in any case.

stujones11 commented 8 years ago

@Cat5TV any word on the status of this? I would really like to get 0.5.0 released but I want to be sure this has been resolved before I do.

Cat5TV commented 8 years ago

Checking the logs for you now. I have not noticed any crashes as of late, but didn't realize you had changed anything since the last comment.

Cat5TV commented 8 years ago

@stujones11 the last instance of the crash was on May 26th, as detailed above. It has not appeared in our logs since that day.

stujones11 commented 8 years ago

Thank you for the update, I do hope that @Raughnbo was able to recover his characters.

Cat5TV commented 8 years ago

I have asked @Raughnbo to sign in ... we'll see.

Cat5TV commented 8 years ago

No good. Different line of init.lua though... perhaps unrelated? But still, a crash from 3d_armor.

2016-06-01 20:49:28: ACTION[Server]: TSmith [xx.xx.xx.xx] joins game. 2016-06-01 20:49:28: ACTION[Server]: TSmith joins game. List of players: Geraths TSmith 2016-06-01 20:49:28: ACTION[Main]: IRC: Disconnected. 2016-06-01 20:49:29: ERROR[Main]: ServerError: Lua: Runtime error from mod '' in callback on_joinplayer(): ...e/.minetest/mods/minetest-3d_armor/3d_armor/init.lua:92: attempt to index field '?' (a nil value) 2016-06-01 20:49:29: ERROR[Main]: stack traceback: 2016-06-01 20:49:29: ERROR[Main]: ...e/.minetest/mods/minetest-3d_armor/3d_armor/init.lua:92: in function 'get_formspec'

Raughnbo commented 8 years ago

No Good here

On Wed, Jun 1, 2016 at 9:03 PM Robbie Ferguson notifications@github.com wrote:

No good.

2016-06-01 20:49:28: ACTION[Server]: TSmith [67.140.38.52] joins game. 2016-06-01 20:49:28: ACTION[Server]: TSmith joins game. List of players: Geraths TSmith 2016-06-01 20:49:28: ACTION[Main]: IRC: Disconnected. 2016-06-01 20:49:29: ERROR[Main]: ServerError: Lua: Runtime error from mod '' in callback on_joinplayer(): ...e/.minetest/mods/minetest-3d_armor/3d_armor/init.lua:92: attempt to index field '?' (a$ 2016-06-01 20:49:29: ERROR[Main]: stack traceback: 2016-06-01 20:49:29: ERROR[Main]: ...e/.minetest/mods/minetest-3d_armor/3d_armor/init.lua:92: in function 'get_formspec'

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/stujones11/minetest-3d_armor/issues/61#issuecomment-223169143, or mute the thread https://github.com/notifications/unsubscribe/AR0g0oTuqo316kyC3qdKTF6y5oZwu6jfks5qHivYgaJpZM4Ihed4 .

stujones11 commented 8 years ago

No good. Different line of init.lua though... perhaps unrelated?

It is almost definitely related but it really should not be possible for the player's armor.def entry to be nil. This can only mean that either register_on_joinplayer is somehow being skipped for that player or some other mod is errantly modifying the armor definition table.

e6da523b979adf281da5b536212d387043a5a3f2 should stop it crashing there again anyway.

Cat5TV commented 8 years ago

Just a crazy stab in the dark, but could it be related to this? https://github.com/NathanSalapat/kickafk

I only wonder because @Raughnbo said above "Both players died while AFK and now everytime I try to log either character into the server the server resets." -- and this mod specifically deals with AFK players.

Will e6da523 be integrated into 0.5.0?

Thanks!!

stujones11 commented 8 years ago

@Cat5TV I think you might be on the right lines there but I cannot see anything in Nathan's code that could possibly explain this.

Will e6da523 be integrated into 0.5.0?

Did you mean current master? That commit is already part of 0.5.0-dev, so it will be part of the eventual release in some form or other.

numberZero commented 8 years ago

...from mod '' in... — no mod name ...field '?' (a nil... — literal “?”, again (unless Cat5TV removed actual player name...)

Certainly something messes up the API. That may be a rogue mod, a broken patch for the builtins. strange engine bug, etc. @Cat5TV can you give me a tarball of mods installed on your server? I would try to investigate that further then. Also, do you know who else suffers from this bug? Maybe Zool, maybe someone else?

stujones11 commented 8 years ago

...field '?' (a nil... — literal “?”, again (unless Cat5TV removed actual player name...)

afaik, the '?' is not literal here, it effectively means that the code tried to do nil[index]. The mystery is how it is being deleted or not initialized. Thank you for your assistance, I hope you are able to reproduce this anomaly and find the cause.

Cat5TV commented 8 years ago

@numberZero happy to provide a tar. However, out of respect for contributors who would prefer their custom work not be shared publicly, I cannot upload it here. Can I email it to your yandex address? Again, simply to honor the wishes of those who have coded some of the "not public" mods, I'd ask that you kindly use it only for testing this bug, not share it, and remove it when you are done. Cool?

Thanks so much!

numberZero commented 8 years ago

@stujones11 sorry, I forgot that Lua is so weird sometimes @Cat5TV received, will try to find out what exactly happens

numberZero commented 8 years ago

Crash happens, but in different way Steps:

  1. Start server with 3d_armor and unified_inventory
  2. Connect, die, but don’t respawn
  3. Restart the server
  4. Connect again with the same name
2016-06-04 14:36:40: ERROR[Main]: ServerError: Lua: Runtime error from mod '' in callback on_dieplayer(): ...t5tv/minetest/bin/../mods/unified_inventory/internal.lua:178: attempt to concatenate a nil value
2016-06-04 14:36:40: ERROR[Main]: stack traceback:
2016-06-04 14:36:40: ERROR[Main]:       ...t5tv/minetest/bin/../mods/unified_inventory/internal.lua:178: in function 'get_formspec'
2016-06-04 14:36:40: ERROR[Main]:       ...t5tv/minetest/bin/../mods/unified_inventory/internal.lua:233: in function 'set_inventory_formspec'
2016-06-04 14:36:40: ERROR[Main]:       ...minetest/bin/../mods/minetest-3d_armor/3d_armor/init.lua:294: in function <...minetest/bin/../mods/minetest-3d_armor/3d_armor/init.lua:279>
2016-06-04 14:36:40: ERROR[Main]:       ...support/cat5tv/minetest/bin/../builtin/game/register.lua:369: in function <...support/cat5tv/minetest/bin/../builtin/game/register.lua:349>

UPD: I have 0.4.13-dev; will test on the latest

Cat5TV commented 8 years ago

Thanks numberZero - so glad you were able to replicate the problem. Here's hoping you more experienced folk can figure this one out. I'm here if you need me to answer any questions or provide any more info.

stujones11 commented 8 years ago

Crash happens, but in different way

I would guess that is the same problem, only a different error since I prevented it from re-occurring there. It's great that you have been able to reproduce this, hopefully now we can find the root cause.

What I find strange is why nobody has reported any issue with the master branch. It would be interesting to know if that is effected or whether this only happens with 0.5.0-dev

Cat5TV commented 8 years ago

Agreed @stujones11 - although I'm sure some people would just disable bits and move on if it had problems... whereas I really want these features for our players! :)

It is important to note as well, that the applicable mods themselves on our server (eg., 3D Armor, Unified Inventory) are all up to date with the latest git pulls.

Cat5TV commented 8 years ago

Any updates? Server still crashing with this. Thanks!!

Raughnbo commented 8 years ago

Just checked, both Junebug and Fred are now able to log into the Pixel Shadow Survival Server.

Thanks,

~Raughnbo

On Mon, Jun 20, 2016 at 11:23 AM Robbie Ferguson notifications@github.com wrote:

Any updates? Server still crashing with this. Thanks!!

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/stujones11/minetest-3d_armor/issues/61#issuecomment-227175292, or mute the thread https://github.com/notifications/unsubscribe/AR0g0tFavB5yViwOG5L68xg4qloVJvlxks5qNrBzgaJpZM4Ihed4 .

Cat5TV commented 8 years ago

@Raughnbo while I'm glad you're able to login, this is because I finally gave up on 3D_armor 0.5.0 and downgraded to 0.4.5. So you're able to login again because of a downgrade. Several features will be missing (eg., armor stands, shield frames), but at least it doesn't crash the server. Hopefully Stu can get this solved so when 0.5.0 comes out, we can upgrade.

Raughnbo commented 8 years ago

Thanks Robbie, I hope the problem gets solved too.

On Tue, Jun 21, 2016 at 7:53 AM Robbie Ferguson notifications@github.com wrote:

@Raughnbo https://github.com/Raughnbo while I'm glad you're able to login, this is because I finally gave up on 3D_armor 0.5.0 and downgraded to 0.4.5. So you're able to login again because of a downgrade. Several features will be missing (eg., armor stands, shield frames), but at least it doesn't crash the server. Hopefully Stu can get this solved so when 0.5.0 comes out, we can upgrade.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/stujones11/minetest-3d_armor/issues/61#issuecomment-227417534, or mute the thread https://github.com/notifications/unsubscribe/AR0g0tGorAwyPvlAdbfHgv5JWZ5fro_qks5qN9C6gaJpZM4Ihed4 .

stujones11 commented 8 years ago

@Cat5TV so you can confirm that is only happens with the 0.5.0-dev branch? I was hoping that @numberZero might have come back with a solution but since this information narrows things down a lot, I will take another look at it myself. btw, you should be able to use the armor and shield stands from the dev branch if you wanted, only clothing won't work without the multiskin mod.

Cat5TV commented 8 years ago

@stujones11 yay, let the complaints about clothing begin! ;) Yes, after downgrading to 0.4.5 the issue went away, or at least seemingly so (the players who couldn't login and would crash our server when they tried can now login just fine).

Sorry I'm not well versed at Lua, otherwise I'd love to be more help.

stujones11 commented 8 years ago

I think I have finally figured this one out and it really comes down to an engine bug: https://github.com/minetest/minetest/issues/3565

When a player dies but does not respawn, the on_dieplayer callback is being re-called when the server is restarted but before any of the mod initialization, hence the nil values. It only does not happen in 0.4.5 because the old get_valid_player method checked for a valid detached inventory. If I am correct then you should be seeing lots of 3d_armor: Detached armor inventory is nil messages in your logs.

I have submitted a patch to the 0.5.0-dev branch to make it behave the same as 0.4.5 under these circumstances, it is not really a fix but a work-around until the root cause is fixed. Note that you will continue to receive the warning messages.

Cat5TV commented 8 years ago

@stujones11 yes, I ran a grep and in the course of 4 days we had 84 instances of that message in the logs.

Okay, I will reinstall 0.5.0-dev and hope all is well :) @Raughnbo can you let us know if there are any problems after the upgrade?

Thanks so much Stu. Keep up the great work, and let me know what I can do to help.

stujones11 commented 8 years ago

If you could get someone to die but not respawn until the server is restarted, then you can be reasonably sure the crash is fixed, however, there may still be other problems with the player, like missing armor for example.

You could also try to push for some action on https://github.com/minetest/minetest/pull/4127, that should solve the problem properly.