WebHandler issue

Posted by goo on 07-Feb-2020 11:52

12.0

I have the following handlers in my openedge.properties file:

handler42=SPWebHandle : /v1/Coverages/{OrganizationId}
handler41=SPWebHandle : /v1/Coverages/{OrganizationId}/getCoverageById/{coverageid}
handler40=SPWebHandle : /v1/Coverages/{OrganizationId}/getCoveragesByProductId/{productid}
handler39=SPWebHandle : /v1/Customers/{OrganizationId}
handler38=SPWebHandle : /v1/Customers/{OrganizationId}/getLatestEventByCustomerId/{customerid}
handler37=SPWebHandle : /v1/Customers/{OrganizationId}/listInvoicesByCustomerId/{customerid}
handler36=SPWebHandle : /v1/Customers/{OrganizationId}/listDocuments/
handler35=SPWebHandle : /v1/Customers/{OrganizationId}/listDocumentsByCustomerId/{customerid}
handler34=SPWebHandle : /v1/Customers/{OrganizationId}/getCustomerBySSN/{ssn}
handler33=SPWebHandle : /v1/Customers/{OrganizationId}/getCustomerById/{customerid}
handler32=SPWebHandle : /v1/Customers/{OrganizationId}/getCustomerAddressesByCustomerId/{customerid}
handler31=SPWebHandle : /v1/Organizations/
handler30=SPWebHandle : /v1/Organizations/{OrganizationId}
handler29=SPWebHandle : /v1/PersonRoles/
handler28=SPWebHandle : /v1/PersonRoles/getPersonRoleById/{personroleid}
handler27=SPWebHandle : /v1/Persons/{OrganizationId}
handler26=POSTWebHandle : /v1/Persons/{OrganizationId}/deletePersonsByCustomerId/{customerid}
handler25=POSTWebHandle : /v1/Persons/{OrganizationId}/addPersonByCustomerId/{customerid}
handler24=SPWebHandle : /v1/Persons/{OrganizationId}/getPersonsByCustomerId/{customerid}
handler23=SPWebHandle : /v1/Persons/{OrganizationId}/getPersonById/{personid}
handler22=SPWebHandle : /v1/ProductCategories/{OrganizationId}
handler21=SPWebHandle : /v1/ProductCategories/{OrganizationId}/getProductCategoryById/{productcategoryid}
handler20=SPWebHandle : /v1/Products/{OrganizationId}
handler19=SPWebHandle : /v1/Products/{OrganizationId}/getProductMatrix/
handler18=SPWebHandle : /v1/Products/{OrganizationId}/getProductMatrixByCustomerId/{customerid}
handler17=SPWebHandle : /v1/Products/{OrganizationId}/getProductById/{productid}
handler16=SPWebHandle : /v1/Products/{OrganizationId}/getProductsByCustomerId/{customerid}
handler15=SPWebHandle : /v1/ProductTypes/{OrganizationId}
handler14=SPWebHandle : /v1/ProductTypes/{OrganizationId}/getProductTypesByProductCategoryId/{productcategoryid}
handler13=SPWebHandle : /v1/ProductTypes/{OrganizationId}/getProductTypeById/{producttypeid}
handler12=SPWebHandle : /v1/Token/
handler11=DocumentHandler : /v1/Various/{OrganizationId}/getDocumentById/{documentid}
handler10=POSTWebHandle : /v1/Various/{OrganizationId}/getPriceByCoverageId/{coverageid}
handler9=POSTWebHandle : /v1/Various/{OrganizationId}/getPricesByProductId/{productid}
handler8=POSTWebHandle : /v1/Various/{OrganizationId}/addBelongingByCustomerId/{customerid}
handler7=SPWebHandle : /v1/Various/{OrganizationId}/getForeignInsuranceCompanies/
handler6=SPWebHandle : /v1/WebBasket/listWebBasketStatus/
handler5=POSTWebHandle : /v1/WebBasket/{OrganizationId}/deleteWebBasketByCustomerId/{customerid}
handler4=POSTWebHandle : /v1/WebBasket/{OrganizationId}/updateWebBasketByCustomerId/{customerid}
handler3=SPWebHandle : /v1/WebBasket/{OrganizationId}/getWebBasketById/{webbasketid}
handler2=SPWebHandle : /v1/WebBasket/{OrganizationId}/listWebBasketsByCustomerId/{customerid}
handler1=SPWebHandle : /v1/WebBasket/{OrganizationId}/getWebBasketByCustomerId/{customerid}

Handler 25 is working - giving me correct StatusCode: 400

2020-02-07T11:37:35.140+0100 010608 005328 3 AS-4 ROOT:w:00000003 AS -- TRACE: SINGLETON Non-Void Method 'Progress.Web.InternalWebHandler:HandleRequest' START (Proxy 558792390).
2020-02-07T11:37:35.157+0100 010608 005328 1 AS-4 ROOT:w:00000003 DEBUG ------>:INNNNNNNNE
2020-02-07T11:37:35.158+0100 010608 005328 1 AS-4 ROOT:w:00000003 DEBUG URItemplate:/v1/Persons/{OrganizationId}/addPersonByCustomerId/{customerid}
2020-02-07T11:37:35.158+0100 010608 005328 1 AS-4 ROOT:w:00000003 DEBUG Context:
2020-02-07T11:37:35.158+0100 010608 005328 1 AS-4 ROOT:w:00000003 DEBUG Entity:Progress.Json.ObjectModel.JsonArray_1396
2020-02-07T11:37:35.164+0100 010608 005328 1 AS-4 ROOT:w:00000003 DEBUG Content-type: application/json; charset="utf-8"
2020-02-07T11:37:35.164+0100 010608 005328 1 AS-4 ROOT:w:00000003 -- (Procedure: 'HandlePost POSTWebHandle' Line:252) ServiceTable: Persons
2020-02-07T11:37:35.164+0100 010608 005328 1 AS-4 ROOT:w:00000003 -- (Procedure: 'HandlePost POSTWebHandle' Line:252) ServiceMethod:
2020-02-07T11:37:35.295+0100 010608 005328 3 AS-4 ROOT:w:00000003 AS -- TRACE: SINGLETON Non-Void Method (Proxy 558792390) END SUCCESS.

It is this handler I have problems with, though I have not testet everything when changing the handlersequence. If I change the handlersequence to the following:

handler42=DocumentHandler : /v1/Various/{OrganizationId}/getDocumentById/{documentid}
handler41=POSTWebHandle : /v1/Persons/{OrganizationId}/deletePersonsByCustomerId/{customerid}
handler40=POSTWebHandle : /v1/Persons/{OrganizationId}/addPersonByCustomerId/{customerid}
handler39=POSTWebHandle : /v1/Various/{OrganizationId}/getPriceByCoverageId/{coverageid}
handler38=POSTWebHandle : /v1/Various/{OrganizationId}/getPricesByProductId/{productid}
handler37=POSTWebHandle : /v1/Various/{OrganizationId}/addBelongingByCustomerId/{customerid}
handler36=POSTWebHandle : /v1/WebBasket/{OrganizationId}/deleteWebBasketByCustomerId/{customerid}
handler35=POSTWebHandle : /v1/WebBasket/{OrganizationId}/updateWebBasketByCustomerId/{customerid}
handler34=SPWebHandle : /v1/Coverages/{OrganizationId}
handler33=SPWebHandle : /v1/Coverages/{OrganizationId}/getCoverageById/{coverageid}
handler32=SPWebHandle : /v1/Coverages/{OrganizationId}/getCoveragesByProductId/{productid}
handler31=SPWebHandle : /v1/Customers/{OrganizationId}
handler30=SPWebHandle : /v1/Customers/{OrganizationId}/getLatestEventByCustomerId/{customerid}
handler29=SPWebHandle : /v1/Customers/{OrganizationId}/listInvoicesByCustomerId/{customerid}
handler28=SPWebHandle : /v1/Customers/{OrganizationId}/listDocuments/
handler27=SPWebHandle : /v1/Customers/{OrganizationId}/listDocumentsByCustomerId/{customerid}
handler26=SPWebHandle : /v1/Customers/{OrganizationId}/getCustomerBySSN/{ssn}
handler25=SPWebHandle : /v1/Customers/{OrganizationId}/getCustomerById/{customerid}
handler24=SPWebHandle : /v1/Customers/{OrganizationId}/getCustomerAddressesByCustomerId/{customerid}
handler23=SPWebHandle : /v1/Organizations/
handler22=SPWebHandle : /v1/Organizations/{OrganizationId}
handler21=SPWebHandle : /v1/PersonRoles/
handler20=SPWebHandle : /v1/PersonRoles/getPersonRoleById/{personroleid}
handler19=SPWebHandle : /v1/Persons/{OrganizationId}
handler18=SPWebHandle : /v1/Persons/{OrganizationId}/getPersonsByCustomerId/{customerid}
handler17=SPWebHandle : /v1/Persons/{OrganizationId}/getPersonById/{personid}
handler16=SPWebHandle : /v1/ProductCategories/{OrganizationId}
handler15=SPWebHandle : /v1/ProductCategories/{OrganizationId}/getProductCategoryById/{productcategoryid}
handler14=SPWebHandle : /v1/Products/{OrganizationId}
handler13=SPWebHandle : /v1/Products/{OrganizationId}/getProductMatrix/
handler12=SPWebHandle : /v1/Products/{OrganizationId}/getProductMatrixByCustomerId/{customerid}
handler11=SPWebHandle : /v1/Products/{OrganizationId}/getProductById/{productid}
handler10=SPWebHandle : /v1/Products/{OrganizationId}/getProductsByCustomerId/{customerid}
handler9=SPWebHandle : /v1/ProductTypes/{OrganizationId}
handler8=SPWebHandle : /v1/ProductTypes/{OrganizationId}/getProductTypesByProductCategoryId/{productcategoryid}
handler7=SPWebHandle : /v1/ProductTypes/{OrganizationId}/getProductTypeById/{producttypeid}
handler6=SPWebHandle : /v1/Token/
handler5=SPWebHandle : /v1/Various/{OrganizationId}/getForeignInsuranceCompanies/
handler4=SPWebHandle : /v1/WebBasket/listWebBasketStatus/
handler3=SPWebHandle : /v1/WebBasket/{OrganizationId}/getWebBasketById/{webbasketid}
handler2=SPWebHandle : /v1/WebBasket/{OrganizationId}/listWebBasketsByCustomerId/{customerid}
handler1=SPWebHandle : /v1/WebBasket/{OrganizationId}/getWebBasketByCustomerId/{customerid}

