On 12/12/2013 07:05 PM, Lennart Poettering wrote: > On Thu, 12.12.13 17:42, Karol Lewandowski (lmc...@gmail.com) wrote: > >>> Hmm, but this wouldn't be any different from old syslog, right? I mean, >>> old syslog also uses sendv() and recv() on AF_UNIX SOCK_DGRAM sockets... >> >> That's true, however, we aren't migrating from syslog, but from >> Android Logger. Android provides /dev/log_{main,radio,...} device >> nodes which are simple in-kernel circular buffers apps can write to at >> any time. This was invented when /dev/kmsg wasn't writable and serves >> more-or-less same purpose. >> >> From 2.6.29 it's in mailine kernel under >> drivers/staging/android/logger.c > > But if the the socket layer is really thaaaaat much slower than android > logging, then that's kinda sad, and the kernel socket stuff should > probably be fixed?
It's not that slower when we take throughput as only parameter: packet | | size [B] | Adnroid [kB] | DGRAM [kB] ---------+--------------+------------ 64 | 110640 | 84827 128 | 212602 | 166866 256 | 423880 | 328440 512 | 815094 | 644499 1024 | 1543326 | 1246914 2048 | 2751674 | 2359654 4096 | 2821260 | 4145395 However, if take context switches into account picture starts to look differently: | Android | DGRAM -----------------+-----------+-------------- context switches | 1818 | 580443 (involuntary + voluntary) | | system time | 149.97 | 118.62 [seconds] user time | 4.03 | 7.45 [secodns] (Columns contain cumulative data: client + server) Attached raw results and test program. >>>> This is why I decided to try to make logging completely async and see >>>> if/what changes. >>> >>> Well, if AF_UNIX is slow, then we really should try to fix that in the >>> kernel instead of bypassing it in userspace... Whether we rely on the >>> socket buffer of the AF_UNIX socket or put together our own buffer in >>> /dev/shm shouldn't be much of a difference if they both have the same >>> size and can take the same number of entries... >> >> I do agree. Truth is I have looked at linux/net/ code once but I >> didn't grok it well. I guess it's the time to take a second look. ;) > > Here's another option: extend journald to use kdbus as additional > transport. This is something we want to do anyway since the kdbus > transport will attach the metadata we need without race to each > packet. Given that kdbus ultimately is just a way to write into an > mmaped tmpfs that some other process owns this should not be much worse > than the android logger in performance. I doubt it would help as other side would still be woken up on _every_ message, right? Cheers, Karol
Client: /usr/bin/time --verbose ./logger-client ================================================ Average stats: packet size = Bytes/s 64 = 113295768 Bytes/s = 110640 kB/s 128 = 217704976 Bytes/s = 212602 kB/s 256 = 434053344 Bytes/s = 423880 kB/s 512 = 834656704 Bytes/s = 815094 kB/s 1024 = 1580365824 Bytes/s = 1543326 kB/s 2048 = 2817714432 Bytes/s = 2751674 kB/s 4096 = 2888970749 Bytes/s = 2821260 kB/s Command being timed: "./logger-client" User time (seconds): 2.20 System time (seconds): 74.80 Percent of CPU this job got: 100% Elapsed (wall clock) time (h:mm:ss or m:ss): 1:17.00 Average shared text size (kbytes): 0 Average unshared data size (kbytes): 0 Average stack size (kbytes): 0 Average total size (kbytes): 0 Maximum resident set size (kbytes): 624 Average resident set size (kbytes): 0 Major (requiring I/O) page faults: 0 Minor (reclaiming a frame) page faults: 204 Voluntary context switches: 1064 Involuntary context switches: 368 Swaps: 0 File system inputs: 0 File system outputs: 0 Socket messages sent: 0 Socket messages received: 0 Signals delivered: 0 Page size (bytes): 4096 Exit status: 0 Server: /usr/bin/time --verbose ./logger-server ================================================ Command being timed: "./logger-server" User time (seconds): 1.83 System time (seconds): 75.17 Percent of CPU this job got: 30% Elapsed (wall clock) time (h:mm:ss or m:ss): 4:08.72 Average shared text size (kbytes): 0 Average unshared data size (kbytes): 0 Average stack size (kbytes): 0 Average total size (kbytes): 0 Maximum resident set size (kbytes): 480 Average resident set size (kbytes): 0 Major (requiring I/O) page faults: 0 Minor (reclaiming a frame) page faults: 167 Voluntary context switches: 242 Involuntary context switches: 144 Swaps: 0 File system inputs: 0 File system outputs: 0 Socket messages sent: 0 Socket messages received: 0 Signals delivered: 0 Page size (bytes): 4096 Exit status: 0
Client: /usr/bin/time --verbose ./sock-client ============================================== Average stats: packet size = Bytes/s 64 = 86863584 Bytes/s = 84827 kB/s 128 = 170870896 Bytes/s = 166866 kB/s 256 = 336323520 Bytes/s = 328440 kB/s 512 = 659967424 Bytes/s = 644499 kB/s 1024 = 1276840448 Bytes/s = 1246914 kB/s 2048 = 2416285952 Bytes/s = 2359654 kB/s 4096 = 4244884480 Bytes/s = 4145395 kB/s Command being timed: "./sock-client" User time (seconds): 2.14 System time (seconds): 46.97 Percent of CPU this job got: 63% Elapsed (wall clock) time (h:mm:ss or m:ss): 1:17.00 Average shared text size (kbytes): 0 Average unshared data size (kbytes): 0 Average stack size (kbytes): 0 Average total size (kbytes): 0 Maximum resident set size (kbytes): 636 Average resident set size (kbytes): 0 Major (requiring I/O) page faults: 0 Minor (reclaiming a frame) page faults: 207 Voluntary context switches: 577696 Involuntary context switches: 633 Swaps: 0 File system inputs: 0 File system outputs: 0 Socket messages sent: 0 Socket messages received: 0 Signals delivered: 0 Page size (bytes): 4096 Exit status: 0 Server: /usr/bin/time --verbose ./sock-server ============================================== Command being timed: "./sock-server" User time (seconds): 5.31 System time (seconds): 71.65 Percent of CPU this job got: 84% Elapsed (wall clock) time (h:mm:ss or m:ss): 1:31.51 Average shared text size (kbytes): 0 Average unshared data size (kbytes): 0 Average stack size (kbytes): 0 Average total size (kbytes): 0 Maximum resident set size (kbytes): 500 Average resident set size (kbytes): 0 Major (requiring I/O) page faults: 0 Minor (reclaiming a frame) page faults: 172 Voluntary context switches: 1765 Involuntary context switches: 349 Swaps: 0 File system inputs: 0 File system outputs: 0 Socket messages sent: 0 Socket messages received: 0 Signals delivered: 0 Page size (bytes): 4096 Exit status: 0
android-dgram-test.tar
Description: Unix tar archive
_______________________________________________ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel