taskotron / resultsdb

Clone
Source Code
GIT

#98 Add more logging around result creation
Merged 6 years ago by jskladan. Opened 6 years ago by sochotni.
taskotron/ sochotni/resultsdb logging-additions  into  develop

Add more logging around result creation
Stanislav Ochotnicky • 6 years ago  
0a93edd
file modified
+2 
@@ -186,3 +186,5 @@ 
 

  

  from resultsdb.controllers.api_v2 import api as api_v2
 

  app.register_blueprint(api_v2, url_prefix="/api/v2.0")
 

+ 

+ app.logger.debug("Finished ResultsDB initialization")

file modified
+9 
@@ -580,11 +580,13 @@ 
 

  

      outcome = args['outcome'].strip().upper()
 

      if outcome not in RESULT_OUTCOME:
 

+         app.logger.warning("Invalid result outcome submitted: %s", outcome)
 

          return jsonify({'message': "outcome must be one of %r" % (RESULT_OUTCOME,)}), 400
 

  

      if args['data']:
 

          invalid_keys = [key for key in args['data'].iterkeys() if ':' in key]
 

          if invalid_keys:
 

+             app.logger.warning("Colon not allowed in key name: %s", invalid_keys)
 

              return jsonify({'message': "Colon not allowed in key name: %r" % invalid_keys}), 400
 

  

      # args[testcase] can be either string or object
 
@@ -593,12 +595,15 @@ 
 

      if isinstance(tc, basestring):
 

          tc = dict(name=args['testcase'])
 

          if not tc['name']:
 

+             app.logger.warning("Result submitted without valid testcase.name: %s", tc)
 

              return jsonify({'message': "testcase name not set"}), 400
 

      elif isinstance(tc, dict) and 'name' not in tc:
 

+         app.logger.warning("Result submitted without testcase.name: %s", tc)
 

          return jsonify({'message': "testcase.name not set"}), 400
 

  

      testcase = Testcase.query.filter_by(name=tc['name']).first()
 

      if not testcase:
 

+         app.logger.debug("Testcase %s does not exist yet. Creating", tc['name'])
 

          testcase = Testcase(name=tc['name'])
 

      testcase.ref_url = tc.get('ref_url', testcase.ref_url)
 

      db.session.add(testcase)
 
@@ -660,8 +665,10 @@ 
 

      db.session.commit()
 

  

      db.session.add(result)
 

+     app.logger.debug("Created new result for testcase %s with outcome %s", testcase.name, outcome)
 

  

      if app.config['MESSAGE_BUS_PUBLISH']:
 

+         app.logger.debug("Preparing to publish message for result id %d", result.id)
 

          prev_result = get_prev_result(result)
 

          # result is considered duplicate of prev_result when
 

          # outcomes are the same.
 
@@ -671,6 +678,8 @@ 
 

                  kwargs=app.config['MESSAGE_BUS_KWARGS'],
 

              )
 

              plugin.publish(plugin.create_message(result, prev_result))
 

+         else:
 

+             app.logger.debug("Skipping messaging, result %d outcome has not changed", result.id)
 

  

  

      return jsonify(SERIALIZE(result)), 201

file modified
+1 
@@ -129,6 +129,7 @@ 
 

          conn.connect()
 

          try:
 

              conn.send(**kwargs)
 

+             log.debug("Published message through stomp: %s", msg)
 

          finally:
 

              conn.disconnect()

This should help debug issues if needed

Sort of related to issue #96

I'll admit I have trouble running the testsuite - tox passes but pytest fails to run even in virtualenv. Would need to look into it...

:+1:, this will help. :)

@sochotni Not really sure what your issue with the testsuite is, I just ran it without any issues:
virtualenv --no-site-packages /tmp/vrtest
source /tmp/vrtest/bin/activate
pip install -r requirements.txt
python setup.py develop
py.test testing/

All of the above executed from a fresh git-checkout of the develop branch.

I'd rather see this as debug level.

The project's line lenght is set to 99 chars, please unwrap.

The project's line lenght is set to 99 chars, please unwrap.

The project's line lenght is set to 99 chars, please unwrap.

The project's line lenght is set to 99 chars, please unwrap.

The project's line lenght is set to 99 chars, please unwrap.

sigh once again, Pagure's UX fails me...

The patch, as is, looks fine, if the comments above get addressed.

My question here, though, is what is the "grand scheme" here? Seems like it is just half-done, as the debug logs you added do not cover all the "this went wrong" (= where non-2xx HTTP status code is returned) cases in the code. I'd much rather see us logging in all the cases, as this could have the "I see no errors in the debug log, but it still does not work, what the heck?!?" effect quite easily.

Thanks!

@sochotni Not really sure what your issue with the testsuite is, I just ran it without any issues:
virtualenv --no-site-packages /tmp/vrtest
source /tmp/vrtest/bin/activate
pip install -r requirements.txt
python setup.py develop
py.test testing/
All of the above executed from a fresh git-checkout of the develop branch.

For some reason pytest-cov >= 1.6 from requirements.txt didn't actually work? I had to manually install python2-pytest-cov from rpm

I agree logging as a whole could use a boost - as things are I don't think you'll get much out of logs even if you turn on debug. I'd be very much in favor of adding much more logging. This was just adding it in place where I could have just find it useful :-)

As an example - we have a few prod services with debug logs enabled and logs go directly into ELK. Value of this is immense when something goes wrong. We don't even need access to the machine and know exactly what happened. And generally for most systems the amount of generated logs is of no consequence.

Will address the comments in a bit
Edited 6 years ago by sochotni

For some reason pytest-cov >= 1.6 from requirements.txt didn't actually work? I had to manually install python2-pytest-cov from rpm

Weird, works for me with the virtualenv:
$ rpm -qa | grep cov
$ which coverage
/tmp/vrtest/bin/coverage

But I'm glad you were able to find/fix the issue!
Edited 6 years ago by jskladan

rebased onto 7e5ca61634d18123fb5f1039e534f82626d37022
6 years ago

rebased onto 0a93edd
6 years ago

Unwrapped the lines and added few more debug statements for early returns

Awesome, thanks. I think this is a great start for even more excessive logging, should you/we ever need it. Will merge shortly.

Pull-Request has been merged by jskladan
6 years ago
Metadata
None
No Tags
Changes Summary 3
+2 -0
file changed
resultsdb/__init__.py
+9 -0
file changed
resultsdb/controllers/api_v2.py
+1 -0
file changed
resultsdb/messaging.py
Powered by Pagure 5.13.3
Documentation • File an Issue • About • SSH Hostkey/Fingerprint
© Red Hat, Inc. and others.