Asterisk is showing Warning: Translated frame write failed

[ConnectedDialer]

I recently experimented with upgrading our vicidial installation from 8 to 9. After importing DB from older server and running upgrade sql, everything went fine and appears to be working, however for some reason I see a lot of warning popping up in asterisk during calls. These two lines keep repeating:

Code: Select all

[Oct  6 12:50:57] WARNING[12791][C-00000004]: file.c:259 ast_writestream: Translated frame write failed
[Oct  6 12:50:57] WARNING[12791][C-00000004]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream


I've checked ips and they are set right in server section
I've ran update ip script.
/etc/astguiclient.conf has right ipfor VARserver_ip.
There's plenty of space on the machine.

I feel it is somehow related to imported db/data settings, because this warning does not appear on fresh install.

Any ideas how I could troubleshoot this?

[ambiorixg12]

if (ast_writestream(chan->monitor->read_stream, f) < 0)
ast_log(LOG_WARNING, "Failed to write data to channel monitor read stream\n");
}

[ConnectedDialer]

Having investigated further, I discovered that the issue is related to PRI Callerid settings in extensions.conf. Below is the configuration that I use that appears to be causing those warning messages. If I comment out below lines, then warning messages disappear.

Code: Select all

; special Canadian PRI callerIDname settings FOR USE IN LOOPBACK CONTEXT ONLY
exten => _91NXXNXXXXXX,1,Set(CALLERID(name)=ourdomain.ca)
exten => _91NXXNXXXXXX,n,AGI(agi-CANADA_PRI_CIDname.agi)
exten => _91NXXNXXXXXX,n,Dial(${DIAL9TRUNK}/+1${EXTEN:2},,To)
exten => _91NXXNXXXXXX,n,Hangup()

exten => _9NXXNXXXXXX,1,Set(CALLERID(name)=ourdomain.ca)
exten => _9NXXNXXXXXX,n,AGI(agi-CANADA_PRI_CIDname.agi)
exten => _9NXXNXXXXXX,n,Dial(${DIAL9TRUNK}/+1${EXTEN:1},,To)
exten => _9NXXNXXXXXX,n,Hangup()




exten => _91NXXNXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _91NXXNXXXXXX,n,Dial(${TRUNKloop}/888${EXTEN:2},55,o)
exten => _91NXXNXXXXXX,n,Hangup()
exten => _888NXXNXXXXXX,1,Goto(loopback-no-log,91${EXTEN:3},1)
exten => _888NXXNXXXXXX,n,Hangup()

exten => _9NXXNXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _9NXXNXXXXXX,n,Dial(${TRUNKloop}/888${EXTEN:1},55,o)
exten => _9NXXNXXXXXX,n,Hangup()
exten => _888NXXNXXXXXX,1,Goto(loopback-no-log,91${EXTEN:3},1)
exten => _888NXXNXXXXXX,n,Hangup()



Any ideas what could be going wrong?

[williamconley]

If you comment out "those lines", how does it make the call? Since those lines represent your connection to the carrier, wouldn't that mean the call fails?

[ConnectedDialer]

williamconley, by commenting out the lines I'm basically enabling/disabling using loopback context to set the CALLERID(name) in Canada. If I enable using loopback context, I get the warning, otherwise it's fine. This does not happen on fresh install, only after importing old DB and upgrading sql I get this issue. Any idea what could be causing this?

[williamconley]

If you comment out "those lines", how does it make the call? Since those lines represent your connection to the carrier, wouldn't that mean the call fails?

OK: If you comment out those lines in the [loopback-no-log] context, but leave the call in the [loopback-no-log] context, then the call will fail as those lines represent your connection to your carrier.

What other changes are you making besides commenting out those lines? If one method results in this logged error (Failed to write data to channel monitor write stream), and the other method does not, then either the error is related directly or indirectly to the method being changed OR you also made another change.

The devil is in those details.

[ConnectedDialer]

The call does not fail because I'm also commenting out this portion: (The section in extensions.conf that starts with ; dial a USA long distance outbound number through the loopback-no-log context):

Code: Select all

exten => _91NXXNXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _91NXXNXXXXXX,n,Dial(${TRUNKloop}/888${EXTEN:2},55,o)
exten => _91NXXNXXXXXX,n,Hangup()
exten => _888NXXNXXXXXX,1,Goto(loopback-no-log,91${EXTEN:3},1)
exten => _888NXXNXXXXXX,n,Hangup()

