Having some trouble creating a health monitor for our OWA through ISA site

I should also note that I'm only using the basic HTTPS monitor now, which only confirms that SSL traffic is reaching ISA. I conducted a failure test (took down the backend Exchange Client Access systems) to simulate a failure and the LTM did not know that the backend was in a bad state. As I feared, a simple HTTPS monitor only confirmed that the SSL port is up on the frontend NIC of the ISA hosts.

 

 

So as I mentioned I'm now trying to configure a more intelligent monitor - one in which the LTM calls the OWA application and passes login credentials, then pattern matches something off of the resulting page. Here's what I've been testing with, to no avail:

 

 

SEND: GET /owa HTTP/1.1\r\nHost: dev.mail.company.com\r\nConnection: Close\r\n\r\n

 

RECV: Set-Cookie: cada (I chose this because I found that I have a cookie, which starts with this string, set upon successful login to OWA)

 

 

I also did some TCPDUMPs as well to dig into the failing HTTPS monitor traffic and for some reason the SSL cert key was not able to decrypt the capture traffic so I couldn't really tell where or why the probe was failing. So, still flying blind here!

 

 

Any help is much appreciated. Thank you all in advance.

 

 

Regards,

 

Brian

I should also note that I'm only using the basic HTTPS monitor now, which only confirms that SSL traffic is reaching ISA. I conducted a failure test (took down the backend Exchange Client Access systems) to simulate a failure and the LTM did not know that the backend was in a bad state. As I feared, a simple HTTPS monitor only confirmed that the SSL port is up on the frontend NIC of the ISA hosts.

 

 

So as I mentioned I'm now trying to configure a more intelligent monitor - one in which the LTM calls the OWA application and passes login credentials, then pattern matches something off of the resulting page. Here's what I've been testing with, to no avail:

 

 

SEND: GET /owa HTTP/1.1\r\nHost: dev.mail.company.com\r\nConnection: Close\r\n\r\n

 

RECV: Set-Cookie: cada (I chose this because I found that I have a cookie, which starts with this string, set upon successful login to OWA)

 

 

I also did some TCPDUMPs as well to dig into the failing HTTPS monitor traffic and for some reason the SSL cert key was not able to decrypt the capture traffic so I couldn't really tell where or why the probe was failing. So, still flying blind here!

 

 

Any help is much appreciated. Thank you all in advance.

 

 

Regards,

 

Brian

Hi Brian,

 

 

Can you try enabling bigd debug, retest and check the output in /var/log/bigdlog?

 

 

http://devcentral.f5.com/wiki/AdvDesignConfig.TroubleshootingLtmMonitors.ashx

 

 

Do you see any errors or logs on ISA for the failing monitor requests? How about on the web server(s)?

 

 

Aaron

Hi Aaron,

 

 

I did check the bigdlog and didn't find anything useful. I see a 400 Bad Request but I'm just not sure what. I've put the output below in case you see anything I should clue in on. I will check the ISA/OWA logs next.. Thanks for the continued advice! I think getting the Wireshark trace decrypted would help a lot.. just don't know if I can get that working just yet.

 

 

Oh, I noticed the bigdlog file is growing at a rate of 250MB every 5 hours. How do I disable it again?

 

 

Thanks!

 

Brian

 

 

BIGDLOG output (for monitor in question):

 

 

 

2012-01-20 19:20:50.103037: ID 408 :(_do_ping): time to ping, now=1327105250.098992 [ addr=::ffff:192.168.253.170:443 mon=https fd=-1 pend=0 up_intvl=5 dn_intvl=5 timeout=16 time_until_up=0 immed=0 next_ping=1327105250.008992 last_ping=1327105245.068992 deadline=1327105266.008992 snd_cnt=2349 rcv_cnt=2349 ]

 

2012-01-20 19:20:50.103113: ID 408 :(_send_active_service_ping): pinging [ addr=::ffff:192.168.253.170:443 srcaddr=none ]

 

2012-01-20 19:20:50.103188: ID 408 :(_connect_to_service): creating new socket [ addr=::ffff:192.168.253.170:443 ]

 

2012-01-20 19:20:50.103313: ID 408 :(_connect_to_service): connect: Operation now in progress [ addr=::ffff:192.168.253.170:443 srcaddr=::ffff:192.168.253.5:50862 ]

 

