8

I'm trying to print to console before and after processing that takes a while in a Django management command, like this:

import requests
import xmltodict

from django.core.management.base import BaseCommand


def get_all_routes():
    url = 'http://busopen.jeju.go.kr/OpenAPI/service/bis/Bus'

    r = requests.get(url)
    data = xmltodict.parse(r.content)

    return data['response']['body']['items']['item']


class Command(BaseCommand):

    help = 'Updates the database via Bus Info API'

    def handle(self, *args, **options):
        self.stdout.write('Saving routes ... ', ending='')
        for route in get_all_routes():
            route_obj = Route(
                route_type=route['routeTp'], route_id=route['routeId'], route_number=route['routeNum'])
            route_obj.save()
        self.stdout.write('done.')

In the above code, Saving routes ... is expected to print before the loop begins, and done. right next to it when the loop completes so that it looks like Saving routes ... done. in the end.

However, the former doesn't print until the loop completes, when both strings finally print at the same time, which is not what I expected.

I found this question, where the answer suggests flushing the output i.e. self.stdout.flush(), so I added that to my code:

    def handle(self, *args, **options):
        self.stdout.write('Saving routes ... ', ending='')
        self.stdout.flush()
        for route in get_all_routes():
            route_obj = Route(
                route_type=route['routeTp'], route_id=route['routeId'], route_number=route['routeNum'])
            route_obj.save()
        self.stdout.write('done.')

Still, the result remains unchanged.

What could have I done wrong?

Sunwoo Park
  • 386
  • 3
  • 15
  • I've tested your code and it works as expected, even without flushing. you may want to add the complete code to your question. – Igor Moraru May 26 '20 at 10:27
  • @IgorMoraru oh, never thought that could be a problem. I edited my question to include `get_all_routes`. Basically it's a function that has requests call a web API that returns a large amount of XML data, which is then parsed into a dictionary. – Sunwoo Park May 26 '20 at 11:15
  • 1
    I cant see any issues. The only thought is to use sys.stdout instead of self.stdout. It may be some issue with django's internal buffering of stdout output. – Igor Moraru May 26 '20 at 12:32
  • Substituting the URL to the one that returns an even larger response like [this](http://busopen.jeju.go.kr/OpenAPI/service/bis/StationRoute) makes it clearer that nothing gets printed before the loop begins. – Sunwoo Park May 26 '20 at 12:47
  • I also suspect stdout buffering as a possible cause, but if it were an issue, wouldn't `self.stdout.flush()` be supposed to fix it? – Sunwoo Park May 26 '20 at 12:50
  • It looks like flushing is not implemented: https://code.djangoproject.com/ticket/29533 – rfkortekaas May 28 '20 at 18:06
  • @rfkortekaas I failed to locate in Django's source code which the ticket is talking about (`flush()` being defined as `pass`). Do you have any idea? I found django themselves is using `self.stdout.flush()` in their own managemant command the same way as I am. How come is that possible? https://github.com/django/django/blob/0382ecfe020b4c51b4c01e4e9a21892771e66941/django/core/management/commands/migrate.py#L278 – Sunwoo Park May 29 '20 at 06:59
  • You can give it a try by using time.sleep(2) after stdout.write so you may try to fake it. You don't need to use flush. – Rikkas May 29 '20 at 21:33

2 Answers2

7

The thing to keep in mind is you're using self.stdout (as suggested in the Django docs), which is BaseCommand's override of Python's standard sys.stdout. There are two main differences between the 2 relevant to your problem:

  1. The default "ending" in BaseCommand's version of self.stdout.write() is a new-line, forcing you to use the ending='' parameter, unlike sys.stdout.write() that has an empty ending as the default. This in itself is not causing your problem.
  2. The BaseCommand version of flush() does not really do anything (who would have thought?). This is a known bug: https://code.djangoproject.com/ticket/29533

So you really have 2 options:

  1. Not use BaseCommand's self.stdout but instead use sys.stdout, in which case the flush does work
  2. Force the stdout to be totally unbuffered while running the management command by passing the "-u" parameter to python. So instead of running python manage.py <subcommand>, run python -u manage.py <subcommand>

Hope this helps.

bkrishnan
  • 796
  • 5
  • 4
  • 3
    Option 3: call self.stdout.reconfigure(write_through=True) once and call self.stdout.buffer.flush(). –  Jun 03 '20 at 07:11
  • Yes, I’m using `self.stdout` as per Django docs. Is there any negative effect if I choose to ditch `self.stdout` in favor of `sys.stdout`? – Sunwoo Park Jun 03 '20 at 16:00
  • 2
    @SunwooPark - If you want to be able to run the management command with the output redirected to a file, for example, instead of just printing the output to the console, then I would suggest using the self.stdout as suggested by the docs and just add the "-u" parameter while calling the command (option 2 in my answer). If you don't care about output redirection of the command, maybe you're always running the command from the command line, it shouldn't make a difference if you use sys.stdout. – bkrishnan Jun 03 '20 at 17:13
  • @Melvyn your comment wins the day. Too bad it's not an answer. – Routhinator Feb 01 '21 at 04:57
0

Have you try to set PYTHONUNBUFFERED environment variable?

Toan Nguyen
  • 631
  • 4
  • 10