Using Golang Mutexes on Structs

When creating a "thing" that I didn't want other functions or operations to touch when something else might be doing something that could affect that thing, I would create a variable...usually a global-scoped variable...that I'd set with a particular value. Then I'd have code check that variable before doing anything that might upset other functions by altering the state of data. I usually called this a flag, but I'm sure in some cases it was more appropriate to call it a semaphore or...I'm not sure. It's probably against "proper" coding standards to do that. But it seemed to work as long as I was careful and commented what I was doing.

Go has a mechanism in the "sync" package called a mutex, used to lock something against alterations when concurrent routines might try altering data. From what I could find it's often recommended that when possible you should use alternate methods like channels and waitgroups to guarantee concurrency doesn't upset your variables/structs/etc, but mutexes should be used for exclusive access when working on caches and variable state. 

But how do they work? As in, how should I model their behavior for implementation in my application?

Let's try some simple applications to see how mutexes work.

What I want to do is have a struct whose values are "protected" and altered by only one section of code at a time. Can a mutex do that? 

Test One

First test I'll spin off some goroutines to hammer a change on a struct, with another routine locking the struct.

// How do mutexes work on a struct? Let's see if this works the way I hope it does...
package main

import (
 "fmt"
 "sync"
 "time"
)

func main() {

 type ProtectThese struct {
  secure    sync.Mutex
  firstname string
  lastname  string
 }

 // Create an instance of the structs
 var protected ProtectThese

 // And a cheap flag for quitting the main() goroutine
 var Stop bool = false

 // What time is it?
 StartTime := time.Now()

 // Spin off a goroutine that just locks protected and waits
 go func() {

  // Lock it
  protected.secure.Lock()
        
        // Tell us when it was locked
        fmt.Println("Locked at " + time.Since(StartTime).String())

  // Create a timer
  WaitForIt := time.NewTimer(time.Minute * 1)
        
  // After the timer elapses
  <-WaitForIt.C
        
  // Unlock the struct
  protected.secure.Unlock()
        
  // All done
  return

 }()

 // Another goroutine will try writing a value to firstname
 go func() {
        
  // An infinite loop because...why not?
  for {
   protected.firstname = "John"
  }
        
 }()

 // This goroutine will write a value to lastname
 go func() {
        
  // See the previous routine
  for {
   protected.lastname = "Doe"
  }
        
 }()

 // And yet another goroutine does nothing but reads values from protected to the stdout
 go func() {

  // A couple quick flags
  var firstchanged bool = false
  var lastchanged bool = false

  // Create a ticker to check the status of the struct periodically
  ticker := time.NewTicker(time.Nanosecond * 5)

  for range ticker.C {
            
   if protected.firstname == "John" && firstchanged == false {
    // Did the first name get filled in?
    fmt.Println("Firstname changed at " + time.Since(StartTime).String())
    firstchanged = true
   }
            
   if protected.lastname == "Doe" && lastchanged == false {
    // Did the last name change?
    fmt.Println("Lastname changed at " + time.Since(StartTime).String())
    lastchanged = true
   }
            
   if firstchanged == true && lastchanged == true {
    // Both are done. Change the running flag.
    Stop = true
   }
            
  }
 }()

 // This basically spins wheels until the variable for stopping is set
 // Checks every 50 milliseconds to see if we should quit
 for Stop == false {
  Waiting := time.NewTimer(time.Millisecond * 50)
  <-Waiting.C
 }
}

What's happening here?

Main() has only a few jobs to perform. It creates a struct holding 2 strings and a mutex, it creates an instance of that struct, it gets the current time, and creates a little flag variable (old habits die hard) and then checks every 50 milliseconds for that variable to become true.

There are also 4 goroutines:
Goroutine(a) locks the mutex in the struct, prints out the time since Main took the current time that the lock was set, then sits for a minute before unlocking it.
Goroutine(b) keeps trying to set the firstname string in the struct to John.
Goroutine(c) keeps trying to set the lastname string in the struct to Doe.
Goroutine(d) checks every 5 nanoseconds whether the firstname and lastname have changed, and if they did, prints the time since main() set the current time that it was changed. When both firstname and lastname are set, goroutine(d) also sets the "Stop" variable telling main() to quit.

Pretty simple. What happens when it's run?

Locked at 27.549µs
Firstname changed at 174.431µs
Lastname changed at 251.301µs

That's...fast. It ran on the order of microseconds. Pretty good indication that goroutine(a)'s lock didn't stop goroutine(b) and (c) from altering the struct.

Test Two

Let's try something a little different.

// How do mutexes work on a struct? Let's see if this works the way I hope it does...
package main

import (
 "fmt"
 "sync"
 "time"
)

func main() {

 type ProtectThese struct {
  secure    sync.Mutex
  firstname string
  lastname  string
 }

 // Create an instance of the structs
 var protected ProtectThese

 // And a cheap flag for quitting the main() goroutine
 var Stop bool = false

 // What time is it?
 StartTime := time.Now()

 // Spin off a goroutine that just locks protected and waits
 go func() {

  // Lock it
  protected.secure.Lock()
        
        // Tell us when it was locked
        fmt.Println("Locked at " + time.Since(StartTime).String())

  // Create a timer
  WaitForIt := time.NewTimer(time.Minute * 1)
        
  // After the timer elapses
  <-WaitForIt.C
        
  // Unlock the struct
  protected.secure.Unlock()
        
  // All done
  return

 }()

 // Another goroutine will try writing a value to firstname
 go func() {
        
        // Let's wait a little bit before trying to set this.
        Pause := time.NewTimer(time.Second * 30)
        <-Pause.C
        
  // An infinite loop because...why not?
  for {
   protected.firstname = "John"
  }
        
 }()

 // This goroutine will write a value to lastname
 go func() {
        
  // See the previous routine
  for {
   protected.lastname = "Doe"
  }
        
 }()

 // And yet another goroutine does nothing but reads values from protected to the stdout
 go func() {

  // A couple quick flags
  var firstchanged bool = false
  var lastchanged bool = false

  // Create a ticker to check the status of the struct periodically
  ticker := time.NewTicker(time.Nanosecond * 5)

  for range ticker.C {
            
   if protected.firstname == "John" && firstchanged == false {
    // Did the first name get filled in?
    fmt.Println("Firstname changed at " + time.Since(StartTime).String())
    firstchanged = true
   }
            
   if protected.lastname == "Doe" && lastchanged == false {
    // Did the last name change?
    fmt.Println("Lastname changed at " + time.Since(StartTime).String())
    lastchanged = true
   }
            
   if firstchanged == true && lastchanged == true {
    // Both are done. Change the running flag.
    Stop = true
   }
            
  }
 }()

 // This basically spins wheels until the variable for stopping is set
 // Checks every 50 milliseconds to see if we should quit
 for Stop == false {
  Waiting := time.NewTimer(time.Millisecond * 50)
  <-Waiting.C
 }
}

