Newly created user cannot log into a new realm

I have created a new realm with the onboard script, and now creating a new user for that realm with the create-user script.

Actual result: The newly created user cannot log into the system. The UI displays - 'Your email address and/or password were not recognized'

Expected result: The user would be able to log into the realm with the email/password provided in the script.

In the script output, it looks like the user is created, and its seen in the db, please note the nullpointer at the end.

Create user script and output:

[jelliott@aq-qa-tomcat1 groovy]$ groovy create-user.groovy -ah http://aq-qa-tomcat1 -u jelliott@thesearchagency.com -ra reseller2 -d "jen user2" -r sales -l en -c us -active true -p jenTest2
Caught: java.lang.StringIndexOutOfBoundsException: String index out of range: -8
java.lang.StringIndexOutOfBoundsException: String index out of range: -8
at java_lang_String$substring.call(Unknown Source)
at create-user.run(create-user.groovy:90)
[jelliott@aq-qa-tomcat1 groovy]$ groovy create-user.groovy -ah http://aq-qa-tomcat1:8080/sapi/rest/ -u jelliott@thesearchagency.com -ra reseller2 -d "jen user2" -r sales -l en -c us -active true -p jenTest2
INFO - API Host: http://aq-qa-tomcat1:8080/sapi/rest/
INFO - Protocol: http
INFO - API Host name: aq-qa-tomcat1
INFO - Port Number: 8080
Please enter the password for admin+tsa@thesearchagency.com:
DEBUG - Logging in as TSA Admin
DEBUG - username = admin+tsa@thesearchagency.com, password = admin, realm alias = thesearchagency

DEBUG - response status: HTTP/1.1 200 OK
DEBUG - Headers: -----------
DEBUG - Server : Apache-Coyote/1.1
DEBUG - Expires : -1
DEBUG - Cache-Control : no-cache
DEBUG - Pragma : no-cache
DEBUG - X-AML-API-ID : 621e56d2-63c2-4e5f-a7c3-ea44047413a4
DEBUG - Date : Thu, 14 Feb 2013 15:22:10 GMT
DEBUG - Content-Type : text/plain
DEBUG - Transfer-Encoding : chunked
DEBUG - Response data: -----
DEBUG - X2CU34D5NWDJVF5XDLKFPPF62BSWAXBLZM4YO5SEVGFMW665DFQKIGDKC72KGG7HP63KKAIB2YTDPWLKOJFMSYBBHB2XF7C6QEBN4352JHPHSUAZZMLKIKRPVVC233URONSSQPTKHW4XFJRYL7K76BHFB2S4QTKKQN6Q2BOTCXUZDM6ZHRYUC2JRGQQGXJXSWMWB7JUXDGSGAQNMMCGZGIXZJPI4BHV4GNBJRTI=
DEBUG - --------------------

INFO - Creating the new user
DEBUG -
{
'displayName' : 'jen user2',
'countryCode' : 'us',
'active' : true,
'language' : 'en',
'realm' : 'com.reseller2',
'email' : 'jelliott@thesearchagency.com'
}

Feb 14, 2013 3:22:10 PM groovyx.net.http.ParserRegistry getAt
WARNING: Cannot find parser for content-type: application/json, text/plain – using default parser.
DEBUG - response status: HTTP/1.1 200 OK
DEBUG - Headers: -----------
DEBUG - Server : Apache-Coyote/1.1
DEBUG - Expires : -1
DEBUG - Cache-Control : no-cache
DEBUG - Pragma : no-cache
DEBUG - X-AML-API-ID : 02e50232-a140-4366-a7a2-a69fa52f614d
DEBUG - Date : Thu, 14 Feb 2013 15:22:10 GMT
DEBUG - Content-Type : application/json
DEBUG - Transfer-Encoding : chunked
DEBUG - Response data: -----
DEBUG - {lastName=, birthday=null, lastLoginDate=1970-01-01T00:00:00.000+0000, countryCode=us, workPhoneExtension=null, properties=

{password=ZW6ZRgnk}

, homePhone=, id=7bf6cf7d-7410-46c9-8238-be27f89ff21a, timezone=EST, organization=, mobilePhone=, createdBy=c7542d20-f6ba-4784-842b-9202a92190e2, realm=com.reseller2, email=jelliott@thesearchagency.com, description=, lastModifiedBy=c7542d20-f6ba-4784-842b-9202a92190e2, gender=M, lastModifiedDate=2013-02-14T15:22:10.000+0000, active=true, language=en, firstName=, workPhone=, displayName=jen user2, createdDate=2013-02-14T15:22:10.000+0000}
DEBUG - --------------------

