<p>Harald Welte <strong>merged</strong> this change.</p><p><a href="https://gerrit.osmocom.org/12147">View Change</a></p><div style="white-space:pre-wrap">Approvals:
  Jenkins Builder: Verified
  Harald Welte: Looks good to me, approved

Objections:
  daniel: I would prefer this is not merged as is

</div><pre style="font-family: monospace,monospace; white-space: pre-wrap;">ctrl2cgi: log request time<br><br>Log http request timestamp and duration on debug loglevel. This is<br>especially helpful while troubleshooting issues with multiple concurrent<br>requests under significant load while network issues are present.<br><br>Change-Id: I11c8ac67a2730a9c6912694e5b83bbdf08fe357d<br>Related: SYS#4399<br>---<br>M scripts/ctrl2cgi.py<br>1 file changed, 9 insertions(+), 6 deletions(-)<br><br></pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;"><span>diff --git a/scripts/ctrl2cgi.py b/scripts/ctrl2cgi.py</span><br><span>index 5c675bc..e11e6e6 100755</span><br><span>--- a/scripts/ctrl2cgi.py</span><br><span>+++ b/scripts/ctrl2cgi.py</span><br><span>@@ -22,9 +22,9 @@</span><br><span>  */</span><br><span> """</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-__version__ = "0.0.6" # bump this on every non-trivial change</span><br><span style="color: hsl(120, 100%, 40%);">+__version__ = "0.0.7" # bump this on every non-trivial change</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-import argparse, os, logging, logging.handlers</span><br><span style="color: hsl(120, 100%, 40%);">+import argparse, os, logging, logging.handlers, datetime</span><br><span> import hashlib</span><br><span> import json</span><br><span> import configparser</span><br><span>@@ -40,11 +40,12 @@</span><br><span> assert V(twisted_ipa_version) > V('0.4')</span><br><span> </span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-def handle_reply(bid, f, log, resp):</span><br><span style="color: hsl(120, 100%, 40%);">+def handle_reply(ts, bid, f, log, resp):</span><br><span>     """</span><br><span>     Reply handler: process raw CGI server response, function f to run for each command</span><br><span>     """</span><br><span>     decoded = json.loads(resp.decode('utf-8'))</span><br><span style="color: hsl(120, 100%, 40%);">+    log.debug('request for BSC %s took %d seconds' % (bid, (datetime.datetime.now() - ts).total_seconds()))</span><br><span>     comm_proc(decoded.get('commands'), bid, f, log)</span><br><span> </span><br><span> def gen_hash(params, skey):</span><br><span>@@ -60,9 +61,9 @@</span><br><span>     #print('HASH: \nparams="%r"\ninput="%s" \nres="%s"' %(params, input, res))</span><br><span>     return res</span><br><span> </span><br><span style="color: hsl(0, 100%, 40%);">-def make_async_req(dst, par, f_write, f_log):</span><br><span style="color: hsl(120, 100%, 40%);">+def make_async_req(ts, dst, par, f_write, f_log):</span><br><span>     d = post(dst, par)</span><br><span style="color: hsl(0, 100%, 40%);">-    d.addCallback(collect, partial(handle_reply, par['bsc_id'], f_write, f_log)) # treq's collect helper is handy to get all reply content at once</span><br><span style="color: hsl(120, 100%, 40%);">+    d.addCallback(collect, partial(handle_reply, ts, par['bsc_id'], f_write, f_log)) # treq's collect helper is handy to get all reply content at once</span><br><span>     d.addErrback(lambda e: f_log.critical("HTTP POST error %s while trying to register BSC %s on %s" % (e, par['bsc_id'], dst))) # handle HTTP errors</span><br><span>     return d</span><br><span> </span><br><span>@@ -106,8 +107,10 @@</span><br><span>         params = make_params(bsc, data)</span><br><span>         self.factory.log.info('location-state@%s.%s.%s.%s (%s) => %s' % (net, bsc, bts, trx, params['time_stamp'], data))</span><br><span>         params['h'] = gen_hash(params, self.factory.secret_key)</span><br><span style="color: hsl(120, 100%, 40%);">+        t = datetime.datetime.now()</span><br><span style="color: hsl(120, 100%, 40%);">+        self.factory.log.debug('Preparing request for BSC %s @ %s...' % (params['bsc_id'], t))</span><br><span>         # Ensure that we run only limited number of requests in parallel:</span><br><span style="color: hsl(0, 100%, 40%);">-        self.factory.semaphore.run(make_async_req, self.factory.location, params, self.transport.write, self.factory.log)</span><br><span style="color: hsl(120, 100%, 40%);">+        self.factory.semaphore.run(make_async_req, t, self.factory.location, params, self.transport.write, self.factory.log)</span><br><span> </span><br><span>     def handle_notificationrejectionv1(self, net, bsc, bts, trx, data):</span><br><span>         """</span><br><span></span><br></pre><p>To view, visit <a href="https://gerrit.osmocom.org/12147">change 12147</a>. To unsubscribe, or for help writing mail filters, visit <a href="https://gerrit.osmocom.org/settings">settings</a>.</p><div itemscope itemtype="http://schema.org/EmailMessage"><div itemscope itemprop="action" itemtype="http://schema.org/ViewAction"><link itemprop="url" href="https://gerrit.osmocom.org/12147"/><meta itemprop="name" content="View Change"/></div></div>

<div style="display:none"> Gerrit-Project: python/osmo-python-tests </div>
<div style="display:none"> Gerrit-Branch: master </div>
<div style="display:none"> Gerrit-MessageType: merged </div>
<div style="display:none"> Gerrit-Change-Id: I11c8ac67a2730a9c6912694e5b83bbdf08fe357d </div>
<div style="display:none"> Gerrit-Change-Number: 12147 </div>
<div style="display:none"> Gerrit-PatchSet: 1 </div>
<div style="display:none"> Gerrit-Owner: Max <msuraev@sysmocom.de> </div>
<div style="display:none"> Gerrit-Reviewer: Harald Welte <laforge@gnumonks.org> </div>
<div style="display:none"> Gerrit-Reviewer: Jenkins Builder (1000002) </div>
<div style="display:none"> Gerrit-Reviewer: Pau Espin Pedrol <pespin@sysmocom.de> </div>
<div style="display:none"> Gerrit-Reviewer: daniel <dwillmann@sysmocom.de> </div>