Error after upgrading to jdbc-mysql 8.0: ActiveRecord::JDBCError: HOUR_OF_DAY: 2 -> 3

[mohamedhafez]

I'm getting the following error after upgrading from jdbc-mysql from the 5.1.* series to 8.0.20: ActiveRecord::JDBCError: HOUR_OF_DAY: 2 -> 3

It looks like its due to upgrading Connector/J from the 5.1 series to the 8.0 series. It seems like someone reported the the bug to the Connector/J bug tracker here, and that it was marked as a possible duplicate of this bug that was resolved in Connector/J 8.0.22.

Currently, jdbc-mysql is using Connector/J 8.0.20, could we get an update to the latest version in the hopes of getting a fix to this bug?

Here's the stack trace I'm getting btw:

arjdbc/jdbc/RubyJdbcConnection.java:1082:in `execute_query'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activerecord-jdbc-adapter-61.1-java/lib/arjdbc/abstract/database_statements.rb:44:in `block in exec_query'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activerecord-6.1.4/lib/active_record/connection_adapters/abstract_adapter.rb:696:in `block in log'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activesupport-6.1.4/lib/active_support/concurrency/load_interlock_aware_monitor.rb:26:in `block in synchronize'
        org/jruby/RubyThread.java:759:in `handle_interrupt'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activesupport-6.1.4/lib/active_support/concurrency/load_interlock_aware_monitor.rb:25:in `block in synchronize'
        org/jruby/RubyThread.java:759:in `handle_interrupt'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activesupport-6.1.4/lib/active_support/concurrency/load_interlock_aware_monitor.rb:21:in `synchronize'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activerecord-6.1.4/lib/active_record/connection_adapters/abstract_adapter.rb:695:in `block in log'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activesupport-6.1.4/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activerecord-6.1.4/lib/active_record/connection_adapters/abstract_adapter.rb:687:in `log'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activerecord-jdbc-adapter-61.1-java/lib/arjdbc/abstract/core.rb:73:in `log'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activerecord-jdbc-adapter-61.1-java/lib/arjdbc/abstract/database_statements.rb:44:in `exec_query'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activerecord-6.1.4/lib/active_record/connection_adapters/abstract/database_statements.rb:532:in `select'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activerecord-6.1.4/lib/active_record/connection_adapters/abstract/database_statements.rb:69:in `select_all'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activerecord-6.1.4/lib/active_record/connection_adapters/abstract/query_cache.rb:103:in `select_all'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activerecord-jdbc-adapter-61.1-java/lib/arjdbc/abstract/database_statements.rb:86:in `select_all'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activerecord-6.1.4/lib/active_record/querying.rb:47:in `find_by_sql'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activerecord-6.1.4/lib/active_record/relation.rb:843:in `block in exec_queries'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activerecord-6.1.4/lib/active_record/relation.rb:861:in `skip_query_cache_if_necessary'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activerecord-6.1.4/lib/active_record/relation.rb:828:in `exec_queries'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activerecord-6.1.4/lib/active_record/relation.rb:631:in `load'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activerecord-6.1.4/lib/active_record/relation.rb:249:in `records'
        /var/www/vhosts/myapp/shared/bundle/jruby/2.5.0/gems/activerecord-6.1.4/lib/active_record/relation/delegation.rb:88:in `each'
        /var/www/vhosts/myapp/releases/20210805091448/app/models/account.rb:817:in `customer_stats_str'

[mohamedhafez]

Just a little bump on this, it seems like some relevant fixes were made in Connector/J 8.0.22 and especially 8.0.23:

in 8.0.23:

After upgrading from Connector/J 5.1 to 8.0, the results of saving and then retrieving DATETIME and TIMESTAMP values became different sometimes. It was because while Connector/J 5.1 does not preserve a time instant by default, Connector/J 8.0.22 and earlier tried to do so by converting a timestamp to the server's session time zone before sending its value to the server. In this release, new mechanisms for controlling timezone conversion has been introduced—see Preserving Time Instants for details. Under this new mechanism, the default behavior of Connector/J 5.1 in this respect is preserved by setting the connection property preserveInstants=false. (Bug #30962953, Bug #98695, Bug #30573281, Bug #95644)

in 8.0.22:

LocalDate, LocalDateTime, and LocalTime values set through Connector/J were altered when there was a timezone difference between the server and the client. This fix corrects the issue by handling the LocalDate, LocalTime, and LocalDateTime with no time zone conversion and no intermediate conversions to other date-time classes. Thanks to Iwao Abe for his contribution to the fix. (Bug #29015453, Bug #93444)

[mohamedhafez]

(Note: i made some edits to the title of the bug and the original description of the bug to reflect that this error has nothing to do with going from activerecord-jdbcmysql-adapter 60.0 to 60.1, 60.1 works just fine if you make it use jdbc-mysql 5.1.49. Its only when when we upgrade jdbc-mysql from 5.1.* to 8.0.17 or 8.0.20 that I see the issue)

[mohamedhafez]

I just tested out with jdbc-mysql 8.0.27, and unfortunately the issue persists. I tried setting preserveInstants: false as per the Connector/J 8.0.23 release notes instructions to keep the Connector/J 5.1 behavior, but no luck. Perhaps part of the issue is that I've been setting serverTimezone: "America/Los_Angeles" as per https://github.com/jruby/activerecord-jdbc-adapter#mysql-specific-notes? I'm stumped. I understand that in general asking for database setup help here is inappropriate, but considering that the behavior here is very different than MRI, some help would very much be appreciated @headius, @enebo, or @kares!

[kares]

seems like a Connector/J bug to me - AR-JDBC uses roughly the same JDBC code when retrieving timestamps.
we did the 8.x driver update as requested as the issue persist I recommend staying on 5.1.

there seems to be no capacity atm to look into driver specific issue esp. since the existing code works with the old one as well as MariaDB driver. happy to review PRs though, should not be hard to detetc the 8.0 driver being used.

the bug report is useful - thanks for that, any chance we'll get an isolated (AR) reproducer? (including your time-zone info)

[mohamedhafez]

Ok found an example of where this is happening!

Time Zone info:
I'm running my MySQL 8.0.27 on AWS's RDS service, so the timezone data has been correctly loaded into MySQL by default, and all the time zone variables were left at their AWS default settings of UTC (system_time_zone, time_zone, etc). I've been connecting with serverTimezone: "America/Los_Angeles" in my database.yml, as per https://github.com/jruby/activerecord-jdbc-adapter#mysql-specific-notes. In my Rails application.rb, I have config.time_zone = 'America/Los_Angeles', and my Linux machine is also set to have a time zone of 'America/Los_Angeles' (Java seems to automatically pick this up, Java::JavaUtil::TimeZone.getDefault returns 'America/Los_Angeles'`

