# Rufus-scheduler error: TZInfo::PeriodNotFound

**URL:** https://discuss.elastic.co/t/rufus-scheduler-error-tzinfo-periodnotfound/278811
**Category:** Logstash
**Created:** [July 15, 2021, 2:53pm UTC](https://discuss.elastic.co/t/rufus-scheduler-error-tzinfo-periodnotfound/278811 "2021-07-15T14:53:18Z")
**Posts on this page:** 5
**Page:** 1

<div class="post-metadata">

### Author: ![chris\_ts24](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/chris_ts24/32/79048_2.png) [@chris\_ts24](https://discuss.elastic.co/u/chris_ts24)
#### Post date: [July 15, 2021, 2:53pm UTC](https://discuss.elastic.co/t/rufus-scheduler-error-tzinfo-periodnotfound/278811/1 "2021-07-15T14:53:18Z")

</div>

Hi all,

I recently posted a [question](https://discuss.elastic.co/t/jdbc-timestamp-doesnt-refresh-leads-to-large-queues/278393/4) about my logstash pipeline at some point (seemingly) randomly not updating the jdbc metadata for sql\_last\_value substitution. For completeness, I'll include the input plugin of my configuration here. As output to ES is not the problem, I won't include the output or filtering here, but are available in the above link.

```auto
input {
        jdbc {
                jdbc_driver_class => "Java::oracle.jdbc.driver.OracleDriver"
                jdbc_driver_library => "/usr/local/bin/ojdbc8.jar"
                jdbc_connection_string => "jdbc:oracle:thin:@<connectionstring>"
                jdbc_default_timezone => "Europe/Berlin"
                jdbc_user => "user"
                jdbc_password => "pass"
                statement_filepath => "/path/to/update.sql"
                schedule => "* * * * *"
                last_run_metadata_path => "/path/to/.logstash_jdbc_update"
     }
}

```

I've since dug into the logs and found something of use, the following error. Note the timestamps:

```auto
Jul 15 02:24:11 <user> logstash[840964]: { 11402 rufus-scheduler intercepted an error:
Jul 15 02:24:11 <user> logstash[840964]: 11402 job:
Jul 15 02:24:11 <user> logstash[840964]: 11402 Rufus::Scheduler::CronJob "* * * * *" {}
Jul 15 02:24:11 <user> logstash[840964]: 11402 error:
Jul 15 02:24:11 <user> logstash[840964]: 11402 11402
Jul 15 02:24:11 <user> logstash[840964]: 11402 Sequel::InvalidValue
Jul 15 02:24:11 <user> logstash[840964]: 11402 TZInfo::PeriodNotFound: 2022-03-27 02:27:00 is an invalid local time.
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/tzinfo-2.0.4/lib/tzinfo/timezone.rb:500:in `period_for_local'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/sequel-5.44.0/lib/sequel/extensions/named_timezones.rb:115:in `convert_input_datetime_other'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/sequel-5.44.0/lib/sequel/timezones.rb:136:in `convert_input_datetime_no_offset'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/sequel-5.44.0/lib/sequel/timezones.rb:185:in `convert_input_timestamp'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/sequel-5.44.0/lib/sequel/timezones.rb:94:in `convert_timestamp'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/sequel-5.44.0/lib/sequel/database/misc.rb:306:in `to_application_timestamp'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/sequel-5.44.0/lib/sequel/adapters/jdbc.rb:715:in `timestamp_convert'
Jul 15 02:24:11 <user> logstash[840964]: 11402 org/jruby/RubyMethod.java:123:in `call'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/sequel-5.44.0/lib/sequel/adapters/jdbc.rb:825:in `process_result_set'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/sequel-5.44.0/lib/sequel/adapters/jdbc.rb:755:in `block in fetch_rows'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/sequel-5.44.0/lib/sequel/adapters/jdbc.rb:268:in `block in execute'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/sequel-5.44.0/lib/sequel/adapters/jdbc.rb:704:in `statement'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/sequel-5.44.0/lib/sequel/adapters/jdbc.rb:263:in `block in execute'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/sequel-5.44.0/lib/sequel/connection_pool/threaded.rb:92:in `hold'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/sequel-5.44.0/lib/sequel/database/connecting.rb:269:in `synchronize'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/sequel-5.44.0/lib/sequel/adapters/jdbc.rb:262:in `execute'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/sequel-5.44.0/lib/sequel/dataset/actions.rb:1093:in `execute'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/sequel-5.44.0/lib/sequel/adapters/jdbc.rb:755:in `fetch_rows'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/sequel-5.44.0/lib/sequel/dataset/actions.rb:152:in `each'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-integration-jdbc-5.0.7/lib/logstash/plugin_mixins/jdbc/statement_handler.rb:41:in `perform_query'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-integration-jdbc-5.0.7/lib/logstash/plugin_mixins/jdbc/jdbc.rb:217:in `execute_statement'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-integration-jdbc-5.0.7/lib/logstash/inputs/jdbc.rb:316:in `execute_query'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-integration-jdbc-5.0.7/lib/logstash/inputs/jdbc.rb:279:in `block in run'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/rufus-scheduler-3.0.9/lib/rufus/scheduler/jobs.rb:234:in `do_call'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/rufus-scheduler-3.0.9/lib/rufus/scheduler/jobs.rb:258:in `do_trigger'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/rufus-scheduler-3.0.9/lib/rufus/scheduler/jobs.rb:300:in `block in start_work_thread'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/rufus-scheduler-3.0.9/lib/rufus/scheduler/jobs.rb:299:in `block in start_work_thread'
Jul 15 02:24:11 <user> logstash[840964]: 11402 org/jruby/RubyKernel.java:1442:in `loop'
Jul 15 02:24:11 <user> logstash[840964]: 11402 /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/rufus-scheduler-3.0.9/lib/rufus/scheduler/jobs.rb:289:in `block in start_work_thread'
Jul 15 02:24:11 <user> logstash[840964]: 11402 tz:
Jul 15 02:24:11 <user> logstash[840964]: 11402 ENV['TZ']:
Jul 15 02:24:11 <user> logstash[840964]: 11402 Time.now: 2021-07-15 00:24:11 +0000
Jul 15 02:24:11 <user> logstash[840964]: 11402 scheduler:
Jul 15 02:24:11 <user> logstash[840964]: 11402 object_id: 2058
Jul 15 02:24:11 <user> logstash[840964]: 11402 opts:
Jul 15 02:24:11 <user> logstash[840964]: 11402 {:max_work_threads=>1}
Jul 15 02:24:11 <user> logstash[840964]: 11402 frequency: 0.3
Jul 15 02:24:11 <user> logstash[840964]: 11402 scheduler_lock: #<Rufus::Scheduler::NullLock:0x4924933b>
Jul 15 02:24:11 <user> logstash[840964]: 11402 trigger_lock: #<Rufus::Scheduler::NullLock:0x617e4ace>
Jul 15 02:24:11 <user> logstash[840964]: 11402 uptime: 140203.227072 (1d14h56m43s227)
Jul 15 02:24:11 <user> logstash[840964]: 11402 down?: false
Jul 15 02:24:11 <user> logstash[840964]: 11402 threads: 2
Jul 15 02:24:11 <user> logstash[840964]: 11402 thread: #<Thread:0x34182421>
Jul 15 02:24:11 <user> logstash[840964]: 11402 thread_key: rufus_scheduler_2058
Jul 15 02:24:11 <user> logstash[840964]: 11402 work_threads: 1
Jul 15 02:24:11 <user> logstash[840964]: 11402 active: 1
Jul 15 02:24:11 <user> logstash[840964]: 11402 vacant: 0
Jul 15 02:24:11 <user> logstash[840964]: 11402 max_work_threads: 1
Jul 15 02:24:11 <user> logstash[840964]: 11402 mutexes: {}
Jul 15 02:24:11 <user> logstash[840964]: 11402 jobs: 1
Jul 15 02:24:11 <user> logstash[840964]: 11402 at_jobs: 0
Jul 15 02:24:11 <user> logstash[840964]: 11402 in_jobs: 0
Jul 15 02:24:11 <user> logstash[840964]: 11402 every_jobs: 0
Jul 15 02:24:11 <user> logstash[840964]: 11402 interval_jobs: 0
Jul 15 02:24:11 <user> logstash[840964]: 11402 cron_jobs: 1
Jul 15 02:24:11 <user> logstash[840964]: 11402 running_jobs: 1
Jul 15 02:24:11 <user> logstash[840964]: 11402 work_queue: 0
Jul 15 02:24:11 <user> logstash[840964]: } 11402 .

```

When I look my record of generated JDBC timestamps that Logstash creates, I see:

```auto
[Date / Time Created] --- !ruby/object:DateTime 'GENERATED TIMESTAMP'
2021-07-15 02:23:01 --- !ruby/object:DateTime '2021-07-15 00:21:54.000000000 Z'
2021-07-15 02:24:01 --- !ruby/object:DateTime '2021-07-15 00:22:56.000000000 Z'
2021-07-15 02:25:01 --- !ruby/object:DateTime '2021-07-15 00:22:56.000000000 Z'
2021-07-15 02:26:01 --- !ruby/object:DateTime '2021-07-15 00:22:56.000000000 Z'
... 
2021-07-15 16:32:01 --- !ruby/object:DateTime '2021-07-15 00:22:56.000000000 Z'

```

Where --- !ruby/object:DateTime 'GENERATED TIMESTAMP' is contained within "/path/to/.logstash\_jdbc\_update".

So in the same pipeline cycle the scheduler throws this error, the pipeline fails to schedule the next cycle. Coincidence? I think not. However, this part of the rufus scheduler error really throws me off.

> TZInfo::PeriodNotFound: 2022-03-27 02:27:00 is an invalid local time.

Where is the scheduler getting this timestamp from? Has anyone any experience with this?

Any help / direction is greatly appreciated!

---

<div class="post-metadata">

### Author: ![Badger](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/badger/32/25190_2.png) [@Badger](https://discuss.elastic.co/u/Badger)
#### Post date: [July 15, 2021, 3:58pm UTC](https://discuss.elastic.co/t/rufus-scheduler-error-tzinfo-periodnotfound/278811/2 "2021-07-15T15:58:13Z")

</div>

> [@chris\_ts24](#):
>
> TZInfo::PeriodNotFound: 2022-03-27 02:27:00 is an invalid local time.

I cannot say why the scheduler is generating that time, but the reason it is invalid is probably that your server is in a location (e.g. Albania, or Denmark) where daylight savings time starts at 02:00 on 2022/3/27, and 02:00:00 is immediately followed by 03:00:01. 02:27:00 does not happen.

---

<div class="post-metadata">

### Author: ![chris\_ts24](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/chris_ts24/32/79048_2.png) [@chris\_ts24](https://discuss.elastic.co/u/chris_ts24)
#### Post date: [July 15, 2021, 6:01pm UTC](https://discuss.elastic.co/t/rufus-scheduler-error-tzinfo-periodnotfound/278811/3 "2021-07-15T18:01:08Z")

</div>

Strangely, as the recorded JDBC timestamps show, the timestamps are written at least 21 minutes past 2am CEST. I would understand that Logstash prevents the timestamp write if it did it for all times past 2am, but if it's already writing at 2:21am, why stop suddenly at 2:27 due to an issue that will become a problem on the 27th of March, 2022?

I assume that the jdbc plugin can be used on a minute schedule, but wherein lies the problem with my implementation? Do I perhaps need to incorporate the timezone into the schedule, as [here](https://www.elastic.co/guide/en/logstash/current/plugins-inputs-jdbc.html) with the cited example `0 6 * * * America/Chicago`?

---

<div class="post-metadata">

### Author: ![chris\_ts24](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/chris_ts24/32/79048_2.png) [@chris\_ts24](https://discuss.elastic.co/u/chris_ts24)
#### Post date: [July 26, 2021, 12:12pm UTC](https://discuss.elastic.co/t/rufus-scheduler-error-tzinfo-periodnotfound/278811/4 "2021-07-26T12:12:58Z")

</div>

I have in the meantime found the reason for the problem, albeit an unexpected one that took a bit of digging into our database data.

The pipeline was attempting to rewrite all timestamps from the database into the timezone CET. This was, as @Badger has indicated, a problem because any timestamp between 2 and 3 in the morning on the 27th of march will not exist, as time will roll forward. So, how did we deal with this?

After some testing, it seemed that the conflict was occurring between how our machines were storing / retrieving timestamps from the database. So we removed jdbc timezone information from our configuration, which then defaults the timestamp to UTC. Then, looking into our database properties, we noticed that our DB is set in UTC, so we should never have been using this argument, as according to the [jdbc plugin docu](https://www.elastic.co/guide/en/logstash/current/plugins-inputs-jdbc.html#plugins-inputs-jdbc-jdbc_default_timezone), `If your database timezone is UTC then you do not need to set either of these settings.`

The remaining step was to find another strategy of saving the metadata timestamp, so that it too was saved in UTC. After struggling to get the query run timestamp to be saved in UTC and understood as UTC in the next scheduled run, we ultimately decided on saving the timestamp by tracking the modification timestamp column of our jdbc requests. In other words, the metadata timestamps are now saved in a timestamp format from the DB Column, as opposed to the timestamp Logstash saves in local time.

```auto
input {
        jdbc {
                jdbc_driver_class => "Java::oracle.jdbc.driver.OracleDriver"
                jdbc_driver_library => "/usr/local/bin/ojdbc8.jar"
                jdbc_connection_string => "jdbc:oracle:thin:@<DB ADDRESS>"
                jdbc_user => "<user>"
                jdbc_password => "<pass>"
                statement_filepath => "<path>/<to>/<SQL file>"
                schedule => "* * * * *"
                last_run_metadata_path => "<path>/<to>/<jdbc_metadata_file>"
                enable_metric => false
                tracking_column => "date_changed"
                use_column_value => true
                tracking_column_type => "timestamp"
     }
}

```

To any struggling with timestamp issues, I would suggest finding a way to bring all your timestamps into a singular TZ to avoid this struggle, especially if you're using these metadata timestamps in your SQL WHERE clause. UTC is naturally the TZ of choice, as you won't have to worry about these DST problems from timestamps that don't exist.

I hope this helps! If confusion arises from this description, please let me know so I can make this more readable. These TZ issues are extremely frustrating.

Good luck!

---

<div class="post-metadata">

### Author: ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)
#### Post date: [August 23, 2021, 12:13pm UTC](https://discuss.elastic.co/t/rufus-scheduler-error-tzinfo-periodnotfound/278811/5 "2021-08-23T12:13:03Z")

</div>

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.
