Skip to content

log,time: improve performance for writing a line to a log, add Time.format_rfc3339_micro/0 - #22662

Merged
spytheman merged 11 commits into
vlang:masterfrom
enghitalo:perf/log
Oct 27, 2024
Merged

spytheman merged 11 commits into
vlang:masterfrom
enghitalo:perf/log

Conversation

@enghitalo

@enghitalo enghitalo commented Oct 26, 2024 •

Copy link
Copy Markdown
Contributor

v wipe-cache && v -prod crun log_.v > lala.log

Before

max_iterations: 1000000
SPENT  354.390 ms in log.info
SPENT  354.037 ms in log.error
SPENT   40.974 ms in println

After

max_iterations: 1000000
SPENT  171.269 ms in log.info
SPENT  171.246 ms in log.error
SPENT   38.279 ms in println
import log
import benchmark

const max_iterations := 1000000

fn main() {
	println('max_iterations: $max_iterations')

 	mut l := log.Log{}
	l.set_level(.info)
	l.set_full_logpath('./info.log')

	mut b := benchmark.start()

	for i := 0; i < max_iterations; i++ {
		l.info('Hello, World!')
	}

	b.measure('log.info')

	for i := 0; i < max_iterations; i++ {
		l.error('Hello, World!')
	}

	b.measure('log.error')

	for i := 0; i < max_iterations; i++ {
		println('Hello, World!')
	}
	b.measure('println')
}

*Note: if I remove time related format from log module

max_iterations: 1000000
SPENT   36.868 ms in log.info
SPENT   37.979 ms in log.error
SPENT   47.548 ms in println

*Note2: This was just a quick tweak I discovered out of curiosity. I'm not interested in making any major improvements right now, but there are several other tweaks and tests, such as using safe-threads when have logpath defined to log without interfering with the application's performance, and reusing time variables in some cases and managing cache.

Huly®: V_0.6-21111

@enghitalo

enghitalo commented Oct 26, 2024 •

Copy link
Copy Markdown
Contributor Author

Write file in intervals should be good. like what happens here

pub fn (mut pv Picoev) serve() {
	spawn update_date_string(mut pv)

	for {
		pv.loop_once(1)
	}
}

// update_date updates the date field of the Picoev instance every second for HTTP headers
fn update_date_string(mut pv Picoev) {
	for {
		// get GMT (UTC) time for the HTTP Date header
		gmt := time.utc()
		pv.date = gmt.http_header_string()
		time.sleep(time.second)
	}
}

Comment thread vlib/log/log.v
@spytheman

Copy link
Copy Markdown
Contributor

Write file in intervals should be good. like what happens here

This is good for a web server, but not as a general default.

@spytheman spytheman changed the title perf: log log: improve performance for writing a line to the log Oct 26, 2024
@spytheman spytheman changed the title log: improve performance for writing a line to the log log: improve performance for writing a line to a log Oct 26, 2024
@spytheman spytheman changed the title log: improve performance for writing a line to a log log,time: improve performance for writing a line to a log, add Time.format_rfc3339_micro/0 Oct 27, 2024
@spytheman

Copy link
Copy Markdown
Contributor

With the latest changes, on my machine:
image

@spytheman

Copy link
Copy Markdown
Contributor

The musl CI jobs are failing due to an unrelated problem, that is fixed in #22667 .

@spytheman
spytheman merged commit d7d88b9 into vlang:master Oct 27, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants