DynamicTableEntity Timestamp property parsing gives wrong date

[rjha]

Environment
Java SDK 1.7
Azure Java sdk 0.4.4

To reproduce

1. insert an entity using a partition key and row key and use the following code to read back the Timestamp property of the Entity

private static void do_query() throws Exception {

        String partitionKey = "tsdb;64922243-22e9-4b00-8a8d-83c532a1d38b;datapoint" ;
        String rowKey = "9223370653970047780" ;
        CloudTableClient client = Table.getInstance();

        System.out.println("*** using query *** ");
        String where_condition = String.format("(PartitionKey eq '%s') and (RowKey eq '%s')",partitionKey, rowKey);
        TableQuery<DynamicTableEntity> query = TableQuery
                .from("test", DynamicTableEntity.class)
                .where(where_condition).take(1);

        Iterator<DynamicTableEntity> rows = client.execute(query).iterator();
        EntityProperty ep;

        while (rows.hasNext()) {
            DynamicTableEntity row = rows.next();
            HashMap<String, EntityProperty> map = row.getProperties();

            for (String key : map.keySet()) {
                ep = map.get(key);
                System.out.println("key=" + key + ", value= " + ep.getValueAsString());
                System.out.println("server timestamp= " + row.getTimestamp());
                System.out.println("server ETag= " + row.getEtag());
            }
        }
    }

2. The entity was inserted at 14:38 (approx.) as verified by ETag, however this code returns different values for ETag and Timestamp

server timestamp= Sun Oct 27 21:24:57 IST 2013
server ETag= W/"datetime'2013-10-27T14%3A38%3A48.4569602Z'"
You can see how the timestamp is different from server ETag

3. Wire capture shows that Azure Table service is returning correct timestamp (14:38 GMT or 20:08 IST) but we get 21:24 in Java layer some-where. Since the client program is not doing any date manipulation, it could be a problem in Azure SDK Atom feed date parsing.

4. Actual wire capture

we do a wire capture using tcpflow tool.
$sudo tcpflow -c -e -i eth0

we can see one request and one response. The timestamp returned from the server appears fine.

172.016.135.176.48122-168.062.001.144.00080: GET /test?$filter=%28PartitionKey%20eq%20%27tsdb%3B64922243-22e9-4b00-8a8d-83c532a1d38b%3Bdatapoint%27%29%20and%20%28RowKey%20eq%20%279223370653970047780%27%29&$top=1&timeout=60 HTTP/1.1                                                                        
x-ms-version: 2012-02-12                                                                             
User-Agent: WA-Storage/Client v0.1.3.2                                                               
Content-Type: application/atom+xml                                                                   
Accept: application/atom+xml,application/xml                                                         
Accept-Charset: UTF-8                                                                                
MaxDataServiceVersion: 2.0;NetFx                                                                     
x-ms-date: Sun, 27 Oct 2013 15:14:20 GMT                                                             
Authorization: SharedKey  ***deleted****
Host: sensordb.table.core.windows.net                                                                
Connection: keep-alive                                                                               


168.062.001.144.00080-172.016.135.176.48122: HTTP/1.1 200 OK
Cache-Control: no-cache                                                                              
Transfer-Encoding: chunked                                                                           
Content-Type: application/atom+xml;charset=utf-8                                                     
Server: Windows-Azure-Table/1.0 Microsoft-HTTPAPI/2.0                                                
x-ms-request-id: 5e30f814-ef33-4ec2-9a01-5a9f2136f70d                                                
x-ms-version: 2012-02-12                                                                             
Date: Sun, 27 Oct 2013 15:14:21 GMT 


<?xml version="1.0" encoding="utf-8" standalone="yes"?>                                              
<feed xml:base="http://sensordb.table.core.windows.net/" xmlns:d="http://schemas.microsoft.com/ado/2007/08/dataservices" xmlns:m="http://schemas.microsoft.com/ado/2007/08/dataservices/metadata" xmlns="http://www.w3.org/2005/Atom">                                                                         
  <title type="text">test</title>                                                                    
  <id>http://sensordb.table.core.windows.net/test</id>                                               
  <updated>2013-10-27T15:14:21Z</updated>                                                            
  <link rel="self" title="test" href="test" />                                                       
  <entry m:etag="W/&quot;datetime'2013-10-27T14%3A38%3A48.4569602Z'&quot;">
    <id>http://sensordb.table.core.windows.net/test(PartitionKey='tsdb%3B64922243-22e9-4b00-8a8d-83c532a1d38b%3Bdatapoint',RowKey='9223370653970047780')</id>
    <title type="text"></title>
    <updated>2013-10-27T15:14:21Z</updated>
    <author>
      <name />
    </author>
    <link rel="edit" title="test" href="test(PartitionKey='tsdb%3B64922243-22e9-4b00-8a8d-83c532a1d38b%3Bdatapoint',RowKey='9223370653970047780')" />
    <category term="sensordb.test" scheme="http://schemas.microsoft.com/ado/2007/08/dataservices/scheme" />
    <content type="application/xml">
      <m:pro
