Error in Generating TimeSheet Detail Report

Topics brought up by the TimeTrex open source community.
Post Reply
joshsard
Posts: 55
Joined: Sun Feb 14, 2016 6:09 pm

Error in Generating TimeSheet Detail Report

Post by joshsard »

Hi,

I would like to ask for your help regarding an issue we have on our TimeTrex application.
When we try to generate a report using the TimeSheet Detail Report, we get the following error:

502 Proxy Error
The proxy server received an invalid response from an upstream server
The proxy server could not handle the request
Reason: Error reading from remote server

Our original issue was the report is displaying that we should 'reduce the size of the report'. Since then, we have been changing settings in php, apache and postgresql (also upgraded memory and cpu too) continuously with trial and error testing, and still have no true improvements.

Then we discovered a file inside TimeTrex called Report.class.php, where we increased values like below:
'maximum_page_limit' => 900 (orig 100)
'query_statement_timeout' => 3600000 (orig 600000)
'maximum_memory_limit' => '4096M' (orig 1024M)
'maximum_execution_limit' => 36000 (orig 1800)

This is our latest change, and could have affected the current proxy error below.
What could be the cause of this?

Also I would like to note that we have two environments, Test and Prod, which are both version 9.0.2 but what's weird is they have the same settings in the Report.class.php but the Test env can produce a big filesize of the report, but the Prod could not.
shaunw
Posts: 7839
Joined: Tue Sep 19, 2006 2:22 pm

Re: Error in Generating TimeSheet Detail Report

Post by shaunw »

First I would recommend upgrading to the latest version of TimeTrex, if its an issue with TimeTrex its likely already corrected in the latest version.

Next, you need to get error logs from your server, either TimeTrex, Apache or PHP error logs (better yet, all three). Anytime you have problems 99% of the time the error logs will tell you exactly what the problem is and often how to fix it. Without those we have nothing to go on.
joshsard
Posts: 55
Joined: Sun Feb 14, 2016 6:09 pm

Re: Error in Generating TimeSheet Detail Report

Post by joshsard »

We already created a separate TimeTrex test server which is the later version (9.1.3), and loaded our prod data there and ran the report, it still does not work.
joshsard
Posts: 55
Joined: Sun Feb 14, 2016 6:09 pm

Re: Error in Generating TimeSheet Detail Report

Post by joshsard »

Hi,

I would like to add additional information while debugging the report through the Chrome browser:
NOT OK:
timesheet_detail_report.png
There was no error pop-up like before (ERROR: Please try again later or narrow your search criteria to decrease the size of your report). But the excel is not generated, aka nothing happens after the progress bars are finished.

The screenshot above shows a proxy error when grouping the data. The link when clicked show the json text below:
{"api_retval":false,"api_details":{"code":"VALIDATION","description":"INVALID DATA","record_details":{"total":1,"valid":0,"invalid":1},"user_generic_status_batch_id":false,"details":[{"time_period":["No time period defined for this report"],"columns":["No columns specified to display on report"]}]}}

But what's weird is the same link/log shows after a successful generation of excel report, but chosen date range is different. See below:
OK:
timesheet_detail_report_ok.png
This time the link has no red font, and has no proxy error.
joshsard
Posts: 55
Joined: Sun Feb 14, 2016 6:09 pm

Re: Error in Generating TimeSheet Detail Report

Post by joshsard »

Hi,

I found another interesting log in /var/log/timetrex/php_errors.log:

Code: Select all

Allowed memory size of 2425131008 bytes exhausted (tried to allocate 1024 bytes) in /home/timetrex/timetrex/classes/modules/report/TimesheetDetailReport.class.php on line 1294
the line contains:

Code: Select all

if ( strpos($format, 'pdf_') === FALSE ) {
      $this->data[] = array_merge( $this->tmp_data['user'][$user_id], $tmp_default_branch, $tmp_default_department, $tmp_branch, $tmp_department, $row, $date_columns, $hire_date_columns, $processed_data );
}
shaunw
Posts: 7839
Joined: Tue Sep 19, 2006 2:22 pm

Re: Error in Generating TimeSheet Detail Report

Post by shaunw »

