Open Codelica opened 9 years ago
I encountered a similar issue. I triggered it simply by running 'nmap' on my server and it crashed ocspd.
Feb 2 12:49:38 localhost ocspd[876]: OpenCA OCSPD v3.1.1 - starting.
Feb 2 12:49:38 localhost ocspd[876]: No CRL Entries for My_Test_CA
Feb 2 12:49:38 localhost ocspd: Starting OCSP Responder: Done.
Feb 2 13:05:58 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:05:58 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:05:58 localhost ocspd[915]: [request.c:72] [ERROR] Memory Allocation Error!
Feb 2 13:05:58 localhost ocspd[915]: [http_s.c:167] [ERROR] Unsupported HTTP Method detected (OPTIONS)
Feb 2 13:05:58 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:05:58 localhost ocspd[915]: [http_s.c:167] [ERROR] Unsupported HTTP Method detected (OPTIONS)
Feb 2 13:05:58 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:05:58 localhost ocspd[915]: [request.c:93] [ERROR] Memory Allocation Error
Feb 2 13:05:58 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:06:03 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:06:03 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:06:03 localhost ocspd[915]: [http_s.c:109] [ERROR] Can not parse HTTP method
Feb 2 13:06:03 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:06:08 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:06:08 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:06:13 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:06:13 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:06:18 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:06:18 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:06:23 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:06:23 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:06:28 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:06:28 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:06:33 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:06:33 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:06:38 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:06:38 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:06:43 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:06:43 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:06:48 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:06:48 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:06:53 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:06:53 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:06:58 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:06:58 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:06:58 localhost ocspd[915]: [http_s.c:167] [ERROR] Unsupported HTTP Method detected (OPTIONS)
Feb 2 13:06:58 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:07:03 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:07:03 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:07:08 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:07:08 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:07:13 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:07:13 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:07:18 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:07:18 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:07:23 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:07:23 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:07:28 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:07:28 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:07:33 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:07:33 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:07:38 localhost ocspd[915]: [http_s.c:453] File Read Error
Feb 2 13:07:38 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:07:40 localhost ocspd[915]: [request.c:105] [ERROR] Can not parse REQ
Feb 2 13:07:40 localhost ocspd[915]: [request.c:128] [ERROR] Can not parse REQ
Feb 2 13:07:40 localhost ocspd: *** Error in `/usr/sbin/ocspd': free(): invalid next size (fast): 0x00007f5cf0000c10 ***
Feb 2 13:07:40 localhost ocspd[915]: [http_s.c:167] [ERROR] Unsupported HTTP Method detected (PROPFIND)
Feb 2 13:07:40 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:07:40 localhost ocspd[915]: [request.c:93] [ERROR] Memory Allocation Error
Feb 2 13:07:40 localhost ocspd[915]: [http_s.c:167] [ERROR] Unsupported HTTP Method detected (OPTIONS)
Feb 2 13:07:40 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:07:40 localhost ocspd[915]: [http_s.c:167] [ERROR] Unsupported HTTP Method detected (OPTIONS)
Feb 2 13:07:40 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:07:40 localhost ocspd[915]: [request.c:93] [ERROR] Memory Allocation Error
Feb 2 13:07:40 localhost ocspd[915]: [request.c:72] [ERROR] Memory Allocation Error!
Feb 2 13:07:40 localhost ocspd[915]: [request.c:72] [ERROR] Memory Allocation Error!
Feb 2 13:07:40 localhost ocspd[915]: [http_s.c:167] [ERROR] Unsupported HTTP Method detected (OPTIONS)
Feb 2 13:07:40 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:07:40 localhost ocspd[915]: [request.c:105] [ERROR] Can not parse REQ
Feb 2 13:07:40 localhost ocspd[915]: [http_s.c:167] [ERROR] Unsupported HTTP Method detected (PROPFIND)
Feb 2 13:07:40 localhost ocspd[915]: [request.c:46] [ERROR] Network Error while reading Request!
Feb 2 13:07:40 localhost ocspd[915]: [core.c:291] [ERROR] SIGABRT::received - should not happen,
Feb 2 13:07:40 localhost ocspd[915]: [core.c:292] [ERROR] SIGABRT::please enable strict locking.
Feb 2 13:07:40 localhost ocspd[915]: [core.c:293] [ERROR] ERROR::SIGABRT::Fatal Error, aborting server!
Feb 2 13:07:40 localhost ocspd: ======= Backtrace: =========
Feb 2 13:07:40 localhost ocspd: /lib64/libc.so.6(+0x7cfe1)[0x7f5d0f7e6fe1]
Feb 2 13:07:40 localhost ocspd: /lib64/libpki.so.88(PKI_MEM_free+0x31)[0x7f5d11486321]
Feb 2 13:07:40 localhost ocspd: /lib64/libpki.so.88(PKI_HTTP_free+0x4a)[0x7f5d114b1b3a]
Feb 2 13:07:40 localhost ocspd: /usr/sbin/ocspd[0x404f1e]
Feb 2 13:07:40 localhost ocspd: /usr/sbin/ocspd[0x404cda]
Feb 2 13:07:40 localhost ocspd: /lib64/libpthread.so.0(+0x7dc5)[0x7f5d11246dc5]
Feb 2 13:07:40 localhost ocspd: /lib64/libc.so.6(clone+0x6d)[0x7f5d0f86021d]
Feb 2 13:07:40 localhost ocspd: ======= Memory map: ========
Feb 2 13:07:40 localhost ocspd: 00400000-0040c000 r-xp 00000000 fd:03 142088 /usr/sbin/ocspd
Feb 2 13:07:40 localhost ocspd: 0060b000-0060c000 r--p 0000b000 fd:03 142088 /usr/sbin/ocspd
Feb 2 13:07:40 localhost ocspd: 0060c000-0060d000 rw-p 0000c000 fd:03 142088 /usr/sbin/ocspd
Feb 2 13:07:40 localhost ocspd: 0154e000-015b1000 rw-p 00000000 00:00 0 [heap]
...
On other runs (using name -A -T4 ocsp.example.com) I get * Error in `ocspd': malloc(): memory corruption: 0x00007fffd8001380 * Setting a breakpoint there shows it is within the PKI library
0 0x00007ffff5e885f7 in raise () from /lib64/libc.so.6
#1 0x00007ffff5e89ce8 in abort () from /lib64/libc.so.6
#2 0x00007ffff5ecf515 in free_check () from /lib64/libc.so.6
#3 0x00007ffff7b6ef20 in PKI_Free (ret=0x650150) at pki_mem.c:312
#4 0x00007ffff7b6ef83 in PKI_ZFree (pnt=0x650150, size=88) at pki_mem.c:331
#5 0x00007ffff7b6eb3e in PKI_MEM_free (buf=0x64c7b0) at pki_mem.c:162
#6 0x00007ffff7ba55d2 in PKI_HTTP_free (rv=0x64efe0) at http_s.c:192
#7 0x000000000040563c in ocspd_req_get_socket (connfd=8, ocspd_conf=0x63a290) at request.c:155
#8 0x000000000040512c in thread_main (arg=0x64c440) at threads.c:116
#9 0x00007ffff792fdc5 in start_thread () from /lib64/libpthread.so.0
#10 0x00007ffff5f4921d in clone () from /lib64/libc.so.6
Also, under valgrind, I am seeing stuff like:
==1657== Invalid read of size 1
==1657== at 0x4C304E4: __GI___rawmemchr (in /usr/lib64/valgrind/vgpreload_memcheck-amd64-linux.so)
==1657== by 0x6A76371: _IO_str_init_static_internal (in /usr/lib64/libc-2.17.so)
==1657== by 0x6A65586: __isoc99_vsscanf (in /usr/lib64/libc-2.17.so)
==1657== by 0x6A65526: __isoc99_sscanf (in /usr/lib64/libc-2.17.so)
==1657== by 0x4E608EE: PKI_MEM_get_url_decoded (pki_mem.c:649)
==1657== by 0x4E60B01: PKI_MEM_get_decoded (pki_mem.c:743)
==1657== by 0x4E60BFF: PKI_MEM_decode (pki_mem.c:811)
==1657== by 0x4053B4: ocspd_req_get_socket (request.c:76)
==1657== by 0x40512B: thread_main (threads.c:116)
==1657== by 0x50D3DC4: start_thread (in /usr/lib64/libpthread-2.17.so)
==1657== by 0x6AF221C: clone (in /usr/lib64/libc-2.17.so)
==1657== Address 0x83c4d03 is 0 bytes after a block of size 19 alloc'd
==1657== at 0x4C2B974: calloc (in /usr/lib64/valgrind/vgpreload_memcheck-amd64-linux.so)
==1657== by 0x4E5FEE3: PKI_Malloc (pki_mem.c:294)
==1657== by 0x4E5F7BA: PKI_MEM_new (pki_mem.c:34)
==1657== by 0x4E5F85C: PKI_MEM_new_data (pki_mem.c:54)
==1657== by 0x405375: ocspd_req_get_socket (request.c:69)
==1657== by 0x40512B: thread_main (threads.c:116)
==1657== by 0x50D3DC4: start_thread (in /usr/lib64/libpthread-2.17.so)
==1657== by 0x6AF221C: clone (in /usr/lib64/libc-2.17.so)
==1657==
I've been running some test queries to our OpenCA OCSPd server using several clients. Queries from OpenSSL's ocsp command and our test .NET/C# client work fine.
However when making queries from a Node OCSP module (https://github.com/indutny/ocsp) the calls randomly result in malloc() memory corruption errors which, after several attempts, kill OCSPd:
I haven't debugged things enough to tell if it's a malformed query by that module (as I never get success), but in any event I figured I'd post this since it seemed pretty severe and could take ocspd offline.
If you're interested in checking it out further I can supply some simple test code or set things up to loop against some server & cert.
Thanks!