2.26 + Asterisk Action Buttons not working

[jlitwicki]

We recently upgraded to FOP 2.26 using Asterisk and the Action Bar on the client now stops responding after one use. After the first AMI command, nothing is sent to the manager on 5038 after the first command. How can we troubleshoot and resolve this ASAP?

[nicolas]

You can start fop2 in full debug as described here:

View Post 1322

[jlitwicki]

That's fine and good, but I don't see anywhere in this debug how to troubleshoot the manager connection or anything related to the Action Bar.

** COLLECT INCLUDES fop2.cfg , tipo server

** READ SERVER CONFIG
** READ SERVER CONFIG - archivo fop2.cfg
** READ SERVER calling COLLECT INCLUDES archivo btns_jimbo.cfg context JIMBO!buttons

** COLLECT INCLUDES btns_jimbo.cfg , tipo JIMBO!buttons

** READ SERVER calling COLLECT INCLUDES archivo btns_test_1.cfg context TEST_1!buttons

** COLLECT INCLUDES btns_test_1.cfg , tipo TEST_1!buttons

** READ SERVER calling COLLECT INCLUDES archivo btns_pat.cfg context PAT!buttons

** COLLECT INCLUDES btns_pat.cfg , tipo PAT!buttons

** READ SERVER calling COLLECT INCLUDES archivo btns_test_panel.cfg context TEST_PANEL!buttons

** COLLECT INCLUDES btns_test_panel.cfg , tipo TEST_PANEL!buttons

** READ SERVER calling COLLECT INCLUDES archivo btns_demo.cfg context DEMO!buttons

** COLLECT INCLUDES btns_demo.cfg , tipo DEMO!buttons

** READ SERVER calling COLLECT INCLUDES archivo btns_Jake_Test.cfg context JAKE_TEST!buttons

** COLLECT INCLUDES btns_Jake_Test.cfg , tipo JAKE_TEST!buttons

** READ SERVER calling COLLECT INCLUDES archivo btns_training.cfg context TRAINING!buttons

** COLLECT INCLUDES btns_training.cfg , tipo TRAINING!buttons

** READ SERVER calling collect_includes btns_jimbo.cfg

** COLLECT INCLUDES btns_jimbo.cfg , tipo JIMBO!buttons

** btns_jimbo.cfg already included

** READ SERVER calling collect_includes btns_test_1.cfg

** COLLECT INCLUDES btns_test_1.cfg , tipo TEST_1!buttons

** btns_test_1.cfg already included

** READ SERVER calling collect_includes btns_pat.cfg

** COLLECT INCLUDES btns_pat.cfg , tipo PAT!buttons

** btns_pat.cfg already included

** READ SERVER calling collect_includes btns_test_panel.cfg

** COLLECT INCLUDES btns_test_panel.cfg , tipo TEST_PANEL!buttons

** btns_test_panel.cfg already included

** READ SERVER calling collect_includes btns_demo.cfg

** COLLECT INCLUDES btns_demo.cfg , tipo DEMO!buttons

** btns_demo.cfg already included

** READ SERVER calling collect_includes btns_Jake_Test.cfg

** COLLECT INCLUDES btns_Jake_Test.cfg , tipo JAKE_TEST!buttons

** btns_Jake_Test.cfg already included

** READ SERVER calling collect_includes btns_training.cfg

** COLLECT INCLUDES btns_training.cfg , tipo TRAINING!buttons

** btns_training.cfg already included

** READ BUTTONS CONFIG btns_jimbo.cfg para contexto JIMBO
** READ BUTTONS CONFIG btns_test_1.cfg para contexto TEST_1
** READ BUTTONS CONFIG btns_pat.cfg para contexto PAT
** READ BUTTONS CONFIG btns_test_panel.cfg para contexto TEST_PANEL
** READ BUTTONS CONFIG btns_demo.cfg para contexto DEMO
** READ BUTTONS CONFIG btns_Jake_Test.cfg para contexto JAKE_TEST
** READ BUTTONS CONFIG btns_training.cfg para contexto TRAINING

** GENERA CONFIG START
** GENERA CONFIG - GENERAL
** GENERA CONFIG - TRAINING
** GENERA CONFIG - JIMBO
** GENERA CONFIG - PAT
** GENERA CONFIG - DEMO
** GENERA CONFIG - TEST_PANEL
** GENERA CONFIG - TEST_1
** GENERA CONFIG - JAKE_TEST
** GENERA CONFIG END

Can't listen to port 4445

