headers
John F. Morse | 4 Jan 2012 18:25

Division by zero in innreport

INN 2.5.2 on Debian 6.0.3 (Squeeze)

Servers installed from both DEB-APT and compiled from source.

Older INN 2.4.3 on Debian 5.0.9 (Lenny) are not reporting this error.

Errors started on January 1. First change of the year.

Illegal division by zero at /usr/lib/news/bin/innreport line 1747.
Daily Usenet report for my.net from Jan  3 00:00:02 to Jan  4 00:00:01

  1743   foreach $key (sort keys %$dates) {
    1744     $x_min = $key if $x_min > $key;
    1745     $x_max = $$dates{$key} if $x_max < $$dates{$key};
    1746     my $delta = $dates->{$key} - $key;
    1747     my $t = $out->{$key} / $delta;
    1748     $y_max_out = $t if $y_max_out < $t;
    1749     $t = $in->{$key} / $delta;
    1750     $y_max_in = $t if $y_max_in < $t;
    1751   }

--

-- 
John
Permalink | Reply |
headers
Julien ÉLIE | 5 Jan 2012 00:14
Favicon

Re: Division by zero in innreport

Hi John,

> Errors started on January 1. First change of the year.
> 
> Illegal division by zero at /usr/lib/news/bin/innreport line 1747.
> Daily Usenet report for my.net from Jan 3 00:00:02 to Jan 4 00:00:01
> 
> 
> 1743 foreach $key (sort keys %$dates) {
> 1744 $x_min = $key if $x_min > $key;
> 1745 $x_max = $$dates{$key} if $x_max < $$dates{$key};
> 1746 my $delta = $dates->{$key} - $key;
> 1747 my $t = $out->{$key} / $delta;
> 1748 $y_max_out = $t if $y_max_out < $t;
> 1749 $t = $in->{$key} / $delta;
> 1750 $y_max_in = $t if $y_max_in < $t;
> 1751 }

Thanks for the bug report.

The problem comes from the parsing of innreport.db (for HTML pages generated
by innreport).

If you have in this file a change of year for which the hours are the same
between Dec 31th and Jan 1st, then this error is generated.

For instance:

  news-notice.2010.12.31-04.15.02.html|Dec 31 04:15:02 -- Jan  1 04:15:02|28079|2791|7.9
MB|34320|1500|4.6 MB
(Continue reading)

Permalink | Reply |
headers
Russ Allbery | 5 Jan 2012 02:42
Picon
Favicon
Gravatar

Re: Division by zero in innreport

Julien ÉLIE <julien <at> trigofacile.com> writes:

> There is an issue in how innreport translates these dates.  The
> ConvDate() function assumes the dates are relative to the *current*
> year.  So it thinks it has been passed Dec 31th 2012 and Jan 1st 2012
> (whereas it was Dec 31th 2010 and Jan 1st 2011).  As 2012 is a leap
> year, and Dec 31th is after Feb 28th, the translated date contains an
> unexpected "+1 day".

This bug has been around for a long time.  I think it may even be in Trac
or TODO or somewhere, since I recall trying to fix it once and then
getting too confused by the date parsing code and giving up.

--

-- 
Russ Allbery (rra <at> stanford.edu)             <http://www.eyrie.org/~eagle/>

    Please send questions to the list rather than mailing me directly.
     <http://www.eyrie.org/~eagle/faqs/questions.html> explains why.
_______________________________________________
inn-workers mailing list
inn-workers <at> lists.isc.org
https://lists.isc.org/mailman/listinfo/inn-workers
Permalink | Reply |
headers
Julien ÉLIE | 7 Jan 2012 01:01
Favicon

Re: Division by zero in innreport

Hi Russ,

>> There is an issue in how innreport translates these dates.  The
>> ConvDate() function assumes the dates are relative to the *current*
>> year.  So it thinks it has been passed Dec 31th 2012 and Jan 1st 2012
>> (whereas it was Dec 31th 2010 and Jan 1st 2011).  As 2012 is a leap
>> year, and Dec 31th is after Feb 28th, the translated date contains an
>> unexpected "+1 day".
>
> This bug has been around for a long time.  I think it may even be in Trac
> or TODO or somewhere, since I recall trying to fix it once and then
> getting too confused by the date parsing code and giving up.

I think you refer to:
   http://inn.eyrie.org/trac/ticket/90

The identified bug (counting the right number of days) was fixed but 
another trickier one was introduced.

It is true that the date parsing code is confusing!

In the patch I attached to my previous mail, I make use of Time::Local 
to convert dates to seconds since epoch, thus modifying the behaviour of 
ConvDate() which was converting dates to seconds since January, 1st.

I bet innreport now runs slower, but I think it is better to achieve 
robustness (the code using Time::Local seems easier to read and maintain).
In case you, Alexander or another reader here see improvements, do not 
hesitate to tell.
(Continue reading)

Permalink | Reply |
headers
John F. Morse | 5 Jan 2012 03:25

Re: Division by zero in innreport

Julien ÉLIE wrote:
> Hi John,
> 
>> Errors started on January 1. First change of the year.
>>
>> Illegal division by zero at /usr/lib/news/bin/innreport line 1747.
>> Daily Usenet report for my.net from Jan 3 00:00:02 to Jan 4 00:00:01
>>
>>
>> 1743 foreach $key (sort keys %$dates) {
>> 1744 $x_min = $key if $x_min > $key;
>> 1745 $x_max = $$dates{$key} if $x_max < $$dates{$key};
>> 1746 my $delta = $dates->{$key} - $key;
>> 1747 my $t = $out->{$key} / $delta;
>> 1748 $y_max_out = $t if $y_max_out < $t;
>> 1749 $t = $in->{$key} / $delta;
>> 1750 $y_max_in = $t if $y_max_in < $t;
>> 1751 }
> 
> Thanks for the bug report.
> 
> The problem comes from the parsing of innreport.db (for HTML pages generated
> by innreport).
> 
> If you have in this file a change of year for which the hours are the same
> between Dec 31th and Jan 1st, then this error is generated.
> 
> For instance:
> 
>   news-notice.2010.12.31-04.15.02.html|Dec 31 04:15:02 -- Jan  1 04:15:02|28079|2791|7.9
(Continue reading)

Permalink | Reply |
headers
Julien ÉLIE | 7 Jan 2012 00:41
Favicon

Re: Division by zero in innreport

Hi John,

> Earlier I didn't notice the main page was "frozen" like albasani's is,
> but I see the same things here, and can find the good reports.
>
> Is there anything you could suggest to change to get it restarted?
> Something like a quick text edit of a date and/or time in /var/www perhaps?

There is a quick text edit to modify the identical timestamps, as I 
hinted at in my previous mail ("Dec 31 04:15:02 -- Jan  1 04:15:02" 
could become "Dec 31 04:15:02 -- Jan  1 05:15:02").

However, real fixes are better!

Could you please try the patch I attach to this mail?
Just apply it against <pathbin>/innreport.

Alexander, could you please also try it on Albasani so that we verify 
that your HTML reports are properly updated the following day?

Thanks beforehand to both of you,

--

-- 
Julien ÉLIE

