1015348 - Call setup code chokes when main thread is busy

Status: RESOLVED DUPLICATE of bug 991037

(Core :: WebRTC: Signaling, defect)

Description

[Byron Campen [:bwc]]

While replicating some problems with 3-way calls at http://meet.tokbox.com/p2p_test, I observed extreme delays in call setup time when trying to add a third participant to a chrome/firefox call. Here's an example timecard output:

    0.000067 |    0.000067 | Constructor Completed          | PeerConnectionImpl.cpp:506   | PeerConnectionImpl     
    0.007966 |    0.007899 | Initializing PC Ctx            | PeerConnectionImpl.cpp:814   | Initialize             
    0.007969 |    0.000003 | Done Initializing PC Ctx       | PeerConnectionImpl.cpp:820   | Initialize             
    0.009156 |    0.001187 | Generating DTLS Identity       | PeerConnectionImpl.cpp:860   | Initialize             
    0.346949 |    0.337793 | Done Generating DTLS Identity  | PeerConnectionImpl.cpp:863   | Initialize             
    0.383320 |    0.036371 | Create Offer                   | PeerConnectionImpl.cpp:1233  | CreateOffer            
    0.383511 |    0.000191 | Processing create offer event  |           ccprovider.c:666   | processSessionEvent    
    0.383560 |    0.000049 | Sending message to queue       |                ccapi.c:1246  | send_message_helper    
    8.539946 |    8.156386 | Posting message to PC          |                   ui.c:1574  | post_message_helper    
    8.674469 |    0.134523 | Operation Completed            | PeerConnectionImpl.cpp:1822  | onCallEvent            
    8.746995 |    0.072526 | Set Local Description          | PeerConnectionImpl.cpp:1274  | SetLocalDescription    
    8.750752 |    0.003757 | Processing set local event     |           ccprovider.c:676   | processSessionEvent    
    8.750967 |    0.000215 | Sending message to queue       |                ccapi.c:1246  | send_message_helper    
   14.308536 |    5.557569 | Posting message to PC          |                   ui.c:1574  | post_message_helper    
   14.717935 |    0.409399 | Operation Completed            | PeerConnectionImpl.cpp:1822  | onCallEvent            
   16.862590 |    2.144655 | Set Remote Description         | PeerConnectionImpl.cpp:1305  | SetRemoteDescription   
   16.866529 |    0.003939 | Processing set remote event    |           ccprovider.c:680   | processSessionEvent    
   16.866578 |    0.000049 | Sending message to queue       |                ccapi.c:1246  | send_message_helper    
   22.448559 |    5.581981 | ICE Attributes Installed       |               fsmdef.c:3853  | fsmdef_ev_setremotedesc
   23.371336 |    0.922777 | Posting message to PC          |                   ui.c:1574  | post_message_helper    
   23.406568 |    0.035232 | Operation Completed            | PeerConnectionImpl.cpp:1822  | onCallEvent            
   23.422280 |    0.015712 | Add Ice Candidate              | PeerConnectionImpl.cpp:1387  | AddIceCandidate        
   23.422554 |    0.000274 | Processing add candidate event |           ccprovider.c:708   | processSessionEvent    
   32.280296 |    8.857742 | Posting message to PC          |                   ui.c:1574  | post_message_helper    
   32.311061 |    0.030765 | Operation Completed            | PeerConnectionImpl.cpp:1822  | onCallEvent            
   32.337225 |    0.026164 | Add Ice Candidate              | PeerConnectionImpl.cpp:1387  | AddIceCandidate        
   32.337641 |    0.000416 | Processing add candidate event |           ccprovider.c:708   | processSessionEvent    
   39.739154 |    7.401513 | Posting message to PC          |                   ui.c:1574  | post_message_helper    
   41.061398 |    1.322244 | Operation Completed            | PeerConnectionImpl.cpp:1822  | onCallEvent            
   41.341132 |    0.279734 | Add Ice Candidate              | PeerConnectionImpl.cpp:1387  | AddIceCandidate        
   41.341883 |    0.000751 | Processing add candidate event |           ccprovider.c:708   | processSessionEvent    
   41.394562 |    0.052679 | Posting message to PC          |                   ui.c:1574  | post_message_helper    
   41.400741 |    0.006179 | Operation Completed            | PeerConnectionImpl.cpp:1822  | onCallEvent            
   41.406927 |    0.006186 | Add Ice Candidate              | PeerConnectionImpl.cpp:1387  | AddIceCandidate        
   41.408700 |    0.001773 | Processing add candidate event |           ccprovider.c:708   | processSessionEvent    
   41.410852 |    0.002152 | Posting message to PC          |                   ui.c:1574  | post_message_helper    
   41.418748 |    0.007896 | Operation Completed            | PeerConnectionImpl.cpp:1822  | onCallEvent            
   41.421404 |    0.002656 | Add Ice Candidate              | PeerConnectionImpl.cpp:1387  | AddIceCandidate        
   41.422001 |    0.000597 | Processing add candidate event |           ccprovider.c:708   | processSessionEvent    
   41.431617 |    0.009616 | Posting message to PC          |                   ui.c:1574  | post_message_helper    
   41.529589 |    0.097972 | Operation Completed            | PeerConnectionImpl.cpp:1822  | onCallEvent            
   41.566667 |    0.037078 | Add Ice Candidate              | PeerConnectionImpl.cpp:1387  | AddIceCandidate        
   41.571310 |    0.004643 | Processing add candidate event |           ccprovider.c:708   | processSessionEvent    
   41.577492 |    0.006182 | Posting message to PC          |                   ui.c:1574  | post_message_helper    
   41.598035 |    0.020543 | Operation Completed            | PeerConnectionImpl.cpp:1822  | onCallEvent            
   54.007092 |   12.409057 | Destructor Invoked             | PeerConnectionImpl.cpp:512   | ~PeerConnectionImpl

Comment 1

[Byron Campen [:bwc]]

From what I can tell, the problem occurs when we perform sync dispatches to main from the various sipcc threads; it stands to reason that if main is very busy (rendering video, for example), sync dispatches will block the calling thread for long periods of time, causing quite large delays once we've spun up a few PeerConnections. It may be that some of the work in bug 991037 will help with this, so I'll give that a try.