One quite haunted Gateway cache issue
I meet with one weird issue these days and I felt very confused.
I have added several news node to my OData models in backend system and I can ensure that the development are correct, since I have tested the related services on those new nodes in Gateway client and Chrome and every thing works.
The annoying issue is, some times the service suddenly does not work, and the issue is caused by that the old metadata before my enhancement is wrongly loaded in gateway system. See one error message for example: (ComplexNotes is one of the new nodes I added to the Model )
Even I have cleared the cache in both gateway and backend via tcode /IWFND/CACHE_CLEANUP and /IWBEP/CACHE_CLEANUP, the issue still occurs from time to time, but is NOT always reproducible.
Taking today's test for example.The last change timestamp for backend cache is say 20150112052753,
And it has been sent to gateway system and cached there ( pay attention to the timestamp )
And regarding the difference of type id between gateway and crm is I have done the following customizing in gateway system:
so far so good. Unfortunately sometimes I could really observe that the cache in gateway came to an old state , taking one below for example: today is 2015-01-12, why the cache in gateway is restored to the version on last Thursday(2015-01-08)??
I did some whereused list search on table /IWFND/I_MED_CTC, the only place to fill some data to this table is /IWFND/CL_MED_MDL_CACHE_PERSIS~SET_MERGED_MODEL, which is furtherly only called by /IWFND/CL_MED_MDL_PROVIDER~CREATE_CLUSTERED_MODEL. The latter is only called when a request for Medata model is issued.
Then comes my question: since the backend cache is already update-to-date ( 2015-01-12 ) and the same with Gateway cache, how could any Meta model request force the Gateway cache to be refreshed to the previous version ( 2015-01-08 ) ????
Jerry Wang replied
finally we found out the root cause of this strange issue, no ghost actually, the system just works as designed.
I share with your how I figured it out:
I have written the following report ( in the end of my reply ) and scheduled it as background job running periodically to monitor the cache table change. For example it runs every five minutes and check whether current cache is latest one ( latest means it contains the node OpportunityComplexNotesSet I have added in wave 8 development phase ). The check result is written to a z-table.
After sometimes' run, the result is really interesting.
There are actually two types of caches with different cache timestamp. The red one is the latest and the expected one, since it has all my wave 8 enhancement,
And its timestamp also perfectly match the one in my backend system, AG3:
However, where does the other one, 20150205082736, come from?? Soon I found out that it comes from another CRM backend system in lower release.
It turns out that some other colleagues have made configuration in the gateway system with different backend system Alias which has different versions of the Odata implementation.
Considering the following use case:
1. User A logs on GM6 with user role which matches to the backend system QHD, which has lower version of Odata model
2. the request is served by QHD, and the cache from QHD is fetched and filled into GM6.
3. User B logs on GM6 with user role which matches to a higher version of OData model, AG3, to ask for data for new node OpportunityComplexNotes.
4. The metadata is served from GM6 cache table, and do not have the new node OpportunityComplexNotes since the cache comes from QHD.
5. This also explain the behavior why sometimes we manually clear the cache in GM6, and the scenario could work for sometime. However once the odata request is sent and served by QHD, the older cache there will overwrite the latest cache, then issue reoccurs.
After we delete the system alias configuration which points to the lower version system, QHD, everything works perfectly and stably.
DATA: ls_model_data TYPE /IWFND/IF_MED_MDL_OBJECT_CLASS=>TY_S_DOM_MODEL_CLASS,
LS_CACHE_AREA TYPE /IWFND/I_MED_CTC,
lv_cache_key TYPE c length 81 value '-ZCRM_OPPORTUNITY_0001_BE',
lv_wave8_exist TYPE abap_bool VALUE abap_true,
ls_log TYPE ZCACJETRACE.
IMPORT tab = ls_model_data
FROM DATABASE /iwfnd/i_med_ctc(md)
WRITE: / 'Timestamp: ' COLOR COL_GROUP , ls_cache_area-TIMESTAMP COLOR COL_NEGATIVE.
READ TABLE ls_model_data-ASSOCIATIONS WITH KEY external_name = 'OpportunityComplexNotesSet' TRANSPORTING NO FIELDS.
IF sy-subrc <> 0.
WRITE: / 'wave 8 enhancement does not exist.' COLOR COL_NEGATIVE.
lv_wave8_exist = abap_false.
WRITE: / 'cache ok, the latest node is there' COLOR COL_POSITIVE.
ls_log-HAS_WAVE8_ENHANCE = lv_wave8_exist.
ls_log-OPERATION_DATE = sy-DATUM.
ls_log-OPERATION_TIME = sy-TIMLO.
ls_log-OPERATION_USER = sy-uname.
ls_log-CACHE_TIMESTAMP = ls_cache_area-TIMESTAMP.
CALL FUNCTION 'GUID_CREATE'
EV_GUID_16 = ls_log-OPERATION_ID.
INSERT ZCACJETRACE FROM ls_log.