Missing file update form field

[Andrew Dixon]

Hi All,

I've got a very odd intermittent issue that is showing up in my error logging but I'm unable to repeat at all myself, however it is occurring reasonably regularly in the logs. The error I'm getting is:

key [file] doesn't exist

The form field being passed in is called "file" and the line of code on which the error is occurring is:

bolPhotoProcessed = objImageProcessor.processUploadImage(form.file);

The only code before this line is a 600 second request timeout setting and the creation of the objImageProcessor object.

From the logging I can see the "form" scope is completely empty, which backs up the error message however in the request variables I can see that the request had a length, which looks like an image was attached and it was passed as a multipart form:

content-length 3232542

content-type multipart/form-data; boundary=----WebKitFormBoundary6cV5GGYpB01k7J50

I can also see from the logging that is it not happening with any particular browser, OS or device type, it is across the board.

Has anyone else ever seen anything like this or have idea what might be going on?

Kind regards,

Andrew

about.me - mso - Lucee Association Member

[Nando Breiter]

Could it be a bot probing your server?

Aria Media Sagl
Via Rompada 40
6987 Caslano
Switzerland

+41 (0)91 600 9601
+41 (0)76 303 4477 cell
skype: ariamedia

--
See Lucee at CFCamp Oct 22 & 23 2015 @ Munich Airport, Germany - Get your ticket NOW - http://www.cfcamp.org/
---
You received this message because you are subscribed to the Google Groups "Lucee" group.
To unsubscribe from this group and stop receiving emails from it, send an email to lucee+un...@googlegroups.com.
To post to this group, send email to lu...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/lucee/CAG1WijUHvc-kFkC109q4uBWqKGGvD6Py7%2BKr-GrGaFC3FEBmAQ%40mail.gmail.com.
For more options, visit https://groups.google.com/d/optout.

[Andrew Dixon]

No, it is a members area that you need to be logged into before being able to upload a photo. Also the user agents are always for different systems and not for bots. 

Kind regards,

Andrew

about.me - mso - Lucee Association Member

To view this discussion on the web visit https://groups.google.com/d/msgid/lucee/CAGHrs%3D--069ArooQekQ2Lk70Ne%3DohyxnCfTh%2BGZmwSu7jCsidw%40mail.gmail.com.

[Adam Cameron]

On Saturday, 31 October 2015 09:18:27 UTC, Andrew Dixon wrote:

Hi All,

I've got a very odd intermittent issue that is showing up in my error logging but I'm unable to repeat at all myself, however it is occurring reasonably regularly in the logs. 

Have your attempts to reproduce it also included putting it under load? Might be some sort of concurrency issue? 

[Igal @ Lucee.org]

are you sure that the requests that trigger the error are POSTed?

some browsers make a GET request in addition to the POST request (don't ask me which or why, but I've seen it happen many times in my applications), so the first POST request is handled properly, and then the GET request fails and you see it in the logs.  this is likely hidden from the user so they never complain about it either.

I recommend logging all of the requests to that script, something like:

    log file="troubleshoot" text="#now()# #CGI.REQUEST_METHOD# #CGI.REQUEST_URL# #CGI.REMOTE_ADDR# #Cookie.CFID#";

it will help you determine if this is the issue in your case.

Igal Sapir
Lucee Core Developer
Lucee.org

To view this discussion on the web visit https://groups.google.com/d/msgid/lucee/CAG1WijUygP1r0KGempyEC0NDTnBsm_95oi6ZRVTLMqxVj%3DwkLQ%40mail.gmail.com.

[Andrew Dixon]

Hi Igal,

The errors are logged in Sentry (https://github.com/getsentry/sentry) and it logs loads of details and the requests are logged as POST requests, but I'm inclined to believe this is correct, however if it continues I will add the logging for every request as you have suggested and see what that shows me.

Kind regards,

Andrew

about.me - mso - Lucee Association Member

To view this discussion on the web visit https://groups.google.com/d/msgid/lucee/5635225A.1060306%40lucee.org.

[Andrew Dixon]

Hi Adam,

Yes, I've attempted it under some simulated load as well and it has always worked for me, on my local VM, test server and production server. Also from the logs it doesn't appear to be load related as it happens at all times of day, even in the early hours of the day when the site is extremely quiet. It's not occurring at any particular times of day, etc... or consistently throughout the day, for example the last occurrence (as of writing this at 21:55 GMT) was at 11:12 GMT today, so about 11 hours ago, however yesterday it occurred several times spread across the day.

One thing that has just occurred to me while writing this is that it might be something like an "aborted" request, e.g. part way through the file uploading the user navigates away from the page, causing the browser to abort the request, but maybe Lucee carries on processing the request despite not receiving all the data. I'm going to go and try that now and see what I can find.

Kind regards,

Andrew

about.me - mso - Lucee Association Member

--

See Lucee at CFCamp Oct 22 & 23 2015 @ Munich Airport, Germany - Get your ticket NOW - http://www.cfcamp.org/
---
You received this message because you are subscribed to the Google Groups "Lucee" group.
To unsubscribe from this group and stop receiving emails from it, send an email to lucee+un...@googlegroups.com.
To post to this group, send email to lu...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/lucee/3a74df21-582b-40cd-9c37-5f2f1d6192bd%40googlegroups.com.

[Andrew Dixon]

Bingo, that is exactly what it is. I set it uploading a large image and while it was in the middle of uploading I navigated away from the page and the exact same error turned up in my Sentry logs straight away with the request coming from my IP. I'll just add in a check for the form field at the beginning of the script then.

Kind regards,

Andrew

about.me - mso - Lucee Association Member