Invalid format is too short

[simao]

Hi,

When using joda time with slick-pg I get the following error when reading a record from the database:

Invalid format: "2015-10-16 15:56:04.041" is too short.

Is this a known problem? Seems the database is returning a string without the timezone.

In the database the record is stored as "2015-10-16 15:56:04.041+02"

Thank you

[onsails]

I have the same problem with LocalDateTime column (timestamp in Postgres)

[rockjam]

Same problem with LocalDateTime

[motns]

Out of curiosity, what version of Slick, slick-pg and Postgres JDBC are you guys using? I'm only asking because I had pretty much the same problem a while back when I upgraded my version of the JDBC driver from 9.4-1201-jdbc41 to 9.4-1203-jdbc42, while using Slick 3.0.1 and slick-pg 0.9.2. I didn't have time to fully investigate (I just rolled back to the older JDBC driver which fixed it), but from the limited time I spent debugging it, it seemed like that the actual JDBC driver itself was returning TIMESTAMP WITH TIMEZONE columns without the actual Time Zone at the end...

I haven't looked at this since, but I tried to reproduce it just now with Slick 3.1.0 and slick-pg 0.10.0, upgrading the Postgres driver to the latest version (9.4-1204-jdbc42), and I don't seem to get the error any more, so maybe whatever was causing it has been fixed.

[motns]

Scratch that - it does seem to be broken still. Everything works fine with Postgres driver version 9.4-1201-jdbc41, but using version 9.4-1202-* and above results in an error. Here's an example stack trace:

DateTimeParseException: Text '2015-07-24 16:14:13.0' could not be parsed at index 21
    at java.lang.Thread.run
    at java.util.concurrent.ThreadPoolExecutor$Worker.run
    at java.util.concurrent.ThreadPoolExecutor.runWorker
    at slick.backend.DatabaseComponent$DatabaseDef$$anon$2.run
    at slick.backend.DatabaseComponent$DatabaseDef$$anon$2.liftedTree1$1
    at slick.driver.JdbcActionComponent$QueryActionExtensionMethodsImpl$$anon$1.run
    at slick.driver.JdbcActionComponent$QueryActionExtensionMethodsImpl$$anon$1.run
    at slick.jdbc.StreamingInvokerAction$class.run
    at slick.jdbc.StatementInvoker.foreach
    at slick.jdbc.Invoker$class.foreach
    at slick.jdbc.PositionedResultIterator.foreach
    at scala.collection.Iterator$class.foreach
    at slick.jdbc.PositionedResultIterator.hasNext
    at slick.util.ReadAheadIterator$class.hasNext
    at slick.util.ReadAheadIterator$class.slick$util$ReadAheadIterator$$update
    at slick.jdbc.PositionedResultIterator.fetchNext
    at slick.jdbc.StatementInvoker$$anon$1.extractValue
    at slick.driver.JdbcInvokerComponent$QueryInvokerImpl.extractValue
    at slick.relational.TypeMappingResultConverter.read
    at slick.relational.ProductResultConverter.read
    at slick.relational.ProductResultConverter.read
    at slick.jdbc.SpecializedJdbcResultConverter$$anon$1.read
    at slick.jdbc.SpecializedJdbcResultConverter$$anon$1.read
    at com.github.tminglei.slickpg.utils.PgCommonJdbcTypes$GenericJdbcType.getValue
    at com.github.tminglei.slickpg.PgDate2Support$Date2DateTimeFormatters$$anonfun$fromInfinitable$1.apply
    at com.github.tminglei.slickpg.PgDate2Support$Date2DateTimeFormatters$$anonfun$fromInfinitable$1.apply
    at com.github.tminglei.slickpg.PgDate2Support$Date2DateTimeFormatters$$anonfun$4.apply
    at com.github.tminglei.slickpg.PgDate2Support$Date2DateTimeFormatters$$anonfun$4.apply
    at java.time.ZonedDateTime.parse
    at java.time.format.DateTimeFormatter.parse
    at java.time.format.DateTimeFormatter.parseResolved0

I had a quick look at the issues for the Postgres driver on GitHub (https://github.com/pgjdbc/pgjdbc) and didn't immediately see anything related, so maybe this is somehow expected behavior? I don't have much experience with using JDBC directly, so I can't tell...

@tminglei - what do you think?

[tminglei]

Hey guys, I just upgraded posgres driver to 9.4-1204 and did some adjustments. Changes' here. Yes, I encountered some problems, but it's not related to this issue.

I haven't reproduced the problem, maybe you guys can paste some reproducable codes?

---

I tried 9.4-1202-jdbc41, 9.4-1202-jdbc42, 9.4-1203-jdbc41, 9.4-1203-jdbc42, 9.4-1204-jdbc41 and 9.4-1204-jdbc42.

[simao]

Hi,

I will try to write a failing test during the weekend, see if I can isolate it.

Thanks

On 17 October 2015 11:44:48 CEST, "涂名雷" [email protected] wrote:

Hey guys, I just upgraded posgres driver to 9.4-1204. Changes' here. Yes, I encountered some problems, but it's not related to this issue.

I haven't reproduced the problem, maybe you guys can paste some usable codes?

---

Reply to this email directly or view it on GitHub: https://github.com/tminglei/slick-pg/issues/220#issuecomment-148899889

[simao]

Hi.

I could not isolate this in a standalone project but I managed to write a test on my project where this happens.

I have the following code:

val f = for {
  _ <- db.run(schema.vehicles += testVehicle)
  _ ← db.run(schema.vehicles.take(100).result)
  _ ← db.run(schema.vehicles.take(100).result)
  _ ← db.run(schema.vehicles.take(100).result)
  _ ← db.run(schema.vehicles.take(100).result)
  _ ← db.run(schema.vehicles.take(100).result)
  _ ← db.run(schema.vehicles.take(100).result)
} yield ()

whenReady(f) { _ =>

}

If I remove a single one of those db.run(...result) then the test will be green.

I don't do any special setup, just create some tables and this test runs alone, no other tests are running before/after/during.

This is really weird.

Thank you

[onsails]

@motns I have this error with both 9.4-1201-jdbc41 and 9.4-1202-*and above

[tminglei]

Can you guys provide reproduce codes? I can't reproduce it yet.

[joakim-ribier]

Hi,

I have the same error since the 0.10.1 release. The code is very simple, I try to fetch an user with a 'createdAt' field (TIMESTAMPTZ) in a Postgresql database. The first fetch is good, the "user.createdAt" equals to "2015-10-20 14:43:45.602+02" but the next, contains only the datetime without timezone "2015-10-20 14:43:45.602".

I have this code:

Schemas.users.filter(_.id === userInfo.userId).result.headOption

And the error:

java.lang.IllegalArgumentException: Invalid format: "2015-10-20 14:43:45.602" is too short at org.joda.time.format.DateTimeFormatter.parseDateTime(DateTimeFormatter.java:899) ~[joda-time-2.8.2.jar:2.8.2] at org.joda.time.DateTime.parse(DateTime.java:160) ~[joda-time-2.8.2.jar:2.8.2] at com.github.tminglei.slickpg.PgDateSupportJoda$JodaDateTimeImplicits$$anonfun$8.apply(PgDateSupportJoda.scala:40) ~[slick-pg_joda-time_2.11-0.10.1.jar:0.10.1] at com.github.tminglei.slickpg.PgDateSupportJoda$JodaDateTimeImplicits$$anonfun$8.apply(PgDateSupportJoda.scala:40) ~[slick-pg_joda-time_2.11-0.10.1.jar:0.10.1] at

Thanks a lot

[dvic]

For me, this occurs at random it seems (Postgres 9.4.5, 9.4-1204-jdbc41, slick-pg 0.10.1). I don't know if this is related to slick-pg, as it gets fed a date time that is too short (it's missing the date time offset part like mentioned previously). The weird thing is that when I just start my Play app, it works a couple of times, after that it stops working and I get each time the error described above. I'll see if I can get an app out there that demonstrates this problem.

[dvic]

I tried the following:

override def all: Future[Seq[User]] = {
  db.run(sql"select USERS.birth_date from USERS".as[(String)]).flatMap { birthdates =>
    println(birthdates)
    db.run(allUsers)
  }
}

When I get the error, the println statement outputs something like Vector(2015-10-29 22:56:02.719), does this mean that the problem is actually in slick itself?