INFO - Adding jen user2 to reseller group
DEBUG - Searching for reseller role

DEBUG - response status: HTTP/1.1 200 OK
DEBUG - Headers: -----------
DEBUG - Server : Apache-Coyote/1.1
DEBUG - Expires : -1
DEBUG - Cache-Control : no-cache
DEBUG - Pragma : no-cache
DEBUG - X-AML-API-ID : 73f7cc7c-6bb2-4949-9645-16f455c0b1b0
DEBUG - Date : Thu, 14 Feb 2013 15:22:10 GMT
DEBUG - Content-Type : application/json
DEBUG - Transfer-Encoding : chunked
DEBUG - Response data: -----
DEBUG - {total=1, results=[

{id=183219bc-0a71-4e4d-9232-dafc1fb09c1f, createdBy=admin, realm=com.thesearchagency, description=Role for resellers, name=reseller, lastModifiedBy=admin, active=true, lastModifiedDate=1970-01-01T01:01:01.000+0000, displayName=Reseller Role, createdDate=1970-01-01T01:01:01.000+0000}

]}
DEBUG - --------------------

DEBUG - Retrieving all groups with the reseller role

DEBUG - response status: HTTP/1.1 200 OK
DEBUG - Headers: -----------
DEBUG - Server : Apache-Coyote/1.1
DEBUG - Expires : -1
DEBUG - Cache-Control : no-cache
DEBUG - Pragma : no-cache
DEBUG - X-AML-API-ID : e0c33c04-2795-452a-8a8f-8c18e2539b0e
DEBUG - Date : Thu, 14 Feb 2013 15:22:11 GMT
DEBUG - Content-Type : application/json
DEBUG - Transfer-Encoding : chunked
DEBUG - Response data: -----
DEBUG - [[4cdb43c1-bf60-4a59-8cdb-43c1bf60ea59, G], [1111a81e-1197-4a79-9111-a81e11973a79, G], [d5bb5e72-82f9-4ba4-8d16-0ff49ed21bcc, G]]
DEBUG - --------------------

DEBUG - Searching for reseller group

DEBUG - response status: HTTP/1.1 200 OK
DEBUG - Headers: -----------
DEBUG - Server : Apache-Coyote/1.1
DEBUG - Expires : -1
DEBUG - Cache-Control : no-cache
DEBUG - Pragma : no-cache
DEBUG - X-AML-API-ID : 5c830547-921e-4ba3-af86-961aaf1feb18
DEBUG - Date : Thu, 14 Feb 2013 15:22:11 GMT
DEBUG - Content-Type : application/json
DEBUG - Transfer-Encoding : chunked
DEBUG - Response data: -----
DEBUG -

{id=4cdb43c1-bf60-4a59-8cdb-43c1bf60ea59, createdBy=c7542d20-f6ba-4784-842b-9202a92190e2, realm=com.reseller1, description=Reseller 1 group, name=reseller1Group, lastModifiedBy=c7542d20-f6ba-4784-842b-9202a92190e2, active=true, lastModifiedDate=1970-01-01T01:01:01.000+0000, displayName=Reseller 1, createdDate=1970-01-01T01:01:01.000+0000}

DEBUG - --------------------

DEBUG - response status: HTTP/1.1 200 OK
DEBUG - Headers: -----------
DEBUG - Server : Apache-Coyote/1.1
DEBUG - Expires : -1
DEBUG - Cache-Control : no-cache
DEBUG - Pragma : no-cache
DEBUG - X-AML-API-ID : 94515a9d-5d77-4ef4-89ae-659a171d44c1
DEBUG - Date : Thu, 14 Feb 2013 15:22:11 GMT
DEBUG - Content-Type : application/json
DEBUG - Transfer-Encoding : chunked
DEBUG - Response data: -----
DEBUG -

{id=1111a81e-1197-4a79-9111-a81e11973a79, createdBy=c7542d20-f6ba-4784-842b-9202a92190e2, realm=com.optus, description=Optus reseller group, name=optusGroup, lastModifiedBy=c7542d20-f6ba-4784-842b-9202a92190e2, active=true, lastModifiedDate=1970-01-01T01:01:01.000+0000, displayName=Optus, createdDate=1970-01-01T01:01:01.000+0000}

DEBUG - --------------------

