Description of problem: mmjsonparse fails to parse json message. Version-Release number of selected component (if applicable): Name : rsyslog-mmjsonparse Arch : x86_64 Version : 7.2.6 Release : 1.fc19 Size : 11 k Repo : installed From repo : fedora Summary : JSON enhanced logging support URL : http://www.rsyslog.com/ License : (GPLv3+ and ASL 2.0) Description : This module provides the capability to recognize and parse JSON : enhanced syslog messages. How reproducible: Add below config into rsyslog #### GLOBAL DIRECTIVES #### #$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat $ModLoad mmjsonparse :mmjsonparse: template(name="GLFS_template" type="list") { constant(value="[") property(name="timereported" dateFormat="rfc3339") constant(value="] ") property(name="$!msg") constant(value="\n") } $ActionFileDefaultTemplate GLFS_template and restart rsyslog Steps to Reproduce: 1. run command # logger '@cee: {"msg": "json message"}' Actual results: raw json message appears in log file. for example [2013-07-30T12:04:49.927523+05:30] {"msg": "json message"} Expected results: parsed json message should appear. for example [2013-07-30T11:57:22.660955+05:30] json message Additional info: Running rsyslog in debug mode throws below 6172.415459260:7f7f82513700: Message from UNIX socket: #4 6172.415481722:7f7f82513700: main Q: entry added, size now log 1, phys 1 entries 6172.415488519:7f7f82513700: main Q: EnqueueMsg advised worker start 6172.415491862:7f7f82513700: --------imuxsock calling select, active file descriptors (max 4): 4 6172.415501658:7f7f81471700: wti 0x7f7f857fcff0: worker awoke from idle processing 6172.415505597:7f7f81471700: we deleted 0 objects and enqueued 0 objects 6172.415507350:7f7f81471700: delete batch from store, new sizes: log 1, phys 1 6172.415510217:7f7f81471700: processBatch: batch of 1 elements must be processed 6172.415513059:7f7f81471700: RRRR: scriptExec: batch of 1 elements, active (nil), stmt 0x7f7f85801130, nodetype 4004 6172.415515619:7f7f81471700: RRRR: execAct [mmjsonparse]: batch of 1 elements, active (nil) 6172.415518624:7f7f81471700: Called action(NotAllMark), processing batch[0] via 'mmjsonparse' 6172.415520590:7f7f81471700: Called action(Batch), logging to mmjsonparse 6172.415523379:7f7f81471700: tryDoAction 0x7f7f858016e0, pnElem 1, nElem 1 6172.415525486:7f7f81471700: Action 0x7f7f858016e0 transitioned to state: itx 6172.415527344:7f7f81471700: entering actionCalldoAction(), state: itx 6172.415529946:7f7f81471700: mmjsonparse: toParse: ' {"msg": "json message"}' 6172.415551947:7f7f81471700: mmjsonparse: Error parsing JSON ' {"msg": "json message"}': Extra characters after JSON object 6172.415555778:7f7f81471700: Action 0x7f7f858016e0 transitioned to state: rdy 6172.415557880:7f7f81471700: action 0x7f7f858016e0 call returned 0 6172.415560613:7f7f81471700: RRRR: scriptExec: batch of 1 elements, active (nil), stmt 0x7f7f85802080, nodetype 4001 6172.415562840:7f7f81471700: batch: item 0 PRIFILT 1 6172.415564789:7f7f81471700: RRRR: scriptExec: batch of 1 elements, active 0x7f7f740008c0, stmt 0x7f7f85801190, nodetype 4004 6172.415567083:7f7f81471700: RRRR: execAct [builtin:omfile]: batch of 1 elements, active 0x7f7f740008c0 6172.415569147:7f7f81471700: Called action(NotAllMark), processing batch[0] via 'builtin:omfile' 6172.415570926:7f7f81471700: Called action(Batch), logging to builtin:omfile 6172.415577211:7f7f81471700: tryDoAction 0x7f7f85801e30, pnElem 1, nElem 1 6172.415579223:7f7f81471700: Action 0x7f7f85801e30 transitioned to state: itx 6172.415581006:7f7f81471700: entering actionCalldoAction(), state: itx 6172.415583062:7f7f81471700: file to log to: /var/log/messages 6172.415584985:7f7f81471700: write to stream, pData->pStrm 0x7f7f74000ef0, lenBuf 60 6172.415587223:7f7f81471700: action 0x7f7f85801e30 call returned -2121 6172.415589773:7f7f81471700: strm 0x7f7f74000ef0: file 6(messages) flush, buflen 60 6172.415592062:7f7f81471700: strmPhysWrite, stream 0x7f7f74000ef0, len 60 6172.415610465:7f7f81471700: strm 0x7f7f74000ef0: file 6 write wrote 60 bytes 6172.415612931:7f7f81471700: Action 0x7f7f85801e30 transitioned to state: rdy 6172.415615361:7f7f81471700: RRRR: scriptExec: batch of 1 elements, active (nil), stmt 0x7f7f85803010, nodetype 4001 6172.415617408:7f7f81471700: batch: item 0 PRIFILT 0 6172.415619258:7f7f81471700: RRRR: scriptExec: batch of 1 elements, active 0x7f7f740008c0, stmt 0x7f7f858020e0, nodetype 4004 6172.415621227:7f7f81471700: RRRR: execAct [builtin:omfile]: batch of 1 elements, active 0x7f7f740008c0 6172.415622944:7f7f81471700: Called action(Batch), logging to builtin:omfile 6172.415625303:7f7f81471700: tryDoAction 0x7f7f85802ac0, pnElem 1, nElem 1 6172.415627273:7f7f81471700: RRRR: scriptExec: batch of 1 elements, active (nil), stmt 0x7f7f85803700, nodetype 4001 6172.415629176:7f7f81471700: batch: item 0 PRIFILT 0 6172.415630840:7f7f81471700: RRRR: scriptExec: batch of 1 elements, active 0x7f7f740008c0, stmt 0x7f7f85803070, nodetype 4004 6172.415633396:7f7f81471700: RRRR: execAct [builtin:omfile]: batch of 1 elements, active 0x7f7f740008c0 6172.415635013:7f7f81471700: Called action(Batch), logging to builtin:omfile 6172.415637054:7f7f81471700: tryDoAction 0x7f7f858031b0, pnElem 1, nElem 1 6172.415638917:7f7f81471700: RRRR: scriptExec: batch of 1 elements, active (nil), stmt 0x7f7f85803df0, nodetype 4001 6172.415640788:7f7f81471700: batch: item 0 PRIFILT 0 6172.415642482:7f7f81471700: RRRR: scriptExec: batch of 1 elements, active 0x7f7f740008c0, stmt 0x7f7f85803760, nodetype 4004 6172.415644482:7f7f81471700: RRRR: execAct [builtin:omfile]: batch of 1 elements, active 0x7f7f740008c0 6172.415646100:7f7f81471700: Called action(Batch), logging to builtin:omfile 6172.415647988:7f7f81471700: tryDoAction 0x7f7f858038a0, pnElem 1, nElem 1 6172.415649864:7f7f81471700: RRRR: scriptExec: batch of 1 elements, active (nil), stmt 0x7f7f85804510, nodetype 4001 6172.415651748:7f7f81471700: batch: item 0 PRIFILT 0 6172.415653512:7f7f81471700: RRRR: scriptExec: batch of 1 elements, active 0x7f7f740008c0, stmt 0x7f7f85803e50, nodetype 4004 6172.415655795:7f7f81471700: RRRR: execAct [builtin:omusrmsg]: batch of 1 elements, active 0x7f7f740008c0 6172.415657395:7f7f81471700: Called action(Batch), logging to builtin:omusrmsg 6172.415659373:7f7f81471700: tryDoAction 0x7f7f85803fc0, pnElem 1, nElem 1 6172.415661240:7f7f81471700: RRRR: scriptExec: batch of 1 elements, active (nil), stmt 0x7f7f85804c00, nodetype 4001 6172.415663160:7f7f81471700: batch: item 0 PRIFILT 0 6172.415664819:7f7f81471700: RRRR: scriptExec: batch of 1 elements, active 0x7f7f740008c0, stmt 0x7f7f85804570, nodetype 4004 6172.415666909:7f7f81471700: RRRR: execAct [builtin:omfile]: batch of 1 elements, active 0x7f7f740008c0 6172.415668518:7f7f81471700: Called action(Batch), logging to builtin:omfile 6172.415670543:7f7f81471700: tryDoAction 0x7f7f858046b0, pnElem 1, nElem 1 6172.415672473:7f7f81471700: RRRR: scriptExec: batch of 1 elements, active (nil), stmt 0x7f7f857fcae0, nodetype 4001 6172.415674387:7f7f81471700: batch: item 0 PRIFILT 0 6172.415676088:7f7f81471700: RRRR: scriptExec: batch of 1 elements, active 0x7f7f740008c0, stmt 0x7f7f85804c60, nodetype 4004 6172.415678141:7f7f81471700: RRRR: execAct [builtin:omfile]: batch of 1 elements, active 0x7f7f740008c0 6172.415679720:7f7f81471700: Called action(Batch), logging to builtin:omfile 6172.415681704:7f7f81471700: tryDoAction 0x7f7f85804da0, pnElem 1, nElem 1 6172.416721483:7f7f81471700: ruleset.ProcessMsg() returns 0 6172.416724669:7f7f81471700: regular consumer finished, iret=0, szlog 0 sz phys 1 6172.416728384:7f7f81471700: we deleted 1 objects and enqueued 0 objects 6172.416730225:7f7f81471700: delete batch from store, new sizes: log 0, phys 0 6172.416732276:7f7f81471700: regular consumer finished, iret=4, szlog 0 sz phys 0 6172.416734222:7f7f81471700: main Q:Reg/w0: worker IDLE, waiting for work. After recompiling rsyslog-7.2.6-1.fc19.src.rpm got from fedora repo on fedora 19 system solves this.
Bala, can you test that this now works correctly with the latest packages in f19/f20? It works for me with json-c-0.11-5.fc21.x86_64 rsyslog-7.4.2-2.fc20.x86_64
This message is a notice that Fedora 19 is now at end of life. Fedora has stopped maintaining and issuing updates for Fedora 19. It is Fedora's policy to close all bug reports from releases that are no longer maintained. Approximately 4 (four) weeks from now this bug will be closed as EOL if it remains open with a Fedora 'version' of '19'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version. Thank you for reporting this issue and we are sorry that we were not able to fix it before Fedora 19 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora, you are encouraged change the 'version' to a later Fedora version prior this bug is closed as described in the policy above. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete.
Fedora 19 changed to end-of-life (EOL) status on 2015-01-06. Fedora 19 is no longer maintained, which means that it will not receive any further security or bug fix updates. As a result we are closing this bug. If you can reproduce this bug against a currently maintained version of Fedora please feel free to reopen this bug against that version. If you are unable to reopen this bug, please file a new report against the current release. If you experience problems, please add a comment to this bug. Thank you for reporting this bug and we are sorry it could not be fixed.