[Asterisk-Users] chan_iax2: ast_sched_runq

[Richard Scobie]

Today I updated a couple of TDM400 based asterisks to the latest CVS 
head and started seeing the following messages. The update prior to 
today was a couple of weeks ago.

     -- Starting simple switch on 'Zap/6-1'
     -- Executing Dial("Zap/6-1", "IAX2/pbxak at 192.168.4.223/0") in new stack
     -- Called pbxak at 192.168.4.223/0
     -- Call accepted by 192.168.4.223 (format alaw)
     -- Format for call is alaw
     -- IAX2/pbxwn-1 answered Zap/6-1
Nov 10 15:44:34 WARNING[7972]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 140 scheduled tasks all at once
Nov 10 15:44:34 WARNING[7972]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 110 scheduled tasks all at once
Nov 10 15:44:34 WARNING[7972]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 106 scheduled tasks all at once
Nov 10 15:44:34 WARNING[7972]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 86 scheduled tasks all at once
Nov 10 15:44:34 WARNING[7972]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 96 scheduled tasks all at once
Nov 10 15:44:34 WARNING[7972]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 300 scheduled tasks all at once
Nov 10 15:44:34 WARNING[7972]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 400 scheduled tasks all at once
Nov 10 15:44:34 WARNING[7972]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 200 scheduled tasks all at once
Nov 10 15:44:35 WARNING[7972]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 1237 scheduled tasks all at once
Nov 10 15:44:35 WARNING[7972]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 3722 scheduled tasks all at once
Nov 10 15:44:35 WARNING[7972]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 242 scheduled tasks all at once
     -- Hungup 'IAX2/pbxwn-1'
   == Spawn extension (default, 0, 1) exited non-zero on 'Zap/6-1'
     -- Hungup 'Zap/6-1'


Zap6-1 is an FXS port on a TDM400 card, calling another identical P4 2.4 
box. It was the only call in progress on a stripped down system running 
a minimal asterisk setup on a custom 2.4 kernel. System load is nil.

The log below is from the box at the other end, placing a call back to 
the box above. Zap/1-1 is an FXO port on a TDM400:

     -- Starting simple switch on 'Zap/1-1'
     -- Executing Answer("Zap/1-1", "") in new stack
     -- Executing Set("Zap/1-1", "TIMEOUT(digit)=10") in new stack
     -- Digit timeout set to 10
     -- Executing Set("Zap/1-1", "TIMEOUT(response)=20") in new stack
     -- Response timeout set to 20
   == CDR updated on Zap/1-1
     -- Executing Dial("Zap/1-1", "IAX2/pbxwn at 192.168.3.223/503") in new 
stack
     -- Called pbxwn at 192.168.3.223/503
     -- Call accepted by 192.168.3.223 (format alaw)
     -- Format for call is alaw
     -- IAX2/pbxak-1 is ringing
     -- IAX2/pbxak-1 stopped sounds
     -- IAX2/pbxak-1 answered Zap/1-1
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 23 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 28 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 35 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 59 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 28 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 27 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 257 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 176 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 199 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 24 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 26 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 173 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 278 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 37 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 73 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 762 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 824 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 27 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 313 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 47 scheduled tasks all at once
Nov 10 16:18:56 WARNING[9362]: chan_iax2.c:7965 network_thread: 
chan_iax2: ast_sched_runq ran 45 scheduled tasks all at once

Again, this was the only call on an otherwise unloaded box.

Nobody has complained so it is not causing an obvious problem to the calls.

In a previous thread on this same error, Steve Kaan asked if there were 
any DNS lookups involved. I can't see it unless there are reverse 
lookups being done.

Both boxes are 600km apart on a good 10Mb connection.

Regards,

Richard