Authentication/feed collection via java/apache httpclient. Working on some servers not on others. (JSESSIONID changes after login)
I have a java program that uses apache httpclient for collecting RSS feeds. I don't have a lot of experience using httpclient or communicating with RTC servers but the code I have does work just fine on most servers I have tested. (both older servers and 4.0.2)
However there is a group of servers I am having an issue with. Below is the debug log starting with the POST response. It appears (based on my limited experience) I authenticate successfully but then the subsequent GET returns with authrequired as if I was not authenticated. I do notice that the JSESSIONID on the GET response is different from the original JSESSIONID, though I am not sure if this is a cause or effect.
Any idea's what could be going wrong here?
However there is a group of servers I am having an issue with. Below is the debug log starting with the POST response. It appears (based on my limited experience) I authenticate successfully but then the subsequent GET returns with authrequired as if I was not authenticated. I do notice that the JSESSIONID on the GET response is different from the original JSESSIONID, though I am not sure if this is a cause or effect.
Any idea's what could be going wrong here?
2013-07-19 13:22:04,565 DEBUG [main] - RTCCollector loginViaForm: POST Status: HTTP/1.1 302 Found 2013-07-19 13:22:04,566 DEBUG [main] - RTCCollector listVerboseDebugInfo: URL is: https://server.domain.com:9446/jazz/j_security_check
2013-07-19 13:22:04,566 DEBUG [main] - RTCCollector listVerboseDebugInfo: HTTP/1.1 302 Found
2013-07-19 13:22:04,566 DEBUG [main] - RTCCollector listVerboseDebugInfo: HEADERS: Server: Apache-Coyote/1.1
2013-07-19 13:22:04,566 DEBUG [main] - RTCCollector listVerboseDebugInfo: HEADERS: Location: https://server.domain.com:9446/jazz/secure/authenticated/identity?redirectPath=%2Fjazz%2Fsecure%2Fservice%2Fcom.ibm.team.repository.service.internal.webuiInitializer.IWebUIInitializerRestService%2FinitializationData
2013-07-19 13:22:04,566 DEBUG [main] - RTCCollector listVerboseDebugInfo: HEADERS: Content-Length: 0
2013-07-19 13:22:04,566 DEBUG [main] - RTCCollector listVerboseDebugInfo: HEADERS: Date: Fri, 19 Jul 2013 20:22:04 GMT
2013-07-19 13:22:04,566 DEBUG [main] - RTCCollector listVerboseDebugInfo: COOKIES: [version: 0][name: JSESSIONID][value: 4DBC096CF7E01496B57FE11FCE18C78B][domain: server.domain.com][path: /jazz/][expiry: null]
2013-07-19 13:22:04,567 DEBUG [main] - RTCCollector listVerboseDebugInfo: COOKIES: [version: 0][name: JazzFormAuth][value: Form][domain: server.domain.com][path: /jazz][expiry: null]
2013-07-19 13:22:04,567 DEBUG [main] - Releasing connection org.apache.http.impl.conn.SingleClientConnManager$ConnAdapter@29ce8c
2013-07-19 13:22:04,567 DEBUG [main] - RTCCollector listVerboseDebugInfo: GET HEADERS: Referer: https://server.domain.com:9446/jazz/service/com.ibm.team.repository.common.internal.IFeedService
2013-07-19 13:22:04,567 DEBUG [main] - RTCCollector listVerboseDebugInfo: GET HEADERS: X-Jazz-CSRF-Prevent: 4DBC096CF7E01496B57FE11FCE18C78B
2013-07-19 13:22:04,568 DEBUG [main] - RTCCollector listVerboseDebugInfo: Get request line is: GET https://server.domain.com:9446/jazz/service/com.ibm.team.repository.common.internal.IFeedService HTTP/1.1
2013-07-19 13:22:04,568 DEBUG [main] - Get connection for route HttpRoute[{s}->https://server.domain.com:9446]
2013-07-19 13:22:04,568 DEBUG [main] - Stale connection check
2013-07-19 13:22:04,569 DEBUG [main] - CookieSpec selected: best-match
2013-07-19 13:22:04,570 DEBUG [main] - Cookie [version: 0][name: JSESSIONID][value: 4DBC096CF7E01496B57FE11FCE18C78B][domain: server.domain.com][path: /jazz/][expiry: null] match [(secure)server.domain.com:9446/jazz/service/com.ibm.team.repository.common.internal.IFeedService]
2013-07-19 13:22:04,570 DEBUG [main] - Cookie [version: 0][name: JazzFormAuth][value: Form][domain: server.domain.com][path: /jazz][expiry: null] match [(secure)server.domain.com:9446/jazz/service/com.ibm.team.repository.common.internal.IFeedService]
2013-07-19 13:22:04,570 DEBUG [main] - Attempt 1 to execute request
2013-07-19 13:22:04,570 DEBUG [main] - Sending request: GET /jazz/service/com.ibm.team.repository.common.internal.IFeedService HTTP/1.1
2013-07-19 13:22:04,570 DEBUG [main] - >> "GET /jazz/service/com.ibm.team.repository.common.internal.IFeedService HTTP/1.1[\r][\n]"
2013-07-19 13:22:04,570 DEBUG [main] - >> "Referer: https://server.domain.com:9446/jazz/service/com.ibm.team.repository.common.internal.IFeedService[\r][\n]"
2013-07-19 13:22:04,570 DEBUG [main] - >> "X-Jazz-CSRF-Prevent: 4DBC096CF7E01496B57FE11FCE18C78B[\r][\n]"
2013-07-19 13:22:04,570 DEBUG [main] - >> "Host: server.domain.com:9446[\r][\n]"
2013-07-19 13:22:04,570 DEBUG [main] - >> "Connection: Keep-Alive[\r][\n]"
2013-07-19 13:22:04,571 DEBUG [main] - >> "User-Agent: Apache-HttpClient/4.1 (java 1.5)[\r][\n]"
2013-07-19 13:22:04,571 DEBUG [main] - >> "Cookie: JSESSIONID=4DBC096CF7E01496B57FE11FCE18C78B; JazzFormAuth=Form[\r][\n]"
2013-07-19 13:22:04,571 DEBUG [main] - >> "Cookie2: $Version=1[\r][\n]"
2013-07-19 13:22:04,571 DEBUG [main] - >> "[\r][\n]"
2013-07-19 13:22:04,571 DEBUG [main] - >> GET /jazz/service/com.ibm.team.repository.common.internal.IFeedService HTTP/1.1
2013-07-19 13:22:04,571 DEBUG [main] - >> Referer: https://server.domain.com:9446/jazz/service/com.ibm.team.repository.common.internal.IFeedService
2013-07-19 13:22:04,571
DEBUG [main] - >> X-Jazz-CSRF-Prevent: 4DBC096CF7E01496B57FE11FCE18C78B
2013-07-19 13:22:04,571 DEBUG [main] - >> Host: server.domain.com:9446
2013-07-19 13:22:04,571 DEBUG [main] - >> Connection: Keep-Alive
2013-07-19 13:22:04,571 DEBUG [main] - >> User-Agent: Apache-HttpClient/4.1 (java 1.5)
2013-07-19 13:22:04,571 DEBUG [main] - >> Cookie: JSESSIONID=4DBC096CF7E01496B57FE11FCE18C78B; JazzFormAuth=Form
2013-07-19 13:22:04,571 DEBUG [main] - >> Cookie2: $Version=1
2013-07-19 13:22:04,572 DEBUG [main] - << "HTTP/1.1 302 Found[\r][\n]"
2013-07-19 13:22:04,572 DEBUG [main] - << "Server: Apache-Coyote/1.1[\r][\n]"
2013-07-19 13:22:04,573 DEBUG [main] - << "Cache-Control: private[\r][\n]"
2013-07-19 13:22:04,573 DEBUG [main] - << "Expires: Wed, 31 Dec 1969 16:00:00 PST[\r][\n]"
2013-07-19 13:22:04,573 DEBUG [main] - << "X-com-ibm-team-repository-web-auth-msg: authrequired[\r][\n]"
2013-07-19 13:22:04,573 DEBUG [main] - << "Location: https://server.domain.com:9446/jazz/authenticated/identity?redirectPath=%2Fjazz%2Fservice%2Fcom.ibm.team.repository.common.internal.IFeedService[\r][\n]"
2013-07-19 13:22:04,573 DEBUG [main] - << "Content-Length: 0[\r][\n]"
2013-07-19 13:22:04,573 DEBUG [main] - << "Date: Fri, 19 Jul 2013 20:22:04 GMT[\r][\n]"
2013-07-19 13:22:04,573 DEBUG [main] - << "[\r][\n]"
2013-07-19 13:22:04,573 DEBUG [main] - Receiving response: HTTP/1.1 302 Found
2013-07-19 13:22:04,573 DEBUG [main] - << HTTP/1.1 302 Found
2013-07-19 13:22:04,573 DEBUG [main] - << Server: Apache-Coyote/1.1
2013-07-19 13:22:04,573 DEBUG [main] - << Cache-Control: private
2013-07-19 13:22:04,573 DEBUG [main] - << Expires: Wed, 31 Dec 1969 16:00:00 PST
2013-07-19 13:22:04,573 DEBUG [main] - << X-com-ibm-team-repository-web-auth-msg: authrequired
2013-07-19 13:22:04,573 DEBUG [main] - << Location: https://server.domain.com:9446/jazz/authenticated/identity?redirectPath=%2Fjazz%2Fservice%2Fcom.ibm.team.repository.common.internal.IFeedService
2013-07-19 13:22:04,573 DEBUG [main] - << Content-Length: 0
2013-07-19 13:22:04,573 DEBUG [main] - << Date: Fri, 19 Jul 2013 20:22:04 GMT
2013-07-19 13:22:04,574 DEBUG [main] - Connection can be kept alive indefinitely
2013-07-19 13:22:04,574 DEBUG [main] - Redirect requested to location 'https://server.domain.com:9446/jazz/authenticated/identity?redirectPath=%2Fjazz%2Fservice%2Fcom.ibm.team.repository.common.internal.IFeedService'
2013-07-19 13:22:04,574 DEBUG [main] - Redirecting to 'https://server.domain.com:9446/jazz/authenticated/identity?redirectPath=%2Fjazz%2Fservice%2Fcom.ibm.team.repository.common.internal.IFeedService' via HttpRoute[{s}->https://server.domain.com:9446]
2013-07-19 13:22:04,574 DEBUG [main] - CookieSpec selected: best-match
2013-07-19 13:22:04,575 DEBUG [main] - Cookie [version: 0][name: JSESSIONID][value: 4DBC096CF7E01496B57FE11FCE18C78B][domain: server.domain.com][path: /jazz/][expiry: null] match [(secure)server.domain.com:9446/jazz/authenticated/identity]
2013-07-19 13:22:04,575 DEBUG [main] - Cookie [version: 0][name: JazzFormAuth][value: Form][domain: server.domain.com][path: /jazz][expiry: null] match [(secure)server.domain.com:9446/jazz/authenticated/identity]
2013-07-19 13:22:04,575 DEBUG [main] - Attempt 2 to execute request
2013-07-19 13:22:04,575 DEBUG [main] - Sending request: GET /jazz/authenticated/identity?redirectPath=%2Fjazz%2Fservice%2Fcom.ibm.team.repository.common.internal.IFeedService HTTP/1.1
2013-07-19 13:22:04,575 DEBUG [main] - >> "GET /jazz/authenticated/identity?redirectPath=%2Fjazz%2Fservice%2Fcom.ibm.team.repository.common.internal.IFeedService HTTP/1.1[\r][\n]"
2013-07-19 13:22:04,575 DEBUG [main] - >> "Referer: https://server.domain.com:9446/jazz/service/com.ibm.team.repository.common.internal.IFeedService[\r][\n]"
2013-07-19 13:22:04,575 DEBUG [main] - >> "X-Jazz-CSRF-Prevent: 4DBC096CF7E01496B57FE11FCE18C78B[\r][\n]"
2013-07-19 13:22:04,575 DEBUG [main] - >> "Host: server.domain.com:9446[\r][\n]"
2013-07-19 13:22:04,575 DEBUG [main] - >> "Connection: Keep-Alive[\r][\n]"
2013-07-19 13:22:04,576 DEBUG [main] - >> "User-Agent: Apache-HttpClient/4.1 (java 1.5)[\r][\n]"
2013-07-19 13:22:04,576 DEBUG [main] - >> "Cookie: JSESSIONID=4DBC096CF7E01496B57FE11FCE18C78B; JazzFormAuth=Form[\r][\n]"
2013-07-19 13:22:04,576 DEBUG [main] - >> "Cookie2: $Version=1[\r][\n]"
2013-07-19 13:22:04,576 DEBUG [main] - >> "[\r][\n]"
2013-07-19 13:22:04,576 DEBUG [main] - >> GET /jazz/authenticated/identity?redirectPath=%2Fjazz%2Fservice%2Fcom.ibm.team.repository.common.internal.IFeedService HTTP/1.1
2013-07-19 13:22:04,576 DEBUG [main] - >> Referer: https://server.domain.com:9446/jazz/service/com.ibm.team.repository.common.internal.IFeedService
2013-07-19 13:22:04,576 DEBUG [main] - >> X-Jazz-CSRF-Prevent: 4DBC096CF7E01496B57FE11FCE18C78B
2013-07-19 13:22:04,576 DEBUG [main] - >> Host: server.domain.com:9446
2013-07-19 13:22:04,576 DEBUG [main] - >> Connection: Keep-Alive
2013-07-19 13:22:04,576 DEBUG [main] - >> User-Agent: Apache-HttpClient/4.1 (java 1.5)
2013-07-19 13:22:04,576 DEBUG [main] - >> Cookie: JSESSIONID=4DBC096CF7E01496B57FE11FCE18C78B; JazzFormAuth=Form
2013-07-19 13:22:04,576 DEBUG [main] - >> Cookie2: $Version=1
2013-07-19 13:22:04,579 DEBUG [main] - << "HTTP/1.1 200 OK[\r][\n]"
2013-07-19 13:22:04,579 DEBUG [main] - << "Server: Apache-Coyote/1.1[\r][\n]"
2013-07-19 13:22:04,579 DEBUG [main] - << "Cache-Control: private[\r][\n]"
2013-07-19 13:22:04,579 DEBUG [main] - << "Expires: Wed, 31 Dec 1969 16:00:00 PST[\r][\n]"
2013-07-19 13:22:04,579 DEBUG [main] - << "Set-Cookie: JSESSIONID=34C644BA68EC677D805C019E10448B95; Path=/jazz/; Secure; HttpOnly[\r][\n]"
2013-07-19 13:22:04,579 DEBUG [main] - << "Set-Cookie: JazzFormAuth=Form; Path=/jazz[\r][\n]"
2013-07-19 13:22:04,580 DEBUG [main] - << "X-com-ibm-team-repository-web-auth-msg: authrequired[\r][\n]"
2013-07-19 13:22:04,580 DEBUG [main] - << "Content-Type: text/html;charset=UTF-8[\r][\n]"
2013-07-19 13:22:04,580 DEBUG [main] - << "Content-Length: 2778[\r][\n]"
2013-07-19 13:22:04,580 DEBUG [main] - << "Date: Fri, 19 Jul 2013 20:22:04 GMT[\r][\n]"
2013-07-19 13:22:04,580 DEBUG [main] - << "[\r][\n]"
2013-07-19 13:22:04,580 DEBUG [main] - Receiving response: HTTP/1.1 200 OK
2013-07-19 13:22:04,580 DEBUG [main] - << HTTP/1.1 200 OK
2013-07-19 13:22:04,580 DEBUG [main] - << Server: Apache-Coyote/1.1
2013-07-19 13:22:04,580 DEBUG [main] - << Cache-Control: private
2013-07-19 13:22:04,580 DEBUG [main] - << Expires: Wed, 31 Dec 1969 16:00:00 PST
2013-07-19 13:22:04,580 DEBUG [main] - << Set-Cookie: JSESSIONID=34C644BA68EC677D805C019E10448B95; Path=/jazz/; Secure; HttpOnly
2013-07-19 13:22:04,580 DEBUG [main] - << Set-Cookie: JazzFormAuth=Form; Path=/jazz
2013-07-19 13:22:04,580 DEBUG [main] - << X-com-ibm-team-repository-web-auth-msg: authrequired
2013-07-19 13:22:04,580 DEBUG [main] - << Content-Type: text/html;charset=UTF-8
2013-07-19 13:22:04,580 DEBUG [main] - << Content-Length: 2778
2013-07-19 13:22:04,580 DEBUG [main] - << Date: Fri, 19 Jul 2013 20:22:04 GMT
2013-07-19 13:22:04,580 DEBUG [main] - Cookie accepted: "[version: 0][name: JSESSIONID][value: 34C644BA68EC677D805C019E10448B95][domain: server.domain.com][path: /jazz/][expiry: null]".
2013-07-19 13:22:04,581 DEBUG [main] - Cookie accepted: "[version: 0][name: JazzFormAuth][value: Form][domain: server.domain.com][path: /jazz][expiry: null]".
2013-07-19 13:22:04,581 DEBUG [main] - Connection can be kept alive indefinitely
2013-07-19 13:22:04,581 DEBUG [main] - RTCCollector getPage: GET Status: HTTP/1.1 200 OK
2013-07-19 13:22:04,581 DEBUG [main] - RTCCollector listVerboseDebugInfo: URL is: https://server.domain.com:9446/jazz/service/com.ibm.team.repository.common.internal.IFeedService
2013-07-19 13:22:04,581 DEBUG [main] - RTCCollector listVerboseDebugInfo: HTTP/1.1 200 OK
2013-07-19 13:22:04,581 DEBUG [main] - RTCCollector listVerboseDebugInfo: HEADERS: Server: Apache-Coyote/1.1
2013-07-19 13:22:04,582 DEBUG [main] - RTCCollector listVerboseDebugInfo: HEADERS: Cache-Control: private
2013-07-19 13:22:04,582 DEBUG [main] - RTCCollector listVerboseDebugInfo: HEADERS: Expires: Wed, 31 Dec 1969 16:00:00 PST
2013-07-19 13:22:04,582 DEBUG [main] - RTCCollector listVerboseDebugInfo: HEADERS: Set-Cookie: JSESSIONID=34C644BA68EC677D805C019E10448B95; Path=/jazz/; Secure; HttpOnly
2013-07-19 13:22:04,582 DEBUG [main] - RTCCollector listVerboseDebugInfo: HEADERS: Set-Cookie: JazzFormAuth=Form; Path=/jazz
2013-07-19 13:22:04,582 DEBUG [main] - RTCCollector listVerboseDebugInfo: HEADERS: X-com-ibm-team-repository-web-auth-msg: authrequired
2013-07-19 13:22:04,582 DEBUG [main] - RTCCollector listVerboseDebugInfo: HEADERS: Content-Type: text/html;charset=UTF-8
2013-07-19 13:22:04,582 DEBUG [main] - RTCCollector listVerboseDebugInfo: HEADERS: Content-Length: 2778
2013-07-19 13:22:04,582 DEBUG [main] - RTCCollector listVerboseDebugInfo: HEADERS: Date: Fri, 19 Jul 2013 20:22:04 GMT
2013-07-19 13:22:04,582 DEBUG [main] - RTCCollector listVerboseDebugInfo: COOKIES: [version: 0][name: JSESSIONID][value: 34C644BA68EC677D805C019E10448B95][domain: server.domain.com][path: /jazz/][expiry: null]
2013-07-19 13:22:04,583 DEBUG [main] - RTCCollector listVerboseDebugInfo: COOKIES: [version: 0][name: JazzFormAuth][value: Form][domain: server.domain.com][path: /jazz][expiry: null]
2013-07-19 13:22:04,583 ERROR [main] - RTCFeedCollector collectFeedViaFormAuth: Failed collecting feeds for https://server.domain.com:9446/jazz authrequired after successful POST