Java exception full trace

nsivabalan · September 11, 2017, 11:49am

Hi,

I would like see full log trace of the exception in the kibana. Kindly some one let me know the multile pattern for the below log format.

FYR

INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 | 12:00:45 AM |  INFO | Unable to execute HTTP request: sslimages.s3-ap-southeast-1.amazonaws.com:443 failed to re
spond | TaskExecutor-master-34805-ProcessTask [9797909119926] | AmazonHttpClient
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 | org.apache.http.NoHttpResponseException: sslimages.s3-ap-southeast-1.amazonaws.com:443 failed to respond
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:143)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.
java:283)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:
251)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionIm
pl.java:197)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at com.amazonaws.http.protocol.SdkHttpRequestExecutor.doReceiveResponse(SdkHttpRequestExecutor.java:66)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at com.amazonaws.http.AmazonHttpClient.executeOneRequest(AmazonHttpClient.java:685)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at com.amazonaws.http.AmazonHttpClient.executeHelper(AmazonHttpClient.java:460)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:295)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at com.amazonaws.services.s3.AmazonS3Client.invoke(AmazonS3Client.java:3736)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at com.amazonaws.services.s3.AmazonS3Client.deleteObject(AmazonS3Client.java:1796)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at com.amazonaws.services.s3.AmazonS3Client.deleteObject(AmazonS3Client.java:1781)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at de.hybris.platform.amazon.media.storage.S3MediaStorageStrategy.delete(S3MediaStorageStrategy.java:220
)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at de.hybris.platform.jalo.media.MediaManager.deleteMedia(MediaManager.java:298)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.jalo.media.MediaManager$2.execute(MediaManager.java:338)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.tx.Transaction.executeTxAwareInternal(Transaction.java:1687)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.tx.Transaction.executeAllDelayedTransactionExecutions(Transaction.java:1699)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.tx.Transaction.notifyCommit(Transaction.java:986)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.tx.Transaction.clearTxBoundConnectionAndNotify(Transaction.java:909)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.tx.Transaction.commitConnectionAndClearAndUnsetAsCurrent(Transaction.java:717)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.tx.Transaction.commit(Transaction.java:693)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.spring.HybrisTransactionManager.doCommit(HybrisTransactionManager.java:54)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:757)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:726)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:150)
INFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.processengine.process.ProcessengineTaskRunner.lambda$7(ProcessengineTaskRunner.jav:

Thanks in advance,
Siva

andrewkroh · September 11, 2017, 12:50pm

I haven't seen the format of other log lines, but if they have the time (like "12:00:45 AM" in the first line) then you can base the pattern on the existence of that.

filebeat.prospectors:
- input_type: log
  paths:
    - 'input.log'
  multiline.pattern: '^.*\|.*\|.*\|.*\| \d{2}:\d{2}:\d{2} (?:AM|PM)'
  multiline.negate: true
  multiline.match: after

Tester: https://play.golang.org/p/i4fd-DTBGO

nsivabalan · September 11, 2017, 6:26pm

Hi Andrew,

I have added the line in filebeat config. But still I'm not getting the full trace of the exception.

Filebeat config:

filebeat:
  prospectors:
    -
      input_type: log
      paths:
        - /home/ubuntu/SSL/hybris/log/tomcat/console-*.log
      fields:
         type: hybris_console_log
         environment: Production
         layer: App
         servername: ss-new-prod-customerfacing2
      document_type: hybris_console_log
      multiline.pattern: '^.*\|.*\|.*\|.*\| \d{2}:\d{2}:\d{2} (?:AM|PM)'
      multiline.negate: true
      multiline.match: after

    -
      input_type: log
      paths:
        - /home/ubuntu/SSL/hybris/log/tomcat/access.*.log
      fields:
         type: hybris_access_log
         environment: Production
         layer: App
         servername: ss-new-prod-customerfacing2
      document_type: hybris_access_log
      multiline.pattern: '^.*\|.*\|.*\|.*\| \d{2}:\d{2}:\d{2} (?:AM|PM)'
      multiline.negate: true
      multiline.match: after

output:
  logstash:
    hosts: ["10.7.3.210:5044"]
    bulk_max_size: 2048
shipper:
logging:
  to_syslog: false
  to_files: true
  files:
    path: /var/log/filebeat
    name: filebeat.log
    keepfiles: 7
    rotateeverybytes: 10485760 # = 10MB
  level: info

Exception in the log;

Screen Shot 2017-09-11 at 11.52.48 PM

Kibana View:

Screen Shot 2017-09-11 at 11.52.30 PM

Thanks
Siva

andrewkroh · September 11, 2017, 6:36pm

What version of Filebeat are you running?

Are you doing any sort of processing with Logstash?

I tested the log sample you provided in the first post against my config example and it worked for me. Filebeat sent a single event.

{
  "@timestamp": "2017-09-11T12:48:06.597Z",
  "beat": {
    "hostname": "macbook",
    "name": "macbook",
    "version": "5.4.0"
  },
  "input_type": "log",
  "message": "INFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 | 12:00:45 AM |  INFO | Unable to execute HTTP request: sslimages.s3-ap-southeast-1.amazonaws.com:443 failed to re\nspond | TaskExecutor-master-34805-ProcessTask [9797909119926] | AmazonHttpClient\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 | org.apache.http.NoHttpResponseException: sslimages.s3-ap-southeast-1.amazonaws.com:443 failed to respond\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:143)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.\njava:283)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:\n251)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionIm\npl.java:197)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at com.amazonaws.http.protocol.SdkHttpRequestExecutor.doReceiveResponse(SdkHttpRequestExecutor.java:66)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at com.amazonaws.http.AmazonHttpClient.executeOneRequest(AmazonHttpClient.java:685)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at com.amazonaws.http.AmazonHttpClient.executeHelper(AmazonHttpClient.java:460)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:295)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at com.amazonaws.services.s3.AmazonS3Client.invoke(AmazonS3Client.java:3736)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at com.amazonaws.services.s3.AmazonS3Client.deleteObject(AmazonS3Client.java:1796)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at com.amazonaws.services.s3.AmazonS3Client.deleteObject(AmazonS3Client.java:1781)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at de.hybris.platform.amazon.media.storage.S3MediaStorageStrategy.delete(S3MediaStorageStrategy.java:220\n)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.665 |         at de.hybris.platform.jalo.media.MediaManager.deleteMedia(MediaManager.java:298)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.jalo.media.MediaManager$2.execute(MediaManager.java:338)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.tx.Transaction.executeTxAwareInternal(Transaction.java:1687)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.tx.Transaction.executeAllDelayedTransactionExecutions(Transaction.java:1699)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.tx.Transaction.notifyCommit(Transaction.java:986)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.tx.Transaction.clearTxBoundConnectionAndNotify(Transaction.java:909)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.tx.Transaction.commitConnectionAndClearAndUnsetAsCurrent(Transaction.java:717)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.tx.Transaction.commit(Transaction.java:693)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.spring.HybrisTransactionManager.doCommit(HybrisTransactionManager.java:54)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:757)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:726)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:150)\nINFO   | jvm 1    | main    | 2017/09/11 00:00:45.666 |         at de.hybris.platform.processengine.process.ProcessengineTaskRunner.lambda$7(ProcessengineTaskRunner.jav:",
  "offset": 5793,
  "source": "/test/multiline/input.log",
  "type": "log"
}

nsivabalan · September 12, 2017, 6:15am

I'm using filebeat version 1.3.1 (amd64) and I'm not doing any processing on logstash.

Below logstash config is only for syslog but syslog we not required.

filter {
if [type] == "syslog" {
grok {
match => { "message" => "%{SYSLOGTIMESTAMP:syslog_timestamp} %{SYSLOGHOST:syslog_hostname} %{DATA:syslog_program}(?:[%{POSINT:syslog_pid}])?: %{GREEDYDATA:syslog_message}" }
add_field => [ "received_at", "%{@timestamp}" ]
add_field => [ "received_from", "%{host}" ]
}
syslog_pri { }
date {
match => [ "syslog_timestamp", "MMM d HH:mm:ss", "MMM dd HH:mm:ss" ]
}
}
}

andrewkroh · September 12, 2017, 11:30am

The config example I listed is for the current version (v5). For Filebeat 1.3 I think you need to change the multiline config to not use the dotted form for each of the config options. See the example in the 1.3 docs https://www.elastic.co/guide/en/beats/filebeat/1.3/configuration-filebeat-options.html#multiline.

And the regex support in 1.3 is limited to POSIX patterns, so you will need to adjust the example I gave since \d should be [[:digit:]]. See https://www.elastic.co/guide/en/beats/filebeat/1.3/regexp-support.html

Consider upgrading to the latest version.

nsivabalan · September 12, 2017, 4:35pm

After upgrading it's worked Andrew. Thanks.

system · October 10, 2017, 4:35pm

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