Hello Mike,

I have some trouble trying ti generate a PDF on Centos 6.6 with a php server.

I set up this prince version prince-10r7-centos6-x86_64.tar.gz and your last version of php wrapper.

Whenever I start to run my code the process seems to be stuck in an infinite loop and I can't get any $result = true from the method convert_file_to_file. Also setting the log method don't write in the log file.

Here my code sample

$file = "/somepath/randomid.html'; #We have to have a tmp files, multiples request could be done at the same time

file_put_contents($file, $html);
$errors = array();
$pdfFileName="some name";
$prince = new Prince($princePath);
if(!$prince) die("Prince instantiation failed");

$prince->setLog("/u01/app/apache/htdocs/prince.log"); # I don't get any logs written in this file
$prince->setInputType('html');
$prince->setHTML(true);
$prince->addStyleSheet('somecssfile.css');

$returnVar = $prince->convert_file_to_file($file, $pdfFileName, $errors);

I went through the php wrapper's code and the issue seems to be coming from the convert_internal_file_to_file function.

After running the command with proc_open, readmessage() I have some messages in the pipes[2]. PLease see attached the logs. But it did not go to the end of the process and I neither failure nor success...
I had to write this code to be able to log something.

$log= "line  $line\n";
 file_put_contents('/u01/app/apache/htdocs/prince.log', $log, FILE_APPEND)

Is there something wrong witch the code?

I ran the command I found in $pathAndArgs in the shell and it's working without any errors. Could there be issues with user permissions? (also tried but not succesful)

Thanks in advance for your time Mike,

David

1. prince.log‎ 1.6 kB ‎
   Prince logs

This is a side note, but perhaps you could avoid creating a temporary file by calling one of the convert_string methods instead, if you already have your HTML document in a string?

When it loops forever, is the Prince process using any cpu?

We were already using the temporary files architecture while we were using Prince 9.0. Since I followed your advice on upgrading to Prince 10 to be able to enable Korean fonts I'm running into this issue. It's was working on ubuntu but now on Centos6.6/Red hat I'm in trouble.

$ top 
PID   USER     PR  NI  VIRT   RES SHR   S  %CPU     %MEM     TIME+  COMMAND
3958 isweb     2 0   0  193m  10m 4088 S    0.0      0.1   0:00.02 prince

Seems not to be using any CPU.

$ps aux | grep prince

 /usr/lib/prince/bin/prince -s /u01/app/apache/htdocs/extensions/Prince/pdf.css -i html --log=/u01/app/apache/htdocs/images/pdf/ponydocs.log --structured-log=normal -v --debug /app/apache/htdocs/images/pdf/ponydocs-pdf-book57bdb7060b90a.html -o /app/apache/htdocs/images/pdf/IWD-8.5.0-ManagerHelp-book.pdf

It seems that this guy had the same issue... https://www.princexml.com/forum/topic/3275/php-wrapper-idle?p=1#15975

I tried to put directly my html instead of creating a temporary file and pass it to the function convert_string_to_file.

Same issue .

Another thing I tried. Rollbacking to prince 9.0 and the old php wrapper and this is working but We really need this Korean fonts working... I'm waiting for your reply.

Very strange. We will need to create an instrumented version of the PHP wrapper with extra debug checking to help track this down. In the meantime, does it behave differently if you change the --structured-log=normal option to --structured-log=quiet instead?

In quiet mode still the process is still stuck. But nothing now in pipes[2] from readmessages. Function setLog still not logging anything in the defined log file. My logs are still printed with file_put_contents('/u01/app/apache/htdocs/prince.log', $log, FILE_APPEND).

Command got with convert_file_to_file

 "/usr/bin/prince" -s "/u01/app/apache/htdocs/extensions/Prince/pdf.css" -i "html" --log="/u01/app/apache/htdocs/images/pdf/prince.log" --structured-log=quiet --debug "/app/apache/htdocs/images/pdf/ponydocs-pdf-book57be7d51d27dc.html" -o "/app/apache/htdocs/images/pdf/IWD-8.5.0-ManagerHelp-book.pdf"

I get this output and theses logs are my custom logs.

Before read message function
Begin read message function
pipe  Resource id #266

I have another logging line inside the while loop. but nothing is printed.

What can I do to help? It's seems that we are not in the same timezone. It's already 1.00AM for me.

If you run this directly from the command-line it should succeed and produce a single line of output "fin|success" on the standard error stream, is that correct?

If so, the question becomes why this isn't working when invoked via PHP. Is there any difference when you omit the --debug flag, don't apply any style sheet with -s, and try it on the simplest possible document, eg. containing a single word of text and nothing else?

running the command correctly returns me "fin | success".

I tried with a simple html file and a simple css file and it's working. Now the question is why is it working on 9.0 and 10.0 ? I will do more tests today.

Few more testing later...

Seems like size of input both CSS or HTML matters.

This HTML work

<!DOCTYPE html>
<html lang="en" dir="ltr">

<head>
  <meta charset="utf-8" />
</head>

