Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Segfault when accessing CEE fields (master, libfastjson 0.99.4) #1283

Closed
bobthemighty opened this issue Nov 24, 2016 · 5 comments
Closed

Segfault when accessing CEE fields (master, libfastjson 0.99.4) #1283

bobthemighty opened this issue Nov 24, 2016 · 5 comments
Milestone

Comments

@bobthemighty
Copy link
Contributor

I've built both rsyslog and libfastjson from source at various commits, but I keep seeing the same behaviour. Specifically, after calling mmnormalize, if I try to use any of the CEE fields, I get a segfault.

Initially I installed libfastjson from the Arch repos, but I've uninstalled that and built 0.99.2 through to 0.99.4 from source. Likewise, I've uninstalled rsyslog and built from source, versions ranging from 8.21 to 8.24.

Obviously I have done something monumentally stupid, but I can't figure out what.

8842.619379522:imuxsock.c : --------imuxsock calling select, active file descriptors (max 4): 3 4
8842.619390431:main Q:Reg/w0 : wti 0x6bbe70: worker awoke from idle processing
8842.619398385:main Q:Reg/w0 : DeleteProcessedBatch: we deleted 0 objects and enqueued 0 objects
8842.619404380:main Q:Reg/w0 : doDeleteBatch: delete batch from store, new sizes: log 1, phys 1
8842.619411346:imuxsock.c :
8842.619418980:main Q:Reg/w0 : processBATCH: batch of 1 elements must be processed
8842.619423156:main Q:Reg/w0 : processBATCH: next msg 0: <158>Nov 24 20:20:42 docker/availability-api[12345]: {"@message": "I like segfaults", "@timestamp": "2016-11-24T10:14:54.829Z"}
8842.619427308:main Q:Reg/w0 : PRIFILT '[Optimizer Result]'
8842.619433839:main Q:Reg/w0 : pmask: X X X X X X X X X X X X X X X X X X X FF X X X X X X
8842.619480348:main Q:Reg/w0 : PRIFILT condition result is 1
8842.619483164:main Q:Reg/w0 : ACTION 0 [mmnormalize:action(type="mmnormalize" ...)]
8842.619488401:main Q:Reg/w0 : executing action 0
8842.619491697:main Q:Reg/w0 : action 'action 0': called, logging to mmnormalize (susp 0/0, direct q 1)
8842.619495707:main Q:Reg/w0 : wti 0x6bbe70: we need to create a new action worker instance for action 0
8842.619499838:main Q:Reg/w0 : wti 0x6bbe70: created action worker instance 1 for action 0
8842.619503233:main Q:Reg/w0 : Action 0 transitioned to state: itx
8842.619506252:main Q:Reg/w0 : entering actionCalldoAction(), state: itx, actionNbr 0
8842.619527566:main Q:Reg/w0 : Action 0 transitioned to state: rdy
8842.619530474:main Q:Reg/w0 : action 'action 0': set suspended state to 0
8842.619533396:main Q:Reg/w0 : SET !structured!foo =
8842.619540217:main Q:Reg/w0 : string 'ho ho'
8842.619549607:main Q:Reg/w0 : END SET
8842.619558265:main Q:Reg/w0 : eval expr 0x6b5cc0, type 'S'
8842.619561459:main Q:Reg/w0 : eval expr 0x6b5cc0, return datatype 'S':0

Thread 3 "rs:main Q:Reg" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7ffff4927700 (LWP 21864)]
0x00007ffff7190ab0 in fjson_object_iter_peek_name () from /usr/lib/libfastjson.so.4

