Re: SSH key exchange fails 30-70% of the time on Netgear X4S R7800

[Sebastian Gottschall]

how can you make sure that no context switch is happening if the kernel 
uses neon instructions by itself? by stopping the kernel?


this is faily impossible. check if this option is on, and disable it to 
make sure that the kernel does not make use of neon instructions



Am 25.03.2020 um 05:25 schrieb Horshack ‪‬:
I excluded context switches as a possible culprit by looping until a 
corruption happened for which no context switches occurred while the 
test was running (ie, at the start of the test I would save the # of 
involuntary/voluntary context switches from /proc//status, then 
check those counts again after the failure - if they were different I 
restarted the test and kept looping until a failure happened in which 
the ctx switch counts were the same.



*From:* dropbear-bounces+horshack=live@ucc.asn.au 
 on behalf of Sebastian 
Gottschall 

*Sent:* Tuesday, March 24, 2020 9:13 PM
*To:* dropbear@ucc.asn.au 
*Subject:* Re: SSH key exchange fails 30-70% of the time on Netgear 
X4S R7800


if the corruption is caused by a context switch the problem can be 
caused by the kernel.

try the following and disable "CONFIG_KERNEL_MODE_NEON"
in the kernel config. this will disable some kernel crypto assembly code

Am 24.03.2020 um 16:11 schrieb Matt Johnston:

Good work narrowing down a test case there.
That's an interesting finding - I guess it might be worth posting on 
OpenWRT lists/forum to try find other testers.
Could it be power related if the tight multiplication loop is 
stressing it somehow? It doesn't seem to be using the Neon 
instruction for anything apart from loads/stores though - is there 
something that the compiler should be doing mixing Neon and non-Neon 
operations?


Cheers,
Matt

(Your emails got held up being over 100kB, I've trimmed the reply 
below and let them through. Apologies to everyone for the stale old 
one that got let through with them just now, I wasn't looking closely)


On Tue 24/3/2020, at 11:23 am, Horshack ‪‬ > wrote:


I was able to isolate the issue to just a handful of assembly 
instructions within fast_s_mp_sqr(), related to the squaring loop. I 
broke that code out into a separate utility that reproduces the 
issue within a few seconds. The failure is somewhat sensitive to the 
data pattern and very sensitive to timing, indicating a likely 
memory/data path issue within my particular router. I'm guessing 
it's the IPQ8065 and not the SDRAM because I can get it to fail with 
a tiny data set easily fits within DCACHE. I can alter the frequency 
of the failure with a single ARM memory barrier instruction, which 
at first implied a superscalar data ordering condition but the 
memory barrier also alters the timing through the DCACHE so that is 
likely the effect it's having. I was able to exclude the VFP/Neon 
register corruption as the cause with some test code. I also 
excluded any context switch-speciifc issue by measuring the # of 
context switches in /proc//status and catching a failure where 
no switches had occurred. I also modified the affinity so the 
utility runs on just one processor to rule out a specific core 
having the issue.


I put the source and binary of my utility on github - if anyone on 
this mailing list has this model router can you give it a try if 
possible? You only need the ipq8065-sqrbug (binary) and 
run-ipq8065-sqrbug.sh (script). Here's the link to the 
repository:https://github.com/horshack-dpreview/ipq8065-sqrbug 





*From:*Horshack ‪‬ mailto:horsh...@live.com>>
*Sent:*Saturday, March 21, 2020 7:54 AM
*To:*dropbear@ucc.asn.au 
>
*Subject:*SSH key exchange fails 30-70% of the time on Netgear X4S 
R7800

Including mailing list for my last two messages below...

Begin forwarded message:


*From:*Horshack ‪‬ mailto:horsh...@live.com>>
*Date:*March 21, 2020 at 7:35:18 AM PDT
*To:*Matt Johnston mailto:m...@ucc.asn.au>>
*Cc:*"dropbear@ucc.asn.au " 
mailto:dropbear@ucc.asn.au>>
*Subject:**Re:  SSH key exchange fails 30-70% of the time on 
Netgear X4S R7800*



Disassembly of fast_s_mp_sqr() and other libtommath functions 
reveals gcc is utilizing the arm NEON SIMD instructions and 
registers for calculations involved with libtommath's mp_word 
scalar. Based on the 64-bit word corruption I see I'm guessing the 
SIMD registers aren't being preserved/restored properly somewhere, 
probably during a context switch, specifically s16–s31 (d8–d15, 
q4–q7), which AAPCS says must be preserved and which I see being 
used in the disassembly of fast_s_mp_sqr(). I'lll write some test 
code later today to see if this is the case, and if so, try to 
track down where and why the registers aren't being preserved.

Re: SSH key exchange fails 30-70% of the time on Netgear X4S R7800

[Horshack ‪‬]

I excluded context switches as a possible culprit by looping until a corruption 
happened for which no context switches occurred while the test was running (ie, 
at the start of the test I would save the # of involuntary/voluntary context 
switches from /proc//status, then check those counts again after the 
failure - if they were different I restarted the test and kept looping until a 
failure happened in which the ctx switch counts were the same.


From: dropbear-bounces+horshack=live@ucc.asn.au 
 on behalf of Sebastian 
Gottschall 
Sent: Tuesday, March 24, 2020 9:13 PM
To: dropbear@ucc.asn.au 
Subject: Re: SSH key exchange fails 30-70% of the time on Netgear X4S R7800


if the corruption is caused by a context switch the problem can be caused by 
the kernel.
try the following and disable "CONFIG_KERNEL_MODE_NEON"
in the kernel config. this will disable some kernel crypto assembly code

Am 24.03.2020 um 16:11 schrieb Matt Johnston:
Good work narrowing down a test case there.
That's an interesting finding - I guess it might be worth posting on OpenWRT 
lists/forum to try find other testers.
Could it be power related if the tight multiplication loop is stressing it 
somehow? It doesn't seem to be using the Neon instruction for anything apart 
from loads/stores though - is there something that the compiler should be doing 
mixing Neon and non-Neon operations?

Cheers,
Matt

(Your emails got held up being over 100kB, I've trimmed the reply below and let 
them through. Apologies to everyone for the stale old one that got let through 
with them just now, I wasn't looking closely)

On Tue 24/3/2020, at 11:23 am, Horshack ‪‬ 
mailto:horsh...@live.com>> wrote:

I was able to isolate the issue to just a handful of assembly instructions 
within fast_s_mp_sqr(), related to the squaring loop. I broke that code out 
into a separate utility that reproduces the issue within a few seconds. The 
failure is somewhat sensitive to the data pattern and very sensitive to timing, 
indicating a likely memory/data path issue within my particular router. I'm 
guessing it's the IPQ8065 and not the SDRAM because I can get it to fail with a 
tiny data set easily fits within DCACHE. I can alter the frequency of the 
failure with a single ARM memory barrier instruction, which at first implied a 
superscalar data ordering condition but the memory barrier also alters the 
timing through the DCACHE so that is likely the effect it's having. I was able 
to exclude the VFP/Neon register corruption as the cause with some test code. I 
also excluded any context switch-speciifc issue by measuring the # of context 
switches in /proc//status and catching a failure where no switches had 
occurred. I also modified the affinity so the utility runs on just one 
processor to rule out a specific core having the issue.

I put the source and binary of my utility on github - if anyone on this mailing 
list has this model router can you give it a try if possible? You only need the 
ipq8065-sqrbug (binary) and run-ipq8065-sqrbug.sh (script). Here's the link to 
the repository: https://github.com/horshack-dpreview/ipq8065-sqrbug



From: Horshack ‪‬ mailto:horsh...@live.com>>
Sent: Saturday, March 21, 2020 7:54 AM
To: dropbear@ucc.asn.au 
mailto:dropbear@ucc.asn.au>>
Subject: SSH key exchange fails 30-70% of the time on Netgear X4S R7800

Including mailing list for my last two messages below...

Begin forwarded message:

From: Horshack ‪‬ mailto:horsh...@live.com>>
Date: March 21, 2020 at 7:35:18 AM PDT
To: Matt Johnston mailto:m...@ucc.asn.au>>
Cc: "dropbear@ucc.asn.au" 
mailto:dropbear@ucc.asn.au>>
Subject: Re:  SSH key exchange fails 30-70% of the time on Netgear X4S R7800


Disassembly of fast_s_mp_sqr() and other libtommath functions reveals gcc is 
utilizing the arm NEON SIMD instructions and registers for calculations 
involved with libtommath's mp_word scalar. Based on the 64-bit word corruption 
I see I'm guessing the SIMD registers aren't being preserved/restored properly 
somewhere, probably during a context switch, specifically s16–s31 (d8–d15, 
q4–q7), which AAPCS says must be preserved and which I see being used in the 
disassembly of fast_s_mp_sqr(). I'lll write some test code later today to see 
if this is the case, and if so, try to track down where and why the registers 
aren't being preserved.


From: Horshack ‪‬ mailto:horsh...@live.com>>
Sent: Saturday, March 21, 2020 1:11 AM
To: Matt Johnston mailto:m...@ucc.asn.au>>
Cc: dropbear@ucc.asn.au 
mailto:dropbear@ucc.asn.au>>
Subject: Re: SSH key exchange fails 30-70% of the time on Netgear X4S R7800

I have one of the failure paths isolated down to a single corrupt 64-bit word 
in memory, which required a significant amount of code instrumentation to 
achieve. I implemented a code execution history buffer 

Re: SSH key exchange fails 30-70% of the time on Netgear X4S R7800

[Sebastian Gottschall]

if the corruption is caused by a context switch the problem can be 
caused by the kernel.

try the following and disable "CONFIG_KERNEL_MODE_NEON"
in the kernel config. this will disable some kernel crypto assembly code

Am 24.03.2020 um 16:11 schrieb Matt Johnston:

Good work narrowing down a test case there.
That's an interesting finding - I guess it might be worth posting on 
OpenWRT lists/forum to try find other testers.
Could it be power related if the tight multiplication loop is 
stressing it somehow? It doesn't seem to be using the Neon instruction 
for anything apart from loads/stores though - is there something that 
the compiler should be doing mixing Neon and non-Neon operations?


Cheers,
Matt

(Your emails got held up being over 100kB, I've trimmed the reply 
below and let them through. Apologies to everyone for the stale old 
one that got let through with them just now, I wasn't looking closely)


On Tue 24/3/2020, at 11:23 am, Horshack ‪‬ > wrote:


I was able to isolate the issue to just a handful of assembly 
instructions within fast_s_mp_sqr(), related to the squaring loop. I 
broke that code out into a separate utility that reproduces the issue 
within a few seconds. The failure is somewhat sensitive to the data 
pattern and very sensitive to timing, indicating a likely memory/data 
path issue within my particular router. I'm guessing it's the IPQ8065 
and not the SDRAM because I can get it to fail with a tiny data set 
easily fits within DCACHE. I can alter the frequency of the failure 
with a single ARM memory barrier instruction, which at first implied 
a superscalar data ordering condition but the memory barrier also 
alters the timing through the DCACHE so that is likely the effect 
it's having. I was able to exclude the VFP/Neon register corruption 
as the cause with some test code. I also excluded any context 
switch-speciifc issue by measuring the # of context switches in 
/proc//status and catching a failure where no switches had 
occurred. I also modified the affinity so the utility runs on just 
one processor to rule out a specific core having the issue.


I put the source and binary of my utility on github - if anyone on 
this mailing list has this model router can you give it a try if 
possible? You only need the ipq8065-sqrbug (binary) and 
run-ipq8065-sqrbug.sh (script). Here's the link to the 
repository:https://github.com/horshack-dpreview/ipq8065-sqrbug 





*From:*Horshack ‪‬ mailto:horsh...@live.com>>
*Sent:*Saturday, March 21, 2020 7:54 AM
*To:*dropbear@ucc.asn.au 
>

*Subject:*SSH key exchange fails 30-70% of the time on Netgear X4S R7800
Including mailing list for my last two messages below...

Begin forwarded message:


*From:*Horshack ‪‬ mailto:horsh...@live.com>>
*Date:*March 21, 2020 at 7:35:18 AM PDT
*To:*Matt Johnston mailto:m...@ucc.asn.au>>
*Cc:*"dropbear@ucc.asn.au " 
mailto:dropbear@ucc.asn.au>>
*Subject:**Re:  SSH key exchange fails 30-70% of the time on Netgear 
X4S R7800*



Disassembly of fast_s_mp_sqr() and other libtommath functions 
reveals gcc is utilizing the arm NEON SIMD instructions and 
registers for calculations involved with libtommath's mp_word 
scalar. Based on the 64-bit word corruption I see I'm guessing the 
SIMD registers aren't being preserved/restored properly somewhere, 
probably during a context switch, specifically s16–s31 (d8–d15, 
q4–q7), which AAPCS says must be preserved and which I see being 
used in the disassembly of fast_s_mp_sqr(). I'lll write some test 
code later today to see if this is the case, and if so, try to track 
down where and why the registers aren't being preserved.



*From:*Horshack ‪‬ mailto:horsh...@live.com>>
*Sent:*Saturday, March 21, 2020 1:11 AM
*To:*Matt Johnston mailto:m...@ucc.asn.au>>
*Cc:*dropbear@ucc.asn.au  
mailto:dropbear@ucc.asn.au>>
*Subject:*Re: SSH key exchange fails 30-70% of the time on Netgear 
X4S R7800
I have one of the failure paths isolated down to a single corrupt 
64-bit word in memory, which required a significant amount of code 
instrumentation to achieve. I implemented a code execution history 
buffer that gets filled at various checkpoints within s_mp_exptmod() 
and some of the modules called by it. To facilitate this history 
mechanism I packaged all of s_mp_exptmod()'s local variables inside 
a structure , which consists of saving the local scalar vars in 
addition to crc32's of all the mp_int data structures with a 
separate crc32 of the mp_int.dp payload (data). When a failure 
occurs, ie one or more of the three back-to-back debug invocations 
of s_mp_exptmod yields a mismatching signed key result, I  dump out 
the history elements for 

Re: SSH key exchange fails 30-70% of the time on Netgear X4S R7800

[Matt Johnston]

Good work narrowing down a test case there.
That's an interesting finding - I guess it might be worth posting on OpenWRT 
lists/forum to try find other testers.
Could it be power related if the tight multiplication loop is stressing it 
somehow? It doesn't seem to be using the Neon instruction for anything apart 
from loads/stores though - is there something that the compiler should be doing 
mixing Neon and non-Neon operations?

Cheers,
Matt

(Your emails got held up being over 100kB, I've trimmed the reply below and let 
them through. Apologies to everyone for the stale old one that got let through 
with them just now, I wasn't looking closely)

> On Tue 24/3/2020, at 11:23 am, Horshack ‪‬  wrote:
> 
> I was able to isolate the issue to just a handful of assembly instructions 
> within fast_s_mp_sqr(), related to the squaring loop. I broke that code out 
> into a separate utility that reproduces the issue within a few seconds. The 
> failure is somewhat sensitive to the data pattern and very sensitive to 
> timing, indicating a likely memory/data path issue within my particular 
> router. I'm guessing it's the IPQ8065 and not the SDRAM because I can get it 
> to fail with a tiny data set easily fits within DCACHE. I can alter the 
> frequency of the failure with a single ARM memory barrier instruction, which 
> at first implied a superscalar data ordering condition but the memory barrier 
> also alters the timing through the DCACHE so that is likely the effect it's 
> having. I was able to exclude the VFP/Neon register corruption as the cause 
> with some test code. I also excluded any context switch-speciifc issue by 
> measuring the # of context switches in /proc//status and catching a 
> failure where no switches had occurred. I also modified the affinity so the 
> utility runs on just one processor to rule out a specific core having the 
> issue.
> 
> I put the source and binary of my utility on github - if anyone on this 
> mailing list has this model router can you give it a try if possible? You 
> only need the ipq8065-sqrbug (binary) and run-ipq8065-sqrbug.sh (script). 
> Here's the link to the repository: 
> https://github.com/horshack-dpreview/ipq8065-sqrbug 
> 
> 
> 
> From: Horshack ‪‬ mailto:horsh...@live.com>>
> Sent: Saturday, March 21, 2020 7:54 AM
> To: dropbear@ucc.asn.au   >
> Subject: SSH key exchange fails 30-70% of the time on Netgear X4S R7800
>  
> Including mailing list for my last two messages below...
> 
> Begin forwarded message:
> 
>> From: Horshack ‪‬ 
>> Date: March 21, 2020 at 7:35:18 AM PDT
>> To: Matt Johnston 
>> Cc: "dropbear@ucc.asn.au" 
>> Subject: Re:  SSH key exchange fails 30-70% of the time on Netgear X4S R7800
>> 
>> 
>> Disassembly of fast_s_mp_sqr() and other libtommath functions reveals gcc is 
>> utilizing the arm NEON SIMD instructions and registers for calculations 
>> involved with libtommath's mp_word scalar. Based on the 64-bit word 
>> corruption I see I'm guessing the SIMD registers aren't being 
>> preserved/restored properly somewhere, probably during a context switch, 
>> specifically s16–s31 (d8–d15, q4–q7), which AAPCS says must be preserved and 
>> which I see being used in the disassembly of fast_s_mp_sqr(). I'lll write 
>> some test code later today to see if this is the case, and if so, try to 
>> track down where and why the registers aren't being preserved.
>> 
>> From: Horshack ‪‬ 
>> Sent: Saturday, March 21, 2020 1:11 AM
>> To: Matt Johnston 
>> Cc: dropbear@ucc.asn.au 
>> Subject: Re: SSH key exchange fails 30-70% of the time on Netgear X4S R7800
>>  
>> I have one of the failure paths isolated down to a single corrupt 64-bit 
>> word in memory, which required a significant amount of code instrumentation 
>> to achieve. I implemented a code execution history buffer that gets filled 
>> at various checkpoints within s_mp_exptmod() and some of the modules called 
>> by it. To facilitate this history mechanism I packaged all of 
>> s_mp_exptmod()'s local variables inside a structure , which consists of 
>> saving the local scalar vars in addition to crc32's of all the mp_int data 
>> structures with a separate crc32 of the mp_int.dp payload (data). When a 
>> failure occurs, ie one or more of the three back-to-back debug invocations 
>> of s_mp_exptmod yields a mismatching signed key result, I  dump out the 
>> history elements for each of the invocations to determine the first code 
>> checkpoint where failing invocation departed from the known correct 
>> invocation.

*snipped*

Re: SSH key exchange fails 30-70% of the time on Netgear X4S R7800

[Horshack ‪‬]

Disassembly of fast_s_mp_sqr() and other libtommath functions reveals gcc is 
utilizing the arm NEON SIMD instructions and registers for calculations 
involved with libtommath's mp_word scalar. Based on the 64-bit word corruption 
I see I'm guessing the SIMD registers aren't being preserved/restored properly 
somewhere, probably during a context switch, specifically s16–s31 (d8–d15, 
q4–q7), which AAPCS says must be preserved and which I see being used in the 
disassembly of fast_s_mp_sqr(). I'lll write some test code later today to see 
if this is the case, and if so, try to track down where and why the registers 
aren't being preserved.


From: Horshack ‪‬ 
Sent: Saturday, March 21, 2020 1:11 AM
To: Matt Johnston 
Cc: dropbear@ucc.asn.au 
Subject: Re: SSH key exchange fails 30-70% of the time on Netgear X4S R7800

I have one of the failure paths isolated down to a single corrupt 64-bit word 
in memory, which required a significant amount of code instrumentation to 
achieve. I implemented a code execution history buffer that gets filled at 
various checkpoints within s_mp_exptmod() and some of the modules called by it. 
To facilitate this history mechanism I packaged all of s_mp_exptmod()'s local 
variables inside a structure , which consists of saving the local scalar vars 
in addition to crc32's of all the mp_int data structures with a separate crc32 
of the mp_int.dp payload (data). When a failure occurs, ie one or more of the 
three back-to-back debug invocations of s_mp_exptmod yields a mismatching 
signed key result, I  dump out the history elements for each of the invocations 
to determine the first code checkpoint where failing invocation departed from 
the known correct invocation.

Here's a sample capture demonstrating.

Format is event #:, source code line #, crc32 of local scalars, crc32 of mp_int 
structures (minus dp field), and crc32 of all the mp_int dp data payloads. In 
this sample, the crc32 of the dp data payload is different, which causes all 
subsequent crc32's for the remainder of the invocation to be difference since 
the data propagates through all the subsequent calculations performed in the 
routine.

1554: line=0492, crcLocalVars=6a08573e, crcMpIntNoDp=ab967993, 
crcMpIntDp=ded4078e crcRes=2554be5b, 0021 0005 0016 0002 0061 0003 0001
1555: line=0488, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ad3e197a, 
crcMpIntDp=e71d5c11 crcRes=5ef59250, 0021 0005 0016 0002 0061 0004 0001
1556: line=2049, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ad3e197a, 
crcMpIntDp=e71d5c11 crcRes=5ef59250, 0021 0005 0016 0002 0061 0004 0001
1557: line=2062, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ab967993, 
crcMpIntDp=21b13223 crcRes=a43fde70, 0021 0005 0016 0002 0061 0004 0001
1558: line=0492, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ab967993, 
crcMpIntDp=21b13223 crcRes=a43fde70, 0021 0005 0016 0002 0061 0004 0001
1559: line=0501, crcLocalVars=7a3e1d2a, crcMpIntNoDp=ad3e197a, 
crcMpIntDp=7691624d crcRes=6d1388bc, 0021 0005 0016 0002 0061 0005 0001

1554: line=0492, crcLocalVars=6a08573e, crcMpIntNoDp=ab967993, 
crcMpIntDp=ded4078e crcRes=2554be5b, 0021 0005 0016 0002 0061 0003 0001
1555: line=0488, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ad3e197a, 
crcMpIntDp=e71d5c11 crcRes=5ef59250, 0021 0005 0016 0002 0061 0004 0001
1556: line=2049, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ad3e197a, 
crcMpIntDp=e71d5c11 crcRes=5ef59250, 0021 0005 0016 0002 0061 0004 0001
1557: line=2062, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ab967993, 
crcMpIntDp=a2639ce4 crcRes=74f7dec6, 0021 0005 0016 0002 0061 0004 0001
1558: line=0492, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ab967993, 
crcMpIntDp=a2639ce4 crcRes=74f7dec6, 0021 0005 0016 0002 0061 0004 0001
1559: line=0501, crcLocalVars=7a3e1d2a, crcMpIntNoDp=ad3e197a, 
crcMpIntDp=5e3343d2 crcRes=517ed1b0, 0021 0005 0016 0002 0061 0005 0001

I initially found the failure occurs at seemingly random places, affected 
mostly by the variances of code/data placement between builds, which also 
affects the frequency of failure. Through a lot of trial and error I was able 
to tease the failure down to one of the simplest code paths (fast_s_mp_sqr), 
which required balancing debug code placement to keep the movement of the 
failure in control. fast_s_mp_sqr() does only basic arithmetic and is easy to 
follow. I haven't yet determined if the corrupt data is pre-calculation or 
post-calculation due to the limits of how much data I can snapshot in the 
history buffer. Nevertheless I expanded the history mechanism to snapshot the 
specific mp_int that usually is corrupted via this path (s_mp_exptmod's local 
res structure).

Here is correct vs corrupt mp_init at the specific execution point where it 
departs from the previous correction invocation. The data fields prefixed by : 
are the actual content of the mp_int - I've highlighted the mismatching crc32's 
and the mismatching 64-bit word:

Correct invocation:
8057: line=2062, crcLocalVars=1d8f10b6, crcMpIntNoDp=80a0f0a7, 
crcMpIntDp=e92a3e1f 

Re: SSH key exchange fails 30-70% of the time on Netgear X4S R7800

[Horshack ‪‬]

I have one of the failure paths isolated down to a single corrupt 64-bit word 
in memory, which required a significant amount of code instrumentation to 
achieve. I implemented a code execution history buffer that gets filled at 
various checkpoints within s_mp_exptmod() and some of the modules called by it. 
To facilitate this history mechanism I packaged all of s_mp_exptmod()'s local 
variables inside a structure , which consists of saving the local scalar vars 
in addition to crc32's of all the mp_int data structures with a separate crc32 
of the mp_int.dp payload (data). When a failure occurs, ie one or more of the 
three back-to-back debug invocations of s_mp_exptmod yields a mismatching 
signed key result, I  dump out the history elements for each of the invocations 
to determine the first code checkpoint where failing invocation departed from 
the known correct invocation.

Here's a sample capture demonstrating.

Format is event #:, source code line #, crc32 of local scalars, crc32 of mp_int 
structures (minus dp field), and crc32 of all the mp_int dp data payloads. In 
this sample, the crc32 of the dp data payload is different, which causes all 
subsequent crc32's for the remainder of the invocation to be difference since 
the data propagates through all the subsequent calculations performed in the 
routine.

1554: line=0492, crcLocalVars=6a08573e, crcMpIntNoDp=ab967993, 
crcMpIntDp=ded4078e crcRes=2554be5b, 0021 0005 0016 0002 0061 0003 0001
1555: line=0488, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ad3e197a, 
crcMpIntDp=e71d5c11 crcRes=5ef59250, 0021 0005 0016 0002 0061 0004 0001
1556: line=2049, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ad3e197a, 
crcMpIntDp=e71d5c11 crcRes=5ef59250, 0021 0005 0016 0002 0061 0004 0001
1557: line=2062, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ab967993, 
crcMpIntDp=21b13223 crcRes=a43fde70, 0021 0005 0016 0002 0061 0004 0001
1558: line=0492, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ab967993, 
crcMpIntDp=21b13223 crcRes=a43fde70, 0021 0005 0016 0002 0061 0004 0001
1559: line=0501, crcLocalVars=7a3e1d2a, crcMpIntNoDp=ad3e197a, 
crcMpIntDp=7691624d crcRes=6d1388bc, 0021 0005 0016 0002 0061 0005 0001

1554: line=0492, crcLocalVars=6a08573e, crcMpIntNoDp=ab967993, 
crcMpIntDp=ded4078e crcRes=2554be5b, 0021 0005 0016 0002 0061 0003 0001
1555: line=0488, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ad3e197a, 
crcMpIntDp=e71d5c11 crcRes=5ef59250, 0021 0005 0016 0002 0061 0004 0001
1556: line=2049, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ad3e197a, 
crcMpIntDp=e71d5c11 crcRes=5ef59250, 0021 0005 0016 0002 0061 0004 0001
1557: line=2062, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ab967993, 
crcMpIntDp=a2639ce4 crcRes=74f7dec6, 0021 0005 0016 0002 0061 0004 0001
1558: line=0492, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ab967993, 
crcMpIntDp=a2639ce4 crcRes=74f7dec6, 0021 0005 0016 0002 0061 0004 0001
1559: line=0501, crcLocalVars=7a3e1d2a, crcMpIntNoDp=ad3e197a, 
crcMpIntDp=5e3343d2 crcRes=517ed1b0, 0021 0005 0016 0002 0061 0005 0001

I initially found the failure occurs at seemingly random places, affected 
mostly by the variances of code/data placement between builds, which also 
affects the frequency of failure. Through a lot of trial and error I was able 
to tease the failure down to one of the simplest code paths (fast_s_mp_sqr), 
which required balancing debug code placement to keep the movement of the 
failure in control. fast_s_mp_sqr() does only basic arithmetic and is easy to 
follow. I haven't yet determined if the corrupt data is pre-calculation or 
post-calculation due to the limits of how much data I can snapshot in the 
history buffer. Nevertheless I expanded the history mechanism to snapshot the 
specific mp_int that usually is corrupted via this path (s_mp_exptmod's local 
res structure).

Here is correct vs corrupt mp_init at the specific execution point where it 
departs from the previous correction invocation. The data fields prefixed by : 
are the actual content of the mp_int - I've highlighted the mismatching crc32's 
and the mismatching 64-bit word:

Correct invocation:
8057: line=2062, crcLocalVars=1d8f10b6, crcMpIntNoDp=80a0f0a7, 
crcMpIntDp=e92a3e1f crcRes=02003870, 0018 0005 0020 0002 0016 0002 
: 05297100 04f1e4e6 0fb47d28 0ab5d584 00b2778c 08656465 02cc79bb 05e280c3 - 
073117bc 037170a2 0603ef41 0a73c7af 0388c6cd 08b543fa 055d90c9 006afe46
: 0c4d0d2b 0b8753bf 0ba6b917 0dbc26af 0d5d541f 03cbd888 0a8b07bb 06ce141b - 
0f2e2cdc 0d83829c 00b9e992 007a007e 0b35c3fa 0f97fa98 078b16e2 05681c5a
: 09e81cad 0fcb1b35 0f017b34 0828f9c8 08253004 02f4139f 07b97efe 03a2c2c6 - 
0baf31f0 038dc84d 0ec2028d 0a4d2163 0b3d8f14 03a5b8a1 07656722 0636f515
: 047c6a4e 0249e773 074fdaae 0c7affcb 025e144e 0e6e524b 0369a7e6 005e5b18 - 
07359ab7 094aa102 06e091dc 048578b3 0f2023d6 09e16318 0fb25f70 091e7d0c
: 00e038fe 01fe0be1 0c879fba 055feb36 05135c48 063ef5c4 062acf74 0e2ee213 - 
0b32d4b4 01ac1beb 0df27135 0645d3a2 02f54fab 04524d06 0e21e0a0 01a58051
: 0d0dd311 0b10815a 08044871 0bec8042 0473b083 0d99e620 0db94b72 

SSH key exchange fails 30-70% of the time on Netgear X4S R7800

[Horshack ??]

Hi,

I have a strange issue on my Netgear X4S R7800. Running either DD-WRT or 
OpenWrt, approximately 30-70% of my SSH login attempts fail. For OpenSSH 
clients the error reported is "error in libcrypto". For the PuTTY client the 
error is more descriptive - "Signature from server's host key is invalid". The 
failure occurs even when using the OpenSSH client built in to OpenWrt itself 
(ie, SSH'ing into the router from the router via an existing remote SSH 
session).

The failure appears to be at the tail end of the key exchange, before 
authentication. I've tried varying the cipher (aes128-ctr / aes256-ctr), the 
MAC (hmac-sha1 / hmac-sha2-256), and the key exchange algo (curve25519-sha256 / 
curve25519-sha...@libssh.org / diffie-hellman-group14-sha256 / 
diffie-hellman-group14-sha1) but the intermittent failure still occurs. The 
frequency of failure is about the same for all these configuration options 
except for diffie-hellman-group14-sha256, which fails much more frequently - it 
sometimes takes hundreds of attempts to succeed. Perhaps that will provide a 
clue to the underlying cause.

Once an SSH login succeeds the connection is stable. However if I initiate a 
manual rekey operation via ~R then the key re-exchange fails. The router is 
otherwise very stable with no noticeable issues.

I'm an embedded firmware engineer but have never worked on DD-WRT/OpenWrt 
firmware or dropbear. I have a conceptual understanding of the key exchange 
algo but haven't looked at the actual code of any implementation including 
Dropbear's. I'm seek ideas on how to troubleshoot this issue. Considering the 
problem is intermittent I'm thinking it's some variant in the key 
generation/exchange algorithm that's failing due to some issue with the router, 
or a more remote possibility, an issue with the Dropbear implementation.

Here are pastebin links to the PuTTY full debug logs (w/raw data dumps) for 
both the failure and success cases:
Failure Case: https://pastebin.com/MS2BtFmW
Success Case: https://pastebin.com/c4j66Ga9

The only message I see from dropbear for a failed connection attempt is:

authpriv.info dropbear[15948]: Child connection from 192.168.1.249:54819
authpriv.info dropbear[15948]: Exit before auth: Disconnect received


Thanks!

Re: SSH key exchange fails 30-70% of the time on Netgear X4S R7800

[Horshack ‪‬]

I was able to isolate the issue to just a handful of assembly instructions 
within fast_s_mp_sqr(), related to the squaring loop. I broke that code out 
into a separate utility that reproduces the issue within a few seconds. The 
failure is somewhat sensitive to the data pattern and very sensitive to timing, 
indicating a likely memory/data path issue within my particular router. I'm 
guessing it's the IPQ8065 and not the SDRAM because I can get it to fail with a 
tiny data set easily fits within DCACHE. I can alter the frequency of the 
failure with a single ARM memory barrier instruction, which at first implied a 
superscalar data ordering condition but the memory barrier also alters the 
timing through the DCACHE so that is likely the effect it's having. I was able 
to exclude the VFP/Neon register corruption as the cause with some test code. I 
also excluded any context switch-speciifc issue by measuring the # of context 
switches in /proc//status and catching a failure where no switches had 
occurred. I also modified the affinity so the utility runs on just one 
processor to rule out a specific core having the issue.

I put the source and binary of my utility on github - if anyone on this mailing 
list has this model router can you give it a try if possible? You only need the 
ipq8065-sqrbug (binary) and run-ipq8065-sqrbug.sh (script). Here's the link to 
the repository: https://github.com/horshack-dpreview/ipq8065-sqrbug



From: Horshack ‪‬ 
Sent: Saturday, March 21, 2020 7:54 AM
To: dropbear@ucc.asn.au 
Subject: SSH key exchange fails 30-70% of the time on Netgear X4S R7800

Including mailing list for my last two messages below...

Begin forwarded message:

From: Horshack ‪‬ 
Date: March 21, 2020 at 7:35:18 AM PDT
To: Matt Johnston 
Cc: "dropbear@ucc.asn.au" 
Subject: Re:  SSH key exchange fails 30-70% of the time on Netgear X4S R7800


Disassembly of fast_s_mp_sqr() and other libtommath functions reveals gcc is 
utilizing the arm NEON SIMD instructions and registers for calculations 
involved with libtommath's mp_word scalar. Based on the 64-bit word corruption 
I see I'm guessing the SIMD registers aren't being preserved/restored properly 
somewhere, probably during a context switch, specifically s16–s31 (d8–d15, 
q4–q7), which AAPCS says must be preserved and which I see being used in the 
disassembly of fast_s_mp_sqr(). I'lll write some test code later today to see 
if this is the case, and if so, try to track down where and why the registers 
aren't being preserved.


From: Horshack ‪‬ 
Sent: Saturday, March 21, 2020 1:11 AM
To: Matt Johnston 
Cc: dropbear@ucc.asn.au 
Subject: Re: SSH key exchange fails 30-70% of the time on Netgear X4S R7800

I have one of the failure paths isolated down to a single corrupt 64-bit word 
in memory, which required a significant amount of code instrumentation to 
achieve. I implemented a code execution history buffer that gets filled at 
various checkpoints within s_mp_exptmod() and some of the modules called by it. 
To facilitate this history mechanism I packaged all of s_mp_exptmod()'s local 
variables inside a structure , which consists of saving the local scalar vars 
in addition to crc32's of all the mp_int data structures with a separate crc32 
of the mp_int.dp payload (data). When a failure occurs, ie one or more of the 
three back-to-back debug invocations of s_mp_exptmod yields a mismatching 
signed key result, I  dump out the history elements for each of the invocations 
to determine the first code checkpoint where failing invocation departed from 
the known correct invocation.

Here's a sample capture demonstrating.

Format is event #:, source code line #, crc32 of local scalars, crc32 of mp_int 
structures (minus dp field), and crc32 of all the mp_int dp data payloads. In 
this sample, the crc32 of the dp data payload is different, which causes all 
subsequent crc32's for the remainder of the invocation to be difference since 
the data propagates through all the subsequent calculations performed in the 
routine.

1554: line=0492, crcLocalVars=6a08573e, crcMpIntNoDp=ab967993, 
crcMpIntDp=ded4078e crcRes=2554be5b, 0021 0005 0016 0002 0061 0003 0001
1555: line=0488, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ad3e197a, 
crcMpIntDp=e71d5c11 crcRes=5ef59250, 0021 0005 0016 0002 0061 0004 0001
1556: line=2049, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ad3e197a, 
crcMpIntDp=e71d5c11 crcRes=5ef59250, 0021 0005 0016 0002 0061 0004 0001
1557: line=2062, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ab967993, 
crcMpIntDp=21b13223 crcRes=a43fde70, 0021 0005 0016 0002 0061 0004 0001
1558: line=0492, crcLocalVars=7dc8fe2c, crcMpIntNoDp=ab967993, 
crcMpIntDp=21b13223 crcRes=a43fde70, 0021 0005 0016 0002 0061 0004 0001
1559: line=0501, crcLocalVars=7a3e1d2a, crcMpIntNoDp=ad3e197a, 
crcMpIntDp=7691624d crcRes=6d1388bc, 0021 0005 0016 0002 0061 0005 0001

1554: line=0492, crcLocalVars=6a08573e, crcMpIntNoDp=ab967993,