Fun with SEQ Log :-)

[W4WMT]

Hi All,

One of the more interesting results from playing with Richie's new SEQ Log is the phenomenon of repeated packets! Consider a snapshot like this, eg from one of the DDCs:

0 0 0 0 0 -2 0 0 0 0...

AFAIK, the only way to produce a snapshot with deltas like that is for a packet to be repeated.
The mind boggles

73

[w-u-2-o]

I've yet to see a negative number in my seq log. Only positives, sometimes large ones. If I ever hear any audio glitches, which typically only happen when I ask the PC to do something else like load a complex web page, I am sure to see some entries in the seq log showing packet drop outs (positive numbers). I have no idea if this is NIC, IP stack, or blocked thread related. I am most suspicious of blocked threads, though, as since I adjusted things to eliminate the dreaded red box indicator of blocked display threads I almost never get drop outs under any circumstances.

[W4WMT]

I agree that a "lone wolf" cluster of dropped packets (indicated by a single positive delta) is probably due to a blocked thread during a very busy period where the computer is off doing other things unrelated to its SDR duties. The DDC, DUC, and audio streaming threads in Thetis are already being given the highest possible priority available to any Windows task (other than kernel stuff) thanks to the MMCSS, but there's only so much the thread scheduler can do before it gives up and dumps data on the floor.

Repeated packets, though, are a mystery to me. Wouldn't that almost have to be a bug in the fpga? Can the Windows stack do something like that on its own?

73

[w-u-2-o]

Yes, in fact that was why Warren put the packet reordering code into PowerSDR. In fact, we were all waiting for the first instance of negative numbers to be reported, so congratulations

@ramdor: negative numbers in Bryan's seq log...

[ramdor]

I would have expected some more non 0 numbers in the next snapshot really. If there are no more seq errors above -2 line, then the packet following the sequence number from the -2 picket is now correctly sequenced. In essence everything went back 2 sequence numbers.

I would have expected something like this...

DCC2
s0=0 0 0 0 0 0 0 0 0 0 0 0 0 -2 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 11/08 17:39:24:124
s1=0 0 0 0 -2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 11/08 17:39:23:984

That is very interesting indeed, because even if the packet is out of order, its sequence number is used, and the next would have to follow correctly without adding a new seq snapshot.... or.... be out of order in such a way that it became reordered.

Edit: If it had been a -1 then I wouldn't expect the above.

Richie.

[w9mdb]

Where is this seq log?

[Tony EI7BMB]

I've yet to see anything in the log , am i just lucky or perhaps something else not quite right in my set up I wonder ?

[ramdor]

I've yet to see anything in the log , am i just lucky or perhaps something else not quite right in my set up I wonder ?

Don't touch anything Tony All perfect by the sounds of it.

[Tony EI7BMB]

I'll step away from the computer Richie

[W4WMT]

Right Richie! It's like the "packet sender" just hit the rewind button, went back two packets, and started over from there

That must be a firmware fpga glitch!

[ramdor]

So... the wait continues then for some true out of order reports that can be fixed with a re-ordering system

Richie.

[W4WMT]

Hi Richie,

Yes, I believe that is correct.
That is, I think a true out-of-order event should have a delta snapshot like this:

0 0 0 1 -2 1 0 0 0...

In this case, the packet sequence would be like this:

1 2 3 5 4 6 7 8 9...

That is, everything is in order except the #4 packet and #5 packet have traded places.
This is the target scenario for Warren's PRO system.
But AFAIK, no one has captured this critter in the SEQ log, yet?

73

[W4WMT]

From Scott's post in the main 2.6.9 thread:

******************
However, more interestingly, Bryan appears to be the first person to report negative numbers, i.e. packets out of order. So it can and does happen with Thetis as well as PowerSDR. And the numbers are low, just like expected. Therefore it may be worth adding the packet reordering code.
******************

Hi Scott,

I may have captured some negative delta numbers, but not the ones we were looking for. The pattern I am seeing represents repeated packets, not out of order packets. I don't think the PRO can help much with that sort of weirdness!

Nevertheless, I agree, the PRO code should be added. I am getting around to it, albeit slowly. Work is kind of a freakout these days

73

[w-u-2-o]