This is the issue of course:
Allowed memory size of 2,425,131,008 bytes exhausted (tried to allocate 1024 bytes) in /home/timetrex/timetrex/classes/modules/report/TimesheetDetailReport.class.php on line 1294
Your PHP memory limit is 2.4GB and the report that you are trying to run requires more memory than that, therefore PHP is killing the process to avoid going over the memory limit.

You will need to increase the memory limit further (keep in mind if you are running a 32bit version of PHP, around 2GB is the maximum memory that can ever be used), or restrict the criteria on your report to return less data such that it doesn't exceed the memory limit.
joshsard
Posts: 55
Joined: Sun Feb 14, 2016 6:09 pm

Re: Error in Generating TimeSheet Detail Report

Post by joshsard »

But we already changed the setting of php.ini to below:

Code: Select all

memory_limit = 4096M
Our IT admin said that the PHP installed is 64-bit, and our server too is 64-bit.
joshsard
Posts: 55
Joined: Sun Feb 14, 2016 6:09 pm

Re: Error in Generating TimeSheet Detail Report

Post by joshsard »

Update:

We even disabled the memory limit by setting -1 to the above setting, but the excel still does not generate.
Note that in our production, we could only generate the TimeSheetDetail Report when the time period date range is 4 days or lower.
The problem is when the time period date range is 5 days or higher, we encounter errors or no response at all (no file shows up).

Thanks
joshsard
Posts: 55
Joined: Sun Feb 14, 2016 6:09 pm

Re: Error in Generating TimeSheet Detail Report

Post by joshsard »

Update again:

This is the link that produces the error message after the report generation failed:

api/json/api.php?Class=APITimesheetDetailReport&Method=getTimesheetDetailReport&MessageID=7347e925-463e-03e8-c81d-595819a2c72e

How can I use this 'MessageID' to get the correct info?

The link when opened, shows a page reading:
Proxy Error
The proxy server received an invalid response from an upstream server.
The proxy server could not handle the request GET /api/json/api.php.
Reason: Error reading from remote server

Hope this helps.
joshsard
Posts: 55
Joined: Sun Feb 14, 2016 6:09 pm

Re: Error in Generating TimeSheet Detail Report

Post by joshsard »

Hi guys,

Unfortunately, we still have the issue, but I have seen an interesting bit from the log file:

Code: Select all

DEBUG [L2048] [21643ms]: Report::_output(): Format: csv
DEBUG [L2024] [21785ms]: Report::getOutput():  Format: csv Total Time: 21.75560092926 Memory Usage: Current: 45448072 Peak: 411158848
DEBUG [L2025] [21786ms] Array: Report::getOutput():  Profile Timers: 
string(1086) "<pre>
============================================================================
								PROFILER OUTPUT
============================================================================
Calls					 Time  Routine
-----------------------------------------------------------------------------
  1	2.9559 ms (0.01 %)	 Authentication::Check()
 40	5.1248 ms (0.02 %)	 Column Width
  1	2367.2380 ms (10.87 %)	 Group()
  1	8.7221 ms (0.04 %)	 PDF
  1	838.7790 ms (3.85 %)	 Sort()
 82	38.8145 ms (0.18 %)	 __autoload
  1	9.1059 ms (0.04 %)	 currencyConvertToBase
  1	5720.7990 ms (26.26 %)	 getData
 16	3.4194 ms (0.02 %)	 getEmptyRecordSet()
  1	160.8000 ms (0.74 %)	 getLargestColumnData
  1	449.7919 ms (2.06 %)	 group
  1	746.5389 ms (3.43 %)	 postProcess
  1	11229.7690 ms (51.55 %)	 preProcess
  1	47.5287 ms (0.22 %)	 sort
  1	9.2380 ms (0.04 %)	 unprofiled

		144.8889 ms (0.67 %)	 Missed
============================================================================
		21783.5140 ms (100.00 %)	 OVERALL TIME
============================================================================
</pre>"


DEBUG [L0166] [21786ms]: authenticatedInvokeService(): NULL return value, not JSON encoding any additional data.
DEBUG [L0289] [21786ms]: [Function](): Server Response Time: 21.785743951797
What does the pre-process do? It seems like it takes a long time to run.
joshsard
Posts: 55
Joined: Sun Feb 14, 2016 6:09 pm

Re: Error in Generating TimeSheet Detail Report

Post by joshsard »

hi,

i would like to follow up on this, i've put the logs in my previous reply.

thanks
joshsard
Posts: 55
Joined: Sun Feb 14, 2016 6:09 pm

Re: Error in Generating TimeSheet Detail Report

Post by joshsard »

Hi,

There was a finding when we open google chrome dev tools while running the report:
Prod Console Timetrex.png
The red font was being shown in the log when the report is not generated. I believe that is a network related issue.
We only get this in production environment which virtually has the same php, apache and postgresql settings as the one in test where the report is running.

Thanks
shaunw
Posts: 7839
Joined: Tue Sep 19, 2006 2:22 pm

Re: Error in Generating TimeSheet Detail Report

Post by shaunw »

The error itself is "proxy error", have you tried accessing TimeTrex without going through a proxy to see if that makes any difference?
joshsard
Posts: 55
Joined: Sun Feb 14, 2016 6:09 pm

Re: Error in Generating TimeSheet Detail Report

Post by joshsard »

Our sysadmin told me there were no proxy used :(
Do u happen to know if there are timetrex-specific settings relating to proxies?
shaunw
Posts: 7839
Joined: Tue Sep 19, 2006 2:22 pm

Re: Error in Generating TimeSheet Detail Report

Post by shaunw »

Are you still seeing a PHP memory error in your PHP error logs when this issue happens? If so, that is where you need to focus your efforts.
joshsard
Posts: 55
Joined: Sun Feb 14, 2016 6:09 pm

Re: Error in Generating TimeSheet Detail Report

Post by joshsard »

Hi,

The timetrex log only shows same logs like: “Load average within valid limits” from both Test and Prod, although the values from prod is higher than test:
[Test]
DEBUG [L1975] [35967ms]: Misc::isSystemLoadValid(): Load average within valid limits: Current: 0.58 Max: 9999

[Prod]
DEBUG [L1975] [41631ms]: Misc::isSystemLoadValid(): Load average within valid limits: Current: 2.51 Max: 9999

Also I saw one difference in logs seen below, but I think this is OK:

[Test]
DEBUG [L1939] [00056ms]: Misc::getSystemMemoryInfo(): Memory Info: Free: 1257533440b Cached: 6264193024b
DEBUG [L0349] [00056ms]: Report::setExecutionMemoryLimit(): Setting hard memory limit to: 5955678208 Soft Limit: 4294967296 Based on: 4096M
DEBUG [L0101] [00056ms]: ProgressBar::start(): start: 'ef62fb13-5ab4-21be-2deb-a35073106220' Iterations: 2 Update Iterations: Key: ef62fb13-5ab4-21be-2deb-a35073106220(1477290502.4158) Message: Querying Database...
DEBUG [L1890] [00057ms]: Report::setQueryStatementTimeout(): Setting Report DB query statement timeout to: 3600000

[Production]
DEBUG [L1939] [00077ms]: Misc::getSystemMemoryInfo(): Memory Info: Free: 609734656b Cached: 4829327360b
DEBUG [L0345] [00077ms]: Report::setExecutionMemoryLimit(): Available memory is less than maximum, reducing to: 4231730176 Max Memory: 4294967296
DEBUG [L0349] [00077ms]: Report::setExecutionMemoryLimit(): Setting hard memory limit to: 4231730176 Soft Limit: 4231730176 Based on: 4096M
DEBUG [L0101] [00077ms]: ProgressBar::start(): start: '609532a4-3069-8688-5d44-17d7eabe4010' Iterations: 2 Update Iterations: Key: 609532a4-3069-8688-5d44-17d7eabe4010(1477291156.2051) Message: Querying Database...
DEBUG [L1891] [00078ms]: Report::setQueryStatementTimeout(): Setting Report DB query statement timeout to: 3600000

In summary, there are ample memory to process the report, according to the timetrex log.
shaunw
Posts: 7839
Joined: Tue Sep 19, 2006 2:22 pm

Re: Error in Generating TimeSheet Detail Report

Post by shaunw »

You are saying their is ample memory, but the original error message you provided was:
Allowed memory size of 2425131008 bytes exhausted (tried to allocate 1024 bytes) in /home/timetrex/timetrex/classes/modules/report/TimesheetDetailReport.class.php on line 1294
So is that error still happening, and if not, what error message are you seeing your PHP error log now?
Post Reply