I have the following very simple code to persist strings in the datastore. I have pulled it together from various datastore examples but I am still not happy with it.
Its aim is simply to store a string under a key in persist and retrieve it under fromPresistence.
// Used to store the string value.
type Entity struct {
Value string
}
// Grow my key.
func key(x string) *datastore.Key {
return datastore.NewKey(context, "Persist", x, 0, nil)
}
// Get it from persistence storage.
func fromPersistence(x string) string {
var persisted string = x
// Make my key.
k := key(x)
// New entity for filling in.
e := new(Entity)
// Look it up!
if err := datastore.Get(context, k, e); err == nil {
// It was there!
persisted = e.Value
context.Debugf("Persisted %s=%s", x, persisted)
}
return persisted
}
// Persist the latest number.
func persist(x string) func(*big.Int) {
return func(n *big.Int) {
// Make my key.
k := key(x)
// New entity for filling in.
e := new(Entity)
// Value is the decimal form of the number.
e.Value = n.String()
context.Debugf("Persist %s=%s", start, e.Value)
if _, err := datastore.Put(context, k, e); err != nil {
context.Debugf("Persist failed! %s", err)
}
}
}
but it seems to be behind by one each time. Here's some log results:
C:\Go\GAE\go_appengine\google\src>\go\gae\go_appengine\dev_appserver.py unique/
INFO 2013-10-15 20:55:08,296 sdk_update_checker.py:245] Checking for updates to the SDK.
INFO 2013-10-15 20:55:09,726 api_server.py:138] Starting API server at: http://localhost:50218
INFO 2013-10-15 20:55:09,746 dispatcher.py:168] Starting module "default" running at: http://localhost:8080
INFO 2013-10-15 20:55:09,763 admin_server.py:117] Starting admin server at: http://localhost:8000
INFO 2013-10-15 20:56:22,131 module.py:599] default: "GET / HTTP/1.1" 304 -
INFO 2013-10-15 20:56:22,344 module.py:599] default: "GET /favicon.ico HTTP/1.1" 304 -
INFO 2013-10-15 20:56:22,448 module.py:599] default: "GET /favicon.ico HTTP/1.1" 304 -
2013/10/15 20:56:26 DEBUG: Persisted 38913371956013078496870267859=3378577588146889866220112993
2013/10/15 20:56:26 DEBUG: Persist 38913371956013078496870267859=21186844412818184262771263024
...
2013/10/15 20:56:30 DEBUG: Persist 38913371956013078496870267859=1324177775801136516423203939
INFO 2013-10-15 20:56:30,756 module.py:599] default: "GET /n HTTP/1.1" 200 19
INFO 2013-10-15 20:56:30,927 module.py:599] default: "GET /favicon.ico HTTP/1.1" 304 -
2013/10/15 20:56:32 DEBUG: Persist 38913371956013078496870267859=20778614526287997725322370609
C:\Go\GAE\go_appengine\google\src>\go\gae\go_appengine\dev_appserver.py unique/
INFO 2013-10-15 20:57:15,657 sdk_update_checker.py:245] Checking for updates to the SDK.
INFO 2013-10-15 20:57:17,033 api_server.py:138] Starting API server at: http://localhost:50241
INFO 2013-10-15 20:57:17,085 dispatcher.py:168] Starting module "default" running at: http://localhost:8080
INFO 2013-10-15 20:57:17,098 admin_server.py:117] Starting admin server at: http://localhost:8000
2013/10/15 20:57:24 DEBUG: Persisted 38913371956013078496870267859=1324177775801136516423203939
2013/10/15 20:57:24 DEBUG: Persist 38913371956013078496870267859=20778614526287997725322370609
...
See how the last attempt at persistence stores 20778614526287997725322370609 but the retrieval attempt returned the previously persisted value of 1324177775801136516423203939.
What am I doing wrong?
NB: I have changed the code to use the context.Debugf mechanism to print my debug strings to get the strange log records out of the equation.
The old Logf code was as follows. I am sure it was the cause of the strange log entries. It is not the target of my question. I will fix this myself.
func Logf(format string, a ...interface{}) {
if context != nil {
// Context is valid.
if len(logQueue) > 0 {
// Roll out the stored entries.
for i := 0; i < len(logQueue); i++ {
context.Debugf("%s", logQueue[i])
}
// Empty the queue.
logQueue = make([]string, 0)
}
// Pass a "" to just flush the queue
if format != "" {
// Log it through the context.
context.Debugf(format, a)
}
} else {
// No context! Queue it up.
logQueue = append(logQueue, fmt.Sprintf(format, a...))
}
}
There's a good chance here that you're seeing is one of those unexpected aspects of distributed systems. If your calls to persist and fromPersistence end up running on different instances of your application, the log messages may be taking slightly different paths to where they persist. Note that the timestamps on the seemingly-reversed log messages are the same.
look at your datastore code... it's somehow storing the values in with the keys.
the statementLogf("Persist %s=%s", x, e.Value)
2013/10/13 23:21:26 DEBUG: Persist [38913371956013078496870267859 19124562091635092830747528895]=%s(MISSING)
which means your 'x' value there is a slice of the key and some other value (from your text it would seem it's the previous key value).
the actual value is missing... that's what the %s(MISSING) bit means