Yup, I'm really starting to hate work, too

[ramdor]

However as it stands, I am still waiting for some -ve reports that prove that PRO will actually do something if it was in there

Richie.

[W4WMT]

However as it stands, I am still waiting for some -ve reports that prove that PRO will actually do something if it was in there

Richie.

That's correct!

Maybe we don't need a "packet reordering" algorithm, so much as we need a "lost packet finding" algorithm

73

[ramdor]

Hi Bryan,

Just to confirm your expectations, this is a quick grab of an 'out of order' test, with the option turned on in 'clumsy 0.2'.

outOfOrderExample.PNG (7.95 KiB) Viewed 62211 times

Richie.

[W4WMT]

Yep, that's the signature we're looking for!

Also, patterns like:
0 0 0 2 -2 -2 2 0 0
and
0 0 0 3 -3 0 -3 3 0

Those are the sorts of things the PRO can put back into order, like it never happened.

73

[W3MMR]

Heres a shot of my log from this morning. Same errors I got yesterday as well. At this time, i was running OBS and making a recording, streaming WebSDR, and had Thetis maximized to 1920x1027. Zero audio glitches, no drop outs, no freeze ups.

seq.PNG (23.93 KiB) Viewed 62141 times

W3MMR

[w-u-2-o]

And finally...

Capture.JPG (59.96 KiB) Viewed 62027 times

[w9mdb]

Where is this seq log located?

[W4WMT]

And finally...

Capture.JPG

The dreaded "repeated" packet, aka a "rewind" packet!
Any clue as to what kind of network hijinks can cause something like that Scott???

73

[W3MMR]

Where is this seq log located?

Under the "Tests" tab in the Setup menu...

[w-u-2-o]

And finally...

Capture.JPG

The dreaded "repeated" packet, aka a "rewind" packet!
Any clue as to what kind of network hijinks can cause something like that Scott???

73

The best I can do is re-post Warren's notes from back in Dec 1017. Mind you that this describes a situation and a solution for PowerSDR, not necessarily Thetis, but as the root cause is apparently external to both programs it is likely both programs are susceptible to a greater or lesser degree:

The packet reordering software came about because Manfred, XQ6FOD, collected some data indicating that received packets were occasionally not being processed in the PowerSDR software in the same order that they arrived on the network. I was able to quickly determine that the problem was in the Windows networking software. I don't know if the Windows programmers consider this a bug or a feature; however, what seems to happen is that when more than one packet has been buffered in the Windows software, the most recently received packet is sometimes given to the PowerSDR software first, followed by the older packets. In other words, Windows is not always applying a FIFO (first-in first-out) ordering.

At this point, there were two alternatives: (1) write some simple software to check the order of packets delivered to PowerSDR and reorder them if the ordering is not correct, or (2) explore software such as WinPcap to bypass the Windows network software. None of the programmers has had time to explore (2) in depth, and, I suspect that would lead to some new challenges. So, I wrote some simple software to take approach (1).

It is easy to check the order of the packets since each includes a "sequence number". Re-ordering does add some minimal latency. For example, consider a situation where let's say four packets (0, 1, 2, 3) have arrived at the computer but Windows returns them in the order 3, 0, 1, 2. When the packet re-ordering software sees packet 3, it must buffer it and pass along packets 0, 1, and 2, before it passes along 3. Therefore, we have to add a latency of one packet to be able to correct for one out-of-order packet. Similarly, if we want to correct for multiple out-of-order packets within a certain window of time, we much increase the latency more. This is the reason there is a Latency control in Setup. I'm not sure it ever needs to be set to greater than 1; however, the control is there so we can get some feedback from users and learn about this.

Here are a few other comments about packet reordering:

* It works only for incoming (receive) packets. I do not know if the problem is occurring for "outbound" packets, TX I/Q data and audio. The PowerSDR software has no way to know if those packets are appearing on the network in the same order that they are being sent to Windows. However, IF this is occurring, it could be corrected in the FPGA code by checking the sequence numbers of the outbound packets and reordering appropriately.

* This does NOT fix ALL dropout problems -- they can occur for many reasons when the computer does not have sufficient processing power or when other issues in the system are causing Deferred Procedure Calls. That said, some operators have reported a significant reduction in dropouts from the reordering software.

