date being changed between client and server

[dbscott525]

SmartGWT version 5.0-p20141231.

I’m running my SmartGWT application on a browser in one time zone (let’s call it time zone A). My application server is in another time zone (time zone B). In a third time zone (time zone C) I’m running a test program.

To Summarize the time zone situation:

Time zone A (offset -60): SmartGWT browser application
Time zone B (offset 0): SmartGWT server application.
Time zone C (offset 420): TestNG/Selenium test.

These computers are in different time zones due to different vendors providing the services I use for my CI test system.

I store a date in a MySQL database using the SmartGWT client DataSource. The date is originally “Sat Mar 06 00:00:00 PST 2004” (milliseconds=1078560000000).

From another computer in time zone C, I retrieve the date from the database using Hibernate/MySQL. When I retrieve the data no Isomorphic code is involved.

The date that was stored using SmartGWT DataSource and then retrieved using Hibernate/MySQL has an 8 hour difference. 8 hours have been added to the original date generated from the SmartGWT browser.

The date I read directly from the MySQL database with the time zone C computer is “Sat Mar 06 08:00:00 PST 2004” (milliseconds=1078560000000).

Why is Isomorphic adding 8 hours to my date in the storage process? Is there any setting I can use to prevent this date transformation?

I would like to have stored in the MySQL database exactly the date in milliseconds originated from the browser application.

[Isomorphic]

The milliseconds are the same, so the date is the same. What you are seeing is formatting in different timezones. See the Date and Time Format and Storage for more background.

If you are still confused after thoroughly reviewing this doc and need more help, be more precise about exactly when and how you are formatting these dates (client? Server? Using what classes and with what timezone and locale settings?)

[dbscott525]

I had a copy/paste mistake.

At the origin the milliseconds are 1078560000000.

When the are read from the database the milliseconds are 1078588800000.

I have read the doc multiple times and didn't find it clarifying.

[Isomorphic]

Some advice applies: you need to read the Date and Time Format and Storage overview thoroughly, especially the troubleshooting section.

This overview exists, which so much detail, because we routinely receive bug reports about date and time behavior which are not in fact bugs. So please review it thoroughly.

If you believe you've discovered a framework bug, we need a very precise accounting of exactly where you think the bad behavior is, how you are looking at the values, etc, as previously indicated. Also don't forget to mention whether this is a "date" or "datetime" field.

[Isomorphic]

We see you edited your post while we were replying indicating you've read the doc multiple times - please don't take this in the wrong way, but you need to look again, especially at the section "check data at every phase when troubleshooting". You have provided far too little information to allow anyone to diagnose the problem.

[dbscott525]

My apologies for not providing the information you need. Here is a more detailed description:

The test I’m running is done on remote computers that I don’t have direct access to. To discover what is going on I have a logger which logs to a central database. So I can log any information from the SmartGWT browser application, the SmartGWT server application, and my test program to the same log stored in the database.

Right before adding a record in my SmartGWT browser application, the code looks like this:

		Record answerRecord = answer.getRecord();
		Date date = answerRecord.getAttributeAsDate("date");
		if (date != null) {
			DebugLog.log(this, "date.getTime()=" + date.getTime());
		}
		DataSource dataSource = answer.getDataSource();

		switch (answerPersistRequest.getAnswerPersistType()) {
		case ADD:
			dataSource.addData(answerRecord);
			break;
		case DELETE:
			dataSource.removeData(answerRecord);
			break;
		case UPDATE:
			dataSource.updateData(answerRecord);
			break;
		}

This code records the log entry: 'date.getTime()=1078560000000'

The next time I reference this date is when I read the date from the database in my test code using Hibernate.

Here is the test code that reads and logs the time:

	public List<Answers> getPersistedAnswers() throws Exception {
		Answers criteriaAnswer = new Answers();
		criteriaAnswer.setDialogId(currentDialogId);
		List<Answers> answers = criteriaAnswer.readRows();
		for (Answers answer : answers) {
			Date date = answer.getDate();
			if (date != null) {
				DebugLog.log(this, "date.getTime()=" + date.getTime());
			}
		}
		return answers;
	}

The resulting log entry is 'date.getTime()=1078588800000'

So to summarize:

1. I save the Date object in a record with a DataSource. Right before dataSource.addData(answerRecord) the time is logged as 1078560000000.
2. I read the Date object through Hibernate. The time is read and logged as 1078588800000.
3. Computing the difference results in an 8 hour difference.

I do have a working theory of what the bug may be:

- Before transmitting object Date to the server, Isomorphic serializes the Date object to a string.
- The string is serialized without time zone information and is serialized as a date in the time zone of the browser.
- The time zone stored in Date object is different than the time zone of the browser by exactly 8 hours. (I'm creating the Date object in a specific time zone to simulate an end-user in a specific time zone.).
- When the date/time is deserialized on the server it is deserialized in the server or browsers time zone (I don't know which but the browser is in a time zone one hour difference from the server). This causes the original time zone to be lost and causes the actual millisecond time to be changed due to the difference between the original Date object time zone and the browser or server time zone.
- This deserialized but incorrect millisecond time is what is stored in the database and then later read by my test code.

I read through the referenced document again and here are my answers to the trouble shooting guide.

1. what value do I have on the server-side before it's sent to the client?

Answer: the date object originates on the client and is saved in a MySQL database using a client-side DataSource object.

2. what value is being transmitted to the client? (use the RPC Tab of the Developer Console to see the actual data sent)
a. was the value shifted to a different time/date by my serialization approach?
b. does it have the right format? (see above for correct JSON/XML formats)

Answer: no value is being transmitted to the client from the server.

3. what value do I have on the client before it gets to any widgets (eg, do a direct call to DataSource.fetchData() and inspect the data in the callback):

Answer: I don’t use the Date object to store in any widgets. It's only used to save to a MySQL database using a client-side DataSource.

4. what value does the FormItem or other editing widget report before saving is attempted?

Answer: I'm not using a FormItem or other widget to save the date. I'm only using a client-side DataSource.

5. what value is reported right before the value is serialized for transmission to the server (DataSource.transformRequest() is a good place to check)

Answer: I do not implement DataSource.transformRequest() and I am not familiar with this. As indicated above, date.getTime()=1078560000000 before calling dataSource.addData. Is there a way to use DataSource.transformRequest() to get visibility into what is being transmitted to the server?

6. what value is being transmitted to the server? (use the RPC tab - same concerns as for server-to-client transmission above)

Answer: I am running this in a remote automated situation. I do not have direct hands-on access to the browser or any Isomorphic debugging tools. I'm relying on logging information to a database from the client. Let me know if there is a programmatic way to get access to debugging information. If so, I can log that to the database.

7. what value does the server have after de-serialization, before saving to the database or other permanent storage?

Answer: I don’t have visibility into this because this is in the SmartGWT server layer. During this operation my server application is not involved. There is only my SmartGWT browser application which is saving rows to the database via a client-side DataSource.

8. what value is sent to the database or permanent storage? If generating SQL or another similar query language, does the value in the SQL statement include an explicit timezone? If not, how will the database interpret it?

Answer: As indicated above, I'm using the SmartGWT client-side DataSource object to save data to the MySQL database.

Here is my data source xml:

<DataSource
	dbName="Mysql"
	tableName="answers"
	ID="answers"
	dataSourceVersion="1"
	generatedBy="v8.3p_2013-02-26/EVAL Deployment 2013-02-26"
	serverType="sql"
>
	<fields>
		<field name="Id"               title="ID"                 type="text"     length="255"  hidden="true"  primaryKey="true" />
		<field name="Answer"           title="Answer"             type="text"     length="45"   hidden="false"                   />
		<field name="Color"            title="Color"              type="text"     length="10"   hidden="false"                   />
		<field name="Date"             title="Date"               type="datetime"               hidden="false"                   />
		<field name="Description"      title="Description"        type="text"     length="1000" hidden="false"                   />
		<field name="DialogId"         title="Dialog ID"          type="text"     length="45"   hidden="false"                   />
		<field name="Notes"            title="Notes"              type="text"     length="1000" hidden="false"                   />
		<field name="Number"           title="Number"             type="text"     length="25"   hidden="false"                   />
		<field name="OptionType"       title="Option Type"        type="text"     length="25"   hidden="false"                   />
		<field name="SessionStartTime" title="Session Start Time" type="datetime"               hidden="false"                   />
		<field name="Topic"            title="Topic"              type="text"     length="45"   hidden="false"                   />
		<field name="TopicGroup"       title="Topic Group"        type="text"     length="45"   hidden="false"                   />
		<field name="TopicGroupName"   title="Topic Group Name"   type="text"     length="45"   hidden="false"                   />
		<field name="TopicGroupOrder"  title="Topic Group Order"  type="integer"                hidden="false"                   />
		<field name="TopicName"        title="Topic Name"         type="text"     length="45"   hidden="false"                   />
		<field name="TopicOrder"       title="Topic Order"        type="integer"                hidden="false"                   />
		<field name="Value"            title="Value"              type="text"     length="1000" hidden="false"                   />
	</fields>
</DataSource>

[Isomorphic]

Lots of information, but unfortunately, not much of it pertinent...

First, the overview we pointed you explicitly covers client>server serialization works, in particular that datetimes are transmitted as millisecond values. So, your theory is not correct, and you can trivially verify this by just looking at the server logs for the request. In the default logging configuration this will show the request data with datetime values logged in milliseconds.

We're aware you're seeing this this problem in a remote environment with an automated front-end, that's fine, but it doesn't mean you can simply decline to use standard diagnostics and standard troubleshooting approaches :)

You should be able to remotely access both the server logs and Developer Console. If this is hard in any way, then since you think this is a framework bug, just set about creating an environment where you can replicate the problem, and where standard diagnostics will be accessible.

Second, you need to look for possible problems in how you are *accessing* the data as well. We'd recommend directly using MySQL admin tools to see the database value, in order to avoid any possible mistakes in the JDBC/Hibernate layer (such as using the wrong Java bean property type, or wrong annotations/Hibernate mapping).

[dbscott525]

In the default logging configuration this will show the request data with datetime values logged in milliseconds.

We’re running the application server on AWS. It will take some effort but I will see what I can find out from the logs.

but it doesn't mean you can simply decline to use standard diagnostics and standard troubleshooting approaches :)

I’m not trying to decline standard troubleshooting approaches. I’m just not familiar with all of them. I have been working on this problem going on three weeks and will do anything I can to find a resolution.

We'd recommend directly using MySQL admin tools to see the database value

I have done that. The MySQL Workbench displays the date value as “2004-03-06 08:00:00” I exported the table in question and here is how MySQL exports the table

DROP TABLE IF EXISTS `answers`;
/*!40101 SET @saved_cs_client     = @@character_set_client */;
/*!40101 SET character_set_client = utf8 */;
CREATE TABLE `answers` (
  `ID` varchar(255) NOT NULL DEFAULT '',
  `Answer` varchar(45) DEFAULT NULL,
  `Color` varchar(10) DEFAULT NULL,
  `Date` datetime DEFAULT NULL,
  `Description` varchar(1000) DEFAULT NULL,
  `DialogId` varchar(45) DEFAULT NULL,
  `Notes` varchar(1000) DEFAULT NULL,
  `Number` decimal(18,4) DEFAULT NULL,
  `OptionType` varchar(25) DEFAULT NULL,
  `SessionStartTime` datetime DEFAULT NULL,
  `Topic` varchar(45) DEFAULT NULL,
  `TopicGroup` varchar(45) DEFAULT NULL,
  `TopicGroupName` varchar(45) DEFAULT NULL,
  `TopicGroupOrder` int(11) DEFAULT NULL,
  `TopicName` varchar(45) DEFAULT NULL,
  `TopicOrder` int(11) DEFAULT NULL,
  `Value` varchar(1000) DEFAULT NULL,
  PRIMARY KEY (`ID`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8;
/*!40101 SET character_set_client = @saved_cs_client */;

--
-- Dumping data for table `answers`
--

LOCK TABLES `answers` WRITE;
/*!40000 ALTER TABLE `answers` DISABLE KEYS */;
INSERT INTO `answers` VALUES ('GKCLe2BVkcf9tDd7dx70xY71mTCo5spP4tN0jdd39TZCM|foo|FollowUpCall|Choose Date','Choose Date','green','2004-03-06 08:00:00','When is the follow-up call?','GKCLe2BVkcf9tDd7dx70xY71mTCo5spP4tN0jdd39TZCM',NULL,NULL,'DateChooser','2015-04-09 00:34:25','Follow-up Call','CONCLUDE','foo',3,'FollowUpCall',3,'3/6/2004');

As you can see the date is shown as 8 hours off.

If this is hard in any way, then since you think this is a framework bug, just set about creating an environment where you can replicate the problem, and where standard diagnostics will be accessible.

I was able to get access to the Dev Console and able to run the test manually. Because this is a remote browser I could not copy the text, but I did make some screen shots. I made screen shots of the DSRequest, Raw Request, RPCRequest, Raw response, and call stack. Unfortunately, the sizes of these files are larger than the discussion forums permit. However, in each of these it shows the date as being off by 8 hours. I can provide these images via email or DropBox.

[Isomorphic]

I was able to get access to the Dev Console and able to run the test manually. Because this is a remote browser I could not copy the text, but I did make some screen shots. I made screen shots of the DSRequest, Raw Request, RPCRequest, Raw response, and call stack. Unfortunately, the sizes of these files are larger than the discussion forums permit. However, in each of these it shows the date as being off by 8 hours. I can provide these images via email or DropBox.

So you're saying the millisecond value is changed after you call addData() and before the data is serialized. This is a whopper of a claim, contradicting dozens of automated tests and the experience of 10s of thousands of developers, so the first thing we'd recommend is closely re-examining your data: you may have a RequestTransformer manipulating the data, the DataSource you showed earlier may not actually be the one loaded, other files in this environment may not be the ones you're looking at, etc.

If you're satisfied this is really happening, certainly you should go ahead and upload your screenshots to the forums. People routinely upload such screenshots. If you're having trouble, you may have captured them as uncompressed .bmp or similar; just use .jpg, .png or any similar format instead.

[dbscott525]

So you're saying the millisecond value is changed after you call addData() and before the data is serialized

I don't really know when the millisecond value is being changed. Apparently, this date passes through several layers between when I call addData() and when I read it from the MySQL database. I don't know in what layer the change occurs.

you may have a RequestTransformer manipulating the data, the DataSource you showed earlier may not actually be the one loaded, other files in this environment may not be the ones you're looking at, etc.

How can I tell if I have a RequestTransformer manipulating the data? I have never used a RequestTransformer so I don't really know how it works.

That being said, I don't think the change in milliseconds is happening on the client side. I was able to get the server log from the dev console and as you'll see below in the server log the millisecond date doesn't show as being changed. I've never used the server log from the dev console before so I may be misinterpreting this.

I came up with a way to copy text from the Browserstack environment. I copy the text to a Google Doc and then in my own environment copy text from the Google Doc to this posting.

The result is I have copied all the information I could find from the Dev Console as shown below.

My observations:

- The date is displayed in the various client-side versions below as 2004-03-06T08:00:00.000. I think the millisecond date is still correct on the client side, but displayed with the 8 hour difference because the date is being displayed in the time zone of the browser. The time zone I have stored in the Date object is 8 hours different than that of the browser.

- The raw date from the server log is correct based on this snippet from the server log:

=== 2015-04-09 13:59:17,691 [c-18] DEBUG DataSource - [builtinApplication.answers_add] post-validation valueSet: [
    {
        Answer:"Choose Date",
        Color:"green",
        Date:new Date(1078560000000),
        Description:"When is the follow-up call?",
        DialogId:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj",
        Id:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date",
        OptionType:"DateChooser",
        SessionStartTime:new Date(1428587864995),
        Topic:"Follow-up Call",
        TopicGroup:"CONCLUDE",
        TopicGroupName:"foo",
        TopicGroupOrder:3,
        TopicName:"FollowUpCall",
        TopicOrder:3,
        Value:"3/6/2004"
    }
]

- The date transformation may be happening when going from the binary date transmitted to the server to the date used in the MySQL Insert. It looks as though the date is transformed to a string before generating an SQL Insert. Probably the transformation is done in the time zone of the browser (or server) resulting in the 8 hour shift. If you look at the server log you'll see the Isomorphic generated SQL as (I've added line breaks and indentation for clarity):

INSERT INTO answers (
  Answer, 
  Color, 
  Date, 
  Description, 
  DialogId, 
  Id, 
  OptionType, 
  SessionStartTime,
  Topic, 
  TopicGroup, 
  TopicGroupName, 
  TopicGroupOrder, 
  TopicName, 
  TopicOrder, 
  Value
) 
VALUES (
  'Choose Date', 
  'green', 
  '2004-03-06 08:00:00', 
  'When is the follow-up call?', 'IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj',
  'IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date',
  'DateChooser',
  '2015-04-09 13:57:44',
  'Follow-up Call',
  'CONCLUDE',
  'foo',
  3,
  'FollowUpCall',
  3,
  '3/6/2004'
)

Here's a new possible bug scenario:
1. The time zone stored in the Date object on the client is different than that of the browser.
2. The time zone from the Date object is lost when the date is transformed to a millisecond version before being transmitted it to the server.
3. On the server side, to Insert the into the SQL database the millisecond date is converted to a string using the browser time zone
4. This results in the 8 hour difference which is the difference between the original time zone stored in the Date object and the browser time zone.

Here is the raw information I copied from the dev console.

DSRequest

{
    dataSource:"answers", 
    operationType:"add", 
    data:{
        Answer:"Choose Date", 
        Color:"green", 
        Date:"2004-03-06T08:00:00.000", 
        Description:"When is the follow-up call?", 
        DialogId:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj", 
        Id:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date", 
        OptionType:"DateChooser", 
        SessionStartTime:"2015-04-09T13:57:44.995", 
        Topic:"Follow-up Call", 
        TopicGroup:"CONCLUDE", 
        TopicGroupName:"foo", 
        TopicGroupOrder:3, 
        TopicName:"FollowUpCall", 
        TopicOrder:3, 
        Value:"3/6/2004"
    }, 
    textMatchStyle:"exact", 
    showPrompt:true, 
    oldValues:{
        Answer:"Choose Date", 
        Color:"green", 
        Date:"2004-03-06T08:00:00.000", 
        Description:"When is the follow-up call?", 
        DialogId:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj", 
        Id:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date", 
        OptionType:"DateChooser", 
        SessionStartTime:"2015-04-09T13:57:44.995", 
        Topic:"Follow-up Call", 
        TopicGroup:"CONCLUDE", 
        TopicGroupName:"foo", 
        TopicGroupOrder:3, 
        TopicName:"FollowUpCall", 
        TopicOrder:3, 
        Value:"3/6/2004"
    }, 
    requestId:"answers$62724", 
    fallbackToEval:false, 
    lastClientEventThreadCode:"MUP9", 
    bypassCache:true
}

RPC Request

{
    dataSource:"answers", 
    operationType:"add", 
    data:{
        Answer:"Choose Date", 
        Color:"green", 
        Date:"2004-03-06T08:00:00.000", 
        Description:"When is the follow-up call?", 
        DialogId:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj", 
        Id:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date", 
        OptionType:"DateChooser", 
        SessionStartTime:"2015-04-09T13:57:44.995", 
        Topic:"Follow-up Call", 
        TopicGroup:"CONCLUDE", 
        TopicGroupName:"foo", 
        TopicGroupOrder:3, 
        TopicName:"FollowUpCall", 
        TopicOrder:3, 
        Value:"3/6/2004"
    }, 
    textMatchStyle:"exact", 
    showPrompt:true, 
    oldValues:{
        Answer:"Choose Date", 
        Color:"green", 
        Date:"2004-03-06T08:00:00.000", 
        Description:"When is the follow-up call?", 
        DialogId:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj", 
        Id:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date", 
        OptionType:"DateChooser", 
        SessionStartTime:"2015-04-09T13:57:44.995", 
        Topic:"Follow-up Call", 
        TopicGroup:"CONCLUDE", 
        TopicGroupName:"foo", 
        TopicGroupOrder:3, 
        TopicName:"FollowUpCall", 
        TopicOrder:3, 
        Value:"3/6/2004"
    }, 
    requestId:"answers$62724", 
    fallbackToEval:false, 
    lastClientEventThreadCode:"MUP9", 
    bypassCache:true
}

Raw Request

{
    affectedRows:1, 
    data:[
        {
            Value:"3/6/2004", 
            Description:"When is the follow-up call?", 
            Answer:"Choose Date", 
            TopicName:"FollowUpCall", 
            TopicGroup:"CONCLUDE", 
            Color:"green", 
            Date:"2004-03-06T08:00:00.000", 
            TopicGroupName:"foo", 
            SessionStartTime:"2015-04-09T13:57:44.000", 
            TopicGroupOrder:3, 
            Topic:"Follow-up Call", 
            DialogId:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj", 
            TopicOrder:3, 
            Id:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date", 
            OptionType:"DateChooser"
        }
    ], 
    invalidateCache:false, 
    isDSResponse:true, 
    operationType:"add", 
    queueStatus:0, 
    status:0
}

Call Stack

	RPCManager._sendRequest(_1=>Obj) @ ISC_DataBinding.js:1335:127
	DataSource.performSCServerOperation(_1=>Obj, _2=>Obj) @ ISC_DataBinding.js:2452:75
	DataSource.sendDSRequest(_1=>Obj) @ ISC_DataBinding.js:804:24
	DataSource.performDSOperation(_1=>"add", _2=>Obj, _3=>undef, _4=>undef) @ ISC_DataBinding.js:778:13
	DataSource.addData(_1=>Obj, _2=>undef, _3=>undef) @ ISC_DataBinding.js:760:6
	Nxc(c=>com.smartgwt.client.data.DataSource@14e, a=>com.smartgwt.client.data.Record@14f) @ E63AD5E555CAEB4C764F62DEBED1C2DE.cache.html:1711:34
	yb(a=>com.cedarcone.Orchestrate.client.controller.AnswerDatabaseUpdater@150, b=>AnswerPersistRequest [answerPersistType=ADD, answer=Answer [id=IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date, answer=Choose Date, color=green, date=Sat Mar 06 08:00:00 GMT+000 2004, description=When is the follow-up call?, dialogId=IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj, optionType=DateChooser, sessionStartTime=Thu Apr 09 14:57:44 GMT+100 2015, topic=Follow-up Call, topicGroup=CONCLUDE, topicGroupName=foo, topicGroupOrder=3, topicName=FollowUpCall, topicOrder=3, value=3/6/2004]]) @ E63AD5E555CAEB4C764F62DEBED1C2DE.cache.html:3778:152
	Cb(a=>AnswerPersistRequest [answerPersistType=ADD, answer=Answer [id=IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date, answer=Choose Date, color=green, date=Sat Mar 06 08:00:00 GMT+000 2004, description=When is the follow-up call?, dialogId=IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj, optionType=DateChooser, sessionStartTime=Thu Apr 09 14:57:44 GMT+100 2015, topic=Follow-up Call, topicGroup=CONCLUDE, topicGroupName=foo, topicGroupOrder=3, topicName=FollowUpCall, topicOrder=3, value=3/6/2004]]) @ E63AD5E555CAEB4C764F62DEBED1C2DE.cache.html:4116:10009
	PQ(b=>PERSIST_ANSWER, c=>AnswerPersistRequest [answerPersistType=ADD, answer=Answer [id=IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date, answer=Choose Date, color=green, date=Sat Mar 06 08:00:00 GMT+000 2004, description=When is the follow-up call?, dialogId=IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj, optionType=DateChooser, sessionStartTime=Thu Apr 09 14:57:44 GMT+100 2015, topic=Follow-up Call, topicGroup=CONCLUDE, topicGroupName=foo, topicGroupOrder=3, topicName=FollowUpCall, topicOrder=3, value=3/6/2004]], d=>com.cedarcone.Orchestrate.client.controller.AnswerDatabaseUpdater$1@151) @ E63AD5E555CAEB4C764F62DEBED1C2DE.cache.html:3770:32
	NQ(a=>PERSIST_ANSWER, b=>com.cedarcone.Orchestrate.client.conversationguide.shared.CopyOnWriteArrayList@152, c=>AnswerPersistRequest [answerPersistType=ADD, answer=Answer [id=IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date, answer=Choose Date, color=green, date=Sat Mar 06 08:00:00 GMT+000 2004, description=When is the follow-up call?, dialogId=IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj, optionType=DateChooser, sessionStartTime=Thu Apr 09 14:57:44 GMT+100 2015, topic=Follow-up Call, topicGroup=CONCLUDE, topicGroupName=foo, topicGroupOrder=3, topicName=FollowUpCall, topicOrder=3, value=3/6/2004]]) @ E63AD5E555CAEB4C764F62DEBED1C2DE.cache.html:2608:67

Server log from the Dev Console

=== 2015-04-09 13:59:16,529 [c-23] INFO  Compression - /Orchestrate/sc/IDACall: 391 -> 325 bytes
=== 2015-04-09 13:59:17,683 [c-18] INFO  RequestContext - URL: '/Orchestrate/sc/IDACall', User-Agent: 'Mozilla/5.0 (Windows NT 6.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/40.0.2214.93 Safari/537.36': Safari with Accept-Encoding header
=== 2015-04-09 13:59:17,691 [c-18] DEBUG DataSource - [builtinApplication.answers_add] post-validation valueSet: [
    {
        Answer:"Choose Date",
        Color:"green",
        Date:new Date(1078560000000),
        Description:"When is the follow-up call?",
        DialogId:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj",
        Id:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date",
        OptionType:"DateChooser",
        SessionStartTime:new Date(1428587864995),
        Topic:"Follow-up Call",
        TopicGroup:"CONCLUDE",
        TopicGroupName:"foo",
        TopicGroupOrder:3,
        TopicName:"FollowUpCall",
        TopicOrder:3,
        Value:"3/6/2004"
    }
]
=== 2015-04-09 13:59:17,691 [c-18] INFO  SQLDataSource - [builtinApplication.answers_add] Performing add operation with
	criteria: {Answer:"Choose Date",Color:"green",Date:new Date(1078560000000),Description:"When is the follow-up call?",DialogId:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj",Id:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date",OptionType:"DateChooser",SessionStartTime:new Date(1428587864995),Topic:"Follow-up Call",TopicGroup:"CONCLUDE",TopicGroupName:"foo",TopicGroupOrder:3,TopicName:"FollowUpCall",TopicOrder:3,Value:"3/6/2004"}	values: {Answer:"Choose Date",Color:"green",Date:new Date(1078560000000),Description:"When is the follow-up call?",DialogId:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj",Id:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date",OptionType:"DateChooser",SessionStartTime:new Date(1428587864995),Topic:"Follow-up Call",TopicGroup:"CONCLUDE",TopicGroupName:"foo",TopicGroupOrder:3,TopicName:"FollowUpCall",TopicOrder:3,Value:"3/6/2004"}
=== 2015-04-09 13:59:17,694 [c-18] INFO  SQLDriver - [builtinApplication.answers_add] Executing SQL update on 'Mysql': INSERT INTO answers (Answer, Color, Date, Description, DialogId, Id, OptionType, SessionStartTime, Topic, TopicGroup, TopicGroupName, TopicGroupOrder, TopicName, TopicOrder, Value) VALUES ('Choose Date', 'green', '2004-03-06 08:00:00', 'When is the follow-up call?', 'IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj', 'IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date', 'DateChooser', '2015-04-09 13:57:44', 'Follow-up Call', 'CONCLUDE', 'foo', 3, 'FollowUpCall', 3, '3/6/2004')
=== 2015-04-09 13:59:17,716 [c-18] INFO  SQLDataSource - [builtinApplication.answers_add] primaryKeys: {Id=IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date}
=== 2015-04-09 13:59:17,717 [c-18] INFO  SQLDataSource - [builtinApplication.answers_add, builtinApplication.null] Performing fetch operation with
	criteria: {Id:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date"}	values: {Id:"IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date"}
=== 2015-04-09 13:59:17,717 [c-18] INFO  SQLDataSource - [builtinApplication.answers_add, builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
=== 2015-04-09 13:59:17,717 [c-18] INFO  SQLDataSource - [builtinApplication.answers_add, builtinApplication.null] 25: Executing SQL query on 'Mysql': SELECT answers.Id, answers.Answer, answers.Color, answers.Date, answers.Description, answers.DialogId, answers.Notes, answers.Number, answers.OptionType, answers.SessionStartTime, answers.Topic, answers.TopicGroup, answers.TopicGroupName, answers.TopicGroupOrder, answers.TopicName, answers.TopicOrder, answers.Value FROM answers WHERE (answers.Id='IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date')
=== 2015-04-09 13:59:17,717 [c-18] INFO  SQLDriver - [builtinApplication.answers_add, builtinApplication.null] Executing SQL query on 'Mysql': SELECT answers.Id, answers.Answer, answers.Color, answers.Date, answers.Description, answers.DialogId, answers.Notes, answers.Number, answers.OptionType, answers.SessionStartTime, answers.Topic, answers.TopicGroup, answers.TopicGroupName, answers.TopicGroupOrder, answers.TopicName, answers.TopicOrder, answers.Value FROM answers WHERE (answers.Id='IMlwMoQM4uSFKV5lgIH0uiJWQBXR9rqGnDVGEn9IsJejj|foo|FollowUpCall|Choose Date')
=== 2015-04-09 13:59:17,723 [c-18] INFO  DSResponse - [builtinApplication.answers_add, builtinApplication.null] DSResponse: List with 1 items
=== 2015-04-09 13:59:17,723 [c-18] INFO  DSResponse - [builtinApplication.answers_add] DSResponse: List with 1 items
=== 2015-04-09 13:59:17,726 [c-18] INFO  Compression - /Orchestrate/sc/IDACall: 603 -> 379 bytes
=== 2015-04-09 13:59:18,336 [ec-2] INFO  RequestContext - URL: '/images/ConversationGuide/Register/green-dot.png', User-Agent: 'Mozilla/5.0 (Windows NT 6.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/40.0.2214.93 Safari/537.36': Safari with Accept-Encoding header
=== 2015-04-09 13:59:18,338 [ec-7] INFO  RequestContext - URL: '/images/ConversationGuide/Register/pointer-green.png', User-Agent: 'Mozilla/5.0 (Windows NT 6.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/40.0.2214.93 Safari/537.36': Safari with Accept-Encoding header
=== 2015-04-09 13:59:19,799 [c-17] INFO  RequestContext - URL: '/Orchestrate/sc/system/reference/skin/images/server_client_exchange.png', User-Agent: 'Mozilla/5.0 (Windows NT 6.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/40.0.2214.93 Safari/537.36': Safari with Accept-Encoding header
=== 2015-04-09 13:59:19,799 [c-17] INFO  Download - done streaming: /var/lib/tomcat7/webapps/ROOT/Orchestrate/sc/system/reference/skin/images/server_client_exchange.png
=== 2015-04-09 13:59:19,802 [ec-4] INFO  RequestContext - URL: '/Orchestrate/sc/skins/Enterprise/images/DynamicForm/unchecked_Disabled.png', User-Agent: 'Mozilla/5.0 (Windows NT 6.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/40.0.2214.93 Safari/537.36': Safari with Accept-Encoding header
=== 2015-04-09 13:59:19,802 [ec-4] INFO  Download - done streaming: /var/lib/tomcat7/webapps/ROOT/Orchestrate/sc/skins/Enterprise/images/DynamicForm/unchecked_Disabled.png
=== 2015-04-09 13:59:35,117 [c-24] INFO  RequestContext - URL: '/Orchestrate/sc/skins/Enterprise/images/Scrollbar/vscroll_sprite.png', User-Agent: 'Mozilla/5.0 (Windows NT 6.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/40.0.2214.93 Safari/537.36': Safari with Accept-Encoding header
=== 2015-04-09 13:59:35,118 [c-24] INFO  Download - done streaming: /var/lib/tomcat7/webapps/ROOT/Orchestrate/sc/skins/Enterprise/images/Scrollbar/vscroll_sprite.png
=== 2015-04-09 14:13:13,069 [c-15] INFO  RequestContext - URL: '/Orchestrate/sc/system/development/ISC_ServerLogViewer.js', User-Agent: 'Mozilla/5.0 (Windows NT 6.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/40.0.2214.93 Safari/537.36': Safari with Accept-Encoding header
=== 2015-04-09 14:13:13,070 [c-15] INFO  Download - done streaming: /var/lib/tomcat7/webapps/ROOT/Orchestrate/sc/system/development/ISC_ServerLogViewer.js
=== 2015-04-09 14:13:13,070 [c-15] INFO  Compression - /Orchestrate/sc/system/development/ISC_ServerLogViewer.js: 8766 -> 3088 bytes

[Isomorphic]

new Date(1078560000000).toUTCString();

Result is "Sat, 06 Mar 2004 08:00:00 GMT".

In both directions, client<->server, we transmit as a millisecond value or equivalently, we send in UTC and parse in UTC, so the value is never changed in transit at any point.

As you can see from the logs, the value remains consistently in UTC all the way to the MySQL "INSERT" statement. Since we store in UTC, we also parse database values in UTC, and you can also easily verify that we round-trip the date value successfully when it stored from the UI to the server and viewed again in the UI.

What looks to be the problem is that your MySQL table is defined to store the value in server local time, so you either need to change that to UTC, or adjust your code that reads from the database to treat the stored value as UTC.

[dbscott525]

What looks to be the problem is that your MySQL table is defined to store the value in server local time, so you either need to change that to UTC, or adjust your code that reads from the database to treat the stored value as UTC.

So my understanding is that unless the database is on a server where the system time zone is UTC, Isomorphic will save a date to the database that is different than the original date provided to the DataSource record. Also, it is up to the application to resolve this somehow when reading the date from another computer that may be in a different time zone.

This seems to require a lot from the application developer. For many, the time zone of their database server may be unknown and out of their control. That is the case with us. We’re using an Amazon instance of MySQL and don’t have any control of the time zone. In fact, due to Amazon provisioning the MySQL server may be moved to various servers with different time zones without warning.

IMHO, this strikes me as a deficiency that makes it hard for application developers to understand how to get the correct dates saved in the database. In the era of cloud computing where we don’t have a lot of control of provisioning it makes it very difficult to get the right date saved.

I think it would be better for the Isomorphic database layer to control the time zone when they update the database. There are several ways to do this, but one way would be set the time zone in the JDBC connection. This can be done as a JDBC options:

useTimezone=true
serverTimezone=UTC

Here is an example of configuring Hibernate:

<bean id="hibernateAnalysisSessionFactory" class="org.springframework.orm.hibernate4.LocalSessionFactoryBean">
    <property name="hibernateProperties">
        <props>
            <!-- Connection parameters -->
            <prop key="hibernate.connection.driver_class">com.mysql.jdbc.Driver</prop>
            <prop key="hibernate.connection.url">jdbc:mysql://hostname/databaseName?useTimezone=true&amp;serverTimezone=UTC</prop>
            ...

This seems like a small change that would guarantee the correct date is stored in the database.

[Isomorphic]

Database timezone can be controlled in a lot of different ways - different databases offer per-column, per schema, per connection, etc, settings.

If you prefer to control the timezone via JDBC settings, that's great. The settings you are using for entirely from you and not SmartGWT, so you can put whatever you like there; we certainly don't think it would be a good idea for SmartGWT to include some non-default settings.