Odd log messages

Hi guys,

I’ve suddenly started getting lots of repeated logs that look something like these. I have no idea what they mean or what would be causing them… there are no active calls right now. Any ideas as to what these are…???

2021-09-16 20:07:54] DEBUG[31061] chan_sip.c: Initializing initreq for method OPTIONS - callid [email protected] w.x.y.z:5060
[2021-09-16 20:07:54] DEBUG[31061] chan_sip.c: Stopping retransmission on ‘[email protected] w.x.y.z:5060’ of Request 102: Match Found
[2021-09-16 20:07:56] DEBUG[31061] chan_sip.c: Allocating new SIP dialog for [email protected] w.x.y.z:5060 - OPTIONS (No RTP)
[2021-09-16 20:07:56] DEBUG[31061] chan_sip.c: SIP call-id changed from ‘[email protected] w.x.y.z:5060’ to ‘[email protected] w.x.y.z:5060’
[2021-09-16 20:07:56] DEBUG[31061] chan_sip.c: Initializing initreq for method OPTIONS - callid [email protected] w.x.y.z:5060
[2021-09-16 20:07:56] DEBUG[31061] chan_sip.c: Stopping retransmission on ‘[email protected] w.x.y.z:5060’ of Request 102: Match Found
[2021-09-16 20:07:56] DEBUG[31061] chan_sip.c: Allocating new SIP dialog for [email protected] w.x.y.z:5060 - OPTIONS (No RTP)
[2021-09-16 20:07:56] DEBUG[31061] chan_sip.c: SIP call-id changed from ‘[email protected] w.x.y.z:5060’ to ‘[email protected] w.x.y.z:5060’
[2021-09-16 20:07:56] DEBUG[31061] chan_sip.c: Initializing initreq for method OPTIONS - callid [email protected] w.x.y.z:5060
[2021-09-16 20:07:56] DEBUG[31061] chan_sip.c: Stopping retransmission on ‘[email protected] w.x.y.z:5060’ of Request 102: Match Found
[2021-09-16 20:07:57] DEBUG[31061] chan_sip.c: Allocating new SIP dialog for [email protected] w.x.y.z:5060 - OPTIONS (No RTP)
[2021-09-16 20:07:57] DEBUG[31061] chan_sip.c: SIP call-id changed from ‘[email protected] w.x.y.z:5060’ to ‘[email protected] w.x.y.z:5060’
[2021-09-16 20:07:57] DEBUG[31061] chan_sip.c: Initializing initreq for method OPTIONS - callid [email protected] w.x.y.z:5060
[2021-09-16 20:07:57] DEBUG[31061] chan_sip.c: Stopping retransmission on ‘[email protected] w.x.y.z:5060’ of Request 102: Match Found
[2021-09-16 20:08:01] DEBUG[31061] chan_sip.c: Allocating new SIP dialog for [email protected] w.x.y.z:5060 - OPTIONS (No RTP)
[2021-09-16 20:08:01] DEBUG[31061] chan_sip.c: SIP call-id changed from ‘[email protected] w.x.y.z:5060’ to ‘[email protected] w.x.y.z:5060’
[2021-09-16 20:08:01] DEBUG[31061] chan_sip.c: Initializing initreq for method OPTIONS - callid [email protected] w.x.y.z:5060
[2021-09-16 20:08:01] DEBUG[31061] chan_sip.c: Stopping retransmission on ‘[email protected] w.x.y.z:5060’ of Request 102: Match Found
[2021-09-16 20:08:01] DEBUG[26236] manager.c: Running action ‘Login’
[2021-09-16 20:08:01] DEBUG[26237] manager.c: Running action ‘Login’
[2021-09-16 20:08:01] DEBUG[26237] manager.c: Running action ‘Command’
[2021-09-16 20:08:01] DEBUG[26237] manager.c: Running action ‘Command’
[2021-09-16 20:08:01] DEBUG[26237] manager.c: Running action ‘Command’
[2021-09-16 20:08:01] DEBUG[26237] manager.c: Running action ‘Command’
[2021-09-16 20:08:03] DEBUG[31061] chan_sip.c: Allocating new SIP dialog for [email protected] w.x.y.z:5060 - OPTIONS (No RTP)
[2021-09-16 20:08:03] DEBUG[31061] chan_sip.c: SIP call-id changed from ‘[email protected] w.x.y.z:5060’ to ‘[email protected] w.x.y.z:5060’
[2021-09-16 20:08:03] DEBUG[31061] chan_sip.c: Initializing initreq for method OPTIONS - callid [email protected] w.x.y.z:5060
[2021-09-16 20:08:03] DEBUG[31061] chan_sip.c: Stopping retransmission on ‘[email protected] w.x.y.z:5060’ of Request 102: Match Found
[2021-09-16 20:08:04] DEBUG[31061] chan_sip.c: Allocating new SIP dialog for [email protected] w.x.y.z:5060 - OPTIONS (No RTP)
[2021-09-16 20:08:04] DEBUG[31061] chan_sip.c: SIP call-id changed from ‘[email protected] w.x.y.z:5060’ to ‘[email protected] w.x.y.z:5060’
[2021-09-16 20:08:04] DEBUG[31061] chan_sip.c: Initializing initreq for method OPTIONS - callid [email protected] w.x.y.z:5060
[2021-09-16 20:08:04] DEBUG[31061] chan_sip.c: Stopping retransmission on ‘[email protected] w.x.y.z:5060’ of Request 102: Match Found
[2021-09-16 20:08:11] DEBUG[26236] manager.c: Running action ‘Command’
[2021-09-16 20:08:11] DEBUG[26236] manager.c: Running action ‘Command’
[2021-09-16 20:08:11] DEBUG[26236] manager.c: Running action ‘Command’
[2021-09-16 20:08:11] DEBUG[26236] manager.c: Running action ‘Command’
[2021-09-16 20:08:11] DEBUG[26236] manager.c: Running action ‘Command’
[2021-09-16 20:08:11] DEBUG[26236] manager.c: Running action ‘Command’
[2021-09-16 20:08:11] DEBUG[26236] manager.c: Running action ‘Command’
[2021-09-16 20:08:12] DEBUG[31061] chan_sip.c: Allocating new SIP dialog for [email protected] w.x.y.z:5060 - OPTIONS (No RTP)
[2021-09-16 20:08:12] DEBUG[31061] chan_sip.c: SIP call-id changed from ‘[email protected] w.x.y.z:5060’ to ‘[email protected] w.x.y.z:5060’
[2021-09-16 20:08:12] DEBUG[31061] chan_sip.c: Initializing initreq for method OPTIONS - callid [email protected] w.x.y.z:5060
[2021-09-16 20:08:12] DEBUG[31061] chan_sip.c: Stopping retransmission on ‘[email protected] w.x.y.z:5060’ of Request 102: Match Found
[2021-09-16 20:08:13] DEBUG[31061] chan_sip.c: Allocating new SIP dialog for 3c0a8e730658ad90 - REGISTER (No RTP)
[2021-09-16 20:08:13] DEBUG[31061] chan_sip.c: Store REGISTER’s src-IP:port for call routing.
[2021-09-16 20:08:13] DEBUG[31061] chan_sip.c: Allocating new SIP dialog for [email protected] w.x.y.z:5060 - OPTIONS (No RTP)
[2021-09-16 20:08:13] DEBUG[31061] chan_sip.c: SIP call-id changed from ‘[email protected] w.x.y.z:5060’ to ‘[email protected] w.x.y.z:5060’
[2021-09-16 20:08:13] DEBUG[31061] chan_sip.c: Initializing initreq for method OPTIONS - callid [email protected] w.x.y.z:5060
[2021-09-16 20:08:13] DEBUG[31061] chan_sip.c: Stopping retransmission on ‘[email protected] w.x.y.z:5060’ of Request 102: Match Found
[2021-09-16 20:08:14] DEBUG[31061] chan_sip.c: Allocating new SIP dialog for [email protected] w.x.y.z:5060 - OPTIONS (No RTP)
[2021-09-16 20:08:14] DEBUG[31061] chan_sip.c: SIP call-id changed from ‘[email protected] w.x.y.z:5060’ to ‘0[email protected] w.x.y.z:5060’
[2021-09-16 20:08:14] DEBUG[31061] chan_sip.c: Initializing initreq for method OPTIONS - callid [email protected] w.x.y.z:5060
[2021-09-16 20:08:14] DEBUG[31061] chan_sip.c: Stopping retransmission on ‘[email protected] w.x.y.z:5060’ of Request 102: Match Found
[2021-09-16 20:08:15] DEBUG[31061] chan_sip.c: Allocating new SIP dialog for [email protected] w.x.y.z:5060 - OPTIONS (No RTP)
[2021-09-16 20:08:15] DEBUG[31061] chan_sip.c: SIP call-id changed from ‘[email protected] w.x.y.z:5060’ to ‘[email protected] w.x.y.z:5060’
[2021-09-16 20:08:15] DEBUG[31061] chan_sip.c: Initializing initreq for method OPTIONS - callid [email protected] w.x.y.z:5060
[2021-09-16 20:08:15] DEBUG[31061] chan_sip.c: Stopping retransmission on ‘[email protected] w.x.y.z:5060’ of Request 102: Match Found
[2021-09-16 20:08:20] DEBUG[31061] chan_sip.c: Allocating new SIP dialog for [email protected] w.x.y.z:5060 - OPTIONS (No RTP)
[2021-09-16 20:08:20] DEBUG[31061] chan_sip.c: SIP call-id changed from ‘[email protected] w.x.y.z:5060’ to ‘[email protected] w.x.y.z:5060’

I think I must have turned on some additional logging? I ran asterisk -rvd, but apparently when I exited that session it didn’t turn off the -v or -d extras. I had to stop/start asterisk completely to get the messages reported above to stop.

Still, it begs the questions… what were all of those “call-id changed” lines about when there were no calls happening at all… not internal, not external, not voicemail, nothing. And, what are those “Login” and “Command” entries – no one was logging in and running commands either.

The chan_sip module uses the term “call” extremely broadly internally. Sending a qualify request (an OPTIONS) to a device, that’s a call. Sending them a NOTIFY with MWI, that’s a call. It’s essentially a SIP dialog.

As for the Login/Command, those are from AMI. I don’t work on FreePBX, but it probably has stuff logging in automatically and doing stuff.

Generally if you turn on debug level, you’re going to see this kind of stuff, and you’re going to get concerned for no reason.

Thanks for the explanation!

This topic was automatically closed 31 days after the last reply. New replies are no longer allowed.