More problems with server failing to process

So now my new Piwik installation is having problems processing data.

This setup is v1.9 on a machine with 12Gb of RAM, and I’ve allowed that site to use up to 2Gb for PHP, and unlimited run times, and after importing my latest batch of old logs, I’ve been unable to get it to process.

I keep getting the dreaded “500 Server error”, and it’s been nearly 24hrs that I haven’t been able to process.

This is what is in the error log most of the time


(104)Connection reset by peer: mod_fcgid: error reading data from FastCGI server
Premature end of script headers: index.php

When I’d tried changing it to run as something other than FastCGI, I would get file permissions problems, or errors saying that I’d exhausted the memory limit at 512Mb (when it’s actually set to 2Gb)

Will trying to run the archive.php from the shell get around this? Last time I tried to run it from the shell, it corrupted my database and I had to scrap everything and start all over.

Could it be some sort of .htaccess file issue?

nope, was working just fine before I imported another 1Gb of logs, and before I updated to v1.9

it’s like it can’t finish processing via the web interface. And yes, I’ve already cut down how many log entries to keep, lower than I’d like, actually, and with no improvement.

This is what happened a few months ago, and I ended up having to delete that entire setup, and create this new one, losing about 3 months worth of stats in the process.

I’m trying to avoid that in this case, because if I do it from the shell and it corrupts my database again, I’d lose another three months of analytics, and that would just make me cry :slight_smile:

can you update php to latest version?
also could you try using apache2 to see if it works better somehow?

already using Apache 2, have been for years, unless I’m misunderstanding what you mean?

Here’s what I’m using on the new machine:

Apache/2.2.15
mod_fcgid/2.3.7
PHP/5.3.3

Sorry not sure what the problem is, but I would search for this error on the internet:
(104)Connection reset by peer: mod_fcgid: error reading data from FastCGI server
Premature end of script headers: index.php

A quick search for that error under Virtualmin points the finger (several times) at inefficient mysql code as being the culprit, which are in turn causing php queries to hang and time out.

here’s the primary one, from about a year ago: CPU load averages | Virtualmin

is anyone else running Piwik under Virtualmin?

This server is configured with 4 CPUs and 12Gb RAM… I’d think that would be more than enough to handle Piwik for 6-10 websites, the largest of which is doing maybe 150k visitors per month.

Yes it should be more than enough for sure… What exactly is the SQL query that is problematic? can you enable mysql slow query logs?

Not sure what exactly the query is. I was manually importing old acces_log files, 100,000 to 200,000 entries at a time.

Then after each file, I’d have Piwik process the new data by reloading either the site page, or the All Websites page.

After adding one particular logfile, trying to reload that page would fail, giving me a 500 Server error result. It got so bad I had to disable that virtual server so the other websites on the server would go back to normal, so I’m not collecting Piwik stats. Again.

They are going to build me a separate virtual server that I’ll move this install to, but it’ll be a week or so before they can get to it, so it’ll have to wait until then before I can get back with anything concrete. I won’t enable the Piwik server where it is now because of how badly it choked off php resources for the other sites on the server.

When you have more info or steps to reproduce we can help. we run the log import on much more than 100k entries and it works fine… so maybe it’s data dependant or something else.

seems like my server is getting a few kernel patches plus an upgrade to 5.3.18 within the hour, so I’ll enable the Piwik site and see what happens :slight_smile:

okay, I decided to bit the bullet and try running archive.php from the command line.

This is what I get for the first site:


[2012-10-24 02:30:24] [9f31a182] Will process 12 websites
[2012-10-24 02:30:24] [9f31a182] ---------------------------
[2012-10-24 02:30:24] [9f31a182] START
[2012-10-24 02:30:24] [9f31a182] Starting Piwik reports archiving...
[2012-10-24 02:30:25] [9f31a182] Archived website id = 1, period = day, Time elapsed: 0.671s
[2012-10-24 02:35:07] [9f31a182] ERROR: Got invalid response from API request: /index.php?module=API&method=VisitsSummary.getVisits&idSite=1&period=week&date=last52&format=php&trigger=archivephp. The response was empty. This usually means a server error. This solution to this error is generally to increase the value of 'memory_limit' in your php.ini file. Please check your Web server Error Log file for more details.
[2012-10-24 02:35:07] [9f31a182] Archived website id = 1, period = week, 0 visits, Time elapsed: 281.976s
[2012-10-24 02:35:54] [9f31a182] Archived website id = 1, period = month, 407059 visits, Time elapsed: 47.443s
[2012-10-24 02:36:14] [9f31a182] Archived website id = 1, period = year, 407059 visits, Time elapsed: 19.644s
[2012-10-24 02:36:14] [9f31a182] Archived website id = 1, today = 0 visits, last days = 233775 visits, 4 API requests, Time elapsed: 349.734s [1/12 done]

The stats server is set to a 2Gb PHP limit, and an unlimited runtime.

Should I try it again, bumping that up yet again?

The good news is I can view my dashboards again :slight_smile:

okay… not sure what just happened, but I switched to processing the archive.php by cron, and now all my stats are vanishing.

this is crazy.

Set a higher timeout in the General Settings, for example 9000 seconds. Your stats should reappear.

What error is logged in your error log?

when I had to run archive.php manually, I was getting these:


Starting Piwik reports archiving...
Archived website id = 1, period = day, Time elapsed: 74.556s
Archived website id = 1, period = week, 486556 visits, Time elapsed: 66.503s
ERROR: Got invalid response from API request: /index.php?module=API&method=VisitsSummary.getVisits&idSite=1&period=month&date=last52&format=php&trigger=archivephp. Response was '<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN"> <html><head> <title>500 Internal Server Error</title> </head><body> <h1>Internal Server Error</h1> <p>The server encountered an internal error or misconfiguration and was unable to complete your request.</p> <p>Please contact the server administrator,  root@localhost and inform them of the time the error occurred, and anything you might have done that may have caused the error.</p> <p>More information about this error may be available in the server error log.</p> </body></html> '
Archived website id = 1, period = month, 0 visits, Time elapsed: 253.254s
ERROR: Got invalid response from API request: /index.php?module=API&method=VisitsSummary.getVisits&idSite=1&period=year&date=last52&format=php&trigger=archivephp. The response was empty. This usually means a server error. This solution to this error is generally to increase the value of 'memory_limit' in your php.ini file. Please check your Web server Error Log file for more details.
Archived website id = 1, period = year, 0 visits, Time elapsed: 249.967s
Archived website id = 1, today = 0 visits, last days = 313272 visits, 4 API requests, Time elapsed: 644.281s [1/12 done]

and the error log had:


(104)Connection reset by peer: mod_fcgid: error reading data from FastCGI server, referer: /index.php?module=SitesManager&action=index&idSite=1&period=month&date=today
Premature end of script headers: index.php, referer: /index.php?module=SitesManager&action=index&idSite=1&period=month&date=today

I think there may also be a bug in Virtualmin, because sometimes when I tell it to set the PHP max execution time to Unlimited, sometimes it interprets the 0 as 0 instead of Unlimited, and sometimes it respects the 0 as Unlimited… haven’t figured out the connection to which config is doing it wrong, but I was trying to avoid the problems that FastCGI has been giving me with this.

later, a new minor one popped up:


File does not exist: /home/piwikstats/public_html/themes/logo.png, referer: /index.php?module=CoreAdminHome&action=generalSettings

To set unlimited use 7200 for example (2 hours)

update: all 2012 access logs for my main site have been imported, and the site is now up to tracking live visitors (about 25Gb of data, 5 million lines at a time!).

The only issue that’s still unresolved is the failure to purge old visitor data. I’ve had it set to purge visitor log data every week for anything older than 120 days, but for the past 2 weeks it hasn’t purged anything.

The database is still hovering around 3Gb, and the settings page tells me I’ll save about 1.9Gb of space by removing visitor log data. I’d even tried a manual purge once, but that never completed.

Are there any other tricks I should try next?

Great news that you imported so much data in Piwik! Once you’re done with the project & happy with how it’s running, please get in touch by email we can use your experience for a White paper or Testimonial! would be great.

  • can you enable mysql slow query log and look what’s logged there after few days?
  • when purging fails does it show any error in server error logs ?

I’ll see what I can come up with for a procedural/white paper idea for you. My primary goal for this was to compare a year’s worth of actual access_log traffic to what Google Analytics had said we’d been doing for the past year, mostly because the numbers Google Analytics had been reporting were lower than the numbers of impressions that Google Adsense had said we were getting on those same pages, and Quantcast was reporting even lower metrics.

So we wanted a new solution, and the only way to compare was to see what the actual logs tracked, and see what the Piwik js tracked, then see how those both compare to GA and Quantcast, at least for November and December (comparing log data vs live tracking data).

What the import_logs.py did was crunch 25Gb of raw access_log data (in chunks, not one big bite) into about 3Gb of visitor data in the database. Not bad at all :slight_smile:

As for the visitor log purging, I do have slow query tracking on, but it’s not telling me anything useful yet. I have dozens of queries like this:


# Query_time: 10  Lock_time: 0  Rows_sent: 0  Rows_examined: 0
LOAD DATA LOCAL INFILE 
					'/tmp/assets/piwik_archive_blob_2012_01-aa52ede77e7cabbda103a4042a9144f7.csv'
			REPLACE
			INTO TABLE
				piwik_archive_blob_2012_01
			FIELDS TERMINATED BY
				'	'
			ENCLOSED BY
				'"'
		 ESCAPED BY '\\'
			LINES TERMINATED BY
				'
'
			(idarchive,idsite,date1,date2,period,ts_archived,name,value);

complete with the weird tabs, plus several like this:


# Query_time: 18  Lock_time: 0  Rows_sent: 0  Rows_examined: 0
DELETE 
    						FROM piwik_archive_blob_2012_01
    						WHERE idarchive IN (803,802,801,800,820,819,818,817,816,815,814,813,804,805,806,807,808,809,810,811,812);

and this:


# Query_time: 16  Lock_time: 0  Rows_sent: 1  Rows_examined: 5969945
SELECT COUNT(*) FROM piwik_log_link_visit_action WHERE idvisit <= '1364813';

# Query_time: 202  Lock_time: 0  Rows_sent: 1  Rows_examined: 12910042
SELECT COUNT(*) FROM piwik_log_link_visit_action WHERE idvisit <= '2376138';

# Query_time: 17  Lock_time: 0  Rows_sent: 1  Rows_examined: 2324618
SELECT COUNT(*) FROM piwik_log_visit WHERE idvisit <= '2376138';

# Query_time: 200  Lock_time: 0  Rows_sent: 1  Rows_examined: 12810320
SELECT COUNT(*) FROM piwik_log_link_visit_action WHERE idvisit <= '2376138';

# Query_time: 213  Lock_time: 0  Rows_sent: 1  Rows_examined: 12641093
SELECT COUNT(*) FROM piwik_log_link_visit_action WHERE idvisit <= '2376138';

but there’s nothing in the error logs at all. Also, currently have archiving done by cron, every 7200 seconds.

Also, I see a lot of entries for DELETE FROM piwik_archive_blob_2012_somedate, but nothing for deleting visitor logs…

I thought that with the “regularly delete old visitor logs” set to “yes”, and “regularly delete old reports” set to “no”, that would clear out the visitor logs but leave the data (in the blob tables) be… is my understanding of that correct?

Thanks for the details. yes you’re correct it should work and we should see query in the slow query logs. Sorry I’m not sure what to do from here. I could debug on your server etc. but would take some time wihch is lacking unfortunately :frowning:

let us know if you find anything more!