What's happening here?

Not much has changed; I just altered goroutine(b) to have a 30 second pause. What happens when I run it?

Locked at 44.836µs
Lastname changed at 160.966µs
Firstname changed at 30.000173283s

Shows that the timers are working. Still shows the mutex isn't doing anything.

Test Three

Time to try wrapping one of the goroutines in a mutex lock.

// How do mutexes work on a struct? Let's see if this works the way I hope it does...
package main

import (
 "fmt"
 "sync"
 "time"
)

func main() {

 type ProtectThese struct {
  secure    sync.Mutex
  firstname string
  lastname  string
 }

 // Create an instance of the structs
 var protected ProtectThese

 // And a cheap flag for quitting the main() goroutine
 var Stop bool = false

 // What time is it?
 StartTime := time.Now()

 // Spin off a goroutine that just locks protected and waits
 go func() {

  // Lock it
  protected.secure.Lock()

  // Tell us when it was locked
  fmt.Println("Locked at " + time.Since(StartTime).String())

  // Create a timer
  WaitForIt := time.NewTimer(time.Minute * 1)

  // After the timer elapses
  <-WaitForIt.C

  // Unlock the struct
  protected.secure.Unlock()

  // All done
  return

 }()

 // Another goroutine will try writing a value to firstname
 go func() {

  // Set the lock here in addition to the previous goroutine
  protected.secure.Lock()

  // An infinite loop because...why not?
  for {
   protected.firstname = "John"
  }

  // Unlock
  protected.secure.Unlock()

 }()

 // This goroutine will write a value to lastname
 go func() {

  // See the previous routine
  for {
   protected.lastname = "Doe"
  }

 }()

 // And yet another goroutine does nothing but reads values from protected to the stdout
 go func() {

  // A couple quick flags
  var firstchanged bool = false
  var lastchanged bool = false

  // Create a ticker to check the status of the struct periodically
  ticker := time.NewTicker(time.Nanosecond * 5)

  for range ticker.C {

   if protected.firstname == "John" && firstchanged == false {
    // Did the first name get filled in?
    fmt.Println("Firstname changed at " + time.Since(StartTime).String())
    firstchanged = true
   }

   if protected.lastname == "Doe" && lastchanged == false {
    // Did the last name change?
    fmt.Println("Lastname changed at " + time.Since(StartTime).String())
    lastchanged = true
   }

   if firstchanged == true && lastchanged == true {
    // Both are done. Change the running flag.
    Stop = true
   }

  }
 }()

 // This basically spins wheels until the variable for stopping is set
 // Checks every 50 milliseconds to see if we should quit
 for Stop == false {
  Waiting := time.NewTimer(time.Millisecond * 50)
  <-Waiting.C
 }
}

What's happening here?

This time in addition to goroutine(a) setting the mutex, I added the mutex around goroutine(b) as well. This is not entirely safe in that there is a race condition; it appears that goroutine(a) is spun up faster than (b), so it sets the lock sooner in every test I've run. If something were to delay (a) running, (b) could get to it first. Just something to remember.

What happens when this one is run?

Locked at 23.15µs
Lastname changed at 114.786µs
Firstname changed at 1m0.000142691s

Ah-ha! Goroutine(b) is stuck until the lock set by (a) is unlocked! This confirms that the mutex isn't magically wrapping the struct and set by whatever calls it...it's more like a flag, and any code that might interfere with it must still be mindfully set to check that flag before altering things. In other words, if you want the struct to be protected, you still have to place checks in your code where the code might stomp on the state of the struct; the mutex doesn't lock the struct from random changes.

Some of the sources I found online could be interpreted as saying that the mutex only locks the data right under it (that seems strange?) in the declarations, which here would mean firstname is protected, but lastname isn't. Let's test that.

Test Four

// How do mutexes work on a struct? Let's see if this works the way I hope it does...
package main

import (
 "fmt"
 "sync"
 "time"
)

func main() {

 type ProtectThese struct {
  secure    sync.Mutex
  firstname string
  lastname  string
 }

 // Create an instance of the structs
 var protected ProtectThese

 // And a cheap flag for quitting the main() goroutine
 var Stop bool = false

 // What time is it?
 StartTime := time.Now()

 // Spin off a goroutine that just locks protected and waits
 go func() {

  // Lock it
  protected.secure.Lock()

  // Tell us when it was locked
  fmt.Println("Locked at " + time.Since(StartTime).String())

  // Create a timer
  WaitForIt := time.NewTimer(time.Minute * 1)

  // After the timer elapses
  <-WaitForIt.C

  // Unlock the struct
  protected.secure.Unlock()

  // All done
  return

 }()

 // Another goroutine will try writing a value to firstname
 go func() {

  // Set the lock here in addition to the previous goroutine
  protected.secure.Lock()

  // An infinite loop because...why not?
  for {
   protected.firstname = "John"
  }

  // Unlock
  protected.secure.Unlock()

 }()

 // This goroutine will write a value to lastname
 go func() {

  // Set the lock
  protected.secure.Lock()

  // See the previous routine
  for {
   protected.lastname = "Doe"
  }

  // Unlock
  protected.secure.Unlock()

 }()

 // And yet another goroutine does nothing but reads values from protected to the stdout
 go func() {

  // A couple quick flags
  var firstchanged bool = false
  var lastchanged bool = false

  // Create a ticker to check the status of the struct periodically
  ticker := time.NewTicker(time.Nanosecond * 5)

  for range ticker.C {

   if protected.firstname == "John" && firstchanged == false {
    // Did the first name get filled in?
    fmt.Println("Firstname changed at " + time.Since(StartTime).String())
    firstchanged = true
   }

   if protected.lastname == "Doe" && lastchanged == false {
    // Did the last name change?
    fmt.Println("Lastname changed at " + time.Since(StartTime).String())
    lastchanged = true
   }

   if firstchanged == true && lastchanged == true {
    // Both are done. Change the running flag.
    Stop = true
   }

  }
 }()

 // This basically spins wheels until the variable for stopping is set
 // Checks every 50 milliseconds to see if we should quit
 for Stop == false {
  Waiting := time.NewTimer(time.Millisecond * 50)
  <-Waiting.C
 }
}

What's happening here?

Both goroutines(b) and (c) are wrapped in the call to the mutex lock. Output from the application:

Locked at 24.157µs
Firstname changed at 1m0.000158927s
^C

Ooh. I had to control-C that. What happened?

The key probably lay in here:

 // Spin off a goroutine that just locks protected and waits
 go func() {

  // Lock it
  protected.secure.Lock()

  // Tell us when it was locked
  fmt.Println("Locked at " + time.Since(StartTime).String())

  // Create a timer
  WaitForIt := time.NewTimer(time.Minute * 1)

  // After the timer elapses
  <-WaitForIt.C

  // Unlock the struct
  protected.secure.Unlock()

  // All done
  return

 }()

 // Another goroutine will try writing a value to firstname
 go func() {

  // Set the lock here in addition to the previous goroutine
  protected.secure.Lock()

  // An infinite loop because...why not?
  for {
   protected.firstname = "John"
  }

  // Unlock
  protected.secure.Unlock()

 }()

Goroutine(a) locks the struct, waits a minute, then unlocks and quits. The goroutine is gone.

Goroutine(b) then gets the struct next; it locked the struct, then enters an infinite loop setting the firstname repeatedly. The unlock() is never called!

Let's try fixing that.

Test Five

// How do mutexes work on a struct? Let's see if this works the way I hope it does...
package main

import (
 "fmt"
 "sync"
 "time"
)

func main() {

 type ProtectThese struct {
  secure    sync.Mutex
  firstname string
  lastname  string
 }

 // Create an instance of the structs
 var protected ProtectThese

 // And a cheap flag for quitting the main() goroutine
 var Stop bool = false

 // What time is it?
 StartTime := time.Now()

 // Spin off a goroutine that just locks protected and waits
 go func() {

  // Lock it
  protected.secure.Lock()

  // Tell us when it was locked
  fmt.Println("Locked at " + time.Since(StartTime).String())

  // Create a timer
  WaitForIt := time.NewTimer(time.Minute * 1)

  // After the timer elapses
  <-WaitForIt.C

  // Unlock the struct
  protected.secure.Unlock()

  // All done
  return

 }()

 // Another goroutine will try writing a value to firstname
 go func() {

  // Set the lock here in addition to the previous goroutine
  protected.secure.Lock()

  // Loop to set the firstname
  for protected.firstname != "John" {
   protected.firstname = "John"
  }

  // Unlock
  protected.secure.Unlock()

 }()

 // This goroutine will write a value to lastname
 go func() {

  // Set the lock
  protected.secure.Lock()

  // See the previous routine
  for protected.lastname != "Doe" {
   protected.lastname = "Doe"
  }

  // Unlock
  protected.secure.Unlock()

 }()

 // And yet another goroutine does nothing but reads values from protected to the stdout
 go func() {

  // A couple quick flags
  var firstchanged bool = false
  var lastchanged bool = false

  // Create a ticker to check the status of the struct periodically
  ticker := time.NewTicker(time.Nanosecond * 5)

  for range ticker.C {

   if protected.firstname == "John" && firstchanged == false {
    // Did the first name get filled in?
    fmt.Println("Firstname changed at " + time.Since(StartTime).String())
    firstchanged = true
   }

   if protected.lastname == "Doe" && lastchanged == false {
    // Did the last name change?
    fmt.Println("Lastname changed at " + time.Since(StartTime).String())
    lastchanged = true
   }

   if firstchanged == true && lastchanged == true {
    // Both are done. Change the running flag.
    Stop = true
   }

  }
 }()

 // This basically spins wheels until the variable for stopping is set
 // Checks every 50 milliseconds to see if we should quit
 for Stop == false {
  Waiting := time.NewTimer(time.Millisecond * 50)
  <-Waiting.C
 }
}

What's happening here?

Just added a quick check in the goroutines that set firstname and lastname so once the variable has the value set, they unlock and quit. Running the application yields the following output:

Locked at 30.974µs
Firstname changed at 1m0.000698523s
Lastname changed at 1m0.000794631s

That seems to show that yup, it locks for both those values in the struct.

So at this point it seems that you can lock the whole struct by just have a sync.Mutex included, and it's safe from alterations from code that you specifically wrap in a call to lock and unlock; if you forget, though, code that isn't wrapped in a fuzzy lock() blankie will merrily alter the values of your struct without batting an eye.

One last thing...is code trying to do something to the struct blocked, like channels get blocked waiting for a message to be pulled? Or do they try repeatedly? What does goroutine(b) do as it's currently written?

Test Six

 // Another goroutine will try writing a value to firstname
 go func() {

  // Announce what I'm doing
  fmt.Println("About to lock struct so I can change firstname at " + time.Since(StartTime).String())

  // Set the lock here in addition to the previous goroutine
  protected.secure.Lock()

  // I locked it!
  fmt.Println("Locked struct to change firstname at " + time.Since(StartTime).String())

  // Loop to set the firstname
  for protected.firstname != "John" {
   protected.firstname = "John"
  }

  // About to unlock
  fmt.Println("About to unlock struct for firstname at " + time.Since(StartTime).String())

  // Unlock
  protected.secure.Unlock()

  // And done...
  fmt.Println("Finished with altering firstname at " + time.Since(StartTime).String())

 }()

What's happening here?

All I've changed is goroutine(b) so it has some additional announcements to STDOUT. Here's what the new output says:

Locked at 25.739µs
About to lock struct so I can change firstname at 121.747µs
Lastname changed at 1m0.000195611s
Locked struct to change firstname at 1m0.000158478s
Firstname changed at 1m0.000593511s
About to unlock struct for firstname at 1m0.000590839s
Finished with altering firstname at 1m0.000960257s

To me this shows that the mutex blocks access; the process just waits. But that could be because of the structure of the code; let's try constantly hammering it in a loop again.

