edgemicro not logging sourceResponse when info enabled

Google Cloud Apigee
1

Hi,

Just want to confirm the following is an issue in microgateway current version: 2.5.19

Followed the steps in the online docs to install and configure edgemicro. Also enabled logging and set to Info.

Issue is: Sending a request through the hello microproxy only results in logging for SourceRequest, TargetRequest, and TargetResponse. There is no sourceResponse showing in log file. Shouldn’t there be?

Here’s a snippet from log file:

1529130361245 info sourceRequest m=GET, u=/hello/, h=localhost:8000, r=::1:49261, i=237a44d0-712e-11e8-8143-757dbcdb31bb 

1529130361253 info targetRequest m=GET, u=/, h=mocktarget.apigee.net:NaN, i=237a44d0-712e-11e8-8143-757dbcdb31bb 

1529130361350 info targetResponse s=200, d=105, i=237a44d0-712e-11e8-8143-757dbcdb31bb 

1529130366211 stats treqErrors=0, tresErrors=0, statusCodes={1=0, 2=1, 3=0, 4=0, 5=0}, requests=1, responses=1, connections=undefined, rss=47104000, cpu=[17965890, 9376930, 17640610, 9324640]

As you can see from above, sourceResponse is missing. Also, I reviewed the code for plugins-middleware.js and couldn’t find anywhere it is logging for the sourceResponse event. Not sure if this behavior is expected or if a capability was lost along the way (regression)?

I also see this issue in a previous version 2.4.6 as a customer first reported this issue for me to research. I’m thinking it is a bug but want to confirm as perhaps I’m missing something or misunderstanding the logging capabilities?

2

It is being logged, but logged as “res close”. See here: https://github.com/apigee/microgateway-core/blob/master/lib/plugins-middleware.js#L458

3

Hi. @srinandans , thanks for the response!

Did you confirm on your local instance of Microgateway that the logging is happening for the sourceResponse? Unless I misunderstand the code, your answer doesn’t seem correct. Please feel free to clarify and help me understand? :slight_smile:

Otherwise, as I understand it, line 458 - which is the line I was concerned about when I reviewed the code and created this thread - is part of the targetResponse close event. It is wrapped in an anonymous function. You can see it all on lines 452-458.

Again, my issue is that the sourceResponse info is not being written to the logs. Unless I missed it, I also do not see any code to handle this event in the plugins_middleware js file.

A customer reported this issue to me and I reproduced it on my local Microgateway instance. In my initial question (first post on this thread) you can see the log file written from MG and notice that it is missing the sourceResponse.

What we are seeing in the log is the sourceRequest, targetRequest, and targetResponse but no sourceResponse.

If you, or anyone else in the community, are seeing the sourceResponse in the logs (without using a custom plugin), and it is working on your local instance, can you please share the logs showing those details and let me know which version of MG you are using? Otherwise, we need to add code to fix this issue.

4

also, looking at the code again, shouldn’t line 455 be?

res: targetResponse

and then, wouldn’t we need another entry for the sourceResponse —perhaps on line 480-481 insert the following?

sourceResponse.on('close', function() {
debug(‘sourceResponse close', correlation_id);
        logger.info({
            res: sourceResponse,
            d:Date.now() - start,
            i: correlation_id
        }, 'res close');
    });

again, I could be wrong here so please let me know!

5

I found the problem, I’m fixing it.

6

awesome! Thank you so much @srinandans! :slight_smile: