View source for Firefox/Services/Logging

= Firefox Services Logging Standard =

A standard logging scheme for all firefox services that participate in data services (logging pipeline, hindsight alerting, elastic search indexing, kibana dashboards, future data warehousing & api access to data, custom dashboards, etc.). This applies primarily to production logging data.

= Format =

* A Heka protobuf encoding is ideal from a performance perspective: [https://github.com/mozilla-services/heka/blob/dev/message/message.proto Heka protobuf definition], [https://github.com/mozilla-services/lua_sandbox/blob/master/src/util/heka_message.c Hindsight version]
* JSON is a reasonable alternative (and currently used by most of our servers); [[#JSON log schema]]
* Data is consumed by Heka on STDOUT or STDERR streams. For servers logging JSON, non JSON data will be ignored. Some logging packages prefix the timestamp; this can be worked around but is not ideal. 

== Nginx Log Files ==

Most servers will have nginx in front of them, which will generate log files. The ops team uses this data for monitoring in the logging pipeline. We can generate standard kibana dashboards to look at request status, user agent segmentation, response time, etc. We can also create standard alerting in hindsight for unexpected behavior (spikes in traffic, etc.) While its useful to duplicate some of this data in the application request summary to associate with other app specific fields (see below), servers don't need to create adhoc logs that duplicate this information (on production).

== MozLog application logging standard ==

mozlog is JSON schema for a common application logging format. By standardizing on a specific format it is easier to write parsers, extractors and aggregators for logs. It is a Mozilla Cloud Services standard and is reproduced here for ease of reference.

A mozlog message looks like this:
<source lang:json>
{
	"Timestamp": 145767775123456,
	"Type": "request.summary",
	"Logger": "myapp",
	"Hostname": "server-a123.mozilla.org",
	"EnvVersion":"2.0",
	"Severity": 6,
	"Pid": 1337,
	"Fields":{
		"agent": "curl/7.43.0",
		"errno": 0,
		"method": "GET",
		"msg": "the user wanted something.",
		"path": "/something",
		"t": 5,
		"uid": "12345"
	}
}
</source>

=== Top Level Properties ===

{| class="wikitable"
! Name
! Type
! Description
! Required
! Notes
|-
| Timestamp
| int64
| Number of nanoseconds since the [http://pubs.opengroup.org/onlinepubs/9699919799/basedefs/V1_chap04.html#tag_04_16 UNIX epoch] (which is UTC)
| required
| If human readable time is absolutely necessary, add an additional "Time" field (RFC3339).
|-
| Type
| string
| Type of message i.e. “request.summary”
| recommended
| May be used for filtering in kibana, or may be used to not index certain types of logging in elastic search, etc. Dot notation is not required, "request.summary" is a legacy. Dot notation interferes with some types of elasticsearch queries, but this has not yet been a problem with our kibana/elasticsearch usage.
|-
| Logger
| string
| Data source, server that is doing the logging, e.g. “Sync-1_5”
| recommended
| Use the server's name, and avoid implementation details. "FxaAuthWebserver", not "NginxLogs".
|-
| Hostname
| string
| Hostname that generated the message
| recommended
| os.hostname(); used by ops to watch for unusual aws instance behavior
|-
| EnvVersion
| string
| Envelope version; log format version
| recommended
| Semantic version of the log format/content (http://semver.org/ (although in most cases it is just the major version)). Useful if we change logging formats down the road. Logging format version, not app/release version – only change this is the log format changes. Recommended: "1.0" for the first version that is consumed by our shared stack, "2.0" for the version that conforms to the conventions described here, including "Fields".
|-
| Pid
| int32
| Process ID that generated the message
| optional
|  
|-
| Severity
| int32
| [http://en.wikipedia.org/wiki/Syslog#Severity_levels Syslog severity levels]
| optional
|  
|-
| Fields
| object
| Hash of fields
| recommended
| All of the app specific fields go in this hash (see below). Note: we had originally standardized on flattening this for legacy reasons; using the Fields hash incurs less transformational overhead and makes a more clear distinction between meta and app specific fields.
|}

=== Application Request Summary (Type:"request.summary") ===

A common pattern is to log one line that summarizes the results of a request. This duplicates some information in nginx log files, but allows us to associate other information known by the server. While this won't meet all logging needs, we recommend leveraging this log line where possible and not logging duplicate information with multiple app log lines.

{| class="wikitable"
! Field Name
! Type
! Description
! Required
! pii
! Notes
|-
| agent
| string
| User agent string:[http://stackoverflow.com/questions/2601372/what-is-the-standard-format-for-a-browsers-user-agent-string  stack overflow summary]
| recommended
| can be; will be parsed into "user_agent_browser", "user_agent_os", "user_agent_version" for common user agents and then scrubbed by the pii filter
| We often care about device/desktop segmentations, which are derived from this field.
|-
| path
|  
| request path
| recommended
|  
|  
|-
| method
|  
| request method
| recommended if important to distinguish API calls
|  
|  
|-
| code
| int32
| http(s) status code
| recommended
|  
|  
|-
| errno
| int32
| 0 for success or a number [https://github.com/mozilla/fxa-auth-server/blob/master/docs/api.md#response-format > 0] for errors, defined by the application
| recommended
|  
|  
|-
| lang
| string
| the parsed 'accept-language'
| recommended
| can be for unusual locales/languages
| We're also interested in aggregated language segmentations; to detect problems with translations and to understand popularity of services in different areas.
|-
| uid
| string
| user id
| recommended
| yes; will be scrubbed by pii filter before being indexed in es
| This field is often very important for "daily active user" counts (and similar). These counts are usually computed by heka filters before pii scrubbing.
|-
| email
| string
| email used in this request
| discouraged
| yes; will be scrubbed by pii filter before being indexed in es
| Some servers need this to be logged (fraud detection, etc.); only log email addresses if you have a specific need.
|-
| service
| string
| If this server is used by multiple cloud services, which service?
| recommended if appropriate
| can be (in particular if non-mozilla services enter the mix). Not filtering yet but we may need to eventually.
| This field is important for looking at how frequently various services are being used, what services are on-ramps to accounts, etc. Over time this is going to become a very important segmentation.
|-
| context
| string
| Does this request have different contexts it might be coming from? (e.g. "fxos first time experience" vs. "settings panel")
| recommended if appropriate
|  
| Can be useful for understanding how users are using services.
|-
| msg
| string
| Human readable string (often error string)
| optional
| should not contain pii
| Generally not parsed by heka/kibana
|-
| remoteAddressChain
| string array
| array of IP addresses between the client and server
| optional
| yes; will be scrubbed by pii filter before being indexed in es
|  
|-
| rid
| string
| unique request id for correlating other log lines
| optional
|  
|  
|-
| t
| int32
| request processing time in ms
| optional
|  
|  
|}

=== Hawk Client Clock Skew (Type:"server.nonceFunc") ===

{|
! Field Name
! Type
! Description
! Required
! pii
! Notes
|-
| skew
| int32
| client/server clock skew
| required
|  
|  
|}

=== MozLog JSON schema ===
<source lang:json>
{
  "type": "object",
  "required": [
    "Timestamp"
  ],
  "properties": {
    "Timestamp": {
      "type": "integer",
      "minimum": 0
    },
    "Type": {
      "type": "string"
    },
    "Logger": {
      "type": "string"
    },
    "Hostname": {
      "type": "string",
      "format": "hostname"
    },
    "EnvVersion": {
      "type": "string",
      "pattern": "^\\d+(?:\\.\\d+){0,2}$"
    },
    "Severity": {
      "type": "integer",
      "minimum": 0,
      "maximum": 7
    },
    "Pid": {
      "type": "integer",
      "minimum": 0
    },
    "Fields": {
      "type": "object",
      "minProperties": 1,
      "additionalProperties": {
        "anyOf": [
          {
            "$ref": "#/definitions/field_value"
          },
          {
            "$ref": "#/definitions/field_array"
          },
          {
            "$ref": "#/definitions/field_object"
          }
        ]
      }
    }
  },
  "definitions": {
    "field_value": {
      "type": [
        "string",
        "number",
        "boolean"
      ]
    },
    "field_array": {
      "type": "array",
      "minItems": 1,
      "oneOf": [
        {
          "items": {
            "type": "string"
          }
        },
        {
          "items": {
            "type": "number"
          }
        },
        {
          "items": {
            "type": "boolean"
          }
        }
      ]
    },
    "field_object": {
      "type": "object",
      "required": [
        "value"
      ],
      "properties": {
        "value": {
          "oneOf": [
            {
              "$ref": "#/definitions/field_value"
            },
            {
              "$ref": "#/definitions/field_array"
            }
          ]
        },
        "representation": {
          "type": "string"
        }
      }
    }
  }
}
</source>

=== Implementations & Libraries ===
* [https://www.npmjs.com/package/mozlog nodejs]
* [https://github.com/mozilla-services/go-mozlogrus golang]
* [https://github.com/mozilla/fxa-auth-server/blob/master/lib/log.js#L93-L137 Usage in FxA]