test-http-bad-server: unify log printing for `sendall` and `write`
authorPierre-Yves David <pierre-yves.david@octobus.net>
Sun, 23 Jan 2022 21:25:01 +0100
changeset 48611 f91f98e9834a
parent 48610 caa6694dac45
child 48612 11e5cb170d36
test-http-bad-server: unify log printing for `sendall` and `write` The `write` function was logging before calling the function while the `sendall` function were logging after calling the function. We align the `write` behavior on the `sendall` behavior before unifying the code. Differential Revision: https://phab.mercurial-scm.org/D12042
tests/test-http-bad-server.t
tests/testlib/badserverext.py
--- a/tests/test-http-bad-server.t	Fri Jan 21 01:07:50 2022 +0100
+++ b/tests/test-http-bad-server.t	Sun Jan 23 21:25:01 2022 +0100
@@ -272,7 +272,6 @@
   Exception: connection closed after receiving N bytes
   
   write(126) -> HTTP/1.1 500 Internal Server Error\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nTransfer-Encoding: chunked\r\n\r\n (py3 no-py36 !)
-  write(36) -> HTTP/1.1 500 Internal Server Error\r\n (no-py3 !)
 
   $ rm -f error.log
 
@@ -307,7 +306,6 @@
   Exception: connection closed after sending N bytes
   
   write(286) -> HTTP/1.1 200 Script output follows\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nContent-Type: application/mercurial-0.1\r\nContent-Length: 431\r\n\r\nHTTP/1.1 500 Internal Server Error\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nTransfer-Encoding: chunked\r\n\r\n (py3 no-py36 !)
-  write(36) -> HTTP/1.1 500 Internal Server Error\r\n (no-py3 !)
 
   $ rm -f error.log
 
@@ -407,7 +405,6 @@
   Exception: connection closed after sending N bytes
   
   write(285) -> HTTP/1.1 200 Script output follows\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nContent-Type: application/mercurial-0.1\r\nContent-Length: 42\r\n\r\nHTTP/1.1 500 Internal Server Error\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nTransfer-Encoding: chunked\r\n\r\n (py3 no-py36 !)
-  write(36) -> HTTP/1.1 500 Internal Server Error\r\n (no-py3 !)
 
   $ rm -f error.log
 
@@ -552,7 +549,6 @@
   Exception: connection closed after sending N bytes
   
   write(293) -> HTTP/1.1 200 Script output follows\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nContent-Type: application/mercurial-0.2\r\nTransfer-Encoding: chunked\r\n\r\nHTTP/1.1 500 Internal Server Error\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nTransfer-Encoding: chunked\r\n\r\n (py3 no-py36 !)
-  write(36) -> HTTP/1.1 500 Internal Server Error\r\n (no-py3 !)
 
   $ rm -f error.log
 
@@ -577,11 +573,11 @@
 
 #else
   $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -4
+  $LOCALIP - - [$ERRDATE$] Exception happened during processing request '/?cmd=getbundle': (glob)
   Traceback (most recent call last):
   Exception: connection closed after sending N bytes
+  write(293) -> HTTP/1.1 200 Script output follows\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nContent-Type: application/mercurial-0.2\r\nTransfer-Encoding: chunked\r\n\r\nHTTP/1.1 500 Internal Server Error\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nTransfer-Encoding: chunked\r\n\r\n (py3 !)
   
-  write(293) -> HTTP/1.1 200 Script output follows\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nContent-Type: application/mercurial-0.2\r\nTransfer-Encoding: chunked\r\n\r\nHTTP/1.1 500 Internal Server Error\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nTransfer-Encoding: chunked\r\n\r\n (py3 !)
-  write(36) -> HTTP/1.1 500 Internal Server Error\r\n (no-py3 !)
 #endif
 
   $ rm -f error.log
