Missing file update form field

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.

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: ariamediaOn Sat, Oct 31, 2015 at 10:18 AM, Andrew Dixon <@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. 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 http://about.me/andrew_dixon - mso http://www.mso.net - Lucee
Association Member http://lucee.org


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+unsubscribe@googlegroups.com.
To post to this group, send email to lucee@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/lucee/CAG1WijUHvc-kFkC109q4uBWqKGGvD6Py7%2BKr-GrGaFC3FEBmAQ%40mail.gmail.com
https://groups.google.com/d/msgid/lucee/CAG1WijUHvc-kFkC109q4uBWqKGGvD6Py7%2BKr-GrGaFC3FEBmAQ%40mail.gmail.com?utm_medium=email&utm_source=footer
.
For more options, visit https://groups.google.com/d/optout.

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?On Saturday, 31 October 2015 09:18:27 UTC, Andrew Dixon wrote:

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 http://about.me/andrew_dixon - mso http://www.mso.net - Lucee
Association Member http://lucee.orgOn 31 October 2015 at 10:24, Nando Breiter <@Nando_Breiter> wrote:

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

On Sat, Oct 31, 2015 at 10:18 AM, Andrew Dixon <@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. 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 http://about.me/andrew_dixon - mso http://www.mso.net - Lucee
Association Member http://lucee.org


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+unsubscribe@googlegroups.com.
To post to this group, send email to lucee@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/lucee/CAG1WijUHvc-kFkC109q4uBWqKGGvD6Py7%2BKr-GrGaFC3FEBmAQ%40mail.gmail.com
https://groups.google.com/d/msgid/lucee/CAG1WijUHvc-kFkC109q4uBWqKGGvD6Py7%2BKr-GrGaFC3FEBmAQ%40mail.gmail.com?utm_medium=email&utm_source=footer
.
For more options, visit https://groups.google.com/d/optout.


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+unsubscribe@googlegroups.com.
To post to this group, send email to lucee@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/lucee/CAGHrs%3D--069ArooQekQ2Lk70Ne%3DohyxnCfTh%2BGZmwSu7jCsidw%40mail.gmail.com
https://groups.google.com/d/msgid/lucee/CAGHrs%3D--069ArooQekQ2Lk70Ne%3DohyxnCfTh%2BGZmwSu7jCsidw%40mail.gmail.com?utm_medium=email&utm_source=footer
.
For more options, visit https://groups.google.com/d/optout.

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 http://lucee.org/On 10/31/2015 6:06 AM, Andrew Dixon wrote:

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 http://about.me/andrew_dixon - mso http://www.mso.net -
Lucee Association Member http://lucee.org

On 31 October 2015 at 10:24, Nando Breiter <@Nando_Breiter mailto:Nando_Breiter> wrote:

Could it be a bot probing your server?



Aria Media Sagl
Via Rompada 40
6987 Caslano
Switzerland

+41 (0)91 600 9601 <tel:%2B41%20%280%2991%20600%209601>
+41 (0)76 303 4477 <tel:%2B41%20%280%2976%20303%204477> cell
skype: ariamedia

On Sat, Oct 31, 2015 at 10:18 AM, Andrew Dixon <@Andrew_Dixon <mailto:@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. 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-length3232542
    content-typemultipart/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 <http://about.me/andrew_dixon> - mso
    <http://www.mso.net> - Lucee Association Member <http://lucee.org>
    -- 
    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+unsubscribe@googlegroups.com
    <mailto:lucee+unsubscribe@googlegroups.com>.
    To post to this group, send email to lucee@googlegroups.com
    <mailto:lucee@googlegroups.com>.
    To view this discussion on the web visit
    https://groups.google.com/d/msgid/lucee/CAG1WijUHvc-kFkC109q4uBWqKGGvD6Py7%2BKr-GrGaFC3FEBmAQ%40mail.gmail.com
    <https://groups.google.com/d/msgid/lucee/CAG1WijUHvc-kFkC109q4uBWqKGGvD6Py7%2BKr-GrGaFC3FEBmAQ%40mail.gmail.com?utm_medium=email&utm_source=footer>.
    For more options, visit https://groups.google.com/d/optout.


