Mercurial > dnsbl

comparison src/context.cpp @ 314:ef5a6099cbe7 stable-6-0-46

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
enable smtp verify logging
author Carl Byington <carl@five-ten-sg.com>
date Mon, 19 Sep 2016 13:15:02 -0700
parents f5547e7b3a09
children f7c5cfb76e86
comparison
equal deleted inserted replaced
313:68af9ca42ead 314:ef5a6099cbe7
90 const time_t ERROR_SMTP_SOCKET_TIME = 600; // number of seconds between attempts to open a socket to an smtp server 90 const time_t ERROR_SMTP_SOCKET_TIME = 600; // number of seconds between attempts to open a socket to an smtp server
91 91
92 92
93 int SMTP::writer() { 93 int SMTP::writer() {
94 #ifdef VERIFY_DEBUG 94 #ifdef VERIFY_DEBUG
95 log("writer() sees buffer with %s", buffer); 95 log("writer(%d) sees buffer with %s", buffer);
96 log("writer() sees error %d", (int)error); 96 log("writer(%d) sees error %d", (int)error);
97 #endif 97 #endif
98 int rs = 0; 98 int rs = 0;
99 if (!error) { 99 if (!error) {
100 int len = strlen(buffer); 100 int len = strlen(buffer);
101 while (rs < len) { 101 while (rs < len) {
117 117
118 int SMTP::reader() { 118 int SMTP::reader() {
119 // read some bytes terminated by lf or end of buffer. 119 // read some bytes terminated by lf or end of buffer.
120 // we may have a multi line response or part thereof in the buffer. 120 // we may have a multi line response or part thereof in the buffer.
121 #ifdef VERIFY_DEBUG 121 #ifdef VERIFY_DEBUG
122 log("reader() sees error %d", (int)error); 122 log("reader(%d) sees error %d", (int)error);
123 #endif 123 #endif
124 if (error) return 0; 124 if (error) return 0;
125 int len = maxlen-1; // room for null terminator 125 int len = maxlen-1; // room for null terminator
126 while (pending < len) { 126 while (pending < len) {
127 int ws = read(fd, buffer+pending, len-pending); 127 int ws = read(fd, buffer+pending, len-pending);
136 break; 136 break;
137 } 137 }
138 } 138 }
139 buffer[pending] = '\0'; 139 buffer[pending] = '\0';
140 #ifdef VERIFY_DEBUG 140 #ifdef VERIFY_DEBUG
141 log("reader() sees buffer with %s", buffer); 141 log("reader(%d) sees buffer with %s", buffer);
142 #endif 142 #endif
143 return pending; 143 return pending;
144 } 144 }
145 145
146 146
165 pending = 0; 165 pending = 0;
166 buffer[pending] = '\0'; 166 buffer[pending] = '\0';
167 while (true) { 167 while (true) {
168 int r = read_line(); 168 int r = read_line();
169 #ifdef VERIFY_DEBUG 169 #ifdef VERIFY_DEBUG
170 log("read_response() sees line with %s", buffer); 170 log("read_response(%d) sees line with %s", buffer);
171 log("read_response() sees line length %d", r); 171 log("read_response(%d) sees line length %d", r);
172 #endif 172 #endif
173 if (r == 0) return 0; // failed to read any bytes 173 if (r == 0) return 0; // failed to read any bytes
174 if ((r > 4) && (buffer[3] == '-')) { 174 if ((r > 4) && (buffer[3] == '-')) {
175 flush_line(r); 175 flush_line(r);
176 continue; 176 continue;
177 } 177 }
178 log("read_response() sees line with %s", buffer); 178 log("verify::read_response(%d) sees line with %s", buffer);
179 return atoi(buffer); 179 return atoi(buffer);
180 } 180 }
181 return 0; 181 return 0;
182 } 182 }
183 183
248 } 248 }
249 249
250 250
251 void SMTP::log(const char *m, int v) { 251 void SMTP::log(const char *m, int v) {
252 char buf[maxlen]; 252 char buf[maxlen];
253 snprintf(buf, maxlen, m, v); 253 snprintf(buf, maxlen, m, get_fd(), v);
254 my_syslog(queueid, buf); 254 my_syslog(queueid, buf);
255 } 255 }
256 256
257 257
258 void SMTP::log(const char *m, const char *v) { 258 void SMTP::log(const char *m, const char *v) {
259 char buf[maxlen]; 259 char buf[maxlen];
260 snprintf(buf, maxlen, m, v); 260 snprintf(buf, maxlen, m, get_fd(), v);
261 my_syslog(queueid, buf); 261 my_syslog(queueid, buf);
262 } 262 }
263 263
264 264
265 //////////////////////////////////////////////// 265 ////////////////////////////////////////////////
294 } 294 }
295 pthread_mutex_unlock(&mutex); 295 pthread_mutex_unlock(&mutex);
296 // avoid doing this work inside the mutex lock 296 // avoid doing this work inside the mutex lock
297 if (conn) { 297 if (conn) {
298 #ifdef VERIFY_DEBUG 298 #ifdef VERIFY_DEBUG
299 conn->log("closer() closes ancient %d", conn->get_fd()); 299 conn->log("closer(%d) closes ancient socket %s", "");
300 #endif 300 #endif
301 delete conn; 301 delete conn;
302 } 302 }
303 } 303 }
304 } 304 }
305 305
306 306
307 SMTP* VERIFY::get_connection(const char *queueid) { 307 SMTP* VERIFY::get_connection(const char *queueid) {
308 SMTP *conn = NULL; 308 SMTP *conn = NULL;
309 pthread_mutex_lock(&mutex); 309 pthread_mutex_lock(&mutex);
310 if (!connections.empty()) { 310 while (!connections.empty()) {
311 conn = connections.front(); 311 conn = connections.front();
312 conn->set_id(queueid); 312 time_t now = time(NULL);
313 connections.pop_front(); 313 if ((now - conn->get_stamp()) > maxsmtp_age) {
314 #ifdef VERIFY_DEBUG 314 // this connection is ancient, remove it
315 conn->log("get_connection() %d from cache", conn->get_fd()); 315 conn->log("verify::get_connection(%d) closes ancient socket %s", "");
316 #endif 316 connections.pop_front();
317 delete conn;
318 conn = NULL;
319 }
320 else {
321 conn->set_id(queueid);
322 connections.pop_front();
323 #ifdef VERIFY_DEBUG
324 conn->log("verify::get_connection(%d) from cache %s", "");
325 #endif
326 break;
327 }
317 } 328 }
318 pthread_mutex_unlock(&mutex); 329 pthread_mutex_unlock(&mutex);
319 if (conn) return conn; 330 if (conn) return conn;
320 int sock = NULL_SOCKET; 331 int sock = NULL_SOCKET;
321 if ((time(NULL) - last_err) > ERROR_SMTP_SOCKET_TIME) { 332 if ((time(NULL) - last_err) > ERROR_SMTP_SOCKET_TIME) {
339 else last_err = time(NULL); 350 else last_err = time(NULL);
340 } 351 }
341 else last_err = time(NULL); 352 else last_err = time(NULL);
342 } 353 }
343 if (sock != NULL_SOCKET) { 354 if (sock != NULL_SOCKET) {
355 struct timeval tv;
356 tv.tv_sec = 15;
357 tv.tv_usec = 0;
358 setsockopt(sock, SOL_SOCKET, SO_RCVTIMEO, (char *)&tv, sizeof(struct timeval));
344 conn = new SMTP(sock); 359 conn = new SMTP(sock);
345 conn->set_id(queueid); 360 conn->set_id(queueid);
346 #ifdef VERIFY_DEBUG 361 #ifdef VERIFY_DEBUG
347 conn->log("get_connection() %d new socket", conn->get_fd()); 362 conn->log("get_connection(%d) new socket %s", "");
348 #endif 363 #endif
349 int rc = conn->helo(); 364 int rc = conn->helo();
350 conn->log("verify::get_connection() helo sees %d", rc); 365 conn->log("verify::get_connection(%d) helo sees %d", rc);
351 if (rc == 250) return conn; 366 if (rc == 250) return conn;
352 delete conn; 367 delete conn;
353 } 368 }
354 return NULL; 369 return NULL;
355 } 370 }
356 371
357 372
358 void VERIFY::put_connection(SMTP *conn) { 373 void VERIFY::put_connection(SMTP *conn) {
359 if (conn->err()) { 374 if (conn->err()) {
360 #ifdef VERIFY_DEBUG 375 #ifdef VERIFY_DEBUG
361 conn->log("put_socket() %d with error, close it", conn->get_fd()); 376 conn->log("put_socket(%d) with error %s", "");
362 #endif 377 #endif
363 delete conn; 378 delete conn;
364 last_err = time(NULL);
365 } 379 }
366 else { 380 else {
367 #ifdef VERIFY_DEBUG 381 #ifdef VERIFY_DEBUG
368 conn->log("put_socket() %d", conn->get_fd()); 382 conn->log("put_socket(%d) no error %s", "");
369 #endif 383 #endif
370 conn->now(); 384 conn->now();
371 pthread_mutex_lock(&mutex); 385 pthread_mutex_lock(&mutex);
372 connections.push_back(conn); 386 connections.push_back(conn);
373 pthread_mutex_unlock(&mutex); 387 pthread_mutex_unlock(&mutex);
379 if (host == token_myhostname) return true; 393 if (host == token_myhostname) return true;
380 SMTP *conn = get_connection(queueid); 394 SMTP *conn = get_connection(queueid);
381 if (!conn) return true; // cannot verify right now, we have socket errors 395 if (!conn) return true; // cannot verify right now, we have socket errors
382 int rc; 396 int rc;
383 rc = conn->from(from); 397 rc = conn->from(from);
384 conn->log("verify::ok() from sees %d", rc); 398 conn->log("verify::ok(%d) from sees %d", rc);
385 if (rc != 250) { 399 if (rc != 250) {
386 put_connection(conn); 400 put_connection(conn);
387 return (rc >= 500) ? false : true; 401 return (rc >= 500) ? false : true;
388 } 402 }
389 rc = conn->rcpt(to); 403 rc = conn->rcpt(to);
390 conn->log("verify::ok() rcpt sees %d", rc); 404 conn->log("verify::ok(%d) rcpt sees %d", rc);
391 put_connection(conn); 405 put_connection(conn);
392 return (rc >= 500) ? false : true; 406 return (rc >= 500) ? false : true;
393 } 407 }
394 408
395 409