Help with _jsonparsefailure?

ZillaG · February 24, 2017, 8:49pm

I have a multi-line java exception log that I'm correctly sending via rsyslog from a remote server to my ELK stack, like the one below (sorry for the verbosity). It looks, to me, like a valid json file.

{ "type":"pe-log", "host":"ip-10-53-234-234", "timestamp":"2017-02-24T20:06:08.036699+00:00", "@version":"1", "customer":"customer", "role":"app2", "sourcefile":"/tmp/error.log", "message":"2017-02-08 21:59:51,727 ERROR :localhost-startStop-1 [jdbc.sqlonly] 1. PreparedStatement.executeBatch() batching 1 statements:\\n1: insert into CR_CLUSTER_REGISTRY (Cluster_Name, Url, Update_Dttm, Node_Id) values ('customer', 'rmi:\/\/ip-10-53-254.254.eu-west-1.compute.internal:1199\/2', '02\/08\/2017 21:59:51.639', '2')\\n\\njava.sql.BatchUpdateException: [Teradata JDBC Driver] [TeraJDBC 15.00.00.35] [Error 1338] [SQLState HY000] A failure occurred while executing a PreparedStatement batch request. Details of the failure can be found in the exception chain that is accessible with getNextException.\\n at com.teradata.jdbc.jdbc_4.util.ErrorFactory.makeBatchUpdateException(ErrorFactory.java:148)\\n at com.teradata.jdbc.jdbc_4.util.ErrorFactory.makeBatchUpdateException(ErrorFactory.java:137)\\n at com.teradata.jdbc.jdbc_4.TDPreparedStatement.executeBatchDMLArray(TDPreparedStatement.java:272)\\n at com.teradata.jdbc.jdbc_4.TDPreparedStatement.executeBatch(TDPreparedStatement.java:2584)\\n at com.teradata.tal.qes.StatementProxy.executeBatch(StatementProxy.java:186)\\n at net.sf.log4jdbc.StatementSpy.executeBatch(StatementSpy.java:539)\\n at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:70)\\n at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:268)\\n at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:266)\\n at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:167)\\n at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321)\\n at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50)\\n at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1028)\\n at com.teradata.tal.common.persistence.dao.SessionWrapper.flush(SessionWrapper.java:920)\\n at com.teradata.trm.common.persistence.dao.DaoImpl.save(DaoImpl.java:263)\\n at com.teradata.trm.common.service.AbstractService.save(AbstractService.java:509)\\n at com.teradata.trm.common.cluster.Cluster.init(Cluster.java:413)\\n at com.teradata.trm.common.cluster.NodeConfiguration.initialize(NodeConfiguration.java:182)\\n at com.teradata.trm.common.context.Initializer.onApplicationEvent(Initializer.java:73)\\n at com.teradata.trm.common.context.Initializer.onApplicationEvent(Initializer.java:30)\\n at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:97)\\n at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:324)\\n at org.springframework.context.support.AbstractApplicationContext.finishRefresh(AbstractApplicationContext.java:929)\\n at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:467)\\n at org.springframework.web.context.ContextLoader.configureAndRefreshWebApplicationContext(ContextLoader.java:385)\\n at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:284)\\n at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:111)\\n at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4973)\\n at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5467)\\n at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)\\n at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:901)\\n at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:877)\\n at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:632)\\n at org.apache.catalina.startup.HostConfig.deployDirectory(HostConfig.java:1247)\\n at org.apache.catalina.startup.HostConfig$DeployDirectory.run(HostConfig.java:1898)\\n at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)\\n at java.util.concurrent.FutureTask.run(FutureTask.java:262)\\n at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)\\n at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)\\n at java.lang.Thread.run(Thread.java:745)\\nCaused by: java.sql.SQLException: [Teradata Database] [TeraJDBC 15.00.00.35] [Error -2801] [SQLState 23000] Duplicate unique prime key error in CIM_META.CR_CLUSTER_REGISTRY.\\n at com.teradata.jdbc.jdbc_4.util.ErrorFactory.makeDatabaseSQLException(ErrorFactory.java:301)\\n at com.teradata.jdbc.jdbc_4.statemachine.ReceiveInitSubState.action(ReceiveInitSubState.java:114)\\n at com.teradata.jdbc.jdbc_4.statemachine.StatementReceiveState.subStateMachine(StatementReceiveState.java:311)\\n at com.teradata.jdbc.jdbc_4.statemachine.StatementReceiveState.action(StatementReceiveState.java:200)\\n at com.teradata.jdbc.jdbc_4.statemachine.StatementController.runBody(StatementController.java:137)\\n at com.teradata.jdbc.jdbc_4.statemachine.PreparedBatchStatementController.run(PreparedBatchStatementController.java:58)\\n at com.teradata.jdbc.jdbc_4.TDStatement.executeStatement(TDStatement.java:387)\\n at com.teradata.jdbc.jdbc_4.TDPreparedStatement.executeBatchDMLArray(TDPreparedStatement.java:252)\\n ... 37 more\\n"}

I have the following Logstash conf file

input {
  udp {
    port => 55xx
    codec => json
  }
}

Logstash gives a json parse error when it receives this log. Any clues? How can I debug what Logstash is complaining about? I see nothing in logstash.log nor logstash.err files.

ZillaG · February 27, 2017, 4:04pm

Here's yet another example of a log that Logstash complains about a _jsonparsefailure. Again sorry for the verbosity.

`{ "type":"trm-system", "host":"ip-10-xx-xxx", "timestamp":"2017-02-27T14:01:30.298520+00:00", "@version":"1", "customer":"airmiles", "role":"app1", "sourcefile":"/usr/share/tomcat/dist/logs/trm-system.log", "message":"2017-02-27 14:01:30,215 INFO  :SimpleThreadPoolWorker-4 [jdbc.sqlonly]  batching 1 statements:
1:  insert into CR_TEXT_STORAGE_DATA (TEXT_VAL, TEXT_STORAGE_ID, SEQUENCE_ORD) values ('<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
<whiteboard>
    <link>
        <cancelLink>false</cancelLink>
        <destination>
            <connectionPointId>3</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hhl</nodeId>
        </destination>
        <source>
            <connectionPointId>1</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hj5</nodeId>
        </source>
    </link>
    <link>
        <cancelLink>false</cancelLink>
        <destination>
            <connectionPointId>3</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hhv</nodeId>
        </destination>
        <source>
            <connectionPointId>1</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hj5</nodeId>
        </source>
    </link>
    <link>
        <cancelLink>false</cancelLink>
        <destination>
            <connectionPointId>3</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hn4</nodeId>
        </destination>
        <source>
            <connectionPointId>1</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hj5</nodeId>
        </source>
    </link>
    <link>
        <cancelLink>false</cancelLink>
        <destination>
            <connectionPointId>3</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hn8</nodeId>
        </destination>
        <source>
            <connectionPointId>1</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hj5</nodeId>
        </source>
    </link>
    <link>
        <cancelLink>false</cancelLink>
        <destination>
            <connectionPointId>3</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hnr</nodeId>
        </destination>
        <source>
            <connectionPointId>1</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hj5</nodeId>
        </source>
    </link>
    <link>
        <cancelLink>false</cancelLink>
        <destination>
            <connectionPointId>3</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hnw</nodeId>
        </destination>
        <source>
            <connectionPointId>1</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hj5</nodeId>
        </source>
    </link>
    <link>
        <cancelLink>false</cancelLink>
        <destination>
            <connectionPointId>3</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hp1</nodeId>
        </destination>
        <source>
            <connectionPointId>1</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hj5</nodeId>
        </source>
    </link>
    <link>
        <cancelLink>false</cancelLink>
        <destination>
            <connectionPointId>3</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hp7</nodeId>
        </destination>
        <source>
            <connectionPointId>1</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hj5</nodeId>
        </source>
    </link>
    <link>
        <cancelLink>false</cancelLink>
        <destination>
            <connectionPointId>3</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hph</nodeId>
        </destination>
        <source>
            <connectionPointId>1</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hj5</nodeId>
        </source>
    </link>
    <link>
        <cancelLink>false</cancelLink>
        <destination>
            <connectionPointId>3</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13pvn</nodeId>
        </destination>
        <source>
            <connectionPointId>1</connectionPointId>
            <nodeId>1000h6c13hh8 1000h6c13hj5</nodeId>
        </source>
    </link>
    <node isCollapsed="false" isSelectable="false">
        <node isCollapsed="true" isSelectable="false">
            <displayOrder>1</displayOrder>
            <name>F4 - S1a2 - OptIn</name>
            <nodeId>1000h6c13hh8 1000h6c13hhl</nodeId>
            <properties>
                <property name="objectLocalInd" val="true"/>
                <property name="deduplicationOrder" val="1"/>
                <property name="objectStatus" val="1"/>
                <property name="dedupInd" val="true"/>
            </properties>
            <nodeType>100</nodeType>
            <point x="280" y="30"/>
            <selectedTabIndex>0</selectedTabIndex>
            <ZIndex>22</ZIndex>
        </node>
        <node isCollapsed="true" isSelectable="false">
            <displayOrder>2</displayOrder>
            <name>RestitcimT</name>
            <nodeId>1000h6c13hh8 1000h6c13hj5</nodeId>
            <properties>
                <property name="objectLocalInd" val="true"/>
                <property name="mandatorySegmentInd" val="false"/>
                <property name="deduplicationOrder" val="1"/>
                <property name="objectStatus" val="1"/>
                <property name="dedupInd" val="false"/>
            </properties>
            <nodeType>102</nodeType>
            <point x="20" y="30"/>
            <selectedTabIndex>0</selectedTabIndex>
            <ZIndex>18</ZIndex>
        </node>
`

