Forum: Rails deployment Logging problem in production environment

Announcement (2017-05-07): www.ruby-forum.com is now read-only since I unfortunately do not have the time to support and maintain the forum any more. Please see rubyonrails.org/community and ruby-lang.org/en/community for other Rails- und Ruby-related community platforms.
2b891e820c238ded365d035771603f21?d=identicon&s=25 Bill Walton (Guest)
on 2007-02-03 21:43
(Received via mailing list)
Please forgive the cross-post.  I haven't gotten any response on the
BackgrounDRb list and am hoping someone here will have some idea about
what the heck...

I've just moved a small but important piece of my app into the
production environment.  The piece is using BackgrounDRb to do session
management.  It appears that BackgrounDRb is writing to development.log
instead of production.log.  The backgroundrb.yml file specifies
production, as does environment.rb.  Mongel is writing to
production.log.

A little background (no pun intended ;-0 )  I'm using the 'old' version
of backgroundrb for session management.  In the app, whenever a visitor
changes pages I record the time in a db record.  In the worker, once a
second, I'm doing a find for that record.  That find is getting logged
in development.log, not in production.log as I expected.

Can anybody tell me if my assumption that BackgrounDRb is doing this
logging is correct?  Nothing is being written to backgroundrb.log.
What's being written to development.log is a record of the SQL calls
being done in the worker which is why I assume that BackgrounDRb must be
doing the logging.  But we all know about assumptions... ;-)

Anybody got any idea what I've done wrong?  I'm out of ideas: good, bad,
or otherwise.  Any insights, pointers, etc. are most sincerely
appreciated!

Thanks!
Bill
6d3c187a8b3ef53b08e3e7e8572c4fea?d=identicon&s=25 Jeremy McAnally (Guest)
on 2007-02-04 05:30
(Received via mailing list)
How are you doing the logging exactly?  Can we see a code snippet?

As something to try (I'm not sure this will work), but as an
experiment use RAILS_DEFAULT_LOGGER to log the information rather than
whatever you're using now (e.g., RAILS_DEFAULT_LOGGER.info("Blah!")).

--Jeremy

On 2/3/07, Bill Walton <bill.walton@charter.net> wrote:
> production.log.  The backgroundrb.yml file specifies production, as does
> written to development.log is a record of the SQL calls being done in the
> worker which is why I assume that BackgrounDRb must be doing the
> logging.  But we all know about assumptions... ;-)
>
> Anybody got any idea what I've done wrong?  I'm out of ideas: good, bad, or
> otherwise.  Any insights, pointers, etc. are most sincerely appreciated!
>
> Thanks!
> Bill
>  >
>


--
http://www.jeremymcanally.com/

My free Ruby e-book:
http://www.humblelittlerubybook.com/book/

My blogs:
http://www.mrneighborly.com/
http://www.rubyinpractice.com/
77f306388bb6ae00ac0b0401e27cdc99?d=identicon&s=25 Chad Fowler (Guest)
on 2007-02-04 10:56
(Received via mailing list)
> > appears that BackgrounDRb is writing to development.log instead of
> > is correct?  Nothing is being written to backgroundrb.log.  What's being
> > written to development.log is a record of the SQL calls being done in the
> > worker which is why I assume that BackgrounDRb must be doing the
> > logging.  But we all know about assumptions... ;-)
> >
> > Anybody got any idea what I've done wrong?  I'm out of ideas: good, bad, or
> > otherwise.  Any insights, pointers, etc. are most sincerely appreciated!
> >
> > Thanks!
> > Bill

Hi Bill,

It's been a few months since I ran into this, so I can't remember the
details, but I think your problem is actually much worse than just
logging.  I believe BackgrounDrb is being started with RAILS_ENV set
to development, which means it would be hitting the wrong database,
etc.  You might try logging RAILS_ENV to be sure.

I believe you can set :environment in your BackgrounDrb config to
override the default.

Chad
2b891e820c238ded365d035771603f21?d=identicon&s=25 Bill Walton (Guest)
on 2007-02-04 20:12
(Received via mailing list)
Hi Jeremy,

Jeremy McAnally wrote:

> How are you doing the logging exactly?
> Can we see a code snippet?

If you mean the code I'm using to do logging...  I don't have any.  The
problem I'm experiencing is with the logging Rails does on it's own.
Sorry
I wasn't clear.

Thanks much for your reply!
Bill
2b891e820c238ded365d035771603f21?d=identicon&s=25 Bill Walton (Guest)
on 2007-02-04 20:33
(Received via mailing list)
Hi Chad,

Chad Fowler wrote:

> I think your problem is actually much worse than
> just logging.

Gee, that's good news ;-)

> I believe BackgrounDrb is being started with
> RAILS_ENV set to development, which means
> it would be hitting the wrong database, etc.

As I responded to Jeremy, it's not BackgrounDRb logging that's going
haywire.  It's the normal Rails logging.

I went to bed last night believing firmly that the problem I'm having
lay
with my hosted environment and comitted fully to figuring out how to
conclusively demonstrate that to them.

I woke this morning with a plan, but also realizing that I'd missed an
important step in my debugging efforts so far.  Everything works fine on
my
development box in development mode.  But I hadn't tested the behavior
on my
development box in *production* mode.

There definitely appears to be a problem with Backgroundrb in production
mode.

I am seeing *exactly* the same behavior on my local machine that I'm
seeing
on my hosted environment.  In development mode, everything gets written
to
development.log as it should.  Requests, reponses, database activity.
In
production mode, the web server logging goes to
production.log.  But the SQL logging, and not all of it, goes to the
development log.

> You might try logging RAILS_ENV to be sure.

I was just thinking that I should try to log or display what environment
BackgrouDRb is running in.  Like Mongrel displays on-screen when it
starts
(on my Windows XP dev box).  Will RAILS_ENV tell me that?

> I believe you can set :environment in your
> BackgrounDrb config to override the default.

Absolutely right.  I've got that set to production.  I've got the
ENV['RAILS_ENV'] ||= 'production' line in environment.rb uncommented.
Yesterday, in the hosted environment, I went so far as to change the
defaults in the BackgrouDRb start script.  No joy.

The problem I'm seeing looks like some kind of interaction thing where
BackgrounDRb is changing some setting that Rails depends on to determine
where to log what.  What's really giving me fits is understanding why /
how
*some* of the logging gets written to one file and some to the other.
And
even wierder is that only the portion of the database activity being
done in
the BackgrounDRb worker is getting logged _at_all_.  The database writes
that are being done in the Rails controller are just disappearing
altogether!  Does any of that 'ring a bell' re: your past experience?

If anyone is interested, I would be VERY happy to forward the applet.
It's
trivial in terms of size.

Best regards,
Bill
6076c22b65b36f5d75c30bdcfb2fda85?d=identicon&s=25 Ezra Zygmuntowicz (Guest)
on 2007-02-04 20:53
(Received via mailing list)
Bill-

  Have you tried starting backgroundrb after setting RAILS_ENV ? LIke :

$ RAILS_ENV=production script/backgroundrb/start


-Ezra


On Feb 4, 2007, at 11:32 AM, Bill Walton wrote:

>> I believe BackgrounDrb is being started with
>
>
>> You might try logging RAILS_ENV to be sure.
> Absolutely right.  I've got that set to production.  I've got the
> other.  And
>
> Best regards,
> Bill
>
>
>
> >

-- Ezra Zygmuntowicz
-- Lead Rails Evangelist
-- ez@engineyard.com
-- Engine Yard, Serious Rails Hosting
-- (866) 518-YARD (9273)
2b891e820c238ded365d035771603f21?d=identicon&s=25 Bill Walton (Guest)
on 2007-02-04 21:34
(Received via mailing list)
Hi Ezra,

Ezra Zygmuntowicz wrote:

> Have you tried starting backgroundrb after
> setting RAILS_ENV ? LIke :
>
> $ RAILS_ENV=production script/backgroundrb/start

No I haven't.  I did try starting Mongrel and then BackgrounDRb
(thinking
that that would ensure that RAILS_ENV would have a value) and then
stopping
/ starting Mongrel again.  That didn't help.

Given that I'm getting the exact same results on my WinXP box and my
hosted
environment, I'm working today on the WinXP box.

Earlier, I put a 'puts' in the start script to echo the
CONFIG['environment'] value.
puts "Environment: #{CONFIG['environment']}"

That's used in the start script as:

ActiveRecord::Base.establish_connection(YAML.load(ERB.new(IO.read("#{RAILS_ROOT}/#{CONFIG['database_yml']}")).result)[CONFIG['environment']])

It's returning:
Environment: production

Eden Li suggested in an offlist reply to my BackgroundRb-devel post
yesterday that I do as you've suggested but I hadn't done it yet because
RAILS_ENV doesn't appear in the start script.

Since I'm working on the WinXP box today, I just dropped the following
into
the start script.
puts "RAILS_ENV: #{RAILS_ENV}"

It's returning:
RAILS_ENV: development.

I assume that's not good ;-p

I'm guessing I can use the command line you gave me to force things to
the
'right' state on the hosting account.  Yes?  What can I do on my WinXP
box?

Thanks!
Bill
6076c22b65b36f5d75c30bdcfb2fda85?d=identicon&s=25 Ezra Zygmuntowicz (Guest)
on 2007-02-04 22:19
(Received via mailing list)
Hi~

On Feb 4, 2007, at 12:33 PM, Bill Walton wrote:

> Since I'm working on the WinXP box today, I just dropped the
> to the
> 'right' state on the hosting account.  Yes?  What can I do on my
> WinXP box?
>
> Thanks!
> Bill



  I'm sorry but I don't have a clue as to how to set ENV vars on
windows. I know you can do it but you will have to google for window
cmd shell ENV vars and figure out how to set RAILS_ENV=production
before you start backgroundrb.

Cheers-
-- Ezra Zygmuntowicz
-- Lead Rails Evangelist
-- ez@engineyard.com
-- Engine Yard, Serious Rails Hosting
-- (866) 518-YARD (9273)
2b891e820c238ded365d035771603f21?d=identicon&s=25 Bill Walton (Guest)
on 2007-02-04 22:25
(Received via mailing list)
> Ezra Zygmuntowicz wrote:
>
>> Have you tried starting backgroundrb after
>> setting RAILS_ENV ? LIke :
>>
>> $ RAILS_ENV=production script/backgroundrb/start

I can't use this syntax on my WinXP box.  So I put the following line in
start.rb right under the last 'require'.
RAILS_ENV = 'production'

The good news is that Rails is no longer logging the database activity
to
development.log

The not-quite-so-good news is that now Rails is not logging the database
activity at all.

Any ideas?

Thanks!
Bill
77f306388bb6ae00ac0b0401e27cdc99?d=identicon&s=25 Chad Fowler (Guest)
on 2007-02-04 23:05
(Received via mailing list)
On 2/4/07, Bill Walton <bill.walton@charter.net> wrote:
> RAILS_ENV = 'production'
>
> The good news is that Rails is no longer logging the database activity to
> development.log
>
> The not-quite-so-good news is that now Rails is not logging the database
> activity at all.
>
> Any ideas?
>

Rails doesn't log database activity in production mode.  This is
configured via the log level.  If you have a problem you're trying to
debug, you can turn on verbose logging with:

  config.log_level = :debug

in production.rb.  I wouldn't leave it that way, though.

Chad
2b891e820c238ded365d035771603f21?d=identicon&s=25 Bill Walton (Guest)
on 2007-02-04 23:58
(Received via mailing list)
Hi Chad,

Chad Fowler wrote:

> Rails doesn't log database activity in production
> mode.

There's nothing quite so frustrating as not knowing when you're done!
;-)

Thanks very much for your help.  I appreciate it!

Best regards,
Bill
2b891e820c238ded365d035771603f21?d=identicon&s=25 Bill Walton (Guest)
on 2007-02-05 00:03
(Received via mailing list)
Hi Ezra,

Ezra Zygmuntowicz wrote:

> I'm sorry but I don't have a clue as to how to
> set ENV vars on windows.

I didn't realize it was just an system environment variable.  Sorry
about
that.  I'll write up a little thing and put it on the SF repository or
send
it to you, whichever is better.  The applet is working on both the
Windows
and Linux environments now.  Thanks very much for your help.  I _really_
appreciate it!

I guess I can go watch the game now!

Best regards to all, and thanks again for the help!
Bill
34f26dde337f0a0d2d380e11117e82f6?d=identicon&s=25 Vishnu Gopal (Guest)
on 2007-02-05 07:44
(Received via mailing list)
You can set an environment variable using "set" e.g. set
RAILS_ENV=production. Don't use quotes. Just typing in set will return
all the environment variables there.

Vish
This topic is locked and can not be replied to.