oauth-2.0opensocialibm-connectionsibm-sbt

IBM Connections keeps doing the OAuth dance for gadgets


I've got an embedded experience gadget configured for the IBM Connections activity stream. It seems that the OAuth dance never succeeds, only returning me to the beginning of the OAuth dance (prompt for authorisation).

I see errors like this:

[2/25/14 7:17:45:197 EST] 000000c2 BasicOAuth2Me 3   JSONException parsing response
                                 org.apache.commons.json.JSONException: Error occurred during input read.
Caused by: java.io.IOException: Unexpected character '<' on line 1, column 1
    at org.apache.commons.json.internal.Tokenizer.next(Tokenizer.java:185)
    at org.apache.commons.json.internal.Parser.parse(Parser.java:114)
    at org.apache.commons.json.internal.Parser.parse(Parser.java:85)
    at org.apache.commons.json.JSONObject.<init>(JSONObject.java:128)
    at org.json.JSONObject.<init>(JSONObject.java:41)

...which may suggest that XML is returned from something instead of JSON.

I'm also seeing POST /connections/opensocial/gadgets/makeRequest HTTP/1.1 returning:

HTTP/1.1 200 OK
Date: Tue, 25 Feb 2014 12:54:12 GMT
Server: IBM_HTTP_Server
X-Powered-By: Servlet/3.0
X-LConn-Auth: true
X-UA-Compatible: IE=EmulateIE7
Cache-Control: no-cache
Expires: Tue, 25 Feb 2014 12:54:12 GMT
Pragma: no-cache
Content-Disposition: attachment;filename=p.txt
Content-Length: 1029
Content-Type: application/json;charset=UTF-8
Content-Language: en-US

throw 1; < 'invalid javascript' > {"http://appfusions.demos.ibm.com:2990/jira/rest/api/2/issue/DEMO-12/transitions?expand=transitions.fields":{"rc":200,"body":"","oauthApprovalUrl":"http://appfusions.demos.ibm.com:2990/jira/plugins/servlet/af/oauth/authorize?client_id=8821f0cfd9264c4ed08b00861016886c&realGadgetUri=http%3A%2F%2Fappfusions.demos.ibm.com%3A2990%2Fjira%2Frest%2Fgadgets%2F1.0%2Fg%2Fcom.appfusions.jira.connections.jira-immersive-for-connections%3Aconnections-gadgets%2Fgadgets%2Fjira-ee.xml&redirect_uri=https%3A%2F%2Fconnectionsww.demos.ibm.com%2Fconnections%2Fopensocial%2Fgadgets%2Foauth2callback&response_type=code&state=WIn_8DLhmOeRc8aIYomi0j2XGIAAd7Ke3j2E4y9SbXpD6aZcmU_sKbJpOh4CEuJKr1NLEEsm8xAB-gzYz9laubsztcW-I-YC8gfq67kGbW2wxYhFh6PCaqEZgAhzD7sfRGsj_bBLykeVpSCRZCI7h8pbO9UbtiBfKDKUDwyqm2t35GWi0DV3KcWZlnKso97-z8Xlzj5AysY5ifWux0nJwHCLJ70Fq4wV738SQ5ZDExqSQkaiGY-w7NlJRHRCVP0wJzIEWP2fsSkNMbN8ui4ULLD1kR0w4T_VlBYS1QXbjvXJ6XUwEc7xhusC2ixvDzhBjjLOmbrwqOdMQnFRrxilX--Q9mI","DataHash":"qgeopmcf02p09qc016cepu22fo"}}

Here's a full trace.log -- I'm currently logging to trace with these packages:

*=info: 
com.ibm.social.pim.resource.*=all: 
com.ibm.lconn.homepage.services.widget.*=all: 
com.ibm.lconn.news.*=all: 
com.ibm.lconn.events.*=all: 
com.ibm.lotus.search.engine.*=all: 
com.ibm.lotus.search.index.*=all: 
com.ibm.lconn.mailin.*=all: 
com.ibm.lotus.connections.core.notify.*=all: 
com.ibm.lconn.scheduler.*=all:
org.apache.shindig.*=all

I'd love to know a good way of debugging that JSONException as well as more into on the makeRequest POST.

Any clues on how to debug further are greatly appreciated.

Update

I've updated the trace.log after Paul's logging suggestion and I'm now seeing exceptions while storing OAuth information:

[2/27/14 7:16:17:062 EST] 0000014e RetryConnecti 3   Exception caught during attempt
                                 org.springframework.dao.DataIntegrityViolationException: SqlMapClient operation; SQL [];   
--- The error occurred in resources/news/oauth/OAuth2TokenSQL.xml.  
--- The error occurred while applying a parameter map.  
--- Check the insert-OAUTH2_TOKEN-InlineParameterMap.  
--- Check the statement (update failed).  
--- Cause: com.ibm.db2.jcc.am.SqlIntegrityConstraintViolationException: Assignment of a NULL value to a NOT NULL column "TBSPACEID=5, TABLEID=14, COLNO=4" is not allowed.. SQLCODE=-407, SQLSTATE=23502, DRIVER=4.13.80; nested exception is com.ibatis.common.jdbc.exception.NestedSQLException:   
--- The error occurred in resources/news/oauth/OAuth2TokenSQL.xml.  
--- The error occurred while applying a parameter map.  
--- Check the insert-OAUTH2_TOKEN-InlineParameterMap.  
--- Check the statement (update failed).  
--- Cause: com.ibm.db2.jcc.am.SqlIntegrityConstraintViolationException: Assignment of a NULL value to a NOT NULL column "TBSPACEID=5, TABLEID=14, COLNO=4" is not allowed.. SQLCODE=-407, SQLSTATE=23502, DRIVER=4.13.80
    at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:228)
    at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72)
    at org.springframework.orm.ibatis.SqlMapClientTemplate.execute(SqlMapClientTemplate.java:212)
    at org.springframework.orm.ibatis.SqlMapClientTemplate.insert(SqlMapClientTemplate.java:397)
    at com.ibm.lconn.news.data.dao.impl.ibatis.CrudDao.insert(CrudDao.java:394)
    at com.ibm.lconn.news.data.dao.impl.ibatis.oauth.OAuth2TokenDao.insert(OAuth2TokenDao.java:61)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
    at java.lang.reflect.Method.invoke(Method.java:611)

The OAuth provider appears to be supplying OAuth tokens correctly from what I can see -- also in trace.log


Solution

  • I've installed tcpflow on the IBM Connections machine. Tracking the server side OAuth flow on the IBM Connections machine using...

    root$ tcpflow -p -c -i eth0 port 2990 | grep -oE '(GET|POST|HEAD) .* HTTP/1.[01]|Host: .*' > cnx-outgoing-2990.log
    

    I've found a 404 error on the OAuth provider when IBM Connections POSTs to the access_token URL -- will concentrate on that :)