DEBUG - response status: HTTP/1.1 200 OK
DEBUG - Headers: -----------
DEBUG - Server : Apache-Coyote/1.1
DEBUG - Expires : -1
DEBUG - Cache-Control : no-cache
DEBUG - Pragma : no-cache
DEBUG - X-AML-API-ID : d1b7824b-ee01-47c5-88f5-70dbe7c5f4f3
DEBUG - Date : Thu, 14 Feb 2013 15:22:11 GMT
DEBUG - Content-Type : application/json
DEBUG - Transfer-Encoding : chunked
DEBUG - Response data: -----
DEBUG -

{id=d5bb5e72-82f9-4ba4-8d16-0ff49ed21bcc, createdBy=c7542d20-f6ba-4784-842b-9202a92190e2, realm=com.thesearchagency, description=Reseller Account, name=reseller, lastModifiedBy=c7542d20-f6ba-4784-842b-9202a92190e2, active=true, lastModifiedDate=1970-01-01T01:01:01.000+0000, displayName=Resellers, createdDate=1970-01-01T01:01:01.000+0000}

DEBUG - --------------------

Caught: java.lang.NullPointerException: Cannot invoke method getAt() on null object
java.lang.NullPointerException: Cannot invoke method getAt() on null object
at create-user.run(create-user.groovy:453)

Tomcat log:
2013-02-14 15:28:30,459-23641973 [http-8080-10] INFO org.apache.cxf.interceptor.LoggingInInterceptor [] - Inbound Message
----------------------------
ID: 347
Address: http://reseller2.aq-qa-tomcat1:8080/sapi/rest/security/tokens?username=jelliott%40thesearchagency.com&password=jenTest2&realm=reseller2
Http-Method: GET
Content-Type:
Headers:

{Accept=[application/json, text/plain], accept-encoding=[gzip, deflate], accept-language=[en-gb], connection=[keep-alive], Content-Type=[null], host=[reseller2.aq-qa-tomcat1:8080], referer=[http://reseller2.aq-qa-tomcat1:8080/reseller/], user-agent=[Mozilla/5.0 (Windows NT 6.1; WOW64; rv:18.0) Gecko/20100101 Firefox/18.0]}

--------------------------------------
2013-02-14 15:28:30,460-23641974 [http-8080-10] INFO com.thesearchagency.sapi.security.TokenParsingInterceptor [] - handleMessage
2013-02-14 15:28:30,460-23641974 [http-8080-10] DEBUG com.thesearchagency.sapi.security.TokenParsingInterceptor [] - Received query string: username=jelliott%40thesearchagency.com&password=jenTest2&realm=reseller2
2013-02-14 15:28:30,460-23641974 [http-8080-10] DEBUG com.thesearchagency.sapi.security.TokenParsingInterceptor [] - Extracted parameters:

{username=[jelliott@thesearchagency.com], password=[jenTest2], realm=[reseller2]}

2013-02-14 15:28:30,460-23641974 [http-8080-10] DEBUG com.thesearchagency.sapi.security.TokenParsingInterceptor [] - No context found, using guest context
2013-02-14 15:28:30,461-23641975 [http-8080-10] INFO com.thesearchagency.sapi.security.TokenParsingInterceptor [] - Adding (token 2013-02-14T08:54:51.178Z:[e042e3b8-b281-4851-a76d-acfabb994dec]:{}) context to message
2013-02-14 15:28:30,463-23641977 [http-8080-10] DEBUG com.thesearchagency.sapi.jaxrs.JAXRSContextProvider [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Found security context for e042e3b8-b281-4851-a76d-acfabb994dec
2013-02-14 15:28:30,463-23641977 [http-8080-10] DEBUG com.thesearchagency.sapi.jaxrs.JAXRSContextProvider [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Found tokenized security context: (token 2013-02-14T08:54:51.178Z:[e042e3b8-b281-4851-a76d-acfabb994dec]:{})
2013-02-14 15:28:30,463-23641977 [http-8080-10] DEBUG com.thesearchagency.sapi.jaxrs.JAXRSContextProvider [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Getting request context for e042e3b8-b281-4851-a76d-acfabb994dec in realm null
2013-02-14 15:28:30,463-23641977 [http-8080-10] DEBUG com.thesearchagency.util.PropertiesPropertySetFactory [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Property set for settings/null.properties is {}
2013-02-14 15:28:30,463-23641977 [http-8080-10] INFO com.thesearchagency.sapi.security.PermissionsCheckingInterceptor [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - handleMessage
2013-02-14 15:28:30,464-23641978 [http-8080-10] DEBUG com.thesearchagency.sapi.security.PermissionsCheckingInterceptor [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - resource: public javax.ws.rs.core.Response com.thesearchagency.sapi.services.security.SecurityService.getSecurityToken(com.thesearchagency.saas.core.services.IRequestContext,java.lang.String,java.lang.String,java.lang.String)
2013-02-14 15:28:30,464-23641978 [http-8080-10] DEBUG com.thesearchagency.sapi.security.PermissionsCheckingInterceptor [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Executing getSecurityToken
2013-02-14 15:28:30,464-23641978 [http-8080-10] DEBUG com.thesearchagency.sapi.security.PermissionsCheckingInterceptor [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Checking if the principal is active
2013-02-14 15:28:30,464-23641978 [http-8080-10] DEBUG com.thesearchagency.sapi.security.PermissionsCheckingInterceptor [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Getting data source for com_thesearchagency_saas_core_services_user_managers_UserManager
2013-02-14 15:28:30,469-23641983 [http-8080-10] DEBUG com.thesearchagency.sapi.security.PermissionsCheckingInterceptor [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Checking for execute permissions on SAPI:com.thesearchagency.sapi.services.security.SecurityService.getSecurityToken
2013-02-14 15:28:30,469-23641983 [http-8080-10] DEBUG com.thesearchagency.sapi.security.PermissionsCheckingInterceptor [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Getting data source for com_thesearchagency_saas_core_services_security_manager_TSASecurityManager
2013-02-14 15:28:30,471-23641985 [http-8080-10] DEBUG com.thesearchagency.saas.core.services.security.manager.TSASecurityManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Attempting to get permissions for principal e042e3b8-b281-4851-a76d-acfabb994dec
2013-02-14 15:28:30,482-23641996 [http-8080-10] INFO com.thesearchagency.saas.core.services.security.manager.TSASecurityManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - matching 'SAPI:execute:com.thesearchagency.sapi.services.security.SecurityService.getSecurityToken'.matches('SAPI:execute:com.thesearchagency.sapi.services.security.SecurityService.getForgotPasswordToken') -> false
2013-02-14 15:28:30,482-23641996 [http-8080-10] INFO com.thesearchagency.saas.core.services.security.manager.TSASecurityManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - matching 'SAPI:execute:com.thesearchagency.sapi.services.security.SecurityService.getSecurityToken'.matches('SAPI:execute:com.thesearchagency.sapi.services.security.SecurityService.getSecurityToken') -> true
2013-02-14 15:28:30,482-23641996 [http-8080-10] DEBUG com.thesearchagency.sapi.services.security.SecurityService [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Looking up realm for name 'reseller2'
2013-02-14 15:28:30,482-23641996 [http-8080-10] DEBUG com.thesearchagency.sapi.jaxrs.JAXRSContextProvider [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Getting data source for com_thesearchagency_saas_core_services_security_manager_TSASecurityManager
2013-02-14 15:28:30,483-23641997 [http-8080-10] DEBUG com.thesearchagency.database.storage.jdbc.JDBCStorageManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - query: SELECT *
WHERE Realm = 'reseller2'

2013-02-14 15:28:30,484-23641998 [http-8080-10] DEBUG com.thesearchagency.database.storage.jdbc.JDBCStorageManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - current 0 offset 0
2013-02-14 15:28:30,484-23641998 [http-8080-10] DEBUG com.thesearchagency.database.storage.jdbc.JDBCStorageManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - ret.size() == 0 desired 1024
2013-02-14 15:28:30,484-23641998 [http-8080-10] DEBUG com.thesearchagency.database.storage.jdbc.JDBCStorageManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - snarf data: ret.size() == 0 desired 1024
2013-02-14 15:28:30,485-23641999 [http-8080-10] DEBUG com.thesearchagency.database.storage.jdbc.JDBCStorageManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Fetch objects using query sql:
SELECT realms.realm,realms.id FROM realms WHERE (realms.realm = 'reseller2') LIMIT 0 , 150
2013-02-14 15:28:30,487-23642001 [http-8080-10] DEBUG com.thesearchagency.database.storage.jdbc.JDBCStorageManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - snarf data: ret.size() == 1 desired 1024
2013-02-14 15:28:30,487-23642001 [http-8080-10] DEBUG com.thesearchagency.database.storage.jdbc.JDBCStorageManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Fetch objects using query sql:
SELECT realms.realm,realms.id FROM realms WHERE (realms.realm = 'reseller2') LIMIT 150 , 150
2013-02-14 15:28:30,488-23642002 [http-8080-10] DEBUG com.thesearchagency.sapi.services.security.SecurityService [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Realm lookup evaluated to 'com.reseller2'
2013-02-14 15:28:30,488-23642002 [http-8080-10] DEBUG com.thesearchagency.sapi.services.security.SecurityService [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Getting token for 'jelliott@thesearchagency.com' with password 'jenTest2' in realm 'reseller2'
2013-02-14 15:28:30,488-23642002 [http-8080-10] DEBUG com.thesearchagency.saas.core.services.security.manager.TSASecurityManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Attempting authentication on the 'com.reseller2' realm for user 'jelliott@thesearchagency.com' using password 'jenTest2'
2013-02-14 15:28:30,488-23642002 [http-8080-10] DEBUG com.thesearchagency.sapi.jaxrs.JAXRSContextProvider [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Getting data source for com_thesearchagency_saas_core_services_security_manager_TSASecurityManager
2013-02-14 15:28:30,490-23642004 [http-8080-10] DEBUG com.thesearchagency.database.storage.jdbc.JDBCStorageManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - query: SELECT *
WHERE (Email = 'jelliott@thesearchagency.com') AND (Realm = 'com.reseller2')

2013-02-14 15:28:30,490-23642004 [http-8080-10] DEBUG com.thesearchagency.database.storage.jdbc.JDBCStorageManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - current 0 offset 0
2013-02-14 15:28:30,490-23642004 [http-8080-10] DEBUG com.thesearchagency.database.storage.jdbc.JDBCStorageManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - ret.size() == 0 desired 1024
2013-02-14 15:28:30,490-23642004 [http-8080-10] DEBUG com.thesearchagency.database.storage.jdbc.JDBCStorageManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - snarf data: ret.size() == 0 desired 1024
2013-02-14 15:28:30,491-23642005 [http-8080-10] DEBUG com.thesearchagency.database.storage.jdbc.JDBCStorageManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Fetch objects using query sql:
SELECT users.email,users.realm_id,users.id,users.salt,users.password FROM users WHERE ((users.email = 'jelliott@thesearchagency.com') AND (users.realm_id = 'com.reseller2')) LIMIT 0 , 150
2013-02-14 15:28:30,492-23642006 [http-8080-10] DEBUG com.thesearchagency.database.storage.jdbc.JDBCStorageManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - snarf data: ret.size() == 1 desired 1024
2013-02-14 15:28:30,492-23642006 [http-8080-10] DEBUG com.thesearchagency.database.storage.jdbc.JDBCStorageManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Fetch objects using query sql:
SELECT users.email,users.realm_id,users.id,users.salt,users.password FROM users WHERE ((users.email = 'jelliott@thesearchagency.com') AND (users.realm_id = 'com.reseller2')) LIMIT 150 , 150
2013-02-14 15:28:30,493-23642007 [http-8080-10] WARN com.thesearchagency.saas.core.services.security.manager.TSASecurityManager [timezone=UTC, principalId=, requestId=4a1ba6fa-ea88-495b-8272-2e7c05234c55, locale=en_GB, authToken=null, hostname=70.166.144.17, ipAddress=70.166.144.17] - Bad password 'jenTest2' passed for user 'jelliott@thesearchagency.com'
2013-02-14 15:28:30,494-23642008 [http-8080-10] DEBUG com.thesearchagency.sapi.jaxrs.CacheControlResponseHandler [] - Headers: null
2013-02-14 15:28:30,494-23642008 [http-8080-10] DEBUG com.thesearchagency.sapi.jaxrs.CacheControlResponseHandler [] - Adding Expires header
2013-02-14 15:28:30,503-23642017 [http-8080-10] DEBUG com.thesearchagency.sapi.jaxrs.CacheControlResponseHandler [] - Adding Cache-Control header
2013-02-14 15:28:30,503-23642017 [http-8080-10] DEBUG com.thesearchagency.sapi.jaxrs.CacheControlResponseHandler [] - Adding Pragma header
2013-02-14 15:28:30,505-23642019 [http-8080-10] INFO org.apache.cxf.interceptor.LoggingOutInterceptor [] - Outbound Message
---------------------------
ID: 347
Response-Code: 403
Content-Type: text/plain
Headers:

{Expires=[-1], Cache-Control=[no-cache], Pragma=[no-cache], Content-Type=[text/plain], X-AML-API-ID=[4a1ba6fa-ea88-495b-8272-2e7c05234c55], Date=[Thu, 14 Feb 2013 15:28:30 GMT]}

Payload: Invalid credentials
--------------------------------------
201