Browse Source

Adds LOG statements in multiprocess API test

Renames _terminate_workers() to _wait_for_workers_to_end() to accurately
match what is done in that method. Adds a bunch of LOG.info() and
LOG.warn() calls in the various methods in the test to get better
debugging information when bug # 1357578 rears its ugly head.

Change-Id: I6698b7c71ec651c812138c8dd93b1e1b33ee1178
Related-bug: #1357578
tags/2014.2.rc1
Jay Pipes 5 years ago
parent
commit
608630b0b2
1 changed files with 17 additions and 6 deletions
  1. 17
    6
      nova/tests/integrated/test_multiprocess_api.py

+ 17
- 6
nova/tests/integrated/test_multiprocess_api.py View File

@@ -77,6 +77,7 @@ class MultiprocessWSGITest(integrated_helpers._IntegratedTestBase):
77 77
             # Really exit
78 78
             os._exit(status)
79 79
 
80
+        LOG.info("Launched OSAPI WSGI service in process %d", pid)
80 81
         self.pid = pid
81 82
 
82 83
         # Wait at most 10 seconds to spawn workers
@@ -100,19 +101,24 @@ class MultiprocessWSGITest(integrated_helpers._IntegratedTestBase):
100 101
     def tearDown(self):
101 102
         if self.pid:
102 103
             # Make sure all processes are stopped
104
+            LOG.info("in tearDown(), stopping launcher pid %d with SIGTERM",
105
+                     self.pid)
103 106
             os.kill(self.pid, signal.SIGTERM)
104 107
 
105
-            self._terminate_workers()
108
+            self._wait_for_all_workers_to_end()
106 109
 
107 110
             try:
108 111
                 # Make sure we reap our test process
109 112
                 self._reap_test()
110 113
             except fixtures.TimeoutException:
111
-                # If the child gets stuck or is too slow in existing
114
+                # If the child gets stuck or is too slow in exiting
112 115
                 # after receiving the SIGTERM, gracefully handle the
113 116
                 # timeout exception and try harder to kill it. We need
114 117
                 # to do this otherwise the child process can hold up
115 118
                 # the test run
119
+                LOG.warn("got fixtures.TimeoutException during tearDown(). "
120
+                         "going nuclear with a SIGKILL on launcher pid %d.",
121
+                         self.pid)
116 122
                 os.kill(self.pid, signal.SIGKILL)
117 123
 
118 124
         super(MultiprocessWSGITest, self).tearDown()
@@ -132,7 +138,10 @@ class MultiprocessWSGITest(integrated_helpers._IntegratedTestBase):
132 138
 
133 139
         processes = [tuple(int(p) for p in l.strip().split()[:2])
134 140
                      for l in f.readlines()]
135
-        return [p for p, pp in processes if pp == self.pid]
141
+        workers = [p for p, pp in processes if pp == self.pid]
142
+        LOG.info('in _get_workers(), workers: %r for PPID %d',
143
+                 workers, self.pid)
144
+        return workers
136 145
 
137 146
     def wait_on_process_until_end(self, worker_pid):
138 147
         # NOTE: the testing framework itself has a
@@ -155,6 +164,9 @@ class MultiprocessWSGITest(integrated_helpers._IntegratedTestBase):
155 164
                 # needs to check their exit state.
156 165
                 if err.errno == errno.ESRCH:
157 166
                     break
167
+                LOG.warning("got non-ESRCH errno %d when attempting "
168
+                            "status of worker PID %d",
169
+                            err.errno, worker_pid)
158 170
         LOG.info('process %r has exited' % worker_pid)
159 171
 
160 172
     def test_killed_worker_recover(self):
@@ -171,7 +183,6 @@ class MultiprocessWSGITest(integrated_helpers._IntegratedTestBase):
171 183
 
172 184
         # Make sure worker pids don't match
173 185
         end_workers = self._get_workers()
174
-        LOG.info('workers: %r' % end_workers)
175 186
         self.assertNotEqual(start_workers, end_workers)
176 187
 
177 188
         # check if api service still works
@@ -188,9 +199,9 @@ class MultiprocessWSGITest(integrated_helpers._IntegratedTestBase):
188 199
         LOG.info("sent launcher_process pid: %r signal: %r" % (self.pid, sig))
189 200
         os.kill(self.pid, sig)
190 201
 
191
-        self._terminate_workers()
202
+        self._wait_for_all_workers_to_end()
192 203
 
193
-    def _terminate_workers(self):
204
+    def _wait_for_all_workers_to_end(self):
194 205
         worker_pids = self._get_workers()
195 206
 
196 207
         # did you know the test framework has a timeout of its own?

Loading…
Cancel
Save