search

ualbertalib / pushmi_pullyu

Ruby application to manage flow of content from Fedora into Swift for preservation
MIT License
1 stars 3 forks source link

Awkward startup logs #245

Open nmacgreg opened 2 years ago

nmacgreg commented 2 years ago

Re: https://helpdesk.library.ualberta.ca/otrs/index.pl?Action=AgentTicketZoom;TicketID=63598;ArticleID=354564#354545 (Prod was down, root cause: automatic update of Ruby to new version.)

Observed behaviour When systemd service 'pmpy' is started, the current log file begins with this Ruby-styled warning block, with no timestamp:

/usr/lib64/ruby/gems/2.6.0/gems/json-2.6.1/lib/json/common.rb:216:in initialize': no implicit conversion of nil into String (TypeError) from /usr/lib64/ruby/gems/2.6.0/gems/json-2.6.1/lib/json/common.rb:216:innew' from /usr/lib64/ruby/gems/2.6.0/gems/json-2.6.1/lib/json/common.rb:216:in parse' from /usr/lib64/ruby/gems/2.6.0/gems/pushmi_pullyu-2.0.1/lib/pushmi_pullyu/cli.rb:185:inrun_preservation_cycle' from /usr/lib64/ruby/gems/2.6.0/gems/pushmi_pullyu-2.0.1/lib/pushmi_pullyu/cli.rb:214:in run_tick_loop' from /usr/lib64/ruby/gems/2.6.0/gems/pushmi_pullyu-2.0.1/lib/pushmi_pullyu/cli.rb:54:instart_server' from /usr/lib64/ruby/gems/2.6.0/gems/pushmi_pullyu-2.0.1/lib/pushmi_pullyu/cli.rb:279:in block in start_server_as_daemon' from /usr/lib64/ruby/gems/2.6.0/gems/daemons-1.4.1/lib/daemons/application.rb:277:inblock in start_proc' from /usr/lib64/ruby/gems/2.6.0/gems/daemons-1.4.1/lib/daemons/daemonize.rb:84:in call_as_daemon' from /usr/lib64/ruby/gems/2.6.0/gems/daemons-1.4.1/lib/daemons/application.rb:281:instart_proc' from /usr/lib64/ruby/gems/2.6.0/gems/daemons-1.4.1/lib/daemons/application.rb:307:in start' from /usr/lib64/ruby/gems/2.6.0/gems/daemons-1.4.1/lib/daemons/controller.rb:56:inrun' from /usr/lib64/ruby/gems/2.6.0/gems/daemons-1.4.1/lib/daemons.rb:199:in block in run_proc' from /usr/lib64/ruby/gems/2.6.0/gems/daemons-1.4.1/lib/daemons/cmdline.rb:124:incatch_exceptions' from /usr/lib64/ruby/gems/2.6.0/gems/daemons-1.4.1/lib/daemons.rb:198:in run_proc' from /usr/lib64/ruby/gems/2.6.0/gems/pushmi_pullyu-2.0.1/lib/pushmi_pullyu/cli.rb:277:instart_server_as_daemon' from /usr/lib64/ruby/gems/2.6.0/gems/pushmi_pullyu-2.0.1/lib/pushmi_pullyu/cli.rb:34:in run' from /usr/lib64/ruby/gems/2.6.0/gems/pushmi_pullyu-2.0.1/exe/pushmi_pullyu:7:in<top (required)>' from /usr/bin/pushmi_pullyu:23:in load' from /usr/bin/pushmi_pullyu:23:in

'

