search

chu11 / freeipmi-mirror

Mirror of GNU FreeIPMI Git Repo - http://savannah.gnu.org/projects/freeipmi/. I maintain the upstream of FreeIPMI and can accept Github pull requests.
GNU General Public License v3.0
12 stars 16 forks source link

Freeipmi 1.6.3 ipmi-sel command exits with an error on PowerEdge FC830 servers #29

Closed sabbene closed 5 years ago

sabbene commented 5 years ago

Hello this is in reference to the issue we discussed on the following freeipmi users mailing list: https://lists.gnu.org/archive/html/freeipmi-users/2019-08/msg00013.html


$ sudo dmidecode -s system-product-name
PowerEdge FC830
$ sudo ./ipmi-sel --version
ipmi-sel - 1.6.3
Copyright (C) 2003-2015 FreeIPMI Core Team
This program is free software; you may redistribute it under the terms of
the GNU General Public License.  This program has absolutely no warranty.`
$ sudo ./ipmi-sel
Caching SDR repository information: /root/.freeipmi/sdr-cache/sdr-cache-XXXX.localhost
Caching SDR record 216 of 217 (current record ID 216)
ipmi_sdr_cache_create: internal IPMI error`
$ sudo ./ipmi-sel --debug
Caching SDR repository information: /root/.freeipmi/sdr-cache/sdr-cache-XXXX.localhost
=====================================================
Get SDR Repository Info Request
=====================================================
[              20h] = cmd[ 8b]
=====================================================
Get SDR Repository Info Response
=====================================================
[              20h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[               1h] = sdr_version_major[ 4b]
[               5h] = sdr_version_minor[ 4b]
[              D9h] = record_count[16b]
[            FFEFh] = free_space[16b]
[        FFFFFFFFh] = most_recent_addition_timestamp[32b]
[        FFFFFFFFh] = most_recent_erase_timestamp[32b]
[               0h] = get_sdr_repository_allocation_info_command_supported[ 1b]
[               1h] = reserve_sdr_repository_command_supported[ 1b]
[               0h] = partial_add_sdr_command_supported[ 1b]
[               0h] = delete_sdr_command_supported[ 1b]
[               0h] = reserved[ 1b]
[               2h] = modal_non_modal_sdr_repository_update_operation_supported[ 2b]
[               0h] = overflow_flag[ 1b]
=====================================================
Reserve SDR Repository Request
=====================================================
[              22h] = cmd[ 8b]
=====================================================
Reserve SDR Repository Response
=====================================================
[              22h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[              E4h] = reservation_id[16b]
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              E4h] = reservation_id[16b]
[               0h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[               2h] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[22B]
[ 01h 00h 51h 12h 11h 20h 00h 00h ]
[ DFh 00h 00h 00h 07h 01h 00h C6h ]
[ 69h 44h 52h 41h 43h 38h ]
Caching SDR record 1 of 217 (current record ID 0) 
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              E4h] = reservation_id[16b]
[               2h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[               3h] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[35B]
[ 02h 00h 51h 02h 1Eh 20h 00h 72h ]
[ 07h 01h 6Fh C0h 10h 6Fh 50h 00h ]
[ 00h 00h 14h 00h C0h 00h 00h 01h ]
[ 00h 00h 00h 00h 00h 00h 00h C3h ]
[ 53h 45h 4Ch ]
Caching SDR record 2 of 217 (current record ID 2) 
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              E4h] = reservation_id[16b]
[               3h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[               4h] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[28B]
[ 03h 00h 51h 11h 17h 20h 00h 80h ]
[ 00h 00h 09h 02h 07h 01h 00h CCh ]
[ 53h 79h 73h 74h 65h 6Dh 20h 42h ]
[ 6Fh 61h 72h 64h ]
Caching SDR record 3 of 217 (current record ID 3) 
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              E4h] = reservation_id[16b]
[               4h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[               5h] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[20B]
[ 04h 00h 51h 11h 0Fh 00h B0h 00h ]
[ 00h 00h 00h 00h 03h 01h 00h C4h ]
[ 43h 50h 55h 31h ]
<snip>
Caching SDR record 215 of 217 (current record ID 215) 
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              E4h] = reservation_id[16b]
[              D8h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[              D9h] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[43B]
[ D8h 00h 51h 02h 26h B1h 00h 35h ]
[ 22h 01h 2Eh 40h C8h 6Fh 40h 00h ]
[ 00h 00h 40h 00h C0h 00h 00h 11h ]
[ 00h 00h 00h 00h 00h 00h 00h CBh ]
[ 4Dh 52h 43h 20h 57h 61h 72h 6Eh ]
[ 69h 6Eh 67h ]
Caching SDR record 216 of 217 (current record ID 216) 
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              E4h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[              C3h] = comp_code[ 8b]
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              E4h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[               5h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[ 5B]
[ D9h 00h 51h 02h 26h ]
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              E4h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               5h] = offset_into_record[ 8b]
[              10h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[16B]
[ B1h 00h 36h 22h 01h 2Eh 40h C8h ]
[ 6Fh 80h 00h 00h 00h 80h 00h C0h ]
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              E4h] = reservation_id[16b]
[              D9h] = record_id[16b]
[              15h] = offset_into_record[ 8b]
[              10h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[              C3h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[16B]
[ B1h 00h 36h 22h 01h 2Eh 40h C8h ]
[ 6Fh 80h 00h 00h 00h 80h 00h C0h ]

ipmi_sdr_cache_create: internal IPMI error`
chu11 commented 5 years ago

So what's interesting about this is:

Caching SDR record 216 of 217 (current record ID 216) 
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              E4h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[              C3h] = comp_code[ 8b]

First we try to read the entire SDR entry and fail. Not a big deal, because some motherboards require you to read SDR entries in small chunks. BUT every other entry is read in one big chunk.

====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              E4h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[               5h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[ 5B]
[ D9h 00h 51h 02h 26h ]

So we read the header of the SDR entry to get the length of 26h = 38 bytes. Ok so far. I also notice that next_record_id == 0xFFFF, indicating this is the last record entry.

=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              E4h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               5h] = offset_into_record[ 8b]
[              10h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[16B]
[ B1h 00h 36h 22h 01h 2Eh 40h C8h ]
[ 6Fh 80h 00h 00h 00h 80h 00h C0h ]

Next 16 bytes read, things look ok. 

=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              E4h] = reservation_id[16b]
[              D9h] = record_id[16b]
[              15h] = offset_into_record[ 8b]
[              10h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[              C3h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[16B]
[ B1h 00h 36h 22h 01h 2Eh 40h C8h ]
[ 6Fh 80h 00h 00h 00h 80h 00h C0h ]

ipmi_sdr_cache_create: internal IPMI error`

The next 16 bytes read fails (C3h), the data is also identical to the last 16 bytes read, so its likely bad data.

So there is definitely some bug/issue on this motherboard that I don't really know what the issue is. I'm guessing it's just some bug on the motherboard with the last SDR record.

So I'm going to hack up a patch that does the following. If it's the last entry in the SDR (indicated via 0xFFFF and you get an 0xC3 error, we're going to just assume we're done reading the SDR. I have no idea if it'll work, but it's about as good a guess as I can make :-)

chu11 commented 5 years ago

I got a branch up with the fix in https://github.com/chu11/freeipmi-mirror/tree/sdr_read_c3, could you give it a shot?

sabbene commented 5 years ago

I gave it a shot, looks like it didn't work.


$ git clone https://github.com/chu11/freeipmi-mirror.git
$ $ git branch
* master
$ git checkout sdr_read_c3
Branch sdr_read_c3 set up to track remote branch sdr_read_c3 from origin.
Switched to a new branch 'sdr_read_c3'
$ git branch
  master
* sdr_read_c3
$ git pull
Already up-to-date.

$ ./autogen.sh
$ ./configure
$ make
$ sudo ./ipmi-sel
Caching SDR repository information: /root/.freeipmi/sdr-cache/sdr-cache-XXXX.localhost
Caching SDR record 216 of 217 (current record ID 216)
ipmi_sdr_cache_create: internal IPMI error

$ sudo ./ipmi-sel --debug
Caching SDR repository information: /root/.freeipmi/sdr-cache/sdr-cache-XXXXlocalhost
=====================================================
Get SDR Repository Info Request
=====================================================
[              20h] = cmd[ 8b]
=====================================================
Get SDR Repository Info Response
=====================================================
[              20h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[               1h] = sdr_version_major[ 4b]
[               5h] = sdr_version_minor[ 4b]
[              D9h] = record_count[16b]
[            FFEFh] = free_space[16b]
[        FFFFFFFFh] = most_recent_addition_timestamp[32b]
[        FFFFFFFFh] = most_recent_erase_timestamp[32b]
[               0h] = get_sdr_repository_allocation_info_command_supported[ 1b]
[               1h] = reserve_sdr_repository_command_supported[ 1b]
[               0h] = partial_add_sdr_command_supported[ 1b]
[               0h] = delete_sdr_command_supported[ 1b]
[               0h] = reserved[ 1b]
[               2h] = modal_non_modal_sdr_repository_update_operation_supported[ 2b]
[               0h] = overflow_flag[ 1b]
=====================================================
Reserve SDR Repository Request
=====================================================
[              22h] = cmd[ 8b]
=====================================================
Reserve SDR Repository Response
=====================================================
[              22h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[              F1h] = reservation_id[16b]
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              F1h] = reservation_id[16b]
[               0h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[               2h] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[22B]
[ 01h 00h 51h 12h 11h 20h 00h 00h ]
[ DFh 00h 00h 00h 07h 01h 00h C6h ]
[ 69h 44h 52h 41h 43h 38h ]
Caching SDR record 1 of 217 (current record ID 0) 
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              F1h] = reservation_id[16b]
[               2h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[               3h] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[35B]
[ 02h 00h 51h 02h 1Eh 20h 00h 72h ]
[ 07h 01h 6Fh C0h 10h 6Fh 50h 00h ]
[ 00h 00h 14h 00h C0h 00h 00h 01h ]
[ 00h 00h 00h 00h 00h 00h 00h C3h ]
[ 53h 45h 4Ch ]
Caching SDR record 2 of 217 (current record ID 2) 
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              F1h] = reservation_id[16b]
[               3h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[               4h] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[28B]
[ 03h 00h 51h 11h 17h 20h 00h 80h ]
[ 00h 00h 09h 02h 07h 01h 00h CCh ]
[ 53h 79h 73h 74h 65h 6Dh 20h 42h ]
[ 6Fh 61h 72h 64h ]
Caching SDR record 3 of 217 (current record ID 3) 
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              F1h] = reservation_id[16b]
[               4h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[               5h] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[20B]
[ 04h 00h 51h 11h 0Fh 00h B0h 00h ]
[ 00h 00h 00h 00h 03h 01h 00h C4h ]
[ 43h 50h 55h 31h ]
<snip>
Caching SDR record 215 of 217 (current record ID 215) 
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              F1h] = reservation_id[16b]
[              D8h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[              D9h] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[43B]
[ D8h 00h 51h 02h 26h B1h 00h 35h ]
[ 22h 01h 2Eh 40h C8h 6Fh 40h 00h ]
[ 00h 00h 40h 00h C0h 00h 00h 11h ]
[ 00h 00h 00h 00h 00h 00h 00h CBh ]
[ 4Dh 52h 43h 20h 57h 61h 72h 6Eh ]
[ 69h 6Eh 67h ]
Caching SDR record 216 of 217 (current record ID 216) 
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              F1h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[              C3h] = comp_code[ 8b]
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              F1h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[               5h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[ 5B]
[ D9h 00h 51h 02h 26h ]
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              F1h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               5h] = offset_into_record[ 8b]
[              10h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[16B]
[ B1h 00h 36h 22h 01h 2Eh 40h C8h ]
[ 6Fh 80h 00h 00h 00h 80h 00h C0h ]
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[              F1h] = reservation_id[16b]
[              D9h] = record_id[16b]
[              15h] = offset_into_record[ 8b]
[              10h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[              C3h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[16B]
[ B1h 00h 36h 22h 01h 2Eh 40h C8h ]
[ 6Fh 80h 00h 00h 00h 80h 00h C0h ]

ipmi_sdr_cache_create: internal IPMI error
chu11 commented 5 years ago

I guess I got some of the logic wrong. I've re-pushed with some printfs in there. Could you try again? Hopefully we don't have to iterate too much this way.

BTW, you only have to include the debug output at the very end. After the "Caching SDR record 216 of 217 (current record ID 216) ".

sabbene commented 5 years ago

Here is the output with your debugging statements, and the excerpt you requested from the --debug output. (Thanks for that it makes it way easier!)


$ make clean
$ git branch
  master
* sdr_read_c3
$ git pull
remote: Enumerating objects: 5, done.
remote: Counting objects: 100% (5/5), done.
remote: Compressing objects: 100% (5/5), done.
remote: Total 5 (delta 0), reused 1 (delta 0), pack-reused 0
Unpacking objects: 100% (5/5), done.
From https://github.com/chu11/freeipmi-mirror
   64ef6e1..812d004  sdr_read_c3 -> origin/sdr_read_c3
Updating 64ef6e1..812d004
Fast-forward
 libfreeipmi/sdr/ipmi-sdr-cache-create.c |   18 ++++++++++++++++++
 1 files changed, 18 insertions(+), 0 deletions(-)
$ ./configure
$ make
$ sudo ./ipmi-sel
Caching SDR repository information: /root/.freeipmi/sdr-cache/sdr-cache-XXXX.localhost
_sdr_cache_get_record:470 217 (current record ID 216)
_sdr_cache_get_record:477
_sdr_cache_get_record:556
_sdr_cache_get_record:563
_sdr_cache_get_record:570
_sdr_cache_get_record:580 record length 43
_sdr_cache_get_record:586
_sdr_cache_get_record:590 - bytes to read 16
_sdr_cache_get_record:671 offset into record 21
_sdr_cache_get_record:586
_sdr_cache_get_record:590 - bytes to read 16
_sdr_cache_get_record:598
_sdr_cache_get_record:601

ipmi_sdr_cache_create: internal IPMI error
$ sudo ./ipmi-sel --debug
...
...
Caching SDR record 216 of 217 (current record ID 216) =====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[             1F3h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[              C3h] = comp_code[ 8b]
_sdr_cache_get_record:470
_sdr_cache_get_record:477
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[             1F3h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[               5h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[ 5B]
[ D9h 00h 51h 02h 26h ]
_sdr_cache_get_record:556
_sdr_cache_get_record:563
_sdr_cache_get_record:570
_sdr_cache_get_record:580 record length 43
_sdr_cache_get_record:586
_sdr_cache_get_record:590 - bytes to read 16
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[             1F3h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               5h] = offset_into_record[ 8b]
[              10h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[16B]
[ B1h 00h 36h 22h 01h 2Eh 40h C8h ]
[ 6Fh 80h 00h 00h 00h 80h 00h C0h ]
_sdr_cache_get_record:671 offset into record 21
_sdr_cache_get_record:586
_sdr_cache_get_record:590 - bytes to read 16
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[             1F3h] = reservation_id[16b]
[              D9h] = record_id[16b]
[              15h] = offset_into_record[ 8b]
[              10h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[              C3h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[16B]
[ B1h 00h 36h 22h 01h 2Eh 40h C8h ]
[ 6Fh 80h 00h 00h 00h 80h 00h C0h ]
_sdr_cache_get_record:598
_sdr_cache_get_record:601

ipmi_sdr_cache_create: internal IPMI error
chu11 commented 5 years ago

Ahhh, the error from some internal code wasn't what I was expecting it to be. Could you re-pull the branch and try again. Also, could you compile with:

./configure --enable-debug --enable-trace

Hopefully I'll have all the info I need after this run.

sabbene commented 5 years ago

Here you go. let me know if you need anything else.


$ make clean
$ git branch
  master
* sdr_read_c3
$ git pull
Already up-to-date.
$ ./configure --enable-debug --enable-trace
$ make
$ sudo ./ipmi-sel
sdr/ipmi-sdr-cache-read.c: 109: ipmi_sdr_cache_open: errno '' (2)
Caching SDR repository information: /root/.freeipmi/sdr-cache/sdr-cache-XXXX.localhost
api/ipmi-api-util.c: 358: _api_ipmi_cmd_post: error 'Timeout while processing command. Response unavailable.' (195)
api/ipmi-sdr-repository-cmds-api.c: 258: ipmi_cmd_get_sdr: error 'message timeout' (21)
_sdr_cache_get_record:470
_sdr_cache_get_record:477
_sdr_cache_get_record:556
_sdr_cache_get_record:563
_sdr_cache_get_record:570
_sdr_cache_get_record:580 record length 43
_sdr_cache_get_record:586
_sdr_cache_get_record:590 - bytes to read 16
_sdr_cache_get_record:671 offset into record 21
_sdr_cache_get_record:586
_sdr_cache_get_record:590 - bytes to read 16
api/ipmi-api-util.c: 358: _api_ipmi_cmd_post: error 'Timeout while processing command. Response unavailable.' (195)
api/ipmi-sdr-repository-cmds-api.c: 258: ipmi_cmd_get_sdr: error 'message timeout' (21)
_sdr_cache_get_record:598
_sdr_cache_get_record:601
sdr/ipmi-sdr-cache-create.c: 602: _sdr_cache_get_record: error 'internal IPMI error' (24)

ipmi_sdr_cache_create: internal IPMI error
sel/ipmi-sel.c: 183: ipmi_sel_ctx_destroy: error 'context null' (1)
$ sudo ./ipmi-sel --debug
sdr/ipmi-sdr-cache-read.c: 109: ipmi_sdr_cache_open: errno '' (2)
Caching SDR repository information: /root/.freeipmi/sdr-cache/sdr-cache-XXXX.localhost
=====================================================
Get SDR Repository Info Request
=====================================================
[              20h] = cmd[ 8b]
=====================================================
Get SDR Repository Info Response
=====================================================
[              20h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[               1h] = sdr_version_major[ 4b]
[               5h] = sdr_version_minor[ 4b]
[              D9h] = record_count[16b]
[            FFEFh] = free_space[16b]
[        FFFFFFFFh] = most_recent_addition_timestamp[32b]
[        FFFFFFFFh] = most_recent_erase_timestamp[32b]
[               0h] = get_sdr_repository_allocation_info_command_supported[ 1b]
[               1h] = reserve_sdr_repository_command_supported[ 1b]
[               0h] = partial_add_sdr_command_supported[ 1b]
[               0h] = delete_sdr_command_supported[ 1b]
[               0h] = reserved[ 1b]
[               2h] = modal_non_modal_sdr_repository_update_operation_supported[ 2b]
[               0h] = overflow_flag[ 1b]
=====================================================
Reserve SDR Repository Request
=====================================================
[              22h] = cmd[ 8b]
=====================================================
Reserve SDR Repository Response
=====================================================
[              22h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[             204h] = reservation_id[16b]
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[             204h] = reservation_id[16b]
[               0h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[               2h] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[22B]
[ 01h 00h 51h 12h 11h 20h 00h 00h ]
[ DFh 00h 00h 00h 07h 01h 00h C6h ]
[ 69h 44h 52h 41h 43h 38h ]
Caching SDR record 1 of 217 (current record ID 0) 
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[             204h] = reservation_id[16b]
[               2h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[               3h] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[35B]
[ 02h 00h 51h 02h 1Eh 20h 00h 72h ]
[ 07h 01h 6Fh C0h 10h 6Fh 50h 00h ]
[ 00h 00h 14h 00h C0h 00h 00h 01h ]
[ 00h 00h 00h 00h 00h 00h 00h C3h ]
[ 53h 45h 4Ch ]
<snip>
Caching SDR record 216 of 217 (current record ID 216) 
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[             204h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[              C3h] = comp_code[ 8b]
api/ipmi-api-util.c: 358: _api_ipmi_cmd_post: error 'Timeout while processing command. Response unavailable.' (195)
api/ipmi-sdr-repository-cmds-api.c: 258: ipmi_cmd_get_sdr: error 'message timeout' (21)
_sdr_cache_get_record:470
_sdr_cache_get_record:477
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[             204h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[               5h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[ 5B]
[ D9h 00h 51h 02h 26h ]
_sdr_cache_get_record:556
_sdr_cache_get_record:563
_sdr_cache_get_record:570
_sdr_cache_get_record:580 record length 43
_sdr_cache_get_record:586
_sdr_cache_get_record:590 - bytes to read 16
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[             204h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               5h] = offset_into_record[ 8b]
[              10h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[16B]
[ B1h 00h 36h 22h 01h 2Eh 40h C8h ]
[ 6Fh 80h 00h 00h 00h 80h 00h C0h ]
_sdr_cache_get_record:671 offset into record 21
_sdr_cache_get_record:586
_sdr_cache_get_record:590 - bytes to read 16
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[             204h] = reservation_id[16b]
[              D9h] = record_id[16b]
[              15h] = offset_into_record[ 8b]
[              10h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[              C3h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[16B]
[ B1h 00h 36h 22h 01h 2Eh 40h C8h ]
[ 6Fh 80h 00h 00h 00h 80h 00h C0h ]
api/ipmi-api-util.c: 358: _api_ipmi_cmd_post: error 'Timeout while processing command. Response unavailable.' (195)
api/ipmi-sdr-repository-cmds-api.c: 258: ipmi_cmd_get_sdr: error 'message timeout' (21)
_sdr_cache_get_record:598
_sdr_cache_get_record:601
sdr/ipmi-sdr-cache-create.c: 602: _sdr_cache_get_record: error 'internal IPMI error' (24)

ipmi_sdr_cache_create: internal IPMI error
sel/ipmi-sel.c: 183: ipmi_sel_ctx_destroy: error 'context null' (1)
chu11 commented 5 years ago

ok, I just pushed a new change, hopefully it'll work :-)

sabbene commented 5 years ago

Still no luck. Is there any additional information I can get you?


$ make clean
$ $ git branch
  master
* sdr_read_c3
$ git pull
remote: Enumerating objects: 5, done.
remote: Counting objects: 100% (5/5), done.
remote: Compressing objects: 100% (5/5), done.
remote: Total 5 (delta 0), reused 1 (delta 0), pack-reused 0
Unpacking objects: 100% (5/5), done.
From https://github.com/chu11/freeipmi-mirror
   812d004..0b4510f  sdr_read_c3 -> origin/sdr_read_c3
Updating 812d004..0b4510f
Fast-forward
 libfreeipmi/sdr/ipmi-sdr-cache-create.c |    2 +-
 1 files changed, 1 insertions(+), 1 deletions(-)
$ ./configure --enable-debug --enable-trace
$ make
$ sudo ./ipmi-sel
[sudo] password for sabbene:
sdr/ipmi-sdr-cache-read.c: 109: ipmi_sdr_cache_open: errno '' (2)
Caching SDR repository information: /root/.freeipmi/sdr-cache/sdr-cache-XXXX.localhost
api/ipmi-api-util.c: 358: _api_ipmi_cmd_post: error 'Timeout while processing command. Response unavailable.' (195)
api/ipmi-sdr-repository-cmds-api.c: 258: ipmi_cmd_get_sdr: error 'message timeout' (21)
_sdr_cache_get_record:470
_sdr_cache_get_record:477
_sdr_cache_get_record:556
_sdr_cache_get_record:563
_sdr_cache_get_record:570
_sdr_cache_get_record:580 record length 43
_sdr_cache_get_record:586
_sdr_cache_get_record:590 - bytes to read 16
_sdr_cache_get_record:671 offset into record 21
_sdr_cache_get_record:586
_sdr_cache_get_record:590 - bytes to read 16
api/ipmi-api-util.c: 358: _api_ipmi_cmd_post: error 'Timeout while processing command. Response unavailable.' (195)
api/ipmi-sdr-repository-cmds-api.c: 258: ipmi_cmd_get_sdr: error 'message timeout' (21)
_sdr_cache_get_record:598
_sdr_cache_get_record:601 message timeout
sdr/ipmi-sdr-cache-create.c: 602: _sdr_cache_get_record: error 'internal IPMI error' (24)

ipmi_sdr_cache_create: internal IPMI error
sel/ipmi-sel.c: 183: ipmi_sel_ctx_destroy: error 'context null' (1)
sdr/ipmi-sdr-cache-read.c: 109: ipmi_sdr_cache_open: errno '' (2)
Caching SDR repository information: /root/.freeipmi/sdr-cache/sdr-cache-XXXX.localhost
=====================================================
Get SDR Repository Info Request
=====================================================
[              20h] = cmd[ 8b]
=====================================================
Get SDR Repository Info Response
=====================================================
[              20h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[               1h] = sdr_version_major[ 4b]
[               5h] = sdr_version_minor[ 4b]
[              D9h] = record_count[16b]
[            FFEFh] = free_space[16b]
[        FFFFFFFFh] = most_recent_addition_timestamp[32b]
[        FFFFFFFFh] = most_recent_erase_timestamp[32b]
[               0h] = get_sdr_repository_allocation_info_command_supported[ 1b]
[               1h] = reserve_sdr_repository_command_supported[ 1b]
[               0h] = partial_add_sdr_command_supported[ 1b]
[               0h] = delete_sdr_command_supported[ 1b]
[               0h] = reserved[ 1b]
[               2h] = modal_non_modal_sdr_repository_update_operation_supported[ 2b]
[               0h] = overflow_flag[ 1b]
=====================================================
Reserve SDR Repository Request
=====================================================
[              22h] = cmd[ 8b]
=====================================================
Reserve SDR Repository Response
=====================================================
[              22h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[             213h] = reservation_id[16b]
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[             213h] = reservation_id[16b]
[               0h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[               2h] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[22B]
[ 01h 00h 51h 12h 11h 20h 00h 00h ]
[ DFh 00h 00h 00h 07h 01h 00h C6h ]
[ 69h 44h 52h 41h 43h 38h ]
Caching SDR record 1 of 217 (current record ID 0) 
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[             213h] = reservation_id[16b]
[               2h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[               3h] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[35B]
[ 02h 00h 51h 02h 1Eh 20h 00h 72h ]
[ 07h 01h 6Fh C0h 10h 6Fh 50h 00h ]
[ 00h 00h 14h 00h C0h 00h 00h 01h ]
[ 00h 00h 00h 00h 00h 00h 00h C3h ]
[ 53h 45h 4Ch ]
<snip>
Caching SDR record 216 of 217 (current record ID 216) 
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[             213h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[              FFh] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[              C3h] = comp_code[ 8b]
api/ipmi-api-util.c: 358: _api_ipmi_cmd_post: error 'Timeout while processing command. Response unavailable.' (195)
api/ipmi-sdr-repository-cmds-api.c: 258: ipmi_cmd_get_sdr: error 'message timeout' (21)
_sdr_cache_get_record:470
_sdr_cache_get_record:477
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[             213h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               0h] = offset_into_record[ 8b]
[               5h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[ 5B]
[ D9h 00h 51h 02h 26h ]
_sdr_cache_get_record:556
_sdr_cache_get_record:563
_sdr_cache_get_record:570
_sdr_cache_get_record:580 record length 43
_sdr_cache_get_record:586
_sdr_cache_get_record:590 - bytes to read 16
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[             213h] = reservation_id[16b]
[              D9h] = record_id[16b]
[               5h] = offset_into_record[ 8b]
[              10h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[               0h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[16B]
[ B1h 00h 36h 22h 01h 2Eh 40h C8h ]
[ 6Fh 80h 00h 00h 00h 80h 00h C0h ]
_sdr_cache_get_record:671 offset into record 21
_sdr_cache_get_record:586
_sdr_cache_get_record:590 - bytes to read 16
=====================================================
Get SDR Request
=====================================================
[              23h] = cmd[ 8b]
[             213h] = reservation_id[16b]
[              D9h] = record_id[16b]
[              15h] = offset_into_record[ 8b]
[              10h] = bytes_to_read[ 8b]
=====================================================
Get SDR Response
=====================================================
[              23h] = cmd[ 8b]
[              C3h] = comp_code[ 8b]
[            FFFFh] = next_record_id[16b]
[  BYTE ARRAY ... ] = record_data[16B]
[ B1h 00h 36h 22h 01h 2Eh 40h C8h ]
[ 6Fh 80h 00h 00h 00h 80h 00h C0h ]
api/ipmi-api-util.c: 358: _api_ipmi_cmd_post: error 'Timeout while processing command. Response unavailable.' (195)
api/ipmi-sdr-repository-cmds-api.c: 258: ipmi_cmd_get_sdr: error 'message timeout' (21)
_sdr_cache_get_record:598
_sdr_cache_get_record:601 message timeout
sdr/ipmi-sdr-cache-create.c: 602: _sdr_cache_get_record: error 'internal IPMI error' (24)

ipmi_sdr_cache_create: internal IPMI error
sel/ipmi-sel.c: 183: ipmi_sel_ctx_destroy: error 'context null' (1)
chu11 commented 5 years ago

doh! I actually forgot to push the change ... now I've pushed it. Sorry about that.

sabbene commented 5 years ago

oops, I've never done that before ;)

You changes appear to have worked. Tomorrow I'll build this branch for a bunch of different OSes, and run it across a bunch of different hardware and let you know how it goes.


$ make clean
$ git branch
  master
* sdr_read_c3
$ git pull
remote: Enumerating objects: 5, done.
remote: Counting objects: 100% (5/5), done.
remote: Compressing objects: 100% (5/5), done.
remote: Total 5 (delta 0), reused 1 (delta 0), pack-reused 0
Unpacking objects: 100% (5/5), done.
From https://github.com/chu11/freeipmi-mirror
   0b4510f..d22cca6  sdr_read_c3 -> origin/sdr_read_c3
Updating 0b4510f..d22cca6
Fast-forward
 libfreeipmi/sdr/ipmi-sdr-cache-create.c |   47 +++++++++++++++++++++----------
 1 files changed, 32 insertions(+), 15 deletions(-)
$ ./configure --enable-debug --enable-trace
$ make
$ sudo ./ipmi-sel
[sudo] password for sabbene:
sdr/ipmi-sdr-cache-read.c: 109: ipmi_sdr_cache_open: errno '' (2)
Caching SDR repository information: /root/.freeipmi/sdr-cache/sdr-cache-XXXX.localhost
api/ipmi-api-util.c: 358: _api_ipmi_cmd_post: error 'Timeout while processing command. Response unavailable.' (195)
api/ipmi-sdr-repository-cmds-api.c: 258: ipmi_cmd_get_sdr: error 'message timeout' (21)
_sdr_cache_get_record:470
_sdr_cache_get_record:477
_sdr_cache_get_record:556
_sdr_cache_get_record:563
_sdr_cache_get_record:570
_sdr_cache_get_record:580 record length 43
_sdr_cache_get_record:586
_sdr_cache_get_record:590 - bytes to read 16
_sdr_cache_get_record:688 offset into record 21
_sdr_cache_get_record:586
_sdr_cache_get_record:590 - bytes to read 16
api/ipmi-api-util.c: 358: _api_ipmi_cmd_post: error 'Timeout while processing command. Response unavailable.' (195)
api/ipmi-sdr-repository-cmds-api.c: 258: ipmi_cmd_get_sdr: error 'message timeout' (21)
_sdr_cache_get_record:598
_sdr_cache_get_record:611
_sdr_cache_get_record:621 - comp code 195
_sdr_cache_get_record:625
ipmi_sdr_cache_create:1002 record count written 216, record_count 217
ipmi_sdr_cache_create:1021 next record id 65535 record last 65535
ipmi_sdr_cache_create:1027

ID  | Date        | Time     | Name             | Type                     | Event
1   | Jul-29-2019 | 21:40:07 | SEL              | Event Logging Disabled   | Log Area Reset/Cleared
chu11 commented 5 years ago

awesome, I've pushed a patch to cleanup the fprintfs. If this looks good to you, I can squash and merge it all into master. This plus the other fix seems like a good time to release FreeIPMI 1.6.4.

sabbene commented 5 years ago

Sorry I didn't get back to you yesterday. I just compiled your sdr_read_c3 branch, and ran it across a bunch of different OSes, and hardware types. It looks like it is working great. Thanks for all your help!

chu11 commented 5 years ago

awesome, I'll merge in and queue up a new release. Thanks for all the testing. I'll go ahead and close this.