exten => _9NXXNXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _9NXXNXXXXXX,n,Dial(${TRUNKloop}/888${EXTEN:1},55,o)
exten => _9NXXNXXXXXX,n,Hangup()
exten => _888NXXNXXXXXX,1,Goto(loopback-no-log,91${EXTEN:3},1)
exten => _888NXXNXXXXXX,n,Hangup()


I just created separate phone entry to compare if this was somehow related to what data phone entries have in old system compared to new. It looks like the issue is stemming from phone_context='defaultlog' vs phone_context='default'.

For some reason phone_context='defaultlog' (which were set in old system and worked) does not work on new system when using loopback-no-log and is what's causing the warnings. What could I be doing wrong?

[williamconley]

The call does not fail because I'm also commenting out this portion: (The section in extensions.conf that starts with ; dial a USA long distance outbound number through the loopback-no-log context):

Code: Select all

exten => _91NXXNXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _91NXXNXXXXXX,n,Dial(${TRUNKloop}/888${EXTEN:2},55,o)
exten => _91NXXNXXXXXX,n,Hangup()
exten => _888NXXNXXXXXX,1,Goto(loopback-no-log,91${EXTEN:3},1)
exten => _888NXXNXXXXXX,n,Hangup()

exten => _9NXXNXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _9NXXNXXXXXX,n,Dial(${TRUNKloop}/888${EXTEN:1},55,o)
exten => _9NXXNXXXXXX,n,Hangup()
exten => _888NXXNXXXXXX,1,Goto(loopback-no-log,91${EXTEN:3},1)
exten => _888NXXNXXXXXX,n,Hangup()


Um ... I think you said you edited the extensions.conf in two places, enabling this similar extension in ... some other place? Looks like one of them invokes a canadian agi script which expects a PRI connection. An agi script expecting a PRI connection that does not actually HAVE a PRI connection will likely fail. True.

So it comes down to ... you are trying to test something to do with loopback-no-log vs defaulltlog vs default. What are you really trying to accomplish? You can just tell us. We won't freak out. Really.

[ConnectedDialer]

Sorry if my posts were confusing, I will try to be more clear:

What I'm trying to achieve:

1. Record outgoing calls. To do this, when editing Phone in Vicidial admin, I have Phone Context: defaultlog

2. Set custom CALLERID(name) in Canada to ourdomain.ca. To do this: here's changes in /etc/asterisk/extensions.conf

Code: Select all

[loopback-no-log]
; special Canadian PRI callerIDname settings FOR USE IN LOOPBACK CONTEXT ONLY
exten => _91NXXNXXXXXX,1,Set(CALLERID(name)=ourdomain.ca)
exten => _91NXXNXXXXXX,n,AGI(agi-CANADA_PRI_CIDname.agi)
exten => _91NXXNXXXXXX,n,Dial(${DIAL9TRUNK}/+1${EXTEN:2},,To)
exten => _91NXXNXXXXXX,n,Hangup()

exten => _999XX11112,1,Wait(2)
exten => _999XX11112,n,Answer()
exten => _999XX11112,n,Playback(ss-noservice)
exten => _999XX11112,n,Playback(vm-goodbye)
exten => _999XX11112,n,Hangup()


AND

Code: Select all

; dial a USA long distance outbound number through the loopback-no-log context
exten => _91NXXNXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _91NXXNXXXXXX,n,Dial(${TRUNKloop}/888${EXTEN:2},55,o)
exten => _91NXXNXXXXXX,n,Hangup()

exten => _9NXXNXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _9NXXNXXXXXX,n,Dial(${TRUNKloop}/888${EXTEN:1},55,o)
exten => _9NXXNXXXXXX,n,Hangup()

exten => _888NXXNXXXXXX,1,Goto(loopback-no-log,91${EXTEN:3},1)
exten => _888NXXNXXXXXX,n,Hangup()


Somehow this worked on vicidial 8, but in vicidial 9 I'm getting the warnings.

By the way, isn't 'defaultlog' context part of vicidial? It appears in extensions-vicidial.conf and I assume it's not something custom.

[williamconley]

Record outgoing calls.

Recording outgoing calls has no "set callerid name" requirement. There are settings in DID, Ingroup, Campaign, etc for recording calls. What kind of calls are you trying to record? And why are you trying to use a PRI agi script to do so?

I'll guess: You want to record outbound manual dialed calls that are NOT initiated within the Vicidial Agent Screen.

Pretty sure there's a Vicidial Manager Manual entry for this that would have been updated for the latest version of Vicidial (assuming there were some sort of changes from previous versions). It's probably even in the Free version.

[ConnectedDialer]

Recording outgoing calls has no "set callerid name" requirement. There are settings in DID, Ingroup, Campaign, etc for recording calls. What kind of calls are you trying to record? And why are you trying to use a PRI agi script to do so?

I'm using PRI agi script to set callerid name for calls made by vicidial, it's not related to defaultlog context for phones. It is simply my observation that it seems to conflict with it in version 9.

I'll guess: You want to record outbound manual dialed calls that are NOT initiated within the Vicidial Agent Screen.

Correct, when agent makes calls through the sip phone directly, I want the calls to be recorded as well.

Pretty sure there's a Vicidial Manager Manual entry for this that would have been updated for the latest version of Vicidial (assuming there were some sort of changes from previous versions). It's probably even in the Free version.

I've been searching through old paid manual as well as new free one and I do not see instructions on how to set this up.

The new manual says this:

for additional security, change “Phone Context” to phones. This disables the ability
for agents to make calls directly from the phones, they must log into a campaign in
the dialer. This also adds another layer of security against hackers that may attempt to
register their own phones to your dialer.

I could not find a mention for how to record direct sip phone calls.

I will keep searching, but a hint would be greatly appreciated.

[williamconley]

I'm using PRI agi script to set callerid name for calls made by vicidial,

Why? Vicidial already has several controls to set the caller id. You're using an agi script that expects a PRI, but you don't have a PRI (sip calls are not PRI calls). That could be the reason your failure occurs.

Have you tried:

viewtopic.php?f=4&t=23007&p=87769#p87769

Are you saying [defaultlog] doesn't exist in extensions-vicidial.conf?

[ConnectedDialer]

Why? Vicidial already has several controls to set the caller id. You're using an agi script that expects a PRI, but you don't have a PRI (sip calls are not PRI calls). That could be the reason your failure occurs.

I'm using that to set not caller id (the phone number), but rather the name that appears above the number. If i do not use that, calls from vicidial (not calls from sip phone directly but vicidial generated calls) have long IDsin them as name. As far as I know Vicidial uses that internally and in Canada caller id NAME is read from sip From header, not looked up in some database so the solution is to overwrite it by loopback or going through another server that will set it. We use loopback and it works.

How else do you suggest I do it?

Are you saying [defaultlog] doesn't exist in extensions-vicidial.conf?

I checked and it exists. So when I use defaultlog in Phone settings, somehow it creates the warning messages. I don't know how defaultlog is interacting with the loopback but they do not seem to working in version 9 when both are being used. It used to work in version 8.

What do you think I'm doing wrong? How do I both set caller id NAME in Canada and record phones that are calling directly outside of vicidial?

[williamconley]

Have you looked through this post's advice?

viewtopic.php?f=4&t=38023#p131664

If that's where you are coming from, which I suspect, have you checked the output of the asterisk screen (screen -r asterisk) during an attempt to find the First Error Report during a call? Note that this differs from "asterisk -R" output in that the asterisk screen will show perl/agi errors whereas the "asterisk remote console" will not.

[ConnectedDialer]

Code: Select all

Have you looked through this post's advice?

viewtopic.php?f=4&t=38023#p131664


Yes, I've gone through that post.

have you checked the output of the asterisk screen (screen -r asterisk) during an attempt to find the First Error Report during a call? Note that this differs from "asterisk -R" output in that the asterisk screen will show perl/agi errors whereas the "asterisk remote console" will not

I've been observing the poutput using command "asterisk -vvvvr" but using "screen -r asterisk" is showing same warnings when I make a call. See below:

Code: Select all

