Browse code

core: tcp - more details on error log messages

Daniel-Constantin Mierla authored on 03/07/2020 08:49:43
Showing 2 changed files
... ...
@@ -415,13 +415,13 @@ inline static int io_watch_add(	io_wait_h* h,
415 415
 			 */
416 416
 			/* set async & signal */
417 417
 			if (fcntl(fd, F_SETOWN, my_pid())==-1){
418
-				LM_ERR("fnctl: SETOWN failed: %s [%d]\n",
419
-					strerror(errno), errno);
418
+				LM_ERR("fnctl: SETOWN on fd %d failed: %s [%d]\n",
419
+					fd, strerror(errno), errno);
420 420
 				goto error;
421 421
 			}
422 422
 			if (fcntl(fd, F_SETSIG, h->signo)==-1){
423
-				LM_ERR("fnctl: SETSIG failed: %s [%d]\n",
424
-					strerror(errno), errno);
423
+				LM_ERR("fnctl: SETSIG on fd %d failed: %s [%d]\n",
424
+					fd, strerror(errno), errno);
425 425
 				goto error;
426 426
 			}
427 427
 			/* set both non-blocking and async */
... ...
@@ -455,7 +455,8 @@ again1:
455 455
 			n=epoll_ctl(h->epfd, EPOLL_CTL_ADD, fd, &ep_event);
456 456
 			if (unlikely(n==-1)){
457 457
 				if (errno==EAGAIN) goto again1;
458
-				LM_ERR("epoll_ctl failed: %s [%d]\n", strerror(errno), errno);
458
+				LM_ERR("epoll_ctl on fd %d failed: %s [%d]\n",
459
+						fd, strerror(errno), errno);
459 460
 				goto error;
460 461
 			}
461 462
 			break;
... ...
@@ -475,7 +476,8 @@ again2:
475 476
 			n=epoll_ctl(h->epfd, EPOLL_CTL_ADD, fd, &ep_event);
476 477
 			if (unlikely(n==-1)){
477 478
 				if (errno==EAGAIN) goto again2;
478
-				LM_ERR("epoll_ctl failed: %s [%d]\n", strerror(errno), errno);
479
+				LM_ERR("epoll_ctl on fd %d failed: %s [%d]\n",
480
+						fd, strerror(errno), errno);
479 481
 				goto error;
480 482
 			}
481 483
 			break;
... ...
@@ -505,8 +507,8 @@ again2:
505 507
 again_devpoll:
506 508
 			if (write(h->dpoll_fd, &pfd, sizeof(pfd))==-1){
507 509
 				if (errno==EAGAIN) goto again_devpoll;
508
-				LM_ERR("/dev/poll write failed: %s [%d]\n",
509
-					strerror(errno), errno);
510
+				LM_ERR("/dev/poll write of fd %d failed: %s [%d]\n",
511
+					fd, strerror(errno), errno);
510 512
 				goto error;
511 513
 			}
512 514
 			break;
... ...
@@ -532,7 +534,8 @@ check_io_again:
532 534
 				(pf.revents & (e->events|POLLERR|POLLHUP)));
533 535
 		if (unlikely(e->type && (n==-1))){
534 536
 			if (errno==EINTR) goto check_io_again;
535
-			LM_ERR("check_io poll: %s [%d]\n", strerror(errno), errno);
537
+			LM_ERR("check_io poll on fd %d failed: %s [%d]\n",
538
+					fd, strerror(errno), errno);
536 539
 		}
537 540
 	}
538 541
 #endif
... ...
@@ -637,13 +640,13 @@ inline static int io_watch_del(io_wait_h* h, int fd, int idx, int flags)
637 640
 				/* reset ASYNC */
638 641
 				fd_flags=fcntl(fd, F_GETFL);
639 642
 				if (unlikely(fd_flags==-1)){
640
-					LM_ERR("fnctl: GETFL failed: %s [%d]\n",
641
-						strerror(errno), errno);
643
+					LM_ERR("fnctl: GETFL on fd %d failed: %s [%d]\n",
644
+						fd, strerror(errno), errno);
642 645
 					goto error;
643 646
 				}
644 647
 				if (unlikely(fcntl(fd, F_SETFL, fd_flags&(~O_ASYNC))==-1)){
645
-					LM_ERR("fnctl: SETFL failed: %s [%d]\n",
646
-						strerror(errno), errno);
648
+					LM_ERR("fnctl: SETFL on fd %d failed: %s [%d]\n",
649
+						fd, strerror(errno), errno);
647 650
 					goto error;
648 651
 				}
649 652
 			fix_fd_array; /* only on success */
... ...
@@ -664,8 +667,8 @@ again_epoll:
664 667
 				n=epoll_ctl(h->epfd, EPOLL_CTL_DEL, fd, &ep_event);
665 668
 				if (unlikely(n==-1)){
666 669
 					if (errno==EAGAIN) goto again_epoll;
667
-					LM_ERR("removing fd from epoll list failed: %s [%d]\n",
668
-						strerror(errno), errno);
670
+					LM_ERR("removing fd %d from epoll list failed: %s [%d]\n",
671
+						fd, strerror(errno), errno);
669 672
 					goto error;
670 673
 				}
671 674
 #ifdef EPOLL_NO_CLOSE_BUG
... ...
@@ -704,8 +707,8 @@ again_epoll:
704 707
 again_devpoll:
705 708
 				if (write(h->dpoll_fd, &pfd, sizeof(pfd))==-1){
706 709
 					if (errno==EINTR) goto again_devpoll;
707
-					LM_ERR("removing fd from /dev/poll failed: %s [%d]\n",
708
-						strerror(errno), errno);
710
+					LM_ERR("removing fd %d from /dev/poll failed: %s [%d]\n",
711
+						fd, strerror(errno), errno);
709 712
 					goto error;
710 713
 				}
711 714
 				break;
... ...
@@ -831,8 +834,8 @@ again_epoll_lt:
831 834
 				n=epoll_ctl(h->epfd, EPOLL_CTL_MOD, fd, &ep_event);
832 835
 				if (unlikely(n==-1)){
833 836
 					if (errno==EAGAIN) goto again_epoll_lt;
834
-					LM_ERR("modifying epoll events failed: %s [%d]\n",
835
-						strerror(errno), errno);
837
+					LM_ERR("modifying epoll events of fd %d failed: %s [%d]\n",
838
+						fd, strerror(errno), errno);
836 839
 					goto error;
837 840
 				}
838 841
 			break;
... ...
@@ -851,8 +854,8 @@ again_epoll_et:
851 854
 				n=epoll_ctl(h->epfd, EPOLL_CTL_MOD, fd, &ep_event);
852 855
 				if (unlikely(n==-1)){
853 856
 					if (errno==EAGAIN) goto again_epoll_et;
854
-					LM_ERR("modifying epoll events failed: %s [%d]\n",
855
-						strerror(errno), errno);
857
+					LM_ERR("modifying epoll events of fd %d failed: %s [%d]\n",
858
+						fd, strerror(errno), errno);
856 859
 					goto error;
857 860
 				}
858 861
 			break;
... ...
@@ -887,8 +890,8 @@ again_epoll_et:
887 890
 again_devpoll1:
888 891
 				if (unlikely(write(h->dpoll_fd, &pfd, sizeof(pfd))==-1)){
889 892
 					if (errno==EINTR) goto again_devpoll1;
890
-					LM_ERR("removing fd from /dev/poll failed: %s [%d]\n",
891
-								strerror(errno), errno);
893
+					LM_ERR("removing fd %d from /dev/poll failed: %s [%d]\n",
894
+								fd, strerror(errno), errno);
892 895
 					goto error;
893 896
 				}
894 897
 again_devpoll2:
... ...
@@ -896,8 +899,8 @@ again_devpoll2:
896 899
 				pfd.revents=0;
897 900
 				if (unlikely(write(h->dpoll_fd, &pfd, sizeof(pfd))==-1)){
898 901
 					if (errno==EINTR) goto again_devpoll2;
899
-					LM_ERR("re-adding fd to /dev/poll failed: %s [%d]\n",
900
-								strerror(errno), errno);
902
+					LM_ERR("re-adding fd %d to /dev/poll failed: %s [%d]\n",
903
+								fd, strerror(errno), errno);
901 904
 					/* error re-adding the fd => mark it as removed/unhash */
902 905
 					unhash_fd_map(e);
903 906
 					goto error;
... ...
@@ -1846,8 +1846,11 @@ repeat_1st_read:
1846 1846
 			if (unlikely(con->state==S_CONN_BAD)){
1847 1847
 				resp=CONN_ERROR;
1848 1848
 				if (!(con->send_flags.f & SND_F_CON_CLOSE))
1849
-					LM_WARN("F_TCPCONN connection marked as bad: %p id %d refcnt %d\n",
1850
-							con, con->id, atomic_get(&con->refcnt));
1849
+					LM_WARN("F_TCPCONN connection marked as bad: %p id %d fd %d"
1850
+							" refcnt %d ([%s]:%u -> [%s]:%u)\n",
1851
+							con, con->id, con->fd, atomic_get(&con->refcnt),
1852
+							ip_addr2a(&con->rcv.src_ip), con->rcv.src_port,
1853
+							ip_addr2a(&con->rcv.dst_ip), con->rcv.dst_port);
1851 1854
 				goto read_error;
1852 1855
 			}
1853 1856
 			read_flags=((