From 1e07b7db8855a93b8999baffb81f066abd595bc1 Mon Sep 17 00:00:00 2001 From: Rostislav Lisovy Date: Mon, 19 Sep 2011 17:49:52 +0200 Subject: [PATCH] Note on blocking/nonblocking behaviour of CAN socket with some experiments. --- doc/canprio/can_socket_blocking.txt | 304 ++++++++++++++++++++++++++++ 1 file changed, 304 insertions(+) create mode 100644 doc/canprio/can_socket_blocking.txt diff --git a/doc/canprio/can_socket_blocking.txt b/doc/canprio/can_socket_blocking.txt new file mode 100644 index 0000000..2727c4d --- /dev/null +++ b/doc/canprio/can_socket_blocking.txt @@ -0,0 +1,304 @@ +# can_socket_blocking.txt +# +# The purpose of this experiment is to show: +# 1) "Nonblocking behaviour" (return value of -ENOBUFS) of write() call to +# CAN socket (with default settings set to BLOCKING). +# This can be caused by: +# -- Amount of data sent to a device is much higher than +# the device is capable of sending (i.e. frames are dropped by the +# device driver). +# -- Amount of data sent to a qdisc (default pfifo gets its size from +# txqueuelen parameter of a device) is much higher than the qdisc +# can handle -- this leads to packet drop. +# +# 2) Possibility of blocking behaviour of write() call when internal socket +# buffer (SO_SNDBUF option) is smaller than qdiscs buffer. (3rd part of +# the experiment tries to show that write is "really blocked" -- that this +# desired behaviour is not caused only in the manner that none ot the +# buffers overruns). +################################################################################ + +# Set the same for all parts of the experiment +$ sudo ip link set can0 txqueuelen 50 + +################################################################################ +##### Default cangen ##### +################################################################################ + +$ ip link show dev can0 +3: can0: mtu 16 qdisc pfifo_fast state UNKNOWN qlen 50 + link/can + +$ ./cangen -g 0 can0 -I i -L 1 -D i -v -v + can0 0 [1] 00 + can0 1 [1] 01 + can0 2 [1] 02 + can0 3 [1] 03 + can0 4 [1] 04 + can0 5 [1] 05 + can0 6 [1] 06 + can0 7 [1] 07 + can0 8 [1] 08 + can0 9 [1] 09 + can0 A [1] 0A + can0 B [1] 0B + can0 C [1] 0C + can0 D [1] 0D + can0 E [1] 0E + can0 F [1] 0F + can0 10 [1] 10 + can0 11 [1] 11 + can0 12 [1] 12 + can0 13 [1] 13 + can0 14 [1] 14 + can0 15 [1] 15 + can0 16 [1] 16 + can0 17 [1] 17 + can0 18 [1] 18 + can0 19 [1] 19 + can0 1A [1] 1A + can0 1B [1] 1B + can0 1C [1] 1C + can0 1D [1] 1D + can0 1E [1] 1E + can0 1F [1] 1F + can0 20 [1] 20 + can0 21 [1] 21 + can0 22 [1] 22 + can0 23 [1] 23 + can0 24 [1] 24 + can0 25 [1] 25 + can0 26 [1] 26 + can0 27 [1] 27 + can0 28 [1] 28 + can0 29 [1] 29 + can0 2A [1] 2A + can0 2B [1] 2B + can0 2C [1] 2C + can0 2D [1] 2D + can0 2E [1] 2E + can0 2F [1] 2F + can0 30 [1] 30 + can0 31 [1] 31 + can0 32 [1] 32 + can0 33 [1] 33 + can0 34 [1] 34 + can0 35 [1] 35 + can0 36 [1] 36 + can0 37 [1] 37 + can0 38 [1] 38 + can0 39 [1] 39 +write: No buffer space available + +$ strace -o cangen.strace -r ./cangen -g 0 can0 -I 125 -L 1 -D i +write: No buffer space available + +$ cat cangen.strace | tail -30 + 0.000082 write(3, "%\1\0\0\1\0\0\0\27\6\0\0\0\0\0\0", 16) = 16 + 0.000091 write(3, "%\1\0\0\1\0\0\0\30\6\0\0\0\0\0\0", 16) = 16 + 0.000082 write(3, "%\1\0\0\1\0\0\0\31\6\0\0\0\0\0\0", 16) = 16 + 0.000082 write(3, "%\1\0\0\1\0\0\0\32\6\0\0\0\0\0\0", 16) = 16 + 0.000081 write(3, "%\1\0\0\1\0\0\0\33\6\0\0\0\0\0\0", 16) = 16 + 0.000082 write(3, "%\1\0\0\1\0\0\0\34\6\0\0\0\0\0\0", 16) = 16 + 0.000081 write(3, "%\1\0\0\1\0\0\0\35\6\0\0\0\0\0\0", 16) = 16 + 0.000082 write(3, "%\1\0\0\1\0\0\0\36\6\0\0\0\0\0\0", 16) = 16 + 0.000050 write(3, "%\1\0\0\1\0\0\0\37\6\0\0\0\0\0\0", 16) = 16 + 0.000082 write(3, "%\1\0\0\1\0\0\0 \6\0\0\0\0\0\0", 16) = 16 + 0.000082 write(3, "%\1\0\0\1\0\0\0!\6\0\0\0\0\0\0", 16) = 16 + 0.000081 write(3, "%\1\0\0\1\0\0\0\"\6\0\0\0\0\0\0", 16) = 16 + 0.000082 write(3, "%\1\0\0\1\0\0\0#\6\0\0\0\0\0\0", 16) = 16 + 0.000082 write(3, "%\1\0\0\1\0\0\0$\6\0\0\0\0\0\0", 16) = 16 + 0.000082 write(3, "%\1\0\0\1\0\0\0%\6\0\0\0\0\0\0", 16) = 16 + 0.000082 write(3, "%\1\0\0\1\0\0\0&\6\0\0\0\0\0\0", 16) = 16 + 0.000081 write(3, "%\1\0\0\1\0\0\0'\6\0\0\0\0\0\0", 16) = 16 + 0.000080 write(3, "%\1\0\0\1\0\0\0(\6\0\0\0\0\0\0", 16) = 16 + 0.000081 write(3, "%\1\0\0\1\0\0\0)\6\0\0\0\0\0\0", 16) = -1 ENOBUFS (No buffer space available) + 0.000110 dup(2) = 4 + 0.000076 fcntl64(4, F_GETFL) = 0x8002 (flags O_RDWR|O_LARGEFILE) + 0.000177 brk(0) = 0x804e000 + 0.000067 brk(0x806f000) = 0x806f000 + 0.000092 fstat64(4, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 2), ...}) = 0 + 0.000151 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7840000 + 0.000079 _llseek(4, 0, 0xbff26d08, SEEK_CUR) = -1 ESPIPE (Illegal seek) + 0.000107 write(4, "write: No buffer space available"..., 33) = 33 + 0.000095 close(4) = 0 + 0.000066 munmap(0xb7840000, 4096) = 0 + 0.000100 exit_group(1) = ? + + +################################################################################ +##### Cangen with setting of SO_SNDBUF option ##### +################################################################################ + +$ git diff -U0 +diff --git a/can-utils/cangen.c b/can-utils/cangen.c +index 95dfa46..db3fde2 100644 +--- a/can-utils/cangen.c ++++ b/can-utils/cangen.c +@@ -105 +105,3 @@ void print_usage(char *prg) +- "printing sent CAN frames)\n\n"); ++ "printing sent CAN frames)\n"); ++ fprintf(stderr, " -b (set SO_SNDBUF value of a buffer " ++ "-- the kernel doubles this value)\n\n"); +@@ -144,0 +147 @@ int main(int argc, char **argv) ++ int snd_buf = 0; +@@ -168 +171 @@ int main(int argc, char **argv) +- while ((opt = getopt(argc, argv, "ig:eI:L:D:xp:n:vh?")) != -1) { ++ while ((opt = getopt(argc, argv, "ig:eI:L:D:xp:n:vb:h?")) != -1) { +@@ -226,0 +230,4 @@ int main(int argc, char **argv) ++ case 'b': ++ snd_buf = atoi(optarg); ++ break; ++ +@@ -301,0 +309,8 @@ int main(int argc, char **argv) ++ if (snd_buf > 0) ++ setsockopt(s, SOL_SOCKET, SO_SNDBUF, &snd_buf, sizeof(snd_buf)); ++/* { ++ socklen_t len; ++ getsockopt(s, SOL_SOCKET, SO_SNDBUF, &snd_buf, &len); ++ printf("SO_SNDBUF: %d\n", snd_buf); ++ } ++*/ + +$ ip link show dev can0 +3: can0: mtu 16 qdisc pfifo_fast state UNKNOWN qlen 50 + link/can + +# There is no ENOBUFS error +$ ./cangen -b 1024 -g 0 can0 -I 123 -L 1 -D i -v -v | head -10000 | wc -l +10000 + + +################################################################################ +##### Throttling of outgoing traffic with TBF ##### +################################################################################ + +# Default qdisc +$ sudo tc qdisc del dev can0 root + +$ strace -o cangen.strace -r ./cangen -b 1024 -g 0 can0 -I 125 -L 1 -D i + +$ cat cangen.strace | tail -30 + 0.000079 write(3, "%\1\0\0\1\0\0\0\276.\0\0\0\0\0\0", 16) = 16 + 0.000079 write(3, "%\1\0\0\1\0\0\0\277.\0\0\0\0\0\0", 16) = 16 + 0.000079 write(3, "%\1\0\0\1\0\0\0\300.\0\0\0\0\0\0", 16) = 16 + 0.000078 write(3, "%\1\0\0\1\0\0\0\301.\0\0\0\0\0\0", 16) = 16 + 0.000078 write(3, "%\1\0\0\1\0\0\0\302.\0\0\0\0\0\0", 16) = 16 + 0.000079 write(3, "%\1\0\0\1\0\0\0\303.\0\0\0\0\0\0", 16) = 16 + 0.000079 write(3, "%\1\0\0\1\0\0\0\304.\0\0\0\0\0\0", 16) = 16 + 0.000077 write(3, "%\1\0\0\1\0\0\0\305.\0\0\0\0\0\0", 16) = 16 + 0.000047 write(3, "%\1\0\0\1\0\0\0\306.\0\0\0\0\0\0", 16) = 16 + 0.000079 write(3, "%\1\0\0\1\0\0\0\307.\0\0\0\0\0\0", 16) = 16 + 0.000079 write(3, "%\1\0\0\1\0\0\0\310.\0\0\0\0\0\0", 16) = 16 + 0.000078 write(3, "%\1\0\0\1\0\0\0\311.\0\0\0\0\0\0", 16) = 16 + 0.000078 write(3, "%\1\0\0\1\0\0\0\312.\0\0\0\0\0\0", 16) = 16 + 0.000341 write(3, "%\1\0\0\1\0\0\0\313.\0\0\0\0\0\0", 16) = 16 + 0.000077 write(3, "%\1\0\0\1\0\0\0\314.\0\0\0\0\0\0", 16) = 16 + 0.000079 write(3, "%\1\0\0\1\0\0\0\315.\0\0\0\0\0\0", 16) = 16 + 0.000078 write(3, "%\1\0\0\1\0\0\0\316.\0\0\0\0\0\0", 16) = 16 + 0.000078 write(3, "%\1\0\0\1\0\0\0\317.\0\0\0\0\0\0", 16) = 16 + 0.000047 write(3, "%\1\0\0\1\0\0\0\320.\0\0\0\0\0\0", 16) = 16 + 0.000080 write(3, "%\1\0\0\1\0\0\0\321.\0\0\0\0\0\0", 16) = 16 + 0.000352 write(3, "%\1\0\0\1\0\0\0\322.\0\0\0\0\0\0", 16) = 16 + 0.000087 write(3, "%\1\0\0\1\0\0\0\323.\0\0\0\0\0\0", 16) = 16 + 0.000080 write(3, "%\1\0\0\1\0\0\0\324.\0\0\0\0\0\0", 16) = 16 + 0.000078 write(3, "%\1\0\0\1\0\0\0\325.\0\0\0\0\0\0", 16) = 16 + 0.000079 write(3, "%\1\0\0\1\0\0\0\326.\0\0\0\0\0\0", 16) = 16 + 0.000078 write(3, "%\1\0\0\1\0\0\0\327.\0\0\0\0\0\0", 16) = 16 + 0.000114 --- SIGINT (Interrupt) @ 0 (0) --- + 0.000072 sigreturn() = ? (mask now []) + 0.000096 close(3) = 0 + 0.000102 exit_group(0) = ? + + + + +# TBF +$ sudo tc qdisc add dev can0 root tbf rate 1kbit burst 1kbit latency 50ms + +$ strace -o cangen.strace -r ./cangen -b 1024 -g 0 can0 -I 125 -L 1 -D i + +# Each 5th write blocks for a while +$ cat cangen.strace | tail -30 + 0.000048 write(3, "%\1\0\0\1\0\0\0\16\0\0\0\0\0\0\0", 16) = 16 + 0.000047 write(3, "%\1\0\0\1\0\0\0\17\0\0\0\0\0\0\0", 16) = 16 + 0.511054 write(3, "%\1\0\0\1\0\0\0\20\0\0\0\0\0\0\0", 16) = 16 + 0.000081 write(3, "%\1\0\0\1\0\0\0\21\0\0\0\0\0\0\0", 16) = 16 + 0.000047 write(3, "%\1\0\0\1\0\0\0\22\0\0\0\0\0\0\0", 16) = 16 + 0.000048 write(3, "%\1\0\0\1\0\0\0\23\0\0\0\0\0\0\0", 16) = 16 + 0.511835 write(3, "%\1\0\0\1\0\0\0\24\0\0\0\0\0\0\0", 16) = 16 + 0.000104 write(3, "%\1\0\0\1\0\0\0\25\0\0\0\0\0\0\0", 16) = 16 + 0.000050 write(3, "%\1\0\0\1\0\0\0\26\0\0\0\0\0\0\0", 16) = 16 + 0.000047 write(3, "%\1\0\0\1\0\0\0\27\0\0\0\0\0\0\0", 16) = 16 + 0.511787 write(3, "%\1\0\0\1\0\0\0\30\0\0\0\0\0\0\0", 16) = 16 + 0.000078 write(3, "%\1\0\0\1\0\0\0\31\0\0\0\0\0\0\0", 16) = 16 + 0.000049 write(3, "%\1\0\0\1\0\0\0\32\0\0\0\0\0\0\0", 16) = 16 + 0.000048 write(3, "%\1\0\0\1\0\0\0\33\0\0\0\0\0\0\0", 16) = 16 + 0.511823 write(3, "%\1\0\0\1\0\0\0\34\0\0\0\0\0\0\0", 16) = 16 + 0.000080 write(3, "%\1\0\0\1\0\0\0\35\0\0\0\0\0\0\0", 16) = 16 + 0.000048 write(3, "%\1\0\0\1\0\0\0\36\0\0\0\0\0\0\0", 16) = 16 + 0.000049 write(3, "%\1\0\0\1\0\0\0\37\0\0\0\0\0\0\0", 16) = 16 + 0.511859 write(3, "%\1\0\0\1\0\0\0 \0\0\0\0\0\0\0", 16) = 16 + 0.000057 write(3, "%\1\0\0\1\0\0\0!\0\0\0\0\0\0\0", 16) = 16 + 0.000048 write(3, "%\1\0\0\1\0\0\0\"\0\0\0\0\0\0\0", 16) = 16 + 0.000048 write(3, "%\1\0\0\1\0\0\0#\0\0\0\0\0\0\0", 16) = 16 + 0.511819 write(3, "%\1\0\0\1\0\0\0$\0\0\0\0\0\0\0", 16) = 16 + 0.000085 write(3, "%\1\0\0\1\0\0\0%\0\0\0\0\0\0\0", 16) = 16 + 0.000047 write(3, "%\1\0\0\1\0\0\0&\0\0\0\0\0\0\0", 16) = 16 + 0.000048 write(3, "%\1\0\0\1\0\0\0'\0\0\0\0\0\0\0", 16) = 16 + 0.234341 --- SIGINT (Interrupt) @ 0 (0) --- + 0.000036 sigreturn() = ? (mask now []) + 0.000064 close(3) = 0 + 0.000069 exit_group(0) = ? + + +# Setting socket as O_NONBLOCK +# Observing behaviour with throttled outgoing traffic + +$ git diff -U0 +diff --git a/can-utils/cangen.c b/can-utils/cangen.c +index 69b6323..0295f75 100644 +--- a/can-utils/cangen.c ++++ b/can-utils/cangen.c +@@ -58,0 +59 @@ ++#include +@@ -311,0 +313,2 @@ int main(int argc, char **argv) ++ fcntl(s, F_SETFL, O_NONBLOCK); ++ + +$ strace -o cangen.strace -r ./cangen -b 1024 -g 0 can0 -I 125 -L 1 -D i +write: Resource temporarily unavailable + +$ cat cangen.strace | tail -30 + 0.000043 setsockopt(3, SOL_SOCKET, SO_SNDBUF, [1024], 4) = 0 + 0.000043 fcntl64(3, F_SETFL, O_RDONLY|O_NONBLOCK) = 0 + 0.000042 bind(3, {sa_family=0x1d /* AF_??? */, sa_data="\0\0\3\0\0\0\1\0\0\0\3708z\267"}, 16) = 0 + 0.000058 write(3, "%\1\0\0\1\0\0\0\0\0\0\0\0\0\0\0", 16) = 16 + 0.000065 write(3, "%\1\0\0\1\0\0\0\1\0\0\0\0\0\0\0", 16) = 16 + 0.000092 write(3, "%\1\0\0\1\0\0\0\2\0\0\0\0\0\0\0", 16) = 16 + 0.000083 write(3, "%\1\0\0\1\0\0\0\3\0\0\0\0\0\0\0", 16) = 16 + 0.000082 write(3, "%\1\0\0\1\0\0\0\4\0\0\0\0\0\0\0", 16) = 16 + 0.000082 write(3, "%\1\0\0\1\0\0\0\5\0\0\0\0\0\0\0", 16) = 16 + 0.000081 write(3, "%\1\0\0\1\0\0\0\6\0\0\0\0\0\0\0", 16) = 16 + 0.000081 write(3, "%\1\0\0\1\0\0\0\7\0\0\0\0\0\0\0", 16) = 16 + 0.000081 write(3, "%\1\0\0\1\0\0\0\10\0\0\0\0\0\0\0", 16) = 16 + 0.000079 write(3, "%\1\0\0\1\0\0\0\t\0\0\0\0\0\0\0", 16) = 16 + 0.000050 write(3, "%\1\0\0\1\0\0\0\n\0\0\0\0\0\0\0", 16) = 16 + 0.000047 write(3, "%\1\0\0\1\0\0\0\v\0\0\0\0\0\0\0", 16) = 16 + 0.000048 write(3, "%\1\0\0\1\0\0\0\f\0\0\0\0\0\0\0", 16) = 16 + 0.000047 write(3, "%\1\0\0\1\0\0\0\r\0\0\0\0\0\0\0", 16) = 16 + 0.000047 write(3, "%\1\0\0\1\0\0\0\16\0\0\0\0\0\0\0", 16) = 16 + 0.000048 write(3, "%\1\0\0\1\0\0\0\17\0\0\0\0\0\0\0", 16) = -1 EAGAIN (Resource temporarily unavailable) + 0.000064 dup(2) = 4 + 0.000040 fcntl64(4, F_GETFL) = 0x8002 (flags O_RDWR|O_LARGEFILE) + 0.000101 brk(0) = 0x804e000 + 0.000035 brk(0x806f000) = 0x806f000 + 0.000059 fstat64(4, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 4), ...}) = 0 + 0.000079 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7784000 + 0.000047 _llseek(4, 0, 0xbfbb37f8, SEEK_CUR) = -1 ESPIPE (Illegal seek) + 0.000079 write(4, "write: Resource temporarily unav"..., 40) = 40 + 0.000059 close(4) = 0 + 0.000036 munmap(0xb7784000, 4096) = 0 + 0.000061 exit_group(1) = ? + + -- 2.39.2