JS8Call-improved
Replies: 39 comments 34 replies
|
John, If you can, please show a screen-shot of the whole JS8Call window when this occurs with 3.0.2. Also, show a screen shot of the Settings->Networking & Autoreply window: 73, |
|
WIll do, once Field Day is over. |
|
Joe, Thanks and 73, John W2KI 
|
|
John, Unfortunately, I don't see any reason why that should happen. If you don't mind experimenting a little, try the latest v4 beta-test version and see if it still does this. I suspect that it will perform the same, but it's worth a try anyway. If you are not comfortable doing that, I understand, but it should not cause any problem. You can download it from: 73, |
|
@John-W2KI I just tried it on 40m with a couple of groups, and every reply shows in the center window as expected. I tested with the latest v4 beta version. I then did the same test using 3.0.2, and it worked as expected: Every decoded call showed in the RX Text window. There does not seem to be a problem with 3.0.2 as far as I can tell. Those tests were on Linux Mint 22.3. Since I did not observe the problem on Linux, I tried the same tests on Windows, with v4-beta and with 3.0.2, and neither exhibited the "missing" decodes addressed to me in the RX Text window. If you don't find success with installation of a newer version of JS8Call, I suggest that you consider setting up JS8Call with a fresh set of settings. Here are where your settings are located (you might want to back them up by renaming the folder and let JS8Call create new settings): On Linux: In your home directory, in the .config directory there is a file .called JS8Call.ini. If you ran JS8Call with a "-r" modifier (for another radio, like "js8call -r ic705"), then you would see the settings file named "JS8Call - ic705.ini" there. This .ini file is what you need to back up. It would be wise to also back up your log and other temporary files. They are located in a folder named "JS8Call" (or "JS8Call - ic705" if you used a secondary radio) in the home directory, in the .local/share directory. On Windows: It is a little simpler as all the files (both .ini and log files) are located in your home directory in the AppData\Local directory in a folder called "JS8Call" (or "JS8Call - ic705" if you used a "-r" secondary radio). Hopefully you will find success. 73, |
|
Joe, I really appreciate your spending time on this. Because it happened to me multiple times on 3.0.2 and never on 2.2.0 I was sure I had found something. But I will certainly do more testing as you suggest, and will report either success or failure. BTW, I'm on Win 11 Pro, with a Dell Pro Max 16 Plus laptop (64GB Ram, Intel Core Ultra9 processor with 24 cores 24 logical processors), I'm sorry to have made you spin your wheels in vain. 73, John W2KI |
|
No problem John - it's not in vain since you demonstrated a real problem. We just need to find the source. Maybe it's because you have too many cores in that dinky little CPU -- Ha, ha! 73, |
|
Joe, |
|
John, Try it 5 times without JS8Spotter running, then connect JS8Spotter and try it 5 times. That should yield enough instances' worth of data to draw some kind of conclusion. 73, |
|
Joe, I'm getting dizzy.... I must say that I did not use the same group query for every test. Not smart of me to have introduced another variable. So I think I'm still in the soup. Did not continue, in a bid not to annoy on-air respondents. My past life involved with development and rigorous quality assurance is in the past. At 83, I don't quite have the patience I used to. A good step might be to record audio from air, then connect two machines back to back with one playing audio (or a bit less rigorous perhaps would be just one machine playing to its own JS8Call via a virtual audio cable). If I'm able to muster up energy at some point I might try this. So nothing proven as yet.... 73, John W2KI |
|
John, Another question: Have you ever observed the problem without JS8Spotter connected to JS8Call? 73, |
|
To your most recent question, "Have you ever observed the problem without JS8Spotter connected to JS8Call?": Yes, see the last two lines of my comment from about an hour ago, "Joe, To answer your next-to-last question, ".... but if you have audio notifications enabled in either/both JS8Call and/or JS8Spotter (or anything else), disable all audio notifications and try it. " I do have audio notifications enabled. I have not tried this, but I will. 73, John W2KI |
|
Joe, Just tried with Js8Call v4B, All audio notifications OFF, js8Spotter connected. Still FAILS. All responses to query shown in Band Activity window do not appear in RX text window. 
73, John W2KI |
|
John, I apologize for not carefully reading your earlier comment. This may be a silly quesion, but do you have your scroll-bar slider pulled all the way down in the RX Text window? In your screen shot, it kind of looks like it might not be pulled all the way down to reveal more replies. 73, |
|
Joe, Yes, it is most certainly pulled all the way down. :-) 73, John W2KI |
|
I tried this on MacOS and everything worked here normally, as well. It's been awhile since I've looked at that portion of the code. But I'll browse thru there when I get time and see if there's anything that stands out that could cause a potential threading issue on Windows with multiple simultaneous decodes. Those member functions of the UI_Constructor class were broken out of mainwindow.cpp when I did the codebase refactor back in Dec/Jan. So they're much easier now to read and try to pick out potential issues. And they are compiled as object code now, which should provide more efficient threading and memory footprint. |
|
After multiple tries, I still can not duplicate this problem on my Win11-based station. I would think such a problem, if generally present, would have been reported by now. Strange one John! 73, |
|
Another question for you @John-W2KI ... If you run with JS8Spotter connected, and filtering in JS8Spotter set up so that all calls to your callsign are displayed, when you run this test and fail to see all the replies show up in the RX Text window in JS8Call, do those replies show, or do they fail to show in JS8Spotter? In other words, are they being passed through the API yet just failing to display in JS8Call's RX Text window. Maybe that will help @Chris-AC9KH narrow down the problem point in the code. 73, |
|
Good thought, Joe. The answer is, YES, all of the directed replies DO appear in JS8Spotter. And to recap, all of the replies appear as in the JS8Call Band Activity window, but only a very few appear in the JS8Call Rx text pane. But confusingly, some few times all of them DO appear in the Rx text window. (Checked on multiple recent test instances where I had captured JS8Call screenshots. I can look back and also see all of those results in JS8Spotter). 73, John W2KI |
|
Excellent info @John-W2KI - maybe that will help @Chris-AC9KH noodle out the problem, since it's directly related to the RX Text window presentation. Chris, I wouldn't be surprised if something in the "pills" code or call-filtering functionality is interfering with presentation in the RX Text window. 73, |
|
No, it's nothing in "pills" code. I can't get it to happen at all on Mac after two days. I honestly don't see anything wrong with the code. With JS8Spotter - the API's sendNetworkMessage("RX.ACTIVITY") - every incoming activity triggers a sendNetworkMessage call before the display logic even runs. If sendNetworkMessage does any blocking socket I/O (even brief - TCP send buffer full, Windows socket stack, Spotter process not draining its receive buffer), that call sits inline in this loop, before the buffer-matching/display logic for that same decode and all subsequent queued decodes. Stretch that out across several near-simultaneous replies and you get the kind of timing jitter that would make buffer matching miss entries on some passes thru the shouldDisplay logic. Stopping Spotter doesn't make any difference because Windows doesn't tear the socket down or release the port. Once you've run it the damage is done. Add to that, Windows machines vary wildly in what's running in the background - antivirus real-time scanning, Windows Defender, indexing service, OneDrive, other ham radio software polling COM ports - any of which can introduce scheduling hiccups on Windows for JS8Call. If decode results for 10 stations arrive in a tight burst and the GUI/processing thread gets briefly starved, the queue could build up and entries could be processed in clusters rather than evenly, again stressing the same buffer-matching logic. I think we need to be looking for a local environment issue here rather than a code issue. |
Would it be reasonable to decouple the two functions, sendNetworkMessage and Display Logic, so that they essentially run in parallel, or maybe even preferentially display, then send (reversing the order of processing)? 73, |
|
Thanks, guys. Given what Chris is suggesting, I'll try to do a little isolation here by stopping some of the non-important (to me) background tasks, such as OneDrive, Dropbox, GoogleDrive, maybe some others, and perhaps even NMEAtime2 GPS clock syncing, and see if that helps. Once daylight takes hold, 40m where the groups I'm using for tests mostly lurk, becomes not useful for my batch reply tests. It will have to wait until later or mornings. Thanks for all the brain time you've been directing toward my issue. I hope it's not all in vain. 73, John W2KI |
|
@Joe-K0OG they already are decoupled, it's just the order of execution, which is not an issue. This would have to be duplicatable on all platforms, and more than one isolated instance, before I would consider it a problem in the code. If it is only duplicatable on Windows with more than one isolated instance, then we can look at what either the code, Qt or Windows itself might be doing differently. In this case, 64GB Ram, Intel Core Ultra9 processor with 24 cores doesn't make any difference because JS8Call is very low on resource usage and will run on low-end Raspberry Pi hardware. That doesn't, however, alleviate the fact that Windows itself runs a lot of background crud that can interfere with thread scheduling in a precisely timed application like JS8Call. Even simple things like uncompressing a large tar.gz or .zip archive that contains say 70,000 files that is done in less then 2 seconds on Linux or Mac takes several minutes to complete on the fastest Windows hardware there is. Mainly due to Windows Defender "discovering" and "scanning" every single file in the archive. And you can't turn this off in Windows 11 anymore. Windows "scans" and reports every single network connection on every single socket back to the Mother Ship via its telemetry system. They basically track every single key press, your applications, your network connections and what you do with it. This adds a lot of overhead that other systems don't have. If Windows itself issues an interrupt on every thread to collect its data it sends to the Mother Ship it is entirely possible that applications like JS8Call that rely on millisecond thread timing and buffers can be affected. And this will not be the same on any two Windows computers, and Windows 11 Pro is probably worse than the consumer desktop versions. It is not even repeatable on this affected system. It appears to be intermittent after JS8Spotter is run but there doesn't appear to be any rhyme or reason to that either. |
If they are decoupled, then why not run them in parallel, or at least preferrentially the display module before the API module? 73, |
|
By the way... I turn off as much of that "junk" in Windows as I can when I first set it up, so maybe that's partly why I don't observe the problem on my Windows PC when I test (disabled indexing, disabled updates, disabled telemetry, etc...). 73, |
|
Because that's not the problem. What displays in the incoming pane is gated by the shouldDisplay logic in the processRxActivity() member function of the UI_Constructor class to keep cruft out of it we don't want. The other two aren't gated and all the cruft goes to Band Activity and the API. This would have be repeatable in more than one instance to prove there's a problem there. That entire block of code executes in nanosceconds but that doesn't mean Windows itself, or some other process, is not putting a block on the thread. |
|
It's erroneous to prioritize API feed over RX Text window display, in my opinion. The priority should be display of RX Text window that's the primary use and purpose of JS8Call. I think there is indeed a structural problem with JS8Call if the API feed has priority over RX Text display, whether or not this is easily repeatable on another system, and ought to be corrected. If you won't (and I certainly am not capable), is there someone else who will? 73, |
I guess if somebody wants to re-write this whole member function, have at it. First you need to know what you're trying to fix. Without being repeatable except for one isolated instance (this has never been reported anywhere else), what you're going "fix" is undetermined. Being JS8Spotter is involved, I highly suspect we're dealing with an internal state-caching issue that is highly specific to the Windows network stack cleanup. I suspect starting JS8Spotter breaks JS8Call's internal m_rxActivityQueue state processing due to an I/O write block in Windows. Which would not happen on Unix-based systems because they use a different threading model. Stopping Spotter or turning off the API doesn't do anything at that point because the Windows network socket transitions into a TIME_WAIT state at the OS level and is never completely torn down. The code here is already optimized for the clang compiler's auto-vectorization and LICM, and v3.0.2 was still built with gcc on Windows. I just updated the development snapshots a bit ago with the first Windows builds done with Clang 17. I would suggest re-testing with that latest development build and DO NOT start JS8Spotter. Determine if it acts normally before Windows can create that socket. |
He did test with a recent (a couple of days ago) development build, built with QtCreator/Clang, and still observed the problem. However, @John-W2KI trying another build would be a good idea. 73, |
|
@Joe-K0OG you're not understanding the code and what it does. They don't "compete" for priority. What's displayed in the Rx pane is gated and that HAS to execute after the band activity and API because everything goes to those. The gating logic then determines what gets displayed in the Rx pane. The gating logic determines if it was to your actual callsign, if it's within the offset range, etc.. Otherwise the Rx pane will show everything the band activity does. You can't run the shouldDisplay gating ahead of the actual decodes and still be able to process them. |
|
I don't need to understand the code to know, based upon all you've said, that the API has priority over the RX Text display if the API getting "hung" blocks some text from displaying. That priority is backwards. 73, |
|
@Joe-K0OG no it's not "backwards". You DO need to understand and look at the code. The ordering isn't "API gets priority". It's just the only logical sequence. You send out the raw data first because the gating logic doesn't change what was received and decoded. It only decides what to show the operator. Same place as the Band Activity gets it from except the API sends it out over the network. They are NOT "competing" for the same resource, they are operating on completely different things. The API call sends the raw decoded activity out unconditionally (same as Band Activity - everything that was decoded, no filtering). The shouldDisplay gating logic below it decides what's relevant enough to surface in the Rx pane. These are fundamentally different jobs. The real question is whether sendNetworkMessage is blocking, not because of priority, but because it stalls on a Windows thread. That's why I want it tested without JS8Spotter allowed to be anywhere near it to see if we're getting a latency injection inside the loop due to a Windows sockets issue and resulting I/O write block on the thread. |
|
O.k., never mind. The API gets handled to the expense of the TX Text display. Too bad... Nothing more I can say. 73, |
|
If no one will address this, I suggest that this be closed as "Won't fix"... |
|
This is not posted in Issues. It's posted in Discussions. Just because I'm not going to jump right on changing the execution order in the code doesn't mean I'm not addressing it. I want more data to determine positively what the issue is before I'm going to do anything with it. I'm now three days into running the same setup on Mac and it works perfectly every time. I'm about 6 hours into running the same setup on arm64 Windows 11 on Apple silicon without a single glitch. Which leads me to believe we got a thread blocking issue on this particular machine. After doing a little more research on this the processor could actually be the problem. 
They claim there is settings either in the machine's firmware, or in Windows itself - depending on what the manufacturer of the computer is because each vendor supplies their own licensed copy of Windows for their machines. So what you can get here is a situation where Intel's Thread Director tells Windows' Thread Manager to shunt JS8Call's UI thread over to a low-clocked E-core or an LP E-core to save on power. When 10 stations reply simultaneously, that single, low-power E-core gets instantly buried and it can't move the thread to a performance core on-the-fly like Apple silicon can. It manages to dump the text to the simple, lightweight Band Activity text pane and API. But the heavier Rx pane gating and rendering engine misses its execution window because the thread gets blocked. It is apparently a well-known flaw in Intel's design - they don't even run the same architecture and instruction set on the E-cores that they run on the performance cores in an attempt to cheapen up the chip. The E-cores don't have any of the vector extensions and are basically x86 cores from 20 years ago. But they claim there is settings you can use to bypass it and force the thread on to one of the performance cores at the expense of heat and power consumption. They don't tell what those settings are - contact your manufacturer. This is what it points to since it can't be duplicated anywhere (so far) but on this one machine. But if you are 100% certain that you already know what the problem is, I'll wait for a PR to fix it and won't spend any more time on attempting to track down what's actually causing it. |
|
@John-W2KI if it still happens with the diagnostic code then it can't be a cpu core parking issue. Setting affinity in Windows is only useful for single thread applications, and we run 17 in JS8Call. So Intel's ITD overrides it and parks whatever threads it "thinks" it should on e-cores to save on power consumption. In Intel's architecture they use a traditional I/O bus to RAM and disk so it is not anywhere even close the massive amounts of data the modern arm64 architectures can get in and out of the cpu. I did not find any tools in Windows that allows a developer to watch threads and memory usage. I have Visual Studio installed in my arm64 Windows on the Mac but I've never found such tools there either. It still points to a thread execution delay on burst load (which these processors are notoriously known for). And it seems to be intermittent because you mentioned that on some tests it worked fine, others it didn't. This is most definitely an issue with the cpu not keeping up. The decoder thread runs fine, but then the GUI thread lags. And it doesn't really matter if the GUI is even 1,000 milliseconds behind the decoder as long as it executes. But in your case there is something blocking that thread so it doesn't completely execute. What that something is I'm at a loss to identify it. The laptop I borrowed is a Dell 16 something or another. It appeared to have EVERYTHING installed in it and running and it didn't affect that one. Although I did notice some lagginess in simple things like scrolling a window with the scroll bar - it would sometimes jerk or seem to lag a bit. Or other things like right click context menus would sometimes jerk or lag. But I noticed this thruout the entire UI, not just with JS8Call. Windows copied the MacOS Mission Control, where on Mac you can use a three-finger swipe on the trackpad to tile all open application and select the one you want to come to the top. Except Windows has a button in task bar to do it. When using that I noticed the open applications didn't smoothly render and was jerky, but this may be characteristic of Windows since I don't normally use it and maybe it does that all the time. But even so, with the inconsistencies I notice in the Windows UI, JS8Call ran fine on it and did not fail to print to the Rx pane on multi-decodes. |
|
Doing a little searching I find this, which indicates this issue might be isolated to the 12th generation Intel processors only:
This would explain why we're getting a thread block and why my experimental code failed to work. Thread 1 holds resource A and waits for resource B. Simultaneously, thread 2 holds resource B and waits for resource A. If one thread is on a p-core and the other on a e-core, the p-core executes first, thread 2 sitting on the e-core gets blocked and thread execution is silently skipped. In Qt6 where 64-bit parallelization is built-in (vs Qt5 where it's not), these threads are expected to execute sequentially on time while using the vectorization to take advantage of more modern processors. But the code was never written to run on a defective processor design with thread scheduling bugs in it. So the borrowed laptop test, which I figured was the same thing, is not the same thing. It had a newer 13th gen processor where the hardware fix had already been applied. |
|
That explains a lot. And this old brain actually understands most of it ;-) Since I'm not about to ditch this laptop for one with the next generation chip (it was pretty big bucks for a business-class workstation laptop), I'll learn to live with things as they are. Thanks for digging. |
|
Unfortunately, the 12th gen chips were Intel's first attempt at building a hybrid chip. They were lagging far behind newer technology and they pushed it to market before it was ready. Those series chips put Intel into bankruptcy, with the company posting over $18 billion in losses in 2024. They were talking about breaking the company up and selling it off. Then the government bailed them out last year by sticking $8+ billion into them to keep them afloat. But in the mean time virtually all cloud computing and infrastructure including Google, Amazon, Microsoft's Azure, Oracle, etc has switched to arm64 over the last 5 years. So nobody knows what will happen with Intel in the long term. |
|
@John-W2KI I'm looking at this from a different viewpoint because after further research the experimental code I used to pin processor cores SHOULD work. So now I'm wondering about the audio hardware in that particular machine. With 8 or 10 stations replying in a crowded passband, near-threshold decodes are common. Bit-level errors on flag fields (which may not get the same error-correction treatment as a checksummed message body) become more likely under real on-air conditions. One of the reasons why trying recorded audio doesn't really tell you much. Whatever audio codec/driver stack ships on those machines can also be affected by burst load and cpu thread scheduling on the audio stack. While this won't affect what goes to the API and band activity because that's just basically a one line data dump, even a tiny amount of audio jitter could affect the shouldOverwrite boolean in the gating logic. This is a case where you might get one to print but not the rest because it evaluates to false due to timing jitter with the audio thread forced off onto an e-core. This would also explain why it sometimes seems to be fine - it only manifests when a reply's flag bits specifically get corrupted due to bit-level errors on the flag fields in a burst situation that the FEC takes care of fine, but delayed execution of the audio thread messes up the gating logic. And again, you can't say "well it worked fine on 2.2.0" because that doesn't apply. Qt5 uses a TOTALLY different threading model than Qt6, which is designed to take advantage of the newer multi-core processors. But not when you have one that's got a known thread scheduling bug in it. It's not practical to go thru the code and force every single one of the 17 threads onto P-cores with preprocessor directives for Windows. I'm just looking at the code trying to figure out why forcing the GUI thread onto a P-core didn't do anything. |
|
Chris, I too am not fully confident in the validity of playing back a recording of replies into JS8Call through a virtual audio cable. So I went back to testing direct from the IC-7200's built-in soundcard. To restore my recollection of v2.2.0 working OK, I ran another SUCCESSFUL test with that this morning. I then ran 2 more tests with build 05d8d32 with audio again direct from IC-7200, one test was with Spotter off and the second with Spotter on. I'm somewhat ashamed to say that both tests PASSED, with all replies appearing in the Rx pane. The last test screengrab follows. So it appears I may have been needlessly spinning your wheels while I was testing from an audio file. 
The next test (on 05d8d32) after changing the laptop's power mode back to 'Balanced', and that test FAILED. Subsequent test (on 05d8d32) with power mode set back to Best Performance, also FAILED. Then the next test (on 05d8d32) with settings unchanged PASSED. So now I'm seeing mostly Passing tests (all replies appearing in Rx pane) with build 05d8d32. I've got to tell you, Chris, my aged brain is starting to feel like I'm looking into a kaleidoscope, if you know what those are. 40m is closing down for me know, so I'll stop for the day. Further tests will be on 05d8d32. I suspect more results will be forthcoming. I sure wish I still had my QA group's automated testing tools to correlate results with all the variables.... I so appreciate your continued interest. As they say, 'You're the man!' 73, John W2KI |
|
John, it's an interesting issue and I'm 100% convinced that it's caused by what threads get handed off to what cores at any time. Power mode Balanced will definitely cause Windows to prefer the e-cores. And 95% of the time those will work fine. But during a burst load situation if the system has decided to park 2 or 3 of the critical threads onto one e-core because they look like background processes, so the system "thinks" that it's really saving on power, that core will be totally buried. And yes, 2.2.0 won't have this problem because the threading model used by Qt5 was for monolithic or standard core 32-bit processors. Which back in 2012 when Qt5 came out was designed for mainstream processors of the era like the Core Duo. In addition, 2.2.0 spawned a completely separate decoder process written in Fortran, again designed for 32-bit computing. As of Qt 6.4 in 2022 Qt completely dropped support for the older 32-bit Windows systems. You could still side-load some 32-bit applications like OmniRig but we had to drop support for that because OmniRig no longer works after Qt 6.8.1. Since you can get it to work properly on an intermittent basis it's purely what that particular processor decides at the moment is background (less important) threads vs what it thinks it should run on the cores with vectorization (p-cores). Basically, what happened is that Apple had pulled out of Intel after spending major money on processor development for their own hardware (which the PC world benefitted from). Apple revealed their in-house designed M1, which set the whole industry on its ear. Nobody thought it was even possible to build a processor on 5 nanometer technology. But here Apple has a RISC platform built on arm64 that has absolutely massive data I/O at 1/10th the power consumption of x86_64. Suddenly hot-running, power hungry x86_64 CISC processors were old news. The 12th gen was Intel's answer to it, and let's just say it ain't no M1. In the mean time Apple has gone to 3 nanometer density on the die, and the rest of the industry has followed Apple's lead. It's obvious that arm64 is no longer just a hobbiest board chip and Intel is even further behind, putting them into their present financial situation. So that's the history of the chip. It has some known issues, but that doesn't help your situation. Despite all the complaining about it, and criticism of that chip that you can find on the internet, nobody comes up with a good workaround for it. The e-cores on that chip are Gracemont cores, they have no hyperthreading, they are only good for running very light load background processes to save on power consumption. But the chip design can't hand off a background process that suddenly goes to full load (called a "burst event") to a P-core because the chip's bus can't reallocate RAM on-the-fly like the M-series chips can. So the process ends up stuck on that e-core causing the noted issues. The "trick" in code would be to try to prevent Intel's ITD from handing off critical time-sensitive threads to those e-cores. |
|
John, JS8Spotter doesn't make any difference either. The datapoint where you got three good events, then start Spotter and it fails is just coincidental. What goes to the API and band activity is just a data dump that runs no gating logic at all. Even an e-core can handle that with no issues. processRxActivity does not actually print to the textEditRX pane - that's handled later in the GUI thread in mainwindow.cpp - part of the UI_Constructor class. Which is why I thought pinning that thread to a p-core would "fix it", but it didn't. It's hard to determine which function is failing to execute under burst load - is the gating logic failing to run or returning false? Or is it the GUI thread that fails to execute cleanly? I could put logging lines in there and have you run that. But if it's an out-of-order execution problem because one thread runs on a p-core and another runs on an e-core the logging won't show that. |
|
@John-W2KI I did another build that adds extensive logging at each stage of the process we're looking at in JS8Call. That build is here, and it reverts any of the thread pinning we tried before. This is just standard JS8Call master with a bunch of logging stuff added to it: You need Windows PowerShell installed to run this. From in the PowerShell window (do NOT use cmd.exe) run these commands in order. It will start JS8Call so you can duplicate your issue (on-air preferably). At the same time it will log the output to JS8Log.txt in the root of your home folder. After you duplicate the issue you can shut down JS8Call, zip up that text file and post the zip here as an attachment. It should tell us exactly which link in the chain is breaking. $env:QT_LOGGING_RULES="mainwindow.js8=true" |
|
Will do, Chris. Thanks. 73, John W2KI |
|
Here's the Zip file of JS8Log.txt after an event where I got multiple simultaneous responses to a query but far fewer appeared in the Rx text pane. This with your enhanced logging build 7288ff6. 73, John W2KI |
|
@John-W2KI you also mentioned earlier about a double print of a decoded frame. Don't worry about these. Some people consider it a "bug", but it's actually a pragmatic approach as to how to handle decodes by design. So you'll see this in a log for a normal multiple decode, for instance: What happens here takes place inside processDecodeEvent. JS8 decoders can produce multiple candidate decodes (especially around the same frequency/submode) during a period. The logic tried to prevent the UI and downstream systems from processing the same frame multiple times within a short window. It uses half the period as a threshold as a pragmatic choice - it reduces false positives while still being strict enough to avoid redundant handling within the same or adjacent decode cycles. So the way it works:
So some people have seen this and think it's some sort of "bug" because they get a double print in the incoming Rx pane. But it's not a bug. It can be caused by anything from audio jitter, to aurora effect on the signal, or multi-path signals. The people who complain about it simply don't know how it works. JS8 is not perfect, signal paths aren't always perfect, the code errors on the pragmatic side - better to double print a frame that is detected twice at > 1/2 period than it is to miss decodes because somebody's clock is off by 800 milliseconds. |
|
Interesting. Thanks. I really wasn't worried about the duplicates, just curious. Your explanation makes perfect sense. 73, John W2KI |
|
John, thanks for the log. I was looking at the totally wrong part of the code and using your conditions in the log was able to duplicate the issue on the Mac mini M1 this morning. The reason we couldn't duplicate it is because we weren't using the right commands to get it to happen. I should've went with the detailed logging route to determine what's firing and what's not, right up front. Instead I was looking at code logic, determining something wasn't firing right in processRxActivity, and jumping to conclusions without the data needed to actually diagnose it. So this confirms a real, deterministic bug. Look at the sequence starting at 00:55:27 in your log: This is the erase-and-overwrite logic in processCommandActivity() firing. A reply with " NO" doesn't contain " ACK" or " SNR", so shouldOverwrite = true. All five replies decoded within the same second (00:55:26), so d.utcTimestamp.time().toString() is identical for all of them. Each one's find(..., FindBackward) walks backward from the end of the document and finds the previous reply's own line, because it has the same timestamp string - it erases it before writing the new one. Only the last reply in the burst (W4CAT) survives on screen. Block 7 gets reused five times because each erase deletes the prior insertion, so the block count net-zeroes out before the next insert. @Joe-K0OG this is worth noting for testing things. You have to try every single command that can be processed because this is an instance where it only fails to fire properly using a It's intermittent with the affected command(s) because it only manifests when multiple replies land in the same processActivity() tick with matching resolution timestamps. This never happened in 2.2.0 with the same code in this function because the old Fortran decoder was slow and near impossible to decode a burst simultaneously on the same millisecond tick. That old Fortran decoder might work for FT8, which doesn't contain as much data on multiple frames as JS8. So this part of the code got overlooked when we went to the high-performance decoder. The C++ port removed that accidental throttle. Faster decoding didn't introduce a new bug - it just removed the thing that had been silently protecting everyone from a bug that was already there and not caught until now. Anyway, I coded up a fix for it. Verified it works on both the Mac mini M1 and the M4 Pro. The build you can test on your hardware is here and I'll wait for your verification that it fixed it before submitting a PR to master: |
|
Thanks very much, Chris (and Joe, for your initial encouragement). It raises my spirits to know that what I originally reported turned out to be real. I have your latest build installed, Chris, and will let you know whether or not it produces any failures for me. I seem to have quite a bit of noise here this evening (perhaps from all the neighbors' air conditioners. I'm in a pretty dense community with small lots), so hope to test more early tomorrow. 73, John W2KI |
|
John, after verifying here using the conditions from your log, it did fix it here on my Macs. So I have high hopes it will fire off fine now on your hardware too. It's a quite complex area of the code with stuff getting handed off to several different functions. But the logging broke it down by step by step at each stage to see where it failed. Since we went to the new logging setup where we can debug production software without special debug builds, I plan on leaving those in the code because they cause zero overhead unless you use the logging. An being able to step-by-step diagnose issues in this part of the code is extremely handy. |
|
Chris, I'm elated to report more than 8 successful tests of your build e0c5f50 using a combination of on-air mostly 'Query Msgs' (with at least 7 simultaneous replies), and 'SNR?', 'Grid?', with each showing all received responses in the RX text pane. It's not a rigorous test yet, but this is the first time I've seen such positive results at my station. On a separate note, I still find it confusing when multi-period replies often appear broken up and partial in the RX pane. I can manually correlate the replies by referring to their received frequencies, but I can see how this could be confusing to some operators. I do understand your recent explanation of why multiple messages occasionally appear in RX pane, so I surely don't consider it a 'bug', but just thought I'd mention it. If as you say you'll be leaving the diagnostic logging code inline, will there be a way for a user to turn it on/off while still maintaining other logging functionality? I want to thank you again for sticking with my 'one-off station' anomaly report for so long, and for so thoroughly following through to verification and a fix. I hope you feel all your effort was somehow worthwhile. I'll be looking forward to the next formal release at some point. Thanks again, |
|
John, that sounds good. The multi-line replies are an artifact of some of the replies to commands you send being two frames instead of one because the reply won't fit in one frame. This is something that could be looked at but it's kind of a limitation with the mode design. The reason is because the buffering/assembly path only exists for a fixed set of buffered commands by this routing decision in processDecodeActivity() (with some of my own comments inserted): Varicode::isCommandBuffered(cmd.cmd) is what decides whether a directed command's first frame gets held open to wait for more frames. If it's not checksummed it's freeformed directed text so something like "W2KI YES -05 (5m)" isn't itself tagged with a special buffered-command marker on the wire. It's just directed text sent back to the querying station. So when the first frame of that reply arrives and gets parsed by decodedtext.directedMessage(), whatever cmd.cmd gets extracted from it doesn't match anything in the isCommandBuffered() whitelist. No m_messageBuffer entry ever gets created for this. When frame two of that same reply arrives, it's a plain continuation frame. Not itself re-flagged as a directed message. So it falls into the general activity path in processDecodeEvent.cpp and prints on a separate line. So this continuation frame isn't recognized as belonging to anything. It just becomes an ordinary, un-owned RX activity item, subject to processRxActivity()'s normal display logic, and prints as its own independent line with its own timestamp. There could be a reason Jordan originally designed it that way, maybe to prevent crashing the buffers. The buffering path has real capacity/lifetime costs that free-text replies would multiply exponentially. If every directed reply - not just the checksummed command types - opened a buffer, then an @allcall QUERY CALL or QUERY MSGS burst with 8+ simultaneous responders would open 8+ buffers, potentially across offsets tightly packed within rxThreshold of each other and this might bring the whole system down if any of them have missing symbols waiting for an EOT character holding buffers open. So that would have to be studied very carefully before I'd change anything there. The internal logging can be turned on anytime with environment variables as per the Windows instructions I posted (MacOS/Linux are Unix-based systems so they are different commands). There is several different areas of the code that can be logged as per the information in the README: |
|
@John-W2KI I prepared a PR and submitted it for review: #337 I did remove all the extra logging from this one because it was over 70 lines of code. There's logging stuff left in the code for basic items, but things like this where step-by-step diagnosis of function() execution is necessary isn't really all that useful in the long term. When an issue can't be identified right off, developers are expected to insert custom logging in a build for testing and diagnosis. But leaving the amount of debug logging that I added for this one gets pretty extensive and adds a lot of unneeded cruft to the code. Thanks for reporting this and staying with testing all the theories as to what could be causing it! In the end we did find a real, deterministic bug. |
|
Chris, Understood. I'm glad I was able to help. On a different note, I'd like to report an unrelated instance of unexpected behavior, via a video clip (33MB) showing the problem. How do you recommend I go about it? Thanks, |
|
For a video clip, possibly post a link to the clip on YouTube or Vimeo? |
Uh oh!
There was an error while loading. Please reload this page.
I've run into an anomaly in version 3.0.2 that is not present in v2.2.0. I don't know if this has been reported before, but this is what I've encountered.
In v3.0.2, when I send a group a query for messages or ask for SNR reports, and a number of stations (say 10) reply, all of the replies appear in the Band Activity window pane as you would expect, but far fewer (perhaps only 2 or 3) appear in the central window pane under my transmitted text (I don't recall this window's actual name). This happens every time.
If I do this in v2.2.0, all replies DO appear in the central window pane. This is how it should operate, am I correct? Is this a known bug?
Thanks and 73,
John W2KI
All reactions