Skip to content
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.

Sign up for GitHub

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

Jump to bottom

Missing Log Entries #167

Open
CyborgMaster opened this issue Jul 28, 2016 · 6 comments
Open

Missing Log Entries #167

CyborgMaster opened this issue Jul 28, 2016 · 6 comments

Comments

@CyborgMaster
Copy link

Any time multiple lines are appended to the log close together, papertrail only gets some of them. If I can't figure this out, I'm going to have to consider moving to another service.

I'm using the recomended set up for elastic beanstalk using the .ebextensions file here: https://github.com/papertrail/remote_syslog2/blob/master/examples/remote_syslog.ebextensions.config, and my version is set to v0.17.

When I tail the log file directly on the server, I see this:

[2016-07-28T00:09:36.444139 #10758]  INFO [Stats] Running DailyStats from SWF.
[2016-07-28T00:09:36.444282 #10758]  INFO [Stats] Stubbed - Skipping
[2016-07-28T00:18:14.062370 #11234]  INFO [Stats] Running DailyStats from SWF.
[2016-07-28T00:18:14.062513 #11234]  INFO [Stats] Stubbed - Skipping
[2016-07-28T00:23:59.772819 #11547]  INFO [Stats] Running DailyStats from SWF.
[2016-07-28T00:23:59.772978 #11547]  INFO [Stats] Stubbed - Skipping
[2016-07-28T00:24:07.980573 #11565]  INFO [Stats] Running DailyStats from SWF.
[2016-07-28T00:24:07.980711 #11565]  INFO [Stats] Stubbed - Skipping
[2016-07-28T01:05:21.884176 #13911]  INFO Running the comm engine from SWF. Current date: 2016-07-28T01:05:00+00:00
[2016-07-28T01:05:21.884312 #13911]  INFO ------------------------------------------------------------
[2016-07-28T01:05:21.884334 #13911]  INFO Starting CommEngine
[2016-07-28T01:05:48.928765 #13911]  INFO CommEngine Finished.  Elapsed Time: 27
[2016-07-28T01:05:48.928825 #13911]  INFO ------------------------------------------------------------
[2016-07-28T02:05:38.462349 #17294]  INFO Running the comm engine from SWF. Current date: 2016-07-28T02:05:00+00:00
[2016-07-28T02:05:38.462505 #17294]  INFO ------------------------------------------------------------
[2016-07-28T02:05:38.462531 #17294]  INFO Starting CommEngine
[2016-07-28T02:06:05.040441 #17294]  INFO CommEngine Finished.  Elapsed Time: 26
[2016-07-28T02:06:05.040501 #17294]  INFO ------------------------------------------------------------
[2016-07-28T03:05:38.422210 #20657]  INFO Running the comm engine from SWF. Current date: 2016-07-28T03:05:00+00:00
[2016-07-28T03:05:38.422330 #20657]  INFO ------------------------------------------------------------
[2016-07-28T03:05:38.422352 #20657]  INFO Starting CommEngine
[2016-07-28T03:06:06.047091 #20657]  INFO CommEngine Finished.  Elapsed Time: 27
[2016-07-28T03:06:06.047152 #20657]  INFO ------------------------------------------------------------
[2016-07-28T04:05:36.448820 #24057]  INFO Running the comm engine from SWF. Current date: 2016-07-28T04:05:00+00:00
[2016-07-28T04:05:36.448967 #24057]  INFO ------------------------------------------------------------
[2016-07-28T04:05:36.448993 #24057]  INFO Starting CommEngine
[2016-07-28T04:06:03.410103 #24057]  INFO CommEngine Finished.  Elapsed Time: 26
[2016-07-28T04:06:03.410180 #24057]  INFO ------------------------------------------------------------
[2016-07-28T05:05:38.406085 #27464]  INFO Running the comm engine from SWF. Current date: 2016-07-28T05:05:00+00:00
[2016-07-28T05:05:38.406228 #27464]  INFO ------------------------------------------------------------
[2016-07-28T05:05:38.406272 #27464]  INFO Starting CommEngine
[2016-07-28T05:06:05.955976 #27464]  INFO CommEngine Finished.  Elapsed Time: 27
[2016-07-28T05:06:05.956039 #27464]  INFO ------------------------------------------------------------
[2016-07-28T06:05:38.569014 #30833]  INFO Running the comm engine from SWF. Current date: 2016-07-28T06:05:00+00:00
[2016-07-28T06:05:38.569169 #30833]  INFO ------------------------------------------------------------
[2016-07-28T06:05:38.569197 #30833]  INFO Starting CommEngine
[2016-07-28T06:06:06.071618 #30833]  INFO CommEngine Finished.  Elapsed Time: 27
[2016-07-28T06:06:06.071673 #30833]  INFO ------------------------------------------------------------
[2016-07-28T07:05:37.758102 #1740]  INFO Running the comm engine from SWF. Current date: 2016-07-28T07:05:00+00:00
[2016-07-28T07:05:37.758239 #1740]  INFO ------------------------------------------------------------
[2016-07-28T07:05:37.758262 #1740]  INFO Starting CommEngine
[2016-07-28T07:06:05.281828 #1740]  INFO CommEngine Finished.  Elapsed Time: 27
[2016-07-28T07:06:05.281890 #1740]  INFO ------------------------------------------------------------
[2016-07-28T08:00:37.883342 #4827]  INFO [Stats] Running DailyStats from SWF.
[2016-07-28T08:00:37.883486 #4827]  INFO [Stats] Stubbed - Skipping
[2016-07-28T08:05:25.943758 #5170]  INFO Running the comm engine from SWF. Current date: 2016-07-28T08:05:00+00:00
[2016-07-28T08:05:25.943920 #5170]  INFO ------------------------------------------------------------
[2016-07-28T08:05:25.943955 #5170]  INFO Starting CommEngine
[2016-07-28T08:05:53.977286 #5170]  INFO CommEngine Finished.  Elapsed Time: 28
[2016-07-28T08:05:53.977347 #5170]  INFO ------------------------------------------------------------
[2016-07-28T09:05:36.424776 #8538]  INFO Running the comm engine from SWF. Current date: 2016-07-28T09:05:00+00:00
[2016-07-28T09:05:36.424947 #8538]  INFO ------------------------------------------------------------
[2016-07-28T09:05:36.424984 #8538]  INFO Starting CommEngine
[2016-07-28T09:06:03.800633 #8538]  INFO CommEngine Finished.  Elapsed Time: 27
[2016-07-28T09:06:03.800711 #8538]  INFO ------------------------------------------------------------
[2016-07-28T10:05:35.297769 #11990]  INFO Running the comm engine from SWF. Current date: 2016-07-28T10:05:00+00:00
[2016-07-28T10:05:35.297923 #11990]  INFO ------------------------------------------------------------
[2016-07-28T10:05:35.297956 #11990]  INFO Starting CommEngine
[2016-07-28T10:06:02.293771 #11990]  INFO CommEngine Finished.  Elapsed Time: 26
[2016-07-28T10:06:02.293833 #11990]  INFO ------------------------------------------------------------
[2016-07-28T11:05:35.432139 #15376]  INFO Running the comm engine from SWF. Current date: 2016-07-28T11:05:00+00:00
[2016-07-28T11:05:35.432287 #15376]  INFO ------------------------------------------------------------
[2016-07-28T11:05:35.432318 #15376]  INFO Starting CommEngine
[2016-07-28T11:06:02.421432 #15376]  INFO CommEngine Finished.  Elapsed Time: 26
[2016-07-28T11:06:02.421489 #15376]  INFO ------------------------------------------------------------

But papertrail only has this:

Jul 27 20:09:36 nova-background_i-60de5998 production.log:  [2016-07-28T00:09:36.444139 #10758]  INFO [Stats] Running DailyStats from SWF.
Jul 27 20:09:36 nova-background_i-60de5998 production.log:  [2016-07-28T00:09:36.444282 #10758]  INFO [Stats] Stubbed - Skipping
Jul 27 20:24:00 nova-background_i-60de5998 production.log:  [2016-07-28T00:23:59.772819 #11547]  INFO [Stats] Running DailyStats from SWF.
Jul 27 20:24:00 nova-background_i-60de5998 production.log:  [2016-07-28T00:23:59.772978 #11547]  INFO [Stats] Stubbed - Skipping
Jul 27 20:24:08 nova-background_i-60de5998 production.log:  [2016-07-28T00:24:07.980573 #11565]  INFO [Stats] Running DailyStats from SWF.
Jul 27 20:24:08 nova-background_i-60de5998 production.log:  [2016-07-28T00:24:07.980711 #11565]  INFO [Stats] Stubbed - Skipping
Jul 27 21:05:49 nova-background_i-60de5998 production.log:  [2016-07-28T01:05:48.928765 #13911]  INFO CommEngine Finished.  Elapsed Time: 27
Jul 27 21:05:49 nova-background_i-60de5998 production.log:  [2016-07-28T01:05:48.928825 #13911]  INFO ------------------------------------------------------------
Jul 27 22:06:05 nova-background_i-60de5998 production.log:  [2016-07-28T02:06:05.040441 #17294]  INFO CommEngine Finished.  Elapsed Time: 26
Jul 27 22:06:05 nova-background_i-60de5998 production.log:  [2016-07-28T02:06:05.040501 #17294]  INFO ------------------------------------------------------------
Jul 27 23:06:06 nova-background_i-60de5998 production.log:  [2016-07-28T03:06:06.047091 #20657]  INFO CommEngine Finished.  Elapsed Time: 27
Jul 27 23:06:06 nova-background_i-60de5998 production.log:  [2016-07-28T03:06:06.047152 #20657]  INFO ------------------------------------------------------------
Jul 28 00:06:03 nova-background_i-60de5998 production.log:  [2016-07-28T04:06:03.410103 #24057]  INFO CommEngine Finished.  Elapsed Time: 26
Jul 28 00:06:03 nova-background_i-60de5998 production.log:  [2016-07-28T04:06:03.410180 #24057]  INFO ------------------------------------------------------------
Jul 28 01:06:06 nova-background_i-60de5998 production.log:  [2016-07-28T05:06:05.955976 #27464]  INFO CommEngine Finished.  Elapsed Time: 27
Jul 28 01:06:06 nova-background_i-60de5998 production.log:  [2016-07-28T05:06:05.956039 #27464]  INFO ------------------------------------------------------------
Jul 28 02:06:06 nova-background_i-60de5998 production.log:  [2016-07-28T06:06:06.071618 #30833]  INFO CommEngine Finished.  Elapsed Time: 27
Jul 28 02:06:06 nova-background_i-60de5998 production.log:  [2016-07-28T06:06:06.071673 #30833]  INFO ------------------------------------------------------------
Jul 28 03:06:05 nova-background_i-60de5998 production.log:  [2016-07-28T07:06:05.281828 #1740]  INFO CommEngine Finished.  Elapsed Time: 27
Jul 28 03:06:05 nova-background_i-60de5998 production.log:  [2016-07-28T07:06:05.281890 #1740]  INFO ------------------------------------------------------------
Jul 28 04:05:26 nova-background_i-60de5998 production.log:  [2016-07-28T08:05:25.943758 #5170]  INFO Running the comm engine from SWF. Current date: 2016-07-28T08:05:00+00:00
Jul 28 04:05:26 nova-background_i-60de5998 production.log:  [2016-07-28T08:05:25.943920 #5170]  INFO ------------------------------------------------------------
Jul 28 04:05:26 nova-background_i-60de5998 production.log:  [2016-07-28T08:05:25.943955 #5170]  INFO Starting CommEngine
Jul 28 04:05:54 nova-background_i-60de5998 production.log:  [2016-07-28T08:05:53.977286 #5170]  INFO CommEngine Finished.  Elapsed Time: 28
Jul 28 04:05:54 nova-background_i-60de5998 production.log:  [2016-07-28T08:05:53.977347 #5170]  INFO ------------------------------------------------------------
Jul 28 05:06:04 nova-background_i-60de5998 production.log:  [2016-07-28T09:06:03.800633 #8538]  INFO CommEngine Finished.  Elapsed Time: 27
Jul 28 05:06:04 nova-background_i-60de5998 production.log:  [2016-07-28T09:06:03.800711 #8538]  INFO ------------------------------------------------------------
Jul 28 06:06:02 nova-background_i-60de5998 production.log:  [2016-07-28T10:06:02.293771 #11990]  INFO CommEngine Finished.  Elapsed Time: 26
Jul 28 06:06:02 nova-background_i-60de5998 production.log:  [2016-07-28T10:06:02.293833 #11990]  INFO ------------------------------------------------------------
Jul 28 07:06:02 nova-background_i-60de5998 production.log:  [2016-07-28T11:06:02.421432 #15376]  INFO CommEngine Finished.  Elapsed Time: 26
Jul 28 07:06:02 nova-background_i-60de5998 production.log:  [2016-07-28T11:06:02.421489 #15376]  INFO ------------------------------------------------------------
Jul 28 08:06:16 nova-background_i-60de5998 production.log:  [2016-07-28T12:06:15.958981 #18756]  INFO CommEngine Finished.  Elapsed Time: 27
Jul 28 08:06:16 nova-background_i-60de5998 production.log:  [2016-07-28T12:06:15.959043 #18756]  INFO ------------------------------------------------------------
Jul 28 09:06:04 nova-background_i-60de5998 production.log:  [2016-07-28T13:06:03.966806 #22108]  INFO CommEngine Finished.  Elapsed Time: 27
Jul 28 09:06:04 nova-background_i-60de5998 production.log:  [2016-07-28T13:06:03.966871 #22108]  INFO ------------------------------------------------------------
Jul 28 10:06:03 nova-background_i-60de5998 production.log:  [2016-07-28T14:06:03.106766 #25502]  INFO CommEngine Finished.  Elapsed Time: 26
Jul 28 10:06:03 nova-background_i-60de5998 production.log:  [2016-07-28T14:06:03.106841 #25502]  INFO ------------------------------------------------------------

As you can see over half of the entries are missing. It always seems to get at least one or two lines from each group of logs, but misses some as well.
@johlym johlym self-assigned this Jul 29, 2016
@johlym johlym removed their assignment Aug 16, 2016
@snorecone
Copy link
Contributor

Hi @CyborgMaster I'm late to the party here, but if you're still using remote_syslog are you able to reproduce this issue with the latest version v0.19?

@pridit
Copy link

pridit commented Jan 13, 2019

This is still happening. I am using the latest version v0.20. Two lines in my case that occurred on the same second, both completely ignored on Papertrail's end yet present physically in my file. I've had a feeling it was doing something like this as I am erroneously dropping logs elsewhere in a very similar fashion.

@johlym
Copy link
Contributor

johlym commented Jan 13, 2019

@pridit Two questions:

  • What transport protocol are you using (UDP, TCP, TLS)?
  • How long are these messages (# of characters)?

@pridit
Copy link

pridit commented Jan 13, 2019

Thanks for the follow-up, to answer your questions:

  • TLS
  • 36 for the first, and 55 for the second

Logs around this time all came through without issue, but specifically missed two that both occurred on the same second. The logs around the two in question were several minutes apart, so a sizeable gap. I had other logs that were a few seconds prior but I have my filter set to drop those particular ones, and I have confirmed the two logs I expected would not have been impacted by the filter.

I could enter forensic mode and begin isolating every single instance to determine if there's any pattern aside from what I have observed based on this issue, but that would of course take time (and based on the activity here wasn't sure whether it would ever be followed up). I had an initial feeling I was missing logs but never cross referenced with my file until now.

@ibash
Copy link

ibash commented Mar 20, 2019

I'm using the papertrail add on in heroku and noticed the same problem. This makes the service a no-go.

@pridit
Copy link

pridit commented Mar 22, 2019

Yep, I unfortunately can't afford to have logs dropping erroneously so won't be continuing, and this clearly isn't a priority for the team.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@snorecone @ibash @CyborgMaster @johlym @pridit