Invalid column after version upgrade

[RickBollinger]

I just installed SmartClient Version v8.3p_2015-03-27/EVAL over a previous version.

My app was working fine until this install. No changes were made to the code. Now I am getting an Invalid column error every time I start the app.

I run Mozilla Firefox 20.0 with Firebug using Windows 7 Premium 64 bit.

Here is the server log.

=== 2015-04-06 20:25:25,230 [sor7] INFO SQLDriver - [builtinApplication.Issue_fetch] Executing SQL query on 'PlanetProjectDB': SELECT COUNT(*) FROM (P
roject, IssueImpact, IssueLikelihood, IssueType, Issue) LEFT JOIN Category ON Issue.CategoryID = Category.CategoryID LEFT JOIN TeamMember OwnerMember O
N Issue.OwnerID = OwnerMember.TeamMemberID LEFT JOIN TeamMember OrigMember ON Issue.OwnerID = OrigMember.TeamMemberID WHERE Issue.ProjectID = Project.
ProjectID AND Issue.ImpactID = IssueImpact.ImpactID AND Issue.LikelihoodID = IssueLikelihood.LikelihoodID AND Issue.IssueTypeID = IssueType.IssueTypeID
AND (((Issue.OwnerID = 101 AND Issue.OwnerID IS NOT NULL) AND NOT((Issue.IssueStatus = 'Closed' AND Issue.IssueStatus IS NOT NULL))))
=== 2015-04-06 20:25:25,230 [sor4] DEBUG IDACall - remote user: null
=== 2015-04-06 20:25:25,230 [sor3] DEBUG PoolableSQLConnectionFactory - Passing credentials getConnection separately from JDBC URL
=== 2015-04-06 20:25:25,246 [sor7] DEBUG SQLDataSource - [builtinApplication.Issue_fetch] Using SQL Limit query
=== 2015-04-06 20:25:25,246 [sor7] DEBUG SQLDataSource - [builtinApplication.Issue_fetch] SQL windowed select rows 0->75, result size 75. Query: SELECT
Issue.CategoryID, Category.CategoryName, Issue.ClosedDate, Issue.CommunityID, Issue.Created, Issue.Description, Issue.ImpactID, IssueImpact.ImpactName
, Issue.IssueDueDate, Issue.IssueID, Issue.IssueNumber, Issue.IssueStatus, Issue.IssueTitle, Issue.IssueTypeID, IssueType.IssueTypeName, Issue.Likeliho
odID, IssueLikelihood.LikelihoodTitle, Issue.Log, Issue.LogEntry, Issue.MeetingTopicID, Issue.Modified, Issue.OriginalDueDate, Issue.OriginatorID, Orig
Member.OrigMember.TeamMemberName AS OriginatorName, Issue.OwnerID, OwnerMember.OwnerMember.TeamMemberName AS OwnerName, Issue.Private, Issue.ProjectID,
Project.ProjectNumber, Project.ProjectTitle, Issue.Resolution FROM (Project, IssueImpact, IssueLikelihood, IssueType, Issue) LEFT JOIN Category ON Iss
ue.CategoryID = Category.CategoryID LEFT JOIN TeamMember OwnerMember ON Issue.OwnerID = OwnerMember.TeamMemberID LEFT JOIN TeamMember OrigMember ON Iss
ue.OwnerID = OrigMember.TeamMemberID WHERE Issue.ProjectID = Project.ProjectID AND Issue.ImpactID = IssueImpact.ImpactID AND Issue.LikelihoodID = Issu
eLikelihood.LikelihoodID AND Issue.IssueTypeID = IssueType.IssueTypeID AND (((Issue.OwnerID = 101 AND Issue.OwnerID IS NOT NULL) AND NOT((Issue.IssueSt
atus = 'Closed' AND Issue.IssueStatus IS NOT NULL)))) ORDER BY IssueImpact.ImpactName DESC LIMIT 0, 75
=== 2015-04-06 20:25:25,246 [sor4] DEBUG XML - Parsed XML from (in memory stream): 0ms
=== 2015-04-06 20:25:25,261 [sor2] DEBUG PoolableSQLConnectionFactory - [builtinApplication.Task_fetch] makeObject() created a pooled Connection '13013
827'
=== 2015-04-06 20:25:25,261 [sor2] DEBUG PoolableSQLConnectionFactory - [builtinApplication.Task_fetch] Executing pingTest 'select 1 from dual' on conn
ection 13013827
=== 2015-04-06 20:25:25,261 [sor7] WARN RequestContext - dsRequest.execute() failed:
com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Unknown column 'OrigMember.OrigMember.TeamMemberName' in 'field list'
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:525)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
at com.mysql.jdbc.Util.getInstance(Util.java:386)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1053)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4074)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4006)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2468)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2629)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2713)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2663)
at com.mysql.jdbc.StatementImpl.executeQuery(StatementImpl.java:1599)
at org.apache.commons.dbcp.DelegatingStatement.executeQuery(DelegatingStatement.java:208)
at com.isomorphic.sql.SQLDataSource.executeWindowedSelect(SQLDataSource.java:1938)
at com.isomorphic.sql.SQLDataSource.SQLExecute(SQLDataSource.java:1398)
at com.isomorphic.sql.SQLDataSource.processRequest(SQLDataSource.java:314)
at com.isomorphic.sql.SQLDataSource.executeFetch(SQLDataSource.java:258)
at com.isomorphic.datasource.DataSource.execute(DataSource.java:1367)
at com.isomorphic.application.AppBase.executeDefaultDSOperation(AppBase.java:723)
at com.isomorphic.application.AppBase.executeAppOperation(AppBase.java:658)
at com.isomorphic.application.AppBase.execute(AppBase.java:491)
at com.isomorphic.datasource.DSRequest.execute(DSRequest.java:2044)
at com.isomorphic.servlet.IDACall.handleDSRequest(IDACall.java:216)
at com.isomorphic.servlet.IDACall.processRPCTransaction(IDACall.java:173)
at com.isomorphic.servlet.IDACall.processRequest(IDACall.java:138)
at com.isomorphic.servlet.IDACall.doPost(IDACall.java:74)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
at com.isomorphic.servlet.BaseServlet.service(BaseServlet.java:152)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
at com.isomorphic.js.JSSyntaxScannerFilter.doFilter(JSSyntaxScannerFilter.java:242)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
at com.isomorphic.servlet.CompressionFilter.doFilter(CompressionFilter.java:260)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:210)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:174)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:108)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:151)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:870)
at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:665)
at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:528)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:81)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:685)
at java.lang.Thread.run(Thread.java:722)

This is the ds file being used.

<DataSource ID="Issue" dataFormat="iscServer" serverType="sql" dataSourceVersion="1" dbName="PlanetProjectDB" schema="PUBLIC" tableName="Issue" autoDeriveSchema="false">
    <fields>
        <field name="IssueID" type="sequence" detail="true" primaryKey="true"/>
        <field name="ProjectID" type="integer" required="true" title="Project" detail="true" foreignKey="Project.ProjectID"/>
        <field name="ProjectNumber" type="text" detail="true">
            <tableName>Project</tableName>
        </field>
        <field name="ProjectTitle" type="text" detail="true">
            <tableName>Project</tableName>
        </field>
        <field name="CommunityID" type="integer" required="true" title="Community" detail="true" foreignKey="Community.CommunityID"/>
        <field name="IssueNumber" type="integer" required="false" title="Number" canEdit="true"/>
        <field name="IssueTitle" type="text" required="true" length="64" title="Issue Title" canEdit="true"/>
        <field name="CategoryID" type="integer" title="Category" detail="true" canEdit="true" foreignKey="Category.CategoryID"/>
        <field name="CategoryName" type="text" detail="true">
            <tableName>Category</tableName>
        </field>
        <field name="IssueTypeID" type="integer" required="true" title="Issue Type" detail="true" canEdit="true" foreignKey="IssueType.IssueTypeID"/>
        <field name="IssueTypeName" type="text" detail="true">
            <tableName>IssueType</tableName>
        </field>
        <field name="ImpactID" type="integer" required="true" title="Impact" detail="true" canEdit="true" foreignKey="IssueImpact.IssueImpactID"/>
        <field name="ImpactName" type="text">
            <tableName>IssueImpact</tableName>
        </field>
        <field name="LikelihoodID" type="integer" required="true" title="Likelihood" detail="true" canEdit="true" foreignKey="IssueLikelihood.LikelihoodID"/>
        <field name="LikelihoodTitle" type="text" detail="true">
            <tableName>IssueLikelihood</tableName>
        </field>
        <field name="OwnerID" type="integer" title="OwnerID" detail="true" canEdit="true" foreignKey="TeamMember.TeamMemberID"/>
        <field name="OwnerName" type="text" title="Owner" detail="true" canEdit="true">
            <nativeName>TeamMemberName</nativeName>
            <tableName>OwnerMember</tableName>
        </field>
        <field name="OriginatorID" type="integer" required="true" title="Originator" detail="true" canEdit="true" foreignKey="TeamMember.TeamMemberID"/>
        <field name="OriginatorName" type="text" title="Originator" detail="true" canEdit="true">
            <nativeName>TeamMemberName</nativeName>
            <tableName>OrigMember</tableName>
        </field>
        <field name="IssueStatus" type="text" required="true" length="16" title="Status" canEdit="true">
            <valueMap>
                    <value>Open</value>
                    <value>Selected</value>
                    <value>Deferred</value>
                    <value>Rejected</value>
                    <value>Accepted</value>
                    <value>Analysis</value>
                    <value>Started</value>
                    <value>Waiting</value>
                    <value>Resolved</value>
                    <value>Closed</value>
            </valueMap>
        </field>
        <field name="IssueDueDate" type="date" title="Due" canEdit="true"/>
        <field name="ClosedDate" type="date" title="Closed" canEdit="true"/>
        <field name="OriginalDueDate" type="date" title="Originally Due" detail="true" canEdit="true"/>
        <field name="Resolution" type="text" title="Resolution" detail="true" canEdit="true"/>
        <field name="Private" type="boolean" required="true" title="Private Issue" canEdit="true" sqlStorageStrategy="integer"/>
        <field name="Description" type="text" length="2147483647" title="Description" detail="true" canEdit="true"/>
        <field name="LogEntry" type="text" length="1024" title="Log" detail="true" canEdit="false"/>
        <field name="Log" type="text" length="2147483647" title="Log" detail="true" canEdit="false"/>
        <field name="Created" type="creatorTimestamp" title="Created"/>
        <field name="Modified" type="modifierTimestamp" title="Modified" detail="true"/>
        <field name="MeetingTopicID" type="integer" hidden="true" foreignKey="MeetingTopic.MeetingTopicID"/>
    </fields>
    <operationBindings>
        <OperationBinding>
            <operationType>fetch</operationType>
            <tableClause>(Project, IssueImpact, IssueLikelihood, IssueType, Issue) LEFT JOIN Category ON Issue.CategoryID = Category.CategoryID LEFT JOIN TeamMember OwnerMember ON Issue.OwnerID = OwnerMember.TeamMemberID LEFT JOIN TeamMember OrigMember ON Issue.OwnerID = OrigMember.TeamMemberID </tableClause>
            <whereClause>Issue.ProjectID = Project.ProjectID AND Issue.ImpactID = IssueImpact.ImpactID AND Issue.LikelihoodID = IssueLikelihood.LikelihoodID AND Issue.IssueTypeID = IssueType.IssueTypeID AND ($defaultWhereClause)</whereClause>
        </OperationBinding>
    </operationBindings>
    <title>Issue</title>
    <titleField>IssueTitle</titleField>
    <pluralTitle>Issues</pluralTitle>
    <generatedBy>SC_SNAPSHOT-2012-01-09_v8.2p/Pro Deployment 2012-01-09</generatedBy>
</DataSource>

Somehow, both the columns with <tableName> entries are now doubled up in the resulting SQL. This is new behavior. The product has been working real well.

Any ideas where the fix goes?

Thanks,

Rick

[RickBollinger]

&lt;nativeName&gt;

I reviewed my post this morning and noticed that the problem exists only with the columns with <nativeName> values.

Rick

[RickBollinger]

Below is the generated SQL, spread out to help reveal the problem.

The generation correctly tries to rename the result fields with the AS phrase. However, the source fields are incorrectly identified. Somehow, the <tableName> values are inserted twice. If inserted once, they would be OK. But, doubled up they cause an SQL error.

SELECT Issue.CategoryID, Category.CategoryName, Issue.ClosedDate, Issue.CommunityID, Issue.Created, Issue.Description, Issue.ImpactID, IssueImpact.ImpactName, Issue.IssueDueDate, Issue.IssueID, Issue.IssueNumber, Issue.IssueStatus, Issue.IssueTitle, Issue.IssueTypeID, IssueType.IssueTypeName, Issue.LikelihoodID, IssueLikelihood.LikelihoodTitle, Issue.Log, Issue.LogEntry, Issue.MeetingTopicID, Issue.Modified, Issue.OriginalDueDate, Issue.OriginatorID,

OrigMember.OrigMember.TeamMemberName AS OriginatorName,

Issue.OwnerID,

OwnerMember.OwnerMember.TeamMemberName AS OwnerName,

Issue.Private, Issue.ProjectID,Project.ProjectNumber, Project.ProjectTitle, Issue.Resolution
FROM (Project, IssueImpact, IssueLikelihood, IssueType, Issue) LEFT JOIN Category ON Issue.CategoryID = Category.CategoryID
LEFT JOIN TeamMember OwnerMember ON Issue.OwnerID = OwnerMember.TeamMemberID LEFT JOIN TeamMember OrigMember ON Issue.OwnerID = OrigMember.TeamMemberID
WHERE Issue.ProjectID = Project.ProjectID AND Issue.ImpactID = IssueImpact.ImpactID AND Issue.LikelihoodID = IssueLikelihood.LikelihoodID AND Issue.IssueTypeID = IssueType.IssueTypeID AND (((Issue.OwnerID = 101
AND Issue.OwnerID IS NOT NULL) AND NOT((Issue.IssueStatus = 'Closed' AND Issue.IssueStatus IS NOT NULL))))
ORDER BY IssueImpact.ImpactName DESC LIMIT 0, 75

Rick

[RickBollinger]

Below is the code that causes the fetch with the problem.

MyIssuesGrid.sortField="Impact";
MyIssuesGrid.sortDirection="descending";
MyIssuesGrid.fetchData( { _constructor: "AdvancedCriteria",
	operator:"and", criteria: [
		{ fieldName:"OwnerID", operator:"equals", value:teamMemberRecord.TeamMemberID },
		{ operator:"not", criteria: [ { fieldName:"IssueStatus", operator:"equals", value:"Closed"} ] }
		] } , null, { showPrompt: true, prompt: "Logging in..." } );

It is part of the login that populates the grids after the password is matched.

[RickBollinger]

I installed the previous SmartClient_v83p_2015-02-04_Evaluation version I had been using and my code now works again.

You can see below the correct SQL request.

=== 2015-04-17 20:52:09,619 [sor6] DEBUG SQLDataSource - [builtinApplication.Issue_fetch] SQL windowed select rows 0->75, result size 75. Query: SELECT
Issue.CategoryID, Category.CategoryName, Issue.ClosedDate, Issue.CommunityID, Issue.Created, Issue.Description, Issue.ImpactID, IssueImpact.ImpactName
, Issue.IssueDueDate, Issue.IssueID, Issue.IssueNumber, Issue.IssueStatus, Issue.IssueTitle, Issue.IssueTypeID, IssueType.IssueTypeName, Issue.Likeliho
odID, IssueLikelihood.LikelihoodTitle, Issue.Log, Issue.LogEntry, Issue.MeetingTopicID, Issue.Modified, Issue.OriginalDueDate, Issue.OriginatorID, Orig
Member.TeamMemberName AS OriginatorName, Issue.OwnerID, OwnerMember.TeamMemberName AS OwnerName, Issue.Private, Issue.ProjectID, Project.ProjectNumber,
Project.ProjectTitle, Issue.Resolution FROM (Project, IssueImpact, IssueLikelihood, IssueType, Issue) LEFT JOIN Category ON Issue.CategoryID = Categor
y.CategoryID LEFT JOIN TeamMember OwnerMember ON Issue.OwnerID = OwnerMember.TeamMemberID LEFT JOIN TeamMember OrigMember ON Issue.OwnerID = OrigMember
.TeamMemberID WHERE Issue.ProjectID = Project.ProjectID AND Issue.ImpactID = IssueImpact.ImpactID AND Issue.LikelihoodID = IssueLikelihood.LikelihoodI
D AND Issue.IssueTypeID = IssueType.IssueTypeID AND (((Issue.OwnerID = 101 AND Issue.OwnerID IS NOT NULL) AND NOT((Issue.IssueStatus = 'Closed' AND Iss
ue.IssueStatus IS NOT NULL)))) ORDER BY IssueImpact.ImpactName DESC LIMIT 0, 75

It reads better spread out below:

SELECT Issue.CategoryID, Category.CategoryName, Issue.ClosedDate, 
Issue.CommunityID, Issue.Created, Issue.Description, Issue.ImpactID, 
IssueImpact.ImpactName, Issue.IssueDueDate, Issue.IssueID, 
Issue.IssueNumber, Issue.IssueStatus, Issue.IssueTitle, 
Issue.IssueTypeID, IssueType.IssueTypeName, Issue.LikelihoodID, 
IssueLikelihood.LikelihoodTitle, Issue.Log, Issue.LogEntry, 
Issue.MeetingTopicID, Issue.Modified, Issue.OriginalDueDate, Issue.OriginatorID, 

OrigMember.TeamMemberName AS OriginatorName, 

Issue.OwnerID, 

OwnerMember.TeamMemberName AS OwnerName, 

Issue.Private, Issue.ProjectID, Project.ProjectNumber, Project.ProjectTitle, Issue.Resolution 

FROM (Project, IssueImpact, IssueLikelihood, IssueType, Issue) 

LEFT JOIN Category ON Issue.CategoryID = Category.CategoryID 

LEFT JOIN TeamMember OwnerMember ON Issue.OwnerID = OwnerMember.TeamMemberID 

LEFT JOIN TeamMember OrigMember ON Issue.OwnerID = OrigMember.TeamMemberID  

WHERE Issue.ProjectID = Project.ProjectID AND Issue.ImpactID = IssueImpact.ImpactID AND Issue.LikelihoodID = IssueLikelihood.LikelihoodID AND Issue.IssueTypeID = IssueType.IssueTypeID AND (((Issue.OwnerID = 101 AND Issue.OwnerID IS NOT NULL) AND NOT((Issue.IssueStatus = 'Closed' AND Issue.IssueStatus IS NOT NULL)))) ORDER BY IssueImpact.ImpactName DESC LIMIT 0, 75

Note that this previous version of SmartClient did not double up the tablenames on fields with nativeName specified.

If I can help diagnose the problem that was introduced in one of the following 8.3 versions just let me know.

2015-03-18
2015-03-24
2015-03-26
2015-03-27

Maybe it just was such that it avoided the regular regression tests or something.

Rick

[RickBollinger]

Version 9.1 also has problem

I successfully installed SC v9.1 eval. Starting my app it crashes with unknown column error from SQL generated from both Project.ds.xml and Issue.ds.xml files. The two exceptions are captured below.

=== 2015-04-19 15:47:32,658 [sor6] DEBUG XML - Parsed XML from (in memory stream): 4ms
=== 2015-04-19 15:47:32,663 [sor6] DEBUG RPCManager - Processing 1 requests.
=== 2015-04-19 15:47:32,664 [sor6] DEBUG RPCManager - Request #1 (RPCRequest) data: {
appID:"PlanetProject",
className:"PasswordToken",
methodName:"validPassword",
arguments:[
"graham",
"2F93CA7B8F3EF00FA4EDA4AB5D57DE01F1408460583E8BF3A07A35C7BB268AC298C742655C0BD65E8F0E343997AE6ABD"
],
is_ISC_RPC_DMI:true
}
=== 2015-04-19 15:47:32,667 [sor6] INFO IDACall - Performing 1 operation(s)
=== 2015-04-19 15:47:32,682 [sor6] DEBUG XML - Parsed XML from D:\My Websites\Planet Project\shared\app\PlanetProject.app.xml: 2ms
=== 2015-04-19 15:47:32,694 [sor6] DEBUG XML - Parsed XML from D:\My Websites\Planet Project\isomorphic\system\schema\ServerObject.ds.xml: 2ms
=== 2015-04-19 15:47:32,706 [sor6] DEBUG XML - Parsed XML from D:\My Websites\Planet Project\isomorphic\system\schema\Method.ds.xml: 1ms
=== 2015-04-19 15:47:32,710 [sor6] DEBUG RPCDMI - appConfig: isc.Application.create({
rpcBindings:[
{
ID:"MeetingAgenda01",
className:"com.planetproject.server.reports.MeetingAgenda01",
visibleMethods:[
{
name:"report"
}
]
},
{
ID:"MeetingAgenda10",
className:"com.planetproject.server.reports.MeetingAgenda10",
visibleMethods:[
{
name:"report"
}
]
},
{
ID:"MeetingAgenda11",
className:"com.planetproject.server.reports.MeetingAgenda11",
visibleMethods:[
{
name:"report"
}
]
},
{
ID:"PasswordToken",
className:"com.planetproject.applets.PasswordToken",
visibleMethods:[
{
name:"getPasswordToken"
},
{
name:"validPassword"
}
]
},
{
ID:"CreateNewAccount01",
className:"com.planetproject.applets.CreateNewAccount01",
visibleMethods:[
{
name:"createNewAccount"
}
]
},
{
ID:"SendAlertApplet01",
className:"com.planetproject.applets.SendAlertApplet01",
visibleMethods:[
{
name:"sendAlerts"
}
]
},
{
ID:"CreateNewProject01",
className:"com.planetproject.applets.CreateNewProject01",
visibleMethods:[
{
name:"createNewProject"
}
]
}
]
})

