[v3.7.0-rc3] adc_stm32 ASSERTION FAIL policy.c [cnt >= 1] Unbalanced state lock get/put

[zafersn]

ASSERTION FAIL [cnt >= 1] @ WEST_TOPDIR/zephyr/subsys/pm/policy.c:308
        Unbalanced state lock get/put
[00:02:05.576,000] <err> os: r0/a1:  0x00000004  r1/a2:  0x00000134  r2/a3:  0x00000038
[00:02:05.576,000] <err> os: r3/a4:  0x00000004 r12/ip:  0x00000003 r14/lr:  0x08014ec7
[00:02:05.576,000] <err> os:  xpsr:  0x2100004d
[00:02:05.576,000] <err> os: s[ 0]:  0x080684dc  s[ 1]:  0x20001a38  s[ 2]:  0x00000008  s[ 3]:  0x08060f65
[00:02:05.576,000] <err> os: s[ 4]:  0x00000008  s[ 5]:  0x00000000  s[ 6]:  0x00000008  s[ 7]:  0x08018c39
[00:02:05.576,000] <err> os: s[ 8]:  0x00000000  s[ 9]:  0xffffffbc  s[10]:  0xaaaaaaaa  s[11]:  0xaaaaaaaa
[00:02:05.576,000] <err> os: s[12]:  0xaaaaaaaa  s[13]:  0xaaaaaaaa  s[14]:  0xaaaaaaaa  s[15]:  0xaaaaaaaa
[00:02:05.576,000] <err> os: fpscr:  0xaaaaaaaa
[00:02:05.576,000] <err> os: Faulting instruction address (r15/pc): 0x08059c56
[00:02:05.576,000] <err> os: >>> ZEPHYR FATAL ERROR 4: Kernel panic on CPU 0
[00:02:05.576,000] <err> os: Fault during interrupt handling

[00:02:05.576,000] <err> os: Current thread: 0x2000c4d0 (unknown)
[00:02:06.072,000] <err> os: Halting system

After having this error, I noticed that pm_policy_state_lock_put(PM_STATE_SUSPEND_TO_IDLE,PM_ALL_SUBSTATES); called more (options.extra_samplings times) than pm_policy_state_lock_get(PM_STATE_SUSPEND_TO_IDLE, PM_ALL_SUBSTATES); only one time in adc_stm32_read function.

so I fixed the issue by replacing if (++data->samples_count == data->channel_count) condition with if (++data->samples_count == data->ctx.options.extra_samplings)

so I added additional logs to see how many times lock_put and / get functions called: Please see:

ADC reading[0]: - adc@46021000, channel 15: 
[00:02:05.575,000] <dbg> adc_stm32: adc_stm32_read: 1167 WEST_TOPDIR/zephyr/drivers/adc/adc_stm32.c
[00:02:05.575,000] <dbg> adc_stm32: adc_stm32_start_conversion: Starting conversion
[00:02:05.575,000] <dbg> adc_stm32: adc_stm32_isr: 1124 WEST_TOPDIR/zephyr/drivers/adc/adc_stm32.c 1 1
[00:02:05.575,000] <dbg> adc_stm32: adc_stm32_start_conversion: Starting conversion
[00:02:05.575,000] <dbg> adc_stm32: adc_stm32_isr: adc@46021000 ISR triggered.
[00:02:05.575,000] <dbg> adc_stm32: adc_stm32_isr: 1124 WEST_TOPDIR/zephyr/drivers/adc/adc_stm32.c 1 1
[00:02:05.575,000] <dbg> adc_stm32: adc_stm32_start_conversion: Starting conversion
[00:02:05.575,000] <dbg> adc_stm32: adc_stm32_isr: adc@46021000 ISR triggered.
[00:02:05.575,000] <dbg> adc_stm32: adc_stm32_isr: 1124 WEST_TOPDIR/zephyr/drivers/adc/adc_stm32.c 1 1
[00:02:05.575,000] <dbg> adc_stm32: adc_stm32_start_conversion: Starting conversion
[00:02:05.575,000] <dbg> adc_stm32: adc_stm32_isr: adc@46021000 ISR triggered.
[00:02:05.575,000] <dbg> adc_stm32: adc_stm32_isr: 1124 WEST_TOPDIR/zephyr/drivers/adc/adc_stm32.c 1 1
[00:02:05.575,000] <dbg> adc_stm32: adc_stm32_start_conversion: Starting conversion
[00:02:05.575,000] <dbg> adc_stm32: adc_stm32_isr: adc@46021000 ISR triggered.
[00:02:05.575,000] <dbg> adc_stm32: adc_stm32_isr: 1124 WEST_TOPDIR/zephyr/drivers/adc/adc_stm32.c 1 1
[00:02:05.576,000] <dbg> adc_stm32: adc_stm32_start_conversion: Starting conversion
[00:02:05.576,000] <dbg> adc_stm32: adc_stm32_isr: adc@46021000 ISR triggered.
[00:02:05.576,000] <dbg> adc_stm32: adc_stm32_isr: 1124 WEST_TOPDIR/zephyr/drivers/adc/adc_stm32.c 1 1
[00:02:05.576,000] <dbg> adc_stm32: adc_stm32_start_conversion: Starting conversion
[00:02:05.576,000] <dbg> adc_stm32: adc_stm32_isr: adc@46021000 ISR triggered.
[00:02:05.576,000] <dbg> adc_stm32: adc_stm32_isr: 1124 WEST_TOPDIR/zephyr/drivers/adc/adc_stm32.c 1 1
[00:02:05.576,000] <dbg> adc_stm32: adc_stm32_start_conversion: Starting conversion
[00:02:05.576,000] <dbg> adc_stm32: adc_stm32_isr: adc@46021000 ISR triggered.
[00:02:05.576,000] <dbg> adc_stm32: adc_stm32_isr: 1124 WEST_TOPDIR/zephyr/drivers/adc/adc_stm32.c 1 1
[00:02:05.576,000] <dbg> adc_stm32: adc_stm32_start_conversion: Starting conversion
[00:02:05.576,000] <dbg> adc_stm32: adc_stm32_isr: adc@46021000 ISR triggered.
[00:02:05.576,000] <dbg> adc_stm32: adc_stm32_isr: 1124 WEST_TOPDIR/zephyr/drivers/adc/adc_stm32.c 1 1
[00:02:05.576,000] <dbg> adc_stm32: adc_stm32_start_conversion: Starting conversion
[00:02:05.576,000] <dbg> adc_stm32: adc_stm32_isr: adc@46021000 ISR triggered.
[00:02:05.576,000] <dbg> adc_stm32: adc_stm32_isr: 1124 WEST_TOPDIR/zephyr/drivers/adc/adc_stm32.c 1 1
[00:02:05.576,000] <dbg> adc_stm32: adc_stm32_isr: adc@46021000 ISR triggered.
63  = ADC_IN: 1771 mV = VIN: 3649 mV
63  = ADC_IN: 1771 mV = VIN: 3649 mV
63ASSERTION FAIL [cnt >= 1] @ WEST_TOPDIR/zephyr/subsys/pm/policy.c:308
        Unbalanced state lock get/put
[00:02:05.576,000] <err> os: r0/a1:  0x00000004  r1/a2:  0x00000134  r2/a3:  0x00000038
[00:02:05.576,000] <err> os: r3/a4:  0x00000004 r12/ip:  0x00000003 r14/lr:  0x08014ec7
[00:02:05.576,000] <err> os:  xpsr:  0x2100004d
[00:02:05.576,000] <err> os: s[ 0]:  0x080684dc  s[ 1]:  0x20001a38  s[ 2]:  0x00000008  s[ 3]:  0x08060f65
[00:02:05.576,000] <err> os: s[ 4]:  0x00000008  s[ 5]:  0x00000000  s[ 6]:  0x00000008  s[ 7]:  0x08018c39
[00:02:05.576,000] <err> os: s[ 8]:  0x00000000  s[ 9]:  0xffffffbc  s[10]:  0xaaaaaaaa  s[11]:  0xaaaaaaaa
[00:02:05.576,000] <err> os: s[12]:  0xaaaaaaaa  s[13]:  0xaaaaaaaa  s[14]:  0xaaaaaaaa  s[15]:  0xaaaaaaaa
[00:02:05.576,000] <err> os: fpscr:  0xaaaaaaaa
[00:02:05.576,000] <err> os: Faulting instruction address (r15/pc): 0x08059c56
[00:02:05.576,000] <err> os: >>> ZEPHYR FATAL ERROR 4: Kernel panic on CPU 0
[00:02:05.576,000] <err> os: Fault during interrupt handling

[00:02:05.576,000] <err> os: Current thread: 0x2000c4d0 (unknown)
[00:02:06.072,000] <err> os: Halting system