Up to Main Index                             Up to Journal for March, 2018

                     JOURNAL FOR SATURDAY 3RD MARCH, 2018
______________________________________________________________________________

SUBJECT: Not a message buffer issue
   DATE: Sat  3 Mar 19:36:33 GMT 2018

Quick recap from my previous journal entry:


  While experimenting with using the JUNK command on a player I noticed a
  weird bug in the message buffer handling:


    >quit
    You junk an iron bound chest.
    You leave this world behind.
    You junk a small green ball.
    You leave this world behind.

      Main Menu
      ---------

      1. Enter game
      0. Quit

    Select an option:
    >0

    Bye bye...

    Connection closed by foreign host.


  Notice that “You leave this world behind.” appears twice when it should only
  appear once. This only seems to happen if a player quits when there is
  nothing else at the same location. Not sure why, will investigate.


I investigated, and it turns out I was wrong. It wasn’t a bug in the message
buffer handling. Finding the actual cause of the problem took some time, and a
4am flash of insight.

Wednesday, after posting the journal entry, I started digging into the problem
seen above and littering the WolfMUD code with log.Printf statements. This is
a time honoured, traditional way to debug software. To quote Brian Kernighan
and Rob Pike[1]:


  As personal choice, we tend not to use debuggers beyond getting a stack
  trace or the value of a variable or two. One reason is that it is easy to
  get lost in details of complicated data structures and control flow; we find
  stepping through a program less productive than thinking harder and adding
  output statements and self-checking code at critical places. Clicking over
  statements takes longer than scanning the output of judiciously-placed
  displays. It takes less time to decide where to put print statements than to
  single-step to the critical section of code, even assuming we know where
  that is. More important, debugging statements stay with the program;
  debugging sessions are transient.


I also find debuggers cumbersome and distracting. There are times when they
can be helpful. However, if you are in the middle of coding, are thinking in
your language of choice already, dropping in a print statement comes very
naturally.

It soon became apparent that the message buffers where not the problem. The
quit command was running twice, and the JUNK commands were only sometimes
running twice — depending on where you were in the world when you quit.

Thursday night, more log.Printf statements added. I was still attempting to
identify the problem. The attempt failed.

Thursday night I couldn’t sleep, and just before 4am I had a sudden flash of
insight. The JUNK command was causing a resynchronising of the locks after
adding new locks for origins — the place where a junked item was going to
reset. This explained why the location where you quit influenced the messages
displayed. Quitting at a location where one or more of your inventory items
was going to reset meant the lock had already been acquired, resynchronising
wasn’t necessary to acquire new locks.

The urge to grab my Chromebook and start hacking to prove my theory was
strong, even at 4am in the morning. However, work next day, no sleep, blah
blah blah — I resisted the temptation. Instead I mulled over the problem lying
in the dark, until finally falling asleep.

Friday night I had time to prove my theory. I simply took a count of the locks
held before executing the JUNK commands. I then checked the count again after
the JUNK commands had been completed. If the count was different the QUIT
command simply exits instead of completing. This causes the resynchronising
logic to obtain the new locks and execute the QUIT and JUNK commands again.

It worked :)

Checking the lock count is performed in a few places already to see of a
resynchronisation of the locks is required. See: cmd/cleanup.go, cmd/junk.go

I’m now wondering if there should be a better way to detect if the locks have
changed. Checking the length of the locks slice seems a tad messy. Maybe a
method like state.needResync is needed. The state could then handle the
bookkeeping instead of doing it manually.

However, I don’t want to be making such invasive, critical changes right now.
I don’t have the backup of tests to run to make sure I don’t break anything.
After I complete the saving and loading of players I plan on auditing all of
the code and writing tests for everything. I’ve not written tests until now as
the code churn has been quite substantial, which would require constant
rewriting of the tests.

There are also several another logistical problems I need to solve.

What to do about items that cannot be junked. An example in the current world
is the lattice in the tavern which has a veto that prevents it from being
junked. If you are carrying the lattice and quit it is not junked, resulting
in it being destroyed. This is because once the player is removed there are no
other references to the lattice. Maybe force a reset on such items?

Another issue is that of unique containers. If a player has a unique container
that contains items the player can keep, what happens to the items when the
player quits and the container is junked? I think the items should be taken
out of the container automatically — so the container disappears leaving its
content behind. But, the unique container may be in another container, or it
may contain other containers.

The trick here is to come up with generic ways of handling these issues,
instead of handling lots of corner cases. It also needs to be done in such a
way so as not to surprise players, zone authors or other programmers.

--
Diddymus

  [1] The Practice of Programming, Brian W. Kernighan and Rob Pike
      Published by Addison Wesley, 4 February 1999, ISBN-13: 978-0201615869


  Up to Main Index                             Up to Journal for March, 2018