Log times do not match event time

Hi all!

Can anyone explain why the following log times do not match and seem out of
sync? I could not find any reason for this, and neither any docs explaining
why/how.

Jan 14 16:41:07  ire-lab-kamailio1 kamailio[1473633]: INFO: {
1768405267.124447 1473633 1 1 OPTIONS 123} <script>: evapi:message-received
- Received EVAPI message: HEARTBEAT
Jan 14 16:41:11 ire-lab-kamailio1 kamailio[1473632]: DEBUG: {
1768400692.108269 1473632 1 1 OPTIONS 123} evapi [evapi_dispatch.c:517]:
evapi_recv_client(): {0} [10.20.0.1:54190] - received  [9:HEARTBEAT,] (12)
(0)
Jan 14 16:41:11   ire-lab-kamailio1 kamailio[1473632]: DEBUG: {
1768400692.108269 1473632 1 1 OPTIONS 123} evapi [evapi_dispatch.c:611]:
evapi_recv_client(): queueing event route for frame: [HEARTBEAT] (9)
Jan 14 16:41:11   ire-lab-kamailio1 kamailio[1473632]: DEBUG: {
1768400692.108269 1473632 1 1 OPTIONS 123} evapi [evapi_dispatch.c:140]:
evapi_queue_add(): adding message to queue [HEARTBEAT]
Jan 14 16:41:11   ire-lab-kamailio1 kamailio[1473632]: DEBUG: {
1768400692.108269 1473632 1 1 OPTIONS 123} <core>
[core/mem/q_malloc.c:402]: qm_malloc(): qm_malloc(0x7fc804ae6000, 42)
called from evapi: evapi_dispatch.c: evapi_queue_add(142)
Jan 14 16:41:11 ire-lab-kamailio1 kamailio[1473632]: DEBUG: {
1768400692.108269 1473632 1 1 OPTIONS 123} <core>
[core/mem/q_malloc.c:449]: qm_malloc(): qm_malloc(0x7fc804ae6000, 48)
returns address 0x7fc805afd620 frag. 0x7fc805afd5e0 (size=48) on 1 -th hit
Jan 14 16:41:11   ire-lab-kamailio1 kamailio[1473635]: DEBUG: {
1768405257.579389 1473635 1 1 OPTIONS 123} evapi [evapi_dispatch.c:187]:
evapi_queue_get(): getting message from queue [HEARTBEAT]
Jan 14 16:41:11 ire-lab-kamailio1 kamailio[1473635]: DEBUG: {
1768405257.579389 1473635 1 1 OPTIONS 123} evapi [evapi_dispatch.c:880]:
evapi_run_worker(): processing task: 0x7fc805afd620 [HEARTBEAT]

The events are sequential and the server is only receiving OPTIONS, nothing
else (it is a DEV server). So, if events are sequential, why are there
minutes (sometimes hours) of difference between the yellow timestamps and
green timestamps?

 1768405267.124447 = 14 January 2026 15:41:07.124
1768400692.108269 = 14 January 2026 14:24:52.108
Difference = circa 1h17min ....

I understand that the process ($pp or PID) are different, but event times
should be sequential, right?

Kamailio settings for log prefix:
log_prefix_mode = 1
log_prefix="{$TV(Sn) $pp $mt $hdr(CSeq) $ci} "

Atenciosamente / Kind Regards / Cordialement / Un saludo,


*Sérgio Charrua*

__________________________________________________________
Kamailio - Users Mailing List - Non Commercial Discussions -- [email protected]
To unsubscribe send an email to [email protected]
Important: keep the mailing list in the recipients, do not reply only to the sender!