@@ -661,7 +657,6 @@
   Exception: connection closed after sending N bytes
   
   write(293) -> HTTP/1.1 200 Script output follows\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nContent-Type: application/mercurial-0.2\r\nTransfer-Encoding: chunked\r\n\r\nHTTP/1.1 500 Internal Server Error\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nTransfer-Encoding: chunked\r\n\r\n (py3 no-py36 !)
-  write(36) -> HTTP/1.1 500 Internal Server Error\r\n (no-py3 !)
 
   $ rm -f error.log
 
@@ -744,7 +739,6 @@
   Traceback (most recent call last):
   Exception: connection closed after sending N bytes
   
-  write(27) -> 15\r\nInternal Server Error\r\n (no-py3 !)
 
   $ rm -f error.log
 
@@ -779,8 +773,9 @@
   $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -11
   readline(65537) -> (2) \r\n (py3 !)
   write(167 from 167) -> (21) HTTP/1.1 200 Script output follows\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nContent-Type: application/mercurial-0.2\r\nTransfer-Encoding: chunked\r\n\r\n (py3 !)
-  write(28 from 28) -> (23) Transfer-Encoding: chunked\r\n (no-py3 !)
-  write(2 from 2) -> (21) \r\n (no-py3 !)
+  write(41 from 41) -> (51) Content-Type: application/mercurial-0.2\r\n
+  write(28 from 28) -> (23) Transfer-Encoding: chunked\r\n
+  write(2 from 2) -> (21) \r\n
   write(6 from 6) -> (15) 1\\r\\n\x04\\r\\n (esc)
   write(9 from 9) -> (6) 4\r\nnone\r\n
   write(6 from 9) -> (0) 4\r\nHG2
@@ -789,7 +784,6 @@
   Traceback (most recent call last):
   Exception: connection closed after sending N bytes
   
-  write(27) -> 15\r\nInternal Server Error\r\n
 #endif
 
   $ rm -f error.log
@@ -826,8 +820,9 @@
   $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -12
   readline(65537) -> (2) \r\n (py3 !)
   write(167 from 167) -> (30) HTTP/1.1 200 Script output follows\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nContent-Type: application/mercurial-0.2\r\nTransfer-Encoding: chunked\r\n\r\n (py3 !)
-  write(28 from 28) -> (32) Transfer-Encoding: chunked\r\n (no-py3 !)
-  write(2 from 2) -> (30) \r\n (no-py3 !)
+  write(41 from 41) -> (60) Content-Type: application/mercurial-0.2\r\n
+  write(28 from 28) -> (32) Transfer-Encoding: chunked\r\n
+  write(2 from 2) -> (30) \r\n
   write(6 from 6) -> (24) 1\\r\\n\x04\\r\\n (esc)
   write(9 from 9) -> (15) 4\r\nnone\r\n
   write(9 from 9) -> (6) 4\r\nHG20\r\n
@@ -837,7 +832,6 @@
   Traceback (most recent call last):
   Exception: connection closed after sending N bytes
   
-  write(27) -> 15\r\nInternal Server Error\r\n
 #endif
 
   $ rm -f error.log
@@ -873,8 +867,9 @@
   $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -12
   readline(65537) -> (2) \r\n (py3 !)
   write(167 from 167) -> (33) HTTP/1.1 200 Script output follows\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nContent-Type: application/mercurial-0.2\r\nTransfer-Encoding: chunked\r\n\r\n (py3 !)
-  write(28 from 28) -> (35) Transfer-Encoding: chunked\r\n (no-py3 !)
-  write(2 from 2) -> (33) \r\n (no-py3 !)
+  write(41 from 41) -> (63) Content-Type: application/mercurial-0.2\r\n
+  write(28 from 28) -> (35) Transfer-Encoding: chunked\r\n
+  write(2 from 2) -> (33) \r\n
   write(6 from 6) -> (27) 1\\r\\n\x04\\r\\n (esc)
   write(9 from 9) -> (18) 4\r\nnone\r\n
   write(9 from 9) -> (9) 4\r\nHG20\r\n
@@ -884,7 +879,6 @@
   Traceback (most recent call last):
   Exception: connection closed after sending N bytes
   