(gdb) bt
#0 0x00007ffff7190800 in fjson_object_iter_peek_name (iter=iter@entry=0x7ffff4926470) at json_object_iterator.c:135
#1 0x00007ffff718f488 in _fjson_find_child (jso=jso@entry=0x7fffe80020e0, key=key@entry=0x6b5ce1 "foo") at json_object.c:422
#2 0x00007ffff718fd29 in fjson_object_object_get_ex (jso=jso@entry=0x7fffe80020e0, key=key@entry=0x6b5ce1 "foo", value=value@entry=0x7ffff4926938) at json_object.c:532
#3 0x00000000004174fe in jsonVarExtract (root=0x7fffe80020e0, key=key@entry=0x6b5ce1 "foo", value=value@entry=0x7ffff4926938) at msg.c:4580
#4 0x000000000041e461 in msgAddJSON (pM=pM@entry=0x7ffff0004030, name=name@entry=0x6b5ce0 "!foo", json=json@entry=0x7fffe80025e0, force_reset=force_reset@entry=0, sharedReference=sharedReference@entry=0) at msg.c:4731
#5 0x000000000041ee91 in msgSetJSONFromVar (pMsg=pMsg@entry=0x7ffff0004030, varname=0x6b5ce0 "!foo", v=v@entry=0x7ffff4926a30, force_reset=0) at msg.c:4929
#6 0x000000000043a592 in execSet (pMsg=0x7ffff0004030, stmt=0x6ba5e0) at ruleset.c:218
#7 scriptExec (root=, pMsg=pMsg@entry=0x7ffff0004030, pWti=pWti@entry=0x6bbe70) at ruleset.c:540
#8 0x000000000043a5e2 in execPRIFILT (pWti=, pMsg=, stmt=) at ruleset.c:378
#9 scriptExec (root=, pMsg=pMsg@entry=0x7ffff0004030, pWti=pWti@entry=0x6bbe70) at ruleset.c:555
#10 0x000000000043ad8c in processBatch (pBatch=0x6bbea8, pWti=0x6bbe70) at ruleset.c:595
#11 0x000000000044ab64 in msgConsumer (notNeeded=, pBatch=0x6bbea8, pWti=0x6bbe70) at rsyslogd.c:596
#12 0x00000000004369d1 in ConsumerReg (pThis=0x6bb950, pWti=0x6bbe70) at queue.c:2000
#13 0x0000000000432b33 in wtiWorker (pThis=pThis@entry=0x6bbe70) at wti.c:363
#14 0x00000000004312fe in wtpWorker (arg=0x6bbe70) at wtp.c:397
#15 0x00007ffff79ae454 in start_thread () from /usr/lib/libpthread.so.0
#16 0x00007ffff6acd7df in clone () from /usr/lib/libc.so.6
(gdb) bt full
#0 0x00007ffff7190800 in fjson_object_iter_peek_name (iter=iter@entry=0x7ffff4926470) at json_object_iterator.c:135
No locals.
#1 0x00007ffff718f488 in _fjson_find_child (jso=jso@entry=0x7fffe80020e0, key=key@entry=0x6b5ce1 "foo") at json_object.c:422
it = {objs_remain = -402644688, curr_idx = 0, pg = 0x0}
itEnd = {objs_remain = 0, curr_idx = 0, pg = 0x0}
#2 0x00007ffff718fd29 in fjson_object_object_get_ex (jso=jso@entry=0x7fffe80020e0, key=key@entry=0x6b5ce1 "foo", value=value@entry=0x7ffff4926938) at json_object.c:532
chld =
value = 0x7ffff4926938
key = 0x6b5ce1 "foo"
jso = 0x7fffe80020e0
#3 0x00000000004174fe in jsonVarExtract (root=0x7fffe80020e0, key=key@entry=0x6b5ce1 "foo", value=value@entry=0x7ffff4926938) at msg.c:4580
namebuf = '\000' <repeats 24 times>, "\300/\336\367\377\177\000\000\000\000\000\000\000\000\000\000;\000\000\000\000\000\000\000(H\375\367\377\177\000\000X\324\030\367\377\177\000\000\000\336\030\367\377\177\000\000\323\070\336\367\377\177\000\000;\000\000\000\000\000\000\000\000\336\030\367\377\177\000\000(H\375\367\377\177\000\000\330e\222\364\377\177\000\000\324e\222\364\377\177\000\000\220\215\236\366\377\177\000\000(u@\000\000\000\000\000\020\035@\000\000\000\000\000\330e\222\364\377\177\000\000\233\230rN\000\000\000\000b\312\071\001\000\000\000\000\000\336\030\367\377\177\000\000\260f\222\364\377\177\000\000X\324\030\367\377\177\000\000\324e\222\364\377\177\000\000"...
key_len =
array_idx_start =
array_idx_end =
array_idx_num_end_discovered = 0x0
arr = 0x0
#4 0x000000000041e461 in msgAddJSON (pM=pM@entry=0x7ffff0004030, name=name@entry=0x6b5ce0 "!foo", json=json@entry=0x7fffe80025e0, force_reset=force_reset@entry=0, sharedReference=sharedReference@entry=0) at msg.c:4731
pjroot = 0x7ffff0004168
parent = 0x7fffe80020e0
leafnode = 0x0
given =
leaf = 0x6b5ce1 "foo"
iRet = RS_RET_OK
#5 0x000000000041ee91 in msgSetJSONFromVar (pMsg=pMsg@entry=0x7ffff0004030, varname=0x6b5ce0 "!foo", v=v@entry=0x7ffff4926a30, force_reset=0) at msg.c:4929
json = 0x7fffe80025e0
cstr =
#6 0x000000000043a592 in execSet (pMsg=0x7ffff0004030, stmt=0x6ba5e0) at ruleset.c:218
result = {d = {estr = 0x7fffe80025a0, ar = 0x7fffe80025a0, n = 140737085711776, json = 0x7fffe80025a0}, datatype = 83 'S'}
iRet = RS_RET_OK
#7 scriptExec (root=, pMsg=pMsg@entry=0x7ffff0004030, pWti=pWti@entry=0x6bbe70) at ruleset.c:540
stmt = 0x6ba5e0
iRet = RS_RET_OK
#8 0x000000000043a5e2 in execPRIFILT (pWti=, pMsg=, stmt=) at ruleset.c:378
bRet =
iRet =
#9 scriptExec (root=, pMsg=pMsg@entry=0x7ffff0004030, pWti=pWti@entry=0x6bbe70) at ruleset.c:555
stmt = 0x6ba650
iRet = RS_RET_OK
#10 0x000000000043ad8c in processBatch (pBatch=0x6bbea8, pWti=0x6bbe70) at ruleset.c:595
i = 0
pMsg = 0x7ffff0004030
pRuleset =
localRet =
#11 0x000000000044ab64 in msgConsumer (notNeeded=, pBatch=0x6bbea8, pWti=0x6bbe70) at rsyslogd.c:596
i =
#12 0x00000000004369d1 in ConsumerReg (pThis=0x6bb950, pWti=0x6bbe70) at queue.c:2000
iCancelStateSave = 1
bNeedReLock = 1
skippedMsgs = 0
iRet =
PRETTY_FUNCTION = "ConsumerReg"
#13 0x0000000000432b33 in wtiWorker (pThis=pThis@entry=0x6bbe70) at wti.c:363
__cancel_buf = {__cancel_jmp_buf = {{__cancel_jmp_buf = {140737296624976, 852003604640534109, 1, 140737300809071, 7060704, 140737354125312, -852019050560909731, 852003393483673181}, __mask_was_saved = 0}}, __pad = {0x7ffff4926d50, 0x0,
0x0, 0x0}}
__cancel_routine = 0x432250
__cancel_arg = 0x6bbe70
__not_first_call = 0




