Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

tests/subsys/logging/log_timestamp/ failing on qemu_x86[_64] on main #72344

Closed
aescolar opened this issue May 6, 2024 · 2 comments · Fixed by #72345
Closed

tests/subsys/logging/log_timestamp/ failing on qemu_x86[_64] on main #72344

aescolar opened this issue May 6, 2024 · 2 comments · Fixed by #72345
Labels
bug The issue is a bug, or the PR is fixing a bug priority: high High impact/importance bug Regression Something, which was working, does not anymore

Comments

@aescolar
Copy link
Member

aescolar commented May 6, 2024 •
edited

Describe the bug
tests/subsys/logging/log_timestamp/logging.output.custom_timestamp is failing in main since #69705 was merged

To Reproduce
Steps to reproduce the behavior:

  1. twister -p qemu_x86 -T tests/subsys/logging/log_timestamp/ -s logging.output.custom_timestamp
  2. See error

Expected behavior
No errors

Impact
main CI broken

Logs and console output
https://github.com/zephyrproject-rtos/zephyr/actions/runs/8951164071/job/24587211348#step:11:3389

SeaBIOS (version zephyr-v1.0.0-0-g31d4e0e-dirty-20200714_234759-fv-az50-zephyr)
Booting from ROM..
*** Booting Zephyr OS build v3.6.0-3414-gfa7c05cf4718 ***
Running TESTSUITE test_timestamp
===================================================================
START - test_custom_timestamp

    Assertion failed at WEST_TOPDIR/zephyr/tests/subsys/logging/log_timestamp/src/log_timestamp_test.c:78: test_timestamp_test_custom_timestamp: strcmp(exp_str, mock_buffer) not equal to 0

 FAIL - test_custom_timestamp in 0.002 seconds
===================================================================
TESTSUITE test_timestamp failed.

------ TESTSUITE SUMMARY START ------

SUITE FAIL -   0.00% [test_timestamp]: pass = 0, fail = 1, skip = 0, total = 1 duration = 0.002 seconds
 - FAIL - [test_timestamp.test_custom_timestamp] duration = 0.002 seconds

------ TESTSUITE SUMMARY END ------

===================================================================
RunID: d540a6b01e39b244047af44d6af1d792
PROJECT EXECUTION FAILED

Environment (please complete the following information):

  • OS: Linux Ubuntu 22.04 (CI)
  • Toolchain Zephyr SDK (CI)
  • Commit SHA or Version used: fa7c05c

Additional context
Introduced by 7c03e5d
@aescolar aescolar added bug The issue is a bug, or the PR is fixing a bug priority: high High impact/importance bug Regression Something, which was working, does not anymore labels May 6, 2024
@aescolar aescolar mentioned this issue May 6, 2024
Merged
aescolar added a commit to aescolar/zephyr that referenced this issue May 6, 2024
@aescolar
Revert "kernel: retrieve system timer clock frequency at runtime or s…
c8102e1 
…tatic"

This reverts commit 7c03e5d.

zephyrproject-rtos#69705
Introduced a regression in main in which
tests/subsys/logging/log_timestamp
started failing. (See
zephyrproject-rtos#72344
for more info).
Let's revert the PR. It can be submitted after with the issue
fixed.

Signed-off-by: Alberto Escolar Piedras <alberto.escolar.piedras@nordicsemi.no>
aescolar added a commit to aescolar/zephyr that referenced this issue May 6, 2024
@aescolar
Revert "board: x86: enable system timer clock frequency at run time"
49e653a 
This reverts commit 8eabf80.

zephyrproject-rtos#69705
Introduced a regression in main in which
tests/subsys/logging/log_timestamp
started failing. (See
zephyrproject-rtos#72344
for more info).
Let's revert the PR. It can be submitted after with the issue
fixed.

Signed-off-by: Alberto Escolar Piedras <alberto.escolar.piedras@nordicsemi.no>
aescolar added a commit to aescolar/zephyr that referenced this issue May 6, 2024
@aescolar
Revert "tests: kernel: update test case with sys_clock_hw_cycles_per_…
d3bacd3 
…sec"

This reverts commit fd8ca83.

zephyrproject-rtos#69705
Introduced a regression in main in which
tests/subsys/logging/log_timestamp
started failing. (See
zephyrproject-rtos#72344
for more info).
Let's revert the PR. It can be submitted after with the issue
fixed.

Signed-off-by: Alberto Escolar Piedras <alberto.escolar.piedras@nordicsemi.no>
aescolar added a commit to aescolar/zephyr that referenced this issue May 6, 2024
@aescolar
Revert "drivers: timer: tsc: retrieve clock frequency of system timer…
0a88d64 
… at runtime"

This reverts commit d82f4a9.

