wielder.lua:113: bad argument [#1] to 'ipairs' (table expected, got nil)

[Bastrabun]

I do not have a repro unfortunately, but flux did a bit of research here: https://gitea.your-land.de/your-land/bugtracker/issues/1816

2022-04-23 10:31:57: ERROR[ConnectionSend]: con(4/1) dropped reliable packet for non existent peer_id: 899
2022-04-23 10:32:05: ERROR[Main]: ServerError: AsyncErr: Lua: Runtime error from mod 'xp_redo' in callback environment_Step(): ...ve/5.5.0/Minetest_live/bin/../mods/pipeworks/wielder.lua:113: bad argument [#1] to 'ipairs' (table expected, got nil)
2022-04-23 10:32:05: ERROR[Main]: stack traceback:
2022-04-23 10:32:05: ERROR[Main]: [C]: in function 'ipairs'
2022-04-23 10:32:05: ERROR[Main]: ...ve/5.5.0/Minetest_live/bin/../mods/pipeworks/wielder.lua:113: in function 'wielder_on'
2022-04-23 10:32:05: ERROR[Main]: ...ve/5.5.0/Minetest_live/bin/../mods/pipeworks/wielder.lua:147: in function 'action_on'
2022-04-23 10:32:05: ERROR[Main]: ...Minetest_live/bin/../mods/mesecons/mesecons/internal.lua:193: in function <...Minetest_live/bin/../mods/mesecons/mesecons/internal.lua:186>
2022-04-23 10:32:05: ERROR[Main]: ...etest_live/bin/../mods/mesecons/mesecons/actionqueue.lua:137: in function 'old_execute'
2022-04-23 10:32:05: ERROR[Main]: ...ve/worldmods/mesecons_debug/overrides/mesecons_queue.lua:20: in function 'execute'
2022-04-23 10:32:05: ERROR[Main]: ...etest_live/bin/../mods/mesecons/mesecons/actionqueue.lua:111: in function <...etest_live/bin/../mods/mesecons/mesecons/actionqueue.lua:73>
2022-04-23 10:32:05: ERROR[Main]: ...ive/5.5.0/Minetest_live/bin/../builtin/game/register.lua:425: in function <...ive/5.5.0/Minetest_live/bin/../builtin/game/register.lua:409>

For my reference 1816

[wsor4035]

given @fluxionary repro, i would guess that this has something to do with meta left behind by worldedit, or external storage of the position being kept, and worldedit not updating it. (voxel manip doesnt call the destroy/remove callbacks, or remove meta)

[Bastrabun]

When I want to clear an area with WE, I not only set it to air, but I also made a command to get rid of all metadata. And then ofc I clear entities. Anything I forgot?

[wsor4035]

would have to look and see if pipeworks is storing things internally, i know it tracks the entities internally at least

[S-S-X]

Because in minetest it is easy to break node metadata even without any admin commands this might again be just mod assuming false things based on what it did itself. As it is triggered by mesecons event it might also be mvps (or similar) releated problem.

[fluxionary]

I think MVPS is fine, given that you can push chests around and their contents remain.

I think a solution looks like a metadata "sanity check" at the start of wielder_on and similar methods. If it fails, log it, and either abort, or re-initialize and proceed.

I also think WorldEdit needs a blacklist feature.

[Bastrabun]

Unless I am mistaken and it only looks similar: This happened again, not reproducible again:

2024-07-03 15:00:15: ERROR[Main]: ServerError: AsyncErr: Lua: Runtime error from mod '??' in callback environment_Step(): ...mt/5.8.0/Minetest_test/bin/../mods/pipeworks/wielder.lua:71: bad argument #1 to 'ipairs' (table expected, got nil)
2024-07-03 15:00:15: ERROR[Main]: stack traceback:
2024-07-03 15:00:15: ERROR[Main]:   [C]: in function 'ipairs'
2024-07-03 15:00:15: ERROR[Main]:   ...mt/5.8.0/Minetest_test/bin/../mods/pipeworks/wielder.lua:71: in function 'wielder_action'
2024-07-03 15:00:15: ERROR[Main]:   ...mt/5.8.0/Minetest_test/bin/../mods/pipeworks/wielder.lua:86: in function 'wielder_on'
2024-07-03 15:00:15: ERROR[Main]:   ...mt/5.8.0/Minetest_test/bin/../mods/pipeworks/wielder.lua:141: in function 'action_on'
2024-07-03 15:00:15: ERROR[Main]:   ...Minetest_test/bin/../mods/mesecons/mesecons/internal.lua:184: in function <...Minetest_test/bin/../mods/mesecons/mesecons/internal.lua:177>
2024-07-03 15:00:15: ERROR[Main]:   ...etest_test/bin/../mods/mesecons/mesecons/actionqueue.lua:137: in function 'old_execute'
2024-07-03 15:00:15: ERROR[Main]:   .../bin/../mods/mesecons_debug/overrides/mesecons_queue.lua:27: in function 'execute'
2024-07-03 15:00:15: ERROR[Main]:   ...etest_test/bin/../mods/mesecons/mesecons/actionqueue.lua:111: in function <...etest_test/bin/../mods/mesecons/mesecons/actionqueue.lua:73>
2024-07-03 15:00:15: ERROR[Main]:   ...t/5.8.0/Minetest_test/bin/../builtin/common/register.lua:26: in function <...t/5.8.0/Minetest_test/bin/../builtin/common/register.lua:12>

For my reference 7042

[OgelGames]

Yeah it's the same, a wielder that doesn't have an inventory, which should never happen normally.

https://github.com/mt-mods/pipeworks/blob/e9a9bd711ecef35b36d319e3ff9c9f81e17084a6/wielder.lua#L71

[Bastrabun]

Any debugging code to find what's happening or nil guard to stop it from happening or both I could add?

It doesn't happen often, but it hints at some issue somewhere else tbh.

[Bastrabun]

I added some debug:

        def.action(fakeplayer, pointed)
        if def.eject_drops then
                local invlist = inv:get_list("main")
                if (invlist == nil) then
                        core.log("error","#7042 invlist is nil")
                        core.log("error","#7042 invlist is nil def="..dump(def))
                        core.log("error","#7042 invlist is nil pos=".. dump(pos))
                        core.log("error","#7042 invlist is nil node="..dump(node))
                        core.log("error","#7042 invlist is nil index="..dump(index))
                        return
                end
                for i, stack in ipairs(inv:get_list("main")) do
                        if not stack:is_empty() then
                                pipeworks.tube_inject_item(pos, pos, dir, stack)
                                inv:set_stack("main", i, ItemStack(""))
                        end
                end
        end

And this is what it gave me:

2024-08-01 15:18:17: ERROR[Server]: #7042 invlist is nil
2024-08-01 15:18:17: ERROR[Server]: #7042 invlist is nil def={
    eject_drops = true,
    description = "\27(T@pipeworks)Node Breaker\27E",
    name = "pipeworks:nodebreaker",
    action = <function>,
    wield_hand = true,
    wield_inv = {
        width = 1,
        name = "pick",
        height = 1
    },
    tiles = {
        off = {
            "pipeworks_nodebreaker_top_off.png",
            "pipeworks_nodebreaker_bottom_off.png",
            "pipeworks_nodebreaker_side2_off.png",
            "pipeworks_nodebreaker_side1_off.png",
            "pipeworks_nodebreaker_back.png",
            "pipeworks_nodebreaker_front_off.png"
        },
        on = {
            "pipeworks_nodebreaker_top_on.png",
            "pipeworks_nodebreaker_bottom_on.png",
            "pipeworks_nodebreaker_side2_on.png",
            "pipeworks_nodebreaker_side1_on.png",
            "pipeworks_nodebreaker_back.png",
            "pipeworks_nodebreaker_front_on.png"
        }
    },
    connect_sides = {
        right = 1,
        bottom = 1,
        back = 1,
        top = 1,
        left = 1
    }
}
2024-08-01 15:18:17: ERROR[Server]: #7042 invlist is nil pos={
    x = 1893,
    y = -2748,
    z = 1495
}
2024-08-01 15:18:17: ERROR[Server]: #7042 invlist is nil node={
    param1 = 0,
    name = "pipeworks:nodebreaker_on",
    param2 = 15
}
2024-08-01 15:18:17: ERROR[Server]: #7042 invlist is nil index=nil

