Merge pull request #885 from rqlite/better-e2e-http

Better HTTP logging during end-to-end tests

CHANGELOG.md

@@ -1,3 +1,7 @@
+## 6.4.4 (unreleased)
+### Implementation changes and bug fixes
+- [PR #885](https://github.com/rqlite/rqlite/pull/885): Improved responses on HTTP 500.
+
 ## 6.4.3 (September 9th 2021)
 ### Implementation changes and bug fixes
 - [PR #882](https://github.com/rqlite/rqlite/pull/882): Some minor improvements related to on-disk SQLite use.

http/service.go

@@ -565,13 +565,15 @@ func (s *Service) handleStatus(w http.ResponseWriter, r *http.Request) {
 
 	storeStatus, err := s.store.Stats()
 	if err != nil {
-		http.Error(w, err.Error(), http.StatusInternalServerError)
+		http.Error(w, fmt.Sprintf("store stats: %s", err.Error()),
+			http.StatusInternalServerError)
 		return
 	}
 
 	clusterStatus, err := s.cluster.Stats()
 	if err != nil {
-		http.Error(w, err.Error(), http.StatusInternalServerError)
+		http.Error(w, fmt.Sprintf("cluster stats: %s", err.Error()),
+			http.StatusInternalServerError)
 		return
 	}
 
@@ -616,7 +618,8 @@ func (s *Service) handleStatus(w http.ResponseWriter, r *http.Request) {
 		for k, v := range s.statuses {
 			stat, err := v.Stats()
 			if err != nil {
-				http.Error(w, err.Error(), http.StatusInternalServerError)
+				http.Error(w, fmt.Sprintf("registered stats: %s", err.Error()),
+					http.StatusInternalServerError)
 				return
 			}
 			status[k] = stat
@@ -631,12 +634,14 @@ func (s *Service) handleStatus(w http.ResponseWriter, r *http.Request) {
 		b, err = json.Marshal(status)
 	}
 	if err != nil {
-		http.Error(w, err.Error(), http.StatusInternalServerError)
+		http.Error(w, fmt.Sprintf("JSON marshal: %s", err.Error()),
+			http.StatusInternalServerError)
 		return
 	}
 	_, err = w.Write([]byte(b))
 	if err != nil {
-		http.Error(w, err.Error(), http.StatusInternalServerError)
+		http.Error(w, fmt.Sprintf("write: %s", err.Error()),
+			http.StatusInternalServerError)
 		return
 	}
 }
@@ -672,7 +677,8 @@ func (s *Service) handleNodes(w http.ResponseWriter, r *http.Request) {
 	// Get nodes in the cluster, and possibly filter out non-voters.
 	nodes, err := s.store.Nodes()
 	if err != nil {
-		http.Error(w, err.Error(), http.StatusInternalServerError)
+		http.Error(w, fmt.Sprintf("store nodes: %s", err.Error()),
+			http.StatusInternalServerError)
 		return
 	}
 
@@ -686,13 +692,15 @@ func (s *Service) handleNodes(w http.ResponseWriter, r *http.Request) {
 
 	lAddr, err := s.store.LeaderAddr()
 	if err != nil {
-		http.Error(w, err.Error(), http.StatusInternalServerError)
+		http.Error(w, fmt.Sprintf("leader address: %s", err.Error()),
+			http.StatusInternalServerError)
 		return
 	}
 
 	nodesResp, err := s.checkNodes(filteredNodes, t)
 	if err != nil {
-		http.Error(w, err.Error(), http.StatusInternalServerError)
+		http.Error(w, fmt.Sprintf("check nodes: %s", err.Error()),
+			http.StatusInternalServerError)
 		return
 	}
 
@@ -793,7 +801,8 @@ func (s *Service) handleExecute(w http.ResponseWriter, r *http.Request) {
 
 		addr, err := s.store.LeaderAddr()
 		if err != nil {
-			http.Error(w, err.Error(), http.StatusInternalServerError)
+			http.Error(w, fmt.Sprintf("leader address: %s", err.Error()),
+				http.StatusInternalServerError)
 			return
 		}
 		if addr == "" {

system_test/full_system_test.py

@@ -123,17 +123,17 @@ class Node(object):
 
   def status(self):
     r = requests.get(self._status_url())
-    r.raise_for_status()
+    raise_for_status(r)
     return r.json()
 
   def nodes(self):
     r = requests.get(self._nodes_url())
-    r.raise_for_status()
+    raise_for_status(r)
     return r.json()
 
   def expvar(self):
     r = requests.get(self._expvar_url())
-    r.raise_for_status()
+    raise_for_status(r)
     return r.json()
 
   def is_leader(self):
@@ -245,7 +245,7 @@ class Node(object):
     if pretty:
       reqParams['pretty'] = "yes"
     r = requests.post(self._query_url(), params=reqParams, data=json.dumps(body))
-    r.raise_for_status()
+    raise_for_status(r)
     if text:
       return r.text
     return r.json()
@@ -258,26 +258,26 @@ class Node(object):
 
   def execute_raw(self, body):
     r = requests.post(self._execute_url(), data=body)
-    r.raise_for_status()
+    raise_for_status(r)
     return r.json()
 
   def backup(self, file):
     with open(file, 'w') as fd:
       r = requests.get(self._backup_url())
-      r.raise_for_status()
+      raise_for_status(r)
       fd.write(r.content)
 
   def restore(self, file):
     # This is the one API that doesn't expect JSON.
     conn = sqlite3.connect(file)
     r = requests.post(self._load_url(), data='\n'.join(conn.iterdump()))
-    r.raise_for_status()
+    raise_for_status(r)
     conn.close()
     return r.json()
 
   def redirect_addr(self):
     r = requests.post(self._execute_url(redirect=True), data=json.dumps(['nonsense']), allow_redirects=False)
-    r.raise_for_status()
+    raise_for_status(r)
     if r.status_code == 301:
       return "%s://%s" % (urlparse(r.headers['Location']).scheme, urlparse(r.headers['Location']).netloc)
 
@@ -309,6 +309,13 @@ class Node(object):
     self.stdout_fd.close()
     self.stderr_fd.close()
 
+def raise_for_status(r):
+  try:
+    r.raise_for_status()
+  except requests.exceptions.HTTPError as e:
+    print(e)
+    print(r.text)
+
 def random_addr():
   s = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
   s.bind(('localhost', 0))

tcp/pool/channel_test.go

@@ -224,9 +224,9 @@ func TestPoolConcurrent2(t *testing.T) {
 
 	var wg sync.WaitGroup
 
+	wg.Add(10)
 	go func() {
 		for i := 0; i < 10; i++ {
-			wg.Add(1)
 			go func(i int) {
 				conn, _ := p.Get()
 				time.Sleep(time.Millisecond * time.Duration(rand.Intn(100)))