2012-01-20 19:20:50.103414: ID global:(_main_loop): about to select for 0.100000s

 

2012-01-20 19:20:50.104799: ID 408 :(_main_loop): wfd selected [ addr=::ffff:192.168.253.170:443 srcaddr=::ffff:192.168.253.5:50862 fd=37 pend=1 ]

 

2012-01-20 19:20:50.104928: ID 408 :(_send_active_service_ping): pinging [ addr=::ffff:192.168.253.170:443 srcaddr=::ffff:192.168.253.5:50862 ]

 

2012-01-20 19:20:50.105036: ID 408 :(_send_active_service_ping): writing [ addr=::ffff:192.168.253.170:443 srcaddr=::ffff:192.168.253.5:50862 ] send=GET /\x0d\x0a

 

 

2012-01-20 19:20:50.105300: ID global:(_main_loop): about to select for 0.090000s

 

2012-01-20 19:20:50.106791: ID 408 :(_main_loop): rfd selected [ addr=::ffff:192.168.253.170:443 srcaddr=::ffff:192.168.253.5:50862 fd=37 pend=0 ]

 

2012-01-20 19:20:50.106924: ID 408 :(_recv_active_service_ping): reading [ addr=::ffff:192.168.253.170:443 srcaddr=::ffff:192.168.253.5:50862 ]

 

2012-01-20 19:20:50.107003: ID 408 :(_send_active_service_ping): pinging [ addr=::ffff:192.168.253.170:443 srcaddr=::ffff:192.168.253.5:50862 ]

 

2012-01-20 19:20:50.107074: ID 408 :(_send_active_service_ping): writing [ addr=::ffff:192.168.253.170:443 srcaddr=::ffff:192.168.253.5:50862 ] send=GET /\x0d\x0a

 

 

2012-01-20 19:20:50.107352: ID 408 :(_send_active_service_ping): sent ping [ addr=::ffff:192.168.253.170:443 srcaddr=::ffff:192.168.253.5:50862 ]

 

2012-01-20 19:20:50.107458: ID global:(_main_loop): about to select for 0.090000s

 

2012-01-20 19:20:50.108781: ID 408 :(_main_loop): rfd selected [ addr=::ffff:192.168.253.170:443 srcaddr=::ffff:192.168.253.5:50862 fd=37 pend=0 ]

 

2012-01-20 19:20:50.108872: ID 408 :(_recv_active_service_ping): reading [ addr=::ffff:192.168.253.170:443 srcaddr=::ffff:192.168.253.5:50862 ]

 

2012-01-20 19:20:50.109064: ID 408 :(_recv_active_service_ping): rcvd 2111 bytes: -->HTTP/1.1 400 Bad Request ( The data is invalid. )\x0d\x0aConnection: close\x0d\x0aPragma: no-cache\x0d\x0aCache-Control: no-cache\x0d\x0aContent-Type: text/html\x0d\x0aContent-Length: 1946 \x0d\x0a\x0d\x0a\x0d\x0aThe page cannot be displayed\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a \x0d\x0a

\x0d\x0a \x0d\x0a The page cannot be displayed\x0d\x0a

 

\x0d\x0a

\x0d\x0a Explanation: There is a problem with the page you are trying to reach and it cannot be displayed.

 

\x0d\x0a

\x0d\x0a \x0d\x0a \x0d\x0a\x0d\x0a Try the following: \x0d\x0a \x0d\x0a Refresh page: Search for the page again by clicking the Refresh button. The timeout may have occurred due to Internet congestion.\x0d\x0a Check spelling: Check that you typed the Web page address correctly. The address may have been mistyped.\x0d\x0a Access from a link: If there is a link to the page you are looking for, try accessing the page from that link.\x0d\x0a\x0d\x0a \x0d\x0a \x0d\x0a\x0d\x0a Technical Information (for support personnel) \x0d\x0a \x0d\x0a Error Code: 400 Bad Request. The data is invalid. (13)\x0d\x0a\x0d\x0a

 

\x0d\x0a\x0d\x0a<-- [ addr=::ffff:192.168.253.170:443 srcaddr=::ffff:192.168.253.5:50862 ]

 

2012-01-20 19:20:50.109169: ID 408 :(_ssl_shutdown_service): shutting down, return ssl true [ addr=::ffff:192.168.253.170:443 srcaddr=::ffff:192.168.253.5:50862 mon=https fd=37 ]

 

