New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

TNS Console catching not printing all iOS messages #3106

Closed
NathanaelA opened this Issue Sep 6, 2017 · 6 comments

Comments

Projects
None yet
9 participants
@NathanaelA
Contributor

NathanaelA commented Sep 6, 2017

Please, provide the details below:

Did you verify this is a real problem by searching

Yes, this might be related to #3105, however this is a bit different in that 3105 was specially exceptions never being printed. Where this is RANDOM console.logs are not filtered through TNS's filters and are being skipped.

Tell us about the problem

TNS is not always printing console.log messages, it "appears" that console.error is more reliable; but even it will break frequently (see below).

Examples:

  1. Looking at the device system log; I see more of my console.log/error's than I do with tns. I'm trying to debug a specific area so I added several of these console.log("-----------------"); and out of the 10 log statements including two console.dir's,, only ONE console.log made it through to tns on the second run. First run none of them made it. ;-(

  2. This printed in my last run in TNS, I was also looking at the syslog at the same time and did NOT see the cutoff lines in it; it is possible I missed it; because of the pages of logging that was going on, but I backscrolled through it several times to verify this only occurred in the TNS output.

CONSOLE ERROR file:///app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js:569:26: Unhandled
CONSOLE ERROR file:///app/tns_modules

This is what was supposed to have printed:

CONSOLE ERROR file:///app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js:569:26: Unhandled Promise rejection: Animation cancelled. ; Zone: <root> ; Task: null ; Value: Error: Animation cancelled. _rejectAnimationFinishedPromise@file:///app/tns_modules/tns-core-modules/ui/animation/animation-common.js:98:31 [<root>]
CONSOLE ERROR file:///app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js:571:22: Error: Uncaught (in promise): Error: Animation cancelled.   

Which platform(s) does your issue occur on?

IOS only

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

  • CLI: 3.1.3
  • TCM: 3.1.1
  • Runtime - 3.0.1

Please tell us how to recreate the issue in as much detail as possible.

Do lots of console logging. Especially with stuff that might be causing background syslogging to occur like audio, video, gps, orientation, etc.

Is there code involved? If so, please share the minimal amount of code needed to recreate the problem.

Just using console.log/console.error/console.dir
You can also try putting a animate in a setInterval w/o a catch part of the promise. You will see the above 2nd issue logging will fire everytime the inteval fires and cancels the prior animation. This generates lots of logging.

@Mitko-Kerezov

This comment has been minimized.

Show comment
Hide comment
@Mitko-Kerezov

Mitko-Kerezov Oct 5, 2017

Collaborator

Hi, @NathanaelA

Thank you for the detailed description of the issue. Unfortunately, I was unable to reproduce it on my side.
I've tried adding a setInterval in which I call console.log 1000 times with a for loop. The whole thing with different intervals ranging from 500 ms to 1500 ms. Apart from that I've tried adding logging to different button clicks and various actions but cannot seem to grasp the issue.

Could you elaborate a bit more on the matter - do you reproduce it on an iOS Simulator or on a device? If you could provide a sample application illustrating the issue it would help a great deal with debugging.

As a workaround in such cases, we recommend running tns device log in a separate console where no logs will be filtered out and where you should be able to see everything.

Collaborator

Mitko-Kerezov commented Oct 5, 2017

Hi, @NathanaelA

Thank you for the detailed description of the issue. Unfortunately, I was unable to reproduce it on my side.
I've tried adding a setInterval in which I call console.log 1000 times with a for loop. The whole thing with different intervals ranging from 500 ms to 1500 ms. Apart from that I've tried adding logging to different button clicks and various actions but cannot seem to grasp the issue.

Could you elaborate a bit more on the matter - do you reproduce it on an iOS Simulator or on a device? If you could provide a sample application illustrating the issue it would help a great deal with debugging.

As a workaround in such cases, we recommend running tns device log in a separate console where no logs will be filtered out and where you should be able to see everything.

@NathanaelA

This comment has been minimized.

Show comment
Hide comment
@NathanaelA

NathanaelA Oct 6, 2017

Contributor

This is from a real device iPhone 7,

I'm not sure a better way to duplicate this issue; the missing logging I copied is from a real screen output. The missing logging is very easily seen on any app that does a lot of logging and I suspect part of the issue is when the OS doing a lot of logging in the background. I am running a application that causes a lot of system related logging (that tns is filtering out). My guess is that the logging buffer is overflowing and so you are missing things (which would explain the partial output).

In the example above where it is truncated; that was logging from TNS, where the correct value was the output I was getting from idevicesyslog in a second tab -- at this point do to all the missing logging, I by default start idevicesyslog | grep CONSOLE in a second tab -- so that I can see everything.

I'm not sure a better way to duplicate this; and I'm not sure that the missing logging will be seen on emulator or not; I do see it all the time on real devices.

Contributor

NathanaelA commented Oct 6, 2017

