ViewVC Help
View File | Revision Log | Show Annotations | Download File
/cvs/libspf/docs/API/debugging_libspf_1.0.txt
Revision: 1.1
Committed: Tue Nov 13 00:51:24 2007 UTC (18 years, 10 months ago) by root
Content type: text/plain
Branch: MAIN
CVS Tags: HEAD
Log Message: 
initial import of libspf-1.0.0-p5 from freebsd ports

File Contents

# Content
1 Debugging libSPF
2
3 Enabling debugging in libSPF is quite easy. The library provides two compile time flags to define the behaviour of this debugging:
4
5 _SPF_DEBUG
6 _SPF_DEBUG_LOGFILE
7
8 _SPF_DEBUG
9
10 Setting "_SPF_DEBUG" enables the following MACRO's which can be found in util.h:
11
12 #define xprintf(format,...) dbg_printf(FL_A, __FUNCTION__, format, __VA_ARGS__)
13 #define xvprintf(format,...) dbg_printf(FL_B, __FUNCTION__, format, __VA_ARGS__)
14 #define xpprintf(format,...) dbg_printf(FL_D, __FUNCTION__, format, __VA_ARGS__)
15
16 These MACRO's all reference another MACRO, namely dbg_printf. Lets follow the trail back to the real debugging function, and explain why its done this way:
17
18 #if defined _SPF_DEBUG
19 #define dbg_printf _printf_dbg
20 #endif
21
22 #ifndef _ SPF_DEBUG
23 #define dbg_printf dummy_debug
24 #endif
25
26 (In previous versions of libSPF debugging was enabled with the DEBUG flag but as of v1.0 RC3 this changed to strictly be _SPF_DEBUG.)
27
28 As we can see these #ifdef's will assign dbg_printf to a different function depending on the presense of the _SPF_DEBUG MACRO. In its presense _printf_dbg is referenced:
29
30 /* _printf_dbg
31 *
32 * Author: James Couzens <jcouzens@6o4.ca>
33 *
34 * Date: 12/25/03
35 * Date: 02/18/04 (updated)
36 *
37 * Desc:
38 * Tied to a compile time switch this can instantly and at little
39 * to no real expense enable a discreet debugging with out hoards of
40 * #ifdefs all over the place.
41 *
42 */
43 void _printf_dbg(u_int8_t level, const char *function, const char *format,...)
44 {
45 char _dbg_output[MAX_DEBUG_LEN];
46 va_list argptr;
47
48 #ifdef _SPF_DEBUG_LOGFILE
49 FILE *fp = NULL;
50 #endif
51
52 va_start(argptr, format);
53 vsnprintf(_dbg_output, SIZEOF(_dbg_output), format, argptr);
54 va_end(argptr);
55
56 if (f_bit_set(confg.level, level))
57 {
58 #ifndef _SPF_DEBUG_LOGFILE
59 printf("%s :: %s", function, _dbg_output);
60 fflush(stdout);
61 #else
62 if ((fp = fopen(DEBUG_LOG_FILE, "a")) != NULL)
63 {
64 fprintf(fp, "%s", _dbg_output);
65 fclose(fp);
66 }
67 #endif
68
69 }
70
71 return;
72 }
73
74 In its absense dummy_debug is a dummy function is set in its place which does nothing. This was chosen as the best way to facilitate easily enabled and extensive debugging without riddling the entire codebase with #ifdefs:
75
76 /* dummy_debug
77 *
78 * Author: James Couzens <jcouzens@6o4.ca>
79 *
80 * Date: 12/25/03
81 *
82 * Desc:
83 * dummy function thats used instead of the _printf_dbg function
84 * when compiling without debugging
85 *
86 *
87 */
88 void dummy_debug(const u_int8_t level, const char *function,
89 const char *format,...)
90 {
91 return
92 }
93
94 _SPF_DEBUG_LOGFILE
95
96 Setting this macro will help you when you are running libSPF from within a mail server. Rather than highjacking the logging of the MTA in question, or even dumping to syslog it was chosen to instead log to our own specific log file which is defined here:
97
98
99 /* output file for debugging */
100 #define DEBUG_LOG_FILE "/var/log/spf.log"
101
102
103 You can alter this location by altering this MACRO's contents.
104
105 Controlling Output and Verbosity
106
107 Now that we understand how to enable debugging, where can we find it and how can it be controlled? The following flags are provided to alter the behaviour of this output.
108
109 #define FL_A 2 /* xprintf */
110 #define FL_B 4 /* xvprintf */
111 #define FL_C 8 /* xprintf + xvprintf */
112 #define FL_D 16 /* xpprintf */
113 #define FL_E 32 /* xprintf + xpprintf */
114 #define FL_F 64 /* xvprintf + xpprintf */
115 #define FL_G 128 /* xprintf + xvprintf + xpprintf */
116
117 These flags are referenced by macro's defined in util.h and spoken of when explaining the _SPF_DEBUG macro earlier in this document, but we will reference one of them again for explanation:
118
119 #define xprintf(format,...) dbg_printf(FL_A, __FUNCTION__, format, __VA_ARGS__)
120
121 In this case whats important is the FL_A MACRO which is what the debugging function looks at to see if it should output the debugging data it may have been passed. This is handled by the following piece of code which has been emboldened:
122
123 vsnprintf(_dbg_output, SIZEOF(_dbg_output), format, argptr);
124 va_end(argptr);
125
126 if (f_bit_set(confg.level, level))
127 {
128 #ifndef _SPF_DEBUG_LOGFILE
129 printf("%s :: %s", function, _dbg_output);
130
131 So if the bit set, falls within the bit set by your client then the output is displayed, otherwise it isn't. If the log file MACRO has been set then its written to a disk logfile instead of stdout. You don't want to be logging to stdout on your MTA because this would break all e-mail travelling through it!
132
133 I take pride somewhat in being able to say that this library is C/89 compliant, however, this particular debugging implementation actually makes use functionality not available in C/89, but is in C/99. You will see this if you compile the library using the GCC flag '-pedantic':
134
135 gcc -Wall -pedantic -ggdb -D_BSD_SOURCE -D_SPF_DEBUG -c -o static/main.o main.c
136 In file included from main.c:46:
137 util.h:79:24: warning: anonymous variadic macros were introduced in C99
138
139 The point of raising this issue is that in a production environment you would compile without debugging and thus this library is indeed compliant with C/89 standard C.
140
141 Examples of output
142
143 Finally lets have a look at the debugging in action. When compiled without debugging output looks like:
144
145 root@code3 bin # ./spfquery-static -i 10.0.0.2 -s jcouzens@6o4.ca?-h
146 spftools.net
147 neutral
148 policy result: (neutral) from rule (?all)
149
150 See
151 http://spf.pobox.com/why.html?sender=jcouzens@uhfco.net&ip=10.0.0.2&receiver=spfquery
152
153 When using debug level 1 (this is independent of the library and up to the client implementation to make use of and thus only results in output as chosen by the client. In spfquery we have chosen to display the contents as passed from command line:
154
155
156 root@code3 bin # ./spfquery-static -i 10.0.0.2 -s jcouzens@6o4.ca -h spftools.net -v 1
157 DEBUGGING LEVEL IS: 1
158 ipv4: 10.0.0.2
159 sender: jcouzens@6o4.ca
160 helo: spftools.net
161 neutral
162 policy result: (neutral) from rule (?all)
163
164 See http://spf.pobox.com/why.html?sender=jcouzens@uhfco.net&ip=10.0.0.2&receiver=spfquery
165
166 xprintf: normal debugging - This is the overall result of the SPF parse displaying only an overview of process.
167
168 root@code3 bin # ./spfquery-static -i 10.0.0.2 -s jcouzens@6o4.ca -h spftools.net -v 2
169 DEBUGGING LEVEL IS: 2
170 ipv4: 10.0.0.2
171 sender: jcouzens@6o4.ca
172 helo: spftools.net
173 SPF_init :: libspf initialized succesfully. (724 bytes allocated)
174 SPF_smtp_helo :: called with (spftools.net)
175 SPF_smtp_from :: FROM: (jcouzens@6o4.ca) (called with: jcouzens@6o4.ca)
176 SPF_smtp_from :: CUR DOM: (6o4.ca)
177 SPF_policy_main_rec :: (QID: 0) :: Error parsing ANSWER(s)
178 SPF_parse_policy :: (QID: 0) :: about to parse (v=spf1 redirect=uhfco.net ) of len: 26 (none)
179 SPF_parse_policy :: (QID: 0) :: SPF Policy Mechanism: 1 (token: v=spf1) (pos: 6)
180 SPF_parse_policy :: (QID: 0) :: policy mechanism is version (v=spf1)
181 SPF_parse_policy :: (QID: 0) :: SPF Policy Mechanism: 10 (token: redirect=uhfco.net) (pos: 18)
182 SPF_parse_policy :: (QID: 0) :: policy mechanism is redirect (redirect=uhfco.net)
183 SPF_policy_main_rec :: (QID: 1) :: Error parsing ANSWER(s)
184 SPF_parse_policy :: (QID: 1) :: about to parse (v=spf1 mx ptr ip4:24.207.1.85 ip4:24.207.0.192/26 a:cccp.6o4.ca a:moscow.6o4.ca a:tidy.obscurity.org ?all ) of len: 106 (none)
185 SPF_parse_policy :: (QID: 1) :: SPF Policy Mechanism: 1 (token: v=spf1) (pos: 6)
186 SPF_parse_policy :: (QID: 1) :: policy mechanism is version (v=spf1)
187 SPF_parse_policy :: (QID: 1) :: SPF Policy Mechanism: 5 (token: mx) (pos: 2)
188 SPF_parse_policy :: (QID: 1) :: policy mechanism is mx (mx)
189 SPF_parse_policy :: (QID: 1) :: SPF Policy Mechanism: 6 (token: ptr) (pos: 3)
190 SPF_parse_policy :: (QID: 1) :: policy mechanism is ptr (ptr)
191 SPF_parse_policy :: (QID: 1) :: SPF Policy Mechanism: 7 (token: ip4:24.207.1.85) (pos: 15)
192 SPF_parse_policy :: (QID: 1) :: policy mechanism is ip4 (ip4:24.207.1.85)
193 SPF_parse_policy :: (QID: 1) :: SPF Policy Mechanism: 7 (token: ip4:24.207.0.192/26) (pos: 19)
194 SPF_parse_policy :: (QID: 1) :: policy mechanism is ip4 (ip4:24.207.0.192/26)
195 SPF_parse_policy :: (QID: 1) :: SPF Policy Mechanism: 4 (token: a:cccp.6o4.ca) (pos: 13)
196 SPF_parse_policy :: (QID: 1) :: policy mechanism is A (a:cccp.6o4.ca)
197 SPF_parse_policy :: (QID: 1) :: SPF Policy Mechanism: 4 (token: a:moscow.6o4.ca) (pos: 15)
198 SPF_parse_policy :: (QID: 1) :: policy mechanism is A (a:moscow.6o4.ca)
199 SPF_parse_policy :: (QID: 1) :: SPF Policy Mechanism: 4 (token: a:tidy.obscurity.org) (pos: 20)
200 SPF_parse_policy :: (QID: 1) :: policy mechanism is A (a:tidy.obscurity.org)
201 SPF_parse_policy :: (QID: 1) :: SPF Policy Mechanism: 2 (token: all) (pos: 4)
202 SPF_parse_policy :: (QID: 1) :: policy mechanism is all (all) policy: (2)
203 MACRO_process :: called with (S) and len: 2
204 MACRO_process :: local: (jcouzens) cur dom (uhfco.net)
205 MACRO_process :: called with (I) and len: 2
206 MACRO_process :: called with (xR) and len: 3
207 MACRO_expand :: Allocated 89 bytes for return buf
208 SPF_policy_main_rec :: (QID: 1) :: Return policy 5 on mech: (?all) with outcome: (neutral)
209 SPF_policy_main_rec :: (QID: 1) :: Return policy 5 on mech: (?all) with outcome: (neutral)
210 neutral
211 policy result: (neutral) from rule (?all)
212
213 See http://spf.pobox.com/why.html?sender=jcouzens@uhfco.net&ip=10.0.0.2&receiver=spfquery
214
215
216 xvprintf: verbose debugging: This debugging level is just like the name says, its exceptionally verbose, detailing every single operation along the way such as allocating memory, deallocating, expanding macros' and so forth.
217
218 root@code3 bin # ./spfquery-static -i 10.0.0.2 -s jcouzens@6o4.ca -h spftools.net -v 4
219 DEBUGGING LEVEL IS: 4
220 ipv4:?? 10.0.0.2
221 sender: jcouzens@6o4.ca
222 helo:?? spftools.net
223 SPF_init :: Called with: (spfquery) (10.0.0.2) ((null)) ((null)) ((null)) 0:0
224 UTIL_strndup :: Allocated 24 bytes of memory.
225 UTIL_strndup :: Returning string: (v=spf1 a/24 mx/24 ptr )
226 UTIL_strndup :: Allocated 43 bytes of memory.
227 UTIL_strndup :: Returning string: (v=spf1 include:spf.trusted-forwarder.org )
228 UTIL_strndup :: Allocated 9 bytes of memory.
229 UTIL_strndup :: Returning string: (spfquery)
230 UTIL_strndup :: Allocated 9 bytes of memory.
231 UTIL_strndup :: Returning string: (10.0.0.2)
232 UTIL_strndup :: Allocated 9 bytes of memory.
233 UTIL_strndup :: Returning string: (spfquery)
234 UTIL_free :: Free address 0x80603a8 by SPF_init on line 177 (main.c)
235 UTIL_assoc_prefix :: (QID: 0) :: Stored SPF_NEUTRAL (5) (5)
236 UTIL_strdup :: Returning string: (spftools.net)
237 UTIL_free :: Unable to free() on NULL pointer at main.c:1086 in SPF_smtp_from; address 0x0.
238 UTIL_free :: Unable to free() on NULL pointer at main.c:1087 in SPF_smtp_from; address 0x0.
239 UTIL_strdup :: Returning string: (jcouzens@6o4.ca)
240 UTIL_strdup :: Returning string: (6o4.ca)
241 SPF_smtp_from :: LOCAL: (jcouzens) DOMAIN (6o4.ca) SENDER: (jcouzens@6o4.ca)
242 DNS_query :: Called with (6o4.ca) and type: 5
243 UTIL_assoc_prefix :: (QID: 0) :: Stored SPF_NONE (1) (1)
244 DNS_query :: policy result: (none) from rule ()
245 DNS_query :: Called with (6o4.ca) and type: 16
246 DNS_query :: Received packet size of 105 bytes which contains 1 answers.
247 DNS_query :: ANSWERS: 1
248 DNS_query :: QUESTIONS: 1
249 DNS_txt_answer :: Answer 1 has length 26. (26)
250 DNS_txt_answer :: Answer Data: (v=spf1 redirect=uhfco.net ) len: 26
251 DNS_txt_answer :: REALLOCATE memory: 26 bytes
252 DNS_txt_answer :: RR_DATA: (v=spf1 redirect=uhfco.net )
253 DNS_txt_answer :: Returning with valid SPFv1 record
254 UTIL_assoc_prefix :: (QID: 0) :: Stored SPF_NONE (1) (1)
255 UTIL_strndup :: Allocated 27 bytes of memory.
256 UTIL_strndup :: Returning string: (v=spf1 redirect=uhfco.net )
257 UTIL_index :: Found search char: ( ); Returning: (6)
258 UTIL_strndup :: Allocated 7 bytes of memory.
259 UTIL_strndup :: Returning string: (v=spf1)
260 UTIL_is_spf_result :: Called with char (v)
261 UTIL_get_policy_mech :: Called with: (v=spf1)
262 UTIL_get_policy_mech :: Returning 1 (VERSION)
263 UTIL_index :: Found search char: (=); Returning: (1)
264 SPF_parse_policy :: (QID: 0) :: SPF Version defined as: 1
265 UTIL_free :: Free address 0x8060488 by SPF_parse_policy on line 860 (main.c)
266 UTIL_index :: Found search char: ( ); Returning: (18)
267 UTIL_strndup :: Allocated 19 bytes of memory.
268 UTIL_strndup :: Returning string: (redirect=uhfco.net)
269 UTIL_is_spf_result :: Called with char (r)
270 UTIL_get_policy_mech :: Called with: (redirect=uhfco.net)
271 UTIL_get_policy_mech :: Returning 10 (REDIRECT)
272 UTIL_is_macro :: Called with char (uhfco.net)
273 UTIL_free :: Free address 0x80603f8 by SPF_parse_policy on line 780 (main.c)
274 UTIL_strndup :: Allocated 10 bytes of memory.
275 UTIL_strndup :: Returning string: (uhfco.net)
276 DNS_query :: Called with (uhfco.net) and type: 5
277 UTIL_assoc_prefix :: (QID: 1) :: Stored SPF_NONE (1) (1)
278 DNS_query :: policy result: (none) from rule (redirect=uhfco.net)
279 DNS_query :: Called with (uhfco.net) and type: 16
280 DNS_query :: Received packet size of 213 bytes which contains 1 answers.
281 DNS_query :: ANSWERS: 1
282 DNS_query :: QUESTIONS: 1
283 DNS_txt_answer :: Answer 1 has length 106. (106)
284 DNS_txt_answer :: Answer Data: (v=spf1 mx ptr ip4:24.207.1.85 ip4:24.207.0.192/26 a:cccp.6o4.ca a:moscow.6o4.ca a:tidy.obscurity.org ?all ) len: 106
285 DNS_txt_answer :: REALLOCATE memory: 106 bytes
286 DNS_txt_answer :: RR_DATA: (v=spf1 mx ptr ip4:24.207.1.85 ip4:24.207.0.192/26 a:cccp.6o4.ca a:moscow.6o4.ca a:tidy.obscurity.org ?all )
287 DNS_txt_answer :: Returning with valid SPFv1 record
288 UTIL_assoc_prefix :: (QID: 1) :: Stored SPF_NONE (1) (1)
289 UTIL_strndup :: Allocated 107 bytes of memory.
290 UTIL_strndup :: Returning string: (v=spf1 mx ptr ip4:24.207.1.85 ip4:24.207.0.192/26 a:cccp.6o4.ca a:moscow.6o4.ca a:tidy.obscurity.org ?all )
291 UTIL_index :: Found search char: ( ); Returning: (6)
292 UTIL_strndup :: Allocated 7 bytes of memory.
293 UTIL_strndup :: Returning string: (v=spf1)
294 UTIL_is_spf_result :: Called with char (v)
295 UTIL_get_policy_mech :: Called with: (v=spf1)
296 UTIL_get_policy_mech :: Returning 1 (VERSION)
297 UTIL_index :: Found search char: (=); Returning: (1)
298 SPF_parse_policy :: (QID: 1) :: SPF Version defined as: 1
299 UTIL_free :: Free address 0x8060488 by SPF_parse_policy on line 860 (main.c)
300 UTIL_index :: Found search char: ( ); Returning: (2)
301 UTIL_strndup :: Allocated 3 bytes of memory.
302 UTIL_strndup :: Returning string: (mx)
303 UTIL_is_spf_result :: Called with char (m)
304 UTIL_get_policy_mech :: Called with: (mx)
305 UTIL_get_policy_mech :: Returning 5 (MX)
306 DNS_query :: Called with (uhfco.net) and type: 15
307 DNS_query :: Received packet size of 167 bytes which contains 2 answers.
308 DNS_query :: ANSWERS: 2
309 DNS_query :: QUESTIONS: 1
310 DNS_mx_answer :: MX: mx2.uhfco.net Preference: 20
311 DNS_mx_answer :: REALLOCATE memory: 15 bytes
312 DNS_mx_answer :: MX: mx1.uhfco.net Preference: 10
313 DNS_mx_answer :: REALLOCATE memory: 29 bytes
314 UTIL_mx_cmp :: rr_data is: (mx2.uhfco.net mx1.uhfco.net)
315 UTIL_strndup :: Allocated 16 bytes of memory.
316 UTIL_strndup :: Returning string: (10.0.0.2)
317 UTIL_mx_cmp :: TOKEN: (mx2.uhfco.net)
318 UTIL_validate_hostname :: Called with: (134611848) and (mx2.uhfco.net)
319 UTIL_strndup :: Allocated 17 bytes of memory.
320 UTIL_strndup :: Returning string: (24.207.0.211)
321 UTIL_validate_hostname :: CLI: 24.207.0.211 (3540045592) SRV: 10.0.0.2 (33554442)
322 UTIL_free :: Free address 0x8061900 by UTIL_validate_hostname on line 1797 (util.c)
323 UTIL_mx_cmp :: TOKEN: (mx1.uhfco.net)
324 UTIL_validate_hostname :: Called with: (134611848) and (mx1.uhfco.net)
325 UTIL_strndup :: Allocated 17 bytes of memory.
326 UTIL_strndup :: Returning string: (24.207.0.211)
327 UTIL_validate_hostname :: CLI: 24.207.0.211 (3540045592) SRV: 10.0.0.2 (33554442)
328 UTIL_free :: Free address 0x8061900 by UTIL_validate_hostname on line 1797 (util.c)
329 UTIL_free :: Free address 0x80605b8 by UTIL_mx_cmp on line 768 (util.c)
330 UTIL_free :: Free address 0x8060590 by UTIL_mx_cmp on line 769 (util.c)
331 UTIL_free :: Free address 0x8060488 by SPF_parse_policy on line 860 (main.c)
332 UTIL_index :: Found search char: ( ); Returning: (3)
333 UTIL_strndup :: Allocated 4 bytes of memory.
334 UTIL_strndup :: Returning string: (ptr)
335 UTIL_is_spf_result :: Called with char (p)
336 UTIL_get_policy_mech :: Called with: (ptr)
337 UTIL_get_policy_mech :: Returning 6 (PTR)
338 UTIL_ptr_cmp :: Called with (ptr)
339 UTIL_rev_addr :: Called with: (10.0.0.2) len: 8
340 UTIL_strndup :: Allocated 9 bytes of memory.
341 UTIL_strndup :: Returning string: (10.0.0.2)
342 UTIL_rev_addr :: token : (10)
343 UTIL_rev_addr :: token : (0)
344 UTIL_rev_addr :: token : (0)
345 UTIL_rev_addr :: token : (2)
346 UTIL_free :: Free address 0x8060b38 by UTIL_rev_addr on line 1528 (util.c)
347 UTIL_rev_addr :: Returning reversed ip: 2.0.0.10.in-addr.arpa
348 UTIL_ptr_cmp :: address: 2.0.0.10.in-addr.arpa
349 UTIL_strndup :: Allocated 10 bytes of memory.
350 UTIL_strndup :: Returning string: (uhfco.net)
351 DNS_query :: Called with (2.0.0.10.in-addr.arpa) and type: 12
352 UTIL_assoc_prefix :: (QID: 1) :: Stored SPF_NONE (1) (1)
353 DNS_query :: policy result: (none) from rule (ptr)
354 UTIL_ptr_cmp :: PTR lookup failed: (none) (policy result: (none) from rule (ptr)
355 )
356 UTIL_free :: Free address 0x8061918 by UTIL_ptr_cmp on line 955 (util.c)
357 UTIL_free :: Free address 0x8060b38 by UTIL_ptr_cmp on line 956 (util.c)
358 UTIL_free :: Free address 0x8060488 by SPF_parse_policy on line 860 (main.c)
359 UTIL_index :: Found search char: ( ); Returning: (15)
360 UTIL_strndup :: Allocated 16 bytes of memory.
361 UTIL_strndup :: Returning string: (ip4:24.207.1.85)
362 UTIL_is_spf_result :: Called with char (i)
363 UTIL_get_policy_mech :: Called with: (ip4:24.207.1.85)
364 UTIL_get_policy_mech :: Returning 7 (IP4)
365 UTIL_expand_ip :: Called with string: (ip4:24.207.1.85)
366 UTIL_index :: Found search char: (:); Returning: (3)
367 UTIL_expand_ip :: Unable to get position on token (24.207.1.85), assuming /32 cidr block
368 UTIL_strndup :: Allocated 12 bytes of memory.
369 UTIL_strndup :: Returning string: (24.207.1.85)
370 UTIL_free :: Free address 0x8060b38 by UTIL_expand_ip on line 1429 (util.c)
371 UTIL_expand_ip :: CIDR: (32) IP: (24.207.1.85)
372 SPF_parse_policy :: (QID: 1) :: POL: 1426181912 (ip4:24.207.1.85) PEER: 33554442 (10.0.0.2)
373 UTIL_cidr_cmp :: POL: 1426181912 PEER: 33554442 CIDR: 32
374 UTIL_cidr_cmp :: 33554442 and 1426181912 using 32 cidr do not match
375 UTIL_free :: Free address 0x8060488 by SPF_parse_policy on line 717 (main.c)
376 UTIL_free :: Free address 0x80605b8 by SPF_parse_policy on line 860 (main.c)
377 UTIL_index :: Found search char: ( ); Returning: (19)
378 UTIL_strndup :: Allocated 20 bytes of memory.
379 UTIL_strndup :: Returning string: (ip4:24.207.0.192/26)
380 UTIL_is_spf_result :: Called with char (i)
381 UTIL_get_policy_mech :: Called with: (ip4:24.207.0.192/26)
382 UTIL_get_policy_mech :: Returning 7 (IP4)
383 UTIL_expand_ip :: Called with string: (ip4:24.207.0.192/26)
384 UTIL_index :: Found search char: (:); Returning: (3)
385 UTIL_index :: Found search char: (/); Returning: (12)
386 UTIL_strndup :: Allocated 13 bytes of memory.
387 UTIL_strndup :: Returning string: (24.207.0.192)
388 UTIL_free :: Free address 0x8061900 by UTIL_expand_ip on line 1429 (util.c)
389 UTIL_expand_ip :: CIDR: (26) IP: (24.207.0.192)
390 SPF_parse_policy :: (QID: 1) :: POL: 3221278488 (ip4:24.207.0.192/26) PEER: 33554442 (10.0.0.2)
391 UTIL_cidr_cmp :: POL: 3221278488 PEER: 33554442 CIDR: 26
392 UTIL_free :: Free address 0x8060488 by SPF_parse_policy on line 717 (main.c)
393 UTIL_free :: Free address 0x80605b8 by SPF_parse_policy on line 860 (main.c)
394 UTIL_index :: Found search char: ( ); Returning: (13)
395 UTIL_strndup :: Allocated 14 bytes of memory.
396 UTIL_strndup :: Returning string: (a:cccp.6o4.ca)
397 UTIL_is_spf_result :: Called with char (a)
398 UTIL_get_policy_mech :: Called with: (a:cccp.6o4.ca)
399 UTIL_get_policy_mech :: Returning 4 (A)
400 UTIL_a_cmp :: Called with (a:cccp.6o4.ca) and cidr: 32
401 UTIL_strndup :: Allocated 14 bytes of memory.
402 UTIL_strndup :: Returning string: (a:cccp.6o4.ca)
403 UTIL_index :: Found search char: (:); Returning: (1)
404 UTIL_a_cmp :: Checking IP: 1203327256
405 UTIL_cidr_cmp :: POL: 1203327256 PEER: 33554442 CIDR: 32
406 UTIL_cidr_cmp :: 33554442 and 1203327256 using 32 cidr do not match
407 UTIL_free :: Free address 0x8060488 by UTIL_a_cmp on line 891 (util.c)
408 UTIL_free :: Free address 0x8061900 by UTIL_a_cmp on line 892 (util.c)
409 UTIL_free :: Free address 0x80605b8 by SPF_parse_policy on line 860 (main.c)
410 UTIL_index :: Found search char: ( ); Returning: (15)
411 UTIL_strndup :: Allocated 16 bytes of memory.
412 UTIL_strndup :: Returning string: (a:moscow.6o4.ca)
413 UTIL_is_spf_result :: Called with char (a)
414 UTIL_get_policy_mech :: Called with: (a:moscow.6o4.ca)
415 UTIL_get_policy_mech :: Returning 4 (A)
416 UTIL_a_cmp :: Called with (a:moscow.6o4.ca) and cidr: 32
417 UTIL_strndup :: Allocated 16 bytes of memory.
418 UTIL_strndup :: Returning string: (a:moscow.6o4.ca)
419 UTIL_index :: Found search char: (:); Returning: (1)
420 UTIL_a_cmp :: Checking IP: 3272857807
421 UTIL_cidr_cmp :: POL: 3272857807 PEER: 33554442 CIDR: 32
422 UTIL_cidr_cmp :: 33554442 and 3272857807 using 32 cidr do not match
423 UTIL_free :: Free address 0x8060488 by UTIL_a_cmp on line 891 (util.c)
424 UTIL_free :: Free address 0x8061900 by UTIL_a_cmp on line 892 (util.c)
425 UTIL_free :: Free address 0x80605b8 by SPF_parse_policy on line 860 (main.c)
426 UTIL_index :: Found search char: ( ); Returning: (20)
427 UTIL_strndup :: Allocated 21 bytes of memory.
428 UTIL_strndup :: Returning string: (a:tidy.obscurity.org)
429 UTIL_is_spf_result :: Called with char (a)
430 UTIL_get_policy_mech :: Called with: (a:tidy.obscurity.org)
431 UTIL_get_policy_mech :: Returning 4 (A)
432 UTIL_a_cmp :: Called with (a:tidy.obscurity.org) and cidr: 32
433 UTIL_strndup :: Allocated 21 bytes of memory.
434 UTIL_strndup :: Returning string: (a:tidy.obscurity.org)
435 UTIL_index :: Found search char: (:); Returning: (1)
436 UTIL_a_cmp :: Checking IP: 2561197890
437 UTIL_cidr_cmp :: POL: 2561197890 PEER: 33554442 CIDR: 32
438 UTIL_cidr_cmp :: 33554442 and 2561197890 using 32 cidr do not match
439 UTIL_free :: Free address 0x8060488 by UTIL_a_cmp on line 891 (util.c)
440 UTIL_free :: Free address 0x8061918 by UTIL_a_cmp on line 892 (util.c)
441 UTIL_free :: Free address 0x8060590 by SPF_parse_policy on line 860 (main.c)
442 UTIL_index :: Found search char: ( ); Returning: (4)
443 UTIL_strndup :: Allocated 5 bytes of memory.
444 UTIL_strndup :: Returning string: (?all)
445 UTIL_is_spf_result :: Called with char (?)
446 UTIL_get_mech_prefix :: (QID: 1) :: Returning SPF_NEUTRAL (?all) 5
447 UTIL_get_policy_mech :: Called with: (all)
448 UTIL_get_policy_mech :: Returning 2 (ALL)
449 UTIL_assoc_prefix :: (QID: 1) :: Stored SPF_NEUTRAL (5) (5)
450 UTIL_free :: Free address 0x8060488 by SPF_parse_policy on line 860 (main.c)
451 UTIL_assoc_prefix :: (QID: 1) :: Entering function (5) (?all)
452 UTIL_assoc_prefix :: (QID: 1) :: Stored SPF_NEUTRAL (5) (5)
453 UTIL_free :: Free address 0x8060520 by SPF_parse_policy on line 868 (main.c)
454 UTIL_free :: Free address 0x80604b0 by SPF_policy_main_rec on line 331 (main.c)
455 UTIL_strndup :: Allocated 69 bytes of memory.
456 UTIL_strndup :: Returning string: (See http://spf.pobox.com/why.html?sender=%{S}&ip=%{I}&receiver=%{xR})
457 UTIL_index :: Found search char: (%); Returning: (41)
458 MACRO_addbuf :: Called with (See http://spf.pobox.com/why.html?sender=) 42 (41) bytes.
459 MACRO_addbuf :: Added (See http://spf.pobox.com/why.html?sender=) to node of len: 42)
460 MACRO_expand :: Freeing s_macro temp buf (See http://spf.pobox.com/why.html?sender=)
461 UTIL_free :: Free address 0x8060500 by MACRO_expand on line 242 (macro.c)
462 MACRO_expand :: Remaining buffer (%{S}&ip=%{I}&receiver=%{xR})
463 UTIL_index :: Found search char: (}); Returning: (1)
464 MACRO_expand :: Actual macro (S)
465 MACRO_process :: 's' expands to: (jcouzens@uhfco.net)
466 UTIL_strndup :: Allocated 20 bytes of memory.
467 UTIL_strndup :: Returning string: (jcouzens@uhfco.net)
468 MACRO_expand :: Macro expanded to: (jcouzens@uhfco.net) 18 bytes
469 MACRO_addbuf :: Called with (jcouzens@uhfco.net) 18 (18) bytes.
470 MACRO_addbuf :: Added (jcouzens@uhfco.net) to node of len: 18)
471 UTIL_free :: Free address 0x8061900 by MACRO_expand on line 162 (macro.c)
472 MACRO_expand :: Remaining buffer (&ip=%{I}&receiver=%{xR})
473 UTIL_index :: Found search char: (%); Returning: (4)
474 MACRO_addbuf :: Called with (&ip=) 5 (4) bytes.
475 MACRO_addbuf :: Added (&ip=) to node of len: 5)
476 MACRO_expand :: Freeing s_macro temp buf (&ip=)
477 UTIL_free :: Free address 0x8061938 by MACRO_expand on line 242 (macro.c)
478 MACRO_expand :: Remaining buffer (%{I}&receiver=%{xR})
479 UTIL_index :: Found search char: (}); Returning: (1)
480 MACRO_expand :: Actual macro (I)
481 MACRO_process :: 'i' expands to: (10.0.0.2)
482 UTIL_strndup :: Allocated 9 bytes of memory.
483 UTIL_strndup :: Returning string: (10.0.0.2)
484 MACRO_expand :: Macro expanded to: (10.0.0.2) 8 bytes
485 MACRO_addbuf :: Called with (10.0.0.2) 8 (8) bytes.
486 MACRO_addbuf :: Added (10.0.0.2) to node of len: 8)
487 UTIL_free :: Free address 0x8061938 by MACRO_expand on line 162 (macro.c)
488 MACRO_expand :: Remaining buffer (&receiver=%{xR})
489 UTIL_index :: Found search char: (%); Returning: (10)
490 MACRO_addbuf :: Called with (&receiver=) 11 (10) bytes.
491 MACRO_addbuf :: Added (&receiver=) to node of len: 11)
492 MACRO_expand :: Freeing s_macro temp buf (&receiver=)
493 UTIL_free :: Free address 0x8061938 by MACRO_expand on line 242 (macro.c)
494 MACRO_expand :: Remaining buffer (%{xR})
495 UTIL_index :: Found search char: (}); Returning: (2)
496 MACRO_expand :: Actual macro (xR)
497 UTIL_strndup :: Allocated 9 bytes of memory.
498 UTIL_strndup :: Returning string: (spfquery)
499 MACRO_expand :: Macro expanded to: (spfquery) 8 bytes
500 MACRO_addbuf :: Called with (spfquery) 8 (8) bytes.
501 MACRO_addbuf :: Added (spfquery) to node of len: 8)
502 UTIL_free :: Free address 0x8061938 by MACRO_expand on line 162 (macro.c)
503 MACRO_expand :: Remaining buffer ()
504 MACRO_expand :: NODE: (See http://spf.pobox.com/why.html?sender=) LEN: 42
505 UTIL_free :: Free address 0x8060530 by MACRO_expand on line 267 (macro.c)
506 UTIL_free :: Free address 0x8060b38 by MACRO_expand on line 269 (macro.c)
507 MACRO_expand :: NODE: (jcouzens@uhfco.net) LEN: 18
508 UTIL_free :: Free address 0x8060570 by MACRO_expand on line 267 (macro.c)
509 UTIL_free :: Free address 0x8060560 by MACRO_expand on line 269 (macro.c)
510 MACRO_expand :: NODE: (&ip=) LEN: 5
511 UTIL_free :: Free address 0x8061958 by MACRO_expand on line 267 (macro.c)
512 UTIL_free :: Free address 0x8061948 by MACRO_expand on line 269 (macro.c)
513 MACRO_expand :: NODE: (10.0.0.2) LEN: 8
514 UTIL_free :: Free address 0x8061978 by MACRO_expand on line 267 (macro.c)
515 UTIL_free :: Free address 0x8061968 by MACRO_expand on line 269 (macro.c)
516 MACRO_expand :: NODE: (&receiver=) LEN: 11
517 UTIL_free :: Free address 0x8061998 by MACRO_expand on line 267 (macro.c)
518 UTIL_free :: Free address 0x8061988 by MACRO_expand on line 269 (macro.c)
519 MACRO_expand :: NODE: (spfquery) LEN: 8
520 UTIL_free :: Free address 0x80619b8 by MACRO_expand on line 267 (macro.c)
521 UTIL_free :: Free address 0x80619a8 by MACRO_expand on line 269 (macro.c)
522 UTIL_free :: Free address 0x80604b0 by MACRO_expand on line 272 (macro.c)
523 UTIL_free :: Free address 0x8060488 by MACRO_expand on line 273 (macro.c)
524 MACRO_expand :: Returning expanded macro: (See http://spf.pobox.com/why.html?sender=jcouzens@uhfco.net&ip=10.0.0.2&receiver=spfquery)
525 SPF_parse_policy :: (QID: 1) :: redirect returned result 5 (?all)
526 UTIL_free :: Free address 0x8060498 by SPF_parse_policy on line 860 (main.c)
527 UTIL_free :: Free address 0x8060468 by SPF_parse_policy on line 873 (main.c)
528 UTIL_free :: Free address 0x8060448 by SPF_policy_main_rec on line 331 (main.c)
529 neutral
530 policy result: (neutral) from rule (?all)
531
532 See http://spf.pobox.com/why.html?sender=jcouzens@uhfco.net&ip=10.0.0.2&receiver=spfquery
533 UTIL_free :: Free address 0x8060378 by SPF_close on line 219 (main.c)
534 UTIL_free :: Free address 0x80603c8 by SPF_close on line 220 (main.c)
535 UTIL_free :: Free address 0x80603e0 by SPF_close on line 221 (main.c)
536 UTIL_free :: Free address 0x80603f8 by SPF_close on line 222 (main.c)
537 UTIL_free :: Free address 0x8060388 by SPF_close on line 223 (main.c)
538 UTIL_free :: Unable to free() on NULL pointer at main.c:224 in SPF_close; address 0x0.
539 UTIL_free :: Free address 0x80605b8 by SPF_close on line 225 (main.c)
540 UTIL_free :: Free address 0x8060348 by SPF_close on line 226 (main.c)
541 UTIL_free :: Free address 0x8060328 by SPF_close on line 227 (main.c)
542 UTIL_free :: Free address 0x80619c8 by SPF_close on line 228 (main.c)
543 UTIL_free :: Free address 0x8060398 by SPF_close on line 229 (main.c)
544 UTIL_free :: Free address 0x8060050 by SPF_close on line 231 (main.c)
545
546 xpprintf: profile debugging output - Profiling output has been removed in favour of using a substantially more powerful and accurate system profiler.