python gitlab stdout docker-image gitlab-ci.yml

See output of a python app running in the background in a docker image in Gitlab

In my gitlab-ci.yml file I have a script which runs my python app in the background python app.py & and then I do calls to it from other testing scripts.

The problem is I don't see the output of the application in my Gitlab console.

For example, this is the output I get from running my code in Gitlab inside a docker image with python 3.8 :

$ py.test tests/integration/test_integration.py
INFO:werkzeug:127.0.0.1 - - [14/Apr/2023 12:58:54] "GET /getCSRFToken HTTP/1.1" 200 -
WARNING:cassandra.protocol:Server warning: `USE <keyspace>` with prepared statements is considered to be an anti-pattern due to ambiguity in non-qualified table names. Please consider removing instances of `Session#setKeyspace(<keyspace>)`, `Session#execute("USE <keyspace>")` and `cluster.newSession(<keyspace>)` from your code, and always use fully qualified table names (e.g. <keyspace>.<table>). Keyspace used: local, statement keyspace: local, statement id: d7e00993aaf2e878c0a2efb58ade5a06
INFO:werkzeug:127.0.0.1 - - [14/Apr/2023 12:58:54] "POST /series/ HTTP/1.1" 204 -
INFO:werkzeug:127.0.0.1 - - [14/Apr/2023 12:58:54] "POST /orders/power/2023-04-14 HTTP/1.1" 400 -
============================= test session starts ==============================
platform linux -- Python 3.8.16, pytest-7.3.0, pluggy-1.0.0
rootdir: /builds/Biz-IT/pfm-py2api
plugins: cov-3.0.0, forked-1.6.0, xdist-2.5.0
collected 0 items / 1 error
==================================== ERRORS ====================================
____________ ERROR collecting tests/integration/test_integration.py ____________
tests/integration/test_integration.py:182: in <module>
    assert_and_post (payload_custom_order_1, url_orders, headers_orders)
tests/integration/test_integration.py:136: in assert_and_post
    post_data_orders (url_orders, headers_orders, pload)
tests/integration/test_integration.py:132: in post_data_orders
    assert response.status_code == 200, "Something went wrong with your orders!"
E   AssertionError: Something went wrong with your orders!
E   assert 400 == 200
E    +  where 400 = <Response [400]>.status_code
------------------------------- Captured stdout --------------------------------
ImI0NDE1NjcwOGI1NWZhMGEwOTQ3NTJlYWE1YzZmYTQ0YjNmNmJmMGIi.ZDlODg._stOg24LUiOausSseO1lynQI3bw
eyJjc3JmX3Rva2VuIjoiYjQ0MTU2NzA4YjU1ZmEwYTA5NDc1MmVhYTVjNmZhNDRiM2Y2YmYwYiJ9.ZDlODg.dO8FG64QQyJPqIdPScwYC2uIsjE
<Response [400]>
=========================== short test summary info ============================
ERROR tests/integration/test_integration.py - AssertionError: Something went wrong with your orders!
assert 400 == 200
 +  where 400 = <Response [400]>.status_code
!!!!!!!!!!!!!!!!!!!! Interrupted: 1 error during collection !!!!!!!!!!!!!!!!!!!!
=============================== 1 error in 0.93s ===============================
Cleaning up project directory and file based variables 00:00
ERROR: Job failed: exit code 1

The problem is I don't see the output of python app.py &, where the actual problem in the code is pointed out, when doing the request which fails with a 400 error code.

Below I have an example of a logged 400 problem occurring when I launch the python app on localhost and then in another terminal i launch my test scripts :