This is from a real device iPhone 7,

I'm not sure a better way to duplicate this issue; the missing logging I copied is from a real screen output. The missing logging is very easily seen on any app that does a lot of logging and I suspect part of the issue is when the OS doing a lot of logging in the background. I am running a application that causes a lot of system related logging (that tns is filtering out). My guess is that the logging buffer is overflowing and so you are missing things (which would explain the partial output).

In the example above where it is truncated; that was logging from TNS, where the correct value was the output I was getting from idevicesyslog in a second tab -- at this point do to all the missing logging, I by default start idevicesyslog | grep CONSOLE in a second tab -- so that I can see everything.

I'm not sure a better way to duplicate this; and I'm not sure that the missing logging will be seen on emulator or not; I do see it all the time on real devices.

@ksnyde

This comment has been minimized.

Show comment
Hide comment
@ksnyde

ksnyde Oct 18, 2017

I'm using tns version 3.2.1 and all of my console messages are being eaten. I have a very-little-modified version of the TS example template in the in the main-page.ts I have:

// Event handler for Page "navigatingTo" event attached in main-page.xml
export function navigatingTo(args: EventData) {
    console.log('starting');
    let page = <Page>args.object;
    // etc.

and starting is never output to the console. I'm very new to Nativescript but I'd say this is a pretty clear example.

ksnyde commented Oct 18, 2017

I'm using tns version 3.2.1 and all of my console messages are being eaten. I have a very-little-modified version of the TS example template in the in the main-page.ts I have:

// Event handler for Page "navigatingTo" event attached in main-page.xml
export function navigatingTo(args: EventData) {
    console.log('starting');
    let page = <Page>args.object;
    // etc.

and starting is never output to the console. I'm very new to Nativescript but I'd say this is a pretty clear example.

@NathanaelA

This comment has been minimized.

Show comment
Hide comment
@NathanaelA

NathanaelA Oct 18, 2017

Contributor

@ksnyde -- If this is iOS; there is another issue that they are working on that occurred with the new iOS 11 devices, eating all logging from these items. That issue will be fixed in the next version I would expect.

However, in the mean time my blog -- http://fluentreports.com/blog/?p=545 discusses how to get logging back until TNS adds the same fix I came up with to their process.

Unfortunately this bug that I'm listing here; is a lot more insidious. you get log, log, log, missing log, log, log, log... And you don't know if the missing log is missing because it didn't go down that "if" statement, or if it didn't run. I can see a lot of places where random log statements are missing in code that HAD to run (i.e. console.log("1"); console.log("2"); console.log("3"); in sequence and 1 & 3 show up and 2 is missing.

Contributor

NathanaelA commented Oct 18, 2017

@ksnyde -- If this is iOS; there is another issue that they are working on that occurred with the new iOS 11 devices, eating all logging from these items. That issue will be fixed in the next version I would expect.

However, in the mean time my blog -- http://fluentreports.com/blog/?p=545 discusses how to get logging back until TNS adds the same fix I came up with to their process.

Unfortunately this bug that I'm listing here; is a lot more insidious. you get log, log, log, missing log, log, log, log... And you don't know if the missing log is missing because it didn't go down that "if" statement, or if it didn't run. I can see a lot of places where random log statements are missing in code that HAD to run (i.e. console.log("1"); console.log("2"); console.log("3"); in sequence and 1 & 3 show up and 2 is missing.

@ksnyde

This comment has been minimized.

Show comment
Hide comment
@ksnyde

ksnyde Oct 18, 2017

Thanks @NathanaelA . I just came back to here to post that I had moved my simulation back to a IOS 10 device and now things are working. Your explanation helps me understand why.

ksnyde commented Oct 18, 2017

Thanks @NathanaelA . I just came back to here to post that I had moved my simulation back to a IOS 10 device and now things are working. Your explanation helps me understand why.

@KristianDD KristianDD self-assigned this Nov 27, 2017

@Fatme Fatme added this to the 4.0.0 milestone Apr 11, 2018

@miroslavaivanova miroslavaivanova self-assigned this Apr 16, 2018

@Natalia-Hristova

This comment has been minimized.

Show comment
Hide comment
@Natalia-Hristova

Natalia-Hristova Apr 16, 2018

Collaborator

With the latest version of nativescript 4.0.0 I wasn't able to reproduce this behavior. Checked logging on HighSierra, Xcode 9.2, on simulator and device.
Can you give it a try and write what's happen on your side? If you still see this problem, please share details how to reproduce it and feel absolutely free to reopen this issue.

Collaborator

Natalia-Hristova commented Apr 16, 2018

With the latest version of nativescript 4.0.0 I wasn't able to reproduce this behavior. Checked logging on HighSierra, Xcode 9.2, on simulator and device.
Can you give it a try and write what's happen on your side? If you still see this problem, please share details how to reproduce it and feel absolutely free to reopen this issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment