{"action":"created","issue":{"url":"https://api.github.com/repos/natsys/tempesta/issues/54","labels_url":"https://api.github.com/repos/natsys/tempesta/issues/54/labels{/name}","comments_url":"https://api.github.com/repos/natsys/tempesta/issues/54/comments","events_url":"https://api.github.com/repos/natsys/tempesta/issues/54/events","html_url":"https://github.com/natsys/tempesta/issues/54","id":58180460,"number":54,"title":"Many HTTP requests are blocked by Tempesta","user":{"login":"keshonok","id":6352580,"avatar_url":"https://avatars.githubusercontent.com/u/6352580?v=3","gravatar_id":"","url":"https://api.github.com/users/keshonok","html_url":"https://github.com/keshonok","followers_url":"https://api.github.com/users/keshonok/followers","following_url":"https://api.github.com/users/keshonok/following{/other_user}","gists_url":"https://api.github.com/users/keshonok/gists{/gist_id}","starred_url":"https://api.github.com/users/keshonok/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/keshonok/subscriptions","organizations_url":"https://api.github.com/users/keshonok/orgs","repos_url":"https://api.github.com/users/keshonok/repos","events_url":"https://api.github.com/users/keshonok/events{/privacy}","received_events_url":"https://api.github.com/users/keshonok/received_events","type":"User","site_admin":false},"labels":[{"url":"https://api.github.com/repos/natsys/tempesta/labels/bug","name":"bug","color":"eb6420"},{"url":"https://api.github.com/repos/natsys/tempesta/labels/crucial","name":"crucial","color":"ff1010"}],"state":"open","locked":false,"assignee":{"login":"krizhanovsky","id":884694,"avatar_url":"https://avatars.githubusercontent.com/u/884694?v=3","gravatar_id":"","url":"https://api.github.com/users/krizhanovsky","html_url":"https://github.com/krizhanovsky","followers_url":"https://api.github.com/users/krizhanovsky/followers","following_url":"https://api.github.com/users/krizhanovsky/following{/other_user}","gists_url":"https://api.github.com/users/krizhanovsky/gists{/gist_id}","starred_url":"https://api.github.com/users/krizhanovsky/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/krizhanovsky/subscriptions","organizations_url":"https://api.github.com/users/krizhanovsky/orgs","repos_url":"https://api.github.com/users/krizhanovsky/repos","events_url":"https://api.github.com/users/krizhanovsky/events{/privacy}","received_events_url":"https://api.github.com/users/krizhanovsky/received_events","type":"User","site_admin":false},"milestone":null,"comments":3,"created_at":"2015-02-19T08:38:14Z","updated_at":"2015-03-15T17:13:11Z","closed_at":null,"body":"When an SKB consists of multiple parts/fragments Tempesta processes it fragment by fragment, passing each fragment separately to the HTTP parser. The HTTP parser keeps track of the current state of HTTP message parsing. However the code that passes the fragments to the parser is broken. The parser does not receive the complete HTTP message and reports a parsing error, which leads to be message being blocked.\r\n\r\n```\r\nLoading Tempesta kernel modules...\r\n[   13.930348] [tempesta] Initializing Tempesta FW kernel module...\r\n[   13.930891] [tempesta] init: cfg_if\r\n[   13.931200] [tempesta] init: http\r\n[   13.931484] [tempesta] init: server\r\n[   13.931797] [tempesta] init: client\r\n[   13.932138] [tempesta] init: session\r\n[   13.932437] [tempesta] init: connection\r\n[   13.932762] [tempesta]   register cfg: cache\r\n[   13.933103] [tempesta]   register cfg: sock_backend\r\n[   13.933496] [tempesta]   register cfg: sock_frontend\r\n[   13.951327] [tempesta] Registering new scheduler: dummy\r\nStarting Tempesta...\r\n[   13.954693] [tempesta] got state via sysctl: start\r\n[   13.955261] [tempesta]   reading configuration file...\r\n[   13.955846] [tempesta]   reading file: /home/natsys-lab/tfw-run/tempesta/etc/tempesta_fw.conf\r\n[   13.957494] [tempesta]   file size: 2204 bytes\r\n[   13.958008] [tempesta]   read by offset: 0\r\n[   13.960110] [tempesta]   read by offset: 2204\r\n[   13.960690] [tempesta] starting all modules...\r\n[   13.961180] [tempesta]   parsing configuration and pushing it to modules...\r\n[   13.961993] [tempesta]   use default entry: 'cache off;'\r\n[   13.962671] [tempesta]   spec handle: 'cache'\r\n[   13.963279] [tempesta]   use default entry: 'cache_size 262144;'\r\n[   13.964238] [tempesta]   spec handle: 'cache_size'\r\n[   13.964785] [tempesta]   use default entry: 'cache_dir /opt/tempesta/cache;'\r\n[   13.965509] [tempesta]   spec handle: 'cache_dir'\r\n[   13.965986] [tempesta]   use default entry: 'backend 127.0.0.1:8080;'\r\n[   13.966636] [tempesta]   spec handle: 'backend'\r\n[   13.967107] [tempesta]   use default entry: 'listen 0.0.0.0:80;'\r\n[   13.967718] [tempesta]   spec handle: 'listen'\r\n[   13.968259] [tempesta]   created front-end socket: sk=ffff88003cc0c040\r\n[   13.968752] [tempesta]   starting modules...\r\n[   13.969073] [tempesta]   mod_start(): cache\r\n[   13.969388] [tempesta]   mod_start(): sock_backend\r\n[   13.969749] [tempesta]   Starting thread: tfw_bconnd\r\n[   13.970169] [tempesta]   mod_start(): sock_frontend\r\n[   13.970539] [tempesta]   start listening on socket: sk=ffff88003cc0c040\r\n[   13.971042] [tempesta] modules are started\r\nnet.tempesta.state = start\r\ndone\r\ndone\r\nStarting nginx: nginx.\r\n[   17.973654] [tempesta] Connected to backend: 127.0.0.1:8080\r\n[   22.517164] [tempesta]   New client socket ffff88003daf2080 (state=1)\r\n[   22.519380] [tempesta]   Link new msg ffff88003da7e040 with connection ffff88003d923500\r\n[   22.521026] [tempesta]   Add skb ffff88003db603c0 to message ffff88003da7e040\r\n[   22.521026] [tempesta]   Received 62 client data bytes (GET / HTTP/1.1\r\n[   22.521026] User-Agent: Wget/1.15 (linux-gnu)\r\n[   22.521026] Accept: */*) on socket (conn=ffff88003d923500)\r\n[   22.521026] [tempesta]   enter FSM at state 0\r\n[   22.521026] [tempesta]   parser: Req_0(0:0): c=0x47(G), r=-2\r\n[   22.521026] [tempesta]   parser: Req_Method(1:0): c=0x47(G), r=-2\r\n[   22.521026] [tempesta]   parser: Req_MUSpace(2:0): c=0x2f(/), r=-2\r\n[   22.521026] [tempesta]   parser: Req_UriAbsPath(6:0): c=0x20( ), r=-2\r\n[   22.521026] [tempesta]   parser: Req_HttpVer(7:0): c=0x48(H), r=-2\r\n[   22.521026] [tempesta]   parser: Req_EoL(15:0): c=0xd(.), r=-2\r\n[   22.521026] [tempesta]   parser: Req_EoL(15:0): c=0xa(.), r=-2\r\n[   22.521026] [tempesta]   parser: Req_Hdr(16:0): c=0x55(U), r=-2\r\n[   22.521026] [tempesta]   parser: Req_HdrOther(92:0): c=0x55(U), r=-2\r\n[   22.521026] [tempesta]   store header w/ ptr=ffff88003ccdaa92 len=33 flags=0 id=3\r\n[   22.521026] [tempesta]   parser: Req_Hdr(16:0): c=0x41(A), r=-2\r\n[   22.521026] [tempesta]   parser: Req_HdrOther(92:0): c=0x41(A), r=-2\r\n[   22.521026] [tempesta]   store header w/ ptr=ffff88003ccdaab5 len=11 flags=0 id=4\r\n[   22.521026] [tempesta]   request parsed: len=62 parsed=62 msg_len=62 res=-1\r\n[   22.521026] [tempesta]   postpone skb ffff88003db603c0\r\n[   22.521026] [tempesta]   Add skb ffff88003db603c0 to message ffff88003da7e040\r\n[   22.521026] [tempesta]   Received 50 client data bytes () on socket (conn=ffff88003d923500)\r\n[   22.521026] [tempesta]   enter FSM at state 92\r\n[   22.521026] [tempesta]   parser: Req_HdrOther(92:0): c=0x1(.), r=-2\r\n[   22.521026] [tempesta]   store header w/ ptr=          (null) len=40 flags=0 id=4\r\n[   22.521026] [tempesta]   parser: Req_Hdr(16:0): c=0x1(.), r=-2\r\n[   22.521026] [tempesta]   request parsed: len=50 parsed=0 msg_len=0 res=-2\r\n[   22.521026] [tempesta]   Block bad HTTP request\r\n[   22.521026] [sync_socket] Warning: can't process app data on socket ffff88003daf2080\r\n[   22.521026] [sync_socket]   Close socket ffff88003daf2080 (account=1)\r\n[   22.521026] [tempesta]   Close socket ffff88003daf2080, conn=ffff88003d923500\r\n[   22.521026] [tempesta]   Free msg: ffff88003da7e040\r\n[   22.521026] [tempesta]   free skb ffff88003db603c0: truesize=4864 sk=ffff88003daf2080, destructor=ffffffff812d2ea0 users=1\r\n[   22.521026] [tempesta]   Free connection: ffff88003d923500\r\n[   22.521026] [tempesta]   Free session: ffff88003da3f490\r\n[   23.539579] [tempesta]   New client socket ffff88003db7d2c0 (state=1)\r\n[   23.541371] [tempesta]   Link new msg ffff88003e344040 with connection ffff88003d923500\r\n[   23.543410] [tempesta]   Add skb ffff88003db600c0 to message ffff88003e344040\r\n[   23.543471] [tempesta]   Received 62 client data bytes (GET / HTTP/1.1\r\n[   23.543471] User-Agent: Wget/1.15 (linux-gnu)\r\n[   23.543471] Accept: */*) on socket (conn=ffff88003d923500)\r\n[   23.543471] [tempesta]   enter FSM at state 0\r\n[   23.543471] [tempesta]   parser: Req_0(0:0): c=0x47(G), r=-2\r\n[   23.543471] [tempesta]   parser: Req_Method(1:0): c=0x47(G), r=-2\r\n[   23.543471] [tempesta]   parser: Req_MUSpace(2:0): c=0x2f(/), r=-2\r\n[   23.543471] [tempesta]   parser: Req_UriAbsPath(6:0): c=0x20( ), r=-2\r\n[   23.543471] [tempesta]   parser: Req_HttpVer(7:0): c=0x48(H), r=-2\r\n[   23.543471] [tempesta]   parser: Req_EoL(15:0): c=0xd(.), r=-2\r\n[   23.543471] [tempesta]   parser: Req_EoL(15:0): c=0xa(.), r=-2\r\n[   23.543471] [tempesta]   parser: Req_Hdr(16:0): c=0x55(U), r=-2\r\n[   23.543471] [tempesta]   parser: Req_HdrOther(92:0): c=0x55(U), r=-2\r\n[   23.543471] [tempesta]   store header w/ ptr=ffff88003ccdb292 len=33 flags=0 id=3\r\n[   23.543471] [tempesta]   parser: Req_Hdr(16:0): c=0x41(A), r=-2\r\n[   23.543471] [tempesta]   parser: Req_HdrOther(92:0): c=0x41(A), r=-2\r\n[   23.543471] [tempesta]   store header w/ ptr=ffff88003ccdb2b5 len=11 flags=0 id=4\r\n[   23.543471] [tempesta]   request parsed: len=62 parsed=62 msg_len=62 res=-1\r\n[   23.543471] [tempesta]   postpone skb ffff88003db600c0\r\n[   23.543471] [tempesta]   Add skb ffff88003db600c0 to message ffff88003e344040\r\n[   23.543471] [tempesta]   Received 50 client data bytes () on socket (conn=ffff88003d923500)\r\n[   23.543471] [tempesta]   enter FSM at state 92\r\n[   23.543471] [tempesta]   parser: Req_HdrOther(92:0): c=0x1(.), r=-2\r\n[   23.543471] [tempesta]   store header w/ ptr=          (null) len=40 flags=0 id=4\r\n[   23.543471] [tempesta]   parser: Req_Hdr(16:0): c=0x1(.), r=-2\r\n[   23.543471] [tempesta]   request parsed: len=50 parsed=0 msg_len=0 res=-2\r\n[   23.543471] [tempesta]   Block bad HTTP request\r\n[   23.543471] [sync_socket] Warning: can't process app data on socket ffff88003db7d2c0\r\n[   23.543471] [sync_socket]   Close socket ffff88003db7d2c0 (account=1)\r\n[   23.543471] [tempesta]   Close socket ffff88003db7d2c0, conn=ffff88003d923500\r\n[   23.543471] [tempesta]   Free msg: ffff88003e344040\r\n[   23.543471] [tempesta]   free skb ffff88003db600c0: truesize=4864 sk=ffff88003db7d2c0, destructor=ffffffff812d2ea0 users=1\r\n[   23.543471] [tempesta]   Free connection: ffff88003d923500\r\n[   23.543471] [tempesta]   Free session: ffff88003da3f490\r\n[   78.033968] [sync_socket]   Close socket ffff88003daf3280 (account=1)\r\n[   78.036185] [tempesta]   Close socket ffff88003daf3280, conn=ffff88003d923548\r\n[   78.038443] [tempesta]   Free msg:           (null)\r\n[   78.039954] [tempesta]   Free connection: ffff88003d923548\r\n[   78.041824] [sync_socket]   free rcv skb ffff88003d88eda8\r\n```"},"comment":{"url":"https://api.github.com/repos/natsys/tempesta/issues/comments/81164466","html_url":"https://github.com/natsys/tempesta/issues/54#issuecomment-81164466","issue_url":"https://api.github.com/repos/natsys/tempesta/issues/54","id":81164466,"user":{"login":"krizhanovsky","id":884694,"avatar_url":"https://avatars.githubusercontent.com/u/884694?v=3","gravatar_id":"","url":"https://api.github.com/users/krizhanovsky","html_url":"https://github.com/krizhanovsky","followers_url":"https://api.github.com/users/krizhanovsky/followers","following_url":"https://api.github.com/users/krizhanovsky/following{/other_user}","gists_url":"https://api.github.com/users/krizhanovsky/gists{/gist_id}","starred_url":"https://api.github.com/users/krizhanovsky/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/krizhanovsky/subscriptions","organizations_url":"https://api.github.com/users/krizhanovsky/orgs","repos_url":"https://api.github.com/users/krizhanovsky/repos","events_url":"https://api.github.com/users/krizhanovsky/events{/privacy}","received_events_url":"https://api.github.com/users/krizhanovsky/received_events","type":"User","site_admin":false},"created_at":"2015-03-15T17:13:11Z","updated_at":"2015-03-15T17:13:11Z","body":"The patch (https://github.com/natsys/tempesta/commit/a461f6b6f8b2d801dfe0cf8017dd20d3bc40fe3a) is right and I'll apply it. However, motivation of the patch and how does it fix the problem is unclear.\r\n\r\n```skb_frag_address``` is defined in include/linux/skbuff.h as\r\n\r\n        static inline void *skb_frag_address(const skb_frag_t *frag)\r\n        {\r\n                return page_address(skb_frag_page(frag)) + frag->page_offset;\r\n        }\r\n\r\nWhile ```kmap_atomic``` is basically just ```page_address(page)``` (see include/linux/highmem.h). So the patch fixes only the case when frag->page_offset != 0.\r\n\r\nPlease, recheck the bug with the new master branch and provide better explanation how the patch fixes the problem and/or provide test which reproduces the problem and shows that the problem is gone after the patch.\r\n\r\n"}}