[maxcom]

I see the same problem. slick-pg 0.10.0, postgresql driver 9.4-1203-jdbc42.

[tminglei]

In codes of slick-pg date2 support, it first get string from result set, then parse the string value to LocalDate/ZonedDateTime.

I debugged into postgres driver, and here's the related codes of getString(columnIndex):

    // in AbstractJdbc2ResultSet.java
    public String getString(int columnIndex) throws SQLException
    {
        checkResultSet( columnIndex );
        if (wasNullFlag)
            return null;

        // varchar in binary is same as text, other binary fields are converted to their text format
        if (isBinary(columnIndex) && getSQLType(columnIndex) != Types.VARCHAR) {
            Object obj = internalGetObject(columnIndex, fields[columnIndex - 1]);
            if (obj == null) {
                return null;
            }
            // hack to be compatible with text protocol
            if (obj instanceof java.util.Date) {
              return connection.getTimestampUtils().timeToString((java.util.Date) obj);
            }
            if ("hstore".equals(getPGType(columnIndex))) {
                return HStoreConverter.toString((Map) obj);
            }
            return trimString(columnIndex, obj.toString());
        }

        Encoding encoding = connection.getEncoding();
        try
        {
            return trimString(columnIndex, encoding.decode(this_row[columnIndex - 1]));
        }
        catch (IOException ioe)
        {
            throw new PSQLException(GT.tr("Invalid character data was found.  This is most likely caused by stored data containing characters that are invalid for the character set the database was created in.  The most common example of this is storing 8bit data in a SQL_ASCII database."), PSQLState.DATA_ERROR, ioe);
        }
    }

Note: for timestamptz, the return value of getSQLType(columnIndex) is Types.TIMESTAMP, and .

So if the column's format is binary, it will get into the if branch, call internalGetObject(columnIndex, fields[columnIndex - 1]) , and get a Timestamp object, then ... the zone info was discarded.

[tminglei]

But the column format is always text in my test cases. So I didn't reproduce it.

[dvic]

So you are able to reproduce it now? In my case the field is TIMESTAMP WITH TIME ZONE. I debugged in the PgCommonJdbcTypes$GenericJdbcType#getValue method, there the parsed string does not contain the offset. But it is still unclear to me why on server startup the field there does get parsed properly (i.e., with an offset).

[maxcom]

I have a REST endpoint that produces exactly the same SQL request on each call. Problem happens only when I repeat this call several times on busy server (apache benchmark is a good tool for it).

Single requests in non-busy development environment usually works fine.

[tminglei]

@damirv, I haven't reproduced it yet. I just found a possible cause.

[onsails]

I've got a bit more information:

In my project(slick 3.0.3, slick-pg 0.9.0, postgresql 9.4-1201-jdbc41) I used https://github.com/tototoshi/slick-joda-mapper for joda DateTime. After switching to slick-pg's implicits tests started to throw this error.

[tminglei]

@prettynatty, I can't still reproduce it, with your tips.

[onsails]

I still can't localize it to a small project.

[faustas]

Hello,

I can confirm, that this bug also occurs with ZonedDateTime and correct data sets in the Postgresql database.

We use: postgresql 9.4-1205-jdbc42, slick-pg 0.10.1, slick-pg_date 0.10.1, slick-pg_argonaut 0.10.1 and play-slick 1.1.1.

In the Postgresql table the following timestamp with time zone is stored: 2015-11-10 15:51:08.497+01

We get the following error:

2015-11-18 14:01:10,815 [error] a.a.OneForOneStrategy - Text '2015-11-10 15:51:08.497' could not be parsed at index 23
java.time.format.DateTimeParseException: Text '2015-11-10 15:51:08.497' could not be parsed at index 23
    at java.time.format.DateTimeFormatter.parseResolved0(DateTimeFormatter.java:1947) ~[na:1.8.0_45-internal]
    at java.time.format.DateTimeFormatter.parse(DateTimeFormatter.java:1849) ~[na:1.8.0_45-internal]
    at java.time.ZonedDateTime.parse(ZonedDateTime.java:597) ~[na:1.8.0_45-internal]
    at com.github.tminglei.slickpg.PgDate2Support$Date2DateTimeFormatters$$anonfun$4.apply(PgDate2Support.scala:78) ~[slick-pg_date2_2.11-0.10.1.jar:0.10.1]
    at com.github.tminglei.slickpg.PgDate2Support$Date2DateTimeFormatters$$anonfun$4.apply(PgDate2Support.scala:78) ~[slick-pg_date2_2.11-0.10.1.jar:0.10.1]