Handler40 - the same handler that I tested in the other sequence, it gives me a StatusCode: 500

In the agent logfile I get an error saying 

2020-02-07T11:31:55.868+0100 014316 010228 3 AS-4 ROOT:w:00000001 AS -- TRACE: SINGLETON Non-Void Method 'Progress.Web.InternalWebHandler:HandleRequest' START (Proxy 558792390).
2020-02-07T11:31:55.967+0100 014316 010228 1 AS-4 ROOT:w:00000001 LogMgrWrtr [OE.W.WebHandler ERROR] Request error for POST /web/v1/Persons/2/addPersonByCustomerId/10220933: status code 500
2020-02-07T11:31:55.967+0100 014316 010228 1 AS-4 ROOT:w:00000001 LogMgrWrtr Error(s) raised:
2020-02-07T11:31:55.967+0100 014316 010228 1 AS-4 ROOT:w:00000001 LogMgrWrtr ReturnValue: METHOD NOT IMPLEMENTED

Could anyone tell me where to look for errors? Why is the handle not implemented when I change the sequence?

Community Groups - Forum
Posted by Peter Judge on 07-Feb-2020 14:28

The sorting is (very) important. PASOE's web transport selects the first webhandler (looking from handler1…handlerN) it finds and it uses a BEGINS search. So if there's a config earlier that matches the URI it will use that one.
 
I think that it's using handler19 in the "broken" case, because /v1/Persons/{organisationid} is a valid begins match for /web/v1/Persons/2/addPersonByCustomerId/10220933
 
 
 

All Replies

Posted by Peter Judge on 07-Feb-2020 13:30

The chances are good that you're not running the webhandler you think you are.
 
