Children of the init

Example console output:

freeswitch@test01> ais help

ais cluster <show>
ais help

freeswitch@test01> ais cluster show

=======================================================================
Name: 10.0.0.1
 Node ID:                0x100000a
 Node Address:           10.0.0.1
 Node BootTimestamp:     Fri, 13 Aug 2010 15:14:11 GMT
 Node Is Member:         Yes
-----------------------------------------------------------------------
Name: 10.0.0.2
 Node ID:                0x200000a
 Node Address:           10.0.0.2
 Node BootTimestamp:     Mon, 11 Oct 2010 19:21:50 GMT
 Node Is Member:         Yes
=======================================================[  2 node(s) ]==

freeswitch@test01>

Example output of node joining + leaving the cluster:

freeswitch@test01> 2011-01-30 01:31:53.606847 [DEBUG] mod_openais.c:371 CLM event(s) available
2011-01-30 01:31:53.606847 [DEBUG] mod_openais.c:186 clm_cluster_track_cb() called
2011-01-30 01:31:53.606847 [DEBUG] mod_openais.c:192 CLM: Node '10.0.0.2' [ID: 0x200000a, Address: 10.0.0.2], Event: 'Left'

freeswitch@test01> 2011-01-30 01:31:56.803345 [DEBUG] mod_openais.c:371 CLM event(s) available
2011-01-30 01:31:56.804643 [DEBUG] mod_openais.c:186 clm_cluster_track_cb() called
2011-01-30 01:31:56.804643 [DEBUG] mod_openais.c:192 CLM: Node '10.0.0.2' [ID: 0x200000a, Address: 10.0.0.2], Event: 'Joined'

freeswitch@test01>

fs_cli event output (node leaving, still going to rework this a bit):

RECV EVENT
Event-Subclass: OpenAIS-Node-Left
priority: HIGH
Event-Name: CUSTOM
Core-UUID: 86032536-bea5-4a44-87c4-547579b2e4c2
FreeSWITCH-Hostname: test01
FreeSWITCH-IPv4: X.X.X.X
FreeSWITCH-IPv6: ::1
Event-Date-Local: 2011-01-30 01:33:35
Event-Date-GMT: Sun, 30 Jan 2011 00:33:35 GMT
Event-Date-Timestamp: 1296347615442192
Event-Calling-File: mod_openais.c
Event-Calling-Function: clm_send_event
Event-Calling-Line-Number: 152
Node-Name: 10.0.0.2
Node-Address: 10.0.0.2
Node-ID: 0x200000a
Node-BootTimestamp: 1286824910000000000

Incoming braindump…

Connect phone using serial cable (after you built one).

~# cd osmocom-bb/src/host/osmocon
~# ./osmocon -p /dev/ttyUSB0 -m mtk ../../target/firmware/board/mt62xx/loader.mtkram.bin
got 1 bytes from modem, data looks like: 00  .
got 1 bytes from modem, data looks like: 00  .
Sending MTK romloader beacon...
Sending MTK romloader beacon...
Sending MTK romloader beacon...

osmocon waits for answer packets from the phone, keep pressing the power button, the romloader will send the beacon and osmocon will upload the ramloader:

Sending MTK romloader beacon...
got 1 bytes from modem, data looks like: 5f  _
Received init magic byte 1
got 1 bytes from modem, data looks like: f5  .
Received init magic byte 2
got 1 bytes from modem, data looks like: af  .
Received init magic byte 3
got 1 bytes from modem, data looks like: fa  .
Received init magic byte 4, requesting write
got 1 bytes from modem, data looks like: a1  .
Received write ack, sending load address
got 1 bytes from modem, data looks like: 40  @
got 1 bytes from modem, data looks like: 00  .
got 1 bytes from modem, data looks like: 14  .
got 1 bytes from modem, data looks like: 00  .
Received address ack from phone, sending loadsize
read_file(../../target/firmware/board/mt62xx/loader.mtkram.bin): file_size=13856, hdr_len=0, dnload_len=13859
Preparing block 1
got 1 bytes from modem, data looks like: 00  .
got 1 bytes from modem, data looks like: 00  .
got 1 bytes from modem, data looks like: 1c  .
got 1 bytes from modem, data looks like: 00  .
Received size ack
handle_write_block(): 1024 bytes (1024/1024)
handle_write_block(): Block 1 finished
Received Block 1 preparing next block
Preparing block 2
handle_write_block(): 1024 bytes (1024/1024)
handle_write_block(): Block 2 finished
Received Block 2 preparing next block
Preparing block 3
handle_write_block(): 1024 bytes (1024/1024)
handle_write_block(): Block 3 finished
Dropping sample '0'
Received Block 3 preparing next block
Preparing block 4
handle_write_block(): 1024 bytes (1024/1024)
handle_write_block(): Block 4 finished
Received Block 4 preparing next block
Preparing block 5
handle_write_block(): 1024 bytes (1024/1024)
handle_write_block(): Block 5 finished
Received Block 5 preparing next block
Preparing block 6
handle_write_block(): 1024 bytes (1024/1024)
handle_write_block(): Block 6 finished
Received Block 6 preparing next block
Preparing block 7
handle_write_block(): 1024 bytes (1024/1024)
handle_write_block(): Block 7 finished
Received Block 7 preparing next block
Preparing block 8
handle_write_block(): 1024 bytes (1024/1024)
handle_write_block(): Block 8 finished
Received Block 8 preparing next block
Preparing block 9
handle_write_block(): 1024 bytes (1024/1024)
handle_write_block(): Block 9 finished
Received Block 9 preparing next block
Preparing block 10
handle_write_block(): 1024 bytes (1024/1024)
Dropping sample 'X'
handle_write_block(): Block 10 finished
Received Block 10 preparing next block
Preparing block 11
handle_write_block(): 1024 bytes (1024/1024)
handle_write_block(): Block 11 finished
Received Block 11 preparing next block
Preparing block 12
handle_write_block(): 1024 bytes (1024/1024)
handle_write_block(): Block 12 finished
Received Block 12 preparing next block
Preparing block 13
handle_write_block(): 1024 bytes (1024/1024)
handle_write_block(): Block 13 finished
Received Block 13 preparing next block
Preparing the last block, filling 480 bytes
handle_write_block(): 1024 bytes (1024/1024)
handle_write_block(): Block 14 finished
Finished, sent 14 blocks in total
Sending branch command
got 1 bytes from modem, data looks like: a8  .
Received branch command ack, sending address
got 1 bytes from modem, data looks like: 40  @
got 1 bytes from modem, data looks like: 00  .
got 1 bytes from modem, data looks like: 14  .
got 1 bytes from modem, data looks like: 00  .
Received branch address ack, code should run now

Running on mt62xx in environment mtkram

HW_CODE = 0x6235

The ramloader has been loaded successfully.

Keep osmocom running, go to a different terminal window and upload the uboot image using osmoload:

~# cd osmocom-bb/src/host/osmocon
~# ./osmoload memload 0x500000 ~/g2_uboot.bin
Loading 160144 bytes of memory to address 0x500000 from file /home/stkn/uboot-mt623x/u-boot.bin
..................................................................................................
..................................................................................................
..................................................................................................
..................................................................................................
..................................................................................................
..................................................................................................
................................................................................done.
~# ./osmoload jump 0x500000
Confirmed jump to 0x500000.


Close osmocon in the first terminal(!). Open a serial terminal program (e.g. minicom), parameters for the serial connection are: 115200,8n1 (no handshake).
Sciphone> help
?       - alias for 'help'
base    - print or set address offset
bootm   - boot application image from memory
cmp     - memory compare
cp      - memory copy
crc32   - checksum calculation
env     - environment handling commands
exit    - exit script
ext2load- load binary file from a Ext2 filesystem
ext2ls  - list files in a directory (default /)
false   - do nothing, unsuccessfully
fatinfo - print information about filesystem
fatload - load binary file from a dos filesystem
fatls   - list files in a directory (default /)
go      - start application at address 'addr'
help    - print command description/usage
loadb   - load binary file over serial line (kermit mode)
loady   - load binary file over serial line (ymodem mode)
loop    - infinite loop on address range
md      - memory display
mm      - memory modify (auto-incrementing address)
mmc     - MMC sub system
mmcinfo - display MMC info
mtest   - simple RAM read/write test
mw      - memory write (fill)
nand    - NAND sub-system
nboot   - boot from NAND device
nm      - memory modify (constant address)
printenv- print environment variables
reset   - Perform RESET of the CPU
run     - run commands in an environment variable
setenv  - set environment variables
showvar - print local hushshell variables
test    - minimal test like /bin/sh
true    - do nothing, successfully
version - print monitor version

Load the linux kernel (i’m using the kermit protocol here):
Sciphone> loadb
## Ready for binary (kermit) download to 0x00800000 at 115200 bps...

Press Ctrl+S to open the upload menu, select kermit, navigate to the directory where you keep the g2_uImage.bin file, select the file with Space and start the upload with the Okay button. Kermit will start the upload (this will take a couple of minutes!). After the upload is finished, start the kernel:
Sciphone> bootm 0x800000
## Booting kernel from Legacy Image at 00800000 ...
 Image Name:   Linux-2.6.36-next-20101029+
 Image Type:   ARM Linux Kernel Image (uncompressed)
 Data Size:    1516416 Bytes = 1.4 MiB
 Load Address: 00008000
 Entry Point:  00008000
 Verifying Checksum ... OK
 Loading Kernel Image ... OK
OK  

Starting kernel ...

Uncompressing Linux... done, booting the kernel.
Linux version 2.6.36-next-20101029+ (xpumami@xpumami-desktop) (gcc version 4.4.1 (Sourcery G++ Lite 2009q3-67) ) #72 PREEMPT Wed Nov 17 14:10:39 CET 2010
CPU: ARM926EJ-S [41069265] revision 5 (ARMv5TEJ), cr=00053177
CPU: VIVT data cache, VIVT instruction cache
Machine: Sciphone G2
Memory policy: ECC disabled, Data cache writeback
pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
pcpu-alloc: [0] 0
Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 16256
Kernel command line: console=ttyMTK0,115200n8 mem=64M@0
PID hash table entries: 256 (order: -2, 1024 bytes)
Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)
Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)
Memory: 64MB = 64MB total
Memory: 61676k/61676k available, 3860k reserved, 0K highmem
Virtual kernel memory layout:
 vector  : 0xffff0000 - 0xffff1000   (   4 kB)
 fixmap  : 0xfff00000 - 0xfffe0000   ( 896 kB)
 DMA     : 0xffc00000 - 0xffe00000   (   2 MB)
 vmalloc : 0xc4800000 - 0xe0000000   ( 440 MB)
 lowmem  : 0xc0000000 - 0xc4000000   (  64 MB)
 modules : 0xbf000000 - 0xc0000000   (  16 MB)
 .init : 0xc0008000 - 0xc0192000   (1576 kB)
 .text : 0xc0192000 - 0xc0318000   (1560 kB)
 .data : 0xc0318000 - 0xc0323260   (  45 kB)
Preemptable hierarchical RCU implementation.
 RCU-based detection of stalled CPUs is disabled.
 Verbose stalled-CPUs detection is disabled.
NR_IRQS:50
Calibrating delay loop... 104.24 BogoMIPS (lpj=521216)
pid_max: default: 32768 minimum: 301
Mount-cache hash table entries: 512
CPU: Testing write buffer coherency: ok
bio: create slab <bio-0> at 0
Switching to clocksource gpt_3
msgmni has been set to 120
Block layer SCSI generic (bsg) driver version 0.4 loaded (major 254)
io scheduler noop registered
io scheduler deadline registered
io scheduler cfq registered (default)
mt62xx_serial.0: ttyMTK0 at MMIO 0xf1030000 (irq = 7) is a MT62XX Serial Port
console [ttyMTK0] enabled
brd: module loaded
Freeing init memory: 1576K
init started: BusyBox v1.17.3 (2010-11-17 07:35:14 CET)
starting pid 93, tty '': '/etc/rc.init'

Please press Enter to activate this console.

Press Enter to get a console.
starting pid 95, tty '/dev/ttyMTK0': '/bin/ash'
/ # ls
bin   dev   etc   init  proc  sbin  sys   tmp   usr
/ # ps
 PID USER       VSZ STAT COMMAND
 1 0         1764 S    init
 2 0            0 SW   [kthreadd]
 3 0            0 SW   [ksoftirqd/0]
 4 0            0 SW   [kworker/0:0]
 5 0            0 SW   [kworker/u:0]
 6 0            0 SW<  [khelper]
 7 0            0 SW   [kworker/u:1]
 21 0            0 SW   [sync_supers]
 23 0            0 SW   [bdi-default]
 25 0            0 SW<  [kblockd]
 45 0            0 SW   [kswapd0]
 46 0            0 SW   [fsnotify_mark]
 47 0            0 SW<  [aio]
 48 0            0 SW<  [crypto]
 95 0         1768 S    /bin/ash
 96 0            0 SW   [kworker/0:1]
 98 0         1768 R    ps
/ #

Links:
[1] Marcin Mielczarczyk’s uboot and kernel image can be found here
      	

Connections between the cables are a bit flaky (Mr. Solder Iron will fix that next weekend…), but i can already see the MTK bootloader output in minicom (115200,8n1).

Collecting everything here before posting to the relevant places…

The Problem:

People reporting audio distortion on the BRI PTMP (S0) bus after placing calls with FreeTDM (or other unexpected behaviour like devices crashing, acting odd etc.). Those distortions vanish after stopping or restarting FreeSWITCH. (NOTE: I/O module is Zaptel/DAHDI)

The Cause (short):

1. FreeTDM opens the B-Channel immediately, on outgoing and incoming calls, even if no media has been signalled by the NT (via PROGRESS IE or any other means) (this can cause other devices on the bus to crash).

2. FreeTDM (or the signalling module) does not completely close the B-Channel on hangup, leaving the B-Channel open and transmitting frames (this is what causes the distortions on the bus, after the first call).

The Cause (long):

For outgoing channels:

1. mod_freetdm:channel_outgoing_channel()  opens a channel using this piece of code (line 1283 ff.):

if (group_id >= 0) {
  status = ftdm_channel_open_by_group(group_id, direction, &caller_data, &ftdmchan);
} else if (chan_id) {
  status = ftdm_channel_open(span_id, chan_id, &ftdmchan);
} else {
  status = ftdm_channel_open_by_span(span_id, direction, &caller_data, &ftdmchan);
}

each of these functions opens a selected channel using the “channel->fio->open()” callback of the channel’s I/O module, causing the channel to be “physically” openened. In the case of Zaptel/DAHDI (B-)channels this means (the) AUDIO_MODE is enabled, causing audio frames to be transmitted and received from the ISDN bus.
For TE-mode, this behaviour is wrong, the selected channel has not been acknowledged by the NT and may still change after the SETUP message. For NT-mode, opening the B-Channel at this stage is wrong too, even if the channel does not change later. The earliest possible state to open the channel here is, for inbound calls, after the SETUP ACK message for overlap-dial (inband dialtone).
NOTE: This is something the signalling module has to control ({oz,ft}mod_isdn does that already)!
2. The signalling module (e.g. current ftmod_libpri) does not call ftmod_close_channel() on hangup to completely close the channel.
On hangup, the signalling module _MUST_ call ftmod_channel_close() to “physically” close the B-Channel, for Zaptel/DAHDI channels this means disabling AUDIO_MODE to stop transmitting frames on B-Channels and to avoid distortions on the S0 bus and confusing other devices.
This requires the I/O module implements the neccessary code to close a channel in its close() callback.
NOTE: ftmod_zt does that since commit c1517e99d1
[RFD] The solution:
Don’t open channels in mod_freetdm:channel_outgoing_channel() (or any other place that does it too early), reserve and assign the channel instead. Let the signalling module handle opening/closing of channels (or, as a fallback, let the FreeTDM core open the channel upon entering states that really need to have the channel open, e.g. PROGRESS_MEDIA).
      	

Hey wow, it’s been more then a year already, anyway… here’s the current state:

ber_encode_oid(): unimplemented!
successfully encoded 53 octets ASN.1 BER data
------ dump (53 octets) ------
[ bf 7f 32 02 02 02 f5 06 06 04 00 85 69 01 03 30 24 a1 06 80 04 31 30 30 31 a2 03 0a 01 01 a3 03
  02 01 00 a4 06 80 04 31 30 30 31 a6 08 30 06 02 01 00 0a 01 01 ]
------ dump (53 octets) ------
[ bf 7f 32 02 02 02 f5 06 06 00 00 00 00 00 00 30 24 a1 06 80 04 31 30 30 31 a2 03 0a 01 01 a3 03
  02 01 00 a4 06 80 04 31 30 30 31 a6 08 30 06 02 01 00 0a 01 01 ]
compare: 5 octets mismatch
duration 0 seconds, 14701 nanoseconds

Encoding is a lot faster than decoding, even though it has to walk the whole tree twice (maybe malloc is the culprit here, will have to investigate further). Next step is to implement the missing ber_encode_oid() function and the usual cleanups, etc.

Just a short dump of the configuration files involved in getting a BRI PTMP (Point-to-Multipoint) TE setup running (with a HFC-S card and (v)zaphfc):

1. Install latest libpri (1.4.12_beta2 or higher)

2. Configure and install FreeSWITCH / FreeTDM with configure option “–with-libpri”

FreeTDM configure should output this:

<<>> Digium libpri
checking whether libpri is usable... yes
checking whether libpri has BRI support... yes
checking whether libpri has AOC event support... yes

/etc/dahdi/system.conf:

loadzone=nl
defaultzone=nl
span=1,1,0,ccs,ami
bchan=1,2
hardhdlc=3

freetdm.conf:

[span zt BRI_1]
number => 1
trunk_type => BRI_PTMP
b-channel => 1,2
d-channel => 3

freetdm.conf.xml:

...
<libpri_spans>
         <span name="BRI_1">
                 <param name="dialplan" value="XML"/>
                 <param name="context"  value="isdn"/>   <!-- custom context for incoming ISDN calls -->
                 <param name="node"     value="cpe"/>
                 <param name="switch"   value="euroisdn"/>
                <!-- <param name="debug"    value="q931_all"/> -->
                <!-- Some BRI lines may not like the REDIRECTING NUMBER IE,
                     use this option to disable it
                     <param name="opts"     value="omit_redirecting_number"/>
                -->
        </span>
    <!-- other libpri spans -->
</libpri_spans>
...

Q.921 statistic counters are finally useable now:

freeswitch@konata> oz isdn counters 1 q921

=================================================================================
 Q.921 statistic counters for span 1 (cumulative)
=================================================================================
   Name   |     Value     | Flags |                Description                   
---------------------------------------------------------------------------------
ST04      |             1 |       | State: changed to TEI Assigned              
ST05      |             1 |       | State: changed to Awaiting Establishment    
ST06      |             0 |       | State: changed to Awaiting Release          
ST07      |             0 |       | State: changed to Multiple Frame Established
ST08      |             0 |   E   | State: changed to Timer Recovery            
T200      |             4 |       | Timer: T200 Timeouts                        
T201      |             0 |       | Timer: T201 Timeouts                        
T202      |             0 |  G    | Timer: T202 Timeouts                        
T203      |             0 |       | Timer: T203 Timeouts                        
TM01      |             0 |       | Timer: TM01 Timeouts                        
N200      |             1 |   EA  | Limit: Max. retransmit exceeded             
N201      |             0 |  GE   | Limit: Max. frame size exceeded             
N202      |             0 |   E   | Limit: Max. PtMP TE retransmit exceeded     
---=== TX / RX Counters: ===-----------------------------------------------------
TX-S      |             0 |       | TX: S frames sent                           
TX-U      |             5 |       | TX: U frames sent                           
TX-I      |             0 |       | TX: I frames sent                           
TX-DISC   |             0 |       | TX: Disconnect                              
TX-DM     |             0 |       | TX: Disconnected-Mode                       
TX-REJ    |             0 |   E   | TX: Reject                                  
TX-RR     |             0 |       | TX: Receiver-Ready                          
TX-RNR    |             0 |       | TX: Receiver-Not-Ready                      
TX-SABME  |             5 |       | TX: Set Asynchronous Balanced Mode Extended 
TX-UA     |             0 |       | TX: Unnumbered Acknowledgement              
TX-UN     |             0 |       | TX: Unnumbered Information                  
RX-S      |             0 |       | RX: S frames received                       
RX-U      |             0 |       | RX: U frames received                       
RX-I      |             0 |       | RX: I frames received                       
RX-DISC   |             0 |       | RX: Disconnect                              
RX-DM     |             0 |       | RX: Disconnected-Mode                       
RX-REJ    |             0 |   E   | RX: Reject                                  
RX-RNR    |             0 |       | RX: Receiver-Not-Ready                      
RX-RR     |             0 |       | RX: Receiver-Ready                          
RX-SABME  |             0 |       | RX: Set Asynchronous Balanced Mode Extended 
RX-UA     |             0 |       | RX: Unnumbered Acknowledgement              
RX-UN     |             0 |       | RX: Unnumbered Information                  
RX-INV-S  |             0 |   E   | RX: Invalid S frames received               
RX-INV-U  |             0 |   E   | RX: Invalid U frames received               
RX-INV-I  |             0 |   E   | RX: Invalid I frames received               
---------------------------------------------------------------------------------
 Flag description: G = Global counter | E = Error condition | A = Alert
-----------------------------------------------------------------[ 38 counter ]--
+OK

This is from a back-to-back E1 PRI line of my current test setup, Point-To-Multipoint (BRI) lines have a few more counters due to TEI management being active. (Yes, the red marker for actual errors is in the CLI too.)

I’m in the middle of some larger code changes, so it will take a while for this and other improvements to hit any publicly-visible repository.

Slowly moving services to a new root server and i can finally send the old one into retirement.

So, goodbye aura.netdomination.org, you’ve served me well over the past six (or seven?) years, hosting thinks like tracker.netdomination.org, primary DNS server and my personal webspace (= this blog, the old one and a ton of random opensource-related files).

And welcome “whatever i’m going to call you”.netdomination.org, new home of my blog and a bunch of other services that are going to move over, or will be added over time…

If you happen to not like Firefox-3.6’s new behaviour of opening related tabs next to the parent tab instead of at the right end of the tab-bar:

got to “about:config” and set “browser.tabs.insertRelatedAfterCurrent” to “false”.

mod_ssh’s bundled version of libssh has been updated to version 0.4.0. Parts of mod_ssh had to be fixed to compile with the new libssh version and a couple of things have been improved in the process (e.g. error handling in the load function and the “ssh” api command).

No new features otherwise.

NOTE: There still seems to be an issue with buffer handling / ANSI control sequences and reloading mod_ssh kills FreeSWITCH with a SIGBUS.

UPDATE: ANSI control sequence corruption has been fixed (commit 33c6ee7…).