The mystery of the fifteen-millisecond breakpoint instruction • Hacker News Board

Re: The mystery of the fifteen-millisecond breakpoint instruction

#31

Post by tonyg » Sat, Sep 05, 2015, 4:19 PM UTC

TheLoneWolfling wrote: post #30

a1k0n wrote: post #29

Earlier quoted context omitted.

My theory is that it's also being written to the RPi's serial port console, which runs at 115200 baud by default, so 11520 characters/second or ~7ms to write 80 characters.

Good theory. Alas, the author mentioned it took ~ 1 ms, which would be ~11.5 characters, and those log messages are a lot longer than 11.5 characters.

If I understood the article correctly, the ~1ms cost came from having rsyslog running, not from printk. Killing rsyslog led to a ~1ms speedup, but it was removing printk() that led to the rest.

Printing to the console on the RPi could involve either or both of the serial port and the software-character-generator-based text-mode video output. Depending on screen resolution, the video output might be quite slow to print to, especially if it had to scroll a line, depending on exactly how it's implemented.

Re: The mystery of the fifteen-millisecond breakpoint instruction

#32

Post by TheLoneWolfling » Sat, Sep 05, 2015, 4:29 PM UTC

tonyg wrote: post #31

TheLoneWolfling wrote: post #30

Earlier quoted context omitted.

Good theory. Alas, the author mentioned it took ~ 1 ms, which would be ~11.5 characters, and those log messages are a lot longer than 11.5 characters.

If I understood the article correctly, the ~1ms cost came from having rsyslog running, not from printk. Killing rsyslog led to a ~1ms speedup, but it was removing printk() that led to the rest. Printing to the console on the RPi could involve either or both of the serial port and the software-character-generator-based text-mode video output. Depending on screen resolution, the video output might be quite slow to prin…

In which case, what on Earth is rsyslog doing that it takes 1ms to append a line of text to the log file?

I could see it if it was outputting something to software-based video - except that in that case, why is it trying to output to software-based video?

Re: The mystery of the fifteen-millisecond breakpoint instruction

#33

Post by JoachimSchipper » Sat, Sep 05, 2015, 5:37 PM UTC

TheLoneWolfling wrote: post #32

tonyg wrote: post #31

Earlier quoted context omitted.

If I understood the article correctly, the ~1ms cost came from having rsyslog running, not from printk. Killing rsyslog led to a ~1ms speedup, but it was removing printk() that led to the rest. Printing to the console on the RPi could involve either or both of the serial port and the software-character-generator-based text-mode video output. Depending on screen resolution, the video output might be quite slow to prin…

In which case, what on Earth is rsyslog doing that it takes 1ms to append a line of text to the log file? I could see it if it was outputting something to software-based video - except that in that case, why is it trying to output to software-based video?

You need quite a few kerneluserland switches in this case, maybe that's enough?

Re: The mystery of the fifteen-millisecond breakpoint instruction

#34

Post by salgernon » Sat, Sep 05, 2015, 5:49 PM UTC

TheLoneWolfling wrote: post #26

tjoff wrote: post #22

Earlier quoted context omitted.

This is much closer to random access than sequential access. Counter question: How is appending to a log file repeatedly sequential access? No meta data or other interaction required? Surely the sequential writes benefit from larger buffers? Not to mention that the flash block is way larger than the appended message. You would need TRIM to not make that an extremely wasteful operation, not sure if the typical Pi inst…

This is where you benefit by having a file system (or disk controller) that isn't brain-dead. Unfortunately, it seems like both the controller and file system are brain-dead on the RPi. Namely, you have a cache that detects this sort of (relatively-common) append-only operation, and buffers it until it makes sense to actually write it (either because the disk is otherwise unoccupied or because you are close to the li…

The sole purpose of the pi is not to write kernel log files. I'm sure if you want to build a piece of hardware / software kit that did nothing but write sequentially to a flash drive, that'd be blazingly fast.

But if you want log rolling, filtered output, serial output, non-flash file systems (nfs, etc) and a general purpose computing device where printk is the rarest of rare events (in the lifetime of a task) then you're going to lose some of your optimizations.

Re: The mystery of the fifteen-millisecond breakpoint instruction

#35

Post by TheLoneWolfling » Sat, Sep 05, 2015, 5:53 PM UTC

JoachimSchipper wrote: post #33

TheLoneWolfling wrote: post #32

Earlier quoted context omitted.

In which case, what on Earth is rsyslog doing that it takes 1ms to append a line of text to the log file? I could see it if it was outputting something to software-based video - except that in that case, why is it trying to output to software-based video?

You need quite a few kernel userland switches in this case, maybe that's enough?

Potentially, although in that case it's still dsyslog's fault.

Re: The mystery of the fifteen-millisecond breakpoint instruction

#36

Post by TheLoneWolfling » Sat, Sep 05, 2015, 5:55 PM UTC

salgernon wrote: post #34

TheLoneWolfling wrote: post #26

Earlier quoted context omitted.

This is where you benefit by having a file system (or disk controller) that isn't brain-dead. Unfortunately, it seems like both the controller and file system are brain-dead on the RPi. Namely, you have a cache that detects this sort of (relatively-common) append-only operation, and buffers it until it makes sense to actually write it (either because the disk is otherwise unoccupied or because you are close to the li…

The sole purpose of the pi is not to write kernel log files. I'm sure if you want to build a piece of hardware / software kit that did nothing but write sequentially to a flash drive, that'd be blazingly fast. But if you want log rolling, filtered output, serial output, non-flash file systems (nfs, etc) and a general purpose computing device where printk is the rarest of rare events (in the lifetime of a task) then y…

Nevertheless, writing (essentially) append-only files is something that happens often enough that most filesystems should cope with reasonably well. And writing 20x slower than it could is nowhere near coping reasonably well.

(Also: note that you don't need to cope with nfs/etc. Flash is different enough from spinning rust that I have no problem with a filesystem being optimized for one or the other as opposed to both.)

Re: The mystery of the fifteen-millisecond breakpoint instruction

#37

Post by revelation » Sat, Sep 05, 2015, 6:01 PM UTC

derf_ wrote: post #25

evmar wrote: post #24

He wrote: > Think about the common debugging scenario where the user sets a conditional breakpoint: "break if x > y". Testing that condition is going to take 15ms each time. Wouldn't the implementation of a software breakpoint look like: if x > y: bkpt so it'd only be slow on the case where it needed to break? I guess I can imagine you could implement it the other way (always break, check the condition after breaking…

I don't know what gdb does, but even on x86 a conditional breakpoint can be ridiculously slow. On a loop that executes a few hundred thousand times before meeting the condition, it can take minutes to evaluate something that executed instantly before. I often go back, edit the code to add something like if (condition) { foo = foo; } recompile, restart the debugger, and break on the foo = foo line. Even with all of th…

For next time, Windows has the DebugBreak function which will stop the program and (if you have a debugger attached) act the same way as stopping on that line.

On Linux, I've seen some people use asm("int 3") (which is what a debugger would use for software breakpoints).

Re: The mystery of the fifteen-millisecond breakpoint instruction

#38

Post by tjoff » Sat, Sep 05, 2015, 6:37 PM UTC

TheLoneWolfling wrote: post #36

salgernon wrote: post #34

Earlier quoted context omitted.

The sole purpose of the pi is not to write kernel log files. I'm sure if you want to build a piece of hardware / software kit that did nothing but write sequentially to a flash drive, that'd be blazingly fast. But if you want log rolling, filtered output, serial output, non-flash file systems (nfs, etc) and a general purpose computing device where printk is the rarest of rare events (in the lifetime of a task) then y…

Nevertheless, writing (essentially) append-only files is something that happens often enough that most filesystems should cope with reasonably well. And writing 20x slower than it could is nowhere near coping reasonably well. (Also: note that you don't need to cope with nfs/etc. Flash is different enough from spinning rust that I have no problem with a filesystem being optimized for one or the other as opposed to bot…

I'm going to guess that the Pi uses ext3/4 which I'm assuming does pretty well with appending files on a spinning disk.

Yes, we need something tailored for flash and the advent of SSDs have put some effort into that. However, the controller of a SD-card is for understandable reasons not as advanced as one on an SSD. One of the issues that seemed prevalent of the Pi was that SD-cards, when issuing a TRIM command, just erases the flash - immediately. Which of course kind of defeats the purpose and leads to bad performance (trying to optimize for future writes by sacrificing current writes).

The recommendation that I saw was to schedule a pass clearing free space for when the Pi wasn't in active use.

Problem with the controller doing some of the stuff (which I guess is inevitable due to different design needs) and the file system doing some other stuff is that when the filesystem is paired with a bad controller (but one that still does some kind of wear leveling) you are kind of screwed anyway, because either implementation can not rely on the other. So, just use an SSD instead?

I guess it's worse on the Pi since it's somewhat trying to be a workstation on mobile hardware. And sometimes I get the impression that even phone makers can't tailor it well anyway (samsungs android filesystem for the older phones were apparently pretty awful for instance). And android only got TRIM support in, I believe, Kitkat? But only if the whole chain of device hardware and drivers supported it (so god knows which current devices actually support it)... Learning that was quite shocking to me and probably a large source of "my phone just keeps getting slower" problems. But who cares if it just accelerates sales of new phones?

Re: The mystery of the fifteen-millisecond breakpoint instruction

#39

Post by AceJohnny2 » Sat, Sep 05, 2015, 7:06 PM UTC

Very tangential to the topic at hand, it makes me happy to see a somewhat lucid comment on that article by Terry A Davis.

(For those who lack context, Davis is a brilliant but schizophrenic programmer who has some notoriety on HN: https://news.ycombinator.com/item?id=7818823 More info at http://motherboard.vice.com/read/gods-lonely-programmer )

Re: The mystery of the fifteen-millisecond breakpoint instruction

#40

Post by TheLoneWolfling » Sat, Sep 05, 2015, 7:10 PM UTC

tjoff wrote: post #38

TheLoneWolfling wrote: post #36

Earlier quoted context omitted.

Nevertheless, writing (essentially) append-only files is something that happens often enough that most filesystems should cope with reasonably well. And writing 20x slower than it could is nowhere near coping reasonably well. (Also: note that you don't need to cope with nfs/etc. Flash is different enough from spinning rust that I have no problem with a filesystem being optimized for one or the other as opposed to bot…

I'm going to guess that the Pi uses ext3/4 which I'm assuming does pretty well with appending files on a spinning disk. Yes, we need something tailored for flash and the advent of SSDs have put some effort into that. However, the controller of a SD-card is for understandable reasons not as advanced as one on an SSD. One of the issues that seemed prevalent of the Pi was that SD-cards, when issuing a TRIM command, just…

Or you have one filesystem that is geared towards dumb flash, and another that is geared towards smart flash.

I don't see why people try to design filesystems that do everything. As usual for hybrids, they try to do everything and as a result don't work well anywhere.

As long as you keep the limitations of dumb flash in mind (namely, that flipping bits in one direction is slow (things are a little more complex on MLC, but still doable)), it's surprisingly easy to design a filesystem that does well on "dumb" flash.