theFox6 / working_villages

A mod for minetest that adds villagers performing work
https://content.minetest.net/packages/theFox/working_villages/
MIT License
13 stars 10 forks source link

Crash in default:log_player_action when woodcutter places sapling #32

Closed bengardner closed 2 years ago

bengardner commented 2 years ago

Describe the bug When a woodcutter places a sapling, the default game tries to log_player_action(), but player is nil.

To Reproduce Create a villager. Set the job to woodcutter. Toss it a sapling. Woodcutter places it. Crash.

Expected behavior The woodcutter places the sapling.

Log


2022-10-07 16:41:54: [Main]: Automatically selecting world at [/home/user/.minetest/worlds/test]
2022-10-07 16:41:56: ACTION[Main]: [MOD] Animalia [0.4] loaded
2022-10-07 16:41:56: WARNING[Main]: Not registering alias, item with same name is already defined: mushroom:brown_natural -> flowers:mushroom_fertile_brown
2022-10-07 16:41:56: WARNING[Main]: Not registering alias, item with same name is already defined: mushroom:red_natural -> flowers:mushroom_fertile_red
2022-10-07 16:41:56: ACTION[Main]: [working_villages] loading init
2022-10-07 16:41:56: ACTION[Main]: [working_villages] loading modutil portable
2022-10-07 16:41:56: ACTION[Main]: [working_villages] loading logging
2022-10-07 16:41:56: ACTION[Main]: [working_villages] loaded logging
2022-10-07 16:41:56: ACTION[Main]: [working_villages] loading LuaVenusCompiler
2022-10-07 16:41:56: ACTION[Main]: [working_villages] loaded LuaVenusCompiler
2022-10-07 16:41:56: ACTION[Main]: [working_villages] loading local_require
2022-10-07 16:41:56: ACTION[Main]: [working_villages] loaded local_require
2022-10-07 16:41:56: ACTION[Main]: [working_villages] setting modutil global
2022-10-07 16:41:56: ACTION[Main]: [working_villages] loaded portable
2022-10-07 16:41:56: ACTION[Main]: [working_villages] loaded init in 0.0188 s
2022-10-07 16:41:56: ACTION[Main]: [building_sign] loading...
2022-10-07 16:41:57: ACTION[Main]: [building_sign] loaded init in 0.0070 s
2022-10-07 16:41:57: ACTION[Main]: World at [/home/user/.minetest/worlds/test]
2022-10-07 16:41:57: ACTION[Main]: Server for gameid="minetest" listening on 0.0.0.0:56271.
2022-10-07 16:41:58: WARNING[Main]: Texture "youngtree2branch.png" of youngtrees:youngtree2_middle has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]:   This warning can be a false-positive if unused pixels in the texture are transparent. However if it is meant to be transparent, you *MUST* update the nodedef and set use_texture_alpha = "clip"! This compatibility code will be removed in a few releases.
2022-10-07 16:41:58: WARNING[Main]: Texture "molehills_dirt.png" of molehills:molehill has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "ferns_fern_trunk_top.png" of ferns:fern_trunk has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "ferns_tree_fern_leave_big_end.png" of ferns:tree_fern_leave_big_end has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "ferns_fern_trunk_big_top.png^ferns_tree_fern_leave_big_cross.png" of ferns:fern_trunk_big_top has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "ferns_fern_trunk_big_top.png" of ferns:fern_trunk_big has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "bushes_leaves_1.png" of bushes:bushbranches1 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "bushes_leaves_2.png" of bushes:bushbranches3 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "bushes_leaves_1.png" of bushes:bushbranches2 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "bushes_leaves_2.png" of bushes:bushbranches4 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_twig_1.png" of trunks:twig_1 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_twig_2.png" of trunks:twig_2 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_twig_3.png" of trunks:twig_3 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_twig_4.png" of trunks:twig_4 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_twig_5.png" of trunks:twig_5 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_twig_7.png" of trunks:twig_7 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_twig_8.png" of trunks:twig_8 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_twig_9.png" of trunks:twig_9 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_twig_10.png" of trunks:twig_10 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_twig_11.png" of trunks:twig_11 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_twig_12.png" of trunks:twig_12 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_twig_13.png" of trunks:twig_13 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_moss.png" of trunks:moss_plain_0 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_moss_fungus.png" of trunks:moss_with_fungus_0 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_moss.png^[transformR90" of trunks:moss_plain_1 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_moss_fungus.png^[transformR90" of trunks:moss_with_fungus_1 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_moss.png^[transformR180" of trunks:moss_plain_2 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_moss_fungus.png^[transformR180" of trunks:moss_with_fungus_2 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_moss.png^[transformR270" of trunks:moss_plain_3 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "trunks_moss_fungus.png^[transformR270" of trunks:moss_with_fungus_3 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "default_tree.png^trunks_root_mask.png^[makealpha:0,0,0" of trunks:treeroot has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "default_jungletree.png^trunks_root_mask.png^[makealpha:0,0,0" of trunks:jungletreeroot has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "default_pine_tree.png^trunks_root_mask.png^[makealpha:0,0,0" of trunks:pine_treeroot has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "animalia_nest.png" of animalia:nest_song_bird has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "flowers_waterlily.png" of flowers:waterlily has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "default_sign_wall_wood.png" of working_villages:building_marker has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "default_sign_wall_wood.png" of building_sign:building_marker has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "flowers_waterlily_22.5.png" of flowers:waterlily_225 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "flowers_waterlily_45.png" of flowers:waterlily_45 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "flowers_waterlily_67.5.png" of flowers:waterlily_675 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "flowers_waterlily_small_1.png" of flowers:waterlily_s1 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "flowers_waterlily_small_2.png" of flowers:waterlily_s2 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "flowers_waterlily_small_3.png" of flowers:waterlily_s3 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "flowers_waterlily_small_4.png" of flowers:waterlily_s4 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "flowers_sunflower.png" of flowers:sunflower has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "flowers_seaweed.png" of flowers:seaweed has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "flowers_seaweed_2.png" of flowers:seaweed_2 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "flowers_seaweed_3.png" of flowers:seaweed_3 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "flowers_seaweed_4.png" of flowers:seaweed_4 has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "dryplants_grass.png" of dryplants:grass has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: WARNING[Main]: Texture "dryplants_hay.png" of dryplants:hay has transparency, assuming use_texture_alpha = "clip".
2022-10-07 16:41:58: ACTION[Server]: singleplayer [127.0.0.1] joins game. List of players: singleplayer
2022-10-07 16:42:01: ERROR[Main]: ServerError: AsyncErr: Lua: Runtime error from mod 'default' in callback luaentity_Step(): ...ds/working_villages/working_villagers/job_coroutines.lua:42: error in job_thread Runtime error from mod 'default' in callback item_OnPlace(): .../minetest/games/m
2022-10-07 16:42:01: ERROR[Main]: inetest_game/mods/default/functions.lua:730: attempt to index local 'player' (a nil value)
2022-10-07 16:42:01: ERROR[Main]: stack traceback:
2022-10-07 16:42:01: ERROR[Main]:   .../minetest/games/minetest_game/mods/default/functions.lua:730: in function 'log_player_action'
2022-10-07 16:42:01: ERROR[Main]:   ...hare/minetest/games/minetest_game/mods/default/trees.lua:575: in function 'sapling_on_place'
2022-10-07 16:42:01: ERROR[Main]:   ...hare/minetest/games/minetest_game/mods/default/nodes.lua:734: in function <...hare/minetest/games/minetest_game/mods/default/nodes.lua:733>
2022-10-07 16:42:01: ERROR[Main]:   [C]: in function 'resume'
2022-10-07 16:42:01: ERROR[Main]:   ...ds/working_villages/working_villagers/job_coroutines.lua:35: in function 'resume'
2022-10-07 16:42:01: ERROR[Main]:   ...minetest/mods/working_villages/working_villagers/api.lua:952: in function <...minetest/mods/working_villages/working_villagers/api.lua:937>: stack traceback:
2022-10-07 16:42:01: ERROR[Main]:   [C]: in function 'place_node'
2022-10-07 16:42:01: ERROR[Main]:   ...ods/working_villages/working_villagers/async_actions.lua:223: in function 'place'
2022-10-07 16:42:01: ERROR[Main]:   ...s/working_villages/working_villagers/jobs/woodcutter.lua:63: in function <...s/working_villages/working_villagers/jobs/woodcutter.lua:43>
2022-10-07 16:42:01: ERROR[Main]: stack traceback:
2022-10-07 16:42:01: ERROR[Main]:   [C]: in function 'error'
2022-10-07 16:42:01: ERROR[Main]:   ...ds/working_villages/working_villagers/job_coroutines.lua:42: in function 'resume'
2022-10-07 16:42:01: ERROR[Main]:   ...minetest/mods/working_villages/working_villagers/api.lua:952: in function <...minetest/mods/working_villages/working_villagers/api.lua:937>
2022-10-07 16:42:01: ACTION[Server]: singleplayer leaves game. List of players: 
2022-10-07 16:42:02: ACTION[Main]: Server: Shutting down

Desktop (please complete the following information):

Minetest 5.6.1 (Linux)
Using Irrlicht 1.9.0mt8
Using LuaJIT 2.1.0-beta3
BUILD_TYPE=Release
RUN_IN_PLACE=0
USE_CURL=1
USE_GETTEXT=1
USE_SOUND=1
STATIC_SHAREDIR="/usr/share/minetest"
STATIC_LOCALEDIR="/usr/share/locale"

Mods activated:

animalia
anvil
biome_lib
bonemeal
creatura
mesecons
mobkit
mobs
mobs_npc
moreores
plantlife_modpack
working_villages
worldedit

Function that crashes (in default/functions.lua)

function default.log_player_action(player, ...)
    local msg = player:get_player_name()
    if player.is_fake_player or not player:is_player() then
        if not log_non_player_actions then
            return
        end
        msg = msg .. "(" .. (type(player.is_fake_player) == "string"
            and player.is_fake_player or "*") .. ")"
    end
    for _, v in ipairs({...}) do
        -- translate pos
        local part = is_pos(v) and minetest.pos_to_string(v) or v
        -- no leading spaces before punctuation marks
        msg = msg .. (string.match(part, "^[;,.]") and "" or " ") .. part
    end
    minetest.log("action",  msg)
end

This is probably a bug in the Minetest default game. But maybe there is a way to provide a fake player.

bengardner commented 2 years ago

As an update -- I dug into the minetest / default game code a bit and discovered that the issue is in the minetest default game.

The call minetest.place_node() does not include the placer as a parameter. The on_place() callbacks will always have a nil placer. I think that is the root bug. The next layer bug is either in default.sapling_on_place() (trees.lua) or default.log_player_action(). default.sapling_on_place() checks placer for nil in a few places, but passes it to default.log_player_action(). default.log_player_action() doesn't check for nil.

This cannot be fixed in working_villagers without using a different place method.

I suppose this can be tagged as an upstream bug.

sfence commented 2 years ago

Hi. Thanks for using working_villages and for reporting an update about a bug source.

I try to reproduce that error in minetest game with tags 5.6.0 and 5.6.1. Without success. So I hope, this problem is not relevant to minetest game which is included in minetest installation.

bengardner commented 2 years ago

I should have stated that I used working_villagers from contentdb. I did not use the version in git.

It looks like the issue was addressed a year ago in git in commit https://github.com/theFox6/working_villages/commit/abcc4bbb087e183c0cb5f5317061149ec17dc830