Balena Logs missing when printed quickly

[FossFan]

I’m trying to create a pass through logging container for uart on the rpi3. i.e. we have an mcu that is printing out over uart, and I’m wanting to watch that output through connecting the uart lines of an rpi3 to the mcu and printing the uart out to stdout through pyserial.

In going through this, I realized that if you print things too quickly data seems to be lost in the logs. What is the best process for getting around this?

Example code:

from datetime import datetime

for i in range(5000):
    print("UTC "+ str(datetime.now()) + " : " + str(i) )

Expected output ( aka what I see on my local laptop )

UTC 2023-04-08 01:13:34.726017 : 0
UTC 2023-04-08 01:13:34.726069 : 1
UTC 2023-04-08 01:13:34.726075 : 2
UTC 2023-04-08 01:13:34.726079 : 3
UTC 2023-04-08 01:13:34.726082 : 4
UTC 2023-04-08 01:13:34.726086 : 5
UTC 2023-04-08 01:13:34.726089 : 6
UTC 2023-04-08 01:13:34.726093 : 7
UTC 2023-04-08 01:13:34.726096 : 8
UTC 2023-04-08 01:13:34.726100 : 9
UTC 2023-04-08 01:13:34.726103 : 10
UTC 2023-04-08 01:13:34.726106 : 11
UTC 2023-04-08 01:13:34.726110 : 12
UTC 2023-04-08 01:13:34.726113 : 13
UTC 2023-04-08 01:13:34.726116 : 14
UTC 2023-04-08 01:13:34.726120 : 15
UTC 2023-04-08 01:13:34.726123 : 16
UTC 2023-04-08 01:13:34.726126 : 17
UTC 2023-04-08 01:13:34.726130 : 18
UTC 2023-04-08 01:13:34.726133 : 19
UTC 2023-04-08 01:13:34.726136 : 20
UTC 2023-04-08 01:13:34.726140 : 21
UTC 2023-04-08 01:13:34.726143 : 22
UTC 2023-04-08 01:13:34.726146 : 23
UTC 2023-04-08 01:13:34.726149 : 24
UTC 2023-04-08 01:13:34.726153 : 25
UTC 2023-04-08 01:13:34.726156 : 26
UTC 2023-04-08 01:13:34.726159 : 27
UTC 2023-04-08 01:13:34.726176 : 28
UTC 2023-04-08 01:13:34.726179 : 29
UTC 2023-04-08 01:13:34.726182 : 30
UTC 2023-04-08 01:13:34.726185 : 31
UTC 2023-04-08 01:13:34.726188 : 32
UTC 2023-04-08 01:13:34.726192 : 33
UTC 2023-04-08 01:13:34.726195 : 34
UTC 2023-04-08 01:13:34.726198 : 35
UTC 2023-04-08 01:13:34.726201 : 36
UTC 2023-04-08 01:13:34.726204 : 37
UTC 2023-04-08 01:13:34.726208 : 38
UTC 2023-04-08 01:13:34.726211 : 39
UTC 2023-04-08 01:13:34.726214 : 40
UTC 2023-04-08 01:13:34.726217 : 41
UTC 2023-04-08 01:13:34.726220 : 42
UTC 2023-04-08 01:13:34.726224 : 43
UTC 2023-04-08 01:13:34.726227 : 44
UTC 2023-04-08 01:13:34.726230 : 45
UTC 2023-04-08 01:13:34.726233 : 46
UTC 2023-04-08 01:13:34.726236 : 47
UTC 2023-04-08 01:13:34.726240 : 48
UTC 2023-04-08 01:13:34.726243 : 49
UTC 2023-04-08 01:13:34.726246 : 50
 [ this goes all the way smoothly to 5000 ]

output from balena logs

As you can see, hardly any of the logs were registered. I’m perfectly fine with slower latency or going into a terminal or something to see the real output - especially since we’ll need logs that last for weeks at a time.

What’s the balena way of tackling this?

[FossFan]

Looks like this other forum post had similar issues. It appears that its a browser issue on the account that the terminal command balena logs works.

Logs missing - only for some computers

Yes, the computer with problems is my work computer. I use a VPN for my work computer when out of the office, but not when in the office. I have experienced the problems when in the office. There aren’t any differences in how my personal and work computers are connected while in the office. I have docker installed on both my work and personal computers. It is not running on my work computer (which is experiencing the issues), but is running on my personal computer (which is not). I do not …

[FossFan]

Looks like there are still issues even with slower prints and the balena log command ( although the cli drastically improved the performance ). I am unable to reliably print all the characters that I need even at just 100 lines per second with the print commands bundled into one transaction.

import time 
from datetime import datetime

print ( "bundled logs test start" )
count = 0
temp_str = "New String: \n"
for i in range(5000):
    temp_str = temp_str + "UTC "+ str(datetime.now()) + " : " + str(i) + "\n"

    target_bundle_size = 100
    if count >= target_bundle_size -1 :
        time.sleep(1)
        print(temp_str)
        count = 0
        temp_str = "New String: \n"
    else:
        count = count + 1

How do I go about getting reliable logs?
Admittedly, this seems like a critical bug to me. How are you supposed to debug when you aren’t given all of the data?

[thgreasi]

Hi,
Can you clarify what the output is if you press the download button, or even better if you could share that file, including any system warning that might be printed at the very top.
This would help us identify whether the logs are missed while your browser/cli reads them, or whether they are dropped while we are storing them as the device streams them.

Kind regards,
Thodoris

[FossFan]

oloid-testers_james-office-21.04.23_13_47_35_(-0600).txt (76.5 KB)

The download seems more reliable, but it seems that they are being suppressed. How do you go about collecting the non-suppressed prints? Also, what is the timeline of the downloaded logs? We’d be wanting to setup a time frame of several weeks to debug more difficult issues ( like memory leaks etc )