Route Collision?

Hi guys,

I’ve built a REST API using ColdBox and I have setup routes and handler method security so that only certain HTTP methods can access certain handlers.

Yesterday our iPhone developer was hitting the API pretty frequently and it appears we ran into either a concurrency issue or a route collision issue. The iPhone application was polling every 5 seconds and making two requests to the API in tandem.

  1. POST createIncidentEvent /incident/:id
  2. GET IncidentStatus /incident/:id

I realized this morning that the return value of POST createIncidentEvent was actually GET IncidentStatus so the second request wasn’t actually needed. I tailed the logs to watch the poling requests log to the server. For the most part both requests would run without issue, however when the error occurred the log indicated that a method security exception had occurred. The weird thing though is that the method exception occurred on a completely different route - createIncident - which wasn’t even in the request. I do have a route handler called createIncident, but the route for this is POST /incident/ with no ID. What I can deduce below in the logs is that the second time that createIncidentEvent incident/922/ is called it’s being routed to createIncident and then somehow a GET is being called on createIncident which only accepts a POST.

That was a lot of rambling but hopefully it made sense. Any help on this would appreciated. Thanks.

Nolan

“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:38”,“myapp.common.interceptors.Dispatcher”,"--------Dispatcher Pre-Process Called-----------"
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:38”,“coldbox.system.cache.CacheFactory”,“Executing reap on factoryID: 2132978629”
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:38”,“v01.handlers.Incident”,“Incoming request for route: incident/:incidentid/”
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:38”,“coldbox.system.interceptors.SES”,“Extension: json detected and set in rc.format”
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:38”,“coldbox.system.interceptors.SES”,“SES Route matched: {PATTERN={incident/:incidentid/},PACKAGERESOLVEREXEMPT={false},CONSTRAINTS={{}},PATTERNPARAMS={[incidentid]},MODULE={},MODULEROUTING={},HANDLER={Incident},ACTION={{POST={createIncidentEvent},GET={getIncident},DELETE={closeIncident}}},REGEXPATTERN={incident/([^/]+?)/},VALUEPAIRTRANSLATION={true},VIEWNOLAYOUT={false}} on routed string: incident/922/”
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:38”,“coldbox.system.interceptors.SES”,“Matched HTTP Method (POST) to routed action: createIncidentEvent”
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:38”,“v01.interceptors.Security”,"--------Authorization-----------User authorization detected: nolandubeau@gmail.com , route: incident/:incidentid/, action: createIncidentEvent"
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:38”,“v01.interceptors.Security”,"--------Content----------------- ------"
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:38”,“v01.interceptors.Security”,"*****Successful Authorization detected: 349 , route: incident/:incidentid/,action: createIncidentEvent"
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:38”,“myapp.common.interceptors.Dispatcher”,"--------Dispatcher Pre-Process Called-----------"
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:38”,“v01.handlers.Incident”,“Incoming request for route: incident/:incidentid/”
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:43”,“coldbox.system.cache.CacheFactory”,“Executing reap on factoryID: 2132978629”
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:43”,“coldbox.system.cache.CacheFactory”,“Executing reap on factoryID: 2132978629”
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:43”,“coldbox.system.interceptors.SES”,“Extension: json detected and set in rc.format”
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:43”,“coldbox.system.interceptors.SES”,“SES Route matched: {PATTERN={incident/},PACKAGERESOLVEREXEMPT={false},CONSTRAINTS={{}},PATTERNPARAMS={[]},MODULE={},MODULEROUTING={},HANDLER={Incident},ACTION={{POST={createIncident}}},REGEXPATTERN={incident/},VALUEPAIRTRANSLATION={true},VIEWNOLAYOUT={false}} on routed string: incident/922/”
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:43”,“coldbox.system.interceptors.SES”,“Extension: json detected and set in rc.format”
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:43”,“coldbox.system.interceptors.SES”,“SES Route matched: {PATTERN={incident/},PACKAGERESOLVEREXEMPT={false},CONSTRAINTS={{}},PATTERNPARAMS={[]},MODULE={},MODULEROUTING={},HANDLER={Incident},ACTION={{POST={createIncident}}},REGEXPATTERN={incident/},VALUEPAIRTRANSLATION={true},VIEWNOLAYOUT={false}} on routed string: incident/922/"
"DEBUG",“FILELOG”,“02/09/2011”,“17:13:43”,“coldbox.system.interceptors.SES”,"Matched HTTP Method (POST) to routed action: createIncident"
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:43”,“v01.interceptors.Security”,”--------Authorization-----------User authorization detected: nolandubeau@gmail.com , route: incident/, action: createIncident"
“DEBUG”,“FILELOG”,“02/09/2011”,“17:13:43”,“v01.interceptors.Security”,"--------Content----------------- ------"
“ERROR”,“FILELOG”,“02/09/2011”,“17:13:43”,“API v0.1”,"Application Execution Exception CFErrorType=SES.405 CFDetails=The HTTP method used: GET is not valid for the current executing resource. Valid methods are: {POST={createIncident}} CFMessage=Invalid HTTP method: GET CFStackTrace=coldfusion.runtime.CustomException: Invalid HTTP method: GET

do you have auto reload? or config auto reload turned on?
Luis F. Majano
President
Ortus Solutions, Corp

ColdBox Platform: http://www.coldbox.org
Linked In: http://www.linkedin.com/pub/3/731/483
Blog: http://www.luismajano.com
IECFUG Manager: http://www.iecfug.com

Looking into this, I agree with Luis that there must be a simple configuration issue.

The action is extracted directly from the request’s CGI scope and I verified each variable is properly scoped to local in the SES interceptor.

Aaron

Hi guys,

Thanks for your comments. I made some changes to my routes file and ran a preliminary test and no issues occurred. Thanks for the heads up on the settings. I will run more tests today to determine if the issue creeps up.

Cheers,

Nolan