Potential transcoding issue in master branch

whiskerp · January 7, 2023, 3:58pm

I normally build from a git checkout of the “18” or “20” branch. However the latest build from these branches seem to have a transcoding issue on PJSip channels between G.711a (alaw) and G.722. My call is made from a G.722 handset to an alaw destination and there is no discernable audio received, just some faint noises. The SIP messages and RTP debug media types all look OK and there are no obvious errors, it just sounds like the transcoding fails.
I rebuilt using tag 20.1 and that works fine, so it looks like something that changed between 20.1 and 20 master which is the problem. It also fails in the same way in the master branch of Asterisk 18. Sorry not to be more precise.

jcolp · January 7, 2023, 10:52pm

Issues should be reported on the issue tracker[1] with reproduction instructions. To my knowledge nothing has been touched in that area, and we’ve had no other reports yet.

[1] System Dashboard - Digium/Asterisk JIRA

whiskerp · January 9, 2023, 8:27am

Hi

Thanks. I was blaming transcoding but it may be an RTP or PJSip problem – things seem to have been changed in that area. I can reproduce at will.

I build a vanilla “git checkout 20.1” and run with codec order “g722,alaw,ulaw” everywhere. I make a call from a G.722 handset to an G.711a trunk and all works fine.

I do exactly the same with “git checkout 20” and the call to the trunk does not produce audio on the handset. I can hear some bumping and pinging in the background only.

Build is with all dependencies installed as per “contrib/scripts/install_prereq install”

./bootstrap.sh

./configure --prefix=/usr

