Why is my code producing different values for the same code

Question

I'm working on a STM32L072 and have been creating a timeLimit class which job it is to track the amount of time that has passed and if it has gone over the set time. If the required time has elapsed the class will return this so time dependent code can be executed. This class uses ticks internally and as such the function HW_RTC_Tick2ms is used to convert back to ms. This function is provided by ST in their I-CUBE-LRWAN Expansion Package of which I'm using v1.2.1.

I have written the printTimeToSend function for logging/debugging and monitoring reasons. The original form prints out the current amount of elapsed time, the amount of time set to be waited and how much time until the next timeout.

The problem is that this code returns 134318771 when used in the original manner. I have split all the separate steps into variables and printed these out to trace where the conversion went wrong. BUT, it returns the correct results when split into separate steps.

PPRINTF is a printf variant supplied by ST and is blocking. It uses a circulair buffer internally and has the same syntax for parameter passing.
The __nop() operations have been inserted for debugging. I use Keil for development and the stackviewer has trouble with updating variables sometimes in C++. As such the __nop() are a precaution to make sure the value is updated and visible before executing the next bit of relevant code
HW_RTC_GetTimerValue get the current time value in ticks.

/** @author Tarick Welling
 * @brief outputs the current time, timeout time and time to transmission.
 */
void timeLimit::printTimeToSend() const {
  PPRINTF("%s\r\n", __PRETTY_FUNCTION__);
  auto now = HW_RTC_GetTimerValue();
  PPRINTF("now: %i\r\n", now);
  PPRINTF("now: %i\r\n",HW_RTC_Tick2ms(now));
  __nop();
  __nop();
  auto then = startTime;
  PPRINTF("then: %i\r\n", then);
  PPRINTF("then: %i\r\n",HW_RTC_Tick2ms(then));
  __nop();
  __nop();
  auto between = sendDelayTime;
  PPRINTF("between: %i\r\n", between);
  PPRINTF("between: %i\r\n",HW_RTC_Tick2ms(between));
  __nop();
  __nop();
  auto diff = (now - then);
  PPRINTF("diff: %i\r\n", diff);
  PPRINTF("diff: %i\r\n",HW_RTC_Tick2ms(diff));
  __nop();
  __nop();
  PPRINTF("bigger: %i\r\n", between < diff);
  PPRINTF("bigger: %i\r\n",HW_RTC_Tick2ms(between) < HW_RTC_Tick2ms(diff));

  PPRINTF("SEMI\r\n");
  auto subdiv = now - then;
  PPRINTF("\t current time: %i\r\n", __PRETTY_FUNCTION__,
          HW_RTC_Tick2ms(subdiv));
  PPRINTF("\t timeout time: %i\r\n", __PRETTY_FUNCTION__,
          HW_RTC_Tick2ms(between));
  PPRINTF("\t time to send: %i\r\n", __PRETTY_FUNCTION__,
          HW_RTC_Tick2ms(between - subdiv));

  PPRINTF("ORI\r\n");
  PPRINTF("\t current time: %i\r\n", __PRETTY_FUNCTION__,
          HW_RTC_Tick2ms(HW_RTC_GetTimerValue() - startTime));
  PPRINTF("\t timeout time: %i\r\n", __PRETTY_FUNCTION__,
          HW_RTC_Tick2ms(sendDelayTime));
  PPRINTF("\t time to send: %i\r\n", __PRETTY_FUNCTION__,
          HW_RTC_Tick2ms(sendDelayTime - (HW_RTC_GetTimerValue() - startTime)));
}

Output:

void timeLimit::printTimeToSend() const
now: 9702
now: 9474
then: 837
then: 817
between: 7372
between: 7199
diff: 8865
diff: 8657
bigger: 1
bigger: 1
SEMI
         current time: 134318771
         timeout time: 134318771
         time to send: 134318771
ORI
         current time: 134318771
         timeout time: 134318771
         time to send: 134318771

TimerTime_t HW_RTC_Tick2ms(uint32_t tick) {
  uint32_t seconds = tick >> 0x0A;
  tick = tick & 0x03FF;
  return ((seconds * 1000) + ((tick * 1000) >> 0x0A));
}

I'm not able to reason my way from 134318771 which is 0x8018AB3 and 1000000000011000101010110011 be it bit flipped, shifted or otherwise modified in place to the original values.

The architecture of the system is 32 bits and as such the should be more than enough space for all the values which is confirmed in the demonstration of the concept.

Answer 1

All your print calls at the end of your function look like this.

PPRINTF("\t current time: %i\r\n", __PRETTY_FUNCTION__,
          HW_RTC_Tick2ms(subdiv));

You want to format an integer but you provide a C-string and an integer.
134318771 is probably the decimal representation of the address of the C-string __PRETTY_FUNCTION__.

You need to make the format and the parameters match.

PPRINTF("\t current time: %i\r\n", HW_RTC_Tick2ms(subdiv));

or

PPRINTF("\t %s current time: %i\r\n", __PRETTY_FUNCTION__,
          HW_RTC_Tick2ms(subdiv));