KB4MDD
commented
3 months ago I want to confirm this is an outbound call, rf to phone.
Closed eliggett closed 2 months ago
KB4MDD
commented
3 months ago I want to confirm this is an outbound call, rf to phone.
eliggett
commented
3 months ago Correct. I cheated a little and initiated it from the asterisk console (rpt fun 617081 *62...), but it's the same result if I jump in the car and do it with the radio. Limited 900 MHz radio resources here :)
KB4MDD
commented
3 months ago I will setup a test system and report back.
k5dvt
commented
3 months ago I'll also added that I'm having the same issue. Although I have a video demonstrating that when the RF user keys up for a brief moment during the hang time you can hear any audio from the phone side (as demonstrated here by listening to WWV) https://www.youtube.com/watch?v=Ir-EAOG00Yw
-K5DVT
eliggett
commented
3 months ago A little progress, I enabled "reverse autopatch" (where asterisk answers incoming calls and connects them to the repeater), and you know what? Reverse autopatch vox is working perfectly. It works so good!
With outgoing calls though, my experience is the same as yours, @k5dvt . I can catch a brief moment of audio during the tail beep but none beyond that.
I will try and get some debug out of it and see if the way it joins stuff together is wrong. I think we are very close.
eliggett
commented
3 months ago Working call inbound (reverse autopatch):
[2024-08-24 15:03:36.799] VERBOSE[83525] chan_iax2.c: Accepting UNAUTHENTICATED call from 208.100.60.36:4569:
> requested format = ulaw,
> requested prefs = (ulaw|g729|g722|gsm),
> actual format = ulaw,
> host prefs = (ulaw|adpcm|gsm),
> priority = mine
[2024-08-24 15:03:36.852] VERBOSE[83658][C-00000009] pbx.c: Executing [s@voipmscontext:1] Verbose("IAX2/voipms-5692", "1, Caller "W6EL" <6265551212> has entered the voipms-inbound context.") in new stack
[2024-08-24 15:03:36.852] VERBOSE[83658][C-00000009] app_verbose.c: Caller "W6EL" <6265551212> has entered the voipms-inbound context.
[2024-08-24 15:03:36.852] VERBOSE[83658][C-00000009] pbx.c: Executing [s@voipmscontext:2] Answer("IAX2/voipms-5692", "") in new stack
[2024-08-24 15:03:37.353] VERBOSE[83658][C-00000009] pbx.c: Executing [s@voipmscontext:3] Verbose("IAX2/voipms-5692", "1, Answering call and sending to rpt") in new stack
[2024-08-24 15:03:37.353] VERBOSE[83658][C-00000009] app_verbose.c: Answering call and sending to rpt
[2024-08-24 15:03:37.353] VERBOSE[83658][C-00000009] pbx.c: Executing [s@voipmscontext:4] Rpt("IAX2/voipms-5692", "617081|Pv") in new stack
[2024-08-24 15:03:37.353] NOTICE[83658][C-00000009] app_rpt/rpt_vox.c: Running voxinit_link, enable value is: 1
[2024-08-24 15:03:57.185] VERBOSE[83680] chan_dahdi.c: Hungup 'DAHDI/pseudo-1141533344'
[2024-08-24 15:04:01.606] NOTICE[83515] dnsmgr.c: dnssrv: host 'register.allstarlink.org' changed from 162.248.92.131:443 to 34.105.111.212:443
[2024-08-24 15:04:14.218] VERBOSE[83537] chan_iax2.c: Hungup 'IAX2/voipms-5692'
[2024-08-24 15:04:14.225] VERBOSE[83537] chan_dahdi.c: Hungup 'DAHDI/pseudo-163273571'Malfunctioning call outgoing (normal autopatch):
...channel.c DTMF many debug mesages... *61phonenumber as usual.
[2024-08-24 15:16:11.850] NOTICE[83537] app_rpt/rpt_functions.c: Processing autopatch parameter list...
[2024-08-24 15:16:11.850] NOTICE[83537] app_rpt/rpt_functions.c: Setting patchquiet to value: 1
[2024-08-24 15:16:11.851] NOTICE[84020] app_rpt.c: Requested channel DAHDI/pseudo-1775186805
[2024-08-24 15:16:11.851] NOTICE[84020] app_rpt.c: Requested channel DAHDI/pseudo-411491283
[2024-08-24 15:16:11.851] NOTICE[84020] app_rpt.c: tzone: 0, patchquiet: 1, patchexten[0]: 0
[2024-08-24 15:16:11.851] NOTICE[84020] app_rpt.c: Added speaker
[2024-08-24 15:16:11.851] NOTICE[84020] app_rpt.c: did set_tone_zone
[2024-08-24 15:16:11.851] NOTICE[84020] app_rpt.c: About to do play_dialtone
[2024-08-24 15:16:11.851] NOTICE[84020] app_rpt.c: Completed play_dialtone stanzas
[2024-08-24 15:14:24.001] NOTICE[83953][C-0000000e] app_rpt/rpt_vox.c: Running voxinit_link, enable value is: 1
[2024-08-24 15:16:19.663] NOTICE[84020] app_rpt/rpt_bridging.c: Starting rpt_call_bridge_setup...
[2024-08-24 15:16:19.663] NOTICE[84020] app_rpt/rpt_bridging.c: Running rpt_conf_add_speaker
[2024-08-24 15:16:19.663] NOTICE[84020] app_rpt/rpt_bridging.c: Finished rpt_call_bridge_setup, returning 0.
; I think these are when I key up on the RF side, but I will have to test that out to confirm.
[2024-08-24 15:16:19.724] NOTICE[83537] app_rpt/rpt_vox.c: Running voxinit_rpt, enable value is: 1
[2024-08-24 15:16:28.067] NOTICE[83537] app_rpt/rpt_vox.c: Running voxinit_rpt, enable value is: 0
[2024-08-24 15:16:29.859] NOTICE[83537] app_rpt/rpt_vox.c: Running voxinit_rpt, enable value is: 1
[2024-08-24 15:16:38.521] NOTICE[83537] app_rpt/rpt_vox.c: Running voxinit_rpt, enable value is: 0
[2024-08-24 15:16:39.525] NOTICE[83537] app_rpt/rpt_vox.c: Running voxinit_rpt, enable value is: 1
[2024-08-24 15:16:46.074] NOTICE[83537] app_rpt/rpt_vox.c: Running voxinit_rpt, enable value is: 0Indeed, with outgoing (normal) autopatch calls, these debug lines correspond to the radio PTT:
[2024-08-24 15:40:02.663] NOTICE[83537]: app_rpt/rpt_vox.c:17 voxinit_rpt: Running voxinit_rpt, enable value is: 0
; Talking on the radio for two seconds
[2024-08-24 15:40:04.834] NOTICE[83537]: app_rpt/rpt_vox.c:17 voxinit_rpt: Running voxinit_rpt, enable value is: 1
-- Hungup 'DAHDI/pseudo-1772222621'
-- Hungup 'DAHDI/pseudo-1412388947'
[2024-08-24 15:40:10.595] NOTICE[83537]: app_rpt/rpt_vox.c:17 voxinit_rpt: Running voxinit_rpt, enable value is: 0
; Talking on the radio for two seconds
[2024-08-24 15:40:12.901] NOTICE[83537]: app_rpt/rpt_vox.c:17 voxinit_rpt: Running voxinit_rpt, enable value is: 1And worth noting that I do not see all these voxinit_rpt calls during a working reverse autopatch. There is only one voxinit_link called at the beginning.
KB4MDD
commented
2 months ago Can you try loading these modules and see if you have the same problem.
l``` oad => bridge_builtin_features.so load => bridge_builtin_interval_features.so load => bridge_holding.so load => bridge_native_rtp.so load => bridge_simple.so load => bridge_softmix.so load => chan_bridge_media.so
I'll try it out.
eliggett
commented
2 months ago one was already loaded: bridge_simple.
Unfortunately autopatch still does not transmit the audio from the call to the radio.
If I had to guess, the bridge or whatever isn't set up quite right and the dovox is never called (or more precisely, if it is called, we never see the debug from the value flipping).
simplex900*CLI> rpt fun 617081 *617475551212
[2024-08-27 18:30:01.055] NOTICE[83537]: app_rpt/rpt_functions.c:918 function_autopatchup: Processing autopatch parameter list...
[2024-08-27 18:30:01.055] NOTICE[83537]: app_rpt/rpt_functions.c:945 function_autopatchup: Setting patchquiet to value: 1
[2024-08-27 18:30:01.056] NOTICE[200112]: app_rpt.c:1182 rpt_call: Requested channel DAHDI/pseudo-131706274
[2024-08-27 18:30:01.056] NOTICE[200112]: app_rpt.c:1199 rpt_call: Requested channel DAHDI/pseudo-1544421347
[2024-08-27 18:30:01.056] NOTICE[200112]: app_rpt.c:1203 rpt_call: tzone: 0, patchquiet: 1, patchexten[0]: 0
[2024-08-27 18:30:01.056] NOTICE[200112]: app_rpt.c:1216 rpt_call: Added speaker
[2024-08-27 18:30:01.056] NOTICE[200112]: app_rpt.c:1225 rpt_call: did set_tone_zone
[2024-08-27 18:30:01.056] NOTICE[200112]: app_rpt.c:1228 rpt_call: About to do play_dialtone
[2024-08-27 18:30:01.056] NOTICE[200112]: app_rpt.c:1236 rpt_call: Completed play_dialtone stanzas
[2024-08-27 18:30:01.058] NOTICE[83537]: app_rpt/rpt_vox.c:17 voxinit_rpt: Running voxinit_rpt, enable value is: 1
[2024-08-27 18:30:01.059] NOTICE[83537]: app_rpt/rpt_vox.c:34 voxinit_link: Running voxinit_link, enable value is: 0
-- Executing [7475551212@voipmscontext:1] Set("DAHDI/pseudo-131706274", "CALLERID(all)="W6EL" <7472311234>") in new stack
-- Executing [7475551212@voipmscontext:2] Dial("DAHDI/pseudo-131706274", "IAX2/voipms/+17475551212") in new stack
-- Called IAX2/voipms/+17475551212
[2024-08-27 18:30:03.709] NOTICE[200112]: app_rpt/rpt_bridging.c:482 rpt_call_bridge_setup: Starting rpt_call_bridge_setup...
[2024-08-27 18:30:03.709] NOTICE[200112]: app_rpt/rpt_bridging.c:490 rpt_call_bridge_setup: Running rpt_conf_add_speaker
[2024-08-27 18:30:03.709] NOTICE[200112]: app_rpt/rpt_bridging.c:520 rpt_call_bridge_setup: Finished rpt_call_bridge_setup, returning 0.
-- Call accepted by 208.100.60.36:4569 (format ulaw)
-- Format for call is (ulaw)
-- IAX2/voipms-11448 is making progress passing it to DAHDI/pseudo-131706274
-- IAX2/voipms-11448 is making progress passing it to DAHDI/pseudo-131706274
-- IAX2/voipms-11448 answered DAHDI/pseudo-131706274
-- Channel IAX2/voipms-11448 joined 'simple_bridge' basic-bridge <8c698d5b-19cb-49ed-85fe-9b810d82b6cc>
-- Channel DAHDI/pseudo-131706274 joined 'simple_bridge' basic-bridge <8c698d5b-19cb-49ed-85fe-9b810d82b6cc>
-- Channel IAX2/voipms-11448 left 'simple_bridge' basic-bridge <8c698d5b-19cb-49ed-85fe-9b810d82b6cc>
-- Channel DAHDI/pseudo-131706274 left 'simple_bridge' basic-bridge <8c698d5b-19cb-49ed-85fe-9b810d82b6cc>
-- Hungup 'IAX2/voipms-11448'
== Spawn extension (voipmscontext, 7475551212, 2) exited non-zero on 'DAHDI/pseudo-131706274'
-- Hungup 'DAHDI/pseudo-131706274'
[2024-08-27 18:30:17.956] NOTICE[83537]: app_rpt/rpt_vox.c:17 voxinit_rpt: Running voxinit_rpt, enable value is: 0
[2024-08-27 18:30:17.959] NOTICE[83537]: app_rpt/rpt_vox.c:34 voxinit_link: Running voxinit_link, enable value is: 1
-- Hungup 'DAHDI/pseudo-1544421347'
simplex900*CLI>I ran a test. dovox is indeed run during the autopatch call (about every 10ms), but, the vox value always comes back as zero, suggesting that maybe the wrong audio channel is being examined?
KB4MDD
commented
2 months ago There were some changes in the autopatch routines to address a deadlock and some issues with DAHDI. You will find those here. https://github.com/AllStarLink/app_rpt/pull/363
Specifically
The voxchannel could not join the conference using the flag DAHDI_CONF_MONITOR. ioctl would return EINVAL. After testing I changed it to RPT_CONF_CONF | RPT_CONF_LISTENER. This allowed the voxchannel to join the conference. I did not see any side effects, however this needs to be carefully tested.
Since you are working the problem, you will most likely have to review the changes that I made. I did not test vox operation.
This was going to be my starting point on the problem. Since you are working this, you may want to revert my changes and work the problem with the EINVAL.
I spent some time in the DAHDI driver code trying to run down the issue.
eliggett
commented
2 months ago Hi @KB4MDD , I tried reverting the changes. With DAHDI_CONF_MONITOR, indeed, the return is -1, however, the issue remains the same in that I can hear the receive audio on the phone, but the phone's audio is not transmitted.
I also tried reverting the change where the conference number was being returned instead of the channel number. This basically crashes asterisk, the number is definitely wrong.
Can you explain how the vox knows which thing to attach itself to? I kind of get the feeling the vox is attached to the repeater's audio and not the phone audio.
I tried also figuring out how it was that the reverse audopatch vox worked so well while outgoing (normal) autopatch did not, but I didn't get too far.
eliggett
commented
2 months ago I added some tracing to the dovox function, to investigate how it is called. I apologize if this is obvious stuff to more seasoned asterisk gurus...
During normal simplex node operation, when not connected to anything and when there is no autopatch taking place, and nobody is transmitting, dovox is actually called all the time. I do not use vox on my machine, I use COS, so I was a bit surprised to see it constantly checking some audio buffer. This is the vox called by voxchannel_read, which I think is from the sort of enormous while loop in the rpt thread entry function.
During a normal outgoing autopatch call, this does not change. The same voxchannel_read calls continue.
During a reverse autopatch call (incoming autopatch), vox is called by process_link_channels and seems to function well. voxchannel_read calls continue as well.
KB4MDD
commented
2 months ago Unfortunately the original developer is SK. I will look back at this and see if I can discover the issue.
eliggett
commented
2 months ago It seems that the reverse patch is handled quite differently from the outgoing autopatch. The reverse patch is a "link" and is handled in process_link_channels.
Normal outgoing autopatch creates the conference call with the repeater, which handles mixing the audio, and then the voxchannel audio is checked with therpt while(ms>=0) loop.
I added more debug to the rpt_vox, and I can tell now that the voxchannel audio is zero during the phone call. This likely means that when we add the voxchannel to the conference, the mode used is not permitting audio to enter the channel or some similar issue. Maybe some of those flags are incorrect that we are using?
KB4MDD
commented
2 months ago This problem appears to be caused by missing code in the version of dahdi that we are using. I am testing changes now and I have been able to get the phone channel to join the vox conference. More to follow.
eliggett
commented
2 months ago @KB4MDD I can't tell you how much I appreciate your work on this issue. Thank you so much. I can't wait to test it out.
KB4MDD
commented
2 months ago @eliggett if you want to test these changes, you will need to pull my fixes above for app_rpt. You will also need the revised version of DAHDI at https://github.com/KB4MDD/dahdi-linux.
I completed my testing this morning and vox operation appears to be restored. I did see the debug messages that indicated vox was changing.
Please let me know if this corrects your issue.
eliggett
commented
2 months ago What is the recommended method of replacing dahdi with your patched version? I was able to make; make install your version, but I am not sure this replaces all the headers we need with asterisk.
eliggett
commented
2 months ago I ask because asterisk isn't building, but it's an error which I remember was tied with a mismatch in dahdi versions.
chan_dahdi.c: In function ‘dahdievent_to_analogevent’:
chan_dahdi.c:2669:14: error: ‘DAHDI_EVENT_PULSE’ undeclared (first use in this function); did you mean ‘DAHDI_EVENT_NONE’?
2669 | case DAHDI_EVENT_PULSE:
| ^~~~~~~~~~~~~~~~~
| DAHDI_EVENT_NONE
chan_dahdi.c:2669:14: note: each undeclared identifier is reported only once for each function it appears in
chan_dahdi.c:2672:14: error: ‘DAHDI_EVENT_PULSE_BREAK’ undeclared (first use in this function); did you mean ‘ANALOG_EVENT_PULSE_BREAK’?
2672 | case DAHDI_EVENT_PULSE_BREAK:
| ^~~~~~~~~~~~~~~~~~~~~~~
| ANALOG_EVENT_PULSE_BREAK
chan_dahdi.c: In function ‘dahdi_handle_event’:
chan_dahdi.c:7907:14: error: ‘DAHDI_EVENT_PULSE’ undeclared (first use in this function); did you mean ‘DAHDI_EVENT_NONE’?
7907 | case DAHDI_EVENT_PULSE:
| ^~~~~~~~~~~~~~~~~
| DAHDI_EVENT_NONE
chan_dahdi.c:7908:14: error: ‘DAHDI_EVENT_PULSE_BREAK’ undeclared (first use in this function); did you mean ‘ANALOG_EVENT_PULSE_BREAK’?
7908 | case DAHDI_EVENT_PULSE_BREAK:
| ^~~~~~~~~~~~~~~~~~~~~~~
| ANALOG_EVENT_PULSE_BREAKNot your error at all, just some configuration stuff to contend with of course.
eliggett
commented
2 months ago ahh I think I remember, the phreaknet script patches this in some way. I'll poke around.
eliggett
commented
2 months ago Ok, I need some help to make sure I run the patch for dahdi correctly. The phreaknet script contains references to a lot of different patches; which ones do I need to do?
https://github.com/InterLinked1/phreakscript/tree/master/patches
KB4MDD
commented
2 months ago I cannot help you with those patches.
I think I would run phreaknet -d -f That will force the installation of the current dahdi.
When that completes, copy dahdi-base.c from my changes to the same directory and run make, then make install.
On my existing installs (which are from source), I just replaced dahdi-base.c, recompiled and installed.
@InterLinked1 is working on updating the phreaknet script with my patch.
eliggett
commented
2 months ago Got it. Ok, I just went into the phreaknet script and substituted the download of dahdi-linux with your patched version. Hopefully this will run through ok. In theory, it will take your version and then run it through all the usual patching it would otherwise do.
eliggett
commented
2 months ago Ok, I was able to get phreaknet.sh to compile asterisk with the modified dahdi source. I then compiled app_rpt using your branch and the rpt_install script. Unfortunately there are some errors with the autopatch and it is not working:
simplex900*CLI> rpt fun 617081 *616265551212
-- Executing [6265551212@voipmscontext:1] Set("DAHDI/pseudo-1996896128", "CALLERID(all)="W6EL" <7475551212>") in new stack
-- Executing [6265551212@voipmscontext:2] Dial("DAHDI/pseudo-1996896128", "IAX2/voipms/+16265551212") in new stack
-- Called IAX2/voipms/+16265551212
[2024-09-10 10:44:54.990] WARNING[678506]: app_rpt/rpt_bridging.c:343 __join_dahdiconf: app_rpt/rpt_bridging.c:376 (dahdi_conf_add) Unable to set conference mode on DAHDI/pseudo-752078475
[2024-09-10 10:44:54.990] WARNING[678506]: app_rpt/rpt_bridging.c:378 dahdi_conf_add: Failed to join DAHDI conf (mode: 1)
[2024-09-10 10:44:54.990] WARNING[678506]: channel.c:2611 ast_hangup: Hard hangup called by thread LWP 678506 on DAHDI/pseudo-1996896128, while blocked by thread LWP 678507 in procedure ast_waitfor_nandfds! Expect a failure
-- Hungup 'DAHDI/pseudo-1996896128'
[2024-09-10 10:44:54.991] WARNING[678506][C-0000000b]: channel.c:2272 ast_channel_destructor: PBX may not have been terminated properly on 'DAHDI/pseudo-1996896128'
[2024-09-10 10:44:54.993] ERROR[678507][C-0000000b]: channel.c:3099 ast_waitfor_nandfds: FRACK!, Failed assertion bad magic number 0x0 for object 0x7f98000c18 (0)
-- Call accepted by 208.100.60.36:4569 (format ulaw)
-- Format for call is (ulaw)
[2024-09-10 10:44:55.440] ERROR[678507][C-0000000b]: Got 16 backtrace records
# 0: [0x556fb32544] asterisk utils.c:2835 __ast_assert_failed()
# 1: [0x556f999e48] asterisk astobj2.c:220 log_bad_ao2()
# 2: [0x556f999ec8] asterisk astobj2.c:224 __ao2_lock()
# 3: [0x556f9e3180] asterisk channel.c:3100 ast_waitfor_nandfds()
# 4: [0x556f9e35a4] asterisk channel.c:3167 ast_waitfor_n()
# 5: [0x7fa9b27090] app_dial.so app_dial.c:1351 wait_for_answer()
# 6: [0x7fa9b2dc3c] app_dial.so app_dial.c:3055 dial_exec_full()
# 7: [0x7fa9b2fe2c] app_dial.so app_dial.c:3601 dial_exec()
# 8: [0x556fa993c4] asterisk pbx_app.c:492 pbx_exec()
# 9: [0x556fa83c28] asterisk pbx.c:2972 pbx_extension_helper()
#10: [0x556fa87b14] asterisk pbx.c:4228 ast_spawn_extension()
#11: [0x556fa88708] asterisk pbx.c:4401 __ast_pbx_run()
#12: [0x556fa89ce4] asterisk pbx.c:4726 pbx_thread()
#13: [0x556fb2f354] asterisk utils.c:1607 dummy_start()
#14: [0x7facccee30] libc.so.6 pthread_create.c:442 start_thread()
#15: [0x7facd37adc] libc.so.6 clone.S:82 thread_start()
[2024-09-10 10:44:55.440] ERROR[678507][C-0000000b]: channel.c:3101 ast_waitfor_nandfds: FRACK!, Failed assertion bad magic number 0x0 for object 0x7f98000c18 (0)
[2024-09-10 10:44:55.825] ERROR[678507][C-0000000b]: Got 16 backtrace records
# 0: [0x556fb32544] asterisk utils.c:2835 __ast_assert_failed()
# 1: [0x556f999e48] asterisk astobj2.c:220 log_bad_ao2()
# 2: [0x556f99a140] asterisk astobj2.c:290 __ao2_unlock()
# 3: [0x556f9e3200] asterisk channel.c:3098 ast_waitfor_nandfds()
# 4: [0x556f9e35a4] asterisk channel.c:3167 ast_waitfor_n()
# 5: [0x7fa9b27090] app_dial.so app_dial.c:1351 wait_for_answer()
# 6: [0x7fa9b2dc3c] app_dial.so app_dial.c:3055 dial_exec_full()
# 7: [0x7fa9b2fe2c] app_dial.so app_dial.c:3601 dial_exec()
# 8: [0x556fa993c4] asterisk pbx_app.c:492 pbx_exec()
# 9: [0x556fa83c28] asterisk pbx.c:2972 pbx_extension_helper()
#10: [0x556fa87b14] asterisk pbx.c:4228 ast_spawn_extension()
#11: [0x556fa88708] asterisk pbx.c:4401 __ast_pbx_run()
#12: [0x556fa89ce4] asterisk pbx.c:4726 pbx_thread()
#13: [0x556fb2f354] asterisk utils.c:1607 dummy_start()
#14: [0x7facccee30] libc.so.6 pthread_create.c:442 start_thread()
#15: [0x7facd37adc] libc.so.6 clone.S:82 thread_start()
[2024-09-10 10:44:55.825] ERROR[678507][C-0000000b]: channel.c:3137 ast_waitfor_nandfds: FRACK!, Failed assertion bad magic number 0x0 for object 0x7f98000c18 (0)
[2024-09-10 10:44:56.211] ERROR[678507][C-0000000b]: Got 16 backtrace records
# 0: [0x556fb32544] asterisk utils.c:2835 __ast_assert_failed()
# 1: [0x556f999e48] asterisk astobj2.c:220 log_bad_ao2()
# 2: [0x556f999ec8] asterisk astobj2.c:224 __ao2_lock()
# 3: [0x556f9e33d4] asterisk channel.c:3138 ast_waitfor_nandfds()
# 4: [0x556f9e35a4] asterisk channel.c:3167 ast_waitfor_n()
# 5: [0x7fa9b27090] app_dial.so app_dial.c:1351 wait_for_answer()
# 6: [0x7fa9b2dc3c] app_dial.so app_dial.c:3055 dial_exec_full()
# 7: [0x7fa9b2fe2c] app_dial.so app_dial.c:3601 dial_exec()
# 8: [0x556fa993c4] asterisk pbx_app.c:492 pbx_exec()
# 9: [0x556fa83c28] asterisk pbx.c:2972 pbx_extension_helper()
#10: [0x556fa87b14] asterisk pbx.c:4228 ast_spawn_extension()
#11: [0x556fa88708] asterisk pbx.c:4401 __ast_pbx_run()
#12: [0x556fa89ce4] asterisk pbx.c:4726 pbx_thread()
#13: [0x556fb2f354] asterisk utils.c:1607 dummy_start()
#14: [0x7facccee30] libc.so.6 pthread_create.c:442 start_thread()
#15: [0x7facd37adc] libc.so.6 clone.S:82 thread_start()
[2024-09-10 10:44:56.211] ERROR[678507][C-0000000b]: channel.c:3144 ast_waitfor_nandfds: FRACK!, Failed assertion bad magic number 0x0 for object 0x7f98000c18 (0)
[2024-09-10 10:44:56.597] ERROR[678507][C-0000000b]: Got 16 backtrace records
# 0: [0x556fb32544] asterisk utils.c:2835 __ast_assert_failed()
# 1: [0x556f999e48] asterisk astobj2.c:220 log_bad_ao2()
# 2: [0x556f99a140] asterisk astobj2.c:290 __ao2_unlock()
# 3: [0x556f9e347c] asterisk channel.c:3144 ast_waitfor_nandfds()
# 4: [0x556f9e35a4] asterisk channel.c:3167 ast_waitfor_n()
# 5: [0x7fa9b27090] app_dial.so app_dial.c:1351 wait_for_answer()
# 6: [0x7fa9b2dc3c] app_dial.so app_dial.c:3055 dial_exec_full()
# 7: [0x7fa9b2fe2c] app_dial.so app_dial.c:3601 dial_exec()
# 8: [0x556fa993c4] asterisk pbx_app.c:492 pbx_exec()
# 9: [0x556fa83c28] asterisk pbx.c:2972 pbx_extension_helper()
#10: [0x556fa87b14] asterisk pbx.c:4228 ast_spawn_extension()
#11: [0x556fa88708] asterisk pbx.c:4401 __ast_pbx_run()
#12: [0x556fa89ce4] asterisk pbx.c:4726 pbx_thread()
#13: [0x556fb2f354] asterisk utils.c:1607 dummy_start()
#14: [0x7facccee30] libc.so.6 pthread_create.c:442 start_thread()
#15: [0x7facd37adc] libc.so.6 clone.S:82 thread_start()
[2024-09-10 10:44:56.597] ERROR[678507][C-0000000b]: channel.c:3137 ast_waitfor_nandfds: FRACK!, Failed assertion bad magic number 0x0 for object 0x7f98000c18 (0)
[2024-09-10 10:44:57.032] ERROR[678507][C-0000000b]: Got 16 backtrace records
# 0: [0x556fb32544] asterisk utils.c:2835 __ast_assert_failed()
# 1: [0x556f999e48] asterisk astobj2.c:220 log_bad_ao2()
# 2: [0x556f999ec8] asterisk astobj2.c:224 __ao2_lock()
# 3: [0x556f9e33d4] asterisk channel.c:3138 ast_waitfor_nandfds()
# 4: [0x556f9e35a4] asterisk channel.c:3167 ast_waitfor_n()
# 5: [0x7fa9b27090] app_dial.so app_dial.c:1351 wait_for_answer()
# 6: [0x7fa9b2dc3c] app_dial.so app_dial.c:3055 dial_exec_full()
# 7: [0x7fa9b2fe2c] app_dial.so app_dial.c:3601 dial_exec()
# 8: [0x556fa993c4] asterisk pbx_app.c:492 pbx_exec()
# 9: [0x556fa83c28] asterisk pbx.c:2972 pbx_extension_helper()
#10: [0x556fa87b14] asterisk pbx.c:4228 ast_spawn_extension()
#11: [0x556fa88708] asterisk pbx.c:4401 __ast_pbx_run()
#12: [0x556fa89ce4] asterisk pbx.c:4726 pbx_thread()
#13: [0x556fb2f354] asterisk utils.c:1607 dummy_start()
#14: [0x7facccee30] libc.so.6 pthread_create.c:442 start_thread()
#15: [0x7facd37adc] libc.so.6 clone.S:82 thread_start()
[2024-09-10 10:44:57.032] ERROR[678507][C-0000000b]: channel.c:3144 ast_waitfor_nandfds: FRACK!, Failed assertion bad magic number 0x0 for object 0x7f98000c18 (0)
[2024-09-10 10:44:57.419] ERROR[678507][C-0000000b]: Got 16 backtrace records
# 0: [0x556fb32544] asterisk utils.c:2835 __ast_assert_failed()
# 1: [0x556f999e48] asterisk astobj2.c:220 log_bad_ao2()
# 2: [0x556f99a140] asterisk astobj2.c:290 __ao2_unlock()
# 3: [0x556f9e347c] asterisk channel.c:3144 ast_waitfor_nandfds()
# 4: [0x556f9e35a4] asterisk channel.c:3167 ast_waitfor_n()
# 5: [0x7fa9b27090] app_dial.so app_dial.c:1351 wait_for_answer()
# 6: [0x7fa9b2dc3c] app_dial.so app_dial.c:3055 dial_exec_full()
# 7: [0x7fa9b2fe2c] app_dial.so app_dial.c:3601 dial_exec()
# 8: [0x556fa993c4] asterisk pbx_app.c:492 pbx_exec()
# 9: [0x556fa83c28] asterisk pbx.c:2972 pbx_extension_helper()
#10: [0x556fa87b14] asterisk pbx.c:4228 ast_spawn_extension()
#11: [0x556fa88708] asterisk pbx.c:4401 __ast_pbx_run()
#12: [0x556fa89ce4] asterisk pbx.c:4726 pbx_thread()
#13: [0x556fb2f354] asterisk utils.c:1607 dummy_start()
#14: [0x7facccee30] libc.so.6 pthread_create.c:442 start_thread()
#15: [0x7facd37adc] libc.so.6 clone.S:82 thread_start()
[2024-09-10 10:44:57.419] ERROR[678507][C-0000000b]: channel.c:3543 __ast_read: FRACK!, Failed assertion bad magic number 0x0 for object 0x7f98000c18 (0)
[2024-09-10 10:44:57.855] ERROR[678507][C-0000000b]: Got 16 backtrace records
# 0: [0x556fb32544] asterisk utils.c:2835 __ast_assert_failed()
# 1: [0x556f999e48] asterisk astobj2.c:220 log_bad_ao2()
# 2: [0x556f999ec8] asterisk astobj2.c:224 __ao2_lock()
# 3: [0x556f9e445c] asterisk channel.c:3546 __ast_read()
# 4: [0x556f9e66ac] asterisk channel.c:4303 ast_read()
# 5: [0x7fa9b29178] app_dial.so app_dial.c:1834 wait_for_answer()
# 6: [0x7fa9b2dc3c] app_dial.so app_dial.c:3055 dial_exec_full()
# 7: [0x7fa9b2fe2c] app_dial.so app_dial.c:3601 dial_exec()
# 8: [0x556fa993c4] asterisk pbx_app.c:492 pbx_exec()
# 9: [0x556fa83c28] asterisk pbx.c:2972 pbx_extension_helper()
#10: [0x556fa87b14] asterisk pbx.c:4228 ast_spawn_extension()
#11: [0x556fa88708] asterisk pbx.c:4401 __ast_pbx_run()
#12: [0x556fa89ce4] asterisk pbx.c:4726 pbx_thread()
#13: [0x556fb2f354] asterisk utils.c:1607 dummy_start()
#14: [0x7facccee30] libc.so.6 pthread_create.c:442 start_thread()
#15: [0x7facd37adc] libc.so.6 clone.S:82 thread_start()
[2024-09-10 10:44:57.855] ERROR[678507][C-0000000b]: channel.c:4296 __ast_read: FRACK!, Failed assertion bad magic number 0x0 for object 0x7f98000c18 (0)
[2024-09-10 10:44:58.246] ERROR[678507][C-0000000b]: Got 16 backtrace records
# 0: [0x556fb32544] asterisk utils.c:2835 __ast_assert_failed()
# 1: [0x556f999e48] asterisk astobj2.c:220 log_bad_ao2()
# 2: [0x556f99a140] asterisk astobj2.c:290 __ao2_unlock()
# 3: [0x556f9e6678] asterisk channel.c:4297 __ast_read()
# 4: [0x556f9e66ac] asterisk channel.c:4303 ast_read()
# 5: [0x7fa9b29178] app_dial.so app_dial.c:1834 wait_for_answer()
# 6: [0x7fa9b2dc3c] app_dial.so app_dial.c:3055 dial_exec_full()
# 7: [0x7fa9b2fe2c] app_dial.so app_dial.c:3601 dial_exec()
# 8: [0x556fa993c4] asterisk pbx_app.c:492 pbx_exec()
# 9: [0x556fa83c28] asterisk pbx.c:2972 pbx_extension_helper()
#10: [0x556fa87b14] asterisk pbx.c:4228 ast_spawn_extension()
#11: [0x556fa88708] asterisk pbx.c:4401 __ast_pbx_run()
#12: [0x556fa89ce4] asterisk pbx.c:4726 pbx_thread()
#13: [0x556fb2f354] asterisk utils.c:1607 dummy_start()
#14: [0x7facccee30] libc.so.6 pthread_create.c:442 start_thread()
#15: [0x7facd37adc] libc.so.6 clone.S:82 thread_start()
[2024-09-10 10:44:58.246] ERROR[678507][C-0000000b]: stasis_channels.c:713 ast_channel_publish_dial_forward: FRACK!, Failed assertion bad magic number 0x0 for object 0x7f98000c18 (0)
[2024-09-10 10:44:58.639] ERROR[678507][C-0000000b]: Got 17 backtrace records
# 0: [0x556fb32544] asterisk utils.c:2835 __ast_assert_failed()
# 1: [0x556f999e48] asterisk astobj2.c:220 log_bad_ao2()
# 2: [0x556f999ec8] asterisk astobj2.c:224 __ao2_lock()
# 3: [0x556fafd75c] asterisk stasis_channels.c:714 ast_channel_publish_dial_forward()
# 4: [0x556fafd938] asterisk stasis_channels.c:748 ast_channel_publish_dial()
# 5: [0x7fa9b267b4] app_dial.so app_dial.c:1212 publish_dial_end_event()
# 6: [0x7fa9b29200] app_dial.so app_dial.c:1847 wait_for_answer()
# 7: [0x7fa9b2dc3c] app_dial.so app_dial.c:3055 dial_exec_full()
# 8: [0x7fa9b2fe2c] app_dial.so app_dial.c:3601 dial_exec()
# 9: [0x556fa993c4] asterisk pbx_app.c:492 pbx_exec()
#10: [0x556fa83c28] asterisk pbx.c:2972 pbx_extension_helper()
#11: [0x556fa87b14] asterisk pbx.c:4228 ast_spawn_extension()
#12: [0x556fa88708] asterisk pbx.c:4401 __ast_pbx_run()
#13: [0x556fa89ce4] asterisk pbx.c:4726 pbx_thread()
#14: [0x556fb2f354] asterisk utils.c:1607 dummy_start()
#15: [0x7facccee30] libc.so.6 pthread_create.c:442 start_thread()
#16: [0x7facd37adc] libc.so.6 clone.S:82 thread_start()
[2024-09-10 10:44:58.639] ERROR[678507][C-0000000b]: stasis_channels.c:638 ast_channel_publish_dial_internal: FRACK!, Failed assertion bad magic number 0x0 for object 0x7f98000c18 (0)
simplex900*CLI>
Disconnected from Asterisk server
Asterisk cleanly ending (0).
Executing last minute cleanups
root@simplex900:/usr/src#This kind of looks like the problem with the original dahdi.
app_rpt/rpt_bridging.c:378 dahdi_conf_add: Failed to join DAHDI conf (mode: 1)
This looks like the call to join the vox channel.
I think you are running simplex. What do you have duplex set to? I will see if I can duplicate this issue.
eliggett
commented
2 months ago Simplex indeed. Duplex is set to 1.
KB4MDD
commented
2 months ago I have confirmed this crash on my system when duplex is set to 1. I will dig into this and report back.
KB4MDD
commented
2 months ago I am ready for you to test this with the latest changes to app_rpt. I am working now with duplex = 1.
eliggett
commented
2 months ago Ok, the crash is gone, but, the node does not transmit when I speak on the phone.
simplex900*CLI> rpt fun 617081 *616265551212
-- Executing [6265551212@voipmscontext:1] Set("DAHDI/pseudo-655147597", "CALLERID(all)="W6EL" <7475551212>") in new stack
-- Executing [6265551212@voipmscontext:2] Dial("DAHDI/pseudo-655147597", "IAX2/voipms/+16265551212") in new stack
-- Called IAX2/voipms/+16265551212
-- Call accepted by 208.100.60.36:4569 (format ulaw)
-- Format for call is (ulaw)
-- IAX2/voipms-11684 is making progress passing it to DAHDI/pseudo-655147597
-- IAX2/voipms-11684 is making progress passing it to DAHDI/pseudo-655147597
-- IAX2/voipms-11684 answered DAHDI/pseudo-655147597
-- Channel IAX2/voipms-11684 joined 'simple_bridge' basic-bridge <bba31d25-871c-4ced-a3d3-4a58b4bce8b8>
-- Channel DAHDI/pseudo-655147597 joined 'simple_bridge' basic-bridge <bba31d25-871c-4ced-a3d3-4a58b4bce8b8>
...
-- Channel IAX2/voipms-11684 left 'simple_bridge' basic-bridge <bba31d25-871c-4ced-a3d3-4a58b4bce8b8>
-- Channel DAHDI/pseudo-655147597 left 'simple_bridge' basic-bridge <bba31d25-871c-4ced-a3d3-4a58b4bce8b8>
-- Hungup 'IAX2/voipms-11684'
== Spawn extension (voipmscontext, 6265551212, 2) exited non-zero on 'DAHDI/pseudo-655147597'
-- Hungup 'DAHDI/pseudo-655147597'
simplex900*CLI>Additionally, the node became unresponsive after this test. I was unable to kerchunk it or perform a second autopatch test, had to stop/start the asterisk process.
KB4MDD
commented
2 months ago I am not having that issue here. Vox worked ok.
Please turn on debugging. core set debug 4 app_rpt.so Send me the results.
eliggett
commented
2 months ago Ok. Do I need to further update dahdi-linux?
KB4MDD
commented
2 months ago I have not made any additional changes to DAHDI. The only change was to rpt_bridging.c.
Lets turn up the debugging core set debug 7 app_rpt.so
Debug level 1 should show the vox operation.
eliggett
commented
2 months ago simplex900*CLI> rpt fun 617081 *617472558630
[2024-09-11 08:53:47.719] DEBUG[725513]: app_rpt/rpt_telemetry.c:381 cancel_pfxtone: cancel_pfxfone!!
[2024-09-11 08:53:47.719] DEBUG[725513]: app_rpt.c:1435 collect_function_digits: digits=6 source=0
[2024-09-11 08:53:47.826] DEBUG[725513]: app_rpt/rpt_telemetry.c:381 cancel_pfxtone: cancel_pfxfone!!
[2024-09-11 08:53:47.826] DEBUG[725513]: app_rpt.c:1435 collect_function_digits: digits=61 source=0
[2024-09-11 08:53:47.826] DEBUG[725513]: app_rpt.c:1487 collect_function_digits: @@@@ action: autopatchup, param = noct=1,farenddisconnect=1,dialtime=20000,voxalways=1quiet=1,context=voipmscontext
[2024-09-11 08:53:47.826] DEBUG[725513]: app_rpt.c:1493 collect_function_digits: @@@@ table index i = 1
[2024-09-11 08:53:47.826] DEBUG[725513]: app_rpt/rpt_functions.c:905 function_autopatchup: @@@@ Autopatch up
[2024-09-11 08:53:47.826] DEBUG[725513]: app_rpt.c:1505 collect_function_digits: rv=3
[2024-09-11 08:53:47.827] DEBUG[725591]: app_rpt.c:1182 rpt_call: Requested channel DAHDI/pseudo-1632593939
[2024-09-11 08:53:47.827] DEBUG[725591]: app_rpt/rpt_call.c:32 rpt_disable_cdr: No CDR present on DAHDI/pseudo-1632593939
[2024-09-11 08:53:47.827] DEBUG[725591]: app_rpt/rpt_bridging.c:374 dahdi_conf_add: Channel DAHDI/pseudo-1632593939 joining conference 1022
[2024-09-11 08:53:47.828] DEBUG[725591]: app_rpt.c:1199 rpt_call: Requested channel DAHDI/pseudo-1561197811
[2024-09-11 08:53:47.828] DEBUG[725591]: app_rpt/rpt_call.c:32 rpt_disable_cdr: No CDR present on DAHDI/pseudo-1561197811
[2024-09-11 08:53:47.828] DEBUG[725591]: app_rpt/rpt_bridging.c:374 dahdi_conf_add: Channel DAHDI/pseudo-1561197811 joining conference 1022
-- Executing [7472558630@voipmscontext:1] Set("DAHDI/pseudo-1632593939", "CALLERID(all)="W6EL" <7472311234>") in new stack
-- Executing [7472558630@voipmscontext:2] Dial("DAHDI/pseudo-1632593939", "IAX2/voipms/+17472558630") in new stack
-- Called IAX2/voipms/+17472558630
[2024-09-11 08:53:50.467] DEBUG[725591]: app_rpt/rpt_bridging.c:374 dahdi_conf_add: Channel DAHDI/pseudo-1869364309 joining conference 1022
[2024-09-11 08:53:50.467] DEBUG[725591]: app_rpt/rpt_bridging.c:374 dahdi_conf_add: Channel DAHDI/pseudo-912992256 joining conference 32779
-- Call accepted by 208.100.60.36:4569 (format ulaw)
-- Format for call is (ulaw)
-- IAX2/voipms-6267 is making progress passing it to DAHDI/pseudo-1632593939
-- IAX2/voipms-6267 is making progress passing it to DAHDI/pseudo-1632593939
-- IAX2/voipms-6267 answered DAHDI/pseudo-1632593939
-- Channel IAX2/voipms-6267 joined 'simple_bridge' basic-bridge <3ea43de7-9e18-4cd2-ae67-fd1e2763b4bb>
-- Channel DAHDI/pseudo-1632593939 joined 'simple_bridge' basic-bridge <3ea43de7-9e18-4cd2-ae67-fd1e2763b4bb>
-- Channel IAX2/voipms-6267 left 'simple_bridge' basic-bridge <3ea43de7-9e18-4cd2-ae67-fd1e2763b4bb>
-- Channel DAHDI/pseudo-1632593939 left 'simple_bridge' basic-bridge <3ea43de7-9e18-4cd2-ae67-fd1e2763b4bb>
-- Hungup 'IAX2/voipms-6267'
== Spawn extension (voipmscontext, 7472558630, 2) exited non-zero on 'DAHDI/pseudo-1632593939'
-- Hungup 'DAHDI/pseudo-1632593939'
simplex900*CLI> rpt fun 617081 *712
simplex900*CLI>
simplex900*CLI>And it does seem dead after I hand up.
No audio from radio receiver to phone, and no audio from phone to radio transmitter. No vox messages either.
eliggett
commented
2 months ago ok, I did see that I was missing a comma in rpt.conf for the autopatch line, between "voxalways=1" and "quiet=1". I removed "voxalways=1" and made sure the commas were all good. But it is still the same result, silent autopatch in both directions.
KB4MDD
commented
2 months ago Are you sure you have the patched dahdi driver installed?
eliggett
commented
2 months ago Author: Danny Lloyd <kb4mdd@arrl.net>
Date: Mon Sep 9 07:47:47 2024 -0500
Update dahdi-base for ASL3 (#1)
Updated the code with the first set of patches that Jim Dixon published.
commit 22c9556a69e197a1cd73c84c2910680ab97f57cb
Author: Danny Lloyd <kb4mdd@arrl.net>
Date: Sat Sep 7 16:29:41 2024 -0500
Create README.mdThat is what it built from.
Now I did do a make; make install prior to realizing I needed the phreaknet patching, so maybe there is some leftover piece somewhere?
KB4MDD
commented
2 months ago I don't know. Your setup is a little different from mine. I think you have a .deb install along with source.
If you get it to hang, you can try this command to get a dump.
/var/lib/asterisk/scripts/ast_coredumper --running
That will dump and create files in /tmp. If it is hanging in dahdi, it may be hard to determine, but I am willing to look.
eliggett
commented
2 months ago Well, I have found a mismatch between the dahdi kernel module and the source code compiled. I believe the issue came from the phreaknet script running an unintended system upgrade (apt get upgrade) which updated the kernel version. This caused the install location of dahdi's kernel module to not match the kernel which was actually running on reboot. I will see if I can correct this. I could be wrong. dmesg shows dahdi is 3.3.0, but I believe the source should be version 3.4.0.
eliggett
commented
2 months ago The situation is compounded by the presence of dahdi as installed using a package. Asking to remove the dahdi-linux package results in the proposal to remove asl, asterisks, and so on.
root@simplex900:/usr/src# dpkg --list | grep dahd
ii dahdi 1:3.1.0-2 arm64 utilities for using the DAHDI kernel modules
ii dahdi-dkms 1:3.3.0-5+asl all DAHDI telephony interface (dkms kernel driver)
ii dahdi-linux 1:3.3.0-5+asl all DAHDI telephony interface - Linux userspace parts
root@simplex900:/usr/src# apt remove dahdi-linux
The following packages will be REMOVED:
asl3 asl3-asterisk asl3-asterisk-modules asl3-pi-appliance dahdi dahdi-linux libopenr2-3
control-CFor a machine that will be compiling source, I never install the .deb packages. I cannot provide much guidance on that - I don't have any experience.
eliggett
commented
2 months ago @KB4MDD I got the dahdi packages removed using dpkg, and IT WORKS!!!
I even heard the call progress tones on the transmission, which I didn't expect.
Nice work. Thank you for working with me on this so that I could test it.
When you have a new SD card image or upgrade procedure, I will give that a go as well.
73,
--E de W6EL
eliggett
commented
2 months ago One more question, is it possible to communicate the vox state over links to other nodes? Currently any node connected to a node in autopatch will stay keyed the entire time. It would be fantastic if it could key on and off with the vox.
KB4MDD
commented
2 months ago I recommend that you start a new issue asking for that feature. I be glad to research and see what would be involved.
eliggett
commented
2 months ago Ok, then let's consider this issue solved via the code commits referenced herein.
Allan-N
commented
2 months ago The fix for this issue has been incorporated into ASL3-Asterisk 20.9.3+asl3-3.0.5-1
Greetings,
I am having difficulty getting any audio from the autopatch to transmit on my simplex (half-duplex) node.
The app_rpt code is a very recent pull (ie, yesterday), freshly compiled with some additional debug text.
The node uses usbradio, and duplex is set to "1". I had tried setting the vox parameters in rpt.conf, but ultimately decided to not set them and use their default values for now.
Here is the debug from a call. I spoke into the phone during the call and the transmitter did not key. I am able to hear the radio's receive audio on the phone when the squelch/COS is opened, as expected. So receive audio is working, PTT and transmit audio seem to not be working.
Thanks for any help you can provide,
--E de W6EL