<body>
Eius populus ab incunabulis primis ad usque pueritiae tempus extremum, quod annis circumcluditur fere trecentis, circummurana pertulit bella, deinde aetatem ingressus adultam post multiplices bellorum aerumnas Alpes transcendit et fretum, in iuvenem erectus et virum ex omni plaga quam orbis ambit inmensus, reportavit laureas et triumphos, iamque vergens in senium et nomine solo aliquotiens vincens ad tranquilliora vitae discessit.

</body>

</html>

This one stuck the process

<!DOCTYPE html>
<html lang="en" dir="ltr">

<head>
  <meta charset="utf-8" />
</head>

<body>
Eius populus ab incunabulis primis ad usque pueritiae tempus extremum, quod annis circumcluditur fere trecentis, circummurana pertulit bella, deinde aetatem ingressus adultam post multiplices bellorum aerumnas Alpes transcendit et fretum, in iuvenem erectus et virum ex omni plaga quam orbis ambit inmensus, reportavit laureas et triumphos, iamque vergens in senium et nomine solo aliquotiens vincens ad tranquilliora vitae discessit.

Atque, ut Tullius ait, ut etiam ferae fame monitae plerumque ad eum locum ubi aliquando pastae sunt revertuntur, ita homines instar turbinis degressi montibus impeditis et arduis loca petivere mari confinia, per quae viis latebrosis sese convallibusque occultantes cum appeterent noctes luna etiam tum cornuta ideoque nondum solido splendore fulgente nauticos observabant quos cum in somnum sentirent effusos per ancoralia, quadrupedo gradu repentes seseque suspensis passibus iniectantes in scaphas eisdem sensim nihil opinantibus adsistebant et incendente aviditate saevitiam ne cedentium quidem ulli parcendo obtruncatis omnibus merces opimas velut viles nullis repugnantibus avertebant. haecque non diu sunt perpetrata.

</body>

</html>

Edited 25 Aug 2016 by dcheas

Very odd. I think it may be necessary to use strace to see exactly where Prince is blocking. This involves a command-line like this:

strace -o /path/to/output.log prince [options for prince here]

You could edit prince.php to do this directly, or you could invoke /usr/bin/prince instead of /usr/lib/prince/bin/prince, as /usr/bin/prince is a shell script and can be edited to call the Prince binary via strace.

This should save a log of all the system calls Prince makes, hopefully this will show exactly where Prince is blocking. It can also be helpful to look in /proc/PID/fd where PID is the process ID of the stalled Prince process, this will show the currently opened file descriptors as links to the actual files that are open. Also, /proc/PID/environ will show any suspicious environment variables, eg. if PHP is specifying LD_LIBRARY_PATH and overriding some shared libraries.

Sorry for all this inconvenience, and I hope we can resolve this issue.

Actually you don't even need to edit the shell script to use strace, you can attach to the blocked process by checking the process ID and then running "strace -p PID" manually from the command-line and it will attach to the running process, that's much more convenient.

Strace logs shows that the process is stuck in a FUTEX

futex(0x12b6080, FUTEX_WAIT_PRIVATE, 0, NULL

It's seems that this is a known centos 6.6 issue.
https://ma.ttias.be/linux-futex_wait-bug/
https://groups.google.com/forum/#!msg/mechanical-sympathy/QbmpZxp6C64/BonaHiVbEmsJ
https://github.com/torvalds/linux/commit/76835b0ebf8a7fe85beb03c75121419a7dec52f0

I will upgrade my kernel and let you know if this resolves the issue.

Kernel is now upgraded to 2.6.32-642.4.2.el6.x86_64 from 2.6.32-504.30.3.el6.x86_64.

Still not working.... here the full strace file got with this command

 strace -o /u01/app/apache/htdocs/strace.log "/usr/bin/prince" -i "html" --log="/u01/app/apache/htdocs/images/pdf/prince.log" --structured-log=normal --debug "/app/apache/htdocs/images/pdf/simple.html" -o "/app/apache/htdocs/images/pdf/IWD-8.5.0-ManagerHelp-book.pdf"

What can I do next?

1. strace.log‎ 73.1 kB

Edited 26 Aug 2016 by dcheas

Nice work tracking it down! Shame the kernel upgrade didn't fix it. We will investigate and get back to you. If we can disable parallel garbage collection that might workaround the problem, but it would be better if we could fix it at the source.

Thanks you for working on this issue. Do you have any idea for the timeline? Just let me know what I can do to help.

We are still investigating. You could try setting an environment variable GC_MARKERS=1 in the shell script that executes the Prince binary, this will use only one thread for garbage collection which may avoid the problem.

Were you able to try the GC_MARKERS change?

Mike any fix available to this kernel/futex problem ?

Unfortunately we have not been able to reproduce this issue. The kernel bug does not seem to be responsible for it in all cases, but we have heard reports of some Linux security products causing similar issues and this has not yet been resolved.

We have now fixed a deadlock issue when running Prince under PHP which could be related to this one; the fix is available in Prince 11.3.