Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Signal/1.38.2 Chrome/80.0.3987.165 Electron/8.5.2 Safari/537.36 node/12.13.0 env/production INFO 2020-11-25T17:26:30.941Z app ready INFO 2020-11-25T17:26:30.942Z starting version 1.38.2 INFO 2020-11-25T17:26:30.953Z updateSchema: Current user_version: 21; Most recent db schema: 21; SQLite version: 3.30.1; SQLCipher version: 4.3.0 community; (deprecated) schema_version: 60; INFO 2020-11-25T17:26:31.321Z Initializing BrowserWindow config: {"show":false,"width":1920,"height":994,"minWidth":680,"minHeight":550,"autoHideMenuBar":false,"backgroundColor":"#3a76f0","webPreferences":{"nodeIntegration":false,"nodeIntegrationInWorker":false,"contextIsolation":false,"preload":"[REDACTED]/app.asar/preload.js","nativeWindowOpen":true,"spellcheck":true,"backgroundThrottling":false},"icon":"[REDACTED]/app.asar/images/signal-logo-desktop-linux.png","x":0,"y":55} INFO 2020-11-25T17:26:31.364Z spellcheck: user locale: de-DE INFO 2020-11-25T17:26:31.364Z spellcheck: available spellchecker languages: ["af","bg","ca","cs","cy","da","de","el","en-AU","en-CA","en-GB","en-US","es","es-419","es-AR","es-ES","es-MX","es-US","et","fa","fo","fr","he","hi","hr","hu","hy","id","it","ko","lt","lv","nb","nl","pl","pt-BR","pt-PT","ro","ru","sh","sk","sl","sq","sr","sv","ta","tg","tr","uk","vi"] INFO 2020-11-25T17:26:31.364Z spellcheck: setting languages to: ["de"] INFO 2020-11-25T17:26:31.388Z Begin ensuring permissions INFO 2020-11-25T17:26:31.397Z Ensuring file permissions for 2 files INFO 2020-11-25T17:26:31.398Z Finish ensuring permissions in 10ms INFO 2020-11-25T17:26:32.188Z x-attr dependency did not load successfully INFO 2020-11-25T17:26:32.218Z preload complete INFO 2020-11-25T17:26:32.382Z pre-main prep time: 1 ms INFO 2020-11-25T17:26:32.446Z background page reloaded INFO 2020-11-25T17:26:32.446Z environment: production INFO 2020-11-25T17:26:32.463Z SQL channel job 1 (getItemById) succeeded in 17ms INFO 2020-11-25T17:26:32.463Z Storage fetch INFO 2020-11-25T17:26:32.571Z SQL channel job 2 (getAllItems) succeeded in 107ms INFO 2020-11-25T17:26:32.590Z SQL channel job 3 (createOrUpdateItem) succeeded in 17ms INFO 2020-11-25T17:26:32.605Z SQL channel job 4 (createOrUpdateItem) succeeded in 15ms INFO 2020-11-25T17:26:32.621Z SQL channel job 5 (createOrUpdateItem) succeeded in 31ms INFO 2020-11-25T17:26:32.621Z Starting background data migration. Target version: 10 INFO 2020-11-25T17:26:32.624Z GET https://textsecure-service.whispersystems.org/v1/config INFO 2020-11-25T17:26:32.630Z ConversationController: starting initial fetch INFO 2020-11-25T17:26:32.649Z SQL channel job 7 (getAllStickerPacks) succeeded in 19ms INFO 2020-11-25T17:26:32.649Z SQL channel job 9 (getRecentStickers) succeeded in 19ms INFO 2020-11-25T17:26:32.649Z SQL channel job 8 (getAllStickers) succeeded in 19ms INFO 2020-11-25T17:26:32.650Z SQL channel job 10 (getRecentEmojis) succeeded in 20ms INFO 2020-11-25T17:26:32.650Z SQL channel job 11 (getItemById) succeeded in 19ms INFO 2020-11-25T17:26:32.650Z SQL channel job 13 (getAllIdentityKeys) succeeded in 19ms INFO 2020-11-25T17:26:32.651Z SignalProtocolStore: Finished caching identityKeys data INFO 2020-11-25T17:26:32.651Z SQL channel job 14 (getAllSessions) succeeded in 20ms INFO 2020-11-25T17:26:32.651Z SignalProtocolStore: Finished caching sessions data INFO 2020-11-25T17:26:32.651Z SQL channel job 12 (getItemById) succeeded in 20ms INFO 2020-11-25T17:26:32.659Z SQL channel job 52 (getLastConversationActivity) succeeded in 11ms INFO 2020-11-25T17:26:32.659Z SQL channel job 53 (getLastConversationPreview) succeeded in 11ms INFO 2020-11-25T17:26:32.659Z SQL channel job 55 (getLastConversationPreview) succeeded in 11ms INFO 2020-11-25T17:26:32.659Z SQL channel job 54 (getLastConversationActivity) succeeded in 11ms INFO 2020-11-25T17:26:32.660Z SQL channel job 56 (getLastConversationActivity) succeeded in 12ms INFO 2020-11-25T17:26:32.660Z SQL channel job 57 (getLastConversationPreview) succeeded in 12ms INFO 2020-11-25T17:26:32.660Z SQL channel job 58 (getLastConversationActivity) succeeded in 12ms INFO 2020-11-25T17:26:32.660Z SQL channel job 59 (getLastConversationPreview) succeeded in 12ms INFO 2020-11-25T17:26:32.660Z SQL channel job 60 (getLastConversationActivity) succeeded in 12ms INFO 2020-11-25T17:26:32.661Z SQL channel job 61 (getLastConversationPreview) succeeded in 13ms INFO 2020-11-25T17:26:32.661Z SQL channel job 62 (getLastConversationActivity) succeeded in 13ms INFO 2020-11-25T17:26:32.661Z SQL channel job 63 (getLastConversationPreview) succeeded in 13ms INFO 2020-11-25T17:26:32.662Z SQL channel job 64 (getLastConversationActivity) succeeded in 14ms INFO 2020-11-25T17:26:32.662Z SQL channel job 65 (getLastConversationPreview) succeeded in 14ms INFO 2020-11-25T17:26:32.662Z SQL channel job 66 (getLastConversationActivity) succeeded in 14ms INFO 2020-11-25T17:26:32.662Z SQL channel job 67 (getLastConversationPreview) succeeded in 14ms INFO 2020-11-25T17:26:32.663Z SQL channel job 68 (getLastConversationActivity) succeeded in 15ms INFO 2020-11-25T17:26:32.663Z SQL channel job 69 (getLastConversationPreview) succeeded in 15ms INFO 2020-11-25T17:26:32.663Z SQL channel job 70 (getLastConversationActivity) succeeded in 15ms INFO 2020-11-25T17:26:32.663Z SQL channel job 71 (getLastConversationPreview) succeeded in 15ms INFO 2020-11-25T17:26:32.663Z SQL channel job 72 (getLastConversationActivity) succeeded in 15ms INFO 2020-11-25T17:26:32.664Z SQL channel job 73 (getLastConversationPreview) succeeded in 16ms INFO 2020-11-25T17:26:32.664Z SQL channel job 74 (getLastConversationActivity) succeeded in 16ms INFO 2020-11-25T17:26:32.664Z SQL channel job 76 (getLastConversationActivity) succeeded in 16ms INFO 2020-11-25T17:26:32.664Z SQL channel job 75 (getLastConversationPreview) succeeded in 16ms INFO 2020-11-25T17:26:32.665Z SQL channel job 77 (getLastConversationPreview) succeeded in 17ms INFO 2020-11-25T17:26:32.665Z SQL channel job 78 (getLastConversationActivity) succeeded in 17ms INFO 2020-11-25T17:26:32.665Z SQL channel job 79 (getLastConversationPreview) succeeded in 17ms INFO 2020-11-25T17:26:32.665Z SQL channel job 80 (getLastConversationActivity) succeeded in 17ms INFO 2020-11-25T17:26:32.665Z SQL channel job 81 (getLastConversationPreview) succeeded in 17ms INFO 2020-11-25T17:26:32.665Z SQL channel job 82 (getLastConversationActivity) succeeded in 16ms INFO 2020-11-25T17:26:32.666Z SQL channel job 83 (getLastConversationPreview) succeeded in 17ms INFO 2020-11-25T17:26:32.666Z SQL channel job 84 (getLastConversationActivity) succeeded in 17ms INFO 2020-11-25T17:26:32.666Z SQL channel job 85 (getLastConversationPreview) succeeded in 17ms INFO 2020-11-25T17:26:32.666Z SQL channel job 86 (getLastConversationActivity) succeeded in 17ms INFO 2020-11-25T17:26:32.666Z SQL channel job 87 (getLastConversationPreview) succeeded in 17ms INFO 2020-11-25T17:26:32.666Z SQL channel job 88 (getLastConversationActivity) succeeded in 17ms INFO 2020-11-25T17:26:32.666Z ConversationController: done with initial fetch INFO 2020-11-25T17:26:32.666Z SQL channel job 89 (getAllPreKeys) succeeded in 15ms INFO 2020-11-25T17:26:32.669Z SignalProtocolStore: Finished caching preKeys data INFO 2020-11-25T17:26:32.669Z SQL channel job 90 (getAllSignedPreKeys) succeeded in 18ms INFO 2020-11-25T17:26:32.669Z SignalProtocolStore: Finished caching signedPreKeys data INFO 2020-11-25T17:26:32.669Z checkForConflicts: starting... INFO 2020-11-25T17:26:32.669Z checkForConflicts: complete! INFO 2020-11-25T17:26:32.684Z Cleanup: starting... INFO 2020-11-25T17:26:32.685Z Initializing network observer every 5000ms INFO 2020-11-25T17:26:32.685Z Build expires: 2021-02-21T18:41:50.000Z INFO 2020-11-25T17:26:32.685Z SQL channel job 91 (updateConversations) succeeded in 25ms INFO 2020-11-25T17:26:32.685Z Cleanup: Found 0 messages for cleanup INFO 2020-11-25T17:26:32.685Z Cleanup: complete INFO 2020-11-25T17:26:32.685Z listening for registration events INFO 2020-11-25T17:26:32.689Z connect {"connectCount":0} INFO 2020-11-25T17:26:32.689Z GET https://textsecure-service.whispersystems.org/v1/config INFO 2020-11-25T17:26:32.690Z open inbox INFO 2020-11-25T17:26:32.735Z SQL channel job 93 (getNextExpiringMessage) succeeded in 47ms INFO 2020-11-25T17:26:32.736Z SQL channel job 94 (getNextTapToViewMessageToAgeOut) succeeded in 48ms INFO 2020-11-25T17:26:33.179Z SQL channel job 95 (updateConversations) succeeded in 13ms INFO 2020-11-25T17:26:33.449Z GET https://textsecure-service.whispersystems.org/v1/config 200 Success INFO 2020-11-25T17:26:33.449Z GET https://textsecure-service.whispersystems.org/v1/config 200 Success INFO 2020-11-25T17:26:33.449Z Initializing socket and listening for messages INFO 2020-11-25T17:26:33.450Z getAllFromCache INFO 2020-11-25T17:26:33.450Z opening message socket https://textsecure-service.whispersystems.org INFO 2020-11-25T17:26:33.451Z initializeGroupCredentialFetcher: starting... INFO 2020-11-25T17:26:33.452Z maybeFetchCredentials: no new credentials needed INFO 2020-11-25T17:26:33.452Z attachment_downloads/start: enabling INFO 2020-11-25T17:26:33.452Z Start idle detector INFO 2020-11-25T17:26:33.458Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]372 INFO 2020-11-25T17:26:33.464Z SQL channel job 96 (createOrUpdateItem) succeeded in 15ms INFO 2020-11-25T17:26:33.473Z SQL channel job 97 (createOrUpdateItem) succeeded in 24ms INFO 2020-11-25T17:26:33.473Z SQL channel job 98 (getUnprocessedCount) succeeded in 23ms INFO 2020-11-25T17:26:33.474Z SQL channel job 99 (resetAttachmentDownloadPending) succeeded in 22ms INFO 2020-11-25T17:26:33.474Z getAllFromCache loaded 0 saved envelopes INFO 2020-11-25T17:26:33.597Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]372 200 Success INFO 2020-11-25T17:26:33.664Z SQL channel job 102 (createOrUpdateItem) succeeded in 17ms INFO 2020-11-25T17:26:33.972Z SQL channel job 103 (createOrUpdateSessions) succeeded in 15ms INFO 2020-11-25T17:26:34.520Z websocket open INFO 2020-11-25T17:26:34.907Z SQL channel job 104 (saveUnprocesseds) succeeded in 13ms INFO 2020-11-25T17:26:34.908Z queueing envelope 2d8b29ad561a41e6b7888897b963123f INFO 2020-11-25T17:26:34.908Z received unidentified sender message INFO 2020-11-25T17:26:34.908Z queueing envelope f4197396a86d485a997a940432978610 INFO 2020-11-25T17:26:34.909Z queueing envelope 874ccc8a7d274109a5cce3c707e3dbe1 INFO 2020-11-25T17:26:34.909Z queueing envelope [REDACTED]372.1 1606324927507 (b13ad644f0ba4be4a3007e88cb1bdc28) INFO 2020-11-25T17:26:34.909Z queueing envelope 564d6276b6ca474eba19beda55023cf5 INFO 2020-11-25T17:26:34.909Z queueing envelope 6807230ca602485fa3e3f7c9841aeb82 INFO 2020-11-25T17:26:34.913Z New remote ephemeral key INFO 2020-11-25T17:26:34.915Z Deleting chain closed at 1605965482926 INFO 2020-11-25T17:26:34.917Z CallingClass.handleCallingMessage() INFO 2020-11-25T17:26:34.918Z CallingClass.handleCallingMessage(): Handling in RingRTC INFO 2020-11-25T17:26:34.918Z received unidentified sender message INFO 2020-11-25T17:26:34.921Z CallingClass.handleCallingMessage() INFO 2020-11-25T17:26:34.922Z CallingClass.handleCallingMessage(): Handling in RingRTC INFO 2020-11-25T17:26:34.922Z received unidentified sender message INFO 2020-11-25T17:26:34.925Z CallingClass.handleCallingMessage() INFO 2020-11-25T17:26:34.925Z CallingClass.handleCallingMessage(): Handling in RingRTC INFO 2020-11-25T17:26:34.925Z message from [REDACTED]372.1 1606324927507 (b13ad644f0ba4be4a3007e88cb1bdc28) INFO 2020-11-25T17:26:34.925Z New remote ephemeral key INFO 2020-11-25T17:26:34.927Z Deleting chain closed at 1606115829073 INFO 2020-11-25T17:26:34.927Z got keys sync message INFO 2020-11-25T17:26:34.928Z onKeysSync: received keys INFO 2020-11-25T17:26:34.928Z received unidentified sender message INFO 2020-11-25T17:26:34.930Z CallingClass.handleCallingMessage() INFO 2020-11-25T17:26:34.931Z CallingClass.handleCallingMessage(): Handling in RingRTC INFO 2020-11-25T17:26:34.931Z received unidentified sender message INFO 2020-11-25T17:26:34.933Z CallingClass.handleCallingMessage() INFO 2020-11-25T17:26:34.933Z CallingClass.handleCallingMessage(): Handling in RingRTC INFO 2020-11-25T17:26:34.945Z src/core/call_manager.rs:427 API:received_offer(): INFO 2020-11-25T17:26:34.945Z src/core/call_manager.rs:1066 ringrtc! 1606325194918 app -> cm: received_offer() 0xe5ba128973225f32 1 feature=MultiRing primary=false opaque=true/3208; sdp=true/2898 INFO 2020-11-25T17:26:34.945Z src/core/call_manager.rs:1080 ringrtc! 1606325194918 cm -x app: offer expired INFO 2020-11-25T17:26:34.945Z src/core/call_manager.rs:1764 ringrtc! 1606325194918 cm -> app: event(ReceivedOfferExpired) INFO 2020-11-25T17:26:34.945Z src/native.rs:438 NativePlatform::on_event(): remote_peer: [REDACTED]429, event: ReceivedOfferExpired INFO 2020-11-25T17:26:34.945Z src/core/call_manager.rs:1837 ringrtc! 1606325194918 cm -> app: call_concluded() 0xe5ba128973225f32 INFO 2020-11-25T17:26:34.945Z src/native.rs:519 NativePlatform::on_call_concluded(): remote_peer: [REDACTED]429 INFO 2020-11-25T17:26:34.945Z src/core/call_manager.rs:456 API:CallManager::handle_received_ice(): INFO 2020-11-25T17:26:34.945Z src/core/call_manager.rs:1284 ringrtc! 1606325194922 app -> cm: received_ice_candidates(10) 0xe5ba128973225f32 1 INFO 2020-11-25T17:26:34.945Z src/core/call_manager.rs:1295 ringrtc! 1606325194922 cm -x app: inactive INFO 2020-11-25T17:26:34.945Z src/core/call_manager.rs:456 API:CallManager::handle_received_ice(): INFO 2020-11-25T17:26:34.945Z src/core/call_manager.rs:1284 ringrtc! 1606325194925 app -> cm: received_ice_candidates(4) 0xe5ba128973225f32 1 INFO 2020-11-25T17:26:34.945Z src/core/call_manager.rs:1295 ringrtc! 1606325194925 cm -x app: inactive INFO 2020-11-25T17:26:34.945Z src/core/call_manager.rs:456 API:CallManager::handle_received_ice(): INFO 2020-11-25T17:26:34.945Z src/core/call_manager.rs:1284 ringrtc! 1606325194931 app -> cm: received_ice_candidates(1) 0xe5ba128973225f32 1 INFO 2020-11-25T17:26:34.945Z src/core/call_manager.rs:1295 ringrtc! 1606325194931 cm -x app: inactive INFO 2020-11-25T17:26:34.945Z src/core/call_manager.rs:465 API:CallManager::handle_received_hangup(): INFO 2020-11-25T17:26:34.945Z src/core/call_manager.rs:1310 ringrtc! 1606325194933 app -> cm: received_hangup(Normal/None) 0xe5ba128973225f32 1 INFO 2020-11-25T17:26:34.945Z src/core/call_manager.rs:1319 ringrtc! 1606325194933 cm -x app: inactive INFO 2020-11-25T17:26:34.958Z SQL channel job 106 (saveMessage) succeeded in 13ms INFO 2020-11-25T17:26:35.075Z got request PUT /api/v1/queue/empty INFO 2020-11-25T17:26:35.075Z MessageReceiver: finished processing messages after 'empty', now waiting for application INFO 2020-11-25T17:26:35.075Z MessageReceiver: emitting 'empty' event INFO 2020-11-25T17:26:35.095Z SQL channel job 107 (createOrUpdateSessions) succeeded in 20ms INFO 2020-11-25T17:26:35.107Z SQL channel job 108 (updateUnprocessedsWithData) succeeded in 31ms INFO 2020-11-25T17:26:35.118Z SQL channel job 109 (removeUnprocessed) succeeded in 42ms INFO 2020-11-25T17:26:35.118Z onEmpty: All outstanding database requests complete INFO 2020-11-25T17:26:35.118Z Next signed key rotation scheduled for 2020-11-27T16:46:46.838Z INFO 2020-11-25T17:26:35.118Z refreshSenderCertificate: Getting new certificate... INFO 2020-11-25T17:26:35.119Z updater/start: Updates disabled - not starting new version checks INFO 2020-11-25T17:26:35.119Z GET https://textsecure-service.whispersystems.org/v1/certificate/delivery?includeUuid=true INFO 2020-11-25T17:26:35.266Z GET https://textsecure-service.whispersystems.org/v1/certificate/delivery?includeUuid=true 200 Success INFO 2020-11-25T17:26:35.266Z Next sender certificate refresh scheduled for 2020-11-26T17:26:35.266Z INFO 2020-11-25T17:26:35.266Z refreshOurProfile INFO 2020-11-25T17:26:35.268Z GET https://textsecure-service.whispersystems.org/v1/profile/[REDACTED]372/[REDACTED]e81 (unauth) INFO 2020-11-25T17:26:35.282Z SQL channel job 112 (createOrUpdateItem) succeeded in 16ms INFO 2020-11-25T17:26:35.304Z SQL channel job 113 (saveUnprocesseds) succeeded in 11ms INFO 2020-11-25T17:26:35.304Z queueing envelope [REDACTED]372.1 1606325195459 (c728e5eebc2d4a59b0d43a84cbf2d59b) INFO 2020-11-25T17:26:35.304Z message from [REDACTED]372.1 1606325195459 (c728e5eebc2d4a59b0d43a84cbf2d59b) INFO 2020-11-25T17:26:35.305Z got keys sync message INFO 2020-11-25T17:26:35.305Z onKeysSync: received keys INFO 2020-11-25T17:26:35.316Z SQL channel job 114 (createOrUpdateItem) succeeded in 11ms INFO 2020-11-25T17:26:35.814Z SQL channel job 115 (updateConversations) succeeded in 135ms INFO 2020-11-25T17:26:35.823Z storageService.sync: starting... INFO 2020-11-25T17:26:35.823Z storageService.fetchManifest INFO 2020-11-25T17:26:35.824Z GET https://textsecure-service.whispersystems.org/v1/storage/auth INFO 2020-11-25T17:26:35.844Z SQL channel job 116 (createOrUpdateSessions) succeeded in 18ms INFO 2020-11-25T17:26:35.852Z SQL channel job 117 (updateUnprocessedsWithData) succeeded in 26ms INFO 2020-11-25T17:26:35.871Z SQL channel job 118 (removeUnprocessed) succeeded in 45ms INFO 2020-11-25T17:26:35.993Z GET https://textsecure-service.whispersystems.org/v1/storage/auth 200 Success INFO 2020-11-25T17:26:35.993Z GET https://storage.signal.org/v1/storage/manifest/version/64 INFO 2020-11-25T17:26:36.008Z SQL channel job 121 (createOrUpdateItem) succeeded in 14ms INFO 2020-11-25T17:26:36.457Z GET https://storage.signal.org/v1/storage/manifest/version/64 204 Success INFO 2020-11-25T17:26:36.457Z storageService.fetchManifest: nothing changed INFO 2020-11-25T17:26:36.457Z storageService.sync: no new manifest INFO 2020-11-25T17:26:36.500Z GET https://textsecure-service.whispersystems.org/v1/profile/[REDACTED]372/[REDACTED]e81 200 Success INFO 2020-11-25T17:26:36.500Z Setting sealedSender to ENABLED for conversation [REDACTED]372 ([REDACTED]34d) INFO 2020-11-25T17:26:36.501Z GET https://cdn.signal.org/[REDACTED]yaA INFO 2020-11-25T17:26:36.523Z SQL channel job 122 (createOrUpdateItem) succeeded in 22ms INFO 2020-11-25T17:26:37.162Z GET https://cdn.signal.org/[REDACTED]yaA 200 Success INFO 2020-11-25T17:26:37.262Z open inbox INFO 2020-11-25T17:26:37.302Z GET https://textsecure-service.whispersystems.org/v1/profile/[REDACTED]429/[REDACTED]755 (unauth) INFO 2020-11-25T17:26:37.308Z SQL channel job 123 (getMessageMetricsForConversation) succeeded in 13ms INFO 2020-11-25T17:26:37.312Z SQL channel job 125 (getLastConversationActivity) succeeded in 17ms INFO 2020-11-25T17:26:37.313Z SQL channel job 124 (getLastConversationPreview) succeeded in 18ms INFO 2020-11-25T17:26:37.320Z SQL channel job 126 (getMessageById) succeeded in 12ms INFO 2020-11-25T17:26:37.376Z SQL channel job 130 (saveMessage) succeeded in 32ms INFO 2020-11-25T17:26:37.400Z SQL channel job 131 (saveMessage) succeeded in 24ms INFO 2020-11-25T17:26:37.582Z GET https://textsecure-service.whispersystems.org/v1/profile/[REDACTED]429/[REDACTED]755 200 Success INFO 2020-11-25T17:26:37.583Z Setting sealedSender to ENABLED for conversation [REDACTED]429 ([REDACTED]31e) INFO 2020-11-25T17:26:37.802Z SQL channel job 134 (saveMessage) succeeded in 21ms INFO 2020-11-25T17:26:38.279Z SQL channel job 135 (createOrUpdateItem) succeeded in 17ms INFO 2020-11-25T17:26:38.318Z SQL channel job 136 (updateConversations) succeeded in 15ms INFO 2020-11-25T17:26:41.022Z onOutgoingAudioCallInConversation: about to start an audio call INFO 2020-11-25T17:26:41.023Z onOutgoingAudioCallInConversation: call is deemed "safe". Making call INFO 2020-11-25T17:26:41.023Z CallingClass.startCallingLobby() INFO 2020-11-25T17:26:41.024Z CallingClass.startCallingLobby(): Getting call settings INFO 2020-11-25T17:26:41.024Z CallingClass.startCallingLobby(): Starting lobby ERROR 2020-11-25T17:26:41.045Z src/webrtc/peer_connection_factory.rs:438 getAudioRecordingDevices() returned -1 ERROR 2020-11-25T17:26:41.046Z src/webrtc/peer_connection_factory.rs:336 getAudioPlayoutDevices() returned -1 INFO 2020-11-25T17:26:41.091Z MediaDevice: available devices changed (from->to) {"availableMicrophones":[],"availableSpeakers":[],"availableCameras":[]} INFO 2020-11-25T17:26:41.092Z onOutgoingAudioCallInConversation: started the call INFO 2020-11-25T17:26:42.055Z SQL channel job 141 (updateConversations) succeeded in 12ms ERROR 2020-11-25T17:26:44.102Z src/webrtc/peer_connection_factory.rs:438 getAudioRecordingDevices() returned -1 ERROR 2020-11-25T17:26:44.102Z src/webrtc/peer_connection_factory.rs:336 getAudioPlayoutDevices() returned -1 INFO 2020-11-25T17:26:45.515Z CallingClass.startCallingLobby() INFO 2020-11-25T17:26:45.521Z CallingClass.startOutgoingCall(): Getting call settings INFO 2020-11-25T17:26:45.521Z GET https://textsecure-service.whispersystems.org/v1/accounts/turn INFO 2020-11-25T17:26:45.670Z GET https://textsecure-service.whispersystems.org/v1/accounts/turn 200 Success INFO 2020-11-25T17:26:45.671Z CallingClass.startOutgoingCall(): Starting in RingRTC INFO 2020-11-25T17:26:45.707Z src/core/call_manager.rs:371 API:create_outgoing_call(0x7cce0d12520792): INFO 2020-11-25T17:26:45.707Z src/core/call_manager.rs:855 ringrtc! 1606325205671 app -> cm: call() 0x7cce0d12520792 INFO 2020-11-25T17:26:45.707Z src/core/call.rs:227 new(): call_id: 0x7cce0d12520792 INFO 2020-11-25T17:26:45.707Z src/core/call_fsm.rs:258 syncing worker thread: ThreadId(3) INFO 2020-11-25T17:26:45.707Z src/core/call_fsm.rs:258 syncing notify thread: ThreadId(4) INFO 2020-11-25T17:26:45.707Z src/core/call_fsm.rs:215 state: NotYetStarted, event: (StartCall) INFO 2020-11-25T17:26:45.707Z src/core/call_fsm.rs:365 handle_start_call(): INFO 2020-11-25T17:26:45.707Z src/core/call_manager.rs:1748 ringrtc! 1606325205671 cm -> app: start() 0x7cce0d12520792 INFO 2020-11-25T17:26:45.707Z src/native.rs:423 NativePlatform::on_start_call(): remote_peer: [REDACTED]429, call_id: 0x7cce0d12520792, direction: OutGoing, call_media_type: Audio ERROR 2020-11-25T17:26:45.707Z src/webrtc/peer_connection_factory.rs:438 getAudioRecordingDevices() returned -1 ERROR 2020-11-25T17:26:45.707Z src/webrtc/peer_connection_factory.rs:336 getAudioPlayoutDevices() returned -1 INFO 2020-11-25T17:26:45.758Z src/core/call_manager.rs:402 API:CallManager::handle_proceed(): INFO 2020-11-25T17:26:45.758Z src/core/call_manager.rs:938 ringrtc! 1606325205708 app -> cm: proceed() 0x7cce0d12520792 INFO 2020-11-25T17:26:45.758Z src/core/call_manager.rs:944 handle_proceed(): active call_id: 0x7cce0d12520792 INFO 2020-11-25T17:26:45.758Z src/core/call_fsm.rs:215 state: WaitingToProceed, event: (Proceed) INFO 2020-11-25T17:26:45.758Z src/core/call_fsm.rs:378 handle_proceed(): INFO 2020-11-25T17:26:45.758Z src/core/call.rs:510 proceed(): INFO 2020-11-25T17:26:45.758Z src/native.rs:356 NativePlatform::create_connection(): call: thread: ThreadId(3), direction: OutGoing, call_id: 0x7cce0d12520792, state: "ConnectingBeforeAccepted" remote_device_id: 0 signaling_version: V2 INFO 2020-11-25T17:26:45.758Z src/webrtc/peer_connection_observer.rs:240 pc_observer_OnSignalingDataChannel(): 0x7cce0d12520792-0 INFO 2020-11-25T17:26:45.758Z src/webrtc/data_channel.rs:57 data channel is reliable: false INFO 2020-11-25T17:26:45.758Z src/webrtc/data_channel.rs:57 data channel is reliable: false INFO 2020-11-25T17:26:45.758Z src/webrtc/sdp_observer.rs:436 csd_observer_OnSuccess() INFO 2020-11-25T17:26:45.758Z src/webrtc/sdp_observer.rs:361 on_create_success() INFO 2020-11-25T17:26:45.758Z src/core/connection.rs:513 Using V4 signaling for outgoing connection offer: ConnectionParametersV4 { public_key: Some([206, 241, 236, 29, 182, 42, 177, 214, 242, 62, 130, 136, 225, 182, 178, 217, 253, 140, 251, 44, 159, 97, 115, 134, 220, 240, 117, 76, 13, 2, 202, 91]), ice_ufrag: Some("868B"), ice_pwd: Some("IVNA2C0yQec1m8EfDn/AO88K"), receive_video_codecs: [VideoCodec { r#type: Some(Vp8), level: None }] } SDP: v=0 o=- 1 1 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE audio video data a=msid-semantic: WMS m=audio 9 RTP/SAVPF 102 c=IN IP4 0.0.0.0 a=rtcp:9 IN IP4 0.0.0.0 a=ice-ufrag:868B a=ice-pwd:IVNA2C0yQec1m8EfDn/AO88K a=ice-options:trickle renomination a=mid:audio a=extmap:1 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:12 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=sendrecv a=rtcp-mux a=crypto:0 AEAD_AES_256_GCM inline: a=rtpmap:102 opus/48000/2 a=rtcp-fb:102 transport-cc a=fmtp:102 cbr=1;maxaveragebitrate=40000;minptime=10;stereo=0;usedtx=0;useinbandfec=1 a=maxptime:120 a=ptime:20 a=ssrc:1002 cname:CNAMECNAMECNAME! a=ssrc:1002 msid:- audio1 a=ssrc:1002 mslabel:- a=ssrc:1002 label:audio1 m=video 9 RTP/SAVPF 108 118 120 121 122 c=IN IP4 0.0.0.0 a=rtcp:9 IN IP4 0.0.0.0 a=ice-ufrag:868B a=ice-pwd:IVNA2C0yQec1m8EfDn/AO88K a=ice-options:trickle renomination a=mid:video a=extmap:1 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:4 urn:3gpp:video-orientation a=extmap:12 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=extmap:13 urn:ietf:params:rtp-hdrext:toffset a=sendrecv a=rtcp-mux a=rtcp-rsize a=crypto:0 AEAD_AES_256_GCM inline: a=rtpmap:108 VP8/90000 a=rtcp-fb:108 transport-cc a=rtcp-fb:108 ccm fir a=rtcp-fb:108 nack a=rtcp-fb:108 nack pli a=rtcp-fb:108 goog-remb a=rtpmap:118 rtx/90000 a=fmtp:118 apt=108 a=rtpmap:120 red/90000 a=rtpmap:121 rtx/90000 a=fmtp:121 apt=120 a=rtpmap:122 ulpfec/90000 a=ssrc-group:FID 1003 1013 a=ssrc:1003 cname:CNAMECNAMECNAME! a=ssrc:1003 msid:- video1 a=ssrc:1003 mslabel:- a=ssrc:1003 label:video1 a=ssrc:1013 cname:CNAMECNAMECNAME! a=ssrc:1013 msid:- video1 a=ssrc:1013 mslabel:- a=ssrc:1013 label:video1 m=application 9 RTP/SAVPF 101 c=IN IP4 0.0.0.0 b=AS:30 a=rtcp:9 IN IP4 0.0.0.0 a=ice-ufrag:868B a=ice-pwd:IVNA2C0yQec1m8EfDn/AO88K a=ice-options:trickle renomination a=mid:data a=sendrecv a=rtcp-mux a=crypto:0 AEAD_AES_256_GCM inline: a=rtpmap:101 google-data/90000 a=ssrc:1001 cname:CNAMECNAMECNAME! a=ssrc:1001 msid:signaling signaling a=ssrc:1001 mslabel:signaling a=ssrc:1001 label:signaling original SDP: v=0 o=- 3148156746602348068 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE audio video data a=msid-semantic: WMS s m=audio 9 UDP/TLS/RTP/SAVPF 111 c=IN IP4 0.0.0.0 a=rtcp:9 IN IP4 0.0.0.0 a=ice-ufrag:868B a=ice-pwd:IVNA2C0yQec1m8EfDn/AO88K a=ice-options:trickle a=fingerprint:sha-256 62:94:87:89:AA:B5:C8:FD:D6:79:9A:7E:5A:99:14:A7:81:71:64:6F:87:03:1C:52:17:4E:BB:86:AE:C0:CB:98 a=setup:actpass a=mid:audio a=extmap:1 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=extmap:2 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=sendrecv a=rtcp-mux a=rtpmap:111 opus/48000/2 a=rtcp-fb:111 transport-cc a=fmtp:111 cbr=1;minptime=10;useinbandfec=1 a=ssrc:4213760127 cname:u8RIFbfvL+4zI8f3 a=ssrc:4213760127 msid:s audio1 a=ssrc:4213760127 mslabel:s a=ssrc:4213760127 label:audio1 m=video 9 UDP/TLS/RTP/SAVPF 96 97 98 99 100 101 102 103 104 c=IN IP4 0.0.0.0 a=rtcp:9 IN IP4 0.0.0.0 a=ice-ufrag:868B a=ice-pwd:IVNA2C0yQec1m8EfDn/AO88K a=ice-options:trickle a=fingerprint:sha-256 62:94:87:89:AA:B5:C8:FD:D6:79:9A:7E:5A:99:14:A7:81:71:64:6F:87:03:1C:52:17:4E:BB:86:AE:C0:CB:98 a=setup:actpass a=mid:video a=extmap:14 urn:ietf:params:rtp-hdrext:toffset a=extmap:1 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=extmap:3 urn:3gpp:video-orientation a=extmap:2 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=sendrecv a=rtcp-mux a=rtcp-rsize a=rtpmap:96 VP8/90000 a=rtcp-fb:96 goog-remb a=rtcp-fb:96 transport-cc a=rtcp-fb:96 ccm fir a=rtcp-fb:96 nack a=rtcp-fb:96 nack pli a=rtpmap:97 rtx/90000 a=fmtp:97 apt=96 a=rtpmap:98 VP9/90000 a=rtcp-fb:98 goog-remb a=rtcp-fb:98 transport-cc a=rtcp-fb:98 ccm fir a=rtcp-fb:98 nack a=rtcp-fb:98 nack pli a=fmtp:98 profile-id=0 a=rtpmap:99 rtx/90000 a=fmtp:99 apt=98 a=rtpmap:100 VP9/90000 a=rtcp-fb:100 goog-remb a=rtcp-fb:100 transport-cc a=rtcp-fb:100 ccm fir a=rtcp-fb:100 nack a=rtcp-fb:100 nack pli a=fmtp:100 profile-id=2 a=rtpmap:101 rtx/90000 a=fmtp:101 apt=100 a=rtpmap:102 red/90000 a=rtpmap:103 rtx/90000 a=fmtp:103 apt=102 a=rtpmap:104 ulpfec/90000 a=ssrc-group:FID 1915658624 1336426788 a=ssrc:1915658624 cname:u8RIFbfvL+4zI8f3 a=ssrc:1915658624 msid:s video1 a=ssrc:1915658624 mslabel:s a=ssrc:1915658624 label:video1 a=ssrc:1336426788 cname:u8RIFbfvL+4zI8f3 a=ssrc:1336426788 msid:s video1 a=ssrc:1336426788 mslabel:s a=ssrc:1336426788 label:video1 m=application 9 UDP/TLS/RTP/SAVPF 109 c=IN IP4 0.0.0.0 b=AS:30 a=rtcp:9 IN IP4 0.0.0.0 a=ice-ufrag:868B a=ice-pwd:IVNA2C0yQec1m8EfDn/AO88K a=ice-options:trickle a=fingerprint:sha-256 62:94:87:89:AA:B5:C8:FD:D6:79:9A:7E:5A:99:14:A7:81:71:64:6F:87:03:1C:52:17:4E:BB:86:AE:C0:CB:98 a=setup:actpass a=mid:data a=sendrecv a=rtcp-mux a=rtpmap:109 google-data/90000 a=ssrc:749208530 cname:u8RIFbfvL+4zI8f3 a=ssrc:749208530 msid:signaling signaling a=ssrc:749208530 mslabel:signaling a=ssrc:749208530 label:signaling INFO 2020-11-25T17:26:45.758Z src/webrtc/sdp_observer.rs:605 ssd_observer_OnSuccess() INFO 2020-11-25T17:26:45.758Z src/webrtc/sdp_observer.rs:535 on_set_success() INFO 2020-11-25T17:26:45.758Z src/core/connection.rs:466 Starting Connection FSM for 0x7cce0d12520792-0 INFO 2020-11-25T17:26:45.758Z src/core/connection_fsm.rs:328 syncing worker thread: ThreadId(7) INFO 2020-11-25T17:26:45.758Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-0 INFO 2020-11-25T17:26:45.758Z src/core/connection_fsm.rs:328 syncing notify thread: ThreadId(8) INFO 2020-11-25T17:26:45.758Z src/core/call_manager.rs:1894 send_offer(): call_id: 0x7cce0d12520792 INFO 2020-11-25T17:26:45.758Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:26:45.758Z src/core/call_manager.rs:1659 send_next_message(): sending message, len: 0 INFO 2020-11-25T17:26:45.758Z src/core/call_manager.rs:1897 ringrtc! 1606325205713 cm -> app: send_offer() 0x7cce0d12520792 opaque=true/3089; sdp=true/2789 INFO 2020-11-25T17:26:45.758Z src/core/connection_fsm.rs:282 state: IceGathering, event: (ReceivedSignalingDataChannel, dc: 0x2542d5e2ace0) INFO 2020-11-25T17:26:45.758Z src/core/connection_fsm.rs:951 ringrtc! 1606325205713 rtc -> conn: on_data_channel() WARN 2020-11-25T17:26:45.758Z src/core/connection_fsm.rs:1006 Unexpected event ReceivedSignalingDataChannel, while in state IceGathering INFO 2020-11-25T17:26:45.758Z src/core/connection_fsm.rs:282 state: IceGathering, event: (LocalIceCandidate) INFO 2020-11-25T17:26:45.758Z src/core/connection_fsm.rs:782 ringrtc! 1606325205713 rtc -> conn: ice_candidate() 0x7cce0d12520792-0 INFO 2020-11-25T17:26:45.758Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-0 INFO 2020-11-25T17:26:45.758Z src/core/connection_fsm.rs:282 state: IceGathering, event: (LocalIceCandidate) INFO 2020-11-25T17:26:45.758Z src/core/connection_fsm.rs:782 ringrtc! 1606325205713 rtc -> conn: ice_candidate() 0x7cce0d12520792-0 INFO 2020-11-25T17:26:45.758Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-0 INFO 2020-11-25T17:26:45.758Z src/core/connection_fsm.rs:282 state: IceGathering, event: (LocalIceCandidate) INFO 2020-11-25T17:26:45.758Z src/core/connection_fsm.rs:782 ringrtc! 1606325205713 rtc -> conn: ice_candidate() 0x7cce0d12520792-0 INFO 2020-11-25T17:26:45.758Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/124; sdp=true/120; opaque: ...; sdp: candidate:1967680543 1 udp 2122260223 [REDACTED] 55670 typ host generation 0 ufrag 868B network-id 1 network-cost 50 INFO 2020-11-25T17:26:45.758Z src/core/call.rs:456 send_buffered_local_ice_candidates(): ConnectingBeforeAccepted INFO 2020-11-25T17:26:45.758Z src/core/call_manager.rs:1903 call_id: 0x7cce0d12520792, TX offer: opaque: ...; sdp: v=0 o=- 3148156746602348068 2 IN IP4 [REDACTED] s=- t=0 0 a=group:BUNDLE audio video data a=msid-semantic: WMS s m=audio 9 UDP/TLS/RTP/SAVPF 111 c=IN IP4 [REDACTED] a=rtcp:9 IN IP4 [REDACTED] a=ice-ufrag:868B a=ice-pwd:[ REDACTED ] a=ice-options:trickle a=fingerprint:sha-256 [REDACTED]:[REDACTED]:[REDACTED]:[REDACTED] a=setup:actpass a=mid:audio a=extmap:1 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=extmap:2 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=sendrecv a=rtcp-mux a=rtpmap:111 opus/48000/2 a=rtcp-fb:111 transport-cc a=fmtp:111 cbr=1;minptime=10;useinbandfec=1 a=ssrc:4213760127 cname:u8RIFbfvL+4zI8f3 a=ssrc:4213760127 msid:s audio1 a=ssrc:4213760127 mslabel:s a=ssrc:4213760127 label:audio1 m=video 9 UDP/TLS/RTP/SAVPF 96 97 98 99 100 101 102 103 104 c=IN IP4 [REDACTED] a=rtcp:9 IN IP4 [REDACTED] a=ice-ufrag:868B a=ice-pwd:[ REDACTED ] a=ice-options:trickle a=fingerprint:sha-256 [REDACTED]:[REDACTED]:[REDACTED]:[REDACTED] a=setup:actpass a=mid:video a=extmap:14 urn:ietf:params:rtp-hdrext:toffset a=extmap:1 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=extmap:3 urn:3gpp:video-orientation a=extmap:2 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=sendrecv a=rtcp-mux a=rtcp-rsize a=rtpmap:96 VP8/90000 a=rtcp-fb:96 goog-remb a=rtcp-fb:96 transport-cc a=rtcp-fb:96 ccm fir a=rtcp-fb:96 nack a=rtcp-fb:96 nack pli a=rtpmap:97 rtx/90000 a=fmtp:97 apt=96 a=rtpmap:98 VP9/90000 a=rtcp-fb:98 goog-remb a=rtcp-fb:98 transport-cc a=rtcp-fb:98 ccm fir a=rtcp-fb:98 nack a=rtcp-fb:98 nack pli a=fmtp:98 profile-id=0 a=rtpmap:99 rtx/90000 a=fmtp:99 apt=98 a=rtpmap:100 VP9/90000 a=rtcp-fb:100 goog-remb a=rtcp-fb:100 transport-cc a=rtcp-fb:100 ccm fir a=rtcp-fb:100 nack a=rtcp-fb:100 nack pli a=fmtp:100 profile-id=2 a=rtpmap:101 rtx/90000 a=fmtp:101 apt=100 a=rtpmap:102 red/90000 a=rtpmap:103 rtx/90000 a=fmtp:103 apt=102 a=rtpmap:104 ulpfec/90000 a=ssrc-group:FID 1915658624 1336426788 a=ssrc:1915658624 cname:u8RIFbfvL+4zI8f3 a=ssrc:1915658624 msid:s video1 a=ssrc:1915658624 mslabel:s a=ssrc:1915658624 label:video1 a=ssrc:1336426788 cname:u8RIFbfvL+4zI8f3 a=ssrc:1336426788 msid:s video1 a=ssrc:1336426788 mslabel:s a=ssrc:1336426788 label:video1 m=application 9 UDP/DTLS/SCTP webrtc-datachannel c=IN IP4 [REDACTED] a=ice-ufrag:868B a=ice-pwd:[ REDACTED ] a=ice-options:trickle a=fingerprint:sha-256 [REDACTED]:[REDACTED]:[REDACTED]:[REDACTED] a=setup:actpass a=mid:data a=sctp-port:5000 a=max-message-size:262144 INFO 2020-11-25T17:26:45.758Z src/native.rs:538 NativePlatform::on_send_offer(): remote_peer: [REDACTED]429, call_id: 0x7cce0d12520792 INFO 2020-11-25T17:26:45.758Z src/core/call_manager.rs:1984 send_ice_candidates(): call_id: 0x7cce0d12520792 INFO 2020-11-25T17:26:45.758Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:26:45.758Z src/core/call_manager.rs:1653 send_next_message(): messages are in flight already INFO 2020-11-25T17:26:45.758Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/120; sdp=true/116; opaque: ...; sdp: candidate:1195588707 1 udp 2122194687 [REDACTED] 33547 typ host generation 0 ufrag 868B network-id 4 network-cost 50 INFO 2020-11-25T17:26:45.758Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/108; sdp=true/104; opaque: ...; sdp: candidate:1195588707 1 udp 2113937151 [REDACTED] 41430 typ host generation 0 ufrag 868B network-cost 999 INFO 2020-11-25T17:26:45.773Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 (unauth) INFO 2020-11-25T17:26:46.157Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 200 Success INFO 2020-11-25T17:26:46.157Z handleOutgoingSignaling() completed successfully INFO 2020-11-25T17:26:46.160Z src/core/call_manager.rs:407 API:CallManager::handle_message_sent(): INFO 2020-11-25T17:26:46.160Z src/core/call_manager.rs:956 ringrtc! 1606325206157 app -> cm: message_sent() 0x7cce0d12520792 INFO 2020-11-25T17:26:46.160Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:26:46.160Z src/core/call_manager.rs:1659 send_next_message(): sending message, len: 0 INFO 2020-11-25T17:26:46.160Z src/core/connection.rs:1148 take_buffered_local_ice_candidates(): INFO 2020-11-25T17:26:46.160Z src/core/connection.rs:1155 take_buffered_local_ice_candidates(): Local ICE candidates length: 3 INFO 2020-11-25T17:26:46.160Z src/core/call_manager.rs:1993 ringrtc! 1606325206157 cm -> app: send_ice_candidates(3) 0x7cce0d12520792 INFO 2020-11-25T17:26:46.160Z src/native.rs:577 NativePlatform::on_send_ice(): remote_peer: [REDACTED]429, call_id: 0x7cce0d12520792, receiver_device_id: None, candidates: 3 INFO 2020-11-25T17:26:46.167Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 (unauth) INFO 2020-11-25T17:26:46.320Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 200 Success INFO 2020-11-25T17:26:46.320Z handleOutgoingSignaling() completed successfully INFO 2020-11-25T17:26:46.361Z src/core/call_manager.rs:407 API:CallManager::handle_message_sent(): INFO 2020-11-25T17:26:46.361Z src/core/call_manager.rs:956 ringrtc! 1606325206320 app -> cm: message_sent() 0x7cce0d12520792 INFO 2020-11-25T17:26:46.361Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:26:46.361Z src/core/call_manager.rs:1691 send_next_message(): no messages to send INFO 2020-11-25T17:26:46.679Z SQL channel job 142 (createOrUpdateSessions) succeeded in 15ms ERROR 2020-11-25T17:26:47.112Z src/webrtc/peer_connection_factory.rs:438 getAudioRecordingDevices() returned -1 ERROR 2020-11-25T17:26:47.112Z src/webrtc/peer_connection_factory.rs:336 getAudioPlayoutDevices() returned -1 INFO 2020-11-25T17:26:47.814Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-0 INFO 2020-11-25T17:26:47.814Z src/core/connection_fsm.rs:282 state: IceGathering, event: (LocalIceCandidate) INFO 2020-11-25T17:26:47.814Z src/core/connection_fsm.rs:782 ringrtc! 1606325207807 rtc -> conn: ice_candidate() 0x7cce0d12520792-0 INFO 2020-11-25T17:26:47.814Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/143; sdp=true/137; opaque: ...; sdp: candidate:842163049 1 udp 1677729535 [REDACTED] 53398 typ srflx raddr [REDACTED] rport 41430 generation 0 ufrag 868B network-cost 999 INFO 2020-11-25T17:26:47.814Z src/core/call.rs:456 send_buffered_local_ice_candidates(): ConnectingBeforeAccepted INFO 2020-11-25T17:26:47.814Z src/core/call_manager.rs:1984 send_ice_candidates(): call_id: 0x7cce0d12520792 INFO 2020-11-25T17:26:47.814Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:26:47.814Z src/core/call_manager.rs:1659 send_next_message(): sending message, len: 0 INFO 2020-11-25T17:26:47.814Z src/core/connection.rs:1148 take_buffered_local_ice_candidates(): INFO 2020-11-25T17:26:47.814Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-0 INFO 2020-11-25T17:26:47.814Z src/core/connection.rs:1155 take_buffered_local_ice_candidates(): Local ICE candidates length: 1 INFO 2020-11-25T17:26:47.814Z src/core/call_manager.rs:1993 ringrtc! 1606325207807 cm -> app: send_ice_candidates(1) 0x7cce0d12520792 INFO 2020-11-25T17:26:47.814Z src/native.rs:577 NativePlatform::on_send_ice(): remote_peer: [REDACTED]429, call_id: 0x7cce0d12520792, receiver_device_id: None, candidates: 1 INFO 2020-11-25T17:26:47.814Z src/core/connection_fsm.rs:282 state: IceGathering, event: (LocalIceCandidate) INFO 2020-11-25T17:26:47.814Z src/core/connection_fsm.rs:782 ringrtc! 1606325207807 rtc -> conn: ice_candidate() 0x7cce0d12520792-0 INFO 2020-11-25T17:26:47.814Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/155; sdp=true/149; opaque: ...; sdp: candidate:2757933711 1 udp 1685987071 [REDACTED] 8975 typ srflx raddr [REDACTED] rport 33547 generation 0 ufrag 868B network-id 4 network-cost 50 INFO 2020-11-25T17:26:47.814Z src/core/call.rs:456 send_buffered_local_ice_candidates(): ConnectingBeforeAccepted INFO 2020-11-25T17:26:47.814Z src/core/call_manager.rs:1984 send_ice_candidates(): call_id: 0x7cce0d12520792 INFO 2020-11-25T17:26:47.814Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:26:47.814Z src/core/call_manager.rs:1653 send_next_message(): messages are in flight already INFO 2020-11-25T17:26:47.820Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 (unauth) INFO 2020-11-25T17:26:47.915Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-0 INFO 2020-11-25T17:26:47.915Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-0 INFO 2020-11-25T17:26:47.915Z src/core/connection_fsm.rs:282 state: IceGathering, event: (LocalIceCandidate) INFO 2020-11-25T17:26:47.915Z src/core/connection_fsm.rs:782 ringrtc! 1606325207880 rtc -> conn: ice_candidate() 0x7cce0d12520792-0 INFO 2020-11-25T17:26:47.915Z src/core/connection_fsm.rs:282 state: IceGathering, event: (LocalIceCandidate) INFO 2020-11-25T17:26:47.915Z src/core/connection_fsm.rs:782 ringrtc! 1606325207880 rtc -> conn: ice_candidate() 0x7cce0d12520792-0 INFO 2020-11-25T17:26:47.915Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/156; sdp=true/150; opaque: ...; sdp: candidate:1173891001 1 udp 41820415 [REDACTED] 65532 typ relay raddr [REDACTED] rport 8975 generation 0 ufrag 868B network-id 4 network-cost 50 INFO 2020-11-25T17:26:47.915Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/145; sdp=true/139; opaque: ...; sdp: candidate:1173891001 1 udp 33562879 [REDACTED] 65148 typ relay raddr [REDACTED] rport 53398 generation 0 ufrag 868B network-cost 999 INFO 2020-11-25T17:26:47.962Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 200 Success INFO 2020-11-25T17:26:47.962Z handleOutgoingSignaling() completed successfully INFO 2020-11-25T17:26:47.965Z src/core/call_manager.rs:407 API:CallManager::handle_message_sent(): INFO 2020-11-25T17:26:47.965Z src/core/call_manager.rs:956 ringrtc! 1606325207962 app -> cm: message_sent() 0x7cce0d12520792 INFO 2020-11-25T17:26:47.965Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:26:47.965Z src/core/call_manager.rs:1659 send_next_message(): sending message, len: 0 INFO 2020-11-25T17:26:47.965Z src/core/connection.rs:1148 take_buffered_local_ice_candidates(): INFO 2020-11-25T17:26:47.965Z src/core/connection.rs:1155 take_buffered_local_ice_candidates(): Local ICE candidates length: 3 INFO 2020-11-25T17:26:47.965Z src/core/call_manager.rs:1993 ringrtc! 1606325207962 cm -> app: send_ice_candidates(3) 0x7cce0d12520792 INFO 2020-11-25T17:26:47.965Z src/native.rs:577 NativePlatform::on_send_ice(): remote_peer: [REDACTED]429, call_id: 0x7cce0d12520792, receiver_device_id: None, candidates: 3 INFO 2020-11-25T17:26:47.971Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 (unauth) INFO 2020-11-25T17:26:48.015Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-0 INFO 2020-11-25T17:26:48.015Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-0 INFO 2020-11-25T17:26:48.015Z src/core/connection_fsm.rs:282 state: IceGathering, event: (LocalIceCandidate) INFO 2020-11-25T17:26:48.015Z src/core/connection_fsm.rs:782 ringrtc! 1606325208002 rtc -> conn: ice_candidate() 0x7cce0d12520792-0 INFO 2020-11-25T17:26:48.015Z src/core/connection_fsm.rs:282 state: IceGathering, event: (LocalIceCandidate) INFO 2020-11-25T17:26:48.015Z src/core/connection_fsm.rs:782 ringrtc! 1606325208002 rtc -> conn: ice_candidate() 0x7cce0d12520792-0 INFO 2020-11-25T17:26:48.015Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/144; sdp=true/138; opaque: ...; sdp: candidate:192666441 1 udp 16785151 [REDACTED] 53933 typ relay raddr [REDACTED] rport 47213 generation 0 ufrag 868B network-cost 999 INFO 2020-11-25T17:26:48.015Z src/core/call.rs:456 send_buffered_local_ice_candidates(): ConnectingBeforeAccepted INFO 2020-11-25T17:26:48.015Z src/core/call_manager.rs:1984 send_ice_candidates(): call_id: 0x7cce0d12520792 INFO 2020-11-25T17:26:48.015Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:26:48.015Z src/core/call_manager.rs:1653 send_next_message(): messages are in flight already INFO 2020-11-25T17:26:48.015Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/156; sdp=true/150; opaque: ...; sdp: candidate:192666441 1 udp 25042687 [REDACTED] 65108 typ relay raddr [REDACTED] rport 45353 generation 0 ufrag 868B network-id 4 network-cost 50 INFO 2020-11-25T17:26:48.130Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 200 Success INFO 2020-11-25T17:26:48.130Z handleOutgoingSignaling() completed successfully INFO 2020-11-25T17:26:48.166Z src/core/call_manager.rs:407 API:CallManager::handle_message_sent(): INFO 2020-11-25T17:26:48.166Z src/core/call_manager.rs:956 ringrtc! 1606325208130 app -> cm: message_sent() 0x7cce0d12520792 INFO 2020-11-25T17:26:48.166Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:26:48.166Z src/core/call_manager.rs:1659 send_next_message(): sending message, len: 0 INFO 2020-11-25T17:26:48.166Z src/core/connection.rs:1148 take_buffered_local_ice_candidates(): INFO 2020-11-25T17:26:48.166Z src/core/connection.rs:1155 take_buffered_local_ice_candidates(): Local ICE candidates length: 2 INFO 2020-11-25T17:26:48.166Z src/core/call_manager.rs:1993 ringrtc! 1606325208130 cm -> app: send_ice_candidates(2) 0x7cce0d12520792 INFO 2020-11-25T17:26:48.166Z src/native.rs:577 NativePlatform::on_send_ice(): remote_peer: [REDACTED]429, call_id: 0x7cce0d12520792, receiver_device_id: None, candidates: 2 INFO 2020-11-25T17:26:48.170Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 (unauth) INFO 2020-11-25T17:26:48.315Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 200 Success INFO 2020-11-25T17:26:48.315Z handleOutgoingSignaling() completed successfully INFO 2020-11-25T17:26:48.316Z src/core/call_manager.rs:407 API:CallManager::handle_message_sent(): INFO 2020-11-25T17:26:48.316Z src/core/call_manager.rs:956 ringrtc! 1606325208315 app -> cm: message_sent() 0x7cce0d12520792 INFO 2020-11-25T17:26:48.316Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:26:48.316Z src/core/call_manager.rs:1691 send_next_message(): no messages to send INFO 2020-11-25T17:26:48.680Z SQL channel job 143 (createOrUpdateSessions) succeeded in 12ms INFO 2020-11-25T17:26:48.834Z SQL channel job 144 (getMessagesNeedingUpgrade) succeeded in 45ms INFO 2020-11-25T17:26:48.834Z Upgrade message schema (with index): {"done":true,"numProcessed":0,"fetchDuration":45,"upgradeDuration":0,"saveDuration":0,"totalDuration":45} INFO 2020-11-25T17:26:48.834Z Background migration complete. Stopping idle detector. INFO 2020-11-25T17:26:48.834Z Stop idle detector INFO 2020-11-25T17:26:49.999Z SQL channel job 145 (saveUnprocesseds) succeeded in 18ms INFO 2020-11-25T17:26:49.999Z queueing envelope 66213aa502cc40329dfdcf7a665cf61f INFO 2020-11-25T17:26:49.999Z received unidentified sender message INFO 2020-11-25T17:26:50.001Z New remote ephemeral key INFO 2020-11-25T17:26:50.004Z Deleting chain closed at 1605965541981 INFO 2020-11-25T17:26:50.004Z CallingClass.handleCallingMessage() INFO 2020-11-25T17:26:50.005Z CallingClass.handleCallingMessage(): Handling in RingRTC INFO 2020-11-25T17:26:50.020Z src/core/call_manager.rs:447 API:CallManager::handle_received_answer(): INFO 2020-11-25T17:26:50.020Z src/core/call_manager.rs:1258 ringrtc! 1606325210005 app -> cm: received_answer() 0x7cce0d12520792 1 opaque=true/72; sdp=false INFO 2020-11-25T17:26:50.020Z src/core/call_manager.rs:1269 handle_received_answer(): active call_id: 0x7cce0d12520792 INFO 2020-11-25T17:26:50.020Z src/core/call_fsm.rs:215 state: ConnectingBeforeAccepted, event: (ReceivedAnswer, device: 1 feature_level: MultiRing) INFO 2020-11-25T17:26:50.020Z src/core/call.rs:584 id: 0x7cce0d12520792-1, RX answer: opaque: ... INFO 2020-11-25T17:26:50.020Z src/core/call.rs:603 received_answer from device 1; forking enabled, so inject into connection_map INFO 2020-11-25T17:26:50.020Z src/native.rs:356 NativePlatform::create_connection(): call: thread: ThreadId(3), direction: OutGoing, call_id: 0x7cce0d12520792, state: "ConnectingBeforeAccepted" remote_device_id: 1 signaling_version: V4 INFO 2020-11-25T17:26:50.020Z src/webrtc/stats_observer.rs:49 ringrtc_stats!,audio_packets_sent,audio_packets_sent_lost,audio_rtt,audio_packets_received,audio_packets_received_lost,audio_jitter_received,audio_expand_rate,audio_accelerate_rate,audio_preemptive_rate,audio_speech_expand_rate,audio_preferred_buffer_size_ms INFO 2020-11-25T17:26:50.020Z src/webrtc/peer_connection_observer.rs:240 pc_observer_OnSignalingDataChannel(): 0x7cce0d12520792-1 INFO 2020-11-25T17:26:50.020Z src/webrtc/data_channel.rs:57 data channel is reliable: false INFO 2020-11-25T17:26:50.020Z src/webrtc/data_channel.rs:57 data channel is reliable: false INFO 2020-11-25T17:26:50.020Z src/core/connection.rs:580 Using V4 signaling for outgoing connection answer: ConnectionParametersV4 { public_key: Some([14, 170, 19, 164, 100, 140, 107, 111, 184, 74, 96, 142, 174, 168, 180, 115, 186, 226, 192, 178, 151, 81, 109, 121, 156, 119, 118, 239, 206, 216, 67, 80]), ice_ufrag: Some("+KrX"), ice_pwd: Some("IzmDEvZzNFXBbZxDDu7jBK3x"), receive_video_codecs: [VideoCodec { r#type: Some(Vp8), level: None }] } SDP: v=0 o=- 1 1 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE audio video data a=msid-semantic: WMS m=audio 9 RTP/SAVPF 102 c=IN IP4 0.0.0.0 a=rtcp:9 IN IP4 0.0.0.0 a=ice-ufrag:+KrX a=ice-pwd:IzmDEvZzNFXBbZxDDu7jBK3x a=ice-options:trickle renomination a=mid:audio a=extmap:1 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:12 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=sendrecv a=rtcp-mux a=crypto:0 AEAD_AES_256_GCM inline: a=rtpmap:102 opus/48000/2 a=rtcp-fb:102 transport-cc a=fmtp:102 cbr=1;maxaveragebitrate=40000;minptime=10;stereo=0;usedtx=0;useinbandfec=1 a=maxptime:120 a=ptime:20 a=ssrc:1002 cname:CNAMECNAMECNAME! a=ssrc:1002 msid:- audio1 a=ssrc:1002 mslabel:- a=ssrc:1002 label:audio1 m=video 9 RTP/SAVPF 108 118 120 121 122 c=IN IP4 0.0.0.0 a=rtcp:9 IN IP4 0.0.0.0 a=ice-ufrag:+KrX a=ice-pwd:IzmDEvZzNFXBbZxDDu7jBK3x a=ice-options:trickle renomination a=mid:video a=extmap:1 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:4 urn:3gpp:video-orientation a=extmap:12 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=extmap:13 urn:ietf:params:rtp-hdrext:toffset a=sendrecv a=rtcp-mux a=rtcp-rsize a=crypto:0 AEAD_AES_256_GCM inline: a=rtpmap:108 VP8/90000 a=rtcp-fb:108 transport-cc a=rtcp-fb:108 ccm fir a=rtcp-fb:108 nack a=rtcp-fb:108 nack pli a=rtcp-fb:108 goog-remb a=rtpmap:118 rtx/90000 a=fmtp:118 apt=108 a=rtpmap:120 red/90000 a=rtpmap:121 rtx/90000 a=fmtp:121 apt=120 a=rtpmap:122 ulpfec/90000 a=ssrc-group:FID 1003 1013 a=ssrc:1003 cname:CNAMECNAMECNAME! a=ssrc:1003 msid:- video1 a=ssrc:1003 mslabel:- a=ssrc:1003 label:video1 a=ssrc:1013 cname:CNAMECNAMECNAME! a=ssrc:1013 msid:- video1 a=ssrc:1013 mslabel:- a=ssrc:1013 label:video1 m=application 9 RTP/SAVPF 101 c=IN IP4 0.0.0.0 b=AS:30 a=rtcp:9 IN IP4 0.0.0.0 a=ice-ufrag:+KrX a=ice-pwd:IzmDEvZzNFXBbZxDDu7jBK3x a=ice-options:trickle renomination a=mid:data a=sendrecv a=rtcp-mux a=crypto:0 AEAD_AES_256_GCM inline: a=rtpmap:101 google-data/90000 a=ssrc:1001 cname:CNAMECNAMECNAME! a=ssrc:1001 msid:signaling signaling a=ssrc:1001 mslabel:signaling a=ssrc:1001 label:signaling INFO 2020-11-25T17:26:50.020Z src/webrtc/sdp_observer.rs:605 ssd_observer_OnSuccess() INFO 2020-11-25T17:26:50.020Z src/webrtc/sdp_observer.rs:535 on_set_success() INFO 2020-11-25T17:26:50.020Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-1 INFO 2020-11-25T17:26:50.020Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-1 INFO 2020-11-25T17:26:50.020Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-1 INFO 2020-11-25T17:26:50.020Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-1 INFO 2020-11-25T17:26:50.020Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-1 INFO 2020-11-25T17:26:50.020Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-1 INFO 2020-11-25T17:26:50.020Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-1 INFO 2020-11-25T17:26:50.020Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-1 INFO 2020-11-25T17:26:50.020Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x7cce0d12520792-1 INFO 2020-11-25T17:26:50.020Z src/webrtc/peer_connection_observer.rs:158 ringrtc! 1606325210012 rtc -> conn: ice_connection_change(Checking) 0x7cce0d12520792-1 INFO 2020-11-25T17:26:50.020Z src/webrtc/peer_connection_observer.rs:200 pc_observer_OnAddAudioRtpReceiver(): 0x7cce0d12520792-1, rffi_track: 0x2542d73a81e0 INFO 2020-11-25T17:26:50.020Z src/webrtc/peer_connection_observer.rs:220 pc_observer_OnAddVideoRtpReceiver(): 0x7cce0d12520792-1, rffi_track: 0x2542d72d5a40 INFO 2020-11-25T17:26:50.021Z src/webrtc/peer_connection_observer.rs:180 pc_observer_OnAddStream(): 0x7cce0d12520792-1, rffi_stream: 0x2542d73a8120 INFO 2020-11-25T17:26:50.021Z src/webrtc/sdp_observer.rs:605 ssd_observer_OnSuccess() INFO 2020-11-25T17:26:50.021Z src/webrtc/sdp_observer.rs:535 on_set_success() INFO 2020-11-25T17:26:50.021Z src/core/connection.rs:466 Starting Connection FSM for 0x7cce0d12520792-1 INFO 2020-11-25T17:26:50.021Z src/core/connection_fsm.rs:328 syncing worker thread: ThreadId(10) INFO 2020-11-25T17:26:50.021Z src/core/connection_fsm.rs:328 syncing notify thread: ThreadId(11) INFO 2020-11-25T17:26:50.021Z src/core/connection_fsm.rs:282 state: ConnectingBeforeAccepted, event: (ReceivedSignalingDataChannel, dc: 0x2542d698ad60) INFO 2020-11-25T17:26:50.021Z src/core/connection_fsm.rs:951 ringrtc! 1606325210012 rtc -> conn: on_data_channel() INFO 2020-11-25T17:26:50.021Z src/core/connection_fsm.rs:282 state: ConnectingBeforeAccepted, event: (ReceivedIncomingMedia, stream: rffi_media_stream: 0x2542d73a8120) INFO 2020-11-25T17:26:50.021Z src/core/connection.rs:1322 handle_received_incoming_media(): id: 0x7cce0d12520792-1 INFO 2020-11-25T17:26:50.021Z src/native.rs:390 NativePlatform::create_incoming_media() ERROR 2020-11-25T17:26:50.121Z src/webrtc/peer_connection_factory.rs:438 getAudioRecordingDevices() returned -1 ERROR 2020-11-25T17:26:50.121Z src/webrtc/peer_connection_factory.rs:336 getAudioPlayoutDevices() returned -1 INFO 2020-11-25T17:26:50.271Z src/webrtc/peer_connection_observer.rs:158 ringrtc! 1606325210227 rtc -> conn: ice_connection_change(Connected) 0x7cce0d12520792-1 INFO 2020-11-25T17:26:50.271Z src/core/connection_fsm.rs:282 state: ConnectingBeforeAccepted, event: (IceConnected) INFO 2020-11-25T17:26:50.271Z src/core/call.rs:975 on_connection_observer_event(): call_id: 0x7cce0d12520792, remote_device_id: 1, event: ConnectedWithDataChannelBeforeAccepted INFO 2020-11-25T17:26:50.271Z src/core/call_fsm.rs:215 state: ConnectingBeforeAccepted, event: (ConnectionObserverEvent, event: ConnectedWithDataChannelBeforeAccepted, device: 1) INFO 2020-11-25T17:26:50.271Z src/core/call_manager.rs:1764 ringrtc! 1606325210227 cm -> app: event(RemoteRinging) INFO 2020-11-25T17:26:50.271Z src/native.rs:438 NativePlatform::on_event(): remote_peer: [REDACTED]429, event: RemoteRinging INFO 2020-11-25T17:26:50.479Z SQL channel job 146 (saveUnprocesseds) succeeded in 12ms INFO 2020-11-25T17:26:50.479Z queueing envelope 72811994432944268c26db6decbaf28c INFO 2020-11-25T17:26:50.479Z received unidentified sender message INFO 2020-11-25T17:26:50.483Z CallingClass.handleCallingMessage() INFO 2020-11-25T17:26:50.484Z CallingClass.handleCallingMessage(): Handling in RingRTC INFO 2020-11-25T17:26:50.524Z src/core/call_manager.rs:456 API:CallManager::handle_received_ice(): INFO 2020-11-25T17:26:50.524Z src/core/call_manager.rs:1284 ringrtc! 1606325210484 app -> cm: received_ice_candidates(10) 0x7cce0d12520792 1 INFO 2020-11-25T17:26:50.524Z src/core/call_manager.rs:1295 handle_received_ice(): active call_id: 0x7cce0d12520792 INFO 2020-11-25T17:26:50.524Z src/core/call_fsm.rs:215 state: ConnectedWithDataChannelBeforeAccepted, event: (ReceivedIce, device: 1) INFO 2020-11-25T17:26:50.524Z src/core/call.rs:631 received_ice(): id: 0x7cce0d12520792-1 INFO 2020-11-25T17:26:50.524Z src/core/connection_fsm.rs:282 state: ConnectedBeforeAccepted, event: (RemoteIceCandidates) INFO 2020-11-25T17:26:50.524Z src/core/connection.rs:1167 ringrtc! 1606325210484 conn -> rtc: ice_candidates(10) INFO 2020-11-25T17:26:50.994Z SQL channel job 147 (createOrUpdateSessions) succeeded in 12ms INFO 2020-11-25T17:26:51.008Z SQL channel job 148 (updateUnprocessedsWithData) succeeded in 26ms INFO 2020-11-25T17:26:51.019Z SQL channel job 149 (removeUnprocessed) succeeded in 36ms INFO 2020-11-25T17:26:51.977Z src/core/connection_fsm.rs:282 state: ConnectedBeforeAccepted, event: (ReceivedAcceptedViaDataChannel, call_id: 0x7cce0d12520792) INFO 2020-11-25T17:26:51.977Z src/core/connection_fsm.rs:511 ringrtc! 1606325211954 rtc -> conn: dc(accepted) INFO 2020-11-25T17:26:51.977Z src/core/call.rs:975 on_connection_observer_event(): call_id: 0x7cce0d12520792, remote_device_id: 1, event: ReceivedAcceptedViaDataChannel INFO 2020-11-25T17:26:51.977Z src/core/call_fsm.rs:215 state: ConnectedWithDataChannelBeforeAccepted, event: (ConnectionObserverEvent, event: ReceivedAcceptedViaDataChannel, device: 1) INFO 2020-11-25T17:26:51.977Z src/core/call_fsm.rs:696 handle_connection_observer_event(): Accepted from 1 INFO 2020-11-25T17:26:51.978Z src/core/call.rs:705 send_hangup_via_data_channel_to_all_except(): 0x7cce0d12520792 hangup: AcceptedOnAnotherDevice(1) excluded remote_device_id: 1 INFO 2020-11-25T17:26:51.978Z src/core/connection.rs:1334 connect_incoming_media(): id: 0x7cce0d12520792-1 INFO 2020-11-25T17:26:51.978Z src/native.rs:400 NativePlatform::connect_incoming_media() INFO 2020-11-25T17:26:51.978Z src/core/connection.rs:960 set_local_max_send_bitrate(): local_max: DataRate { size_per_second: DataSize { bits: 2000000 } } INFO 2020-11-25T17:26:51.978Z src/core/call_manager.rs:1764 ringrtc! 1606325211956 cm -> app: event(RemoteAccepted) INFO 2020-11-25T17:26:51.978Z src/native.rs:438 NativePlatform::on_event(): remote_peer: [REDACTED]429, event: RemoteAccepted INFO 2020-11-25T17:26:51.978Z src/core/call_manager.rs:737 send_hangup(): call_id: 0x7cce0d12520792 INFO 2020-11-25T17:26:51.978Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:26:51.978Z src/core/call_manager.rs:1659 send_next_message(): sending message, len: 0 INFO 2020-11-25T17:26:51.978Z src/core/call_manager.rs:740 ringrtc! 1606325211956 cm -> app: send_hangup(AcceptedOnAnotherDevice(1)) 0x7cce0d12520792 INFO 2020-11-25T17:26:51.978Z src/native.rs:596 NativePlatform::on_send_hangup(): remote_peer: [REDACTED]429, call_id: 0x7cce0d12520792 INFO 2020-11-25T17:26:51.978Z src/core/call.rs:826 terminate_connections_except_accepted(): INFO 2020-11-25T17:26:51.978Z src/core/call.rs:839 terminate_connections_except_accepted(): len: 1 INFO 2020-11-25T17:26:51.986Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 (unauth) INFO 2020-11-25T17:26:52.028Z src/core/call_manager.rs:561 active_connection(): INFO 2020-11-25T17:26:52.028Z src/core/connection_fsm.rs:282 state: ConnectedAndAccepted, event: (SendSenderStatusViaDataChannel, enabled: false) INFO 2020-11-25T17:26:52.028Z src/core/connection.rs:1265 Sending data channel message: Data { accepted: None, hangup: None, sender_status: Some(SenderStatus { id: Some(35129452649383826), video_enabled: Some(false) }), sequence_number: Some(1), receiver_status: None } INFO 2020-11-25T17:26:52.078Z src/core/call.rs:975 on_connection_observer_event(): call_id: 0x7cce0d12520792, remote_device_id: 1, event: ReceivedSenderStatusViaDataChannel(false) INFO 2020-11-25T17:26:52.078Z src/core/call_fsm.rs:215 state: ConnectedAndAccepted, event: (ConnectionObserverEvent, event: ReceivedSenderStatusViaDataChannel(false), device: 1) INFO 2020-11-25T17:26:52.078Z src/core/call_manager.rs:1764 ringrtc! 1606325212044 cm -> app: event(RemoteVideoDisable) INFO 2020-11-25T17:26:52.078Z src/native.rs:438 NativePlatform::on_event(): remote_peer: [REDACTED]429, event: RemoteVideoDisable INFO 2020-11-25T17:26:52.168Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 200 Success INFO 2020-11-25T17:26:52.168Z handleOutgoingSignaling() completed successfully INFO 2020-11-25T17:26:52.180Z src/core/call_manager.rs:407 API:CallManager::handle_message_sent(): INFO 2020-11-25T17:26:52.180Z src/core/call_manager.rs:956 ringrtc! 1606325212168 app -> cm: message_sent() 0x7cce0d12520792 INFO 2020-11-25T17:26:52.180Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:26:52.180Z src/core/call_manager.rs:1691 send_next_message(): no messages to send INFO 2020-11-25T17:26:52.496Z SQL channel job 150 (createOrUpdateSessions) succeeded in 12ms ERROR 2020-11-25T17:26:53.133Z src/webrtc/peer_connection_factory.rs:438 getAudioRecordingDevices() returned -1 ERROR 2020-11-25T17:26:53.133Z src/webrtc/peer_connection_factory.rs:336 getAudioPlayoutDevices() returned -1 ERROR 2020-11-25T17:26:56.139Z src/webrtc/peer_connection_factory.rs:438 getAudioRecordingDevices() returned -1 ERROR 2020-11-25T17:26:56.139Z src/webrtc/peer_connection_factory.rs:336 getAudioPlayoutDevices() returned -1 INFO 2020-11-25T17:26:59.096Z src/core/connection_fsm.rs:282 state: ConnectedAndAccepted, event: (RemoteHangup, call_id: 0x7cce0d12520792 hangup: Normal/None) INFO 2020-11-25T17:26:59.096Z src/core/connection_fsm.rs:476 ringrtc! 1606325219091 rtc -> conn: dc(hangup/Normal/None) 0x7cce0d12520792 INFO 2020-11-25T17:26:59.096Z src/core/call.rs:975 on_connection_observer_event(): call_id: 0x7cce0d12520792, remote_device_id: 1, event: ReceivedHangup(Normal) INFO 2020-11-25T17:26:59.096Z src/core/call.rs:975 on_connection_observer_event(): call_id: 0x7cce0d12520792, remote_device_id: 1, event: ReceivedSenderStatusViaDataChannel(false) INFO 2020-11-25T17:26:59.096Z src/core/call_fsm.rs:215 state: ConnectedAndAccepted, event: (ConnectionObserverEvent, event: ReceivedHangup(Normal), device: 1) INFO 2020-11-25T17:26:59.096Z src/core/call_fsm.rs:466 handle_received_hangup(): remote_device_id: 1, hangup: Normal/None INFO 2020-11-25T17:26:59.096Z src/core/call_fsm.rs:215 state: Terminating, event: (ConnectionObserverEvent, event: ReceivedSenderStatusViaDataChannel(false), device: 1) INFO 2020-11-25T17:26:59.096Z src/core/call_manager.rs:1818 remote_hangup(): call_id: 0x7cce0d12520792 INFO 2020-11-25T17:26:59.096Z src/core/call_manager.rs:828 terminate_active_call(): INFO 2020-11-25T17:26:59.096Z src/core/call_manager.rs:779 conclude_call(): call_id: 0x7cce0d12520792 INFO 2020-11-25T17:26:59.096Z src/core/call_manager.rs:1764 ringrtc! 1606325219091 cm -> app: event(EndedRemoteHangup) INFO 2020-11-25T17:26:59.096Z src/native.rs:438 NativePlatform::on_event(): remote_peer: [REDACTED]429, event: EndedRemoteHangup INFO 2020-11-25T17:26:59.096Z src/core/call_manager.rs:719 terminate_call(): call_id: 0x7cce0d12520792 INFO 2020-11-25T17:26:59.096Z src/core/call.rs:855 terminate(): ref_count: 7 INFO 2020-11-25T17:26:59.096Z src/core/call.rs:878 terminate(): waiting for terminate complete... INFO 2020-11-25T17:26:59.096Z src/core/call_fsm.rs:215 state: Terminating, event: (Terminate) INFO 2020-11-25T17:26:59.096Z src/core/call_fsm.rs:288 draining worker thread INFO 2020-11-25T17:26:59.096Z src/core/call_fsm.rs:290 draining worker thread: complete INFO 2020-11-25T17:26:59.096Z src/core/call_fsm.rs:295 draining notify thread INFO 2020-11-25T17:26:59.096Z src/core/call_fsm.rs:297 draining notify thread: complete INFO 2020-11-25T17:26:59.096Z src/core/call.rs:903 notify_terminate_complete(): notifying terminate complete... INFO 2020-11-25T17:26:59.096Z src/core/call_fsm.rs:221 No more events! INFO 2020-11-25T17:26:59.096Z src/core/call_fsm.rs:199 Dropping CallStateMachine: INFO 2020-11-25T17:26:59.096Z src/core/call.rs:892 terminate(): terminate complete: ref_count: 7 INFO 2020-11-25T17:26:59.096Z src/native.rs:411 NativePlatform::disconnect_incoming_media() INFO 2020-11-25T17:26:59.096Z src/core/connection.rs:1373 terminate(): ref_count: 2 INFO 2020-11-25T17:26:59.096Z src/core/connection.rs:1438 terminate(): waiting for terminate complete... INFO 2020-11-25T17:26:59.096Z src/core/connection_fsm.rs:282 state: Terminating, event: (Terminate) INFO 2020-11-25T17:26:59.096Z src/core/connection_fsm.rs:358 draining worker thread INFO 2020-11-25T17:26:59.096Z src/core/connection_fsm.rs:360 draining worker thread: complete INFO 2020-11-25T17:26:59.096Z src/core/connection_fsm.rs:365 draining notify thread ERROR 2020-11-25T17:26:59.096Z src/webrtc/peer_connection_factory.rs:438 getAudioRecordingDevices() returned -1 ERROR 2020-11-25T17:26:59.096Z src/webrtc/peer_connection_factory.rs:336 getAudioPlayoutDevices() returned -1 INFO 2020-11-25T17:26:59.096Z src/core/connection_fsm.rs:367 draining notify thread: complete INFO 2020-11-25T17:26:59.096Z src/core/connection_fsm.rs:289 No more events! INFO 2020-11-25T17:26:59.096Z src/core/connection.rs:1454 terminate(): terminate complete: ref_count: 2 INFO 2020-11-25T17:26:59.096Z src/core/connection.rs:354 Connection: Dropping last reference: 0x7cce0d12520792-0 INFO 2020-11-25T17:26:59.096Z src/webrtc/peer_connection.rs:68 PeerConnection::drop() INFO 2020-11-25T17:26:59.096Z src/core/call.rs:806 terminate_connections(): call_id: 0x7cce0d12520792 remote_device_id: 1 INFO 2020-11-25T17:26:59.096Z src/core/connection.rs:1373 terminate(): ref_count: 3 INFO 2020-11-25T17:26:59.096Z src/core/connection.rs:1438 terminate(): waiting for terminate complete... INFO 2020-11-25T17:26:59.096Z src/core/connection_fsm.rs:282 state: Terminating, event: (Terminate) INFO 2020-11-25T17:26:59.096Z src/core/connection_fsm.rs:358 draining worker thread INFO 2020-11-25T17:26:59.096Z src/core/connection_fsm.rs:360 draining worker thread: complete INFO 2020-11-25T17:26:59.096Z src/core/connection_fsm.rs:365 draining notify thread INFO 2020-11-25T17:26:59.096Z src/core/connection_fsm.rs:367 draining notify thread: complete INFO 2020-11-25T17:26:59.096Z src/core/connection_fsm.rs:289 No more events! INFO 2020-11-25T17:26:59.096Z src/core/connection.rs:1454 terminate(): terminate complete: ref_count: 3 INFO 2020-11-25T17:26:59.096Z src/core/connection.rs:1385 close(): stopping the tick runtime INFO 2020-11-25T17:26:59.096Z src/core/connection.rs:354 Connection: Dropping last reference: 0x7cce0d12520792-1 INFO 2020-11-25T17:26:59.096Z src/webrtc/peer_connection.rs:68 PeerConnection::drop() INFO 2020-11-25T17:26:59.096Z src/core/call.rs:58 stopping timeout runtime INFO 2020-11-25T17:26:59.096Z src/core/call.rs:60 stopping timeout runtime: complete INFO 2020-11-25T17:26:59.096Z src/core/call.rs:168 Call: Dropping last reference: 0x7cce0d12520792 INFO 2020-11-25T17:26:59.096Z src/core/call_manager.rs:1837 ringrtc! 1606325219096 cm -> app: call_concluded() 0x7cce0d12520792 INFO 2020-11-25T17:26:59.096Z src/native.rs:519 NativePlatform::on_call_concluded(): remote_peer: [REDACTED]429 INFO 2020-11-25T17:26:59.366Z SQL channel job 151 (saveMessage) succeeded in 270ms INFO 2020-11-25T17:26:59.397Z MediaDevice: available devices changed (from->to) {"availableMicrophones":[],"availableSpeakers":[],"availableCameras":[]} INFO 2020-11-25T17:26:59.829Z SQL channel job 154 (saveUnprocesseds) succeeded in 20ms INFO 2020-11-25T17:26:59.829Z queueing envelope 19f4c604c2554677b74dafeaba0113c9 INFO 2020-11-25T17:26:59.830Z received unidentified sender message INFO 2020-11-25T17:26:59.831Z New remote ephemeral key INFO 2020-11-25T17:26:59.833Z Deleting chain closed at 1605965637346 INFO 2020-11-25T17:26:59.833Z CallingClass.handleCallingMessage() INFO 2020-11-25T17:26:59.834Z CallingClass.handleCallingMessage(): Handling in RingRTC INFO 2020-11-25T17:26:59.861Z src/core/call_manager.rs:465 API:CallManager::handle_received_hangup(): INFO 2020-11-25T17:26:59.861Z src/core/call_manager.rs:1310 ringrtc! 1606325219834 app -> cm: received_hangup(Normal/None) 0x7cce0d12520792 1 INFO 2020-11-25T17:26:59.861Z src/core/call_manager.rs:1319 ringrtc! 1606325219834 cm -x app: inactive INFO 2020-11-25T17:27:00.350Z SQL channel job 157 (createOrUpdateSessions) succeeded in 17ms INFO 2020-11-25T17:27:00.361Z SQL channel job 158 (updateUnprocessedsWithData) succeeded in 28ms INFO 2020-11-25T17:27:00.371Z SQL channel job 159 (removeUnprocessed) succeeded in 38ms INFO 2020-11-25T17:27:00.382Z SQL channel job 160 (updateConversations) succeeded in 22ms INFO 2020-11-25T17:27:00.382Z SQL channel job 161 (getNextExpiringMessage) succeeded in 12ms INFO 2020-11-25T17:27:00.382Z SQL channel job 162 (getNextTapToViewMessageToAgeOut) succeeded in 12ms INFO 2020-11-25T17:27:16.277Z SQL channel job 163 (saveUnprocesseds) succeeded in 15ms INFO 2020-11-25T17:27:16.277Z queueing envelope 3bdb89a3ffd64680b8ecff302b5e970a INFO 2020-11-25T17:27:16.277Z received unidentified sender message INFO 2020-11-25T17:27:16.282Z CallingClass.handleCallingMessage() INFO 2020-11-25T17:27:16.283Z CallingClass.handleCallingMessage(): Handling in RingRTC INFO 2020-11-25T17:27:16.297Z src/core/call_manager.rs:427 API:received_offer(): INFO 2020-11-25T17:27:16.297Z src/core/call_manager.rs:1066 ringrtc! 1606325236283 app -> cm: received_offer() 0x2bb44a7dc03eaad 1 feature=MultiRing primary=false opaque=true/3208; sdp=true/2898 INFO 2020-11-25T17:27:16.297Z src/core/call.rs:227 new(): call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:16.297Z src/core/call_fsm.rs:258 syncing worker thread: ThreadId(25) INFO 2020-11-25T17:27:16.297Z src/core/call_fsm.rs:258 syncing notify thread: ThreadId(26) INFO 2020-11-25T17:27:16.297Z src/core/call.rs:340 id: 0x2bb44a7dc03eaad-1, RX offer: opaque: ...; sdp: v=0 o=- 3689445865819830509 2 IN IP4 [REDACTED] s=- t=0 0 a=group:BUNDLE audio video data a=msid-semantic: WMS ARDAMS m=audio 9 UDP/TLS/RTP/SAVPF 111 c=IN IP4 [REDACTED] a=rtcp:9 IN IP4 [REDACTED] a=ice-ufrag:JHjO a=ice-pwd:[ REDACTED ] a=ice-options:trickle renomination a=fingerprint:sha-256 [REDACTED]:[REDACTED]:[REDACTED]:[REDACTED] a=setup:actpass a=mid:audio a=extmap:1 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=extmap:2 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=sendrecv a=rtcp-mux a=rtpmap:111 opus/48000/2 a=rtcp-fb:111 transport-cc a=fmtp:111 cbr=1;minptime=10;useinbandfec=1 a=ssrc:3924041353 cname:VGk5uU+AM1Es1T8W a=ssrc:3924041353 msid:ARDAMS audio1 a=ssrc:3924041353 mslabel:ARDAMS a=ssrc:3924041353 label:audio1 m=video 9 UDP/TLS/RTP/SAVPF 96 97 98 99 100 101 102 103 104 c=IN IP4 [REDACTED] a=rtcp:9 IN IP4 [REDACTED] a=ice-ufrag:JHjO a=ice-pwd:[ REDACTED ] a=ice-options:trickle renomination a=fingerprint:sha-256 [REDACTED]:[REDACTED]:[REDACTED]:[REDACTED] a=setup:actpass a=mid:video a=extmap:14 urn:ietf:params:rtp-hdrext:toffset a=extmap:1 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=extmap:3 urn:3gpp:video-orientation a=extmap:2 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=sendrecv a=rtcp-mux a=rtcp-rsize a=rtpmap:96 VP8/90000 a=rtcp-fb:96 goog-remb a=rtcp-fb:96 transport-cc a=rtcp-fb:96 ccm fir a=rtcp-fb:96 nack a=rtcp-fb:96 nack pli a=rtpmap:97 rtx/90000 a=fmtp:97 apt=96 a=rtpmap:98 VP9/90000 a=rtcp-fb:98 goog-remb a=rtcp-fb:98 transport-cc a=rtcp-fb:98 ccm fir a=rtcp-fb:98 nack a=rtcp-fb:98 nack pli a=rtpmap:99 rtx/90000 a=fmtp:99 apt=98 a=rtpmap:100 H264/90000 a=rtcp-fb:100 goog-remb a=rtcp-fb:100 transport-cc a=rtcp-fb:100 ccm fir a=rtcp-fb:100 nack a=rtcp-fb:100 nack pli a=fmtp:100 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42e01f a=rtpmap:101 rtx/90000 a=fmtp:101 apt=100 a=rtpmap:102 red/90000 a=rtpmap:103 rtx/90000 a=fmtp:103 apt=102 a=rtpmap:104 ulpfec/90000 a=ssrc-group:FID 2689280225 1052430933 a=ssrc:2689280225 cname:VGk5uU+AM1Es1T8W a=ssrc:2689280225 msid:ARDAMS video1 a=ssrc:2689280225 mslabel:ARDAMS a=ssrc:2689280225 label:video1 a=ssrc:1052430933 cname:VGk5uU+AM1Es1T8W a=ssrc:1052430933 msid:ARDAMS video1 a=ssrc:1052430933 mslabel:ARDAMS a=ssrc:1052430933 label:video1 m=application 9 UDP/DTLS/SCTP webrtc-datachannel c=IN IP4 [REDACTED] a=ice-ufrag:JHjO a=ice-pwd:[ REDACTED ] a=ice-options:trickle renomination a=fingerprint:sha-256 [REDACTED]:[REDACTED]:[REDACTED]:[REDACTED] a=setup:actpass a=mid:data a=sctp-port:5000 a=max-message-size:262144 INFO 2020-11-25T17:27:16.297Z src/core/call_fsm.rs:215 state: NotYetStarted, event: (StartCall) INFO 2020-11-25T17:27:16.297Z src/core/call_fsm.rs:365 handle_start_call(): INFO 2020-11-25T17:27:16.297Z src/core/call_manager.rs:1748 ringrtc! 1606325236283 cm -> app: start() 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:16.297Z src/native.rs:423 NativePlatform::on_start_call(): remote_peer: [REDACTED]429, call_id: 0x2bb44a7dc03eaad, direction: InComing, call_media_type: Audio INFO 2020-11-25T17:27:16.297Z CallingClass.handleIncomingCall() INFO 2020-11-25T17:27:16.298Z CallingClass.handleIncomingCall(): Proceeding INFO 2020-11-25T17:27:16.298Z GET https://textsecure-service.whispersystems.org/v1/accounts/turn INFO 2020-11-25T17:27:16.455Z GET https://textsecure-service.whispersystems.org/v1/accounts/turn 200 Success INFO 2020-11-25T17:27:16.498Z src/core/call_manager.rs:402 API:CallManager::handle_proceed(): INFO 2020-11-25T17:27:16.498Z src/core/call_manager.rs:938 ringrtc! 1606325236457 app -> cm: proceed() 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:16.498Z src/core/call_manager.rs:944 handle_proceed(): active call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:16.498Z src/core/call_fsm.rs:215 state: WaitingToProceed, event: (Proceed) INFO 2020-11-25T17:27:16.498Z src/core/call_fsm.rs:378 handle_proceed(): INFO 2020-11-25T17:27:16.498Z src/core/call.rs:510 proceed(): INFO 2020-11-25T17:27:16.498Z src/core/call.rs:520 proceed(): incoming: remote_device: 1 INFO 2020-11-25T17:27:16.498Z src/native.rs:356 NativePlatform::create_connection(): call: thread: ThreadId(25), direction: InComing, call_id: 0x2bb44a7dc03eaad, state: "ConnectingBeforeAccepted" remote_device_id: 1 signaling_version: V4 INFO 2020-11-25T17:27:16.498Z src/webrtc/stats_observer.rs:49 ringrtc_stats!,audio_packets_sent,audio_packets_sent_lost,audio_rtt,audio_packets_received,audio_packets_received_lost,audio_jitter_received,audio_expand_rate,audio_accelerate_rate,audio_preemptive_rate,audio_speech_expand_rate,audio_preferred_buffer_size_ms INFO 2020-11-25T17:27:16.498Z src/core/connection.rs:671 Using V4 signaling for incoming connection offer: ConnectionParametersV4 { public_key: Some([211, 167, 0, 88, 24, 102, 226, 131, 203, 82, 109, 157, 150, 137, 49, 51, 114, 218, 59, 61, 94, 199, 17, 129, 223, 57, 241, 230, 55, 16, 135, 126]), ice_ufrag: Some("JHjO"), ice_pwd: Some("AxzpZJjXJRV+jA91/bcX2fCg"), receive_video_codecs: [VideoCodec { r#type: Some(Vp8), level: None }, VideoCodec { r#type: Some(H264ConstrainedBaseline), level: Some(31) }] } SDP: v=0 o=- 1 1 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE audio video data a=msid-semantic: WMS m=audio 9 RTP/SAVPF 102 c=IN IP4 0.0.0.0 a=rtcp:9 IN IP4 0.0.0.0 a=ice-ufrag:JHjO a=ice-pwd:AxzpZJjXJRV+jA91/bcX2fCg a=ice-options:trickle renomination a=mid:audio a=extmap:1 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:12 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=sendrecv a=rtcp-mux a=crypto:0 AEAD_AES_256_GCM inline: a=rtpmap:102 opus/48000/2 a=rtcp-fb:102 transport-cc a=fmtp:102 cbr=1;maxaveragebitrate=40000;minptime=10;stereo=0;usedtx=0;useinbandfec=1 a=maxptime:120 a=ptime:20 a=ssrc:1002 cname:CNAMECNAMECNAME! a=ssrc:1002 msid:- audio1 a=ssrc:1002 mslabel:- a=ssrc:1002 label:audio1 m=video 9 RTP/SAVPF 108 118 103 113 120 121 122 c=IN IP4 0.0.0.0 a=rtcp:9 IN IP4 0.0.0.0 a=ice-ufrag:JHjO a=ice-pwd:AxzpZJjXJRV+jA91/bcX2fCg a=ice-options:trickle renomination a=mid:video a=extmap:1 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:4 urn:3gpp:video-orientation a=extmap:12 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=extmap:13 urn:ietf:params:rtp-hdrext:toffset a=sendrecv a=rtcp-mux a=rtcp-rsize a=crypto:0 AEAD_AES_256_GCM inline: a=rtpmap:108 VP8/90000 a=rtcp-fb:108 transport-cc a=rtcp-fb:108 ccm fir a=rtcp-fb:108 nack a=rtcp-fb:108 nack pli a=rtcp-fb:108 goog-remb a=rtpmap:118 rtx/90000 a=fmtp:118 apt=108 a=rtpmap:103 H264/90000 a=rtcp-fb:103 transport-cc a=rtcp-fb:103 ccm fir a=rtcp-fb:103 nack a=rtcp-fb:103 nack pli a=rtcp-fb:103 goog-remb a=fmtp:103 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42e01f a=rtpmap:113 rtx/90000 a=fmtp:113 apt=103 a=rtpmap:120 red/90000 a=rtpmap:121 rtx/90000 a=fmtp:121 apt=120 a=rtpmap:122 ulpfec/90000 a=ssrc-group:FID 1003 1013 a=ssrc:1003 cname:CNAMECNAMECNAME! a=ssrc:1003 msid:- video1 a=ssrc:1003 mslabel:- a=ssrc:1003 label:video1 a=ssrc:1013 cname:CNAMECNAMECNAME! a=ssrc:1013 msid:- video1 a=ssrc:1013 mslabel:- a=ssrc:1013 label:video1 m=application 9 RTP/SAVPF 101 c=IN IP4 0.0.0.0 b=AS:30 a=rtcp:9 IN IP4 0.0.0.0 a=ice-ufrag:JHjO a=ice-pwd:AxzpZJjXJRV+jA91/bcX2fCg a=ice-options:trickle renomination a=mid:data a=sendrecv a=rtcp-mux a=crypto:0 AEAD_AES_256_GCM inline: a=rtpmap:101 google-data/90000 a=ssrc:1001 cname:CNAMECNAMECNAME! a=ssrc:1001 msid:signaling signaling a=ssrc:1001 mslabel:signaling a=ssrc:1001 label:signaling INFO 2020-11-25T17:27:16.498Z src/webrtc/peer_connection_observer.rs:200 pc_observer_OnAddAudioRtpReceiver(): 0x2bb44a7dc03eaad-1, rffi_track: 0x2542d84eb900 INFO 2020-11-25T17:27:16.498Z src/webrtc/peer_connection_observer.rs:220 pc_observer_OnAddVideoRtpReceiver(): 0x2bb44a7dc03eaad-1, rffi_track: 0x2542d7c71a00 INFO 2020-11-25T17:27:16.498Z src/webrtc/peer_connection_observer.rs:240 pc_observer_OnSignalingDataChannel(): 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.498Z src/webrtc/data_channel.rs:57 data channel is reliable: false INFO 2020-11-25T17:27:16.498Z src/webrtc/peer_connection_observer.rs:180 pc_observer_OnAddStream(): 0x2bb44a7dc03eaad-1, rffi_stream: 0x2542d84eb750 INFO 2020-11-25T17:27:16.498Z src/webrtc/sdp_observer.rs:605 ssd_observer_OnSuccess() INFO 2020-11-25T17:27:16.498Z src/webrtc/sdp_observer.rs:535 on_set_success() INFO 2020-11-25T17:27:16.498Z src/webrtc/sdp_observer.rs:436 csd_observer_OnSuccess() INFO 2020-11-25T17:27:16.498Z src/webrtc/sdp_observer.rs:361 on_create_success() INFO 2020-11-25T17:27:16.498Z src/core/connection.rs:722 Using V4 signaling for incoming connection answer: ConnectionParametersV4 { public_key: Some([118, 55, 53, 93, 26, 57, 39, 240, 0, 107, 180, 193, 79, 116, 48, 228, 94, 167, 209, 43, 135, 41, 253, 141, 156, 182, 96, 76, 79, 49, 46, 14]), ice_ufrag: Some("qO5c"), ice_pwd: Some("FCBs6gWBF+RlVNlz0aux8UhE"), receive_video_codecs: [VideoCodec { r#type: Some(Vp8), level: None }] } SDP: v=0 o=- 1 1 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE audio video data a=msid-semantic: WMS m=audio 9 RTP/SAVPF 102 c=IN IP4 0.0.0.0 a=rtcp:9 IN IP4 0.0.0.0 a=ice-ufrag:qO5c a=ice-pwd:FCBs6gWBF+RlVNlz0aux8UhE a=ice-options:trickle renomination a=mid:audio a=extmap:1 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:12 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=sendrecv a=rtcp-mux a=crypto:0 AEAD_AES_256_GCM inline: a=rtpmap:102 opus/48000/2 a=rtcp-fb:102 transport-cc a=fmtp:102 cbr=1;maxaveragebitrate=40000;minptime=10;stereo=0;usedtx=0;useinbandfec=1 a=maxptime:120 a=ptime:20 a=ssrc:1002 cname:CNAMECNAMECNAME! a=ssrc:1002 msid:- audio1 a=ssrc:1002 mslabel:- a=ssrc:1002 label:audio1 m=video 9 RTP/SAVPF 108 118 120 121 122 c=IN IP4 0.0.0.0 a=rtcp:9 IN IP4 0.0.0.0 a=ice-ufrag:qO5c a=ice-pwd:FCBs6gWBF+RlVNlz0aux8UhE a=ice-options:trickle renomination a=mid:video a=extmap:1 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=extmap:4 urn:3gpp:video-orientation a=extmap:12 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=extmap:13 urn:ietf:params:rtp-hdrext:toffset a=sendrecv a=rtcp-mux a=rtcp-rsize a=crypto:0 AEAD_AES_256_GCM inline: a=rtpmap:108 VP8/90000 a=rtcp-fb:108 transport-cc a=rtcp-fb:108 ccm fir a=rtcp-fb:108 nack a=rtcp-fb:108 nack pli a=rtcp-fb:108 goog-remb a=rtpmap:118 rtx/90000 a=fmtp:118 apt=108 a=rtpmap:120 red/90000 a=rtpmap:121 rtx/90000 a=fmtp:121 apt=120 a=rtpmap:122 ulpfec/90000 a=ssrc-group:FID 1003 1013 a=ssrc:1003 cname:CNAMECNAMECNAME! a=ssrc:1003 msid:- video1 a=ssrc:1003 mslabel:- a=ssrc:1003 label:video1 a=ssrc:1013 cname:CNAMECNAMECNAME! a=ssrc:1013 msid:- video1 a=ssrc:1013 mslabel:- a=ssrc:1013 label:video1 m=application 9 RTP/SAVPF 101 c=IN IP4 0.0.0.0 b=AS:30 a=rtcp:9 IN IP4 0.0.0.0 a=ice-ufrag:qO5c a=ice-pwd:FCBs6gWBF+RlVNlz0aux8UhE a=ice-options:trickle renomination a=mid:data a=sendrecv a=rtcp-mux a=crypto:0 AEAD_AES_256_GCM inline: a=rtpmap:101 google-data/90000 a=ssrc:1001 cname:CNAMECNAMECNAME! a=ssrc:1001 msid:signaling signaling a=ssrc:1001 mslabel:signaling a=ssrc:1001 label:signaling INFO 2020-11-25T17:27:16.498Z src/webrtc/sdp_observer.rs:605 ssd_observer_OnSuccess() INFO 2020-11-25T17:27:16.498Z src/webrtc/sdp_observer.rs:535 on_set_success() INFO 2020-11-25T17:27:16.498Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.498Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.498Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.498Z src/core/connection.rs:760 ringrtc! 1606325236467 conn -> rtc: ice_candidates(0) INFO 2020-11-25T17:27:16.498Z src/core/connection.rs:466 Starting Connection FSM for 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.498Z src/core/connection_fsm.rs:328 syncing worker thread: ThreadId(29) INFO 2020-11-25T17:27:16.498Z src/core/connection_fsm.rs:328 syncing notify thread: ThreadId(30) INFO 2020-11-25T17:27:16.498Z src/core/call_manager.rs:1937 send_answer(): call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:16.498Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:27:16.498Z src/core/call_manager.rs:1659 send_next_message(): sending message, len: 0 INFO 2020-11-25T17:27:16.498Z src/core/call_manager.rs:1940 ringrtc! 1606325236467 cm -> app: send_answer() 0x2bb44a7dc03eaad opaque=true/72; sdp=false INFO 2020-11-25T17:27:16.498Z src/core/call_manager.rs:1950 call_id: 0x2bb44a7dc03eaad, TX answer: opaque: ... INFO 2020-11-25T17:27:16.498Z src/native.rs:558 NativePlatform::on_send_answer(): remote_peer: [REDACTED]429, call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:16.498Z src/core/connection_fsm.rs:282 state: ConnectingBeforeAccepted, event: (ReceivedSignalingDataChannel, dc: 0x2542d5f29f20) INFO 2020-11-25T17:27:16.498Z src/core/connection_fsm.rs:951 ringrtc! 1606325236467 rtc -> conn: on_data_channel() INFO 2020-11-25T17:27:16.498Z src/core/connection_fsm.rs:282 state: ConnectingBeforeAccepted, event: (ReceivedIncomingMedia, stream: rffi_media_stream: 0x2542d84eb750) INFO 2020-11-25T17:27:16.498Z src/core/connection_fsm.rs:282 state: ConnectingBeforeAccepted, event: (LocalIceCandidate) INFO 2020-11-25T17:27:16.498Z src/core/connection_fsm.rs:782 ringrtc! 1606325236467 rtc -> conn: ice_candidate() 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.498Z src/core/connection_fsm.rs:282 state: ConnectingBeforeAccepted, event: (LocalIceCandidate) INFO 2020-11-25T17:27:16.498Z src/core/connection.rs:1322 handle_received_incoming_media(): id: 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.498Z src/native.rs:390 NativePlatform::create_incoming_media() INFO 2020-11-25T17:27:16.498Z src/core/connection_fsm.rs:782 ringrtc! 1606325236467 rtc -> conn: ice_candidate() 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.498Z src/core/connection_fsm.rs:282 state: ConnectingBeforeAccepted, event: (LocalIceCandidate) INFO 2020-11-25T17:27:16.498Z src/core/connection_fsm.rs:782 ringrtc! 1606325236467 rtc -> conn: ice_candidate() 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.498Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/124; sdp=true/120; opaque: ...; sdp: candidate:1967680543 1 udp 2122260223 [REDACTED] 60039 typ host generation 0 ufrag qO5c network-id 1 network-cost 50 INFO 2020-11-25T17:27:16.498Z src/core/call.rs:456 send_buffered_local_ice_candidates(): ConnectingBeforeAccepted INFO 2020-11-25T17:27:16.498Z src/core/call_manager.rs:1984 send_ice_candidates(): call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:16.498Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:27:16.498Z src/core/call_manager.rs:1653 send_next_message(): messages are in flight already INFO 2020-11-25T17:27:16.498Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/120; sdp=true/116; opaque: ...; sdp: candidate:1195588707 1 udp 2122194687 [REDACTED] 36735 typ host generation 0 ufrag qO5c network-id 4 network-cost 50 INFO 2020-11-25T17:27:16.498Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/108; sdp=true/104; opaque: ...; sdp: candidate:1195588707 1 udp 2113937151 [REDACTED] 45482 typ host generation 0 ufrag qO5c network-cost 999 INFO 2020-11-25T17:27:16.506Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 (unauth) INFO 2020-11-25T17:27:16.675Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 200 Success INFO 2020-11-25T17:27:16.675Z handleOutgoingSignaling() completed successfully INFO 2020-11-25T17:27:16.697Z SQL channel job 164 (saveUnprocesseds) succeeded in 17ms INFO 2020-11-25T17:27:16.697Z queueing envelope 3d7b132c16b44d2b85819e76bbf7dc80 INFO 2020-11-25T17:27:16.697Z received unidentified sender message INFO 2020-11-25T17:27:16.699Z src/core/call_manager.rs:407 API:CallManager::handle_message_sent(): INFO 2020-11-25T17:27:16.699Z src/core/call_manager.rs:956 ringrtc! 1606325236675 app -> cm: message_sent() 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:16.699Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:27:16.699Z src/core/call_manager.rs:1659 send_next_message(): sending message, len: 0 INFO 2020-11-25T17:27:16.699Z src/core/connection.rs:1148 take_buffered_local_ice_candidates(): INFO 2020-11-25T17:27:16.699Z src/core/connection.rs:1155 take_buffered_local_ice_candidates(): Local ICE candidates length: 3 INFO 2020-11-25T17:27:16.699Z src/core/call_manager.rs:1993 ringrtc! 1606325236675 cm -> app: send_ice_candidates(3) 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:16.699Z src/native.rs:577 NativePlatform::on_send_ice(): remote_peer: [REDACTED]429, call_id: 0x2bb44a7dc03eaad, receiver_device_id: Some(1), candidates: 3 INFO 2020-11-25T17:27:16.699Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.699Z src/core/connection_fsm.rs:282 state: ConnectingBeforeAccepted, event: (LocalIceCandidate) INFO 2020-11-25T17:27:16.699Z src/core/connection_fsm.rs:782 ringrtc! 1606325236687 rtc -> conn: ice_candidate() 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.699Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/143; sdp=true/137; opaque: ...; sdp: candidate:842163049 1 udp 1677729535 [REDACTED] 38374 typ srflx raddr [REDACTED] rport 45482 generation 0 ufrag qO5c network-cost 999 INFO 2020-11-25T17:27:16.699Z src/core/call.rs:456 send_buffered_local_ice_candidates(): ConnectingBeforeAccepted INFO 2020-11-25T17:27:16.699Z src/core/call_manager.rs:1984 send_ice_candidates(): call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:16.699Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:27:16.699Z src/core/call_manager.rs:1653 send_next_message(): messages are in flight already INFO 2020-11-25T17:27:16.699Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.700Z src/core/connection_fsm.rs:282 state: ConnectingBeforeAccepted, event: (LocalIceCandidate) INFO 2020-11-25T17:27:16.700Z src/core/connection_fsm.rs:782 ringrtc! 1606325236689 rtc -> conn: ice_candidate() 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.700Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/156; sdp=true/150; opaque: ...; sdp: candidate:2757933711 1 udp 1685987071 [REDACTED] 47015 typ srflx raddr [REDACTED] rport 36735 generation 0 ufrag qO5c network-id 4 network-cost 50 INFO 2020-11-25T17:27:16.702Z CallingClass.handleCallingMessage() INFO 2020-11-25T17:27:16.703Z CallingClass.handleCallingMessage(): Handling in RingRTC INFO 2020-11-25T17:27:16.707Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 (unauth) INFO 2020-11-25T17:27:16.750Z src/core/call_manager.rs:456 API:CallManager::handle_received_ice(): INFO 2020-11-25T17:27:16.750Z src/core/call_manager.rs:1284 ringrtc! 1606325236703 app -> cm: received_ice_candidates(10) 0x2bb44a7dc03eaad 1 INFO 2020-11-25T17:27:16.750Z src/core/call_manager.rs:1295 handle_received_ice(): active call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:16.750Z src/core/call_fsm.rs:215 state: ConnectingBeforeAccepted, event: (ReceivedIce, device: 1) INFO 2020-11-25T17:27:16.750Z src/core/call.rs:631 received_ice(): id: 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.750Z src/core/connection_fsm.rs:282 state: ConnectingBeforeAccepted, event: (RemoteIceCandidates) INFO 2020-11-25T17:27:16.750Z src/core/connection.rs:1167 ringrtc! 1606325236703 conn -> rtc: ice_candidates(10) INFO 2020-11-25T17:27:16.750Z src/webrtc/peer_connection_observer.rs:158 ringrtc! 1606325236704 rtc -> conn: ice_connection_change(Checking) 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.850Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.850Z src/core/connection_fsm.rs:282 state: ConnectingBeforeAccepted, event: (LocalIceCandidate) INFO 2020-11-25T17:27:16.850Z src/core/connection_fsm.rs:782 ringrtc! 1606325236811 rtc -> conn: ice_candidate() 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.850Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/145; sdp=true/139; opaque: ...; sdp: candidate:1173891001 1 udp 33562879 [REDACTED] 63100 typ relay raddr [REDACTED] rport 38374 generation 0 ufrag qO5c network-cost 999 INFO 2020-11-25T17:27:16.850Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.850Z src/core/connection_fsm.rs:282 state: ConnectingBeforeAccepted, event: (LocalIceCandidate) INFO 2020-11-25T17:27:16.850Z src/core/connection_fsm.rs:782 ringrtc! 1606325236815 rtc -> conn: ice_candidate() 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.850Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/157; sdp=true/151; opaque: ...; sdp: candidate:1173891001 1 udp 41820415 [REDACTED] 52540 typ relay raddr [REDACTED] rport 47015 generation 0 ufrag qO5c network-id 4 network-cost 50 INFO 2020-11-25T17:27:16.879Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 200 Success INFO 2020-11-25T17:27:16.879Z handleOutgoingSignaling() completed successfully INFO 2020-11-25T17:27:16.900Z src/core/call_manager.rs:407 API:CallManager::handle_message_sent(): INFO 2020-11-25T17:27:16.900Z src/core/call_manager.rs:956 ringrtc! 1606325236879 app -> cm: message_sent() 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:16.900Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:27:16.900Z src/core/call_manager.rs:1659 send_next_message(): sending message, len: 0 INFO 2020-11-25T17:27:16.900Z src/core/connection.rs:1148 take_buffered_local_ice_candidates(): INFO 2020-11-25T17:27:16.900Z src/core/connection.rs:1155 take_buffered_local_ice_candidates(): Local ICE candidates length: 4 INFO 2020-11-25T17:27:16.900Z src/core/call_manager.rs:1993 ringrtc! 1606325236879 cm -> app: send_ice_candidates(4) 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:16.900Z src/native.rs:577 NativePlatform::on_send_ice(): remote_peer: [REDACTED]429, call_id: 0x2bb44a7dc03eaad, receiver_device_id: Some(1), candidates: 4 INFO 2020-11-25T17:27:16.905Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 (unauth) INFO 2020-11-25T17:27:16.951Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.951Z src/core/connection_fsm.rs:282 state: ConnectingBeforeAccepted, event: (LocalIceCandidate) INFO 2020-11-25T17:27:16.951Z src/core/connection_fsm.rs:782 ringrtc! 1606325236923 rtc -> conn: ice_candidate() 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.951Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/156; sdp=true/150; opaque: ...; sdp: candidate:192666441 1 udp 25042687 [REDACTED] 57627 typ relay raddr [REDACTED] rport 30681 generation 0 ufrag qO5c network-id 4 network-cost 50 INFO 2020-11-25T17:27:16.951Z src/core/call.rs:456 send_buffered_local_ice_candidates(): ConnectingBeforeAccepted INFO 2020-11-25T17:27:16.951Z src/core/call_manager.rs:1984 send_ice_candidates(): call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:16.951Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:27:16.951Z src/core/call_manager.rs:1653 send_next_message(): messages are in flight already INFO 2020-11-25T17:27:16.951Z src/webrtc/peer_connection_observer.rs:128 pc_observer_OnIceCandidate: 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.951Z src/core/connection_fsm.rs:282 state: ConnectingBeforeAccepted, event: (LocalIceCandidate) INFO 2020-11-25T17:27:16.951Z src/core/connection_fsm.rs:782 ringrtc! 1606325236930 rtc -> conn: ice_candidate() 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:16.951Z src/core/connection.rs:1105 Local ICE candidate: opaque=true/144; sdp=true/138; opaque: ...; sdp: candidate:192666441 1 udp 16785151 [REDACTED] 61831 typ relay raddr [REDACTED] rport 29254 generation 0 ufrag qO5c network-cost 999 INFO 2020-11-25T17:27:17.116Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 200 Success INFO 2020-11-25T17:27:17.116Z handleOutgoingSignaling() completed successfully INFO 2020-11-25T17:27:17.151Z src/core/call_manager.rs:407 API:CallManager::handle_message_sent(): INFO 2020-11-25T17:27:17.151Z src/core/call_manager.rs:956 ringrtc! 1606325237116 app -> cm: message_sent() 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:17.151Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:27:17.151Z src/core/call_manager.rs:1659 send_next_message(): sending message, len: 0 INFO 2020-11-25T17:27:17.151Z src/core/connection.rs:1148 take_buffered_local_ice_candidates(): INFO 2020-11-25T17:27:17.151Z src/core/connection.rs:1155 take_buffered_local_ice_candidates(): Local ICE candidates length: 2 INFO 2020-11-25T17:27:17.151Z src/core/call_manager.rs:1993 ringrtc! 1606325237116 cm -> app: send_ice_candidates(2) 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:17.151Z src/native.rs:577 NativePlatform::on_send_ice(): remote_peer: [REDACTED]429, call_id: 0x2bb44a7dc03eaad, receiver_device_id: Some(1), candidates: 2 INFO 2020-11-25T17:27:17.157Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 (unauth) INFO 2020-11-25T17:27:17.213Z SQL channel job 165 (updateUnprocessedsWithData) succeeded in 12ms INFO 2020-11-25T17:27:17.224Z SQL channel job 166 (removeUnprocessed) succeeded in 22ms INFO 2020-11-25T17:27:17.351Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 200 Success INFO 2020-11-25T17:27:17.351Z handleOutgoingSignaling() completed successfully INFO 2020-11-25T17:27:17.352Z src/core/call_manager.rs:407 API:CallManager::handle_message_sent(): INFO 2020-11-25T17:27:17.352Z src/core/call_manager.rs:956 ringrtc! 1606325237351 app -> cm: message_sent() 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:17.352Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:27:17.352Z src/core/call_manager.rs:1691 send_next_message(): no messages to send INFO 2020-11-25T17:27:17.402Z src/webrtc/peer_connection_observer.rs:158 ringrtc! 1606325237379 rtc -> conn: ice_connection_change(Connected) 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:17.402Z src/core/connection_fsm.rs:282 state: ConnectingBeforeAccepted, event: (IceConnected) INFO 2020-11-25T17:27:17.402Z src/core/call.rs:975 on_connection_observer_event(): call_id: 0x2bb44a7dc03eaad, remote_device_id: 1, event: ConnectedWithDataChannelBeforeAccepted INFO 2020-11-25T17:27:17.402Z src/core/call_fsm.rs:215 state: ConnectingBeforeAccepted, event: (ConnectionObserverEvent, event: ConnectedWithDataChannelBeforeAccepted, device: 1) INFO 2020-11-25T17:27:17.402Z src/core/call_manager.rs:1764 ringrtc! 1606325237379 cm -> app: event(LocalRinging) INFO 2020-11-25T17:27:17.402Z src/native.rs:438 NativePlatform::on_event(): remote_peer: [REDACTED]429, event: LocalRinging INFO 2020-11-25T17:27:17.427Z Approving request for permission 'notifications' INFO 2020-11-25T17:27:17.672Z SQL channel job 167 (createOrUpdateSessions) succeeded in 18ms INFO 2020-11-25T17:27:19.061Z Removing notification INFO 2020-11-25T17:27:19.524Z SQL channel job 168 (saveUnprocesseds) succeeded in 17ms INFO 2020-11-25T17:27:19.524Z queueing envelope b4453ca2838240ce94a577dbdf1f09fd INFO 2020-11-25T17:27:19.524Z received unidentified sender message INFO 2020-11-25T17:27:19.526Z New remote ephemeral key INFO 2020-11-25T17:27:19.528Z Deleting chain closed at 1605966511036 INFO 2020-11-25T17:27:19.528Z CallingClass.handleCallingMessage() INFO 2020-11-25T17:27:19.529Z CallingClass.handleCallingMessage(): Handling in RingRTC INFO 2020-11-25T17:27:19.557Z src/core/call_manager.rs:456 API:CallManager::handle_received_ice(): INFO 2020-11-25T17:27:19.557Z src/core/call_manager.rs:1284 ringrtc! 1606325239529 app -> cm: received_ice_candidates(1) 0x2bb44a7dc03eaad 1 INFO 2020-11-25T17:27:19.557Z src/core/call_manager.rs:1295 handle_received_ice(): active call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:19.557Z src/core/call_fsm.rs:215 state: ConnectedWithDataChannelBeforeAccepted, event: (ReceivedIce, device: 1) INFO 2020-11-25T17:27:19.557Z src/core/call.rs:631 received_ice(): id: 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:19.557Z src/core/connection_fsm.rs:282 state: ConnectedBeforeAccepted, event: (RemoteIceCandidates) INFO 2020-11-25T17:27:19.557Z src/core/connection.rs:1167 ringrtc! 1606325239529 conn -> rtc: ice_candidates(1) INFO 2020-11-25T17:27:19.877Z SQL channel job 171 (saveUnprocesseds) succeeded in 11ms INFO 2020-11-25T17:27:19.878Z queueing envelope 8bf8f20889e24e95bcaa284534f30502 INFO 2020-11-25T17:27:19.878Z received unidentified sender message INFO 2020-11-25T17:27:19.881Z CallingClass.handleCallingMessage() INFO 2020-11-25T17:27:19.881Z CallingClass.handleCallingMessage(): Handling in RingRTC INFO 2020-11-25T17:27:19.908Z src/core/call_manager.rs:456 API:CallManager::handle_received_ice(): INFO 2020-11-25T17:27:19.908Z src/core/call_manager.rs:1284 ringrtc! 1606325239881 app -> cm: received_ice_candidates(2) 0x2bb44a7dc03eaad 1 INFO 2020-11-25T17:27:19.908Z src/core/call_manager.rs:1295 handle_received_ice(): active call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:19.908Z src/core/call_fsm.rs:215 state: ConnectedWithDataChannelBeforeAccepted, event: (ReceivedIce, device: 1) INFO 2020-11-25T17:27:19.908Z src/core/call.rs:631 received_ice(): id: 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:19.908Z src/core/connection_fsm.rs:282 state: ConnectedBeforeAccepted, event: (RemoteIceCandidates) INFO 2020-11-25T17:27:19.908Z src/core/connection.rs:1167 ringrtc! 1606325239881 conn -> rtc: ice_candidates(2) INFO 2020-11-25T17:27:20.075Z SQL channel job 172 (updateConversations) succeeded in 12ms INFO 2020-11-25T17:27:20.286Z CallingClass.accept() ERROR 2020-11-25T17:27:20.309Z src/webrtc/peer_connection_factory.rs:438 getAudioRecordingDevices() returned -1 ERROR 2020-11-25T17:27:20.309Z src/webrtc/peer_connection_factory.rs:336 getAudioPlayoutDevices() returned -1 INFO 2020-11-25T17:27:20.359Z src/core/call_manager.rs:388 API:CallManager::handle_accept_call(): INFO 2020-11-25T17:27:20.360Z src/core/call_manager.rs:890 ringrtc! 1606325240344 app -> cm: accept() 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:20.360Z src/core/call_manager.rs:896 handle_accept_call(): active call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:20.360Z src/core/call_fsm.rs:215 state: ConnectedWithDataChannelBeforeAccepted, event: (AcceptCall) INFO 2020-11-25T17:27:20.360Z src/core/call_fsm.rs:597 handle_accept_call(): INFO 2020-11-25T17:27:20.360Z src/core/connection.rs:1334 connect_incoming_media(): id: 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:20.360Z src/native.rs:400 NativePlatform::connect_incoming_media() INFO 2020-11-25T17:27:20.360Z src/core/connection_fsm.rs:282 state: ConnectedBeforeAccepted, event: (Accept) INFO 2020-11-25T17:27:20.360Z src/core/connection.rs:960 set_local_max_send_bitrate(): local_max: DataRate { size_per_second: DataSize { bits: 2000000 } } INFO 2020-11-25T17:27:20.360Z src/core/call_manager.rs:1764 ringrtc! 1606325240344 cm -> app: event(LocalAccepted) INFO 2020-11-25T17:27:20.360Z src/native.rs:438 NativePlatform::on_event(): remote_peer: [REDACTED]429, event: LocalAccepted INFO 2020-11-25T17:27:20.360Z src/core/connection.rs:1208 ringrtc! 1606325240345 conn -> rtc: dc(accepted) 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:20.360Z src/core/connection.rs:1265 Sending data channel message: Data { accepted: Some(Accepted { id: Some(196826496462219949) }), hangup: None, sender_status: None, sequence_number: Some(1), receiver_status: None } INFO 2020-11-25T17:27:20.393Z SQL channel job 173 (createOrUpdateSessions) succeeded in 12ms INFO 2020-11-25T17:27:20.403Z SQL channel job 174 (updateUnprocessedsWithData) succeeded in 22ms INFO 2020-11-25T17:27:20.410Z src/core/call_manager.rs:561 active_connection(): INFO 2020-11-25T17:27:20.410Z src/core/connection_fsm.rs:282 state: ConnectedAndAccepted, event: (SendSenderStatusViaDataChannel, enabled: false) INFO 2020-11-25T17:27:20.410Z src/core/connection.rs:1265 Sending data channel message: Data { accepted: Some(Accepted { id: Some(196826496462219949) }), hangup: None, sender_status: Some(SenderStatus { id: Some(196826496462219949), video_enabled: Some(false) }), sequence_number: Some(2), receiver_status: None } INFO 2020-11-25T17:27:20.414Z SQL channel job 175 (removeUnprocessed) succeeded in 33ms INFO 2020-11-25T17:27:20.560Z src/core/call.rs:975 on_connection_observer_event(): call_id: 0x2bb44a7dc03eaad, remote_device_id: 1, event: ReceivedSenderStatusViaDataChannel(false) INFO 2020-11-25T17:27:20.560Z src/core/call_fsm.rs:215 state: ConnectedAndAccepted, event: (ConnectionObserverEvent, event: ReceivedSenderStatusViaDataChannel(false), device: 1) INFO 2020-11-25T17:27:20.561Z src/core/call_manager.rs:1764 ringrtc! 1606325240558 cm -> app: event(RemoteVideoDisable) INFO 2020-11-25T17:27:20.561Z src/native.rs:438 NativePlatform::on_event(): remote_peer: [REDACTED]429, event: RemoteVideoDisable INFO 2020-11-25T17:27:21.055Z SQL channel job 178 (saveUnprocesseds) succeeded in 20ms INFO 2020-11-25T17:27:21.056Z queueing envelope fff1839915704d84b362a0b792b2315c INFO 2020-11-25T17:27:21.056Z received unidentified sender message INFO 2020-11-25T17:27:21.058Z CallingClass.handleCallingMessage() INFO 2020-11-25T17:27:21.059Z CallingClass.handleCallingMessage(): Handling in RingRTC INFO 2020-11-25T17:27:21.063Z src/core/call_manager.rs:465 API:CallManager::handle_received_hangup(): INFO 2020-11-25T17:27:21.063Z src/core/call_manager.rs:1310 ringrtc! 1606325241059 app -> cm: received_hangup(AcceptedOnAnotherDevice/2) 0x2bb44a7dc03eaad 1 INFO 2020-11-25T17:27:21.063Z src/core/call_manager.rs:1319 handle_received_hangup(): active call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:21.063Z src/core/call_fsm.rs:215 state: ConnectedAndAccepted, event: (ReceivedHangup, device: 1 hangup: AcceptedOnAnotherDevice/2) INFO 2020-11-25T17:27:21.063Z src/core/call_fsm.rs:466 handle_received_hangup(): remote_device_id: 1, hangup: AcceptedOnAnotherDevice/2 INFO 2020-11-25T17:27:21.064Z src/core/call_fsm.rs:479 handle_received_hangup(): Ignoring hangup message originated by this device INFO 2020-11-25T17:27:21.314Z SQL channel job 179 (updateConversations) succeeded in 15ms INFO 2020-11-25T17:27:21.573Z SQL channel job 180 (createOrUpdateSessions) succeeded in 15ms INFO 2020-11-25T17:27:21.589Z SQL channel job 181 (updateUnprocessedsWithData) succeeded in 30ms INFO 2020-11-25T17:27:21.599Z SQL channel job 182 (removeUnprocessed) succeeded in 40ms INFO 2020-11-25T17:27:21.707Z show window INFO 2020-11-25T17:27:22.645Z SQL channel job 183 (saveUnprocesseds) succeeded in 12ms INFO 2020-11-25T17:27:22.645Z queueing envelope [REDACTED]372.1 1606325243229 (cdeadaff7b5c4b168f6fecb1a1af0249) INFO 2020-11-25T17:27:22.645Z message from [REDACTED]372.1 1606325243229 (cdeadaff7b5c4b168f6fecb1a1af0249) INFO 2020-11-25T17:27:22.647Z contact sync INFO 2020-11-25T17:27:22.648Z GET https://cdn2.signal.org/attachments/[REDACTED]CQ3 INFO 2020-11-25T17:27:23.167Z SQL channel job 184 (createOrUpdateSessions) succeeded in 21ms INFO 2020-11-25T17:27:23.177Z SQL channel job 185 (updateUnprocessedsWithData) succeeded in 31ms INFO 2020-11-25T17:27:23.190Z SQL channel job 186 (removeUnprocessed) succeeded in 43ms ERROR 2020-11-25T17:27:23.369Z src/webrtc/peer_connection_factory.rs:438 getAudioRecordingDevices() returned -1 ERROR 2020-11-25T17:27:23.369Z src/webrtc/peer_connection_factory.rs:336 getAudioPlayoutDevices() returned -1 INFO 2020-11-25T17:27:24.611Z GET https://cdn2.signal.org/attachments/[REDACTED]CQ3 200 Success INFO 2020-11-25T17:27:24.628Z got verified sync for +[REDACTED]054 [REDACTED]b5f DEFAULT via contact sync INFO 2020-11-25T17:27:24.634Z handleContacts: finished INFO 2020-11-25T17:27:24.647Z got verified sync for +[REDACTED]910 [REDACTED]429 VERIFIED via contact sync INFO 2020-11-25T17:27:24.650Z got verified sync for +[REDACTED]952 [REDACTED]cc4 DEFAULT via contact sync INFO 2020-11-25T17:27:24.653Z got verified sync for +[REDACTED]313 [REDACTED]185 DEFAULT via contact sync INFO 2020-11-25T17:27:24.655Z got verified sync for +[REDACTED]950 [REDACTED]165 VERIFIED via contact sync INFO 2020-11-25T17:27:24.656Z got verified sync for +[REDACTED]783 [REDACTED]0bb DEFAULT via contact sync INFO 2020-11-25T17:27:24.656Z incrementProgress: Message count is 10 INFO 2020-11-25T17:27:24.657Z got verified sync for +[REDACTED]155 [REDACTED]c7a DEFAULT via contact sync INFO 2020-11-25T17:27:24.657Z got verified sync for +[REDACTED]699 [REDACTED]393 DEFAULT via contact sync INFO 2020-11-25T17:27:24.657Z No existing record for default status INFO 2020-11-25T17:27:24.658Z Setting sealedSender to UNKNOWN for conversation [REDACTED]2f2 ([REDACTED]f9b) INFO 2020-11-25T17:27:24.663Z got verified sync for +[REDACTED]338 [REDACTED]2f2 DEFAULT via contact sync INFO 2020-11-25T17:27:24.664Z got verified sync for +[REDACTED]631 [REDACTED]1fc DEFAULT via contact sync INFO 2020-11-25T17:27:24.666Z got verified sync for +[REDACTED]243 [REDACTED]399 DEFAULT via contact sync INFO 2020-11-25T17:27:24.668Z Generating request... INFO 2020-11-25T17:27:24.672Z GET https://textsecure-service.whispersystems.org/v1/profile/[REDACTED]2f2/[REDACTED]26f/[REDACTED]a0e (unauth) INFO 2020-11-25T17:27:24.674Z got verified sync for +[REDACTED]523 [REDACTED]699 DEFAULT via contact sync INFO 2020-11-25T17:27:24.674Z got verified sync for +[REDACTED]927 [REDACTED]f40 DEFAULT via contact sync INFO 2020-11-25T17:27:24.674Z No existing record for default status INFO 2020-11-25T17:27:24.675Z got verified sync for +[REDACTED]181 [REDACTED]8f4 VERIFIED via contact sync INFO 2020-11-25T17:27:24.675Z incrementProgress: Message count is 20 INFO 2020-11-25T17:27:24.676Z got verified sync for +[REDACTED]923 [REDACTED]7ea DEFAULT via contact sync INFO 2020-11-25T17:27:24.678Z got verified sync for +[REDACTED]006 [REDACTED]51d DEFAULT via contact sync INFO 2020-11-25T17:27:24.678Z No existing record for default status INFO 2020-11-25T17:27:24.679Z got verified sync for +[REDACTED]054 [REDACTED]61e DEFAULT via contact sync INFO 2020-11-25T17:27:24.680Z got verified sync for +[REDACTED]801 [REDACTED]c06 DEFAULT via contact sync INFO 2020-11-25T17:27:24.680Z SQL channel job 187 (updateConversations) succeeded in 17ms INFO 2020-11-25T17:27:24.681Z got verified sync for +[REDACTED]577 [REDACTED]dbd DEFAULT via contact sync INFO 2020-11-25T17:27:24.682Z got verified sync for +[REDACTED]487 [REDACTED]0c3 DEFAULT via contact sync INFO 2020-11-25T17:27:24.682Z got verified sync for +[REDACTED]989 [REDACTED]c93 DEFAULT via contact sync INFO 2020-11-25T17:27:24.682Z incrementProgress: Message count is 30 INFO 2020-11-25T17:27:24.683Z got verified sync for +[REDACTED]711 [REDACTED]b09 DEFAULT via contact sync INFO 2020-11-25T17:27:24.684Z got verified sync for +[REDACTED]818 [REDACTED]58a DEFAULT via contact sync INFO 2020-11-25T17:27:24.684Z Got sync message with our own profile key INFO 2020-11-25T17:27:24.696Z SQL channel job 188 (updateConversations) succeeded in 16ms INFO 2020-11-25T17:27:24.706Z SQL channel job 189 (createOrUpdateItem) succeeded in 22ms INFO 2020-11-25T17:27:24.880Z GET https://textsecure-service.whispersystems.org/v1/profile/[REDACTED]2f2/[REDACTED]26f/[REDACTED]a0e 401 Error INFO 2020-11-25T17:27:24.880Z Setting sealedSender to DISABLED for conversation [REDACTED]2f2 ([REDACTED]f9b) INFO 2020-11-25T17:27:24.882Z GET https://textsecure-service.whispersystems.org/v1/profile/[REDACTED]2f2/[REDACTED]26f/[REDACTED]a0e INFO 2020-11-25T17:27:25.062Z GET https://textsecure-service.whispersystems.org/v1/profile/[REDACTED]2f2/[REDACTED]26f/[REDACTED]a0e 200 Success INFO 2020-11-25T17:27:25.062Z Setting sealedSender to DISABLED for conversation [REDACTED]2f2 ([REDACTED]f9b) WARN 2020-11-25T17:27:25.063Z getProfile decryption failure: [REDACTED]2f2 ([REDACTED]f9b) ProfileDecryptError: Failed to decrypt profile data. Most likely the profile key has changed. at Object.decryptProfile ([REDACTED]/app.asar/ts/textsecure/Crypto.js:135:23) at Object.decryptProfileName ([REDACTED]/app.asar/ts/textsecure/Crypto.js:158:23) at ConversationModel.setEncryptedProfileName ([REDACTED]/app.asar/ts/models/conversations.js:2595:66) at ConversationModel.getProfile ([REDACTED]/app.asar/ts/models/conversations.js:2564:21) INFO 2020-11-25T17:27:25.063Z Dropping profileKey, setting sealedSender to UNKNOWN for conversation [REDACTED]2f2 ([REDACTED]f9b) INFO 2020-11-25T17:27:25.065Z GET https://textsecure-service.whispersystems.org/v1/profile/[REDACTED]2f2 (unauth) INFO 2020-11-25T17:27:25.217Z GET https://textsecure-service.whispersystems.org/v1/profile/[REDACTED]2f2 401 Error INFO 2020-11-25T17:27:25.217Z Setting sealedSender to DISABLED for conversation [REDACTED]2f2 ([REDACTED]f9b) INFO 2020-11-25T17:27:25.218Z GET https://textsecure-service.whispersystems.org/v1/profile/[REDACTED]2f2 INFO 2020-11-25T17:27:25.409Z GET https://textsecure-service.whispersystems.org/v1/profile/[REDACTED]2f2 200 Success INFO 2020-11-25T17:27:25.409Z Setting sealedSender to DISABLED for conversation [REDACTED]2f2 ([REDACTED]f9b) INFO 2020-11-25T17:27:25.923Z SQL channel job 190 (updateConversations) succeeded in 13ms ERROR 2020-11-25T17:27:26.353Z src/webrtc/peer_connection_factory.rs:438 getAudioRecordingDevices() returned -1 ERROR 2020-11-25T17:27:26.353Z src/webrtc/peer_connection_factory.rs:336 getAudioPlayoutDevices() returned -1 ERROR 2020-11-25T17:27:29.359Z src/webrtc/peer_connection_factory.rs:438 getAudioRecordingDevices() returned -1 ERROR 2020-11-25T17:27:29.359Z src/webrtc/peer_connection_factory.rs:336 getAudioPlayoutDevices() returned -1 INFO 2020-11-25T17:27:29.359Z src/webrtc/stats_observer.rs:72 ringrtc_stats!,0,-1,-1,430,0,4,0.000,0.000,0.000,0.000,120 INFO 2020-11-25T17:27:31.963Z CallingClass.hangup() INFO 2020-11-25T17:27:32.213Z src/core/call_manager.rs:417 API:CallManager::handle_hangup(): INFO 2020-11-25T17:27:32.213Z src/core/call_manager.rs:1048 ringrtc! 1606325251966 app -> cm: hangup() INFO 2020-11-25T17:27:32.213Z src/core/call_manager.rs:1050 handle_hangup(): active call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:32.213Z src/core/call_manager.rs:779 conclude_call(): call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:32.213Z src/core/call_manager.rs:1764 ringrtc! 1606325251966 cm -> app: event(EndedLocalHangup) INFO 2020-11-25T17:27:32.213Z src/native.rs:438 NativePlatform::on_event(): remote_peer: [REDACTED]429, event: EndedLocalHangup INFO 2020-11-25T17:27:32.213Z src/core/call_manager.rs:737 send_hangup(): call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:32.213Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:27:32.214Z src/core/call_manager.rs:1659 send_next_message(): sending message, len: 0 INFO 2020-11-25T17:27:32.214Z src/core/call_manager.rs:740 ringrtc! 1606325251966 cm -> app: send_hangup(Normal) 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:32.214Z src/native.rs:596 NativePlatform::on_send_hangup(): remote_peer: [REDACTED]429, call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:32.214Z src/core/call_manager.rs:719 terminate_call(): call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:32.214Z src/core/call.rs:855 terminate(): ref_count: 6 INFO 2020-11-25T17:27:32.214Z src/core/call.rs:878 terminate(): waiting for terminate complete... INFO 2020-11-25T17:27:32.214Z src/core/call_fsm.rs:215 state: Terminating, event: (SendHangupViaDataChannelToAll, hangup: Normal/None) INFO 2020-11-25T17:27:32.214Z src/core/call_fsm.rs:630 handle_send_hangup_via_data_channel_to_all(): INFO 2020-11-25T17:27:32.214Z src/core/call_fsm.rs:215 state: Terminating, event: (Terminate) INFO 2020-11-25T17:27:32.214Z src/core/call_fsm.rs:288 draining worker thread INFO 2020-11-25T17:27:32.214Z src/core/call.rs:681 send_hangup_via_data_channel_to_all(): call_id: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:32.214Z src/core/call.rs:688 send_hangup_via_data_channel_to_all(): call_id: 0x2bb44a7dc03eaad remote_device_id: 1 INFO 2020-11-25T17:27:32.214Z src/core/connection_fsm.rs:282 state: Terminating, event: (SendHangupViaDataChannel, hangup: Normal/None) INFO 2020-11-25T17:27:32.214Z src/core/connection.rs:1185 ringrtc! 1606325251966 conn -> rtc: dc(hangup/Normal/None) 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:32.214Z src/core/connection.rs:1265 Sending data channel message: Data { accepted: Some(Accepted { id: Some(196826496462219949) }), hangup: Some(Hangup { id: Some(196826496462219949), r#type: Some(HangupNormal), device_id: None }), sender_status: Some(SenderStatus { id: Some(196826496462219949), video_enabled: Some(false) }), sequence_number: Some(3), receiver_status: None } INFO 2020-11-25T17:27:32.214Z src/core/call_fsm.rs:290 draining worker thread: complete INFO 2020-11-25T17:27:32.214Z src/core/call_fsm.rs:295 draining notify thread INFO 2020-11-25T17:27:32.214Z src/core/call_fsm.rs:297 draining notify thread: complete INFO 2020-11-25T17:27:32.214Z src/core/call.rs:903 notify_terminate_complete(): notifying terminate complete... INFO 2020-11-25T17:27:32.214Z src/core/call_fsm.rs:221 No more events! INFO 2020-11-25T17:27:32.214Z src/core/call_fsm.rs:199 Dropping CallStateMachine: INFO 2020-11-25T17:27:32.214Z src/core/call.rs:892 terminate(): terminate complete: ref_count: 5 INFO 2020-11-25T17:27:32.214Z src/native.rs:411 NativePlatform::disconnect_incoming_media() INFO 2020-11-25T17:27:32.214Z src/core/call.rs:806 terminate_connections(): call_id: 0x2bb44a7dc03eaad remote_device_id: 1 INFO 2020-11-25T17:27:32.214Z src/core/connection.rs:1373 terminate(): ref_count: 3 INFO 2020-11-25T17:27:32.214Z src/core/connection.rs:1438 terminate(): waiting for terminate complete... INFO 2020-11-25T17:27:32.214Z src/core/connection_fsm.rs:282 state: Terminating, event: (Terminate) INFO 2020-11-25T17:27:32.214Z src/core/connection_fsm.rs:358 draining worker thread INFO 2020-11-25T17:27:32.214Z src/core/connection_fsm.rs:360 draining worker thread: complete INFO 2020-11-25T17:27:32.214Z src/core/connection_fsm.rs:365 draining notify thread INFO 2020-11-25T17:27:32.214Z src/core/connection_fsm.rs:367 draining notify thread: complete INFO 2020-11-25T17:27:32.214Z src/core/connection_fsm.rs:289 No more events! INFO 2020-11-25T17:27:32.214Z src/core/connection.rs:1454 terminate(): terminate complete: ref_count: 3 INFO 2020-11-25T17:27:32.214Z src/core/connection.rs:1385 close(): stopping the tick runtime INFO 2020-11-25T17:27:32.214Z src/core/connection.rs:354 Connection: Dropping last reference: 0x2bb44a7dc03eaad-1 INFO 2020-11-25T17:27:32.214Z src/webrtc/peer_connection.rs:68 PeerConnection::drop() INFO 2020-11-25T17:27:32.214Z src/core/call.rs:58 stopping timeout runtime INFO 2020-11-25T17:27:32.214Z src/core/call.rs:60 stopping timeout runtime: complete INFO 2020-11-25T17:27:32.214Z src/core/call.rs:168 Call: Dropping last reference: 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:32.214Z src/core/call_manager.rs:1837 ringrtc! 1606325251969 cm -> app: call_concluded() 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:32.214Z src/native.rs:519 NativePlatform::on_call_concluded(): remote_peer: [REDACTED]429 INFO 2020-11-25T17:27:32.383Z SQL channel job 191 (saveMessage) succeeded in 169ms INFO 2020-11-25T17:27:32.455Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 (unauth) INFO 2020-11-25T17:27:32.620Z PUT https://textsecure-service.whispersystems.org/v1/messages/[REDACTED]429 200 Success INFO 2020-11-25T17:27:32.620Z handleOutgoingSignaling() completed successfully INFO 2020-11-25T17:27:32.660Z src/core/call_manager.rs:407 API:CallManager::handle_message_sent(): INFO 2020-11-25T17:27:32.660Z src/core/call_manager.rs:956 ringrtc! 1606325252620 app -> cm: message_sent() 0x2bb44a7dc03eaad INFO 2020-11-25T17:27:32.660Z src/core/call_manager.rs:1626 send_next_message(): INFO 2020-11-25T17:27:32.660Z src/core/call_manager.rs:1691 send_next_message(): no messages to send INFO 2020-11-25T17:27:32.963Z SQL channel job 196 (createOrUpdateSessions) succeeded in 19ms INFO 2020-11-25T17:27:33.224Z SQL channel job 197 (updateConversations) succeeded in 17ms INFO 2020-11-25T17:27:44.924Z Loaded this list of log files from logPath: log.log, log.log.0, log.log.1, log.log.2