Real-Time DSM Timing Data
Posted: Tue Nov 06, 2012 1:45 am
As requested, I'm porting this information to the forum, from various private emails, as well as consolidating the several confusing messages sent to Bertrand and friends, as the full nature of the issues herein gradually came to light.
By way of background, I had been experiencing the odd glitch with DSM2 data, since I started using DSM2=PPM, instead of DSM2=SERIAL, as I had previously. So I inserted some debug code, such that I could see the real-world timing of related invents in the system. This was achieved by outputting on two spare PORTH pins (G9X board) so that relative event timing could be seen on my logic analyser. The results were truly enlightening and valuable, leaving me wondering why I had not thought of this diagnostics approach before!
The following partial screen shots show logic analyser data collected from open9x (approx. r1541). The various signals displayed include PPM (or UART serial) output, the start and end timing of the mixer interrupt routine (HIGH and LOW levels, respectively) and the same again for the entire setupPulses() procedure. Most importantly for the topic at hand, the data shows the relative timing between those three.
First, let's look at normal PPM mode (no DSM2 involved, yet) ...
Here (above) we see that the mixer routine is completing at a tidy 883us before the start of setupPulses(). Quite good. However, in terms of system latency, it could be said that both mixer and setupPulses() are occurring some 6ms too early, relative to the start of the next PPM output frame. (From previous communications, I am confident this was not the intention and indeed, my own fuzzy analysis of the code suggests it should be otherwise. Clearly, we've missed something.)
I should note, just in case it does actually crop for someone else, that I could swear the first time I collected the above PPM normal mode data, the timing was much closer in, as intended by design. But I have tried many things and many times to try and get different results and simply cannot. So for now, I have to write the former recollection off to my now almost famous, unreliable memory.
Now, DSM2=SERIAL mode timing ...
Here we see that setupPulses() is consistently completing just 1.5us before next output stream. Really good. However, now the mixer's completion is way back at around 4,000us (4ms) prior to setupPulses(). I believe the intention here was to have only 500us. So something not quite right there, also.
So far, nothing too serious in terms of practical operation has been discovered. However, this will not remain the case, as we continue onto DSM2=PPM mode ...
DSM2=PPM mode ...
Here we see that setupPulses() is not so ideally timed, but still a safe and respectable 1.13ms before start of next output frame.
But something is wrong with the mixer interrupt timing, entirely.
Let's zoom out to get a clearer picture ...
Unlike the other cases above, where the mixer interrupt is always phase locked in time relative to setupPulses -- I have viewed those zoomed right out, also -- this time we can see that the mixer interrupt is no longer phase locked, but rather asynchronous and drifting backwards in time, relative to setupPulses().
Perhaps more importantly, further tests showed that, on the odd occasion when the mixer interrupt collides with setupPulses(), then the end of setupPulses() is delayed until after the start of the next output frame, resulting in unpredictable or even no output for that frame.
- - -
So there it is. I hope I've laid things out clearly, without missing anything important out, whilst still avoiding the many confusing charts and musings Bertrand et al had to endure the first time around.
Naturally, I am available to run more tests, as the need arises. However, it would be best to email me direct. (I believe all those who need, already have my direct email address.) Thanks.
Gruvin.
P.S: [EDIT: The following now known to apply only to the ATmega2560/G9X board ...] Tangled up with all the above originally, was a problem with the individual bit timings of DSM2 data in DSM2=PPM mode -- namely that they varied from 6us to 10us in length, when they should have been exactly 8us, for 125,000bps. This actually still worked in practice -- but only just! In any case, that issue has now been fixed, so I have left it out of this post entirely, to save the probable confusion. If anyone wants to see the before and after "open9x-r1541 fix" timing diagrams, I have kept some PNG images on file.
By way of background, I had been experiencing the odd glitch with DSM2 data, since I started using DSM2=PPM, instead of DSM2=SERIAL, as I had previously. So I inserted some debug code, such that I could see the real-world timing of related invents in the system. This was achieved by outputting on two spare PORTH pins (G9X board) so that relative event timing could be seen on my logic analyser. The results were truly enlightening and valuable, leaving me wondering why I had not thought of this diagnostics approach before!
The following partial screen shots show logic analyser data collected from open9x (approx. r1541). The various signals displayed include PPM (or UART serial) output, the start and end timing of the mixer interrupt routine (HIGH and LOW levels, respectively) and the same again for the entire setupPulses() procedure. Most importantly for the topic at hand, the data shows the relative timing between those three.
First, let's look at normal PPM mode (no DSM2 involved, yet) ...
Here (above) we see that the mixer routine is completing at a tidy 883us before the start of setupPulses(). Quite good. However, in terms of system latency, it could be said that both mixer and setupPulses() are occurring some 6ms too early, relative to the start of the next PPM output frame. (From previous communications, I am confident this was not the intention and indeed, my own fuzzy analysis of the code suggests it should be otherwise. Clearly, we've missed something.)
I should note, just in case it does actually crop for someone else, that I could swear the first time I collected the above PPM normal mode data, the timing was much closer in, as intended by design. But I have tried many things and many times to try and get different results and simply cannot. So for now, I have to write the former recollection off to my now almost famous, unreliable memory.
Now, DSM2=SERIAL mode timing ...
Here we see that setupPulses() is consistently completing just 1.5us before next output stream. Really good. However, now the mixer's completion is way back at around 4,000us (4ms) prior to setupPulses(). I believe the intention here was to have only 500us. So something not quite right there, also.
So far, nothing too serious in terms of practical operation has been discovered. However, this will not remain the case, as we continue onto DSM2=PPM mode ...
DSM2=PPM mode ...
Here we see that setupPulses() is not so ideally timed, but still a safe and respectable 1.13ms before start of next output frame.
But something is wrong with the mixer interrupt timing, entirely.
Let's zoom out to get a clearer picture ...
Unlike the other cases above, where the mixer interrupt is always phase locked in time relative to setupPulses -- I have viewed those zoomed right out, also -- this time we can see that the mixer interrupt is no longer phase locked, but rather asynchronous and drifting backwards in time, relative to setupPulses().
Perhaps more importantly, further tests showed that, on the odd occasion when the mixer interrupt collides with setupPulses(), then the end of setupPulses() is delayed until after the start of the next output frame, resulting in unpredictable or even no output for that frame.
- - -
So there it is. I hope I've laid things out clearly, without missing anything important out, whilst still avoiding the many confusing charts and musings Bertrand et al had to endure the first time around.
Naturally, I am available to run more tests, as the need arises. However, it would be best to email me direct. (I believe all those who need, already have my direct email address.) Thanks.
Gruvin.
P.S: [EDIT: The following now known to apply only to the ATmega2560/G9X board ...] Tangled up with all the above originally, was a problem with the individual bit timings of DSM2 data in DSM2=PPM mode -- namely that they varied from 6us to 10us in length, when they should have been exactly 8us, for 125,000bps. This actually still worked in practice -- but only just! In any case, that issue has now been fixed, so I have left it out of this post entirely, to save the probable confusion. If anyone wants to see the before and after "open9x-r1541 fix" timing diagrams, I have kept some PNG images on file.