Graylog2 / Graylog2/graylog2-server

Nested Objects from Apple new OSX Log formats - not supported

Open
#6,220 0 comments 0 reactions 0 assignees View on GitHub
feature triaged
Dominant language
Java
Stars
8.1k
Forks
1.1k
Avg merge
1d 20h
Merged PRs (30d)
217

Description

Apple has a BETA version of their new OSX Logging technology and documentation. https://developer.apple.com/documentation/logging

There are 4 different modes that can be output: Default ( Apple standard ), Compact, Syslog, and JSON.

The ideal input logging format for Graylog ( obviously ) would be JSON because the close relationship between JSON and GELF.

## Expected Behavior

Need a JSON parser that supports nested objects when accepting log sources. Ideally, these JSON events would be mapped to their respective, additional or custom fields:

processImagePath >> _processImagePath
senderImagePath >> _senderImagePath
timestamp >> _timestamp
machTimestamp >> _machTimestamp
messageType >> _messageType
processImageUUID >> _processImageUUID
processID >> _processID
senderProgramCounter >> _senderProgramCounter
parentActivityIdentifier >> _parentActivityIdentifier
timezoneName >> _timezoneName
traceID >> _traceID
eventMessage >> _eventMessage
eventType >> _eventType
source >> _source
formatString >> _formatString
activityIdentifier >> _activityIdentifier
subsystem >> _subsystem
category >> _category
threadID >> _threadID
senderImageUUID >> _senderImageUUID
backtrace >> _backtrace
frames >> _frames *** nlvl1
imageOffset >> _imageOffset *** nlvl2
imageUUID >> _imageUUID *** nlvl2
(close nest level 2 )
(close nest level 1 )
(close)

In the example below, my MacBook Pro is streaming ASL logs directly into my terminal ( unfiltered ).

[{
"traceID" : 1663375000482349314,
"eventType" : "activityCreateEvent",
"formatString" : "",
"activityIdentifier" : 275779,
"subsystem" : "",
"category" : "",
"threadID" : 551223,
"senderImageUUID" : "DF7677A7-9765-3B6A-9D1C-3589145E4B65",
"backtrace" : {
"frames" : [
{
"imageOffset" : 973565,
"imageUUID" : "DF7677A7-9765-3B6A-9D1C-3589145E4B65"
}
]
},
"processImagePath" : "\/Library\/Bitdefender\/AVP\/common.bundle\/BDCoreIssues",
"senderImagePath" : "\/System\/Library\/Frameworks\/Security.framework\/Versions\/A\/Security",
"timestamp" : "2019-07-30 12:34:39.549928-0500",
"creatorActivityID" : 0,
"machTimestamp" : 61099719001106,
"eventMessage" : "SecTrustEvaluateIfNecessary",
"processImageUUID" : "159963EE-7225-3064-94C7-5E895D37EEF0",
"processID" : 219,
"senderProgramCounter" : 973565,
"parentActivityIdentifier" : 0,
"timezoneName" : ""
},{
"traceID" : 1449156359159812,
"eventMessage" : "cert[2]: AnchorTrusted =(leaf)[force]> 0",
"eventType" : "logEvent",
"source" : null,
"formatString" : "cert[%d]: %@ =(%s)[%s]> %@",
"activityIdentifier" : 275779,
"subsystem" : "com.apple.securityd",
"category" : "policy",
"threadID" : 551226,
"senderImageUUID" : "24A596F0-327B-306F-8A8B-7C89E5F52DB9",
"backtrace" : {
"frames" : [
{
"imageOffset" : 124126,
"imageUUID" : "24A596F0-327B-306F-8A8B-7C89E5F52DB9"
}
]
},
"processImagePath" : "\/usr\/libexec\/trustd",
"senderImagePath" : "\/usr\/libexec\/trustd",
"timestamp" : "2019-07-30 12:34:39.551409-0500",
"machTimestamp" : 61099720475667,
"messageType" : "Default",
"processImageUUID" : "24A596F0-327B-306F-8A8B-7C89E5F52DB9",
"processID" : 167,
"senderProgramCounter" : 124126,
"parentActivityIdentifier" : 0,
"timezoneName" : ""
},{
"traceID" : 787144355759783940,
"eventMessage" : "pid(6959)\/euid(501) is calling TIS\/TSM in non-main thread environment, ERROR : This is NOT allowed. Please call TIS\/TSM in main thread!!!",
"eventType" : "logEvent",
"source" : null,
"formatString" : "pid(%d)\/euid(%d) is calling TIS\/TSM in non-main thread environment, ERROR : This is NOT allowed. Please call TIS\/TSM in main thread!!!",
"activityIdentifier" : 0,
"subsystem" : "",
"category" : "",
"threadID" : 216425,
"senderImageUUID" : "13F69D4C-D19F-3E09-9231-1978D783A556",
"backtrace" : {
"frames" : [
{
"imageOffset" : 56005,
"imageUUID" : "13F69D4C-D19F-3E09-9231-1978D783A556"
}
]
},
"processImagePath" : "\/Applications\/Synergy.app\/Contents\/MacOS\/synergyc",
"senderImagePath" : "\/System\/Library\/Frameworks\/Carbon.framework\/Versions\/A\/Frameworks\/HIToolbox.framework\/Versions\/A\/HIToolbox",
"timestamp" : "2019-07-30 12:34:40.310194-0500",
"machTimestamp" : 61100479274495,
"messageType" : "Default",
"processImageUUID" : "E1DC97D7-97D9-3C1F-99BD-499149E49627",
"processID" : 6959,
"senderProgramCounter" : 56005,
"parentActivityIdentifier" : 0,
"timezoneName" : ""
},{
"traceID" : 787144355759783940,
"eventMessage" : "pid(6959)\/euid(501) is calling TIS\/TSM in non-main thread environment, ERROR : This is NOT allowed. Please call TIS\/TSM in main thread!!!",
"eventType" : "logEvent",
"source" : null,
"formatString" : "pid(%d)\/euid(%d) is calling TIS\/TSM in non-main thread environment, ERROR : This is NOT allowed. Please call TIS\/TSM in main thread!!!",
"activityIdentifier" : 0,
"subsystem" : "",
"category" : "",
"threadID" : 216425,
"senderImageUUID" : "13F69D4C-D19F-3E09-9231-1978D783A556",
"backtrace" : {
"frames" : [
{
"imageOffset" : 56005,
"imageUUID" : "13F69D4C-D19F-3E09-9231-1978D783A556"
}
]
}

## Current Behavior

Grayog store the nested array JSON object in a separate field (with parent name), without expansion.

The /var/log/graylog-server/server.log is reporting these errors:

`2019-07-30T11:58:34.182-05:00 ERROR [DecodingProcessor] Unable to decode raw message RawMessage{id=44240245-b2eb-11e9-af4b-000c29d6f75a, journalOffset=15847326, codec=gelf, payloadSize=67, timestamp=2019-07-30T16:58:34.178Z, remoteAddress=/192.168.50.89:53447} on input <5d33a8c539cb0a09467e1467>.
2019-07-30T11:58:34.182-05:00 ERROR [DecodingProcessor] Error processing message RawMessage{id=44240242-b2eb-11e9-af4b-000c29d6f75a, journalOffset=15847323, codec=gelf, payloadSize=96, timestamp=2019-07-30T16:58:34.178Z, remoteAddress=/192.168.50.89:53447}
com.fasterxml.jackson.core.JsonParseException: Unexpected character ('<' (code 60)): expected a valid value (number, String, array, object, 'true', 'false' or 'null')
at [Source: <5>Jul 30 11:58:34 UltimaWeapon: "processImageUUID" : "B8F4AC31-17CD-3FF0-A2B6-1C5C17631E79",^@; line: 1, column: 2]
at com.fasterxml.jackson.core.JsonParser._constructError(JsonParser.java:1702) ~[graylog.jar:?]
at com.fasterxml.jackson.core.base.ParserMinimalBase._reportError(ParserMinimalBase.java:558) ~[graylog.jar:?]
at com.fasterxml.jackson.core.base.ParserMinimalBase._reportUnexpectedChar(ParserMinimalBase.java:456) ~[graylog.jar:?]
at com.fasterxml.jackson.core.json.ReaderBasedJsonParser._handleOddValue(ReaderBasedJsonParser.java:1906) ~[graylog.jar:?]
at com.fasterxml.jackson.core.json.ReaderBasedJsonParser.nextToken(ReaderBasedJsonParser.java:749) ~[graylog.jar:?]
at com.fasterxml.jackson.databind.ObjectMapper._initForReading(ObjectMapper.java:3850) ~[graylog.jar:?]
at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:3799) ~[graylog.jar:?]
at com.fasterxml.jackson.databind.ObjectMapper.readTree(ObjectMapper.java:2397) ~[graylog.jar:?]
at org.graylog2.inputs.codecs.GelfCodec.decode(GelfCodec.java:127) ~[graylog.jar:?]
at org.graylog2.shared.buffers.processors.DecodingProcessor.processMessage(DecodingProcessor.java:150) ~[graylog.jar:?]
at org.graylog2.shared.buffers.processors.DecodingProcessor.onEvent(DecodingProcessor.java:91) [graylog.jar:?]
at org.graylog2.shared.buffers.processors.ProcessBufferProcessor.onEvent(ProcessBufferProcessor.java:86) [graylog.jar:?]
at org.graylog2.shared.buffers.processors.ProcessBufferProcessor.onEvent(ProcessBufferProcessor.java:45) [graylog.jar:?]
at com.lmax.disruptor.WorkProcessor.run(WorkProcessor.java:143) [graylog.jar:?]
at com.codahale.metrics.InstrumentedThreadFactory$InstrumentedRunnable.run(InstrumentedThreadFactory.java:66) [graylog.jar:?]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_212]
2019-07-30T11:58:34.182-05:00 ERROR [DecodingProcessor] Unable to decode raw message RawMessage{id=44240244-b2eb-11e9-af4b-000c29d6f75a, journalOffset=15847325, codec=gelf, payloadSize=69, timestamp=2019-07-30T16:58:34.178Z, remoteAddress=/192.168.50.89:53447} on input <5d33a8c539cb0a09467e1467>.
2019-07-30T11:58:34.182-05:00 ERROR [GelfCodec] Could not parse JSON, first 400 characters: <5>Jul 30 11:58:34 UltimaWeapon: "timezoneName" : ""^@
com.fasterxml.jackson.core.JsonParseException: Unexpected character ('<' (code 60)): expected a valid value (number, String, array, object, 'true', 'false' or 'null')
at [Source: <5>Jul 30 11:58:34 UltimaWeapon: "timezoneName" : ""^@; line: 1, column: 2]
at com.fasterxml.jackson.core.JsonParser._constructError(JsonParser.java:1702) ~[graylog.jar:?]
at com.fasterxml.jackson.core.base.ParserMinimalBase._reportError(ParserMinimalBase.java:558) ~[graylog.jar:?]
at com.fasterxml.jackson.core.base.ParserMinimalBase._reportUnexpectedChar(ParserMinimalBase.java:456) ~[graylog.jar:?]
at com.fasterxml.jackson.core.json.ReaderBasedJsonParser._handleOddValue(ReaderBasedJsonParser.java:1906) ~[graylog.jar:?]
at com.fasterxml.jackson.core.json.ReaderBasedJsonParser.nextToken(ReaderBasedJsonParser.java:749) ~[graylog.jar:?]
at com.fasterxml.jackson.databind.ObjectMapper._initForReading(ObjectMapper.java:3850) ~[graylog.jar:?]
at com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:3799) ~[graylog.jar:?]
at com.fasterxml.jackson.databind.ObjectMapper.readTree(ObjectMapper.java:2397) ~[graylog.jar:?]
at org.graylog2.inputs.codecs.GelfCodec.decode(GelfCodec.java:127) [graylog.jar:?]
at org.graylog2.shared.buffers.processors.DecodingProcessor.processMessage(DecodingProcessor.java:150) [graylog.jar:?]
at org.graylog2.shared.buffers.processors.DecodingProcessor.onEvent(DecodingProcessor.java:91) [graylog.jar:?]
at org.graylog2.shared.buffers.processors.ProcessBufferProcessor.onEvent(ProcessBufferProcessor.java:86) [graylog.jar:?]
at org.graylog2.shared.buffers.processors.ProcessBufferProcessor.onEvent(ProcessBufferProcessor.java:45) [graylog.jar:?]
at com.lmax.disruptor.WorkProcessor.run(WorkProcessor.java:143) [graylog.jar:?]
at com.codahale.metrics.InstrumentedThreadFactory$InstrumentedRunnable.run(InstrumentedThreadFactory.java:66) [graylog.jar:?]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_212]`

### JSON Format



[{
"traceID" : 1412296916598788,
"eventMessage" : "059566.841727 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::forcePowerGated: kPowerStateSuspended timeout 1000ms",
"eventType" : "logEvent",
"source" : null,
"formatString" : "%06lu.%06u %s@%s: %s::%s: %s timeout %dms\n",
"activityIdentifier" : 0,
"subsystem" : "",
"category" : "",
"threadID" : 535269,

### Syslog format

Timestamp (process)[PID]
2019-07-30 12:09:06.776462-0500 localhost kernel[0]: (IOUSBHostFamily) 059566.841727 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::forcePowerGated: kPowerStateSuspended timeout 1000ms
2019-07-30 12:09:06.776597-0500 localhost kernel[0]: (IOUSBHostFamily) 059566.841875 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::powerStateWillChangeToGated: kPowerStateSuspended
2019-07-30 12:09:06.776714-0500 localhost kernel[0]: (IOUSBHostFamily) 059566.841954 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::setPowerStateGated: kPowerStateOn -> kPowerStateSuspended
2019-07-30 12:09:06.776725-0500 localhost kernel[0]: (IOUSBHostFamily) 059566.842009 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::setPowerStateGated: suspending pipes
2019-07-30 12:09:06.776842-0500 localhost kernel[0]: (IOUSBHostFamily) 059566.842121 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::forcePowerGated: allowing power level to float
2019-07-30 12:09:06.776858-0500 localhost kernel[0]: (IOUSBHostFamily) 059566.842141 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::forcePowerGated: kPowerStateSuspended completed with 0x00000000 after 0ms
2019-07-30 12:09:08.459923-0500 localhost UserEventAgent[4320]: (CoreLocation) Created Activity ID: 0x421b7, Description: CL: CLLocationManager
2019-07-30 12:09:08.459944-0500 localhost UserEventAgent[4320]: (CoreLocation) [com.apple.locationd.Core:Client] {"msg":"CLLocationManager", "event":"activity", "_cmd":"appsUsingLocationWithInfo", "self":"0x7fff9f350ae8"}
2019-07-30 12:09:08.459946-0500 localhost UserEventAgent[4320]: (CoreLocation) Created Activity ID: 0x421b8, Parent ID: 0x80000000000421b7, Description: CL: CLCopyAppsUsingLocation

### Compact format

Timestamp Ty Process[PID:TID]
2019-07-30 12:09:06.776 Df kernel[0:82ae5] (IOUSBHostFamily) 059566.841727 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::forcePowerGated: kPowerStateSuspended timeout 1000ms
2019-07-30 12:09:06.776 Df kernel[0:708] (IOUSBHostFamily) 059566.841875 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::powerStateWillChangeToGated: kPowerStateSuspended
2019-07-30 12:09:06.776 Df kernel[0:708] (IOUSBHostFamily) 059566.841954 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::setPowerStateGated: kPowerStateOn -> kPowerStateSuspended
2019-07-30 12:09:06.776 Df kernel[0:708] (IOUSBHostFamily) 059566.842009 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::setPowerStateGated: suspending pipes
2019-07-30 12:09:06.776 Df kernel[0:82ae5] (IOUSBHostFamily) 059566.842121 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::forcePowerGated: allowing power level to float
2019-07-30 12:09:06.776 Df kernel[0:82ae5] (IOUSBHostFamily) 059566.842141 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::forcePowerGated: kPowerStateSuspended completed with 0x00000000 after 0ms
2019-07-30 12:09:08.459 A UserEventAgent[4320:829e3] (CoreLocation) CL: CLLocationManager
2019-07-30 12:09:08.459 Df UserEventAgent[4320:829e3] [com.apple.locationd.Core:Client] {"msg":"CLLocationManager", "event":"activity", "_cmd":"appsUsingLocationWithInfo", "self":"0x7fff9f350ae8"}
2019-07-30 12:09:08.459 A UserEventAgent[4320:829e3] (CoreLocation) CL: CLCopyAppsUsingLocation

### Default format

Timestamp Thread Type Activity PID TTL
2019-07-30 12:09:06.776462-0500 0x82ae5 Default 0x0 0 0 kernel: (IOUSBHostFamily) 059566.841727 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::forcePowerGated: kPowerStateSuspended timeout 1000ms
2019-07-30 12:09:06.776597-0500 0x708 Default 0x0 0 0 kernel: (IOUSBHostFamily) 059566.841875 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::powerStateWillChangeToGated: kPowerStateSuspended
2019-07-30 12:09:06.776714-0500 0x708 Default 0x0 0 0 kernel: (IOUSBHostFamily) 059566.841954 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::setPowerStateGated: kPowerStateOn -> kPowerStateSuspended
2019-07-30 12:09:06.776725-0500 0x708 Default 0x0 0 0 kernel: (IOUSBHostFamily) 059566.842009 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::setPowerStateGated: suspending pipes
2019-07-30 12:09:06.776842-0500 0x82ae5 Default 0x0 0 0 kernel: (IOUSBHostFamily) 059566.842121 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::forcePowerGated: allowing power level to float
2019-07-30 12:09:06.776858-0500 0x82ae5 Default 0x0 0 0 kernel: (IOUSBHostFamily) 059566.842141 Bluetooth USB Host Controller@14300000: IOUSBHostDevice::forcePowerGated: kPowerStateSuspended completed with 0x00000000 after 0ms
2019-07-30 12:09:08.459923-0500 0x829e3 Activity 0x421b7 4320 0 UserEventAgent: (CoreLocation) CL: CLLocationManager
2019-07-30 12:09:08.459944-0500 0x829e3 Default 0x421b7 4320 0 UserEventAgent: (CoreLocation) [com.apple.locationd.Core:Client] {"msg":"CLLocationManager", "event":"activity", "_cmd":"appsUsingLocationWithInfo", "self":"0x7fff9f350ae8"}
2019-07-30 12:09:08.459946-0500 0x829e3 Activity 0x421b8 4320 0 UserEventAgent: (CoreLocation) CL: CLCopyAppsUsingLocation

## Possible Solution

Other formats are available ( Syslog, Compact, Default ) - I can move forward with any suggestions for this.

## Steps to Reproduce (for bugs)

1. See /var/log/graylog-server/server.log for these details ( all versions of Graylog )
2.
`
Timestamp | Index | Letter ID | Error message
-- | -- | -- | --
12 hours ago | graylog_0 | e7056730-b2b0-11e9-af4b-000c29d6f75a | {"type":"mapper_parsing_exception","reason":"failed to parse","caused_by":{"type":"illegal_argument_exception","reason":"field name cannot be an empty string"}}
12 hours ago | graylog_0 | e520a1a0-b2b0-11e9-af4b-000c29d6f75a | {"type":"mapper_parsing_exception","reason":"failed to parse","caused_by":{"type":"illegal_argument_exception","reason":"field name cannot be an empty string"}}
12 hours ago | graylog_0 | e43c8330-b2b0-11e9-af4b-000c29d6f75a | {"type":"mapper_parsing_exception","reason":"failed to parse","caused_by":{"type":"illegal_argument_exception","reason":"field name cannot be an empty string"}}
12 hours ago | graylog_0 | dfdde402-b2b0-11e9-af4b-000c29d6f75a | {"type":"mapper_parsing_exception","reason":"failed to parse","caused_by":{"type":"illegal_argument_exception","reason":"field name cannot be an empty string"}}
12 hours ago | graylog_0 | ddfca0e1-b2b0-11e9-af4b-000c29d6f75a | {"type":"mapper_parsing_exception","reason":"failed to parse","caused_by":{"type":"illegal_argument_exception","reason":"field name cannot be an empty string"}}
12 hours ago | graylog_0 | dd157530-b2b0-11e9-af4b-000c29d6f75a | {"type":"mapper_parsing_exception","reason":"failed to parse","caused_by":{"type":"illegal_argument_exception","reason":"field name cannot be an empty string"}}
12 hours ago | graylog_0 | cdfc4101-b2b0-11e9-af4b-000c29d6f75a | {"type":"mapper_parsing_exception","reason":"failed to parse","caused_by":{"type":"illegal_argument_exception","reason":"field name cannot be an empty string"}}
12 hours ago | graylog_0 | cc1865d0-b2b0-11e9-af4b-000c29d6f75a | {"type":"mapper_parsing_exception","reason":"failed to parse","caused_by":{"type":"illegal_argument_exception","reason":"field name cannot be an empty string"}}
12 hours ago | graylog_0 | cb3335f3-b2b0-11e9-af4b-000c29d6f75a | {"type":"mapper_parsing_exception","reason":"failed to parse","caused_by":{"type":"illegal_argument_exception","reason":"field name cannot be an empty string"}}
`

3.
4.

## Context

Darwin is a very popular platform, our community and security user base would greatly benefit from this integration or plugin.

## Your Environment

* Graylog Version: graylog-server.noarch 3.1.0-3.beta.3
* Elasticsearch Version: elasticsearch-oss.noarch 6.8.1-1
* MongoDB Version: mongodb-org.x86_64 4.0.10-1.el7
* Operating System:
`hostnamectl
Static hostname: atx-logger
Icon name: computer-vm
Chassis: vm
Machine ID: 58bf01badf1d4f2ab71013026b535dfa
Boot ID: 775c31d4816948fea62128d01a8e77ac
Virtualization: vmware
Operating System: CentOS Linux 7 (Core)
CPE OS Name: cpe:/o:centos:centos:7
Kernel: Linux 3.10.0-957.21.3.el7.x86_64
Architecture: x86-64
`
* Browser version: Version 76.0.3809.87 (Official Build) beta (64-bit)

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.