ubic-watchdog function issue

135 views
Skip to first unread message

Yongbin Yu

unread,
Feb 17, 2014, 10:36:28 PM2/17/14
to ubic...@googlegroups.com
Hi there.

We migrate our plack apps which managed by supervisord to Ubic recently
Most of feature looks fine so far. but I can't get ubic-watchdog function.

I already read this thread
https://groups.google.com/forum/#!msg/ubic-perl/uThkf0iTqOo/o04ODbs53tUJ and I
installed perlbrew and ubic locally.

When I do following commands
  1. cpanm Ubic
  2. ubic-admin setup --batch 
  3. pkill ubic-watchdog
  4. ubic-watchdog ubic.watchdog
at this time i got following error

[Tue Feb 18 12:17:18 2014]    ubic.watchdog status is 'not running', restarting
[Tue Feb 18 12:17:18 2014]    Failed to revive ubic.watchdog: not running

but at this time, command `ubic start ubic.watchdog' is success as I expected

is this proper result? what's wrong with me? I missed something?

We can't bootstraping with minute trigged cronjob also. I thinks all this stuffs
connected with ubic-watchdog function.

I tested this situation in 4 instence of Debian 7.4 and MacOSX 10.8.5 with perlbrewed perl
5.18.2, 5.18,1,5.18.0

thanks

Vyacheslav Matyukhin

unread,
Feb 18, 2014, 4:23:45 AM2/18/14
to ubic...@googlegroups.com
Hi!
 
What do you see in ~/ubic/log/watchdog.log?
Also, can you edit ~/ubic/service/ubic/watchdog and add 'stdout', 'stderr' and 'ubic_log' options there (pointing to wherever you like), and then check what goes into these logs?
 
This is definitely not a proper result and there's nothing wrong with you :)
 
'ubic-watchdog X' and 'ubic start X' usually behave in the same way (i.e., if X is broken, they both either start it correctly or both fail).
You say that the first one gives you the error and second one is a success. It might be just a race condition: if the daemon you're trying to run (ubic.watchdog in this case) fails immediately after being started, then sometimes you get the "not running" error and sometimes you get the success, but it fails immediately after.
Anyway, our goal at this point is to look at logs and figure out why it fails.
 
 
18.02.2014, 13:14, "Yongbin Yu" <super...@gmail.com>:
--
You received this message because you are subscribed to the Google Groups "Ubic" group.
To unsubscribe from this group and stop receiving emails from it, send an email to ubic-perl+...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

yongbin

unread,
Feb 18, 2014, 4:52:16 AM2/18/14
to ubic...@googlegroups.com
Hi Vyacheslav

Thanks you for your reply.
I found following clues as your advice

first of all I added 'stdout','stderr','ubic_log' arguments for ~/ubic/service/ubic/watchdog's Ubic::Service::SimpleDaemon constructor
and I got following logs

# when I pkill ubic-watchdog(ubic_log)
> [Tue Feb 18 18:39:50 2014]    13392    daemon 13393 failed with signal TERM (15)

# when I ubic-watchdog ubic.watchdog(ubic_log)
> [Tue Feb 18 18:40:22 2014]    13430    guardian name: ubic-guardian ubic-periodic --rotate-logs --period=60 --stdout=/home/ircbot/ubic/log/watchdog.log --stderr=/home/ircbot/ubic/log/watchdog.err.log ubic-watchdog
> [Tue Feb 18 18:40:22 2014]    13430    obtaining lock...
> [Tue Feb 18 18:40:22 2014]    13430    got lock
> [Tue Feb 18 18:40:22 2014]    13430    guardian pid: 13430
> [Tue Feb 18 18:40:22 2014]    13430    daemon pid: 13431
> [Tue Feb 18 18:40:22 2014]    13430    child guid: 9170926
> [Tue Feb 18 18:40:22 2014]    13430    daemon 13431 failed, exit code 127c <------

# at this time, watchdog's stderr
> /usr/bin/env: perl: No such file or directory

# when I ubic start ubic.watchdog(ubic_log)
> [Tue Feb 18 18:40:49 2014]    13436    guardian name: ubic-guardian ubic-periodic --rotate-logs --period=60 --stdout=/home/ircbot/ubic/log/watchdog.log --stderr=/home/ircbot/ubic/log/watchdog.err.log ubic-watchdog
> [Tue Feb 18 18:40:49 2014]    13436    obtaining lock...
> [Tue Feb 18 18:40:49 2014]    13436    got lock
> [Tue Feb 18 18:40:49 2014]    13436    guardian pid: 13436
> [Tue Feb 18 18:40:49 2014]    13436    daemon pid: 13437
> [Tue Feb 18 18:40:49 2014]    13436    child guid: 9173664

It seems watchdog's stderr log is crucial clue of this problem at this time. but
I don't know why /usr/bin/env have found perl. - it seems process shebeng line.
but as you know ~/ubic/service/watchdog has no shebeng line

Thanks

Vyacheslav Matyukhin

unread,
Feb 18, 2014, 2:01:05 PM2/18/14
to ubic...@googlegroups.com
Huh.
What happens if you run 'ubic-periodic --rotate-logs --period=60 --stdout=/home/ircbot/ubic/log/watchdog.log --stderr=/home/ircbot/ubic/log/watchdog.err.log ubic-watchdog' manually?
 
This is weird. Inability to find perl suggests environment issues, but these usually happen when combined with cron (because cron uses clear environment and, particulary, very limited PATH), not when you use command line.
 
Just to be sure, do you have ubic installed *only* locally?
Do you have perlbrew configured and its configs sourced in the command line where you try all these examples?
 
PS: shebang line comes either from ubic-periodic script or from ubic-watchdog script, probably the former.
It works like this: ~/ubic/service/ubic/watchdog is config, which tells ubic that it should run `ubic-periodic` script as a daemon, which, in its turn, runs `ubic-watchdog` script every minute.
 
18.02.2014, 14:23, "yongbin" <super...@gmail.com>:

yongbin

unread,
Feb 18, 2014, 7:57:53 PM2/18/14
to ubic...@googlegroups.com
Hi

If I command ubic-periodic --rotate-logs --period=60 ubic-watchdog manulally( detatch stderr,stdout options for
immediate check ) I got same result for every minute

$ ubic-periodic --rotate-logs --period=60 ubic-watchdog
> Use of uninitialized value $file in -e at /home/ircbot/.perlbrew/libs/perl-5.18.2@ircbot/bin/ubic-periodic line 52.
> Use of uninitialized value $file in -e at /home/ircbot/.perlbrew/libs/perl-5.18.2@ircbot/bin/ubic-periodic line 52.
> [Wed Feb 19 09:32:41 2014]    ubic.watchdog status is 'not running', restarting
> [Wed Feb 19 09:32:41 2014]    Failed to revive ubic.watchdog: not running
> Use of uninitialized value $file in -e at /home/ircbot/.perlbrew/libs/perl-5.18.2@ircbot/bin/ubic-periodic line 52.
> Use of uninitialized value $file in -e at /home/ircbot/.perlbrew/libs/perl-5.18.2@ircbot/bin/ubic-periodic line 52.
> [Wed Feb 19 09:33:41 2014]    ubic.watchdog status is 'not running', restarting
> [Wed Feb 19 09:33:41 2014]    Failed to revive ubic.watchdog: not running

But as your privious email, I got some other clues about my perlbrew env
I use 'LIB' command of perlbrew for separate clean as-is copy of perl installation libs and
my working libs

https://metacpan.org/pod/release/GUGOD/App-perlbrew-0.67/bin/perlbrew#COMMAND:-LIB

so when I setup perlbrew, my steps might like below

> $ perlbrew install 5.18.2 --thread --switch
> - install successfuly complete -
> $ perlbrew lib create work
> $ perlbrew switch perl-5.18.2@work
> - starting to install cpanm, ubic, mojolicious, plack ...

and my current 'perl -V' is below

>   %ENV:
>     PERLBREW_BASHRC_VERSION="0.67"
>     PERLBREW_HOME="/home/ircbot/.perlbrew"
>     PERLBREW_MANPATH="/home/ircbot/perl5/perlbrew/perls/perl-5.18.2/man"
>     PERLBREW_PATH="/home/ircbot/perl5/perlbrew/bin:/home/ircbot/perl5/perlbrew/perls/perl-5.18.2/bin"
>     PERLBREW_PERL="perl-5.18.2"
>     PERLBREW_ROOT="/home/ircbot/perl5/perlbrew"
>     PERLBREW_VERSION="0.67"
>   @INC:
>     /home/ircbot/perl5/perlbrew/perls/perl-5.18.2/lib/site_perl/5.18.2/x86_64-linux
>     /home/ircbot/perl5/perlbrew/perls/perl-5.18.2/lib/site_perl/5.18.2
>     /home/ircbot/perl5/perlbrew/perls/perl-5.18.2/lib/5.18.2/x86_64-linux
>     /home/ircbot/perl5/perlbrew/perls/perl-5.18.2/lib/5.18.2

It seems Env problem as you said, ( I already have been seprated env passing problem because I used to use
djb's daemontools before I start supervisord. as you know daemontools is very very strict for Env variables ) but
most weird thing at this time is why even CLI invok of 'ubic-watchdog ubic.watchdog' is fail

to be sure, I do same test in switched normal perlbrew installation (perlbrew switch perl-5.18.2),then it's
ubic-watchdog ubic.watchdog and even cron invoked  ubic-periodic ubic-watchdog working we expected.


Vyacheslav Matyukhin

unread,
Feb 21, 2014, 4:32:14 AM2/21/14
to ubic...@googlegroups.com
What's your PATH after you do perlbrew switch perl-5.18.2@work? Does it include /usr/local/bin?
Do you have /usr/local/bin/perl installed?
 
ubic-watchdog prepends your PATH with /usr/local/bin if it's not present (it's an ugly hack for fixing default crontab path which usually doesn't include /usr/local/bin).
 
If your path doesn't include /usr/local/bin, then you may add it (in the end: export PATH=$PATH:/usr/local/bin) and see if it fixes anything.
 
Sorry for the late answer.
 
19.02.2014, 04:58, "yongbin" <super...@gmail.com>:

yongbin

unread,
Feb 22, 2014, 8:32:29 AM2/22/14
to ubic...@googlegroups.com
> What's your PATH after you do perlbrew switch perl-5.18.2@work? Does it include /usr/local/bin?
> Do you have /usr/local/bin/perl installed?

Yes It include "/usr/local/bin" in PATH env and It has no binary at there (Debian 7.4)

Could you execute ubic-watchdog after switching local lib created perlbrew installation for just reappearance?

Vyacheslav Matyukhin

unread,
Feb 22, 2014, 8:49:51 AM2/22/14
to ubic...@googlegroups.com
If there's no binary there, it shouldn't be a problem.
I'm out of ideas...
 
> Could you execute ubic-watchdog after switching local lib created perlbrew installation for just reappearance?
I don't understand what you mean.
 
22.02.2014, 17:32, "yongbin" <super...@gmail.com>:
Reply all
Reply to author
Forward
0 new messages