VS Arduino
>> >> Serial Monitor loses high volume usb data
https://www.visualmicro.com/forums/YaBB.pl?num=1660533075

Message started by cfeied on Aug 15th, 2022 at 3:11am

Title: Serial Monitor loses high volume usb data
Post by cfeied on Aug 15th, 2022 at 3:11am
I am not attaching build output because I believe it is not germane to this particular serial terminal problem. Instead, I am attaching excerpts from the serial terminal logs showing missing serial data, along with snaps from a port monitoring sniffer showing what's happening at the serial signaling layer.

===
My Visual Studio, Visual Micro, and Teensyduino are all up to date. I am using a teensy device configured for dual USB serial emulation. Both ports work perfectly for "ordinary" communications. Using a single usb_serial port, I am able to send at least 3 Mbps from the device to a windows10 .net application without data loss. This is achieved by dedicating a .net thread to continuously read the virtual serial port on the PC, buffering received data within my application. This works equally well with any of the teensy "serial USB" ports (Serial, SerialUSB1, SerialUSB2).

Now I am using one of those serial ports to send ascii output used to trace program progress.  I'm using the visual micro serial monitor window with everything set up for release mode (i.e., no debugging). I'm experiencing two distinct problems with the serial terminal.

===
Problem #1:
The VM serial terminal periodically hangs, leaving my device running normally but with no further output appearing in the terminal window.  The device is listening on the serial ports and continues to respond to commands and to send responses, though the responses are not (initially) visible in the VM terminal.

By design, teensy usb_serial ports rely on USB transport and do not respond to RTS or DTR, so playing with those settings makes no difference. Disconnecting and reconnecting the serial terminal likewise makes no difference.

However, if I turn off power to the device (which causes the serial port to be torn down in Windows) the "missing" output very often suddenly appears in the serial terminal and is correctly written to the log file.

I do not yet have a sniffer capture of this behavior -- it happens just often enough to be annoying and I've not been able to reproduce it on demand.

= = =
Problem #2:
I'm seeing periodic loss of data where the missing data chunk occurs at different times but is always exactly 128 bytes. This does not happen with certain other terminal monitor programs, nor does it happen with my own code to read and display data from the usb_serial port.

A port sniffer shows that when the VM terminal requests and receives a a first group of bytes and then requests and receives a second group of bytes, 128 bytes are simply missing between the end of the first group and the beginning of the second group. The sizes of the first or second group of bytes does not matter -- they can be any size, and I'm still missing 128 bytes between them.

I don't think it's a coincidence that the teensy 3.6 USB serial port implementation has two buffers of 64 bytes each. I suspect the USB_Serial driver on the PC and/or on the teensy may be suboptimal, causing data to be discarded when the PC doesn't read the serial port fast enough, even though the PC has plenty of room to buffer it.

The thing is that I *can* receive all the data if I use an external serial terminal that reads continuously, but then I lose the extremely useful integration with VisualMicro and the automated port disconnect-connect when compiling and uploading code.

I'm attaching a zip of some files illustrating the data-loss problem.
FirstDataSegment.txt
Missing128Bytes.txt
SecondDataSegment.txt
PortSnifferResults.txt

For this particular example, my device starts up and transmits 18318 characters reflecting initialization activities.

The serial monitor correctly received the first 14281 bytes of ascii data, then 128 bytes are missing, and then 3909 bytes are received correctly. The serial terminal window correctly shows everything that was received, smushed together.

Similar data loss occurs whenever I'm sending a lot of messages in a short time. The problem is easily reproduced, and is worse if I increase the volume of messages.

In my use case, my device has to interact with a number of other external devices with strict timing requirements, so the tracking messages have to be sent rapidly and often are sent in bursts. It would be awfully nice if the VM terminal were able to keep up.  8-)



https://www.visualmicro.com/forums/YaBB.pl?action=downloadfile;file=SerialMonitorProblem.zip ( 20 KB | 1 Download )

