I've noticed that my task workers never run in tests, and there's an almost complete de-coupling of enqueue/dequeue logic in testing that prevents me from even verifying that the task was properly enqueued.
Consider the following minimal example:
app.yaml:
runtime: go
api_version: go1
handlers:
- url: /worker/.*
script: _go_app
login: admin
- url: /.*
script: _go_app
worker/settle.go (package worker)
func SettleWorker(w http.ResponseWriter, r *http.Request) {
ctx := appengine.NewContext(r)
log.Infof(ctx, "Worker was successfully invoked")
}
service/main.go (package service)
func TestHandler(w http.ResponseWriter, r *http.Request) {
ctx := appengine.NewContext(r)
t := taskqueue.NewPOSTTask("/worker/wrongpath", map[string][]string{"name": {"BLAH"}})
task, err := taskqueue.Add(ctx, t, "")
if err != nil {
http.Error(w, "Error", http.StatusBadRequest)
return
}
log.Infof(ctx, "Successfully posted task to worker: %+v", task)
}
func init() {
http.HandleFunc("/worker/settle", worker.SettleWorker)
http.HandleFunc("/test", TestHandler)
}
service/main_test.go (package service_test)
func TestTestHandler(t *testing.T) {
inst, err := aetest.NewInstance(nil)
if err != nil {
t.Fatal(err.Error())
}
req, err := inst.NewRequest("GET", "/", nil)
if err != nil {
t.Fatal(err.Error())
}
resp := httptest.NewRecorder()
http.HandlerFunc(service.TestHandler).ServeHTTP(resp, req)
}
Note that the path being passed to taskqueue.Add ("/worker/wrongpath") doesn't actually have a registered handler. At a glance, this seems to causes no issues when I test this using goapp test bitwyrm/service -v, but the worker doesn't actually run. I see the happy logging statement and a status code of 200 is returned from TestHandler, but the logging statement from SettleWorker does not appear.
The same thing happens if the path is correct (i.e. set to "/worker/settle"). So I have no way of writing tests to assert that the test is getting properly enqueued.
To make this even worse, for some reason running this test also leaves an orphaned dev_appserver.py process (regardless of which path is used). Running this repeatedly eventually fills up my computer with orphaned test processes, which eventually causes the dev server invoked via goapp test to run into database locking issues, meaning I can't run my test suite without manually killing all of the orphaned test processes. Typical stacktrace:
...successful test output...
INFO 2018-05-04 09:02:10,762 stub_util.py:357] Applying all pending transactions and saving the datastore
INFO 2018-05-04 09:02:13,827 stub_util.py:360] Saving search indexes
Exception in thread Thread-1:
Traceback (most recent call last):
File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/threading.py", line 810, in __bootstrap_inner
self.run()
File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/threading.py", line 763, in run
self.__target(*self.__args, **self.__kwargs)
File "/Users/ursa/Code/google-cloud-sdk/platform/google_appengine/google/appengine/api/taskqueue/taskqueue_stub.py", line 2182, in MainLoop
self._ProcessQueues()
File "/Users/ursa/Code/google-cloud-sdk/platform/google_appengine/google/appengine/api/taskqueue/taskqueue_stub.py", line 2127, in _ProcessQueues
response_code = self.task_executor.ExecuteTask(task, queue)
File "/Users/ursa/Code/google-cloud-sdk/platform/google_appengine/google/appengine/api/taskqueue/taskqueue_stub.py", line 2059, in ExecuteTask
'0.1.0.2')
File "/Users/ursa/Code/google-cloud-sdk/platform/google_appengine/google/appengine/tools/devappserver2/dispatcher.py", line 776, in add_request
inst)
File "/Users/ursa/Code/google-cloud-sdk/platform/google_appengine/google/appengine/tools/devappserver2/dispatcher.py", line 862, in _handle_request
request_type=request_type)
File "/Users/ursa/Code/google-cloud-sdk/platform/google_appengine/google/appengine/tools/devappserver2/module.py", line 818, in _handle_request
module=self._module_configuration.module_name)
File "/Users/ursa/Code/google-cloud-sdk/platform/google_appengine/google/appengine/api/apiproxy_stub.py", line 186, in WrappedMethod
return method(self, *args, **kwargs)
File "/Users/ursa/Code/google-cloud-sdk/platform/google_appengine/google/appengine/api/logservice/logservice_stub.py", line 181, in start_request
host, start_time, method, resource, http_version, module))
OperationalError: database is locked
Note that this all seems to work fine outside of testing - when I hit this http handler in dev using Paw and dev_appserver.py, the correct path does trigger the worker, and the incorrect path sees logging of 403 responses with a series of retries (both behaviors you'd expect).
I've spent enough time trying to debug this that I'm assuming it's an actual bug in dev_appserver.py or aetest, but I'm a firm believer in making sure it's not the application's fault before blaming the tools. Am I doing something wrong here that's obvious?