2012-01-20 19:20:50.109291: ID 408 :(_ssl_shutdown_service_internal): recurse from 388

 

[ addr=::ffff:192.168.253.170:443 mon=https ]

 

2012-01-20 19:20:50.109371: ID 408 :(_ssl_shutdown_service): shutting down, return ssl true [ addr=::ffff:192.168.253.170:443 srcaddr=::ffff:192.168.253.5:50862 mon=https fd=37 ]

 

2012-01-20 19:20:50.109455: ID 408 :(_recv_active_service_ping): got data [ addr=::ffff:192.168.253.170:443 srcaddr=none ]

 

b db bigd.debug [enable | disable]

 

 

* Enables or disables debug on bigd. Output is written to /var/log/bigdlog

 

Note: The logging is very verbose and increases resource usage. So debug should be enabled sparingly and disabled when troubleshooting is complete.

 

 

That bigdlog just shows a GET /\r\n request being sent which the server answers with a 400. Do you have logs of this request failing?

 

 

GET /owa HTTP/1.1\r\nHost: dev.mail.company.com\r\nConnection: Close\r\n\r\n

 

 

Aaron

Oddly, that is almost definitely the request for the /owa page. I wonder if the bigdlog can't show the full request as it's encrypted via SSL. I filtered the bigdlog for the IP address of the pool member ISA server, which is the 192.168.253.170 you see above. I dont see any of the full request components in the log though. I think the SSL encryption is throwing me off.. but not positive.

Hey Aaron,

 

 

So I circled back to work on this today and here's the latest. I've configured a standard HTTP monitor and captured the bigdlog output as well. Although I've specified the username/password in the appropriate fields (and we're using Basic Authentication on the site), the monitor still seems to fail with a 401 Unauthorized. I have confirmed that I'm using the right username and password at least five times. Any ideas on where to go next? I am able to use these credentials to login to the site directly and view my Inbox.

 

 

Thanks!

 

B

 

 

BigDLog output (grepped for this monitor session ID):

 

 

2012-01-31 11:02:52.969796: ID 443 :(_analyze_pings): visit DOWN, now=1328025772.968992 [ addr=::ffff:192.168.253.171:443 mon=https_isa_dev_mail fd=-1 pend=0 up_intvl=5 dn_intvl=5 timeout=16 time_until_up=0 immed=0 next_ping=1328025773.858992 last_ping=1328025768.948992 deadline=1328025772.948992 snd_cnt=15 rcv_cnt=0 ]

 

2012-01-31 11:02:53.866114: ID 443 :(_do_ping): time to ping, now=1328025773.868992 [ addr=::ffff:192.168.253.171:443 mon=https_isa_dev_mail fd=-1 pend=0 up_intvl=5 dn_intvl=5 timeout=16 time_until_up=0 immed=0 next_ping=1328025773.858992 last_ping=1328025768.948992 deadline=1328025777.968992 snd_cnt=15 rcv_cnt=0 ]

 

2012-01-31 11:02:53.866230: ID 443 :(_send_active_service_ping): pinging [ addr=::ffff:192.168.253.171:443 srcaddr=none ]

 

2012-01-31 11:02:53.866299: ID 443 :(_connect_to_service): creating new socket [ addr=::ffff:192.168.253.171:443 ]

 

2012-01-31 11:02:53.866469: ID 443 :(_connect_to_service): connect: Operation now in progress [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:26840 ]

 

2012-01-31 11:02:53.867500: ID 443 :(_main_loop): wfd selected [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:26840 fd=31 pend=1 ]

 

2012-01-31 11:02:53.867635: ID 443 :(_send_active_service_ping): pinging [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:26840 ]

 

2012-01-31 11:02:53.867743: ID 443 :(_send_active_service_ping): writing [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:26840 ] send=GET /owa HTTP/1.1\x0d\x0aHost: dev.mail.lifetech.com\x0d\x0aConnection: Close\x0d\x0a\x0d\x0aAuthorization: Basic YnJpYW4ubWF5ZXJAZGV2Lmludml0cm9nZW4ubmV0OlBhc3N3b3JkMTIz\x0d\x0a\x0d\x0a

 

