FORT 1.5.3 Crashing - ERR: Unknown protocol: 114 #83

InsaneSplash · 2022-05-16T10:58:31Z

Hello,

I am picking up that the latest version of FORT 1.5.3 keeps crashing on a regular basis. We has paired FORT with FRRouting which is also running on the latest version on Oracle Linux V8

fort-1.5.3-1.el8.x86_64
frr-8.2.2-02.el8.x86_64

Below is the extract from the log showing the crashed process.

May 16 12:37:03 fort[5745]: ERR: Unknown protocol: 114
May 16 12:37:03 fort[5745]: Stack trace:
May 16 12:37:03 fort[5745]:  /usr/bin/fort(print_stack_trace+0x1f) [0x417e5f]
May 16 12:37:03 fort[5745]:  /usr/bin/fort(pr_crit+0x81) [0x4194e1]
May 16 12:37:03 fort[5745]:  /usr/bin/fort() [0x433d95]
May 16 12:37:03 fort[5745]:  /usr/bin/fort() [0x43168d]
May 16 12:37:03 fort[5745]:  /usr/bin/fort(compute_deltas+0x46) [0x4336c6]
May 16 12:37:03 fort[5745]:  /usr/bin/fort() [0x43440d]
May 16 12:37:03 fort[5745]:  /usr/bin/fort(vrps_update+0x110) [0x434b80]
May 16 12:37:03 fort[5745]:  /usr/bin/fort(validation_run_cycle+0x29) [0x41d729]
May 16 12:37:03 fort[5745]:  /usr/bin/fort(main+0x16c) [0x413e6c]
May 16 12:37:03 fort[5745]: Expand failed !
May 16 12:37:03 fort[5745]:  /lib64/libc.so.6(__libc_start_main+0xf3) [0x7f337ec3e493]
May 16 12:37:03 fort[5745]:  /usr/bin/fort(_start+0x2e) [0x413e9e]
May 16 12:37:03 fort[5745]: (End of stack trace)
May 16 12:37:03 systemd[1]: fort.service: Main process exited, code=exited, status=255/n/a
May 16 12:37:03 systemd[1]: fort.service: Failed with result 'exit-code'.

The text was updated successfully, but these errors were encountered:

Found this quirk while eyeballing #83. I don't think it's going to fix the problem, but it's definitely an improvement.

ydahhrk · 2022-05-16T22:26:43Z

I uploaded a small patch. I don't think it's going to solve the problem, but you might as well try it.

Are you using --output.roa?

If you enable it, do you get a slightly different error mesage?

Can you please post your fort command, with flags (and configuration file, if applies) included?

InsaneSplash · 2022-05-31T08:09:01Z

Hey, sorry for the late reply..... another instance just crashed.

Command Line:
/usr/bin/fort --configuration-file /etc/fort/config.json

Config file:

{
        "tal": "/etc/fort/tal",
        "local-repository": "/var/lib/fort/repository",
        "slurm": "/etc/fort/slurm",
        "server": {
                "port": "3323",
                "interval": {
                        "validation": 3600,
                        "refresh": 3600,
                        "retry": 600,
                        "expire": 7200
        }
        },
        "log": {
                "output": "syslog"
        }
}

InsaneSplash · 2022-05-31T08:43:13Z

May 27 07:59:16 fort[98190]: /usr/bin/fort[0x417d97]
May 27 07:59:16 fort[98190]: /lib64/libpthread.so.0(+0x12c30)[0x7f6d27f1cc30]
May 27 07:59:16 fort[98190]: /usr/bin/fort(x509_name_put+0x0)[0x427dc0]
May 27 07:59:16 fort[98190]: /usr/bin/fort[0x4143cc]
May 27 07:59:16 fort[98190]: /usr/bin/fort[0x4144ac]
May 27 07:59:16 fort[98190]: /usr/bin/fort(deferstack_pop+0x3b)[0x4146eb]
May 27 07:59:16 fort[98190]: /usr/bin/fort[0x428cc4]
May 27 07:59:16 fort[98190]: /usr/bin/fort[0x4296c9]
May 27 07:59:16 fort[98190]: /usr/bin/fort[0x437307]
May 27 07:59:16 fort[98190]: /lib64/libpthread.so.0(+0x818a)[0x7f6d27f1218a]
May 27 07:59:16 fort[98190]: /lib64/libc.so.6(clone+0x43)[0x7f6d27c41dd3]

InsaneSplash · 2022-05-31T08:47:20Z

Interesting the process provides a stack trace if you provide it a unknown option.

May 31 10:16:17 fort[916765]: ERR: Unrecognized option: 63
May 31 10:16:17 fort[916765]: Stack trace:
May 31 10:16:17 fort[916765]:  fort(print_stack_trace+0x1f) [0x417e5f]
May 31 10:16:17 fort[916765]:  fort(__pr_op_err+0x84) [0x418424]
May 31 10:16:17 fort[916765]:  fort(handle_flags_config+0x315) [0x416145]
May 31 10:16:17 fort[916765]:  fort(main+0x66) [0x413d66]
May 31 10:16:17 fort[916765]:  /lib64/libc.so.6(__libc_start_main+0xf3) [0x7f59ef759493]
May 31 10:16:17 fort[916765]:  fort(_start+0x2e) [0x413e9e]
May 31 10:16:17 fort[916765]: (End of stack trace)
May 31 10:16:17 fort[916765]: ERR: Try 'fort --usage' or 'fort --help' for more information.
May 31 10:16:17 fort[916765]: Stack trace:
May 31 10:16:17 fort[916765]:  fort(print_stack_trace+0x1f) [0x417e5f]
May 31 10:16:17 fort[916765]:  fort(__pr_op_err+0x84) [0x418424]
May 31 10:16:17 fort[916765]:  fort(handle_flags_config+0x33b) [0x41616b]
May 31 10:16:17 fort[916765]:  fort(main+0x66) [0x413d66]
May 31 10:16:17 fort[916765]:  /lib64/libc.so.6(__libc_start_main+0xf3) [0x7f59ef759493]
May 31 10:16:17 fort[916765]:  fort(_start+0x2e) [0x413e9e]
May 31 10:16:17 fort[916765]: (End of stack trace)

kmisak · 2022-06-06T07:58:19Z

I also getting this crash regularly, but with Unknown protocol: 0

InsaneSplash · 2022-06-06T11:58:48Z

Ive left the service running with no BGP services using it and lost 2 instances this weekend.

note: dont update librtr to version 8

ydahhrk · 2022-06-06T21:15:42Z

Do you have files in the SLURM directory? (/etc/fort/slurm)
If so, can I have them? (It's fine if you want to censor IPs)

Mostly quality of life improvements. On the other hand, it looks like the notfatal hash table API was being used incorrectly. HASH_ADD_KEYPTR can OOM, but `errno` wasn't being catched. Fixing this is nontrivial, however, because strange `reqs_error` functions are in the way, and that's a spaggetti I decided to avoid. Instead, I converted HASH_ADD_KEYPTR usage to the fatal hash table API. That's the future according to #40, anyway. I don't think this has anything to do with #83, though.

ydahhrk · 2022-06-07T03:49:03Z

Ok, it looks like this is going to be a difficult bug.

Is either of you willing to run a custom debug-heavy Fort binary?

kmisak · 2022-07-04T10:54:29Z

I will do that, no problem

InsaneSplash · 2022-07-11T10:09:14Z

This is all I have in that file

{
  "slurmVersion": 1,
  "validationOutputFilters": {
    "prefixFilters": [],
    "bgpsecFilters": []
  },
  "locallyAddedAssertions": {
    "prefixAssertions": [],
    "bgpsecAssertions": []
  }
}

ydahhrk · 2022-07-21T21:33:49Z

Sorry it's taken so long. Debug commit is at branch issue83.

I need the first logging line that contains the string "VRP Corrupted!":

Jul 21 21:21:10 ERR [V]: After standalone: VRP corrupted!
Jul 21 21:21:10 ERR [V]: After SLURM: VRP corrupted!

It shouldn't crash anymore, but I'm not entirely sure what side effects the bogus VRP might induce.

This is all I have in that file

Ok thank you. Probably not the problem either.

NICMx/FORT-validator#83

ydahhrk · 2023-02-01T04:37:35Z

Have you gotten any "VRP corrupted!" messages yet?

Just to clarify: The issue83 branch contains a patch that prevents Fort from crashing, but does not, in fact, fix the bug.

There are no readers, so there's no point in this being a reader-writer lock. Still not meant to be a fix for #83/#89. I'm mostly just trying to force myself to interact with the code in hopes of finding the bug.

1. Revert panic back into the code. - Fort SHOULD die as soon as it realizes the VRP table is corrupted, as we should not send garbage to the routers. - Also, I'm not entirely sure the code would not crash later anyway, since the table is, in fact, corrupted. - Plus, if it doesn't crash, there would be no core dump to further analyze the bug. 2. Point bug output to the currently active bug report Might help us get some output earlier.

ydahhrk · 2023-02-21T17:56:50Z

Didn't mean to close this.

Jhoanor · 2023-07-04T08:20:32Z

With us sometimes it crashes after 1 day, sometimes after more than 6 weeks...

(Cannot implement 1.5.4 though because that would require a RPM package.
But if I read correctly I understand #83 is not yet resolved in 1.5.4. anyway)

ydahhrk · 2023-07-06T00:26:17Z

Ok, I managed to apparently successfully generate the RPMs for 1.5.4, and uploaded them here.

(I say "apparently" because CentOS 8's death forced me to migrate to Rocky Linux 8, and I'm not sure if packages generated there will be compatible with other RHELs. Please feedback.)

In other news, I have so far discovered and fixed at least one undefined behavior during the development of 1.5.5, so the bug might already be fixed in the main branch. For your convenience, I packaged this as rpm-1.5.4.1.tar.gz.

Please install either 1.5.4 or 1.5.4.1, and provide the crashing output once it happens. If it never happens, I would also like to know it.

rfc1036 · 2023-07-06T08:20:45Z

Do you mind tagging 1.5.4 (and 1.5.4.1?) in the repository? This way I will be able to update the Debian package.

ydahhrk · 2023-07-06T15:58:47Z

Do you mind tagging 1.5.4

What do you mean? It's been tagged since release.

rfc1036 · 2023-07-06T18:44:23Z

Nevermind: I tought that you had released a new version with the more recent changes. I will wait for the next one, unless you think that I should package a snapshot right now.

Jhoanor · 2023-07-07T05:45:08Z

RPM 1.5.4-1 package installs fine on RHEL. Thank you.
Now running one day, and still up.
I'll let you know over a week if still running (or earlier in case of crash)

Jhoanor · 2023-08-10T07:34:46Z

Well, it looks like it did the trick. No crashes in more than a month. Chapeau and thanks! :)

ydahhrk added a commit that referenced this issue May 16, 2022

Employ proper API to iterate through hash table entries

5cfb2f6

Found this quirk while eyeballing #83. I don't think it's going to fix the problem, but it's definitely an improvement.

ydahhrk added a commit that referenced this issue Jul 21, 2022

Issue #83: Add first iteration of debugging messages

dfc2955

gentoo-repo-qa-bot pushed a commit to gentoo-mirror/SwordArMor that referenced this issue Dec 5, 2022

net-misc/FORT-validator: Adding patch for upstream issue #83

3ce2cbd

NICMx/FORT-validator#83

ydahhrk added a commit that referenced this issue Feb 1, 2023

Bug #83/#89: Print more data

0b8449e

ydahhrk added a commit that referenced this issue Feb 2, 2023

Bug #83/#89: Print even more data

f945394

ydahhrk added a commit that referenced this issue Feb 3, 2023

Bug #83/#89: Print even more data

dd3b144

ydahhrk closed this as completed in f6d3573 Feb 7, 2023

ydahhrk reopened this Feb 21, 2023

ydahhrk closed this as completed Dec 1, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

FORT 1.5.3 Crashing - ERR: Unknown protocol: 114 #83

FORT 1.5.3 Crashing - ERR: Unknown protocol: 114 #83

InsaneSplash commented May 16, 2022 •

edited

Loading

ydahhrk commented May 16, 2022

InsaneSplash commented May 31, 2022

InsaneSplash commented May 31, 2022 •

edited

Loading

InsaneSplash commented May 31, 2022

kmisak commented Jun 6, 2022

InsaneSplash commented Jun 6, 2022 •

edited

Loading

ydahhrk commented Jun 6, 2022 •

edited

Loading

ydahhrk commented Jun 7, 2022

kmisak commented Jul 4, 2022

InsaneSplash commented Jul 11, 2022

ydahhrk commented Jul 21, 2022 •

edited

Loading

ydahhrk commented Feb 1, 2023

ydahhrk commented Feb 21, 2023

Jhoanor commented Jul 4, 2023

ydahhrk commented Jul 6, 2023

rfc1036 commented Jul 6, 2023

ydahhrk commented Jul 6, 2023

rfc1036 commented Jul 6, 2023

Jhoanor commented Jul 7, 2023

Jhoanor commented Aug 10, 2023

FORT 1.5.3 Crashing - ERR: Unknown protocol: 114 #83

FORT 1.5.3 Crashing - ERR: Unknown protocol: 114 #83

Comments

InsaneSplash commented May 16, 2022 • edited Loading

ydahhrk commented May 16, 2022

InsaneSplash commented May 31, 2022

InsaneSplash commented May 31, 2022 • edited Loading

InsaneSplash commented May 31, 2022

kmisak commented Jun 6, 2022

InsaneSplash commented Jun 6, 2022 • edited Loading

ydahhrk commented Jun 6, 2022 • edited Loading

ydahhrk commented Jun 7, 2022

kmisak commented Jul 4, 2022

InsaneSplash commented Jul 11, 2022

ydahhrk commented Jul 21, 2022 • edited Loading

ydahhrk commented Feb 1, 2023

ydahhrk commented Feb 21, 2023

Jhoanor commented Jul 4, 2023

ydahhrk commented Jul 6, 2023

rfc1036 commented Jul 6, 2023

ydahhrk commented Jul 6, 2023

rfc1036 commented Jul 6, 2023

Jhoanor commented Jul 7, 2023

Jhoanor commented Aug 10, 2023

InsaneSplash commented May 16, 2022 •

edited

Loading

InsaneSplash commented May 31, 2022 •

edited

Loading

InsaneSplash commented Jun 6, 2022 •

edited

Loading

ydahhrk commented Jun 6, 2022 •

edited

Loading

ydahhrk commented Jul 21, 2022 •

edited

Loading