Ubuntu
ampache package

When logging is enabled, web pages display "Unable to write to log"

Bug #722274 reported by Jim Patterson
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
ampache (Ubuntu)
Fix Released
Undecided
Charlie_Smotherman

Bug Description

I've installed Ampache from the Ubuntu Maverick repository (version 3.5.4-7ubuntu1). It has a problem, though. When I visit my "ampache" web site, hosted in Apache 2.2 (also from the repository), each page is plastered with messages like:

    Unable to write to log (/var/log/ampache/ampache.20110219.log) Please check your log_path variable in ampache.cfg.php

This problem occurs only once I enabled logging through ampache.cfg.php:
    debug="true";
    log_path="/var/log/ampache";
It also only happens after the system has been sitting for a day (so that the daily catalog update job gets run). Even then it's not for certain. The update job has to run first that day; if the web site gets hit first, then all is fine.

My web site is not public, but you can see identical behaviour on this site, which I found through Google (nothing to do with me):

http://spacemachines.net/ampache/localplay.php?action=show_playlist

** Warning ** you're likely violating someone's intellectual property rights if you actually try to play a song from this site.

The underlying problem is that the log file is created each day by user/group root/root, but Apache of course runs as user/group www-data/www-data. My guess as to why this happens is because ampache is set up with a cron job as well, and it's creating the log file first (as it is a php script that pulls in the same Ampache configuration script). Here are some directory lists to show the log file situation:

drwxrwxr-x 3 www-data www-data 12288 2011-02-20 12:45 /var/log/ampache
-rw-r--r-- 1 root root 6537 2011-02-15 22:06 /var/log/ampache/ampache.20110215.log
-rw-r--r-- 1 root root 582053 2011-02-15 22:06 /var/log/ampache/ampache-catalog.20110215.log

A possible solution is to replace the command at the end of /etc/cron.daily/ampache with this command. This should work for both Apache and lighttpd web servers, but will fail if the log directory is moved from its default:
    logowner=$(ls -dl /var/log/ampache | sed 's/^d......... [0-9]\+ \([^ ]\+\) .*/\1/')
    sudo -u ${logowner} php /usr/share/ampache/www/bin/catalog_update.inc -a -c

Charlie_Smotherman (cjsmo)
Changed in ampache (Ubuntu):
status: New → In Progress
assignee: nobody → Charlie_Smotherman (porthose) (cjsmo)
Revision history for this message
Charlie_Smotherman (cjsmo) wrote :

Jim,

Thank you for the bug report.

If you have a look at 3.5.4-8ubuntu1, I have setup the package maintainer scripts to set /var/log/ampache to be owned by www-data:www-data, and so far I have not had any problems with ampache writing to logs even when manually invoking /usr/share/ampache/www/bin/catalog_update.inc. I also patched log.lib.php to remove the date so ampache only creates ampache-catalog.log and ampache.log for some reason logrotate was chocking on the date being in the log file name.

http://bazaar.launchpad.net/~ubuntu-branches/ubuntu/natty/ampache/natty/view/head:/debian/patches/logrotate_fix.patch

So the net result is that www-data owns /var/log/ampache, log.lib.php has been patched to remove the date in the log file names, ampache continually appends ampache.log, and ampache-catalog.log until logrotate grabs ampache.log and ampache-catalog.log, ranames and compresses the log files, logrotate has been setup to rotate the logs daily with logs older that 7days get deleted/shredded.

Actually this bug should be set to fixed-released (since this has been fixed in the current development branch) but I would like to keep it open for further discussion.

There is a sync request for 3.5.4-11 to be synced over from debian.

https://bugs.launchpad.net/ubuntu/+source/ampache/+bug/721412

Revision history for this message
Jim Patterson (jimp-launchpad-rs9z) wrote :

This bug seems to be a "next day" kind of thing. I only see it after coming back to the system from not working on it for a while. If you stop Apache, manually remove the latest log files, then run catalog_update.inc and finally restart apache, then as long as logging was enabled, I think you'll be able to reproduce the bug. That's a bit easier to set up than the actual circumstance, which seems to happen if the catalog update job gets run before anyone or anything hits the ampache web site on a given day.

I don't think removing the current date from the log file name will rectify the problem. If logrotate is periodically compressing and renaming log files, there will still be a window after a logrotate operation where catalog_update.inc could be run and trigger the issue. The key factor here is whether the log files exist when this job runs. If they aren't, and if any logging is done, then the log files will end up being owned by root/root instead of www-data/www-data.

Revision history for this message
Charlie_Smotherman (cjsmo) wrote : Re: [Bug 722274] Re: When logging is enabled, web pages display "Unable to write to log"

Jim,

On Sun, Feb 20, 2011 at 5:34 PM, Jim Patterson
<email address hidden> wrote:
> This bug seems to be a "next day" kind of thing. I only see it after
> coming back to the system from not working on it for a while. If you
> stop Apache, manually remove the latest log files, then run
> catalog_update.inc and finally restart apache, then as long as logging
> was enabled, I think you'll be able to reproduce the bug. That's a bit
> easier to set up than the actual circumstance, which seems to happen if
> the catalog update job gets run before anyone or anything hits the
> ampache web site on a given day.

This is indeed a unusual use case (my home server never gets
shutdown). I will set this up in a vm tonight to see if I can
reproduce this behavior in the current development branch.
>
> I don't think removing the current date from the log file name will
> rectify the problem.

As stated earlier, the date was removed so logrotate can operate correctly

If logrotate is periodically compressing and
> renaming log files, there will still be a window after a logrotate
> operation where catalog_update.inc could be run and trigger the issue.
> The key factor here is whether the log files exist when this job runs.
> If they aren't, and if any logging is done, then the log files will end
> up being owned by root/root instead of www-data/www-data.

If need be the catalog_update.inc cron job can be removed, as this is
not a critical feature for ampache to operate.

Charlie Smotherman

--
Charlie Smotherman
Debian Contributor
Ubuntu Developer

Revision history for this message
Charlie_Smotherman (cjsmo) wrote :

I have added your patch to the packaging branch, setting bug to fix committed.

Changed in ampache (Ubuntu):
status: In Progress → Fix Committed
Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package ampache - 3.5.4-11ubuntu1

---------------
ampache (3.5.4-11ubuntu1) oneiric; urgency=low

  * Added postrotate stanza to debian/ampache.logrotate. Logrotate rotates
    logs as root, the postrotate stanza reverts ownership of /var/log/ampache
    back to www-data so the webserver and subsequently ampache can write to
    the needed logs. (LP: #722274)
 -- Charlie Smotherman <email address hidden> Sat, 14 May 2011 16:20:44 -0500

Changed in ampache (Ubuntu):
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Related questions

Remote bug watches

Bug watches keep track of this bug in other bug trackers.