Test Seven

 // Another goroutine will try writing a value to firstname
 go func() {

  // Loop to set the firstname
  for protected.firstname != "John" {
   // Announce what I'm doing
   fmt.Println("About to lock struct so I can change firstname at " + time.Since(StartTime).String())

   // Set the lock here in addition to the previous goroutine
   protected.secure.Lock()

   // I locked it!
   fmt.Println("Locked struct to change firstname at " + time.Since(StartTime).String())

   // Make the change
   protected.firstname = "John"

   // About to unlock
   fmt.Println("About to unlock struct for firstname at " + time.Since(StartTime).String())

   // Unlock
   protected.secure.Unlock()

   // And done...
   fmt.Println("Finished with altering firstname at " + time.Since(StartTime).String())
  }

 }()

What's happening here?

Once again it's a relatively minor change in goroutine(b); now everything is encased in a loop instead of just the "let's make a change" bit. What is the output?

Locked at 36.342µs
About to lock struct so I can change firstname at 155.914µs
Lastname changed at 1m0.000200095s
Locked struct to change firstname at 1m0.000167036s
Firstname changed at 1m0.001612157s
About to unlock struct for firstname at 1m0.001605558s
Finished with altering firstname at 1m0.003361782s

Still blocking while the lock is set; it's not constantly retrying the loop or the "About to lock" message would keep repeating. I'm fairly confident that if you have a second process trying to do something on a struct you've locked from another process, it'll just block until the mutex is unlocked!

One last bit of fun, just to see what effect it would have; I wrapped the routine that checked for the status of the struct in a lock vs. no lock to see how many times it checked (after lowering the lock from goroutine(a) to 5 seconds);

 // And yet another goroutine does nothing but reads values from protected to the stdout
 go func() {

  // A couple quick flags
  var firstchanged bool = false
  var lastchanged bool = false

  // Create a ticker to check the status of the struct periodically
  ticker := time.NewTicker(time.Nanosecond * 5)

  for range ticker.C {

   // Add one to the counter
   counter = counter + 1

            // Lock it
            //protected.secure.Lock()
            
   if protected.firstname == "John" && firstchanged == false {
    // Did the first name get filled in?
    fmt.Println("Firstname changed at " + time.Since(StartTime).String())
    firstchanged = true
   }

   if protected.lastname == "Doe" && lastchanged == false {
    // Did the last name change?
    fmt.Println("Lastname changed at " + time.Since(StartTime).String())
    lastchanged = true
   }

   if firstchanged == true && lastchanged == true {
    // Both are done. Change the running flag.
    Stop = true
   }
            
            // Unlock it
            //protected.secure.Unlock()

  }
 }()

