Has anyone seen any CORS related issues between Lu...
# lucee
d
Has anyone seen any CORS related issues between Lucee 5.3.9.141 and 5.3.9.160? Running a javascript app on my local dev machine connecting to a local Lucee server (Commandbox) I am seeing random CORS errors when making requests (Taffy API). I can hit the same api endpoint 5 times and 1 out of the 5 will return a CORS error when on Lucee 5.3.9.160. If I simply stop the server and then start again with Lucee 5.3.9.141 no more CORS errors. It is happening intermittently on most of my API endpoints. I recently deployed the API to AWS with Lucee 5.3.9.160 and started seeing the same random CORS errors - reverted back to 5.3.9.141 and they are gone. The only change I am making is between Lucee version .141 to .160.
z
what do the errors look like?
d
Standard Chrome CORS error in the browser console. The GET request shows no CORS related headers - it could be a red herring and there is another error. Let me try and get a simple reproducible test setup just on the api end point and see if I get a different error.
Whatever is happening is related to a difference between Lucee versions.
Here’s the error in the browser console:
Copy code
Access to XMLHttpRequest at '<https://api.test:8080/v3/organisations/>' from origin '<https://app.test>' has been blocked by CORS policy: No 'Access-Control-Allow-Origin' header is present on the requested resource.
with the endpoint GET request returning a 500 status with a ‘Failed to load response data: No data found for resource with given identifier’
The browser makes an initial OPTIONS request which returns a 200 response code and response headers including these:
Copy code
access-control-allow-headers: Origin,User-Agent,Authorization,Referrer,X-Requested-With,Accept,X-CSRF-Token,X-HTTP-Method-Override,Content-Type
access-control-allow-methods: GET,POST,OPTIONS
access-control-allow-origin: *
allow: GET,POST,OPTIONS
The following GET request then blows up with the 500 error and a CORS error. If I replay the XHR (via Chrome devtools) the GET request works.
Changing server.json from this:
Copy code
"cfengine":"lucee@5.3.9.141"
to this:
Copy code
"cfengine":"lucee@5.3.9.160"
breaks the application
z
reviewing commits....
nothing jumps out... can you try some snapshots inbetween?
d
Will do
5.3.9-SNAPSHOT+150
No errors in +150 and lower.
5.3.9-SNAPSHOT+151… errors
z
what changes in the headers again?
d
Nothing - the options request returns a 200 with the headers above. Then randomly the GET request will fail.
So the functioning GET request running on the +150 snapshot for the /organisations endpoint has the following Reponse Headers:
Copy code
access-control-allow-headers: Origin, Authorization, X-CSRF-Token, X-Requested-With, Content-Type, X-HTTP-Method-Override, Accept, Referrer, User-Agent
access-control-allow-methods: GET,POST
access-control-allow-origin: *
allow: GET,POST
content-encoding: gzip
content-language: en-GB
content-type: application/json;charset=utf-8
date: Thu, 08 Sep 2022 15:51:18 GMT
x-time-in-cache-check: 0
x-time-in-cache-save: 0
x-time-in-ontaffyrequest: 336
x-time-in-ontaffyrequestend: 0
x-time-in-parse: 0
x-time-in-resource: 373
x-time-in-serialize: 0
x-time-in-taffy: 0
In +151 for a failing /organisations request: Response Headers:
Copy code
content-encoding: gzip
content-length: 4072
content-type: text/html;charset=UTF-8
date: Thu, 08 Sep 2022 15:58:36 GMT
The front end app is an old backboneJS application so is using the fetch function to handle the ajax get request as details here: http://backbonejs.org/#Collection-fetch
z
request headers look the same?
d
Yep, request headers are same for each request of the specific resources.
z
try setting env var lucee.request.limit.concurrent.maxnormprio = 0
d
Sorry, where do I need to set those?
z
the code in question reduces the priority of threads when there are too many requests from a single user
or sleeps for 100ms
tho MAX_NORMAL_PRIORITY = 0; was changed (from 5) in 5.3.9.158
d
There are lots of requests coming in to load a particular section. For example the settings section makes 10 (yes 10!) separate xhr requests to different endpoints
z
anything in your log files?
my log viewer admin plugin is great for checking all log files quickly
what to the two different response's content look like?
d
Yes I use that on other servers - our api has lucee admin disabled by default.
z
cool
d
Will have to do some more digging tomorrow.
z
but the http response is the same?
d
Return eldest child back to Uni tomorrow and packing help is needed!
z
ok I understand
d
I'd find out what's setting the headers. I'm guessing it's Taffy based on the
x-time
headers. I suspect the issue is Taffy is setting the headers and then those changes are being reset. It might be related to how Taffy is setting the headers, or perhaps a change of behavior in Lucee.
z
i wanna know what the response shows? there's a 500 error
Looking at that code it can be improved a bit, only needs to count till it reaches the thresholds and the thresholds probably can be cached
You can have 10k pageContexts and they all get their IP checked
d
The 500 error has an empty response as far as I can tell. I have to leave it for this evening. I’ll try and create a standalone test that makes several simultaneous requests to the API and switch on Lucee admin to log it all.
z
Nothing in exception.log?
a
I've posted an answer to the lucee community forum. Pretty sure the problem is comming because of the port 8080. Domain origin must match including port. You need to find out why the port 8080 and the ommited 443 port is changing.
d
@Andreas that would be the case if it was happening in all versions of Lucee that I have tried and for every request. However it happens intermittently on different requests whilst working for other similar requests. Also, I was seeing the problem on our production version. As soon is I reverted back to previous version of Lucee the errors were gone.
a
Yeah, I see now.
z
if there's a 500 error, there's must be a strack trace
d
The problem I have at the moment is that hitting the taffy api endpoints directly - one at a time doesn’t seem to trigger the 500. It only happens intermittently from the backboneJS application that makes a number of simultaneous fetch calls to several different endpoints. So, for example the settings section of the app calls the following endpoints: • /organisations • /users • /changelog • /plans • /billing • /banners • … Then only 1 of the above will throw the 500 error - but not every time.
I am not sure how to return the stack trace into the api result without rewriting a whole load of endpoints.
z
are you on tomcat or commandbox/undertow?
d
This is on commandbox/undertow but I also saw the same errors when I deployed onto our AWS Elastic Beanstalk which is running on tomcat.
z
good to know
so it's a lucee native 500 error, not a applicaiton 500?
d
I wonder if it is related to the number of calls to the api the app is making in quick succession.
z
that's what the code in question for that version where it starts to occur relates to
d
I don’t know whether it is a native 500 or taffy 500 as there is only an empty response from the endpoint.
z
anything in the
server.out.txt
from commandbox?
d
OK, just running through some checks to rule out user error (my bad code!) - I just ran the server with trace and console and debug flags so that I see loads of info in the console as I make the requests. After 3 loads of the /settings section in the app 1 of the api endpoints gave a 500 error. The other endpoints in that ‘set’ all return normally. I notice that the tuckey rewrite filters had this for the modules section:
Copy code
org.tuckey.web.filters.urlrewrite.SetAttribute: set Set response-header Access-Control-Allow-Origin null called
[DEBUG] org.tuckey.web.filters.urlrewrite.SetAttribute: setting response header
[DEBUG] org.tuckey.web.filters.urlrewrite.SetAttribute: set Set response-header Access-Control-Allow-Methods null called
[DEBUG] org.tuckey.web.filters.urlrewrite.SetAttribute: setting response header
[DEBUG] org.tuckey.web.filters.urlrewrite.SetAttribute: set Set response-header Access-Control-Allow-Headers null called
[DEBUG] org.tuckey.web.filters.urlrewrite.SetAttribute: setting response header
[DEBUG] org.tuckey.web.filters.urlrewrite.SetAttribute: set Set response-header Access-Control-Allow-Credentials null called
[DEBUG] org.tuckey.web.filters.urlrewrite.SetAttribute: setting response header
In fact, that is happening on all of the api endpoints. Here’s the tuckey rule set for CORS:
Copy code
<rule>
		<note>
		  <http://enable-cors.org>
		</note>
		<condition type="header" name="Origin">.*</condition>
		<condition type="header" name="Access-Control-Request-Method">.*</condition>
		<condition type="header" name="Access-Control-Request-Headers">.*</condition>
		<set type="response-header" name="Access-Control-Allow-Origin"></set>
		<set type="response-header" name="Access-Control-Allow-Methods"></set>
		<set type="response-header" name="Access-Control-Allow-Headers"></set>
		<set type="response-header" name="Access-Control-Allow-Credentials"></set>
	</rule>
