Localtime Updating

Anonymous Monk has asked for the wisdom of the Perl Monks concerning the following question:

Hi Monks!
I have a module that creates log files and uses localtime to get the time for the logs. My question is when I try to call this subroutine from the module from inside of a loop, the time from localtime keeps the same, I think that the call should happen on every interaction of the loop, creating a different time stamp for every line printed on this log file, instead all the lines have the same time as the first line created. Here is the example:

This is part of the code inside the module:

sub LOGGIN
{
....
 open(LOG, ">>$log") 
      or croak "Unable to append to $log: $!";
  print LOG "[$localtime] $log : @data \n";
 close LOG or die "Cannot close log file:: $log : $!\n";

....
}
[download]

Now here, I am calling it into my code, everything it's fine but when I look at the log lines:

#test code
my $i=0;        
for (my $count=1; $count<11; $count++)
{
$i++;

app_log($log,"Loading transac from \$file - $1");

print "cool<br>";
}
[download]

The times are all the same:

[Fri Feb 14 09:28:30 2005] test_of_log.txt : Loading transac  
[Fri Feb 14 09:28:30 2005] test_of_log.txt : Loading transac 
[Fri Feb 14 09:28:30 2005] test_of_log.txt : Loading transac 
[Fri Feb 14 09:28:30 2005] test_of_log.txt : Loading transac
[Fri Feb 14 09:28:30 2005] test_of_log.txt : Loading transac
[Fri Feb 14 09:28:30 2005] test_of_log.txt : Loading transac  
[Fri Feb 14 09:28:30 2005] test_of_log.txt : Loading transac 
[Fri Feb 14 09:28:30 2005] test_of_log.txt : Loading transac
[Fri Feb 14 09:28:30 2005] test_of_log.txt : Loading transac
[Fri Feb 14 09:28:30 2005] test_of_log.txt : Loading transac
....
[download]

I just can't figure it out, shouldn't I get seconds apart on each line? Any help?
Thanks a lot!

Comment on Localtime Updating Select or Download Code

Replies are listed 'Best First'.
Re: Localtime Updating by ikegami (Patriarch) on Feb 24, 2006 at 15:20 UTC
You didn't show us where `$localtime` is set, so it could very well be stale. If the transactions really do take less than a second (which is quite possible, not knowing any details) then you might want to look into Time::HiRes `use Time::HiRes qw( time ); sub LOGGIN { my $time = time; my $mili = sprintf("%03d", ($time - int($time)) * 100); my $localtime = localtime($time); open(local *LOG, '>>', $log) or croak "Unable to append to $log: $!"; print LOG "[$localtime.$mili] $log : @data \n"; close LOG or die "Cannot close log file:: $log : $!\n"; }` [download]	[reply] [d/l] [select]
Re^2: Localtime Updating by Anonymous Monk on Feb 24, 2006 at 15:45 UTC
I don't know if you all noticed, but this is where in the module localtime gets set. It is part of the code in the module like: `our $localtime = localtime;` [download]	[reply] [d/l]
Re^3: Localtime Updating by duff (Parson) on Feb 24, 2006 at 15:59 UTC
Anonymonk, now explain why you think the value of that scalar should change over time. Do you assign the value of `localtime()` many times? Do you think that by calling your subroutine, it somehow magically knows to update the value stored in `$localtime`? I don't understand your difficulty. duff	[reply] [d/l] [select]
Re^4: Localtime Updating by Anonymous Monk on Feb 24, 2006 at 16:08 UTC
Re^5: Localtime Updating by duff (Parson) on Feb 24, 2006 at 18:52 UTC
Re^3: Localtime Updating by davorg (Chancellor) on Feb 24, 2006 at 16:00 UTC
Yes. We all noticed that. But how many times does that piece of code get executed? It looks as tho' it's only called once, so the value of `$localtime` is set once but never changed. -- <http://dave.org.uk> "The first rule of Perl club is you do not talk about Perl club." -- Chip Salzenberg	[reply]
Re^4: Localtime Updating by Anonymous Monk on Feb 24, 2006 at 16:09 UTC
Re^5: Localtime Updating by davorg (Chancellor) on Feb 24, 2006 at 16:41 UTC
Re^2: Localtime Updating by Anonymous Monk on Feb 24, 2006 at 16:05 UTC
Still doesn't work, it gives me the same lines with repeated times: `[Fri Feb 24 10:55:45 2006.068] test_of_log.txt : Loading trans [Fri Feb 24 10:55:45 2006.068] test_of_log.txt : Loading trans [Fri Feb 24 10:55:45 2006.068] test_of_log.txt : Loading trans [Fri Feb 24 10:55:45 2006.068] test_of_log.txt : Loading trans [Fri Feb 24 10:55:45 2006.068] test_of_log.txt : Loading trans [Fri Feb 24 10:55:45 2006.068] test_of_log.txt : Loading trans [Fri Feb 24 10:55:45 2006.068] test_of_log.txt : Loading trans` [download]	[reply] [d/l]
Re: Localtime Updating by duff (Parson) on Feb 24, 2006 at 14:57 UTC
It looks like you're using the value of a scalar variable called `$localtime` but you don't show where this variable it set. I suspect it's only set once rather than on each invocation of the subroutine duff	[reply] [d/l]
Re^2: Localtime Updating by Anonymous Monk on Feb 24, 2006 at 15:25 UTC
It is part of the code in the module like; our $localtime = localtime;	[reply]
Re^3: Localtime Updating by davorg (Chancellor) on Feb 24, 2006 at 15:29 UTC
But is that set each time you go round the loop? -- <http://dave.org.uk> "The first rule of Perl club is you do not talk about Perl club." -- Chip Salzenberg	[reply]
Re: Localtime Updating by davorg (Chancellor) on Feb 24, 2006 at 15:14 UTC
print LOG "[$localtime] $log : @data \n"; Maybe that should be: `print LOG '[' . scalar localtime . "] $log : @data \n";` [download] Update: Stupid error fixed :-/ -- <http://dave.org.uk> "The first rule of Perl club is you do not talk about Perl club." -- Chip Salzenberg	[reply] [d/l]
Re^2: Localtime Updating by ikegami (Patriarch) on Feb 24, 2006 at 15:18 UTC
I think you mean `print LOG "[".localtime()."] $log : @data \n";` or `print LOG "[", scalar localtime, "] $log : @data \n";` Your point being that we don't know where `$localtime` is being set, so it might be stale.	[reply] [d/l] [select]
Re^2: Localtime Updating by kwaping (Priest) on Feb 24, 2006 at 15:19 UTC
Close... `print LOG '[' . localtime() . "] $log : @data \n";` [download] Update: Removed superfluous "scalar" and added parens to my previously-untested reply.	[reply] [d/l]
Re^2: Localtime Updating by Fletch (Bishop) on Feb 24, 2006 at 16:34 UTC
Or even . . . `print LOG "[@{[scalar localtime]}] $log: @data \n";` [download] </TMTOWTDI>	[reply] [d/l]
Re: Localtime Updating by chargrill (Parson) on Feb 24, 2006 at 18:45 UTC
I'm assuming this still isn't working for you. I'll save you the trouble of admonishing you for using globals (like `$log` and `@data` appear to be, but in fact may not be as you've omitted a lot of your code). But this change should fix the specific issue you're after with your code: `sub LOGGIN { .... # sleep 1; $localtime = localtime(); open(LOG, ">>$log") or croak "Unable to append to $log: $!"; print LOG "[$localtime] $log : @data \n"; close LOG or die "Cannot close log file:: $log : $!\n"; .... }` [download] To prove it, uncomment the sleep line. --chargrill `$/ = q#(\w)# ; sub sig { print scalar reverse join ' ', @_ } + sig map { s$\$/\$/$\$2\$1$g && $_ } split( ' ', ",erckha rlPe erthnoa stJu +" );` [download]	[reply] [d/l] [select]