You can see the part I commented out, of course, to enable to lock. The results were kind of interesting (I assume it's because the check just blocked for the vast majority of 5 seconds...)

Without the lock: "I checked the status of the struct 124 times."
With the lock: "I checked the status of the struct 222896 times."

Maybe something to keep in mind if you have mutexes, a number of goroutines hitting excluded data, and performance issues!

Check Raspbian Filesystem/Disk on Raspberry Pi

How do I check my Pi's (root) filesystem?

There's often a certain air in the voice of the experienced Linux users when asked a question like this; "How do I check the filesystem on my Linux system?"

The tool to use is fsck, the filesystem checker. The problem is that if you're checking a mounted filesystem, fsck will warn you vehemently that you can and will risk destroying your filesystem when checking a mounted device.

And you, stupid user, are asking this all-too-common question when you should have RTFM'd.

It turns out that the answer to the question is to log in to the Pi and run this at the terminal:

sudo touch /forcefsck

Once the system comes back up, you can look for the results in /var/log/daemon.log.

If you did try to RTFM, there's a number of sites that say you should run shutdown with a "-F" parameter. At some point that was removed from the shutdown command, yielding a somewhat cryptic error about unhandled options and leaving behind a LOT of documentation cruft that won't work. After doing some digging, it looks like the -F did automatically what the touch command above does; it was decided that if your filesystem is in a yarked state, writing an empty file to the filesystem would be possibly more damaging than helpful. From the bug report:

If you want to force an fsck on next boot, please add fsck.mode=force to
the kernel command line (see man systemd-fsck@.service).

systemd intentionally doesn't write a /force.fsck flag file to the disk
to achieve that. You typically want to avoid writing to a file system if
you are concerned about it's consistency. That's why the -F parameter is
not supported (and won't be added).

So that's the "official" fix.

There's also a setting found in /etc/Default/rcS (a text file) where you change "FSCKFIX=no" to yes and your system should check the root filesystem at each reboot.

How do I know when the filesystem on my Pi was last checked?

This involves the use of tune2fs. Run

mount

...to get the /dev device name of the filesystem you want to check. For me, it said /dev/mmcblk0p2 was mounted on /. Then I ran:

sudo tune2fs -l /dev/mmcblk0p2|grep Last\ c

... to get the time and date the filesystem was last checked.

Forcing a check on non-root partitions isn't the same as above; you can't use /forcefsck on the partitions to auto-check it. It instead involves digging into the filesystem configuration and the filetab file.

First, I checked the Maximum mount count for my external drive.

sudo tune2fs -l /dev/sda1|grep Max

...which gave me a value of -1, meaning fsck is disabled on /dev/sda1. That number has to be a positive integer in order to run checks; if I want to check it every time, I run:

sudo tune2fs -c 1 /dev/sda1

If I wanted to check every other mount, I'd change that 1 to a 2. Or 3 for every third. You get the idea.

The second thing to check is the PASS count, which is in the fstab file. I need the UUID of my external drive;

sudo blkid|grep sda1

...which gives the long string of characters identifying the drive. I then grep in my fstab:

grep 7c275 /etc/fstab

...where the 7c275 was a hopefully distinct set of characters from the ID so I didn't type it all in while being too lazy to cut and paste. That gave me the result:

UUID=4ba44c85-659d-45fc-b36a-dad3e8e7c275 /mnt/mydrive ext4 defaults,noatime 0 2

...and the end of that line, the 2, is the part that gave the PASS value. According to this website, 0 means disabled (don't check), 1 means it has a higher priority and check first (usually reserved for /), and 2 means these partitions should be checked last.

At this point it seems my PASS value is 2 and the maximum check count is 1 for the external drive, and a /forcefsck is on the root filesystem. A reboot means that running tune2fs should show today's date as the most recent check upon restart...time for sudo shutdown -r!

Note: Seems no matter what option I try, my /dev/mmcblk0p2 is reporting its last fsck check, with tune2fs, was performed in the far past by several months. But when I check the logs with a grep of fsck, they show that a check was performed on that device at bootup. Not sure why it's not registering.

Note 2: Websites for reference information are here and here.

Channels, WaitGroups and Goroutines: Simply Complex

This post is less about coding and more about creating a mental model for your application with some simple concurrency baked in. With a little code thrown in at the end.

Bob is an amateur programmer turned fast food restaurant entrepreneur. He franchised a Burrito Barn and a Pizza Boot restaurant (I made those up, but don't know if such places exist. If there is such a thing as a Burrito Barn, it sounds good, mainly because burritos are great. And now I wonder if there's such a thing as a pizza burrito...)

Bob has only these two restaurants, but he has eyes on the future, and in that future he's going to own more Burrito Barns and Pizza Boots. But Bob wants statistics on his franchises. He wants to see how busy they are during the day and what kinds of orders are going through the kitchen so he can find trends over the course of the day and optimize service options and kitchen operations. This will help ease him into a growing empire of burrito and pizza outlets.

Fortunately for Bob his two restaurants have electronic service systems that display fast food orders to the kitchen; unfortunately, they're missing the type of options he's looking for. He decides to write a Go program that will scrape the data from the restaurants and display the results on a web page.

He starts coding. On the surface this isn't too hard; it seems the task is ideally suited for two of Go's strongest features: goroutines and channels. The main() function will spawn a goroutine to scrape the pizza restaurant's order system at periodic intervals and a second goroutine to pull data from the burrito restaurant's order system. Channels can be used to pass data back to a logging goroutine.

That seems pretty straightforward. A timer in Main() launches the scraping goroutines periodically; they launch, drop messages into the channel, and the logger reads messages. The goroutines then exit, leaving the Logger() to run and listen for future launches of the scrapers.

 For testing purposes, Bob wrote a small goroutine whose only job is to use time.NewTimer() to send a "quit" signal to his application (otherwise, the way it's written as he's working on it, the application just runs in a loop and killing it means no cleanup/housekeeping is done to close out his scraping processes.)

Now the scrapers run periodically with time.NewTicker(), and there's a StopTime that sends a quit message to Main() using a separate channel myStopChannel. When that quit message is sent to Main(), Main() stops launching the scrapers and then sends a "quit" message into myChannel to tell Logger() it needs to close up file handles and whatever other housekeeping chores it must perform before exiting. But how does Main() know when Logger() is done?

Bob thinks about it for a moment and decides to dump a message from Logger() into myStopChannel, and Main() will just keep reading myStopChannel until the message comes in from Logger().

There! That looks pretty simple. The scrapers run and exit until a new timer.NewTicker() ticks to kick off another scraper, Logger() is listening for information, and StopTime() runs until the timer goes off and signals a quitting time while Bob is testing everything, and Main() coordinates the kickoff and graceful shutdown of goroutines.

Bob's tests are working well, too. But then he realizes another problem; what happens when he opens another restaurant?

There are two problems here. One is that there are two PizzaScrape() goroutines running, one for each restaurant. How do we know which is running for which restaurant? They'll have to identify which restaurant they represent, and send that information with any logging information sent to Logger(). That's actually not a difficult problem to solve.

The second is how Main() knows when all the processes are done running. It's not hard to know how many goroutines are spawned. Bob wants a neat and orderly shutdown when the quit signal comes in; that means not closing until it knows for sure that all the scrape processes are done, then closing out the Logger() routine knowing that nothing will be trying to send data to it in the middle of shutting it down. There's no direct communication communication method back to Main().

Main() already sends a "quit" signal into myChannel for Logger() to process. Maybe Main() could have the scrapers listen to myChannel as well as send on that channel, and quit if they find a quit signal? Channels are the idiomatic way to communicate among goroutines, after all.

But turning the scrapers into readers and writers with myChannel is a bad idea. Why? Because channels aren't broadcasting information; they are water troughs where someone, or many someones, places a paper boat upon the water, and someone picks up the paper boat to read the message they carry. Or you can have many someones pick up the boats. But once they're removed from the water, they're removed. Other goroutines can't read them. For example...

// Chantest - a way of testing the behavior of channels and routines that receive messages

package main

import (
    "fmt"
    "strconv"
    "sync"
)

func main() {
    
    // Create a channel for communicating and a channel for quitting
    chanMyChannel := make(chan string)
    chanQuit := make(chan string)
    
    // We need to make sure the processes all finish
    var wg sync.WaitGroup
    
    // Launch 5 listening processes
    for a := 0; a < 5; a++ {
        wg.Add(1)
        go Listen(chanMyChannel, chanQuit, a, &wg)
    }
    
    // Say hello 500 times to the channel
    for a := 0; a < 500; a++ {
        chanMyChannel <- "Hello"
    }
    
    // Now say "quit" 5 times.
    for a:= 0; a < 5; a++ {
        chanQuit <- "Quit"
    }

    wg.Wait()
}

// Listen() takes the communications channel, quit channel, an identifier, and a waitgroup
func Listen(chanMyChannel chan string, chanQuit chan string, intRoutineNum int, wg *sync.WaitGroup) {
    
    // Simple counter to keep track of our hello's
    var counter int
    
    // Tell the waitgroup this process is done when we return
    defer wg.Done()
    
    for{
        select {
            // If we get anything on the channel, increment the counter
            case <- chanMyChannel:
            counter = counter + 1
            
            // If we get a quit, print out the state of the counter and return
            case <- chanQuit:
            fmt.Println("Goroutine " + strconv.Itoa(intRoutineNum)+" received " + strconv.Itoa(counter) +" messages")
            return
            
        }
    }
}

Sample chantest output:

Goroutine 4 received 17 messages
Goroutine 1 received 173 messages
Goroutine 0 received 14 messages
Goroutine 2 received 209 messages
Goroutine 3 received 87 messages

Goroutine 1 received 190 messages
Goroutine 2 received 33 messages
Goroutine 4 received 225 messages
Goroutine 3 received 26 messages
Goroutine 0 received 26 messages

See how they end up randomly distributed? They add up to 500. But the distribution across the channels is seemingly random...whenever a goroutine happened to check the channel to see if a message was waiting, it took it and processed it (by incrementing the counter). They didn't even quit in a predictable manner because there was no way to control which one got the "quit" message in what order.

The answer to Main() knowing when all the scrapers are finished, as well as confirmation for Logger() being closed, is in the chantest program. They're called WaitGroups, part of the sync package.

sync.WaitGroups "group" together processes; each process signals, using Done(), when they're exiting and are then removed from the WaitGroup pool. Ordinarily if Main() spins off goroutines and there's nothing to process or make it wait, the moment Main() hits the end of the function the application exits. WaitGroups, using sync.Wait(), block until all the processes have called Done().

Using a WaitGroup on Logger() is a simple way to know that it has exited without needing to add complication through communication channel processing.

The example here is admittedly contrived, but nonetheless demonstrates that there are added complications when dealing with concurrently-running processes (or goroutines, in this case.) Go gives you great tools for communicating among processes, but they have limitations that can trip up beginners, such as thinking that sending a message from one processes into the channel will be picked up by all the other "listeners" instead of just whichever process reads the channel first. If you have processes doing something...such as logging to a file, or processing data, or anything that should be "cleaned up" rather than abruptly cut off with a call to Exit(), it can be easy to forget that some mechanism needs to be employed to make sure they close down cleanly using something like a WaitGroup.

This also illustrates what can happen when you have a test case...in this example, two restaurants...that doesn't test for conditions you want to expand to down the road (in this case, the multiple restaurants of the same kind.) There are items here that would have worked just fine in single-checking scenarios; Main() could keep track of launching one process and used a channel to tell when that process was returning, but weird things could start happening when dealing with multiple processes (or the logic behind channels to track goroutine starts and exits could get complicated with multiple processes in comparison to the use of WaitGroups.)

Thinking of the implications of applications running with concurrent processes can be difficult to wrap your head around if you're not accustomed to the tools Go provides specifically for managing concurrency.

Apartment Rent and Building Management in the City

I was recently presented with the opportunity to renew my lease with the company that manages the apartment complex.

I grew up in a really small town; most people live in houses and worry about mortgage payments, not rent payments. At least, that's what it was like when I was growing up. After gas well people came to town the number of rentals...some apartments, some homes, and some homes converted into apartments...swelled. But that's another story.

Having grown up in a small town where the familiar experience dealt with home ownership, the logistics of living in a big city is still baffling, and definitely not what you are shown on television. Another important factor is that I moved to the city and have a job that pays above-average, both of which count against you when trying to find affordable rental space.

Pretty much standard is the idea that you'll be treated in a way that lends evidence to the idea that the management company hates their tenants. And in the city, you're almost always dealing with a management company. There doesn't seem to be many individuals or co-ops that own buildings in the city; it's almost always a large company that has little reason to listen to the individual needs of tenants in a city where housing is scarce and rent is always on the rise (my rent was raised by over $200/month, but it shouldn't change for the next two years, which for this area isn't too horrible. This is still absolutely crazy for someone back home to consider when rent here started at $1600/month.)

Many would think that for rent like that, you'd get some nice amenities. There's a laundry room where sometimes most of the washing machines and dryers are all working, and there's even some machines free if I get there at the right time. It is nice that there are three elevators; I've actually had very little problem with them so far, despite looking like they're from the 70's and leaving me to wonder if they're going to fail at an inopportune moment when they rattle.

The building has a "front desk" guy and doors that are badged with a keyfob in order to pass, but to be honest I'm not sure why. The guard doesn't stop anyone. I routinely come home to find various business cards, menus and door hangers stuck to my apartment entrance. Once someone started getting into my apartment; my wife and I were sitting in the living area watching a movie when there came a knock at the door followed by the sound of a key in the lock. The two people in the hall were held out only by the chain on the door; they muttered something upon seeing us, shut the door, and disappeared before I could get to the door and look for them in the hallway. I reported it to the front desk. A "special patrol" NYPD officer came up and wrote a brief statement on the back of scrap paper (literal scrap paper; it looked to have been torn from something on the desk.)

To my knowledge, they never did check the elevator camera footage to try finding them.

The front desk doesn't provide much in the way of security; nor do they assist with packages. If it doesn't fit in the mailbox, you might as well arrange to deliver a package to a local storage area or post office box, unless you can be certain someone will be available in the apartment to get the delivery.

The only thing I've seen the front desk people do is patrol the front parking area to make notes of who's parked too long so they can be booted and have fines collected.

But the way the company does business that more cynical people would think that the management company is purposely doing things inefficiently. The office that handles renewals is down the street from me. It is about five minutes' walk from my building, just past a post office.

The renewal forms came with an envelope for mailing it back to them (the office address is the destination and sender on the envelope) but I was still required to put on postage. It at least had a helpful box for the stamps with a note saying "Extra postage required." It didn't tell me how many stamps it would need, but it did imply more than one.

The renewal meant not just filling in forms but also including a check for the difference to go towards my security deposit. I'm not entirely comfortable sending these things through mail to the office...I mean, it's five minutes away. Why not just deliver it?

Unfortunately the weekday hours are 10AM to 6PM most days. I leave by 6 in the morning and usually get back around 7 or 8 at night. But their listed hours did say that they were open on Saturday from 10 to 5!

So I emailed the building superintendent and assistant super asking if I can deliver the renewal papers that weekend. I waited a day, and when I didn't hear anything, I tried another address in my contact list, and she confirmed I could deliver them. Great!

I got to the office on Saturday and the front desk buzzed me in. I asked about going up to the renewal office, and the person at the front desk said that office was closed.

"The leasing office is open, but the office that renews leases is closed?"

"Yes."

"And I can't leave this here for delivery?"

"No..."

Now I was just getting over the fact that this is 2016 and I have to write a paper check for renewing my lease, but I was having a lot more trouble figuring out why their leasing office was separate from their lease renewal office, and why their office hours are squarely placed in the time period when people trying to afford rent would most likely be at work trying to get a paycheck to afford the rent, and they expected residents to mail the letter out to traverse...at a small but inconvenient price...the mail delivery system so it would be delivered five minutes away from the apartment being renewed.

Why?

Perhaps they really don't care. Or maybe they don't like their tenants. Or they are just used to doing things this way and change is annoying. There are a number of possibilities, the number of which I can come up with changes depending on my mood and how annoyed I am.

Of course, I still put up with it.

The space is nice compared to a lot of other apartments. My first apartment was close to the size of a hotel room, and I had to walk eight flights of stairs to get to it. This apartment has an elevator to get me to the right floor.

And I am near suburbia. It's not as low-population as back home, but it's familiar...malls within 10 minutes walk from me. A grocery store at an even more convenient reach. There's a Costco not far from me. And a parking garage that isn't exactly cheap, but still less than the average Manhattan parking garage.

My previous apartment also had a building super that didn't live in the building; I think he lived in New Jersey, if he didn't work a second job there, because when I did get ahold of him for a repair request he would have to schedule it at a time he could come in when traffic wasn't horrible on the connecting bridges or tunnels. The staff here are relatively good about accommodating schedules and doing decent work.

And best of all I'm not horribly far from a subway line that leads pretty close to work. Maybe a ten or fifteen minute hike.

The neighborhood is relatively nice. I'm close to the densely populated island of Manhattan while being far enough away to have a slightly more affordable rent in an area not surrounded by skyscrapers.

In the end, living the apartment life in the city is a series of compromises. You pay way too much money to co-habitate with bugs and hopefully you will have a management company that might reply to you when you contact them about a leaky faucet or malfunctioning heater, and in return you get to live in one of the most cultured, active and diverse places in the country. Love it or hate it, my new lease says I'll be (barring unforeseen events) experiencing it for the next two years!

Lessons From an Elementary School: Censorship and Systems

My son recently came under increased scrutiny at school after he arrived home from school with tape on his shirt.

He wore a shirt that he had worn several times before. It said something to the effect of "I have a freaking awesome mom, and yes, she bought this shirt for me." The exact wording is inconsequential; on this particular day the operative, taped-over word was "freaking."

I took umbrage to this for a few reasons. One, my son did not understand what he did wrong. He, like many sensible individuals, did not consider the word "freaking" to be offensive, especially taken in context.

Two, he had worn the shirt before and didn't have problems. When something is disruptive to the learning environment, you'd think that it would be something that causes a noticeable problem.

Three, he didn't know who was offended by his shirt. His homeroom teacher was delegated the duty of covering up or eliminating this newly-created problem, and he says he has no idea who "told on him" (so to speak.)

Four, he often has a similar way of thinking that I do. If something like this were to happen to me, I'd interpret it as someone has a "thing" against me, and tattling...especially by hiding behind procedures to prevent anyone from knowing who was too cowardly to take responsibility and say that they have a problem with it, so I'd know to avoid them in the future...would make me want to avoid everyone, knowing that one of them may well "attack" me again and I have no defense against them.

He's working on ways to better cope with the world. But he is still learning. He's still adapting. And for him, he's very anxious when he feels he is "breaking rules." He wants nothing more than to keep his head down and stay off the radar with the exception of his one self-imposed defining trait, which is his unique hair coloring. Otherwise he stays behaviorally nondescript to the point of being described by many as "shy."

So he's confused and a bit upset that he was singled out. The act of covering the shirt drew attention to it, like a bit of fashion-themed Streisand effect.  My wife and I felt that this was mishandled because it dealt with something that was only marginally offensive, as evidenced by the fact that no one seemed to have a problem with it the previous times he wore the shirt and in this case it clearly wasn't causing a disruption in the classroom. It was, we were told, one teacher having an issue with the word and complaining.

I emailed the principal asking what lesson he would suggest Little Dude take away from this; to me, it was against the principle of personal responsibility since the teacher was hiding their identity (although this is a common practice as you get older; you have people who don't want to deal with angry retribution for complaining but feel the need to have the perceived issue addressed which leads to fun office politics and HR speaking in the third person during special meetings...I guess kudos to the school administrator for showing support for the teacher in this case? Administrators supporting their staff seems to be a rare occurrence nowadays, what with teachers waging a war and all...see previous posts if you don't get that reference.) The school liked pushing the idea of character traits to focus on, but this was less "taking personal responsibility" and more a demonstration of "do as I say and not as I do."

It was also arbitrary enforcement of a rule, which just made him more confused. There's no rule in any handbook, from what I could find, saying that "freaking" is a forbidden word. He'd displayed it without issue before. He'd heard religious people use similar words in the context of swearing...darn, gosh, etc...as an alternative to "actual" pejoratives. One day the shirt was fine. The next, he's given a choice of wearing his shirt inside out, taping across the offensive word or wearing a sweatshirt over it (he had no sweatshirt available.)

So how should I explain this in a way that contextualizes and makes the situation make sense to Little Dude, turning this into a teachable moment? I didn't elaborate on my feelings in the message to the principal as I did above; I mostly focused on asking him what lessons the school was imparting, and how to explain them to a confused 10-year-old.

The principal replied with a message asking if we could all meet in person.

It would be easy to say that this was because the principal didn't want his words recorded, or that perhaps he was, like so many others in the education field, technophobic. Maybe he wanted witnesses, or maybe he felt his strength in placating angry parents lay in dealing with issues in person so he can get a "read" on the person, which the written word is often not conducive to conveying for many people. But at this point it didn't really matter. I was supposed to be in town that day anyway, so we arranged to meet Monday morning.

As for the meeting itself, my wife and I didn't go in with any set outcome in mind. I figured he was planning on meeting angry, raving helicopter parents; to be sure, I was angry, but I didn't speak much at all. After having dealt with the school, both as an employee and as a parent (and as a student...this school was similar in many ways to the schools I attended)  I figured they would be loathe to actually address the concerns I asked about directly, nor would they want to (or be able to, at this point) argue how stupid it was to consider "freaking" an offensive word. They had committed. An apology would even be out of the question.

I wasn't disappointed. It was made kind of clear through social cues that the position of the school is that this was an inappropriate thing, and they trusted that the shirt would not be a problem in the future. The tone quickly shifted to one of Little Dude needs to just cope with it. If they can help, they will, but really it's not their fault that he can't handle it (this is all paraphrasing and my interpretation of the situation, by the way...I wouldn't want to quote what is said and have misremembered something.) No one is out to "get him" and his homeroom teacher tried to handle it as quietly as she could.

Which...we already knew. The problem is that it's not how his brain interprets things, and the reaction to the situation was such that it drew extra attention to him. But the conversation was, at the 10,000 foot level, quickly communicated that the school was in the right, it was handled how it was handled, and to deal with it in the future realize it was nothing personal. I'm really glad I didn't have to travel 150 miles to get that outcome.

I did email a follow up that pointed out that the original question, asking what lessons were taught by this action, was never really answered, and suggesting that in the future a note home requesting he not have that shirt in school again would probably suffice. The shirt wasn't causing a disruption, and my issue was with how Little Dude interpreted the situation and singling him out over something silly. If he had to go through this the least we could do was have a teachable moment with him...introducing a different perspective that wasn't part of a narrative that sometimes people take advantage of a system to anonymously attack you or that sometimes things the majority of people don't care about will still piss someone off and they'll try to silence you for it.

A simple note home would have meant that I'd still think you were doing something silly and overreacting. But I'd at least have ridiculed that in silence. There would not have been an email, nor this posting, or the obligatory "What the shit, school?!" FaceBook posting. Focusing attention on him, making him think he did something wrong, punishing him for an arbitrary and opinionated interpretation of something like that was a bit much.

The reply I got was probably one of the most diplomatic "go away" messages I'd ever gotten. (Honestly, it was. Very succinct and staying on-message.) It still didn't answer the question nor address the suggestion I made.

Or perhaps it did. The question, he said, may not have an easy answer. And at the end, he said that the teachers will proceed as usual, although the context may be up for interpretation. I'm kind of stretching to say that the questions were addressed rather than deflected.

So I'm back to square one. Part of the problem is my own history with school systems. I came from a family of educators. I worked in the public school system. And it took me a ridiculously long time to come to terms with some things, such as a school isn't really concerned with the craft of teaching or finding better ways to learn. That is what is in the brochure version of the school system. Education. Learning. Academics. Helping kids achieve their potentials, preparing them for tomorrow. Even Little Dude's school district proclaims that it's "Building Foundations for Future Success!"

But really schools are a system. I believed the brochure version of reality growing up...that schools were places to learn, and they cared about learning. If I didn't understand something then it was because I didn't understand the situation, not because of a dissonance between what the school system claimed and what they actually did. I had the flaw. I didn't see why they're doing this but it really made sense, so I had something broken in my head.

This was a kind of example of that. Not just the personal responsibility thing..."I'm so offended this must be stopped, but I don't want them to know who it was in case the parents are mad," but the idea that this was an arbitrary rule enforcement ("Nothing personal, we just found someone who doesn't like it") and a common sense approach to this, seeing as it wasn't actually causing a problem but instead was purely a "we feel like this is breaking an interpretation of the rules" (again...I don't believe this is actually written out as "thou shalt not wear a freaking shirt in school" in any of the rules) that this could just as readily been handled by asking us not to send him to school in that shirt again. Not just Little Dude. Any kid. This was an interpretation of the rules that no one else had bothered to go through the trouble of being offended over.

The principal felt that the fact he had worn it several times without being noticed was unfortunate, but that doesn't make it ok. As an experiment, I wondered what would happen if we sent him in a shirt that read, "Fuck this shit," would that go several days without being noticed? I think it's a little disingenuous to characterize it as a "we didn't notice" when really it was "no one gave a damn until Bob down the hall was offended by it."

I suppose I have to tell Little Dude that schools are systems. They thrive on rules that can be enforced, sometimes arbitrarily, and not treating people as individuals because that takes resources and attention. It took me a long time to learn that; like, an embarrassingly long time. That's part of the reason that it was made clear almost right off the bat that there would be no discussion about the relevance of "Freaking" to the colorful metaphor list (we didn't bring that up, by the way...it seemed to be something he wanted to address right off that we'd not discuss that before diving right into why it was Little Dude's problem to properly perceive the situation.)