[Oct 14 12:50:31] WARNING[12346][C-00000004]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 12:50:31] WARNING[12346][C-00000004]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 12:50:32]     -- SIP/twac-00000005 requested media update control 26, passing it to IAX2/ASTloop-11536
[Oct 14 12:50:32]     -- SIP/twac-00000005 answered IAX2/ASTloop-11536
[Oct 14 12:50:32]     -- Channel SIP/twac-00000005 joined 'simple_bridge' basic-bridge <a39b48aa-7835-4637-b052-b3b42e22c4fb>
[Oct 14 12:50:32]     -- Channel IAX2/ASTloop-11536 joined 'simple_bridge' basic-bridge <a39b48aa-7835-4637-b052-b3b42e22c4fb>
[Oct 14 12:50:32] WARNING[12346][C-00000004]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 12:50:32] WARNING[12346][C-00000004]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 12:50:33]     -- IAX2/127.0.0.1:40569-8904 answered SIP/4001-00000004
[Oct 14 12:50:33]     -- Channel IAX2/127.0.0.1:40569-8904 joined 'simple_bridge' basic-bridge <8ce488cb-633a-4ddd-9a36-8042db31bc8a>
[Oct 14 12:50:33]     -- Channel SIP/4001-00000004 joined 'simple_bridge' basic-bridge <8ce488cb-633a-4ddd-9a36-8042db31bc8a>
[Oct 14 12:50:33] WARNING[12346][C-00000004]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 12:50:33] WARNING[12346][C-00000004]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 12:50:33] WARNING[12346][C-00000004]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 12:50:33] WARNING[12346][C-00000004]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 12:50:33] WARNING[12346][C-00000004]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 12:50:33] WARNING[12346][C-00000004]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 12:50:33] WARNING[12346][C-00000004]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 12:50:33] WARNING[12346][C-00000004]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 12:50:33] WARNING[12346][C-00000004]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 12:50:33] WARNING[12346][C-00000004]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 12:50:33] WARNING[12346][C-00000004]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 12:50:33] WARNING[12346][C-00000004]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 12:50:33] WARNING[12346][C-00000004]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 12:50:33] WARNING[12346][C-00000004]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 12:50:33] WARNING[12346][C-00000004]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 12:50:33] WARNING[12346][C-00000004]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 12:50:33] WARNING[12346][C-00000004]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 12:50:33] WARNING[12346][C-00000004]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 12:50:33] WARNING[12346][C-00000004]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 12:50:33] WARNING[12346][C-00000004]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 12:50:33] WARNING[12346][C-00000004]: file.c:259 ast_writestream: Translated frame write failed


[williamconley]

Is that the first failure? Please show one call from beginning to end with no other traffic (using screen -r asterisk).

[ConnectedDialer]

Here is one full outbound call call, where cellphone rejects call, so it goes to voicemail, and soon after sip phone hangs up.

(I've changed ip, phone number dialed and name of person in Phones entry in this log for privacy)

Code: Select all

[Oct 14 20:45:01]   == Manager 'sendcron' logged on from 127.0.0.1
[Oct 14 20:45:01]   == Manager 'sendcron' logged off from 127.0.0.1
[Oct 14 20:45:01]   == Manager 'sendcron' logged on from 127.0.0.1
[Oct 14 20:45:06]   == Manager 'sendcron' logged on from 127.0.0.1
[Oct 14 20:45:06]   == Manager 'sendcron' logged off from 127.0.0.1
[Oct 14 20:45:10]   == Manager 'sendcron' logged off from 127.0.0.1
[Oct 14 20:45:15]   == Using SIP RTP CoS mark 5
[Oct 14 20:45:15]        > 0x7f497002ad40 -- Strict RTP learning after remote address set to: 24.25.26.27:8000
[Oct 14 20:45:15]     -- Executing [96471234567@defaultlog:1] AGI("SIP/4001-00000000", "agi-NVA_recording.agi,BOTH------Y---Y---Y") in new stack
[Oct 14 20:45:15]     -- Launched AGI Script /usr/share/asterisk/agi-bin/agi-NVA_recording.agi
2020-10-14 20:45:15|agi-NVA_recording.agi|Perl Environment Dump:
2020-10-14 20:45:15|agi-NVA_recording.agi|BOTH||Y|Y||
2020-10-14 20:45:15|agi-NVA_recording.agi|request|agi-NVA_recording.agi
2020-10-14 20:45:15|agi-NVA_recording.agi|channel|SIP/4001-00000000
2020-10-14 20:45:15|agi-NVA_recording.agi|language|en
2020-10-14 20:45:15|agi-NVA_recording.agi|type|SIP
2020-10-14 20:45:15|agi-NVA_recording.agi|uniqueid|1602722715.0
2020-10-14 20:45:15|agi-NVA_recording.agi|version|13.29.2-vici
2020-10-14 20:45:15|agi-NVA_recording.agi|callerid|14167890080
2020-10-14 20:45:15|agi-NVA_recording.agi|calleridname|Firstname Lastname
2020-10-14 20:45:15|agi-NVA_recording.agi|callingpres|0
2020-10-14 20:45:15|agi-NVA_recording.agi|callingani2|0
2020-10-14 20:45:15|agi-NVA_recording.agi|callington|0
2020-10-14 20:45:15|agi-NVA_recording.agi|callingtns|0
2020-10-14 20:45:15|agi-NVA_recording.agi|dnid|96471234567
2020-10-14 20:45:15|agi-NVA_recording.agi|rdnis|unknown
2020-10-14 20:45:15|agi-NVA_recording.agi|context|defaultlog
2020-10-14 20:45:15|agi-NVA_recording.agi|extension|96471234567
2020-10-14 20:45:15|agi-NVA_recording.agi|priority|1
2020-10-14 20:45:15|agi-NVA_recording.agi|enhanced|0.0
2020-10-14 20:45:15|agi-NVA_recording.agi|accountcode|4001
2020-10-14 20:45:15|agi-NVA_recording.agi|threadid|139953320978176
2020-10-14 20:45:15|agi-NVA_recording.agi|arg_1|BOTH------Y---Y---Y
2020-10-14 20:45:15|agi-NVA_recording.agi|Not a Vicidial call: Firstname Lastname
[Oct 14 20:45:15]     -- AGI Script Executing Application: (Monitor) Options: (wav,/var/spool/asterisk/monitor/MIX/20201014204515_4001_96471234567)
[Oct 14 20:45:15]     -- <SIP/4001-00000000>AGI Script agi-NVA_recording.agi completed, returning 0
[Oct 14 20:45:15]     -- Executing [96471234567@defaultlog:2] Goto("SIP/4001-00000000", "default,96471234567,1") in new stack
[Oct 14 20:45:15]     -- Goto (default,96471234567,1)
[Oct 14 20:45:15]     -- Executing [96471234567@default:1] AGI("SIP/4001-00000000", "agi://127.0.0.1:4577/call_log") in new stack
[Oct 14 20:45:15]     -- <SIP/4001-00000000>AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Oct 14 20:45:15]     -- Executing [96471234567@default:2] Dial("SIP/4001-00000000", "IAX2/ASTloop:2UqSUSR0D6OAysO@127.0.0.1:40569/8886471234567,55,o") in new stack
[Oct 14 20:45:15]     -- Called IAX2/ASTloop:2UqSUSR0D6OAysO@127.0.0.1:40569/8886471234567
[Oct 14 20:45:15]     -- Accepting AUTHENTICATED call from 127.0.0.1:59948:
[Oct 14 20:45:15]     --        > requested format = ulaw,
[Oct 14 20:45:15]     --        > requested prefs = (ulaw|gsm),
[Oct 14 20:45:15]     --        > actual format = ulaw,
[Oct 14 20:45:15]     --        > host prefs = (ulaw),
[Oct 14 20:45:15]     --        > priority = mine
[Oct 14 20:45:15]     -- Call accepted by 127.0.0.1:40569 (format ulaw)
[Oct 14 20:45:15]     -- Format for call is (ulaw)
[Oct 14 20:45:15]     -- Executing [8886471234567@default:1] Goto("IAX2/ASTloop-15738", "loopback-no-log,916471234567,1") in new stack
[Oct 14 20:45:15]     -- Goto (loopback-no-log,916471234567,1)
[Oct 14 20:45:15]     -- Executing [916471234567@loopback-no-log:1] Set("IAX2/ASTloop-15738", "CALLERID(name)=OurDomain.ca") in new stack
[Oct 14 20:45:15]     -- Executing [916471234567@loopback-no-log:2] AGI("IAX2/ASTloop-15738", "agi-CANADA_PRI_CIDname.agi") in new stack
[Oct 14 20:45:15]     -- Launched AGI Script /usr/share/asterisk/agi-bin/agi-CANADA_PRI_CIDname.agi
[Oct 14 20:45:15]     -- <IAX2/ASTloop-15738>AGI Script agi-CANADA_PRI_CIDname.agi completed, returning 0
[Oct 14 20:45:15]     -- Executing [916471234567@loopback-no-log:3] Dial("IAX2/ASTloop-15738", "SIP/twac/+16471234567,,To") in new stack
[Oct 14 20:45:15]   == Using SIP RTP CoS mark 5
[Oct 14 20:45:15]     -- Called SIP/twac/+16471234567
[Oct 14 20:45:19]        > 0x7f498801f290 -- Strict RTP learning after remote address set to: 34.203.250.208:14738
[Oct 14 20:45:19]     -- SIP/twac-00000001 is making progress passing it to IAX2/ASTloop-15738
[Oct 14 20:45:19]        > 0x7f498801f290 -- Strict RTP switching to RTP target address 34.203.250.208:14738 as source
[Oct 14 20:45:19]     -- IAX2/127.0.0.1:40569-2724 is making progress passing it to SIP/4001-00000000
[Oct 14 20:45:19]        > 0x7f497002ad40 -- Strict RTP switching to RTP target address 24.25.26.27:8000 as source
[Oct 14 20:45:20]        > 0x7f497002ad40 -- Strict RTP learning complete - Locking on source address 24.25.26.27:8000
[Oct 14 20:45:20] WARNING[5529][C-00000000]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 20:45:20] WARNING[5529][C-00000000]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 20:45:24]        > 0x7f498801f290 -- Strict RTP learning complete - Locking on source address 34.203.250.208:14738
[Oct 14 20:45:25]     -- SIP/twac-00000001 requested media update control 26, passing it to IAX2/ASTloop-15738
[Oct 14 20:45:25]     -- SIP/twac-00000001 answered IAX2/ASTloop-15738
[Oct 14 20:45:25]     -- Channel SIP/twac-00000001 joined 'simple_bridge' basic-bridge <c8ae3a78-151b-47b5-88fc-6b32339ab910>
[Oct 14 20:45:25]     -- Channel IAX2/ASTloop-15738 joined 'simple_bridge' basic-bridge <c8ae3a78-151b-47b5-88fc-6b32339ab910>
[Oct 14 20:45:25]     -- IAX2/127.0.0.1:40569-2724 answered SIP/4001-00000000
[Oct 14 20:45:25]     -- Channel IAX2/127.0.0.1:40569-2724 joined 'simple_bridge' basic-bridge <6a42436d-7615-4b8b-9665-a7894575c879>
[Oct 14 20:45:25]     -- Channel SIP/4001-00000000 joined 'simple_bridge' basic-bridge <6a42436d-7615-4b8b-9665-a7894575c879>
[Oct 14 20:45:25] WARNING[5529][C-00000000]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 20:45:25] WARNING[5529][C-00000000]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 20:45:25] WARNING[5529][C-00000000]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 20:45:25] WARNING[5529][C-00000000]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 20:45:25] WARNING[5529][C-00000000]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 20:45:25] WARNING[5529][C-00000000]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 20:45:25] WARNING[5529][C-00000000]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 20:45:25] WARNING[5529][C-00000000]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 20:45:25] WARNING[5529][C-00000000]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 20:45:25] WARNING[5529][C-00000000]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 20:45:25] WARNING[5529][C-00000000]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 20:45:25] WARNING[5529][C-00000000]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 20:45:25] WARNING[5529][C-00000000]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 20:45:25] WARNING[5529][C-00000000]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 20:45:25] WARNING[5529][C-00000000]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 20:45:25] WARNING[5529][C-00000000]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 20:45:25] WARNING[5529][C-00000000]: file.c:259 ast_writestream: Translated frame write failed
[Oct 14 20:45:25] WARNING[5529][C-00000000]: channel.c:5478 ast_write: Failed to write data to channel monitor write stream
[Oct 14 20:45:26]     -- Channel SIP/4001-00000000 left 'simple_bridge' basic-bridge <6a42436d-7615-4b8b-9665-a7894575c879>
[Oct 14 20:45:26]   == Spawn extension (default, 96471234567, 2) exited non-zero on 'SIP/4001-00000000'
[Oct 14 20:45:26] WARNING[5529][C-00000000]: func_hangupcause.c:140 hangupcause_read: Unable to find information for channel
[Oct 14 20:45:26]     -- Executing [h@default:1] AGI("SIP/4001-00000000", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----10-----1-----)") in new stack
[Oct 14 20:45:26]     -- Channel IAX2/127.0.0.1:40569-2724 left 'simple_bridge' basic-bridge <6a42436d-7615-4b8b-9665-a7894575c879>
[Oct 14 20:45:26]     -- Hungup 'IAX2/127.0.0.1:40569-2724'
[Oct 14 20:45:26]     -- Channel IAX2/ASTloop-15738 left 'simple_bridge' basic-bridge <c8ae3a78-151b-47b5-88fc-6b32339ab910>
[Oct 14 20:45:26]   == Spawn extension (loopback-no-log, 916471234567, 3) exited non-zero on 'IAX2/ASTloop-15738'
[Oct 14 20:45:26]     -- Hungup 'IAX2/ASTloop-15738'
[Oct 14 20:45:26]     -- Channel SIP/twac-00000001 left 'simple_bridge' basic-bridge <c8ae3a78-151b-47b5-88fc-6b32339ab910>
[Oct 14 20:45:26]     -- <SIP/4001-00000000>AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----10-----1-----) completed, returning 0



