FS#46643 - [ddclient] fails to start (invalid opcode in libcrypto)

Attached to Project: Community Packages
Opened by JC Francois (jeancf) - Saturday, 10 October 2015, 12:12 GMT
Last edited by Johannes Löthberg (demize) - Friday, 24 February 2017, 21:18 GMT
Task Type Bug Report
Category Packages
Status Closed
Assigned To Johannes Löthberg (demize)
Architecture x86_64
Severity Medium
Priority Normal
Reported Version
Due in Version Undecided
Due Date Undecided
Percent Complete 100%
Votes 0
Private No

Details

Description:
ddclient fails to start. This happens since July 25, 2015.

Additional info:
* package version(s)
ddclient-3.8.3-1 upgraded 2015-06-06
openssl 1.0.2.d-1 installed 2015-07-11

* config and/or log files etc.

> journalctl -e | grep ddclient
Oct 10 13:24:19 server sudo[1375]: jeancf : TTY=pts/0 ; PWD=/var/log ; USER=root ; COMMAND=/usr/bin/systemctl start ddclient
Oct 10 13:24:19 server ddclient[1384]: WARNING: forcing update of JCF from 81.241.87.162 to 81.241.61.194; 25 days since last update on Mon Jul 20 09:02:58 2015.
Oct 10 13:24:20 server kernel: traps: ddclient - send[1383] trap invalid opcode ip:7fe1f9848fe8 sp:7ffdc1690e58 error:0 in libcrypto.so.1.0.0[7fe1f979e000+24d000]
Oct 10 13:24:20 server systemd[1]: ddclient.service: Main process exited, code=dumped, status=4/ILL
Oct 10 13:24:20 server systemd[1]: ddclient.service: Unit entered failed state.
Oct 10 13:24:20 server systemd[1]: ddclient.service: Failed with result 'core-dump'.
Oct 10 13:24:20 server systemd-coredump[1385]: Process 1383 (ddclient - send) of user 0 dumped core.

# What package owns libcrypto
> pacman -Qo /usr/lib/libcrypto.so
/usr/lib/libcrypto.so is owned by openssl 1.0.2.d-1

# What got installed on 2015-07-25
> cat pacman.log | grep 2015-07-25
[2015-07-25 10:09] [PACMAN] starting full system upgrade
[2015-07-25 10:10] [ALPM] transaction started
[2015-07-25 10:10] [ALPM] upgraded gcc-libs (5.1.0-5 -> 5.2.0-1)
[2015-07-25 10:10] [ALPM] upgraded crypto++ (5.6.2-2 -> 5.6.2-3)
[2015-07-25 10:10] [ALPM] upgraded libsystemd (221-2 -> 222-1)
[2015-07-25 10:10] [ALPM] upgraded systemd (221-2 -> 222-1)
[2015-07-25 10:10] [ALPM] upgraded device-mapper (2.02.123-1 -> 2.02.125-1)
[2015-07-25 10:10] [ALPM] upgraded mpfr (3.1.3-1 -> 3.1.3.p4-1)
[2015-07-25 10:10] [ALPM] upgraded gcc (5.1.0-5 -> 5.2.0-1)
[2015-07-25 10:10] [ALPM] upgraded jre7-openjdk-headless (7.u79_2.5.5-1 -> 7.u85_2.6.1-1)
[2015-07-25 10:10] [ALPM] upgraded libtool (2.4.6-2 -> 2.4.6-3)
[2015-07-25 10:10] [ALPM] upgraded libunistring (0.9.5-1 -> 0.9.6-1)
[2015-07-25 10:10] [ALPM] upgraded lvm2 (2.02.123-1 -> 2.02.125-1)
[2015-07-25 10:10] [ALPM] upgraded openssh (6.9p1-1 -> 6.9p1-2)
[2015-07-25 10:10] [ALPM] warning: /etc/pacman.d/mirrorlist installed as /etc/pacman.d/mirrorlist.pacnew
[2015-07-25 10:10] [ALPM] upgraded pacman-mirrorlist (20150713-1 -> 20150719-1)
[2015-07-25 10:10] [ALPM] upgraded perl-uri (1.68-1 -> 1.69-1)
[2015-07-25 10:10] [ALPM] upgraded phpmyadmin (4.4.11-1 -> 4.4.12-1)
[2015-07-25 10:10] [ALPM] warning: /etc/sudoers installed as /etc/sudoers.pacnew
[2015-07-25 10:10] [ALPM] upgraded sudo (1.8.13-1 -> 1.8.14.p3-2)
[2015-07-25 10:10] [ALPM] upgraded systemd-sysvcompat (221-2 -> 222-1)
[2015-07-25 10:10] [ALPM] transaction completed

