Description

Enabled json logging engine, with the following setup:

What I see that certain json lines are truncated, for example

Troubleshooting

What I can observe is that seems to happens always with same "kind" of line, usually internal logs, which don't have callid etc.

Log Messages

The following first 3 lines are ok, then the latest is corrupted:

{ "time": "2025-04-04T15:51:44.448427533Z", "idx": 193, "pid": 200, "level": "DEBUG", "module": "core", "file": "core/receive.c", "line": 128, "function": "sip_check_fline", "message": "first line indicates a SIP reply" }
{ "time": "2025-04-04T15:51:44.448682606Z", "idx": 194, "pid": 201, "level": "DEBUG", "module": "core", "file": "core/receive.c", "line": 128, "function": "sip_check_fline", "message": "first line indicates a SIP reply" }
{ "time": "2025-04-04T15:52:14.448279053Z", "idx": 195, "pid": 202, "level": "DEBUG", "module": "core", "file": "core/receive.c", "line": 128, "function": "sip_check_fline", "message": "first line indicates a SIP reply" }
{ "time": "2025-04-04T15:52:14.448505797Z", "idx": 196, "pid": 203, "level": "DEBUG", "module": "core", "file": "core/receive.c"{ "time": "2025-04-04T15:52:14.448508084Z", "idx": 195, "pid": 202, "level": "DEBUG", "module": "core", "file": "core/parser/msg, "line": 128, "function": "sip_check_fline", "message": "first line indicates a SIP reply" }

or (notice 2nd line or 5th one)

{ "time": "2025-04-04T16:13:33.789641936Z", "idx": 221, "pid": 228, "level": "DEBUG", "module": "core", "file": "core/receive.c"{ "time": "2025-04-04T16:13:33.789642978Z", "idx": 222, "pid": 229, "level": "DEBUG", "module": "core", "file": "core/xavp.c", ", "line": 265, "function": "ksr_evrt_pre_routing", "callid": "5715efe40e9b7721-264@127.0.0.1", "ts": 1743783213.789640 , "message": "event route core:pre-routing not defined" }
line": 630, "function": "xavp_destroy_list", "callid": "5715efe40e9b7720-264@127.0.0.1", "ts": 1743783213.789527 , "message": "destroying xavp list (nil)" }
{ "time": "2025-04-04T16:13:33.789646470Z", "idx": 222, "pid": 229, "level": "DEBUG", "module": "core", "file": "core/xavp.c", "line": 630, "function": "xavp_destroy_list", "callid": "5715efe40e9b7720-264@127.0.0.1", "ts": 1743783213.789527 , "message": "destroying xavp list (nil)" }
{ "time": "2025-04-04T16:13:33.789648201Z", "idx": 221, "pid": 228, "level": "DEBUG", "module": "tm", "file": "t_lookup.c", "line": 1579, "function": "t_check_msg", "callid": "5715efe40e9b7721-264@127.0.0.1", "ts": 1743783213.789640 , "message": "msg (0x7f{ "time": "2025-04-04T16:13:33.789649346Z", "idx": 222, "pid": 229, "level": "DEBUG", "module": "core", "file": "core/receive.c"8f7a693c50) id=2/228 global id=1/228 T start=0xffffffffffffffff" }
, "line": 637, "function": "receive_msg", "callid": "5715efe40e9b7720-264@127.0.0.1", "ts": 1743783213.789527 , "message": "cleaning up" }
{ "time": "2025-04-04T16:13:33.789652839Z", "idx": 221, "pid": 228, "level": "DEBUG", "module": "tm", "file": "t_lookup.c", "line": 1424, "function": "t_reply_matching", "callid": "5715efe40e9b7721-264@127.0.0.1", "ts": 1743783213.789640 , "message": "t_reply_matching: hash 26404 label 0 branch 0" }

Additional Information

6.0.1

happens also with 5.8.x

Debian noble, docker container


Reply to this email directly, view it on GitHub, or unsubscribe.
You are receiving this because you are subscribed to this thread.Message ID: <kamailio/kamailio/issues/4203@github.com>

xadhoomxadhoom created an issue (kamailio/kamailio#4203)

Description

Enabled json logging engine, with the following setup:

What I see that certain json lines are truncated, for example

Troubleshooting

What I can observe is that seems to happens always with same "kind" of line, usually internal logs, which don't have callid etc.

Log Messages

The following first 3 lines are ok, then the latest is corrupted:

{ "time": "2025-04-04T15:51:44.448427533Z", "idx": 193, "pid": 200, "level": "DEBUG", "module": "core", "file": "core/receive.c", "line": 128, "function": "sip_check_fline", "message": "first line indicates a SIP reply" }
{ "time": "2025-04-04T15:51:44.448682606Z", "idx": 194, "pid": 201, "level": "DEBUG", "module": "core", "file": "core/receive.c", "line": 128, "function": "sip_check_fline", "message": "first line indicates a SIP reply" }
{ "time": "2025-04-04T15:52:14.448279053Z", "idx": 195, "pid": 202, "level": "DEBUG", "module": "core", "file": "core/receive.c", "line": 128, "function": "sip_check_fline", "message": "first line indicates a SIP reply" }
{ "time": "2025-04-04T15:52:14.448505797Z", "idx": 196, "pid": 203, "level": "DEBUG", "module": "core", "file": "core/receive.c"{ "time": "2025-04-04T15:52:14.448508084Z", "idx": 195, "pid": 202, "level": "DEBUG", "module": "core", "file": "core/parser/msg, "line": 128, "function": "sip_check_fline", "message": "first line indicates a SIP reply" }

or (notice 2nd line or 5th one)

{ "time": "2025-04-04T16:13:33.789641936Z", "idx": 221, "pid": 228, "level": "DEBUG", "module": "core", "file": "core/receive.c"{ "time": "2025-04-04T16:13:33.789642978Z", "idx": 222, "pid": 229, "level": "DEBUG", "module": "core", "file": "core/xavp.c", ", "line": 265, "function": "ksr_evrt_pre_routing", "callid": "5715efe40e9b7721-264@127.0.0.1", "ts": 1743783213.789640 , "message": "event route core:pre-routing not defined" }
line": 630, "function": "xavp_destroy_list", "callid": "5715efe40e9b7720-264@127.0.0.1", "ts": 1743783213.789527 , "message": "destroying xavp list (nil)" }
{ "time": "2025-04-04T16:13:33.789646470Z", "idx": 222, "pid": 229, "level": "DEBUG", "module": "core", "file": "core/xavp.c", "line": 630, "function": "xavp_destroy_list", "callid": "5715efe40e9b7720-264@127.0.0.1", "ts": 1743783213.789527 , "message": "destroying xavp list (nil)" }
{ "time": "2025-04-04T16:13:33.789648201Z", "idx": 221, "pid": 228, "level": "DEBUG", "module": "tm", "file": "t_lookup.c", "line": 1579, "function": "t_check_msg", "callid": "5715efe40e9b7721-264@127.0.0.1", "ts": 1743783213.789640 , "message": "msg (0x7f{ "time": "2025-04-04T16:13:33.789649346Z", "idx": 222, "pid": 229, "level": "DEBUG", "module": "core", "file": "core/receive.c"8f7a693c50) id=2/228 global id=1/228 T start=0xffffffffffffffff" }
, "line": 637, "function": "receive_msg", "callid": "5715efe40e9b7720-264@127.0.0.1", "ts": 1743783213.789527 , "message": "cleaning up" }
{ "time": "2025-04-04T16:13:33.789652839Z", "idx": 221, "pid": 228, "level": "DEBUG", "module": "tm", "file": "t_lookup.c", "line": 1424, "function": "t_reply_matching", "callid": "5715efe40e9b7721-264@127.0.0.1", "ts": 1743783213.789640 , "message": "t_reply_matching: hash 26404 label 0 branch 0" }

Additional Information

6.0.1

happens also with 5.8.x

Debian noble, docker container


Reply to this email directly, view it on GitHub, or unsubscribe.
You are receiving this because you are subscribed to this thread.Message ID: <kamailio/kamailio/issues/4203@github.com>