PHP :: Bug #79751 :: "VirtualProtect() failed" entries in apache error.log

Bug #79751	"VirtualProtect() failed" entries in apache error.log
Submitted:	2020-06-28 08:29 UTC	Modified:	2020-06-30 21:44 UTC
From:	buschmann at nidsa dot net	Assigned:
Status:	Open	Package:	opcache
PHP Version:	8.0.0alpha1	OS:	Windows Server 2019 64bit
Private report:	No	CVE-ID:	None

View Add Comment Developer Edit

Welcome! If you don't have a Git account, you can't do anything here.
You can add a comment by following this link or if you reported this bug, you can edit this bug over here.

php.net Username: php.net Password:

Quick Fix:	(description)
	Block user comment
Status:		Assign to:
Package:
Bug Type:
Summary:
From:	buschmann at nidsa dot net
New email:
PHP Version:		OS:

New/Additional Comment:

[2020-06-28 08:29 UTC] buschmann at nidsa dot net

Description:
------------
When trying to load the opcache with php-scripts from tools and our application in a script to preload the opcache: (here one example line:)

<?php
 $bresult=opcache_compile_file('N:\Apache\tcpdf\include\tcpdf_colors.php');

I get multiple entries in the apache error.log file as :
...
[Sun Jun 28 09:58:00.642291 2020] [mpm_winnt:notice] [pid 6572:tid 548] AH00354: Child: Starting 64 worker threads.
VirtualProtect() failed
VirtualProtect() failed
...

This was the first operation (explicitly and manually called from a browser) after a fresh start from Apache/php as a service.

It seems that 2 entries per compile request are generated (without timestamp).

There are no errors reported in php_err.log.

The scripts have been successfully loaded into opcache as reported by 
https://github.com/amnuts/opcache-gui - version 2.5.4

The same preload script has been used under 7.x.y until 7.4.7 for a long time without this issue.


Environment:
- Windows server 2019 64bit Standard in a VM under HyperV
- Apache 2.43 64bit from apachelounge
- php 8 alpha1 64bit thread safe from php.net QA download
- php loaded as a module with php_module


Test script:
---------------
<?php
 $bresult=opcache_compile_file('N:\Apache\tcpdf\include\tcpdf_colors.php');


Expected result:
----------------
No error log entry in error.log

Patches

Add a Patch

Pull Requests

Add a Pull Request

History

AllCommentsChangesGit/SVN commitsRelated reports

[2020-06-29 08:49 UTC] nikic@php.net

Does the problem go away if you set opcache.protect_memory=0? This is an debugging setting, that should not be enabled for production opcache use.

Of course, it still shouldn't cause failures...

[2020-06-29 15:42 UTC] buschmann at nidsa dot net

when I set opcache.protect_memory=0 (verified in php_info

opcache.protect_memory	Off	Off)

the problem stays the same.

I don't know the internals, but the sripts in the web application are working in both situations.

[2020-06-30 07:25 UTC] cmb@php.net

I think these log entries are from OPcache JIT.  Do you have JIT
enabled (see PHP info)?

[2020-06-30 09:18 UTC] buschmann at nidsa dot net

I have not changed any configuration for opcache/jit from the proven values of version 7.x.x (for opcache mostly the buffer/string sizes).

JIT seems to be ON by default as is the case here.

Here are the complete config settings from Zend OPcache from phpinfo:
 
Opcode Caching 	Up and Running
Optimization 	Enabled
SHM Cache 	Enabled
File Cache 	Disabled
JIT 	On
Startup 	OK
Shared memory model 	win32
Cache hits 	0
Cache misses 	1
Used memory 	4242384
Free memory 	29312048
Wasted memory 	0
Interned Strings Used memory 	199520
Interned Strings Free memory 	2945736
Cached scripts 	1
Cached keys 	2
Max keys 	983
OOM restarts 	0
Hash keys restarts 	0
Manual restarts 	0 

opcache.blacklist_filename	no value	no value
opcache.cache_id	no value	no value
opcache.consistency_checks	0	0
opcache.dups_fix	Off	Off
opcache.enable	On	On
opcache.enable_cli	Off	Off
opcache.enable_file_override	Off	Off
opcache.error_log	no value	no value
opcache.file_cache	no value	no value
opcache.file_cache_consistency_checks	On	On
opcache.file_cache_fallback	On	On
opcache.file_cache_only	Off	Off
opcache.file_update_protection	2	2
opcache.force_restart_timeout	180	180
opcache.interned_strings_buffer	4	4
opcache.jit	1205	1205
opcache.jit_bisect_limit	0	0
opcache.jit_blacklist_root_trace	16	16
opcache.jit_blacklist_side_trace	8	8
opcache.jit_buffer_size	0	0
opcache.jit_debug	0	0
opcache.jit_hot_func	127	127
opcache.jit_hot_loop	64	64
opcache.jit_hot_return	8	8
opcache.jit_hot_side_exit	8	8
opcache.jit_max_loops_unroll	8	8
opcache.jit_max_polymorphic_calls	2	2
opcache.jit_max_recursive_calls	2	2
opcache.jit_max_recursive_returns	2	2
opcache.jit_max_root_traces	1024	1024
opcache.jit_max_side_traces	128	128
opcache.jit_prof_threshold	0.005	0.005
opcache.log_verbosity_level	1	1
opcache.max_accelerated_files	980	980
opcache.max_file_size	0	0
opcache.max_wasted_percentage	5	5
opcache.memory_consumption	32	32
opcache.mmap_base	no value	no value
opcache.opt_debug_level	0	0
opcache.optimization_level	0x7FFEBFFF	0x7FFEBFFF
opcache.preferred_memory_model	no value	no value
opcache.preload	no value	no value
opcache.protect_memory	Off	Off
opcache.record_warnings	Off	Off
opcache.restrict_api	no value	no value
opcache.revalidate_freq	60	60
opcache.revalidate_path	Off	Off
opcache.save_comments	Off	Off
opcache.use_cwd	On	On
opcache.validate_permission	Off	Off
opcache.validate_timestamps	On	On

[2020-06-30 11:30 UTC] cmb@php.net

> JIT 	On
> opcache.jit_buffer_size	0	0

That looks pretty strange to me.  Would you still get the
"VirtualProtect() failed" errors, if you set
opcache.jit_buffer_size=16M?

[2020-06-30 13:18 UTC] buschmann at nidsa dot net

When setting opcache.jit_buffer_size=16M and a fresh start the error messages in error.log disappear !!

But I have only  used the defaults, so maybe JIT=On and opcache.jit_buffer_size=0 don't play well together...

BUT: I have also found, that not all opcache config parameters are reported by phpinfo:

In my config file I had set 

opcache.huge_code_pages=1

which is not reported as seen below.

BTW: seems OK with huge_pages=1 in a second test,
BUT in the documentation the flag should be marked as boolean, not string:
(from online manual)

 opcache.huge_code_pages string 

Here are the opcache data from phpinfo after fresh start, scripts reloads and some test with the application, which seems working OK (huge pages disabled for now!):

Opcode Caching 	Up and Running
Optimization 	Enabled
SHM Cache 	Enabled
File Cache 	Disabled
JIT 	On
Startup 	OK
Shared memory model 	win32
Cache hits 	47
Cache misses 	299
Used memory 	22870456
Free memory 	10683976
Wasted memory 	0
Interned Strings Used memory 	2597400
Interned Strings Free memory 	547856
Cached scripts 	299
Cached keys 	538
Max keys 	983
OOM restarts 	0
Hash keys restarts 	0
Manual restarts 	0 

opcache.blacklist_filename	no value	no value
opcache.cache_id	no value	no value
opcache.consistency_checks	0	0
opcache.dups_fix	Off	Off
opcache.enable	On	On
opcache.enable_cli	Off	Off
opcache.enable_file_override	Off	Off
opcache.error_log	no value	no value
opcache.file_cache	no value	no value
opcache.file_cache_consistency_checks	On	On
opcache.file_cache_fallback	On	On
opcache.file_cache_only	Off	Off
opcache.file_update_protection	2	2
opcache.force_restart_timeout	180	180
opcache.interned_strings_buffer	4	4
opcache.jit	1205	1205
opcache.jit_bisect_limit	0	0
opcache.jit_blacklist_root_trace	16	16
opcache.jit_blacklist_side_trace	8	8
opcache.jit_buffer_size	16M	16M
opcache.jit_debug	0	0
opcache.jit_hot_func	127	127
opcache.jit_hot_loop	64	64
opcache.jit_hot_return	8	8
opcache.jit_hot_side_exit	8	8
opcache.jit_max_loops_unroll	8	8
opcache.jit_max_polymorphic_calls	2	2
opcache.jit_max_recursive_calls	2	2
opcache.jit_max_recursive_returns	2	2
opcache.jit_max_root_traces	1024	1024
opcache.jit_max_side_traces	128	128
opcache.jit_prof_threshold	0.005	0.005
opcache.log_verbosity_level	1	1
opcache.max_accelerated_files	980	980
opcache.max_file_size	0	0
opcache.max_wasted_percentage	5	5
opcache.memory_consumption	32	32
opcache.mmap_base	no value	no value
opcache.opt_debug_level	0	0
opcache.optimization_level	0x7FFEBFFF	0x7FFEBFFF
opcache.preferred_memory_model	no value	no value
opcache.preload	no value	no value
opcache.protect_memory	Off	Off
opcache.record_warnings	Off	Off
opcache.restrict_api	no value	no value
opcache.revalidate_freq	60	60
opcache.revalidate_path	Off	Off
opcache.save_comments	Off	Off
opcache.use_cwd	On	On
opcache.validate_permission	Off	Off
opcache.validate_timestamps	On	On

[2020-06-30 14:32 UTC] cmb@php.net

-Package: Apache2 related +Package: opcache

[2020-06-30 14:32 UTC] cmb@php.net

> When setting opcache.jit_buffer_size=16M and a fresh start the
> error messages in error.log disappear !!

Good news!

> […], so maybe JIT=On and opcache.jit_buffer_size=0 don't play
> well together...

If opcache.jit_buffer_size=0, JIT should be disabled.  I have no
idea why it has been enabled in your case.

> BUT in the documentation the flag should be marked as boolean,
> not string:

Fixed.  Thanks!

[2020-06-30 15:01 UTC] buschmann at nidsa dot net

When it helps, I can show below all lines from my active php.ini containing "opcache.":


zend_extension = N:\Apache\php8\ext\php_opcache.dll
;zend_extension = N:\Apache\php8\php_opcache.dll
;opcache.enable=0
opcache.enable=1
;opcache.enable_cli=0
;opcache.memory_consumption=64
opcache.memory_consumption=32
;opcache.interned_strings_buffer=4
opcache.interned_strings_buffer=4
;opcache.max_accelerated_files=2000
opcache.max_accelerated_files=980
;opcache.max_wasted_percentage=5
;opcache.use_cwd=1
;opcache.validate_timestamps=1
;opcache.revalidate_freq=2
opcache.revalidate_freq=60
;opcache.revalidate_path=0
;opcache.save_comments=1
opcache.save_comments=0
;opcache.load_comments=1
opcache.load_comments=0
;opcache.fast_shutdown=0
;opcache.fast_shutdown=0
;opcache.enable_file_override=0
;opcache.optimization_level=0xffffffff
;opcache.inherited_hack=1
;opcache.dups_fix=0
;opcache.blacklist_filename=
;opcache.max_file_size=0
;opcache.consistency_checks=0
;opcache.force_restart_timeout=180
;opcache.error_log=
;opcache.log_verbosity_level=1
;opcache.preferred_memory_model=
;opcache.protect_memory=0
;opcache.protect_memory=0
opcache.huge_code_pages=1
; http://php.net/opcache.preload
;opcache.preload=
;;opcache.preload="N:\Apache\Apache24\conf\local\php_preload.php"
opcache.jit_buffer_size=16M

This seems to set/change only the following settings:

[opcache]
opcache.enable=1

opcache.memory_consumption=32

opcache.interned_strings_buffer=4

opcache.max_accelerated_files=980

opcache.revalidate_freq=60

opcache.save_comments=0

opcache.load_comments=0

opcache.huge_code_pages=1


opcache.jit_buffer_size=16M

Perhaps this may help to explain where the defaults JIT=ON and jit_buffer_size=0 stem from.

BTW: Do you have an idea with php_info and opcache.huge_code_pages not showing?

In my php.ini I left it on but never confirmed that it worked under windows (it requires OS support, but how exactly ?!?!)

I have managed to activate and verify huge pages usage for Postgres shared buffers on Windows 64bit (by pinning memory with gpedit.msc).

I would like to test JIT with huge pages on on Windows.

Thanks!

[2020-06-30 21:44 UTC] cmb@php.net

> I would like to test JIT with huge pages on on Windows.

I just learned that these are not supported by PHP on Windows.

	php.net \| support \| documentation \| report a bug \| advanced search \| search howto \| statistics \| random bug \| login
go to bug id or search bugs for


Copyright © 2001-2020 The PHP Group All rights reserved.	Last updated: Thu Oct 29 14:01:44 2020 UTC