NativeScript / nativescript-cli

Command-line interface for building NativeScript apps
https://www.npmjs.com/package/nativescript
Apache License 2.0
1.04k stars 195 forks source link

iOS: Unexpected CFNetwork logs on `tns run ios` as of {N} 4.0.0 #3544

Closed NickIliev closed 2 years ago

NickIliev commented 6 years ago

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:

Copied from original issue: NativeScript/NativeScript#5714

NickIliev commented 6 years ago

@mrothstein can you share what is the code invoked in file:///app/src/common/services/logging/console.target.js:16 - is that the connectivity module or some specific plugin/code? Any demo application showing how t reproduce the logs will be appreciated - I have used this one but was not able to reproduce the logs.

Note: I've noticed that you are using tns-core-modules@3.4.1 - please update your modules to 4.0.0 and retest the logs again.

NickIliev commented 6 years ago

From @cerireyhan on April 23, 2018 13:6

I have the same problem, terminal is full of network logs after 'tns run ios' on real device, simulator works fine though. CLI: 4.0.0

"hooks": [
            {
                "type": "after-prepare",
                "script": "after-prepare.js"
            }
        ],
        "tns-android": {
            "version": "4.0.1"
        },
        "tns-ios": {
            "version": "4.0.1"
        }
    },
    "dependencies": {
        "@angular/animations": "~5.2.0",
        "@angular/common": "~5.2.0",
        "@angular/compiler": "~5.2.0",
        "@angular/core": "~5.2.0",
        "@angular/forms": "~5.2.0",
        "@angular/http": "~5.2.0",
        "@angular/platform-browser": "~5.2.0",
        "@angular/platform-browser-dynamic": "~5.2.0",
        "@angular/router": "~5.2.0",
        "nativescript-angular": "5.2.0",
        "nativescript-appversion": "^1.4.1",
        "nativescript-floatingactionbutton": "^4.1.3",
        "nativescript-iqkeyboardmanager": "^1.2.0",
        "nativescript-loading-indicator": "^2.4.0",
        "nativescript-modal-datetimepicker": "^1.1.2",
        "nativescript-orientation": "^2.2.0",
        "nativescript-plugin-firebase": "^5.2.0",
        "nativescript-pulltorefresh": "^2.1.0",
        "nativescript-snackbar": "^2.0.1",
        "nativescript-theme-core": "^1.0.4",
        "nativescript-websockets": "^1.4.0",
        "reflect-metadata": "~0.1.8",
        "rxjs": "^5.5.0",
        "tns-core-modules": "4.0.0",
        "zone.js": "^0.8.4"
    },
    "devDependencies": {
        "babel-traverse": "6.9.0",
        "babel-types": "6.10.0",
        "babylon": "6.8.1",
        "cross-env": "^5.1.3",
        "lazy": "1.0.11",
        "mkdirp": "^0.5.1",
        "nativescript-dev-typescript": "next",
        "typescript": "~2.6.2"
    }
}
mrothstein commented 6 years ago

I've updated my tns-core-modules to 4.0.0 and the logs persist.

The code that's being invoked in those logs is specific to our application. I'll try to build a test application with the right modules to see if the logs remain.

NickIliev commented 6 years ago

@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.

toddanglin commented 6 years ago

Revisiting and updating an older app to 4.1.0, and I hit this same problem. Definitely makes it hard to debug since these network logs spit TONS of junk in to the console.

Is there a workaround to squash these log messages? Or will it be patched in 4.2?

ghost commented 6 years ago

Any progress or workaround to solve this problem?

toddanglin commented 6 years ago

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.

surdu commented 6 years ago

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.

toddanglin commented 6 years ago

@EddyVerbruggen Hey Eddy. Any thoughts on this being related to the Firebase plug-in?

EddyVerbruggen commented 6 years ago

I haven't seen those, but always willing to look at a bare-bones repo showing the issue.

surdu commented 6 years ago

I can confirm that after installing and configuring nativescript-plugin-firebase on a blank project the terminal starts spamming those TIC .... messages.

Versions: ios: 11.2.2 device: iPad Air tns: 4.2.4 tns-core-modules: 4.2.1 tns-ios: 4.2.0

fhackenb commented 5 years ago

Any updates / resolution on this? Seems like a lingering and really annoying issue affecting a lot of people

danbockapps commented 5 years ago

I experienced this issue with NativeScript 5.0.3 after I added nativescript-plugin-firebase. Removing that plugin made the logs go back to normal. I opened this issue: https://github.com/EddyVerbruggen/nativescript-plugin-firebase/issues/1066

NickIliev commented 5 years ago

Update: this seem related to a native issue with verbose HTTP logging - possible solution for native projects is provide here

We should investigate if editing the scheme to add the OS_ACTIVITY_MODE (set to disable) is possible via the CLI or with changes in the native project we are using for builds.

fhackenb commented 5 years ago

@toddanglin 's grep command works for quick filtering it out and another solution seems to be running it in debug mode using visual studio https://docs.nativescript.org/tooling/visual-studio-code-extension

toddanglin commented 5 years ago

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.

FranciZ commented 5 years ago

Adding OS_ACTIVITY_MODE:disabled to scheme environment variables and running from XCode does clear the excessive logs for me but not when running by tns run ios.

This is a significant issue since it makes development on iOS very painful by making it very hard to parse logs.

kenny-evitt commented 5 years ago

I've run into this issue but I'm not using the Firebase plugin.

GrEg00z commented 5 years ago

3727

Naxos84 commented 5 years ago

Still present in TNS 5.4.0 without firebase plugin. Just make a https get request.

kennethkeim commented 5 years ago

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'