prologue
prologue copied to clipboard
planety
--gc:orc --threads:on slower than --threads:off
Firstly: Thank you for working on this project. It is a wonderful framework to use, and I am using it in production, rather than Jester.
The issue: The bit of code below is slower with threads than without, when built using orc.
NOTE: The issue is also present when NOT using a {.threadvar.} although less pronounced than with {.threadvar.}.
resp htmlResponse("<h2>Welcome to Prologue</h2>"):
Non-threadvar single-thread: 28970 req/s
Non-threadvar multi-thread: 16319 req/s (1.7x slower)
threadvar single-thread: 22371 req/s threadvar multi-thread: 6406 req/s (3.49x slower)
Nim version (latest devel)
nim --version
Nim Compiler Version 1.5.1 [Linux: amd64]
Compiled at 2020-10-16
Copyright (c) 2006-2020 by Andreas Rumpf
git hash: 6b8baab536d25c744150e0190d2e172165faf92e
active boot switches: -d:release
system info:
OS: Arch Linux
Kernel: x86_64 Linux 5.8.8-arch1-1
CPU: Intel Core i5-6200U @ 4x 2.8GHz [41.0°C]
GPU: Intel Corporation Skylake GT2 [HD Graphics 520] (rev 07)
RAM: 5680MiB / 15739MiB
Testing with wrk -t2 -c100 -d10s http://localhost:8000
Using --gc:orc (multi-threaded has lower throughput)
nim c -r -d:danger -d:release --opt:speed --gc:orc main
Running 10s test @ http://localhost:8000
2 threads and 100 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 4.93ms 3.56ms 85.98ms 82.41%
Req/Sec 11.27k 0.93k 13.46k 76.50%
224424 requests in 10.03s, 104.45MB read
Requests/sec: 22371.13
Transfer/sec: 10.41MB
nim c -r -d:danger -d:release --opt:speed --gc:orc --threads:on main
Running 10s test @ http://localhost:8000
2 threads and 100 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 17.24ms 12.43ms 110.90ms 87.82%
Req/Sec 3.23k 413.09 4.39k 81.50%
64325 requests in 10.04s, 29.94MB read
Requests/sec: 6406.63
Transfer/sec: 2.98MB
Using --gc:markAndSweep (multi-threaded has more throughput as expected)
nim c -r -d:danger -d:release --opt:speed --gc:markAndSweep main
Running 10s test @ http://localhost:8000
2 threads and 100 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 3.59ms 1.89ms 101.07ms 98.98%
Req/Sec 14.21k 1.29k 15.80k 94.50%
282931 requests in 10.03s, 131.67MB read
Requests/sec: 28206.92
Transfer/sec: 13.13MB
nim c -r -d:danger -d:release --opt:speed --gc:markAndSweep --threads:on main
Running 10s test @ http://localhost:8000
2 threads and 100 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 2.12ms 1.75ms 23.15ms 90.73%
Req/Sec 26.01k 1.72k 29.89k 68.50%
517948 requests in 10.04s, 241.05MB read
Requests/sec: 51598.09
Transfer/sec: 24.01MB
Example code:
import prologue
import nwt
let settings = newSettings(
address="0.0.0.0",
debug=false,
port=Port(8000),
staticDirs=["/static"],
)
var app = newApp(settings=settings)
## Set up threadvar for `templates` for per thread initialization.
var templates {.threadvar.} : Nwt
proc initTemplates() =
if templates.isNil:
templates = newNwt("templates/*.html")
proc index(ctx: Context) {.gcsafe, async.} =
initTemplates()
resp templates.renderTemplate("index.html")
app.addRoute("/", index)
app.run()
Thanks for choosing Prologue famework :)
You should look at this issue: https://github.com/nim-lang/Nim/issues/14224. I guess ORC still needs improvement.
Did some testing of nimforum with ORC both single-threaded/multi-threaded. In single-threaded mode nimforum with ORC seems to leak ~3mb per 95k requests. In multi-threaded mode nimforum with ORC is ~3.5x SLOWER than single-threaded, and leaks orders > of magnitude more (~800MB RAM for 26k requests) - with other GCes like refc or markAndSweep > multi-threaded performance is of course much better than single-threaded. It really seems to me that httpbeast and ORC don't like each other at all
If you have any question, you could ask me in discord: https://discord.gg/e2dB4WT
Prologue will release 0.4.0 and contains many changes. For examples, static file serving will become middlewares.
import prologue
import prologue/middlewares/staticfile
import nwt
let settings = newSettings(
address="0.0.0.0",
debug=false,
port=Port(8000)
)
var app = newApp(settings=settings, middlewares = staticFileMiddleware(["/static"]))
# or
# var app = newApp(settings=settings)
# app.use(staticFileMiddleware(["/static"]))
## Set up threadvar for `templates` for per thread initialization.
var templates {.threadvar.} : Nwt
proc initTemplates() =
if templates.isNil:
templates = newNwt("templates/*.html")
proc index(ctx: Context) {.gcsafe, async.} =
initTemplates()
resp templates.renderTemplate("index.html")
app.addRoute("/", index)
app.run()
Btw, user can extend their own Context in 0.4.0. But I'm still thinking about a better way. https://gist.github.com/xflywind/62ac7a29e40016261c2ff046791493ed
Thank you for the reply. Good information to know! And thanks for the Discord invitation (I joined it immediately).
The user defined context extension reminds me of Python decorators. Very cool.
While we're talking about middlewares, is there a possible way of using a library that doesn't support threading inherently (say anonimongo) with prologue, in threaded mode, by perhaps making use of the middleware functionality, or some other trickery?
I don't think so. The library must be thread-safe to be used with Prologue.
Alright. I had started putting this together when I saw your reply in Discord.
This is scaled down and changed from some production code, to use {.threadvar.} and thread-local initialization procs.
import os
import re
import json
import times
import strformat
import strutils
import parsecfg
import sequtils
import algorithm
import logging
import asyncdispatch
import timeit
import oids
import anonimongo
import anonimongo/core/bson
import prologue
import nwt
import ./helpers
#[ Logging ~ ]#
var
logFmtStr = "$levelname [$date @ $time]: "
consoleLog = newConsoleLogger(fmtStr=logFmtStr)
logLevel : logging.Level
logging.addHandler(consoleLog)
when defined(debug) or defined(test):
logLevel = logging.lvlDebug
when defined prod:
logLevel = logging.lvlError
#[ Logging ~ ]#
#[ Config ~ ]#
var
configFileName {.threadvar.} : string
cfg {.threadvar.} : <//>Config
# MongoDB
mongoConnString {.threadvar.} : string
# WebService
port {.threadvar.} : Port
debug {.threadvar.} : bool
appName {.threadvar.} : string
staticDirs {.threadvar.} : string
secretKey {.threadvar.} : string
proc initConfig() =
if cfg.isNil:
when defined(production) or defined(prod):
let configFileName = "config.ini"
else:
let configFileName = "configTest.ini"
cfg = loadConfig(configFileName)
# MongoDB
mongoConnString = cfg.getSectionValue("MongoDB", "connString")
# WebService
port = parseInt(cfg.getSectionValue("WebService", "port")).Port
debug = parseBool(cfg.getSectionValue("WebService", "debug"))
appName = cfg.getSectionValue("WebService", "appName")
staticDirs = cfg.getSectionValue("WebService", "staticDirs")
secretKey = cfg.getSectionValue("WebService", "secretKey")
# init config so main thread will have web service params
initConfig()
#[ ~ Config ]#
#[ MongoDB ~ ]#
var
mongo {.threadvar.} : Mongo
db {.threadvar.} : Database
collTest {.threadvar.} : Collection
proc initMongo() =
initConfig()
if mongo.isNil:
mongo = newMongo()
mongo = newMongo(MongoUri(mongoConnString))
if not waitfor mongo.connect:
logging.fatal "MongoDB: Cannot connect to domain-host"
quit 1
else:
logging.info "MongoDB: Connected!"
if not waitfor mongo.authenticate[:Sha256Digest]():
logging.warn "MongoDB: Could not authenticate with SHA256. Trying SHA1. You should really update MongoDB!"
if not waitfor mongo.authenticate[:SHA1Digest]():
logging.fatal "Cannot login to domain-host"
quit 1
else:
logging.info "MongoDB: Authenticated with SHA1. This is not secure."
else:
logging.info "MongoDB: Authenticated with SHA256!"
db = mongo["LamiNation"]
collTest = db["query"]
#[ ~ MongoDB ]#
proc jsonResponse*(s: string, code = Http200, headers = newHttpHeaders(),
version = HttpVer11): Response {.inline.} =
headers["Content-Type"] = "application/json"
result = initResponse(version, code, headers, body = s)
#[ Routes ~ ]#
let
settings = newSettings(
appName = appName,
debug = debug,
port = port,
staticDirs = [staticDirs],
secretKey = secretKey
)
proc queryDB(ctx: Context) {.gcsafe, async.} =
initMongo()
let pipeline = @[
bson({
"$match":
{ active: true }
}),
bson({
"$project": {
"id": {
"$toString": "$_id"
},
"_id": 0,
"URI": 1,
"active": 1,
"bgImageURI": 1,
"bgPosition": 1,
"bgSize": 1,
"hasButton": 1,
"buttonColor": 1,
"buttonText": 1,
"buttonTextColor": 1,
"buttonWidth": 1,
"displayTime": 1,
"hasHeadline": 1,
"headlineText": 1,
"headlineTextColor": 1
}
})
]
let query = await collTest.aggregate(pipeline)
resp jsonResonse ($query).strip(chars={'@'}, leading=true)
#[ ~ Routes ]#
var app = newApp(settings = settings)
if debug or logLevel == logging.lvlDebug:
logLevel = lvlDebug
else:
logLevel = lvlInfo
setLogFilter(logLevel)
app.addRoute("/queryDB", queryDB, @[HttpGet, HttpPost])
app.run()
I would run your performance test against https://github.com/nim-lang/Nim/pull/15588 and see if the results differ.
I was excited there for a second, but sadly the issue persists.
$ choosenim update self
$ choosenim update devel
Updating devel
Downloading Nim 2020-10-19-devel-78cbb52fa01d6c73307fe276bdf7d4c34d7a556c-2 from GitHub
[##################################################] 100.0% 0kb/s
Extracting nim-1.5.1-2-linux_x64.tar.xz
Setting up git repository
Building Nim #devel
Compiler: Already built
Tools: Already built
Updated to #devel
Info: Version #devel already selected
$ nim --version
Nim Compiler Version 1.5.1 [Linux: amd64]
Compiled at 2020-10-19
Copyright (c) 2006-2020 by Andreas Rumpf
git hash: 78cbb52fa01d6c73307fe276bdf7d4c34d7a556c
active boot switches: -d:release
nim c -r -d:danger -d:release --opt:speed --gc:orc main
Running 10s test @ http://localhost:8000
2 threads and 100 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 5.21ms 3.72ms 70.41ms 80.02%
Req/Sec 10.72k 0.91k 12.38k 81.50%
213441 requests in 10.04s, 99.33MB read
Requests/sec: 21254.98
Transfer/sec: 9.89MB
nim c -r -d:danger -d:release --opt:speed --gc:orc --threads:on main
Running 10s test @ http://localhost:8000
2 threads and 100 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 17.02ms 11.34ms 89.19ms 87.47%
Req/Sec 3.22k 365.96 4.37k 79.00%
64041 requests in 10.04s, 29.80MB read
Requests/sec: 6380.90
Transfer/sec: 2.97MB
Even tried with the following, thinking maybe the nightly didn't have the change yet.
choosenim update devel --latest
nim --version
Nim Compiler Version 1.5.1 [Linux: amd64]
Compiled at 2020-10-19
Copyright (c) 2006-2020 by Andreas Rumpf
git hash: 833035bacd91c2cf16ea006b64bf996e87eac75d
active boot switches: -d:release
Same disparity in r/s
Okay, thanks for testing it. Do we have a compiler issue for this? If not, please create an issue specifically for this performance problem. I'm assuming that the first code snippet is a reliable reproduction; that's correct, right? We don't need the mongo version?
For sure.
I'm not sure whether an issue similar to this exists on the compiler repo. The initial snippet is all that is required to reproduce. No need for Mongo code.
How should I go about opening the issue on the Nim repo? just mention it and cross reference this one? Or should I copy the whole example and also link to this thread?
@RecruitMain707 See the full OP. markAndSweep is quite a bit faster with threads than without. This is an arc/orc issue as confirmed by disruptek.