The time zone is not delivered to PgDate2Support for parsing the value as ZonedDateTime

Would it be a solution to set the system time zone, if no time zone is available?

We tested also with the following postgresql versions: 9.4-1205-jdbc42 - 9.4-1200-jdbc42

[tminglei]

@faustas, can you always reproduce it?

If yes, can you debug into AbstractJdbc2ResultSet.getString(int columnIndex)? I want to know whether isBinary(columnIndex) return true or false.

BTW, I can't reproduce it on my local.

[faustas]

Hello,

I debugged the application and can tell you the following.

Within AbstractJdbc2ResultSet.getString(int columnIndex), the isBinary(columnIndex) is true.

The following code Object obj = internalGetObject(columnIndex, fields[columnIndex - 1]); returns the Timestamp without the Timezone.

As far as I understand the problem:

• getTimestamp within internalGetObject already calculates the Timezone into the return value. Therefore, the time string does not need the Timezone anymore.

The final problem is the type conversion into ZonedDateTime which expects a Timezone at the parsed string.

The Postgresql guys seem to have some problems in returning Timestamp with / without timezone correctly. See:

• https://github.com/pgjdbc/pgjdbc/issues/373
• https://github.com/pgjdbc/pgjdbc/issues/304

It would be great, if slick-pg could provide a workaround and select the values correctly.

[tminglei]

Thanks @faustas, you confirmed my guess!

But I haven't a good solution to resolve it yet.

[jan0sch]

@tminglei Would it be possible to change the fetching logic for timestamp related values? I'm thinking in the direction of pulling them out as formatted datetime strings and parsing them afterwards. So far writing these values seems to work, therefore it should suffice to change the "read logic".

I currently have no idea how to implement that and I know that this is a "hack" but it would maybe provide a useable workaround as long as the postgresql guys haven't fixed that.

[tminglei]

@jan0sch, this is what I did in slick-pg.

But the returned value true of isBinary(columnIndex) in AbstractJdbc2ResultSet.getString(int columnIndex) caused pgjdbc to run into a code branch, where it read a timestamp object, then covert it to string, and time zone info was lost in the process.

See the AbstractJdbc2ResultSet.getString(int columnIndex) codes from above comments of mine.

---

So, as pgjdbc/pgjdbc#373 and pgjdbc/pgjdbc#304 pointed out, the root cause is postgres sent back binary (float or long) w/o time zone instead time string to jdbc driver.

[jan0sch]

Ah, okay. So the problem is that the column is a binary one. Which means we would have to wait for a fix from the postgresql side or store timstamp values as strings and that would be rather ugly. :-(

[jan0sch]

This is just a quickshot but would something like this maybe provide a workaround until this is officially fixed?

diff --git a/org/postgresql/jdbc2/AbstractJdbc2ResultSet.java b/org/postgresql/jdbc2/AbstractJdbc2ResultS
index 64d949f..efbc370 100644
--- a/org/postgresql/jdbc2/AbstractJdbc2ResultSet.java
+++ b/org/postgresql/jdbc2/AbstractJdbc2ResultSet.java
@@ -2986,7 +2986,14 @@ public abstract class AbstractJdbc2ResultSet implements BaseResultSet, org.postg
      * @return True if the column is in binary format.
      */
     protected boolean isBinary(int column) {
-        return fields[column - 1].getFormat() == Field.BINARY_FORMAT;
+        Field f = fields[column - 1];
+        if (f.getPGType().equalsIgnoreCase("timestamptz") || f.getPGType().equalsIgnoreCase("timetz")) {
+            // Prevent binary treating of fields with timezone.
+            return false;
+        }
+        else {
+            return fields[column - 1].getFormat() == Field.BINARY_FORMAT;
+        }
     }

     //----------------- Formatting Methods -------------------

[jan0sch]

I've just realised that the problem roots far deeper. Forget that workaround. ;-)