Endless loop after call Fugit::Cron#next_time with time zone 'CST'

[w11th]

environment:

• ruby 2.3.3p222
• fugit 1.1.6
• Time.now.zone is CST(+08:00)

code:

Time.now.utc # "2019-01-02T05:25:53.960Z"
cron = Fugit.do_parse_cron('0 0 1 1 *')
cron.next_time.to_s

expected:

"2019-12-01 00:00:00 +0000"

got:

Endless loop

What I found:

After some debugging, I thought the method TimeCursor#inc_mont doesn't work right in timezone CST (maybe all positive east of UTC timezones).

https://github.com/floraison/fugit/blob/6488c5f4e47ac63a2a5b7f290656a344ff9d2ca9/lib/fugit/cron.rb#L88 This line will parse the year and month as time zone CST, and then transfer to UTC.

For example:

::EtOrbi.make(2019, 2).to_s

expected: 2019-02-01 00:00:00 +0000 but got: 2019-01-31 16:00:00 +0000

The month isn't increased, and the loop in next_time will last forever.

Thank you for your work.

[jmettraux]

Hello, thanks for the very professional issue report.

Could you please tell me what is your operating system?

Could you please try with:

require 'fugit'

ENV['TZ'] = 'Asia/Shanghai'
#ENV['TZ'] = 'CST'

puts "---"

p Time.now
p Time.now.utc
p cron = Fugit.do_parse_cron('0 0 1 1 *')
p cron.next_time.to_s
p cron.next_time.utc.to_s

puts "---"

p Time.now
p Time.now.utc
p cron = Fugit.do_parse_cron('0 0 1 1 * UTC')
p cron.next_time.to_s
p cron.next_time.utc.to_s

and tell me how it behaves?

CST is too ambiguous as a timezone name. See https://24timezones.com/time-zone/cst Please use Asia/Shanghai or something more appropriate.

Please note that "cron.next_time" yields a result in the time zone for its cron.

Thanks in advance.

[w11th]

:My operating system is macOS:

ProductName:    Mac OS X
ProductVersion: 10.14.2
BuildVersion:   18C54

Here is the output of the code:

---
2019-01-02 14:20:24 +0800
2019-01-02 06:20:24 UTC
#<Fugit::Cron:0x007fdc7d0f5260 @original="0 0 1 1 *", @cron_s=nil, @seconds=[0], @minutes=[0], @hours=[0], @monthdays=[1], @months=[1], @weekdays=nil, @zone=nil, @timezone=nil>
"2020-01-01 00:00:00 +0800"
"2019-12-31 16:00:00 UTC"
---
2019-01-02 14:20:25 +0800
2019-01-02 06:20:25 UTC
#<Fugit::Cron:0x007fdc7c1496e0 @original="0 0 1 1 * UTC", @cron_s=nil, @seconds=[0], @minutes=[0], @hours=[0], @monthdays=[1], @months=[1], @weekdays=nil, @zone="UTC", @timezone=#<TZInfo::DataTimezone: UTC>>
"2020-01-01 00:00:00 +0800"
"2019-12-31 16:00:00 UTC"

The code in my issue run in the rails console. It seems to work after set ENV['TZ'].

Is ENV['TZ'] a requirement while working in a different time zone?

And the result in part 2 seems to be incorrect, should it be 2020-01-01 00:00:00 UTC?

[jmettraux]

Hello,

Is ENV['TZ'] a requirement while working in a different time zone?

Outside of Windows, that should not be necessary.

What does

bundle exec ruby -r et-orbi -e "EtOrbi._make_info"

in your project terminal yield?

And the result in part 2 seems to be incorrect, should it be 2020-01-01 00:00:00 UTC?

Indeed, I will investigate that.

Thanks in advance.

[w11th]

(secs:1546415129.1046982,utc~:"2019-01-02 07:45:29.10469818115234375",ltz~:"CST")
(etz:nil,tnz:"CST",tzid:nil,rv:"2.3.3",rp:"x86_64-darwin18",
  win:false,rorv:nil,astz:nil,eov:"1.1.6",eotnz:#<TZInfo::TimezoneProxy: Asia/Chongqing>,
  eotnfz:"+0800",eotlzn:"Asia/Chongqing",debian:nil,centos:nil,osx:"zoneinfo/Asia/Shanghai")

[jmettraux]

Hello,

I've set my Mac to Changzhou - China and tried your code:

