-
Notifications
You must be signed in to change notification settings - Fork 10
Logging Strategy
The logging strategy for the OpenConext Stepup services must:
- cancel a request if unable to log;
- allow tracing of inter-application client requests;
- allow tracing of SAML authentication requests and responses;
- allow tracing of all requests a client makes in an application;
- report important application decisions;
- include the hostname, application name and machine name with each log message;
- report the request URIs during a client request;
- report the duration of a request (configurable);
- report database/cache/storage query times (configurable);
- report all PHP errors;
- report uncaught exceptions;
- and, in production, refrain from logging
<= INFOmessages unless messages of level>= NOTICEare logged.
If the application log handler (./app/logs/<env_name>.log) fails the request must be aborted. As all actions produce an event in the database, the audit trail is guaranteed. The logging infrastructure (currently rsyslog to ELK stack) must not be a SPOF. Application may assume that if they could deliver to syslog, the logging was successful. Failure to communicate within e.g. the ELK stack does not require the request to be aborted.
In Symfony2, when logging fails, an exception must be thrown, at which point a kernel.exception listener can display a user-friendly page or Internal Server Error API response to API clients.
A client request describes all application request/response cycles executed for a single client interaction. A single client interaction includes any SAML communication/redirects.
To be able to trace such information, a request ID is, if unknown, generated and sent with each subsequent request (e.g. HTTP) to other systems. Each system logs messages, attaching the request ID.
The request ID should be generated by hashing the application and machine name and timestamp to a hexadecimal string.
The request ID must be stored in the additional field _request_id. In case of Symfony2 applications, this can be achieved by listening for the kernel.request event and providing this information to a Monolog Processor.
Sub-system HTTP requests must store the request ID in the header X-Stepup-Request-Id. The X-Stepup-Request-Id header should be added to the response in dev and test environments. In case of Symfony2 applications, this can be achieved by listening for the kernel.response event and setting the header.
In order to trace a SAML authentication request and response, all requests within the Step-up systems that pertain to a single authentication request must be tagged with the same SAML authentication request ID or SARI . This enables an authentication procedure to be traced from Self-Service, to the Gateway, to its IdP, and back again.
An authentication request can be one of the following:
- A user logs in from the Self-Service or RA application, passes the Gateway to SURFconext and the final IdP. Information regarding the request is logged in the Self-Service/RA and Gateway applications.
- A user logs in from a Service Provider, passes the Gateway to SURFconext and the final IdP. Information regarding the request is logged in the Gateway application.
An authentication request is not:
- An GSSP Enrollment or verification. E.g. the verification or enrollment of a Tiqr token through SAML at the Tiqr GSSP IdP.
This SARI should be a UUID.
The ID must be stored with each log message in the additional field _sari.
To trace all requests a client makes in an application during his/her session, a session ID must be included with each log message.
The session ID must be hashed, so it cannot be traced back to the true session ID.
The session ID must be stored in the additional field _session_id.
In case of Symfony2 applications, the session ID can be achieved by listening for the kernel.request event, retrieving the session ID through $request->getSession()->getId() and providing this information to a Monolog Processor.
Log important decisions the application makes on level NOTICE. Log whether access is granted or denied to systems or parts of systems (security decisions).
To allow log analysis at least timestamp, the hostname, application name and machine name must be included with each log message. If you use syslog some of these will be taken care of for you, you will need to set an unique application name: e.g. "Stepup-Gateway"
To help tracing client interaction, when a specific action takes place, the request URI must be logged with the log message on NOTICE level.
This URI must be stored in the additional field _request_uri.
To help monitor performance, the duration of requests must be logged on INFO level.
In Symfony2 applications, this can be achieved by listening for kernel.request and kernel.response events and logging the time difference (see the Stopwatch Component).
To help monitor software errors, all PHP errors, including notices and warnings, should be logged.
This can easily be achieved by activating Monolog's ErrorHandler.
To help monitor software errors, all uncaught exception should be logged. The log message must be logged on ERROR level. For Graylog2, the full exception description with backtrace must be included in the full_message. The stream handler must include it in context.exception.
This can easily be achieved by activating Monolog's ErrorHandler and decorating the GelfMessageFormatter to add the backtrace from the context's exception to the full message (Gelf\\Message::setFullMessage()).
In production, refrain from logging debug and info messages, but do provide them when an error occurs
Only if a message of level ERROR or more severe occurs while handeling a request are we interested in DEBUG and INFO messages for that request. In absence of ERROR-level messages, we are interested in NOTICEs and WARNINGs.
This can be achieved by logging through a FilterHandler set to NOTICE,WARNING and a FingersCrossedHandler, which can be configured to buffer log messages until an ERROR-level message occurs.