Setting blank responses seems a little odd - should those empty headers contain ‘*’?
Still seems odd to only break certain requests on certain runs.
Just as a follow up to this - I created a runner in Postman that hit several of my local commandbox api endpoints simultaneously and then repeated the run 10 times - not a single 500 error. I wonder if the problem is actually a combination of my old backbone app and Chrome and some weird CORS header issue. I’ll carry on trying to replicate it outside of my application and jump back on here if I have a testable case. Thanks for the help @zackster
z
thanks for the update, so there were no exceptions in any of the logs?
d
Nope - all very odd!
Postman api calls returned 0 500 errors from 10 loops of 6 different endpoint requests.
Must be something weird with my ageing frontend - time to begin the VueJS rebuild.
z
no, I reckon, it's definately something on the lucee side
d
It does seem odd that it happens for lucee@5.3.9-SNAPSHOT+151 onwards and not previous versions. And my app may be unusual in that it is making multiple simultaneous fetch requests to different endpoints in the API. I’m a bit swamped at the moment on another project but will be back on this in the next few days. I’ll try and build a simple index.htm page with a bunch of fetch calls to the api and see if I can try and replicate the issue - and get some log data etc.
z
Was postman threaded and using sessions?
d
Good question - not sure how I can see that in Postman.
z
you'd need to do a login and then pass in the session cookies for subsequent requests
but that underlying change in lucee is only per IP address
d
cfm session cookies? Our API is stateless - no cookies
z
ok
d
We pass an authorization header from the backbone app for each fetch request. The authorization header contains a unique user token which then returns the correct data for that user.