Channel not in Stasis application

Hi all,

I am trying to snoop a call in queue using Stasis application. The program used to work fine, but couple of days back it started giving “Channel not in Stasis application” error.

To debug I captured the HTTP messages between Stasis application and Asterisk. The application does the following steps:

  1. Get the values of two variables: SNOOP_CHAN and SNOOP_TYPE. First gives the channel to snoop and second the type
  2. List all channels and from all channels get the full channel id matching the SIP id to snoop
  3. Snoop the channel
  4. Create a bridge and add the calling channel and snoop channel.

The error occurs in the last step. I am not able to figure out why this happens, and looking for some clues to understand why one of this channel is not in Stasis application.

The HTTP requests are as follows:

GET /ari/channels/er-01-1652199362.2652/variable?variable=SNOOP_CHAN HTTP/1.1
Host: localhost:8088
Connection: keep-alive
Accept-Encoding: gzip, deflate
Accept: */*
User-Agent: python-requests/2.27.1
Authorization: Basic dXNlci1uZnVpaTpJb01JN1dBV09U

HTTP/1.1 200 OK
Server: Asterisk
Date: Tue, 10 May 2022 16:16:02 GMT
Cache-Control: no-cache, no-store
Content-type: application/json
Content-Length: 31

{"value":"MCM-fpyQSE-20001139"}

GET /ari/channels/er-01-1652199362.2652/variable?variable=SNOOP_TYPE HTTP/1.1
Host: localhost:8088
Connection: keep-alive
Accept-Encoding: gzip, deflate
Accept: */*
User-Agent: python-requests/2.27.1
Authorization: Basic dXNlci1uZnVpaTpJb01JN1dBV09U

HTTP/1.1 200 OK
Server: Asterisk
Date: Tue, 10 May 2022 16:16:02 GMT
Cache-Control: no-cache, no-store
Content-type: application/json
Content-Length: 17

{"value":"SNOOP"}

GET /ari/channels HTTP/1.1
Host: localhost:8088
Connection: keep-alive
Accept-Encoding: gzip, deflate
Accept: */*
User-Agent: python-requests/2.27.1
Authorization: Basic dXNlci1uZnVpaTpJb01JN1dBV09U

HTTP/1.1 200 OK
Server: Asterisk
Date: Tue, 10 May 2022 16:16:02 GMT
Cache-Control: no-cache, no-store
Content-type: application/json
Content-Length: 1173

[{"id":"er-01-1652199329.2644","name":"PJSIP/erxin02-ex-01-00000148","state":"Up","caller":{"name":"07510680128","number":"07510680128"},"connected":{"name":"","number":"4466636600"},"accountcode":"","dialplan":{"context":"leaf-queue","exten":"s","priority":8,"app_name":"Queue","app_data":"queue-name-en,b(sub_crmurl^s^1(queue-name-en,,07510680128,07510680128,English,N))"},"creationtime":"2022-05-10T21:45:29.909+0530","language":"en"},{"id":"er-01-1652199332.2647","name":"PJSIP/MCM-fpyQSE-20001139-00000149","state":"Up","caller":{"name":"","number":"4466636600"},"connected":{"name":"07510680128","number":"07510680128"},"accountcode":"","dialplan":{"context":"mettle","exten":"s","priority":1,"app_name":"AppQueue","app_data":"(Outgoing Line)"},"creationtime":"2022-05-10T21:45:32.700+0530","language":"en"},{"id":"er-01-1652199362.2652","name":"PJSIP/MCM-Gvu8eu-20001020-0000014a","state":"Up","caller":{"name":"","number":"MCM-Gvu8eu-20001020"},"connected":{"name":"","number":""},"accountcode":"","dialplan":{"context":"mettle","exten":"102","priority":6,"app_name":"Stasis","app_data":"snoop"},"creationtime":"2022-05-10T21:46:02.075+0530","language":"en"}]

POST /ari/channels/er-01-1652199362.2652/play?media=sound%3Awelcome HTTP/1.1
Host: localhost:8088
Connection: keep-alive
Accept-Encoding: gzip, deflate
Accept: */*
User-Agent: python-requests/2.27.1
Content-Length: 0
Authorization: Basic dXNlci1uZnVpaTpJb01JN1dBV09U

HTTP/1.1 201 Created
Server: Asterisk
Date: Tue, 10 May 2022 16:16:02 GMT
Cache-Control: no-cache, no-store
Location: /ari/playbacks/a56003a0-7e2f-444c-8d0a-7017f9060e93
Content-type: application/json
Content-Length: 151

{"id":"a56003a0-7e2f-444c-8d0a-7017f9060e93","media_uri":"sound:welcome","target_uri":"channel:er-01-1652199362.2652","language":"en","state":"queued"}

POST /ari/channels/er-01-1652199332.2647/snoop?spy=both&app=snoop&snoopId=snoop-er-01-1652199332.2647&whisper=none HTTP/1.1
Host: localhost:8088
Connection: keep-alive
Accept-Encoding: gzip, deflate
Accept: */*
User-Agent: python-requests/2.27.1
Content-Length: 0
Authorization: Basic dXNlci1uZnVpaTpJb01JN1dBV09U

HTTP/1.1 200 OK
Server: Asterisk
Date: Tue, 10 May 2022 16:16:02 GMT
Cache-Control: no-cache, no-store
Content-type: application/json
Content-Length: 329

{"id":"snoop-er-01-1652199332.2647","name":"Snoop/er-01-1652199332.2647-00000054","state":"Up","caller":{"name":"","number":""},"connected":{"name":"","number":""},"accountcode":"","dialplan":{"context":"default","exten":"s","priority":1,"app_name":"","app_data":""},"creationtime":"2022-05-10T21:46:02.376+0530","language":"en"}

POST /ari/bridges?type=mixing HTTP/1.1
Host: localhost:8088
Connection: keep-alive
Accept-Encoding: gzip, deflate
Accept: */*
User-Agent: python-requests/2.27.1
Content-Length: 0
Authorization: Basic dXNlci1uZnVpaTpJb01JN1dBV09U

HTTP/1.1 200 OK
Server: Asterisk
Date: Tue, 10 May 2022 16:16:02 GMT
Cache-Control: no-cache, no-store
Content-type: application/json
Content-Length: 232

{"id":"e24d7693-11f1-40cd-b513-e4c610088ee3","technology":"simple_bridge","bridge_type":"mixing","bridge_class":"stasis","creator":"Stasis","name":"","channels":[],"creationtime":"2022-05-10T21:46:02.392+0530","video_mode":"talker"}

POST /ari/bridges/e24d7693-11f1-40cd-b513-e4c610088ee3/addChannel?channel=er-01-1652199362.2652%2Csnoop-er-01-1652199332.2647 HTTP/1.1
Host: localhost:8088
Connection: keep-alive
Accept-Encoding: gzip, deflate
Accept: */*
User-Agent: python-requests/2.27.1
Content-Length: 0
Authorization: Basic dXNlci1uZnVpaTpJb01JN1dBV09U

HTTP/1.1 422 Unprocessable Entity
Server: Asterisk
Date: Tue, 10 May 2022 16:16:02 GMT
Cache-Control: no-cache, no-store
Content-type: application/json
Content-Length: 47

{"message":"Channel not in Stasis application"}

Is the channel being snooped on still active? What does the Asterisk console show? Do you still see the Snoop channel in “core show channels”? What comes across on the Websocket events?

Yes, from the console, I presume channel being snooped is active. Asterisk console do not show any errors. Please see the console and websocket output while snooping is going on:

POST /ari/channels/er-01-1652717008.3368/play?media=sound%3Awelcome HTTP/1.1
Host: localhost:8088
Connection: keep-alive
Accept-Encoding: gzip, deflate
Accept: */*
User-Agent: python-requests/2.27.1
Content-Length: 0
Authorization: Basic dXNlci1uZnVpaTpJb01JN1dBV09U

HTTP/1.1 201 Created
Server: Asterisk
Date: Mon, 16 May 2022 16:03:28 GMT
Cache-Control: no-cache, no-store
Location: /ari/playbacks/80ee098d-2fea-4ba3-9884-f44757a2d7aa
Content-type: application/json
Content-Length: 151

{"id":"80ee098d-2fea-4ba3-9884-f44757a2d7aa","media_uri":"sound:welcome","target_uri":"channel:er-01-1652717008.3368","language":"en","state":"queued"}

