github.com/honeycombio/honeytail@v1.9.0/parsers/mongodb/mongodb_test.go (about) 1 package mongodb 2 3 import ( 4 "testing" 5 "time" 6 7 "github.com/stretchr/testify/assert" 8 9 "github.com/honeycombio/honeytail/event" 10 "github.com/honeycombio/honeytail/httime" 11 "github.com/honeycombio/honeytail/httime/httimetest" 12 ) 13 14 const ( 15 CONTROL = "2010-01-02T12:34:56.000Z I CONTROL [conn123456789] git version fooooooo" 16 UBUNTU_3_2_9_INSERT = `2016-09-14T23:39:23.450+0000 I COMMAND [conn68] command protecteddb.comedy command: insert { insert: "comedy", documents: [ { _id: ObjectId('57d9dfab9fc9998ce4e0c072'), name: "Bill & Ted's Excellent Adventure", year: 1989.0, extrakey: "benisawesome" } ], ordered: true } ninserted:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:25 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } protocol:op_command 0ms` 17 UBUNTU_3_2_9_FIND = `2016-09-15T00:01:55.387+0000 I COMMAND [conn93] command protecteddb.comedy command: find { find: "comedy", filter: { $where: "this.year > 2000" } } planSummary: COLLSCAN keysExamined:0 docsExamined:5 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:2 reslen:245 locks:{ Global: { acquireCount: { r: 7, w: 1 } }, Database: { acquireCount: { r: 3, w: 1 } }, Collection: { acquireCount: { r: 3, w: 1 } }, Metadata: { acquireCount: { W: 1 } } } protocol:op_command 29ms` 18 UBUNTU_3_2_9_UPDATE = `2016-09-14T23:36:36.793+0000 I WRITE [conn61] update protecteddb.comedy query: { name: "Hulk" } update: { $unset: { cast: 1.0 } } keysExamined:0 docsExamined:4 nMatched:0 nModified:0 keyUpdates:0 writeConflicts:0 numYields:0 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } 0ms` 19 UBUNTU_2_6_FIND = `2016-09-15T02:38:10.395-0400 [conn1579035] query starfruit_production.users query: { $query: { altemails: { $in: [ "REDACTED@domain.org" ] } }, $orderby: { _id: 1 } } planSummary: IXSCAN { _id: 1 } ntoskip:0 nscanned:67439 nscannedObjects:67439 keyUpdates:0 numYields:1 locks(micros) r:114782 nreturned:0 reslen:20 105ms` 20 UBUNTU_2_4_FIND = `Tue Sep 13 21:10:33.961 [TTLMonitor] query btest.system.indexes query: { expireAfterSeconds: { $exists: true } } ntoreturn:0 ntoskip:0 nscanned:1 keyUpdates:0 locks(micros) r:60 nreturned:0 reslen:20 0ms` 21 ATLAS_3_6_0_FIND = `2018-06-29T16:21:19.864+0000 I COMMAND [conn8080] command foo.abc appName: "MongoDB Shell" command: find { find: "foo.abc", filter: { a: 99.0 }, $clusterTime: { clusterTime: Timestamp(1530289263, 1), signature: { hash: BinData(0, D296E984640196C4D2977BECF468865948F7704C), keyId: 6571916458190700545 } }, $db: "foo" } planSummary: IXSCAN { a: 1 } keysExamined:2 docsExamined:2 cursorExhausted:1 numYields:0 nreturned:2 reslen:303 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_msg 0ms` 22 OSX_3_2_9_AGGREGATE = `2016-09-14T14:46:13.879-0700 I COMMAND [conn1] command testtest.zips command: aggregate { aggregate: "zips", pipeline: [ { $group: { _id: "$state", totalPop: { $sum: "$pop" } } }, { $match: { totalPop: { $gte: 10000000.0 } } } ], cursor: {} } keyUpdates:0 writeConflicts:0 numYields:229 reslen:342 locks:{ Global: { acquireCount: { r: 466 } }, Database: { acquireCount: { r: 233 } }, Collection: { acquireCount: { r: 233 } } } protocol:op_command 34ms` 23 HEARTBEAT = `Sun Sep 18 07:20:03.246 [conn123456789] command admin.$cmd command: replSetHeartbeat { replSetHeartbeat: "replica-set-here", from: "host:port" } ntoreturn:1 keyUpdates:0 numYields:0 reslen:100 0ms` 24 NESTED_QUOTES = `2016-09-20T14:55:06.189-0400 [conn2915444] update namespace.collection query: { _id: ObjectId('51abe5b6c') } update: { $set: { recent_data: [ { id: ObjectId('57e1860'), msg: "Nietzsche said "For what constitutes the tremendous historical uniqueness of that Persian is just the opposite of this."" } ] } } nscanned:1 nscannedObjects:1 nMatched:1 nModified:1 keyUpdates:0 numYields:0 locks(micros) w:393 0ms` 25 UBUNTU_3_0_KILLCURSORS = `2016-09-20T14:55:06.189-0400 I QUERY [conn924267662] killcursors keyUpdates:0 writeConflicts:0 numYields:0 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } user_key_comparison_count:0 block_cache_hit_count:0 block_read_count:0 block_read_byte:0 internal_key_skipped_count:0 internal_delete_skipped_count:0 get_from_memtable_count:0 seek_on_memtable_count:0 seek_child_seek_count:0 0ms` 26 T1_STRING = "2010-01-02T12:34:56.000Z" 27 MONGO_3_4_QUERY = `2016-10-20T22:27:54.580+0000 I COMMAND [Balancer] command config.locks command: findAndModify { findAndModify: "locks", query: { _id: "balancer", state: 0 }, update: { $set: { ts: ObjectId('580944e96a82726bb4a8427f'), state: 2, who: "ConfigServer:Balancer", process: "ConfigServer", when: new Date(1477002473519), why: "CSRS Balancer" } }, upsert: true, new: true, writeConcern: { w: "majority", wtimeout: 15000 } } planSummary: IXSCAN { _id: 1 } update: { $set: { ts: ObjectId('580944e96a82726bb4a8427f'), state: 2, who: "ConfigServer:Balancer", process: "ConfigServer", when: new Date(1477002473519), why: "CSRS Balancer" } } keysExamined:0 docsExamined:0 nMatched:0 nModified:0 upsert:1 keysInserted:3 numYields:0 reslen:338 locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 9385 } }, Collection: { acquireCount: { w: 1 } }, Metadata: { acquireCount: { w: 1 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 18 } }, oplog: { acquireCount: { w: 1 } } } protocol:op_query 1061ms` 28 MONGO_3_4_GETMORE = `2016-10-20T22:28:01.785+0000 I COMMAND [conn8] command TestDB.TestColl appName: "MongoDB Shell" command: getMore { getMore: 18862806827, collection: "TestColl" } originatingCommand: { find: "TestColl", projection: { _id: 0.0, Counter: 1.0 }, shardVersion: [ Timestamp 1000|0, ObjectId('580944efeaec999c2d8e0d5b') ] } planSummary: COLLSCAN cursorid:18862806827 keysExamined:0 docsExamined:59899 cursorExhausted:1 numYields:468 nreturned:59899 reslen:1726100 locks:{ Global: { acquireCount: { r: 938 } }, Database: { acquireCount: { r: 469 } }, Collection: { acquireCount: { r: 469 } } } protocol:op_command 120ms` 29 MONGO_3_4_INIT = `2016-10-20T21:13:03.294+0000 I CONTROL [initandlisten] options: { net: { port: 23511 }, nopreallocj: true, replication: { oplogSizeMB: 40, replSet: "test-configRS" }, setParameter: { enableTestCommands: "1", logComponentVerbosity: "{tracking:1}", numInitialSyncAttempts: "1", numInitialSyncConnectAttempts: "60", writePeriodicNoops: "false" }, sharding: { clusterRole: "configsvr" }, storage: { dbPath: "/data/db/job14/mongorunner/test-configRS-0", engine: "wiredTiger", journal: { enabled: true }, mmapv1: { preallocDataFiles: false, smallFiles: true }, wiredTiger: { engineConfig: { cacheSizeGB: 1.0 } } }}` 30 MONGO_3_4_INDEX = `2016-10-20T22:27:59.508+0000 I INDEX [conn5] build index on: TestDB.TestColl properties: { v: 2, key: { Counter: 1.0 }, name: "Counter_1", ns: "TestDB.TestColl" }` 31 MONGO_3_4_SHARDING = `2016-10-20T22:27:59.516+0000 I SHARDING [conn1] about to log metadata event into changelog: { _id: "ip-10-69-189-27-2016-10-20T22:27:59.516+0000-580944efeaec999c2d8e0d58", server: "ip-10-69-189-27", clientAddr: "127.0.0.1:35756", time: new Date(1477002479516), what: "shardCollection.start", ns: "TestDB.TestColl", details: { shardKey: { Counter: 1.0 }, collection: "TestDB.TestColl", primary: "shard0000:ip-10-69-189-27:23760", initShards: [], numChunks: 1 } }` 32 UPDATE_SIMPLE_COMMAND = `Tue Sep 13 21:10:33.961 I COMMAND [conn11896572] command data.$cmd command: update { update: "currentMood", updates: [ { q: { mood: "bright" }, u: { $set: { mood: "dark" } } } ], writeConcern: { getLastError: 1, w: 1 }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:95 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } user_key_comparison_count:466 block_cache_hit_count:10 block_read_count:0 block_read_byte:0 internal_key_skipped_count:17 internal_delete_skipped_count:0 get_from_memtable_count:0 seek_on_memtable_count:2 seek_child_seek_count:12 0ms` 33 UPDATE_COMMAND = `Tue Sep 13 21:10:33.961 I COMMAND [conn11896572] command data.$cmd command: update { update: "avengers", updates: [ { q: { hulkForm: "Bruce Banner" }, u: { $set: { hulkForm: "Big Green" }, $setOnInsert: { hulkForm: "Big Green" } }, upsert: true } ], writeConcern: { getLastError: 1, w: 1 }, ordered: true } keyUpdates:0 writeConflicts:0 numYields:0 reslen:95 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } user_key_comparison_count:466 block_cache_hit_count:10 block_read_count:0 block_read_byte:0 internal_key_skipped_count:17 internal_delete_skipped_count:0 get_from_memtable_count:0 seek_on_memtable_count:2 seek_child_seek_count:12 0ms` 34 DELETE_SIMPLE_COMMAND = `Tue Sep 13 21:10:33.961 I COMMAND [conn11974626] command appdata387.$cmd command: delete { delete: "currentMood", deletes: [ { q: { mood: "bright" } } ], writeConcern: { getLastError: 1, w: 1 } } keyUpdates:0 writeConflicts:0 numYields:0 reslen:80 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } user_key_comparison_count:392 block_cache_hit_count:10 block_read_count:0 block_read_byte:0 internal_key_skipped_count:0 internal_delete_skipped_count:0 get_from_memtable_count:0 seek_on_memtable_count:2 seek_child_seek_count:12 0ms` 35 DELETE_COMMAND = `Tue Sep 13 21:10:33.961 I COMMAND [conn11974626] command appdata387.$cmd command: delete { delete: "avengerMembers", deletes: [ { q: { hulkForm: "Big Green", issue: { $ne: 4 } }, limit: 1 } ], writeConcern: { getLastError: 1, w: 1 } } keyUpdates:0 writeConflicts:0 numYields:0 reslen:80 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { w: 1 } } } user_key_comparison_count:392 block_cache_hit_count:10 block_read_count:0 block_read_byte:0 internal_key_skipped_count:0 internal_delete_skipped_count:0 get_from_memtable_count:0 seek_on_memtable_count:2 seek_child_seek_count:12 0ms` 36 ) 37 38 var ( 39 T1 = time.Date(2010, time.January, 2, 12, 34, 56, 0, time.UTC) 40 UBUNTU_3_2_9_INSERT_TIME, _ = time.ParseInLocation(iso8601LocalTimeFormat, "2016-09-14T23:39:23.450+0000", time.UTC) 41 UBUNTU_3_2_9_FIND_TIME, _ = time.ParseInLocation(iso8601LocalTimeFormat, "2016-09-15T00:01:55.387+0000", time.UTC) 42 UBUNTU_3_2_9_UPDATE_TIME, _ = time.ParseInLocation(iso8601LocalTimeFormat, "2016-09-14T23:36:36.793+0000", time.UTC) 43 ATLAS_3_6_0_FIND_TIME, _ = time.ParseInLocation(iso8601LocalTimeFormat, "2018-06-29T16:21:19.864+0000", time.UTC) 44 HEARTBEAT_TIME, _ = time.ParseInLocation(ctimeTimeFormat, "Sun Sep 18 07:20:03.246", time.UTC) 45 UBUNTU_2_4_FIND_TIME, _ = time.ParseInLocation(ctimeTimeFormat, "Tue Sep 13 21:10:33.961", time.UTC) 46 UBUNTU_2_6_FIND_TIME, _ = time.ParseInLocation(iso8601LocalTimeFormat, "2016-09-15T02:38:10.395-0400", time.UTC) 47 OSX_3_2_9_AGGREGATE_TIME, _ = time.ParseInLocation(iso8601LocalTimeFormat, "2016-09-14T14:46:13.879-0700", time.UTC) 48 NESTED_QUOTES_TIME, _ = time.ParseInLocation(iso8601LocalTimeFormat, "2016-09-20T14:55:06.189-0400", time.UTC) 49 UBUNTU_3_0_KILLCURSORS_TIME, _ = time.ParseInLocation(iso8601LocalTimeFormat, "2016-09-20T14:55:06.189-0400", time.UTC) 50 MONGO_3_4_QUERY_TIME, _ = time.ParseInLocation(iso8601LocalTimeFormat, "2016-10-20T22:27:54.580+0000", time.UTC) 51 MONGO_3_4_GETMORE_TIME, _ = time.ParseInLocation(iso8601LocalTimeFormat, "2016-10-20T22:28:01.785+0000", time.UTC) 52 MONGO_3_4_INIT_TIME, _ = time.ParseInLocation(iso8601LocalTimeFormat, "2016-10-20T21:13:03.294+0000", time.UTC) 53 MONGO_3_4_INDEX_TIME, _ = time.ParseInLocation(iso8601LocalTimeFormat, "2016-10-20T22:27:59.508+0000", time.UTC) 54 MONGO_3_4_SHARDING_TIME, _ = time.ParseInLocation(iso8601LocalTimeFormat, "2016-10-20T22:27:59.516+0000", time.UTC) 55 UPDATE_COMMAND_TIME, _ = time.ParseInLocation(ctimeTimeFormat, "Tue Sep 13 21:10:33.961", time.UTC) 56 DELETE_COMMAND_TIME, _ = time.ParseInLocation(ctimeTimeFormat, "Tue Sep 13 21:10:33.961", time.UTC) 57 ) 58 59 func init() { 60 fakeNow, _ := time.Parse(iso8601UTCTimeFormat, "2010-10-02T12:34:56.000Z") 61 httime.DefaultNower = &httimetest.FakeNower{fakeNow} 62 } 63 64 type processed struct { 65 time time.Time 66 includeData map[string]interface{} 67 excludeKeys []string 68 } 69 70 func TestProcessLines(t *testing.T) { 71 locks_string1 := "locks:{ Global: { acquireCount: { r: 2, w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } }" 72 tlm := []struct { 73 line string 74 expected processed 75 }{ 76 { 77 line: CONTROL, 78 expected: processed{ 79 time: T1, 80 includeData: map[string]interface{}{ 81 "severity": "informational", 82 "component": "CONTROL", 83 "context": "conn123456789", 84 "message": "git version fooooooo", 85 }, 86 }, 87 }, 88 89 { 90 line: T1_STRING + " I QUERY [context12345] query database.collection:Stuff query: {} " + locks_string1 + " 0ms", 91 expected: processed{ 92 time: T1, 93 includeData: map[string]interface{}{ 94 "severity": "informational", 95 "component": "QUERY", 96 "context": "context12345", 97 "operation": "query", 98 "namespace": "database.collection:Stuff", 99 "database": "database", // decomposed from namespace 100 "collection": "collection:Stuff", // decomposed from namespace 101 "query": map[string]interface{}{}, 102 "normalized_query": "{ }", 103 "global_read_lock": float64(2), 104 "global_write_lock": float64(2), 105 "database_write_lock": float64(2), 106 "collection_write_lock": float64(1), 107 "oplog_write_lock": float64(1), 108 "duration_ms": float64(0), 109 }, 110 }, 111 }, 112 113 { 114 line: T1_STRING + " I WRITE [context12345] insert database.collection:Stuff query: {} " + locks_string1 + " 0ms", 115 expected: processed{ 116 time: T1, 117 includeData: map[string]interface{}{ 118 "severity": "informational", 119 "component": "WRITE", 120 "context": "context12345", 121 "operation": "insert", 122 "namespace": "database.collection:Stuff", 123 "database": "database", // decomposed from namespace 124 "collection": "collection:Stuff", // decomposed from namespace 125 "query": map[string]interface{}{}, 126 "normalized_query": "{ }", 127 "global_read_lock": float64(2), 128 "global_write_lock": float64(2), 129 "database_write_lock": float64(2), 130 "collection_write_lock": float64(1), 131 "oplog_write_lock": float64(1), 132 "duration_ms": float64(0), 133 }, 134 excludeKeys: []string{ 135 "database_read_lock", 136 }, 137 }, 138 }, 139 140 { 141 line: T1_STRING + " I COMMAND [context12345] command database.$cmd command: insert { } " + locks_string1 + " 0ms", 142 expected: processed{ 143 time: T1, 144 includeData: map[string]interface{}{ 145 "severity": "informational", 146 "component": "COMMAND", 147 "context": "context12345", 148 "operation": "command", 149 "namespace": "database.$cmd", 150 "database": "database", // decomposed from namespace 151 "collection": "$cmd", // decomposed from namespace 152 "command_type": "insert", 153 "command": map[string]interface{}{}, 154 "global_read_lock": float64(2), 155 "global_write_lock": float64(2), 156 "database_write_lock": float64(2), 157 "collection_write_lock": float64(1), 158 "oplog_write_lock": float64(1), 159 "duration_ms": float64(0), 160 }, 161 excludeKeys: []string{ 162 "database_read_lock", 163 }, 164 }, 165 }, 166 167 { 168 line: UBUNTU_3_2_9_INSERT, 169 expected: processed{ 170 time: UBUNTU_3_2_9_INSERT_TIME, 171 includeData: map[string]interface{}{ 172 "severity": "informational", 173 "operation": "command", 174 "command_type": "insert", 175 "namespace": "protecteddb.comedy", 176 "keyUpdates": 0.0, 177 "reslen": 25.0, 178 "global_read_lock": 1.0, 179 "global_write_lock": 1.0, 180 "database_write_lock": 1.0, 181 "collection_write_lock": 1.0, 182 }, 183 excludeKeys: []string{ 184 "oplog_write_lock", 185 "collection_read_lock", 186 }, 187 }, 188 }, 189 190 { 191 line: UBUNTU_3_2_9_FIND, 192 expected: processed{ 193 time: UBUNTU_3_2_9_FIND_TIME, 194 includeData: map[string]interface{}{ 195 "severity": "informational", 196 "operation": "command", 197 "command_type": "find", 198 "namespace": "protecteddb.comedy", 199 "keyUpdates": 0.0, 200 "reslen": 245.0, 201 "global_read_lock": 7.0, 202 "global_write_lock": 1.0, 203 "database_read_lock": 3.0, 204 "database_write_lock": 1.0, 205 "collection_read_lock": 3.0, 206 "collection_write_lock": 1.0, 207 "docsExamined": 5.0, 208 "duration_ms": 29.0, 209 }, 210 excludeKeys: []string{ 211 "oplog_write_lock", 212 }, 213 }, 214 }, 215 216 { 217 line: UBUNTU_3_2_9_UPDATE, 218 expected: processed{ 219 time: UBUNTU_3_2_9_UPDATE_TIME, 220 includeData: map[string]interface{}{ 221 "severity": "informational", 222 "operation": "update", 223 "namespace": "protecteddb.comedy", 224 "keyUpdates": 0.0, 225 "global_read_lock": 1.0, 226 "global_write_lock": 1.0, 227 "database_write_lock": 1.0, 228 "collection_write_lock": 1.0, 229 "docsExamined": 4.0, 230 }, 231 excludeKeys: []string{ 232 "database_read_lock", 233 "oplog_write_lock", 234 }, 235 }, 236 }, 237 238 { 239 line: UBUNTU_2_6_FIND, 240 expected: processed{ 241 time: UBUNTU_2_6_FIND_TIME, 242 includeData: map[string]interface{}{ 243 "operation": "query", 244 "context": "conn1579035", 245 "namespace": "starfruit_production.users", 246 "read_lock_held_us": int64(114782), 247 "duration_ms": 105.0, 248 "reslen": 20.0, 249 "nscanned": 67439.0, 250 "database": "starfruit_production", 251 "collection": "users", 252 }, 253 }, 254 }, 255 { 256 line: ATLAS_3_6_0_FIND, 257 expected: processed{ 258 time: ATLAS_3_6_0_FIND_TIME, 259 includeData: map[string]interface{}{ 260 "operation": "command", 261 "context": "conn8080", 262 "namespace": "foo.abc", 263 "duration_ms": 0.0, 264 "reslen": 303.0, 265 "database": "foo", 266 "collection": "abc", 267 }, 268 }, 269 }, 270 { 271 line: HEARTBEAT, 272 expected: processed{ 273 time: HEARTBEAT_TIME.AddDate(httime.Now().Year(), 0, 0), 274 includeData: map[string]interface{}{ 275 "command_type": "replSetHeartbeat", 276 "replica_set": "replica-set-here", 277 }, 278 }, 279 }, 280 281 { 282 line: UBUNTU_2_4_FIND, 283 expected: processed{ 284 time: UBUNTU_2_4_FIND_TIME.AddDate(httime.Now().Year(), 0, 0), 285 includeData: map[string]interface{}{ 286 "operation": "query", 287 "read_lock_held_us": int64(60), 288 "replica_set": "replica-set-here", 289 }, 290 }, 291 }, 292 293 { 294 line: OSX_3_2_9_AGGREGATE, 295 expected: processed{ 296 time: OSX_3_2_9_AGGREGATE_TIME, 297 includeData: map[string]interface{}{ 298 "duration_ms": 34.0, 299 "replica_set": "replica-set-here", 300 }, 301 excludeKeys: []string{}, 302 }, 303 }, 304 305 { 306 line: NESTED_QUOTES, 307 expected: processed{ 308 time: NESTED_QUOTES_TIME, 309 includeData: map[string]interface{}{ 310 "duration_ms": 0.0, 311 }, 312 excludeKeys: []string{}, 313 }, 314 }, 315 { 316 line: UBUNTU_3_0_KILLCURSORS, 317 expected: processed{ 318 time: UBUNTU_3_0_KILLCURSORS_TIME, 319 includeData: map[string]interface{}{ 320 "duration_ms": 0.0, 321 "operation": "killcursors", 322 "component": "QUERY", 323 }, 324 excludeKeys: []string{}, 325 }, 326 }, 327 { 328 line: MONGO_3_4_QUERY, 329 expected: processed{ 330 time: MONGO_3_4_QUERY_TIME, 331 includeData: map[string]interface{}{ 332 "duration_ms": 1061.0, 333 "component": "COMMAND", 334 "command_type": "findAndModify", 335 "keysInserted": 3.0, 336 "normalized_query": `{ "_id": 1, "state": 1 }`, 337 }, 338 excludeKeys: []string{}, 339 }, 340 }, 341 { 342 line: MONGO_3_4_GETMORE, 343 expected: processed{ 344 time: MONGO_3_4_GETMORE_TIME, 345 includeData: map[string]interface{}{ 346 "duration_ms": 120.0, 347 "component": "COMMAND", 348 "command_type": "getMore", 349 "collection": "TestColl", 350 "docsExamined": 59899.0, 351 }, 352 excludeKeys: []string{}, 353 }, 354 }, 355 { 356 line: MONGO_3_4_INIT, 357 expected: processed{ 358 time: MONGO_3_4_INIT_TIME, 359 includeData: map[string]interface{}{ 360 "component": "CONTROL", 361 }, 362 excludeKeys: []string{}, 363 }, 364 }, 365 { 366 line: MONGO_3_4_INDEX, 367 expected: processed{ 368 time: MONGO_3_4_INDEX_TIME, 369 includeData: map[string]interface{}{ 370 "component": "INDEX", 371 "context": "conn5", 372 }, 373 excludeKeys: []string{}, 374 }, 375 }, 376 { 377 line: MONGO_3_4_SHARDING, 378 expected: processed{ 379 time: MONGO_3_4_SHARDING_TIME, 380 includeData: map[string]interface{}{ 381 "component": "SHARDING", 382 "context": "conn1", 383 "namespace": "TestDB.TestColl", 384 "database": "TestDB", 385 "collection": "TestColl", 386 "sharding_collection": "changelog", 387 "changelog_primary": "shard0000:ip-10-69-189-27:23760", 388 "changelog_what": "shardCollection.start", 389 "changelog_changeid": "ip-10-69-189-27-2016-10-20T22:27:59.516+0000-580944efeaec999c2d8e0d58", 390 }, 391 excludeKeys: []string{}, 392 }, 393 }, 394 { 395 line: UPDATE_SIMPLE_COMMAND, 396 expected: processed{ 397 time: UPDATE_COMMAND_TIME.AddDate(httime.Now().Year(), 0, 0), 398 includeData: map[string]interface{}{ 399 "normalized_query": `{ "updates": [ { "$query": { "mood": 1 }, "$update": { "$set": { "mood": 1 } } } ] }`, 400 }, 401 excludeKeys: []string{}, 402 }, 403 }, 404 { 405 line: UPDATE_COMMAND, 406 expected: processed{ 407 time: UPDATE_COMMAND_TIME.AddDate(httime.Now().Year(), 0, 0), 408 includeData: map[string]interface{}{ 409 "normalized_query": `{ "updates": [ { "$query": { "hulkForm": 1 }, "$update": { "$set": { "hulkForm": 1 }, "$setOnInsert": { "hulkForm": 1 } } } ] }`, 410 }, 411 excludeKeys: []string{}, 412 }, 413 }, 414 { 415 line: DELETE_SIMPLE_COMMAND, 416 expected: processed{ 417 time: DELETE_COMMAND_TIME.AddDate(httime.Now().Year(), 0, 0), 418 includeData: map[string]interface{}{ 419 "normalized_query": `{ "deletes": [ { "$query": { "mood": 1 } } ] }`, 420 }, 421 excludeKeys: []string{}, 422 }, 423 }, 424 { 425 line: DELETE_COMMAND, 426 expected: processed{ 427 time: DELETE_COMMAND_TIME.AddDate(httime.Now().Year(), 0, 0), 428 includeData: map[string]interface{}{ 429 "normalized_query": `{ "deletes": [ { "$limit": 1, "$query": { "hulkForm": 1, "issue": { "$ne": 1 } } } ] }`, 430 }, 431 excludeKeys: []string{}, 432 }, 433 }, 434 } 435 m := &Parser{ 436 conf: Options{ 437 NumParsers: 1, 438 }, 439 } 440 lines := make(chan string, len(tlm)) 441 send := make(chan event.Event, len(tlm)) 442 // prep the incoming channel with test lines for the processor 443 go func() { 444 for _, pair := range tlm { 445 lines <- pair.line 446 } 447 close(lines) 448 }() 449 // spin up the processor to process our test lines 450 m.ProcessLines(lines, send, nil) 451 // We expect that it got sent through in order, serialized thanks to NumParsers = 1 452 for _, pair := range tlm { 453 ev := <-send 454 assert.Equal(t, pair.expected.time.UnixNano(), ev.Timestamp.UnixNano()) 455 456 var missing []string 457 for k := range pair.expected.includeData { 458 if _, ok := ev.Data[k]; !ok { 459 missing = append(missing, k) 460 } else { 461 assert.Equal(t, pair.expected.includeData[k], ev.Data[k]) 462 } 463 } 464 assert.Nil(t, missing) 465 for _, k := range pair.expected.excludeKeys { 466 _, ok := ev.Data[k] 467 assert.False(t, ok) 468 } 469 } 470 close(send) 471 }