pgrep fop2_server returns a pid, yet the same issue remains. After using the action bar once, the manager connection fails until FOP2 is restarted.

[nicolas]

You must stop the fop2 service and start in debug mode as instructed in the post, your log file shows that fop2 could not start at all because it was already started and binding to port 4445.

So, first stop your current fop2:

service fop2 stop

Then start the capture

[sdolloff]

this was being caused by the branch of astmanproxy that we are using returning duplicate Server: fields on Response and Event message such as this:

127.0.0.1 <- Server: localhost
127.0.0.1 <- Server: 0

to fix it i had to patch astmanproxy to not add the header, but you might want to fix your script to not crash on multiple server fields.

edited debug below, let me know if you want or need more info.

1. first originate

** MAIN AMI event received...
** MAIN Processing command received from flash clients...

209.XXX.XXX.XXX <= <msg data="3|originate|4|0f26945d6535b67424e49bdbefa0XXXX" />

-- PROCESS_FLASH_COMMAND origen 3 accion originate destino 4 password 0f26945d6535b67424e49bdbefa0XXXX

VALIDAR USUARIO 256@TRAINING

VALIDAR USUARIO 256 OK con clave regular (209.XXXX.XXXX.XXXX)

Validation ok, have all permissions for all buttons (0) 4

GET SERVER para SIP/256 = 0

ORIGINATE:
Action: Originate
Channel: SIP/256
Exten: 129
Context: outbound
Priority: 1
CallerID: Steve Test: 256 <256>
Async: True

2. extension state change

127.0.0.1 <- Event: Newstate
127.0.0.1 <- Privilege: call,all
127.0.0.1 <- Channel: SIP/256-00000004
127.0.0.1 <- ChannelState: 6
127.0.0.1 <- ChannelStateDesc: Up
127.0.0.1 <- CallerIDNum: 256
127.0.0.1 <- CallerIDName: Steve Test: 256
127.0.0.1 <- ConnectedLineNum: 256
127.0.0.1 <- ConnectedLineName: Steve Test: 256
127.0.0.1 <- Uniqueid: 1343249677.4
127.0.0.1 <- Server: localhost
127.0.0.1 <- Server: 0

** MAIN AMI event received...
** MAIN There's an 'Event' in the event block
** MAIN Event detected block_count = 1 (Event: Newstate)
** MAIN There are 1 blocks for processing
** MAIN Answer block cleared

** DIGEST_EVENT: start

** PROCESA_BLOQUE 0
** PROCESA_BLOQUE NEWSTATE ARRAY(0xbb578f4)

It's blessed into class Extension

State UP para canal SIP/256-00000004 en slot 1

GETSTATE para SIP/256-00000004 estaba definido y devuelve UP

GET CALL SLOT para SIP/256-00000004 definido, devuelvo 1

SET SECONDS SIP/256-00000004 = 0

GET SECONDS devuelve 0

SET SERVER para SIP/256 = ARRAY(0xbb578f4)

3. 2nd originate

** MAIN AMI event received...
** MAIN Processing command received from flash clients...

209.242.9.134 <= <msg data="3|originate|4|0f26945d6535b67424e49bdbefa0XXXX" />

-- PROCESS_FLASH_COMMAND origen 3 accion originate destino 4 password 0f26945d6535b67424e49bdbefa0XXXX

VALIDAR USUARIO 256@TRAINING

VALIDAR USUARIO 256 OK con clave regular (209.XXX.XXX.XXXX)

Validation ok, have all permissions for all buttons (0) 4

GET SERVER para SIP/256 = ARRAY(0xbb578f4)

ORIGINATE:
Action: Originate
Channel: SIP/256
Exten: 129
Context: outbound
Priority: 1
CallerID: Steve Test: 256 <256>
Async: True

Use of reference "ARRAY(0xbb578f4)" as array index at script/fop2_server.pl line 8246.
Use of uninitialized value in hash element at script/fop2_server.pl line 12129.
Use of uninitialized value in concatenation (.) or string at script/fop2_server.pl line 12133.

Cannot send command to (unauthenticated or connection failed)

Exiting...

[nicolas]

Thanks for the detailed post. Not sure how can I do something about it, because the problem seems to be the non numeric server line instead of just a duplicate server line. FOP2 has its own server hash/array and it expects to be an index number, but your manager proxy adds a second server line with a hostname.

Adding an option to remove headers from Ami can be done, but it could be pretty much overkill, taking lots of cpu cicles. Its a hard call.