-  write(27) -> 15\r\nInternal Server Error\r\n
 #endif
 
   $ rm -f error.log
@@ -922,8 +916,9 @@
   $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -13
   readline(65537) -> (2) \r\n (py3 !)
   write(167 from 167) -> (42) HTTP/1.1 200 Script output follows\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nContent-Type: application/mercurial-0.2\r\nTransfer-Encoding: chunked\r\n\r\n (py3 !)
-  write(28 from 28) -> (44) Transfer-Encoding: chunked\r\n (no-py3 !)
-  write(2 from 2) -> (42) \r\n (no-py3 !)
+  write(41 from 41) -> (72) Content-Type: application/mercurial-0.2\r\n
+  write(28 from 28) -> (44) Transfer-Encoding: chunked\r\n
+  write(2 from 2) -> (42) \r\n
   write(6 from 6) -> (36) 1\\r\\n\x04\\r\\n (esc)
   write(9 from 9) -> (27) 4\r\nnone\r\n
   write(9 from 9) -> (18) 4\r\nHG20\r\n
@@ -934,7 +929,6 @@
   Traceback (most recent call last):
   Exception: connection closed after sending N bytes
   
-  write(27) -> 15\r\nInternal Server Error\r\n
 #endif
 
   $ rm -f error.log
@@ -975,8 +969,9 @@
   $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -14
   readline(65537) -> (2) \r\n (py3 !)
   write(167 from 167) -> (89) HTTP/1.1 200 Script output follows\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nContent-Type: application/mercurial-0.2\r\nTransfer-Encoding: chunked\r\n\r\n (py3 !)
-  write(28 from 28) -> (91) Transfer-Encoding: chunked\r\n (no-py3 !)
-  write(2 from 2) -> (89) \r\n (no-py3 !)
+  write(41 from 41) -> (119) Content-Type: application/mercurial-0.2\r\n
+  write(28 from 28) -> (91) Transfer-Encoding: chunked\r\n
+  write(2 from 2) -> (89) \r\n
   write(6 from 6) -> (83) 1\\r\\n\x04\\r\\n (esc)
   write(9 from 9) -> (74) 4\r\nnone\r\n
   write(9 from 9) -> (65) 4\r\nHG20\r\n
@@ -988,7 +983,6 @@
   Traceback (most recent call last):
   Exception: connection closed after sending N bytes
   
-  write(27) -> 15\r\nInternal Server Error\r\n
 #endif
 
   $ rm -f error.log
@@ -1031,7 +1025,8 @@
 #else
   $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -15
   write(167 from 167) -> (110) HTTP/1.1 200 Script output follows\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nContent-Type: application/mercurial-0.2\r\nTransfer-Encoding: chunked\r\n\r\n (py3 !)
-  write(2 from 2) -> (110) \r\n (no-py3 !)
+  write(28 from 28) -> (112) Transfer-Encoding: chunked\r\n
+  write(2 from 2) -> (110) \r\n
   write(6 from 6) -> (104) 1\\r\\n\x04\\r\\n (esc)
   write(9 from 9) -> (95) 4\r\nnone\r\n
   write(9 from 9) -> (86) 4\r\nHG20\r\n
@@ -1045,7 +1040,6 @@
   Traceback (most recent call last):
   Exception: connection closed after sending N bytes
   
-  write(27) -> 15\r\nInternal Server Error\r\n
 #endif
 
   $ rm -f error.log
@@ -1088,8 +1082,9 @@
   $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -16
   readline(65537) -> (2) \r\n (py3 !)
   write(167 from 167) -> (571) HTTP/1.1 200 Script output follows\r\nServer: badhttpserver\r\nDate: $HTTP_DATE$\r\nContent-Type: application/mercurial-0.2\r\nTransfer-Encoding: chunked\r\n\r\n (py3 !)
