D2842: util: don't log low-level I/O calls for HTTP peer

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
6 messages Options
Reply | Threaded
Open this post in threaded view
|

D2842: util: don't log low-level I/O calls for HTTP peer

indygreg (Gregory Szorc)
indygreg created this revision.
Herald added a subscriber: mercurial-devel.
Herald added a reviewer: hg-reviewers.

REVISION SUMMARY
  `hg debugwireproto` is useful for testing HTTP interactions. Possibly
  more useful than `get-with-headers.py`. But one thing that makes it
  annoying for mid-level tests is that it logs all API calls, such
  as readline(). This makes output - especially headers - overly
  verbose.
 
  This commit teaches our file and socket observers to not log API
  calls on functions dealing with data.
 
  We change the behavior of `hg debugwireproto` to enable this mode
  by default. --debug can be added to restore the previous behavior.
 
  As the test changes demonstrate, this makes tests much easier to
  read. As a bonus, it also removes some required (glob) over lengths
  in system call results.
 
  One thing that's lacking is knowing which side sent data. But we can
  fix this in a follow-up once it becomes a problem.

REPOSITORY
  rHG Mercurial

REVISION DETAIL
  https://phab.mercurial-scm.org/D2842

AFFECTED FILES
  mercurial/debugcommands.py
  mercurial/util.py
  tests/test-http-protocol.t

CHANGE DETAILS

diff --git a/tests/test-http-protocol.t b/tests/test-http-protocol.t
--- a/tests/test-http-protocol.t
+++ b/tests/test-http-protocol.t
@@ -175,29 +175,21 @@
   > command listkeys
   >     namespace namespaces
   > EOF
-  s> sendall(*, 0): (glob)
   s>     GET /?cmd=capabilities HTTP/1.1\r\n
   s>     Accept-Encoding: identity\r\n
   s>     accept: application/mercurial-0.1\r\n
   s>     host: $LOCALIP:$HGPORT\r\n (glob)
   s>     user-agent: mercurial/proto-1.0 (Mercurial *)\r\n (glob)
   s>     \r\n
   s> makefile('rb', None)
-  s> readline() -> 36:
   s>     HTTP/1.1 200 Script output follows\r\n
-  s> readline() -> 28:
   s>     Server: testing stub value\r\n
-  s> readline() -> *: (glob)
   s>     Date: $HTTP_DATE$\r\n
-  s> readline() -> 41:
   s>     Content-Type: application/mercurial-0.1\r\n
-  s> readline() -> 21:
   s>     Content-Length: *\r\n (glob)
-  s> readline() -> 2:
   s>     \r\n
-  s> read(*) -> *: lookup branchmap pushkey known getbundle unbundlehash batch changegroupsubset streamreqs=generaldelta,revlogv1 $USUAL_BUNDLE2_CAPS_SERVER$ unbundle=HG10GZ,HG10BZ,HG10UN httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx compression=$BUNDLE2_COMPRESSIONS$ (glob)
+  s>     lookup branchmap pushkey known getbundle unbundlehash batch changegroupsubset streamreqs=generaldelta,revlogv1 $USUAL_BUNDLE2_CAPS_SERVER$ unbundle=HG10GZ,HG10BZ,HG10UN httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx compression=$BUNDLE2_COMPRESSIONS$
   sending listkeys command
-  s> sendall(*, 0): (glob)
   s>     GET /?cmd=listkeys HTTP/1.1\r\n
   s>     Accept-Encoding: identity\r\n
   s>     vary: X-HgArg-1,X-HgProto-1\r\n
@@ -208,19 +200,12 @@
   s>     user-agent: mercurial/proto-1.0 (Mercurial *)\r\n (glob)
   s>     \r\n
   s> makefile('rb', None)
-  s> readline() -> 36:
   s>     HTTP/1.1 200 Script output follows\r\n
-  s> readline() -> 28:
   s>     Server: testing stub value\r\n
-  s> readline() -> *: (glob)
   s>     Date: $HTTP_DATE$\r\n
-  s> readline() -> 41:
   s>     Content-Type: application/mercurial-0.1\r\n
-  s> readline() -> 20:
   s>     Content-Length: 30\r\n
-  s> readline() -> 2:
   s>     \r\n
-  s> read(30) -> 30:
   s>     bookmarks \n
   s>     namespaces \n
   s>     phases
@@ -235,28 +220,20 @@
   >     x-hgarg-1: namespace=namespaces
   > EOF
   using raw connection to peer
-  s> sendall(*, 0): (glob)
   s>     GET /?cmd=listkeys HTTP/1.1\r\n
   s>     Accept-Encoding: identity\r\n
   s>     accept: application/mercurial-0.1\r\n
   s>     user-agent: mercurial/proto-1.0 (Mercurial 42)\r\n (glob)
   s>     x-hgarg-1: namespace=namespaces\r\n
   s>     host: $LOCALIP:$HGPORT\r\n (glob)
   s>     \r\n
   s> makefile('rb', None)
-  s> readline() -> 36:
   s>     HTTP/1.1 200 Script output follows\r\n
-  s> readline() -> 28:
   s>     Server: testing stub value\r\n
-  s> readline() -> *: (glob)
   s>     Date: $HTTP_DATE$\r\n
-  s> readline() -> 41:
   s>     Content-Type: application/mercurial-0.1\r\n
-  s> readline() -> 20:
   s>     Content-Length: 30\r\n
-  s> readline() -> 2:
   s>     \r\n
-  s> read(30) -> 30:
   s>     bookmarks \n
   s>     namespaces \n
   s>     phases
diff --git a/mercurial/util.py b/mercurial/util.py
--- a/mercurial/util.py
+++ b/mercurial/util.py
@@ -755,7 +755,8 @@
         return makeloggingfileobject(observer.fh, res, observer.name,
                                      reads=observer.reads,
                                      writes=observer.writes,
-                                     logdata=observer.logdata)
+                                     logdata=observer.logdata,
+                                     logdataapis=observer.logdataapis)
 
     def recv(self, *args, **kwargs):
         return object.__getattribute__(self, r'_observedcall')(
@@ -818,26 +819,34 @@
 class baseproxyobserver(object):
     def _writedata(self, data):
         if not self.logdata:
-            self.fh.write('\n')
+            if self.logdataapis:
+                self.fh.write('\n')
             return
 
         # Simple case writes all data on a single line.
         if b'\n' not in data:
-            self.fh.write(': %s\n' % escapedata(data))
+            if self.logdataapis:
+                self.fh.write(': %s\n' % escapedata(data))
+            else:
+                self.fh.write('%s>     %s\n' % (self.name, escapedata(data)))
             return
 
         # Data with newlines is written to multiple lines.
-        self.fh.write(':\n')
+        if self.logdataapis:
+            self.fh.write(':\n')
+
         lines = data.splitlines(True)
         for line in lines:
             self.fh.write('%s>     %s\n' % (self.name, escapedata(line)))
 
 class fileobjectobserver(baseproxyobserver):
     """Logs file object activity."""
-    def __init__(self, fh, name, reads=True, writes=True, logdata=False):
+    def __init__(self, fh, name, reads=True, writes=True, logdata=False,
+                 logdataapis=True):
         self.fh = fh
         self.name = name
         self.logdata = logdata
+        self.logdataapis = logdataapis
         self.reads = reads
         self.writes = writes
 
@@ -848,22 +857,28 @@
         if res is None:
             res = ''
 
-        self.fh.write('%s> read(%d) -> %d' % (self.name, size, len(res)))
+        if self.logdataapis:
+            self.fh.write('%s> read(%d) -> %d' % (self.name, size, len(res)))
+
         self._writedata(res)
 
     def readline(self, res, limit=-1):
         if not self.reads:
             return
 
-        self.fh.write('%s> readline() -> %d' % (self.name, len(res)))
+        if self.logdataapis:
+            self.fh.write('%s> readline() -> %d' % (self.name, len(res)))
+
         self._writedata(res)
 
     def readinto(self, res, dest):
         if not self.reads:
             return
 
-        self.fh.write('%s> readinto(%d) -> %r' % (self.name, len(dest),
-                                                  res))
+        if self.logdataapis:
+            self.fh.write('%s> readinto(%d) -> %r' % (self.name, len(dest),
+                                                      res))
+
         data = dest[0:res] if res is not None else b''
         self._writedata(data)
 
@@ -876,7 +891,9 @@
         if res is None and data:
             res = len(data)
 
-        self.fh.write('%s> write(%d) -> %r' % (self.name, len(data), res))
+        if self.logdataapis:
+            self.fh.write('%s> write(%d) -> %r' % (self.name, len(data), res))
+
         self._writedata(data)
 
     def flush(self, res):
@@ -887,32 +904,44 @@
 
     # For observedbufferedinputpipe.
     def bufferedread(self, res, size):
-        self.fh.write('%s> bufferedread(%d) -> %d' % (
-            self.name, size, len(res)))
+        if not self.reads:
+            return
+
+        if self.logdataapis:
+            self.fh.write('%s> bufferedread(%d) -> %d' % (
+                self.name, size, len(res)))
+
         self._writedata(res)
 
     def bufferedreadline(self, res):
-        self.fh.write('%s> bufferedreadline() -> %d' % (self.name, len(res)))
+        if not self.reads:
+            return
+
+        if self.logdataapis:
+            self.fh.write('%s> bufferedreadline() -> %d' % (
+                self.name, len(res)))
+
         self._writedata(res)
 
 def makeloggingfileobject(logh, fh, name, reads=True, writes=True,
-                          logdata=False):
+                          logdata=False, logdataapis=True):
     """Turn a file object into a logging file object."""
 
     observer = fileobjectobserver(logh, name, reads=reads, writes=writes,
-                                  logdata=logdata)
+                                  logdata=logdata, logdataapis=logdataapis)
     return fileobjectproxy(fh, observer)
 
 class socketobserver(baseproxyobserver):
     """Logs socket activity."""
     def __init__(self, fh, name, reads=True, writes=True, states=True,
-                 logdata=False):
+                 logdata=False, logdataapis=True):
         self.fh = fh
         self.name = name
         self.reads = reads
         self.writes = writes
         self.states = states
         self.logdata = logdata
+        self.logdataapis = logdataapis
 
     def makefile(self, res, mode=None, bufsize=None):
         if not self.states:
@@ -925,32 +954,39 @@
         if not self.reads:
             return
 
-        self.fh.write('%s> recv(%d, %d) -> %d' % (
-            self.name, size, flags, len(res)))
+        if self.logdataapis:
+            self.fh.write('%s> recv(%d, %d) -> %d' % (
+                self.name, size, flags, len(res)))
         self._writedata(res)
 
     def recvfrom(self, res, size, flags=0):
         if not self.reads:
             return
 
-        self.fh.write('%s> recvfrom(%d, %d) -> %d' % (
-            self.name, size, flags, len(res[0])))
+        if self.logdataapis:
+            self.fh.write('%s> recvfrom(%d, %d) -> %d' % (
+                self.name, size, flags, len(res[0])))
+
         self._writedata(res[0])
 
     def recvfrom_into(self, res, buf, size, flags=0):
         if not self.reads:
             return
 
-        self.fh.write('%s> recvfrom_into(%d, %d) -> %d' % (
-            self.name, size, flags, res[0]))
+        if self.logdataapis:
+            self.fh.write('%s> recvfrom_into(%d, %d) -> %d' % (
+                self.name, size, flags, res[0]))
+
         self._writedata(buf[0:res[0]])
 
     def recv_into(self, res, buf, size=0, flags=0):
         if not self.reads:
             return
 
-        self.fh.write('%s> recv_into(%d, %d) -> %d' % (
-            self.name, size, flags, res))
+        if self.logdataapis:
+            self.fh.write('%s> recv_into(%d, %d) -> %d' % (
+                self.name, size, flags, res))
+
         self._writedata(buf[0:res])
 
     def send(self, res, data, flags=0):
@@ -965,9 +1001,11 @@
         if not self.writes:
             return
 
-        # Returns None on success. So don't bother reporting return value.
-        self.fh.write('%s> sendall(%d, %d)' % (
-            self.name, len(data), flags))
+        if self.logdataapis:
+            # Returns None on success. So don't bother reporting return value.
+            self.fh.write('%s> sendall(%d, %d)' % (
+                self.name, len(data), flags))
+
         self._writedata(data)
 
     def sendto(self, res, data, flagsoraddress, address=None):
@@ -979,8 +1017,10 @@
         else:
             flags = 0
 
-        self.fh.write('%s> sendto(%d, %d, %r) -> %d' % (
-            self.name, len(data), flags, address, res))
+        if self.logdataapis:
+            self.fh.write('%s> sendto(%d, %d, %r) -> %d' % (
+                self.name, len(data), flags, address, res))
+
         self._writedata(data)
 
     def setblocking(self, res, flag):
@@ -1009,11 +1049,12 @@
             self.name, level, optname, value))
 
 def makeloggingsocket(logh, fh, name, reads=True, writes=True, states=True,
-                      logdata=False):
+                      logdata=False, logdataapis=True):
     """Turn a socket into a logging socket."""
 
     observer = socketobserver(logh, name, reads=reads, writes=writes,
-                              states=states, logdata=logdata)
+                              states=states, logdata=logdata,
+                              logdataapis=logdataapis)
     return socketproxy(fh, observer)
 
 def version():
diff --git a/mercurial/debugcommands.py b/mercurial/debugcommands.py
--- a/mercurial/debugcommands.py
+++ b/mercurial/debugcommands.py
@@ -2825,9 +2825,13 @@
                 r'loggingname': b's',
                 r'loggingopts': {
                     r'logdata': True,
+                    r'logdataapis': False,
                 },
             }
 
+        if ui.debugflag:
+            openerargs[r'loggingopts'][r'logdataapis'] = True
+
         opener = urlmod.opener(ui, authinfo, **openerargs)
 
         if opts['peer'] == 'raw':



To: indygreg, #hg-reviewers
Cc: mercurial-devel
_______________________________________________
Mercurial-devel mailing list
[hidden email]
https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
Reply | Threaded
Open this post in threaded view
|

D2842: util: don't log low-level I/O calls for HTTP peer

indygreg (Gregory Szorc)
indygreg updated this revision to Diff 7008.

REPOSITORY
  rHG Mercurial

CHANGES SINCE LAST UPDATE
  https://phab.mercurial-scm.org/D2842?vs=6996&id=7008

REVISION DETAIL
  https://phab.mercurial-scm.org/D2842

AFFECTED FILES
  mercurial/debugcommands.py
  mercurial/util.py
  tests/test-http-protocol.t

CHANGE DETAILS

diff --git a/tests/test-http-protocol.t b/tests/test-http-protocol.t
--- a/tests/test-http-protocol.t
+++ b/tests/test-http-protocol.t
@@ -175,29 +175,21 @@
   > command listkeys
   >     namespace namespaces
   > EOF
-  s> sendall(*, 0): (glob)
   s>     GET /?cmd=capabilities HTTP/1.1\r\n
   s>     Accept-Encoding: identity\r\n
   s>     accept: application/mercurial-0.1\r\n
   s>     host: $LOCALIP:$HGPORT\r\n (glob)
   s>     user-agent: mercurial/proto-1.0 (Mercurial *)\r\n (glob)
   s>     \r\n
   s> makefile('rb', None)
-  s> readline() -> 36:
   s>     HTTP/1.1 200 Script output follows\r\n
-  s> readline() -> 28:
   s>     Server: testing stub value\r\n
-  s> readline() -> *: (glob)
   s>     Date: $HTTP_DATE$\r\n
-  s> readline() -> 41:
   s>     Content-Type: application/mercurial-0.1\r\n
-  s> readline() -> 21:
   s>     Content-Length: *\r\n (glob)
-  s> readline() -> 2:
   s>     \r\n
-  s> read(*) -> *: lookup branchmap pushkey known getbundle unbundlehash batch changegroupsubset streamreqs=generaldelta,revlogv1 $USUAL_BUNDLE2_CAPS_SERVER$ unbundle=HG10GZ,HG10BZ,HG10UN httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx compression=$BUNDLE2_COMPRESSIONS$ (glob)
+  s>     lookup branchmap pushkey known getbundle unbundlehash batch changegroupsubset streamreqs=generaldelta,revlogv1 $USUAL_BUNDLE2_CAPS_SERVER$ unbundle=HG10GZ,HG10BZ,HG10UN httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx compression=$BUNDLE2_COMPRESSIONS$
   sending listkeys command
-  s> sendall(*, 0): (glob)
   s>     GET /?cmd=listkeys HTTP/1.1\r\n
   s>     Accept-Encoding: identity\r\n
   s>     vary: X-HgArg-1,X-HgProto-1\r\n
@@ -208,19 +200,12 @@
   s>     user-agent: mercurial/proto-1.0 (Mercurial *)\r\n (glob)
   s>     \r\n
   s> makefile('rb', None)
-  s> readline() -> 36:
   s>     HTTP/1.1 200 Script output follows\r\n
-  s> readline() -> 28:
   s>     Server: testing stub value\r\n
-  s> readline() -> *: (glob)
   s>     Date: $HTTP_DATE$\r\n
-  s> readline() -> 41:
   s>     Content-Type: application/mercurial-0.1\r\n
-  s> readline() -> 20:
   s>     Content-Length: 30\r\n
-  s> readline() -> 2:
   s>     \r\n
-  s> read(30) -> 30:
   s>     bookmarks \n
   s>     namespaces \n
   s>     phases
@@ -235,28 +220,20 @@
   >     x-hgarg-1: namespace=namespaces
   > EOF
   using raw connection to peer
-  s> sendall(*, 0): (glob)
   s>     GET /?cmd=listkeys HTTP/1.1\r\n
   s>     Accept-Encoding: identity\r\n
   s>     accept: application/mercurial-0.1\r\n
   s>     user-agent: mercurial/proto-1.0 (Mercurial 42)\r\n (glob)
   s>     x-hgarg-1: namespace=namespaces\r\n
   s>     host: $LOCALIP:$HGPORT\r\n (glob)
   s>     \r\n
   s> makefile('rb', None)
-  s> readline() -> 36:
   s>     HTTP/1.1 200 Script output follows\r\n
-  s> readline() -> 28:
   s>     Server: testing stub value\r\n
-  s> readline() -> *: (glob)
   s>     Date: $HTTP_DATE$\r\n
-  s> readline() -> 41:
   s>     Content-Type: application/mercurial-0.1\r\n
-  s> readline() -> 20:
   s>     Content-Length: 30\r\n
-  s> readline() -> 2:
   s>     \r\n
-  s> read(30) -> 30:
   s>     bookmarks \n
   s>     namespaces \n
   s>     phases
diff --git a/mercurial/util.py b/mercurial/util.py
--- a/mercurial/util.py
+++ b/mercurial/util.py
@@ -760,7 +760,8 @@
         return makeloggingfileobject(observer.fh, res, observer.name,
                                      reads=observer.reads,
                                      writes=observer.writes,
-                                     logdata=observer.logdata)
+                                     logdata=observer.logdata,
+                                     logdataapis=observer.logdataapis)
 
     def recv(self, *args, **kwargs):
         return object.__getattribute__(self, r'_observedcall')(
@@ -823,26 +824,34 @@
 class baseproxyobserver(object):
     def _writedata(self, data):
         if not self.logdata:
-            self.fh.write('\n')
+            if self.logdataapis:
+                self.fh.write('\n')
             return
 
         # Simple case writes all data on a single line.
         if b'\n' not in data:
-            self.fh.write(': %s\n' % escapedata(data))
+            if self.logdataapis:
+                self.fh.write(': %s\n' % escapedata(data))
+            else:
+                self.fh.write('%s>     %s\n' % (self.name, escapedata(data)))
             return
 
         # Data with newlines is written to multiple lines.
-        self.fh.write(':\n')
+        if self.logdataapis:
+            self.fh.write(':\n')
+
         lines = data.splitlines(True)
         for line in lines:
             self.fh.write('%s>     %s\n' % (self.name, escapedata(line)))
 
 class fileobjectobserver(baseproxyobserver):
     """Logs file object activity."""
-    def __init__(self, fh, name, reads=True, writes=True, logdata=False):
+    def __init__(self, fh, name, reads=True, writes=True, logdata=False,
+                 logdataapis=True):
         self.fh = fh
         self.name = name
         self.logdata = logdata
+        self.logdataapis = logdataapis
         self.reads = reads
         self.writes = writes
 
@@ -853,22 +862,28 @@
         if res is None:
             res = ''
 
-        self.fh.write('%s> read(%d) -> %d' % (self.name, size, len(res)))
+        if self.logdataapis:
+            self.fh.write('%s> read(%d) -> %d' % (self.name, size, len(res)))
+
         self._writedata(res)
 
     def readline(self, res, limit=-1):
         if not self.reads:
             return
 
-        self.fh.write('%s> readline() -> %d' % (self.name, len(res)))
+        if self.logdataapis:
+            self.fh.write('%s> readline() -> %d' % (self.name, len(res)))
+
         self._writedata(res)
 
     def readinto(self, res, dest):
         if not self.reads:
             return
 
-        self.fh.write('%s> readinto(%d) -> %r' % (self.name, len(dest),
-                                                  res))
+        if self.logdataapis:
+            self.fh.write('%s> readinto(%d) -> %r' % (self.name, len(dest),
+                                                      res))
+
         data = dest[0:res] if res is not None else b''
         self._writedata(data)
 
@@ -881,7 +896,9 @@
         if res is None and data:
             res = len(data)
 
-        self.fh.write('%s> write(%d) -> %r' % (self.name, len(data), res))
+        if self.logdataapis:
+            self.fh.write('%s> write(%d) -> %r' % (self.name, len(data), res))
+
         self._writedata(data)
 
     def flush(self, res):
@@ -892,32 +909,44 @@
 
     # For observedbufferedinputpipe.
     def bufferedread(self, res, size):
-        self.fh.write('%s> bufferedread(%d) -> %d' % (
-            self.name, size, len(res)))
+        if not self.reads:
+            return
+
+        if self.logdataapis:
+            self.fh.write('%s> bufferedread(%d) -> %d' % (
+                self.name, size, len(res)))
+
         self._writedata(res)
 
     def bufferedreadline(self, res):
-        self.fh.write('%s> bufferedreadline() -> %d' % (self.name, len(res)))
+        if not self.reads:
+            return
+
+        if self.logdataapis:
+            self.fh.write('%s> bufferedreadline() -> %d' % (
+                self.name, len(res)))
+
         self._writedata(res)
 
 def makeloggingfileobject(logh, fh, name, reads=True, writes=True,
-                          logdata=False):
+                          logdata=False, logdataapis=True):
     """Turn a file object into a logging file object."""
 
     observer = fileobjectobserver(logh, name, reads=reads, writes=writes,
-                                  logdata=logdata)
+                                  logdata=logdata, logdataapis=logdataapis)
     return fileobjectproxy(fh, observer)
 
 class socketobserver(baseproxyobserver):
     """Logs socket activity."""
     def __init__(self, fh, name, reads=True, writes=True, states=True,
-                 logdata=False):
+                 logdata=False, logdataapis=True):
         self.fh = fh
         self.name = name
         self.reads = reads
         self.writes = writes
         self.states = states
         self.logdata = logdata
+        self.logdataapis = logdataapis
 
     def makefile(self, res, mode=None, bufsize=None):
         if not self.states:
@@ -930,32 +959,39 @@
         if not self.reads:
             return
 
-        self.fh.write('%s> recv(%d, %d) -> %d' % (
-            self.name, size, flags, len(res)))
+        if self.logdataapis:
+            self.fh.write('%s> recv(%d, %d) -> %d' % (
+                self.name, size, flags, len(res)))
         self._writedata(res)
 
     def recvfrom(self, res, size, flags=0):
         if not self.reads:
             return
 
-        self.fh.write('%s> recvfrom(%d, %d) -> %d' % (
-            self.name, size, flags, len(res[0])))
+        if self.logdataapis:
+            self.fh.write('%s> recvfrom(%d, %d) -> %d' % (
+                self.name, size, flags, len(res[0])))
+
         self._writedata(res[0])
 
     def recvfrom_into(self, res, buf, size, flags=0):
         if not self.reads:
             return
 
-        self.fh.write('%s> recvfrom_into(%d, %d) -> %d' % (
-            self.name, size, flags, res[0]))
+        if self.logdataapis:
+            self.fh.write('%s> recvfrom_into(%d, %d) -> %d' % (
+                self.name, size, flags, res[0]))
+
         self._writedata(buf[0:res[0]])
 
     def recv_into(self, res, buf, size=0, flags=0):
         if not self.reads:
             return
 
-        self.fh.write('%s> recv_into(%d, %d) -> %d' % (
-            self.name, size, flags, res))
+        if self.logdataapis:
+            self.fh.write('%s> recv_into(%d, %d) -> %d' % (
+                self.name, size, flags, res))
+
         self._writedata(buf[0:res])
 
     def send(self, res, data, flags=0):
@@ -970,9 +1006,11 @@
         if not self.writes:
             return
 
-        # Returns None on success. So don't bother reporting return value.
-        self.fh.write('%s> sendall(%d, %d)' % (
-            self.name, len(data), flags))
+        if self.logdataapis:
+            # Returns None on success. So don't bother reporting return value.
+            self.fh.write('%s> sendall(%d, %d)' % (
+                self.name, len(data), flags))
+
         self._writedata(data)
 
     def sendto(self, res, data, flagsoraddress, address=None):
@@ -984,8 +1022,10 @@
         else:
             flags = 0
 
-        self.fh.write('%s> sendto(%d, %d, %r) -> %d' % (
-            self.name, len(data), flags, address, res))
+        if self.logdataapis:
+            self.fh.write('%s> sendto(%d, %d, %r) -> %d' % (
+                self.name, len(data), flags, address, res))
+
         self._writedata(data)
 
     def setblocking(self, res, flag):
@@ -1014,11 +1054,12 @@
             self.name, level, optname, value))
 
 def makeloggingsocket(logh, fh, name, reads=True, writes=True, states=True,
-                      logdata=False):
+                      logdata=False, logdataapis=True):
     """Turn a socket into a logging socket."""
 
     observer = socketobserver(logh, name, reads=reads, writes=writes,
-                              states=states, logdata=logdata)
+                              states=states, logdata=logdata,
+                              logdataapis=logdataapis)
     return socketproxy(fh, observer)
 
 def version():
diff --git a/mercurial/debugcommands.py b/mercurial/debugcommands.py
--- a/mercurial/debugcommands.py
+++ b/mercurial/debugcommands.py
@@ -2825,9 +2825,13 @@
                 r'loggingname': b's',
                 r'loggingopts': {
                     r'logdata': True,
+                    r'logdataapis': False,
                 },
             }
 
+        if ui.debugflag:
+            openerargs[r'loggingopts'][r'logdataapis'] = True
+
         opener = urlmod.opener(ui, authinfo, **openerargs)
 
         if opts['peer'] == 'raw':



To: indygreg, #hg-reviewers
Cc: mercurial-devel
_______________________________________________
Mercurial-devel mailing list
[hidden email]
https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
Reply | Threaded
Open this post in threaded view
|

D2842: util: don't log low-level I/O calls for HTTP peer

indygreg (Gregory Szorc)
In reply to this post by indygreg (Gregory Szorc)
durin42 accepted this revision.
durin42 added a comment.
This revision is now accepted and ready to land.


  This one needs rebased, but looks good.

REPOSITORY
  rHG Mercurial

REVISION DETAIL
  https://phab.mercurial-scm.org/D2842

To: indygreg, #hg-reviewers, durin42
Cc: durin42, mercurial-devel
_______________________________________________
Mercurial-devel mailing list
[hidden email]
https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
Reply | Threaded
Open this post in threaded view
|

D2842: util: don't log low-level I/O calls for HTTP peer

indygreg (Gregory Szorc)
In reply to this post by indygreg (Gregory Szorc)
indygreg updated this revision to Diff 7161.

REPOSITORY
  rHG Mercurial

CHANGES SINCE LAST UPDATE
  https://phab.mercurial-scm.org/D2842?vs=7008&id=7161

REVISION DETAIL
  https://phab.mercurial-scm.org/D2842

AFFECTED FILES
  mercurial/debugcommands.py
  mercurial/util.py
  tests/test-http-protocol.t

CHANGE DETAILS

diff --git a/tests/test-http-protocol.t b/tests/test-http-protocol.t
--- a/tests/test-http-protocol.t
+++ b/tests/test-http-protocol.t
@@ -175,29 +175,21 @@
   > command listkeys
   >     namespace namespaces
   > EOF
-  s> sendall(*, 0): (glob)
   s>     GET /?cmd=capabilities HTTP/1.1\r\n
   s>     Accept-Encoding: identity\r\n
   s>     accept: application/mercurial-0.1\r\n
   s>     host: $LOCALIP:$HGPORT\r\n (glob)
   s>     user-agent: mercurial/proto-1.0 (Mercurial *)\r\n (glob)
   s>     \r\n
   s> makefile('rb', None)
-  s> readline() -> 36:
   s>     HTTP/1.1 200 Script output follows\r\n
-  s> readline() -> 28:
   s>     Server: testing stub value\r\n
-  s> readline() -> *: (glob)
   s>     Date: $HTTP_DATE$\r\n
-  s> readline() -> 41:
   s>     Content-Type: application/mercurial-0.1\r\n
-  s> readline() -> 21:
   s>     Content-Length: *\r\n (glob)
-  s> readline() -> 2:
   s>     \r\n
-  s> read(*) -> *: lookup branchmap pushkey known getbundle unbundlehash batch changegroupsubset streamreqs=generaldelta,revlogv1 $USUAL_BUNDLE2_CAPS_SERVER$ unbundle=HG10GZ,HG10BZ,HG10UN httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx compression=$BUNDLE2_COMPRESSIONS$ (glob)
+  s>     lookup branchmap pushkey known getbundle unbundlehash batch changegroupsubset streamreqs=generaldelta,revlogv1 $USUAL_BUNDLE2_CAPS_SERVER$ unbundle=HG10GZ,HG10BZ,HG10UN httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx compression=$BUNDLE2_COMPRESSIONS$
   sending listkeys command
-  s> sendall(*, 0): (glob)
   s>     GET /?cmd=listkeys HTTP/1.1\r\n
   s>     Accept-Encoding: identity\r\n
   s>     vary: X-HgArg-1,X-HgProto-1\r\n
@@ -208,19 +200,12 @@
   s>     user-agent: mercurial/proto-1.0 (Mercurial *)\r\n (glob)
   s>     \r\n
   s> makefile('rb', None)
-  s> readline() -> 36:
   s>     HTTP/1.1 200 Script output follows\r\n
-  s> readline() -> 28:
   s>     Server: testing stub value\r\n
-  s> readline() -> *: (glob)
   s>     Date: $HTTP_DATE$\r\n
-  s> readline() -> 41:
   s>     Content-Type: application/mercurial-0.1\r\n
-  s> readline() -> 20:
   s>     Content-Length: 30\r\n
-  s> readline() -> 2:
   s>     \r\n
-  s> read(30) -> 30:
   s>     bookmarks \n
   s>     namespaces \n
   s>     phases
@@ -235,28 +220,20 @@
   >     x-hgarg-1: namespace=namespaces
   > EOF
   using raw connection to peer
-  s> sendall(*, 0): (glob)
   s>     GET /?cmd=listkeys HTTP/1.1\r\n
   s>     Accept-Encoding: identity\r\n
   s>     accept: application/mercurial-0.1\r\n
   s>     user-agent: mercurial/proto-1.0 (Mercurial 42)\r\n (glob)
   s>     x-hgarg-1: namespace=namespaces\r\n
   s>     host: $LOCALIP:$HGPORT\r\n (glob)
   s>     \r\n
   s> makefile('rb', None)
-  s> readline() -> 36:
   s>     HTTP/1.1 200 Script output follows\r\n
-  s> readline() -> 28:
   s>     Server: testing stub value\r\n
-  s> readline() -> *: (glob)
   s>     Date: $HTTP_DATE$\r\n
-  s> readline() -> 41:
   s>     Content-Type: application/mercurial-0.1\r\n
-  s> readline() -> 20:
   s>     Content-Length: 30\r\n
-  s> readline() -> 2:
   s>     \r\n
-  s> read(30) -> 30:
   s>     bookmarks \n
   s>     namespaces \n
   s>     phases
diff --git a/mercurial/util.py b/mercurial/util.py
--- a/mercurial/util.py
+++ b/mercurial/util.py
@@ -762,7 +762,8 @@
         return makeloggingfileobject(observer.fh, res, observer.name,
                                      reads=observer.reads,
                                      writes=observer.writes,
-                                     logdata=observer.logdata)
+                                     logdata=observer.logdata,
+                                     logdataapis=observer.logdataapis)
 
     def recv(self, *args, **kwargs):
         return object.__getattribute__(self, r'_observedcall')(
@@ -825,29 +826,37 @@
 class baseproxyobserver(object):
     def _writedata(self, data):
         if not self.logdata:
-            self.fh.write('\n')
-            self.fh.flush()
+            if self.logdataapis:
+                self.fh.write('\n')
+                self.fh.flush()
             return
 
         # Simple case writes all data on a single line.
         if b'\n' not in data:
-            self.fh.write(': %s\n' % escapedata(data))
+            if self.logdataapis:
+                self.fh.write(': %s\n' % escapedata(data))
+            else:
+                self.fh.write('%s>     %s\n' % (self.name, escapedata(data)))
             self.fh.flush()
             return
 
         # Data with newlines is written to multiple lines.
-        self.fh.write(':\n')
+        if self.logdataapis:
+            self.fh.write(':\n')
+
         lines = data.splitlines(True)
         for line in lines:
             self.fh.write('%s>     %s\n' % (self.name, escapedata(line)))
         self.fh.flush()
 
 class fileobjectobserver(baseproxyobserver):
     """Logs file object activity."""
-    def __init__(self, fh, name, reads=True, writes=True, logdata=False):
+    def __init__(self, fh, name, reads=True, writes=True, logdata=False,
+                 logdataapis=True):
         self.fh = fh
         self.name = name
         self.logdata = logdata
+        self.logdataapis = logdataapis
         self.reads = reads
         self.writes = writes
 
@@ -858,22 +867,28 @@
         if res is None:
             res = ''
 
-        self.fh.write('%s> read(%d) -> %d' % (self.name, size, len(res)))
+        if self.logdataapis:
+            self.fh.write('%s> read(%d) -> %d' % (self.name, size, len(res)))
+
         self._writedata(res)
 
     def readline(self, res, limit=-1):
         if not self.reads:
             return
 
-        self.fh.write('%s> readline() -> %d' % (self.name, len(res)))
+        if self.logdataapis:
+            self.fh.write('%s> readline() -> %d' % (self.name, len(res)))
+
         self._writedata(res)
 
     def readinto(self, res, dest):
         if not self.reads:
             return
 
-        self.fh.write('%s> readinto(%d) -> %r' % (self.name, len(dest),
-                                                  res))
+        if self.logdataapis:
+            self.fh.write('%s> readinto(%d) -> %r' % (self.name, len(dest),
+                                                      res))
+
         data = dest[0:res] if res is not None else b''
         self._writedata(data)
 
@@ -886,7 +901,9 @@
         if res is None and data:
             res = len(data)
 
-        self.fh.write('%s> write(%d) -> %r' % (self.name, len(data), res))
+        if self.logdataapis:
+            self.fh.write('%s> write(%d) -> %r' % (self.name, len(data), res))
+
         self._writedata(data)
 
     def flush(self, res):
@@ -897,32 +914,44 @@
 
     # For observedbufferedinputpipe.
     def bufferedread(self, res, size):
-        self.fh.write('%s> bufferedread(%d) -> %d' % (
-            self.name, size, len(res)))
+        if not self.reads:
+            return
+
+        if self.logdataapis:
+            self.fh.write('%s> bufferedread(%d) -> %d' % (
+                self.name, size, len(res)))
+
         self._writedata(res)
 
     def bufferedreadline(self, res):
-        self.fh.write('%s> bufferedreadline() -> %d' % (self.name, len(res)))
+        if not self.reads:
+            return
+
+        if self.logdataapis:
+            self.fh.write('%s> bufferedreadline() -> %d' % (
+                self.name, len(res)))
+
         self._writedata(res)
 
 def makeloggingfileobject(logh, fh, name, reads=True, writes=True,
-                          logdata=False):
+                          logdata=False, logdataapis=True):
     """Turn a file object into a logging file object."""
 
     observer = fileobjectobserver(logh, name, reads=reads, writes=writes,
-                                  logdata=logdata)
+                                  logdata=logdata, logdataapis=logdataapis)
     return fileobjectproxy(fh, observer)
 
 class socketobserver(baseproxyobserver):
     """Logs socket activity."""
     def __init__(self, fh, name, reads=True, writes=True, states=True,
-                 logdata=False):
+                 logdata=False, logdataapis=True):
         self.fh = fh
         self.name = name
         self.reads = reads
         self.writes = writes
         self.states = states
         self.logdata = logdata
+        self.logdataapis = logdataapis
 
     def makefile(self, res, mode=None, bufsize=None):
         if not self.states:
@@ -935,32 +964,39 @@
         if not self.reads:
             return
 
-        self.fh.write('%s> recv(%d, %d) -> %d' % (
-            self.name, size, flags, len(res)))
+        if self.logdataapis:
+            self.fh.write('%s> recv(%d, %d) -> %d' % (
+                self.name, size, flags, len(res)))
         self._writedata(res)
 
     def recvfrom(self, res, size, flags=0):
         if not self.reads:
             return
 
-        self.fh.write('%s> recvfrom(%d, %d) -> %d' % (
-            self.name, size, flags, len(res[0])))
+        if self.logdataapis:
+            self.fh.write('%s> recvfrom(%d, %d) -> %d' % (
+                self.name, size, flags, len(res[0])))
+
         self._writedata(res[0])
 
     def recvfrom_into(self, res, buf, size, flags=0):
         if not self.reads:
             return
 
-        self.fh.write('%s> recvfrom_into(%d, %d) -> %d' % (
-            self.name, size, flags, res[0]))
+        if self.logdataapis:
+            self.fh.write('%s> recvfrom_into(%d, %d) -> %d' % (
+                self.name, size, flags, res[0]))
+
         self._writedata(buf[0:res[0]])
 
     def recv_into(self, res, buf, size=0, flags=0):
         if not self.reads:
             return
 
-        self.fh.write('%s> recv_into(%d, %d) -> %d' % (
-            self.name, size, flags, res))
+        if self.logdataapis:
+            self.fh.write('%s> recv_into(%d, %d) -> %d' % (
+                self.name, size, flags, res))
+
         self._writedata(buf[0:res])
 
     def send(self, res, data, flags=0):
@@ -975,9 +1011,11 @@
         if not self.writes:
             return
 
-        # Returns None on success. So don't bother reporting return value.
-        self.fh.write('%s> sendall(%d, %d)' % (
-            self.name, len(data), flags))
+        if self.logdataapis:
+            # Returns None on success. So don't bother reporting return value.
+            self.fh.write('%s> sendall(%d, %d)' % (
+                self.name, len(data), flags))
+
         self._writedata(data)
 
     def sendto(self, res, data, flagsoraddress, address=None):
@@ -989,8 +1027,10 @@
         else:
             flags = 0
 
-        self.fh.write('%s> sendto(%d, %d, %r) -> %d' % (
-            self.name, len(data), flags, address, res))
+        if self.logdataapis:
+            self.fh.write('%s> sendto(%d, %d, %r) -> %d' % (
+                self.name, len(data), flags, address, res))
+
         self._writedata(data)
 
     def setblocking(self, res, flag):
@@ -1019,11 +1059,12 @@
             self.name, level, optname, value))
 
 def makeloggingsocket(logh, fh, name, reads=True, writes=True, states=True,
-                      logdata=False):
+                      logdata=False, logdataapis=True):
     """Turn a socket into a logging socket."""
 
     observer = socketobserver(logh, name, reads=reads, writes=writes,
-                              states=states, logdata=logdata)
+                              states=states, logdata=logdata,
+                              logdataapis=logdataapis)
     return socketproxy(fh, observer)
 
 def version():
diff --git a/mercurial/debugcommands.py b/mercurial/debugcommands.py
--- a/mercurial/debugcommands.py
+++ b/mercurial/debugcommands.py
@@ -2839,9 +2839,13 @@
                 r'loggingname': b's',
                 r'loggingopts': {
                     r'logdata': True,
+                    r'logdataapis': False,
                 },
             }
 
+        if ui.debugflag:
+            openerargs[r'loggingopts'][r'logdataapis'] = True
+
         opener = urlmod.opener(ui, authinfo, **openerargs)
 
         if opts['peer'] == 'raw':



To: indygreg, #hg-reviewers, durin42
Cc: durin42, mercurial-devel
_______________________________________________
Mercurial-devel mailing list
[hidden email]
https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
Reply | Threaded
Open this post in threaded view
|

D2842: util: don't log low-level I/O calls for HTTP peer

indygreg (Gregory Szorc)
In reply to this post by indygreg (Gregory Szorc)
indygreg updated this revision to Diff 7192.

REPOSITORY
  rHG Mercurial

CHANGES SINCE LAST UPDATE
  https://phab.mercurial-scm.org/D2842?vs=7161&id=7192

REVISION DETAIL
  https://phab.mercurial-scm.org/D2842

AFFECTED FILES
  mercurial/debugcommands.py
  mercurial/util.py
  tests/test-http-protocol.t

CHANGE DETAILS

diff --git a/tests/test-http-protocol.t b/tests/test-http-protocol.t
--- a/tests/test-http-protocol.t
+++ b/tests/test-http-protocol.t
@@ -175,29 +175,21 @@
   > command listkeys
   >     namespace namespaces
   > EOF
-  s> sendall(*, 0): (glob)
   s>     GET /?cmd=capabilities HTTP/1.1\r\n
   s>     Accept-Encoding: identity\r\n
   s>     accept: application/mercurial-0.1\r\n
   s>     host: $LOCALIP:$HGPORT\r\n (glob)
   s>     user-agent: mercurial/proto-1.0 (Mercurial *)\r\n (glob)
   s>     \r\n
   s> makefile('rb', None)
-  s> readline() -> 36:
   s>     HTTP/1.1 200 Script output follows\r\n
