Guru: The PHP Path To Victory, Part 2
August 7, 2017 Chris Ringer
Part 1 of this article discussed the path a PHP request takes on its way to your backend RPG program through the magic of an external SQL stored procedure. You may need to review the SQL, PHP, and RPG code there before continuing here. If you have not yet downloaded the code to your IBM i (found in Part 1), now would be a good time to do that.
Part 2 will give you the confidence to troubleshoot those times when something unexpected occurs in this PHP environment. And if you are a developer for large company, the responsibility of installing your applications may actually fall to an operations department when the system is in a restricted state. They may benefit from this information, too, since some configurations involve security.
Injury Report
Errors and warnings could be listed in four different places, which I indicate with these labels:
- Chrome: Any output in the browser from the browser itself or the Apache server or a PHP script. In some cases, Microsoft Internet Explorer (MSIE) displays a different error than Chrome and that error is also listed.
- Apache Log: Messages logged by the Apache server on the IFS.
- PHP Log: Messages logged by Zend Server in the PHP log file on the IFS.
- Job Log: Messages written to IBM i job logs.
As I alluded to in Part 1, certain subsystems and related jobs must be active for a PHP request to be processed. If the Apache server ZENDSVR6 jobs are not active (Figure 1) or the ZENDSVR6 subsystem is not active (Figure 2), the PHP request will fail with an error similar to this:
- Chrome: This site can’t be reached. YourSystem.com refused to connect.
- MSIE: This page can’t be displayed. Make sure the web address “http://YourSystem.com:10080” is correct.
Figure 1 – QHTTPSVR Subsystem ZENDSVR6 jobs.
Figure 2 – ZENDSVR6 Subsystem Active Jobs.
The remedy is to start those jobs with options 1 and 5 on the Zend Server menu (Figure 3). And, of course, the QSYSWRK subsystem should also have QSQSRVR jobs active (Figure 4) to execute SQL statements.
Figure 3 – Zend Server Menu.
Figure 4 – QSYSWRK Subsystem Active Jobs.
Another possibility is that you are using the wrong port number (“telephone extension”) in the URL. The Zend Server default is port 10080 but if you type http://YourSystem.com:10999/cust600.php you will likely receive this error:
- Chrome: This site can’t be reached. YourSystem.com took too long to respond.
- MSIE: This page can’t be displayed – Make sure the web address http://YourSystem.com:10999 is correct.
Use the Display File (DSPF) command to see which ports Apache is listening to.
DSPF '/www/zendsvr6/conf/httpd.conf'
You will see a second port number listed. Port 10081 is normally used for the Zend Server Admin interface.
Listen *:10080 Listen *:10081
If you try the following two URLs in the browser, use the port number (from httpd.conf) that outputs the “Congrats” message here to Chrome.
http://YourSystem.com:10080
Chrome: Congrats! Zend Server is now up and running
http://YourSystem.com:10081
Chrome: Login to your account
To verify that Apache is listening on that port number, do this from an IBM i command line:
- Type NETSTAT *CNN .
- Press F14 to display port numbers.
- Press F13 to sort by column and select a local port.
- Page down to find the local port, again probably 10080, in the list (Figure 5).
Figure 5 – Connection Status Ports.
Minimize The Turnovers
When a PHP script is parsed by the Zend Server PHP engine and executes, where do you look for problems? That would be the php.log. This file’s contents are similar to QSYSOPR messages and the QHST history log but mostly errors and warnings are logged here at the end (bottom) of the file. Use the Display File (DSPF) command to view the log.
DSPF '/usr/local/zendsvr6/var/log/php.log'
For example, the sample PHP script in Part 1 contains the following line:
// echo $myUndefinedVar ;
If you were to uncomment that line, the echo would reference an undeclared variable. After running the script via the URL, the bottom of the php.log would contain this warning:
PHP Notice: Undefined variable: myUndefinedVar in /www/zendsvr6/htdocs/cust600.php on line 11
You must trap and log some errors yourself. Our sample PHP script echoes “scary” diagnostic errors directly back to the browser. A more secure practice is to echo a general error to the client (browser) and write the specific error yourself to the php.log.
echo 'An error occurred! The IT department will review this.' ;
$errMsg = __FILE__ . ' ' . __FUNCTION__ . ' ERROR! Problem connecting to DB2: ' .
db2_conn_error() . ' ' . db2_conn_errormsg() ;
error_log($errMsg) ;
Cut From The Roster
If a browser requests a PHP script or HTML document that does not exist, the response will be the infamous HTTP 404 “Not found” error. To generate this error, enter a URL in a browser for a non-existent PHP script such as this:
http://YourSystem.com:10080/cust600Bad.php
Because this is not requesting a static HTML document, the browser output may not be what you expect. You can also see the 404 response in the Apache access log.
- Chrome: No input file specified.
- MSIE: HTTP 404 Not Found – The webpage cannot be found
- Apache access log: “GET /cust600Bad.php HTTP/1..1” 404
The Apache logs are stored in directory /www/zendsvr6/logs. New files are automatically created daily, the names of which contain the current system date in format YYMMDD, where YY, MM, DD are the two-digit year, month, and day (Figure 6). The access log is a list of each incoming HTTP request. The error log contains errors and warnings. Use the Work with Links (WRKLNK) command to view logs. For example, here’s how to view logs for February 10, 2017:
WRKLNK '/www/zendsvr6/logs/*170210*'
Use option 5 to display the file. New messages are stored at the end of each file.
Figure 6 – Apache Logs.
Shot Rejected!
When our sample PHP request arrives, Apache will do at least five authority checks on this IFS path
/www/zendsvr6/htdocs/cust600.php for user profile QTMHHTTP. If any of those authority checks fail, the PHP request is never executed.
User profile QTMHHTTP needs *X (Execute) authority to these four directories, checked in this order:
- /
- /www
- /www/zendsvr6
- /www/zendsvr6/htdocs
Execute authority allows a user profile to use a directory. Without it, the errors for the first three directories listed above are:
- Chrome: Forbidden: You do not have permission to access /cust600.php on this server.
- MSIE: HTTP 403 Forbidden – The website declined to show this webpage
- Apache error log: [error] (3401) Permission denied.: ZSRV_MSG064B: access to /cust600.php denied
So what’s different about the htdocs directory? Well, now we are in the realm of the Apache document root (see Part 1.) Apache allows an optional configuration override file named .htaccess in directories, and QTMHHTTP does not have the authority to look for that file in htdocs. Even though the error messages are different in this case, the bottom line is the same in that QTMHHTTP needs *X Execute authority to the htdocs folder. And if .htaccess does exist, user profile QTMHHTTP needs *R Read authority to it.
- Chrome: Forbidden – access to file is never allowed [no ACL file].
- MSIE: HTTP 403 Forbidden – The website declined to show this webpage
- Apache error log: [crit] (3401)Permission denied.: ZSRV_MSG0014: Error opening htaccess file /www/zendsvr6/htdocs/.htaccess. Error: Permission denied.
You can edit authorities with the Work with Authority (WRKAUT) command (Figure 7)
WRKAUT '/www/zendsvr6'
Figure 7 – Work with Authority.
The final authority check is to the PHP script cust600.php in the htdocs directory. User profile QTMHHTTP needs *R (Read) authority to open that file. The 403 in the Apache access message below is the HTTP status meaning Forbidden.
- Chrome: Access denied.
- MSIE: HTTP 403 Forbidden – The website declined to show this webpage
- Apache access log: “GET /cust600.php HTTP/1.1” 403
Bad Pass
Here we get a connection to DB2, which is needed downstream to call the SQL stored procedure.
$conn = db2_pconnect('*LOCAL','','',$connArray) ;
If db2_pconnect() fails, most likely the user profile and password credentials are invalid or the user profile is disabled. The second and third parameters in this function are the user profile and password respectively.
- Chrome: /www/zendsvr6/htdocs/cust600.php getConn ERROR! Problem connecting:
08001 SQLSTATE=08001 SQLCODE=-30082 Authorization failure on distributed database connection attempt. - log : Same as Chrome since our PHP script created the message.
- QHTTPSVR ZENDSVR6 Job Log: SQ30082 Authorization failure on distributed database connection attempt.
To automatically connect as user profile QTMHHTTP, the user profile and password parameters must be empty strings. This predefined IBM profile seems to connect just fine, even when *DISABLED, which makes sense. You wouldn’t want someone to be able to shut down your PHP scripts by typing incorrect passwords for QTMHHTTP at a sign-on screen.
Prepare To Succeed
The PHP script now prepares an SQL statement to later call our external stored procedure.
$callString = 'CALL CUST600SP(?,?,?,?)' ; $stmt = db2_prepare($conn, $callString) ;
A stored procedure definition is saved in the system table SYSROUTINE, keyed by the library (schema) and the stored procedure name. In our case, those values are YOURLIB and CUST600SP. However, our CALL statement above does not qualify a library. Therefore each library name in the library list will be checked for a match in SYSROUTINE (Figure 8). If no match is found, the errors are:
- Chrome: Preparing Statement Failed: 42704 SQLSTATE=42704 SQLCODE=-204 CUST600SP in *N type *N not found.
- log: PHP Warning: db2_prepare() Statement Prepare Failed in /www/zendsvr6/htdocs/cust600.php on line 47
Figure 8 – Finding SYSROUTINE Row with Library List.
If a stored procedure name is found in the SYSROUTINE table but without those same parameter definitions (i.e. no matching parameter signature in the corresponding SYSPARMS system table), the errors are:
- Chrome: Preparing Statement Failed: 42884 SQLSTATE=42884 SQLCODE=-440 Routine CUST600SP in *N not found with specified parameters.
- log PHP Warning: db2_prepare(): Statement Prepare Failed in /www/zendsvr6/htdocs/cust600.php on line 47
You could simply add a fifth parameter marker to force this error.
$callString = 'CALL CUST600SP(?,?,?,?,?)' ;
Poor Execution
Now we are ready to execute the SQL stored procedure.
$status = db2_execute($stmt) ;
If the external program (in this case, the RPG program CUST600SP) is not found in library list, the errors are:
- Chrome: SQL Execute error: 42724 SQLSTATE=42724 SQLCODE=-444 External program CUST600SP in *LIBL not found.
- log: PHP Warning: db2_execute(): Statement Execute Failed in /www/zendsvr6/htdocs/cust600.php on line 69
Just rename the CUST600SP program and refresh the browser to create this scenario.
And if the connecting user profile is not authorized to the program, the errors are:
- Chrome: SQL Execute error: 42501 SQLSTATE=42501 SQLCODE=-551 Not authorized to object CUST600SP in *LIBL type *PGM.
- log: PHP Warning: db2_execute(): Statement Execute Failed in /www/zendsvr6/htdocs/cust600.php on line 69
To create this scenario, set the authority for CUST600SP *PGM to *EXCLUDE for the connecting user profile. Normally this authority needs to be *USE (or minimally just “Execute”) authority.
EDTOBJAUT OBJ(CUST600SP) OBJTYPE(*PGM)
If a PHP value is too large to fit into a stored procedure parameter, this will cause an error too. The sort order parameter is defined as 10a. If a user entered a sort value in the URL as sort=unitedstates, which is 12 characters long, this may cause a run time error unless you prevent it. Check the string length this way:
if ( strlen($tempSort) >= 1 && strlen($tempSort) <= 10 ) {
Otherwise the errors are:
- Chrome: SQL Execute error: 22001 SQLSTATE=22001 SQLCODE=-302 Conversion error on variable or parameter *N.
- log: PHP Warning: db2_execute(): Statement Execute Failed in /www/zendsvr6/htdocs/cust600.php on line 69
Out Of Bounds
If you review our stored procedure, you will see that it requires four parameters, so PHP should bind to the same number and types of parameters. If you were to comment out the binding of the fourth parameter in the PHP script, like this:
// db2_bind_param($stmt, 4, 'oJobInfo', DB2_PARAM_OUT) ;
The refreshed the browser, the errors would be:
- Chrome: SQL Execute error: 07001 SQLSTATE=07001 SQLCODE=-313 Number of host variables not valid.
- log: PHP Warning: db2_execute(): More parameters bound than present in /www/zendsvr6/htdocs/cust600.php on line 69
- log: PHP Warning: db2_execute(): Statement Execute Failed in /www/zendsvr6/htdocs/cust600.php on line 69
- QHTTPSVR ZENDSVR6 Job Log: SQ99999 Error occurred in SQL Call Level Interface. 9 — Argument value not valid.
And conversely, coding an additional fifth bound parameter would also generate warnings, but the PHP script would still run and return the customer data.
db2_bind_param($stmt, 5, 'junk5th', DB2_PARAM_OUT) ;
The generated errors are:
- log: PHP Warning: db2_bind_param(): Describe Param Failed in /www/zendsvr6/htdocs/cust600.php on line 60
- QHTTPSVR ZENDSVR6 Job Log: SQ99999 Error occurred in SQL Call Level Interface. 9 — Argument value not valid.
A Full Timeout
A PHP script has a limited number of seconds in which to return a response to the client. This value is defined in the php.ini file. Think of this file as system values for PHP. The full path is /usr/local/zendsvr6/etc/php.ini and the value is defined with this statement, in seconds.
max_execution_time = 30
A PHP script can override this value with the set-time-limit() function, which adds additional seconds to that maximum run time. In reality though, a PHP script will usually not time out because system calls are not included in the total run time. In our case, the maximum run seconds of the QSQSRVR helper job is controlled by a different configuration setting in file /www/zendsvr6/conf/fastcgi.conf.
RequestTimeout="60"
If you put the CUST600SP RPG program in debug with STRSRVJOB/STRDBG, set a breakpoint, and run the PHP script, it will stop at the breakpoint. Do nothing else, and after about 60 seconds, the errors will be:
- Chrome: 408 Request Time-out. Server timeout waiting for the HTTP request from the client.
- MSIE: HTTP 408/409 – The website is too busy to show the webpage
- log: PHP Fatal error: Maximum execution time of 60 seconds exceeded in /www/zendsvr6/htdocs/cust600.php on line 69
Sixty seconds seems like an eternity, but you may get this error if someone set the value too low or if a stored procedure halted with an error. If you change the RequestTimeout value, restart the QHTTPSVR subsystem ZENDSVR6 jobs.
Box Score
Obviously, I could not cover all the possible error conditions but you should be equipped with enough knowledge now to handle these particular problems. Any new PHP issues that come your way will hopefully be revealed in the logs.
