forms sends empty POST (sometimes)

Question

I have a problem with my webapp (php, kohana 2.x) and i don't really have a clue on how solving it. This is happening to only some users and no matter what, i can't replicate it by changing browser. Normally the login form is working but sometimes it sends NULL post:

language en_US
2012-01-07 19:55:24 +01:00 --- info: Called login, but POST is empty.
2012-01-07 19:55:24 +01:00 --- info: <pre>(array) Array
(
)
</pre>
2012-01-07 19:55:24 +01:00 --- info: <pre>(array) Array
(
)
</pre>

This is the form code:

<div id="form">

<form action="/index.php/user/login" method="post">
<input type="text" id="username" name="username"  style="width:140px">
<input type="password" id="password" name="password"  style="width:140px">
<input type="submit" id="submit" value="Enter" class="submit"  />           
</form>

</div>

any clue?

Thanks.

Update: A user experienced the problem again: this is the log file with the info you asked to look:

2012-01-18 05:28:06 +01:00 --- info: ----------------------------------------
2012-01-18 05:28:06 +01:00 --- info: IP address: x.x.x.x
2012-01-18 05:28:06 +01:00 --- info: Method: POST
2012-01-18 05:28:06 +01:00 --- info: Type: application/x-www-form-urlencoded
2012-01-18 05:28:06 +01:00 --- info: Length: 34
2012-01-18 05:28:06 +01:00 --- info: Raw: username=xxx&password=yyy
2012-01-18 05:28:06 +01:00 --- info: ----------------------------------------
2012-01-18 05:28:07 +01:00 --- info: ----------------------------------------
2012-01-18 05:28:07 +01:00 --- info: ----------------------------------------
2012-01-18 05:28:07 +01:00 --- info: IP address: x.x.x.x
2012-01-18 05:28:07 +01:00 --- info: Method: GET
2012-01-18 05:28:07 +01:00 --- info: Type:
2012-01-18 05:28:07 +01:00 --- info: Length:
2012-01-18 05:28:07 +01:00 --- info: Raw:
2012-01-18 05:28:07 +01:00 --- info: ----------------------------------------

Apache Access log:

x.x.x.x - - [18/Jan/2012:05:27:47 +0100] "GET /media/images/template/table-bottom.png HTTP/1.1" 200 80034 "http://www.medieval-europe.eu/index.php/" "M
ozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.
30729; OfficeLiveConnector.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:27:47 +0100] "GET /media/images/template/background.jpg HTTP/1.1" 200 220187 "http://www.medieval-europe.eu/index.php/" "Mo
zilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.3
0729; OfficeLiveConnector.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:06 +0100] "POST /index.php/user/login HTTP/1.1" 302 782 "http://www.medieval-europe.eu/index.php/" "Mozilla/4.0 (compati
ble; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; OfficeLiveCo
nnector.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:07 +0100] "GET /index.php/region/view_announcements/region/106 HTTP/1.1" 302 602 "http://www.medieval-europe.eu/index.ph
p/" "Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CL
R 3.5.30729; OfficeLiveConnector.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:07 +0100] "GET /index.php/user/login HTTP/1.1" 302 572 "http://www.medieval-europe.eu/index.php/" "Mozilla/4.0 (compatib
le; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; OfficeLiveCon
nector.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:08 +0100] "GET /index.php/ HTTP/1.1" 200 5854 "http://www.medieval-europe.eu/index.php/" "Mozilla/4.0 (compatible; MSIE
8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; OfficeLiveConnector.1.
3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:09 +0100] "GET /media/css/home.css HTTP/1.1" 304 241 "http://www.medieval-europe.eu/index.php/" "Mozilla/4.0 (compatible
; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; OfficeLiveConne
ctor.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:21 +0100] "GET /index.php/page/index HTTP/1.1" 200 5854 "-" "Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/
4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; OfficeLiveConnector.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:22 +0100] "GET /media/css/home.css HTTP/1.1" 304 241 "http://www.medieval-europe.eu/index.php/page/index" "Mozilla/4.0 (
compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; Offic
eLiveConnector.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:30 +0100] "POST /index.php/user/login HTTP/1.1" 302 782 "http://www.medieval-europe.eu/index.php/page/index" "Mozilla/4.
0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; Of
ficeLiveConnector.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:30 +0100] "GET /index.php/region/view_announcements/region/106 HTTP/1.1" 302 602 "http://www.medieval-europe.eu/index.ph
p/page/index" "Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.215
2; .NET CLR 3.5.30729; OfficeLiveConnector.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:30 +0100] "GET /index.php/user/login HTTP/1.1" 302 572 "http://www.medieval-europe.eu/index.php/page/index" "Mozilla/4.0
 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; Off
iceLiveConnector.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:31 +0100] "GET /index.php/ HTTP/1.1" 200 5854 "http://www.medieval-europe.eu/index.php/page/index" "Mozilla/4.0 (compati
ble; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; OfficeLiveCo
nnector.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:32 +0100] "GET /media/css/home.css HTTP/1.1" 304 241 "http://www.medieval-europe.eu/index.php/" "Mozilla/4.0 (compatible
; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; OfficeLiveConne
ctor.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:42 +0100] "POST /index.php/user/login HTTP/1.1" 302 782 "http://www.medieval-europe.eu/index.php/" "Mozilla/4.0 (compati
ble; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; OfficeLiveCo
nnector.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:42 +0100] "GET /index.php/region/view_announcements/region/106 HTTP/1.1" 302 602 "http://www.medieval-europe.eu/index.ph
p/" "Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CL
R 3.5.30729; OfficeLiveConnector.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:43 +0100] "GET /index.php/user/login HTTP/1.1" 302 572 "http://www.medieval-europe.eu/index.php/" "Mozilla/4.0 (compatib
le; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; OfficeLiveCon
nector.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:43 +0100] "GET /index.php/ HTTP/1.1" 200 5854 "http://www.medieval-europe.eu/index.php/" "Mozilla/4.0 (compatible; MSIE
8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; OfficeLiveConnector.1.
3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:44 +0100] "GET /media/css/home.css HTTP/1.1" 304 241 "http://www.medieval-europe.eu/index.php/" "Mozilla/4.0 (compatible
; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; OfficeLiveConne
ctor.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:58 +0100] "GET /index.php/page/index HTTP/1.1" 200 5955 "-" "Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/
4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; OfficeLiveConnector.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:59 +0100] "GET /media/css/home.css HTTP/1.1" 200 4340 "http://www.medieval-europe.eu/index.php/page/index" "Mozilla/4.0
(compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; Offi
ceLiveConnector.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:59 +0100] "GET /media/images/flags-lang/gb.png HTTP/1.1" 200 921 "http://www.medieval-europe.eu/index.php/page/index" "M
ozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.
30729; OfficeLiveConnector.1.3; OfficeLivePatch.0.0)"
x.x.x.x - - [18/Jan/2012:05:28:59 +0100] "GET /media/images/flags-lang/it.png HTTP/1.1" 200 742 "http://www.medieval-europe.eu/index.php/page/index" "M
ozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; EasyBits GO v1.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.
30729; OfficeLiveConnector.1.3; OfficeLivePatch.0.0)"

Answer 1

I learned that there are some Browser Plugins out there are doing additional requests links the user is visiting.

One example is a Chrome Plugin that displays some server headers in the address bar, that Plugin is sending additional Requests to the server to read the header information, producing a second request without the user knowing it. My online banking and several websites with cookie based session handling broke for me because of this.

To identify the source of your problem you should log as many data as possible like the complete $_SERVER and $_REQUEST arrays for requests to that link. To better understand the circumstances you should combine your analysis with the webserver logfile to see all other requests sent by the same client to your server prior to the "null" submit.

Answer 2

I don't think Kohana is to blame here. I've seen the same with an Apache/PHP setup. In some cases, when the headers are not set correctly in the request to the server, $_POST is empty.

Take a look at code snippet from felixsigl here to convert the raw http input into $_POST in these cases

PHP some $_POST values missing but are present in php://input

Answer 3

try add "/" to form-action:

<form action="/index.php/user/login/" method="post">