[ramdor]

....and still PRO isn't going to do anything for that single -1 when the packet following is the one expected. Ideally, if there is some sort of network issue one would expect an out of order problem somewhere in the following packets, but no, everything is sequenced correctly.

Odd indeed.

[w9mdb]

One other solution would be to use RUDP. But I guess we might not have enough room in the rigs memory to do it?
https://en.wikipedia.org/wiki/Reliable_ ... m_Protocol
Here's a C# implementation
https://github.com/MatthiWare/RUDP.Net

[w9mdb]

I'm guessing these numbers aren't good....I'll see a pattern like this repeated but shifting by one "s#" each time
DCC0
s0=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 243 0 0 0
s1=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 85 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s2=0 0 0 123 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s3=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 118 0 0 0
s4=0 0 0 0 0 0 0 0 0 0 0 0 0 0 784 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s5=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1520 0 0
s6=0 0 0 0 321 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s7=0 0 0 0 0 0 0 0 940 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s8=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 516 0 0 0 0 0 0 0 0 0 0 0
s9=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 517 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s10=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 162 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s11=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 59
s12=0 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s13=0 0 0 0 3 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s14=0 0 0 0 0 0 0 0 0 0 0 0 0 0 3 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s15=0 0 0 0 0 0 0 0 0 0 0 0 0 0 3 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s16=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 39 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s17=0 0 0 91 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s18=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 30 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s19=0 0 23 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0

DCC0
s0=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 85 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s1=0 0 0 123 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s2=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 118 0 0 0
s3=0 0 0 0 0 0 0 0 0 0 0 0 0 0 784 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s4=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1520 0 0
s5=0 0 0 0 321 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s6=0 0 0 0 0 0 0 0 940 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s7=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 516 0 0 0 0 0 0 0 0 0 0 0
s8=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 517 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s9=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 162 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s10=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 59
s11=0 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s12=0 0 0 0 3 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s13=0 0 0 0 0 0 0 0 0 0 0 0 0 0 3 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s14=0 0 0 0 0 0 0 0 0 0 0 0 0 0 3 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s15=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 39 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s16=0 0 0 91 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s17=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 30 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s18=0 0 23 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s19=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 752 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0

DCC0
s0=0 0 0 123 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s1=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 118 0 0 0
s2=0 0 0 0 0 0 0 0 0 0 0 0 0 0 784 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s3=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1520 0 0
s4=0 0 0 0 321 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s5=0 0 0 0 0 0 0 0 940 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s6=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 516 0 0 0 0 0 0 0 0 0 0 0
s7=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 517 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s8=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 162 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s9=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 59
s10=0 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s11=0 0 0 0 3 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s12=0 0 0 0 0 0 0 0 0 0 0 0 0 0 3 0 0 0 2 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s13=0 0 0 0 0 0 0 0 0 0 0 0 0 0 3 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s14=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 39 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s15=0 0 0 91 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s16=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 30 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s17=0 0 23 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s18=0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 752 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
s19=0 0 0 0 0 0 0 0 0 0 0 0 0 0 63 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0

[w-u-2-o]

w9mdb: they may be good or bad. If you have a torrent of these reports then it is bad, and indicative of a problem somewhere. The potential problem list is LONG.

If it's just a few now and again and you don't hear anything (pop, clicks, etc.) then it really doesn't matter too much and it's nothing to stress over.

[w9mdb]

How does one know if it's a torrent? There's no time tag on these things.
Does the seq log just keep appending? That wouldn't seem like a good idea unless these sequence problems are very infrequent.

[ramdor]

A couple of things.

a) you are using version without time stamps, so log is a bit pointless, the s0-s19 could be spread over hours, we cant tell
b) there are no -ve numbers
c) all +ve's signify packet loss, which can be 1e6+1 things
d) a new snapshot drops s19, adds s0, and everything moves down
s0 is the latest
s19 is the oldest
e) the packet delta (received sequence number vs expected) following your large number deltas are 0, which 100% implies that you have packet loss. After that loss everything resumed correctly, you didn't see any of those old packets coming in after the event (would be signified by -ve numbers)

See here : viewtopic.php?f=9&t=3182&start=90#p8975

Richie.