states/statemgr: Local locks meta is near output path, not input path

This was a mistake while adapting this code from the old state.LocalState.
Since the lock is held on the output file (s.path) the metadata should
live adjacent to that rather than being built from the read path
(s.readPath) that is used only as the initial snapshot on first
instantiation.

This also includes more logging, continuing the trend of other recent
commits in these files. The local state behavior is sufficiently complex
that these trace logs are a great help in debugging issues such as this
one with the wrong files being used or actions being taken in the wrong
order.

states/statemgr/filesystem.go

@@ -345,7 +345,9 @@ func (s *Filesystem) Unlock(id string) error {
 		}
 	}
 
-	os.Remove(s.lockInfoPath())
+	lockInfoPath := s.lockInfoPath()
+	log.Printf("[TRACE] statemgr.Filesystem: removing lock metadata file %s", lockInfoPath)
+	os.Remove(lockInfoPath)
 
 	fileName := s.stateFileOut.Name()
 
@@ -466,7 +468,7 @@ func (s *Filesystem) createStateFiles() error {
 
 // return the path for the lockInfo metadata.
 func (s *Filesystem) lockInfoPath() string {
-	stateDir, stateName := filepath.Split(s.readPath)
+	stateDir, stateName := filepath.Split(s.path)
 	if stateName == "" {
 		panic("empty state file path")
 	}
@@ -500,6 +502,7 @@ func (s *Filesystem) writeLockInfo(info *LockInfo) error {
 	info.Path = s.readPath
 	info.Created = time.Now().UTC()
 
+	log.Printf("[TRACE] statemgr.Filesystem: writing lock metadata to %s", path)
 	err := ioutil.WriteFile(path, info.Marshal(), 0600)
 	if err != nil {
 		return fmt.Errorf("could not write lock info for %q: %s", s.readPath, err)

states/statemgr/filesystem_lock_unix.go

@@ -3,6 +3,7 @@
 package statemgr
 
 import (
+	"log"
 	"os"
 	"syscall"
 )
@@ -10,6 +11,7 @@ import (
 // use fcntl POSIX locks for the most consistent behavior across platforms, and
 // hopefully some campatibility over NFS and CIFS.
 func (s *Filesystem) lock() error {
+	log.Printf("[TRACE] statemgr.Filesystem: locking %s using fcntl flock", s.path)
 	flock := &syscall.Flock_t{
 		Type:   syscall.F_RDLCK | syscall.F_WRLCK,
 		Whence: int16(os.SEEK_SET),
@@ -22,6 +24,7 @@ func (s *Filesystem) lock() error {
 }
 
 func (s *Filesystem) unlock() error {
+	log.Printf("[TRACE] statemgr.Filesystem: unlocking %s using fcntl flock", s.path)
 	flock := &syscall.Flock_t{
 		Type:   syscall.F_UNLCK,
 		Whence: int16(os.SEEK_SET),

states/statemgr/filesystem_lock_windows.go

@@ -3,6 +3,7 @@
 package statemgr
 
 import (
+	"log"
 	"math"
 	"syscall"
 	"unsafe"
@@ -22,6 +23,8 @@ const (
 )
 
 func (s *Filesystem) lock() error {
+	log.Printf("[TRACE] statemgr.Filesystem: locking %s using LockFileEx", s.path)
+
 	// even though we're failing immediately, an overlapped event structure is
 	// required
 	ol, err := newOverlapped()
@@ -41,6 +44,8 @@ func (s *Filesystem) lock() error {
 }
 
 func (s *Filesystem) unlock() error {
+	log.Printf("[TRACE] statemgr.Filesystem: unlocked by closing %s", s.path)
+
 	// the file is closed in Unlock
 	return nil
 }