POST /ari/channels/er-01-1652716959.3363/snoop?spy=both&app=snoop&snoopId=snoop-er-01-1652716959.3363&whisper=none HTTP/1.1
Host: localhost:8088
Connection: keep-alive
Accept-Encoding: gzip, deflate
Accept: */*
User-Agent: python-requests/2.27.1
Content-Length: 0
Authorization: Basic dXNlci1uZnVpaTpJb01JN1dBV09U

HTTP/1.1 200 OK
Server: Asterisk
Date: Mon, 16 May 2022 16:03:28 GMT
Cache-Control: no-cache, no-store
Content-type: application/json
Content-Length: 329

{"id":"snoop-er-01-1652716959.3363","name":"Snoop/er-01-1652716959.3363-0000005c","state":"Up","caller":{"name":"","number":""},"connected":{"name":"","number":""},"accountcode":"","dialplan":{"context":"default","exten":"s","priority":1,"app_name":"","app_data":""},"creationtime":"2022-05-16T21:33:28.507+0530","language":"en"}

POST /ari/bridges?type=mixing HTTP/1.1
Host: localhost:8088
Connection: keep-alive
Accept-Encoding: gzip, deflate
Accept: */*
User-Agent: python-requests/2.27.1
Content-Length: 0
Authorization: Basic dXNlci1uZnVpaTpJb01JN1dBV09U

HTTP/1.1 200 OK
Server: Asterisk
Date: Mon, 16 May 2022 16:03:28 GMT
Cache-Control: no-cache, no-store
Content-type: application/json
Content-Length: 232

{"id":"6cd459f0-13f4-4989-907d-ab5215a8e3e5","technology":"simple_bridge","bridge_type":"mixing","bridge_class":"stasis","creator":"Stasis","name":"","channels":[],"creationtime":"2022-05-16T21:33:28.521+0530","video_mode":"talker"}