-  s> readline() -> 28:
   s>     Server: testing stub value\r\n
-  s> readline() -> *: (glob)
   s>     Date: $HTTP_DATE$\r\n
-  s> readline() -> 41:
   s>     Content-Type: application/mercurial-0.1\r\n
-  s> readline() -> 21:
   s>     Content-Length: *\r\n (glob)
-  s> readline() -> 2:
   s>     \r\n
-  s> read(*) -> *: lookup branchmap pushkey known getbundle unbundlehash batch changegroupsubset streamreqs=generaldelta,revlogv1 $USUAL_BUNDLE2_CAPS_SERVER$ unbundle=HG10GZ,HG10BZ,HG10UN httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx compression=$BUNDLE2_COMPRESSIONS$ (glob)
+  s>     lookup branchmap pushkey known getbundle unbundlehash batch changegroupsubset streamreqs=generaldelta,revlogv1 $USUAL_BUNDLE2_CAPS_SERVER$ unbundle=HG10GZ,HG10BZ,HG10UN httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx compression=$BUNDLE2_COMPRESSIONS$
   sending listkeys command
-  s> sendall(*, 0): (glob)
   s>     GET /?cmd=listkeys HTTP/1.1\r\n
   s>     Accept-Encoding: identity\r\n
   s>     vary: X-HgArg-1,X-HgProto-1\r\n
@@ -208,19 +200,12 @@
   s>     user-agent: mercurial/proto-1.0 (Mercurial *)\r\n (glob)
   s>     \r\n
   s> makefile('rb', None)
-  s> readline() -> 36:
   s>     HTTP/1.1 200 Script output follows\r\n
-  s> readline() -> 28:
   s>     Server: testing stub value\r\n
-  s> readline() -> *: (glob)
   s>     Date: $HTTP_DATE$\r\n
-  s> readline() -> 41:
   s>     Content-Type: application/mercurial-0.1\r\n
-  s> readline() -> 20:
   s>     Content-Length: 30\r\n
-  s> readline() -> 2:
   s>     \r\n
-  s> read(30) -> 30:
   s>     bookmarks \n
   s>     namespaces \n
   s>     phases
@@ -235,28 +220,20 @@
   >     x-hgarg-1: namespace=namespaces
   > EOF
   using raw connection to peer
-  s> sendall(*, 0): (glob)
   s>     GET /?cmd=listkeys HTTP/1.1\r\n
   s>     Accept-Encoding: identity\r\n
   s>     accept: application/mercurial-0.1\r\n
   s>     user-agent: mercurial/proto-1.0 (Mercurial 42)\r\n
   s>     x-hgarg-1: namespace=namespaces\r\n
   s>     host: $LOCALIP:$HGPORT\r\n (glob)
   s>     \r\n
   s> makefile('rb', None)
-  s> readline() -> 36:
   s>     HTTP/1.1 200 Script output follows\r\n
-  s> readline() -> 28:
   s>     Server: testing stub value\r\n
-  s> readline() -> *: (glob)
   s>     Date: $HTTP_DATE$\r\n
-  s> readline() -> 41:
   s>     Content-Type: application/mercurial-0.1\r\n
-  s> readline() -> 20:
   s>     Content-Length: 30\r\n
-  s> readline() -> 2:
   s>     \r\n
-  s> read(30) -> 30:
   s>     bookmarks \n
   s>     namespaces \n
   s>     phases
diff --git a/mercurial/util.py b/mercurial/util.py
--- a/mercurial/util.py
+++ b/mercurial/util.py
@@ -762,7 +762,8 @@
         return makeloggingfileobject(observer.fh, res, observer.name,
                                      reads=observer.reads,
                                      writes=observer.writes,
-                                     logdata=observer.logdata)
+                                     logdata=observer.logdata,
+                                     logdataapis=observer.logdataapis)
 
     def recv(self, *args, **kwargs):
         return object.__getattribute__(self, r'_observedcall')(
@@ -825,29 +826,37 @@
 class baseproxyobserver(object):
     def _writedata(self, data):
         if not self.logdata:
-            self.fh.write('\n')
-            self.fh.flush()
+            if self.logdataapis:
+                self.fh.write('\n')
+                self.fh.flush()
             return
 
         # Simple case writes all data on a single line.
         if b'\n' not in data:
-            self.fh.write(': %s\n' % escapedata(data))
+            if self.logdataapis:
+                self.fh.write(': %s\n' % escapedata(data))
+            else:
+                self.fh.write('%s>     %s\n' % (self.name, escapedata(data)))
             self.fh.flush()
             return
 
         # Data with newlines is written to multiple lines.
-        self.fh.write(':\n')
+        if self.logdataapis:
+            self.fh.write(':\n')
+
         lines = data.splitlines(True)
         for line in lines:
             self.fh.write('%s>     %s\n' % (self.name, escapedata(line)))
         self.fh.flush()
 
 class fileobjectobserver(baseproxyobserver):
     """Logs file object activity."""
-    def __init__(self, fh, name, reads=True, writes=True, logdata=False):
+    def __init__(self, fh, name, reads=True, writes=True, logdata=False,
+                 logdataapis=True):
         self.fh = fh
         self.name = name
         self.logdata = logdata
+        self.logdataapis = logdataapis
         self.reads = reads
         self.writes = writes
 
@@ -858,22 +867,28 @@
         if res is None:
             res = ''
 
-        self.fh.write('%s> read(%d) -> %d' % (self.name, size, len(res)))
+        if self.logdataapis:
+            self.fh.write('%s> read(%d) -> %d' % (self.name, size, len(res)))
+
         self._writedata(res)
 
     def readline(self, res, limit=-1):
         if not self.reads:
             return
 
-        self.fh.write('%s> readline() -> %d' % (self.name, len(res)))
+        if self.logdataapis:
+            self.fh.write('%s> readline() -> %d' % (self.name, len(res)))
+
         self._writedata(res)
 
     def readinto(self, res, dest):
         if not self.reads:
             return
 
-        self.fh.write('%s> readinto(%d) -> %r' % (self.name, len(dest),
-                                                  res))
+        if self.logdataapis:
+            self.fh.write('%s> readinto(%d) -> %r' % (self.name, len(dest),
+                                                      res))
+
         data = dest[0:res] if res is not None else b''
         self._writedata(data)
 
@@ -886,7 +901,9 @@
         if res is None and data:
             res = len(data)
 
-        self.fh.write('%s> write(%d) -> %r' % (self.name, len(data), res))
+        if self.logdataapis:
+            self.fh.write('%s> write(%d) -> %r' % (self.name, len(data), res))
+
         self._writedata(data)
 
     def flush(self, res):
@@ -897,32 +914,44 @@
 
     # For observedbufferedinputpipe.
     def bufferedread(self, res, size):
-        self.fh.write('%s> bufferedread(%d) -> %d' % (
-            self.name, size, len(res)))
+        if not self.reads:
+            return
+
+        if self.logdataapis:
+            self.fh.write('%s> bufferedread(%d) -> %d' % (
+                self.name, size, len(res)))
+
         self._writedata(res)
 
     def bufferedreadline(self, res):
-        self.fh.write('%s> bufferedreadline() -> %d' % (self.name, len(res)))
+        if not self.reads:
+            return
+
+        if self.logdataapis:
+            self.fh.write('%s> bufferedreadline() -> %d' % (
+                self.name, len(res)))
+
         self._writedata(res)
 
 def makeloggingfileobject(logh, fh, name, reads=True, writes=True,
-                          logdata=False):
+                          logdata=False, logdataapis=True):
     """Turn a file object into a logging file object."""
 
     observer = fileobjectobserver(logh, name, reads=reads, writes=writes,
-                                  logdata=logdata)
+                                  logdata=logdata, logdataapis=logdataapis)
     return fileobjectproxy(fh, observer)
 
 class socketobserver(baseproxyobserver):
     """Logs socket activity."""
     def __init__(self, fh, name, reads=True, writes=True, states=True,
-                 logdata=False):
+                 logdata=False, logdataapis=True):
         self.fh = fh
         self.name = name
         self.reads = reads
         self.writes = writes
         self.states = states
         self.logdata = logdata
+        self.logdataapis = logdataapis
 
     def makefile(self, res, mode=None, bufsize=None):
         if not self.states:
@@ -935,32 +964,39 @@
         if not self.reads:
             return
 
-        self.fh.write('%s> recv(%d, %d) -> %d' % (
-            self.name, size, flags, len(res)))
+        if self.logdataapis:
+            self.fh.write('%s> recv(%d, %d) -> %d' % (
+                self.name, size, flags, len(res)))
         self._writedata(res)
 
     def recvfrom(self, res, size, flags=0):
         if not self.reads:
             return
 
-        self.fh.write('%s> recvfrom(%d, %d) -> %d' % (
-            self.name, size, flags, len(res[0])))
+        if self.logdataapis:
+            self.fh.write('%s> recvfrom(%d, %d) -> %d' % (
+                self.name, size, flags, len(res[0])))
+
         self._writedata(res[0])
 
     def recvfrom_into(self, res, buf, size, flags=0):
         if not self.reads:
             return
 
-        self.fh.write('%s> recvfrom_into(%d, %d) -> %d' % (
-            self.name, size, flags, res[0]))
+        if self.logdataapis:
+            self.fh.write('%s> recvfrom_into(%d, %d) -> %d' % (
+                self.name, size, flags, res[0]))
+
         self._writedata(buf[0:res[0]])
 
     def recv_into(self, res, buf, size=0, flags=0):
         if not self.reads:
             return
 
-        self.fh.write('%s> recv_into(%d, %d) -> %d' % (
-            self.name, size, flags, res))
+        if self.logdataapis:
+            self.fh.write('%s> recv_into(%d, %d) -> %d' % (
+                self.name, size, flags, res))
+
         self._writedata(buf[0:res])
 
     def send(self, res, data, flags=0):
@@ -975,9 +1011,11 @@
         if not self.writes:
             return
 
-        # Returns None on success. So don't bother reporting return value.
-        self.fh.write('%s> sendall(%d, %d)' % (
-            self.name, len(data), flags))
+        if self.logdataapis:
+            # Returns None on success. So don't bother reporting return value.
+            self.fh.write('%s> sendall(%d, %d)' % (
+                self.name, len(data), flags))
+
         self._writedata(data)
 
     def sendto(self, res, data, flagsoraddress, address=None):
@@ -989,8 +1027,10 @@
         else:
             flags = 0
 
-        self.fh.write('%s> sendto(%d, %d, %r) -> %d' % (
-            self.name, len(data), flags, address, res))
+        if self.logdataapis:
+            self.fh.write('%s> sendto(%d, %d, %r) -> %d' % (
+                self.name, len(data), flags, address, res))
+
         self._writedata(data)
 
     def setblocking(self, res, flag):
@@ -1019,11 +1059,12 @@
             self.name, level, optname, value))
 
 def makeloggingsocket(logh, fh, name, reads=True, writes=True, states=True,
-                      logdata=False):
+                      logdata=False, logdataapis=True):
     """Turn a socket into a logging socket."""
 
     observer = socketobserver(logh, name, reads=reads, writes=writes,
-                              states=states, logdata=logdata)
+                              states=states, logdata=logdata,
+                              logdataapis=logdataapis)
     return socketproxy(fh, observer)
 
 def version():
diff --git a/mercurial/debugcommands.py b/mercurial/debugcommands.py
--- a/mercurial/debugcommands.py
+++ b/mercurial/debugcommands.py
@@ -2839,9 +2839,13 @@
                 r'loggingname': b's',
                 r'loggingopts': {
                     r'logdata': True,
+                    r'logdataapis': False,
                 },
             }
 
+        if ui.debugflag:
+            openerargs[r'loggingopts'][r'logdataapis'] = True
+
         opener = urlmod.opener(ui, authinfo, **openerargs)
 
         if opts['peer'] == 'raw':



To: indygreg, #hg-reviewers, durin42
Cc: durin42, mercurial-devel
_______________________________________________
Mercurial-devel mailing list
[hidden email]
https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel
Reply | Threaded
Open this post in threaded view
|

D2842: util: don't log low-level I/O calls for HTTP peer

indygreg (Gregory Szorc)
In reply to this post by indygreg (Gregory Szorc)
This revision was automatically updated to reflect the committed changes.
Closed by commit rHGd3a9036d9ae9: util: don't log low-level I/O calls for HTTP peer (authored by indygreg, committed by ).

REPOSITORY
  rHG Mercurial

CHANGES SINCE LAST UPDATE
  https://phab.mercurial-scm.org/D2842?vs=7192&id=7220

REVISION DETAIL
  https://phab.mercurial-scm.org/D2842

AFFECTED FILES
  mercurial/debugcommands.py
  mercurial/util.py
  tests/test-http-protocol.t

CHANGE DETAILS

diff --git a/tests/test-http-protocol.t b/tests/test-http-protocol.t
--- a/tests/test-http-protocol.t
+++ b/tests/test-http-protocol.t
@@ -175,29 +175,21 @@
   > command listkeys
   >     namespace namespaces
   > EOF
-  s> sendall(*, 0): (glob)
   s>     GET /?cmd=capabilities HTTP/1.1\r\n
   s>     Accept-Encoding: identity\r\n
   s>     accept: application/mercurial-0.1\r\n
   s>     host: $LOCALIP:$HGPORT\r\n (glob)
   s>     user-agent: mercurial/proto-1.0 (Mercurial *)\r\n (glob)
   s>     \r\n
   s> makefile('rb', None)
-  s> readline() -> 36:
   s>     HTTP/1.1 200 Script output follows\r\n
-  s> readline() -> 28:
   s>     Server: testing stub value\r\n
-  s> readline() -> *: (glob)
   s>     Date: $HTTP_DATE$\r\n
-  s> readline() -> 41:
   s>     Content-Type: application/mercurial-0.1\r\n
-  s> readline() -> 21:
   s>     Content-Length: *\r\n (glob)
-  s> readline() -> 2:
   s>     \r\n
-  s> read(*) -> *: lookup branchmap pushkey known getbundle unbundlehash batch changegroupsubset streamreqs=generaldelta,revlogv1 $USUAL_BUNDLE2_CAPS_SERVER$ unbundle=HG10GZ,HG10BZ,HG10UN httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx compression=$BUNDLE2_COMPRESSIONS$ (glob)
+  s>     lookup branchmap pushkey known getbundle unbundlehash batch changegroupsubset streamreqs=generaldelta,revlogv1 $USUAL_BUNDLE2_CAPS_SERVER$ unbundle=HG10GZ,HG10BZ,HG10UN httpheader=1024 httpmediatype=0.1rx,0.1tx,0.2tx compression=$BUNDLE2_COMPRESSIONS$
   sending listkeys command
-  s> sendall(*, 0): (glob)
   s>     GET /?cmd=listkeys HTTP/1.1\r\n
   s>     Accept-Encoding: identity\r\n
   s>     vary: X-HgArg-1,X-HgProto-1\r\n
@@ -208,19 +200,12 @@
   s>     user-agent: mercurial/proto-1.0 (Mercurial *)\r\n (glob)
   s>     \r\n
   s> makefile('rb', None)
-  s> readline() -> 36:
   s>     HTTP/1.1 200 Script output follows\r\n
-  s> readline() -> 28:
   s>     Server: testing stub value\r\n
-  s> readline() -> *: (glob)
   s>     Date: $HTTP_DATE$\r\n
-  s> readline() -> 41:
   s>     Content-Type: application/mercurial-0.1\r\n
-  s> readline() -> 20:
   s>     Content-Length: 30\r\n
-  s> readline() -> 2:
   s>     \r\n
-  s> read(30) -> 30:
   s>     bookmarks \n
   s>     namespaces \n
   s>     phases
@@ -235,28 +220,20 @@
   >     x-hgarg-1: namespace=namespaces
   > EOF
   using raw connection to peer
-  s> sendall(*, 0): (glob)
   s>     GET /?cmd=listkeys HTTP/1.1\r\n
   s>     Accept-Encoding: identity\r\n
   s>     accept: application/mercurial-0.1\r\n
   s>     user-agent: mercurial/proto-1.0 (Mercurial 42)\r\n
   s>     x-hgarg-1: namespace=namespaces\r\n
   s>     host: $LOCALIP:$HGPORT\r\n (glob)
   s>     \r\n
   s> makefile('rb', None)
-  s> readline() -> 36:
   s>     HTTP/1.1 200 Script output follows\r\n
-  s> readline() -> 28:
   s>     Server: testing stub value\r\n
-  s> readline() -> *: (glob)
   s>     Date: $HTTP_DATE$\r\n
-  s> readline() -> 41:
   s>     Content-Type: application/mercurial-0.1\r\n
-  s> readline() -> 20:
   s>     Content-Length: 30\r\n
-  s> readline() -> 2:
   s>     \r\n
-  s> read(30) -> 30:
   s>     bookmarks \n
   s>     namespaces \n
   s>     phases
