# Troubleshooting and debugging

# Seek Assistance

- [Chatroom](https://matrix.to/#/#forgejo-chat:matrix.org)
- [Issue tracker](https://codeberg.org/forgejo/forgejo/issues)

> [!note] Note
> When asking for support, it may be a good idea to have the following available so that the person helping has all the info they need:

1. Your `app.ini` (with any sensitive data scrubbed as necessary).
2. The Forgejo logs, and any other appropriate log files for the situation.
   - When using systemd, use `journalctl --lines 1000 --unit forgejo` to collect logs.
   - When using docker, use `docker logs --tail 1000 <forgejo-container>` to collect logs.
   - By default, the logs are outputted to console. If you need to collect logs from files,
     you could copy the following config into your `app.ini` (remove all other `[log]` sections),
     then you can find the `*.log` files in Forgejo's log directory (default: `%(FORGEJO_WORK_DIR)/log`).

   ```ini
   ; To show all SQL logs, you can also set LOG_SQL=true in the [database] section
   [log]
   LEVEL=debug
   MODE=console,file
   ROUTER=console,file
   XORM=console,file
   ENABLE_XORM_LOG=true
   FILE_NAME=forgejo.log
   [log.file.router]
   FILE_NAME=router.log
   [log.file.xorm]
   FILE_NAME=xorm.log
   ```

3. Any error messages you are seeing.
4. If you meet slow/hanging/deadlock problems, please report the stack trace when the problem occurs:
   1. Enable pprof in `app.ini` and restart Forgejo.

      ```ini
      [server]
      ENABLE_PPROF = true
      ```

   2. Trigger the bug, and when Forgejo gets stuck, use curl or browser to visit: `http://127.0.0.1:6060/debug/pprof/goroutine?debug=1` (IP must be `127.0.0.1` and port must be `6060`).
   3. If you are using Docker, please use `docker exec -it <container-name> curl "http://127.0.0.1:6060/debug/pprof/goroutine?debug=1"`.
   4. Report the output (the stack trace doesn't contain sensitive data).

# Logging Configuration

The logging configuration of Forgejo mainly consists of 3 types of components:

- The `[log]` section for general configuration.
- `[log.<mode-name>]` sections for the configuration of different log writers to output logs, aka: "writer mode", the mode name is also used as "writer name".
- The `[log]` section can also contain sub-logger configurations following the key schema `logger.<logger-name>.<CONFIG-KEY>`.

There is a fully functional log output by default, so it is not necessary to define one.

## The `[log]` section

Configuration of logging facilities in Forgejo happens in the `[log]` section and its subsections.

The top level section `[log]` has the following properties:

- `ROOT_PATH`: (Default: **_[AppWorkPath](/link/1226#bkmrk-default-configuratio)_/log**): Base path for log files.
- `MODE`: (Default: **console**): List of log outputs to use for the Default logger.
- `LEVEL`: (Default: **Info**): Least severe log events to persist, case-insensitive. Possible values, sorted by increasing severity, are: `Trace`, `Debug`, `Info`, `Warn`, `Error`, `Fatal`.
- `STACKTRACE_LEVEL`: (Default: **None**): Least severe events to print stacktrace for. Possible values are the same as for the `LEVEL` option.

The `[log]` section can contain sub-logger modes as well:

- `LOGGER_DEFAULT_MODE`: (Default: **,**): List of log outputs to use for the default logger.
- `LOGGER_ROUTER_MODE`: (Default: **,**): List of log outputs to use for the Router logger.
- `LOGGER_ACCESS_MODE`: (Default: **\<empty\>**): List of log outputs to use for the Access logger. By default, the access logger is disabled.
- `LOGGER_XORM_MODE`: (Default: **,**): List of log outputs to use for the XORM logger.

Setting a sub-logger's mode to a comma (`,`) makes it use the global `MODE`.

## Quick samples

### Default (empty) Configuration

The empty configuration is equivalent to default:

```ini
[log]
ROOT_PATH = %(GITEA_WORK_DIR)/log
MODE = console
LEVEL = Info
STACKTRACE_LEVEL = None
LOGGER_DEFAULT_MODE = ,
LOGGER_ROUTER_MODE = ,
LOGGER_XORM_MODE = ,
LOGGER_ACCESS_MODE =

; this is the config options of "console" mode (used by MODE=console above)
[log.console]
MODE = console
FLAGS = stdflags
PREFIX =
COLORIZE = true
```

This is equivalent to sending all logs to the console, with default Golang log being sent to the console log too.

This is only a sample, and it is the default, do not need to write it into your configuration file.

### Disable Router logs and record some access logs to file

The Router logger is disabled, the access logs (>=Warn) goes into `access.log`:

```ini
[log]
LOGGER_ROUTER_MODE =
LOGGER_ACCESS_MODE = access-file

[log.access-file]
MODE = file
LEVEL = Warn
FILE_NAME = access.log
```

### Set different log levels for different modes

Default logs (>=Warn) goes into `gitea.log`, while Error logs goes into `file-error.log`:

```ini
[log]
LEVEL = Warn
MODE = file, file-error

; by default, the "file" mode will record logs to %(log.ROOT_PATH)/gitea.log, so we don't need to set it
; [log.file]
; by default, the MODE (actually it's the output writer of this logger) is taken from the section name, so we don't need to set it either
; MODE = file

[log.file-error]
MODE = file
LEVEL = Error
FILE_NAME = file-error.log
```

## Log outputs (mode and writer)

Forgejo provides the following log output writers:

- `console` - Log to `stdout` (or `stderr` if it is set in the config).
- `file` - Log to a file.
- `conn` - Log to a socket (network or unix).

### Common configuration

Certain configuration is common to all modes of log output:

- `MODE` is the mode of the log output writer. It will default to the mode name in the ini section. Thus `[log.console]` will default to `MODE = console`.
- `LEVEL` is the lowest level that this output will log.
- `STACKTRACE_LEVEL` is the lowest level that this output will print a stacktrace.
- `COLORIZE` will default to `true` for `console` if writing to the terminal
  (see below), otherwise it will default to `false`.

#### `EXPRESSION`

`EXPRESSION` represents a regular expression that log events must match to be logged by the output writer.
Either the log message, (with colors removed), must match or the `longfilename:linenumber:functionname` must match.
NB: the whole message or string doesn't need to completely match.

Please note this expression will be run in the writer's goroutine but not the logging event goroutine.

#### `EXCLUSION`

`EXCLUSION` represents a regular expression that log events must not match in order to be logged by the output writer.
Either the log message (with colors removed) or the `longfilename:linenumber:functionname` must not match the exclusion pattern.
NB: the whole message or string doesn't need to completely match.

Please note this exclusion will be run in the writer's goroutine but not the logging event goroutine.

For example, you can collect logs from the Router, but requests to `/api/healthz` and `/api/metrics` are excluded:

```ini
[log.router]
MODE  = console
LEVEL = INFO
EXCLUSION = (\/api\/healthz|\/metrics)
```

#### `FLAGS`

`FLAGS` represents the preceding logging context information that is
printed before each message. It is a comma-separated string set. The order of values does not matter.

It defaults to `stdflags` (= `date,time,medfile,shortfuncname,levelinitial`). Except for the access log which defaults to `none`

Possible values are:

- `none` or `,` - No flags.
- `date` - the date in the local time zone: `2009/01/23`.
- `time` - the time in the local time zone: `01:23:23`.
- `microseconds` - microsecond resolution: `01:23:23.123123`. Assumes time.
- `longfile` - full file name and line number: `/a/b/c/d.go:23`.
- `shortfile` - final file name element and line number: `d.go:23`.
- `funcname` - function name of the caller: `runtime.Caller()`.
- `shortfuncname` - last part of the function name. Overrides `funcname`.
- `utc` - if date or time is set, use UTC rather than the local time zone.
- `levelinitial` - initial character of the provided level in brackets eg. `[I]` for info.
- `level` - level in brackets `[INFO]`.
- `levelprefix` - journald-style log level prefix, such as `<5>` for "info".
- `gopid` - the Goroutine-PID of the context.
- `medfile` - last 20 characters of the filename - equivalent to `shortfile,longfile`.
- `stdflags` - equivalent to `date,time,medfile,shortfuncname,levelinitial`.
- `journaldflags` - equivalent to `levelprefix`.

### Console mode

In this mode the logger will forward log messages to the stdout and
stderr streams attached to the Forgejo process.

For loggers in console mode, `COLORIZE` will default to `true` when appropriate:

- not on Windows, if the output is connected to a tty;
- on Windows, if the output is connected to either a Windows terminal
  that can be switched into ANSI mode (Windows 10+), or a Cygwin/MSYS terminal.

Settings:

- `STDERR`: **false**: Whether the logger should print to `stderr` instead of `stdout`.

### journald mode

As an extension to the console mode, if Forgejo detects that stdout and/or stderr
are connected to systemd-journald (which will happen automatically when Forgejo
is running under systemd), the defaults will change:

- `STDERR` will default to **true** if stderr is connected to systemd-journald;
- `FLAGS` will default to `journaldflags` if the chosen stream is connected to
  systemd-journald.

When `FLAGS = journaldflags` is used, instead of decorating log entries with
color or a textual representation of severity (e.g. `[INFO]` or `[ERROR]`),
Forgejo will annotate each log entry with a machine-readable log level prefix
that is captured by journald, enabling native filtering capabilities
(e.g. run `journalctl -u forgejo -p err` to only show errors or worse).

In short, if Forgejo is running under systemd, it is recommended to leave the
logging configuration at their defaults, which will use `MODE = console` and
adjust formatting to reduce clutter and enable native log level filtering.

### File mode

In this mode the logger will save log messages to a file.

Settings:

- `FILE_NAME`: The file to write the log events to, relative to `ROOT_PATH`, Default to `%(ROOT_PATH)/gitea.log`. Exception: access log will default to `%(ROOT_PATH)/access.log`.
- `MAX_SIZE_SHIFT`: **28**: Maximum size shift of a single file. 28 represents 256Mb. For details see below.
- `LOG_ROTATE` **true**: Whether to rotate the log files. If `false`, log files will always be appended.
- `DAILY_ROTATE`: **true**: Whether to rotate logs daily.
- `MAX_DAYS`: **7**: Delete rotated log files after this number of days.
- `COMPRESS`: **true**: Whether to compress old log files by default with gzip.
- `COMPRESSION_LEVEL`: **-1**: Compression level. For details see below.

`MAX_SIZE_SHIFT` defines the maximum size of a file by left shifting 1 the given number of times (`1 << x`).

The useful values of `COMPRESSION_LEVEL` are from 1 to (and including) 9, where higher numbers mean better compression.
Beware that better compression might come with higher resource usage.
Must be preceded with a `-` sign.

### Conn mode

In this mode the logger will send log messages over a network socket.

Settings:

- `ADDR`: **:7020**: Sets the address to connect to.
- `PROTOCOL`: **tcp**: Set the protocol, either "tcp", "unix" or "udp".
- `RECONNECT`: **false**: Try to reconnect when connection is lost.
- `RECONNECT_ON_MSG`: **false**: Reconnect host for every single message.

### The "Router" logger

The Router logger logs the following message types when Forgejo's route handlers work:

- `started` messages will be logged at TRACE level.
- `polling`/`completed` routers will be logged at INFO. Exception: "/assets" static resource requests are also logged at TRACE.
- `slow` routers will be logged at WARN.
- `failed` routers will be logged at WARN.

### The "XORM" logger

To make XORM outputs SQL logs, the `LOG_SQL` in `[database]` section should also be set to `true`.

### The "Access" logger

The Access logger provides a NCSA
Common Log compliant log format. It's highly configurable but caution
should be taken when changing its template. The main benefit of this
logger is that Forgejo can now log accesses in a standard log format so
standard tools may be used.

You can enable this logger using `LOGGER_ACCESS_MODE = ...`.

If desired the format of the Access logger can be changed by changing
the value of the `ACCESS_LOG_TEMPLATE`.

Please note, the access logger will log at `INFO` level, setting the
`LEVEL` of this logger to `WARN` or above will result in no access logs.

#### The ACCESS_LOG_TEMPLATE

This value represents a go template. Its default value is

```handlebars
{{.Ctx.RemoteHost}} - {{.Identity}} {{.Start.Format "[02/Jan/2006:15:04:05 -0700]" }} "{{.Ctx.Req.Method}} {{.Ctx.Req.URL.RequestURI}} {{.Ctx.Req.Proto}}" {{.ResponseWriter.Status}} {{.ResponseWriter.Size}} "{{.Ctx.Req.Referer}}" "{{.Ctx.Req.UserAgent}}"`
```

The template is passed following options:

- `Ctx` is the `context.Context`.
- `Identity` is the `SignedUserName` or `"-"` if the user is not logged in.
- `Start` is the start time of the request.
- `ResponseWriter` is the `http.ResponseWriter`.

Caution must be taken when changing this template as it runs outside of
the standard panic recovery trap. The template should also be as simple
as it runs for every request..

## Releasing-and-Reopening, Pausing and Resuming logging

If you are running on Unix you may wish to release-and-reopen logs in order to use `logrotate` or other tools.
It is possible force Forgejo to release and reopen its logging files and connections by sending `SIGUSR1` to the
running process, or running `forgejo manager logging release-and-reopen`.

Alternatively, you may wish to pause and resume logging - this can be accomplished through the use of the
`forgejo manager logging pause` and `forgejo manager logging resume` commands. Please note that whilst logging
is paused log events below INFO level will not be stored and only a limited number of events will be stored.
Logging may block, albeit temporarily, slowing Forgejo considerably whilst paused - therefore it is
recommended that pausing only done for a very short period of time.

## Adding and removing logging whilst Forgejo is running

It is possible to add and remove logging whilst Forgejo is running using the `forgejo manager logging add` and `remove` subcommands.
This functionality can only adjust running log systems and cannot be used to start the access or router loggers if they
were not already initialized. If you wish to start these systems you are advised to adjust the app.ini and (gracefully) restart
the Forgejo service.

The main intention of these commands is to easily add a temporary logger to investigate problems on running systems where a restart
may cause the issue to disappear.

## Using `logrotate` instead of built-in log rotation

Forgejo includes built-in log rotation, which should be enough for most deployments. However, if you instead want to use the `logrotate` utility:

- Disable built-in log rotation by setting `LOG_ROTATE` to `false` in your `app.ini`.
- Install `logrotate`.
- Configure `logrotate` to match your deployment requirements, see `man 8 logrotate` for configuration syntax details.
  In the `postrotate/endscript` block send Forgejo a `USR1` signal via `kill -USR1` or `kill -10` to the `forgejo` process itself,
  or run `forgejo manager logging release-and-reopen` (with the appropriate environment).
  Ensure that your configurations apply to all files emitted by Forgejo loggers as described in the above sections.
- Always do `logrotate /etc/logrotate.conf --debug` to test your configurations.
- If you are using docker and are running from outside the container you can use
  `docker exec -u $OS_USER $CONTAINER_NAME sh -c 'forgejo manager logging release-and-reopen'`
  or `docker exec $CONTAINER_NAME sh -c '/bin/s6-svc -1 /etc/s6/gitea/'` or send `USR1` directly to the Forgejo process itself.

The next `logrotate` jobs will include your configurations, so no restart is needed.
You can also immediately reload `logrotate` with `logrotate /etc/logrotate.conf --force`.


# Profiling

Forgejo is written in [Go](https://go.dev), which means Forgejo can leverage [the extensive profiling tooling](https://go.dev/doc/diagnostics) that is provided by Go's runtime.
Profiling in Forgejo can be done in production; it is safe and with low overhead; no settings need to be enabled for that.
A good knowledge of Forgejo internals helps with drawing conclusions from profiling.
It is easy to draw the wrong conclusions, be overwhelmed by the data, or try to find a needle in a haystack.
In the case you are reading this because you are suspecting or experiencing performance problems with Forgejo, it is recommended to [make an issue](https://codeberg.org/forgejo/forgejo/issues) or contact [the Forgejo developers](https://matrix.to/#/#forgejo-development:matrix.org); this can help in narrowing down where to look or with interpreting profiling results.

The following sections go into more details about the different types of profiling that can be done in Forgejo.

## Process stacktraces

This is by far the simplest way of profiling, even if it can be better described as diagnostics.
Most goroutines[^0], whether short-lived or long-lived, are tracked by Forgejo as processes, which means that Forgejo knows they exist, have a description, and can cancel them at any time.

[^0]: This can be conceptually seen as lightweight thread that are managed by the Go runtime.

In the admin settings navigate to the "Stacktrace" item in the "Monitoring" menu; this is also the page where the other profiling will take place.
The two buttons on above the segment determine what type of processes you want to see, "Running processes" show all non-system processes and "Stacktrace" shows all processes.
It is good to note that the information of the processes are only a snapshot of what the process was doing at the time of you loading this page, it is not continuously being updated; they could no longer exist or kept running and no longer be at this particular point in the codepath.

Each process in the list has a few key details:

- Title: this is the description that was given to the process, this should identify why it was created and what the purpose is.
- Date: this indicates when the process was created.

And a stacktrace, it is possible that a process has more than one stacktrace, in which case the first stacktrace can be seen as the _main_ stacktrace of that process and the others are children of that process that were not marked as new processes. The stacktrace is read from top to bottom, where each entry in the stacktrace represents a stack frame[^1]. The top entry is where the deepest stack frame and the bottom entry is the outer stack frame and where this process started its lifecycle.

[^1]: This can be conceptually seen as where the program made a function call.

Interpreting the meaning of a stackframe requires a bit of Go's runtime knowledge. In the case that a process is waiting or polling on a resource (this would often be the case because short lived process where this does not happen will likely not have any meaningful wall time and are finished quickly) would be represented by the deepeste entry being a `runtime.xxx` function, this simply tells what it currently is doing but not how it got to that point, for that you need to search for the outer entry that starts with `forgejo.org/`.

This type of diagnosis can be helpful if there are many requests that are not being processed quickly enough. By searching for the corresponding URL path on the "Running processes" page, you can find the process that is responsible for processing this particular HTTP request. However, this is only possible with a bit of luck if the monitoring page is loaded in the time period when the actual problem is blocking the process, otherwise the stacktrace would be meaningless to determine the problem. Git processes are shown to be blocked on a syscall function, which is entirely correct and expected as the syscall invokes the Git binary and logically Forgejo cannot show what Git is doing and provide a stacktrace of it, some Git processes (notably `cat-file --batch` and `cat-file --batch-check`) are _long-lived_ Git processes, which are kept open (on-demand) in case another call has to be made to one of these two processes within the processing of the same HTTP request and thus the blocking is correct in the case of a syscall and it should rather be checked why the associated HTTP request takes a long time as they are closed after the handling HTTP request is finished.

## Memory profiling

Before starting a memory profiling it is good to know what the **actual** memory usage of Forgejo is. Using `top` and similar tools might give a unrealistic picture, because of [how unused memory](https://www.linuxatemyram.com/) by applications is represented by Linux and other operating systems. Go's runtime keep track of [a lot of](https://pkg.go.dev/runtime#MemStats) memory statistics which can give a precise and up to date picture[^3] of the memory usage of Forgejo.

[^3]: These memory statistics are not collected during garbage collection, but are instead calculated or fetched on demand, see documentation of [runtime.ReadMemStats](https://pkg.go.dev/runtime#ReadMemStats).

These numbers are displayed on the Admin Dashboard in the “System Status” section. Simply navigate to “Admin Configuration”; the dashboard is the default page. Note that this section is updated live and therefore the numbers will change as you view the page. The **Current memory usage** is the most important value, this is the heap memory currently used by Forgejo, although it is somewhat skewed as it only shrinks when a garbage collection cycle occurs, but this represents the memory used which is lower than the memory obtained/allocated for Forgejo as per the OS, that value is an implementation detail of Go's runtime and cannot be influenced by Forgejo.

There are other values that you should pay attention to. If a lot of memory has been allocated in a short period of time, the **Total memory allocated** value will rise steeply. Another value to watch out for is related to Go's garbage collection. Although it is fast, the application must be stopped[^4], which means that the entire execution is paused and only Go's garbage collector is running. The total time of the so-called stop-the-world pause is displayed in **Total GC pause**, this is heavily influenced by the number of garbage collections since startup, which is the **GC times** value, this is best kept low and the time between garbage collections as high as possible, a lot of garbage collections usually indicates that a lot of memory is allocated and also released immediately, then the memory allocation itself can become a CPU time bottleneck.

[^4]: For exact details of Go's garbage collector stop-the-world pause we refer to [the official documentation](https://tip.golang.org/doc/gc-guide#Latency).

You can download the heap profile from Forgejo on the stacktrace page in the admin configuration page. It is recommended to set the seconds to zero as this is not relevant for memory profiling. The output is a file named `forgejo-diagnosis-xxx.zip`, in this zip file there is a `heap.dat` file which is relevant for memory profiling. This file does not contain the actual heap, but only information that is relevant for analyzing memory usage. Forgejo enforces garbage collection before taking a snapshot of the heap, this prevents the heap from containing memory that is no longer used.

### pprof tool

Go provides tooling to analyze the `heap.dat` file, make sure to have this file extracted and then execute `go tool pprof heap.dat` in a terminal in the directory that contains the `heap.dat` file. Another complete example of how to make use of this tooling is also [provided by a Go article](https://go.dev/blog/pprof), but to also re-iterate the most important ways to analyze:

- `topN`: Replace `N` with any number and it will display the top `N` functions that have allocated the most memory. It is important to note that this sorts by the `flat%` and not the `cum%` value, `flat%` is just the amount of memory the function itself has allocated, if the function has called another function its memory usage would be included in the `cum%` value.
- `web`: Opens up a visual goldmine to show which function uses how much memory and which functions called those functions. A good way to learn how a function was called. This does not show individual calls to function, for that the `traces <regex>` (works similar to the `list` option) can be used.
- `list <regex>`: Replace `<regex>` with a function name or a file name (case sensitive) and it will show exactly which line of source code was responsible for which amount of memory. Note that this requires the source code of Forgejo on a specific path (mainly the path where the Forgejo binary was built), so this option is usually only possible if Forgejo was built from source.

To take an example of how to effectively memory profile, in Forgejo a lot of regexps are compiled on startup and that means that they will show up in the heap, but e.g. via `topN` it will only show that `regexp.makeOnePass` and `regexp/syntax.(*compiler).inst` allocated memory and it does not show which regexps are actually taking the most memory (and how much). First we can consult the visualization of traces with `web`, we find `regexp.Compile` (this is where a bit of Go knowledges comes in handy to know what the main entry to compiling regexp is which would ultimately called by Forgejo) and in this case it's possible that only two traces are shown, one from the inserting routes in `go-chi` package and one `data.init` via `MustCompile`. For simplicity we will explore the `go-chi` trace. Executing `traces InsertRoute` shows indeed some traces to `regexp.Compile` and they actually come from the `addChild` function. You either can search this function on Github or use `list addChild` and see the following:

```go
.          .    253:           if segTyp == ntRegexp {
.        1MB    254:                   rex, err := regexp.Compile(segRexpat)
.          .    255:                   if err != nil {
.          .    256:                           panic(fmt.Sprintf("chi: invalid regexp pattern '%s' in route param", segRexpat))
.          .    257:                   }
.          .    258:                   child.prefix = segRexpat
.          .    259:                   child.rex = rex
.          .    260:           }
```

There's indeed a call to regexp compile when the route path contains regexp (that's important information to understand _why_ it was allocated in the first place and what the precondition for it is). To find out which routes these are we go back to the output of `traces addChild` and follow the trace back to code in Forgejo. One trace comes from Git HTTP route and another from the API. Now to actually find the exact line in the API and Git HTTP file you can execute `granularity=lines` and then execute `traces addChild` again. This leads to finding [`routers/web/githttp.go:39`](https://codeberg.org/forgejo/forgejo/src/commit/b54424316410803da5d67fe7315ee931b1c84035/routers/web/githttp.go#L39) and [`routers/api/v1/api.go:1262`](https://codeberg.org/forgejo/forgejo/src/commit/b54424316410803da5d67fe7315ee931b1c84035/routers/api/v1/api.go#L1262). According to the Go's memory profile the regexp created for these two routes are combined 1MB. If we want to avoid this allocation we understand now that the route must no longer be a regexp or a regexp that requires less allocated memory.[^5] As noted before, the heap profile does not contain the actual heap and thus it's not possible determine what the content of the heap was and analyze what was contained in the 1MB regexp objects.

[^5]: This approach involves also understanding the source code and behavior of another library to verify if this is possible and for this example understand why these two particular regexp routes allocated more memory than other regexp routes.

## Performance profiling

When talking about profiling, it usually refers to performance profiling or, more precisely, profiling where the CPU is spending time in a time period. It should be noted that if profiling is done on a production instance, you will have no indication of which particular request or task contributed to the CPU time of a particular function; it's merely a sum of the time being spent in a function. If that information is needed, [tracing](#bkmrk-tracing) should be used.

You can download the CPU profile from Forgejo on the stacktrace page in the admin configuration page. The seconds value is important here; it specifies the time period for which you want to collect a CPU profile, and this value should be chosen somewhat carefully to avoid having too much data; keep it as low as possible. After having the `forgejo-diagnosis-xxx.zip` file, extract the `cpu-profile.dat` file. You can continue with the explanation of how to use the pprof tool from [the section in memory profiling](#bkmrk-pprof-tool); it is largely the same, but now instead of memory, the CPU time is being analyzed.

Although Go provides a CPU profiler that is offered by Forgejo, in certain scenarios using a wall-clock profiler might give better results, where I/O and CPU time are mixed into one profile. Forgejo uses [felixge/fgprof](https://github.com/felixge/fgprof) to provide that. This profile is not available by default in the `forgejo-diagnosis-xxx.zip` file; it can only be retrieved by enabling it in the config `[server].ENABLE_PPROF = true` and then downloading `http://localhost:6060/debug/fgprof?seconds=5`. This must be fetched on the same machine where the Forgejo instance is running.

The results from fgprof are quite a lot and hard to take in, and using the filtering capabilities of pprof is a necessity. Forgejo has many long-lived background goroutines that are all sleeping and spending zero CPU time, which means they will show that they are spending **all** their time in `runtime.gopark`, which simply means the goroutine is sleeping and not active. This also usually means it doesn't actually take up an OS thread.[^6] Therefore you should usually start with Go's provided CPU profile and only revert to this profile if you suspect slowdowns related to I/O events. Also, by using Go's provided CPU profile, you have a way better picture of the functions that are being called, which can be used for filtering out unrelated functions in the fgprof profile.

[^6]: This has to do with the fact that goroutines are lightweight threads; if one goroutine is sleeping, it no longer takes up a thread, and another goroutine can take (now or in the future) up that thread.

When trying to optimize a function or procedure for performance, remember that optimization should be limited to what you can measure in order to avoid the root of all evil: premature optimization.[^7] This can be done by creating a [benchmark function](https://pkg.go.dev/testing#hdr-Benchmarks) in the Forgejo codebase, which allows CPU profiling over this specific function and avoids any other disturbance; additionally, use [benchstat](https://pkg.go.dev/golang.org/x/perf/cmd/benchstat) to compare results between benchmark runs.

[^7]: A infamous quote by [Donald Knuth](https://en.wikipedia.org/wiki/Donald_Knuth) in [Computer Programming as an Art (1974)](https://doi.org/10.1145/361604.361612) on page 671.

## Tracing

To be upfront, this type of profiling is quite powerful and gives you a lot of data in return, but is hard to understand and can be confusing to follow what the output is actually saying, it also requires an intermediate understanding of Go's runtime and Forgejo internals. The tracing implemented in Go is an execution tracer and precisely traces the execution of tasks; these tasks can be SQL queries, HTTP requests, or a queue handler, for example. It therefore can exactly tell you where a specific task was spending its time.

Similar to the CPU profile, to download the tracing profile from Forgejo, go to the stack trace page in the admin configuration page. The seconds specify for how long you want to do tracing; existing processes that were not created after the tracing started will also be included in the tracing but will contain skewed results as they are being traced somewhere in the middle of their task. After having the `forgejo-diagnosis-xxx.zip` file, extract the `tracing.dat` file.

There are two tools to analyze the tracing results, Go's native tooling that uses [Catapult](https://chromium.googlesource.com/catapult) or the more modern alternative [gotraceui](https://github.com/dominikh/gotraceui)[^8]. For now, we will stick with Go's native tools to explain the essentials of analyzing tracing results.

[^8]: You have to build this from source and apply [this patch](https://github.com/dominikh/gotraceui/pull/166).

Execute `go tool trace trace.dat` after loading the file, it will open a web UI, which is the main interface for analyzing trace results. There are many options to choose from, although only one is really of interest for Forgejo traces: "User-defined tasks" in the "User-defined tasks and regions" section allows you to see all the individual traces categorized by the task of the trace; you should primarily look here to find a trace such as an HTTP request. It also allows you to quickly find slow traces in a particular categorization. For HTTP requests you should avoid taking into account `GET /user/events`; this is a long-lived request that is kept open between navigating the Forgejo UI. Each task logs the main purpose of that task; for HTTP requests, it logs the method and request URI, and SQL logs the SQL query and its arguments. To see what the task actually executed, you can click on "Goroutine overview"; this opens the trace viewer for that task.

In the trace viewer there are a few sections; only "Tasks" and "G" are really of interest. The tasks show the SQL and Git operations that were done; some Git tasks are long-lived, which means they are reused later on without needing to invoke a Git command again. Unfortunately, it is not possible to quickly see what the purpose of the task is; the logging information is not available in the trace view. It is, however, possible to deduce this partially from the stack trace that is shown after clicking on the task. In the "G" section, "goroutines are shown, and it shows what the goroutine(s) that were associated with this task were doing; this can conceptually be seen as where CPU time was spent in the goroutine and thus gives a detailed breakdown of the execution of a particular trace. Some functions have a relatively low amount of CPU time; it's therefore recommended to make liberal use of the zoom tool (press 3) to zoom into the timescale to see in greater detail the functions that were called; to move around the timescale, press 2.