2012-01-31 11:02:53.869517: ID 443 :(_main_loop): rfd selected [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:26840 fd=31 pend=0 ]

 

2012-01-31 11:02:53.869628: ID 443 :(_recv_active_service_ping): reading [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:26840 ]

 

2012-01-31 11:02:53.869704: ID 443 :(_send_active_service_ping): pinging [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:26840 ]

 

2012-01-31 11:02:53.869781: ID 443 :(_send_active_service_ping): writing [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:26840 ] send=GET /owa HTTP/1.1\x0d\x0aHost: dev.mail.lifetech.com\x0d\x0aConnection: Close\x0d\x0a\x0d\x0aAuthorization: Basic YnJpYW4ubWF5ZXJAZGV2Lmludml0cm9nZW4ubmV0OlBhc3N3b3JkMTIz\x0d\x0a\x0d\x0a

 

2012-01-31 11:02:53.870087: ID 443 :(_send_active_service_ping): sent ping [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:26840 ]

 

2012-01-31 11:02:53.871513: ID 443 :(_main_loop): rfd selected [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:26840 fd=31 pend=0 ]

 

2012-01-31 11:02:53.871603: ID 443 :(_recv_active_service_ping): reading [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:26840 ]

 

2012-01-31 11:02:53.871800: ID 443 :(_recv_active_service_ping): rcvd 2390 bytes: -->HTTP/1.1 401 Unauthorized ( The server requires authorization to fulfill the request. Access to the Web server is denied. Contact the server administrator. )\x0d\x0aWWW-Authenticate: Basic Realm="dev.mail.lifetech.com"\x0d\x0aConnection: Keep-Alive\x0d\x0aPragma: no-cache\x0d\x0aCache-Control: no-cache\x0d\x0aContent-Type: text/html\x0d\x0aContent-Length: 2057 \x0d\x0a\x0d\x0a\x0d\x0aThe page cannot be displayed\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a \x0d\x0a

\x0d\x0a \x0d\x0a The page cannot be displayed\x0d\x0a

 

\x0d\x0a

\x0d\x0a Explanation: There is a problem with the page you are trying to reach and it cannot be displayed.

 

\x0d\x0a

\x0d\x0a \x0d\x0a \x0d\x0a\x0d\x0a Try the following: \x0d\x0a \x0d\x0a Refresh page: Search for the page again by clicking the Refresh button. The timeout may have occurred due to Internet congestion.\x0d\x0a Check spelling: Check that you typed the Web page address correctly. The address may have been mistyped.\x0d\x0a Access from a link: If there is a link to the page you are looking for, try accessing the page from that link.\x0d\x0a\x0d\x0a \x0d\x0a \x0d\x0a\x0d\x0a Technical Information (for support personnel) \x0d\x0a \x0d\x0a Error Code: 401 Unauthorized. The server requires authorization to fulfill the request. Access to the Web server is denied. Contact the server administrator. (12209)\x0d\x0a\x0d\x0a

 

\x0d\x0a\x0d\x0a<-- [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:26840 ]

 

2012-01-31 11:02:53.871908: ID 443 :(_recv_active_service_ping): Response did not match recv regex yet [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:26840 ]

 

2012-01-31 11:02:53.872098: ID 443 :(_main_loop): rfd selected [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:26840 fd=31 pend=0 ]

 

2012-01-31 11:02:53.872171: ID 443 :(_recv_active_service_ping): reading [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:26840 ]

 

2012-01-31 11:02:53.873244: ID 443 :(_main_loop): rfd selected [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:26840 fd=31 pend=0 ]

 

I should also note my health monitor settings:

 

 

monitor https_isa_dev_mail {

 

defaults from https

 

password "Password123"

 

recv "Tahoma,Arial,Helvetica"

 

send "GET /owa/8.3.192.1/themes/base/owafont.css HTTP/1.1\r\nHost: dev.mail.lifetech.com\r\nConnection: Close\r\n\r\n"

 

username "first.last@dev.invitrogen.net"

 

}

 

 

I must use the UPN syntax for the username as that is the only way Exchange is able to locate the account in Active Directory.

 

 

Thanks

 

Brian

 

 

 

I tried updating the monitor to look for a static object on the internal OWA web server (a CSS page), but I'm still getting the 401 errors:

 

 

 

