llng-fastcgi-server exited with signal 13
Concerned version
Version: 2.0.11 (but the issue appeared in 2.0.10)
Platform: (Nginx/Apache/Node.js)
CentOS Stream 8 (fully up to date) nginx 1.19.3.1 (openresty build, with lua support)
Summarize the bug encountered concisely
The problem is quite random, but frequent enough. I leave opened tab on protected application in the evening. In the morning, I just F5 the page, as my LL::NG session expired, I'm redirected on LL::NG auth form. But when I submit it, instead of being redirected back to the protected app, I get a 502 Bad Gateway message from nginx. It seemed to appear with the 2.0.10 update (but it could be another package update made at the same time). I've not encountered it with the same setup on EL7
févr. 05 08:36:50 proxyin LLNG[170237]: [debug] New request
févr. 05 08:36:50 proxyin llng-fastcgi-server[170236]: [Fri Feb 5 08:36:50 2021] [LLNG:170237] [debug] VH feeds.private.fws.fr is HTTPS
févr. 05 08:36:50 proxyin llng-fastcgi-server[170236]: [Fri Feb 5 08:36:50 2021] [LLNG:170237] [info] Session 0f7fcfd2d2fdabb954c5309359562e8f3a794b0eb68d547ee41851531a3e0618 can't be retrieved
févr. 05 08:36:50 proxyin llng-fastcgi-server[170236]: [Fri Feb 5 08:36:50 2021] [LLNG:170237] [info] Session cannot be tied: Object does not exist in the data store at /usr/share/perl5/vendor_perl/Apache/Session/Store/DBI.pm line 93.
févr. 05 08:36:50 proxyin llng-fastcgi-server[170236]: [Fri Feb 5 08:36:50 2021] [LLNG:170237] [debug] Build URL https://feeds.private.fws.fr/
févr. 05 08:36:50 proxyin llng-fastcgi-server[170236]: [Fri Feb 5 08:36:50 2021] [LLNG:170237] [debug] Redirect 192.168.7.101 to portal (url was /)
févr. 05 08:36:50 proxyin llng-fastcgi-server[170236]: [Fri Feb 5 08:36:50 2021] [LLNG:173715] [debug] VH sso.private.fws.fr is HTTPS
févr. 05 08:36:50 proxyin llng-fastcgi-server[170236]: [Fri Feb 5 08:36:50 2021] [LLNG:173715] [info] Session 0f7fcfd2d2fdabb954c5309359562e8f3a794b0eb68d547ee41851531a3e0618 can't be retrieved
févr. 05 08:36:50 proxyin llng-fastcgi-server[170236]: [Fri Feb 5 08:36:50 2021] [LLNG:173715] [info] Session cannot be tied: Object does not exist in the data store at /usr/share/perl5/vendor_perl/Apache/Session/Store/DBI.pm line 93.
févr. 05 08:36:50 proxyin llng-fastcgi-server[170236]: [Fri Feb 5 08:36:50 2021] [LLNG:173715] [debug] Build URL https://sso.private.fws.fr/?url=aHR0cHM6Ly9mZWVkcy5sYXBpb2xlLm9yZy8%3D
févr. 05 08:36:50 proxyin llng-fastcgi-server[170236]: [Fri Feb 5 08:36:50 2021] [LLNG:173715] [debug] Redirect 192.168.7.101 to portal (url was /?url=aHR0cHM6Ly9mZWVkcy5sYXBpb2xlLm9yZy8%3D)
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] User not authenticated, Try in use, cancel redirection
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Start routing default route
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Processing checkUnauthLogout
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Processing controlUrl
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Required URL (param: urldc | value: https://feeds.private.fws.fr/ | alias: https://feeds.private.fws.fr)
févr. 05 08:36:50 proxyin llng-fastcgi-server[170236]: [Fri Feb 5 08:36:50 2021] [LLNG:173715] [debug] No URL authentication level found...
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Processing code ref
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Processing code ref
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Launching ::Issuer::CAS::storeEnvAndCheckGateway
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Processing code ref
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Launching ::Issuer::OpenIDConnect::exportRequestParameters
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Processing extractFormInfo
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Prepare token
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Token 1612438730_1867 created
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Returned error: 1 (PE_SESSIONEXPIRED)
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Returned userId: anonymous
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Display type standardform
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Skin returned: login
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Calling sendHtml with template login
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Starting HTML generation using /usr/share/lemonldap-ng/portal/templates/bootstrap/login.tpl
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Sending /usr/share/lemonldap-ng/portal/templates/bootstrap/login.tpl
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Apply following CORS policy :
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Access-Control-Allow-Origin
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] *
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Access-Control-Allow-Credentials
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] true
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Access-Control-Allow-Headers
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] *
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Access-Control-Allow-Methods
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] POST,GET
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Access-Control-Expose-Headers
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] *
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Access-Control-Max-Age
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] 86400
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Required urldc : https://feeds.private.fws.fr/
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Set CSP form-action with urldc : https://feeds.private.fws.fr
févr. 05 08:36:50 proxyin LLNG[173715]: [debug] Apply following CSP : default-src 'self';img-src 'self' data:;style-src 'self';font-src 'self';connect-src 'self';script-src 'self';form-action 'self' https://*.private.fws.fr https://feeds.private.fws.fr;frame-ancestors 'none';
févr. 05 08:36:52 proxyin llng-fastcgi-server[170236]: [Fri Feb 5 08:36:52 2021] [LLNG:177906] [debug] VH sso.private.fws.fr is HTTPS
févr. 05 08:36:52 proxyin llng-fastcgi-server[170236]: [Fri Feb 5 08:36:52 2021] [LLNG:177906] [info] No cookie found
févr. 05 08:36:52 proxyin llng-fastcgi-server[170236]: [Fri Feb 5 08:36:52 2021] [LLNG:177906] [debug] Build URL https://sso.private.fws.fr/?url=aHR0cHM6Ly9mZWVkcy5sYXBpb2xlLm9yZy8%3D
févr. 05 08:36:52 proxyin llng-fastcgi-server[170236]: [Fri Feb 5 08:36:52 2021] [LLNG:177906] [debug] Redirect 192.168.7.101 to portal (url was /?url=aHR0cHM6Ly9mZWVkcy5sYXBpb2xlLm9yZy8%3D)
févr. 05 08:36:52 proxyin LLNG[177906]: [debug] User not authenticated, Try in use, cancel redirection
févr. 05 08:36:52 proxyin LLNG[177906]: [debug] Start routing default route
févr. 05 08:36:52 proxyin LLNG[177906]: [debug] Processing checkUnauthLogout
févr. 05 08:36:52 proxyin LLNG[177906]: [debug] Processing restoreArgs
févr. 05 08:36:52 proxyin LLNG[177906]: [debug] Processing controlUrl
févr. 05 08:36:52 proxyin LLNG[177906]: [debug] Required URL (param: urldc | value: https://feeds.private.fws.fr/ | alias: https://feeds.private.fws.fr)
févr. 05 08:36:52 proxyin llng-fastcgi-server[170236]: [Fri Feb 5 08:36:52 2021] [LLNG:177906] [debug] No URL authentication level found...
févr. 05 08:36:52 proxyin LLNG[177906]: [debug] Processing code ref
févr. 05 08:36:52 proxyin LLNG[177906]: [debug] Processing code ref
févr. 05 08:36:52 proxyin LLNG[177906]: [debug] Launching ::Issuer::CAS::storeEnvAndCheckGateway
févr. 05 08:36:52 proxyin LLNG[177906]: [debug] Processing code ref
févr. 05 08:36:52 proxyin LLNG[177906]: [debug] Launching ::Issuer::OpenIDConnect::exportRequestParameters
févr. 05 08:36:52 proxyin LLNG[177906]: [debug] Processing extractFormInfo
févr. 05 08:36:52 proxyin LLNG[177906]: [debug] Trying to load token 1612438730_1867
févr. 05 08:36:52 proxyin LLNG[177906]: [debug] Processing getUser
févr. 05 08:36:52 proxyin llng-fastcgi-server[170236]: FastCGI: manager (pid 170236): server (pid 177906) exited with status 13
févr. 05 08:36:52 proxyin llng-fastcgi-server[170236]: FastCGI: manager (pid 170236): server (pid 188588) started
févr. 05 08:36:52 proxyin llng-fastcgi-server[170236]: FastCGI: server (pid 188588): initialized
févr. 05 08:36:53 proxyin LLNG[179381]: [debug] New request
On nginx side, I have
2021/02/05 08:36:52 [error] 135027#135027: *157268 upstream prematurely closed connection while reading response header from upstream, client: 192.168.7.101, server: sso.private.fws.fr, request: "POST /?url=aHR0cHM6Ly9mZWVkcy5sYXBpb2xlLm9yZy8%3D HTTP/2.0", upstream: "fastcgi://unix:/var/run/llng-fastcgi-server/llng-fastcgi.sock:", host: "sso.private.fws.fr", referrer: "https://sso.private.fws.fr/?url=aHR0cHM6Ly9mZWVkcy5sYXBpb2xlLm9yZy8%3D"
Backends used
MySQL for the config, AD against samba4 for User and Password DB