The dialplan is built using FreePBX 16 but I can provide any sections which may be required. In between the tests I make no changes to /etc/asterisk and I switch between the systems with “rm /usr/lib/asterisk/modules/*.so;make install”

Regards

Peter

jcolp · January 9, 2023, 9:46am

A bug report still needs to be filed on JIRA with this information, an actual packet capture and core debug of Asterisk would also be useful with it.

gjoseph · January 9, 2023, 1:27pm

I can reproduce the issue and have opened
https://issues.asterisk.org/jira/browse/ASTERISK-30391

whiskerp · January 9, 2023, 9:45pm

Thanks, I’ve tested after you applied your patch and it has fixed the issue.
Regards
Peter

gjoseph · January 10, 2023, 12:14pm

Thanks for testing!

whiskerp · January 10, 2023, 2:42pm

Hi

I rebuild git checkout 20 again just now (Jan 10 14:30 UTC) after the JIRA merge update emails and the audio has gone badly bumpy again on G722<->ALAW.

It’s not the as bad as before in that the audio is recognisable, but the quality is again very poor.

Did you make further changes since my first build of tag 20 at Jan 9 21:06 UTC or is it that the MER had been pulled and is now reinstated?

Thanks

Peter

gjoseph · January 10, 2023, 2:51pm

For the 20 branch, I reverted the MES changes yesterday at about 14:20Z then remerged it back in with the fixes about an hour and 40 minutes ago (13:00Z or thereabouts) If you pulled between those times then you got the version without the MES changes and issue. If you pulled since about 13:00Z, you got the MES changes + the fixes. If it’s still not working, confirm that you have this commit…

commit 4710f37ef603aacea9cb3ea657373ee3f6c67e37 (HEAD -> 20, gerrit/20)
Author: George Joseph <gjoseph@digium.com>
Date:   2022-10-28 04:57:56 -0600

    res_rtp_asterisk: Asterisk Media Experience Score (MES)
    
    -----------------
    
    This commit reinstates MES with some casting fixes to the
    functions in time.h that convert between doubles and timeval
    structures.  The casting issues were causing incorrect
    timestamps to be calculated which caused transcoding from/to
    G722 to produce bad or no audio.
    
    ASTERISK-30391
    
    -----------------

gjoseph · January 10, 2023, 2:57pm

Also, with a test call up, can you paste the results of a core show channel <channel_a> and core show channel <channel_b> and also tell me the setting of transcode_via_sln in asterisk.conf.

whiskerp · January 10, 2023, 3:41pm

Hi

I can confirm that the commit is present:

git log | grep 4710f37ef603aacea9cb3ea657373ee3f6c67e37

commit 4710f37ef603aacea9cb3ea657373ee3f6c67e37

git branch --contains 4710f37ef603aacea9cb3ea657373ee3f6c67e37

20

The value transcode_via_sln is not present in /etc/asterisk/asterisk.conf so I think it defaults to yes (which is borne out below)

rilian*CLI> core show channel PJSIP/1324-00000002
– General –
Name: PJSIP/1324-00000002
Type: PJSIP
UniqueID: 1673364743.2
LinkedID: 1673364743.2
Caller ID: 01932xxxxxx
Caller ID Name: 01932xxxxxx
Connected Line ID: 08000798xxx
Connected Line ID Name: CID:01932xxxxxx
Eff. Connected Line ID: 08000798xxx
Eff. Connected Line ID Name: CID:01932xxxxxx
DNID Digits: 01932150
Language: en_GB
State: Up (6)
NativeFormats: (g722)
WriteFormat: slin16
ReadFormat: slin16
WriteTranscode: Yes (slin@16000)->(g722@16000)
ReadTranscode: Yes (g722@16000)->(slin@16000)
Time to Hangup: 0
Elapsed Time: 0h0m7s
Bridge ID: 51ad105e-4cc8-4982-bce5-abcf342c274d
– PBX –
Context: macro-dialout-trunk
Extension: s
Priority: 27
Call Group: 0
Pickup Group: 0
Application: Dial
Call Identifer: [C-00000002]
Variables:
BRIDGEPVTCALLID=6601c4cd-a849-4a80-8107-78198b59ffd8
BRIDGEPEER=PJSIP/1200497-1000-00000003
DIALEDPEERNUMBER=08000798xxx@1200497-1000
DIALEDPEERNAME=PJSIP/1200497-1000-00000003
DIALSTATUS=ANSWER
RINGTIME_MS=297
RINGTIME=0
PROGRESSTIME_MS=
PROGRESSTIME=
DIALEDTIME_MS=
DIALEDTIME=
ANSWEREDTIME_MS=
ANSWEREDTIME=
MACRO_DEPTH=1
~HASH~SIPHEADERS~Alert-Info~=unset
DB_RESULT=INT 4
MACRO_PRIORITY=11
MACRO_CONTEXT=from-internal-additional
MACRO_EXTEN=08000798xxx
ARG1=28
DIAL_TRUNK_OPTIONS=M(setmusic^none)
custom=PJSIP
OUTNUM=08000798xxx
TIOHIDE=no
TRUNKOUTCID=“01932xxxxxx” <01932xxxxxx>
EMERGENCYCID=
USEROUTCID=“01932xxxxxx” <01932xxxxxx>
ALLOWTHISROUTE=NO
HOTDESKCALL=0
HOTDESKEXTEN=1324
HOTDESCKCHAN=1324-00000002
OUTBOUND_GROUP=OUT_28
DIAL_NUMBER=08000798xxx
DIAL_TRUNK=28
ARG4=on
ARG3=
ARG2=08000798xxx
NODEST=
EMAILNOTIFICATION=FALSE
CALLERIDNUMINTERNAL=1324
CALLERIDNAMEINTERNAL=INT 4
MOHCLASS=none
ROUTENAME=to-freefone-0[58]0
ROUTEID=6
OUTBOUND_ROUTE_NAME=to-freefone-0[58]0
GOSUB_RETVAL=
REC_STATUS=RECORDING
RECORD_ID=PJSIP/1324-00000002
MIXMON_ID=
MIXMONITOR_FILENAME=/var/spool/asterisk/monitor/2023/01/10/out-08000798xxx-1324-20230110-153223-1673364743.2.sln
CALLFILENAME=out-08000798xxx-1324-20230110-153223-1673364743.2
REC_POLICY_MODE=YES
RECMODE=dontcare
REC_POLICY_MODE_SAVE=
MON_FMT=sln
FROMEXTEN=1324
TIMESTR=20230110-153223
YEAR=2023
MONTH=01
DAY=10
NOW=1673364743
AMPUSER=1324
CHANEXTEN=1324-00000002
CHANEXTENCONTEXT=1324-00000002
CHANCONTEXT=
TOUCH_MONITOR=1673364743.2
TTL=64
DIAL_OPTIONS=r
AMPUSERCID=1324
AMPUSERCIDNAME=INT 4
REALCALLERIDNUM=1324
SIPDOMAIN=whisker.org.uk
CDR Variables:
level 1: outbound_cnam=01932xxxxxx
level 1: outbound_cnum=01932xxxxxx
level 1: recordingfile=out-08000798xxx-1324-20230110-153223-1673364743.2.sln
level 1: cnum=1324
level 1: cnam=INT 4
level 1: dnid=01932150
level 1: clid=“01932xxxxxx” <01932xxxxxx>
level 1: src=01932xxxxxx
level 1: dst=s
level 1: dcontext=macro-dialout-trunk
level 1: channel=PJSIP/1324-00000002
level 1: dstchannel=PJSIP/1200497-1000-00000003
level 1: lastapp=Dial
level 1: lastdata=PJSIP/08000798xxx@1200497-1000,300,M(setmusic^none)b(func-apply-sipheaders^s^1,(28))U(sub-send-obroute-email^08000798xxx^08000798xxx^28^1673364743^01932xxxxxx^01932xxxxxx)
level 1: start=1673364743.300376
level 1: answer=1673364746.033281
level 1: end=0.000000
level 1: duration=6
level 1: billsec=3
level 1: disposition=8
level 1: amaflags=3
level 1: uniqueid=1673364743.2
level 1: linkedid=1673364743.2
level 1: sequence=2

– Streams –
Name: audio-0
Type: audio
State: sendrecv
Group: -1
Formats: (g722|alaw|ulaw)
Metadata:
rilian*CLI> core show channel PJSIP/1200497-1000-00000003
– General –
Name: PJSIP/1200497-1000-00000003
Type: PJSIP
UniqueID: 1673364743.3
LinkedID: 1673364743.2
Caller ID: 08000798xxx
Caller ID Name: CID:01932xxxxxx
Connected Line ID: 01932xxxxxx
Connected Line ID Name: 01932xxxxxx
Eff. Connected Line ID: 01932xxxxxx
Eff. Connected Line ID Name: 01932xxxxxx
DNID Digits: (N/A)
Language: en_GB
State: Up (6)
NativeFormats: (alaw)
WriteFormat: slin16
ReadFormat: slin16
WriteTranscode: Yes (slin@16000)->(slin@8000)->(alaw@8000)
ReadTranscode: Yes (alaw@8000)->(slin@8000)->(slin@16000)
Time to Hangup: 0
Elapsed Time: 0h0m13s
Bridge ID: 51ad105e-4cc8-4982-bce5-abcf342c274d
– PBX –
Context: macro-dialout-trunk
Extension: s
Priority: 1
Call Group: 0
Pickup Group: 0
Application: AppDial
Data: (Outgoing Line)
Call Identifer: [C-00000002]
Variables:
BRIDGEPVTCALLID=2616539734@192_168_25_35
BRIDGEPEER=PJSIP/1324-00000002
GOSUB_RETVAL=
MACRO_DEPTH=0
sipkey=
sipheader=unset
SIPHEADERKEYS=
TECH=PJSIP
DIALEDPEERNUMBER=08000798xxx@1200497-1000
~HASH~SIPHEADERS~Alert-Info~=unset
NODEST=
EMAILNOTIFICATION=FALSE
CALLERIDNUMINTERNAL=1324
CALLERIDNAMEINTERNAL=INT 4
ROUTENAME=to-freefone-0[58]0
ROUTEID=6
REC_STATUS=RECORDING
RECORD_ID=PJSIP/1324-00000002
MIXMON_ID=
CALLFILENAME=out-08000798xxx-1324-20230110-153223-1673364743.2
REC_POLICY_MODE=YES
MON_FMT=sln
FROMEXTEN=1324
TIMESTR=20230110-153223
YEAR=2023
MONTH=01
DAY=10
TTL=64
DIAL_OPTIONS=r
CDR Variables:
level 1: clid=“CID:01932xxxxxx” <08000798xxx>
level 1: src=08000798xxx
level 1: dst=s
level 1: dcontext=macro-dialout-trunk
level 1: channel=PJSIP/1200497-1000-00000003
level 1: lastapp=AppDial
level 1: lastdata=(Outgoing Line)
level 1: start=1673364743.350521
level 1: answer=1673364746.011442
level 1: end=1673364746.035468
level 1: duration=2
level 1: billsec=0
level 1: disposition=8
level 1: amaflags=3
level 1: uniqueid=1673364743.3
level 1: linkedid=1673364743.2
level 1: sequence=3

– Streams –
Name: audio-0
Type: audio
State: sendrecv
Group: -1
Formats: (alaw)
Metadata:
rilian*CLI>

The audio is present but “bumpy” as if it is muting a proportion of the packets.

Peter

gjoseph · January 10, 2023, 3:47pm

Are there local channels involved in this call?

Your channel dumps don’t look like mine…
Specifically…

NativeFormats: (g722)
WriteFormat: slin16
ReadFormat: slin16
WriteTranscode: Yes (slin@16000)->(g722@16000)
ReadTranscode: Yes (g722@16000)->(slin@16000)

and

NativeFormats: (alaw)
WriteFormat: slin16
ReadFormat: slin16
WriteTranscode: Yes (slin@16000)->(slin@8000)->(alaw@8000)
ReadTranscode: Yes (alaw@8000)->(slin@8000)->(slin@16000)

Can you reproduce this on a minimal asterisk-only install with a simple dialplan?

Can you do a pjsip show endpoint on both endpoints?

whiskerp · January 10, 2023, 4:15pm

Hi

I have a FreePBX 16.0.30 setup. So it would take a time to build a new system with a basic dialplan. Here are the endpoints. It works perfectly with git 20.1 but git 20 is still not right.

Peter

rilian*CLI> pjsip show endpoint 1324

Endpoint: <Endpoint/CID…> <State…> <Channels.>
I/OAuth: <AuthId/UserName…>
Aor: <Aor…>
Contact: <Aor/ContactUri…> <Hash…> <RTT(ms)…>
Transport: <TransportId…> <BindAddress…>
Identify: <Identify/Endpoint…>
Match: <criteria…>
Channel: <ChannelId…> <State…> <Time…>
Exten: <DialedExten…> CLCID: <ConnectedLineCID…>

gjoseph · January 10, 2023, 4:19pm

Yeah I understand. I don’t see the endpoint details though.

One more thing, can you capture the log of a call with core set verbose 3. That’ll give me more info to go on. Please attach it to the issue I referenced above.

gjoseph · January 10, 2023, 5:27pm

I managed to reproduce your translation paths between the two channels but I still get perfect audio. Can you use wireshark to capture the full call flow between the two devices and attach to the issue? You can use a filter like udp and (host <device_a_ip> or host <device_b_ip).

whiskerp · January 10, 2023, 9:34pm

It looks like the forum stripped out the endpoint details.

cable · January 11, 2023, 2:10am

I can confirm the “bumpy” audio as worded by whiskerp on the current git-master. Release version 20.0.1 works normal.

The audio sounds like it fades/recovers about once per second. There is also a oscillating background noise at about 2 per second. The conversation was difficult but probably bad only on my end (I was the caller) because the other party made no mention of it. A couple test calls after that allowed me to further scrutinize.

I’m transcoding with ulaw, g722, opus (AMI shows Write: ulaw8000, slin8000, slin48000, opus48000 and Read: opus48000, slin48000). I tried without Opus with no audible change.

I’m back on 20.0.1 but if I have some time I’ll reload master and do more tests.

The ‘MES’ returned avgrxMES and avgtxMES as 83 which seems too high (?) for what it sounded like. There were no lost packets and jitter was normal.

whiskerp · January 11, 2023, 4:35am

I agree with the description by “cable”. I wondered if the active “MixMonitor” in the dialplan was doing anything so switched it off, nut no difference. Here is the call setup. I am not allowed to post attachments as a “New user”.

Connected to Asterisk GIT-20-4710f37ef6M currently running on rilian (pid = 1407184)
  == Using SIP RTP Audio TOS bits 184
  == Using SIP RTP Audio TOS bits 184 in TCLASS field.
  == Using SIP RTP Audio CoS mark 5
    -- Executing [01932150@from-gigaset:1] Goto("PJSIP/1324-00000002", "from-gigaset_rulematch,150,1") in new stack
    -- Goto (from-gigaset_rulematch,150,1)
    -- Executing [150@from-gigaset_rulematch:1] NoOp("PJSIP/1324-00000002", "Running miscapp 10: 150 EE") in new stack
    -- Executing [150@from-gigaset_rulematch:2] Macro("PJSIP/1324-00000002", "user-callerid,") in new stack
    -- Executing [s@macro-user-callerid:1] Set("PJSIP/1324-00000002", "TOUCH_MONITOR=1673411166.2") in new stack
    -- Executing [s@macro-user-callerid:2] Set("PJSIP/1324-00000002", "CHANCONTEXT=") in new stack
    -- Executing [s@macro-user-callerid:3] Set("PJSIP/1324-00000002", "CHANCONTEXT=") in new stack
    -- Executing [s@macro-user-callerid:4] Set("PJSIP/1324-00000002", "CHANEXTENCONTEXT=1324-00000002") in new stack
    -- Executing [s@macro-user-callerid:5] Set("PJSIP/1324-00000002", "CHANEXTEN=1324-00000002") in new stack
    -- Executing [s@macro-user-callerid:6] Set("PJSIP/1324-00000002", "CALLERID(number)=1324") in new stack
    -- Executing [s@macro-user-callerid:7] Set("PJSIP/1324-00000002", "AMPUSER=1324") in new stack
    -- Executing [s@macro-user-callerid:8] Set("PJSIP/1324-00000002", "HOTDESCKCHAN=1324-00000002") in new stack
    -- Executing [s@macro-user-callerid:9] Set("PJSIP/1324-00000002", "HOTDESKEXTEN=1324") in new stack
    -- Executing [s@macro-user-callerid:10] Set("PJSIP/1324-00000002", "HOTDESKCALL=0") in new stack
    -- Executing [s@macro-user-callerid:11] ExecIf("PJSIP/1324-00000002", "0?Set(HOTDESKCALL=1)") in new stack
    -- Executing [s@macro-user-callerid:12] ExecIf("PJSIP/1324-00000002", "0?Set(CALLERID(name)=)") in new stack
    -- Executing [s@macro-user-callerid:13] GotoIf("PJSIP/1324-00000002", "0?report") in new stack
    -- Executing [s@macro-user-callerid:14] ExecIf("PJSIP/1324-00000002", "1?Set(REALCALLERIDNUM=1324)") in new stack
    -- Executing [s@macro-user-callerid:15] Set("PJSIP/1324-00000002", "AMPUSER=1324") in new stack
    -- Executing [s@macro-user-callerid:16] GotoIf("PJSIP/1324-00000002", "0?limit") in new stack
    -- Executing [s@macro-user-callerid:17] Set("PJSIP/1324-00000002", "AMPUSERCIDNAME=INT 4") in new stack
    -- Executing [s@macro-user-callerid:18] ExecIf("PJSIP/1324-00000002", "0?Set(__CIDMASQUERADING=TRUE)") in new stack
    -- Executing [s@macro-user-callerid:19] GotoIf("PJSIP/1324-00000002", "0?report") in new stack
    -- Executing [s@macro-user-callerid:20] Set("PJSIP/1324-00000002", "AMPUSERCID=1324") in new stack
    -- Executing [s@macro-user-callerid:21] Set("PJSIP/1324-00000002", "__DIAL_OPTIONS=r") in new stack
    -- Executing [s@macro-user-callerid:22] Set("PJSIP/1324-00000002", "CALLERID(all)="INT 4" <1324>") in new stack
    -- Executing [s@macro-user-callerid:23] ExecIf("PJSIP/1324-00000002", "0?Set(CUSDIAL=)") in new stack
    -- Executing [s@macro-user-callerid:24] ExecIf("PJSIP/1324-00000002", "0?Set(CALLERID(all)="INT 4" <1324>)") in new stack
    -- Executing [s@macro-user-callerid:25] GotoIf("PJSIP/1324-00000002", "0?limit") in new stack
    -- Executing [s@macro-user-callerid:26] ExecIf("PJSIP/1324-00000002", "0?Set(GROUP(concurrency_limit)=1324)") in new stack
    -- Executing [s@macro-user-callerid:27] ExecIf("PJSIP/1324-00000002", "1?Set(CHANNEL(language)=en_GB)") in new stack
    -- Executing [s@macro-user-callerid:28] NoOp("PJSIP/1324-00000002", "Macro Depth is 1") in new stack
    -- Executing [s@macro-user-callerid:29] GotoIf("PJSIP/1324-00000002", "1?report2:macroerror") in new stack
    -- Goto (macro-user-callerid,s,30)
    -- Executing [s@macro-user-callerid:30] GotoIf("PJSIP/1324-00000002", "0?continue") in new stack
    -- Executing [s@macro-user-callerid:31] Set("PJSIP/1324-00000002", "__TTL=64") in new stack
    -- Executing [s@macro-user-callerid:32] GotoIf("PJSIP/1324-00000002", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,48)
    -- Executing [s@macro-user-callerid:48] Set("PJSIP/1324-00000002", "CALLERID(number)=1324") in new stack
    -- Executing [s@macro-user-callerid:49] Set("PJSIP/1324-00000002", "CALLERID(name)=INT 4") in new stack
    -- Executing [s@macro-user-callerid:50] GotoIf("PJSIP/1324-00000002", "0?cnum") in new stack
    -- Executing [s@macro-user-callerid:51] Set("PJSIP/1324-00000002", "CDR(cnam)=INT 4") in new stack
    -- Executing [s@macro-user-callerid:52] Set("PJSIP/1324-00000002", "CDR(cnum)=1324") in new stack
    -- Executing [s@macro-user-callerid:53] Set("PJSIP/1324-00000002", "CHANNEL(language)=en_GB") in new stack
    -- Executing [150@from-gigaset_rulematch:3] Goto("PJSIP/1324-00000002", "custom,150,1") in new stack
    -- Goto (custom,150,1)
    -- Executing [150@custom:1] Goto("PJSIP/1324-00000002", "from-internal-additional,08000798586,1") in new stack
    -- Goto (from-internal-additional,08000798586,1)
    -- Executing [08000798586@from-internal-additional:1] Macro("PJSIP/1324-00000002", "user-callerid,LIMIT,EXTERNAL,") in new stack
    -- Executing [s@macro-user-callerid:1] Set("PJSIP/1324-00000002", "TOUCH_MONITOR=1673411166.2") in new stack
    -- Executing [s@macro-user-callerid:2] Set("PJSIP/1324-00000002", "CHANCONTEXT=") in new stack
    -- Executing [s@macro-user-callerid:3] Set("PJSIP/1324-00000002", "CHANCONTEXT=") in new stack
    -- Executing [s@macro-user-callerid:4] Set("PJSIP/1324-00000002", "CHANEXTENCONTEXT=1324-00000002") in new stack
    -- Executing [s@macro-user-callerid:5] Set("PJSIP/1324-00000002", "CHANEXTEN=1324-00000002") in new stack
    -- Executing [s@macro-user-callerid:6] Set("PJSIP/1324-00000002", "CALLERID(number)=1324") in new stack
    -- Executing [s@macro-user-callerid:7] Set("PJSIP/1324-00000002", "AMPUSER=1324") in new stack
    -- Executing [s@macro-user-callerid:8] Set("PJSIP/1324-00000002", "HOTDESCKCHAN=1324-00000002") in new stack
    -- Executing [s@macro-user-callerid:9] Set("PJSIP/1324-00000002", "HOTDESKEXTEN=1324") in new stack
    -- Executing [s@macro-user-callerid:10] Set("PJSIP/1324-00000002", "HOTDESKCALL=0") in new stack
    -- Executing [s@macro-user-callerid:11] ExecIf("PJSIP/1324-00000002", "0?Set(HOTDESKCALL=1)") in new stack
    -- Executing [s@macro-user-callerid:12] ExecIf("PJSIP/1324-00000002", "0?Set(CALLERID(name)=)") in new stack
    -- Executing [s@macro-user-callerid:13] GotoIf("PJSIP/1324-00000002", "5?report") in new stack
    -- Goto (macro-user-callerid,s,28)
    -- Executing [s@macro-user-callerid:28] NoOp("PJSIP/1324-00000002", "Macro Depth is 1") in new stack
    -- Executing [s@macro-user-callerid:29] GotoIf("PJSIP/1324-00000002", "1?report2:macroerror") in new stack
    -- Goto (macro-user-callerid,s,30)
    -- Executing [s@macro-user-callerid:30] GotoIf("PJSIP/1324-00000002", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,48)
    -- Executing [s@macro-user-callerid:48] Set("PJSIP/1324-00000002", "CALLERID(number)=1324") in new stack
    -- Executing [s@macro-user-callerid:49] Set("PJSIP/1324-00000002", "CALLERID(name)=INT 4") in new stack
    -- Executing [s@macro-user-callerid:50] GotoIf("PJSIP/1324-00000002", "0?cnum") in new stack
    -- Executing [s@macro-user-callerid:51] Set("PJSIP/1324-00000002", "CDR(cnam)=INT 4") in new stack
    -- Executing [s@macro-user-callerid:52] Set("PJSIP/1324-00000002", "CDR(cnum)=1324") in new stack
    -- Executing [s@macro-user-callerid:53] Set("PJSIP/1324-00000002", "CHANNEL(language)=en_GB") in new stack
    -- Executing [08000798586@from-internal-additional:2] Gosub("PJSIP/1324-00000002", "sub-record-check,s,1(out,08000798586,yes)") in new stack
    -- Executing [s@sub-record-check:1] GotoIf("PJSIP/1324-00000002", "0?initialized") in new stack
    -- Executing [s@sub-record-check:2] Set("PJSIP/1324-00000002", "__REC_STATUS=INITIALIZED") in new stack
    -- Executing [s@sub-record-check:3] Set("PJSIP/1324-00000002", "NOW=1673411166") in new stack
    -- Executing [s@sub-record-check:4] Set("PJSIP/1324-00000002", "__DAY=11") in new stack
    -- Executing [s@sub-record-check:5] Set("PJSIP/1324-00000002", "__MONTH=01") in new stack
    -- Executing [s@sub-record-check:6] Set("PJSIP/1324-00000002", "__YEAR=2023") in new stack
    -- Executing [s@sub-record-check:7] Set("PJSIP/1324-00000002", "__TIMESTR=20230111-042606") in new stack
    -- Executing [s@sub-record-check:8] Set("PJSIP/1324-00000002", "__FROMEXTEN=1324") in new stack
    -- Executing [s@sub-record-check:9] Set("PJSIP/1324-00000002", "__MON_FMT=sln") in new stack
    -- Executing [s@sub-record-check:10] NoOp("PJSIP/1324-00000002", "Recordings initialized") in new stack
    -- Executing [s@sub-record-check:11] ExecIf("PJSIP/1324-00000002", "0?Set(ARG3=dontcare)") in new stack
    -- Executing [s@sub-record-check:12] Set("PJSIP/1324-00000002", "REC_POLICY_MODE_SAVE=") in new stack
    -- Executing [s@sub-record-check:13] ExecIf("PJSIP/1324-00000002", "0?Set(REC_STATUS=NO)") in new stack
    -- Executing [s@sub-record-check:14] GotoIf("PJSIP/1324-00000002", "3?checkaction") in new stack
    -- Goto (sub-record-check,s,17)
    -- Executing [s@sub-record-check:17] GotoIf("PJSIP/1324-00000002", "1?sub-record-check,out,1") in new stack
    -- Goto (sub-record-check,out,1)
    -- Executing [out@sub-record-check:1] NoOp("PJSIP/1324-00000002", "Outbound Recording Check from 1324 to 08000798586") in new stack
    -- Executing [out@sub-record-check:2] Set("PJSIP/1324-00000002", "RECMODE=dontcare") in new stack
    -- Executing [out@sub-record-check:3] ExecIf("PJSIP/1324-00000002", "1?Goto(routewins)") in new stack
    -- Goto (sub-record-check,out,7)
    -- Executing [out@sub-record-check:7] Gosub("PJSIP/1324-00000002", "recordcheck,1(yes,out,08000798586)") in new stack
    -- Executing [recordcheck@sub-record-check:1] NoOp("PJSIP/1324-00000002", "Starting recording check against yes") in new stack
    -- Executing [recordcheck@sub-record-check:2] Goto("PJSIP/1324-00000002", "yes") in new stack
    -- Goto (sub-record-check,recordcheck,9)
    -- Executing [recordcheck@sub-record-check:9] ExecIf("PJSIP/1324-00000002", "0?Return()") in new stack
    -- Executing [recordcheck@sub-record-check:10] Set("PJSIP/1324-00000002", "__REC_POLICY_MODE=YES") in new stack
    -- Executing [recordcheck@sub-record-check:11] Goto("PJSIP/1324-00000002", "startrec") in new stack
    -- Goto (sub-record-check,recordcheck,16)
    -- Executing [recordcheck@sub-record-check:16] NoOp("PJSIP/1324-00000002", "Starting recording: out, 08000798586") in new stack
    -- Executing [recordcheck@sub-record-check:17] Set("PJSIP/1324-00000002", "__CALLFILENAME=out-08000798586-1324-20230111-042606-1673411166.2") in new stack
    -- Executing [recordcheck@sub-record-check:18] MixMonitor("PJSIP/1324-00000002", "2023/01/11/out-08000798586-1324-20230111-042606-1673411166.2.sln,abi(),") in new stack
    -- Executing [recordcheck@sub-record-check:19] Set("PJSIP/1324-00000002", "__MIXMON_ID=") in new stack
    -- Executing [recordcheck@sub-record-check:20] Set("PJSIP/1324-00000002", "__RECORD_ID=PJSIP/1324-00000002") in new stack
    -- Executing [recordcheck@sub-record-check:21] Set("PJSIP/1324-00000002", "__REC_STATUS=RECORDING") in new stack
    -- Executing [recordcheck@sub-record-check:22] Set("PJSIP/1324-00000002", "CDR(recordingfile)=out-08000798586-1324-20230111-042606-1673411166.2.sln") in new stack
    -- Executing [recordcheck@sub-record-check:23] Return("PJSIP/1324-00000002", "") in new stack
    -- Executing [out@sub-record-check:8] Return("PJSIP/1324-00000002", "") in new stack
    -- Executing [08000798586@from-internal-additional:3] NoOp("PJSIP/1324-00000002", "[TRACE](1) Calling Out Route: to-freefone-0[58]0") in new stack
    -- Executing [08000798586@from-internal-additional:4] Set("PJSIP/1324-00000002", "_ROUTEID=6") in new stack
    -- Executing [08000798586@from-internal-additional:5] Set("PJSIP/1324-00000002", "_ROUTENAME=to-freefone-0[58]0") in new stack
    -- Executing [08000798586@from-internal-additional:6] Set("PJSIP/1324-00000002", "MOHCLASS=none") in new stack
    -- Executing [08000798586@from-internal-additional:7] Set("PJSIP/1324-00000002", "_CALLERIDNAMEINTERNAL=INT 4") in new stack
    -- Executing [08000798586@from-internal-additional:8] Set("PJSIP/1324-00000002", "_CALLERIDNUMINTERNAL=1324") in new stack
    -- Executing [08000798586@from-internal-additional:9] Set("PJSIP/1324-00000002", "_EMAILNOTIFICATION=FALSE") in new stack
    -- Executing [08000798586@from-internal-additional:10] Set("PJSIP/1324-00000002", "_NODEST=") in new stack
    -- Executing [08000798586@from-internal-additional:11] Macro("PJSIP/1324-00000002", "dialout-trunk,28,08000798586,,on") in new stack
    -- Executing [s@macro-dialout-trunk:1] Set("PJSIP/1324-00000002", "DIAL_TRUNK=28") in new stack
    -- Executing [s@macro-dialout-trunk:2] ExecIf("PJSIP/1324-00000002", "0?Set(DIAL_OPTIONS=r)") in new stack
    -- Executing [s@macro-dialout-trunk:3] GosubIf("PJSIP/1324-00000002", "0?sub-pincheck,s,1()") in new stack
    -- Executing [s@macro-dialout-trunk:4] ExecIf("PJSIP/1324-00000002", "0?Set(CALLERID(num)=1324)") in new stack
    -- Executing [s@macro-dialout-trunk:5] GotoIf("PJSIP/1324-00000002", "0?disabletrunk,1") in new stack
    -- Executing [s@macro-dialout-trunk:6] Set("PJSIP/1324-00000002", "DIAL_NUMBER=08000798586") in new stack
    -- Executing [s@macro-dialout-trunk:7] Set("PJSIP/1324-00000002", "DIAL_TRUNK_OPTIONS=r") in new stack
    -- Executing [s@macro-dialout-trunk:8] Set("PJSIP/1324-00000002", "OUTBOUND_GROUP=OUT_28") in new stack
    -- Executing [s@macro-dialout-trunk:9] Set("PJSIP/1324-00000002", "DIAL_TRUNK_OPTIONS=") in new stack
    -- Executing [s@macro-dialout-trunk:10] GotoIf("PJSIP/1324-00000002", "0?nomax") in new stack
    -- Executing [s@macro-dialout-trunk:11] GotoIf("PJSIP/1324-00000002", "0?chanfull") in new stack
    -- Executing [s@macro-dialout-trunk:12] GotoIf("PJSIP/1324-00000002", "0?skipoutcid") in new stack
    -- Executing [s@macro-dialout-trunk:13] Macro("PJSIP/1324-00000002", "outbound-callerid,28") in new stack
    -- Executing [s@macro-outbound-callerid:1] NoOp("PJSIP/1324-00000002", "1324") in new stack
    -- Executing [s@macro-outbound-callerid:2] NoOp("PJSIP/1324-00000002", "") in new stack
    -- Executing [s@macro-outbound-callerid:3] NoOp("PJSIP/1324-00000002", "all") in new stack
    -- Executing [s@macro-outbound-callerid:4] ExecIf("PJSIP/1324-00000002", "0?Set(CALLERID(name-pres)=)") in new stack
  == Begin MixMonitor Recording PJSIP/1324-00000002
    -- Executing [s@macro-outbound-callerid:5] ExecIf("PJSIP/1324-00000002", "0?Set(CALLERID(num-pres)=)") in new stack
    -- Executing [s@macro-outbound-callerid:6] Set("PJSIP/1324-00000002", "HOTDESCKCHAN=1324-00000002") in new stack
    -- Executing [s@macro-outbound-callerid:7] Set("PJSIP/1324-00000002", "HOTDESKEXTEN=1324") in new stack
    -- Executing [s@macro-outbound-callerid:8] Set("PJSIP/1324-00000002", "HOTDESKCALL=0") in new stack
    -- Executing [s@macro-outbound-callerid:9] ExecIf("PJSIP/1324-00000002", "0?Set(HOTDESKCALL=1)") in new stack
    -- Executing [s@macro-outbound-callerid:10] ExecIf("PJSIP/1324-00000002", "0?Set(CALLERID(name)=)") in new stack
    -- Executing [s@macro-outbound-callerid:11] Set("PJSIP/1324-00000002", "ALLOWTHISROUTE=NO") in new stack
    -- Executing [s@macro-outbound-callerid:12] ExecIf("PJSIP/1324-00000002", "0?Set(ALLOWTHISROUTE=YES)") in new stack
    -- Executing [s@macro-outbound-callerid:13] ExecIf("PJSIP/1324-00000002", "0?Hangup()") in new stack
    -- Executing [s@macro-outbound-callerid:14] ExecIf("PJSIP/1324-00000002", "0?Set(REALCALLERIDNUM=1324)") in new stack
    -- Executing [s@macro-outbound-callerid:15] ExecIf("PJSIP/1324-00000002", "0?Set(AMPUSER=1324)") in new stack
    -- Executing [s@macro-outbound-callerid:16] GotoIf("PJSIP/1324-00000002", "1?normcid") in new stack
    -- Goto (macro-outbound-callerid,s,20)
    -- Executing [s@macro-outbound-callerid:20] Set("PJSIP/1324-00000002", "USEROUTCID="01932955088" <01932955088>") in new stack
    -- Executing [s@macro-outbound-callerid:21] Set("PJSIP/1324-00000002", "EMERGENCYCID=") in new stack
    -- Executing [s@macro-outbound-callerid:22] ExecIf("PJSIP/1324-00000002", "0?Set(EMERGENCYCID=)") in new stack
    -- Executing [s@macro-outbound-callerid:23] Set("PJSIP/1324-00000002", "TRUNKOUTCID="01932842536" <01932842536>") in new stack
    -- Executing [s@macro-outbound-callerid:24] GotoIf("PJSIP/1324-00000002", "1?trunkcid") in new stack
    -- Goto (macro-outbound-callerid,s,30)
    -- Executing [s@macro-outbound-callerid:30] ExecIf("PJSIP/1324-00000002", "1?Set(CALLERID(all)="01932842536" <01932842536>)") in new stack
    -- Executing [s@macro-outbound-callerid:31] ExecIf("PJSIP/1324-00000002", "1?Set(CALLERID(all)="01932955088" <01932955088>)") in new stack
    -- Executing [s@macro-outbound-callerid:32] ExecIf("PJSIP/1324-00000002", "1?Set(CALLERID(all)="01932842536" <01932842536>)") in new stack
    -- Executing [s@macro-outbound-callerid:33] ExecIf("PJSIP/1324-00000002", "0?Set(CALLERID(all)=1324)") in new stack
    -- Executing [s@macro-outbound-callerid:34] ExecIf("PJSIP/1324-00000002", "0?Set(CALLERID(all)=1324)") in new stack
    -- Executing [s@macro-outbound-callerid:35] Set("PJSIP/1324-00000002", "TIOHIDE=no") in new stack
    -- Executing [s@macro-outbound-callerid:36] ExecIf("PJSIP/1324-00000002", "0?Set(CALLERID(name-pres)=prohib_passed_screen)") in new stack
    -- Executing [s@macro-outbound-callerid:37] ExecIf("PJSIP/1324-00000002", "0?Set(CALLERID(num-pres)=prohib_passed_screen)") in new stack
    -- Executing [s@macro-outbound-callerid:38] ExecIf("PJSIP/1324-00000002", "0?Set(CALLERID(name-pres)=prohib_passed_screen)") in new stack
    -- Executing [s@macro-outbound-callerid:39] ExecIf("PJSIP/1324-00000002", "0?Set(CALLERID(num-pres)=prohib_passed_screen)") in new stack
    -- Executing [s@macro-outbound-callerid:40] Set("PJSIP/1324-00000002", "CDR(outbound_cnum)=01932842536") in new stack
    -- Executing [s@macro-outbound-callerid:41] Set("PJSIP/1324-00000002", "CDR(outbound_cnam)=01932842536") in new stack
    -- Executing [s@macro-dialout-trunk:14] GosubIf("PJSIP/1324-00000002", "0?sub-flp-28,s,1()") in new stack
    -- Executing [s@macro-dialout-trunk:15] Set("PJSIP/1324-00000002", "OUTNUM=08000798586") in new stack
    -- Executing [s@macro-dialout-trunk:16] Set("PJSIP/1324-00000002", "custom=PJSIP") in new stack
    -- Executing [s@macro-dialout-trunk:17] ExecIf("PJSIP/1324-00000002", "1?Set(DIAL_TRUNK_OPTIONS=M(setmusic^none))") in new stack
    -- Executing [s@macro-dialout-trunk:18] ExecIf("PJSIP/1324-00000002", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^none)M(confirm))") in new stack
    -- Executing [s@macro-dialout-trunk:19] Macro("PJSIP/1324-00000002", "dialout-trunk-predial-hook,") in new stack
    -- Executing [s@macro-dialout-trunk-predial-hook:1] NoOp("PJSIP/1324-00000002", "CUSTOM: number is 01932842536 : name is 01932842536 : called number is 08000798586 : WH is  : EXT is 1324") in new stack
    -- Executing [s@macro-dialout-trunk-predial-hook:2] GotoIf("PJSIP/1324-00000002", "0?vol") in new stack
    -- Executing [s@macro-dialout-trunk-predial-hook:3] GotoIf("PJSIP/1324-00000002", "0?vol") in new stack
    -- Executing [s@macro-dialout-trunk-predial-hook:4] MacroExit("PJSIP/1324-00000002", "") in new stack
    -- Executing [s@macro-dialout-trunk:20] GotoIf("PJSIP/1324-00000002", "0?bypass,1") in new stack
    -- Executing [s@macro-dialout-trunk:21] ExecIf("PJSIP/1324-00000002", "1?Set(CONNECTEDLINE(num,i)=08000798586)") in new stack
    -- Executing [s@macro-dialout-trunk:22] ExecIf("PJSIP/1324-00000002", "1?Set(CONNECTEDLINE(name,i)=CID:01932842536)") in new stack
    -- Executing [s@macro-dialout-trunk:23] ExecIf("PJSIP/1324-00000002", "0?Set(CONNECTEDLINE(name,i)=CID:(Hidden)01932842536)") in new stack
    -- Executing [s@macro-dialout-trunk:24] GotoIf("PJSIP/1324-00000002", "0?customtrunk") in new stack
    -- Executing [s@macro-dialout-trunk:25] ExecIf("PJSIP/1324-00000002", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^none))") in new stack
    -- Executing [s@macro-dialout-trunk:26] Set("PJSIP/1324-00000002", "HASH(__SIPHEADERS,Alert-Info)=unset") in new stack
    -- Executing [s@macro-dialout-trunk:27] Dial("PJSIP/1324-00000002", "PJSIP/08000798586@1200497-1000,300,M(setmusic^none)b(func-apply-sipheaders^s^1,(28))U(sub-send-obroute-email^08000798586^08000798586^28^1673411166^01932842536^01932842536)") in new stack
    -- PJSIP/1200497-1000-00000003 Internal Gosub(func-apply-sipheaders,s,1(28)) start
    -- Executing [s@func-apply-sipheaders:1] NoOp("PJSIP/1200497-1000-00000003", "Applying SIP Headers to channel PJSIP/1200497-1000-00000003") in new stack
    -- Executing [s@func-apply-sipheaders:2] Set("PJSIP/1200497-1000-00000003", "TECH=PJSIP") in new stack
    -- Executing [s@func-apply-sipheaders:3] Set("PJSIP/1200497-1000-00000003", "SIPHEADERKEYS=Alert-Info") in new stack
    -- Executing [s@func-apply-sipheaders:4] While("PJSIP/1200497-1000-00000003", "1") in new stack
    -- Executing [s@func-apply-sipheaders:5] Set("PJSIP/1200497-1000-00000003", "sipheader=unset") in new stack
    -- Executing [s@func-apply-sipheaders:6] ExecIf("PJSIP/1200497-1000-00000003", "1?Set(PJSIP_HEADER(remove,Alert-Info)=)") in new stack
[2023-01-11 04:26:06] ERROR[1408410]: res_pjsip_header_funcs.c:717 remove_header: No headers had been previously added to this session.
    -- Executing [s@func-apply-sipheaders:7] ExecIf("PJSIP/1200497-1000-00000003", "0?Set(sipheader=<http://127.0.0.1>;info=unset)") in new stack
    -- Executing [s@func-apply-sipheaders:8] ExecIf("PJSIP/1200497-1000-00000003", "0?Set(sipheader=<http://127.0.0.1>unset)") in new stack
    -- Executing [s@func-apply-sipheaders:9] ExecIf("PJSIP/1200497-1000-00000003", "0?Set(PJSIP_HEADER(add,Alert-Info)=unset)") in new stack
    -- Executing [s@func-apply-sipheaders:10] EndWhile("PJSIP/1200497-1000-00000003", "") in new stack
    -- Executing [s@func-apply-sipheaders:4] While("PJSIP/1200497-1000-00000003", "0") in new stack
    -- Executing [s@func-apply-sipheaders:11] Return("PJSIP/1200497-1000-00000003", "") in new stack
  == Spawn extension (func-apply-sipheaders, s, 11) exited non-zero on 'PJSIP/1200497-1000-00000003'
    -- PJSIP/1200497-1000-00000003 Internal Gosub(func-apply-sipheaders,s,1(28)) complete GOSUB_RETVAL=
    -- Called PJSIP/08000798586@1200497-1000
    -- PJSIP/1200497-1000-00000003 is ringing
    -- PJSIP/1200497-1000-00000003 answered PJSIP/1324-00000002
    -- Executing [s@macro-setmusic:1] Set("PJSIP/1200497-1000-00000003", "CHANNEL(musicclass)=none") in new stack
    -- PJSIP/1200497-1000-00000003 Internal Gosub(sub-send-obroute-email,s,1(08000798586,08000798586,28,1673411166,01932842536,01932842536)) start
    -- Executing [s@sub-send-obroute-email:1] GotoIf("PJSIP/1200497-1000-00000003", "0?sendEmail") in new stack
    -- Executing [s@sub-send-obroute-email:2] NoOp("PJSIP/1200497-1000-00000003", "email notifications disabled..exiting.") in new stack
    -- Executing [s@sub-send-obroute-email:3] Return("PJSIP/1200497-1000-00000003", "") in new stack
  == Spawn extension (sub-send-obroute-email, s, 3) exited non-zero on 'PJSIP/1200497-1000-00000003'
    -- PJSIP/1200497-1000-00000003 Internal Gosub(sub-send-obroute-email,s,1(08000798586,08000798586,28,1673411166,01932842536,01932842536)) complete GOSUB_RETVAL=

whiskerp · January 11, 2023, 4:37am

I’ll try to post the PJSIP endpoints fom yesterday again (via the forum rather than e-mail):

rilian*CLI> core show channel PJSIP/1324-00000006
 -- General --
           Name: PJSIP/1324-00000006
           Type: PJSIP
       UniqueID: 1673364452.7
       LinkedID: 1673364452.7
      Caller ID: 01932842536
 Caller ID Name: 01932842536
Connected Line ID: 08000798586
Connected Line ID Name: CID:01932842536
Eff. Connected Line ID: 08000798586
Eff. Connected Line ID Name: CID:01932842536
    DNID Digits: 01932150
       Language: en_GB
          State: Up (6)
  NativeFormats: (g722)
    WriteFormat: slin16
     ReadFormat: slin16
 WriteTranscode: Yes (slin@16000)->(g722@16000)
  ReadTranscode: Yes (g722@16000)->(slin@16000)
 Time to Hangup: 0
   Elapsed Time: 0h0m12s
      Bridge ID: 7b2e021a-1e6e-41e5-8ff6-31db328497b5
 --   PBX   --
        Context: macro-dialout-trunk
      Extension: s
       Priority: 27
     Call Group: 0
   Pickup Group: 0
    Application: Dial
           Data: PJSIP/08000798586@1200497-1000,300,M(setmusic^none)b(func-apply-sipheaders^s^1,(28))U(sub-send-obroute-email^08000798586^08000798586^28^1673364452^01932842536^01932842536)
 Call Identifer: [C-00000005]
      Variables:
BRIDGEPVTCALLID=f88b3940-1a23-48e1-b060-6a247b9aedde
BRIDGEPEER=PJSIP/1200497-1000-00000007
DIALEDPEERNUMBER=08000798586@1200497-1000
DIALEDPEERNAME=PJSIP/1200497-1000-00000007
DIALSTATUS=ANSWER
RINGTIME_MS=443
RINGTIME=0
PROGRESSTIME_MS=
PROGRESSTIME=
DIALEDTIME_MS=
DIALEDTIME=
ANSWEREDTIME_MS=
ANSWEREDTIME=
MACRO_DEPTH=1
~HASH~SIPHEADERS~Alert-Info~=unset
DB_RESULT=INT 4
MACRO_PRIORITY=11
MACRO_CONTEXT=from-internal-additional
MACRO_EXTEN=08000798586
ARG1=28
DIAL_TRUNK_OPTIONS=M(setmusic^none)
custom=PJSIP
OUTNUM=08000798586
TIOHIDE=no
TRUNKOUTCID="01932842536" <01932842536>
EMERGENCYCID=
USEROUTCID="01932955088" <01932955088>
ALLOWTHISROUTE=NO
HOTDESKCALL=0
HOTDESKEXTEN=1324
HOTDESCKCHAN=1324-00000006
OUTBOUND_GROUP=OUT_28
DIAL_NUMBER=08000798586
DIAL_TRUNK=28
ARG4=on
ARG3=
ARG2=08000798586
NODEST=
EMAILNOTIFICATION=FALSE
CALLERIDNUMINTERNAL=1324
CALLERIDNAMEINTERNAL=INT 4
MOHCLASS=none
ROUTENAME=to-freefone-0[58]0
ROUTEID=6
OUTBOUND_ROUTE_NAME=to-freefone-0[58]0
GOSUB_RETVAL=
REC_STATUS=RECORDING
RECORD_ID=PJSIP/1324-00000006
MIXMON_ID=
MIXMONITOR_FILENAME=/var/spool/asterisk/monitor/2023/01/10/out-08000798586-1324-20230110-152732-1673364452.7.sln
CALLFILENAME=out-08000798586-1324-20230110-152732-1673364452.7
REC_POLICY_MODE=YES
RECMODE=dontcare
REC_POLICY_MODE_SAVE=
MON_FMT=sln
FROMEXTEN=1324
TIMESTR=20230110-152732
YEAR=2023
MONTH=01
DAY=10
NOW=1673364452
AMPUSER=1324
CHANEXTEN=1324-00000006
CHANEXTENCONTEXT=1324-00000006
CHANCONTEXT=
TOUCH_MONITOR=1673364452.7
TTL=64
DIAL_OPTIONS=r
AMPUSERCID=1324
AMPUSERCIDNAME=INT 4
REALCALLERIDNUM=1324
SIPDOMAIN=whisker.org.uk
  CDR Variables:
level 1: outbound_cnam=01932842536
level 1: outbound_cnum=01932842536
level 1: recordingfile=out-08000798586-1324-20230110-152732-1673364452.7.sln
level 1: cnum=1324
level 1: cnam=INT 4
level 1: dnid=01932150
level 1: clid="01932842536" <01932842536>
level 1: src=01932842536
level 1: dst=s
level 1: dcontext=macro-dialout-trunk
level 1: channel=PJSIP/1324-00000006
level 1: dstchannel=PJSIP/1200497-1000-00000007
level 1: lastapp=Dial
level 1: lastdata=PJSIP/08000798586@1200497-1000,300,M(setmusic^none)b(func-apply-sipheaders^s^1,(28))U(sub-send-obroute-email^08000798586^08000798586^28^1673364452^01932842536^01932842536)
level 1: start=1673364452.762040
level 1: answer=1673364455.604521
level 1: end=0.000000
level 1: duration=12
level 1: billsec=9
level 1: disposition=8
level 1: amaflags=3
level 1: uniqueid=1673364452.7
level 1: linkedid=1673364452.7
level 1: sequence=7

 -- Streams --
Name: audio-0
    Type: audio
    State: sendrecv
    Group: -1
    Formats: (g722|alaw|ulaw)
    Metadata:
rilian*CLI> core show channel PJSIP/1
PJSIP/1200497-1000-00000007  PJSIP/1324-00000006
rilian*CLI> core show channel PJSIP/1200497-1000-00000007
 -- General --
           Name: PJSIP/1200497-1000-00000007
           Type: PJSIP
       UniqueID: 1673364452.8
       LinkedID: 1673364452.7
      Caller ID: 08000798586
 Caller ID Name: CID:01932842536
Connected Line ID: 01932842536
Connected Line ID Name: 01932842536
Eff. Connected Line ID: 01932842536
Eff. Connected Line ID Name: 01932842536
    DNID Digits: (N/A)
       Language: en_GB
          State: Up (6)
  NativeFormats: (alaw)
    WriteFormat: slin16
     ReadFormat: slin16
 WriteTranscode: Yes (slin@16000)->(slin@8000)->(alaw@8000)
  ReadTranscode: Yes (alaw@8000)->(slin@8000)->(slin@16000)
 Time to Hangup: 0
   Elapsed Time: 0h0m19s
      Bridge ID: 7b2e021a-1e6e-41e5-8ff6-31db328497b5
 --   PBX   --
        Context: macro-dialout-trunk
      Extension: s
       Priority: 1
     Call Group: 0
   Pickup Group: 0
    Application: AppDial
           Data: (Outgoing Line)
 Call Identifer: [C-00000005]
      Variables:
BRIDGEPVTCALLID=49757632@192_168_25_35
BRIDGEPEER=PJSIP/1324-00000006
GOSUB_RETVAL=
MACRO_DEPTH=0
sipkey=
sipheader=unset
SIPHEADERKEYS=
TECH=PJSIP
DIALEDPEERNUMBER=08000798586@1200497-1000
~HASH~SIPHEADERS~Alert-Info~=unset
NODEST=
EMAILNOTIFICATION=FALSE
CALLERIDNUMINTERNAL=1324
CALLERIDNAMEINTERNAL=INT 4
ROUTENAME=to-freefone-0[58]0
ROUTEID=6
REC_STATUS=RECORDING
RECORD_ID=PJSIP/1324-00000006
MIXMON_ID=
CALLFILENAME=out-08000798586-1324-20230110-152732-1673364452.7
REC_POLICY_MODE=YES
MON_FMT=sln
FROMEXTEN=1324
TIMESTR=20230110-152732
YEAR=2023
MONTH=01
DAY=10
TTL=64
DIAL_OPTIONS=r
  CDR Variables:
level 1: clid="CID:01932842536" <08000798586>
level 1: src=08000798586
level 1: dst=s
level 1: dcontext=macro-dialout-trunk
level 1: channel=PJSIP/1200497-1000-00000007
level 1: lastapp=AppDial
level 1: lastdata=(Outgoing Line)
level 1: start=1673364452.858876
level 1: answer=1673364455.582481
level 1: end=1673364455.609153
level 1: duration=2
level 1: billsec=0
level 1: disposition=8
level 1: amaflags=3
level 1: uniqueid=1673364452.8
level 1: linkedid=1673364452.7
level 1: sequence=8

 -- Streams --
Name: audio-0
    Type: audio
    State: sendrecv
    Group: -1
    Formats: (alaw)
    Metadata:

whiskerp · January 11, 2023, 5:20am

I have saved tcpdump PCAP traces from both normal (branch 20.1) and “bumpy” (branch 20 master) calls for the G.722 stream to the handset. The Wireshark analysis of the bumpy call shows regular incorrect timestamps every 240 or 260ms eg:
10.820, 11.080, 11.320, 11.580, 11.820, 12.080 (seconds). The timestamps increment by regular 160 in the file and then there is a jump by 152 then eleven or twelve regular 160 then another 152. I can’t attach anything so let me know how to get it to you. The good stream timestamps always increment by 160.