2012-01-31 11:27:52.167483: ID 443 :(_send_active_service_ping): pinging [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:8631 ]

 

2012-01-31 11:27:52.167587: ID 443 :(_send_active_service_ping): writing [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:8631 ] send=GET /owa/8.3.192.1/themes/base/owafont.css HTTP/1.1\x0d\x0aHost: dev.mail.lifetech.com\x0d\x0aConnection: Close\x0d\x0a\x0d\x0aAuthorization: Basic YnJpYW4ubWF5ZXJAZGV2Lmludml0cm9nZW4ubmV0OlBhc3N3b3JkMTIz\x0d\x0a\x0d\x0a

 

2012-01-31 11:27:52.167909: ID 443 :(_send_active_service_ping): sent ping [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:8631 ]

 

2012-01-31 11:27:52.169870: ID 443 :(_main_loop): rfd selected [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:8631 fd=25 pend=0 ]

 

2012-01-31 11:27:52.169969: ID 443 :(_recv_active_service_ping): reading [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:8631 ]

 

2012-01-31 11:27:52.170324: ID 443 :(_recv_active_service_ping): rcvd 2390 bytes: -->HTTP/1.1 401 Unauthorized ( The server requires authorization to fulfill the request. Access to the Web server is denied. Contact the server administrator. )\x0d\x0aWWW-Authenticate: Basic Realm="dev.mail.lifetech.com"\x0d\x0aConnection: Keep-Alive\x0d\x0aPragma: no-cache\x0d\x0aCache-Control: no-cache\x0d\x0aContent-Type: text/html\x0d\x0aContent-Length: 2057 \x0d\x0a\x0d\x0a\x0d\x0aThe page cannot be displayed\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a\x0d\x0a \x0d\x0a

\x0d\x0a \x0d\x0a The page cannot be displayed\x0d\x0a

 

\x0d\x0a

\x0d\x0a Explanation: There is a problem with the page you are trying to reach and it cannot be displayed.

 

\x0d\x0a

\x0d\x0a \x0d\x0a \x0d\x0a\x0d\x0a Try the following: \x0d\x0a \x0d\x0a Refresh page: Search for the page again by clicking the Refresh button. The timeout may have occurred due to Internet congestion.\x0d\x0a Check spelling: Check that you typed the Web page address correctly. The address may have been mistyped.\x0d\x0a Access from a link: If there is a link to the page you are looking for, try accessing the page from that link.\x0d\x0a\x0d\x0a \x0d\x0a \x0d\x0a\x0d\x0a Technical Information (for support personnel) \x0d\x0a \x0d\x0a Error Code: 401 Unauthorized. The server requires authorization to fulfill the request. Access to the Web server is denied. Contact the server administrator. (12209)\x0d\x0a\x0d\x0a

 

\x0d\x0a\x0d\x0a<-- [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:8631 ]

 

2012-01-31 11:27:52.170546: ID 443 :(_recv_active_service_ping): Response did not match recv regex yet [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:8631 ]

 

2012-01-31 11:27:52.171539: ID 443 :(_main_loop): rfd selected [ addr=::ffff:192.168.253.171:443 srcaddr=::ffff:192.168.253.5:8631 fd=25 pend=0 ]

 

I'm not sure why you're getting a 401. One thing to note that I forgot is that if you're using the username and password fields on the monitor, you should terminate the send string with one \r\n as the monitoring daemon appends the Authorization header after the send string along with two \r\n's to terminate the request.

 

 

I just tested on 10.2.1 with our OWA server. This example worked:

 

 

GET /owa/auth/logon.aspx HTTP/1.1\r\nAuthorization: Basic dXNlcm5hbWU6cGFzc3dvcmQ=\r\nUser-Agent: LTM-Monitor\r\nHost: owa.example.com\r\nAccept: */*\r\n\r\n

 

 

Instead of setting the user/pass in the monitor fields, I just base64 encoded them manually and set that in the Authorization header. Can you give something like this a try?

 

 

Aaron

Also, if that doesn't work, can you try testing using curl from the LTM command line to the pool member and then direct to the OWA server (if you can bypass the ISA)?

 

 

curl -kv https://1.1.1.1/owa/auth/logon.aspx -H "Host: owa.example.com" -u my_user

 

 

You'll be prompted for the basic auth password before curl sends the request.

 

 

Aaron