I probably have a repro now, although I must admit I don't understand it. What now?

[SwissalpS]

You say you found a way to reproduce the error situation, do you mind sharing it?

[Bastrabun]

Repro as in "happens again 100% of the time I load the mapblock".

It's not a repro where I could build a machine and it 100% fails. If you want, I'll show you ingame, you can read out values via lua.

Visit me on the YL testserver if that helps or poke me on discord, matrix, IRC or anywhere else:

address your-land.de port 30001

[BuckarooBanzay]

@Bastrabun can you provide a worldedit schematic from the area mentioned in the above stacktrace:

Should include the region around this:

{
    x = 1893,
    y = -2748,
    z = 1495
}

Or somewhere else where this happens

[OgelGames]

Repro as in "happens again 100% of the time I load the mapblock".

It's not a repro where I could build a machine and it 100% fails. If you want, I'll show you ingame, you can read out values via lua.

That's what is needed though, we know why it fails when loading the mapblock (it's missing an inventory), but we need to know how it got that way.

As far as I know the only way it can happen is with worldedit, or some other mod that places nodes with a VoxelManip and doesn't call the appropriate callbacks.

[Bastrabun]

worldedit schematic from the area mentioned in the above stacktrace:

bugtracker7042_nodebreaker_01.we.zip

but we need to know how it got that way.

The area is from before 13.6.2022, the player did not have Worldedit or any priv above normal player.