diff --git a/mercurial/util.py b/mercurial/util.py
--- a/mercurial/util.py
+++ b/mercurial/util.py
@@ -762,7 +762,8 @@
         return makeloggingfileobject(observer.fh, res, observer.name,
                                      reads=observer.reads,
                                      writes=observer.writes,
-                                     logdata=observer.logdata)
+                                     logdata=observer.logdata,
+                                     logdataapis=observer.logdataapis)
 
     def recv(self, *args, **kwargs):
         return object.__getattribute__(self, r'_observedcall')(
@@ -825,29 +826,37 @@
 class baseproxyobserver(object):
     def _writedata(self, data):
         if not self.logdata:
-            self.fh.write('\n')
-            self.fh.flush()
+            if self.logdataapis:
+                self.fh.write('\n')
+                self.fh.flush()
             return
 
         # Simple case writes all data on a single line.
         if b'\n' not in data:
-            self.fh.write(': %s\n' % escapedata(data))
+            if self.logdataapis:
+                self.fh.write(': %s\n' % escapedata(data))
+            else:
+                self.fh.write('%s>     %s\n' % (self.name, escapedata(data)))
             self.fh.flush()
             return
 
         # Data with newlines is written to multiple lines.
-        self.fh.write(':\n')
+        if self.logdataapis:
+            self.fh.write(':\n')
+
         lines = data.splitlines(True)
         for line in lines:
             self.fh.write('%s>     %s\n' % (self.name, escapedata(line)))
         self.fh.flush()
 
 class fileobjectobserver(baseproxyobserver):
     """Logs file object activity."""
-    def __init__(self, fh, name, reads=True, writes=True, logdata=False):
+    def __init__(self, fh, name, reads=True, writes=True, logdata=False,
+                 logdataapis=True):
         self.fh = fh
         self.name = name
         self.logdata = logdata
+        self.logdataapis = logdataapis
         self.reads = reads
         self.writes = writes
 
@@ -858,22 +867,28 @@
         if res is None:
             res = ''
 
-        self.fh.write('%s> read(%d) -> %d' % (self.name, size, len(res)))
+        if self.logdataapis:
+            self.fh.write('%s> read(%d) -> %d' % (self.name, size, len(res)))
+
         self._writedata(res)
 
     def readline(self, res, limit=-1):
         if not self.reads:
             return
 
-        self.fh.write('%s> readline() -> %d' % (self.name, len(res)))
+        if self.logdataapis:
+            self.fh.write('%s> readline() -> %d' % (self.name, len(res)))
+
         self._writedata(res)
 
     def readinto(self, res, dest):
         if not self.reads:
             return
 
-        self.fh.write('%s> readinto(%d) -> %r' % (self.name, len(dest),
-                                                  res))
+        if self.logdataapis:
+            self.fh.write('%s> readinto(%d) -> %r' % (self.name, len(dest),
+                                                      res))
+
         data = dest[0:res] if res is not None else b''
         self._writedata(data)
 
@@ -886,7 +901,9 @@
         if res is None and data:
             res = len(data)
 
-        self.fh.write('%s> write(%d) -> %r' % (self.name, len(data), res))
+        if self.logdataapis:
+            self.fh.write('%s> write(%d) -> %r' % (self.name, len(data), res))
+
         self._writedata(data)
 
     def flush(self, res):
@@ -897,32 +914,44 @@
 
     # For observedbufferedinputpipe.
     def bufferedread(self, res, size):
-        self.fh.write('%s> bufferedread(%d) -> %d' % (
-            self.name, size, len(res)))
+        if not self.reads:
+            return
+
+        if self.logdataapis:
+            self.fh.write('%s> bufferedread(%d) -> %d' % (
+                self.name, size, len(res)))
+
         self._writedata(res)
 
     def bufferedreadline(self, res):
-        self.fh.write('%s> bufferedreadline() -> %d' % (self.name, len(res)))
+        if not self.reads:
+            return
+
+        if self.logdataapis:
+            self.fh.write('%s> bufferedreadline() -> %d' % (
+                self.name, len(res)))
+
         self._writedata(res)
 
 def makeloggingfileobject(logh, fh, name, reads=True, writes=True,
-                          logdata=False):
+                          logdata=False, logdataapis=True):
     """Turn a file object into a logging file object."""
 
     observer = fileobjectobserver(logh, name, reads=reads, writes=writes,
-                                  logdata=logdata)
+                                  logdata=logdata, logdataapis=logdataapis)
     return fileobjectproxy(fh, observer)
 
 class socketobserver(baseproxyobserver):
     """Logs socket activity."""
     def __init__(self, fh, name, reads=True, writes=True, states=True,
-                 logdata=False):
+                 logdata=False, logdataapis=True):
         self.fh = fh
         self.name = name
         self.reads = reads
         self.writes = writes
         self.states = states
         self.logdata = logdata
+        self.logdataapis = logdataapis
 
     def makefile(self, res, mode=None, bufsize=None):
         if not self.states:
@@ -935,32 +964,39 @@
         if not self.reads:
             return
 
-        self.fh.write('%s> recv(%d, %d) -> %d' % (
-            self.name, size, flags, len(res)))
+        if self.logdataapis:
+            self.fh.write('%s> recv(%d, %d) -> %d' % (
+                self.name, size, flags, len(res)))
         self._writedata(res)
 
     def recvfrom(self, res, size, flags=0):
         if not self.reads:
             return
 
-        self.fh.write('%s> recvfrom(%d, %d) -> %d' % (
-            self.name, size, flags, len(res[0])))
+        if self.logdataapis:
+            self.fh.write('%s> recvfrom(%d, %d) -> %d' % (
+                self.name, size, flags, len(res[0])))
+
         self._writedata(res[0])
 
     def recvfrom_into(self, res, buf, size, flags=0):
         if not self.reads:
             return
 
-        self.fh.write('%s> recvfrom_into(%d, %d) -> %d' % (
-            self.name, size, flags, res[0]))
+        if self.logdataapis:
+            self.fh.write('%s> recvfrom_into(%d, %d) -> %d' % (
+                self.name, size, flags, res[0]))
+
         self._writedata(buf[0:res[0]])
 
     def recv_into(self, res, buf, size=0, flags=0):
         if not self.reads:
             return
 
-        self.fh.write('%s> recv_into(%d, %d) -> %d' % (
-            self.name, size, flags, res))
+        if self.logdataapis:
+            self.fh.write('%s> recv_into(%d, %d) -> %d' % (
+                self.name, size, flags, res))
+
         self._writedata(buf[0:res])
 
     def send(self, res, data, flags=0):
@@ -975,9 +1011,11 @@
         if not self.writes:
             return
 
-        # Returns None on success. So don't bother reporting return value.
-        self.fh.write('%s> sendall(%d, %d)' % (
-            self.name, len(data), flags))
+        if self.logdataapis:
+            # Returns None on success. So don't bother reporting return value.
+            self.fh.write('%s> sendall(%d, %d)' % (
+                self.name, len(data), flags))
+
         self._writedata(data)
 
     def sendto(self, res, data, flagsoraddress, address=None):
@@ -989,8 +1027,10 @@
         else:
             flags = 0
 
-        self.fh.write('%s> sendto(%d, %d, %r) -> %d' % (
-            self.name, len(data), flags, address, res))
+        if self.logdataapis:
+            self.fh.write('%s> sendto(%d, %d, %r) -> %d' % (
+                self.name, len(data), flags, address, res))
+
         self._writedata(data)
 
     def setblocking(self, res, flag):
@@ -1019,11 +1059,12 @@
             self.name, level, optname, value))
 
 def makeloggingsocket(logh, fh, name, reads=True, writes=True, states=True,
-                      logdata=False):
+                      logdata=False, logdataapis=True):
     """Turn a socket into a logging socket."""
 
     observer = socketobserver(logh, name, reads=reads, writes=writes,
-                              states=states, logdata=logdata)
+                              states=states, logdata=logdata,
+                              logdataapis=logdataapis)
     return socketproxy(fh, observer)
 
 def version():
diff --git a/mercurial/debugcommands.py b/mercurial/debugcommands.py
--- a/mercurial/debugcommands.py
+++ b/mercurial/debugcommands.py
@@ -2839,9 +2839,13 @@
                 r'loggingname': b's',
                 r'loggingopts': {
                     r'logdata': True,
+                    r'logdataapis': False,
                 },
             }
 
+        if ui.debugflag:
+            openerargs[r'loggingopts'][r'logdataapis'] = True
+
         opener = urlmod.opener(ui, authinfo, **openerargs)
 
         if opts['peer'] == 'raw':



To: indygreg, #hg-reviewers, durin42
Cc: durin42, mercurial-devel
_______________________________________________
Mercurial-devel mailing list
[hidden email]
https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel