Garbled apinger messages in the system log
-
I'm running snapshot 2.0-RC1 (i386)
built on Mon Mar 7 12:03:17 EST 2011In system log I see entries of the form:
Mar 10 11:34:54 apinger: alarm canceled: GW_WAN(F¶óýÔxÙ?;ßOM-^MM-^WnÚ?o^RM-^CÀÊ¡Ý?\M-^OÂõ(\ß?Õxé&1^HÜ?j¼tM-^S^X^DÞ?M-^MM-^Wn^RM-^CÀÚ?ö(\M-^OÂõØ?) *** down ***
Mar 10 11:35:02 check_reload_status: reloading filter
Mar 10 11:35:04 check_reload_status: reloading filter
Mar 10 11:35:14 apinger: ALARM: GW_WAN(^B+M-^G^VÙÎß?ßOM-^MM-^Wn^RÛ?^Y^DV^N-²Ý?shM-^Qí|?Ý?ºI^L^B+M-^GÞ?w¾M-^^Z/ÝÜ?þÔxé&1à?Õxé&1^HÜ?) *** down ***
Mar 10 11:35:16 apinger: alarm canceled: GW_WAN(^B+M-^G^VÙÎß?-²M-^]ï§ÆÛ?o^RM-^CÀÊ¡Ý?¤p= ×£Ø?ºI^L^B+M-^GÞ?w¾M-^^Z/ÝÜ?þÔxé&1à?Õxé&1^HÜ?) *** down ***
Mar 10 11:35:24 check_reload_status: reloading filterMy WAN link is a PPP link to my ISP. At the time it was down because ppp had dropped out and ddn't automatically restore itself. After I successfully restarted the WAN link the garbled message was not in the system log when next I looked.
-
Here are the apinger reports from bootup to around the time I reset the hurricane electric IPV4 "remote tunnel endpoint". I deleted some of the garbled entries in between the two endpoints of the segment in order to reduce the size of the post (and because they didn't seem to add any value).
clog /var/log/system.log | grep apinger
Mar 10 17:09:27 pfsense apinger: Starting Alarm Pinger, apinger(62457)
Mar 10 17:09:38 pfsense apinger: ALARM: HE_NET(2001:470:1f04:14b3::1) *** down ***
Mar 10 17:09:46 pfsense apinger: Exiting on signal 15.
Mar 10 17:09:48 pfsense apinger: Starting Alarm Pinger, apinger(51188)
Mar 10 17:09:59 pfsense apinger: ALARM: HE_NET(2001:470:1f04:14b3::1) *** down ***
Mar 10 17:10:43 pfsense apinger: ALARM: GW_WAN(����x��?^FM-^AM-^UCM-^Kl�?�tM-^S^X^DV�?j�tM-^S^X^D�?M-^ZM-^YM-^YM-^YM-^YM-^Y�?T��M-^[� �?�tM-^S^X^DV�?DM-^Kl����?) *** down ***
Mar 10 17:10:48 pfsense apinger: Error while feeding rrdtool: Broken pipe
Mar 10 17:10:48 pfsense kernel: pid 51188 (apinger), uid 0: exited on signal 11
Mar 10 17:13:22 pfsense apinger: Starting Alarm Pinger, apinger(49293)
Mar 10 17:13:32 pfsense apinger: ALARM: HE_NET(2001:470:1f04:14b3::1) *** down ***
Mar 10 17:14:21 pfsense apinger: ALARM: GW_WAN(�E�����?Zd;�OM-^M�?Nb^PX9��?^L^B+M-^G^V��?X9��v��?R�^^M-^E�Q�? ףp= �?�rhM-^Q�|�?) *** down ***
Mar 10 17:14:27 pfsense apinger: alarm canceled: GW_WAN(M-^C�ʡE��?�M-^^Z/�$�?��v�M-^^Z�?^T�G�z^T�?X9��v��?R�^^M-^E�Q�? ףp= �?��x�&1�?) *** down ***
Mar 10 17:14:37 pfsense apinger: ALARM: GW_WAN( ףp= �?��"���?) *** down *** Mar 10 17:15:13 pfsense apinger: alarm canceled: GW_WAN(}?5^�I�?^PX9��v�?^DV^N-�M-^]�?ffffff�?M-^VCM-^Kl���?ffffff�?�G�z^T��?^?j�tM-^S^X�?) *** down *** Mar 10 17:15:23 pfsense apinger: ALARM: GW_WAN(���x�&�?^H�^\Zd;�?��K7M- A�?�M-^]���K�?����Mb�?hM-^Q�|?5�?uM-^S^X^DV^N�?Zd;�OM-^M�?) *** down *** Mar 10 17:15:23 pfsense apinger: alarm canceled: GW_WAN(���x�&�?^H�^\Zd;�?��K7M- A�?�M-^]���K�?����Mb�?hM-^Q�|?5�?uM-^S^X^DV^N�?Zd;�OM-^M�?) *** down *** Mar 10 17:16:27 pfsense apinger: ALARM: GW_WAN(M-^Xn^RM-^C���?^RM-^C�ʡE�?�M-^]���K�?�M-^]���K�?\M-^O��(\�?M-^^���K7�?^PX9��v�?) *** down *** Mar 10 17:16:32 pfsense apinger: alarm canceled: GW_WAN(M-^Xn^RM-^C���?^RM-^C�ʡE�?+M-^G^V����?�"��~j�?m������?^PX9��v�?M-^MM-^Wn^RM-^C��?^H�^\Zd;�?) *** down *** Mar 10 17:17:12 pfsense apinger: ALARM: GW_WAN(+M-^G^V����?���Mb^P�?7M- A���?uM-^S^X^DV^N�?M-^C�ʡE��? ףp= �?�G�z^T��?;�OM-^MM-^Wn�?) *** down ***
Mar 10 17:17:40 pfsense apinger: alarm canceled: GW_WAN(R�^^M-^E�Q�?Nb^PX9��?^PX9��v�?^L^B+M-^G^V��?= ףp=�?ffffff�?^RM-^C�ʡE�?��~j�t�?) *** down ***
Mar 10 17:18:19 pfsense apinger: ALARM: GW_WAN(�$^FM-^AM-^UC�?� �rhM-^Q�?ˡE����?�^^M-^E�Q��?�~j�tM-^S�?J^L^B+M-^G^V�?��x�&1�?R�^^M-^E�Q�?) *** down ***
Mar 10 17:18:24 pfsense apinger: alarm canceled: GW_WAN(�$^FM-^AM-^UC�?� �rhM-^Q�?ˡE����?�^^M-^E�Q��?���x�&�?�|?5^��?7M- A���?^B+M-^G^V���?) *** down *** Mar 10 17:18:35 pfsense apinger: ALARM: GW_WAN(d;�OM-^MM-^W�?�"��~j�?shM-^Q�|?�?X9��v��?�S��M-^[��??5^�I^L�?�E�����?J^L^B+M-^G^V�?) *** down *** Mar 10 17:18:57 pfsense apinger: alarm canceled: GW_WAN(^?j�tM-^S^X�?M-^Kl�����?w�M-^_^Z/��?�$^FM-^AM-^UC�?/�$^FM-^AM-^U�?M-^Q�|?5^�?F����x�?M-^Q�|?5^�?) *** down *** Mar 10 17:19:14 pfsense apinger: ALARM: GW_WAN(�^Z/�$^F�?H�z^T�G�?7M- A���?9��v�M-^_�?uM-^S^X^DV^N�?��"��~�?^B+M-^G^V���?/�$^FM-^AM-^U�?) *** down ***
Mar 10 17:19:26 pfsense apinger: alarm canceled: GW_WAN(���x�&�?\M-^O��(\�?��(\M-^O��?-�M-^]����?��x�&1�?d;�OM-^MM-^W�?^L^B+M-^G^V��?�&1^H�^\�?) *** down ***
Mar 10 17:19:36 pfsense apinger: ALARM: GW_WAN(H�z^T�G�?���x�&�?M-^ZM-^YM-^YM-^YM-^YM-^Y�?M-^Kl�����?ףp= ��?�OM-^MM-^Wn^R�?�z^T�G��?Nb^PX9��?) *** down ***
Mar 10 17:21:00 pfsense apinger: Exiting on signal 15.
Mar 10 17:21:02 pfsense apinger: Starting Alarm Pinger, apinger(40386)
Mar 10 17:21:14 pfsense apinger: ALARM: HE_NET(2001:470:1f04:14b3::1) *** down ***
Mar 10 17:24:14 pfsense apinger: ALARM: GW_WAN(M-^C�ʡE��?5^�I^L^B�?^FM-^AM-^UCM-^Kl�?Nb^PX9��?M-^VCM-^Kl���?M-^O��(\M-^O�?M-^S^X^DV^N-�?) *** down ***
Mar 10 17:24:24 pfsense apinger: alarm canceled: GW_WAN(M-^S^X^DV^N-�?}?5^�I�?^T�G�z^T�?�����M�?M-^G^V���S�?V^N-�M-^]��?/�$^FM-^AM-^U�?^B+M-^G^V���?) *** down ***Mar 10 17:57:36 pfsense apinger: alarm canceled: GW_WAN(�Q�^^M-^E��?M-^G^V���S�?!�rhM-^Q��?/�$^FM-^AM-^U�?7M- A
���?5^�I^L^B�?^W���S��?�M-^_^Z/�$�?) *** down *** Mar 10 17:58:21 pfsense apinger: ALARM: GW_WAN(;�OM-^MM-^Wn�?m������?�"��~j�?shM-^Q�|?�?R�^^M-^E�Q�?^L^B+M-^G^V��?��K7M- A�?�������?) *** down *** Mar 10 17:58:27 pfsense apinger: Exiting on signal 15. Mar 10 17:58:29 pfsense apinger: Starting Alarm Pinger, apinger(49037) Mar 10 17:58:39 pfsense apinger: ALARM: HE_NET(2001:470:1f04:14b3::1) *** down *** Mar 10 17:59:06 pfsense apinger: ALARM: GW_WAN(�E�����?J^L^B+M-^G^V�?^RM-^C�ʡE�?7M- A���?^�I^L^B+�?M-^Xn^RM-^C���?��v�M-^_^Z�?^_M-^E�Q�^^�?) *** down ***
Mar 10 17:59:07 pfsense apinger: alarm canceled: GW_WAN(�E�����?J^L^B+M-^G^V�?^RM-^C�ʡE�?7M- A`���?^�I^L^B+�?9��v�M-^_�?^PX9��v�?^_M-^E�Q�^^�?) *** down ***Mar 10 19:01:21 pfsense apinger: ALARM: GW_WAN(?5^�I^L�?���x�&�?����x��?^H�^\Zd;�?q= ףp�?X9��v��?M-^E�Q�^^M-^E�?^[/�$^FM-^A�?) *** loss ***
Mar 10 19:02:08 pfsense apinger: alarm canceled: GW_WAN(`��"���?�I^L^B+M-^G�?M-^O��(\M-^O�?!�rhM-^Q��?�G�z^T��?M-^G^V���S�?333333�?M-^C�ʡE��?) *** loss ***
Mar 10 19:02:25 pfsense apinger: alarm canceled: HE_NET(2001:470:1f04:14b3::1) *** down ***
[/quote] -
Is that on a standard 2.0 image or are you on the ipv6 code?
-
-
This may be a side effect of the ipv6 code. I haven't heard of that happening on a stock 2.0 image, and there are probably several places in the ipv6 where such a buglet may have slipped in. I moved the thread to the ipv6 board in case someone else there might have seen it.
-
Not sure if this is related to the IPv6 code at all. Never seen it before though.
-
Not sure if this is related to the IPv6 code at all. Never seen it before though.
I thought since apinger was reporting the garbled message and the apinger application on my system is dated 2009 that it probably was more an apinger problem than a problem in the IPv6 mods. But maybe the IPv6 mods touch a file used by apinger in a way that causes confusion in apinger.
-
Here are the current apinger configuration file and status file.
It is perhaps curious that though there are 4 targets in the configuration file (SROUTE1 seemingly duplicating SROUTE0) there seem to be only 3 entries in the status file.
more /var/etc/apinger.conf
pfSense apinger configuration file. Automatically Generated!
User and group the pinger should run as
user "root"
group "wheel"Mailer to use (default: "/usr/lib/sendmail -t")
#mailer "/var/qmail/bin/qmail-inject"
Location of the pid-file (default: "/var/run/apinger.pid")
pid_file "/var/run/apinger.pid"
Format of timestamp (%s macro) (default: "%b %d %H:%M:%S")
#timestamp_format "%Y%m%d%H%M%S"
status {
## File where the status information whould be written to
file "/tmp/apinger.status"
## Interval between file updates
## when 0 or not set, file is written only when SIGUSR1 is received
interval 5s
}########################################
RRDTool status gathering configuration
Interval between RRD updates
rrd interval 60s;
These parameters can be overriden in a specific alarm configuration
alarm default {
command on "/usr/local/sbin/pfSctl -c 'filter reload'"
command off "/usr/local/sbin/pfSctl -c 'filter reload'"
combine 10s
}"Down" alarm definition.
This alarm will be fired when target doesn't respond for 30 seconds.
alarm down "down" {
time 10s
}"Delay" alarm definition.
This alarm will be fired when responses are delayed more than 200ms
it will be canceled, when the delay drops below 100ms
alarm delay "delay" {
delay_low 200ms
delay_high 500ms
}"Loss" alarm definition.
This alarm will be fired when packet loss goes over 20%
it will be canceled, when the loss drops below 10%
alarm loss "loss" {
percent_low 10
percent_high 20
}target default {
## How often the probe should be sent
interval 1s
## How many replies should be used to compute average delay
## for controlling "delay" alarms
avg_delay_samples 10
## How many probes should be used to compute average loss
avg_loss_samples 50## The delay (in samples) after which loss is computed
## without this delays larger than interval would be treated as loss
avg_loss_delay_samples 20## Names of the alarms that may be generated for the target
alarms "down","delay","loss"## Location of the RRD
#rrd file "/var/db/rrd/apinger-%t.rrd"
}
target "121.50.212.5" {
description "GW_WAN"
srcip "203.144.5.171"
alarms override "loss","delay","down";
rrd file "/var/db/rrd/GW_WAN-quality.rrd"
}target "192.168.211.217" {
description "SROUTE0"
srcip "192.168.211.173"
alarms override "loss","delay","down";
rrd file "/var/db/rrd/SROUTE0-quality.rrd"
}target "192.168.211.217" {
description "SROUTE1"
srcip "192.168.211.173"
alarms override "loss","delay","down";
rrd file "/var/db/rrd/SROUTE1-quality.rrd"
}target "2001:470:1f04:14b3::1" {
description "HE_NET"
srcip "2001:470:1f04:14b3::2"
alarms override "loss","delay","down";
rrd file "/var/db/rrd/HE_NET-quality.rrd"
}more /tmp/apinger.status
sh<91><ed>|?
<dd>?<bc>t<93>^X^DV<d6>?^_<85><eb>Q<b8>^^<d5>?'<ac>^\Z<e0>?ESC/</e0></ac></d5></b8></eb></d6></bc></dd>
<dd>$^F<81><d5>?<d1>"<db><f9>~j<e0>?^Y^DV^N- <b2><d5>? <c5><b0>rh<91></b0></c5></d5></b2></e0></f9></db></d1></d5></dd>
<dd>?|203.144.5.171|GW_WAN|56|55|1299819488|40.422ms||none
192.168.211.217|192.168.211.173|SROUTE1|56|55|1299819488|0.473ms||none
2001:470:1f04:14b3::1|2001:470:1f04:14b3::2|HE_NET|56|0|0|0.000ms||down
#</dd></ed>I guess the two apinger targets seemingly the same are from two static routes: 192.168.217.0/24 and 192.168.51.0/24 are both accessible through 192.168.211.217.
-
Looks like the entry with 203.144.5.171 is corrupt, that "sh …" stuff shouldn't be there. It should look like the other lines.
Side note: The timestamp is kept on some files even if their contents have been updated. It's unlikely that your apinger binary is really from 2009.
-
Ok, that is a upgrade bug that exists in 2.0-RC1. When we originally wrote the static route upgrade code it appears we've forgotten to collapse the routes by target. This is a clear bug.
2 routes pointing to the same IP should always result in a single target. This was clearly a oversight.
Is this a install upgraded from 1.2.3 or is this a upgrade from a 2.0-RC or BETA install
-
Is this a install upgraded from 1.2.3 or is this a upgrade from a 2.0-RC or BETA install
Upgrade from 1.2.3 through various 2.0 BETA snapshot builds.
-
Aha! That explains it
-
Can you please provide the 1.2.3 config static route section?
-
Create a 1.2.3 vm, create 2 routes to a lan IP. Upgrade that and it should trigger it
