search

tropo / PhonoSDK

Phono.com - The jQuery Phone API
http://phono.com
Other
131 stars 63 forks source link

Java Phono - There is a noise when answering the call from Blink #9

Closed javen closed 12 years ago

javen commented 12 years ago

phonosdk-0.3 build #117 on Hudson

Test Scenario: call from Blink to Phono(Java)

Test Platform: IE7/FF3.6 on XP, IE8/FF3.6 on Win7

Steps: 1) Add a New Phono using Java for audio; 2) Call from Phono to Blink; 3) Checkpoint1: The conversation is good; 4) Call from Blink to Phono; 5) Answer the call, and say words from each side

Expected result: Conversation can be established, and will be heared from each other.

Actually result: There is a noise heared from Phono side, and can not heared anything from each other.

Note: FF7 and Salaris5 on Mac OSX 10.6 are ok

javen commented 12 years ago

Here are logs from Developer Tool on IE8: LOG: Phono Logger Initialized LOG: 15:59:06.364 DEBUG - [STROPHE] CORS with IE LOG: 15:59:06.364 DEBUG - [INVOKE] Phono.connect() LOG: 15:59:06.365 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests LOG: 15:59:06.365 DEBUG - [STROPHE] request id 8.0 posting LOG: 15:59:06.366 DEBUG - WIRE LOG: 15:59:24.012 DEBUG - [STROPHE] Request 7 timed out, over 66 seconds since last activity LOG: 15:59:24.012 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests LOG: 15:59:24.012 DEBUG - [STROPHE] request id 9.1 posting LOG: 15:59:24.013 DEBUG - WIRE LOG: 16:00:12.438 DEBUG - [STROPHE] Request 8 timed out, over 66 seconds since last activity LOG: 16:00:12.438 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests LOG: 16:00:12.439 DEBUG - [STROPHE] request id 10.1 posting LOG: 16:00:12.439 DEBUG - WIRE LOG: 16:00:30.076 DEBUG - [STROPHE] Request 9 timed out, over 66 seconds since last activity LOG: 16:00:30.076 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests LOG: 16:00:30.076 DEBUG - [STROPHE] request id 11.2 posting LOG: 16:00:30.077 DEBUG - WIRE LOG: 16:00:37.088 DEBUG - [STROPHE] request id 10.2 state changed to 4 LOG: 16:00:37.088 DEBUG - [STROPHE] removing request LOG: 16:00:37.088 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:00:37.088 DEBUG - [STROPHE] request id 10 should now be removed LOG: 16:00:37.088 DEBUG - [STROPHE] request id 10.2 got 200 LOG: 16:00:37.088 DEBUG - [STROPHE] _connect_cb was called LOG: 16:00:37.088 DEBUG - WIRE PLAINANONYMOUS/stream:features LOG: 16:00:37.089 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:00:37.189 DEBUG - [STROPHE] request id 12.0 posting LOG: 16:00:37.190 DEBUG - WIRE LOG: 16:00:37.811 DEBUG - [STROPHE] request id 12.1 state changed to 4 LOG: 16:00:37.811 DEBUG - [STROPHE] removing request LOG: 16:00:37.811 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:00:37.811 DEBUG - [STROPHE] request id 12 should now be removed LOG: 16:00:37.812 DEBUG - [STROPHE] request id 12.1 got 200 LOG: 16:00:37.812 DEBUG - WIRE LOG: 16:00:37.812 DEBUG - [STROPHE] SASL authentication succeeded. LOG: 16:00:37.812 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:00:37.908 DEBUG - [STROPHE] request id 13.0 posting LOG: 16:00:37.909 DEBUG - WIRE LOG: 16:00:38.497 DEBUG - [STROPHE] request id 13.1 state changed to 4 LOG: 16:00:38.497 DEBUG - [STROPHE] removing request LOG: 16:00:38.497 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:00:38.497 DEBUG - [STROPHE] request id 13 should now be removed LOG: 16:00:38.498 DEBUG - [STROPHE] request id 13.1 got 200 LOG: 16:00:38.498 DEBUG - WIRE /stream:features LOG: 16:00:38.501 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:00:38.614 DEBUG - [STROPHE] request id 14.0 posting LOG: 16:00:38.615 DEBUG - WIRE LOG: 16:00:38.692 DEBUG - [STROPHE] request id 11.3 state changed to 4 LOG: 16:00:38.692 DEBUG - [STROPHE] removing request LOG: 16:00:38.692 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:00:38.692 DEBUG - [STROPHE] request id 11 should now be removed LOG: 16:00:38.692 DEBUG - [STROPHE] request id 11.3 got 200 LOG: 16:00:38.693 DEBUG - WIRE LOG: 16:00:38.722 DEBUG - [STROPHE] no requests during idle cycle, sending blank request LOG: 16:00:38.723 DEBUG - [STROPHE] request id 15.0 posting LOG: 16:00:38.723 DEBUG - WIRE LOG: 16:00:39.216 DEBUG - [STROPHE] request id 14.1 state changed to 4 LOG: 16:00:39.217 DEBUG - [STROPHE] removing request LOG: 16:00:39.217 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:00:39.217 DEBUG - [STROPHE] request id 14 should now be removed LOG: 16:00:39.217 DEBUG - [STROPHE] request id 14.1 got 200 LOG: 16:00:39.217 DEBUG - WIRE jid>bcb2a5c9-7884-4a6a-a57c-1c72995ec42a@gw114.phono.com/voxeo</jid LOG: 16:00:39.218 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:00:39.329 DEBUG - [STROPHE] request id 16.0 posting LOG: 16:00:39.330 DEBUG - WIRE LOG: 16:00:39.948 DEBUG - [STROPHE] request id 16.1 state changed to 4 LOG: 16:00:39.948 DEBUG - [STROPHE] removing request LOG: 16:00:39.948 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:00:39.949 DEBUG - [STROPHE] request id 16 should now be removed LOG: 16:00:39.949 DEBUG - [STROPHE] request id 16.1 got 200 LOG: 16:00:39.949 DEBUG - WIRE LOG: 16:00:39.950 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:00:39.950 DEBUG - [INVOKE] Phono.handleConnect() LOG: 16:00:40.197 DEBUG - [STROPHE] request id 17.0 posting LOG: 16:00:40.198 DEBUG - WIRE C17D167F-09C6-4E4C-A3DD-2025D48BA243 LOG: 16:00:40.809 DEBUG - [STROPHE] request id 17.1 state changed to 4 LOG: 16:00:40.809 DEBUG - [STROPHE] removing request LOG: 16:00:40.809 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:00:40.809 DEBUG - [STROPHE] request id 17 should now be removed LOG: 16:00:40.809 DEBUG - [STROPHE] request id 17.1 got 200 LOG: 16:00:40.809 DEBUG - WIRE LOG: 16:00:40.857 DEBUG - [STROPHE] no requests during idle cycle, sending blank request LOG: 16:00:40.857 DEBUG - [STROPHE] request id 18.0 posting LOG: 16:00:40.858 DEBUG - WIRE LOG: 16:00:42.954 INFO - [EVENT] ready[undefined] LOG: 16:00:42.954 DEBUG - [INVOKE] Phono.onready([object Object],undefined) LOG: 16:00:42.956 DEBUG - [INVOKE] JavaAudio.audioInDevices() LOG: devices are :Let my system choose,Primary Sound Capture Driver,Microphone (High Definition Aud LOG: [Phono2] Phono loaded LOG: 16:00:42.961 DEBUG - [INVOKE] JavaAudio.permission() LOG: [Phono2] [Call2] Calling phono@sip2sip.info LOG: 16:01:19.760 DEBUG - [INVOKE] Phone.dial(phono@sip2sip.info,[object Object]) LOG: 16:01:19.760 DEBUG - [INVOKE] Phone.headset() LOG: 16:01:19.760 DEBUG - [INVOKE] JavaAudio.transport() LOG: 16:01:19.806 DEBUG - [INVOKE] Phone.ringTone() LOG: 16:01:19.806 DEBUG - [INVOKE] JavaAudio.play(ringtones/Diggztone_Marimba.mp3) LOG: 16:01:20.068 DEBUG - [INVOKE] Phone.ringbackTone() LOG: 16:01:20.068 DEBUG - [INVOKE] JavaAudio.play(ringtones/ringback-us.mp3) LOG: 16:01:20.114 DEBUG - [INVOKE] Phone.audioInput() LOG: 16:01:20.114 DEBUG - [INVOKE] JavaAudio.audioIn(System Default) LOG: 16:01:20.115 DEBUG - [INVOKE] Phone.beforeDial([object Object]) LOG: 16:01:20.115 DEBUG - [INVOKE] Call.start() LOG: 16:01:20.116 DEBUG - [INVOKE] JavaAudio.codecs() LOG: 16:01:20.143 DEBUG - [INVOKE] Phone.wideband() LOG: 16:01:20.144 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests LOG: 16:01:20.144 DEBUG - [STROPHE] _processRequest: first request has readyState of 2 LOG: 16:01:20.252 DEBUG - [STROPHE] request id 19.0 posting LOG: 16:01:20.252 DEBUG - WIRE LOG: 16:01:20.940 DEBUG - [STROPHE] request id 18.1 state changed to 4 LOG: 16:01:20.940 DEBUG - [STROPHE] removing request LOG: 16:01:20.940 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests LOG: 16:01:20.941 DEBUG - [STROPHE] _processRequest: first request has readyState of 2 LOG: 16:01:20.941 DEBUG - [STROPHE] request id 18 should now be removed LOG: 16:01:20.941 DEBUG - [STROPHE] request id 18.1 got 200 LOG: 16:01:20.941 DEBUG - WIRE LOG: 16:01:20.970 DEBUG - [STROPHE] request id 19.1 state changed to 4 LOG: 16:01:20.970 DEBUG - [STROPHE] removing request LOG: 16:01:20.970 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:01:20.971 DEBUG - [STROPHE] request id 19 should now be removed LOG: 16:01:20.971 DEBUG - [STROPHE] request id 19.1 got 200 LOG: 16:01:20.971 DEBUG - WIRE LOG: 16:01:21.011 DEBUG - [STROPHE] no requests during idle cycle, sending blank request LOG: 16:01:21.011 DEBUG - [STROPHE] request id 20.0 posting LOG: 16:01:21.012 DEBUG - WIRE LOG: 16:01:23.642 DEBUG - [STROPHE] request id 20.1 state changed to 4 LOG: 16:01:23.642 DEBUG - [STROPHE] removing request LOG: 16:01:23.643 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:01:23.643 DEBUG - [STROPHE] request id 20 should now be removed LOG: 16:01:23.643 DEBUG - [STROPHE] request id 20.1 got 200 LOG: 16:01:23.643 DEBUG - WIRE LOG: 16:01:23.646 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:01:23.744 DEBUG - [STROPHE] request id 21.0 posting LOG: 16:01:23.745 DEBUG - WIRE LOG: 16:01:32.978 DEBUG - [STROPHE] request id 21.1 state changed to 4 LOG: 16:01:32.978 DEBUG - [STROPHE] removing request LOG: 16:01:32.978 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:01:32.978 DEBUG - [STROPHE] request id 21 should now be removed LOG: 16:01:32.978 DEBUG - [STROPHE] request id 21.1 got 200 LOG: 16:01:32.978 DEBUG - WIRE LOG: 16:01:32.980 DEBUG - [INVOKE] Call.negotiate() LOG: 16:01:32.981 DEBUG - [INVOKE] JavaAudio.codecs() LOG: 16:01:33.010 DEBUG - [INVOKE] Phone.wideband() LOG: 16:01:33.010 DEBUG - [INVOKE] JavaAudio.codecs() LOG: 16:01:33.029 DEBUG - [INVOKE] Phone.wideband() LOG: 16:01:33.030 DEBUG - [INVOKE] JavaAudio.play(rtp://172.21.99.112:56905:199.230.57.114:20000,false) LOG: 16:01:33.030 DEBUG - [INVOKE] JavaAudio.share(rtp://172.21.99.112:56905:199.230.57.114:20000,false,[object Object]) LOG: 16:01:33.042 DEBUG - [INVOKE] Call.bindAudio([object Object]) LOG: 16:01:33.042 DEBUG - [INVOKE] Call.volume() LOG: 16:01:33.042 DEBUG - [INVOKE] Call.volume(50) LOG: 16:01:33.042 DEBUG - [INVOKE] Call.gain() LOG: 16:01:33.043 DEBUG - [INVOKE] Call.gain(50) LOG: 16:01:33.049 DEBUG - [INVOKE] Call.mute() LOG: 16:01:33.049 DEBUG - [INVOKE] Call.mute(false) LOG: 16:01:33.049 DEBUG - [INVOKE] Call.hold() LOG: 16:01:33.049 DEBUG - [INVOKE] Call.hold(undefined) LOG: 16:01:33.049 DEBUG - [INVOKE] Call.headset() LOG: 16:01:33.050 DEBUG - [INVOKE] Call.headset(false) LOG: 16:01:33.050 DEBUG - [INVOKE] Call.pushToTalkStateChanged() LOG: 16:01:33.070 DEBUG - [STROPHE] no requests during idle cycle, sending blank request LOG: 16:01:33.070 DEBUG - [STROPHE] request id 22.0 posting LOG: 16:01:33.071 DEBUG - WIRE LOG: 16:01:33.100 DEBUG - [INVOKE] Call.startAudio() LOG: 16:01:33.110 INFO - [EVENT] answer[undefined] LOG: 16:01:33.110 DEBUG - [INVOKE] Call.onanswer([object Object],undefined) LOG: [Phono2] [Call2] Call answered using g722/8000 LOG: 16:01:33.111 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests LOG: 16:01:33.112 DEBUG - [STROPHE] _processRequest: first request has readyState of 2 LOG: 16:01:33.210 DEBUG - [STROPHE] request id 23.0 posting LOG: 16:01:33.211 DEBUG - WIRE LOG: 16:01:33.615 DEBUG - [INVOKE] Call.energy() LOG: 16:01:33.617 DEBUG - [INVOKE] Call.energy() LOG: 16:01:33.830 DEBUG - [STROPHE] request id 22.1 state changed to 4 LOG: 16:01:33.830 DEBUG - [STROPHE] removing request LOG: 16:01:33.830 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests LOG: 16:01:33.830 DEBUG - [STROPHE] _processRequest: first request has readyState of 2 LOG: 16:01:33.831 DEBUG - [STROPHE] request id 22 should now be removed LOG: 16:01:33.831 DEBUG - [STROPHE] request id 22.1 got 200 LOG: 16:01:33.831 DEBUG - WIRE LOG: 16:01:34.130 DEBUG - [INVOKE] Call.energy() LOG: 16:01:34.132 DEBUG - [INVOKE] Call.energy() LOG: 16:01:34.644 DEBUG - [INVOKE] Call.energy() LOG: 16:01:34.647 DEBUG - [INVOKE] Call.energy() LOG: 16:01:35.144 DEBUG - [INVOKE] Call.energy() LOG: 16:01:35.147 DEBUG - [INVOKE] Call.energy() LOG: 16:01:35.659 DEBUG - [INVOKE] Call.energy() LOG: 16:01:35.663 DEBUG - [INVOKE] Call.energy() LOG: 16:01:36.159 DEBUG - [INVOKE] Call.energy() LOG: 16:01:36.162 DEBUG - [INVOKE] Call.energy() LOG: 16:01:36.673 DEBUG - [INVOKE] Call.energy() LOG: 16:01:36.676 DEBUG - [INVOKE] Call.energy() LOG: 16:01:37.183 DEBUG - [INVOKE] Call.energy() LOG: 16:01:37.185 DEBUG - [INVOKE] Call.energy() LOG: 16:01:37.703 DEBUG - [INVOKE] Call.energy() LOG: 16:01:37.705 DEBUG - [INVOKE] Call.energy() LOG: 16:01:38.218 DEBUG - [INVOKE] Call.energy() LOG: 16:01:38.221 DEBUG - [INVOKE] Call.energy() LOG: 16:01:38.310 DEBUG - [STROPHE] request id 15.1 state changed to 4 LOG: 16:01:38.310 DEBUG - [STROPHE] removing request LOG: 16:01:38.310 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:01:38.310 DEBUG - [STROPHE] request id 15 should now be removed LOG: 16:01:38.310 DEBUG - [STROPHE] request id 15.1 got 200 LOG: 16:01:38.311 DEBUG - WIRE LOG: 16:01:38.315 DEBUG - [STROPHE] no requests during idle cycle, sending blank request LOG: 16:01:38.315 DEBUG - [STROPHE] request id 24.0 posting LOG: 16:01:38.316 DEBUG - WIRE LOG: 16:01:38.732 DEBUG - [INVOKE] Call.energy() LOG: 16:01:38.771 DEBUG - [INVOKE] Call.energy() LOG: 16:01:39.325 DEBUG - [INVOKE] Call.energy() LOG: 16:01:39.362 DEBUG - [INVOKE] Call.energy() LOG: 16:01:39.902 DEBUG - [INVOKE] Call.energy() LOG: 16:01:39.906 DEBUG - [INVOKE] Call.energy() LOG: 16:01:40.417 DEBUG - [INVOKE] Call.energy() LOG: 16:01:40.419 DEBUG - [INVOKE] Call.energy() LOG: 16:01:40.929 DEBUG - [INVOKE] Call.energy() LOG: 16:01:40.931 DEBUG - [INVOKE] Call.energy() LOG: 16:01:41.447 DEBUG - [INVOKE] Call.energy() LOG: 16:01:41.449 DEBUG - [INVOKE] Call.energy() LOG: 16:01:41.961 DEBUG - [INVOKE] Call.energy() LOG: 16:01:41.964 DEBUG - [INVOKE] Call.energy() LOG: 16:01:42.476 DEBUG - [INVOKE] Call.energy() LOG: 16:01:42.521 DEBUG - [INVOKE] Call.energy() LOG: 16:01:43.084 DEBUG - [INVOKE] Call.energy() LOG: 16:01:43.087 DEBUG - [INVOKE] Call.energy() LOG: 16:01:43.599 DEBUG - [INVOKE] Call.energy() LOG: 16:01:43.601 DEBUG - [INVOKE] Call.energy() LOG: 16:01:44.114 DEBUG - [INVOKE] Call.energy() LOG: 16:01:44.116 DEBUG - [INVOKE] Call.energy() LOG: 16:01:44.629 DEBUG - [INVOKE] Call.energy() LOG: 16:01:44.632 DEBUG - [INVOKE] Call.energy() LOG: 16:01:45.129 DEBUG - [INVOKE] Call.energy() LOG: 16:01:45.135 DEBUG - [INVOKE] Call.energy() LOG: 16:01:45.643 DEBUG - [INVOKE] Call.energy() LOG: 16:01:45.646 DEBUG - [INVOKE] Call.energy() LOG: 16:01:46.142 DEBUG - [INVOKE] Call.energy() LOG: 16:01:46.145 DEBUG - [INVOKE] Call.energy() LOG: 16:01:46.657 DEBUG - [INVOKE] Call.energy() LOG: 16:01:46.659 DEBUG - [INVOKE] Call.energy() LOG: 16:01:46.843 DEBUG - [STROPHE] request id 23.1 state changed to 4 LOG: 16:01:46.844 DEBUG - [STROPHE] removing request LOG: 16:01:46.844 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:01:46.844 DEBUG - [STROPHE] request id 23 should now be removed LOG: 16:01:46.844 DEBUG - [STROPHE] request id 23.1 got 200 LOG: 16:01:46.844 DEBUG - WIRE LOG: 16:01:46.845 DEBUG - [INVOKE] Call.stopAudio() LOG: 16:01:46.875 INFO - [EVENT] hangup[undefined] LOG: 16:01:46.875 DEBUG - [INVOKE] Call.onhangup([object Object],undefined) LOG: [Phono2] [Call2] Call hungup LOG: 16:01:46.881 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:01:46.990 DEBUG - [STROPHE] request id 25.0 posting LOG: 16:01:46.991 DEBUG - WIRE LOG: 16:02:12.040 DEBUG - [STROPHE] request id 25.1 state changed to 4 LOG: 16:02:12.040 DEBUG - [STROPHE] removing request LOG: 16:02:12.040 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:02:12.041 DEBUG - [STROPHE] request id 25 should now be removed LOG: 16:02:12.041 DEBUG - [STROPHE] request id 25.1 got 200 LOG: 16:02:12.041 DEBUG - WIRE LOG: 16:02:12.044 DEBUG - [INVOKE] JavaAudio.transport() LOG: 16:02:12.076 DEBUG - [INVOKE] Phone.ringTone() LOG: 16:02:12.077 DEBUG - [INVOKE] JavaAudio.play(ringtones/Diggztone_Marimba.mp3) LOG: 16:02:12.078 DEBUG - [INVOKE] Phone.ringbackTone() LOG: 16:02:12.078 DEBUG - [INVOKE] JavaAudio.play(ringtones/ringback-us.mp3) LOG: 16:02:12.079 DEBUG - [INVOKE] Phone.audioInput() LOG: 16:02:12.079 DEBUG - [INVOKE] JavaAudio.audioIn(System Default) LOG: 16:02:12.080 DEBUG - [INVOKE] Call.negotiate() LOG: 16:02:12.081 DEBUG - [INVOKE] JavaAudio.codecs() LOG: 16:02:12.096 DEBUG - [INVOKE] Phone.wideband() LOG: 16:02:12.096 DEBUG - [INVOKE] JavaAudio.codecs() LOG: 16:02:12.110 DEBUG - [INVOKE] Phone.wideband() LOG: 16:02:12.111 DEBUG - [INVOKE] JavaAudio.codecs() LOG: 16:02:12.126 DEBUG - [INVOKE] Phone.wideband() LOG: 16:02:12.126 DEBUG - [INVOKE] JavaAudio.codecs() LOG: 16:02:12.144 DEBUG - [INVOKE] Phone.wideband() LOG: 16:02:12.144 DEBUG - [INVOKE] JavaAudio.codecs() LOG: 16:02:12.164 DEBUG - [INVOKE] Phone.wideband() LOG: 16:02:12.165 DEBUG - [INVOKE] JavaAudio.codecs() LOG: 16:02:12.189 DEBUG - [INVOKE] Phone.wideband() LOG: 16:02:12.190 DEBUG - [INVOKE] JavaAudio.play(rtp://172.21.99.112:56906:199.230.57.114:20006,false) LOG: 16:02:12.190 DEBUG - [INVOKE] JavaAudio.share(rtp://172.21.99.112:56906:199.230.57.114:20006,false,[object Object]) LOG: 16:02:12.192 DEBUG - [INVOKE] Call.bindAudio([object Object]) LOG: 16:02:12.192 DEBUG - [INVOKE] Call.volume() LOG: 16:02:12.192 DEBUG - [INVOKE] Call.volume(50) LOG: 16:02:12.192 DEBUG - [INVOKE] Call.gain() LOG: 16:02:12.193 DEBUG - [INVOKE] Call.gain(50) LOG: 16:02:12.193 DEBUG - [INVOKE] Call.mute() LOG: 16:02:12.193 DEBUG - [INVOKE] Call.mute(false) LOG: 16:02:12.193 DEBUG - [INVOKE] Call.hold() LOG: 16:02:12.193 DEBUG - [INVOKE] Call.hold(undefined) LOG: 16:02:12.194 DEBUG - [INVOKE] Call.headset() LOG: 16:02:12.194 DEBUG - [INVOKE] Call.headset(undefined) LOG: 16:02:12.194 DEBUG - [INVOKE] Call.pushToTalkStateChanged() LOG: 16:02:12.196 DEBUG - [INVOKE] Call.accept() LOG: 16:02:12.196 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:02:12.196 INFO - [EVENT] incomingCall[undefined] LOG: 16:02:12.197 DEBUG - [INVOKE] Phone.onincomingcall([object Object],undefined) LOG: [Phono2] New incoming call LOG: 16:02:12.207 DEBUG - [INVOKE] JavaAudio.permission() LOG: 16:02:12.207 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:02:12.309 DEBUG - [STROPHE] request id 26.0 posting LOG: 16:02:12.310 DEBUG - WIRE LOG: 16:02:13.058 DEBUG - [STROPHE] request id 26.1 state changed to 4 LOG: 16:02:13.059 DEBUG - [STROPHE] removing request LOG: 16:02:13.059 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:02:13.059 DEBUG - [STROPHE] request id 26 should now be removed LOG: 16:02:13.059 DEBUG - [STROPHE] request id 26.1 got 200 LOG: 16:02:13.059 DEBUG - WIRE LOG: 16:02:13.073 DEBUG - [STROPHE] no requests during idle cycle, sending blank request LOG: 16:02:13.073 DEBUG - [STROPHE] request id 27.0 posting LOG: 16:02:13.074 DEBUG - WIRE LOG: 16:02:20.445 DEBUG - [INVOKE] Call.answer() LOG: 16:02:20.445 DEBUG - [INVOKE] JavaAudio.codecs() LOG: 16:02:20.455 DEBUG - [INVOKE] Phone.wideband() LOG: 16:02:20.455 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests LOG: 16:02:20.456 DEBUG - [STROPHE] _processRequest: first request has readyState of 2 LOG: Call answered LOG: 16:02:20.562 DEBUG - [STROPHE] request id 28.0 posting LOG: 16:02:20.563 DEBUG - WIRE LOG: 16:02:21.320 DEBUG - [STROPHE] request id 27.1 state changed to 4 LOG: 16:02:21.320 DEBUG - [STROPHE] removing request LOG: 16:02:21.320 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests LOG: 16:02:21.321 DEBUG - [STROPHE] _processRequest: first request has readyState of 2 LOG: 16:02:21.321 DEBUG - [STROPHE] request id 27 should now be removed LOG: 16:02:21.321 DEBUG - [STROPHE] request id 27.1 got 200 LOG: 16:02:21.321 DEBUG - WIRE LOG: 16:02:21.323 DEBUG - [STROPHE] request id 28.1 state changed to 4 LOG: 16:02:21.323 DEBUG - [STROPHE] removing request LOG: 16:02:21.323 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:02:21.323 DEBUG - [STROPHE] request id 28 should now be removed LOG: 16:02:21.324 DEBUG - [STROPHE] request id 28.1 got 200 LOG: 16:02:21.324 DEBUG - WIRE LOG: 16:02:21.325 DEBUG - [INVOKE] Call.startAudio() LOG: 16:02:21.343 DEBUG - [STROPHE] no requests during idle cycle, sending blank request LOG: 16:02:21.343 DEBUG - [STROPHE] request id 29.0 posting LOG: 16:02:21.344 DEBUG - WIRE LOG: 16:02:38.216 DEBUG - [STROPHE] request id 24.1 state changed to 4 LOG: 16:02:38.216 DEBUG - [STROPHE] removing request LOG: 16:02:38.216 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:02:38.217 DEBUG - [STROPHE] request id 24 should now be removed LOG: 16:02:38.217 DEBUG - [STROPHE] request id 24.1 got 200 LOG: 16:02:38.217 DEBUG - WIRE LOG: 16:02:38.310 DEBUG - [STROPHE] no requests during idle cycle, sending blank request LOG: 16:02:38.310 DEBUG - [STROPHE] request id 30.0 posting LOG: 16:02:38.311 DEBUG - WIRE LOG: 16:03:10.931 DEBUG - [INVOKE] Call.hangup() LOG: 16:03:10.932 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests LOG: 16:03:10.932 DEBUG - [STROPHE] _processRequest: first request has readyState of 2 LOG: 16:03:11.085 DEBUG - [STROPHE] request id 31.0 posting LOG: 16:03:11.085 DEBUG - WIRE LOG: 16:03:11.776 DEBUG - [STROPHE] request id 29.1 state changed to 4 LOG: 16:03:11.776 DEBUG - [STROPHE] removing request LOG: 16:03:11.777 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests LOG: 16:03:11.777 DEBUG - [STROPHE] _processRequest: first request has readyState of 2 LOG: 16:03:11.777 DEBUG - [STROPHE] request id 29 should now be removed LOG: 16:03:11.777 DEBUG - [STROPHE] request id 29.1 got 200 LOG: 16:03:11.777 DEBUG - WIRE LOG: 16:03:11.894 DEBUG - [STROPHE] request id 31.1 state changed to 4 LOG: 16:03:11.894 DEBUG - [STROPHE] removing request LOG: 16:03:11.894 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests LOG: 16:03:11.894 DEBUG - [STROPHE] request id 31 should now be removed LOG: 16:03:11.894 DEBUG - [STROPHE] request id 31.1 got 200 LOG: 16:03:11.894 DEBUG - WIRE LOG: 16:03:11.895 INFO - [EVENT] hangup[undefined] LOG: [Phono2] [Call3] Call hungup LOG: 16:03:11.895 DEBUG - [INVOKE] Call.stopAudio() LOG: 16:03:11.974 DEBUG - [STROPHE] no requests during idle cycle, sending blank request LOG: 16:03:11.974 DEBUG - [STROPHE] request id 32.0 posting LOG: 16:03:11.975 DEBUG - WIRE

javen commented 12 years ago

Here are logs from FireBug on Firefox3.6: 14:33:08.137 DEBUG - [STROPHE] request id 18.1 state changed to 2 14:33:08.141 DEBUG - [STROPHE] request id 18.1 state changed to 3 14:33:08.142 DEBUG - [STROPHE] request id 18.1 state changed to 4 14:33:08.143 DEBUG - [STROPHE] removing request 14:33:08.144 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests 14:33:08.145 DEBUG - [STROPHE] request id 18 should now be removed 14:33:08.146 DEBUG - [STROPHE] request id 18.1 got 200 14:33:08.147 DEBUG - WIRE 14:33:08.156 DEBUG - [STROPHE] no requests during idle cycle, sending blank request 14:33:08.163 DEBUG - [STROPHE] request id 22.0 posting 14:33:08.167 DEBUG - [STROPHE] request id 22.0 state changed to 1 14:33:08.171 DEBUG - [STROPHE] request id 22.0 state changed to 1 14:33:08.174 DEBUG - WIRE 14:33:20.121 DEBUG - [STROPHE] request id 21.1 state changed to 2 14:33:20.125 DEBUG - [STROPHE] request id 21.1 state changed to 3 14:33:20.129 DEBUG - [STROPHE] request id 21.1 state changed to 4 14:33:20.132 DEBUG - [STROPHE] removing request 14:33:20.136 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests 14:33:20.139 DEBUG - [STROPHE] request id 21 should now be removed 14:33:20.142 DEBUG - [STROPHE] request id 21.1 got 200 14:33:20.146 DEBUG - WIRE 14:33:20.177 DEBUG - [STROPHE] no requests during idle cycle, sending blank request 14:33:20.180 DEBUG - [STROPHE] request id 23.0 posting 14:33:20.183 DEBUG - [STROPHE] request id 23.0 state changed to 1 14:33:20.186 DEBUG - [STROPHE] request id 23.0 state changed to 1 14:33:20.189 DEBUG - WIRE 14:33:33.141 DEBUG - [STROPHE] request id 23.1 state changed to 2 14:33:33.146 DEBUG - [STROPHE] request id 23.1 state changed to 3 14:33:33.150 DEBUG - [STROPHE] request id 23.1 state changed to 4 14:33:33.153 DEBUG - [STROPHE] removing request 14:33:33.157 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests 14:33:33.160 DEBUG - [STROPHE] request id 23 should now be removed 14:33:33.164 DEBUG - [STROPHE] request id 23.1 got 200 14:33:33.167 DEBUG - WIRE 14:33:33.179 DEBUG - [INVOKE] JavaAudio.transport() 14:33:33.204 DEBUG - [STROPHE] no requests during idle cycle, sending blank request 14:33:33.208 DEBUG - [STROPHE] request id 24.0 posting 14:33:33.212 DEBUG - [STROPHE] request id 24.0 state changed to 1 14:33:33.216 DEBUG - [STROPHE] request id 24.0 state changed to 1 14:33:33.220 DEBUG - WIRE 14:33:33.227 DEBUG - [INVOKE] Phone.ringTone() 14:33:33.230 DEBUG - [INVOKE] JavaAudio.play(ringtones/Diggztone_Marimba.mp3) 14:33:33.237 DEBUG - [INVOKE] Phone.ringbackTone() 14:33:33.241 DEBUG - [INVOKE] JavaAudio.play(ringtones/ringback-us.mp3) 14:33:33.249 DEBUG - [INVOKE] Phone.audioInput() 14:33:33.252 DEBUG - [INVOKE] JavaAudio.audioIn(System Default) 14:33:33.256 DEBUG - [INVOKE] Call.negotiate([object Element]) 14:33:33.260 DEBUG - [INVOKE] JavaAudio.codecs() 14:33:33.283 DEBUG - [INVOKE] Phone.wideband() 14:33:33.286 DEBUG - [INVOKE] JavaAudio.codecs() 14:33:33.312 DEBUG - [INVOKE] Phone.wideband() 14:33:33.315 DEBUG - [INVOKE] JavaAudio.codecs() 14:33:33.328 DEBUG - [INVOKE] Phone.wideband() 14:33:33.331 DEBUG - [INVOKE] JavaAudio.codecs() 14:33:33.343 DEBUG - [INVOKE] Phone.wideband() 14:33:33.346 DEBUG - [INVOKE] JavaAudio.codecs() 14:33:33.359 DEBUG - [INVOKE] Phone.wideband() 14:33:33.361 DEBUG - [INVOKE] JavaAudio.codecs() 14:33:33.371 DEBUG - [INVOKE] Phone.wideband() 14:33:33.372 DEBUG - [INVOKE] JavaAudio.play(rtp://172.21.99.112:63947:199.230.57.114:20006,false) 14:33:33.372 DEBUG - [INVOKE] JavaAudio.share(rtp://172.21.99.112:63947:199.230.57.114:20006,false,[object Object]) 14:33:33.377 DEBUG - [INVOKE] Call.bindAudio([object Object]) 14:33:33.377 DEBUG - [INVOKE] Call.volume() 14:33:33.377 DEBUG - [INVOKE] Call.volume(50) 14:33:33.378 DEBUG - [INVOKE] Call.gain() 14:33:33.378 DEBUG - [INVOKE] Call.gain(50) 14:33:33.378 DEBUG - [INVOKE] Call.mute() 14:33:33.379 DEBUG - [INVOKE] Call.mute(false) 14:33:33.379 DEBUG - [INVOKE] Call.hold() 14:33:33.380 DEBUG - [INVOKE] Call.hold(undefined) 14:33:33.380 DEBUG - [INVOKE] Call.headset() 14:33:33.380 DEBUG - [INVOKE] Call.headset(undefined) 14:33:33.381 DEBUG - [INVOKE] Call.pushToTalkStateChanged() 14:33:33.382 DEBUG - [INVOKE] Call.accept() 14:33:33.382 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests 14:33:33.382 DEBUG - [STROPHE] _processRequest: first request has readyState of 1 14:33:33.383 INFO - [EVENT] incomingCall[undefined] 14:33:33.383 DEBUG - [INVOKE] Phone.onincomingcall([object Object],undefined) [Phono2] New incoming call 14:33:33.387 DEBUG - [INVOKE] JavaAudio.permission() 14:33:33.387 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests 14:33:33.388 DEBUG - [STROPHE] _processRequest: first request has readyState of 1 14:33:33.479 DEBUG - [STROPHE] request id 25.0 posting 14:33:33.479 DEBUG - [STROPHE] request id 25.0 state changed to 1 14:33:33.480 DEBUG - [STROPHE] request id 25.0 state changed to 1 14:33:33.481 DEBUG - WIRE 14:33:37.075 DEBUG - [STROPHE] request id 25.1 state changed to 2 14:33:37.078 DEBUG - [STROPHE] request id 25.1 state changed to 3 14:33:37.081 DEBUG - [STROPHE] request id 25.1 state changed to 4 14:33:37.084 DEBUG - [STROPHE] removing request 14:33:37.086 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests 14:33:37.089 DEBUG - [STROPHE] _processRequest: first request has readyState of 1 14:33:37.091 DEBUG - [STROPHE] request id 25 should now be removed 14:33:37.093 DEBUG - [STROPHE] _processRequest: first request has readyState of 1 14:33:37.095 DEBUG - [STROPHE] request id 25.1 got 200 14:33:37.098 DEBUG - WIRE 14:33:37.104 DEBUG - [STROPHE] request id 24.1 state changed to 2 14:33:37.107 DEBUG - [STROPHE] request id 24.1 state changed to 3 14:33:37.110 DEBUG - [STROPHE] request id 24.1 state changed to 4 14:33:37.112 DEBUG - [STROPHE] removing request 14:33:37.114 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests 14:33:37.117 DEBUG - [STROPHE] request id 24 should now be removed 14:33:37.119 DEBUG - [STROPHE] request id 24.1 got 200 14:33:37.122 DEBUG - WIRE 14:33:37.165 DEBUG - [STROPHE] no requests during idle cycle, sending blank request 14:33:37.169 DEBUG - [STROPHE] request id 26.0 posting 14:33:37.172 DEBUG - [STROPHE] request id 26.0 state changed to 1 14:33:37.177 DEBUG - [STROPHE] request id 26.0 state changed to 1 14:33:37.180 DEBUG - WIRE 14:33:41.018 DEBUG - [INVOKE] Call.answer() 14:33:41.022 DEBUG - [INVOKE] JavaAudio.codecs() 14:33:41.040 DEBUG - [INVOKE] Phone.wideband() 14:33:41.044 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests 14:33:41.047 DEBUG - [STROPHE] _processRequest: first request has readyState of 1 Call answered 14:33:41.149 DEBUG - [STROPHE] request id 27.0 posting 14:33:41.153 DEBUG - [STROPHE] request id 27.0 state changed to 1 14:33:41.157 DEBUG - [STROPHE] request id 27.0 state changed to 1 14:33:41.161 DEBUG - WIRE 14:33:41.751 DEBUG - [STROPHE] request id 26.1 state changed to 2 14:33:41.756 DEBUG - [STROPHE] request id 26.1 state changed to 3 14:33:41.759 DEBUG - [STROPHE] request id 26.1 state changed to 4 14:33:41.763 DEBUG - [STROPHE] removing request 14:33:41.767 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests 14:33:41.770 DEBUG - [STROPHE] _processRequest: first request has readyState of 1 14:33:41.773 DEBUG - [STROPHE] request id 26 should now be removed 14:33:41.776 DEBUG - [STROPHE] request id 26.1 got 200 14:33:41.778 DEBUG - WIRE 14:33:41.783 DEBUG - [STROPHE] request id 27.1 state changed to 2 14:33:41.786 DEBUG - [STROPHE] request id 27.1 state changed to 3 14:33:41.789 DEBUG - [STROPHE] request id 27.1 state changed to 4 14:33:41.791 DEBUG - [STROPHE] removing request 14:33:41.794 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests 14:33:41.796 DEBUG - [STROPHE] request id 27 should now be removed 14:33:41.799 DEBUG - [STROPHE] request id 27.1 got 200 14:33:41.801 DEBUG - WIRE 14:33:41.805 DEBUG - [INVOKE] Call.startAudio() 14:33:41.876 DEBUG - [STROPHE] no requests during idle cycle, sending blank request 14:33:41.880 DEBUG - [STROPHE] request id 28.0 posting 14:33:41.884 DEBUG - [STROPHE] request id 28.0 state changed to 1 14:33:41.888 DEBUG - [STROPHE] request id 28.0 state changed to 1 14:33:41.892 DEBUG - WIRE 14:33:52.930 DEBUG - [INVOKE] Call.hangup() 14:33:52.934 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests 14:33:52.937 DEBUG - [STROPHE] _processRequest: first request has readyState of 1 14:33:53.044 DEBUG - [STROPHE] request id 29.0 posting 14:33:53.045 DEBUG - [STROPHE] request id 29.0 state changed to 1 14:33:53.046 DEBUG - [STROPHE] request id 29.0 state changed to 1 14:33:53.046 DEBUG - WIRE 14:33:53.645 DEBUG - [STROPHE] request id 28.1 state changed to 2 14:33:53.649 DEBUG - [STROPHE] request id 28.1 state changed to 3 14:33:53.653 DEBUG - [STROPHE] request id 28.1 state changed to 4 14:33:53.657 DEBUG - [STROPHE] removing request 14:33:53.661 DEBUG - [STROPHE] _throttledRequestHandler called with 1 requests 14:33:53.664 DEBUG - [STROPHE] _processRequest: first request has readyState of 1 14:33:53.668 DEBUG - [STROPHE] request id 28 should now be removed 14:33:53.671 DEBUG - [STROPHE] request id 28.1 got 200 14:33:53.675 DEBUG - WIRE 14:33:53.682 DEBUG - [STROPHE] request id 29.1 state changed to 2 14:33:53.685 DEBUG - [STROPHE] request id 29.1 state changed to 3 14:33:53.688 DEBUG - [STROPHE] request id 29.1 state changed to 4 14:33:53.690 DEBUG - [STROPHE] removing request 14:33:53.693 DEBUG - [STROPHE] _throttledRequestHandler called with 0 requests 14:33:53.695 DEBUG - [STROPHE] request id 29 should now be removed 14:33:53.698 DEBUG - [STROPHE] request id 29.1 got 200 14:33:53.700 DEBUG - WIRE 14:33:53.704 INFO - [EVENT] hangup[undefined] [Phono2] [Call3] Call hungup 14:33:53.709 DEBUG - [INVOKE] Call.stopAudio() 14:33:53.774 DEBUG - [STROPHE] no requests during idle cycle, sending blank request 14:33:53.778 DEBUG - [STROPHE] request id 30.0 posting 14:33:53.781 DEBUG - [STROPHE] request id 30.0 state changed to 1 14:33:53.786 DEBUG - [STROPHE] request id 30.0 state changed to 1 14:33:53.789 DEBUG - WIRE

javen commented 12 years ago

codec info in phono java side DEBUG: 1321439915012 Applet 6 LiveConnect Worker Thread->in play() uri = http://localhost:8081/phonosdk-0.3/samples/kitchen-sink/www/ringtones/Diggztone_AngryBirds.mp3 DEBUG: 1321439915065 Applet 6 LiveConnect Worker Thread->in play() uri = http://localhost:8081/phonosdk-0.3/samples/kitchen-sink/www/ringtones/Diggztone_AngryBirds.mp3 DEBUG: 1321439915127 Applet 6 LiveConnect Worker Thread->Set audio input device preference to System Default DEBUG: 1321439915181 Applet 6 LiveConnect Worker Thread->getting audio is 16000.0 = 16000.0 ? Yes DEBUG: 1321439915182 Applet 6 LiveConnect Worker Thread->PhonoAudio.init(): com.phono.codecs.speex.SpeexCodec@88c615 DEBUG: 1321439915182 Applet 6 LiveConnect Worker Thread->EsupPhonoAudio.setAudioProperty(): _doEc=true DEBUG: 1321439915182 Applet 6 LiveConnect Worker Thread->PhonoAudio.setAudioProperty(): name=doEC, value=true DEBUG: 1321439915182 Applet 6 LiveConnect Worker Thread->PhonoAudio.init(): _deep=10 DEBUG: 1321439915182 Applet 6 LiveConnect Worker Thread->Looking at Mixer 0 Primary Sound Driver DEBUG: 1321439915182 Applet 6 LiveConnect Worker Thread->Looking at Mixer 1 Speakers (High Definition Audio Device) DEBUG: 1321439915182 Applet 6 LiveConnect Worker Thread->Looking at Mixer 2 Speakers (High Definition Audio Device) DEBUG: 1321439915182 Applet 6 LiveConnect Worker Thread->Looking at Mixer 3 Primary Sound Capture Driver DEBUG: 1321439915182 Applet 6 LiveConnect Worker Thread->Looking at Mixer 4 Microphone (High Definition Aud DEBUG: 1321439915182 Applet 6 LiveConnect Worker Thread->Looking at Mixer 5 Java Sound Audio Engine DEBUG: 1321439915182 Applet 6 LiveConnect Worker Thread->Looking at Mixer 6 Port Speakers (High Definition Audio DEBUG: 1321439915182 Applet 6 LiveConnect Worker Thread->Looking at Mixer 7 Port Speakers (High Definition Audio DEBUG: 1321439915182 Applet 6 LiveConnect Worker Thread->Looking at Mixer 8 Port Microphone (High Definition Aud DEBUG: 1321439915182 Applet 6 LiveConnect Worker Thread->EsupPhonoAudio.muteMic(): mute=false DEBUG: 1321439915183 Applet 6 LiveConnect Worker Thread->EsupPhonoAudio.setAudioProperty(): _doEc=true DEBUG: 1321439915183 Applet 6 LiveConnect Worker Thread->PhonoAudio.setAudioProperty(): name=doEC, value=true DEBUG: 1321439920401 Applet 6 LiveConnect Worker Thread->in Share.start() DEBUG: 1321439920402 Applet 6 LiveConnect Worker Thread->Start Rec called DEBUG: 1321439920403 Applet 6 LiveConnect Worker Thread->PhonoAudio.startRec(): rec started DEBUG: 1321439920404 Applet 6 LiveConnect Worker Thread->PhonoAudio.startRec(): recThread started DEBUG: 1321439920404 Applet 6 LiveConnect Worker Thread->starting : original local uri was rtp://172.21.99.112:52325:199.230.57.114:20038 DEBUG: 1321439920404 Applet 6 LiveConnect Worker Thread->starting : using local 0.0.0.0/0.0.0.0:52325 remote /199.230.57.114:20038 with pt=103 codec SPEEX

steely-glint commented 12 years ago

Interestingly complex this one - phono uses a different codec when answering from the one it uses when calling. unfortunately the java was cache'ing the codec so 722 was used when speex was needed. checking in a fix now.

javen commented 12 years ago

Retest phonosdk-0.3 with Hudson build #120. The Defect can not be reproduced again. So, close the issue.