<commit_before>---
layout: post
title: "Django Performance: POSTGIS_VERSION"
date: 2015-05-21
tag: [django, performance, postgis, geodjango]
twitter: starefossen
published: true
facts:
  - title: Norwegian Trekking Association (DNT)
    facts:
      - Norway's largest outdoor life organization.
      - 250.000 members across 57 local member organisations.
      - Maintain a network of 20,000 km marked foot trails and 7000 km of
        branch-marked ski tracks.
      - DNT activities are based on extensive volunteer work spanning more
        than 175,000 work hours each year.
    source: dnt.no
  - title: Django
    facts:
      - Free and open source web application framework, written in Python.
      - Emphasizes reusability and "pluggability" of components, rapid
        development, and the principle of don't repeat yourself.
      - Initial release July 21th 2005.
      - Maintained by the Django Software Foundation (DSF).
    source: djangoproject.com
---

This is the first post in a series of posts about boosting performance in the
main Django application for the [Norwegian Trekking
Association](http://english.turistforeningen.no) (DNT).  The application is
scheduled to serve all of DNTs 200+ official web sites with a total of 1.5
million monthly page views by the end of 2015.

<!--more-->

[Sherpa](https://github.com/turistforeningen/sherpa) is a fairly typical Django
application.  It uses Django 1.7 served through Gunicorn 1.8 via Nginx 1.9 using
memcachd 1.4 for caching and Postgres 9.3 with Postgis 2.1 as its main database.
I will try to get a another post out outlining the technical details of our
production setup soon.

## Step 1 - Gathering Data

We have been measuring the response time of some key pages through our Pingdom
monitoring checks for years, and they all yielded the same average of 730ms
(originating from Europe since our servers are located in the eu-west-1 aws
region).

![Pre Response Time](/uploads/2015/05/21/response_pre.png "Pre Response Time")

Other than that we had fairly little data to work with so we decided to log all
Postgres queries longer than 300 ms over the weekend using the [
log\_min\_duration\_statement](http://www.postgresql.org/docs/current/static/runtime-config-logging.html#GUC-LOG-STATEMENT)
method as suggested in [this Postgres wiki
page](https://wiki.postgresql.org/wiki/Logging_Difficult_Queries) on logging
difficult queries.

## Step 2 - Analyze

When we returned to work next Monday we had 10 GB of query logs to sift through
😥.  [Postgres System Impact report (pgsi)](https://bucardo.org/wiki/Pgsi) to the
rescue!

```
perl pgsi.pl --file=postgresql-head.log > pg_analyze.html
```

Now we had a nicely formatted html page with all the different queries ordered
by type (SELECT, INSERT, UPDATE, etc) and system impact.  The first entry
immediately stood out as a big surprise! 😮

```
System Impact:    3.43
Mean Duration:    9.69 ms
Median Duration:  5.34 ms
Total Count:      624439
Mean Interval:    282.11 ms
Std. Deviation:   208.81 ms

SELECT postgis_lib_version()
```
<commit_msg>The original log configuration did not work as intended<commit_after>---
layout: post
title: "Django Performance: POSTGIS_VERSION"
date: 2015-05-21
tag: [django, performance, postgis, geodjango]
twitter: starefossen
published: true
facts:
  - title: Norwegian Trekking Association (DNT)
    facts:
      - Norway's largest outdoor life organization.
      - 250.000 members across 57 local member organisations.
      - Maintain a network of 20,000 km marked foot trails and 7000 km of
        branch-marked ski tracks.
      - DNT activities are based on extensive volunteer work spanning more
        than 175,000 work hours each year.
    source: dnt.no
  - title: Django
    facts:
      - Free and open source web application framework, written in Python.
      - Emphasizes reusability and "pluggability" of components, rapid
        development, and the principle of don't repeat yourself.
      - Initial release July 21th 2005.
      - Maintained by the Django Software Foundation (DSF).
    source: djangoproject.com
---

This is the first post in a series of posts about boosting performance in the
main Django application for the [Norwegian Trekking
Association](http://english.turistforeningen.no) (DNT).  The application is
scheduled to serve all of DNTs 200+ official web sites with a total of 1.5
million monthly page views by the end of 2015.

<!--more-->

[Sherpa](https://github.com/turistforeningen/sherpa) is a fairly typical Django
application.  It uses Django 1.7 served through Gunicorn 1.8 via Nginx 1.9 using
memcachd 1.4 for caching and Postgres 9.3 with Postgis 2.1 as its main database.
I will try to get a another post out outlining the technical details of our
production setup soon.

## Step 1 - Gathering Data

We have been measuring the response time of some key pages through our Pingdom
monitoring checks for years, and they all yielded the same average of 730ms
(originating from Europe since our servers are located in the eu-west-1 aws
region).

![Pre Response Time](/uploads/2015/05/21/response_pre.png "Pre Response Time")

Other than that we had fairly little data to work with so we decided to log all
Postgres queries <del>longer than 300 ms</del> over the weekend using the [
log\_min\_duration\_statement](http://www.postgresql.org/docs/current/static/runtime-config-logging.html#GUC-LOG-STATEMENT)
method as suggested in [this Postgres wiki
page](https://wiki.postgresql.org/wiki/Logging_Difficult_Queries) on logging
difficult queries. **Update:** We later learned that our configuration was not
entirely correct, and subsequently *all* queries were logged. 😁  Oops!

## Step 2 - Analyze

When we returned to work next Monday we had 10 GB of query logs to sift through
😥.  [Postgres System Impact report (pgsi)](https://bucardo.org/wiki/Pgsi) to the
rescue!

```
perl pgsi.pl --file=postgresql-head.log > pg_analyze.html
```

Now we had a nicely formatted html page with all the different queries ordered
by type (SELECT, INSERT, UPDATE, etc) and system impact.  The first entry
immediately stood out as a big surprise! 😮

```
System Impact:    3.43
Mean Duration:    9.69 ms
Median Duration:  5.34 ms
Total Count:      624439
Mean Interval:    282.11 ms
Std. Deviation:   208.81 ms

SELECT postgis_lib_version()
```

{'fraction_non_alphanumeric': 0.07311692404664355, 'fraction_numerical': 0.032146233848093286, 'mean_word_length': 3.7471952131637996, 'pattern_counts': {'":': 0, '<': 7, '<?xml version=': 0, '>': 9, 'https://': 6, 'lorem ipsum': 0, 'www.': 2, 'xml': 0}, 'pii_count': 0, 'substrings_counts': 0, 'word_list_counts': {'cursed_substrings.json': 0, 'profanity_word_list.json': 0, 'sexual_word_list.json': 0, 'zh_pornsignals.json': 0}}
{'dir': 'git-commits-cleaned', 'id': '5827568', 'n_tokens_mistral': 2042, 'n_tokens_neox': 1795, 'n_words': 823}