Fixes "Logs are not line buffered" #868 issue in sugar repo

[radiidev]

Reason why it was working in python 2 is because this file is added only when switched to python 3. Compare logger.py file in sugar3 directory of v0.95.2 with sugar directory of v0.95.1

Following is not address in this commit from https://github.com/sugarlabs/sugar/issues/868:

Perhaps what we should be doing now is to configure Sugar and activities for fully buffered logs, and configure line-buffering only when Sugar is being used by a developer. i.e. set sys.stderr.line_buffering = True based on an environment variable. Comments?

[quozl]

Doesn't work. I get TypeError: 'buffer' is an invalid keyword argument for this function.

[radiidev]

Yes James, you're right, it doesn't work. Sorry for not evaluating thoroughly before PR. In fact original code works fine. I tested it in two scenarios:

1. Running following script both interactively and non-interactively:

#!/usr/bin/python3

from sugar import logger
import sys
import time

if sys.stdout.isatty():
    string = " Interactive"
else:
    string = " Non-interactive"

logger.start("custom_log")

import logging

while True:
    log_message = time.ctime() + string
    logging.critical(log_message)
    time.sleep(10)

2. edit ~/.sugar/default/debug to uncomment:

   export SUGAR_LOGGER_LEVEL=debug

Logs are line buffered in scenario(1) (or not at all buffered). In scenario(2) as well, I see logfile shell.log continuously being populated but that could be due to buffer filling up, given the verbosity.

Can you help me in reproducing #868 and how I can confirm if it's fixed?

[quozl]

Sure, it's easy to reproduce. Find a suitable button activate callback to modify temporarily, add a logging.error call to it, restart Sugar, and then prove that sugar.log contains the added message. Then restart Sugar again, use tail -f to watch sugar.log (over SSH or another terminal), then activate the suitable button and verify if you see instant output in sugar.log, or if the output is delayed until Sugar is stopped.

https://github.com/sugarlabs/sugar/issues/868 has an explanation and a solution "sys.stderr.line_buffering = True" that seems like it should work. Have you tried it?

[radiidev]

Sure, it's easy to reproduce. Find a suitable button activate callback to modify temporarily, add a logging.error call to it, restart Sugar, and then prove that sugar.log contains the added message. Then restart Sugar again, use tail -f to watch sugar.log (over SSH or another terminal), then activate the suitable button and verify if you see instant output in sugar.log, or if the output is delayed until Sugar is stopped.

sugarlabs/sugar#868 has an explanation and a solution "sys.stderr.line_buffering = True" that seems like it should work. Have you tried it?

Thanks James, I am seeing logs instantly. Perhaps you can give me specific steps to follow to reproduce this error.

I made following changes to /usr/src/sugar/src/jarabe/model/sound.py:

• import logging
• In PlaybackSound.set_muted() inserted logging.error('xyzabc')

You can see the output below:

[quozl]

Thanks, I agree.

Closing as Not Sugar.

Problem is solved by upgrading to Python 3.8.2, though there may be an earlier version that had the fix.