---

When I just connect to mysql via the command line (with the session time_zone going to the default of UTC), I get the following result for this given row:

mysql> SELECT created_at FROM accounts WHERE id = 1996;
+---------------------+
| created_at          |
+---------------------+
| 2013-03-10 02:21:54 |
+---------------------+

---

With jdbc-mysql 5.1.49, I get the following:

>> Account.where(id: 1996).pluck(:created_at)
=> [Sat, 09 Mar 2013 19:21:54.000000000 PST -08:00]

NOTE THAT THIS IS INCORRECT!! Time.parse("2013-03-10 02:21:54 UTC").in_time_zone('America/Los_Angeles') is actually Sat, 09 Mar 2013 18:21:54.000000000 PST -08:00

---

With jdbc-mysql 8.0.27, I get the following error:

>> Account.where(id: 1996).pluck(:created_at)
Traceback (most recent call last):
        1: from (irb):12:in `evaluate'
ActiveRecord::StatementInvalid (ActiveRecord::JDBCError: HOUR_OF_DAY: 2 -> 3)

On March 10, 2013 at 2am, America/Los_Angeles was supposed to spring forward to 3am. That's the "HOUR_OF_DAY: 2 -> 3" error. It seems like it is trying to interpret that UTC time stamp as being an America/Los_Angeles timestamp for some reason, and complaining that its an invalid time since there should be no times between 2:00am and 2:59am on that day in that timezone.

Doing ActiveRecord::Base.connection.execute("SELECT @@SESSION.time_zone;").to_a showed that the session timezone was still UTC, so I added forceConnectionTimeZoneToSession: true to database.yml (which essentially executes the mysql statement set time_zone = <whatever serverTimezone/connectionTimeZone is>), and verified that ActiveRecord::Base.connection.execute("SELECT @@SESSION.time_zone;").to_a did indeed now report America/Los_Angeles, but I got the exact same error when doing Account.where(id: 1996).pluck(:created_at)

---

As per the suggestion in #897 (comment), I also tried setting time_zone = 'America/Los_Angeles' globally, and removed the serverTimezone variable from my database.yml, but got the exact same results as above: jdbc-mysql 5.1.49 is off by an hour, and jdbc-mysql 8.0.27 returns the same error

[mohamedhafez]

If I start jruby with -J-Duser.timezone=UTC, and have default_time_zone=UTC in my mysqld config, basically turning off all of Connector/J and mysql's time zone conversion magic, then everything works perfectly with both jdbc-mysql 5.1.49 and 8.0.27

Perhaps there is a more elegant way of doing that that won't affect other parts of JRuby? Since there are issues with both jdbc-mysql 5.1.49 and 8.0.27 I'm hoping it merits a fix...

[jbaiza]

We at eazyBI faced a similar error and, in the end, created our fork to fix it by catching the exception. I made a new PR with our solution - #1160.

Here are my findings about possible solutions after more investigation and conversation with @headius:

• The current solution will fail with the HOUR_OF_DAY: 3 -> 4 error with the following time (assuming that the local time is Europe/Prague) - "2024-03-31 03:00:01".
• I tried to implement a similar timestampToRuby method as in the PostgreSQLRubyJdbcConnection (https://github.com/jruby/activerecord-jdbc-adapter/blob/master/src/java/arjdbc/postgresql/PostgreSQLRubyJdbcConnection.java#L920) using DateTimeUtils.parseDateTime. But that implementation failed wor time "2024-03-31 02:00:01" with the following error when ActiveRecord.default_timezone is set to :local - "Illegal instant due to time zone offset transition (daylight savings time 'gap'): 2024-03-31T02:00:01.000 (Europe/Prague)"

With the patched AR JDBC JAR file, I compared results with the C Ruby in a sample test app, and they matched:

• ActiveRecord.default_timezone=:utc

Time	Returned value MRI	Returned value JRuby
2024-03-31 00:00:01	Sun, 31 Mar 2024 01:00:01.000000000 CET +01:00	Sun, 31 Mar 2024 01:00:01.000000000 CET +01:00
2024-03-31 01:00:01	Sun, 31 Mar 2024 03:00:01.000000000 CEST +02:00	Sun, 31 Mar 2024 03:00:01.000000000 CEST +02:00
2024-03-31 02:00:01	Sun, 31 Mar 2024 04:00:01.000000000 CEST +02:00	Sun, 31 Mar 2024 04:00:01.000000000 CEST +02:00
2024-03-31 03:00:01	Sun, 31 Mar 2024 05:00:01.000000000 CEST +02:00	Sun, 31 Mar 2024 05:00:01.000000000 CEST +02:00

• ActiveRecord.default_timezone=:local

Time	Returned value MRI	Returned value JRuby
2024-03-31 00:00:01	Sun, 31 Mar 2024 00:00:01.000000000 CET +01:00	Sun, 31 Mar 2024 00:00:01.000000000 CET +01:00
2024-03-31 01:00:01	Sun, 31 Mar 2024 01:00:01.000000000 CET +01:00	Sun, 31 Mar 2024 01:00:01.000000000 CET +01:00
2024-03-31 02:00:01	Sun, 31 Mar 2024 03:00:01.000000000 CEST +02:00	Sun, 31 Mar 2024 03:00:01.000000000 CEST +02:00
2024-03-31 03:00:01	Sun, 31 Mar 2024 03:00:01.000000000 CEST +02:00	Sun, 31 Mar 2024 03:00:01.000000000 CEST +02:00

From the PR test results, I see that not only is the time zone set in the code important, but the environment time zone is also taken into account.
My tests were conducted using the "Europe/Riga" time zone.
When I run the tests using TZ="Europe/Prague", the error is "HOUR_OF_DAY: 2 -> 3" and occurs at "2024-03-31 02:00:01", not 3 AM. There is no MySQL HOUR_OF_DAY error with TZ="UTC".

[headius]

There's lots of posts online asking about this same issue, some with suggested fixes such as:

• https://stackoverflow.com/questions/58025438/error-sqlexceptionhelper-hour-of-day-2-3

Suggested fixes here include fixing data in the database (the time entered is not valid and so should be fixed), configuring the connection for UTC, and setting the server timezone to UTC. @mohamedhafez suggested a similar workaround in #1091 (comment).

I'm guessing that in @jbaiza's case we may be talking about databases we do not control, such as those set up by users of EazyBI? That certainly limits our options.

• https://confluence.atlassian.com/jirakb/jira-throws-hour_of_day-2-3-exception-with-mysql-1306297291.html

This one also suggests bulk scrubbing the data using a stored procedure that adjusts all datetime fields.

The fix in #1160 is not terrible but obviously it would be nice to avoid the error altogether. I'm wondering if that's really possible though.

@jbaiza A few more questions for you (and @mohamedhafez if you have some input):

• Would you agree with the posts saying that this is basically bad data? If so how are these invalid timestamps getting into the database in the first place?
• Do any of the other workarounds in the posts above and others online fix the problem? Am I right in thinking you can't use them because you don't always control the database server?

I don't know what the right answer is here but getting a not-great fix in place for now would seem better than leaving it broken until we have a perfect solution (which may not exist if this is indeed bad data).

[jbaiza]

@headius, I can imagine two cases when the error could occur in eazyBI, and in both cases, the data stored in the database are valid:

• In some cases, we need to store times both in the local time zone and in UTC. Data inserts/updates are performed using direct SQLs, so there are no issues with time zone conversions, UTC time will be stored as is. However, data reads using AR JDBC could face an error. For this case, we think storing the Unix timestamp instead of the datetime would be better to avoid the error.
• As you mentioned, we don't control servers (both database and application) when eazyBI is installed on-premise. The instance could be used globally with users in different time zones. Users from various countries could select data to be prepared (stored in the database for reporting) in their time zone. So, in one database, datetime values could be stored in different actual time zones. And, with a slight possibility, a valid datetime value in one zone may fall into the missing DST hour in the database time zone.