zephyrproject-rtos#69705
Introduced a regression in main in which
tests/subsys/logging/log_timestamp
started failing. (See
zephyrproject-rtos#72344
for more info).
Let's revert the PR. It can be submitted after with the issue
fixed.

Signed-off-by: Alberto Escolar Piedras <alberto.escolar.piedras@nordicsemi.no>
@aescolar aescolar mentioned this issue May 6, 2024
Merged
@najumon1980
Copy link
Collaborator

The regression is due to following reason:
sys_clock_hw_cycles_per_sec() used in log_core_init() which invoked during cstart (EARLY init) but HPET driver init is PRE_KERNEL_2. So the z_clock_hw_cycles_per_sec need to init with some default CONFIG_SYS_CLOCK_HW_CYCLES_PER_SEC (though it is not right) or ideally need to init z_clock_hw_cycles_per_sec run time during cstart (EARLY init).

@najumon1980 najumon1980 mentioned this issue May 6, 2024
Open
@najumon1980
Copy link
Collaborator

Provided following fix for the regression:
#72352

najumon1980 added a commit to najumon1980/zephyr that referenced this issue May 6, 2024
@najumon1980
kernel: sys_timer: fix regression timescale conversions
17eda03 
fixes for log_timestamp test case failer (issue zephyrproject-rtos#72344) due
to timer PR regression. The regression is due to following reason:
sys_clock_hw_cycles_per_sec() used in log_core_init() which invoked
during cstart (EARLY init) but HPET driver init is PRE_KERNEL_2.
So the z_clock_hw_cycles_per_sec need to init with some default
CONFIG_SYS_CLOCK_HW_CYCLES_PER_SEC (though it is not right) or
ideally need to init z_clock_hw_cycles_per_sec run time during
cstart (EARLY init). Current Fixes: put back the older code for
static initialization for z_clock_hw_cycles_per_sec with
CONFIG_SYS_CLOCK_HW_CYCLES_PER_SEC. This will be later update
with run time during HPTET driver init (PRE_KERNEL2).

Signed-off-by: Najumon B.A <najumon.ba@intel.com>
jhedberg pushed a commit that referenced this issue May 6, 2024
@aescolar @jhedberg
Revert "kernel: retrieve system timer clock frequency at runtime or s…
2f5e939 
…tatic"

This reverts commit 7c03e5d.

#69705
Introduced a regression in main in which
tests/subsys/logging/log_timestamp
started failing. (See
#72344
for more info).
Let's revert the PR. It can be submitted after with the issue
fixed.

Signed-off-by: Alberto Escolar Piedras <alberto.escolar.piedras@nordicsemi.no>
jhedberg pushed a commit that referenced this issue May 6, 2024
@aescolar @jhedberg
Revert "board: x86: enable system timer clock frequency at run time"
b1c3ba7 
This reverts commit 8eabf80.

#69705
Introduced a regression in main in which
tests/subsys/logging/log_timestamp
started failing. (See
#72344
for more info).
Let's revert the PR. It can be submitted after with the issue
fixed.

Signed-off-by: Alberto Escolar Piedras <alberto.escolar.piedras@nordicsemi.no>
jhedberg pushed a commit that referenced this issue May 6, 2024
@aescolar @jhedberg
Revert "tests: kernel: update test case with sys_clock_hw_cycles_per_…
ba4bbe9 
…sec"

This reverts commit fd8ca83.

#69705
Introduced a regression in main in which
tests/subsys/logging/log_timestamp
started failing. (See
#72344
for more info).
Let's revert the PR. It can be submitted after with the issue
fixed.

Signed-off-by: Alberto Escolar Piedras <alberto.escolar.piedras@nordicsemi.no>
jhedberg pushed a commit that referenced this issue May 6, 2024
@aescolar @jhedberg
Revert "drivers: timer: tsc: retrieve clock frequency of system timer…
0b87cb1 
… at runtime"

This reverts commit d82f4a9.

#69705
Introduced a regression in main in which
tests/subsys/logging/log_timestamp
started failing. (See
#72344
for more info).
Let's revert the PR. It can be submitted after with the issue
fixed.

Signed-off-by: Alberto Escolar Piedras <alberto.escolar.piedras@nordicsemi.no>
coreboot-org-bot pushed a commit to coreboot/zephyr-cros that referenced this issue May 7, 2024
@aescolar
Revert "kernel: retrieve system timer clock frequency at runtime or s…
aa22a50 
…tatic"

This reverts commit 7c03e5d.

zephyrproject-rtos/zephyr#69705
Introduced a regression in main in which
tests/subsys/logging/log_timestamp
started failing. (See
zephyrproject-rtos/zephyr#72344
for more info).
Let's revert the PR. It can be submitted after with the issue
fixed.

(cherry picked from commit 2f5e939)

Original-Signed-off-by: Alberto Escolar Piedras <alberto.escolar.piedras@nordicsemi.no>
GitOrigin-RevId: 2f5e939
Change-Id: I904d99c435ed85eaec1989ef2bdcca04d9f3cb6d
Reviewed-on: https://chromium-review.googlesource.com/c/chromiumos/third_party/zephyr/+/5520239
Reviewed-by: Ting Shen <phoenixshen@chromium.org>
Commit-Queue: Ting Shen <phoenixshen@chromium.org>
Tested-by: Ting Shen <phoenixshen@chromium.org>
Tested-by: ChromeOS Prod (Robot) <chromeos-ci-prod@chromeos-bot.iam.gserviceaccount.com>
coreboot-org-bot pushed a commit to coreboot/zephyr-cros that referenced this issue May 7, 2024
@aescolar
Revert "board: x86: enable system timer clock frequency at run time"
771a469 
This reverts commit 8eabf80.

zephyrproject-rtos/zephyr#69705
Introduced a regression in main in which
tests/subsys/logging/log_timestamp
started failing. (See
zephyrproject-rtos/zephyr#72344
for more info).
Let's revert the PR. It can be submitted after with the issue
fixed.

(cherry picked from commit b1c3ba7)

Original-Signed-off-by: Alberto Escolar Piedras <alberto.escolar.piedras@nordicsemi.no>
GitOrigin-RevId: b1c3ba7
Change-Id: I47c186d80a29c39d7e2f7f09ac654d4b9b4cea2b
Reviewed-on: https://chromium-review.googlesource.com/c/chromiumos/third_party/zephyr/+/5520240
Commit-Queue: Ting Shen <phoenixshen@chromium.org>
Reviewed-by: Ting Shen <phoenixshen@chromium.org>
Tested-by: ChromeOS Prod (Robot) <chromeos-ci-prod@chromeos-bot.iam.gserviceaccount.com>
Tested-by: Ting Shen <phoenixshen@chromium.org>
coreboot-org-bot pushed a commit to coreboot/zephyr-cros that referenced this issue May 7, 2024
@aescolar
Revert "tests: kernel: update test case with sys_clock_hw_cycles_per_…
b026829 
…sec"

This reverts commit fd8ca83.

zephyrproject-rtos/zephyr#69705
Introduced a regression in main in which
tests/subsys/logging/log_timestamp
started failing. (See
zephyrproject-rtos/zephyr#72344
for more info).
Let's revert the PR. It can be submitted after with the issue
fixed.

(cherry picked from commit ba4bbe9)

Original-Signed-off-by: Alberto Escolar Piedras <alberto.escolar.piedras@nordicsemi.no>
GitOrigin-RevId: ba4bbe9
Change-Id: I39bcc9dc7f77d5e43cc73f257d1480ae44f92b06
Reviewed-on: https://chromium-review.googlesource.com/c/chromiumos/third_party/zephyr/+/5520241
Tested-by: Ting Shen <phoenixshen@chromium.org>
Tested-by: ChromeOS Prod (Robot) <chromeos-ci-prod@chromeos-bot.iam.gserviceaccount.com>
Reviewed-by: Ting Shen <phoenixshen@chromium.org>
Commit-Queue: Ting Shen <phoenixshen@chromium.org>
coreboot-org-bot pushed a commit to coreboot/zephyr-cros that referenced this issue May 7, 2024
@aescolar
Revert "drivers: timer: tsc: retrieve clock frequency of system timer…
dc92d06 
… at runtime"

This reverts commit d82f4a9.

zephyrproject-rtos/zephyr#69705
Introduced a regression in main in which
tests/subsys/logging/log_timestamp
started failing. (See
zephyrproject-rtos/zephyr#72344
for more info).
Let's revert the PR. It can be submitted after with the issue
fixed.

(cherry picked from commit 0b87cb1)

Original-Signed-off-by: Alberto Escolar Piedras <alberto.escolar.piedras@nordicsemi.no>
GitOrigin-RevId: 0b87cb1
Change-Id: I36faabf3f6afda8749f28122073de3b7d1dddfd3
Reviewed-on: https://chromium-review.googlesource.com/c/chromiumos/third_party/zephyr/+/5520242
Tested-by: Ting Shen <phoenixshen@chromium.org>
Reviewed-by: Ting Shen <phoenixshen@chromium.org>
Tested-by: ChromeOS Prod (Robot) <chromeos-ci-prod@chromeos-bot.iam.gserviceaccount.com>
Commit-Queue: Ting Shen <phoenixshen@chromium.org>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug The issue is a bug, or the PR is fixing a bug priority: high High impact/importance bug Regression Something, which was working, does not anymore
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Revert 69705 and fix #72344 aescolar/zephyr
2 participants
@aescolar @najumon1980