074113 pollux 仁 ~/w/fugit (master)↑ ダ make info
uname -a
Darwin pollux.local 17.7.0 Darwin Kernel Version 17.7.0: Fri Nov  2 20:43:16 PDT 2018; root:xnu-4570.71.17~1/RELEASE_X86_64 x86_64
bundle exec ruby -v
ruby 2.3.7p456 (2018-03-28 revision 63024) [x86_64-darwin17]
bundle exec ruby -Ilib -r et-orbi -e "EtOrbi._make_info"
(secs:1546469146.095888,utc~:"2019-01-02 22:45:46.09588789939880371",ltz~:"CST")
(etz:nil,tnz:"CST",tzid:nil,rv:"2.3.7",rp:"x86_64-darwin17",win:false,rorv:nil,astz:nil,eov:"1.1.6",eotnz:#<TZInfo::TimezoneProxy: Asia/Chongqing>,eotnfz:"+0800",eotlzn:"Asia/Chongqing",debian:nil,centos:nil,osx:"zoneinfo/Asia/Shanghai")

064546 pollux 仁 ~/w/fugit (master)↑ ダ bxr wenhui.rb 
#<Fugit::Cron:0x00007fec499b88a8 @original="0 0 1 1 *", @cron_s=nil, @seconds=[0], @minutes=[0], @hours=[0], @monthdays=[1], @months=[1], @weekdays=nil, @zone=nil, @timezone=nil>
#<EtOrbi::EoTime:0x00007fec49aa9c58 @seconds=1577808000.0, @zone=#<TZInfo::TimezoneProxy: Asia/Chongqing>, @time=nil>
"2020-01-01 00:00:00 +0800"

064603 pollux 仁 ~/w/fugit (master)↑ ダ cat wenhui.rb 
require 'fugit'
#Time.now.utc # "2019-01-02T05:25:53.960Z"
cron = Fugit.do_parse_cron('0 0 1 1 *')
p cron
p cron.next_time
p cron.next_time.to_s

and, as you, I couldn't get it to fail :-(

After some debugging, I thought the method TimeCursor#inc_mont doesn't work right in timezone CST (maybe all positive east of UTC timezones).

Fortunately, it works in my JST (Asia/Tokyo) UTC+0900 time zone.

I'm going on investigating. Thanks again.

[jmettraux]

@w11th By the way, what version number for your tzinfo gem? what version number your tzinfo-data gem (if you use it)?

Thanks in advance.

[w11th]

Appreciate your help.

My tzinfo gem version number is 1.2.5, and I didn't use the tzinfo-data gem.

and, as you, I couldn't get it to fail :-(

I found that the code behaves differently in my rails console.

In my rails console, EtOrbi parse time with Chronic gem:

https://github.com/floraison/et-orbi/blob/ef6b69644c4b19e1c72b87539173f9e87c2f6986/lib/et-orbi.rb#L26

Chronic parse the time with Time class, and then return a new EoTime with code:T

 EoTime.new(t, nil)

This initialization build time with the time zone which EtOrbi.determine_local_tzone method returns. It's #<TZInfo::DataTimezone: Etc/UTC>(Time.zone value) in my rails console.

so, the code ::EtOrbi.make(2019, 2) parse the time in local time zone, and transfer to UTC time zone.

[jmettraux]

I tried to require 'chronic' in the example you gave, but still, no loop.

What is the simplest piece of code that you can come up with that shows the problem? Does adding Chronic and/or Active Support shows the problem on your system?

[w11th]

I think the problem is, method TimeCursor#inc_mont builds the new time with ::EtOrbi.make(y,m). The time zone of cron job wasn't passed to EtOrbi.

[jmettraux]

I would love to find the simplest piece of code that shows the problem so that I can fix it.

[w11th]

require 'fugit'
require 'active_support/all'
require 'chronic'

# Do not set ENV['TZ']
# ENV['TZ'] = 'Asia/Shanghai'
puts EtOrbi.os_tz

Time.zone = ::TZInfo::Timezone.get('UTC')

puts Time.now
puts Time.now.zone
puts Time.current

cron = Fugit.do_parse_cron('0 0 1 1 *')
p cron

puts cron.next_time

here is my output:

zoneinfo/Asia/Shanghai
2019-01-03 11:18:40 +0800
CST
2019-01-03 03:18:40 UTC
#<Fugit::Cron:0x007faabf185620 @original="0 0 1 1 *", @cron_s=nil, @seconds=[0], @minutes=[0], @hours=[0], @monthdays=[1], @months=[1], @weekdays=nil, @zone=nil, @timezone=nil>
<Endless loop>

[jmettraux]

Very good, it loops in my Asia/Tokyo as well.

I will fix that.

[godfat]

I am not sure if this is related, but this will freeze indefinitely for me:

Fugit::Cron.parse('0 0 0 * *').next_time

Previously, we're using refus-scheduler and 0 0 0 * * is supposed to be an invalid syntax. This was the test:

it 'does not allow invalid cron patters' do
  pipeline_schedule = build(:ci_pipeline_schedule, cron: '0 0 0 * *')

  expect(pipeline_schedule).not_to be_valid
end

It passed with refus-scheduler but it's valid for fugit, and calling next_time on the cron object will not stop. You can find all the context at WIP: Update sidekiq-cron 0.6.0 -> 1.0 and here's the failing test

[jmettraux]

Hello @godfat,

could you please give me more details? What does bundle exec ruby -r et-orbi -e "EtOrbi._make_info" yield on your platform? What version of Ruby, what operating system?

Thanks in advance.

[jmettraux]

Hello again @godfat,

sorry, your issue is simpler. As you mentioned a "day of month" of 0 should not be accepted. I opened gh-13 just for that. No need for further information.

Thank you very much, I will fix that.

[jmettraux]

@w11th

Sorry for taking time on this. I'm cleaning et-orbi since it's where the issue is at. I hope to be finished soon and address your issue directly then.

Kind regards.

[w11th]

@w11th

Sorry for taking time on this. I'm cleaning et-orbi since it's where the issue is at. I hope to be finished soon and address your issue directly then.

Kind regards.

It's totally OK. Thank you for your hard working and kindness. 😁

[jmettraux]

Hello @w11th,

could you please tell me if the current fugit (@ commit commit 7791dbb5635ed561894bb3a2335715d53d9298e) (combined with et-orbi 1.1.7) solves the issue for you?

If yes, I'll look at gh-12, solve it and then release fugit 1.1.7.

Thanks in advance,

[w11th]

Yes, it works.

Thank you very much 🙏

[jmettraux]

You're welcome :-)

[jmettraux]

Fix included in the 1.1.7 release. Many thanks!

[conet]

@jmettraux are you sure that this is fixed? I'm using gitlab-11.8.2-ee and it seems to be stuck in this loop:

2019-03-20_21:58:36.80890 2019-03-20T21:58:36.808Z 5353 TID-oxdlhwzy1 WARN: /opt/gitlab/embedded/lib/ruby/gems/2.5.0/gems/activesupport-5.0.7.1/lib/active_support/core_ext/time/calculations.rb:239:in `+'
2019-03-20_21:58:36.80891 /opt/gitlab/embedded/lib/ruby/gems/2.5.0/gems/activesupport-5.0.7.1/lib/active_support/core_ext/time/calculations.rb:239:in `plus_with_duration'
2019-03-20_21:58:36.80891 /opt/gitlab/embedded/lib/ruby/gems/2.5.0/gems/et-orbi-1.1.7/lib/et-orbi/eo_time.rb:129:in `utc'
2019-03-20_21:58:36.80891 /opt/gitlab/embedded/lib/ruby/gems/2.5.0/gems/et-orbi-1.1.7/lib/et-orbi/eo_time.rb:358:in `to_time'
2019-03-20_21:58:36.80892 /opt/gitlab/embedded/lib/ruby/gems/2.5.0/gems/et-orbi-1.1.7/lib/et-orbi/eo_time.rb:203:in `block (2 levels) in <class:EoTime>'
2019-03-20_21:58:36.80892 /opt/gitlab/embedded/lib/ruby/gems/2.5.0/gems/fugit-1.1.7/lib/fugit/cron.rb:76:in `block (2 levels) in <class:TimeCursor>'
2019-03-20_21:58:36.80892 /opt/gitlab/embedded/lib/ruby/gems/2.5.0/gems/fugit-1.1.7/lib/fugit/cron.rb:119:in `sec_match?'
2019-03-20_21:58:36.80893 /opt/gitlab/embedded/lib/ruby/gems/2.5.0/gems/fugit-1.1.7/lib/fugit/cron.rb:252:in `block in previous_time'
2019-03-20_21:58:36.80893 /opt/gitlab/embedded/lib/ruby/gems/2.5.0/gems/fugit-1.1.7/lib/fugit/cron.rb:232:in `loop'
2019-03-20_21:58:36.80894 /opt/gitlab/embedded/lib/ruby/gems/2.5.0/gems/fugit-1.1.7/lib/fugit/cron.rb:232:in `previous_time'
2019-03-20_21:58:36.80894 /opt/gitlab/embedded/lib/ruby/gems/2.5.0/gems/sidekiq-cron-1.0.4/lib/sidekiq/cron/job.rb:561:in `not_past_scheduled_time?'
2019-03-20_21:58:36.80894 /opt/gitlab/embedded/lib/ruby/gems/2.5.0/gems/sidekiq-cron-1.0.4/lib/sidekiq/cron/job.rb:23:in `block in should_enque?'

[jmettraux]

Hello @conet,

what is gitlab-11.8.2-ee? Never heard of it.

Please give me the shortest piece of code that shows this behaviour.

Please give me as well the output of bundle exec ruby -r et-orbi -e "EtOrbi._make_info" in your project/system.

Thanks in advance.

[godfat]

@jmettraux It's https://gitlab.com/gitlab-org/gitlab-ee/tree/v11.8.2-ee

@conet What's the cron pattern you're using?

[godfat]

Cross referencing the GitLab issue, which has more information: https://gitlab.com/gitlab-org/gitlab-ce/issues/59273

[jmettraux]

Cross referencing the GitLab issue

Thanks @godfat !

I am opening a new issue, I think it has nothing to do with the original issue here. Stay tuned.