... and only after that confusing pre-amble does it begin with timestamped logs: I, [2022-04-05T04:56:07.613497 #14010] INFO -- : Loading PushmiPullyu 2.0.1 I, [2022-04-05T04:56:07.613603 #14010] INFO -- : Running in ruby 2.6.7p197 (2021-04-05 revision 67941) [x86_64-linux]

Expected behavior:

henryzhang87 commented 2 years ago

These error messages caming from stopping of the service if my memory is right. I noted it to DI before.

pgwillia commented 2 years ago

I can confirm

pushmi_pullyu start

I, [2022-04-06T11:27:50.101164 #13770] INFO -- : Loading PushmiPullyu 2.0.2 I, [2022-04-06T11:27:50.101252 #13770] INFO -- : Running in ruby 2.7.5p203 (2021-11-24 revision f69aeb8314) [x86_64-linux]

pushmi_pullyu stop

Exiting... Interrupt again to force quit. /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/json-2.6.1/lib/json/common.rb:216:in initialize': no implicit conversion of nil into String (TypeError) from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/json-2.6.1/lib/json/common.rb:216:innew' from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/json-2.6.1/lib/json/common.rb:216:in parse' from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/pushmi_pullyu-2.0.2/lib/pushmi_pullyu/cli.rb:185:inrun_preservation_cycle' from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/pushmi_pullyu-2.0.2/lib/pushmi_pullyu/cli.rb:214:in run_tick_loop' from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/pushmi_pullyu-2.0.2/lib/pushmi_pullyu/cli.rb:54:instart_server' from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/pushmi_pullyu-2.0.2/lib/pushmi_pullyu/cli.rb:279:in block in start_server_as_daemon' from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/daemons-1.4.1/lib/daemons/application.rb:277:inblock in start_proc' from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/daemons-1.4.1/lib/daemons/daemonize.rb:84:in call_as_daemon' from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/daemons-1.4.1/lib/daemons/application.rb:281:instart_proc' from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/daemons-1.4.1/lib/daemons/application.rb:307:in start' from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/daemons-1.4.1/lib/daemons/controller.rb:56:inrun' from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/daemons-1.4.1/lib/daemons.rb:199:in block in run_proc' from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/daemons-1.4.1/lib/daemons/cmdline.rb:124:incatch_exceptions' from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/daemons-1.4.1/lib/daemons.rb:198:in run_proc' from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/pushmi_pullyu-2.0.2/lib/pushmi_pullyu/cli.rb:277:instart_server_as_daemon' from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/pushmi_pullyu-2.0.2/lib/pushmi_pullyu/cli.rb:34:in run' from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/pushmi_pullyu-2.0.2/exe/pushmi_pullyu:7:in<top (required)>' from /home/pjenkins/.asdf/installs/ruby/2.7.5/bin/pushmi_pullyu:23:in load' from /home/pjenkins/.asdf/installs/ruby/2.7.5/bin/pushmi_pullyu:23:in

'

It also complains when not using the daemon

$ pushmi_pullyu 
Loading PushmiPullyu 2.0.2
Running in ruby 2.7.5p203 (2021-11-24 revision f69aeb8314) [x86_64-linux]
Starting processing, hit Ctrl-C to stop
^CExiting...  Interrupt again to force quit.
Traceback (most recent call last):
    9: from /home/pjenkins/.asdf/installs/ruby/2.7.5/bin/pushmi_pullyu:23:in `<main>'
    8: from /home/pjenkins/.asdf/installs/ruby/2.7.5/bin/pushmi_pullyu:23:in `load'
    7: from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/pushmi_pullyu-2.0.2/exe/pushmi_pullyu:7:in `<top (required)>'
    6: from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/pushmi_pullyu-2.0.2/lib/pushmi_pullyu/cli.rb:38:in `run'
    5: from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/pushmi_pullyu-2.0.2/lib/pushmi_pullyu/cli.rb:54:in `start_server'
    4: from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/pushmi_pullyu-2.0.2/lib/pushmi_pullyu/cli.rb:214:in `run_tick_loop'
    3: from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/pushmi_pullyu-2.0.2/lib/pushmi_pullyu/cli.rb:185:in `run_preservation_cycle'
    2: from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/json-2.6.1/lib/json/common.rb:216:in `parse'
    1: from /home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/json-2.6.1/lib/json/common.rb:216:in `new'
/home/pjenkins/.asdf/installs/ruby/2.7.5/lib/ruby/gems/2.7.0/gems/json-2.6.1/lib/json/common.rb:216:in `initialize': no implicit conversion of nil into String (TypeError)
henryzhang87 commented 1 year ago

on the one hand, when pmpy stops, it throws a lot of error messages, on the other hand, when last time we enqueued a lot items, somehow, pmpy was auto restarted many times. I guess it was because the pmpy service was stopped many times. But what is the cause of the stop of the pmpy service during ingestion, it remains to be investigated.