Steps to reproduce (always):
systemctl start ddclient
This task depends upon

Closed by  Johannes Löthberg (demize)
Friday, 24 February 2017, 21:18 GMT
Reason for closing:  None
Additional comments about closing:  Reported fixed
Comment by Johannes Löthberg (demize) - Sunday, 11 October 2015, 12:17 GMT
Hmm, works fine for me, odd. Could you paste the output of `uname -a` and the configuration you're using. (Without your password, of course.)
Comment by JC Francois (jeancf) - Sunday, 11 October 2015, 18:31 GMT
> uname -a
Linux server 4.2.2-1-ARCH #1 SMP PREEMPT Tue Sep 29 22:21:33 CEST 2015 x86_64 GNU/Linux

I have a fully updated arch system that I am using as a server (no graphical environment).

In the meantime I tried removing ddclient and dependencies (pacman -Rs ddclient) and reinstall but no luck.

ddclient worked flawlessly for years with the following ddclient.conf:

daemon=360 # check every 300 seconds
ssl=no # use ssl-support
use=web,web='myip.dnsomatic.com' # use dyndns IP address check page
#use=if, if=eth0 # use IP address of interface eth0
syslog=yes # log update msgs to syslog
mail-failure=root # mail failed update msgs to root
pid=/var/run/ddclient.pid # record PID in file.

##
## afraid.org account configuration
##
server=freedns.afraid.org
protocol=freedns
login=jeancf
password=passwordremoved
jeancf.ignorelist.com

##
## OpenDNS.com account-configuration
##
ssl=yes
server=updates.opendns.com
protocol=dyndns2
login=jc@noirextreme.com
password=passwordremoved
JCF
Comment by JC Francois (jeancf) - Sunday, 25 October 2015, 10:09 GMT
Any idea? Can you suggest where to look for clues?
Comment by JC Francois (jeancf) - Wednesday, 28 October 2015, 09:15 GMT
I just played around with the options of the configuration file and I found out that it is the line ssl=yes (in the header of the conf file or in any specific service section) that triggers the crash. Without this line ddclient works as expected. Could this be due to a openssl version mismatch? I have openssl 1.0.2.d-1 installed.
Comment by Johannes Löthberg (demize) - Wednesday, 28 October 2015, 12:56 GMT
ddclient uses perl-io-socket-ssl, not openssl directly, but hmm...

Could you try running eg

perl -MIO::Socket::SSL -e 'my $cl = IO::Socket::SSL->new("www.google.com:443"); print $cl "GET / HTTP/1.0\r\n\r\n"; print <$cl>;'

and see if it works? Would help narrow it down to whether it's due to the SSL library.
Comment by Johannes Löthberg (demize) - Wednesday, 28 October 2015, 12:58 GMT
Oh, and if that doesn't give the same error, --debug output from ddclient would be useful.
Comment by Johannes Löthberg (demize) - Wednesday, 28 October 2015, 13:05 GMT
And could you also paste the contents of /proc/cpuinfo?
Comment by JC Francois (jeancf) - Wednesday, 28 October 2015, 14:38 GMT
The perl command returns:

HTTP/1.0 302 Found
Cache-Control: private
Content-Type: text/html; charset=UTF-8
Location: https://www.google.be/?gfe_rd=cr&ei=wNwwVqSeIKn4iQbN1YbABQ
Content-Length: 259
Date: Wed, 28 Oct 2015 14:33:36 GMT
Server: GFE/2.0
Alternate-Protocol: 443:quic,p=1
Alt-Svc: quic="www.google.com:443"; p="1"; ma=600,quic=":443"; p="1"; ma=600

<HTML><HEAD><meta http-equiv="content-type" content="text/html;charset=utf-8">
<TITLE>302 Moved</TITLE></HEAD><BODY>
<H1>302 Moved</H1>
The document has moved
<A HREF="https://www.google.be/?gfe_rd=cr&amp;ei=wNwwVqSeIKn4iQbN1YbABQ">here</A>.
</BODY></HTML>

-------------------------------------------
> /proc/cpuinfo