(note see next post for other half of log, since posts are limited to 7000 characters)

ZillaG · February 27, 2017, 4:07pm

(Continuation of above log)

<node isCollapsed="true" isSelectable="false">
    <displayOrder>2</displayOrder>
    <name>F4 - S1a2 - OptOut</name>
    <nodeId>1000h6c13hh8 1000h6c13hhv</nodeId>
    <properties>
        <property name="objectLocalInd" val="true"/>
        <property name="deduplicationOrder" val="2"/>
        <property name="objectStatus" val="1"/>
        <property name="dedupInd" val="true"/>
    </properties>
    <nodeType>100</nodeType>
    <point x="280" y="97"/>
    <selectedTabIndex>0</selectedTabIndex>
    <ZIndex>31</ZIndex>
</node>
<node isCollapsed="true" isSelectable="false">
    <displayOrder>3</displayOrder>
    <name>F4 - S1a2 - OptIn - Rem</name>
    <nodeId>1000h6c13hh8 1000h6c13hn4</nodeId>
    <properties>
        <property name="objectLocalInd" val="true"/>
        <property name="deduplicationOrder" val="3"/>
        <property name="objectStatus" val="1"/>
        <property name="dedupInd" val="true"/>
    </properties>
    <nodeType>100</nodeType>
    <point x="280" y="164"/>
    <selectedTabIndex>0</selectedTabIndex>
    <ZIndex>34</ZIndex>
</node>
<node isCollapsed="true" isSelectable="false">
    <displayOrder>4</displayOrder>
    <name>F4 - S1a2 - OptOut - Rem</name>
    <nodeId>1000h6c13hh8 1000h6c13hn8</nodeId>
    <properties>
        <property name="objectLocalInd" val="true"/>
        <property name="deduplicationOrder" val="4"/>
        <property name="objectStatus" val="1"/>
        <property name="dedupInd" val="true"/>
    </properties>
    <nodeType>100</nodeType>
    <point x="280" y="231"/>
    <selectedTabIndex>0</selectedTabIndex>
    <ZIndex>36</ZIndex>
</node>

ZillaG · February 27, 2017, 4:08pm

(part 3 of above log)

<node isCollapsed="true" isSelectable="false">
    <displayOrder>5</displayOrder>
    <name>F4 - S1b - Optin</name>
    <nodeId>1000h6c13hh8 1000h6c13hnr</nodeId>
    <properties>
        <property name="objectLocalInd" val="true"/>
        <property name="deduplicationOrder" val="5"/>
        <property name="objectStatus" val="1"/>
        <property name="dedupInd" val="true"/>
    </properties>
    <nodeType>100</nodeType>
    <point x="280" y="298"/>
    <selectedTabIndex>0</selectedTabIndex>
    <ZIndex>38</ZIndex>
</node>
<node isCollapsed="true" isSelectable="false">
    <displayOrder>6</displayOrder>
    <name>F4 - S1b - OptOut</name>
    <nodeId>1000h6c13hh8 1000h6c13hnw</nodeId>
    <properties>
        <property name="objectLocalInd" val="true"/>
        <property name="deduplicationOrder" val="6"/>
        <property name="objectStatus" val="1"/>
        <property name="dedupInd" val="true"/>
    </properties>
    <nodeType>100</nodeType>
    <point x="280" y="365"/>
    <selectedTabIndex>0</selectedTabIndex>
    <ZIndex>40</ZIndex>
</node>
<node isCollapsed="true" isSelectable="false">
    <displayOrder>7</displayOrder>
    <name>F4 - S1b - Optin - Rem</name>
    <nodeId>1000h6c13hh8 1000h6c13hp1</nodeId>
    <properties>
        <property name="objectLocalInd" val="true"/>
        <property name="deduplicationOrder" val="7"/>
        <property name="objectStatus" val="1"/>
        <property name="dedupInd" val="true"/>
    </properties>
    <nodeType>100</nodeType>
    <point x="280" y="432"/>
    <selectedTabIndex>0</selectedTabIndex>
    <ZIndex>43</ZIndex>
</node>
<node isCollapsed="true" isSelectable="false">
    <displayOrder>8</displayOrder>
    <name>F4 - S1b - OptOut - Rem</name>
    <nodeId>1000h6c13hh8 1000h6c13hp7</nodeId>
    <properties>
        <property name="objectLocalInd" val="true"/>
        <property name="deduplicationOrder" val="8"/>
        <property name="objectStatus" val="1"/>
        <property name="dedupInd" val="true"/>
    </properties>
    <nodeType>100</nodeType>
    <point x="280" y="499"/>
    <selectedTabIndex>0</selectedTabIndex>
    <ZIndex>47</ZIndex>
</node>
<node isCollapsed="true" isSelectable="false">
    <displayOrder>9</displayOrder>
    <name>F4 - Winback - OptIn</name>
    <nodeId>1000h6c13hh8 1000h6c13hph</nodeId>
    <properties>
        <property name="objectLocalInd" val="true"/>
        <property name="deduplicationOrder" val="9"/>
        <property name="objectStatus" val="1"/>
        <property name="dedupInd" val="true"/>
    </properties>
    <nodeType>100</nodeType>
    <point x="280" y="566"/>
    <selectedTabIndex>0</selectedTabIndex>
    <ZIndex>52</ZIndex>
</node>
<node isCollapsed="true" isSelectable="false">
    <displayOrder>10</displayOrder>
    <name>F4 - Winback - OptOut</name>
    <nodeId>1000h6c13hh8 1000h6c13pvn</nodeId>
    <properties>
        <property name="objectLocalInd" val="true"/>
        <property name="deduplicationOrder" val="10"/>
        <property name="objectStatus" val="1"/>
        <property name="dedupInd" val="true"/>
    </properties>
    <nodeType>100</nodeType>
    <point x="280" y="633"/>
    <selectedTabIndex>0</selectedTabIndex>
    <ZIndex>55</ZIndex>
</node>
<name>Test_M&amp;M_Live04</name>
<nodeId>1000h6c13hh8</nodeId>
<properties>
    <property name="uniquenessLevel" val="8"/>
</properties>
<nodeType>116</nodeType>
<point x="5" y="5"/>
<selectedTabIndex>0</selectedTabIndex>
</node>
<stale>false</stale>
</whiteboard>
', '1000h6c14b2m', 0) "}

ZillaG · February 28, 2017, 3:37pm

I ran Logstash in debug mode, and see this. How can I further debug this error? I cropped the error message.

{:timestamp=>"2017-02-28T15:19:00.086000+0000", :message=>"JSON parse failure. Falling back to plain-text", :error=>#<LogStash::Json::ParserError: Unexpected end-of-input in VALUE_STRING
 at [Source: [B@5318943e; line: 1, column: 16193]>, :data=>"{ \"type\":\"trm-error\", \"host\":\"ip-10-53-xxx-xxx\", \"timestamp\":\"2017-02-28T15:19:00.076224+00:00\", \"@version\":\"1\", \"customer\":\"airmiles\", \"role\":\"app1\", \"sourcefile\":\"

system · March 28, 2017, 3:37pm

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.

Topic		Replies	Views
Error parsing json using jdbc input Logstash	2	2106	July 6, 2017
Json filer error Logstash	6	373	May 18, 2018
Keep getting _jsonparsefailures Logstash	3	22	October 11, 2024
JSON parse error, original data now in message field Logstash	8	3483	September 1, 2020
Logstash flags XML header in log message as _jsonparsefailure? Logstash	7	1084	April 6, 2017

Help with _jsonparsefailure?

Related topics