127.0.0.1 - - [11/Apr/2023 16:02:13] "POST /series/ HTTP/1.1" 204 -
127.0.0.1 - - [11/Apr/2023 16:02:13] "POST /orders/power/2023-04-11 HTTP/1.1" 200 -
[2023-04-11 16:02:13,545] ERROR in handlers: "Traceback (most recent call last):\n  File \"app.py\", line 416, in create_order_user\n    request_params = create_order.load(request.json)\n  File \"/myvenv/lib/python3.8/site-packages/marshmallow/schema.py\", line 722, in load\n    return self._do_load(\n  File \"/myvenv/lib/python3.8/site-packages/marshmallow/schema.py\", line 909, in _do_load\n    raise exc\nmarshmallow.exceptions.ValidationError: {'stoploss': ['Not a valid string.'], 'targetlimit': ['Not a valid string.']}\n\nDuring handling of the above exception, another exception occurred:\n\nTraceback (most recent call last):\n  File \"/myvenv/lib/python3.8/site-packages/flask/app.py\", line 1823, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/myvenv/lib/python3.8/site-packages/flask/app.py\", line 1799, in dispatch_request\n    return self.ensure_sync(self.view_functions[rule.endpoint])(**view_args)\n  File \"app.py\", line 418, in create_order_user\n    abort(HTTP_400_BAD_REQUEST, description=str(e))\n  File \"/myvenv/lib/python3.8/site-packages/flask/helpers.py\", line 310, in abort\n    current_app.aborter(code, *args, **kwargs)\n  File \"/myvenv/lib/python3.8/site-packages/werkzeug/exceptions.py\", line 864, in __call__\n    raise self.mapping[code](*args, **kwargs)\nwerkzeug.exceptions.BadRequest: 400 Bad Request: {'stoploss': ['Not a valid string.'], 'targetlimit': ['Not a valid string.']}\n"
127.0.0.1 - - [11/Apr/2023 16:02:13] "POST /orders/power/2023-04-11 HTTP/1.1" 400

Solution that I tried :

running the python app.py & > /dev/null 2>&1 but it does not work.

EDIT 1

My gitlab-ci.yml file contains a Cassandra service already and I don't want to run my app in a separate container, I want the current container with Python 3.8 to show me logs of the app.

image: python:3.8

variables:
  PIP_CACHE_DIR: "$CI_PROJECT_DIR/.cache/pip"

cache:
  paths:
    - .cache/pip
    - venv/

before_script:
  - python -V  # Print out python version for debugging
  - ...
  - python app.py &
  - sleep 20

stages:
  - build
  - ...

include:
  - project: ...

services:
        - name: cassandra:3.11
          alias: cassandra

test:unit:
  stage: ...


test:integration:
    stage: test
    script:
        - echo "0"
        - py.test tests/integration/test_integration.py

Solution

Actually the logs of my app are already present in the output of Gitlab which I've posted above, more precisely is shown in the following lines as flask output :

INFO:werkzeug:127.0.0.1 - - [14/Apr/2023 12:58:54] "GET /getCSRFToken HTTP/1.1" 200 -
WARNING:cassandra.protocol:Server warning: `USE <keyspace>` with prepared statements is considered to be an anti-pattern due to ambiguity in non-qualified table names. Please consider removing instances of `Session#setKeyspace(<keyspace>)`, `Session#execute("USE <keyspace>")` and `cluster.newSession(<keyspace>)` from your code, and always use fully qualified table names (e.g. <keyspace>.<table>). Keyspace used: local, statement keyspace: local, statement id: d7e00993aaf2e878c0a2efb58ade5a06
INFO:werkzeug:127.0.0.1 - - [14/Apr/2023 12:58:54] "POST /series/ HTTP/1.1" 204 -
INFO:werkzeug:127.0.0.1 - - [14/Apr/2023 12:58:54] "POST /orders/power/2023-04-14 HTTP/1.1" 400 -
============================= test session starts ==============================

The error that I was expecting to see is not actually an error, I trigger a 400 error code from the python app, so the logs with the detailed exception I was expecting to see are not there because there is no error.

What I should have logged in my integration tests which I run after running the python app are the response body like:

def post_data_orders (url, headers, txtdata):
  payload = json.dumps(json.loads(txtdata))
  response = requests.request("POST", url, headers=headers, data=payload)
  print(response)
  print(response.text) # the actual code which would indicate the "problem"
  ...

This will show the response like this :

------------------------------- Captured stdout --------------------------------
...
<Response [400]>
User is not allowed

Which does not contain a stack trace like in the following case, when there is an actual error in the app and its stack trace is shown in Gitlab :

$ py.test tests/integration/test_integration.py
INFO:werkzeug:127.0.0.1 - - [17/Apr/2023 07:35:57] "GET /getCSRFToken HTTP/1.1" 200 -
WARNING:cassandra.protocol:Server warning: `USE <keyspace>` with prepared statements is considered to be an anti-pattern due to ambiguity in non-qualified table names. Please consider removing instances of `Session#setKeyspace(<keyspace>)`, `Session#execute("USE <keyspace>")` and `cluster.newSession(<keyspace>)` from your code, and always use fully qualified table names (e.g. <keyspace>.<table>). Keyspace used: local, statement keyspace: local, statement id: d7e00993aaf2e878c0a2efb58ade5a06
INFO:werkzeug:127.0.0.1 - - [17/Apr/2023 07:35:58] "POST /series/ HTTP/1.1" 204 -
ERROR:src:"Traceback (most recent call last):\n  File \"/builds/Biz-IT/pfm-py2api/venv/lib/python3.8/site-packages/flask/app.py\", line 1516, in full_dispatch_request\n    rv = self.dispatch_request()\n  File \"/builds/Biz-IT/pfm-py2api/venv/lib/python3.8/site-packages/flask/app.py\", line 1502, in dispatch_request\n    return self.ensure_sync(self.view_functions[rule.endpoint])(**req.view_args)\n  File \"app.py\", line 137, in upload_series\n    abort(HTTP_400_BAD_REQUEST, description=str(errors))\n  File \"/builds/Biz-IT/pfm-py2api/venv/lib/python3.8/site-packages/werkzeug/exceptions.py\", line 881, in abort\n    _aborter(status, *args, **kwargs)\n  File \"/builds/Biz-IT/pfm-py2api/venv/lib/python3.8/site-packages/werkzeug/exceptions.py\", line 864, in __call__\n    raise self.mapping[code](*args, **kwargs)\nwerkzeug.exceptions.BadRequest: 400 Bad Request: {'data': {0: {'permission': ['Unknown field.'], 'displayname': ['Unknown field.'], 'tradername': ['Unknown field.'], 'user': ['Unknown field.']}, 1: {'permission': ['Unknown field.'], 'displayname': ['Unknown field.'], 'tradername': ['Unknown field.'], 'user': ['Unknown field.']}, 2: {'permission': ['Unknown field.'], 'displayname': ['Unknown field.'], 'tradername': ['Unknown field.'], 'user': ['Unknown field.']}, 3: {'permission': ['Unknown field.'], 'displayname': ['Unknown field.'], 'tradername': ['Unknown field.'], 'user': ['Unknown field.']}, 4: {'permission': ['Unknown field.'], 'displayname': ['Unknown field.'], 'tradername': ['Unknown field.'], 'user': ['Unknown field.']}, 5: {'permission': ['Unknown field.'], 'displayname': ['Unknown field.'], 'tradername': ['Unknown field.'], 'user': ['Unknown field.']}, 6: {'permission': ['Unknown field.'], 'displayname': ['Unknown field.'], 'tradername': ['Unknown field.'], 'user': ['Unknown field.']}, 7: {'permission': ['Unknown field.'], 'displayname': ['Unknown field.'], 'tradername': ['Unknown field.'], 'user': ['Unknown field.']}, 8: {'permission': ['Unknown field.'], 'displayname': ['Unknown field.'], 'tradername': ['Unknown field.'], 'user': ['Unknown field.']}, 9: {'permission': ['Unknown field.'], 'displayname': ['Unknown field.'], 'tradername': ['Unknown field.'], 'user': ['Unknown field.']}, 10: {'permission': ['Unknown field.'], 'displayname': ['Unknown field.'], 'tradername': ['Unknown field.'], 'user': ['Unknown field.']}, 11: {'permission': ['Unknown field.'], 'displayname': ['Unknown field.'], 'tradername': ['Unknown field.'], 'user': ['Unknown field.']}, 12: {'permission': ['Unknown field.'], 'displayname': ['Unknown field.'], 'tradername': ['Unknown field.'], 'user': ['Unknown field.']}, 13: {'permission': ['Unknown field.'], 'displayname': ['Unknown field.'], 'tradername': ['Unknown field.'], 'user': ['Unknown field.']}, 14: {'permission': ['Unknown field.'], 'displayname': ['Unknown field.'], 'tradername': ['Unknown field.'], 'user': ['Unknown field.']}, 15: {'permission': ['Unknown field.'], 'displayname': ['Unknown field.'], 'tradername': ['Unknown field.'], 'user': ['Unknown field.']}, 16: {'permission': ['Unknown field.'], 'displayname': ['Unknown field.'], 'tradername': ['Unknown field.'], 'user': ['Unknown field.']}}}\n"
INFO:werkzeug:127.0.0.1 - - [17/Apr/2023 07:35:58] "POST /series/ HTTP/1.1" 400 -
============================= test session starts ==============================
...

So I can keep the way of launching my app in the background like python app.py & and then run my integration tests.

The only opened question is why did I get a negative vote :( ?