Cannot open socache DBM file

[Lewis G Rosenthal]

Apache 2.4.54
PHP 7.4.32
WordPress 6.1.1
WooCommerce 7.3.0

In production, I'm now seeing:

[Thu Jan 19 11:52:05.765000 2023] [socache_dbm:error] [pid 76:tid 24] (OS
32)SYS0032: The process cannot access the file because it is being used by
another process. : AH00807: Cannot open socache DBM file
`J:/var/cache/ssl_scache' for writing (store)

httpd.conf says:

LoadModule socache_dbm_module modules/socacdbm.dll

I can confirm that I do have:

ssl_scache.dir
ssl_scache.pag

present, non-zero-length, with recent timestamps, and 281GB free space on
the volume.

I wasn't seeing this issue in the test setup, but I was the only connection
in that configuration, and I did not siege test it.

Thoughts?

--
Lewis
-------------------------------------------------------------
Lewis G Rosenthal, CNA, CLP, CLE, CWTS, EA
Rosenthal & Rosenthal, LLC www.2rosenthals.com
visit my IT blog www.2rosenthals.net/wordpress
-------------------------------------------------------------

[Steven Levine]

In <63C9B724...@2rosenthals.com>, on 01/19/23
at 04:33 PM, Lewis G Rosenthal <lgros...@2rosenthals.com> said:

Hi,

>In production, I'm now seeing:

Intermittently or always?

>[Thu Jan 19 11:52:05.765000 2023] [socache_dbm:error] [pid 76:tid 24] (OS
> 32)SYS0032: The process cannot access the file because it is being used
>by another process. : AH00807: Cannot open socache DBM file
>`J:/var/cache/ssl_scache' for writing (store)

Can you tell if the file is already opened by some other process when this
occurs? Also, is the file held open or opened/closed as needed?

If the latter, we may need to add some retry logic.

Steven

--
----------------------------------------------------------------------
"Steven Levine" <ste...@earthlink.net> Warp/DIY/BlueLion etc.
www.scoug.com www.arcanoae.com www.warpcave.com
----------------------------------------------------------------------

[Lewis G Rosenthal]

Hi...

On 01/19/23 10:31 pm, Steven Levine wrote:
> In <63C9B724...@2rosenthals.com>, on 01/19/23
> at 04:33 PM, Lewis G Rosenthal <lgros...@2rosenthals.com> said:
>
> Hi,
>
>> In production, I'm now seeing:
> Intermittently or always?

Seems to be intermittent.

>> [Thu Jan 19 11:52:05.765000 2023] [socache_dbm:error] [pid 76:tid 24] (OS
>> 32)SYS0032: The process cannot access the file because it is being used
>> by another process. : AH00807: Cannot open socache DBM file
>> `J:/var/cache/ssl_scache' for writing (store)
> Can you tell if the file is already opened by some other process when this
> occurs? Also, is the file held open or opened/closed as needed?
>

The only other process would be one of the configured Apache server
processes. I guess I should see whether mod_status is working... No, not at
the moment.

> If the latter, we may need to add some retry logic.
>

I'll see if I can figure out how to get that in some meaningful way.

[Steven Levine]

In <63CA129B...@2rosenthals.com>, on 01/19/23

at 11:03 PM, Lewis G Rosenthal <lgros...@2rosenthals.com> said:

Hi,

>Seems to be intermittent.

Good. That sorta tells us the file is not being held open permanently.

>The only other process would be one of the configured Apache server
>processes.

That's what I would expect.

>I'll see if I can figure out how to get that in some meaningful way.

Paul and I will handle the code updates to implement the required retry.
What you need to do is help gather enough information so that we know this
is an appropriate solution.

psfiles | find "SSL_CACHE"

will tell you if the file is always open when the httpd processes are
running. If this is not the case, we can wrap the open call in something
like

do forever
try open
if not E_PERM leave
retry++
if retry > limit leave
sleep a bit
end

You can use

rexxtry `do forever ; 'psfiles | find "SSL_CACHE"' ; say 'sleeping for 5'
; call syssleep 10 ; end`

to get an idea of how long the file stays open.

[Lewis G Rosenthal]

Hi...

On 01/20/23 01:03 am, Steven Levine wrote:
> In <63CA129B...@2rosenthals.com>, on 01/19/23
> at 11:03 PM, Lewis G Rosenthal <lgros...@2rosenthals.com> said:
>
> Hi,
>
>> Seems to be intermittent.
> Good. That sorta tells us the file is not being held open permanently.

Indeed.

>> The only other process would be one of the configured Apache server
>> processes.
> That's what I would expect.

...as opposed to some errant backup script or some such, which is definitely
not the case.

>> I'll see if I can figure out how to get that in some meaningful way.
> Paul and I will handle the code updates to implement the required retry.
> What you need to do is help gather enough information so that we know this
> is an appropriate solution.
>
> psfiles | find "SSL_CACHE"
>
> will tell you if the file is always open when the httpd processes are
> running. If this is not the case, we can wrap the open call in something
> like
>
> do forever
> try open
> if not E_PERM leave
> retry++
> if retry > limit leave
> sleep a bit
> end
>
> You can use
>
> rexxtry `do forever ; 'psfiles | find "SSL_CACHE"' ; say 'sleeping for 5'
> ; call syssleep 10 ; end`
>
> to get an idea of how long the file stays open.
>

That should be "SSL_SCACHE", FWIW.

The files don't appear to be held open very long. Example:

0367 000e 01c9 0001 00000000 000020c2 00000000 0108 0060
J:\VAR\CACHE\SSL_SCACHE.DIR
0367 000e 01c9 0001 00000000 000020c2 00000000 0108 0060
J:\VAR\CACHE\SSL_SCACHE.PAG
sleeping for 5
psfiles
sleeping for 5
psfiles
sleeping for 5
psfiles
sleeping for 5
psfiles
sleeping for 5
psfiles
sleeping for 5
psfiles
0367 000b 016d 0001 00000000 000020c2 00000000 0108 0060
J:\VAR\CACHE\SSL_SCACHE.DIR
0367 000c 0164 0001 00000000 000020c2 00000000 0108 0060
J:\VAR\CACHE\SSL_SCACHE.PAG
sleeping for 5
psfiles
sleeping for 5

[Steven Levine]

In <63CADE1C...@2rosenthals.com>, on 01/20/23

at 01:31 PM, Lewis G Rosenthal <lgros...@2rosenthals.com> said:

Hello,

>That should be "SSL_SCACHE", FWIW.

:-)

>0367 000e 01c9 0001 00000000 000020c2 00000000 0108 0060
>J:\VAR\CACHE\SSL_SCACHE.DIR
>0367 000e 01c9 0001 00000000 000020c2 00000000 0108 0060
>J:\VAR\CACHE\SSL_SCACHE.PAG
>sleeping for 5
>psfiles
>sleeping for 5
>psfiles
>sleeping for 5
>psfiles
>sleeping for 5
>psfiles
>sleeping for 5
>psfiles
>sleeping for 5
>psfiles
>0367 000b 016d 0001 00000000 000020c2 00000000 0108 0060
>J:\VAR\CACHE\SSL_SCACHE.DIR
>0367 000c 0164 0001 00000000 000020c2 00000000 0108 0060
>J:\VAR\CACHE\SSL_SCACHE.PAG
>sleeping for 5
>psfiles
>sleeping for 5

OK. We know what to do. I've added a note to implement something the
next time I put my httpd coding hat on.

The E_BUSY is mostly the result of differing file open semantics when
comparing OS/2 and Linux.

[Lewis G Rosenthal]

Hi...

This isn't the first time we've seen this, nor is it likely to be the last. ;-)

Thanks.