« Whenever you set out to do something, something else must be done
   first. » (Murphy's Fourth Corollary)

--- innreport	2010-08-01 12:07:53.000000000 +0200
(Continue reading)

Permalink | Reply |
headers
Alexander Bartolich | 7 Jan 2012 04:41
Picon
Picon

Re: Division by zero in innreport

Julien ÉLIE wrote:
> [...]
> Alexander, could you please also try it on Albasani so that
 > we verify that your HTML reports are properly updated the following day?

Your patch works. Thank you.

http://common.albasani.net/innreport/index.xhtml

Ciao

     Alexander.
Permalink | Reply |
headers
John F. Morse | 7 Jan 2012 05:03

Re: Division by zero in innreport

Hi Julien,

> Could you please try the patch I attach to this mail?
> Just apply it against <pathbin>/innreport.
> 
> 
> Alexander, could you please also try it on Albasani so that we verify 
> that your HTML reports are properly updated the following day?
> 
> Thanks beforehand to both of you,

Thanks to you, Julien.

Patch applied to one server.

We'll look at the results after midnight.

news <at> n102:/usr/lib/news/bin$ patch -b --verbose innreport innreport_patch
Hmm...  Looks like a unified diff to me...
The text leading up to this was:
--------------------------
|--- innreport	2010-08-01 12:07:53.000000000 +0200
|+++ innreport	2012-01-07 00:24:00.000000000 +0100
--------------------------
Patching file innreport using Plan A...
Hunk #1 succeeded at 95.
Hunk #2 succeeded at 339.
Hunk #3 succeeded at 365.
Hunk #4 succeeded at 445.
Hunk #5 succeeded at 471.
(Continue reading)

Permalink | Reply |
headers
John F. Morse | 7 Jan 2012 09:24

Re: Division by zero in innreport

Hi Julien,

>> Could you please try the patch I attach to this mail?
>> Just apply it against <pathbin>/innreport.
>>
>>
>> Alexander, could you please also try it on Albasani so that we verify 
>> that your HTML reports are properly updated the following day?
>>
>> Thanks beforehand to both of you,
> 
> 
> Thanks to you, Julien.
> 
> Patch applied to one server.
> 
> We'll look at the results after midnight.

Looks good here also and no previous HTML was lost.

Applied to remaining INN 2.5.2 servers and ran "scanlogs norotate" which 
worked and displayed the missing six days of HTML.

Evidentially the 2.4.3 code does not suffer from this bug. They are all 
working fine, and haven't had any error messages in the Daily Reports.

As for your thoughts of additional time to run, I see no difference between 
the time the e-mail was sent at 00:22 and previous days.

Thanks for your work.
(Continue reading)

Permalink | Reply |
headers
Julien ÉLIE | 7 Jan 2012 11:31
Favicon

Re: Division by zero in innreport

Hi John and Alexander,

Thanks for the good news!

> news <at> n102:/usr/lib/news/bin$ patch -b --verbose innreport innreport_patch
> Hunk #9 succeeded at 743 (offset 5 lines).
> Hunk #10 succeeded at 1119 (offset 6 lines).

Yep, that's fine.  The version of innreport shipped with INN 2.5.2 has a 
few lines more than the STABLE and CURRENT versions of INN against which 
I made the patch.  No problem (assignment to the deprecated "$[" 
variable for the index of the first element of an array has been removed 
in innreport shipped with 2.5.3 and later).

> Evidentially the 2.4.3 code does not suffer from this bug. They are
> all working fine, and haven't had any error messages in the Daily
> Reports.

That's right.  Nonetheless, the 2.4.3 code suffers from several other 
bugs that have been fixed in later versions, especially thanks to Alexander.

> As for your thoughts of additional time to run, I see no difference
> between the time the e-mail was sent at 00:22 and previous days.

Time::Local::localtime() is then probably well optimized; good news too.

--

-- 
Julien ÉLIE

« Les ouvriers qui font la pause lentilles voient arriver un visiteur
(Continue reading)

Permalink | Reply |
headers
Petr Novopashenniy | 17 Jan 2012 14:02
Picon

Re: Division by zero in innreport


Good day, All!

On Sat, 7 Jan 2012, Julien ?LIE wrote:

JL> Hi John,
JL> 
JL> > Earlier I didn't notice the main page was "frozen" like albasani's is,
JL> > but I see the same things here, and can find the good reports.
JL> > 
JL> > Is there anything you could suggest to change to get it restarted?
JL> > Something like a quick text edit of a date and/or time in /var/www
JL> > perhaps?
JL> 
JL> There is a quick text edit to modify the identical timestamps, as I hinted
JL> at in my previous mail ("Dec 31 04:15:02 -- Jan  1 04:15:02" could become
JL> "Dec 31 04:15:02 -- Jan  1 05:15:02").
JL> 
JL> However, real fixes are better!
JL> 
JL> Could you please try the patch I attach to this mail?
JL> Just apply it against <pathbin>/innreport.
JL> 

After patching, I get this error:
"
Day '29' out of range 1..28 at /usr/local/news/bin/innreport line 771
"

And innreport does not update the index page.
(Continue reading)

Permalink | Reply |
headers
Julien ÉLIE | 17 Jan 2012 21:55
Favicon

Re: Division by zero in innreport

Hi Petr,

> After patching, I get this error:
> "
> Day '29' out of range 1..28 at /usr/local/news/bin/innreport line 771
> "

What is the result of a search for 'Feb 28' and 'Feb 29' in
your <pathhttp>/innreport.db file?

21:36 news <at> trigo /var/log/news/http% grep 'Feb 28' innreport.db
news-notice.2011.02.28-04.15.03.html|Feb 28 04:15:03 -- Mar  1 04:15:02|32222|3787|8.6
MB|38707|1803|4.8 MB
news-notice.2011.02.27-04.15.02.html|Feb 27 04:15:02 -- Feb 28 04:15:02|20548|2252|7.2
MB|33734|1377|3.6 MB
news-notice.2010.02.28-04.15.03.html|Feb 28 04:15:03 -- Mar  1 04:15:03|36788|3981|9.8
MB|51931|2616|6.6 MB
news-notice.2010.02.27-04.15.03.html|Feb 27 04:15:03 -- Feb 28 04:15:02|42328|4393|8.9
MB|53560|2606|5.9 MB
news-notice.2009.02.28-04.15.03.html|Feb 28 04:15:03 -- Mar  1 04:15:01|34943|3929|8.5
MB|47366|2216|6.0 MB
news-notice.2009.02.27-04.15.03.html|Feb 27 04:15:03 -- Feb 28 04:15:02|47363|5079|11.2
MB|60341|3299|9.0 MB
news-notice.2004.02.29-04.15.03.html|Feb 29 04:15:03 -- Mar  1 04:15:02|32222|3787|8.6
MB|38707|1803|4.8 MB
news-notice.2004.02.28-04.15.03.html|Feb 28 04:15:03 -- Feb 29  1 04:15:02|32222|3787|8.6
MB|38707|1803|4.8 MB
21:36 news <at> trigo /var/log/news/http% grep 'Feb 29' innreport.db
news-notice.2004.02.29-04.15.03.html|Feb 29 04:15:03 -- Mar  1 04:15:02|32222|3787|8.6
MB|38707|1803|4.8 MB
(Continue reading)

Permalink | Reply |
headers
Julien ÉLIE | 17 Jan 2012 22:26
Favicon

Re: Division by zero in innreport

Hi Petr,

> The line for "Mar 1 00:00:00 -- Feb 29 23:59:59" looks very suspicious.
> goblin2 and goblin3 were not active in 2007 so I can check only on goblin1.

At second glance, they were!

> I would suggest to remove the line for "Mar 1 00:00:00 -- Feb 29 23:59:59"
> in innreport.db to fix the problem.
> Maybe it has been generated by a previous version of innreport that had a bug;
> yet, it seems strange that it occurred in 2007 (a non-leap year)!!

Looking at up your reports, I see the following weird dates:

- goblin1 :
change of year 2007-2008 -> Jan 1 00:00:00 -- Dec 31 23:59:59
2007 -> Mar 1 00:00:00 -- Feb 29 23:59:59
change of year 2006-2007 -> Jan 1 00:00:00 -- Dec 31 23:59:59

- goblin2 :
change of year 2010-2011 -> Jan 1 00:00:00 -- Dec 31 23:59:59
change of year 2009-2010 -> Jan 1 00:00:00 -- Dec 31 23:59:59
change of year 2008-2009 -> Jan 1 00:00:00 -- Dec 31 23:59:59
change of year 2007-2008 -> Jan 1 00:00:00 -- Dec 31 23:59:59
change of year 2006-2007 -> Jan 1 00:00:00 -- Dec 31 23:59:59
2007 -> Mar 1 00:00:00 -- Feb 29 23:59:59
change of year 2006-2007 -> Jan 1 00:00:00 -- Dec 31 23:59:59

- goblin3 :
change of year 2010-2011 -> Jan 1 00:00:00 -- Dec 31 23:59:59
(Continue reading)

Permalink | Reply |
headers
Petr Novopashenniy | 18 Jan 2012 15:36
Picon

Re: Division by zero in innreport


Good day, Julien!

On Tue, 17 Jan 2012, Julien ?LIE wrote:

JL> Hi Petr,
JL> 
JL> > The line for "Mar 1 00:00:00 -- Feb 29 23:59:59" looks very suspicious.
JL> > goblin2 and goblin3 were not active in 2007 so I can check only on
JL> > goblin1.
JL> 
JL> At second glance, they were!
JL> 
JL> 
JL> > I would suggest to remove the line for "Mar 1 00:00:00 -- Feb 29 23:59:59"
JL> > in innreport.db to fix the problem.
JL> > Maybe it has been generated by a previous version of innreport that had a
JL> > bug;
JL> > yet, it seems strange that it occurred in 2007 (a non-leap year)!!
JL> 
JL> Looking at up your reports, I see the following weird dates:
JL> 
JL> - goblin1 :
JL> change of year 2007-2008 -> Jan 1 00:00:00 -- Dec 31 23:59:59
JL> 2007 -> Mar 1 00:00:00 -- Feb 29 23:59:59
JL> change of year 2006-2007 -> Jan 1 00:00:00 -- Dec 31 23:59:59
JL> 
JL> - goblin2 :
JL> change of year 2010-2011 -> Jan 1 00:00:00 -- Dec 31 23:59:59
JL> change of year 2009-2010 -> Jan 1 00:00:00 -- Dec 31 23:59:59
(Continue reading)

Permalink | Reply |
headers
Julien ÉLIE | 12 Jun 2012 20:04
Favicon

Re: Division by zero in innreport

Hi Petr,

> JL>  >  I would suggest to remove the line for "Mar 1 00:00:00 -- Feb 29 23:59:59"
> JL>  >  in innreport.db to fix the problem.
> JL>  >  Maybe it has been generated by a previous version of innreport that had a
> JL>  >  bug;
> 
> JL>  As for innreport for INN 2.5.3, what would be the best behaviour?
> JL>  Maybe checking the validity of a date before using it and not process the
> JL>  line if the date is not coherent?  Should such lines be automatically
> JL>  removed from innreport.db?
> 
> Perhaps, this is a good solution!

On second thought, I believe skipping such lines is better.
This way, we do not lose any data (in case an issue is noticed, the news administrator
may decide to fix it manually in innreport.db -- otherwise, the information would have
be deleted).

Thanks, Peter, for your bug report.

Suggested patch, that will be included in INN 2.5.3.
The release is expected within a week.  At last!

Index: scripts/innreport.in
===================================================================
--- scripts/innreport.in	(révision 9413)
+++ scripts/innreport.in	(copie de travail)
 <at>  <at>  -739,6 +739,8  <at>  <at> 
 }
(Continue reading)

Permalink | Reply |
headers
Petr Novopashenniy | 18 Jan 2012 15:44
Picon

Re: Division by zero in innreport


Good day, Julien!

On Tue, 17 Jan 2012, Julien ?LIE wrote:

JL> Hi Petr,
JL> 
JL> > After patching, I get this error:
JL> > "
JL> > Day '29' out of range 1..28 at /usr/local/news/bin/innreport line 771
JL> > "
JL> 
JL> What is the result of a search for 'Feb 28' and 'Feb 29' in
JL> your <pathhttp>/innreport.db file?
JL> 

<dd>

[news <at> goblin /usr/local/www/News/stats/goblin1]$ grep 'Feb 28' 
innreport.db
news-notice.2011.02.28-03.00.03.html|Feb 28 03:00:03 -- Mar  1 
03:00:03|8297897|626946|59.1 GB|22603757|4487147|182.5 GB
news-notice.2011.02.27-03.00.03.html|Feb 27 03:00:03 -- Feb 28 
03:00:03|7866524|637928|67.5 GB|20556159|4501693|195.4 GB
news-notice.2010.02.28-03.00.01.html|Feb 28 03:00:01 -- Mar  1 
03:00:01|9138035|562029|60.7 GB|21667090|2790506|116.3 GB
news-notice.2010.02.27-03.00.02.html|Feb 27 03:00:02 -- Feb 28 
03:00:01|10906787|546110|500.8 MB|15493521|1929150|75.8 GB
news-notice.2009.02.28-03.00.01.html|Feb 28 03:00:01 -- Mar  1 
03:00:02|13817111|658743|73.3 GB|29274366|4145309|170.0 GB
(Continue reading)

Permalink | Reply |
headers
Petr Novopashenniy | 21 Jan 2012 16:14
Picon

Re: Division by zero in innreport


Good day, Julien!

On Wed, 18 Jan 2012, Petr Novopashenniy wrote:

<dd>

PN> 
PN> On Tue, 17 Jan 2012, Julien ?LIE wrote:
PN> 
PN> JL> I would suggest to remove the line for "Mar 1 00:00:00 -- Feb 29 23:59:59"
PN> JL> in innreport.db to fix the problem.
PN> JL> Maybe it has been generated by a previous version of innreport that had a bug;
PN> JL> yet, it seems strange that it occurred in 2007 (a non-leap year)!!
PN> 
PN> Ok, I remove this strange line from innreport.db, and wait nightly report 
PN> now.

The problem is gone, thanks for your help, Julien!

--pety
Permalink | Reply |
headers
River Tarnell | 7 Jan 2012 17:17

Re: Division by zero in innreport

In article <4F04DD69.9070500 <at> trigofacile.com>,
Julien ÉLIE  <julien <at> trigofacile.com> wrote:
>The visible effect of this bug is for instance:
>  http://common.albasani.net/innreport/
>where the main page has not been updated since the beginning of the year.
>It is caused by the presence of "Dec 31 04:15:02 -- Jan 1 04:15:02".