Title: Re: Serial Monitor loses data
Post by Tim@Visual Micro on Aug 15th, 2022 at 12:30pm
Lets take these one at a time. Do you know that if you click into the serial terminal it pauses? Then when the port is closed or when you cursor to the end of the terminal output it starts again? There is also a button to control this behaviour but it works the same as all vs output windows.

Does this sound a possibility?

Title: Re: Serial Monitor loses data
Post by cfeied on Aug 19th, 2022 at 10:10pm

Tim@Visual Micro wrote on Aug 15th, 2022 at 12:30pm:
Lets take these one at a time. Do you know that if you click into the serial terminal it pauses? ... Does this sound a possibility?

Hi Tim,

LOL I wish it were that simple. This doesn't appear to be an auto-scroll issue: I'm not clicking in the window at all, and scrolling to the bottom or toggling the auto-scroll button doesn't have any effect.

When the freeze occurs, data stops being displayed at a seemingly random position. Sometimes it happens when a full screen of data hasn't yet been displayed (no scrolling has yet occurred).

After a freeze, I can see my device still blinking its loop monitoring patterns. If I send the device a series of commands that trigger various outputs, I see no response in the terminal but the led blink patterns show that the commands are being received and output is being sent. If data then appears when the device is powered off, I can see that in fact all the responses were sent (multiple pages of data).

To be clear, though, when I power off the device the missing data fails to appear more often than not. Also, the missing output occasionally shows up if I merely click the terminal connect button to disconnect the device, but usually that does not do anything.

The freeze / unfreeze behavior is similar to the way some old green-screen terminal emulators behaved in response to spurious xon-xoff characters. Although I haven't yet been able to catch this freeze happening, when I sniff the port setup negotiation it does appear as if xon/xoff handshaking is at times being requested.

You'll have noticed that I'm working with a Teensy 3.6, which has native USB & sends serial data at USB rates that will overwhelm anything that expects the baud rate setting to be a limiting factor. 

A final thought is that on the device side I'm not looking at DTR/RTS (they have no intrinsic effect in the teensy serialUSB port drivers, but are available to read) -- however, on the the windows side the serial port implementations have some strange behaviors. Furthermore, the .net serial comm wrappers fail to wrap some key elements from the win32API and there are several known nonrecoverable states as a result...

Is there a way I can force handshaking OFF for the connection just to get that out of the picture?

Or perhaps you can make the codebase or at least debugging symbols available for this module?  8-)

thanks,

Craig

Title: Re: Serial Monitor loses data
Post by Tim@Visual Micro on Aug 19th, 2022 at 11:49pm
What speed are you using?

If I recall Teensy virtual com ports have to be handled outside of the normal windows serial port wrapper.

We can look to see what options there might be. Can you please confirm which port and settings you are using for the Teensy. + If you haven't already done so please attach the info request in yellow above.

Title: Re: Serial Monitor loses data
Post by cfeied on Aug 20th, 2022 at 1:26am

Tim@Visual Micro wrote on Aug 19th, 2022 at 11:49pm:
What speed are you using?

If I recall Teensy virtual com ports have to be handled outside of the normal windows serial port wrapper.

I've attached my build output.

The question of serial port speed isn't really meaningful for a teensy. The serial ports are actually just endpoints for USB ports and they run at USB speed, which in this case is 12 Mbps. The concept of serial port baud rate is meaningless since there isn't really a serial port on the teensy side. You can set it to anything and it just gets ignored.

On the windows side the serial endpoints are part of the standard windows usb driver. When connected, windows presents them as ordinary serial ports using all the usual serial layers -- only the transport is different, since the hardware is native USB. 

But I have encountered the problem again and this time there is some evidence that it *might* be related to auto-scroll.

The display spontaneously froze half-way down (image attached) without any human interaction with the terminal. This time I tried clicking repeatedly on the auto-scroll button. At first nothing happened, but after clicking several more times on auto-scroll, the missing data did appear.  I'll await the next occurrence to see whether this is a reliable solution.

===
In the meantime, can you perhaps look at the documents I uploaded for issue #2, in which 128 bytes of data periodically goes missing when data arrives quickly and the VM serial terminal is used? 

I believe this is occurring because the terminal isn't reading the port quickly enough, causing buffers to fill and discard data.

Thanks!

https://www.visualmicro.com/forums/YaBB.pl?action=downloadfile;file=frozen_screen.zip ( 46 KB | 2 Downloads )
https://www.visualmicro.com/forums/YaBB.pl?action=downloadfile;file=Output-MicroBuild_027.txt ( 378 KB | 5 Downloads )

Title: Re: Serial Monitor loses data
Post by Tim@Visual Micro on Aug 20th, 2022 at 1:58pm
Thanks for the info. So for our tests we should use Teensy in Dual Serial Mode where only the main upload port is being used for serial?

Can you try to increase the "vMicro>General>Global Properties>Communications>Screen Buffer Size" to a larger value.

Thanks

Title: Re: Serial Monitor loses data
Post by cfeied on Aug 22nd, 2022 at 4:34pm

Tim@Visual Micro wrote on Aug 20th, 2022 at 1:58pm:
Thanks for the info. So for our tests we should use Teensy in Dual Serial Mode where only the main upload port is being used for serial?

I *think* the port that VM identifies as the upload port is the one I'm currently using for serial ASCII communications between my device and the VM serial terminal.  I'm not 100% sure of that because the Teensy does not use any serial ports for uploading, and in fact, virtual serial ports "go away" during uploading and are rebuilt at runtime only if the user defines them in the device software.

Port assignments in Windows are non-deterministic in the sense that when a USB endpoint is defined with two or three virtual serial ports, Windows does not honor the order defined in the USB request. For example, a dual virtual serial port connection with hard-coded setup request sometimes is assigned so that serialusb0 = Com2 and serialusb1 = Com3, and sometimes it may be the other way around. Once assigned they are stable on reconnect unless some external disruption occurs.

Depending on the installation, I've found that VisualMicro may identify either device port as the "upload" port, though this is stable once established.

In my specific case, the device sets up two virtual serial ports. At the moment, those appear in Windows as Com4 and Com9.  The device and host communicate using a high-speed binary protocol on one port (the SESSION_PORT). The device communicates with the Visual Micro serial terminal on the other port (the DEBUG_PORT). 

My device listens on all device ports for a probe from the host application and responds with a device portID, so serial communication with the VM terminal could be on either the higher or the lower COM port of the pair. However, in the device this communication activity is currently mapped to serialusb1, which is currently mapped to COM4, while serialusb0 is currently mapped to COM9 in WIndows.

At this time, when I "build and run" using VM, it is COM4 that is disconnected and reconnected, and I *think* this means VM identifies COM4 as the upload port.


Quote:

Can you try to increase the "vMicro>General>Global Properties>Communications>Screen Buffer Size" to a larger value.

This was set to 1,000,000 and I have now set it to 10,000,000 & will test to see whether it will affect the 128 byte data loss issue. I suspect it may not, because I sometimes see data loss within the first screenful of data received.

I suspect the problem likely relates to the frequency of reads on the PC side, because I can cause similar data loss in testing by slowing down serial port read activity in my own programs. To keep up with the high speed serial channel I have to put serial port reading in a tight loop on a dedicated thread that does nothing but feed a circular buffer.

Of course my ascii output for debugging purposes is at nowhere near that sustained rate, but it is somewhat bursty when I'm tracking microsecond intervals between block writes for an SD card filesystem or something like that.


Also: I figured out some of what was going on with problem #1 (the "terminal freezing problem").

The freezing is definitely due to AutoScroll getting turned off. I still do not know what causes / caused AutoScroll to occasionally freeze when I'm working in a completely different window, but that's not really a critical problem so long as I can un-freeze it. My previous inability to do so (thus my belief that the problem was not with auto-scroll) was due to user error and misunderstanding arising from interactions with an obscure VM bug and a couple of design "features." I will attach a short video illustrating the bug. Here's what was happening:

I always use the VM terminal window at nearly full screen height, so the bottom of the VM window is close to the windows taskbar. If I hover over any of the buttons at the bottom of the VM window, a tooltip appears for that button. If that tooltip is vertically large enough to overlap the taskbar, it begins to flicker on and off as the two battle for visibility (perhaps just Z-order, but since the taskbar is owned by the OS maybe there's even a momentary loss of focus). This can happen with any of the buttons, but as a practical matter the risk is highest for AutoScroll and Auto-Recon because they have the tallest tooltips.  I'd have to shorten the window significantly to stop these two from flickering.

During flickering, the color of the AutoScroll button is constantly changing from enabled to disabled. During this time, clicking on the AutoScroll button often doesn't turn it on, or if it does, it turns back off right away. Your suggestion to check auto-scroll led me to the realization that the flickering is the reason the Auto-scroll button did not un-freeze the screen. When I tried multiple clicks it did eventually work ("because timing??").

Another element contributing to the confusion arises from the fact that VM does not recognize a button click when first regaining focus. After working in another window, the first click on the autoscroll button does nothing at all, regardless of flickering. This "first click" issue is well known in the UX field and is readily addressed through a careful choice of events to handle.

Another point of confusion for me was the fact that "scrolling to the bottom" (as I understand that phrase) does not by itself reactivate auto-scroll, since I scroll to the bottom of a window using the mouse wheel (or occasionally the scrollbar or scroll arrows). What reactivates autoscroll is placing a cursor in the window and moving the cursor to the very bottom of the document. It took me quite awhile to figure that out -- it wasn't clear to me from the documentation, nor had I understood it from anything I found in the forums. It's possible that I may be the only person who would reach for the mouse wheel or scrollbar when instructed to to scroll to the bottom...

Finally, I was misled by the fact that the colors of active, inactive, and hovered buttons are so similar on my system that I can barely tell the difference between them. The text itself does not dim (except for the Connect button, which is dim when connected, which seems more like an ON state than an OFF state). Even after years of VM use I was never sure which pale blue color was ON and which pale blue color was OFF. With a little effort I can tell the difference now, though! But if there's ever a significant new release, it might be worth revisiting those visual cues.

= = = = =
I will test changing the screen buffer size and will let you know whether that affects the remaining data loss scenario.

Thanks!


https://www.visualmicro.com/forums/YaBB.pl?action=downloadfile;file=VisualMicro_bug.zip ( 9097 KB | 1 Download )

Title: Re: Serial Monitor loses data
Post by Tim@Visual Micro on Aug 26th, 2022 at 2:53pm
Thanks for the info. Which vs theme are you using?

I don't think the buffer size will help, it only affects the amount of data retained in the console at any one time. The read buffer is unlimited. I suggested it before the auto-scroll had become clearer.

The serial is read faster than it is displayed on screen, however because the UI is on the main visual studio thread we have to be careful not to slow VS to a crawl when the serial is being read. New users of microcontrollers often put a serial print() in the loop() without a delay() (or last millis check). Visual Micro does attempt to protect from this potentially huge stream of data otherwise the IDE would become unsuably slow.

Sending so much serial to a pc so quickly, might not be best suited for a console inside an IDE, maybe puTTy might be better to read the data.

If you need to use serial debugging that can be configured on a different serial and com port, either a hardware serial port or software serial for example. nb: The serial debugger does by default share the upload port (the port selected on toolbar or vMicro upload menu which won't work well in this high volume case.

Before we test this it would be useful to know this?

Question: Does your serial output send /n (or /r/n) char at any time? if so then after so many chars approx? More than 3000?


Thanks

Title: Re: Serial Monitor loses data
Post by cfeied on Aug 27th, 2022 at 8:21pm

Tim@Visual Micro wrote on Aug 26th, 2022 at 2:53pm:
Question: Does your serial output send /n (or /r/n) char at any time? if so then after so many chars approx? More than 3000?

Thanks for the response.

In VS I use Color Theme "Blue."

I don't *think* the termination characters are related to the issue, for the following reasons.

Sometimes I'm sending status messages (e.g., debugging statements sent to serialUSB1) with a terminating newline character (0x0A). The message length could be anywhere between 0 and 200 bytes before a newline, but not more.

for example, just now I'm timing SD card writes that are a few microseconds long, so the intervals between messages in a group tend to be at least 10 or 20 microseconds and there are gaps of 4  to 16 milliseconds between each series of a half-dozen messages. I do occasionally see data loss in these messages.

After data has been written to the SD card I'm reading it back and sending a hexdump for inspection. This data consists of an ascii representation of the hex code for each data byte, followed by a printable representation of the data (non-printing characters are substituted with "." as is customary). When this data is transmitted, any newline or CR/LF characters that were in the binary data are substituted with a period, and a newline appears regularly after exactly 73 characters. In a scenario like this there are plenty of newlines, yet data loss invariably occurs and is far more frequent than when individual status messages are sent.

The data loss may occur within the first screen of displayed characters, or it may only occur after several screens.  It may occur at any point in a line.

I'll attach a file of the output displayed on the VM serial terminal when sending these short fixed-length lines with a newline character at the end of each line.  If you scroll through you can easily spot the positions of data loss because the affected line will be either longer or shorter than a normal line.
=====

I think the data loss likely occurs because the data is sent on a fast port without adding an artificial delay. This sometimes results in bursts of data that are accepted by the sending USB port but are not read quickly enough on the receiving USB port.

A USB serial port on the teensy 3 can transmit about 25K lines / second, and the teensy 4 can transfer at least 500K lines/second. We can receive and buffer at that rate on the PC without difficulty, but only by using a dedicated thread to do so.

Obviously the VM serial display itself won't be able to keep up with that kind of throughput. However, I believe my problem is manageable. I think the total amount of data being sent over a few seconds is easily displayable, but is being sent in bursts so that the data rate is (momentarily) too fast for the rate at which the VM terminal reads the port. If the VM terminal does not read the port rapidly enough, data will be discarded somewhere on the device side. 

If I had more memory available, I would buffer the output and send at a more controlled rate. However, I'm space constrained and I'm tracing code that can't be slowed down due to interactions with external sensors and multiple SD and serial flash devices. Writing directly to the port is the best I can do. 

I think this will increasingly become a problem for everybody who uses an emulated serial_usb port (i.e., no actual UART) on any of the newer embedded systems.

May I ask at what rate you are actually reading and buffering the windows serial port?

thanks!

Craig


https://www.visualmicro.com/forums/YaBB.pl?action=downloadfile;file=VisualMicroTerminalDataLoss.txt ( 551 KB | 1 Download )

Title: Re: Serial Monitor loses data
Post by Tim@Visual Micro on Aug 28th, 2022 at 2:07am
That's useful info thanks. Visual Micro supports multiple serial windows open at the same time which does cause even more caution. We will look at moving to streaming the inbound data instead of reading it.

Currently it is read at approx 10hz with a 40k buffer for each read. As a short term workaround we can see if adding an option to control the "read frequency" helps.


Title: Re: Serial Monitor loses high volume usb data
Post by cfeied on Sep 8th, 2022 at 4:17am
I installed the interim release that included the ability to set read timing and timeouts -- thank you for including that functionality!

That did significantly reduce the frequency of data loss, though it did not completely resolve the problem. 

At very fast read intervals, if I rebuild the solution I definitely see alternation of data appearing in the serial port window and verbose output appearing in the output window.

That's actually sort of hilarious to watch. Perhaps certain activities would be better situated in a task and off the gui thread  8-)

Anyway, the data loss is now down to a minimum frequency that allows me to continue working, for which I'm quite grateful.

===
Today I ran into a VM extension incompatibility with the latest visual studio update, and have opened a new issue on the forum for that problem. Thanks again!

VS Arduino » Powered by YaBB 2.6.12!
YaBB Forum Software © 2000-2024. All Rights Reserved.