Search code examples
python-3.xsocketswindows-10command-promptbuffering

Why my console application is buffering log and socket messages?

Background:

I have a Python (console) application which includes a socket server. This application receives messages from a 3rd party client (start and stop messages from certain Process A) to control a recording data task (like start and stop recording). You can think of it as receiving messages via sockets to start and stop recording data from the same Process A for about 5 minutes. The 3rd party client sends messages for nearly 2 hours and then stops, and at the end, the Python application will be producing a group of files per session.

This application is running 24/7 (unattended on a Windows 10 Desktop machine) and there is a logging console open as well, but I have noticed that sometimes (Haven't identified a pattern) after running for 4 or 5 days, I access the system remotely, using TeamViewer, and the console window is showing that the last message is of 1-2 days ago. But once I click on the console or press a key in that console, I receive a full batch of messages from the sessions missed during those last days, thus, start and stop messages are received "simultaneously" leading to rubbish data files.

The code:

This is the socket server part of the code. I know I'm setting a buffer of 1024, but in normal operation, this buffer should not be full to read the data

            with conn:
                #display client information
                logger.info('Connected with ' + addr[0] + ':' + str(addr[1]))

                while self.enable:
                    #now keep talking with the client
                    data = conn.recv(1024)

                    if data:
                        self.data_cb(data)
                    else:                            
                        logger.debug("no data, closing connection." )
                        break

Question:

What is leading to this buffering behaviour? Could it be...

  • the 3rd party client?
  • my Python application?
  • Something in Windows network stuff?

Has anyone had experienced something like this?

Any idea is really appreciated as I have no clue why is this happening? Thanks.

Edit - Additional info:

  • The application is running on a real desktop machine (no virtual machine)
  • The application has been able to work continuously for almost a month (just stopped for valid external reasons, power outage, version update, etc)
  • Last time I accessed through Teamviewer and noticed that the app wasn't receiving messages for a day (the app was running for 4 days at that time), BUT I assumed it was for another reason and planned to go to the site and check (Because something similar happened before). I accessed the next day, and it was the same. But on the third day, I click on the console and tried to review the messages and instantly the whole batch of messages from the previous 2 days appeared on the log.
  • The app has been running for 2 weeks and did not access the PC through TeamViewer during the last 4 days, in case that accessing it could prevent the issue to occur.
Solution

  • TL;DR

    The selection feature of Command Prompt window prevents somehow the application from printing logging messages and/or reading data from the socket (both are in the same thread).

    Well, I found the cause of this buffering behaviour but I am not sure if it is a known thing or not (It was not for me, so I will post later a specific question about that selection feature).

    When I checked the system today I found that the console messages were frozen at 3 days before, so I clicked on the console window, and hit a key and all the messages for 3 days were shown at once. Then, I suspected of the selection feature of the console output.

    I started the application as usual and followed these steps:

    • I selected a part of the content in the application console.
    • Using another console, I connected from a dummy client using ncat (At this point the expected client connected message didn't show up)
    • I sent dummy messages (didn't show up either)
    • I finished ncat connection (CTRL-C)
    • Clicked on the application console and hit any key

    Voila! All the logging messages (regarding connection and data appeared), and all the messages that I sent using ncat were received as one big message.

    EDIT: Didn't need to create a question, it's a known "feature". There are good questions here, here and here. The last one shows how to disable this "feature".