My innreport (2.5.2) is running fine since the new year:

	http://news.rt.uk.eu.org/stats/

Is something else necessary to trigger the bug?

Regards,
--

-- 
        -- river.                      | Free Usenet: http://news.rt.uk.eu.org/
Non-Reciprocal Laws of Expectations:   | PGP: 2B9CE6F2
    Negative expectations yield negative results.
    Positive expectations yield negative results.

In article <4F04DD69.9070500 <at> trigofacile.com>,
Julien ÉLIE  <julien <at> trigofacile.com> wrote:
>The visible effect of this bug is for instance:
>  http://common.albasani.net/innreport/
>where the main page has not been updated since the beginning of the year.
>It is caused by the presence of "Dec 31 04:15:02 -- Jan 1 04:15:02".

My innreport (2.5.2) is running fine since the new year:
(Continue reading)

Permalink | Reply |
headers
Julien ÉLIE | 8 Jan 2012 22:46
Favicon

Re: Division by zero in innreport

Hi River,

> My innreport (2.5.2) is running fine since the new year:
>
> 	http://news.rt.uk.eu.org/stats/
>
> Is something else necessary to trigger the bug?

Yes.  The bug occurs when both of these two conditions are met:
a/ the current year is a leap year (like 2012);
b/ <pathhttp>/innreport.db contains a line, of whatever year, for "Dec 
31 - Jan 1" with the same hh:mm:ss for both "Dec 31" and "Jan 1".

--

-- 
Julien ÉLIE

« Le bonheur, c'est vouloir ce que l'on a. »
Permalink | Reply |

Gmane