Logging

Logging events can significantly improve the debugging experience. Frappe's development and production environments come with logging capabilities out of the box.

There's two main categories of logs based on accessibility. Desk Logs, which are stored in your site database and can be accessed and queried as Documents and the Server Logs, that are stored in files managed by a Log Rotation system.

Desk Logs

Logs that can be accessed via the Desk UI (generally searched for, from the Awesomebar). These track the operational events generally; but you can utilize their APIs to track about anything from your Frappe apps.

Some of the logs in the Core module are:

• Access Log
• Activity Log
• Error Log
• Scheduled Job Log

You can find more information about them from the embedded links. The best way to find out more about each of them is checking them out directly on your site.

Server Logs

Server Logs generally consist of lower level, transactional data as compared to those accessible from Desk. From Version 13, logs are available at site level too. These site logs are created by the Frappe Application, while many of the bench level log files are generated by the processes that support your Frappe environment. From your bench folder, you may find logs under:

• ./logs
• ./sites/{site}/logs

At the time of writing this, only frappe.web.log and scheduler.log are logged at site and bench-level. At bench level, some of the most useful files could be:

• bench.log
• scheduler.log
• worker.log

Tracking the bench commands executed, status of the jobs run by your Scheduler or Background Jobs can be found in these logs.

To enable Frappe Web Logging on your site, update the site config with enable_frappe_logger: true

Error Snapshots

Along with these, Frappe maintains error snapshots for your sites for HTTP response codes from 500 and above. This is done in order to provide more context for failures in case of server errors. Consider, a desk action failing with HTTP status code 500, this would add a corresponding log in the ./sites/{site}/frappe.log file as follows:

2021-05-06 14:08:12,177 ERROR frappe New Exception collected with snapshot id: 2021-05-06 14:08:11.940809-127.0.0.1-bde
Site: frappeframework.com
Form Dict: {'docs': '{"name":"assets.frappeframework.com","owner":"Administrator","creation":"2020-04-04 14:58:18.771247","modified":"2021-02-08 09:40:56.820300","modified_by":"gavin@frappe.io","idx":0,"docstatus":0,"status":"Active","hostname":"assets","domain":"frappeframework.com","cluster":"Default","provider":"Generic","is_server_setup":1,"ip":"192.168.29.100","private_ip":"10.120.120.120","agent_password":"*****","is_primary":1,"doctype":"Server","__last_sync_on":"2021-05-06T08:38:08.931Z"}', 'method': 'ping_agent', 'cmd': 'run_doc_method'}

The first line of the log mentions the snapshot ID of the error, which in this case was 2021-05-06 14:08:11.940809-127.0.0.1-bde. A corresponding file identified with the snapshot ID should be under ./sites/frappeframework.com/error-snapshots, with the name 2021-05-06 14:08:11.940809-127.0.0.1-bde.json. Contents of the file may be:

    {
    "etype": "UnboundLocalError",
    "evalue": "UnboundLocalError(\"local variable 'headers' referenced before assignment\")",
    "exception": {
      "args": [...],
      "with_traceback": [...]
    },
    "frames": [
      {
      "call": "(request=<request 'https:="" frappeframework.com="" api="" method="" run_doc_method'="" [post]="">)",
      "dump": {
        "frappe. api": "<module 'frappe.api'="" from="" '="" home="" frappe="" frappe-bench="" apps="" api.py'="">",
        "frappe.api. handle": "<function handle="">",
        "global frappe": "<module 'frappe'="" from="" '="" home="" frappe="" frappe-bench="" apps="" __init__.py'="">",
        "response": "None"
      },
      "file": "/home/frappe/frappe-bench/apps/frappe/frappe/app.py",
      "func": "application",
      "lines": {
        "66": "",
        "67": "\t\telif request.path.startswith(\"/api/\"):",
        "68": "\t\t\tresponse = frappe.api.handle()",
        "69": "",
        "70": "\t\telif request.path.startswith('/backups'):"
      },
      "lnum": 68
      },
    ...
    ],
    "locals": {
      "data": "None",
      "files": "None",
      "method": "GET",
      "path": "ping",
      "self": "<orchestrator.agent.agent object="">",
      "url": "https://assets.frappeframework.com:443/agent/ping"
    },
    "pyver": "Python 3.8.2: /home/frappe/frappe-bench/env/bin/python (prefix: /home/frappe/frappe-bench/env)",
    "timestamp": "2021-05-06 14:08:11.940971",
    "traceback": "Traceback (most recent call last):\n  File \"/home/frappe/frappe-bench/env/lib/python3.8/site-packages/cryptography/fernet.py\", line 119, in _verify_signature\n    h.verify(data[-32:])\n  File \"/home/frappe/frappe-bench/env/lib/python3.8/site-packages/cryptography/hazmat/primitives/hmac.py\", line 74, in verify\n    ctx.verify(signature)\n  File \"/home/frappe/frappe-bench/env/lib/python3.8/site-packages/cryptography/hazmat/backends/openssl/hmac.py\", line 75, in verify\n    raise InvalidSignature(\"Signature did not match digest.\")\ncryptography.exceptions.InvalidSignature: Signature did not match digest.\n\nDuring handling of the above exception, another exception occurred:\n\nTraceback (most recent call last):\n  File \"/home/frappe/frappe-bench/apps/frappe/frappe/app.py\", line 68, in application\n    response = frappe.api.handle()\n  File \"/home/frappe/frappe-bench/apps/frappe/frappe/api.py\", line 54, in handle\n    return frappe.handler.handle()\n  File \"/home/frappe/frappe-bench/apps/orchestrator/orchestrator/agent.py\", line 474, in request\n    headers=headers,\nUnboundLocalError: local variable 'headers' referenced before assignment\n"
    }

These snapshots are synced periodically with the site's database and are available via the desk with records added under the DocType Error Snapshot. They are maintained for a month from creation before each record is deleted.

Error snapshots are tracked by default. To disable this for your site, update the site config with disable_error_snapshot: true

Processes

Server Logs may be generated by the bench CLI, your process manager or the Frappe application directly. Your process managers take care of getting all the moving parts up and running for your Frappe environment as well as directing output and error streams to your log files.

Apart from the "always running" default logging, you can also use Monitor to log more information about all the requests to your site.

Maintainence

The log files generated by your process manager may get pretty large over time if you aren't paying attention. To know which files you have to track for this, checkout the supervisor.conf or Procfile on your bench, depending on whether you're running a production or development instance respectively.

Auto cleanup of old logs

Most logging doctypes in Frappe support configurable retention period with sane defaults.

"Log Settings" doctype lets you configure retention period for default logging doctypes.

You can also register your custom logging doctype with log settings by adding a single static method to your doctype controller like this. Custom logging doctypes which implement this method will automatically show up in Log Settings.

class CustomLoggingDoctype(Document):
    @staticmethod
    def clear_old_logs(days=180):
        from frappe.query_builder import Interval
        from frappe.query_builder.functions import Now

        table = frappe.qb.DocType("Custom Logging Doctype")
        frappe.db.delete(table, filters=(table.modified < (Now() - Interval(days=days))))

More

In a production environment, you'd likely want to log more information for your Frappe Applications or the processes that make up your Frappe Environment. Here's some resources you could go over to find out more.

Frappe Application

• Frappe Logging API

Server Monitoring

• MySQL
• PostgreSQL
• NGINX