Config looks like this:

module(load="imuxsock" SysSock.Use="on")
input (type="imuxsock" Socket="/dev/log")
module(load="mmnormalize")

template(name="prestructured" type="list") {
property(name="$!structured")
}

if $syslogfacility == 19 then {

. action(type="mmnormalize" rulebase="/home/bob/.config/rsyslog.d/structured.rb")
set $!structured!foo = "ho ho";
}


and structured.rb looks like this:

version=2

rule=structured:%structured:json%
rule=structured: %structured:json%


I'm a little bit confused. I had to rebuild my laptop, so I'm just trying to get my dev env working again.

@rgerhards
Copy link
Member

Can you build with cflags -fsanitze=address -g ? That could probably bring more light on this.

@bobthemighty
Copy link
Contributor Author

=================================================================
==31033==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x60700000a7f8 at pc 0x7f0bf372d734 bp 0x7f0bedd88380 sp 0x7f0bedd88378
READ of size 8 at 0x60700000a7f8 thread T2 (rs:main Q:Reg)
#0 0x7f0bf372d733 (/usr/lib/libfastjson.so.4+0xb733)
#1 0x7f0bf372d28c (/usr/lib/libfastjson.so.4+0xb28c)
#2 0x7f0bf3729af5 (/usr/lib/libfastjson.so.4+0x7af5)
#3 0x7f0bf372a425 (/usr/lib/libfastjson.so.4+0x8425)
#4 0x53dc7c (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x53dc7c)
#5 0x55008e (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x55008e)
#6 0x551282 (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x551282)
#7 0x5d5f48 (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x5d5f48)
#8 0x5d5717 (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x5d5717)
#9 0x5d69cd (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x5d69cd)
#10 0x5d57d6 (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x5d57d6)
#11 0x5d3db8 (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x5d3db8)
#12 0x62702b (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x62702b)
#13 0x5bcd79 (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x5bcd79)
#14 0x5aecf2 (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x5aecf2)
#15 0x5abd0e (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x5abd0e)
#16 0x7f0bf3b5d453 (/usr/lib/libpthread.so.0+0x7453)
#17 0x7f0bf273b7de (/usr/lib/libc.so.6+0xe87de)