Sometimes, being a system, schools will say one thing while still violating those principles when they do things. It's hypocritical. But they'll justify it to themselves, and move on, and be even more offended if you don't accept your situation and do the same.

And sometimes situations just aren't fair, and never will be fair. That's something that schools indirectly teach that is actually quite relevant to life later on. You'll still find yourself in a situation that is uncomfortable, and you don't have the power to tell people that it's wrong. Storybook endings don't necessarily exist, where being right means you end up winning in the end.

Last, perhaps, just because it feels like someone possibly has a problem with you doesn't mean everyone is out to get you, metaphorically speaking. But you should probably be careful who you trust. Teachers are teachers, not friends. It's an important distinction, and one I think many kids don't quite learn the way they should (as well as some teachers...) That's a tough lesson for a kid to learn when your brain is wired to be more literal in interpreting things; the brochure of ideals doesn't match what schools actually do, and that gets confusing unless you start internalizing the dissonance as a problem with yourself and not the situation. It took me way too long to start coming to terms with that. I'd hate to have Little Dude go through years without benefiting from that late realization.

Upgrading to Go 1.6 on a Raspberry Pi

I had written previously about upgrading from Golang 1.4 to 1.5; the steps were largely the same, but I did run into a few extra snags.

The quick version of the instructions:
Go is installed in my home directory on the Pi.