POST /ari/bridges/6cd459f0-13f4-4989-907d-ab5215a8e3e5/addChannel?channel=er-01-1652717008.3368%2Csnoop-er-01-1652716959.3363 HTTP/1.1
Host: localhost:8088
Connection: keep-alive
Accept-Encoding: gzip, deflate
Accept: */*
User-Agent: python-requests/2.27.1
Content-Length: 0
Authorization: Basic dXNlci1uZnVpaTpJb01JN1dBV09U

HTTP/1.1 422 Unprocessable Entity
Server: Asterisk
Date: Mon, 16 May 2022 16:03:28 GMT
Cache-Control: no-cache, no-store
Content-type: application/json
Content-Length: 47

{"message":"Channel not in Stasis application"}

Console output, before start of snoop:

er-01*CLI> core show channels concise
PJSIP/MCM-fpyQSE-20001139-000001a8!server!s!1!Up!AppQueue!(Outgoing Line)!4466636600!!!3!36!e8fd6c89-3807-4d90-a70d-384f7591ab0d!er-01-1652716959.3363
PJSIP/erxin02-ex-01-000001a7!leaf-queue!s!8!Up!Queue!queue-name-en,b(sub_crmurl^s^1(queue-name-en,,07510680128,07510680128,English,N))!07510680128!!!3!42!e8fd6c89-3807-4d90-a70d-384f7591ab0d!er-01-1652716953.3360
er-01*CLI>
er-01*CLI>
    -- Executing [102@server:1] NoOp("PJSIP/MCM-Gvu8eu-20001020-000001a9", "") in new stack
    -- Executing [102@server:2] NoOp("PJSIP/MCM-Gvu8eu-20001020-000001a9", "ID is MCM-fpyQSE-20001139") in new stack
    -- Executing [102@server:3] Set("PJSIP/MCM-Gvu8eu-20001020-000001a9", "SNOOP_CHAN=MCM-fpyQSE-20001139") in new stack
    -- Executing [102@server:4] Set("PJSIP/MCM-Gvu8eu-20001020-000001a9", "SNOOP_TYPE=SNOOP") in new stack
    -- Executing [102@server:5] Answer("PJSIP/MCM-Gvu8eu-20001020-000001a9", "") in new stack
    -- Executing [102@server:6] Stasis("PJSIP/MCM-Gvu8eu-20001020-000001a9", "snoop") in new stack
    -- <PJSIP/MCM-Gvu8eu-20001020-000001a9> Playing 'welcome.slin' (language 'en')
er-01*CLI>

After snoop command is sent:

er-01*CLI>
er-01*CLI> core show channels concise
PJSIP/MCM-fpyQSE-20001139-000001a8!server!s!1!Up!AppQueue!(Outgoing Line)!4466636600!!!3!56!e8fd6c89-3807-4d90-a70d-384f7591ab0d!er-01-1652716959.3363
PJSIP/erxin02-ex-01-000001a7!leaf-queue!s!8!Up!Queue!queue-name-en,b(sub_crmurl^s^1(queue-name-en,,07510680128,07510680128,English,N))!07510680128!!!3!62!e8fd6c89-3807-4d90-a70d-384f7591ab0d!er-01-1652716953.3360
Snoop/er-01-1652716959.3363-0000005c!default!s!1!Up!Stasis!snoop!!!!3!6!!snoop-er-01-1652716959.3363
PJSIP/MCM-Gvu8eu-20001020-000001a9!server!102!6!Up!Stasis!snoop!MCM-Gvu8eu-20001020!!!3!7!!er-01-1652717008.3368
er-01*CLI>

After snoop ended:

er-01*CLI>
er-01*CLI> core show channels concise
PJSIP/MCM-fpyQSE-20001139-000001a8!server!s!1!Up!AppQueue!(Outgoing Line)!4466636600!!!3!73!e8fd6c89-3807-4d90-a70d-384f7591ab0d!er-01-1652716959.3363
PJSIP/erxin02-ex-01-000001a7!leaf-queue!s!8!Up!Queue!queue-name-en,b(sub_crmurl^s^1(queue-name-en,,07510680128,07510680128,English,N))!07510680128!!!3!79!e8fd6c89-3807-4d90-a70d-384f7591ab0d!er-01-1652716953.3360
Snoop/er-01-1652716959.3363-0000005c!default!s!1!Up!Stasis!snoop!!!!3!23!!snoop-er-01-1652716959.3363
er-01*CLI> 
er-01*CLI> 

Hangup caller:

er-01*CLI> 
    -- Channel PJSIP/erxin02-ex-01-000001a7 left 'simple_bridge' basic-bridge <e8fd6c89-3807-4d90-a70d-384f7591ab0d>
  == Spawn extension (leaf-queue, s, 8) exited non-zero on 'PJSIP/erxin02-ex-01-000001a7'
  == MixMonitor close filestream (mixed)
    -- Channel PJSIP/MCM-fpyQSE-20001139-000001a8 left 'simple_bridge' basic-bridge <e8fd6c89-3807-4d90-a70d-384f7591ab0d>
  == End MixMonitor Recording PJSIP/erxin02-ex-01-000001a7
er-01*CLI> 

When the snoop was working fine, I could see the following output:

er-01*CLI>
    -- Executing [102@server:1] NoOp("PJSIP/MCM-Gvu8eu-20001020-000001a4", "") in new stack
    -- Executing [102@server:2] NoOp("PJSIP/MCM-Gvu8eu-20001020-000001a4", "ID is MCM-fpyQSE-20001139") in new stack
    -- Executing [102@server:3] Set("PJSIP/MCM-Gvu8eu-20001020-000001a4", "SNOOP_CHAN=MCM-fpyQSE-20001139") in new stack
    -- Executing [102@server:4] Set("PJSIP/MCM-Gvu8eu-20001020-000001a4", "SNOOP_TYPE=SNOOP") in new stack
    -- Executing [102@server:5] Answer("PJSIP/MCM-Gvu8eu-20001020-000001a4", "") in new stack
    -- Executing [102@server:6] Stasis("PJSIP/MCM-Gvu8eu-20001020-000001a4", "snoop") in new stack
    -- <PJSIP/MCM-Gvu8eu-20001020-000001a4> Playing 'welcome.slin' (language 'en')
    -- Channel PJSIP/MCM-Gvu8eu-20001020-000001a4 joined 'simple_bridge' stasis-bridge <608348a6-3e50-4fbe-be97-aa95000d71d8>
    -- Channel Snoop/er-01-1652709485.3309-00000059 joined 'simple_bridge' stasis-bridge <608348a6-3e50-4fbe-be97-aa95000d71d8>

I don’t see any Websocket events in your response, just HTTP requests and responses. I think that your Snoop channel is actually fine, but the other channel you’re adding to the bridge at the same time isn’t in Stasis. You can confirm this by splitting your addChannel into two separate requests, one for each channel.

You may be assuming timing and things being synchronous when they are not.

What I understood by websocket is the connection between stasis program and asterisk. That is the ARI connection. The tcpdump was taken in that port. Is there some other websocket connection that is required?

As advised I have split the bridge addition into two and that part looks like the following:

            bridge = client.bridges.create(type='mixing')
            bridge.addChannel(channel=[snoop_chan.id])
            playback = channel.play(media='sound:welcome')
            bridge.addChannel(channel=[channel.id])

The HTTP command sent by the stasis program is as follows:

POST /ari/channels/er-01-1652882734.3844/snoop?spy=both&app=snoop&snoopId=snoop-er-01-1652882734.3844&whisper=none HTTP/1.1
Host: localhost:8088
Connection: keep-alive
Accept-Encoding: gzip, deflate
Accept: */*
User-Agent: python-requests/2.27.1
Content-Length: 0
Authorization: Basic dXNlci1uZnVpaTpJb01JN1dBV09U

HTTP/1.1 200 OK
Server: Asterisk
Date: Wed, 18 May 2022 14:06:01 GMT
Cache-Control: no-cache, no-store
Content-type: application/json
Content-Length: 329

{
	"id": "snoop-er-01-1652882734.3844",
	"name": "Snoop/er-01-1652882734.3844-0000006b",
	"state": "Up",
	"caller": {
		"name": "",
		"number": ""
	},
	"connected": {
		"name": "",
		"number": ""
	},
	"accountcode": "",
	"dialplan": {
		"context": "default",
		"exten": "s",
		"priority": 1,
		"app_name": "",
		"app_data": ""
	},
	"creationtime": "2022-05-18T19:36:01.909+0530",
	"language": "en"
}

POST /ari/bridges?type=mixing HTTP/1.1
Host: localhost:8088
Connection: keep-alive
Accept-Encoding: gzip, deflate
Accept: */*
User-Agent: python-requests/2.27.1
Content-Length: 0
Authorization: Basic dXNlci1uZnVpaTpJb01JN1dBV09U

HTTP/1.1 200 OK
Server: Asterisk
Date: Wed, 18 May 2022 14:06:01 GMT
Cache-Control: no-cache, no-store
Content-type: application/json
Content-Length: 232

{
	"id": "71a5b2d3-b2c9-4c1d-a5fb-074371171aef",
	"technology": "simple_bridge",
	"bridge_type": "mixing",
	"bridge_class": "stasis",
	"creator": "Stasis",
	"name": "",
	"channels": [],
	"creationtime": "2022-05-18T19:36:01.920+0530",
	"video_mode": "talker"
}

POST /ari/bridges/71a5b2d3-b2c9-4c1d-a5fb-074371171aef/addChannel?channel=snoop-er-01-1652882734.3844 HTTP/1.1
Host: localhost:8088
Connection: keep-alive
Accept-Encoding: gzip, deflate
Accept: */*
User-Agent: python-requests/2.27.1
Content-Length: 0
Authorization: Basic dXNlci1uZnVpaTpJb01JN1dBV09U

HTTP/1.1 422 Unprocessable Entity
Server: Asterisk
Date: Wed, 18 May 2022 14:06:01 GMT
Cache-Control: no-cache, no-store
Content-type: application/json
Content-Length: 47

{"message":"Channel not in Stasis application"}

I am getting error when adding the snoop channel itself.

Also the context in the snoop command is:

	"dialplan": {
		"context": "default",
		"exten": "s",
		"priority": 1,
		"app_name": "",
		"app_data": ""
	}

There is no default context, could that be a problem? What should be the value there?

Another observation is that after hanging up the snoop call the snoop channel remains in the asterisk