P.S. I have confirmed that even on a fresh vicidial 9 install, if you use Canadian loopback context and set phone context to defaultlog, the warning appear. Should I post another thread for this? Is there a way to report a bug - if this indeed is a bug?

[williamconley]

What does your [defaultlog] context have in it?

Did you modify extensions-vicidial.conf in some fashion? Perhaps by editing or removing the "defaultlog" call menu that's automatically included in Vicidial at buildout?

[ConnectedDialer]

What does your [defaultlog] context have in it?

defaultlog has not been changed.

Code: Select all

[defaultlog]
exten => s,1,Answer
exten => s,n,AGI(agi-VDAD_inbound_calltime_check.agi,-----NO-----defaultlog-------------------------NO-----YES)
exten => s,n,Set(INVCOUNT=0)
exten => s,n,Background(sip-silence)
exten => s,n,WaitExten(20)


; hangup
exten => t,1,Playback(vm-goodbye)
exten => t,n,Hangup()
exten => i,1,Goto(s,4)
exten => i,n,Hangup()
; hangup
exten => h,1,AGI(agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----${HANGUPCAUSE}-----${DIALSTATUS}-----${DIALEDTIME}-----${ANSWEREDTIME}-----${HANGUPCAUSE(${HANGUPCAUSE_KEYS()},tech)}))