mv ./go ./go1.4
git clone https://go.googlesource.com/go
git checkout go1.6
cd src
./all.bash

Note: I renamed my installed version go1.5. In the instructions above I named it go1.4. That's because go1.6 looked for the previous compiler in ~/go1.4; it prompted me to change an environment variable to make it work, which took the form of:

export GOROOT_BOOTSTRAP=/home/pi/go1.5

...or you can use go1.4 and it might find it automatically. At least, that's what the error implied.

It tried to complete, but I hit some issues due to resource scarcity on the Pi. It looks like the compiler compiled but tests would fail spectacularly. I needed to make a couple of tweaks, as per Dave Cheney.

First I changed a ulimit size because otherwise the tests will exhaust the 32 bit address space.

ulimit -s 1024

Second, I needed some swap. Otherwise it will exhaust available memory and poof everything dies.

The default way Raspberry Pi's configure swap is using dphys-swapfile. The configuration is contained in /etc/dphys-swapfile.

The default is a 100 MB file called /var/swap. It'll need to be enlarged, and if you have an external drive connected, it might be a good idea to put it there. It's slower but placing it on a physical platter drive will save wear on the SD card.

On my system I changed the lines:

CONF_SWAPSIZE=512
CONF_SWAPFILE=/mnt/mydrive/swap/swapfile

(Of course I had to create a directory called swap on the mount point with appropriate permissions first...)

Then I ran

sudo /etc/init.d/dphys-swapfile stop
sudo /etc/init./dphys-swapfile start

...to rebuild the swapfile.

Last step I needed to do was execute the ./all.bash script with a variable to change the scaling factor, which apparently works well on 64 bit machines but not little underpowered Pi's. Instead of ./all.bash, I ran:

env GO_TEST_TIMEOUT_SCALE=10 ./all.bash

All these small changes allowed Go 1.6 to not only compile, but pass the tests on my RasPi 2!