After snoop command
===================
er-01*CLI>
er-01*CLI>
    -- Executing [102@server:1] NoOp("PJSIP/MCM-Gvu8eu-20001020-000001e4", "") in new stack
    -- Executing [102@server:2] NoOp("PJSIP/MCM-Gvu8eu-20001020-000001e4", "ID is MCM-fpyQSE-20001139") in new stack
    -- Executing [102@server:3] Set("PJSIP/MCM-Gvu8eu-20001020-000001e4", "SNOOP_CHAN=MCM-fpyQSE-20001139") in new stack
    -- Executing [102@server:4] Set("PJSIP/MCM-Gvu8eu-20001020-000001e4", "SNOOP_TYPE=SNOOP") in new stack
    -- Executing [102@server:5] Answer("PJSIP/MCM-Gvu8eu-20001020-000001e4", "") in new stack
    -- Executing [102@server:6] Stasis("PJSIP/MCM-Gvu8eu-20001020-000001e4", "snoop") in new stack
er-01*CLI>
er-01*CLI>
er-01*CLI> core show channels concise
PJSIP/MCM-fpyQSE-20001139-000001e3!server!s!1!Up!AppQueue!(Outgoing Line)!4466636600!!!3!38!2083f3fc-36b6-4949-8258-0dc9751ad1fe!er-01-1652882734.3844
PJSIP/erxin02-ex-01-000001e2!leaf-queue!s!8!Up!Queue!queue-name-en,b(sub_crmurl^s^1(queue-name-en,,9327815015,97815015,English,N))!9327815015!!!3!51!2083f3fc-36b6-4949-8258-0dc9751ad1fe!er-01-1652882722.3841
PJSIP/MCM-Gvu8eu-20001020-000001e4!server!102!6!Up!Stasis!snoop!MCM-Gvu8eu-20001020!!!3!11!!er-01-1652882761.3849
Snoop/er-01-1652882734.3844-0000006b!default!s!1!Up!Stasis!snoop!!!!3!11!!snoop-er-01-1652882734.3844
er-01*CLI>
er-01*CLI>


After snoop stopped
=======================
er-01*CLI>
er-01*CLI>
er-01*CLI> core show channels concise
PJSIP/MCM-fpyQSE-20001139-000001e3!server!s!1!Up!AppQueue!(Outgoing Line)!4466636600!!!3!79!2083f3fc-36b6-4949-8258-0dc9751ad1fe!er-01-1652882734.3844
PJSIP/erxin02-ex-01-000001e2!leaf-queue!s!8!Up!Queue!queue-name-en,b(sub_crmurl^s^1(queue-name-en,,9327815015,9327815015,Malayalam,N))!9327815015!!!3!92!2083f3fc-36b6-4949-8258-0dc9751ad1fe!er-01-1652882722.3841
PJSIP/MCM-Gvu8eu-20001020-000001e4!server!102!6!Up!Stasis!snoop!MCM-Gvu8eu-20001020!!!3!52!!er-01-1652882761.3849
Snoop/er-01-1652882734.3844-0000006b!default!s!1!Up!Stasis!snoop!!!!3!52!!snoop-er-01-1652882734.3844
er-01*CLI> 
er-01*CLI> 
er-01*CLI> 

It is a websocket connection, but everything you’re providing have been HTTP requests and responses which aren’t part of a websocket - not the ARI events that come over the websocket, which give you information on the state of things. The reason it would be good to see them is many ARI requests are asynchronous so until you get the respective event you can’t do anything.

How did you try to hang up the Snoop channel? If you do it from the console does it work?

While I figure out how to inspect data from the websocket, here is lil some thing I saw in twitter:

A programmer had a problem. He thought — “I know, I’ll use async!”

has problems Now . two he

There’s pros and cons to both, for something like ARI using asynchronous made more sense. For your particular use case it MAY have been possible to get away with synchronous, but that would quickly change depending on usage.

I have changed the order in which the channels are getting added to bridge and looks like its working:

            bridge = client.bridges.create(type='mixing')
            bridge.addChannel(channel=[channel.id])
            playback = channel.play(media='sound:welcome')
            bridge.addChannel(channel=[snoop_chan.id])

Now the snoop chanal is added last. Will observe for some more time before declaring it as working.

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.