0x60700000a7f8 is located 0 bytes to the right of 72-byte region [0x60700000a7b0,0x60700000a7f8)
allocated by thread T2 (rs:main Q:Reg) here:
#0 0x4d40a0 (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x4d40a0)
#1 0x7f0bee18f66f (/usr/lib/libjson-c.so.2+0x366f)

Thread T2 (rs:main Q:Reg) created by T1 (in:imuxsock) here:
#0 0x436a1d (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x436a1d)
#1 0x5aabfa (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x5aabfa)
#2 0x5aa4d9 (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x5aa4d9)
#3 0x5be2be (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x5be2be)
#4 0x5c10df (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x5c10df)
#5 0x627f28 (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x627f28)
#6 0x5dbaab (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x5dbaab)
#7 0x7f0bee7c7477 (/usr/lib/rsyslog/imuxsock.so+0x12477)
#8 0x7f0bee7c48ba (/usr/lib/rsyslog/imuxsock.so+0xf8ba)
#9 0x7f0bee7bfcae (/usr/lib/rsyslog/imuxsock.so+0xacae)
#10 0x60233a (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x60233a)
#11 0x7f0bf3b5d453 (/usr/lib/libpthread.so.0+0x7453)

Thread T1 (in:imuxsock) created by T0 here:
#0 0x436a1d (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x436a1d)
#1 0x601d7c (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x601d7c)
#2 0x522bda (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x522bda)
#3 0x51cec2 (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x51cec2)
#4 0x62a84c (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x62a84c)
#5 0x628fec (/home/bob/code/open-source/rsyslog/tools/rsyslogd+0x628fec)
#6 0x7f0bf2673290 (/usr/lib/libc.so.6+0x20290)

SUMMARY: AddressSanitizer: heap-buffer-overflow (/usr/lib/libfastjson.so.4+0xb733)
Shadow bytes around the buggy address:
0x0c0e7fff94a0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c0e7fff94b0: 00 00 00 00 00 00 00 00 00 05 fa fa fa fa 00 00
0x0c0e7fff94c0: 00 00 00 00 00 00 00 fa fa fa fa fa 00 00 00 00
0x0c0e7fff94d0: 00 00 00 00 00 06 fa fa fa fa 00 00 00 00 00 00
0x0c0e7fff94e0: 00 00 00 fa fa fa fa fa fd fd fd fd fd fd fd fd
=>0x0c0e7fff94f0: fd fd fa fa fa fa 00 00 00 00 00 00 00 00 00[fa]
0x0c0e7fff9500: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c0e7fff9510: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c0e7fff9520: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c0e7fff9530: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c0e7fff9540: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
Shadow byte legend (one shadow byte represents 8 application bytes):
Addressable: 00
Partially addressable: 01 02 03 04 05 06 07
Heap left redzone: fa
Heap right redzone: fb
Freed heap region: fd
Stack left redzone: f1
Stack mid redzone: f2
Stack right redzone: f3
Stack partial redzone: f4
Stack after return: f5
Stack use after scope: f8
Global redzone: f9
Global init order: f6
Poisoned by user: f7
Container overflow: fc
Array cookie: ac
Intra object redzone: bb
ASan internal: fe
Left alloca redzone: ca
Right alloca redzone: cb
==31033==ABORTING

@rgerhards
Copy link
Member

Unfortunately the symbolizer seems not to be present or needs to be set:

http://clang.llvm.org/docs/AddressSanitizer.html#symbolizing-the-reports

I'll try to reproduce the issue next week, but if you want to have a look at symbolizing, I wouldn't mind. Note that this is not vital, just possibly a bit helpful. So if you are too busy, don't waste time here.

@rgerhards rgerhards added this to the v8.32 milestone Nov 26, 2017
@rgerhards
Copy link
Member

This was probably an error in libfastjson. Version 0.99.8 has been released yesterday. I assume this fixes the issue. If not, please let me know and I'll re-open the issue.

@lock
Copy link

lock bot commented Dec 26, 2019

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.

@lock lock bot locked as resolved and limited conversation to collaborators Dec 26, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

2 participants