[JRuby 1.1.3 -- Glassfish 9.1_01] Time slowly out of sync?

Discussion in 'Ruby' started by David Westerink, Jun 5, 2009.

  1. [Note: parts of this message were removed to make it a legal post.]

    Hi all!

    This is my first post to this mailinglist, so be gentle :)

    I hope you can help me with this very strange issue I'm having...
    I have an application in JRuby on GlassFish deployed on 2 servers. One
    is production, the other is fail-over. We had an power outage a few
    days ago, and now I'm having a strange issue on the production server.
    It seems that the application (NOT the server) is slowly losing track
    of time...

    I've investigated the log file, and here are some results, consider
    the times:

    [#|2009-06-04T15:00:00.446+0200|INFO|sun-appserver9.1|
    javax.enterprise.system.container.web|
    _ThreadID=19;_ThreadName=httpSSLWorkerThread-80-0;|PWC1412: WebModule
    [] ServletContext.log():

    Processing PdfsController#index (for 172.50.0.5 at 2009-06-04
    14:56:10) [GET]
    Session ID: 1306c85395433b5445b1f93211ce952e
    Parameters: {"controller"=>"pdfs", "action"=>"index"}
    Redirected to http://sano01/session/new
    Filter chain halted as [:check_roles] rendered_or_redirected.
    Completed in 0.00150 (666 reqs/sec) | DB: 0.00235 (156%) | 302 Found |
    #]

    This gets worse:

    [#|2009-06-04T16:52:03.366+0200|INFO|sun-appserver9.1|
    javax.enterprise.system.container.web|
    _ThreadID=19;_ThreadName=httpSSLWorkerThread-80-0;|PWC1412: WebModule
    [] ServletContext.log():

    Processing PdfsController#index (for 172.50.0.5 at 2009-06-04
    16:27:07) [GET]
    Session ID: 144a9aeaad71dfd6c1241a70cffc5bfd
    Parameters: {"controller"=>"pdfs", "action"=>"index"}
    Redirected to http://sano01/session/new
    Filter chain halted as [:check_roles] rendered_or_redirected.
    Completed in 0.00137 (731 reqs/sec) | DB: 0.00095 (69%) | 302 Found|#]

    Really worse:

    [#|2009-06-05T02:53:25.696+0200
    |INFO|sun-appserver9.1|javax.enterprise.system.container.web|
    _ThreadID=19;_ThreadName=httpSSLWorkerThread-80-0;|PWC1412: WebModule
    [] ServletContext.log():

    Processing SessionsController#new (for 172.16.0.14 at 2009-06-05
    00:35:14) [GET]
    Session ID: 94ce2b52338cda7c03c2a08de8629ff1
    Parameters: {"controller"=>"sessions", "action"=>"new"}
    Rendering template within layouts/application
    Rendering sessions/new
    Completed in 0.01545 (64 reqs/sec) | Rendering: 0.01272 (82%) | DB:
    0.00319 (20%) | 200 OK|#]

    [#|2009-06-05T08:56:42.932+0200 |INFO|sun-appserver9.1|
    javax.enterprise.system.container.web|
    _ThreadID=20;_ThreadName=httpSSLWorkerThread-80-2;|PWC1412: WebModule
    [] ServletContext.log():

    Processing SessionsController#new (for 172.50.0.5 at 2009-06-05
    05:30:05) [GET]
    Session ID: a0a85a83bede7cf072acf6a16fa6fc0c
    Parameters: {"controller"=>"sessions", "action"=>"new"}
    Rendering template within layouts/application
    Rendering sessions/new
    Completed in 0.01425 (70 reqs/sec) | Rendering: 0.01193 (83%) | DB:
    0.00374 (26%) | 200 OK|#]

    As you can see, the time goes way off!!!

    How can this be happening? Is there a way I can sync time in JRuby
    (GalssFish doen't seem to be the issue) with the server time?

    Anyone with some help/anwsers/hints?

    With kind regards,

    David Westerink

    --
    David (davidakachaos)

    blog: http://www.davidakachaos.nl
    Hyves: http://davidakachaos.hyves.nl
    David Westerink, Jun 5, 2009
    #1
    1. Advertising

  2. Is this actually 1.1.3? If so, that's probably part of the problem :)
    1.1.3 is almost a year old, and used some timekeeping logic that has
    since been removed because of drift and because of suspend/sleep
    throwing it way off. I'd strongly recommend updating to 1.2 or higher.

    - Charlie

    David Westerink wrote:
    > Hi all!
    >
    > This is my first post to this mailinglist, so be gentle :)
    >
    > I hope you can help me with this very strange issue I'm having...
    > I have an application in JRuby on GlassFish deployed on 2 servers. One
    > is production, the other is fail-over. We had an power outage a few
    > days ago, and now I'm having a strange issue on the production server.
    > It seems that the application (NOT the server) is slowly losing track
    > of time...
    >
    > I've investigated the log file, and here are some results, consider
    > the times:
    >
    > [#|2009-06-04T15:00:00.446+0200|INFO|sun-appserver9.1|
    > javax.enterprise.system.container.web|
    > _ThreadID=19;_ThreadName=httpSSLWorkerThread-80-0;|PWC1412: WebModule
    > [] ServletContext.log():
    >
    > Processing PdfsController#index (for 172.50.0.5 at 2009-06-04
    > 14:56:10) [GET]
    > Session ID: 1306c85395433b5445b1f93211ce952e
    > Parameters: {"controller"=>"pdfs", "action"=>"index"}
    > Redirected to http://sano01/session/new
    > Filter chain halted as [:check_roles] rendered_or_redirected.
    > Completed in 0.00150 (666 reqs/sec) | DB: 0.00235 (156%) | 302 Found |
    > #]
    >
    > This gets worse:
    >
    > [#|2009-06-04T16:52:03.366+0200|INFO|sun-appserver9.1|
    > javax.enterprise.system.container.web|
    > _ThreadID=19;_ThreadName=httpSSLWorkerThread-80-0;|PWC1412: WebModule
    > [] ServletContext.log():
    >
    > Processing PdfsController#index (for 172.50.0.5 at 2009-06-04
    > 16:27:07) [GET]
    > Session ID: 144a9aeaad71dfd6c1241a70cffc5bfd
    > Parameters: {"controller"=>"pdfs", "action"=>"index"}
    > Redirected to http://sano01/session/new
    > Filter chain halted as [:check_roles] rendered_or_redirected.
    > Completed in 0.00137 (731 reqs/sec) | DB: 0.00095 (69%) | 302 Found|#]
    >
    > Really worse:
    >
    > [#|2009-06-05T02:53:25.696+0200
    > |INFO|sun-appserver9.1|javax.enterprise.system.container.web|
    > _ThreadID=19;_ThreadName=httpSSLWorkerThread-80-0;|PWC1412: WebModule
    > [] ServletContext.log():
    >
    > Processing SessionsController#new (for 172.16.0.14 at 2009-06-05
    > 00:35:14) [GET]
    > Session ID: 94ce2b52338cda7c03c2a08de8629ff1
    > Parameters: {"controller"=>"sessions", "action"=>"new"}
    > Rendering template within layouts/application
    > Rendering sessions/new
    > Completed in 0.01545 (64 reqs/sec) | Rendering: 0.01272 (82%) | DB:
    > 0.00319 (20%) | 200 OK|#]
    >
    > [#|2009-06-05T08:56:42.932+0200 |INFO|sun-appserver9.1|
    > javax.enterprise.system.container.web|
    > _ThreadID=20;_ThreadName=httpSSLWorkerThread-80-2;|PWC1412: WebModule
    > [] ServletContext.log():
    >
    > Processing SessionsController#new (for 172.50.0.5 at 2009-06-05
    > 05:30:05) [GET]
    > Session ID: a0a85a83bede7cf072acf6a16fa6fc0c
    > Parameters: {"controller"=>"sessions", "action"=>"new"}
    > Rendering template within layouts/application
    > Rendering sessions/new
    > Completed in 0.01425 (70 reqs/sec) | Rendering: 0.01193 (83%) | DB:
    > 0.00374 (26%) | 200 OK|#]
    >
    > As you can see, the time goes way off!!!
    >
    > How can this be happening? Is there a way I can sync time in JRuby
    > (GalssFish doen't seem to be the issue) with the server time?
    >
    > Anyone with some help/anwsers/hints?
    >
    > With kind regards,
    >
    > David Westerink
    >
    Charles Oliver Nutter, Jun 6, 2009
    #2
    1. Advertising

  3. [Note: parts of this message were removed to make it a legal post.]

    Hi,

    Thanks, I will look into that. I just got handed this application to
    maintain, so I'll if I can upgrade savely :)

    2009/6/6 Charles Oliver Nutter <>

    > Is this actually 1.1.3? If so, that's probably part of the problem :) 1.1.3
    > is almost a year old, and used some timekeeping logic that has since been
    > removed because of drift and because of suspend/sleep throwing it way off.
    > I'd strongly recommend updating to 1.2 or higher.
    >
    > - Charlie
    >
    >
    > David Westerink wrote:
    >
    >> Hi all!
    >>
    >> This is my first post to this mailinglist, so be gentle :)
    >>
    >> I hope you can help me with this very strange issue I'm having...
    >> I have an application in JRuby on GlassFish deployed on 2 servers. One
    >> is production, the other is fail-over. We had an power outage a few
    >> days ago, and now I'm having a strange issue on the production server.
    >> It seems that the application (NOT the server) is slowly losing track
    >> of time...
    >>
    >> I've investigated the log file, and here are some results, consider
    >> the times:
    >>
    >> [#|2009-06-04T15:00:00.446+0200|INFO|sun-appserver9.1|
    >> javax.enterprise.system.container.web|
    >> _ThreadID=19;_ThreadName=httpSSLWorkerThread-80-0;|PWC1412: WebModule
    >> [] ServletContext.log():
    >>
    >> Processing PdfsController#index (for 172.50.0.5 at 2009-06-04
    >> 14:56:10) [GET]
    >> Session ID: 1306c85395433b5445b1f93211ce952e
    >> Parameters: {"controller"=>"pdfs", "action"=>"index"}
    >> Redirected to http://sano01/session/new
    >> Filter chain halted as [:check_roles] rendered_or_redirected.
    >> Completed in 0.00150 (666 reqs/sec) | DB: 0.00235 (156%) | 302 Found |
    >> #]
    >>
    >> This gets worse:
    >>
    >> [#|2009-06-04T16:52:03.366+0200|INFO|sun-appserver9.1|
    >> javax.enterprise.system.container.web|
    >> _ThreadID=19;_ThreadName=httpSSLWorkerThread-80-0;|PWC1412: WebModule
    >> [] ServletContext.log():
    >>
    >> Processing PdfsController#index (for 172.50.0.5 at 2009-06-04
    >> 16:27:07) [GET]
    >> Session ID: 144a9aeaad71dfd6c1241a70cffc5bfd
    >> Parameters: {"controller"=>"pdfs", "action"=>"index"}
    >> Redirected to http://sano01/session/new
    >> Filter chain halted as [:check_roles] rendered_or_redirected.
    >> Completed in 0.00137 (731 reqs/sec) | DB: 0.00095 (69%) | 302 Found|#]
    >>
    >> Really worse:
    >>
    >> [#|2009-06-05T02:53:25.696+0200
    >> |INFO|sun-appserver9.1|javax.enterprise.system.container.web|
    >> _ThreadID=19;_ThreadName=httpSSLWorkerThread-80-0;|PWC1412: WebModule
    >> [] ServletContext.log():
    >>
    >> Processing SessionsController#new (for 172.16.0.14 at 2009-06-05
    >> 00:35:14) [GET]
    >> Session ID: 94ce2b52338cda7c03c2a08de8629ff1
    >> Parameters: {"controller"=>"sessions", "action"=>"new"}
    >> Rendering template within layouts/application
    >> Rendering sessions/new
    >> Completed in 0.01545 (64 reqs/sec) | Rendering: 0.01272 (82%) | DB:
    >> 0.00319 (20%) | 200 OK|#]
    >>
    >> [#|2009-06-05T08:56:42.932+0200 |INFO|sun-appserver9.1|
    >> javax.enterprise.system.container.web|
    >> _ThreadID=20;_ThreadName=httpSSLWorkerThread-80-2;|PWC1412: WebModule
    >> [] ServletContext.log():
    >>
    >> Processing SessionsController#new (for 172.50.0.5 at 2009-06-05
    >> 05:30:05) [GET]
    >> Session ID: a0a85a83bede7cf072acf6a16fa6fc0c
    >> Parameters: {"controller"=>"sessions", "action"=>"new"}
    >> Rendering template within layouts/application
    >> Rendering sessions/new
    >> Completed in 0.01425 (70 reqs/sec) | Rendering: 0.01193 (83%) | DB:
    >> 0.00374 (26%) | 200 OK|#]
    >>
    >> As you can see, the time goes way off!!!
    >>
    >> How can this be happening? Is there a way I can sync time in JRuby
    >> (GalssFish doen't seem to be the issue) with the server time?
    >>
    >> Anyone with some help/anwsers/hints?
    >>
    >> With kind regards,
    >>
    >> David Westerink
    >>
    >>

    >
    >



    --
    David (davidakachaos)

    blog: http://www.davidakachaos.nl
    Hyves: http://davidakachaos.hyves.nl
    msn:

    I never said it was your fault, I said I was going to blame you!!!
    Sent from Utrecht, UT, Netherlands
    George Bernard Shaw<http://www.brainyquote.com/quotes/authors/g/george_bernard_shaw.html>
    - "A government that robs Peter to pay Paul can always depend on the
    support of Paul."
    David Westerink, Jun 6, 2009
    #3
  4. 2009/6/5 David Westerink <>:
    > I hope you can help me with this very strange issue I'm having...
    > I have an application in JRuby on GlassFish deployed on 2 servers. One
    > is production, the other is fail-over. We had an power outage a few
    > days ago, and now I'm having a strange issue on the production server.
    > It seems that the application (NOT the server) is slowly losing track
    > of time...


    > As you can see, the time goes way off!!!
    >
    > How can this be happening? Is there a way I can sync time in JRuby
    > (GalssFish doen't seem to be the issue) with the server time?
    >
    > Anyone with some help/anwsers/hints?


    We had a similar issue just recently with a JVM run on HP Itanium. It
    turned out that it was the JVM not using a system call to get at the
    time but did some internal sampling. This was remedied by using JVM
    option "-XX:+UseGetTimeOfDay":

    http://www.google.com/search?q="-XX:+UseGetTimeOfDay"

    Knowing that the HP JVM is written by Sun and OEM'ed by HP I would not
    totally exclude the possibility of a similar phenomenon on Solaris
    although we did not observe this yet.

    Kind regards

    robert

    --
    remember.guy do |as, often| as.you_can - without end
    http://blog.rubybestpractices.com/
    Robert Klemme, Jun 8, 2009
    #4
  5. Robert Klemme wrote:
    > 2009/6/5 David Westerink <>:
    >> I hope you can help me with this very strange issue I'm having...
    >> I have an application in JRuby on GlassFish deployed on 2 servers. One
    >> is production, the other is fail-over. We had an power outage a few
    >> days ago, and now I'm having a strange issue on the production server.
    >> It seems that the application (NOT the server) is slowly losing track
    >> of time...

    >
    >> As you can see, the time goes way off!!!
    >>
    >> How can this be happening? Is there a way I can sync time in JRuby
    >> (GalssFish doen't seem to be the issue) with the server time?
    >>
    >> Anyone with some help/anwsers/hints?

    >
    > We had a similar issue just recently with a JVM run on HP Itanium. It
    > turned out that it was the JVM not using a system call to get at the
    > time but did some internal sampling. This was remedied by using JVM
    > option "-XX:+UseGetTimeOfDay":
    >
    > http://www.google.com/search?q="-XX:+UseGetTimeOfDay"
    >
    > Knowing that the HP JVM is written by Sun and OEM'ed by HP I would not
    > totally exclude the possibility of a similar phenomenon on Solaris
    > although we did not observe this yet.


    Wow, very interesting. I'd never seen or heard of that issue before.
    Thanks for the pointer!

    - Charlie
    Charles Oliver Nutter, Jun 9, 2009
    #5
    1. Advertising

Want to reply to this thread or ask your own question?

It takes just 2 minutes to sign up (and it's free!). Just click the sign up button to choose a username and then you can ask your own questions on the forum.
Similar Threads
  1. Madhur Ahuja

    problem with java version "1.4.1_01"

    Madhur Ahuja, Jul 29, 2004, in forum: Java
    Replies:
    4
    Views:
    1,515
    Minh Tran-Le
    Jul 30, 2004
  2. Slim Baltagi
    Replies:
    0
    Views:
    398
    Slim Baltagi
    Dec 15, 2007
  3. Trans
    Replies:
    2
    Views:
    478
    Trans
    Dec 12, 2005
  4. Ronald Fischer
    Replies:
    2
    Views:
    207
    Scott Miller
    May 16, 2007
  5. Arun
    Replies:
    0
    Views:
    91
Loading...

Share This Page