Timed out waiting for challenge

  1. 10 years ago

    What am I trying to do:

    root@asterisk1:/etc/asterisk# /usr/local/fop2/fop2_server --test
    Flash Operator Panel 2 - License file fop2.lic not found.
    Running in Demo Mode
    EV: error in callback (ignoring): Unknown warnings category 'FOP2::AMI2' at /tmp/par-root/cache-a35c6b2917b72b70bb45f0e4dec9f6353395ad95/inc/lib/FOP2/AMI2.pm line 311
    Failed to connect to asterisk - 127.0.0.1:5038
    Error Message: Timed out waiting for challenge

    System environment:

    Debian GNU/Linux 7 asterisk1 3.2.0-4-amd64 #1 SMP Debian 3.2.51-1 x86_64 GNU/Linux
    Asterisk 12.0.0 built by root @ asterisk1 on a x86_64 running Linux on 2014-01-14 15:37:23 UTC

    NOT part of a package / freepbx etc

    Ports:

    Active Internet connections (servers and established)
    Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
    tcp        0      0 127.0.0.1:5038          0.0.0.0:*               LISTEN      21457/asterisk
    tcp        0      0 0.0.0.0:2000            0.0.0.0:*               LISTEN      21457/asterisk

    Manager.conf:

    [general]
    enabled = yes
    port = 5038
    bindaddr = 127.0.0.1
    
    [admin]
    secret = helloworld
    read = system,call,log,verbose,agent,user,config,dtmf,reporting,cdr,dialplan
    write = system,call,agent,user,config,command,reporting,originate,message

    fop2.cfg

    ; AMI definitions
    manager_host=127.0.0.1
    manager_port=5038
    manager_user=admin
    manager_secret=helloworld
    ;event_mask=agent,call,command,system,user,dialplan

    Raw traffic:

    Local telnet session with manual input (>):

    < Asterisk Call Manager/2.0.0
    > Action:Login
    > Username:admin
    > Secret:helloworld
    
    < Response: Success
    < Message: Authentication accepted
    
    < Event: FullyBooted
    < Privilege: system,all
    < Status: Fully Booted

    This is the traffic on LO(calhost) TCP stream with the demo being executed, yes thats it.

    > AuthType: md5
    > Action: Challenge
    > ActionID: 1
    
    < Asterisk Call Manager/2.0.0
    < Response: Success
    < ActionID: 1
    < Challenge: 212179247

    What am i doing wrong?

  2. admin

    24 Jan 2014 Administrator

    Try to run fop2 in debug mode:

    /usr/local/fop2/fop2_server -X 3

    What do you see there? Also, what asterisk version are you using?

  3. As quoted above:
    Asterisk 12.0.0 built by root @ asterisk1 on a x86_64 running Linux on 2014-01-14 15:37:23 UTC

    Regarding the results of the commandline execution, nothing unexpected, the output was already verified on TCP level.

    Flash Operator Panel 2 - License file fop2.lic not found.
    ** SSL Certificate File cannot be read (/etc/pki/tls/certs/localhost.crt). Disabling TLS.
    
    ** SSL Certificate Private Key File cannot be read (/etc/pki/tls/private/localhost.key). Disabling TLS.
    
    127.0.0.1            -> AuthType: md5
    127.0.0.1            -> Action: Challenge
    127.0.0.1            -> ActionID: 1
    
    EV: error in callback (ignoring): Unknown warnings category 'FOP2::AMI2' at /tmp/par-root/cache-a35c6b2917b72b70bb45f0e4dec9f6353395ad95/inc/lib/FOP2/AMI2.pm line 311
    Failed to connect to asterisk - 127.0.0.1:5038
    Error Message: Timed out waiting for challenge
    Error occured on socket FOP2::AMI2=HASH(0x326b310)
    CLEAN activity for buttons for server 127.0.0.1 as the connection was lost
    
    127.0.0.1            -> AuthType: md5
    127.0.0.1            -> Action: Challenge
    127.0.0.1            -> ActionID: 1
    
    EV: error in callback (ignoring): Unknown warnings category 'FOP2::AMI2' at /tmp/par-root/cache-a35c6b2917b72b70bb45f0e4dec9f6353395ad95/inc/lib/FOP2/AMI2.pm line 311
    Failed to connect to asterisk - 127.0.0.1:5038
    Error Message: Timed out waiting for challenge
    Error occured on socket FOP2::AMI2=HASH(0x326b760)
    CLEAN activity for buttons for server 127.0.0.1 as the connection was lost
    
    127.0.0.1            -> AuthType: md5
    127.0.0.1            -> Action: Challenge
    127.0.0.1            -> ActionID: 1
    
    EV: error in callback (ignoring): Unknown warnings category 'FOP2::AMI2' at /tmp/par-root/cache-a35c6b2917b72b70bb45f0e4dec9f6353395ad95/inc/lib/FOP2/AMI2.pm line 311
    ^CRemoving /var/www/html/fop2/fop2-variablesGENERAL.txt...
    
    Disconnecting from settings DB
    
    Exiting...

    Can you help me any further than this?

  4. admin

    27 Jan 2014 Administrator

    I am helping you all I can in a very limited medium like this forum. It is really hard and slow to troubleshoot interactive protocols via forum posts.

    I do not see the challenge response in the fop2 capture log, so it is not the same you had before. For some reason, there is no challenge response captured/received by fop2.

    I do notice a difference that might lead to problems, the Call Manager version advertisement includes a 3 digit, compare this:

    Asterisk Call Manager/1.3

    to

    Asterisk Call Manager/2.0.0

    That *could* be an issue, but I have to test it out locally/further.

  5. Nicolás, I understand your situation. We really appreciate the help and we are trying to be as verbose as we can on this.

    We're building a test setup to implement in our callcenter/support setup.

    If this issue is indeed the one you suggest, this problem will persist in all future versions of Asterisk and it is worth looking into. Could you post your findings and a possible fix?

  6. admin

    30 Jan 2014 Administrator

    Try downloading http://download3.fop2.com/fop2-2.27-debian-x86_64.tgz, extract it and replace your fop2_server binary with the one from the tarball, and run it in debug level 3 ( -X 3)

    Best regards,

  7. The resulting output:

    root@asterisk1:~# wget http://download3.fop2.com/fop2-2.27-debian-x86_64.tgz
    --2014-01-30 13:14:00--  http://download3.fop2.com/fop2-2.27-debian-x86_64.tgz
    Resolving download3.fop2.com (download3.fop2.com)... 69.85.88.167
    Connecting to download3.fop2.com (download3.fop2.com)|69.85.88.167|:80... connected.
    HTTP request sent, awaiting response... 200 OK
    Length: 8566172 (8.2M) [application/octet-stream]
    Saving to: `fop2-2.27-debian-x86_64.tgz'
    
    100%[===================================================================>] 8,566,172   1.92M/s   in 5.1s
    
    2014-01-30 13:14:05 (1.61 MB/s) - `fop2-2.27-debian-x86_64.tgz' saved [8566172/8566172]
    
    root@asterisk1:~# tar -xvzf fop2-2.27-debian-x86_64.tgz
    [..]
    fop2/server/fop2_server
    root@asterisk1:~# cp fop2/server/fop2_server /usr/local/fop2/fop2_server
    root@asterisk1:~# /usr/local/fop2/fop2_server -X 3
    Flash Operator Panel 2 - License file fop2.lic not found.
    ** SSL Certificate File cannot be read (/etc/pki/tls/certs/localhost.crt). Disabling TLS.
    
    ** SSL Certificate Private Key File cannot be read (/etc/pki/tls/private/localhost.key). Disabling TLS.
    
    127.0.0.1            -> AuthType: md5
    127.0.0.1            -> Action: Challenge
    127.0.0.1            -> ActionID: 1
    
    127.0.0.1            <- Response: Success
    127.0.0.1            <- ActionID: 1
    127.0.0.1            <- Challenge: 518046693
    
    127.0.0.1            -> AuthType: md5
    127.0.0.1            -> Events: on
    127.0.0.1            -> Username: admin
    127.0.0.1            -> Action: login
    127.0.0.1            -> Key: [*Redacted*]
    127.0.0.1            -> ActionID: 2
    
    127.0.0.1            <- Response: Success
    127.0.0.1            <- ActionID: 2
    127.0.0.1            <- Message: Authentication accepted
    
    127.0.0.1            -> Action: Status
    
    127.0.0.1            -> Action: QueueStatus
    
    127.0.0.1            -> Action: Agents
    
    127.0.0.1            -> Action: SipPeers
    
    127.0.0.1            -> Action: IaxPeers
    
    127.0.0.1            -> Action: ParkedCalls
    
    127.0.0.1            -> Command: database show fop2notes
    127.0.0.1            -> Action: Command
    127.0.0.1            -> ActionID: 3
    
    127.0.0.1            -> Command: database show fop2state
    127.0.0.1            -> Action: Command
    127.0.0.1            -> ActionID: 4
    
    127.0.0.1            -> Action: CoreSettings
    127.0.0.1            -> ActionID: 5
    
    127.0.0.1            <- Event: FullyBooted
    127.0.0.1            <- Privilege: system,all
    127.0.0.1            <- Status: Fully Booted
    
    127.0.0.1            <- Response: Success
    127.0.0.1            <- Message: Channel status will follow
    
    127.0.0.1            <- Event: StatusComplete
    127.0.0.1            <- Items: 0
    
    127.0.0.1            <- Response: Success
    127.0.0.1            <- Message: Queue status will follow
    
    127.0.0.1            <- Event: QueueStatusComplete
    
    127.0.0.1            <- Response: Success
    127.0.0.1            <- Message: Agents will follow
    
    127.0.0.1            <- Event: AgentsComplete
    
    127.0.0.1            <- Response: Success
    127.0.0.1            <- EventList: start
    127.0.0.1            <- Message: Peer status list will follow
    
    127.0.0.1            <- Event: PeerlistComplete
    127.0.0.1            <- EventList: Complete
    127.0.0.1            <- ListItems: 0
    
    127.0.0.1            <- Response: Success
    127.0.0.1            <- EventList: start
    127.0.0.1            <- Message: Peer status list will follow
    
    127.0.0.1            <- Event: PeerEntry
    127.0.0.1            <- Channeltype: IAX2
    127.0.0.1            <- ObjectName: demo/asterisk
    127.0.0.1            <- ChanObjectType: peer
    127.0.0.1            <- IPaddress: [*Redacted*]
    127.0.0.1            <- IPport: [*Redacted*]
    127.0.0.1            <- Dynamic: no
    127.0.0.1            <- Trunk: no
    127.0.0.1            <- Encryption: no
    127.0.0.1            <- Status: Unmonitored
    127.0.0.1            <- Description: Demo System At Digium
    
    127.0.0.1            <- Event: PeerlistComplete
    127.0.0.1            <- EventList: Complete
    127.0.0.1            <- ListItems: 1
    
    127.0.0.1            <- Response: Success
    127.0.0.1            <- Message: Parked calls will follow
    
    127.0.0.1            <- Event: ParkedCallsComplete
    127.0.0.1            <- Total: 0
    
    127.0.0.1            <- Response: Follows
    127.0.0.1            <- Privilege: Command
    127.0.0.1            <- ActionID: 3
    127.0.0.1            <- 0 results found.
    --END COMMAND--
    
    127.0.0.1            <- Response: Follows
    127.0.0.1            <- Privilege: Command
    127.0.0.1            <- ActionID: 4
    127.0.0.1            <- 0 results found.
    --END COMMAND--
    
    127.0.0.1            <- Response: Success
    127.0.0.1            <- ActionID: 5
    127.0.0.1            <- AMIversion: 2.0.0
    127.0.0.1            <- AsteriskVersion: 12.0.0
    127.0.0.1            <- SystemName:
    127.0.0.1            <- CoreMaxCalls: 0
    127.0.0.1            <- CoreMaxLoadAvg: 0.000000
    127.0.0.1            <- CoreRunUser:
    127.0.0.1            <- CoreRunGroup:
    127.0.0.1            <- CoreMaxFilehandles: 0
    127.0.0.1            <- CoreRealTimeEnabled: No
    127.0.0.1            <- CoreCDRenabled: Yes
    127.0.0.1            <- CoreHTTPenabled: No

    This seems to be succesful.

    When running as server daemon I get prompted the Login details now. It seems that the problem is solved!
    Just out of curiousity, was the problem the response header?

    Thank you for this, we can now proceed with implementation tests :D

  8. admin

    30 Jan 2014 Administrator

    Yes, the problem was the AMI Version response header.

or Sign Up to reply!