********************************PasswordToken: validPassword() invoked with: graham and token: 2F93CA7B8F3EF00FA4EDA4AB5D57DE01F1408460583E8BF3A07A35C7
BB268AC298C742655C0BD65E8F0E343997AE6ABD
********************************PasswordToken: validPassword() matching with: Team_Paper_Trailgraham and token: 2F93CA7B8F3EF00FA4EDA4AB5D57DE01F140846
0583E8BF3A07A35C7BB268AC298C742655C0BD65E8F0E343997AE6ABD
=== 2015-04-19 15:47:32,798 [sor6] DEBUG RPCDMI - rpc returned data
=== 2015-04-19 15:47:32,799 [sor6] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
=== 2015-04-19 15:47:32,801 [sor6] INFO Compression - /isomorphic/IDACall: 70 -> 76 bytes
=== 2015-04-19 15:47:33,062 [sor6] INFO RequestContext - URL: '/isomorphic/IDACall', User-Agent: 'Mozilla/5.0 (Windows NT 6.1; WOW64; rv:37.0) Gecko/2
0100101 Firefox/37.0': Moz (Gecko) with Accept-Encoding header
=== 2015-04-19 15:47:33,064 [sor6] DEBUG IDACall - Header Name:Value pair: host:localhost:8080
=== 2015-04-19 15:47:33,064 [sor6] DEBUG IDACall - Header Name:Value pair: user-agent:Mozilla/5.0 (Windows NT 6.1; WOW64; rv:37.0) Gecko/20100101 Firef
ox/37.0
=== 2015-04-19 15:47:33,066 [sor6] DEBUG IDACall - Header Name:Value pair: accept:text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
=== 2015-04-19 15:47:33,067 [sor6] DEBUG IDACall - Header Name:Value pair: accept-language:en-US,de;q=0.5
=== 2015-04-19 15:47:33,084 [sor6] DEBUG IDACall - Header Name:Value pair: accept-encoding:gzip, deflate
=== 2015-04-19 15:47:33,084 [sor6] DEBUG IDACall - Header Name:Value pair: dnt:1
=== 2015-04-19 15:47:33,089 [sor6] DEBUG IDACall - Header Name:Value pair: content-type:application/x-www-form-urlencoded; charset=UTF-8
=== 2015-04-19 15:47:33,092 [sor6] DEBUG IDACall - Header Name:Value pair: referer:http://localhost:8080/tools/visualBu...anetProjectAlp
haAppZ.jsp
=== 2015-04-19 15:47:33,097 [sor6] DEBUG IDACall - Header Name:Value pair: content-length:1210
=== 2015-04-19 15:47:33,100 [sor6] DEBUG IDACall - Header Name:Value pair: cookie:GLog=%7B%0D%20%20%20%20left%3A-1152%2C%20%0D%20%20%20%20top%3A-9%2C%2
0%0D%20%20%20%20width%3A1143%2C%20%0D%20%20%20%20height%3A786%2C%20%0D%20%20%20%20priorityDefaults%3A%7B%0D%20%20%20%20%20%20%20%20Log%3A5%0D%20%20%20%
20%7D%2C%20%0D%20%20%20%20defaultPriority%3A3%0D%7D; isc_cState=ready; JSESSIONID=D4BB082541F47AF12B487DBBB64BA398
=== 2015-04-19 15:47:33,106 [sor6] DEBUG IDACall - Header Name:Value pair: connection:keep-alive
=== 2015-04-19 15:47:33,107 [sor6] DEBUG IDACall - Header Name:Value pair: pragma:no-cache
=== 2015-04-19 15:47:33,113 [sor6] DEBUG IDACall - Header Name:Value pair: cache-control:no-cache
=== 2015-04-19 15:47:33,116 [sor6] DEBUG IDACall - session exists: D4BB082541F47AF12B487DBBB64BA398
=== 2015-04-19 15:47:33,083 [sor2] INFO RequestContext - URL: '/isomorphic/IDACall', User-Agent: 'Mozilla/5.0 (Windows NT 6.1; WOW64; rv:37.0) Gecko/2
0100101 Firefox/37.0': Moz (Gecko) with Accept-Encoding header
=== 2015-04-19 15:47:33,083 [sor8] INFO RequestContext - URL: '/isomorphic/IDACall', User-Agent: 'Mozilla/5.0 (Windows NT 6.1; WOW64; rv:37.0) Gecko/2
0100101 Firefox/37.0': Moz (Gecko) with Accept-Encoding header
=== 2015-04-19 15:47:33,082 [sor3] INFO RequestContext - URL: '/isomorphic/IDACall', User-Agent: 'Mozilla/5.0 (Windows NT 6.1; WOW64; rv:37.0) Gecko/2
0100101 Firefox/37.0': Moz (Gecko) with Accept-Encoding header
=== 2015-04-19 15:47:33,131 [sor3] DEBUG IDACall - Header Name:Value pair: host:localhost:8080
=== 2015-04-19 15:47:33,134 [sor3] DEBUG IDACall - Header Name:Value pair: user-agent:Mozilla/5.0 (Windows NT 6.1; WOW64; rv:37.0) Gecko/20100101 Firef
ox/37.0
=== 2015-04-19 15:47:33,137 [sor3] DEBUG IDACall - Header Name:Value pair: accept:text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
=== 2015-04-19 15:47:33,140 [sor3] DEBUG IDACall - Header Name:Value pair: accept-language:en-US,de;q=0.5
=== 2015-04-19 15:47:33,144 [sor3] DEBUG IDACall - Header Name:Value pair: accept-encoding:gzip, deflate
=== 2015-04-19 15:47:33,148 [sor3] DEBUG IDACall - Header Name:Value pair: dnt:1
=== 2015-04-19 15:47:33,151 [sor3] DEBUG IDACall - Header Name:Value pair: content-type:application/x-www-form-urlencoded; charset=UTF-8
=== 2015-04-19 15:47:33,154 [sor3] DEBUG IDACall - Header Name:Value pair: referer:http://localhost:8080/tools/visualBu...anetProjectAlp
haAppZ.jsp
=== 2015-04-19 15:47:33,158 [sor3] DEBUG IDACall - Header Name:Value pair: content-length:892
=== 2015-04-19 15:47:33,163 [sor3] DEBUG IDACall - Header Name:Value pair: cookie:GLog=%7B%0D%20%20%20%20left%3A-1152%2C%20%0D%20%20%20%20top%3A-9%2C%2
0%0D%20%20%20%20width%3A1143%2C%20%0D%20%20%20%20height%3A786%2C%20%0D%20%20%20%20priorityDefaults%3A%7B%0D%20%20%20%20%20%20%20%20Log%3A5%0D%20%20%20%
20%7D%2C%20%0D%20%20%20%20defaultPriority%3A3%0D%7D; isc_cState=ready; JSESSIONID=D4BB082541F47AF12B487DBBB64BA398
=== 2015-04-19 15:47:33,166 [sor3] DEBUG IDACall - Header Name:Value pair: connection:keep-alive
=== 2015-04-19 15:47:33,168 [sor3] DEBUG IDACall - Header Name:Value pair: pragma:no-cache
=== 2015-04-19 15:47:33,172 [sor3] DEBUG IDACall - Header Name:Value pair: cache-control:no-cache
=== 2015-04-19 15:47:33,176 [sor3] DEBUG IDACall - session exists: D4BB082541F47AF12B487DBBB64BA398
=== 2015-04-19 15:47:33,179 [sor3] DEBUG IDACall - remote user: null
=== 2015-04-19 15:47:33,081 [sor7] INFO RequestContext - URL: '/isomorphic/IDACall', User-Agent: 'Mozilla/5.0 (Windows NT 6.1; WOW64; rv:37.0) Gecko/2
0100101 Firefox/37.0': Moz (Gecko) with Accept-Encoding header
=== 2015-04-19 15:47:33,189 [sor7] DEBUG IDACall - Header Name:Value pair: host:localhost:8080
=== 2015-04-19 15:47:33,192 [sor7] DEBUG IDACall - Header Name:Value pair: user-agent:Mozilla/5.0 (Windows NT 6.1; WOW64; rv:37.0) Gecko/20100101 Firef
ox/37.0
=== 2015-04-19 15:47:33,194 [sor7] DEBUG IDACall - Header Name:Value pair: accept:text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
=== 2015-04-19 15:47:33,197 [sor7] DEBUG IDACall - Header Name:Value pair: accept-language:en-US,de;q=0.5
=== 2015-04-19 15:47:33,200 [sor7] DEBUG IDACall - Header Name:Value pair: accept-encoding:gzip, deflate
=== 2015-04-19 15:47:33,203 [sor7] DEBUG IDACall - Header Name:Value pair: dnt:1
=== 2015-04-19 15:47:33,206 [sor7] DEBUG IDACall - Header Name:Value pair: content-type:application/x-www-form-urlencoded; charset=UTF-8
=== 2015-04-19 15:47:33,210 [sor7] DEBUG IDACall - Header Name:Value pair: referer:http://localhost:8080/tools/visualBu...anetProjectAlp
haAppZ.jsp
=== 2015-04-19 15:47:33,213 [sor7] DEBUG IDACall - Header Name:Value pair: content-length:2472
=== 2015-04-19 15:47:33,216 [sor7] DEBUG IDACall - Header Name:Value pair: cookie:GLog=%7B%0D%20%20%20%20left%3A-1152%2C%20%0D%20%20%20%20top%3A-9%2C%2
0%0D%20%20%20%20width%3A1143%2C%20%0D%20%20%20%20height%3A786%2C%20%0D%20%20%20%20priorityDefaults%3A%7B%0D%20%20%20%20%20%20%20%20Log%3A5%0D%20%20%20%
20%7D%2C%20%0D%20%20%20%20defaultPriority%3A3%0D%7D; isc_cState=ready; JSESSIONID=D4BB082541F47AF12B487DBBB64BA398
=== 2015-04-19 15:47:33,221 [sor7] DEBUG IDACall - Header Name:Value pair: connection:keep-alive
=== 2015-04-19 15:47:33,223 [sor7] DEBUG IDACall - Header Name:Value pair: pragma:no-cache
=== 2015-04-19 15:47:33,230 [sor7] DEBUG IDACall - Header Name:Value pair: cache-control:no-cache
=== 2015-04-19 15:47:33,234 [sor7] DEBUG IDACall - session exists: D4BB082541F47AF12B487DBBB64BA398
=== 2015-04-19 15:47:33,238 [sor7] DEBUG IDACall - remote user: null
=== 2015-04-19 15:47:33,076 [sor1] INFO RequestContext - URL: '/isomorphic/IDACall', User-Agent: 'Mozilla/5.0 (Windows NT 6.1; WOW64; rv:37.0) Gecko/2
0100101 Firefox/37.0': Moz (Gecko) with Accept-Encoding header
=== 2015-04-19 15:47:33,249 [sor1] DEBUG IDACall - Header Name:Value pair: host:localhost:8080
=== 2015-04-19 15:47:33,250 [sor1] DEBUG IDACall - Header Name:Value pair: user-agent:Mozilla/5.0 (Windows NT 6.1; WOW64; rv:37.0) Gecko/20100101 Firef
ox/37.0
=== 2015-04-19 15:47:33,253 [sor1] DEBUG IDACall - Header Name:Value pair: accept:text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
=== 2015-04-19 15:47:33,256 [sor1] DEBUG IDACall - Header Name:Value pair: accept-language:en-US,de;q=0.5
=== 2015-04-19 15:47:33,260 [sor1] DEBUG IDACall - Header Name:Value pair: accept-encoding:gzip, deflate
=== 2015-04-19 15:47:33,263 [sor1] DEBUG IDACall - Header Name:Value pair: dnt:1
=== 2015-04-19 15:47:33,191 [sor3] DEBUG XML - Parsed XML from (in memory stream): 6ms
=== 2015-04-19 15:47:33,128 [sor8] DEBUG IDACall - Header Name:Value pair: host:localhost:8080
=== 2015-04-19 15:47:33,273 [sor8] DEBUG IDACall - Header Name:Value pair: user-agent:Mozilla/5.0 (Windows NT 6.1; WOW64; rv:37.0) Gecko/20100101 Firef
ox/37.0
=== 2015-04-19 15:47:33,278 [sor8] DEBUG IDACall - Header Name:Value pair: accept:text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
=== 2015-04-19 15:47:33,280 [sor8] DEBUG IDACall - Header Name:Value pair: accept-language:en-US,de;q=0.5
=== 2015-04-19 15:47:33,283 [sor8] DEBUG IDACall - Header Name:Value pair: accept-encoding:gzip, deflate
=== 2015-04-19 15:47:33,125 [sor2] DEBUG IDACall - Header Name:Value pair: host:localhost:8080
=== 2015-04-19 15:47:33,290 [sor2] DEBUG IDACall - Header Name:Value pair: user-agent:Mozilla/5.0 (Windows NT 6.1; WOW64; rv:37.0) Gecko/20100101 Firef
ox/37.0
=== 2015-04-19 15:47:33,294 [sor2] DEBUG IDACall - Header Name:Value pair: accept:text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
=== 2015-04-19 15:47:33,297 [sor2] DEBUG IDACall - Header Name:Value pair: accept-language:en-US,de;q=0.5
=== 2015-04-19 15:47:33,300 [sor2] DEBUG IDACall - Header Name:Value pair: accept-encoding:gzip, deflate
=== 2015-04-19 15:47:33,304 [sor2] DEBUG IDACall - Header Name:Value pair: dnt:1
=== 2015-04-19 15:47:33,307 [sor2] DEBUG IDACall - Header Name:Value pair: content-type:application/x-www-form-urlencoded; charset=UTF-8
=== 2015-04-19 15:47:33,312 [sor2] DEBUG IDACall - Header Name:Value pair: referer:http://localhost:8080/tools/visualBu...anetProjectAlp
haAppZ.jsp
=== 2015-04-19 15:47:33,315 [sor2] DEBUG IDACall - Header Name:Value pair: content-length:880
=== 2015-04-19 15:47:33,318 [sor2] DEBUG IDACall - Header Name:Value pair: cookie:GLog=%7B%0D%20%20%20%20left%3A-1152%2C%20%0D%20%20%20%20top%3A-9%2C%2
0%0D%20%20%20%20width%3A1143%2C%20%0D%20%20%20%20height%3A786%2C%20%0D%20%20%20%20priorityDefaults%3A%7B%0D%20%20%20%20%20%20%20%20Log%3A5%0D%20%20%20%
20%7D%2C%20%0D%20%20%20%20defaultPriority%3A3%0D%7D; isc_cState=ready; JSESSIONID=D4BB082541F47AF12B487DBBB64BA398
=== 2015-04-19 15:47:33,322 [sor2] DEBUG IDACall - Header Name:Value pair: connection:keep-alive
=== 2015-04-19 15:47:33,325 [sor2] DEBUG IDACall - Header Name:Value pair: pragma:no-cache
=== 2015-04-19 15:47:33,329 [sor2] DEBUG IDACall - Header Name:Value pair: cache-control:no-cache
=== 2015-04-19 15:47:33,332 [sor2] DEBUG IDACall - session exists: D4BB082541F47AF12B487DBBB64BA398
=== 2015-04-19 15:47:33,335 [sor2] DEBUG IDACall - remote user: null
=== 2015-04-19 15:47:33,121 [sor6] DEBUG IDACall - remote user: null
=== 2015-04-19 15:47:33,347 [sor6] DEBUG XML - Parsed XML from (in memory stream): 3ms
=== 2015-04-19 15:47:33,288 [sor8] DEBUG IDACall - Header Name:Value pair: dnt:1
=== 2015-04-19 15:47:33,350 [sor8] DEBUG IDACall - Header Name:Value pair: content-type:application/x-www-form-urlencoded; charset=UTF-8
=== 2015-04-19 15:47:33,353 [sor8] DEBUG IDACall - Header Name:Value pair: referer:http://localhost:8080/tools/visualBu...anetProjectAlp
haAppZ.jsp
=== 2015-04-19 15:47:33,356 [sor8] DEBUG IDACall - Header Name:Value pair: content-length:884
=== 2015-04-19 15:47:33,360 [sor8] DEBUG IDACall - Header Name:Value pair: cookie:GLog=%7B%0D%20%20%20%20left%3A-1152%2C%20%0D%20%20%20%20top%3A-9%2C%2
0%0D%20%20%20%20width%3A1143%2C%20%0D%20%20%20%20height%3A786%2C%20%0D%20%20%20%20priorityDefaults%3A%7B%0D%20%20%20%20%20%20%20%20Log%3A5%0D%20%20%20%
20%7D%2C%20%0D%20%20%20%20defaultPriority%3A3%0D%7D; isc_cState=ready; JSESSIONID=D4BB082541F47AF12B487DBBB64BA398
=== 2015-04-19 15:47:33,363 [sor8] DEBUG IDACall - Header Name:Value pair: connection:keep-alive
=== 2015-04-19 15:47:33,366 [sor8] DEBUG IDACall - Header Name:Value pair: pragma:no-cache
=== 2015-04-19 15:47:33,370 [sor8] DEBUG IDACall - Header Name:Value pair: cache-control:no-cache
=== 2015-04-19 15:47:33,373 [sor8] DEBUG IDACall - session exists: D4BB082541F47AF12B487DBBB64BA398
=== 2015-04-19 15:47:33,377 [sor8] DEBUG IDACall - remote user: null
=== 2015-04-19 15:47:33,273 [sor3] DEBUG RPCManager - Processing 1 requests.
=== 2015-04-19 15:47:33,267 [sor1] DEBUG IDACall - Header Name:Value pair: content-type:application/x-www-form-urlencoded; charset=UTF-8
=== 2015-04-19 15:47:33,388 [sor1] DEBUG IDACall - Header Name:Value pair: referer:http://localhost:8080/tools/visualBu...anetProjectAlp
haAppZ.jsp
=== 2015-04-19 15:47:33,390 [sor1] DEBUG IDACall - Header Name:Value pair: content-length:2471
=== 2015-04-19 15:47:33,394 [sor1] DEBUG IDACall - Header Name:Value pair: cookie:GLog=%7B%0D%20%20%20%20left%3A-1152%2C%20%0D%20%20%20%20top%3A-9%2C%2
0%0D%20%20%20%20width%3A1143%2C%20%0D%20%20%20%20height%3A786%2C%20%0D%20%20%20%20priorityDefaults%3A%7B%0D%20%20%20%20%20%20%20%20Log%3A5%0D%20%20%20%
20%7D%2C%20%0D%20%20%20%20defaultPriority%3A3%0D%7D; isc_cState=ready; JSESSIONID=D4BB082541F47AF12B487DBBB64BA398
=== 2015-04-19 15:47:33,398 [sor1] DEBUG IDACall - Header Name:Value pair: connection:keep-alive
=== 2015-04-19 15:47:33,401 [sor1] DEBUG IDACall - Header Name:Value pair: pragma:no-cache
=== 2015-04-19 15:47:33,405 [sor1] DEBUG IDACall - Header Name:Value pair: cache-control:no-cache
=== 2015-04-19 15:47:33,408 [sor1] DEBUG IDACall - session exists: D4BB082541F47AF12B487DBBB64BA398
=== 2015-04-19 15:47:33,411 [sor1] DEBUG IDACall - remote user: null
=== 2015-04-19 15:47:33,250 [sor7] DEBUG XML - Parsed XML from (in memory stream): 9ms
=== 2015-04-19 15:47:33,418 [sor1] DEBUG XML - Parsed XML from (in memory stream): 2ms
=== 2015-04-19 15:47:33,390 [sor3] DEBUG XML - Parsed XML from D:\My Websites\Planet Project\shared\ds\Organization.ds.xml: 4ms
=== 2015-04-19 15:47:33,384 [sor8] DEBUG XML - Parsed XML from (in memory stream): 2ms
=== 2015-04-19 15:47:33,350 [sor6] DEBUG RPCManager - Processing 1 requests.
=== 2015-04-19 15:47:33,347 [sor2] DEBUG XML - Parsed XML from (in memory stream): 6ms
=== 2015-04-19 15:47:33,434 [sor3] INFO SQLDataSource - Deriving dataSource Organization from table: Organization
=== 2015-04-19 15:47:33,439 [sor3] DEBUG PoolableSQLConnectionFactory - Executing pingTest 'select 1 from dual' on connection 27812789
=== 2015-04-19 15:47:33,443 [sor3] DEBUG SQLConnectionManager - Borrowed connection '27812789'
=== 2015-04-19 15:47:33,446 [sor3] INFO SQLDSGenerator - Fetching column metadata for table: Organization
=== 2015-04-19 15:47:33,449 [sor3] INFO SQLDSGenerator - =============Using catalog: PUBLIC
=== 2015-04-19 15:47:33,463 [sor3] INFO SQLDSGenerator - Fetching column metadata for Organization complete
=== 2015-04-19 15:47:33,468 [sor3] DEBUG SQLConnectionManager - About to close ISCPoolableConnection with hashcode "27812789"
=== 2015-04-19 15:47:33,469 [sor3] DEBUG PoolableSQLConnectionFactory - Executing pingTest 'select 1 from dual' on connection 27812789
=== 2015-04-19 15:47:33,472 [sor3] DEBUG RPCManager - Request #1 (DSRequest) payload: {
criteria:{
},
operationConfig:{
dataSource:"Organization",
repo:null,
operationType:"fetch",
textMatchStyle:"exact"
},
componentId:"(cacheAllData fetch)",
appID:"builtinApplication",
operation:"Organization_fetch",
oldValues:null
}
=== 2015-04-19 15:47:33,476 [sor3] INFO IDACall - Performing 1 operation(s)
=== 2015-04-19 15:47:33,480 [sor3] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
=== 2015-04-19 15:47:33,484 [sor3] DEBUG DeclarativeSecurity - DataSource Organization is not in the pre-checked list, processing...
=== 2015-04-19 15:47:33,489 [sor3] DEBUG AppBase - [builtinApplication.Organization_fetch] No userTypes defined, allowing anyone access to all operatio
ns for this application
=== 2015-04-19 15:47:33,491 [sor3] DEBUG AppBase - [builtinApplication.Organization_fetch] No public zero-argument method named '_Organization_fetch' f
ound, performing generic datasource operation
=== 2015-04-19 15:47:33,474 [sor2] DEBUG RPCManager - Processing 1 requests.
=== 2015-04-19 15:47:33,493 [sor3] INFO SQLDataSource - [builtinApplication.Organization_fetch] Performing fetch operation with
criteria: {} values: {}
=== 2015-04-19 15:47:33,502 [sor3] INFO SQLWhereClause - [builtinApplication.Organization_fetch] empty condition
=== 2015-04-19 15:47:33,505 [sor3] INFO SQLDataSource - [builtinApplication.Organization_fetch] derived query: SELECT $defaultSelectClause FROM $defau
ltTableClause WHERE $defaultWhereClause
=== 2015-04-19 15:47:33,509 [sor3] INFO SQLDataSource - [builtinApplication.Organization_fetch] 128: Executing SQL query on 'PlanetProjectDB': SELECT
Organization.OrganizationID, Organization.TimeZoneKey, Organization.LocaleKey, Organization.DateFormatKey, Organization.CommunityID, Organization.Organ
izationName, Organization.Internal, Organization.ContactName, Organization.ContactEmail, Organization.ContactPhone, Organization.ContactAddress, Organi
zation.Description, Organization.Log, Organization.Created, Organization.Modified FROM PUBLIC.Organization WHERE ('1'='1')
=== 2015-04-19 15:47:33,513 [sor3] DEBUG PoolableSQLConnectionFactory - [builtinApplication.Organization_fetch] Executing pingTest 'select 1 from dual'
on connection 27812789
=== 2015-04-19 15:47:33,480 [sor6] DEBUG XML - Parsed XML from D:\My Websites\Planet Project\shared\ds\Project.ds.xml: 4ms
=== 2015-04-19 15:47:33,518 [sor3] DEBUG SQLConnectionManager - [builtinApplication.Organization_fetch] Borrowed connection '27812789'
=== 2015-04-19 15:47:33,525 [sor3] DEBUG SQLTransaction - [builtinApplication.Organization_fetch] Started new PlanetProjectDB transaction "27812789"
=== 2015-04-19 15:47:33,528 [sor3] DEBUG SQLDriver - [builtinApplication.Organization_fetch] About to execute SQL query in 'PlanetProjectDB' using conn
ection '27812789'
=== 2015-04-19 15:47:33,531 [sor3] INFO SQLDriver - [builtinApplication.Organization_fetch] Executing SQL query on 'PlanetProjectDB': SELECT Organizat
ion.OrganizationID, Organization.TimeZoneKey, Organization.LocaleKey, Organization.DateFormatKey, Organization.CommunityID, Organization.OrganizationNa
me, Organization.Internal, Organization.ContactName, Organization.ContactEmail, Organization.ContactPhone, Organization.ContactAddress, Organization.De
scription, Organization.Log, Organization.Created, Organization.Modified FROM PUBLIC.Organization WHERE ('1'='1')
=== 2015-04-19 15:47:33,539 [sor3] INFO DSResponse - [builtinApplication.Organization_fetch] DSResponse: List with 5 items
=== 2015-04-19 15:47:33,541 [sor3] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
=== 2015-04-19 15:47:33,542 [sor3] DEBUG SQLTransaction - Committing PlanetProjectDB transaction "27812789"
=== 2015-04-19 15:47:33,546 [sor6] INFO SQLDataSource - Deriving dataSource Project from table: Project
=== 2015-04-19 15:47:33,548 [sor3] DEBUG RPCManager - non-DMI response, dropExtraFields: false
=== 2015-04-19 15:47:33,549 [sor6] DEBUG PoolableSQLConnectionFactory - Executing pingTest 'select 1 from dual' on connection 29908324
=== 2015-04-19 15:47:33,556 [sor3] DEBUG SQLTransaction - getConnection() found transactional connection for PlanetProjectDB with hashcode "27812789"
=== 2015-04-19 15:47:33,560 [sor3] DEBUG SQLTransaction - Ending PlanetProjectDB transaction "27812789"
=== 2015-04-19 15:47:33,560 [sor6] DEBUG SQLConnectionManager - Borrowed connection '29908324'
=== 2015-04-19 15:47:33,566 [sor6] INFO SQLDSGenerator - Fetching column metadata for table: Project
=== 2015-04-19 15:47:33,569 [sor6] INFO SQLDSGenerator - =============Using catalog: PUBLIC
=== 2015-04-19 15:47:33,564 [sor3] DEBUG SQLConnectionManager - About to close ISCPoolableConnection with hashcode "27812789"
=== 2015-04-19 15:47:33,576 [sor3] DEBUG PoolableSQLConnectionFactory - Executing pingTest 'select 1 from dual' on connection 27812789
=== 2015-04-19 15:47:33,588 [sor6] INFO SQLDSGenerator - Fetching column metadata for Project complete
=== 2015-04-19 15:47:33,595 [sor6] DEBUG SQLConnectionManager - About to close ISCPoolableConnection with hashcode "29908324"
=== 2015-04-19 15:47:33,596 [sor6] DEBUG PoolableSQLConnectionFactory - Executing pingTest 'select 1 from dual' on connection 29908324
=== 2015-04-19 15:47:33,603 [sor3] INFO Compression - /isomorphic/IDACall: 1227 -> 376 bytes
=== 2015-04-19 15:47:33,603 [sor6] DEBUG RPCManager - Request #1 (DSRequest) payload: {
criteria:{
ProjectManagerID:101
},
operationConfig:{
dataSource:"Project",
repo:null,
operationType:"fetch",
textMatchStyle:"exact"
},
startRow:0,
endRow:75,
componentId:"MyProjectsGrid",
appID:"builtinApplication",
operation:"Project_fetch",
oldValues:{
ProjectManagerID:101
}
}
=== 2015-04-19 15:47:33,608 [sor6] INFO IDACall - Performing 1 operation(s)
=== 2015-04-19 15:47:33,611 [sor6] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
=== 2015-04-19 15:47:33,621 [sor6] DEBUG DeclarativeSecurity - DataSource Project is not in the pre-checked list, processing...
=== 2015-04-19 15:47:33,606 [sor8] DEBUG RPCManager - Processing 1 requests.
=== 2015-04-19 15:47:33,626 [sor6] DEBUG AppBase - [builtinApplication.Project_fetch] No userTypes defined, allowing anyone access to all operations fo
r this application
=== 2015-04-19 15:47:33,630 [sor6] DEBUG AppBase - [builtinApplication.Project_fetch] No public zero-argument method named '_Project_fetch' found, perf
orming generic datasource operation
=== 2015-04-19 15:47:33,624 [sor3] INFO RequestContext - URL: '/isomorphic/IDACall', User-Agent: 'Mozilla/5.0 (Windows NT 6.1; WOW64; rv:37.0) Gecko/2
0100101 Firefox/37.0': Moz (Gecko) with Accept-Encoding header
=== 2015-04-19 15:47:33,638 [sor3] DEBUG IDACall - Header Name:Value pair: host:localhost:8080
=== 2015-04-19 15:47:33,615 [sor2] DEBUG XML - Parsed XML from D:\My Websites\Planet Project\shared\ds\Locale.ds.xml: 3ms
=== 2015-04-19 15:47:33,612 [sor1] DEBUG RPCManager - Processing 1 requests.
=== 2015-04-19 15:47:33,640 [sor3] DEBUG IDACall - Header Name:Value pair: user-agent:Mozilla/5.0 (Windows NT 6.1; WOW64; rv:37.0) Gecko/20100101 Firef
ox/37.0
=== 2015-04-19 15:47:33,651 [sor3] DEBUG IDACall - Header Name:Value pair: accept:text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
=== 2015-04-19 15:47:33,634 [sor6] INFO SQLDataSource - [builtinApplication.Project_fetch] Performing fetch operation with
criteria: {ProjectManagerID:101} values: {ProjectManagerID:101}
=== 2015-04-19 15:47:33,654 [sor3] DEBUG IDACall - Header Name:Value pair: accept-language:en-US,de;q=0.5
=== 2015-04-19 15:47:33,651 [sor2] INFO SQLDataSource - Deriving dataSource Locale from table: Locale
=== 2015-04-19 15:47:33,661 [sor3] DEBUG IDACall - Header Name:Value pair: accept-encoding:gzip, deflate
=== 2015-04-19 15:47:33,668 [sor3] DEBUG IDACall - Header Name:Value pair: dnt:1
=== 2015-04-19 15:47:33,658 [sor6] INFO SQLDataSource - [builtinApplication.Project_fetch] derived query: SELECT $defaultSelectClause FROM Project LEF
T JOIN TeamMember ON Project.ProjectManagerID = TeamMember.TeamMemberID LEFT JOIN Project OwningProject ON Project.OwningProjectID = OwningProject.Proj
ectID WHERE $defaultWhereClause
=== 2015-04-19 15:47:33,678 [sor6] DEBUG SQLDataSource - [builtinApplication.Project_fetch] Executing row count query: SELECT COUNT(*) FROM Project LEF
T JOIN TeamMember ON Project.ProjectManagerID = TeamMember.TeamMemberID LEFT JOIN Project OwningProject ON Project.OwningProjectID = OwningProject.Proj
ectID WHERE $defaultWhereClause
=== 2015-04-19 15:47:33,681 [sor6] DEBUG SQLDataSource - [builtinApplication.Project_fetch] Eval'd row count query: SELECT COUNT(*) FROM Project LEFT J
OIN TeamMember ON Project.ProjectManagerID = TeamMember.TeamMemberID LEFT JOIN Project OwningProject ON Project.OwningProjectID = OwningProject.Project
ID WHERE (Project.ProjectManagerID=101)
=== 2015-04-19 15:47:33,674 [sor3] DEBUG IDACall - Header Name:Value pair: content-type:application/x-www-form-urlencoded; charset=UTF-8
=== 2015-04-19 15:47:33,688 [sor3] DEBUG IDACall - Header Name:Value pair: referer:http://localhost:8080/tools/visualBu...anetProjectAlp
haAppZ.jsp
=== 2015-04-19 15:47:33,691 [sor3] DEBUG IDACall - Header Name:Value pair: content-length:888
=== 2015-04-19 15:47:33,695 [sor3] DEBUG IDACall - Header Name:Value pair: cookie:GLog=%7B%0D%20%20%20%20left%3A-1152%2C%20%0D%20%20%20%20top%3A-9%2C%2
0%0D%20%20%20%20width%3A1143%2C%20%0D%20%20%20%20height%3A786%2C%20%0D%20%20%20%20priorityDefaults%3A%7B%0D%20%20%20%20%20%20%20%20Log%3A5%0D%20%20%20%
20%7D%2C%20%0D%20%20%20%20defaultPriority%3A3%0D%7D; isc_cState=ready; JSESSIONID=D4BB082541F47AF12B487DBBB64BA398
=== 2015-04-19 15:47:33,699 [sor3] DEBUG IDACall - Header Name:Value pair: connection:keep-alive
=== 2015-04-19 15:47:33,702 [sor3] DEBUG IDACall - Header Name:Value pair: pragma:no-cache
=== 2015-04-19 15:47:33,706 [sor3] DEBUG IDACall - Header Name:Value pair: cache-control:no-cache
=== 2015-04-19 15:47:33,709 [sor3] DEBUG IDACall - session exists: D4BB082541F47AF12B487DBBB64BA398
=== 2015-04-19 15:47:33,714 [sor3] DEBUG IDACall - remote user: null
=== 2015-04-19 15:47:33,664 [sor2] DEBUG PoolableSQLConnectionFactory - Executing pingTest 'select 1 from dual' on connection 29908324
=== 2015-04-19 15:47:33,726 [sor2] DEBUG SQLConnectionManager - Borrowed connection '29908324'
=== 2015-04-19 15:47:33,727 [sor2] INFO SQLDSGenerator - Fetching column metadata for table: Locale
=== 2015-04-19 15:47:33,728 [sor2] INFO SQLDSGenerator - =============Using catalog: PUBLIC
=== 2015-04-19 15:47:33,727 [sor3] DEBUG XML - Parsed XML from (in memory stream): 7ms
=== 2015-04-19 15:47:33,727 [sor6] DEBUG PoolableSQLConnectionFactory - [builtinApplication.Project_fetch] Executing pingTest 'select 1 from dual' on c
onnection 27812789
=== 2015-04-19 15:47:33,741 [sor6] DEBUG SQLConnectionManager - [builtinApplication.Project_fetch] Borrowed connection '27812789'
=== 2015-04-19 15:47:33,744 [sor6] DEBUG SQLTransaction - [builtinApplication.Project_fetch] Started new PlanetProjectDB transaction "27812789"
=== 2015-04-19 15:47:33,746 [sor6] DEBUG SQLDriver - [builtinApplication.Project_fetch] About to execute SQL query in 'PlanetProjectDB' using connectio
n '27812789'
=== 2015-04-19 15:47:33,750 [sor6] INFO SQLDriver - [builtinApplication.Project_fetch] Executing SQL query on 'PlanetProjectDB': SELECT COUNT(*) FROM
Project LEFT JOIN TeamMember ON Project.ProjectManagerID = TeamMember.TeamMemberID LEFT JOIN Project OwningProject ON Project.OwningProjectID = OwningP
roject.ProjectID WHERE (Project.ProjectManagerID=101)
=== 2015-04-19 15:47:33,751 [sor2] INFO SQLDSGenerator - Fetching column metadata for Locale complete
=== 2015-04-19 15:47:33,759 [sor6] DEBUG SQLDataSource - [builtinApplication.Project_fetch] Using SQL Limit query
=== 2015-04-19 15:47:33,760 [sor6] DEBUG SQLDataSource - [builtinApplication.Project_fetch] SQL windowed select rows 0->75, result size 75. Query: SELE
CT Project.ProjectID, Project.CommunityID, Project.ProjectNumber, Project.ProjectTitle, Project.TaskOrder, Project.ProjectHashCode, Project.Inactive, P
roject.AutoAnnotateIssues, Project.AutoAnnotateRisks, Project.CloseIssuesInMeetings, Project.SendAlertsOnSave, Project.IssueNearlyDueDays, Project.Task
NearlyDueDays, Project.OwningProjectID, Project.ProjectManagerID, Project.LastIssueNumber, Project.LastTaskNumber, Project.AgendaServletName, Project.A
gendaPrintOptions, Project.MinutesServletName, Project.MinutesPrintOptions, Project.ReportServletName, Project.ReportPrintOptions, Project.Description,
Project.Log, Project.Created, Project.Modified, OwningProject.OwningProject.ProjectNumber AS OwningProjectNumber, TeamMember.TeamMemberName FROM Proje
ct LEFT JOIN TeamMember ON Project.ProjectManagerID = TeamMember.TeamMemberID LEFT JOIN Project OwningProject ON Project.OwningProjectID = OwningProjec
t.ProjectID WHERE (Project.ProjectManagerID=101) LIMIT 0, 75
=== 2015-04-19 15:47:33,765 [sor2] DEBUG SQLConnectionManager - About to close ISCPoolableConnection with hashcode "29908324"
=== 2015-04-19 15:47:33,766 [sor6] DEBUG SQLDataSource - [builtinApplication.Project_fetch] SQL windowed select rows 0->75, result size 75. Query: SELE
CT Project.ProjectID, Project.CommunityID, Project.ProjectNumber, Project.ProjectTitle, Project.TaskOrder, Project.ProjectHashCode, Project.Inactive, P
roject.AutoAnnotateIssues, Project.AutoAnnotateRisks, Project.CloseIssuesInMeetings, Project.SendAlertsOnSave, Project.IssueNearlyDueDays, Project.Task
NearlyDueDays, Project.OwningProjectID, Project.ProjectManagerID, Project.LastIssueNumber, Project.LastTaskNumber, Project.AgendaServletName, Project.A
gendaPrintOptions, Project.MinutesServletName, Project.MinutesPrintOptions, Project.ReportServletName, Project.ReportPrintOptions, Project.Description,
Project.Log, Project.Created, Project.Modified, OwningProject.OwningProject.ProjectNumber AS OwningProjectNumber, TeamMember.TeamMemberName FROM Proje
ct LEFT JOIN TeamMember ON Project.ProjectManagerID = TeamMember.TeamMemberID LEFT JOIN Project OwningProject ON Project.OwningProjectID = OwningProjec
t.ProjectID WHERE (Project.ProjectManagerID=101) LIMIT 0, 75
=== 2015-04-19 15:47:33,767 [sor2] DEBUG PoolableSQLConnectionFactory - Executing pingTest 'select 1 from dual' on connection 29908324
=== 2015-04-19 15:47:33,780 [sor2] DEBUG RPCManager - Request #1 (DSRequest) payload: {
criteria:{
},
operationConfig:{
dataSource:"Locale",
repo:null,
operationType:"fetch",
textMatchStyle:"exact"
},
componentId:"(cacheAllData fetch)",
appID:"builtinApplication",
operation:"Locale_fetch",
oldValues:null
}
=== 2015-04-19 15:47:33,783 [sor1] DEBUG XML - Parsed XML from D:\My Websites\Planet Project\shared\ds\Issue.ds.xml: 2ms
=== 2015-04-19 15:47:33,780 [sor6] WARN RequestContext - dsRequest.execute() failed:
com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Unknown column 'OwningProject.OwningProject.ProjectNumber' in 'field list'
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:525)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
at com.mysql.jdbc.Util.getInstance(Util.java:386)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1053)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4074)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4006)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2468)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2629)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2713)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2663)
at com.mysql.jdbc.StatementImpl.executeQuery(StatementImpl.java:1599)
at org.apache.commons.dbcp.DelegatingStatement.executeQuery(DelegatingStatement.java:208)
at com.isomorphic.sql.SQLDataSource.executeWindowedSelect(SQLDataSource.java:2493)
at com.isomorphic.sql.SQLDataSource.SQLExecute(SQLDataSource.java:1905)
at com.isomorphic.sql.SQLDataSource.processRequest(SQLDataSource.java:448)
at com.isomorphic.sql.SQLDataSource.executeFetch(SQLDataSource.java:393)
at com.isomorphic.datasource.DataSource.execute(DataSource.java:1582)
at com.isomorphic.application.AppBase.executeDefaultDSOperation(AppBase.java:723)
at com.isomorphic.application.AppBase.executeAppOperation(AppBase.java:658)
at com.isomorphic.application.AppBase.execute(AppBase.java:491)
at com.isomorphic.datasource.DSRequest.execute(DSRequest.java:2540)
at com.isomorphic.servlet.IDACall.handleDSRequest(IDACall.java:224)
at com.isomorphic.servlet.IDACall.processRPCTransaction(IDACall.java:181)
at com.isomorphic.servlet.IDACall.processRequest(IDACall.java:149)
at com.isomorphic.servlet.IDACall._processRequest(IDACall.java:114)
at com.isomorphic.servlet.IDACall.doPost(IDACall.java:73)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
at com.isomorphic.servlet.BaseServlet.service(BaseServlet.java:152)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
at com.isomorphic.js.JSSyntaxScannerFilter.doFilter(JSSyntaxScannerFilter.java:242)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
at com.isomorphic.servlet.CompressionFilter.doFilter(CompressionFilter.java:260)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:210)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:174)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:108)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:151)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:870)
at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:665)
at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:528)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:81)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:685)
at java.lang.Thread.run(Thread.java:722)
=== 2015-04-19 15:47:33,803 [izer] DEBUG PoolableSQLConnectionFactory - Executing pingTest 'select 1 from dual' on connection 27812789
=== 2015-04-19 15:47:33,812 [sor1] DEBUG RPCManager - Request #1 (DSRequest) payload: {
criteria:{
_constructor:"AdvancedCriteria",
operator:"and",
criteria:[
{
fieldName:"OwnerID",
operator:"equals",
value:101
},
{
operator:"not",
criteria:[
{
fieldName:"IssueStatus",
operator:"equals",
value:"Closed"
}
]
}
]
},
operationConfig:{
dataSource:"Issue",
repo:null,
operationType:"fetch",
textMatchStyle:"exact"
},
startRow:0,
endRow:75,
sortBy:[
"-ImpactName"
],
componentId:"MyIssuesGrid",
appID:"builtinApplication",
operation:"Issue_fetch",
oldValues:{
_constructor:"AdvancedCriteria",
operator:"and",
criteria:[
{
fieldName:"OwnerID",
operator:"equals",
value:101
},
{
operator:"not",
criteria:[
{
fieldName:"IssueStatus",
operator:"equals",
value:"Closed"
}
]
}
]
}
}
=== 2015-04-19 15:47:33,804 [sor6] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
=== 2015-04-19 15:47:33,784 [sor2] INFO IDACall - Performing 1 operation(s)
=== 2015-04-19 15:47:33,832 [sor6] DEBUG SQLTransaction - Rolling back PlanetProjectDB transaction "27812789"
=== 2015-04-19 15:47:33,831 [sor1] INFO IDACall - Performing 1 operation(s)
=== 2015-04-19 15:47:33,816 [sor8] DEBUG XML - Parsed XML from D:\My Websites\Planet Project\shared\ds\TimeZone.ds.xml: 4ms
=== 2015-04-19 15:47:33,858 [sor1] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
=== 2015-04-19 15:47:33,865 [sor1] DEBUG DeclarativeSecurity - DataSource Issue is not in the pre-checked list, processing...
=== 2015-04-19 15:47:33,869 [sor1] DEBUG AppBase - [builtinApplication.Issue_fetch] No userTypes defined, allowing anyone access to all operations for
this application
=== 2015-04-19 15:47:33,873 [sor1] DEBUG AppBase - [builtinApplication.Issue_fetch] No public zero-argument method named '_Issue_fetch' found, performi
ng generic datasource operation
=== 2015-04-19 15:47:33,854 [sor6] WARN RPCManager - Exception thrown during onFailure processing
java.sql.SQLException: Connection com.mysql.jdbc.JDBC4Connection@1a863b5 is closed.
at org.apache.commons.dbcp.DelegatingConnection.checkOpen(DelegatingConnection.java:398)
at org.apache.commons.dbcp.DelegatingConnection.rollback(DelegatingConnection.java:368)
at com.isomorphic.sql.SQLTransaction.rollbackTransaction(SQLTransaction.java:176)
at com.isomorphic.sql.SQLDataSource.onFailure(SQLDataSource.java:3896)
at com.isomorphic.rpc.RPCManager.onFailure(RPCManager.java:1741)
at com.isomorphic.rpc.RPCManager.onFailure(RPCManager.java:1637)
at com.isomorphic.rpc.RPCManager.completeResponse(RPCManager.java:1239)
at com.isomorphic.rpc.RPCManager.send(RPCManager.java:643)
at com.isomorphic.servlet.IDACall.processRPCTransaction(IDACall.java:181)
at com.isomorphic.servlet.IDACall.processRequest(IDACall.java:149)
at com.isomorphic.servlet.IDACall._processRequest(IDACall.java:114)
at com.isomorphic.servlet.IDACall.doPost(IDACall.java:73)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
at com.isomorphic.servlet.BaseServlet.service(BaseServlet.java:152)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
at com.isomorphic.js.JSSyntaxScannerFilter.doFilter(JSSyntaxScannerFilter.java:242)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
at com.isomorphic.servlet.CompressionFilter.doFilter(CompressionFilter.java:260)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:210)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:174)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:108)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:151)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:870)
at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:665)
at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:528)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:81)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:685)
at java.lang.Thread.run(Thread.java:722)
=== 2015-04-19 15:47:33,853 [sor2] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
=== 2015-04-19 15:47:33,887 [sor6] DEBUG RPCManager - non-DMI response, dropExtraFields: false
=== 2015-04-19 15:47:33,877 [sor1] INFO SQLDataSource - [builtinApplication.Issue_fetch] Performing fetch operation with
criteria: {criteria:[{fieldName:"OwnerID",operator:"equals",value:101},{criteria:[{fieldName:"IssueStatus",operator:"equals",value:"Closed"}],o
perator:"not"}],operator:"and",_constructor:"AdvancedCriteria"} values: {criteria:[{fieldName:"OwnerID",operator:"equals",value:101},{criteria:[{fieldN
ame:"IssueStatus",operator:"equals",value:"Closed"}],operator:"not"}],operator:"and",_constructor:"AdvancedCriteria"}
=== 2015-04-19 15:47:33,874 [sor8] INFO SQLDataSource - Deriving dataSource TimeZone from table: TimeZone
=== 2015-04-19 15:47:33,898 [sor6] DEBUG SQLTransaction - getConnection() found transactional connection for PlanetProjectDB with hashcode "27812789"
=== 2015-04-19 15:47:33,888 [sor2] DEBUG DeclarativeSecurity - DataSource Locale is not in the pre-checked list, processing...
=== 2015-04-19 15:47:33,912 [sor6] DEBUG SQLTransaction - Ending PlanetProjectDB transaction "27812789"
=== 2015-04-19 15:47:33,909 [sor1] INFO SQLDataSource - [builtinApplication.Issue_fetch] derived query: SELECT $defaultSelectClause FROM (Project, Iss
ueImpact, IssueLikelihood, IssueType, Issue) LEFT JOIN Category ON Issue.CategoryID = Category.CategoryID LEFT JOIN TeamMember OwnerMember ON Issue.Own
erID = OwnerMember.TeamMemberID LEFT JOIN TeamMember OrigMember ON Issue.OwnerID = OrigMember.TeamMemberID WHERE Issue.ProjectID = Project.ProjectID A
ND Issue.ImpactID = IssueImpact.ImpactID AND Issue.LikelihoodID = IssueLikelihood.LikelihoodID AND Issue.IssueTypeID = IssueType.IssueTypeID AND ($defa
ultWhereClause) ORDER BY $defaultOrderClause
=== 2015-04-19 15:47:33,908 [sor8] DEBUG PoolableSQLConnectionFactory - Executing pingTest 'select 1 from dual' on connection 27812789
=== 2015-04-19 15:47:33,924 [sor1] DEBUG SQLDataSource - [builtinApplication.Issue_fetch] Executing row count query: SELECT COUNT(*) FROM (Project, Iss
ueImpact, IssueLikelihood, IssueType, Issue) LEFT JOIN Category ON Issue.CategoryID = Category.CategoryID LEFT JOIN TeamMember OwnerMember ON Issue.Own
erID = OwnerMember.TeamMemberID LEFT JOIN TeamMember OrigMember ON Issue.OwnerID = OrigMember.TeamMemberID WHERE Issue.ProjectID = Project.ProjectID A
ND Issue.ImpactID = IssueImpact.ImpactID AND Issue.LikelihoodID = IssueLikelihood.LikelihoodID AND Issue.IssueTypeID = IssueType.IssueTypeID AND ($defa
ultWhereClause)
=== 2015-04-19 15:47:33,919 [sor6] DEBUG SQLConnectionManager - About to close ISCPoolableConnection with hashcode "27812789"
=== 2015-04-19 15:47:33,915 [sor2] DEBUG AppBase - [builtinApplication.Locale_fetch] No userTypes defined, allowing anyone access to all operations for
this application
=== 2015-04-19 15:47:33,936 [sor6] DEBUG PoolableSQLConnectionFactory - Executing pingTest 'select 1 from dual' on connection 27812789
=== 2015-04-19 15:47:33,934 [sor1] DEBUG SQLDataSource - [builtinApplication.Issue_fetch] Eval'd row count query: SELECT COUNT(*) FROM (Project, IssueI
mpact, IssueLikelihood, IssueType, Issue) LEFT JOIN Category ON Issue.CategoryID = Category.CategoryID LEFT JOIN TeamMember OwnerMember ON Issue.OwnerI
D = OwnerMember.TeamMemberID LEFT JOIN TeamMember OrigMember ON Issue.OwnerID = OrigMember.TeamMemberID WHERE Issue.ProjectID = Project.ProjectID AND
Issue.ImpactID = IssueImpact.ImpactID AND Issue.LikelihoodID = IssueLikelihood.LikelihoodID AND Issue.IssueTypeID = IssueType.IssueTypeID AND (((Issue.
OwnerID = 101 AND Issue.OwnerID IS NOT NULL) AND NOT((Issue.IssueStatus LIKE BINARY 'Closed' AND Issue.IssueStatus IS NOT NULL))))
=== 2015-04-19 15:47:33,926 [sor8] DEBUG SQLConnectionManager - Borrowed connection '27812789'
=== 2015-04-19 15:47:33,948 [sor1] DEBUG PoolableSQLConnectionFactory - [builtinApplication.Issue_fetch] Executing pingTest 'select 1 from dual' on con
nection 27812789
=== 2015-04-19 15:47:33,939 [sor2] DEBUG AppBase - [builtinApplication.Locale_fetch] No public zero-argument method named '_Locale_fetch' found, perfor
ming generic datasource operation
=== 2015-04-19 15:47:33,955 [sor1] DEBUG SQLConnectionManager - [builtinApplication.Issue_fetch] Borrowed connection '27812789'
=== 2015-04-19 15:47:33,950 [sor8] INFO SQLDSGenerator - Fetching column metadata for table: TimeZone
=== 2015-04-19 15:47:33,962 [sor1] DEBUG SQLTransaction - [builtinApplication.Issue_fetch] Started new PlanetProjectDB transaction "27812789"
=== 2015-04-19 15:47:33,957 [sor2] INFO SQLDataSource - [builtinApplication.Locale_fetch] Performing fetch operation with
criteria: {} values: {}
=== 2015-04-19 15:47:33,968 [sor1] DEBUG SQLDriver - [builtinApplication.Issue_fetch] About to execute SQL query in 'PlanetProjectDB' using connection
'27812789'
=== 2015-04-19 15:47:33,964 [sor8] INFO SQLDSGenerator - =============Using catalog: PUBLIC
=== 2015-04-19 15:47:33,975 [sor1] INFO SQLDriver - [builtinApplication.Issue_fetch] Executing SQL query on 'PlanetProjectDB': SELECT COUNT(*) FROM (P
roject, IssueImpact, IssueLikelihood, IssueType, Issue) LEFT JOIN Category ON Issue.CategoryID = Category.CategoryID LEFT JOIN TeamMember OwnerMember O
N Issue.OwnerID = OwnerMember.TeamMemberID LEFT JOIN TeamMember OrigMember ON Issue.OwnerID = OrigMember.TeamMemberID WHERE Issue.ProjectID = Project.
ProjectID AND Issue.ImpactID = IssueImpact.ImpactID AND Issue.LikelihoodID = IssueLikelihood.LikelihoodID AND Issue.IssueTypeID = IssueType.IssueTypeID
AND (((Issue.OwnerID = 101 AND Issue.OwnerID IS NOT NULL) AND NOT((Issue.IssueStatus LIKE BINARY 'Closed' AND Issue.IssueStatus IS NOT NULL))))
=== 2015-04-19 15:47:33,972 [sor2] INFO SQLWhereClause - [builtinApplication.Locale_fetch] empty condition
=== 2015-04-19 15:47:33,987 [sor2] INFO SQLDataSource - [builtinApplication.Locale_fetch] derived query: SELECT $defaultSelectClause FROM $defaultTabl
eClause WHERE $defaultWhereClause
=== 2015-04-19 15:47:33,991 [sor1] DEBUG SQLDataSource - [builtinApplication.Issue_fetch] Using SQL Limit query
=== 2015-04-19 15:47:33,997 [sor1] DEBUG SQLDataSource - [builtinApplication.Issue_fetch] SQL windowed select rows 0->75, result size 75. Query: SELECT
Issue.IssueID, Issue.ProjectID, Project.ProjectNumber, Project.ProjectTitle, Issue.CommunityID, Issue.IssueNumber, Issue.IssueTitle, Issue.CategoryID,
Category.CategoryName, Issue.IssueTypeID, IssueType.IssueTypeName, Issue.ImpactID, IssueImpact.ImpactName, Issue.LikelihoodID, IssueLikelihood.Likelih
oodTitle, Issue.OwnerID, OwnerMember.OwnerMember.TeamMemberName AS OwnerName, Issue.OriginatorID, OrigMember.OrigMember.TeamMemberName AS OriginatorNam
e, Issue.IssueStatus, Issue.IssueDueDate, Issue.ClosedDate, Issue.OriginalDueDate, Issue.Resolution, Issue.Private, Issue.Description, Issue.LogEntry,
Issue.Log, Issue.Created, Issue.Modified, Issue.MeetingTopicID FROM (Project, IssueImpact, IssueLikelihood, IssueType, Issue) LEFT JOIN Category ON Iss
ue.CategoryID = Category.CategoryID LEFT JOIN TeamMember OwnerMember ON Issue.OwnerID = OwnerMember.TeamMemberID LEFT JOIN TeamMember OrigMember ON Iss
ue.OwnerID = OrigMember.TeamMemberID WHERE Issue.ProjectID = Project.ProjectID AND Issue.ImpactID = IssueImpact.ImpactID AND Issue.LikelihoodID = Issu
eLikelihood.LikelihoodID AND Issue.IssueTypeID = IssueType.IssueTypeID AND (((Issue.OwnerID = 101 AND Issue.OwnerID IS NOT NULL) AND NOT((Issue.IssueSt
atus LIKE BINARY 'Closed' AND Issue.IssueStatus IS NOT NULL)))) ORDER BY IssueImpact.ImpactName DESC LIMIT 0, 75
=== 2015-04-19 15:47:34,002 [sor1] DEBUG SQLDataSource - [builtinApplication.Issue_fetch] SQL windowed select rows 0->75, result size 75. Query: SELECT
Issue.IssueID, Issue.ProjectID, Project.ProjectNumber, Project.ProjectTitle, Issue.CommunityID, Issue.IssueNumber, Issue.IssueTitle, Issue.CategoryID,
Category.CategoryName, Issue.IssueTypeID, IssueType.IssueTypeName, Issue.ImpactID, IssueImpact.ImpactName, Issue.LikelihoodID, IssueLikelihood.Likelih
oodTitle, Issue.OwnerID, OwnerMember.OwnerMember.TeamMemberName AS OwnerName, Issue.OriginatorID, OrigMember.OrigMember.TeamMemberName AS OriginatorNam
e, Issue.IssueStatus, Issue.IssueDueDate, Issue.ClosedDate, Issue.OriginalDueDate, Issue.Resolution, Issue.Private, Issue.Description, Issue.LogEntry,
Issue.Log, Issue.Created, Issue.Modified, Issue.MeetingTopicID FROM (Project, IssueImpact, IssueLikelihood, IssueType, Issue) LEFT JOIN Category ON Iss
ue.CategoryID = Category.CategoryID LEFT JOIN TeamMember OwnerMember ON Issue.OwnerID = OwnerMember.TeamMemberID LEFT JOIN TeamMember OrigMember ON Iss
ue.OwnerID = OrigMember.TeamMemberID WHERE Issue.ProjectID = Project.ProjectID AND Issue.ImpactID = IssueImpact.ImpactID AND Issue.LikelihoodID = Issu
eLikelihood.LikelihoodID AND Issue.IssueTypeID = IssueType.IssueTypeID AND (((Issue.OwnerID = 101 AND Issue.OwnerID IS NOT NULL) AND NOT((Issue.IssueSt
atus LIKE BINARY 'Closed' AND Issue.IssueStatus IS NOT NULL)))) ORDER BY IssueImpact.ImpactName DESC LIMIT 0, 75
=== 2015-04-19 15:47:33,995 [sor2] INFO SQLDataSource - [builtinApplication.Locale_fetch] 145: Executing SQL query on 'PlanetProjectDB': SELECT Locale
.LocaleKey, Locale.LocaleName FROM PUBLIC.Locale WHERE ('1'='1')
=== 2015-04-19 15:47:34,010 [sor2] DEBUG PoolableSQLConnectionFactory - [builtinApplication.Locale_fetch] Executing pingTest 'select 1 from dual' on co
nnection 29908324
=== 2015-04-19 15:47:34,011 [sor8] INFO SQLDSGenerator - Fetching column metadata for TimeZone complete
=== 2015-04-19 15:47:34,011 [sor1] WARN RequestContext - dsRequest.execute() failed:
com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Unknown column 'OwnerMember.OwnerMember.TeamMemberName' in 'field list'
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:525)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
at com.mysql.jdbc.Util.getInstance(Util.java:386)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1053)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4074)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4006)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2468)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2629)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2713)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2663)
at com.mysql.jdbc.StatementImpl.executeQuery(StatementImpl.java:1599)
at org.apache.commons.dbcp.DelegatingStatement.executeQuery(DelegatingStatement.java:208)
at com.isomorphic.sql.SQLDataSource.executeWindowedSelect(SQLDataSource.java:2493)
at com.isomorphic.sql.SQLDataSource.SQLExecute(SQLDataSource.java:1905)
at com.isomorphic.sql.SQLDataSource.processRequest(SQLDataSource.java:448)
at com.isomorphic.sql.SQLDataSource.executeFetch(SQLDataSource.java:393)
at com.isomorphic.datasource.DataSource.execute(DataSource.java:1582)
at com.isomorphic.application.AppBase.executeDefaultDSOperation(AppBase.java:723)
at com.isomorphic.application.AppBase.executeAppOperation(AppBase.java:658)
at com.isomorphic.application.AppBase.execute(AppBase.java:491)
at com.isomorphic.datasource.DSRequest.execute(DSRequest.java:2540)
at com.isomorphic.servlet.IDACall.handleDSRequest(IDACall.java:224)
at com.isomorphic.servlet.IDACall.processRPCTransaction(IDACall.java:181)
at com.isomorphic.servlet.IDACall.processRequest(IDACall.java:149)
at com.isomorphic.servlet.IDACall._processRequest(IDACall.java:114)
at com.isomorphic.servlet.IDACall.doPost(IDACall.java:73)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
at com.isomorphic.servlet.BaseServlet.service(BaseServlet.java:152)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
at com.isomorphic.js.JSSyntaxScannerFilter.doFilter(JSSyntaxScannerFilter.java:242)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
at com.isomorphic.servlet.CompressionFilter.doFilter(CompressionFilter.java:260)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:210)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:174)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:108)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:151)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:870)
at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:665)
at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:528)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:81)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:685)
at java.lang.Thread.run(Thread.java:722)
=== 2015-04-19 15:47:34,025 [sor8] DEBUG SQLConnectionManager - About to close ISCPoolableConnection with hashcode "27812789"
=== 2015-04-19 15:47:34,017 [sor2] DEBUG SQLConnectionManager - [builtinApplication.Locale_fetch] Borrowed connection '29908324'
=== 2015-04-19 15:47:34,045 [sor8] DEBUG PoolableSQLConnectionFactory - Executing pingTest 'select 1 from dual' on connection 27812789
=== 2015-04-19 15:47:34,034 [sor1] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
=== 2015-04-19 15:47:34,064 [sor8] DEBUG RPCManager - Request #1 (DSRequest) payload: {
criteria:{
},
operationConfig:{
dataSource:"TimeZone",
repo:null,
operationType:"fetch",
textMatchStyle:"exact"
},
componentId:"(cacheAllData fetch)",
appID:"builtinApplication",
operation:"TimeZone_fetch",
oldValues:null
}
=== 2015-04-19 15:47:34,073 [sor8] INFO IDACall - Performing 1 operation(s)
=== 2015-04-19 15:47:34,074 [sor8] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
=== 2015-04-19 15:47:34,080 [sor8] DEBUG DeclarativeSecurity - DataSource TimeZone is not in the pre-checked list, processing...
=== 2015-04-19 15:47:34,084 [sor8] DEBUG AppBase - [builtinApplication.TimeZone_fetch] No userTypes defined, allowing anyone access to all operations f
or this application
=== 2015-04-19 15:47:34,087 [sor8] DEBUG AppBase - [builtinApplication.TimeZone_fetch] No public zero-argument method named '_TimeZone_fetch' found, pe
rforming generic datasource operation
=== 2015-04-19 15:47:34,091 [sor8] INFO SQLDataSource - [builtinApplication.TimeZone_fetch] Performing fetch operation with
criteria: {} values: {}
=== 2015-04-19 15:47:34,071 [sor3] DEBUG RPCManager - Processing 1 requests.
=== 2015-04-19 15:47:34,067 [sor7] DEBUG RPCManager - Processing 1 requests.
=== 2015-04-19 15:47:34,064 [sor1] DEBUG SQLTransaction - Rolling back PlanetProjectDB transaction "27812789"
=== 2015-04-19 15:47:34,104 [sor1] WARN RPCManager - Exception thrown during onFailure processing
java.sql.SQLException: Connection com.mysql.jdbc.JDBC4Connection@1a863b5 is closed.
at org.apache.commons.dbcp.DelegatingConnection.checkOpen(DelegatingConnection.java:398)
at org.apache.commons.dbcp.DelegatingConnection.rollback(DelegatingConnection.java:368)
at com.isomorphic.sql.SQLTransaction.rollbackTransaction(SQLTransaction.java:176)
at com.isomorphic.sql.SQLDataSource.onFailure(SQLDataSource.java:3896)
at com.isomorphic.rpc.RPCManager.onFailure(RPCManager.java:1741)
at com.isomorphic.rpc.RPCManager.onFailure(RPCManager.java:1637)
at com.isomorphic.rpc.RPCManager.completeResponse(RPCManager.java:1239)
at com.isomorphic.rpc.RPCManager.send(RPCManager.java:643)
at com.isomorphic.servlet.IDACall.processRPCTransaction(IDACall.java:181)
at com.isomorphic.servlet.IDACall.processRequest(IDACall.java:149)
at com.isomorphic.servlet.IDACall._processRequest(IDACall.java:114)
at com.isomorphic.servlet.IDACall.doPost(IDACall.java:73)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
at com.isomorphic.servlet.BaseServlet.service(BaseServlet.java:152)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
at com.isomorphic.js.JSSyntaxScannerFilter.doFilter(JSSyntaxScannerFilter.java:242)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
at com.isomorphic.servlet.CompressionFilter.doFilter(CompressionFilter.java:260)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:210)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:174)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:108)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:151)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:870)
at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:665)
at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:528)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:81)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:685)
at java.lang.Thread.run(Thread.java:722)

I have not had the chance to check out the behavior of my app after the transition from 8.3 to 9.1. It seemed ok in what little I could see before cut off by the crashes. It might be worth it to take the leap and try out version 10. I did not want to take that path just for a prototype. But, it might work to test if the problem is also in that version.

Time for lunch and reflection.

A check of the 8.3 version on 03/27/15 changelog says under Databinding:

DataSource - fixed bug where if we have a field with an includeFrom specification, then it's possible we would alias the field twice in the generated SQL

I wonder if that is in the same module.

If I get a chance this coming week, I will try to install each of the 2015-03-18, 2015-03-24 and 2015-03-26 versions of 8.3 to find which introduced the problem so it can be fixed. I hope it can be fixed in version 9, too. I should be able to upgrade to it from 8.3 and buy the Power version after enough people have seen the app run.

Rick

[RickBollinger]

All 8.3 versions since 2015-02-04 have problem

I installed and tested all the following 8.3 versions and they all crash my app. The last working version was 2015-02-04, so the problem was introduced in 2015-03-18 and propagated into these subsequent versions.

2015-03-18
2015-03-24
2015-03-26
2015-03-27

Issue.ds.xml is above. It fails and causes the app to crash.

<DataSource ID="Project" dataFormat="iscServer" serverType="sql" dataSourceVersion="1" dbName="PlanetProjectDB" schema="PUBLIC" tableName="Project" autoDeriveSchema="true">
    <fields>
        <field name="ProjectID" type="sequence" primaryKey="true"/>
        <field name="CommunityID" type="integer" required="true" title="Community" foreignKey="Community.CommunityID"/>
        <field name="ProjectNumber" type="text" length="16" required="true" title="Number" canEdit="true"/>
        <field name="ProjectTitle" type="text" length="64" required="true" title="Title" canEdit="true"/>
        <field name="TaskOrder" type="text" length="32" title="Task Order" canEdit="true"/>
        <field name="ProjectHashCode" type="text" required="false" length="16"/>
        <field name="Inactive" type="boolean" sqlStorageStrategy="integer" title="Inactive" canEdit="true"/>
		<field name="AutoAnnotateIssues" type="boolean" sqlStorageStrategy="integer" required="false"/>
		<field name="AutoAnnotateRisks" type="boolean" sqlStorageStrategy="integer" required="false"/>
		<field name="CloseIssuesInMeetings" type="boolean" sqlStorageStrategy="integer" required="false"/>
        <field name="SendAlertsOnSave" type="boolean" sqlStorageStrategy="integer" required="false"/>
        <field name="OwningProjectID" type="integer" title="OwningProjectID" detail="false" canEdit="true"  foreignKey="Project.ProjectID"/>
        <field name="OwningProjectNumber" type="text" title="Owning Project">
            <nativeName>ProjectNumber</nativeName>
            <tableName>OwningProject</tableName>
            </field>		        
        <field name="ProjectManagerID" type="integer" title="Project Manager" canEdit="true" foreignKey="TeamMember.TeamMemberID"/>
        <field name="TeamMemberName" type="text" title="Project Manager" detail="false" canEdit="true" tableName="TeamMember"/>
        <field name="AgendaServletName" type="text" length="64" required="true" title="Agenda Template" canEdit="true" foreignKey="AgendaTemplate.AgendaTemplateID"/>
        <field name="AgendaPrintOptions" type="text" length="2147483647" title="Agenda Options" detail="true" canEdit="true"/>
        <field name="MinutesServletName" type="text" length="64" required="true" title="Minutes Template" canEdit="true" foreignKey="MinutesTemplate.MinutesTemplateID"/>
        <field name="MinutesPrintOptions" type="text" length="2147483647" title="Minutes Options" detail="true" canEdit="true"/>
        <field name="ReportServletName" type="text" length="64" required="true" title="Report Template" canEdit="true" foreignKey="ReportTemplate.ReportTemplateID"/>
        <field name="ReportPrintOptions" type="text" length="2147483647" title="Report Options" detail="true" canEdit="true"/>        
        <field name="Description" type="text" length="2147483647" title="Description" detail="true" canEdit="true"/>
        <field name="Log" type="text" length="2147483647" title="Log" detail="true"/>
        <field name="Created" type="creatorTimestamp" title="Created" detail="true"/>
        <field name="Modified" type="modifierTimestamp" title="Modified" detail="true"/>
    </fields>
	<operationBindings>
		<OperationBinding>
			<operationType>fetch</operationType>
			<tableClause>Project LEFT JOIN TeamMember ON Project.ProjectManagerID = TeamMember.TeamMemberID LEFT JOIN Project OwningProject ON Project.OwningProjectID = OwningProject.ProjectID</tableClause>  
		</OperationBinding>
    </operationBindings>
    <title>Project</title>
    <titleField>ProjectTitle</titleField>
    <pluralTitle>Projects</pluralTitle>
    <generatedBy>SC_SNAPSHOT-2012-01-09_v8.2p/Pro Deployment 2012-01-09</generatedBy>
