app_softmodem closes connection to netcat immediately

[ChuckFoo]

Hi, I was previously experimenting w/ asterisk 18 and the older versions (John Newcombe's) app_softmodem.c and having it connect to a listening netcat (nc -l 12345) to simply be able to type in the tty for the modem and see the text arrive at netcat and vice versa, then I decided to upgrade to the phreakscript version to see if it had any stability improvements from either the changes to app_softmodem.c or the newer asterisk version...but it seems to send like a byte or two to the listening netcat even before the modem negotiation starts, then kills the socket connection for some unknown reason during the modem negotiation.

Any ideas why this might be or tips on how to debug? I'm new to asterisk but a 40 year veteran at programming...I tried setting debug logging to the console and turning on debugging for app_softmodem.so and SoftModem, but am seeing no messages from it (I can get other debug message from core stuff to show up in the console though, just not anything from the softmodem code).

I'm also starting to dig through the differences in the 2 versions of app_softmodem.c to try and glean any hints (sadly searching the internet also didn't reveal any hints yet), but being able to see debugging messages would make experimentation & investigation easier.

The config for this in extensions.conf (that worked w/ the earlier version):

exten => 6000,1,Set(VOLUME(TX)=1)
exten => 6000,n,Set(VOLUME(RX)=1)
exten => 6000,n,Answer()
exten => 6000,n,Wait(1)
exten => 6000,n,Softmodem(127.0.0.1,12345,v(V22bis)ld(8)s(1)e)
exten => 6000,n,Hangup()

Thanks,
Chuck

[InterLinked1]

Hi Chuck,
You should see some debug messages of some sort... how are you enabling debug? If you do core set debug 10 app_softmodem, you should get all the debug messages from the module - not that there are a lot, but there are some you should be seeing.

[ChuckFoo]

Hmm, I'm pretty sure I tried that command first, got an error from it, so tried adding the .so to the end and it said it set it to 100, then I repeated w/ the string SoftModem instead, which it also seemed to be successful with, but no output...but maybe I fudged up something else the first time...I'll try that again when I get home from work.

[InterLinked1]

Hmm, I'm pretty sure I tried that command first, got an error from it, so tried adding the .so to the end and it said it set it to 100, then I repeated w/ the string SoftModem instead, which it also seemed to be successful with, but no output...but maybe I fudged up something else the first time...I'll try that again when I get home from work.

It doesn't matter whether you add the .so or not, and there aren't any debug levels beyond 10. But that should work too.

[ChuckFoo]

Okay, getting debug messages now, I think maybe because this time I did the command before initiating a softmodem connection the first time? Now poking around to see what I can see (I have general debug level set to 3 right now and there is a LOT of extra info around the softmodem messages as well) but I'm seeing some potentially interesting things:

[Jul 31 20:29:52] DEBUG[4818][C-00000001]: pbx.c:2977 pbx_extension_helper: Launching 'Softmodem'
    -- Executing [6000@from-internal:5] Softmodem("PJSIP/7000-00000000", "127.0.0.1,12345,v(V22bis)ld(8)s(1)e") in new stack
[Jul 31 20:29:52] DEBUG[4818][C-00000001]: channel.c:5701 set_format: Channel PJSIP/7000-00000000 setting read format path: alaw -> slin
[Jul 31 20:29:52] DEBUG[4818][C-00000001]: channel.c:5701 set_format: Channel PJSIP/7000-00000000 setting write format path: slin -> alaw
[Jul 31 20:29:52] DEBUG[4818][C-00000001]: channel.c:3172 ast_settimeout_full: Scheduling timer at (50 requested / 50 actual) timer ticks per second
[Jul 31 20:29:53] DEBUG[4818][C-00000001]: res_rtp_asterisk.c:5822 calc_rxstamp_and_jitter: 1754008191.0: pkt:    52 Arrival sec:   0.742  Arrival ts:       5933  RX ts:  632295356 Transit samp: -632289423 Last transit samp: -632289446 d:   23 Curr jitter:       1(  0.000) Prev Jitter:      14(  0.002) New Jitter:      15(  0.002)
[Jul 31 20:29:53] DEBUG[4818][C-00000001]: res_rtp_asterisk.c:5603 ast_rtp_write: (1754008191.0) RTP ooh, format changed from none to alaw

(bunch more jitter related msgs)

[Jul 31 20:29:54] DEBUG[4818][C-00000001]: res_rtp_asterisk.c:6680 ast_rtcp_interpret: (1754008191.0) RTCP got report of 112 bytes from 192.168.1.133:16457
[Jul 31 20:29:54] DEBUG[4818][C-00000001]: res_rtp_asterisk.c:6380 update_reported_mes_stats: 1754008191.0: rtt: 0.000000000 j: 0.002000000 sjh: 0.000000000 lost: 0.000000000 mes: 88.1

(more jitter)

      > 0x7fb428027a70 -- Strict RTP learning complete - Locking on source address 192.168.1.133:16456

(jitter)

[Jul 31 20:29:56] DEBUG[4766]: res_rtp_asterisk.c:6414 update_local_mes_stats:    1754008191.0: rtt: 0.000000000 j: 0.001875000 sjh: 0.000315610 lost: 0.000000000 mes: 88.1

(jitter)

[Jul 31 20:29:57] DEBUG[4818][C-00000001]: app_softmodem.c:320 modem_put_bit: send: 31, n
[Jul 31 20:29:57] DEBUG[4818][C-00000001]: res_rtp_asterisk.c:5822 calc_rxstamp_and_jitter: 1754008191.0: pkt:   296 Arrival sec:   5.620  Arrival ts:      44961  RX ts:  632334396 Transit samp: -632289435 Last transit samp: -632289423 d:   12 Curr jitter:      -0(  0.000) Prev Jitter:      16(  0.002) New Jitter:      16(  0.002)
[Jul 31 20:29:57] DEBUG[4818][C-00000001]: app_softmodem.c:320 modem_put_bit: send: 31, *
[Jul 31 20:29:57] DEBUG[4818][C-00000001]: app_softmodem.c:281 modem_put_bit: Bit is -1? Ignoring!

(jitter)

[Jul 31 20:29:58] DEBUG[4818][C-00000001]: res_rtp_asterisk.c:6680 ast_rtcp_interpret: (1754008191.0) RTCP got report of 12 bytes from 192.168.1.133:16457
[Jul 31 20:29:58] DEBUG[4818][C-00000001]: res_rtp_asterisk.c:6697 ast_rtcp_interpret: (1754008191.0) RTCP 0x7fb428027a70 -- from 192.168.1.133:16457: Failed first packet validity check
[Jul 31 20:29:58] DEBUG[4734]: res_pjsip/pjsip_distributor.c:499 distributor: Searching for serializer associated with dialog dlg0x7fb428004e88 for Request msg BYE/cseq=103 (rdata0x7fb424002368)

(some stuff about dealing w/ the BYE method & ending the session)

[Jul 31 20:29:58] DEBUG[4818][C-00000001]: channel.c:3172 ast_settimeout_full: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Jul 31 20:29:58] DEBUG[4818][C-00000001]: app_softmodem.c:896 softmodem_communicate: Channel hangup
[Jul 31 20:29:58] DEBUG[4818][C-00000001]: channel.c:5701 set_format: Channel PJSIP/7000-00000000 setting write format path: ulaw -> alaw
[Jul 31 20:29:58] DEBUG[4818][C-00000001]: channel.c:5701 set_format: Channel PJSIP/7000-00000000 setting read format path: alaw -> alaw
[Jul 31 20:29:58] DEBUG[4818][C-00000001]: pbx.c:4476 __ast_pbx_run: Spawn extension (from-internal,6000,5) exited non-zero on 'PJSIP/7000-00000000'
  == Spawn extension (from-internal, 6000, 5) exited non-zero on 'PJSIP/7000-00000000'
[Jul 31 20:29:58] DEBUG[4818][C-00000001]: channel.c:2427 ast_softhangup_nolock: Soft-Hanging (0x10) up channel 'PJSIP/7000-00000000'
[Jul 31 20:29:58] DEBUG[4818][C-00000001]: channel.c:2515 ast_hangup: Channel 0x7fb428038440 'PJSIP/7000-00000000' hanging up.  Refs: 2
[Jul 31 20:29:58] DEBUG[4818][C-00000001]: chan_pjsip.c:2573 chan_pjsip_hangup:  PJSIP/7000-00000000
[Jul 31 20:29:58] DEBUG[4818][C-00000001]: chan_pjsip.c:2484 hangup_cause2sip: AST hangup cause 16 (no match found in PJSIP)
[Jul 31 20:29:58] DEBUG[4818][C-00000001]: chan_pjsip.c:2591 chan_pjsip_hangup:  Cause: 0
[Jul 31 20:29:58] DEBUG[4812]: chan_pjsip.c:2531 hangup:  PJSIP/7000-00000000

Then a bunch more bookkeeping about closing the channel, destroying threads, etc.

I'm going to continue digging through the info there and the source code and see if I can figure anything out, but figured I'd put what I'm guessing are the relavent bits of info here so you might look at them and go "oh, yeah, you've got XYZ misconfigured" or "looks like a minor bug in the code doing ABC" or something like that before I figure anything out. 😃

Thanks!

[InterLinked1]

I think we only need debug for the softmodem module so you could turn the other stuff off: core set debug 0, then core set debug 10 app_softmodem.

It seems to be sending a couple characters, but then there's a debug message about -1. I don't recall for sure, but that seems unusual to me.

[ChuckFoo]

Yup - comment in the code seemed to indicate that it was ignoring something from the spandsp library? And from the logs there and the logs in the Cisco ATA-191 the USR modem is connected to seemed to indicate that the ATA side was sending the BYE because of not liking something about one of the RTP packets I think. I'll be continuing to dig in now that I can get debug out, but I've got something going on tonight so I won't be able to really dig in until this weekend.

[ChuckFoo]

FYI did a lot of experimentation over the weekend, and to check some things at one point I reverted to my original Asterisk 18.x w/ the older app_softmodem and looks like the same behavior is occurring there now, which makes me think that I must have changed something at the ATA level that is triggering this issue...

After that I moved back to latest asterisk (stock, unpatched) w/ your app_softmodem to continue debugging there, but haven't figured out the underlying issue(s) yet...

[InterLinked1]

FYI did a lot of experimentation over the weekend, and to check some things at one point I reverted to my original Asterisk 18.x w/ the older app_softmodem and looks like the same behavior is occurring there now, which makes me think that I must have changed something at the ATA level that is triggering this issue...

After that I moved back to latest asterisk (stock, unpatched) w/ your app_softmodem to continue debugging there, but haven't figured out the underlying issue(s) yet...

That kind of makes sense to me, as I'm not really sure what change I might have made would be causing your issue - most of what I've done is minor fixes and maintenance and adding support for other modem standards.

What do you actually plan to use this with? I use this softmodem with my BBS for dial-in support with computer terminals and even TDDs, and it's been working fine.

[ChuckFoo]

Well, I work for a small cybersecurity company, and every year a few of us put on a Capture The Flag event with various cybersecurity related (and adjacent) puzzles as a fun team building thing for the company.

In particular I and one other guy build a hardware "badge" with baked in puzzles and things to solve other puzzles with, and we decided to do some phreaking challenges (this year's badge is a bluebox, among other things) so we're setting up an ancient asterisk server with an old 2600 trunk control mod (from ProjectMF), setup a bunch of old phones including a payphone, etc.

And to go with that, I wanted to add a war dialing challenge to find a bbs which will have some puzzles & easter eggs. So I picked up some old modems to add to the mix, was originally going to go all real modems but we decided it'd be "simpler" (and cheaper) if we could get a soft modem solution for the server side of it. This on a newer asterisk running alongside the bluebox one.

If I'm being honest, it's all proving to be a bit more challenging to setup than we expected. 😃 We do have a fair amount of the bluebox stuff working, mostly, but the modem stuff (HW or SW) is proving more challenging.

[ChuckFoo]

Hopefully none of my coworkers (except my partner in crime on this) will see that comment, don't want to spoil anything for them.

[InterLinked1]

Well, I work for a small cybersecurity company, and every year a few of us put on a Capture The Flag event with various cybersecurity related (and adjacent) puzzles as a fun team building thing for the company.

You know, it's funny you say that - you wouldn't be the first person doing that sort of thing that has come to this repo for Asterisk modules. Sounds like fun and hope this can help with that.

In particular I and one other guy build a hardware "badge" with baked in puzzles and things to solve other puzzles with, and we decided to do some phreaking challenges (this year's badge is a bluebox, among other things) so we're setting up an ancient asterisk server with an old 2600 trunk control mod (from ProjectMF), setup a bunch of old phones including a payphone, etc.

Very cool! If you're not aware already, you may also want to check out PhreakNet: https://portal.phreaknet.org/
Admittedly, blue boxing the 2600 Hz controlled trunks doesn't work as well there as on Project MF, at the moment.

And to go with that, I wanted to add a war dialing challenge to find a bbs which will have some puzzles & easter eggs. So I picked up some old modems to add to the mix, was originally going to go all real modems but we decided it'd be "simpler" (and cheaper) if we could get a soft modem solution for the server side of it. This on a newer asterisk running alongside the bluebox one.

I can vouch that this absolutely works for that use case, because I have this softmodem fronting my BBS (I'm running LBBS, not that it shouldn't work with any other BBS though)

While I'm still puzzled about the netcat stuff, I would encourage you to just try it with your BBS as it should work. All you need to do is send it to the Telnet port. For example, Softmodem(127.0.0.1,23,v(V23)l)

If you don't have a BBS configured yet, you could try it with LBBS as it has fairly good debugging messages for I/O if needed - you should see the telnet connection coming in as soon as someone dials the softmodem.

[ChuckFoo]

Yeah, I just discovered your stuff recently after we had already started well down the other path(s) and will definitely check out your BBS setup (I haven't settled on that stuff yet, although was looking at a couple of the old DOS BBSes, figuring I'd run one in DOSBox, DOSBox-X, or QEMU to connect it up).

We will probably also look at your bluebox setup as well, because the ProjectMF stuff has been less than stable too (although more stable than the modems).

The use of netcat was just originally how we were testing the other softmodem stuff when we first set it up, basically just seeing the connection work and characters typed at one end appearing at the other (similarly to how I tested 2 of the HW modems communicating over the asterisk setup when I first/finally got that working before looking into the softmodem route).

Then the amount of noise we were seeing in that connection (when it worked, which wasn't every time) led me down the path of looking for potential alternatives, preferably one with built in error correction, or in the absence of that, that was at least a little more stable. In addition to playing around w/ various ATA and Asterisk settings trying to improve it.

That's when I ran across your version, which I hoped with its improvements and the newer Asterisk base that it might be a little more stable, but now I fear the issue is more in the ATA configs or HW. Hopefully the configs and NOT the HW, but don't know yet.... I ended up basically resetting 2 of the ATAs that had been working w/ HW to HW previously to try and get that functionality back, which I more or less did, then went back to your softmodem for one end and got a connection that didn't immediately disconnect but showed a ton of noise, so I may be getting closer to getting it to working(ish) again.

[InterLinked1]

Yeah, I just discovered your stuff recently after we had already started well down the other path(s) and will definitely check out your BBS setup (I haven't settled on that stuff yet, although was looking at a couple of the old DOS BBSes, figuring I'd run one in DOSBox, DOSBox-X, or QEMU to connect it up).

We will probably also look at your bluebox setup as well, because the ProjectMF stuff has been less than stable too (although more stable than the modems).

The use of netcat was just originally how we were testing the other softmodem stuff when we first set it up, basically just seeing the connection work and characters typed at one end appearing at the other (similarly to how I tested 2 of the HW modems communicating over the asterisk setup when I first/finally got that working before looking into the softmodem route).

Then the amount of noise we were seeing in that connection (when it worked, which wasn't every time) led me down the path of looking for potential alternatives, preferably one with built in error correction, or in the absence of that, that was at least a little more stable. In addition to playing around w/ various ATA and Asterisk settings trying to improve it.

That's when I ran across your version, which I hoped with its improvements and the newer Asterisk base that it might be a little more stable, but now I fear the issue is more in the ATA configs or HW. Hopefully the configs and NOT the HW, but don't know yet.... I ended up basically resetting 2 of the ATAs that had been working w/ HW to HW previously to try and get that functionality back, which I more or less did, then went back to your softmodem for one end and got a connection that didn't immediately disconnect but showed a ton of noise, so I may be getting closer to getting it to working(ish) again.

Is this going over a LAN or WAN? If it's over the Internet, low speeds are never going to work well - at best, it'll work intermittently, but you'll get corruption frequently. Adding support for higher speeds has been on my to do list and I made an attempt once but it didn't quite work right.

On a local network or over a good voice network, like POTS, it should work pretty well.

[ChuckFoo]

All local LAN, setup especially for this event, all in the same office.