nativescript-cli: iOS: Unexpected CFNetwork logs on `tns run ios` as of {N} 4.0.0

From @mrothstein on April 20, 2018 17:7

Tell us about the problem

After upgrading to {N} 4.0.0, a ton of logs normally only visible using tns device log are showing up on the console during a tns run ios. Sample output from tns run ios:

TIC TLS Event [1:0x1c0564440]: 1, Pending(0)
TIC TLS Event [1:0x1c0564440]: 2, Pending(0)
TIC TLS Event [1:0x1c0564440]: 11, Pending(0)
TIC TLS Event [1:0x1c0564440]: 12, Pending(0)
TIC TLS Event [1:0x1c0564440]: 14, Pending(0)
TIC TLS Event [2:0x1c436e940]: 1, Pending(0)
TIC TLS Event [2:0x1c436e940]: 2, Pending(0)
TIC TLS Event [2:0x1c436e940]: 11, Pending(0)
TIC TLS Event [2:0x1c436e940]: 12, Pending(0)
TIC TLS Event [2:0x1c436e940]: 14, Pending(0)

Sample output from tns device log:

Apr 20 11:43:41 Maxs-iPhone OnSIP(CFNetwork)[7575] <Notice>: TIC TLS Event [9:0x1c436b580]: 1, Pending(0)
Apr 20 11:43:41 Maxs-iPhone OnSIP(CFNetwork)[7575] <Notice>: TIC TLS Event [9:0x1c436b580]: 2, Pending(0)
Apr 20 11:43:41 Maxs-iPhone OnSIP(CFNetwork)[7575] <Notice>: TIC TLS Event [9:0x1c436b580]: 11, Pending(0)
Apr 20 11:43:41 Maxs-iPhone OnSIP(CFNetwork)[7575] <Notice>: TIC TLS Event [9:0x1c436b580]: 12, Pending(0)
Apr 20 11:43:41 Maxs-iPhone OnSIP(CFNetwork)[7575] <Notice>: TIC TLS Event [9:0x1c436b580]: 14, Pending(0)
Apr 20 11:43:41 Maxs-iPhone OnSIP(CFNetwork)[7575] <Notice>: System Trust Evaluation yielded status(0)
Apr 20 11:43:41 Maxs-iPhone OnSIP(CFNetwork)[7575] <Notice>: TIC TLS Trust Result [9:0x1c436b580]: 0
Apr 20 11:43:41 Maxs-iPhone OnSIP(CFNetwork)[7575] <Notice>: TIC TLS Event [9:0x1c436b580]: 20, Pending(0)
Apr 20 11:43:41 Maxs-iPhone OnSIP(CFNetwork)[7575] <Notice>: TIC TCP Conn Connected [9:0x1c436b580]: Err(16)
Apr 20 11:43:41 Maxs-iPhone OnSIP(CFNetwork)[7575] <Notice>: TIC TCP Conn Event [9:0x1c436b580]: 1
Apr 20 11:43:41 Maxs-iPhone OnSIP(CFNetwork)[7575] <Notice>: TIC TCP Conn Event [9:0x1c436b580]: 8

The device logs are consistent with output from running on {N} 3.4.1 (the CFNetwork logs themselves are not new). The new behavior is that they show up when running tns run ios. In the past, only console.log output would show when running tns run ios, like so:

CONSOLE LOG file:///app/src/common/services/logging/console.target.js:16:46: App Service Constructed -> Platform Target = mobile
CONSOLE LOG file:///app/src/common/services/logging/console.target.js:16:46: Connectivity: Connection type changed to wifi.
CONSOLE LOG file:///app/src/common/services/logging/console.target.js:16:46: Connectivity Initialized

There appears to be an issue with the logs that are “let through” to the console.

Which platform(s) does your issue occur on?

iOS

Please provide the following version numbers that your issue occurs with:

  • CLI: 4.0.0
  • Runtime(s): 4.0.1 (tns-ios)
  • package.json:
  // ...
  "nativescript": {
    "id": "com.onsip.OnSIP",
    "tns-android": {
      "version": "4.0.1"
    },
    "tns-ios": {
      "version": "4.0.1"
    }
  },
  "dependencies": {
    "@angular/animations": "^5.2.7",
    "@angular/common": "^5.2.7",
    "@angular/compiler": "^5.2.7",
    "@angular/core": "^5.2.7",
    "@angular/forms": "^5.2.7",
    "@angular/http": "^5.2.7",
    "@angular/platform-browser": "^5.2.7",
    "@angular/platform-browser-dynamic": "^5.2.7",
    "@angular/router": "^5.2.7",
    "@ngx-translate/core": "^8.0.0",
    "awesome-phonenumber": "^2.2.5",
    "json-stringify-safe": "^5.0.1",
    "moment": "^2.20.1",
    "moment-timezone": "^0.5.14",
    "nativescript-angular": "^5.2.0",
    "nativescript-appversion": "^1.4.1",
    "nativescript-feedback": "^1.1.2",
    "nativescript-localstorage": "^1.1.5",
    "nativescript-mixpanel": "file:../nativescript-mixpanel",
    "nativescript-permissions": "^1.2.3",
    "nativescript-plugin-firebase": "^4.2.1",
    "nativescript-theme-core": "^1.0.4",
    "nativescript-webrtc": "git+ssh://gitolite@git.jnctn.net:2/nativescript-webrtc#59",
    "nativescript-websockets": "file:../nativescript-websockets-1.4.0.tgz",
    "nativescript-xml2js": "^0.5.2",
    "raven-js": "^3.22.4",
    "reflect-metadata": "^0.1.12",
    "rxjs": "^5.5.6",
    "tns-core-modules": "^3.4.1",
    "zone.js": "^0.8.20"
  },
  "devDependencies": {
    "@angular/compiler-cli": "^5.2.7",
    "@ngtools/webpack": "^1.10.1",
    "babel-traverse": "^6.26.0",
    "babel-types": "^6.26.0",
    "babylon": "^6.18.0",
    "codelyzer": "^4.2.0",
    "copy-webpack-plugin": "^4.5.0",
    "css-loader": "^0.28.10",
    "extract-text-webpack-plugin": "^3.0.2",
    "fs-extra": "^5.0.0",
    "lazy": "^1.0.11",
    "nativescript-css-loader": "^0.26.1",
    "nativescript-dev-sass": "^1.3.5",
    "nativescript-dev-typescript": "^0.6.0",
    "nativescript-dev-webpack": "^0.9.2",
    "nativescript-worker-loader": "^0.8.1",
    "raw-loader": "^0.5.1",
    "resolve-url-loader": "^2.1.0",
    "sass-loader": "^6.0.6",
    "tns-platform-declarations": "^3.4.1",
    "tslint": "^5.9.1",
    "typescript": "^2.6.2",
    "uglifyjs-webpack-plugin": "^1.2.2",
    "webpack": "^3.11.0",
    "webpack-bundle-analyzer": "^2.11.1",
    "webpack-sources": "^1.1.0"
  },
  "scripts": {
    "tslint": "tslint -p tsconfig.json"
  }
}

Copied from original issue: NativeScript/NativeScript#5714

About this issue

  • Original URL
  • State: closed
  • Created 6 years ago
  • Reactions: 6
  • Comments: 21 (5 by maintainers)

Most upvoted comments

Unfortunately, this problem seems to persist in {N} 5.x with Firebase plugin 7.7.

The OS_ACTIVITY_MODE setting did not seem to have any effect on my console output…at least when running the app with tns run.

It seems we’ve validated that the issue is reproducible. Any further thoughts on a fix? The challenge is that these verbose network/TCP logs make it virtually impossible to use console log output, especially if an app is making lots of network calls.

FWIW…as a “dirty” hack around the issue, you can just pipe the output of the tns run command thru a grep filter. It doesn’t work well with LiveSync, so not a perfect solution, but can help get rid of the noise if you’re looking for specific console messages.

Example: $ (tns run ios --device 1) | grep '^CONSOLE'

Will only output messages that were explicitly console logged. Hope that helps.

@Fatme the issue is reproducible on my side on this project with the login HTTP requests. When the HTTP request is invalid it prints a lot of logs that should be filtered.

This is annoying but less so than the terminal messages: tns run ios | grep -v 'TIC\|tcp_\|0x\|Task\|System\|nw_\|new conn\|RTT_\|Cookie\|cookie\|tcp\|HTHangEvent\|<private>\|path:cancel\|Hostname#\|packets\|dns\|DNS\|ipv4\|IPv4\|Conn_Time\|TLS'

I suspect nativescript-plugin-firebase is the culprit of all this logs.

I have the same issue on my project, yet when I tried with a clean new project, the logs stopped.

Looking at both projects mentioned above, the only thing in common in between them and my project, plugin wise, is nativescript-plugin-firebase.

Unfortunately, I don’t have time to test now 😞.

I’ll post here the results if I have the time to test it before anyone else has a chance.