</DataSource>

Project.ds.xml also gets the unknown column exception, above.

<DataSource ID="Task" dataFormat="iscServer" serverType="sql" dataSourceVersion="1" dbName="PlanetProjectDB" schema="PUBLIC" autoDeriveSchema="true">
    <fields>
        <field name="TaskNumber" type="integer" required="false" title="Task#"/>
        <field name="TaskTitle" type="text" required="true" length="64" title="Task Title"/>
        <field name="TaskDueDate" type="date" title="Due Date" detail="true"/>
        <field name="OwnerID" type="integer" title="Owner" detail="true" foreignKey="TeamMember.TeamMemberID"/>
        <field name="TeamMemberName" type="text">
            <tableName>TeamMember</tableName>
        </field>
        <field name="TaskStatus" type="text" required="true" length="16" title="Status">
            <valueMap>
                    <value>Open</value>
                    <value>Rejected</value>
                    <value>Accepted</value>
                    <value>Started</value>
                    <value>Waiting</value>
                    <value>Completed</value>
            </valueMap>
        </field>
        <field name="CompletedDate" type="date" title="Completed Date" detail="true"/>
        <field name="TaskID" type="sequence" detail="true" primaryKey="true"/>
        <field name="ProjectID" type="integer" required="true" detail="true" foreignKey="Project.ProjectID"/>
        <field name="ProjectNumber" type="text" title="Project#" detail="true">
            <tableName>Project</tableName>
        </field>
        <field name="ProjectTitle" type="text" title="Project Title" detail="true">
            <tableName>Project</tableName>
        </field>
        <field name="CommunityID" type="integer" required="true" hidden="true" foreignKey="Community.CommunityID"/>
        <field name="IssueID" type="integer" required="true" title="Issue#" detail="true" foreignKey="Issue.IssueID"/>
        <field name="IssueTitle" type="text" title="Issue Title" detail="true">
            <tableName>Issue</tableName>
        </field>
        <field name="Private" type="boolean" required="false" title="Private" canEdit="false" sqlStorageStrategy="integer">
		    <tableName>Issue</tableName>
        </field>
        <field name="IssueNumber" type="text" title="Issue#" detail="true">
            <tableName>Issue</tableName>
        </field>
        <field name="IssueOwner" type="text" title="Issue Owner" detail="true">
            <nativeName>TeamMemberName</nativeName>
            <tableName>IssueMember</tableName>
        </field>
        <field name="IssueStatus" type="text" title="Issue Status" detail="true">
            <tableName>Issue</tableName>
        </field>
        <field name="IssueImpact" type="text" title="Issue Impact" detail="false">
            <nativeName>ImpactName</nativeName>
            <tableName>IssueImpact</tableName>
        </field>
        <field name="OriginalDueDate" type="date" title="Original Due" detail="true"/>
        <field name="StartDate" type="date" title="Start Date" detail="true"/>
        <field name="Description" type="text" length="2147483647" title="Description" detail="true"/>
        <field name="LogEntry" type="text" length="1024" title="Log" detail="true" canEdit="false"/>
        <field name="Log" type="text" length="2147483647" title="Log" detail="true"/>
        <field name="Created" type="creatorTimestamp" title="Created"/>
        <field name="Modified" type="modifierTimestamp" title="Modified" detail="true"/>
    </fields>
    <operationBindings>
        <OperationBinding>
            <operationType>fetch</operationType>
            <tableClause>(Project, Issue, Task, IssueImpact) LEFT JOIN TeamMember ON Task.OwnerID = TeamMember.TeamMemberID LEFT JOIN TeamMember IssueMember ON IssueMember.TeamMemberID = Issue.OwnerID</tableClause>
            <whereClause>IssueImpact.ImpactID = Issue.ImpactID AND Task.IssueID = Issue.IssueID AND Task.ProjectID = Project.ProjectID  AND ($defaultWhereClause)</whereClause>
        </OperationBinding>
    </operationBindings>
    <title>Task</title>
    <titleField>TaskTitle</titleField>
    <pluralTitle>Tasks</pluralTitle>
    <generatedBy>SC_SNAPSHOT-2012-01-09_v8.2p/Pro Deployment 2012-01-09</generatedBy>
</DataSource>

Task.ds.xml, above, however WORKS! Even though it uses nativeName.

I was not able to see a pattern of difference with Issue.ds.xml or otherwise diagnose a cause.

I can confirm that the problem still exists in v8.3 release for 2015-04-23. That, too, crashes my app.

Rick

[RickBollinger]

Problem fixed! Hooray!

This problem seems to have been fixed in the SmartClient_v91p_2015-05-06_Evaluation version. The SQL generated appears to be correct.

Thanks very much. I really appreciate the help.

Some other odd things are broken. But that would be for another post if I can't fix them.

Rick