-- 
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+unsubscribe@googlegroups.com
<mailto:lucee+unsubscribe@googlegroups.com>.
To post to this group, send email to lucee@googlegroups.com
<mailto:lucee@googlegroups.com>.
To view this discussion on the web visit
https://groups.google.com/d/msgid/lucee/CAGHrs%3D--069ArooQekQ2Lk70Ne%3DohyxnCfTh%2BGZmwSu7jCsidw%40mail.gmail.com
<https://groups.google.com/d/msgid/lucee/CAGHrs%3D--069ArooQekQ2Lk70Ne%3DohyxnCfTh%2BGZmwSu7jCsidw%40mail.gmail.com?utm_medium=email&utm_source=footer>.
For more options, visit https://groups.google.com/d/optout.


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+unsubscribe@googlegroups.com
mailto:lucee+unsubscribe@googlegroups.com.
To post to this group, send email to lucee@googlegroups.com
mailto:lucee@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/lucee/CAG1WijUygP1r0KGempyEC0NDTnBsm_95oi6ZRVTLMqxVj%3DwkLQ%40mail.gmail.com
https://groups.google.com/d/msgid/lucee/CAG1WijUygP1r0KGempyEC0NDTnBsm_95oi6ZRVTLMqxVj%3DwkLQ%40mail.gmail.com?utm_medium=email&utm_source=footer.
For more options, visit https://groups.google.com/d/optout.

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 http://about.me/andrew_dixon - mso http://www.mso.net - Lucee
Association Member http://lucee.orgOn 31 October 2015 at 20:19, Igal @ Lucee.org <@Igal> wrote:

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 http://lucee.org/
On 10/31/2015 6:06 AM, Andrew Dixon wrote:

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 http://about.me/andrew_dixon - mso http://www.mso.net - Lucee
Association Member http://lucee.org

On 31 October 2015 at 10:24, Nando Breiter <@Nando_Breiter> wrote:

Could it be a bot probing your server?

Aria Media Sagl
Via Rompada 40
6987 Caslano
Switzerland

+41 (0)91 600 9601 <%2B41%20%280%2991%20600%209601>
+41 (0)76 303 4477 <%2B41%20%280%2976%20303%204477> cell
skype: ariamedia

On Sat, Oct 31, 2015 at 10:18 AM, Andrew Dixon < <@Andrew_Dixon> @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. 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 http://about.me/andrew_dixon - mso http://www.mso.net - Lucee
Association Member http://lucee.org

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+unsubscribe@googlegroups.com
lucee+unsubscribe@googlegroups.com.
To post to this group, send email to lucee@googlegroups.com
lucee@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/lucee/CAG1WijUHvc-kFkC109q4uBWqKGGvD6Py7%2BKr-GrGaFC3FEBmAQ%40mail.gmail.com?utm_medium=email&utm_source=footer
https://groups.google.com/d/msgid/lucee/CAG1WijUHvc-kFkC109q4uBWqKGGvD6Py7%2BKr-GrGaFC3FEBmAQ%40mail.gmail.com
.
For more options, visit https://groups.google.com/d/optout
https://groups.google.com/d/optout.


See Lucee at CFCamp Oct 22 & 23 2015 @ Munich Airport, Germany - Get your
ticket NOW - http://www.cfcamp.org/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+unsubscribe@googlegroups.com.
To post to this group, send email to lucee@googlegroups.com
lucee@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/lucee/CAGHrs%3D--069ArooQekQ2Lk70Ne%3DohyxnCfTh%2BGZmwSu7jCsidw%40mail.gmail.com?utm_medium=email&utm_source=footer
https://groups.google.com/d/msgid/lucee/CAGHrs%3D--069ArooQekQ2Lk70Ne%3DohyxnCfTh%2BGZmwSu7jCsidw%40mail.gmail.com
.
For more options, visit https://groups.google.com/d/optout.


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+unsubscribe@googlegroups.com.
To post to this group, send email to lucee@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/lucee/CAG1WijUygP1r0KGempyEC0NDTnBsm_95oi6ZRVTLMqxVj%3DwkLQ%40mail.gmail.com?utm_medium=email&utm_source=footer
https://groups.google.com/d/msgid/lucee/CAG1WijUygP1r0KGempyEC0NDTnBsm_95oi6ZRVTLMqxVj%3DwkLQ%40mail.gmail.com
.
For more options, visit https://groups.google.com/d/optout.


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+unsubscribe@googlegroups.com.
To post to this group, send email to lucee@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/lucee/5635225A.1060306%40lucee.org
https://groups.google.com/d/msgid/lucee/5635225A.1060306%40lucee.org?utm_medium=email&utm_source=footer
.

For more options, visit https://groups.google.com/d/optout.

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 http://about.me/andrew_dixon - mso http://www.mso.net - Lucee
Association Member http://lucee.orgOn 31 October 2015 at 13:11, Adam Cameron <@Adam_Cameron> wrote:

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?


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+unsubscribe@googlegroups.com.
To post to this group, send email to lucee@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/lucee/3a74df21-582b-40cd-9c37-5f2f1d6192bd%40googlegroups.com
https://groups.google.com/d/msgid/lucee/3a74df21-582b-40cd-9c37-5f2f1d6192bd%40googlegroups.com?utm_medium=email&utm_source=footer
.

For more options, visit https://groups.google.com/d/optout.