-  write(28 from 28) -> (573) Transfer-Encoding: chunked\r\n (no-py3 !)
-  write(2 from 2) -> (571) \r\n (no-py3 !)
+  write(41 from 41) -> (601) Content-Type: application/mercurial-0.2\r\n
+  write(28 from 28) -> (573) Transfer-Encoding: chunked\r\n
+  write(2 from 2) -> (571) \r\n
   write(6 from 6) -> (565) 1\\r\\n\x04\\r\\n (esc)
   write(9 from 9) -> (556) 4\r\nnone\r\n
   write(9 from 9) -> (547) 4\r\nHG20\r\n
@@ -1103,7 +1098,6 @@
   Traceback (most recent call last):
   Exception: connection closed after sending N bytes
   
-  write(27) -> 15\r\nInternal Server Error\r\n
 #endif
 
   $ rm -f error.log
@@ -1149,6 +1143,7 @@
 
 #else
   $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -17
+  write(2 from 2) -> (602) \r\n
   write(6 from 6) -> (596) 1\\r\\n\x04\\r\\n (esc)
   write(9 from 9) -> (587) 4\r\nnone\r\n
   write(9 from 9) -> (578) 4\r\nHG20\r\n
@@ -1165,7 +1160,6 @@
   Traceback (most recent call last):
   Exception: connection closed after sending N bytes
   
-  write(27) -> 15\r\nInternal Server Error\r\n
 #endif
 
   $ rm -f error.log
@@ -1215,6 +1209,7 @@
 
 #else
   $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -21
+  write(9 from 9) -> (753) 4\r\nHG20\r\n
   write(9 from 9) -> (744) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (735) 4\\r\\n\x00\x00\x00)\\r\\n (esc)
   write(47 from 47) -> (688) 29\\r\\n\x0bCHANGEGROUP\x00\x00\x00\x00\x01\x01\x07\x02	\x01version02nbchanges1\\r\\n (esc)
@@ -1235,7 +1230,6 @@
   Traceback (most recent call last):
   Exception: connection closed after sending N bytes
   
-  write(27) -> 15\r\nInternal Server Error\r\n
 #endif
 
   $ rm -f error.log
@@ -1285,6 +1279,7 @@
 
 #else
   $ "$PYTHON" $TESTDIR/filtertraceback.py < error.log | tail -22
+  write(9 from 9) -> (756) 4\r\nHG20\r\n
   write(9 from 9) -> (747) 4\\r\\n\x00\x00\x00\x00\\r\\n (esc)
   write(9 from 9) -> (738) 4\\r\\n\x00\x00\x00)\\r\\n (esc)
   write(47 from 47) -> (691) 29\\r\\n\x0bCHANGEGROUP\x00\x00\x00\x00\x01\x01\x07\x02	\x01version02nbchanges1\\r\\n (esc)
@@ -1306,7 +1301,6 @@
   Traceback (most recent call last):
   Exception: connection closed after sending N bytes
   
-  write(27) -> 15\r\nInternal Server Error\r\n
 #endif
 
   $ rm -f error.log
--- a/tests/testlib/badserverext.py	Fri Jan 21 01:07:50 2022 +0100
+++ b/tests/testlib/badserverext.py	Sun Jan 23 21:25:01 2022 +0100
@@ -284,8 +284,8 @@
 
         # No byte limit on this operation. Call original function.
         if not remaining:
+            result = object.__getattribute__(self, '_orig').write(data)
             self._writelog(b'write(%d) -> %s' % (len(data), data))
-            result = object.__getattribute__(self, '_orig').write(data)
             return result
 
         if len(data) > remaining:
@@ -295,13 +295,13 @@
 
         remaining -= len(newdata)
 
+        result = object.__getattribute__(self, '_orig').write(newdata)
+
         self._writelog(
             b'write(%d from %d) -> (%d) %s'
             % (len(newdata), len(data), remaining, newdata)
         )
 
-        result = object.__getattribute__(self, '_orig').write(newdata)
-
         object.__getattribute__(self, '_cond').remaining_send_bytes = remaining
 
         if remaining <= 0: