Module:Cache checkAssignHandler error 2

#1
I am running OpenLiteSpeed 1.5.11 under Ubuntu Linux and the error log for each virtual host keeps getting flooded up with errors like so:

2020-02-07 23:19:22.530572 [ERROR] [167.179.136.91:38358:HTTP2-31#www.XXXX] [Module:Cache]checkAssignHandler error 2.

XXXX = virtual host name.

This also happened with OpenLiteSpeed 1.5.10.

Is this a file permissions problem? I have:

drwxr-xr-x 2 nobody nogroup 4096 Feb 3 2018 /usr/local/lsws/cachedata/
 

David

Active Member
#2
Should have some errors before this error. Please check if the configuration of the server level or the VHost level.
 
#3
There are no errors apart from this in the virtual host error log.

I also have deleted /tmp/lshttpd, where the "swap" directory was, and restarted the server, in case there was some file permission problem, but that hasn't stopped the error messages coming through.
 
#6
Please check your server error log which may tell the reason.
Not the Vhost log.
The main server logs in /usr/local/lsws/logs don't reveal anything at the time all those [Module:Cache]checkAssignHandler errors come up.

The actual web server functions well, despite the cache error message.

Now that OpenLiteSpeed 1.6.9 is marked as "stable", I might upgrade from 1.5.11 to that and see if anything changes.
 
#7
I have the same problem.
I'm using version 1.6.9
See the logs below:

Code:
2020-03-06 07:45:26.219990    DEBUG    [*:80] New connection from 162........ip:27264.
2020-03-06 07:45:26.220034    DEBUG    NtwkIOLink::setLink called pInfo is m_pClientInfo 0x2d616a0, m_pCrypto (nil), m_pServerAddrInfo 0x2d3fdd0, m_remotePort 27264
2020-03-06 07:45:26.220088    DEBUG    [162........ip:27264] onInitConnected(): HSPS_START -> HSPS_READ_REQ_HEADER
2020-03-06 07:45:26.220116    DEBUG    [162........ip:27264] NtwkIOLink::continueRead()...
2020-03-06 07:45:26.220122    DEBUG    [162........ip:27264] Read resumed!
2020-03-06 07:45:26.220129    DEBUG    [162........ip:27264] concurrent conn: 1
2020-03-06 07:45:26.220137    DEBUG    [162........ip:27264] NtwkIOLink::handleEvents() fd: 34, mask=25, events=1!
2020-03-06 07:45:26.220145    DEBUG    [162........ip:27264] HttpSession::onReadEx(), state: 1!
2020-03-06 07:45:26.220151    DEBUG    [162........ip:27264] Run State: HSPS_READ_REQ_HEADER
2020-03-06 07:45:26.220158    DEBUG    [162........ip:27264] readToHeaderBuf().
2020-03-06 07:45:26.220172    DEBUG    [162........ip:27264] Read from client: 1075
2020-03-06 07:45:26.220180    DEBUG    [162........ip:27264] Read 1075 bytes to header buffer.
2020-03-06 07:45:26.220207    DEBUG    [162........ip:27264] processHeader() returned 0, header state: 3.
2020-03-06 07:45:26.220215    DEBUG    [162........ip:27264] readToHeaderBuf(): HSPS_READ_REQ_HEADER -> HSPS_NEW_REQ
2020-03-06 07:45:26.220223    DEBUG    [162........ip:27264] processNewReq(), request header buffer size: 1079, header used: 734, processed: 734.
2020-03-06 07:45:26.220232    DEBUG    [162........ip:27264] Headers: POST /?version=1.0.0&ref=mps HTTP/1.1
Host: myhost.com
Connection: Keep-Alive
Accept-Encoding: gzip
CF-IPCountry: BR
X-Forwarded-For: 2804:d59:25db:2700:39c7:6b4a:7a87:c128
CF-RAY: 56fc3a8f9ccbf203-EWR
Content-Length: 345
X-Forwarded-Proto: https
CF-Visitor: {"scheme":"https"}
origin: https://www.google.com
user-agent: Mozilla/5.0 (Windows NT 6.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/49.0.2623.112 Safari/537.36
content-type: application/x-www-form-urlencoded
accept: */*
referer: https://www.google.com/
accept-language: pt-BR,pt;q=0.8,en-US;q=0.6,en;q=0.4
cookie: __cfduid=ddc9a2c41ae9d521b0aea40d54c4e2eeb1554902337
CF-Connecting-IP: 2804:d59:25db:2700:39c7:6b4a:7a87:c128
CDN-Loop: cloudflare
2020-03-06 07:45:26.220240    DEBUG    [162........ip:27264] HttpSession::processNewReqInit client IP from 'CF-Connecting-IP: 2804:d59:25db:2700:39c7:6b4a:7a87:c128'.
2020-03-06 07:45:26.220271    DEBUG    [162........ip:27264] update REMOTE_ADDR based on CF-Connecting-IP header to 2804:d59:25db:2700:39c7:6b4a:7a87:c128
2020-03-06 07:45:26.220296    DEBUG    [162........ip:27264#myhost.com] processNewReqInit(): HSPS_NEW_REQ -> HSPS_HKPT_HTTP_BEGIN
2020-03-06 07:45:26.220306    DEBUG    [162........ip:27264#myhost.com] [HTTP_BEGIN] run Hook function for [Module:cache] session=0x2df5d68
2020-03-06 07:45:26.220328    DEBUG    [162........ip:27264#myhost.com] [HTTP_BEGIN] [Module:cache] session=0x2df5d68 ret 0
2020-03-06 07:45:26.220336    DEBUG    [162........ip:27264#myhost.com] runEventHkpt(): HSPS_HKPT_HTTP_BEGIN -> HSPS_HKPT_RCVD_REQ_HEADER
2020-03-06 07:45:26.220343    DEBUG    [162........ip:27264#myhost.com] runEventHkpt(): HSPS_HKPT_RCVD_REQ_HEADER -> HSPS_PROCESS_NEW_REQ_BODY
2020-03-06 07:45:26.220352    DEBUG    [162........ip:27264#myhost.com] Read Request Body!
2020-03-06 07:45:26.220362    DEBUG    [162........ip:27264#myhost.com] Read 345/345 bytes of request body!
2020-03-06 07:45:26.220369    DEBUG    [162........ip:27264] NtwkIOLink::suspendRead()...
2020-03-06 07:45:26.220376    DEBUG    [162........ip:27264#myhost.com] Finished request body 345 bytes!
2020-03-06 07:45:26.220383    DEBUG    [162........ip:27264#myhost.com] HttpSession::reqBodyDone().
2020-03-06 07:45:26.220390    DEBUG    [162........ip:27264#myhost.com] reqBodyDone(): HSPS_PROCESS_NEW_REQ_BODY -> HSPS_HKPT_RCVD_REQ_BODY
2020-03-06 07:45:26.220398    DEBUG    [162........ip:27264#myhost.com] processNewUri(): HSPS_PROCESS_NEW_URI -> HSPS_VHOST_REWRITE
2020-03-06 07:45:26.220405    DEBUG    [162........ip:27264#myhost.com] processVHostRewrite(): HSPS_VHOST_REWRITE -> HSPS_CONTEXT_MAP
2020-03-06 07:45:26.220415    DEBUG    [162........ip:27264] Find context with URI: [/], location: [/usr/local/lsws/DEFAULT/myhost.com/html/].
2020-03-06 07:45:26.220424    DEBUG    [162........ip:27264#myhost.com] processContextMap(): HSPS_CONTEXT_MAP -> HSPS_CONTEXT_REWRITE
2020-03-06 07:45:26.220431    DEBUG    [162........ip:27264#myhost.com] [REWRITE] Rewrite engine is not enabled for context '/'
2020-03-06 07:45:26.220438    DEBUG    [162........ip:27264#myhost.com] processContextRewrite(): HSPS_CONTEXT_REWRITE -> HSPS_HKPT_URI_MAP
2020-03-06 07:45:26.220446    DEBUG    [162........ip:27264#myhost.com] preUriMap check serving by static url file cache: 0
2020-03-06 07:45:26.220454    DEBUG    [162........ip:27264#myhost.com] [URI_MAP] run Hook function for [Module:cache] session=0x2df5d68
2020-03-06 07:45:26.220466    ERROR    [162........ip:27264#myhost.com] [Module:Cache]checkAssignHandler error 2.
2020-03-06 07:45:26.220474    DEBUG    [162........ip:27264#myhost.com] [URI_MAP] [Module:cache] session=0x2df5d68 ret 0
 
#9
I'm currently running 1.6.10 and the "checkAssignHandler error 2" thing is still appearing in the error log files.

Maybe no one is checking their log files for errors?

It uses a lot of disk space. My virtual host's "access_log" file for June so far is 1,563,745 lines and "error_log" is at 1,133,379 lines. So it's almost like every server request triggers a cache module checkAssignHandler error.
 
#10
With regards to the cache module, some further questions and observations.

Is there supposed to be a "X-LiteSpeed-Cache" header in the server response?

My response headers look like this and is missing that header:

accept-ranges: bytes
alt-svc: quic=":443"; ma=2592000; v="43…000, h3-27=":443"; ma=2592000
content-encoding: br
content-length: 4553
content-type: text/html
date: Tue, 09 Jun 2020 11:04:32 GMT
etag: "4a98-5ede0dcd;br"
last-modified: Mon, 08 Jun 2020 10:07:09 GMT
server: LiteSpeed
vary: Accept-Encoding
X-Firefox-Spdy: h2

Also, in /usr/local/lsws/modules, I have:

-rw-r--r-- 1 root root 688 Jun 1 10:37 cache.def
lrwxrwxrwx 1 root nogroup 14 Oct 1 2019 cache.so -> cache.so-1.5.6*
-rwxr-xr-x 1 root nogroup 803792 Oct 1 2019 cache.so-1.5.6*
-rwxr-xr-x 1 root root 806312 Oct 1 2019 cache.so.old*

The first line of cache.def reads:

version:1.62

I am running OpenLiteSpeed 1.6.10.
 
#12
Hello,
I created a "Server Module" and the problem was resolved.
Thanks so much, that stopped all the anoying error messages in the log files.

Given that the module is disabled, I left the module parameters section blank, but the module updated /usr/local/lsws/modules/cache.def with its default parameters anyway.
 
#13
OpenLiteSpeed 1.6.15

I am also getting the same error.

2020-08-31 17:58:42.245710 [ERROR] [3.128.26.105:24524#XXXXX.com] [Module:Cache]checkAssignHandler error 2.
2020-08-31 17:58:42.265022 [ERROR] [3.128.26.105:24534#XXXXX.com] [Module:Cache]checkAssignHandler error 2.

Created Module as said above but the question is -- cache module is discontinued and not recommend than how to fix it?
 

David

Active Member
#16
I checked the cache code, the "checkAssignHandler error 2." error cause by cacheconfig is not initialized.
Did you have cache module registered in server level?
Even one line in server level config, such as "module cache" will register it.
 
#20
I am not able to reproduce the same issue but I have one query.

Having module at a global level with below ( disable )

enableCache 0

Means all websites on the server do not use OLS cache?

Many time I noticed -->

The same website with support .htaccess rules on OLS not working perfectly as LSWS free license. I compared the requirement nothing greatly required but still. I tested with WHMCS. Many times users not able to login or facing issues. The moment I shift to LSWS. Everything perfectly working.

I have to disable Cache. I am not able to understand where is the problem?

I had tested with some more CRM but the same result. Any idea/hint?
 
Top