XPost: linux.debian.bugs.dist

Hello,

I came across this bug report using 'how-can-i-help --old --show
newcomer' and am having trouble reproducing in isolation. I would like
to request a log sample to further, and more accurately, investigate.

I am assuming this bug still persists as there have been no
commits/updates to https://anonscm.debian.org/cgit/collab-maint/wiki.debian.org.git/tree/bin/rotate-logs
since the date this bug was filed.

Thank you!
--
monty

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

XPost: linux.debian.bugs.dist

On Thu, 2017-09-14 at 22:06 -0400, James Montgomery wrote:

I came across this bug report using 'how-can-i-help --old --show
newcomer' and am having trouble reproducing in isolation. I would like
to request a log sample to further, and more accurately, investigate.

Thanks for you interest in helping with the Debian wiki!

Here is the output from the problematic part of the script, with added
logdate debugging to make it more obvious where the issue is:

Splitting up event-log-TEMP:
logdate 1433471906044661433635204430807
gmtime(1433471906044661392216497848320) too large at /srv/wiki.debian.org/bin/rotate-logs line 117, <$fh_in> line 1.
gmtime(1433471906044661392216497848320) failed at /srv/wiki.debian.org/bin/rotate-logs line 117, <$fh_in> line 1.
Use of uninitialized value $year in addition (+) at /srv/wiki.debian.org/bin/rotate-logs line 119, <$fh_in> line 1.
Use of uninitialized value $mon in addition (+) at /srv/wiki.debian.org/bin/rotate-logs line 119, <$fh_in> line 1.

event-log-CURRENT: 27342430 lines
27342430 total
Splitting up event-log-TEMP:
logdate 1505621750678650
event-log-CURRENT: 76 lines
76 total

Here is a sample of the event log, with the private data removed:

1505622178372608 VIEWPAGE pagename=...&HTTP_USER_AGENT=...&REMOTE_ADDR=...

If I grep the event log for the logdate listed above, I get this:

1433471906044661433635204430807 VIEWPAGE pagename=...&HTTP_USER_AGENT=...&HTTP_REFERER=...&REMOTE_ADDR=...

I also noticed another line with the very long timestamp:

1438244879888341438473603006892 VIEWPAGE pagename=...&HTTP_USER_AGENT=...&HTTP_REFERER=...&REMOTE_ADDR=...

Hopefully the data above helps to resolve this, while getting this data
I noticed that this bug has resulted in a very large log file.

I am assuming this bug still persists

Correct.

--
bye,
pabs

https://wiki.debian.org/PaulWise

-----BEGIN PGP SIGNATURE-----

iQIzBAABCgAdFiEEYQsotVz8/kXqG1Y7MRa6Xp/6aaMFAlm9/w0ACgkQMRa6Xp/6 aaOa1xAAp4yWS3q8C7MkMjJP4wao3YTu/Z2Trp1tzMPRyPHd5XtBaRA2btMsebEL nhP2KuPsvF/f3XCdKsXFA7N/hjCrDwiIsEo3cVd/A3zIZHNQQndgeSdSwd8XsGrd R2i2cDBClTS75X1GvddQboEBEJlKadqK+pWdgRZ2tYv8EpaRunXcfVj4TcBtPPdj /QP/3IFqrU6l31tx0ynmzK66po+RwFV180PWi+3+8DecpNJCsQ6Ub1o4JXxTUpjr XShzH8bJoEU7hkXRlUPFocEK/hmlWqZMPDdbckVXEKtrKipR5nACc+xzQicAptg1 dZhXV8u24uLSQKRMg5SqMFC+PmgVVIC7MNUBtLC8qvWb92Nkb9d3T3JNRa/Zyobt h6jvRYcZHCfaCZkcZ2dV4W2KWRKlWCjCYvMfzLzprBPKipV5cV8YvLfOJHETOb5Q mS+6SrLnTwFN3FtkLnKfvd+kkmlGA+y6Ovjf4Qwv4sCc5pHT+hPxepeftRaj1Obr VPmvt8stPbcGbWsIQmE6hF0/eydqgLn2lRUhZuOfcypcEvKxZgV1hgmIZtTG8KDA J/NdtrAB7yaLKlLCZHLaxnvCXGY08tlP/YU6bAWWTYb9jSBXSGT77zjG2KO8WAPc ToxvBQV7Fz/323bkDwzvUnDl/yAkmu9njeLIfWDtqfwB31ODAs4=
=6aHi
-----END PGP SIGNATURE-----

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)

XPost: linux.debian.bugs.dist

Paul,

Thank you for the log sample! I have attached a patch that updates the
pattern matching for the moin event log processing for your review.

I do not believe the rotate-logs script is responsible for the malformed entries you are seeing. It also appears the original author was seeing
the errors, too, as indicated by a specific else clause meant to disgard such occurrences:

163: print "Ignoring malformed log line #" .$fh_in->input_line_number() . ": $line\n";

This particular clause was not being triggered due to the original regex
being a bit too greedy resulting in malformed timestamps being passed to gmtime().

The attached patch corrects the issue, but the script could use some
additional tidying up as it does have a few 'magic
numbers' scattered about which took some extra time for me to discern
their meaning. I didn't want to get too liberal with the modifications
and end up in refactor territority when all that was asked was to make
the errors go away :)

--
James Montgomery

From 5db19f4426a99e4b9c52491df2cad23afee26129 Mon Sep 17 00:00:00 2001
From: James Montgomery <james@onedev.org>
Date: Mon, 18 Sep 2017 21:11:34 -0400
Subject: [PATCH] Update regex match

---
bin/rotate-logs | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/bin/rotate-logs b/bin/rotate-logs
index 532e9a8..c171836 100755
--- a/bin/rotate-logs
+++ b/bin/rotate-logs
@@ -250,7 +250,7 @@ $gid = get_gid_by_name("wikiweb");
chdir $moin_logdir or die "Can't cd to $moin_logdir: $!\n";

rotate_log("edit-log", '^(\d+)\s+(\d+)\s+(\S+)\s+(\S)+\s+(\S+)', 'moin'); -rotate_log("event-log", '^(\d+)\s+(\S+)\s+(\S+)', 'moin'); +rotate_log("event-log", '^(\d{0,16})\s+(\S+)\s+(\S+)', 'moin');

chdir $local_logdir or die "Can't cd to $local_logdir: $!\n";

--
2.14.1

--- SoupGate-Win32 v1.05
* Origin: fsxNet Usenet Gateway (21:1/5)