What exactly does "bad output" mean

ID:264521
 
Sep 12 2009, 8:28 am
I'm having some issues with a list I'm dropping into a savefile, which intermittently causes a proc crash resulting in the client's mob not being deleted. Of course, this causes all manner of problems, but I have yet to figure out what "bad output" is supposed to translate to in terms of preventative code measures.

//code snippet:
if(!isnull(c.reprimand_data))
    var/reprimand_save[0]
    for(var/a in c.reprimand_data)
        if(istype(c.reprimand_data[a],/list)) reprimand_save[a] = c.reprimand_data[a]
    s["reprimand_data"] << reprimand_save //this is line 511
    c.reprimand_data = null
else s.dir.Remove("reprimand_data")

//runtime:
runtime error: bad output
proc name: Del (/client/Del)
  source file: support.dm,511
  usr: Britjudson (/mob/pc/character)
  src: Britjudson (/client)
  call stack:
Britjudson (/client): Del(0)
Sep 12 2009, 10:54 am
What does the reprimand_data list contain?
Sep 12 2009, 11:29 am
In response to Garthor
Garthor wrote:
What does the reprimand_data list contain?

reprimand_data is an associative list of lists. A string key is associated to a list value to hold pertinent information about reprimand handed down from the host, or anyone they put in power, in the order issued_time, moderator, expiration_time. An example (with made up realtime values):

reprimand_data = list(
"audio" = list(1102993635,"tiberath",0)
"ban" = list(2229479482,"renocovault",3927728176)
"mute" = list(1188928222,"mobiusevalon",2200192827)
)


The entire list is null when there's no reprimand to keep track of, and is only populated with those currently in effect (such as if the player isn't muted, the "mute" value doesn't appear).
Sep 20 2009, 9:41 am (Edited on Sep 20 2009, 9:51 am)
No thoughts on this? For the time being I've employed the highly undesirable solution of manually deleting leftover player mobs intermittently, but insight on how to avoid this happening in the first place would be preferred.

I can't figure out what exactly could be contained in reprimand_save that would amount to "bad output". In the case there's nothing to stash in the savefile, reprimand_save would be an empty list and shouldn't cause any problems to output. In the case there is data, the istype() check should ensure that only (valid) lists are collected.

The occurrence is rare but causes problems of a catastrophic nature. What would reprimand_save contain for BYOND to crash the proc and label it as "bad output"?

I've since changed the above to the following:
var/reprimand_save[0]
if(!isnull(c.reprimand_data))
    for(var/a in c.reprimand_data)
        if(istype(c.reprimand_data[a],/list)) reprimand_save[a] = c.reprimand_data[a]
    c.reprimand_data = null
if(istype(reprimand_save,/list) && reprimand_save.len) s["reprimand_data"] << reprimand_save
else s.dir.Remove("reprimand_data")


I took a random stab at the type and length of the list being output, but without the particulars I can't address the issue intelligently.
Sep 20 2009, 9:53 am
In response to Mobius Evalon
Random suspicion: could you post the proc where you save players? I can see where there may be an issue if you are calling Write().
Sep 20 2009, 10:18 am
In response to Garthor
The above is part of it. I don't use Write() or Read(), I do everything required in client/Del() and mob/player/Login(), respectively.

This is client/Del:

client/Del(invisible=0)
    var/mob/pc/character/c = src.mob
    if(istype(c) && copytext(src.key,1,7) != "Guest-")
        //pending forms and prompts
        for(var/form/f)
            if(f.target_mob == c) del(f)
        for(var/prompt/p)
            if(p.dialogue_recipient == c) del(p)
        var/savefile/s = new /savefile("players/[c.ckey].ius")
        s.cd = "/"
        //reprimand data
        var/reprimand_save[0]
        if(!isnull(c.reprimand_data))
            for(var/a in c.reprimand_data)
                if(istype(c.reprimand_data[a],/list)) reprimand_save[a] = c.reprimand_data[a]
            c.reprimand_data = null
        if(istype(reprimand_save,/list) && reprimand_save.len) s["reprimand_data"] << reprimand_save
        else s.dir.Remove("reprimand_data")
        //last login time
        s["last_login_time"] << world.realtime
        //vehicle
        if(c.vehicle) c.vehicle.vehicle_exit(c)
        //reset eye
        if(src.eye != c)
            var/obj/ownable/inventory/i = src.eye
            if(istype(i)) i.Move(c)
        if(c.sight & SEE_MOBS) c.sight &= ~(SEE_MOBS|SEE_OBJS|SEE_TURFS)
        c.tag = null
        //reset other's client.eye if this mob is being spied on
        if(!isnull(c.listeners))
            for(var/mob/pc/character/m in c.listeners)
                if(m.client.eye == c) m.client.eye = m
            c.listeners = null
        //moderator items
        for(var/obj/ownable/inventory/imm/i in c.contents) del(i)
        //paintball
        if(paintball_game && (c in paintball_game.game_players)) paintball_game.player_logged(c)
        //pets
        if(c.pet)
            for(var/obj/hud/pet/p in src.screen) src.screen -= p
            c.pet.owner = null
            c.pet.loc = c
        //custom afk state
        if(array_get(c.status,"previous_afk_state")) c.icon_state = array_get(c.status,"previous_afk_state")
        //rename queue
        if(rename_queue && (c in rename_queue.waiting)) rename_queue.remove(c)
        //overlays and underlays
        c.overlays.Cut()
        c.underlays.Cut()
        if(c.old_icon)
            c.icon = c.old_icon
            c.old_icon = null
        //drop temporary AIS members
        var/p
        if(!isnull(ais_commandunit) && (c.ckey in ais_commandunit))
            p = ais_commandunit.Find(c.ckey)
            if(p > length(initial(ais_commandunit))) list_remove(ais_commandunit,c.ckey)
        if(!isnull(ais_airunit) && (c.ckey in ais_airunit))
            p = ais_airunit.Find(c.ckey)
            if(p > length(initial(ais_airunit))) list_remove(ais_airunit,c.ckey)
        if(!isnull(ais_groundunit) && (c.ckey in ais_groundunit))
            p = ais_groundunit.Find(c.ckey)
            if(p > length(initial(ais_groundunit))) list_remove(ais_groundunit,c.ckey)
        if(!isnull(ais_navalunit) && (c.ckey in ais_navalunit))
            p = ais_navalunit.Find(c.ckey)
            if(p > length(initial(ais_navalunit))) list_remove(ais_navalunit,c.ckey)
        //basic logout stuff
        c.invisibility = 0
        c.layer = MOB_LAYER
        c.verbs.Cut()
        var
            area/courtroom_building/courtroom = locate()
            turf/t = c.loc
        if(t.z == 1 || (t in courtroom.contents))
            c.prev_x = t.x
            c.prev_y = t.y
            c.prev_z = t.z
        c.prev_d = c.dir
        var/level = System.rank2num(c.client)
        array_set(server,"player_count","-1")
        if(level >= STAFF_ASSISTANT) array_set(server,"staff_count","-1")
        s["character"] << c
        del(s)
        //announce character logout
        var/diff = round((world.time-src.login_time),600)
        if(level < STAFF_ADMIN || !array_get(c.status,"invisible")) server("<span class=\"general\">[c.clean_name] ([c.key]) has logged out after [diff >= 600 ? tick2time(diff) : "less than a minute"].</span>")
    //announce client disconnection
    announce("Closed connection: <a href=\"byond://?src=\ref[System];action=search;param=[src.ckey]\" title=\"[src.key]\">[src.key]</a> (<a href=\"byond://?src=\ref[System];action=search;param=[src._remote_address]\" title=\"[src._remote_address]\">[src._remote_address]</a>)","wiznet")
    del(src.mob)
    . = ..()
Sep 20 2009, 10:38 am
In response to Mobius Evalon
Mobius Evalon wrote:
An example (with made up realtime values):
reprimand_data = list(
> "audio" = list(1102993635,"tiberath",0)
> "ban" = list(2229479482,"renocovault",3927728176)
> "mute" = list(1188928222,"mobiusevalon",2200192827)
> )


Made up examples are good for theoretical use but for bug hunting you actually want to dump exactly what is in the list when you're trying to save it. Write up a small proc to dump all the values, associated values, and recursively dump the contained lists via the same proc, and share with us some actual data associated with one of these runtime errors. To track "bad output" it helps to actually see specifically what you're trying to output.

It would also be useful to provide a real result of list2params() of your list during one of the calls which causes these runtimes.

If not every call causes a runtime error, you could simply write the result of these list dumps to the world log at the time of saving. Then your log should have list dumps for each save and ones that try to write something naughty will be surrounded by runtimes.
Sep 20 2009, 5:33 pm
In response to Kuraudo
I grabbed a savefile from a client that was exhibiting this problem, but ExportText fails to display its contents, and I have no idea what the issue with it is. The "bad output" may be resulting in bork savefiles.

I've got the file here if anyone has the means to pull it apart:

http://mobiusevalon.tibbius.com/britjudson.ius
Sep 20 2009, 6:05 pm
In response to Mobius Evalon
Again, it is likely going to be much more helpful to see specifically what you're trying to output rather than the borked result of your "bad output."
Sep 20 2009, 6:09 pm
In response to Kuraudo
Kuraudo wrote:
Again, it is likely going to be much more helpful to see specifically what you're trying to output rather than the borked result of your "bad output."

I'm still waiting on the error to crop up again now that I've got a debug dump in place. I'll post something when I've got a bite, I just thought an example of what I have at the end of the problem may offer insight to earlier events in the timeline while I lie in wait for it to happen again.