; custom dialplan entries
exten => _X.,1,AGI(agi-NVA_recording.agi,BOTH------Y---Y---Y)
exten => _X.,n,Goto(default,${EXTEN},1)



Did you modify extensions-vicidial.conf in some fashion? Perhaps by editing or removing the "defaultlog" call menu that's automatically included in Vicidial at buildout?

No, I have not removed or made any changes to extensions-vicidial.conf.

I have now confirmed that even when I do not do any modifications or import old data, just using fresh install, if I use loopback enabled and use defaultlog I get warnings. I suspect this is a bug in v9?

[williamconley]

In your provided log, the "s,1,Answer" appears to have been skipped.

Also in your previous example, the options passed to the agi script showed as "BOTH------Y---Y---Y", but in this context it now shows as "-----NO-----defaultlog-------------------------NO-----YES".

So ... are you sure the one you are showing (with the answer) is the one being used?

[ConnectedDialer]

In your provided log, the "s,1,Answer" appears to have been skipped.

In the cal log I provided earlier from 'screen -r asterisk', I make a call with sip phone, call rings on cellphone. I decline the call and it goes to voicemail, then I almost immediately hang up from sip phone.

Also in your previous example, the options passed to the agi script showed as "BOTH------Y---Y---Y", but in this context it now shows as "-----NO-----defaultlog-------------------------NO-----YES".

I don't know what it should be or how it got to be that way, but I have not changed anything, the only thing I'm changing is enabling loopback for caller id name and setting phone context in Phones to defaultlog.

So ... are you sure the one you are showing (with the answer) is the one being used?

I am sure. I have not changed anything else. I am using a fresh VM image that I created for testing purposes. Nothing is changed, other than:

* I configured firewall
* Setup carrier
* Added basic Phone record in admin area.
* Enabled using loopback for Canada
* set phone context to defaultlog in Phones admin area edit page.

The warnings disappear if I disable using loopback for Canada or if i use default instead of defaultlog. If I'm using both, warning reappear.

[ConnectedDialer]

Is there a way to report a bug for vicidial? Should I open a separate thread that's more concise?

[williamconley]

Did you try with just the defaultlog?

[ConnectedDialer]

Did you try with just the defaultlog?

yes, with just defaultlog it works without warnings.

But I need to set the CNAM with loopback, because in Canada customers see the long ID strings instead,