Error in log because PJSIP removing header when none exist

FreePBX Providers
1

This is what I have:
PBX Version:16.0.19
PBX Distro:12.7.8-2203-1.sng7
Asterisk Version:16.24.0

Outbound calls via a trunk generates this error:
res_pjsip_header_funcs.c: No headers had been previously added to this session
As per this post previously done here (Error in log because PJSIP removing header when none exist), the worker round suggested to copy the func-apply-sipheaders block (lines 10680 to 10694) into /etc/asterisk/extensions_override_freepbx.conf, doesn’t seem to work because I have nothing in the extensions_override_freepbx.conf file.

Here is my pastebin URL for logs: Trunk Error - FreePBX Pastebin

2

Is there any issue here other than a log error? Are calls working as expected?

3

@lgaetz Calls drop and i get all extensions busy. So no call don’t work.

So i set up a CHAN-SIP Trunk, now I don’t get the headers error but service unavailable as show in part of the logs below::

[2022-06-13 16:00:52] VERBOSE[50620][C-00000019] app_dial.c: Called SIP/Sip_OUT_test/0436

1874[2022-06-13 16:00:52] VERBOSE[2954][C-00000019] chan_sip.c: Got SIP response 503 “Service Unavailable” back from xxxxxxx:5060

1875[2022-06-13 16:00:52] VERBOSE[50620][C-00000019] app_dial.c: SIP/Sip_OUT_test-00000012 is circuit-busy

1876[2022-06-13 16:00:52] VERBOSE[50620][C-00000019] app_dial.c: Everyone is busy/congested at this time (1:0/1/0)

4

I don’t believe the log error has anything to do with your call failure. It may be a misconfig of your trunk, or an issue with your SIP account. Also chan_sip is deprecated, you should be using pjsip.

5

@lgaetz I believe my SIP account is okay as well as the trunk, because when i use the same trunk to another FreePBX server, I am able to call/receive calls from extensions on that server. To the cisco cucm is where I get the header session error. Any idea of logs i can share that could help debugging?

6

At the Asterisk command prompt, type
pjsip set logger on
make a failing call and paste a new log

7

@Stewart1 here is the link.
https://pastebin.freepbx.org/view/9632d053

8

CUCM rejected the call and in the SIP response gave this:

Warning: 399 FB-CUCM1 "Unable to find a device handler for the request received on port 5060 from 172.30.1.144"

What exactly it is looking for, or what needs to change, I do not know.

9

Just guessing, perhaps

10

@Stewart1

Thanks for this,

Now this is what i have as logs…Unable to find a device handler for the request received on port 5060 from

Filter

Highlight (None)

Auto-Scroll

2[2022-06-13 18:09:15] ERROR[2954] chan_sip.c: Serious Network Trouble; __sip_xmit returns error for pkt data

3[2022-06-13 18:09:18] VERBOSE[2921] res_pjsip_logger.c: <— Received SIP request (1802 bytes) from TCP:192.168.1.19:49406 —>

4INVITE sip:[email protected];user=phone SIP/2.0

5Via: SIP/2.0/TCP 192.168.1.19:49406;branch=z9hG4bK6de48c83

6From: “DM-7070” sip:[email protected];tag=00ccfca768da006c7e48e592-307a5643

7To: sip:[email protected]

8Call-ID: [email protected]

9Max-Forwards: 70

10Session-ID: 37a5b0a000105000a00000ccfca768da;remote=00000000000000000000000000000000

11Date: Mon, 13 Jun 2022 15:09:17 GMT

12CSeq: 101 INVITE

13User-Agent: Cisco-CP7811/11.0.1

14Contact: sip:[email protected]:49406;transport=tcp;+u.sip!devicename.ccm.cisco.com=“SEP00CCFCA768DA”

15Expires: 180

16Accept: application/sdp

17Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE,INFO

18Remote-Party-ID: “DM-7070” sip:[email protected];party=calling;id-type=subscriber;privacy=off;screen=yes

19Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-7.0.0,X-cisco-xsi-8.5.1

20Allow-Events: kpml,dialog

21Authorization: Digest username=“7070”,realm=“asterisk”,uri="sip:[email protected];user=phone",response=“8586d8dbb76251f953344812d24986d9”,nonce=“1655132464/3f0e3a4fdc49a02e07519b477a36765c”,opaque=“714ee2701ab61236”,cnonce=“7a9d6baf”,qop=auth,nc=00000003,algorithm=md5

22Content-Length: 350

23Content-Type: application/sdp

24Content-Disposition: session;handling=optional

25

26v=0

27o=Cisco-SIPUA 16962 0 IN IP4 192.168.1.19

28s=SIP Call

29b=AS:4064

30t=0 0

31m=audio 31510 RTP/AVP 0 8 116 18 101

32c=IN IP4 192.168.1.19

33b=TIAS:64000

34a=rtpmap:0 PCMU/8000

35a=rtpmap:8 PCMA/8000

36a=rtpmap:116 iLBC/8000

37a=fmtp:116 mode=20

38a=rtpmap:18 G729/8000

39a=fmtp:18 annexb=yes

40a=rtpmap:101 telephone-event/8000

41a=fmtp:101 0-15

42a=sendrecv

43

44[2022-06-13 18:09:18] VERBOSE[17114] res_pjsip_logger.c: <— Transmitting SIP response (537 bytes) to TCP:192.168.1.19:49406 —>

45SIP/2.0 401 Unauthorized

46Via: SIP/2.0/TCP 192.168.1.19:49406;rport=49406;received=192.168.1.19;branch=z9hG4bK6de48c83

47Call-ID: [email protected]

48From: “DM-7070” sip:[email protected];tag=00ccfca768da006c7e48e592-307a5643

49To: sip:[email protected];tag=z9hG4bK6de48c83

50CSeq: 101 INVITE

51WWW-Authenticate: Digest realm=“asterisk”,nonce=“1655132958/ba3a7866f3499bdf88aaa615a27a898f”,opaque=“6eb6ec5d023995d1”,stale=true,algorithm=md5,qop=“auth”

52Server: FPBX-16.0.19(16.24.0)

53Content-Length: 0

54

55

56[2022-06-13 18:09:18] VERBOSE[2921] res_pjsip_logger.c: <— Received SIP request (473 bytes) from TCP:192.168.1.19:49406 —>

57ACK sip:[email protected];user=phone SIP/2.0

58Via: SIP/2.0/TCP 192.168.1.19:49406;branch=z9hG4bK6de48c83

59From: “DM-7070” sip:[email protected];tag=00ccfca768da006c7e48e592-307a5643

60To: sip:[email protected];tag=z9hG4bK6de48c83

61Call-ID: [email protected]

62Session-ID: 37a5b0a000105000a00000ccfca768da;remote=00000000000000000000000000000000

63Max-Forwards: 70

64Date: Mon, 13 Jun 2022 15:09:17 GMT

65CSeq: 101 ACK

66Content-Length: 0

67

68

69[2022-06-13 18:09:18] VERBOSE[2921] res_pjsip_logger.c: <— Received SIP request (1802 bytes) from TCP:192.168.1.19:49406 —>

70INVITE sip:[email protected];user=phone SIP/2.0

71Via: SIP/2.0/TCP 192.168.1.19:49406;branch=z9hG4bK4f27e0af

72From: “DM-7070” sip:[email protected];tag=00ccfca768da006c7e48e592-307a5643

73To: sip:[email protected]

74Call-ID: [email protected]

75Max-Forwards: 70

76Session-ID: 37a5b0a000105000a00000ccfca768da;remote=00000000000000000000000000000000

77Date: Mon, 13 Jun 2022 15:09:17 GMT

78CSeq: 102 INVITE

79User-Agent: Cisco-CP7811/11.0.1

80Contact: sip:[email protected]:49406;transport=tcp;+u.sip!devicename.ccm.cisco.com=“SEP00CCFCA768DA”

81Expires: 180

82Accept: application/sdp

83Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE,INFO

84Remote-Party-ID: “DM-7070” sip:[email protected];party=calling;id-type=subscriber;privacy=off;screen=yes

85Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-7.0.0,X-cisco-xsi-8.5.1

86Allow-Events: kpml,dialog

87Authorization: Digest username=“7070”,realm=“asterisk”,uri="sip:[email protected];user=phone",response=“d5eea1d939032a1d083253fe78698001”,nonce=“1655132958/ba3a7866f3499bdf88aaa615a27a898f”,opaque=“6eb6ec5d023995d1”,cnonce=“18db86fe”,qop=auth,nc=00000002,algorithm=md5

88Content-Length: 350

89Content-Type: application/sdp

90Content-Disposition: session;handling=optional

91

92v=0

93o=Cisco-SIPUA 16962 0 IN IP4 192.168.1.19

94s=SIP Call

95b=AS:4064

96t=0 0

97m=audio 31510 RTP/AVP 0 8 116 18 101

98c=IN IP4 192.168.1.19

99b=TIAS:64000

100a=rtpmap:0 PCMU/8000

101a=rtpmap:8 PCMA/8000

102a=rtpmap:116 iLBC/8000

103a=fmtp:116 mode=20

104a=rtpmap:18 G729/8000

105a=fmtp:18 annexb=yes

106a=rtpmap:101 telephone-event/8000

107a=fmtp:101 0-15

108a=sendrecv

109

110[2022-06-13 18:09:18] VERBOSE[17114] res_pjsip_logger.c: <— Transmitting SIP response (354 bytes) to TCP:192.168.1.19:49406 —>

111SIP/2.0 100 Trying

112Via: SIP/2.0/TCP 192.168.1.19:49406;rport=49406;received=192.168.1.19;branch=z9hG4bK4f27e0af

113Call-ID: [email protected]

114From: “DM-7070” sip:[email protected];tag=00ccfca768da006c7e48e592-307a5643

115To: sip:[email protected]

116CSeq: 102 INVITE

117Server: FPBX-16.0.19(16.24.0)

118Content-Length: 0

119

120

121[2022-06-13 18:09:18] VERBOSE[17114] netsock2.c: Using SIP RTP Audio TOS bits 184

122[2022-06-13 18:09:18] VERBOSE[17114] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.

123[2022-06-13 18:09:18] VERBOSE[17114] netsock2.c: Using SIP RTP Audio CoS mark 5

124[2022-06-13 18:09:18] VERBOSE[96174][C-0000002b] pbx.c: Executing [0436@from-internal:1] Dial(“PJSIP/7070-00000012”, “SIP/0436@outgoing”) in new stack

125[2022-06-13 18:09:18] VERBOSE[96174][C-0000002b] netsock2.c: Using SIP RTP TOS bits 184

126[2022-06-13 18:09:18] VERBOSE[96174][C-0000002b] netsock2.c: Using SIP RTP CoS mark 5

127[2022-06-13 18:09:18] VERBOSE[96174][C-0000002b] app_dial.c: Called SIP/0436@outgoing

128[2022-06-13 18:09:18] VERBOSE[2954][C-0000002b] chan_sip.c: Got SIP response 503 “Service Unavailable” back from 172.17.0.44:5060

129[2022-06-13 18:09:18] VERBOSE[96174][C-0000002b] app_dial.c: SIP/outgoing-00000029 is circuit-busy

130[2022-06-13 18:09:18] VERBOSE[96174][C-0000002b] app_dial.c: Everyone is busy/congested at this time (1:0/1/0)

131[2022-06-13 18:09:18] VERBOSE[96174][C-0000002b] pbx.c: Executing [0436@from-internal:2] Hangup(“PJSIP/7070-00000012”, “”) in new stack

132[2022-06-13 18:09:18] VERBOSE[96174][C-0000002b] pbx.c: Spawn extension (from-internal, 0436, 2) exited non-zero on ‘PJSIP/7070-00000012’

133[2022-06-13 18:09:18] VERBOSE[96174][C-0000002b] pbx.c: Executing [h@from-internal:1] Macro(“PJSIP/7070-00000012”, “hangupcall”) in new stack

134[2022-06-13 18:09:18] VERBOSE[96174][C-0000002b] pbx.c: Executing [s@macro-hangupcall:1] GotoIf(“PJSIP/7070-00000012”, “1?theend”) in new stack

135[2022-06-13 18:09:18] VERBOSE[96174][C-0000002b] pbx_builtins.c: Goto (macro-hangupcall,s,3)

136[2022-06-13 18:09:18] VERBOSE[96174][C-0000002b] pbx.c: Executing [s@macro-hangupcall:3] ExecIf(“PJSIP/7070-00000012”, “0?Set(CDR(recordingfile)=)”) in new stack

137[2022-06-13 18:09:18] VERBOSE[96174][C-0000002b] pbx.c: Executing [s@macro-hangupcall:4] Hangup(“PJSIP/7070-00000012”, “”) in new stack

138[2022-06-13 18:09:18] VERBOSE[96174][C-0000002b] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘PJSIP/7070-00000012’ in macro ‘hangupcall’

139[2022-06-13 18:09:18] VERBOSE[96174][C-0000002b] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on ‘PJSIP/7070-00000012’

140[2022-06-13 18:09:18] VERBOSE[66792] res_pjsip_logger.c: <— Transmitting SIP response (432 bytes) to TCP:192.168.1.19:49406 —>

141SIP/2.0 503 Service Unavailable

142Via: SIP/2.0/TCP 192.168.1.19:49406;rport=49406;received=192.168.1.19;branch=z9hG4bK4f27e0af

143Call-ID: [email protected]

144From: “DM-7070” sip:[email protected];tag=00ccfca768da006c7e48e592-307a5643

145To: sip:[email protected];tag=fe52e51e-1bdd-4fbb-bcf9-f346ad323a6c

146CSeq: 102 INVITE

147Server: FPBX-16.0.19(16.24.0)

148Reason: Q.850;cause=34

149Content-Length: 0

150

151

152[2022-06-13 18:09:18] VERBOSE[2921] res_pjsip_logger.c: <— Received SIP request (494 bytes) from TCP:192.168.1.19:49406 —>

153ACK sip:[email protected];user=phone SIP/2.0

154Via: SIP/2.0/TCP 192.168.1.19:49406;branch=z9hG4bK4f27e0af

155From: “DM-7070” sip:[email protected];tag=00ccfca768da006c7e48e592-307a5643

156To: sip:[email protected];tag=fe52e51e-1bdd-4fbb-bcf9-f346ad323a6c

157Call-ID: [email protected]

158Session-ID: 37a5b0a000105000a00000ccfca768da;remote=00000000000000000000000000000000

159Max-Forwards: 70

160Date: Mon, 13 Jun 2022 15:09:17 GMT

161CSeq: 102 ACK

162Content-Length: 0

163

164

165[2022-06-13 18:09:27] VERBOSE[66792] res_pjsip_logger.c: <— Transmitting SIP request (439 bytes) to UDP:172.17.0.44:5060 —>

166OPTIONS sip:172.17.0.44 SIP/2.0

167Via: SIP/2.0/UDP 172.30.1.144:5060;rport;branch=z9hG4bKPjb04245f9-513f-48a9-a54a-adae68579c4e

168From: sip:[email protected];tag=60a41bb7-448a-4bf3-b1a0-0126ebfb26b7

169To: sip:172.17.0.44

170Contact: sip:[email protected]:5060

171Call-ID: a5ab0ab3-9e94-4c0d-809c-4a01e93a1e37

172CSeq: 8986 OPTIONS

173Max-Forwards: 70

174User-Agent: FPBX-16.0.19(16.24.0)

175Content-Length: 0

176

177

178[2022-06-13 18:09:27] VERBOSE[2921] res_pjsip_logger.c: <— Received SIP response (493 bytes) from UDP:172.17.0.44:5060 —>

179SIP/2.0 503 Service Unavailable

180Via: SIP/2.0/UDP 172.30.1.144:5060;rport;branch=z9hG4bKPjb04245f9-513f-48a9-a54a-adae68579c4e

181From: sip:[email protected];tag=60a41bb7-448a-4bf3-b1a0-0126ebfb26b7

182To: sip:172.17.0.44;tag=1941530912

183Date: Mon, 13 Jun 2022 15:08:50 GMT

184Call-ID: a5ab0ab3-9e94-4c0d-809c-4a01e93a1e37

185CSeq: 8986 OPTIONS

186Warning: 399 FB-CUCM1 “Unable to find a device handler for the request received on port 5060 from 172.30.1.144”

187Content-Length: 0

188

189

190[2022-06-13 18:09:29] ERROR[2954] chan_sip.c: Serious Network Trouble; __sip_xmit returns error for pkt data

191[2022-06-13 18:09:43] VERBOSE[66792] res_pjsip_logger.c: <— Transmitting SIP request (419 bytes) to UDP:172.17.0.44:5060 —>

192OPTIONS sip:172.17.0.44:5060 SIP/2.0

193Via: SIP/2.0/UDP 172.30.1.144:5060;rport;branch=z9hG4bKPj6a5aa215-828e-4498-8369-5fdbee0eee0a

194From: sip:[email protected];tag=7cc5032f-5fe1-4b1d-8b93-86e02d813567

195To: sip:172.17.0.44

196Contact: sip:[email protected]:5060

197Call-ID: 38c07d14-ab81-4fac-938c-5e2796b762cc

198CSeq: 21520 OPTIONS

199Max-Forwards: 70

200User-Agent: FPBX-16.0.19(16.24.0)

201Content-Length: 0

202

203

204[2022-06-13 18:09:43] VERBOSE[2921] res_pjsip_logger.c: <— Received SIP response (481 bytes) from UDP:172.17.0.44:5060 —>

205SIP/2.0 503 Service Unavailable

206Via: SIP/2.0/UDP 172.30.1.144:5060;rport;branch=z9hG4bKPj6a5aa215-828e-4498-8369-5fdbee0eee0a

207From: sip:[email protected];tag=7cc5032f-5fe1-4b1d-8b93-86e02d813567

208To: sip:172.17.0.44;tag=991139817

209Date: Mon, 13 Jun 2022 15:09:06 GMT

210Call-ID: 38c07d14-ab81-4fac-938c-5e2796b762cc

211CSeq: 21520 OPTIONS

212Warning: 399 FB-CUCM1 “Unable to find a device handler for the request received on port 5060 from 172.30.1.144”

213Content-Length: 0

214

215

216[2022-06-13 18:09:43] ERROR[2954] chan_sip.c: Serious Network Trouble; __sip_xmit returns error for pkt data

217[2022-06-13 18:09:45] VERBOSE[66792] res_pjsip_logger.c: <— Transmitting SIP request (460 bytes) to TCP:192.168.1.19:49406 —>

218OPTIONS sip:[email protected]:49406;transport=TCP SIP/2.0

219Via: SIP/2.0/TCP 192.168.1.144:5060;rport;branch=z9hG4bKPjacafeb82-27db-4ef5-b64e-ffc8e10f9f01;alias

220From: sip:[email protected];tag=c03553df-e58c-467c-8c5c-6e0f8eb22f78

221To: sip:[email protected]

222Contact: sip:[email protected]:5060;transport=TCP

223Call-ID: 6ffd6587-7114-442e-a969-36d0733b3eb7

224CSeq: 58104 OPTIONS

225Max-Forwards: 70

226User-Agent: FPBX-16.0.19(16.24.0)

227Content-Length: 0

228

229

230[2022-06-13 18:09:45] VERBOSE[2921] res_pjsip_logger.c: <— Received SIP response (1319 bytes) from TCP:192.168.1.19:49406 —>

231SIP/2.0 200 OK

232Via: SIP/2.0/TCP 192.168.1.144:5060;rport;branch=z9hG4bKPjacafeb82-27db-4ef5-b64e-ffc8e10f9f01;alias

233From: sip:[email protected];tag=c03553df-e58c-467c-8c5c-6e0f8eb22f78

234To: sip:[email protected];tag=00ccfca768da006e18b8101c-5002842f

235Call-ID: 6ffd6587-7114-442e-a969-36d0733b3eb7

236Session-ID: 91e44fb600105000a00000ccfca768da;remote=00000000000000000000000000000000

237Date: Mon, 13 Jun 2022 15:09:44 GMT

238CSeq: 58104 OPTIONS

239Server: Cisco-CP7811/11.0.1

240Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE

241Allow-Events: kpml,dialog,refer

242Accept: application/sdp,multipart/mixed,multipart/alternative

243Accept-Encoding: identity

244Accept-Language: en

245Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-7.0.0

246Content-Length: 299

247Content-Type: application/sdp

248Content-Disposition: session;handling=optional

249

250v=0

251o=Cisco-SIPUA 5517 0 IN IP4 192.168.1.19

252s=SIP Call

253t=0 0

254m=audio 0 RTP/AVP 0 8 116 18 101

255b=TIAS:64000

256a=rtpmap:0 PCMU/8000

257a=rtpmap:8 PCMA/8000

258a=rtpmap:116 iLBC/8000

259a=fmtp:116 mode=20

260a=rtpmap:18 G729/8000

261a=fmtp:18 annexb=yes

262a=rtpmap:101 telephone-event/8000

263a=fmtp:101 0-15

264

11

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