processor : 0
vendor_id : AuthenticAMD
cpu family : 22
model : 0
model name : AMD Athlon(tm) 5350 APU with Radeon(tm) R3
stepping : 1
microcode : 0x700010f
cpu MHz : 800.000
cache size : 2048 KB
physical id : 0
siblings : 4
core id : 0
cpu cores : 4
apicid : 0
initial apicid : 0
fpu : yes
fpu_exception : yes
cpuid level : 13
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt pdpe1gb rdtscp lm constant_tsc rep_good nopl nonstop_tsc extd_apicid aperfmperf eagerfpu pni pclmulqdq monitor ssse3 cx16 sse4_1 sse4_2 movbe popcnt aes xsave avx f16c lahf_lm cmp_legacy svm extapic cr8_legacy abm sse4a misalignsse 3dnowprefetch osvw ibs skinit wdt topoext perfctr_nb bpext perfctr_l2 arat hw_pstate proc_feedback npt lbrv svm_lock nrip_save tsc_scale flushbyasid decodeassists pausefilter pfthreshold vmmcall bmi1 xsaveopt
bugs : fxsave_leak sysret_ss_attrs
bogomips : 4093.72
TLB size : 1024 4K pages
clflush size : 64
cache_alignment : 64
address sizes : 40 bits physical, 48 bits virtual
power management: ts ttp tm 100mhzsteps hwpstate [11]

processor : 1
vendor_id : AuthenticAMD
cpu family : 22
model : 0
model name : AMD Athlon(tm) 5350 APU with Radeon(tm) R3
stepping : 1
microcode : 0x700010f
cpu MHz : 800.000
cache size : 2048 KB
physical id : 0
siblings : 4
core id : 1
cpu cores : 4
apicid : 1
initial apicid : 1
fpu : yes
fpu_exception : yes
cpuid level : 13
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt pdpe1gb rdtscp lm constant_tsc rep_good nopl nonstop_tsc extd_apicid aperfmperf eagerfpu pni pclmulqdq monitor ssse3 cx16 sse4_1 sse4_2 movbe popcnt aes xsave avx f16c lahf_lm cmp_legacy svm extapic cr8_legacy abm sse4a misalignsse 3dnowprefetch osvw ibs skinit wdt topoext perfctr_nb bpext perfctr_l2 arat hw_pstate proc_feedback npt lbrv svm_lock nrip_save tsc_scale flushbyasid decodeassists pausefilter pfthreshold vmmcall bmi1 xsaveopt
bugs : fxsave_leak sysret_ss_attrs
bogomips : 4093.72
TLB size : 1024 4K pages
clflush size : 64
cache_alignment : 64
address sizes : 40 bits physical, 48 bits virtual
power management: ts ttp tm 100mhzsteps hwpstate [11]

processor : 2
vendor_id : AuthenticAMD
cpu family : 22
model : 0
model name : AMD Athlon(tm) 5350 APU with Radeon(tm) R3
stepping : 1
microcode : 0x700010f
cpu MHz : 800.000
cache size : 2048 KB
physical id : 0
siblings : 4
core id : 2
cpu cores : 4
apicid : 2
initial apicid : 2
fpu : yes
fpu_exception : yes
cpuid level : 13
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt pdpe1gb rdtscp lm constant_tsc rep_good nopl nonstop_tsc extd_apicid aperfmperf eagerfpu pni pclmulqdq monitor ssse3 cx16 sse4_1 sse4_2 movbe popcnt aes xsave avx f16c lahf_lm cmp_legacy svm extapic cr8_legacy abm sse4a misalignsse 3dnowprefetch osvw ibs skinit wdt topoext perfctr_nb bpext perfctr_l2 arat hw_pstate proc_feedback npt lbrv svm_lock nrip_save tsc_scale flushbyasid decodeassists pausefilter pfthreshold vmmcall bmi1 xsaveopt
bugs : fxsave_leak sysret_ss_attrs
bogomips : 4093.72
TLB size : 1024 4K pages
clflush size : 64
cache_alignment : 64
address sizes : 40 bits physical, 48 bits virtual
power management: ts ttp tm 100mhzsteps hwpstate [11]

processor : 3
vendor_id : AuthenticAMD
cpu family : 22
model : 0
model name : AMD Athlon(tm) 5350 APU with Radeon(tm) R3
stepping : 1
microcode : 0x700010f
cpu MHz : 800.000
cache size : 2048 KB
physical id : 0
siblings : 4
core id : 3
cpu cores : 4
apicid : 3
initial apicid : 3
fpu : yes
fpu_exception : yes
cpuid level : 13
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt pdpe1gb rdtscp lm constant_tsc rep_good nopl nonstop_tsc extd_apicid aperfmperf eagerfpu pni pclmulqdq monitor ssse3 cx16 sse4_1 sse4_2 movbe popcnt aes xsave avx f16c lahf_lm cmp_legacy svm extapic cr8_legacy abm sse4a misalignsse 3dnowprefetch osvw ibs skinit wdt topoext perfctr_nb bpext perfctr_l2 arat hw_pstate proc_feedback npt lbrv svm_lock nrip_save tsc_scale flushbyasid decodeassists pausefilter pfthreshold vmmcall bmi1 xsaveopt
bugs : fxsave_leak sysret_ss_attrs
bogomips : 4093.72
TLB size : 1024 4K pages
clflush size : 64
cache_alignment : 64
address sizes : 40 bits physical, 48 bits virtual
power management: ts ttp tm 100mhzsteps hwpstate [11]
Comment by Peter Chinetti (ddaygold) - Thursday, 05 November 2015, 03:03 GMT
I think this bug is triggered by running on an AMD CPU vs a Intel one.

Disassembling in GDB:
(gdb) disassemble /r
Dump of assembler code for function aesni_cbc_sha256_enc:
0x00007fdeb8b29f80 <+0>: 4c 8d 1d d9 bc 3c 00 lea 0x3cbcd9(%rip),%r11 # 0x7fdeb8ef5c60 <OPENSSL_ia32cap_P>
0x00007fdeb8b29f87 <+7>: b8 01 00 00 00 mov $0x1,%eax
0x00007fdeb8b29f8c <+12>: 48 83 ff 00 cmp $0x0,%rdi
0x00007fdeb8b29f90 <+16>: 74 62 je 0x7fdeb8b29ff4 <aesni_cbc_sha256_enc+116>
0x00007fdeb8b29f92 <+18>: 41 8b 03 mov (%r11),%eax
0x00007fdeb8b29f95 <+21>: 4d 8b 53 04 mov 0x4(%r11),%r10
0x00007fdeb8b29f99 <+25>: 49 0f ba e2 3d bt $0x3d,%r10
0x00007fdeb8b29f9e <+30>: 0f 82 bc 3e 00 00 jb 0x7fdeb8b2de60 <aesni_cbc_sha256_enc_shaext>
0x00007fdeb8b29fa4 <+36>: 4d 89 d3 mov %r10,%r11
0x00007fdeb8b29fa7 <+39>: 49 c1 eb 20 shr $0x20,%r11
0x00007fdeb8b29fab <+43>: 41 f7 c2 00 08 00 00 test $0x800,%r10d
0x00007fdeb8b29fb2 <+50>: 0f 85 08 03 00 00 jne 0x7fdeb8b2a2c0 <aesni_cbc_sha256_enc_xop>
0x00007fdeb8b29fb8 <+56>: 41 81 e3 28 01 00 00 and $0x128,%r11d
0x00007fdeb8b29fbf <+63>: 41 81 fb 28 01 00 00 cmp $0x128,%r11d
0x00007fdeb8b29fc6 <+70>: 0f 84 34 24 00 00 je 0x7fdeb8b2c400 <aesni_cbc_sha256_enc_avx2>
0x00007fdeb8b29fcc <+76>: 25 00 00 00 40 and $0x40000000,%eax
0x00007fdeb8b29fd1 <+81>: 41 81 e2 00 02 00 10 and $0x10000200,%r10d
0x00007fdeb8b29fd8 <+88>: 41 09 c2 or %eax,%r10d
0x00007fdeb8b29fdb <+91>: 41 81 fa 00 02 00 50 cmp $0x50000200,%r10d
0x00007fdeb8b29fe2 <+98>: 0f 84 d8 12 00 00 je 0x7fdeb8b2b2c0 <aesni_cbc_sha256_enc_avx>
=> 0x00007fdeb8b29fe8 <+104>: 0f 0b ud2
0x00007fdeb8b29fea <+106>: 31 c0 xor %eax,%eax
0x00007fdeb8b29fec <+108>: 48 83 ff 00 cmp $0x0,%rdi
0x00007fdeb8b29ff0 <+112>: 74 02 je 0x7fdeb8b29ff4 <aesni_cbc_sha256_enc+116>
0x00007fdeb8b29ff2 <+114>: 0f 0b ud2
0x00007fdeb8b29ff4 <+116>: f3 c3 repz retq
End of assembler dump.

How do I build Arch packages with debuginfo?
Comment by Peter Chinetti (ddaygold) - Thursday, 05 November 2015, 03:05 GMT
ddclient works for me on a machine with:
Model name: Intel(R) Core(TM) i5-2500K CPU @ 3.30GHz
and breaks on:
Model name: AMD GX-210HA SOC with Radeon(tm) HD Graphics
Comment by Peter Chinetti (ddaygold) - Monday, 09 November 2015, 00:27 GMT
So, after building with debuginfo, the problem is in crypto/aes/aesni-sha256-x86_64.s:29, an assembly file.

The ud2 instruction is specifically called, so I'm assuming that this is some sort of "cheap and easy" safety check.
Comment by JC Francois (jeancf) - Friday, 01 January 2016, 14:21 GMT
This issue seems to be fixed now. ddclient does not crash anymore on my AMD server.

Thanks.

Loading...