[Skiboot] [PATCH] ipmi: Log exact NetFn value in OPAL logs

[Vipin K Parashar]

Hi Cyril,
            Thanks!! for review.  One observation as below:

On Monday 29 February 2016 06:22 AM, Cyril Bur wrote:
> On Sat, 27 Feb 2016 02:13:26 +0530
> Vipin K Parashar <vipin at linux.vnet.ibm.com> wrote:
>
> Hi Vipin,
>
>> As per IPMI message format NetFn value in present in first 6 bits
>> while last 2 bits contain LUN value. This needs to be taken care
>> while printing NetFn value in OPAL logs which is useful while debugging
>> fails.
>>
> At the moment it is confusing that the netfn/lun byte is printed as the netfn,
> good idea.
>
>> [root at fir01 /]# ipmitool raw 0x0a 0x48
>>   47 b1 d0 56
>> [root at fir01 /]#
>>
>>  From OPAL Logs
>> ---------------
>> [133969609199,7] BT: seq 0x3d netfn 0x0a cmd 0x48: Message sent to host
>> [133975465455,7] BT: seq 0x3d netfn 0x0a cmd 0x48: IPMI MSG done
>>
>>  From BMC Logs
>> --------------
>> IPMIMain: [693 WARNING][corecmdselect.c:913]
>>   Request: Channel:f; Netfn:a; Cmd:48;
>> IPMIMain: [693 INFO][corecmdselect.c:924]
>>   Response: Channel:f; Netfn:a; Cmd:48; Data:0 47 b1 d0 56
>>
>> Signed-off-by: Vipin K Parashar <vipin at linux.vnet.ibm.com>
>> ---
>>   core/ipmi.c | 2 +-
>>   hw/bt.c     | 5 +++--
>>   2 files changed, 4 insertions(+), 3 deletions(-)
>>
>> diff --git a/core/ipmi.c b/core/ipmi.c
>> index 60e9640..6fdb9a7 100644
>> --- a/core/ipmi.c
>> +++ b/core/ipmi.c
>> @@ -141,7 +141,7 @@ void ipmi_cmd_done(uint8_t cmd, uint8_t netfn, uint8_t cc, struct ipmi_msg *msg)
>>   	}
>>   
>>   	if ((msg->netfn >> 2) + 1 != (netfn >> 2)) {
>> -		prerror("IPMI: Incorrect netfn 0x%02x in response\n", netfn);
>> +		prerror("IPMI: Incorrect netfn 0x%02x in response\n", netfn >> 2);
>>   		cc = IPMI_ERR_UNSPECIFIED;
> This change makes sense as the error reported is the failure of the condition
> which is looking at strictly the netfn.
>
>>   	}
>>   	msg->netfn = netfn;
>> diff --git a/hw/bt.c b/hw/bt.c
>> index 3325f69..ca8bd1e 100644
>> --- a/hw/bt.c
>> +++ b/hw/bt.c
>> @@ -15,6 +15,7 @@
>>    */
>>   
>>   #define pr_fmt(fmt) "BT: " fmt
>> +
>>   #include <skiboot.h>
>>   #include <lpc.h>
>>   #include <lock.h>
>> @@ -80,7 +81,7 @@
>>   #define _BT_Q_LOG(level, msg, fmt, args...) \
>>   	do { if (msg) \
>>   			prlog(level, "seq 0x%02x netfn 0x%02x cmd 0x%02x: " fmt "\n", \
>> -			(msg)->seq, (msg)->ipmi_msg.netfn, (msg)->ipmi_msg.cmd, ##args); \
>> +			(msg)->seq, ((msg)->ipmi_msg.netfn >> 2), (msg)->ipmi_msg.cmd, ##args); \
>>   		else \
>>   			prlog(level, "seq 0x?? netfn 0x?? cmd 0x??: " fmt "\n", ##args); \
>>   	} while(0)
>> @@ -346,7 +347,7 @@ static void bt_get_resp(void)
>>   	if (!bt_msg) {
>>   		/* A response to a message we no longer care about. */
>>   		prlog(PR_INFO, "Nobody cared about a response to an BT/IPMI message"
>> -		       "(seq 0x%02x netfn 0x%02x cmd 0x%02x)\n", seq, netfn, cmd);
>> +		       "(seq 0x%02x netfn 0x%02x cmd 0x%02x)\n", seq, (netfn >> 2), cmd);
>>   		bt_flush_msg();
>>   		return;
> These two hunks are debug prints which actually show all the bytes that aren't
> data bytes. Perhaps renaming the label to 'netfn/lun' makes more sense here as
> it keeps more information for debugging (I'm assuming that someone debugging
> will know how the netfn/lun is put in one byte obviously...).

hmm, actually LUN is always 0 in OPAL and exact netfn value is more sought
after. ipmitool raw command and BMC traces also use/print exact netfn value
So printing exact netfn value with BT_Q_LOG/ DBG / INFO label takes it more
closer to what we see see with BMC traces and can directly use with 
ipmitool
raw command. It also enables any netfn based grep to run unmodified on OPAL
logs and BMC traces while debugging fails.
    Though its always helpful to print out more info like response data 
obtained,
netfn/lun value with PR_DEBUG option in OPAL logs, but in my opinion 
printing
exact netfn might of immediate use as if now.

>
> Thanks,
>
> Cyril
>>   	}