You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Charles Richard <ch...@thelearningbar.com> on 2014/07/21 16:32:59 UTC

mod_jk "NetworkError: 400 Bad Request - https://xxx.xx.xxx.xxx"

Hi,

I am using Apache 2.2.3 with mod_jk 1.2.31 and Tomcat 6.0.30 .

I have never had issues with using mod_jk to connect my Apache requests to
a tomcat instance before now but I am now running into a situation where
Apache requests going to a tomcat instance on another server are giving me
an "400 Bad Request" and I can't seem to get more information on why this
is happening.

I turned on debug log level for mod_jk and I see the following:

[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
service::jk_lb_worker.c (1118): service sticky_session=1 id='empty'
[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
get_most_suitable_worker::jk_lb_worker.c (1001): found best worker
w1worker1 (w1worker1) using method 'Request'
[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
service::jk_lb_worker.c (1161): service worker=w1worker1 route=w1worker1
[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
ajp_get_endpoint::jk_ajp_common.c (3096): acquired connection pool slot=0
after 0 retries
[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
ajp_marshal_into_msgb::jk_ajp_common.c (605): ajp marshaling done
[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
ajp_service::jk_ajp_common.c (2379): processing w1worker1 with 2 retries
[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
ajp_send_request::jk_ajp_common.c (1572): (w1worker1) all endpoints are
disconnected.
[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
jk_open_socket::jk_connect.c (484): socket TCP_NODELAY set to On
[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
jk_open_socket::jk_connect.c (608): trying to connect socket 46 to
172.23.1.132:8009
[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
jk_open_socket::jk_connect.c (634): socket 46 [172.23.1.133:37865 ->
172.23.1.132:8009] connected

[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
ajp_send_request::jk_ajp_common.c (1632): (w1worker1) request body to send
0 - request body to resend 0
[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): received from ajp13
pos=0 len=19 max=8192
[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0000    04 01 90 00
0B 42 61 64 20 52 65 71 75 65 73 74  - .....Bad.Request
[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0010    00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00  - ................
[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
ajp_unmarshal_response::jk_ajp_common.c (660): status = 400
[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
ajp_unmarshal_response::jk_ajp_common.c (667): Number of headers is = 0
[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): received from ajp13
pos=0 len=2 max=8192
[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0000    05 01 00 00
00 00 00 00 00 00 00 00 00 00 00 00  - ................
[Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
ajp_process_callback::jk_ajp_common.c (1943): AJP13 protocol: Reuse is OK

In this example, it's trying to connect to a tomcat on another server
listening to port 8009 (172.23.1.132:8009). From the Apache server, I can
telnet to port 8009 on server 172.23.1.132 so I know the port is listening
and not blocked by a firewall.

I'm not really sure what else to try.

Sorry if this is the wrong forum.

Thanks,
Charles

Re: mod_jk "NetworkError: 400 Bad Request - https://xxx.xx.xxx.xxx"

Posted by Charles Richard <ch...@thelearningbar.com>.
On Mon, Jul 21, 2014 at 11:39 AM, Daniel Mikusa <dm...@gopivotal.com>
wrote:

> On Mon, Jul 21, 2014 at 10:32 AM, Charles Richard <
> charles.r@thelearningbar.com> wrote:
>
> > Hi,
> >
> > I am using Apache 2.2.3 with mod_jk 1.2.31 and Tomcat 6.0.30 .
> >
> > I have never had issues with using mod_jk to connect my Apache requests
> to
> > a tomcat instance before now but I am now running into a situation where
> > Apache requests going to a tomcat instance on another server are giving
> me
> > an "400 Bad Request" and I can't seem to get more information on why this
> > is happening.
> >
> > I turned on debug log level for mod_jk and I see the following:
> >
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > service::jk_lb_worker.c (1118): service sticky_session=1 id='empty'
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > get_most_suitable_worker::jk_lb_worker.c (1001): found best worker
> > w1worker1 (w1worker1) using method 'Request'
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > service::jk_lb_worker.c (1161): service worker=w1worker1 route=w1worker1
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > ajp_get_endpoint::jk_ajp_common.c (3096): acquired connection pool slot=0
> > after 0 retries
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > ajp_marshal_into_msgb::jk_ajp_common.c (605): ajp marshaling done
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > ajp_service::jk_ajp_common.c (2379): processing w1worker1 with 2 retries
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > ajp_send_request::jk_ajp_common.c (1572): (w1worker1) all endpoints are
> > disconnected.
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > jk_open_socket::jk_connect.c (484): socket TCP_NODELAY set to On
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > jk_open_socket::jk_connect.c (608): trying to connect socket 46 to
> > 172.23.1.132:8009
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > jk_open_socket::jk_connect.c (634): socket 46 [172.23.1.133:37865 ->
> > 172.23.1.132:8009] connected
> >
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > ajp_send_request::jk_ajp_common.c (1632): (w1worker1) request body to
> send
> > 0 - request body to resend 0
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > ajp_connection_tcp_get_message::jk_ajp_common.c (1329): received from
> ajp13
> > pos=0 len=19 max=8192
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0000    04 01 90
> 00
> > 0B 42 61 64 20 52 65 71 75 65 73 74  - .....Bad.Request
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0010    00 00 00
> 00
> > 00 00 00 00 00 00 00 00 00 00 00 00  - ................
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > ajp_unmarshal_response::jk_ajp_common.c (660): status = 400
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > ajp_unmarshal_response::jk_ajp_common.c (667): Number of headers is = 0
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > ajp_connection_tcp_get_message::jk_ajp_common.c (1329): received from
> ajp13
> > pos=0 len=2 max=8192
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0000    05 01 00
> 00
> > 00 00 00 00 00 00 00 00 00 00 00 00  - ................
> > [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> > ajp_process_callback::jk_ajp_common.c (1943): AJP13 protocol: Reuse is OK
> >
> > In this example, it's trying to connect to a tomcat on another server
> > listening to port 8009 (172.23.1.132:8009). From the Apache server, I
> can
> > telnet to port 8009 on server 172.23.1.132 so I know the port is
> listening
> > and not blocked by a firewall.
> >
>
> The debug logs are showing that it's connecting as well and if it were not,
> you'd get a definitive error in the logs.  The problem you're seeing is
> different.



> The 400 response is from Tomcat or your app.  What do you see on the Tomcat
> / application side of the logs?  Also, what is originating the request and
> what does the request you are sending look like?  Maybe it's legitimately a
> bad request?
>
> I have found the issue. I was missing an alias directive in Tomcat as I
did not have an alias setup for the web server hitting Tomcat on a
different server. Hopefully this helps someone else with similar issues.


> Dan
>
>
> >
> > I'm not really sure what else to try.
> >
> > Sorry if this is the wrong forum.
> >
> > Thanks,
> > Charles
> >
>

Re: mod_jk "NetworkError: 400 Bad Request - https://xxx.xx.xxx.xxx"

Posted by Daniel Mikusa <dm...@gopivotal.com>.
On Mon, Jul 21, 2014 at 10:32 AM, Charles Richard <
charles.r@thelearningbar.com> wrote:

> Hi,
>
> I am using Apache 2.2.3 with mod_jk 1.2.31 and Tomcat 6.0.30 .
>
> I have never had issues with using mod_jk to connect my Apache requests to
> a tomcat instance before now but I am now running into a situation where
> Apache requests going to a tomcat instance on another server are giving me
> an "400 Bad Request" and I can't seem to get more information on why this
> is happening.
>
> I turned on debug log level for mod_jk and I see the following:
>
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> service::jk_lb_worker.c (1118): service sticky_session=1 id='empty'
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> get_most_suitable_worker::jk_lb_worker.c (1001): found best worker
> w1worker1 (w1worker1) using method 'Request'
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> service::jk_lb_worker.c (1161): service worker=w1worker1 route=w1worker1
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> ajp_get_endpoint::jk_ajp_common.c (3096): acquired connection pool slot=0
> after 0 retries
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> ajp_marshal_into_msgb::jk_ajp_common.c (605): ajp marshaling done
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> ajp_service::jk_ajp_common.c (2379): processing w1worker1 with 2 retries
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> ajp_send_request::jk_ajp_common.c (1572): (w1worker1) all endpoints are
> disconnected.
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> jk_open_socket::jk_connect.c (484): socket TCP_NODELAY set to On
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> jk_open_socket::jk_connect.c (608): trying to connect socket 46 to
> 172.23.1.132:8009
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> jk_open_socket::jk_connect.c (634): socket 46 [172.23.1.133:37865 ->
> 172.23.1.132:8009] connected
>
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> ajp_send_request::jk_ajp_common.c (1632): (w1worker1) request body to send
> 0 - request body to resend 0
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> ajp_connection_tcp_get_message::jk_ajp_common.c (1329): received from ajp13
> pos=0 len=19 max=8192
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0000    04 01 90 00
> 0B 42 61 64 20 52 65 71 75 65 73 74  - .....Bad.Request
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0010    00 00 00 00
> 00 00 00 00 00 00 00 00 00 00 00 00  - ................
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> ajp_unmarshal_response::jk_ajp_common.c (660): status = 400
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> ajp_unmarshal_response::jk_ajp_common.c (667): Number of headers is = 0
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> ajp_connection_tcp_get_message::jk_ajp_common.c (1329): received from ajp13
> pos=0 len=2 max=8192
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> ajp_connection_tcp_get_message::jk_ajp_common.c (1329): 0000    05 01 00 00
> 00 00 00 00 00 00 00 00 00 00 00 00  - ................
> [Mon Jul 21 09:57:20 2014] [16825:47908532024176] [debug]
> ajp_process_callback::jk_ajp_common.c (1943): AJP13 protocol: Reuse is OK
>
> In this example, it's trying to connect to a tomcat on another server
> listening to port 8009 (172.23.1.132:8009). From the Apache server, I can
> telnet to port 8009 on server 172.23.1.132 so I know the port is listening
> and not blocked by a firewall.
>

The debug logs are showing that it's connecting as well and if it were not,
you'd get a definitive error in the logs.  The problem you're seeing is
different.

The 400 response is from Tomcat or your app.  What do you see on the Tomcat
/ application side of the logs?  Also, what is originating the request and
what does the request you are sending look like?  Maybe it's legitimately a
bad request?

Dan


>
> I'm not really sure what else to try.
>
> Sorry if this is the wrong forum.
>
> Thanks,
> Charles
>