Debugging in Python, part 10: A logical error
MP 151: How do you debug a program that doesn't crash?
Note: This post is part of an ongoing series about debugging in Python. The posts in this series will only be available to paid subscribers for the first 6 weeks. After that they will be available to everyone. Thank you to everyone who supports my ongoing work on Mostly Python.
In the last two posts we made models called Card, Hand, and Deck, which can form the foundation of any game that uses playing cards. In this post we'll start building a terminal-based implementation of Go Fish. If you haven't played it before, it's a game where you try to get as many pairs of cards as you can, by asking the other player if they have a card you want.
An intentional error
There are a couple logical errors in the models that were developed in the previous posts. Those errors won't show up right away, so I'm going to start with a slight variation of those models, with an error that I've intentionally introduced. This will let us focus right away on how to deal with logical errors while developing a project. The full game will bring us back to the errors I accidentally wrote into the initial implementation.
The version of Card, Hand, and Deck with the intentional error can be found here.
Game specs
Even if you've played Go Fish before, it's good to jot a few specifics about what we're going to build:
- There will be two players, the human player and the computer. The human player will always go first.
- When it's your turn, you ask the computer if it has a card that will help you make a pair. If it does, you get that pair, and you go again. The computer will do the same when it takes its turn.
- Whoever makes the most pairs wins.
- We won't worry about the computer playing well now, we'll just make sure the computer plays according to the rules.
- At the end of the game, the player will be given the choice of whether to play again, or quit.
That should be enough to let us start coding an implementation of Go Fish.
Starting the game
We'll write the game in a single file called go_fish.py, and the game as a whole will be represented by a class called GoFish:
"""Go Fish game, where one person plays against the computer.""" from card_models import Card, Hand, Deck class GoFish: def __init__(self): # Start with a new shuffled deck. self.deck = Deck() self.deck.shuffle()
When a game starts, we build a deck and shuffle it.
Now let's write a method to start the game:
... class GoFish: ... def start_game(self): # Deal two hands. hands = self.deck.deal(num_hands=2, num_cards=7) self.player_hand, self.computer_hand = hands self.player_hand.organize() self.computer_hand.organize() self.player_pairs = [] self.computer_pairs = [] # Player goes first. self.player_turn()
When start_game() is called, we deal two hands of seven cards each from the deck. One hand is assigned to self.player_hand, and the other is assigned to self.computer_hand. We organize each hand as well. We also initialize an empty list for each player to store the pairs they make throughout the game.
After setting up the game, we call player_turn() to manage the human player's turn.
Managing the human player's turn
Here's the first part of player_turn():
... class GoFish: ... def player_turn(self): """Manage the human player's turn.""" self.show_state() def show_state(self): """Show the current state of the game.""" print("Player hand:") self.player_hand.show() print("\nComputer hand:") self.computer_hand.show(hidden=True)
When it's the player's turn, the first thing we want to do is show the current state of the game. We'll do this more than once, so we put that logic in a show_state() method. To show the state, we're calling hand.show() for the player, and then for the computer.
This brings up the first refinement we need to make to one of the card models. We can't just show the computer's hand, or the game wouldn't be any fun. So we'll add an argument called hidden to hand.show(), that lets you display a hand without showing its cards.
Here's the update to Hand:
class Hand: ... def show(self, hidden=False): if hidden: hand_string = " ".join(["X" for card in self.cards]) else: hand_string = " ".join([str(card) for card in self.cards]) print(hand_string)
The default behavior is to not hide cards when showing them. If hidden is True, we show a capital X for each card in the hand. We also insert two spaces between each X, so the X's roughly match up with visible cards when multiple hands are shown. If hidden is False, we show all the cards in the hand as we were doing before.
Playing the game
Let's add a block to the end of go_fish.py to start a game when we run the module directly:
... class GoFish: ... if __name__ == "__main__": gf_game = GoFish() gf_game.start_game()
Now we should be able to run go_fish.py, and play through as much of the game as we've implemented:
$ python go_fish.py Player hand: 2♦ 4♠ 5♠ 6♣ 7♥ 8♣ 9♣ 10♣ 10♠ J♣ J♠ Q♦ K♦ A♣ Computer hand: X X X X X X X X X X X X X X
Well, that's somewhat correct. We were expecting to see two hands, which we do. The player's hand is visible and the computer's is hidden, which is what we wanted. However, each player was supposed to have seven cards. I can see there's more than seven cards in each hand, and when I look closely I count 14 cards in each hand!
This is a logical error. The program ran without crashing, but the output is not entirely correct. Let's jump into debugging.
Note: If you want to run the project at this point to focus on the debugging process, you can download the files from this directory.
Entirely contrived?
This might seem like an entirely contrived example. If you had this project under version control, you could run git diff against the project from the last post, and see what I changed in card_models.py to cause this error. But it's entirely common for code that went years without causing an error to suddenly be involved in a newly-discovered logical error. Codebases are large and complex enough these days that this happens all the time.
You should use version history and test results as part of your debugging process, when they're available and relevant. For the purpose of this post, we're going to pretend we were handed this code base without any history, and without any tests. Let's reason through what's happening, with the use of Python's built-in debugging tools.
Getting started
Something's going on with the hands. Let's first take out the hidden argument when we show the computer's hand, so we can see its cards as well:
def show_state(self): ... print("\nComputer hand:") self.computer_hand.show(hidden=False)
Now we can see both player's hands, and hopefully get a little better understanding of what's happening:
$ python go_fish.py Player hand: 4♦ 5♠ 6♦ 6♥ 7♣ 7♦ 7♠ 10♦ 10♥ 10♠ J♠ Q♦ Q♠ K♠ Computer hand: 4♦ 5♠ 6♦ 6♥ 7♣ 7♦ 7♠ 10♦ 10♥ 10♠ J♠ Q♦ Q♠ K♠
That's interesting, both players have the same exact hand! At first glance, it seems like the two hands have somehow been combined.
Print debugging?
If you haven't heard of it, print debugging is the process of inserting print() calls into your code and then running your program in order to see the values of certain variables. I used this approach for a long time, because if you have some intuition about what's going wrong it can be quite effective and efficient enough. When I started programming, more advanced debugging approaches required more setup work.
Once I learned how to use a debugger though, I never went back to print debugging. You can get the same information from using a breakpoint as you would from inserting a print() call, and a whole lot more. These days, considering how easy it is to jump into a debugging session, there isn't much reason to stay with print debugging.
Adding a breakpoint
A breakpoint is a place in your program where you want execution to pause, so you can examine what's happening. Once the program has paused, you can interact with your program in a variety of ways. You can inspect the value of any variables at that point in the program's execution. You can step through individual lines after the breakpoint, or step through entire functions. You can quit the debugging session, and try to implement a fix. In short, you get to poke at your project in a variety of ways, which can quickly give you a lot of insight into exactly what's happening in your project.
For this bug, let's put a breakpoint right after the hands are created. We'll see if the hands start out correct and then get combined, or if they start in an incorrect state.
The breakpoint needs to be added in start_game():
... class GoFish: ... def start_game(self): # Deal two hands. hands = self.deck.deal(num_hands=2, num_cards=7) breakpoint() self.player_hand, self.computer_hand = hands ...
The next time we run go_fish.py, execution will pause here. Here's what the beginning of a debugging session looks like:
$ python go_fish.py > go_fish.py(16)start_game() -> breakpoint() (Pdb)
We're not running the program any differently. When Python reaches the breakpoint, it pauses and opens a special terminal session. It tells us that it paused at line 16 of go_fish.py, while running the start_game() method. It shows a (Pdb) prompt, which is short for Python debugger. This is similar to a standard Python terminal session (usually indicated by >>>), except there are some special commands available to help control the program's execution from this point forward.
Let's first examine the value of hands:
(Pdb) hands [<card_models.Hand object at 0x100497770>, <card_models.Hand object at 0x1005d9a90>] (Pdb)
This looks good so far. The list hands has two separate instances of Hand. Let's look at the first one, and see if it's correct:
(Pdb) hand = hands[0] (Pdb) hand.show() 2♥ 5♣ 3♦ 10♠ 9♦ 10♥ K♣ 5♠ 8♣ 7♥ 7♣ Q♠ Q♣ 2♣ (Pdb) hand = hands[1] (Pdb) hand.show() 2♥ 5♣ 3♦ 10♠ 9♦ 10♥ K♣ 5♠ 8♣ 7♥ 7♣ Q♠ Q♣ 2♣ (Pdb) q Traceback (most recent call last): ... bdb.BdbQuit
We pull the first hand from the list, and call show(). We can see that this hand is incorrect already. It has 14 cards, and looking at the second hand shows what we saw earlier. The cause of the problem is in code that runs before the location of our current breakpoint.
We don't need to go any further in this debugging session. You can exit a debugging session by entering q for quit. Don't be alarmed at the traceback; pdb raises a BdbQuit exception to leave the program's execution early. You could also enter c to continue the program's execution, for example if you had changed the value of a variable and wanted to see if that fixed the issue you were facing.
Back to Hand
The problem doesn't appear to be in go_fish.py, so let's look at where the hands are being created. They're being created by the deal() method in Deck, so let's remove the breakpoint from start_game() in go_fish.py. Then, let's insert a breakpoint at the start of deal() in card_models.py:
... class Deck: ... def deal(self, num_hands=2, num_cards=5): """Return a single Hand, or list of Hands.""" # Build empty hands. hands = [Hand() for _ in range(num_hands)] breakpoint() ...
We'll insert the breakpoint after the empty Hand instances have been created at the start of a deal. We can make sure we have two hands here, and that they both start out empty. We can also step through the dealing process, and see what happens as each card is added to the two hands:
$ python go_fish.py > card_models.py(93)deal() -> breakpoint() (Pdb) hands [<card_models.Hand object at 0x1021bb770>, <card_models.Hand object at 0x1022fda90>] (Pdb) p_hand = hands[0] (Pdb) c_hand = hands[1] (Pdb) p_hand.show() (Pdb) c_hand.show() (Pdb)
Here we're running go_fish.py, just as we have been all along. This time execution pauses in card_models.py, at line 93 in the deal() method. The variable hands should be a list with two empty instances of Hand. Entering hands in the debugger session shows the list of two Hand instances; we can't tell right away if they're empty or not.
We can write any Python code we want in this debugger session. We don't have to use the same names we're using in the project. I'm assigning the first Hand instance to p_hand, and the second instance to c_hand. We then call show() for each of these, which shows they're both empty hands.
So far, so good. Now we'd like to see what happens as cards are added to each hand. The n command moves forward to the next line in the function. The confusing part is that the line that pdb shows has not actually been executed yet. Here are the lines following the breakpoint:
def deal(self, num_hands=2, num_cards=5): ... breakpoint() # Add cards to each hand, one at a time. for _ in range(num_cards): for hand in hands: hand.cards.append(self.draw())
The line we're interested in is the last one shown here, which appends a card to hand. So we need to enter n in the debugger until we see this line, and then enter n once more so that line is executed. At that point, we'll look at the hand to see if a card was added:
(Pdb) n > card_models.py(96)deal() -> for _ in range(num_cards): (Pdb) n > card_models.py(97)deal() -> for hand in hands: (Pdb) n > card_models.py(98)deal() -> hand.cards.append(self.draw()) (Pdb) n > card_models.py(97)deal() -> for hand in hands: (Pdb) p_hand.show() 10♠ (Pdb)
This looks good. After the line with append() is executed we can see that Python moves back to the inner loop for another cycle. When we call p_hand.show(), we can see that one card has been added.
Let's take a look at c_hand here as well:
(Pdb) c_hand.show() 10♠
Oof, that's not good! The computer's hand should be empty at this point, because we've only executed hand.cards.append() once so far. Also, this is the same card that was just added to p_hand.
Let's run through the call to append() again, and see what happens with the next card that's drawn from the deck:
(Pdb) n > card_models.py(98)deal() -> hand.cards.append(self.draw()) (Pdb) n > card_models.py(97)deal() -> for hand in hands: (Pdb) p_hand.show() 10♠ K♦ (Pdb) c_hand.show() 10♠ K♦ (Pdb)
It looks like every card that's being drawn is being added to both hands.
A bit of reflection
This process really highlights the difference between bugs that result in tracebacks, and bugs associated with logical errors. When there's a traceback, Python points us to the parts of the project that are problematic. With a logical error, Python offers no guidance; we need to keep reasoning about what's happening. Python offers tools to help us examine the state of the project as it's being executed, but we need to do the reasoning.
We could look at the draw() method, but that's probably not the issue. We're seeing one card drawn each time append() is called, but it's being added to both hands at the same time.
There are a number of ways you could continue reasoning at this point. You could keep working in the current debugging session, you could quit and rerun from the same breakpoint, or you could put a breakpoint somewhere else. I have an intuition about the empty hands that I want to investigate, so I'm going to quit this session and start the program again at the same breakpoint.
Identity
Here's a fresh debugger session, from the same breakpoint in deal():
$ python go_fish.py > card_models.py(93)deal() -> breakpoint() (Pdb) hands [<card_models.Hand object at 0x1021b7770>, <card_models.Hand object at 0x1022f9a90>] (Pdb)
Okay, we're back to the point where the two empty hands were created at the start of deal(). I want to look at these two instances of Hand right after they were created:
(Pdb) p_hand = hands[0] (Pdb) c_hand = hands[1] (Pdb) id(p_hand) 4330321776 (Pdb) id(c_hand) 4331641488 (Pdb) p_hand is c_hand False
First, I wanted to make sure we do in fact have two separate instances of Hand. The id() function returns a unique number for every object in memory. (In CPython, this is the memory address of the object.) The two hands exist at different points in memory, so they're distinct instances of Hand. Comparing them with is, which uses id() under the hood, confirms that the two hands do not refer to the same object.
But now let's look at the cards attribute associated with each hand:
(Pdb) id(p_hand.cards) 4331765504 (Pdb) id(c_hand.cards) 4331765504 (Pdb) p_hand.cards is c_hand.cards True
This is the problem! The hands are unique objects, but the attribute cards associated with each Hand instance points to the same list. p_hand.cards is the same exact list as c_hand.cards! If you add a card to one hand, it shows up in the other hand as well. These are two distinct hands, sharing the exact same list of cards.
Looking at Hand
Let's look at Hand, and see how the cards attribute is defined:
... class Hand: def __init__(self, cards=[]): self.cards = cards ...
There's a problem with how the default value for cards is being defined here. (As a reminder, this is different than the __init__() method that was shown in the previous post for Hand.)
When Python imports a function for the first time, it evaluates any default argument values. In this case, that means creating an empty list for cards. When Python executes the same function a second time, it reuses the default arguments that have already been defined. So when the second instance of Hand is made, it gets the same list for cards that was used for the first Hand instance.
If that's not clear, you can see this in a regular terminal session:
$ python >>> from card_models import Hand >>> hand_1 = Hand() >>> id(hand_1.cards) 4368061504 >>> hand_2 = Hand() >>> id(hand_2.cards) 4368061504 ...
You can make as many empty hands as you want; every hand's cards attribute will point to the exact same list.
This issue comes from using a mutable default value for an argument. A mutable value is one that can change, such as a list or dictionary. Most of the default values we see in function definitions are not mutable. For example we might see an integer used as a default value like this:
class Student: def __init__(self, name, grade=1): ...
Every student has their own name, so there's no default value for name. But every new student in this school is assumed to start at grade 1. If you make a student and change the value of grade for that student to another number, the new value replaces the original value, for that student. Integers aren't mutable, so Python still keeps the default value for new instances of Student at 1.
Fixing Hand
Let's fix Hand, so every instance points to its own list of cards. To do this, we need to use a non-mutable default value for cards. That's one of the purposes of None:
... class Hand: def __init__(self, cards=None): if cards: self.cards = cards else: self.cards = [] ...
Now if a new instance of Hand is created with some existing cards, those cards are assigned to self.cards just like before. But if an instance is created using the default value, that value is None. Inside the __init__() method, this makes the else block run, where a new, unique empty list is created for each new instance.
Let's run another terminal session to verify this before running go_fish.py again:
$ python >>> from card_models import Hand >>> hand_1 = Hand() >>> id(hand_1.cards) 4349029760 >>> hand_2 = Hand() >>> id(hand_2.cards) 4349029824 >>> hand_1.cards is hand_2.cards False
The two lists associated with each hand now occupy different memory addresses, and is confirms that the two lists are unique.
If we run go_fish.py now, we should see that the player and computer hands have seven cards each, and they shouldn't share any of the same cards:
$ python go_fish.py Player hand: 3♥ 3♠ 4♦ 4♥ 5♥ 7♣ 7♦ Computer hand: 5♣ 5♠ 8♣ 9♥ Q♦ A♥ A♠
This is correct. Now that we know the computer has an appropriate hand, we can set the hidden argument back to True:
... class GoFish: ... def show_state(self): ... self.computer_hand.show(hidden=True) ...
Now we should see our cards, and only see how many cards the computer has:
$ python go_fish.py Player hand: 4♥ 6♥ 8♦ 8♥ 10♣ 10♠ J♦ Computer hand: X X X X X X X
All right, we're ready to implement the game logic! We'll continue building Go Fish in the next post, until the next logical error appears.
Conclusions
For most logical errors, there's a lot more to think about in order to find the cause than when you have a traceback. Python gives you tools to help figure out what's happening, but you need to reason about what your program is trying to do, and how it's doing it. Even if you don't get all the way to the root cause, sharing what you've found with others gives them a lot more information they can use to help you.
If you're currently using print debugging, I highly recommend using a debugging tool like pdb instead. You'll get all the information you were getting from print() calls, but you'll be able to do a lot more investigating and poking around as well. The investigation described in this post would have taken a lot more time and effort using only print() calls.
I recognize many readers may have been able to spot the root issue by looking through the code in card_models.py. But in a larger codebase, with a more subtle bug, that can be impossible. The process shown here will help lead you to the root problem, regardless of the complexity of the project you're working on.
Resources
Resources used in this post can be found in the mostly_python GitHub repository.
