Just came across one issue - not all apm-server http requests are logged in the same way:

/ and /intake/v2/events happy paths include response_code

INFO	[request]	beater/common_handler.go:184	handled request	{"request_id": "6f3e2013-ebd2-405f-ad1f-a4f02e252109", "method": "GET", "URL": "/", "content_length": 0, "remote_address": "127.0.0.1", "user-agent": "Go-http-client/1.1", "response_code": 200}
INFO	[request]	beater/common_handler.go:184	handled request	{"request_id": "2a98868c-6b44-403d-951d-c82922250e0c", "method": "POST", "URL": "/intake/v2/events", "content_length": 3585, "remote_address": "127.0.0.1", "user-agent": "curl/7.54.0", "response_code": 202}

/intake/v2/events errors do not:

ERROR	[request]	beater/intake_handler.go:93	error handling request	{"request_id": "c35b6689-c617-46e1-8cb2-1cb4fce940db", "method": "POST", "URL": "/intake/v2/events", "content_length": 3585, "remote_address": "127.0.0.1", "user-agent": "curl/7.54.0", "error": "queue is full"}
ERROR	[request]	beater/intake_handler.go:93	error handling request	{"request_id": "c27a2c7a-59f1-4271-bf68-369b1b1206f5", "method": "POST", "URL": "/intake/v2/events", "content_length": 1675, "remote_address": "127.0.0.1", "user-agent": "curl/7.54.0", "error": "error validating JSON document against schema: I[#] S[#] doesn't validate with \"transaction#\"\n  I[#] S[#/allOf/1] allOf failed\n    I[#/context/response/status_code] S[#/allOf/1/properties/context/properties/response/properties/status_code/type] expected integer or null, but got string [{\"transaction\": {\"id\": \"4340a8e0df1906ecbfa9\", \"trace_id\": \"0acd456789abcdef0123456789abcdef\", \"name\": \"GET /api/types\",\"type\": \"request\",\"duration\": 32.592981,\"result\": \"success\", \"timestamp\": 1496170407154000, \"sampled\": true, \"span_count\": {\"started\": 17},\"context\": {\"service\": {\"runtime\": {\"version\": \"7.0\"}},\"page\":{\"referer\":\"http://localhost:8000/test/e2e/\",\"url\":\"http://localhost:8000/test/e2e/general-usecase/\"}, \"request\": {\"socket\": {\"remote_address\": \"12.53.12.1\",\"encrypted\": true},\"http_version\": \"1.1\",\"method\": \"POST\",\"url\": {\"protocol\": \"https:\",\"full\": \"https://www.example.com/p/a/t/h?query=string#hash\",\"hostname\": \"www.example.com\",\"port\": \"8080\",\"pathname\": \"/p/a/t/h\",\"search\": \"?query=string\",\"hash\": \"#hash\",\"raw\": \"/p/a/t/h?query=string#hash\"},\"headers\": {\"user-agent\": \"Mozilla Chrome Edge\",\"content-type\": \"text/html\",\"cookie\": \"c1=v1, c2=v2\",\"some-other-header\": \"foo\",\"array\": [\"foo\",\"bar\",\"baz\"]},\"cookies\": {\"c1\": \"v1\",\"c2\": \"v2\"},\"env\": {\"SERVER_SOFTWARE\": \"nginx\",\"GATEWAY_INTERFACE\": \"CGI/1.1\"},\"body\": {\"str\": \"hello world\",\"additional\": { \"foo\": {},\"bar\": 123,\"req\": \"additional information\"}}},\"response\": {\"status_code\": \"200\",\"headers\": {\"content-type\": \"application/json\"},\"headers_sent\": true,\"finished\": true}, \"user\": {\"id\": \"99\",\"username\": \"foo\"},\"tags\": {\"organization_uuid\": \"9f0e9d64-c185-4d21-a6f4-4673ed561ec8\", \"tag2\": 12, \"tag3\": 12.45, \"tag4\": false, \"tag5\": null },\"custom\": {\"my_key\": 1,\"some_other_value\": \"foo bar\",\"and_objects\": {\"foo\": [\"bar\",\"baz\"]},\"(\": \"not a valid regex and that is fine\"}}}}]"}

The last example also demonstrates a second issue - the message is error handling request in both cases - perhaps it would be more useful if those were queue is full and error validating JSON document against schema respectively, leaving the details to the error?

[self instrumentation] Enhance Logging #2201

Description

Metadata

Metadata

Assignees

Labels

Type

Fields

Projects

Milestone

Relationships

Development

Issue actions