If you set the logging level in the openedge.properties to 5, you'll see a message like
logger:Debug(substitute('Request for path "&1" using template "&2" and handler "&3"',
in the agent log. 
 
Or save the below as logging.config in the CATALINA_BASE/openedge  directory (and delete when you're done).
{
  "logger": {
    "OpenEdge.Web.InternalWebRouter": {
      "logLevel": "DEBUG",
      "filters": [
        "ERROR_FORMAT",
        "TOKEN_FORMAT",
        "REPLACE_TOKENS_FORMAT",
        "LOG_MANAGER_FORMAT",
        "LOG_MANAGER_WRITER"
      ]
    }
  }
}
 
 

Posted by goo on 07-Feb-2020 14:18

Thanks Peter, but how can that happen? It is the same handlers, only changed the sorting. I need to be sure that I can depend on it. I will check the logging.
 
//Geir Otto
 

Posted by Peter Judge on 07-Feb-2020 14:28

The sorting is (very) important. PASOE's web transport selects the first webhandler (looking from handler1…handlerN) it finds and it uses a BEGINS search. So if there's a config earlier that matches the URI it will use that one.
 
I think that it's using handler19 in the "broken" case, because /v1/Persons/{organisationid} is a valid begins match for /web/v1/Persons/2/addPersonByCustomerId/10220933
 
 
 

Posted by goo on 07-Feb-2020 14:31

The log when setting level 5:

:

(Progress.Web.InternalWebHandler:HandleRequest) for operation 16 (8458)

2020-02-07T15:28:39.636+0100 004136 010676 3 AS-4 ROOT:w:00000001 AS -- TRACE: SINGLETON Non-Void Method 'Progress.Web.InternalWebHandler:HandleRequest' START (Proxy 558792390).

2020-02-07T15:28:39.636+0100 004136 010676 4 AS-4 ROOT:w:00000001 AS -- TRACE: STATELESS: unable to locate proxy-id 558792390 (Progress.Web.InternalWebHandler) for operation 16 (8458)

2020-02-07T15:28:39.646+0100 004136 010676 4 AS-4 ROOT:w:00000001 AS -- TRACE: cso4GL: After successful loadProc() (8458)

2020-02-07T15:28:39.646+0100 004136 010676 4 AS-4 ROOT:w:00000001 AS -- TRACE: Set open 4GL server state to 2. (8400)

2020-02-07T15:28:39.646+0100 004136 010676 4 AS-4 ROOT:w:00000001 AS -- TRACE: cso4GL: In execProc() - before execution. (8458)

2020-02-07T15:28:39.646+0100 004136 010676 4 AS-4 ROOT:w:00000001 AS -- TRACE: STATELESS: running stateless internal function on proxy-id 558792390  (8458)

2020-02-07T15:28:39.693+0100 004136 010676 1 AS-4 ROOT:w:00000001 LogMgrWrtr     INFO: Current session client type MULTI-SESSION-AGENT does not support named logs

2020-02-07T15:28:39.702+0100 004136 010676 1 AS-4 ROOT:w:00000001 LogMgrWrtr     [OE.W.InternalWebRouter DEBUG] Request for path "/web/v1/Persons/2/addPersonByCustomerId/10220933" using template "/v1/Persons/{OrganizationId}" and handler "SPWebHandle"

2020-02-07T15:28:39.705+0100 004136 010676 1 AS-4 ROOT:w:00000001 LogMgrWrtr     [OE.W.InternalWebRouter DEBUG] Debug mode: ON

2020-02-07T15:28:39.724+0100 004136 010676 1 AS-4 ROOT:w:00000001 LogMgrWrtr     INFO: Current session client type MULTI-SESSION-AGENT does not support named logs

2020-02-07T15:28:39.730+0100 004136 010676 1 AS-4 ROOT:w:00000001 LogMgrWrtr     [OE.W.InternalWebRouter DEBUG] Handler instance SPWebHandle_1112 used for handler SPWebHandle

2020-02-07T15:28:39.740+0100 004136 010676 1 AS-4 ROOT:w:00000001 LogMgrWrtr     [OE.W.WebHandler ERROR] Request error for POST /web/v1/Persons/2/addPersonByCustomerId/10220933: status code 500

2020-02-07T15:28:39.740+0100 004136 010676 1 AS-4 ROOT:w:00000001 LogMgrWrtr     Error(s) raised: Progress.Lang.AppError

2020-02-07T15:28:39.740+0100 004136 010676 1 AS-4 ROOT:w:00000001 LogMgrWrtr     ReturnValue: METHOD NOT IMPLEMENTED

2020-02-07T15:28:39.740+0100 004136 010676 3 AS-4 ROOT:w:00000001 AS -- TRACE: SINGLETON Non-Void Method (Proxy 558792390) END SUCCESS.

2020-02-07T15:28:39.740+0100 004136 010676 4 AS-4 ROOT:w:00000001 AS -- TRACE: cso4GL: In execProc() - successful execution. (8458)

2020-02-07T15:28:39.740+0100 004136 010676 4 AS-4 ROOT:w:00000001 AS -- TRACE: cso4GL: In execCall() - execProc() success. (8458)

2020-02-07T15:28:39.740+0100 004136 010676 4 AS-4 ROOT:w:00000001 AS -- TRACE: Set open 4GL server state to 3. (8400)

2020-02-07T15:28:39.740+0100 004136 010676 4 AS-4 ROOT:w:00000001 AS Server Message state = MSGSTATE_SENDRESP

2020-02-07T15:28:39.741+0100 004136 010676 4 AS-4 ROOT:w:00000001 AS -- TRACE: Set open 4GL server state to 1. (8400)

2020-02-07T15:28:39.741+0100 004136 010676 4 AS-4 ROOT:w:00000001 AS -- TRACE: open4GLRead 87. (8403)

2020-02-07T15:28:39.741+0100 004136 010676 4 AS-4 ROOT:w:00000001 AS Server Message state = MSGSTATE_FINISHRQ

2020-02-07T15:28:39.741+0100 004136 010676 4 AS-4 ROOT:w:00000001 AS Server Message state = MSGSTATE_IDLE

Posted by goo on 07-Feb-2020 14:32

aaaa, ok, that makes sence… thanks…. much better to know why :-) it seems like hat in the logfile as well.

Big thanks!!

//Geir Otto

Posted by goo on 07-Feb-2020 14:40

I thought the sequnce dependeses was based on each webhandler, not for alll webhandlers. So I sorted them on webhandler, then on number of /, but NOW i konw ….

Posted by goo on 07-Feb-2020 14:40

I thought the sequnce dependeses was based on each webhandler, not for alll webhandlers. So I sorted them on webhandler, then on number of /, but NOW i konw ….

This thread is closed