xref: /openbmc/openbmc-test-automation/redfish/systems/eventlog/test_event_logging.robot (revision bade11a2432921a471bf39131693dcc197a96084)
1 *** Settings ***
2 Documentation       Inventory of hardware resources under systems.
3 
4 Resource            ../../../lib/bmc_redfish_resource.robot
5 Resource            ../../../lib/bmc_redfish_utils.robot
6 Resource            ../../../lib/logging_utils.robot
7 Resource            ../../../lib/openbmc_ffdc.robot
8 Resource            ../../../lib/ipmi_client.robot
9 Library             ../../../lib/logging_utils.py
10 
11 Suite Setup         Suite Setup Execution
12 Suite Teardown      Suite Teardown Execution
13 Test Setup          Test Setup Execution
14 Test Teardown       Test Teardown Execution
15 
16 ** Variables ***
17 
18 ${max_num_event_logs}  ${200}
19 
20 *** Test Cases ***
21 
22 Event Log Check After BMC Reboot
23     [Documentation]  Check event log after BMC rebooted.
24     [Tags]  Event_Log_Check_After_BMC_Reboot
25 
26     Redfish Purge Event Log
27     Event Log Should Not Exist
28 
29     Redfish OBMC Reboot (off)
30 
31     Redfish.Login
32     Wait Until Keyword Succeeds  1 mins  15 secs   Redfish.Get  ${EVENT_LOG_URI}Entries
33 
34     Event Log Should Not Exist
35 
36 
37 Event Log Check After Host Poweron
38     [Documentation]  Check event log after host has booted.
39     [Tags]  Event_Log_Check_After_Host_Poweron
40 
41     Redfish Purge Event Log
42     Event Log Should Not Exist
43 
44     Redfish Power On
45 
46     Redfish.Login
47     Event Log Should Not Exist
48 
49 
50 Create Test Event Log And Verify
51     [Documentation]  Create event logs and verify via redfish.
52     [Tags]  Create_Test_Event_Log_And_Verify
53 
54     Create Test Error Log
55     Event Log Should Exist
56 
57 
58 Delete Redfish Event Log And Verify
59     [Documentation]  Delete Redfish event log and verify via Redfish.
60     [Tags]  Delete_Redfish_Event_Log_And_Verify
61 
62     Redfish.Login
63     Redfish Purge Event Log
64     Create Test PEL Log
65     ${elog_entry}=  Get Event Logs
66 
67     Redfish.Delete  /redfish/v1/Systems/system/LogServices/EventLog/Entries/${elog_entry[0]["Id"]}
68 
69     ${error_entries}=  Get Redfish Error Entries
70     Should Be Empty  ${error_entries}
71 
72 
73 Test Event Log Persistency On Restart
74     [Documentation]  Restart logging service and verify event logs.
75     [Tags]  Test_Event_Log_Persistency_On_Restart
76 
77     Create Test Error Log
78     Event Log Should Exist
79 
80     BMC Execute Command
81     ...  systemctl restart xyz.openbmc_project.Logging.service
82     Sleep  10s  reason=Wait for logging service to restart properly.
83 
84     Event Log Should Exist
85 
86 
87 Test Event Entry Numbering Reset On Restart
88     [Documentation]  Restart logging service and verify event logs entry starts
89     ...  from entry "Id" 1.
90     [Tags]  Test_Event_Entry_Numbering_Reset_On_Restart
91     [Setup]  Redfish Power Off  stack_mode=skip
92 
93     #{
94     #  "@odata.context": "/redfish/v1/$metadata#LogEntryCollection.LogEntryCollection",
95     #  "@odata.id": "/redfish/v1/Systems/system/LogServices/EventLog/Entries",
96     #  "@odata.type": "#LogEntryCollection.LogEntryCollection",
97     #  "Description": "Collection of System Event Log Entries",
98     #  "Members": [
99     #  {
100     #    "@odata.context": "/redfish/v1/$metadata#LogEntry.LogEntry",
101     #    "@odata.id": "/redfish/v1/Systems/system/LogServices/EventLog/Entries/1",
102     #    "@odata.type": "#LogEntry.v1_4_0.LogEntry",
103     #    "Created": "2019-05-29T13:19:27+00:00",
104     #    "EntryType": "Event",
105     #    "Id": "1",               <----- Event log ID
106     #    "Message": "org.open_power.Host.Error.Event",
107     #    "Name": "System DBus Event Log Entry",
108     #    "Severity": "Critical"
109     #  }
110     #  ],
111     #  "Members@odata.count": 1,
112     #  "Name": "System Event Log Entries"
113     #}
114 
115     Create Test PEL Log
116     Create Test PEL Log
117     Event Log Should Exist
118 
119     Redfish Purge Event Log
120     Event Log Should Not Exist
121 
122     BMC Execute Command
123     ...  systemctl restart xyz.openbmc_project.Logging.service
124     Sleep  10s  reason=Wait for logging service to restart properly.
125 
126     Create Test PEL Log
127     ${elogs}=  Get Event Logs
128     Should Be Equal  ${elogs[0]["Id"]}  1  msg=Event log entry is not 1
129 
130 
131 Test Event Log Persistency On Reboot
132     [Documentation]  Reboot BMC and verify event log.
133     [Tags]  Test_Event_Log_Persistency_On_Reboot
134 
135     Redfish Purge Event Log
136     Create Test Error Log
137     Event Log Should Exist
138 
139     Redfish OBMC Reboot (off)
140 
141     Redfish.Login
142     Wait Until Keyword Succeeds  1 mins  15 secs   Redfish.Get  ${EVENT_LOG_URI}Entries
143 
144     Event Log Should Exist
145 
146 
147 Create Test Event Log And Verify Time Stamp
148     [Documentation]  Create event logs and verify time stamp.
149     [Tags]  Create_Test_Event_Log_And_Verify_Time_Stamp
150 
151     #{
152     #  "@odata.context": "/redfish/v1/$metadata#LogEntryCollection.LogEntryCollection",
153     #  "@odata.id": "/redfish/v1/Systems/system/LogServices/EventLog/Entries",
154     #  "@odata.type": "#LogEntryCollection.LogEntryCollection",
155     #  "Description": "Collection of System Event Log Entries",
156     #  "Members": [
157     #  {
158     #    "@odata.context": "/redfish/v1/$metadata#LogEntry.LogEntry",
159     #    "@odata.id": "/redfish/v1/Systems/system/LogServices/EventLog/Entries/1",
160     #    "@odata.type": "#LogEntry.v1_4_0.LogEntry",
161     #    "Created": "2019-05-29T13:19:27+00:00", <--- Time stamp
162     #    "EntryType": "Event",
163     #    "Id": "1",
164     #    "Message": "org.open_power.Host.Error.Event",
165     #    "Name": "System DBus Event Log Entry",
166     #    "Severity": "Critical"
167     #  }
168     #  ],
169     #  "Members@odata.count": 1,
170     #  "Name": "System Event Log Entries"
171     #}
172 
173     Redfish Purge Event Log
174 
175     Create Test Error Log
176     Sleep  2s
177     Create Test Error Log
178 
179     ${elog_entry}=  Get Event Logs
180 
181     # The event log generated is associated with the epoc time and unique
182     # for every error and in increasing time stamp.
183     ${time_stamp1}=  Convert Date  ${elog_entry[0]["Created"]}  epoch
184     ${time_stamp2}=  Convert Date  ${elog_entry[1]["Created"]}  epoch
185 
186     Should Be True  ${time_stamp2} > ${time_stamp1}
187 
188 
189 # TODO: openbmc/openbmc-test-automation#1789
190 Verify Setting Error Log As Resolved
191     [Documentation]  Verify modified field of error log is updated when error log is marked resolved.
192     [Tags]  Verify_Setting_Error_Log_As_Resolved
193 
194     Create Test PEL Log
195     ${elog_entry}=  Get Event Logs
196 
197     # Wait for 5 seconds after creating error log.
198     Sleep  5s
199 
200     # Mark error log as resolved by setting it to true.
201     Redfish.Patch  ${EVENT_LOG_URI}Entries/${elog_entry[0]["Id"]}  body={'Resolved':True}
202 
203     ${elog_entry}=  Get Event Logs
204 
205     # Example error log with resolve field set to true:
206     # {
207     #  "@odata.id": "/redfish/v1/Systems/system/LogServices/EventLog/Entries/2045",
208     #  "@odata.type": "#LogEntry.v1_8_0.LogEntry",
209     #  "AdditionalDataURI": "/redfish/v1/Systems/system/LogServices/EventLog/attachment/2045",
210     #  "Created": "2021-05-11T04:45:07+00:00",
211     #  "EntryType": "Event",
212     #  "Id": "2045",
213     #  "Message": "xyz.openbmc_project.Host.Error.Event",
214     #  "Modified": "2021-05-11T07:24:36+00:00",
215     #  "Name": "System Event Log Entry",
216     #  "Resolved": true,
217     #  "Severity": "OK"
218     # }
219 
220     Should Be Equal As Strings  ${elog_entry[0]["Resolved"]}  True
221 
222     # Difference created and modified time of error log should be around 5 seconds.
223     ${creation_time}=  Convert Date  ${elog_entry[0]["Created"]}  epoch
224     ${modification_time}=  Convert Date  ${elog_entry[0]["Modified"]}  epoch
225 
226     ${diff}=  Subtract Date From Date  ${modification_time}  ${creation_time}
227     ${diff}=  Convert To Number  ${diff}
228     Should Be True  4 < ${diff} < 8
229 
230 
231 Verify IPMI SEL Delete
232     [Documentation]  Verify IPMI SEL delete operation.
233     [Tags]  Verify_IPMI_SEL_Delete
234 
235     Redfish Purge Event Log
236     Create Test Error Log
237 
238     ${sel_list}=  Run IPMI Standard Command  sel list
239     Should Not Be Equal As Strings  ${sel_list}  SEL has no entries
240 
241     # Example of SEL List:
242     # 4 | 04/21/2017 | 10:51:16 | System Event #0x01 | Undetermined system hardware failure | Asserted
243 
244     ${sel_entry}=  Fetch from Left  ${sel_list}  |
245     ${sel_entry}=  Evaluate  $sel_entry.replace(' ','')
246     ${sel_entry}=  Convert To Integer  0x${sel_entry}
247 
248     ${sel_delete}=  Run IPMI Standard Command  sel delete ${sel_entry}
249     Should Be Equal As Strings  ${sel_delete}  Deleted entry ${sel_entry}
250     ...  case_insensitive=True
251 
252     ${sel_list}=  Run IPMI Standard Command  sel list
253     Should Be Equal As Strings  ${sel_list}  SEL has no entries
254     ...  case_insensitive=True
255 
256 
257 Delete Non Existing SEL Event Entry
258     [Documentation]  Delete non existing SEL event entry.
259     [Tags]  Delete_Non_Existing_SEL_Event_Entry
260 
261     ${sel_delete}=  Run Keyword And Expect Error  *
262     ...  Run IPMI Standard Command  sel delete 100
263     Should Contain  ${sel_delete}  Unable to delete entry
264     ...  case_insensitive=True
265 
266 
267 Delete Invalid SEL Event Entry
268     [Documentation]  Delete invalid SEL event entry.
269     [Tags]  Delete_Invalid_SEL_Event_Entry
270 
271     ${sel_delete}=  Run Keyword And Expect Error  *
272     ...  Run IPMI Standard Command  sel delete abc
273     Should Contain  ${sel_delete}  Given SEL ID 'abc' is invalid
274     ...  case_insensitive=True
275 
276 
277 Verify IPMI SEL Event Entries
278     [Documentation]  Verify IPMI SEL's entries info.
279     [Tags]  Verify_IPMI_SEL_Event_Entries
280 
281     # Generate error logs of random count.
282     ${count}=  Evaluate  random.randint(1, 5)  modules=random
283     Repeat Keyword  ${count}  Create Test Error Log
284 
285     ${sel_entries_count}=  Get IPMI SEL Setting  Entries
286     Should Be Equal As Strings  ${sel_entries_count}  ${count}
287 
288 
289 Verify IPMI SEL Event Last Add Time
290     [Documentation]  Verify IPMI SEL's last added timestamp.
291     [Tags]  Verify_IPMI_SEL_Event_Last_Add_Time
292 
293     Create Test Error Log
294     ${sel_time}=  Run IPMI Standard Command  sel time get
295     ${sel_time}=  Convert Date  ${sel_time}
296     ...  date_format=%m/%d/%Y %H:%M:%S  exclude_millis=True
297 
298     ${sel_last_add_time}=  Get IPMI SEL Setting  Last Add Time
299     ${sel_last_add_time}=  Convert Date  ${sel_last_add_time}
300     ...  date_format=%m/%d/%Y %H:%M:%S  exclude_millis=True
301 
302     ${time_diff}=
303     ...  Subtract Date From Date  ${sel_last_add_time}  ${sel_time}
304 
305     # Verify if the delay in current time check and last add SEL time
306     # is less or equals to 2 seconds.
307     Should Be True  ${time_diff} <= 2
308 
309 
310 Create Test Event Log And Delete
311     [Documentation]  Create an event log and delete it.
312     [Tags]  Create_Test_Event_Log_And_Delete
313 
314     Create Test Error Log
315     Redfish Purge Event Log
316     Event Log Should Not Exist
317 
318 
319 Create Multiple Test Event Logs And Delete All
320     [Documentation]  Create multiple event logs and delete all.
321     [Tags]  Create_Multiple_Test_Event_Logs_And_Delete_All
322 
323     Create Test Error Log
324     Create Test Error Log
325     Create Test Error Log
326     Redfish Purge Event Log
327     Event Log Should Not Exist
328 
329 
330 Create Two Test Event Logs And Delete One
331     [Documentation]  Create two event logs and delete the first entry.
332     [Tags]  Create_Two_Test_Event_Logs_And_Delete_One
333     [Setup]  Redfish Power Off  stack_mode=skip
334 
335     Redfish Purge Event Log
336     Create Test PEL Log
337     Create Test PEL Log
338     ${error_entries_before}=  Get Redfish Error Entries
339     Redfish.Delete  /redfish/v1/Systems/system/LogServices/EventLog/Entries/${error_entries_before[0]}
340 
341     ${error_entries_after}=  Get Redfish Error Entries
342     Should Not Contain  ${error_entries_after}  ${error_entries_before[0]}
343     Should Contain  ${error_entries_after}  ${error_entries_before[1]}
344 
345 
346 Verify Watchdog Timedout Event
347     [Documentation]  Trigger watchdog timed out and verify event log generated.
348     [Tags]  Verify_Watchdog_Timedout_Event
349 
350     Redfish Power On
351 
352     # Clear errors if there are any.
353     Redfish.Login
354     Redfish Purge Event Log
355 
356     Trigger Host Watchdog Error
357 
358     # Logging takes time to generate the timeout error.
359     Wait Until Keyword Succeeds  2 min  30 sec
360     ...  Verify Watchdog EventLog Content
361 
362 
363 Verify Event Logs Capping
364     [Documentation]  Verify event logs capping.
365     [Tags]  Verify_Event_Logs_Capping
366 
367     Redfish Purge Event Log
368 
369     ${cmd}=  Catenate  for i in {1..201}; do /tmp/tarball/bin/logging-test -c
370     ...  AutoTestSimple;sleep 1;done
371     BMC Execute Command  ${cmd}
372 
373     ${elogs}=  Get Event Logs
374     ${count}=  Get Length  ${elogs}
375     Run Keyword If  ${count} > 200
376     ...  Fail  Error logs created exceeded max capacity 200.
377 
378 
379 Test Event Log Wrapping
380     [Documentation]  Verify event log entries wraps when 200 max cap is reached.
381     [Tags]  Test_Event_Log_Wrapping
382 
383     # Restarting logging service in order to clear logs and get the next log
384     # ID set to 1.
385     BMC Execute Command
386     ...  systemctl restart xyz.openbmc_project.Logging.service
387     Sleep  10s  reason=Wait for logging service to restart properly.
388 
389     # Create ${max_num_event_logs} event logs.
390     ${cmd}=  Catenate  for i in {1..${max_num_event_logs}}; do /tmp/tarball/bin/logging-test -c
391     ...  AutoTestSimple;sleep 1;done
392     BMC Execute Command  ${cmd}
393 
394     # Verify that event logs with IDs 1 and ${max_num_event_logs} exist.
395     ${event_log}=  Get Event Logs
396 
397     ${log_entries}=  Filter Struct  ${event_log}  [('Id', '1')]
398     Rprint Vars  log_entries
399     Should Be Equal As Strings  ${log_entries[0]["Id"]}  1
400 
401     ${log_entries}=  Filter Struct  ${event_log}  [('Id', '${max_num_event_logs}')]
402     Rprint Vars  log_entries
403     Should Be Equal As Strings  ${log_entries[0]["Id"]}  ${max_num_event_logs}
404 
405     # Create event log and verify the entry ID, ${max_num_event_logs + 1}.
406     ${next_event_log_id}=  Set Variable  ${max_num_event_logs + 1}
407 
408     Create Test Error Log
409 
410     ${event_log}=  Get Event Logs
411 
412     ${log_entries}=  Filter Struct  ${event_log}  [('Id', '${next_event_log_id}')]
413     Rprint Vars  log_entries
414     Should Be Equal As Strings  ${log_entries[0]["Id"]}  ${next_event_log_id}
415 
416     # Event log 1 should be wrapped.
417     ${log_entries}=  Filter Struct  ${event_log}  [('Id', '1')]
418     Rprint Vars  log_entries
419 
420     ${length_log_entries}  Get Length  ${log_entries}
421     Should Be Equal As Integers  ${length_log_entries}  0
422     ...  msg=The event log should have wrapped such that entry ID 1 is now purged.
423 
424 
425 *** Keywords ***
426 
427 Suite Setup Execution
428    [Documentation]  Do test case setup tasks.
429 
430     Redfish.Login
431 
432     Redfish Purge Event Log
433 
434     ${status}=  Run Keyword And Return Status  Logging Test Binary Exist
435     Run Keyword If  ${status} == ${False}  Install Tarball
436 
437 
438 Suite Teardown Execution
439     [Documentation]  Do the post suite teardown.
440 
441     Redfish.Logout
442 
443 
444 Test Setup Execution
445    [Documentation]  Do test case setup tasks.
446 
447     Redfish Purge Event Log
448 
449     ${status}=  Run Keyword And Return Status  Logging Test Binary Exist
450     Run Keyword If  ${status} == ${False}  Install Tarball
451 
452 
453 Test Teardown Execution
454     [Documentation]  Do the post test teardown.
455 
456     FFDC On Test Case Fail
457     Redfish.Login
458     Redfish Purge Event Log
459 
460 
461 Get Redfish Error Entries
462     [Documentation]  Return Redfish error ids list.
463     ${error_uris}=  redfish_utils.get_member_list  /redfish/v1/Systems/system/LogServices/EventLog/Entries
464     ${error_ids}=  Create List
465 
466     FOR  ${error_uri}  IN  @{error_uris}
467       ${error_id}=  Fetch From Right  ${error_uri}  /
468       Append To List  ${error_ids}  ${error_id}
469     END
470 
471     [Return]  ${error_ids}
472 
473 
474 Event Log Should Not Exist
475     [Documentation]  Event log entries should not exist.
476 
477     ${elogs}=  Get Event Logs
478     Should Be Empty  ${elogs}  msg=System event log entry is not empty.
479 
480 
481 Event Log Should Exist
482     [Documentation]  Event log entries should exist.
483 
484     ${elogs}=  Get Event Logs
485     Should Not Be Empty  ${elogs}  msg=System event log entry is not empty.
486 
487 
488 Verify Watchdog EventLog Content
489     [Documentation]  Verify watchdog event log content.
490 
491     # Example:
492     # {
493     #    "@odata.context": "/redfish/v1/$metadata#LogEntry.LogEntry",
494     #    "@odata.id": "/redfish/v1/Systems/system/LogServices/EventLog/Entries/31",
495     #    "@odata.type": "#LogEntry.v1_4_0.LogEntry",
496     #    "Created": "2019-05-31T18:41:33+00:00",
497     #    "EntryType": "Event",
498     #    "Id": "31",
499     #    "Message": "org.open_power.Host.Boot.Error.WatchdogTimedOut",
500     #    "Name": "System DBus Event Log Entry",
501     #    "Severity": "Critical"
502     # }
503 
504     ${elog}=  Get Event Logs
505     Should Be Equal As Strings
506     ...  ${elog[0]["Message"]}  org.open_power.Host.Boot.Error.WatchdogTimedOut
507     ...  msg=Watchdog timeout event log was not found.
508     Should Be Equal As Strings
509     ...  ${elog[0]["Severity"]}  Critical
510     ...  msg=Watchdog timeout severity unexpected value.
511