168.062.001.144.00080-172.016.135.176.48122: perties>
        <d:PartitionKey>tsdb;64922243-22e9-4b00-8a8d-83c532a1d38b;datapoint</d:PartitionKey>
        <d:RowKey>9223370653970047780</d:RowKey>
        <d:Timestamp m:type="Edm.DateTime">2013-10-27T14:38:48.4569602Z</d:Timestamp>
        <d:readings>[{"name":"temperature","value":"31","timestamp":"1382884724","type":"NUMBER"},{"name":"humidity","value":"51","timestamp":"1382884724","type":"NUMBER"},{"name":"ldr","value":"501","timestamp":"1382884724","type":"NUMBER"}]</d:readings>
      </m:properties>
    </content>
  </entry>
</feed>

5. The bare bones iso8601DateConverter however returns the correct date so more debugging is needed.

                 // AtomReaderWriter
        // EdmValueConverter is used to deserialize the date time string
        //  Object value = edmValueConverter.deserialize(edmType,      serializedValue);
        // result.put(name, new Property().setEdmType(edmType).setValue(value));
        // DefaultEdmValueConverter 
        // for DateTime
        // return iso8601DateConverter.parse(value);
        // ISO8601DateConverter
        // 
        String strDate = "2013-10-27T14:38:48.4569602Z" ;
        ISO8601DateConverter dateConverter = new ISO8601DateConverter();
        java.util.Date d1 = dateConverter.parse(strDate);
        System.out.println(d1) ;

Output is
Sun Oct 27 20:08:48 IST 2013

[aksh3ll]

Simply because TableQuery don't use it.
It uses the function com.microsoft.windowsazure.services.core.storage.utils.Utility.parseDate
which use the basic function : SimpleDateFormat with this pattern : "yyyy-MM-dd'T'HH:mm:ss.SSSSSSS'Z'"
which don't cares much about format, and so 4569602 become 4569602 ms aka 1h 16m 15s 602ms.
which are added to the date.
See
http://stackoverflow.com/questions/7159895/simpledateformat-is-not-parsing-the-milliseconds-correctly

[rjha]

Hi @aksh3ll

1. so first to confirm - the issue I reported exists and you can reproduce it, right?
2. if you have done the research, can you please share the relevant code path that is causing the issue?
3. Do you have a pull request with the fix? Otherwise I can create one and send it to repo maintainer.

Thanks

[aksh3ll]

Hi, @rjha

1. yes, and i use the last version 0.4.6, you can easily reproduce it with a simple TableOperation.retrieve()
2. not completely,
   all tableOperation result Timestamp are parsed in
   com.microsoft.windowsazure.services.table.client.AtomPubParser.parseEntity()
   which call
   com.microsoft.windowsazure.services.table.client.TableEntity.getValueAsDate()
   which call
   com.microsoft.windowsazure.services.core.storage.utils.Utility.parseDate()
   and line 1071, you have :
   return Utility.parseDateFromString(dateString, Utility.ISO8061_LONG_PATTERN, Utility.UTC_ZONE);
   you can replace it by :
   return new ISO8601DateConverter().parse(value);
   it probably needs to add import com.microsoft.windowsazure.services.core.ISO8601DateConverter;

but all the others call in this function are probably as bad, and may be all replaced directly in com.microsoft.windowsazure.services.table.client.TableEntity.getValueAsDate(). and this function completely scrapped.
it needs a lot more exploration, and tests.
3) no, i'm at work and git port is blocked...
i will try tonight if you don't, i've never done it before, so it may take some time.

[markcowl]

@rjha closing asn obsolete. If this is still an issue, please re-open