Mercurial > hg > freeDiameter

comparison libfdproto/messages.c @ 687:026802543f57

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
Prepare for new message log facility
author Sebastien Decugis <sdecugis@nict.go.jp>
date Wed, 19 Jan 2011 17:08:21 +0900
parents f83d9878bf66
children 8c3dc8584dab
comparison
equal deleted inserted replaced
686:f83d9878bf66 687:026802543f57
658 /* indent inside an object */ 658 /* indent inside an object */
659 #define INOBJHDR "%*s " 659 #define INOBJHDR "%*s "
660 #define INOBJHDRVAL indent<0 ? 1 : indent, indent<0 ? "-" : "|" 660 #define INOBJHDRVAL indent<0 ? 1 : indent, indent<0 ? "-" : "|"
661 661
662 /* Dump a msg_t object */ 662 /* Dump a msg_t object */
663 static void obj_dump_msg (struct msg * msg, int indent ) 663 static void obj_dump_msg (struct msg * msg, int indent, FILE * fstr )
664 { 664 {
665 int ret = 0; 665 int ret = 0;
666 666
667 fd_log_debug("%*sMSG: %p\n", INOBJHDRVAL, msg); 667 fd_log_debug_fstr(fstr, "%*sMSG: %p\n", INOBJHDRVAL, msg);
668 668
669 if (!CHECK_MSG(msg)) { 669 if (!CHECK_MSG(msg)) {
670 fd_log_debug(INOBJHDR "INVALID!\n", INOBJHDRVAL); 670 fd_log_debug_fstr(fstr, INOBJHDR "INVALID!\n", INOBJHDRVAL);
671 return; 671 return;
672 } 672 }
673 673
674 if (!msg->msg_model) { 674 if (!msg->msg_model) {
675 675
676 fd_log_debug(INOBJHDR "(no model)\n", INOBJHDRVAL); 676 fd_log_debug_fstr(fstr, INOBJHDR "(no model)\n", INOBJHDRVAL);
677 677
678 } else { 678 } else {
679 679
680 enum dict_object_type dicttype; 680 enum dict_object_type dicttype;
681 struct dict_cmd_data dictdata; 681 struct dict_cmd_data dictdata;
682 ret = fd_dict_gettype(msg->msg_model, &dicttype); 682 ret = fd_dict_gettype(msg->msg_model, &dicttype);
683 if (ret || (dicttype != DICT_COMMAND)) { 683 if (ret || (dicttype != DICT_COMMAND)) {
684 fd_log_debug(INOBJHDR "(invalid model: %d %d)\n", INOBJHDRVAL, ret, dicttype); 684 fd_log_debug_fstr(fstr, INOBJHDR "(invalid model: %d %d)\n", INOBJHDRVAL, ret, dicttype);
685 goto public; 685 goto public;
686 } 686 }
687 ret = fd_dict_getval(msg->msg_model, &dictdata); 687 ret = fd_dict_getval(msg->msg_model, &dictdata);
688 if (ret != 0) { 688 if (ret != 0) {
689 fd_log_debug(INOBJHDR "(error getting model data: %s)\n", INOBJHDRVAL, strerror(ret)); 689 fd_log_debug_fstr(fstr, INOBJHDR "(error getting model data: %s)\n", INOBJHDRVAL, strerror(ret));
690 goto public; 690 goto public;
691 } 691 }
692 fd_log_debug(INOBJHDR "model : v/m:" DUMP_CMDFL_str "/" DUMP_CMDFL_str ", %u \"%s\"\n", INOBJHDRVAL, 692 fd_log_debug_fstr(fstr, INOBJHDR "model : v/m:" DUMP_CMDFL_str "/" DUMP_CMDFL_str ", %u \"%s\"\n", INOBJHDRVAL,
693 DUMP_CMDFL_val(dictdata.cmd_flag_val), DUMP_CMDFL_val(dictdata.cmd_flag_mask), dictdata.cmd_code, dictdata.cmd_name); 693 DUMP_CMDFL_val(dictdata.cmd_flag_val), DUMP_CMDFL_val(dictdata.cmd_flag_mask), dictdata.cmd_code, dictdata.cmd_name);
694 } 694 }
695 public: 695 public:
696 fd_log_debug(INOBJHDR "public: V:%d L:%d fl:" DUMP_CMDFL_str " CC:%u A:%d hi:%x ei:%x\n", INOBJHDRVAL, 696 fd_log_debug_fstr(fstr, INOBJHDR "public: V:%d L:%d fl:" DUMP_CMDFL_str " CC:%u A:%d hi:%x ei:%x\n", INOBJHDRVAL,
697 msg->msg_public.msg_version, 697 msg->msg_public.msg_version,
698 msg->msg_public.msg_length, 698 msg->msg_public.msg_length,
699 DUMP_CMDFL_val(msg->msg_public.msg_flags), 699 DUMP_CMDFL_val(msg->msg_public.msg_flags),
700 msg->msg_public.msg_code, 700 msg->msg_public.msg_code,
701 msg->msg_public.msg_appl, 701 msg->msg_public.msg_appl,
702 msg->msg_public.msg_hbhid, 702 msg->msg_public.msg_hbhid,
703 msg->msg_public.msg_eteid 703 msg->msg_public.msg_eteid
704 ); 704 );
705 fd_log_debug(INOBJHDR "intern: rwb:%p rt:%d cb:%p(%p) qry:%p asso:%d sess:%p src:%s\n", 705 fd_log_debug_fstr(fstr, INOBJHDR "intern: rwb:%p rt:%d cb:%p(%p) qry:%p asso:%d sess:%p src:%s\n",
706 INOBJHDRVAL, msg->msg_rawbuffer, msg->msg_routable, msg->msg_cb.fct, msg->msg_cb.data, msg->msg_query, msg->msg_associated, msg->msg_sess, msg->msg_src_id?:"(nil)"); 706 INOBJHDRVAL, msg->msg_rawbuffer, msg->msg_routable, msg->msg_cb.fct, msg->msg_cb.data, msg->msg_query, msg->msg_associated, msg->msg_sess, msg->msg_src_id?:"(nil)");
707 } 707 }
708 708
709 /* Dump an avp object */ 709 /* Dump an avp object */
710 static void obj_dump_avp ( struct avp * avp, int indent ) 710 static void obj_dump_avp ( struct avp * avp, int indent, FILE * fstr )
711 { 711 {
712 int ret = 0; 712 int ret = 0;
713 enum dict_avp_basetype type = -1; 713 enum dict_avp_basetype type = -1;
714 714
715 if (!CHECK_AVP(avp)) { 715 if (!CHECK_AVP(avp)) {
716 fd_log_debug(INOBJHDR "INVALID!\n", INOBJHDRVAL); 716 fd_log_debug_fstr(fstr, INOBJHDR "INVALID!\n", INOBJHDRVAL);
717 return; 717 return;
718 } 718 }
719 719
720 if (!avp->avp_model) { 720 if (!avp->avp_model) {
721 721
722 fd_log_debug(INOBJHDR "(no model)\n", INOBJHDRVAL); 722 fd_log_debug_fstr(fstr, INOBJHDR "(no model)\n", INOBJHDRVAL);
723 723
724 } else { 724 } else {
725 725
726 enum dict_object_type dicttype; 726 enum dict_object_type dicttype;
727 struct dict_avp_data dictdata; 727 struct dict_avp_data dictdata;
728 ret = fd_dict_gettype(avp->avp_model, &dicttype); 728 ret = fd_dict_gettype(avp->avp_model, &dicttype);
729 if (ret || (dicttype != DICT_AVP)) { 729 if (ret || (dicttype != DICT_AVP)) {
730 fd_log_debug(INOBJHDR "(invalid model: %d %d)\n", INOBJHDRVAL, ret, dicttype); 730 fd_log_debug_fstr(fstr, INOBJHDR "(invalid model: %d %d)\n", INOBJHDRVAL, ret, dicttype);
731 goto public; 731 goto public;
732 } 732 }
733 ret = fd_dict_getval(avp->avp_model, &dictdata); 733 ret = fd_dict_getval(avp->avp_model, &dictdata);
734 if (ret != 0) { 734 if (ret != 0) {
735 fd_log_debug(INOBJHDR "(error getting model data: %s)\n", INOBJHDRVAL, strerror(ret)); 735 fd_log_debug_fstr(fstr, INOBJHDR "(error getting model data: %s)\n", INOBJHDRVAL, strerror(ret));
736 goto public; 736 goto public;
737 } 737 }
738 fd_log_debug(INOBJHDR "model : v/m:" DUMP_AVPFL_str "/" DUMP_AVPFL_str ", %12s, %u \"%s\"\n", INOBJHDRVAL, 738 fd_log_debug_fstr(fstr, INOBJHDR "model : v/m:" DUMP_AVPFL_str "/" DUMP_AVPFL_str ", %12s, %u \"%s\"\n", INOBJHDRVAL,
739 DUMP_AVPFL_val(dictdata.avp_flag_val), 739 DUMP_AVPFL_val(dictdata.avp_flag_val),
740 DUMP_AVPFL_val(dictdata.avp_flag_mask), 740 DUMP_AVPFL_val(dictdata.avp_flag_mask),
741 type_base_name[dictdata.avp_basetype], 741 type_base_name[dictdata.avp_basetype],
742 dictdata.avp_code, 742 dictdata.avp_code,
743 dictdata.avp_name ); 743 dictdata.avp_name );
744 type = dictdata.avp_basetype; 744 type = dictdata.avp_basetype;
745 } 745 }
746 public: 746 public:
747 fd_log_debug(INOBJHDR "public: C:%u fl:" DUMP_AVPFL_str " L:%d V:%u data:@%p\n", INOBJHDRVAL, 747 fd_log_debug_fstr(fstr, INOBJHDR "public: C:%u fl:" DUMP_AVPFL_str " L:%d V:%u data:@%p\n", INOBJHDRVAL,
748 avp->avp_public.avp_code, 748 avp->avp_public.avp_code,
749 DUMP_AVPFL_val(avp->avp_public.avp_flags), 749 DUMP_AVPFL_val(avp->avp_public.avp_flags),
750 avp->avp_public.avp_len, 750 avp->avp_public.avp_len,
751 avp->avp_public.avp_vendor, 751 avp->avp_public.avp_vendor,
752 avp->avp_public.avp_value 752 avp->avp_public.avp_value
753 ); 753 );
754 /* Dump the value if set */ 754 /* Dump the value if set */
755 if (avp->avp_public.avp_value) { 755 if (avp->avp_public.avp_value) {
756 if (!avp->avp_model) { 756 if (!avp->avp_model) {
757 fd_log_debug(INOBJHDR "(data set but no model: ERROR)\n", INOBJHDRVAL); 757 fd_log_debug_fstr(fstr, INOBJHDR "(data set but no model: ERROR)\n", INOBJHDRVAL);
758 } else { 758 } else {
759 fd_dict_dump_avp_value(avp->avp_public.avp_value, avp->avp_model, indent); 759 fd_dict_dump_avp_value(avp->avp_public.avp_value, avp->avp_model, indent, fstr);
760 } 760 }
761 } 761 }
762 762
763 fd_log_debug(INOBJHDR "intern: src:%p mf:%d raw:%p(%d)\n", INOBJHDRVAL, avp->avp_source, avp->avp_mustfreeos, avp->avp_rawdata, avp->avp_rawlen); 763 fd_log_debug_fstr(fstr, INOBJHDR "intern: src:%p mf:%d raw:%p(%d)\n", INOBJHDRVAL, avp->avp_source, avp->avp_mustfreeos, avp->avp_rawdata, avp->avp_rawlen);
764 } 764 }
765 765
766 /* Dump a single object content */ 766 /* Dump a single object content */
767 static void msg_dump_intern ( int level, msg_or_avp * obj, int indent ) 767 static void msg_dump_intern ( int level, msg_or_avp * obj, int indent, FILE * fstr )
768 { 768 {
769 /* Log only if we are at least at level */ 769 /* Log only if we are at least at level */
770 if ( ! TRACE_BOOL(level) ) 770 if ( ! TRACE_BOOL(level) )
771 return; 771 return;
772 772
773 /* Check the object */ 773 /* Check the object */
774 if (!VALIDATE_OBJ(obj)) { 774 if (!VALIDATE_OBJ(obj)) {
775 fd_log_debug( ">>> invalid object (%p)!.\n", obj); 775 fd_log_debug_fstr(fstr, ">>> invalid object (%p)!.\n", obj);
776 return; 776 return;
777 } 777 }
778 778
779 /* Dump the object */ 779 /* Dump the object */
780 switch (_C(obj)->type) { 780 switch (_C(obj)->type) {
781 case MSG_AVP: 781 case MSG_AVP:
782 obj_dump_avp ( _A(obj), indent ); 782 obj_dump_avp ( _A(obj), indent, fstr );
783 break; 783 break;
784 784
785 case MSG_MSG: 785 case MSG_MSG:
786 obj_dump_msg ( _M(obj), indent ); 786 obj_dump_msg ( _M(obj), indent, fstr );
787 break; 787 break;
788 788
789 default: 789 default:
790 ASSERT(0); 790 ASSERT(0);
791 } 791 }
792 } 792 }
793 793
794 /* Dump a message to a specified file stream */
795 static void fd_msg_dump_fstr ( struct msg * msg, FILE * fstr )
796 {
797 msg_or_avp * ref = msg;
798 int indent = 2;
799 do {
800 msg_dump_intern ( NONE, ref, indent, fstr );
801
802 /* Now find the next object */
803 CHECK_FCT_DO( fd_msg_browse ( ref, MSG_BRW_WALK, &ref, &indent ), break );
804
805 /* dump next object */
806 } while (ref);
807 }
808
794 /* Dump a message content -- for debug mostly */ 809 /* Dump a message content -- for debug mostly */
795 void fd_msg_dump_walk ( int level, msg_or_avp *obj ) 810 void fd_msg_dump_walk ( int level, msg_or_avp *obj )
796 { 811 {
797 msg_or_avp * ref = obj; 812 msg_or_avp * ref = obj;
798 int indent = 1; 813 int indent = 1;
799 814
800 TRACE_DEBUG(level, "------ Dumping object %p (w)-------", obj); 815 TRACE_DEBUG(level, "------ Dumping object %p (w)-------", obj);
801 do { 816 do {
802 msg_dump_intern ( level, ref, indent ); 817 msg_dump_intern ( level, ref, indent, fd_g_debug_fstr );
803 818
804 /* Now find the next object */ 819 /* Now find the next object */
805 CHECK_FCT_DO( fd_msg_browse ( ref, MSG_BRW_WALK, &ref, &indent ), break ); 820 CHECK_FCT_DO( fd_msg_browse ( ref, MSG_BRW_WALK, &ref, &indent ), break );
806 821
807 /* dump next object */ 822 /* dump next object */
812 827
813 /* Dump a single object content -- for debug mostly */ 828 /* Dump a single object content -- for debug mostly */
814 void fd_msg_dump_one ( int level, msg_or_avp * obj ) 829 void fd_msg_dump_one ( int level, msg_or_avp * obj )
815 { 830 {
816 TRACE_DEBUG(level, "------ Dumping object %p (s)-------", obj); 831 TRACE_DEBUG(level, "------ Dumping object %p (s)-------", obj);
817 msg_dump_intern ( level, obj, 1 ); 832 msg_dump_intern ( level, obj, 1, fd_g_debug_fstr );
818 TRACE_DEBUG(level, "------ /end of object %p -------", obj); 833 TRACE_DEBUG(level, "------ /end of object %p -------", obj);
819 } 834 }
820 835
821 836
822 /***************************************************************************************************************/ 837 /***************************************************************************************************************/
1642 /* First handle the case where we have not found this AVP in the dictionary */ 1657 /* First handle the case where we have not found this AVP in the dictionary */
1643 if (!avp->avp_model) { 1658 if (!avp->avp_model) {
1644 1659
1645 if (mandatory && (avp->avp_public.avp_flags & AVP_FLAG_MANDATORY)) { 1660 if (mandatory && (avp->avp_public.avp_flags & AVP_FLAG_MANDATORY)) {
1646 TRACE_DEBUG(INFO, "Unsupported mandatory AVP found:"); 1661 TRACE_DEBUG(INFO, "Unsupported mandatory AVP found:");
1647 msg_dump_intern(INFO, avp, 2); 1662 msg_dump_intern(INFO, avp, 2, fd_g_debug_fstr);
1648 if (error_info) { 1663 if (error_info) {
1649 error_info->pei_errcode = "DIAMETER_AVP_UNSUPPORTED"; 1664 error_info->pei_errcode = "DIAMETER_AVP_UNSUPPORTED";
1650 error_info->pei_avp = avp; 1665 error_info->pei_avp = avp;
1651 } 1666 }
1652 return ENOTSUP; 1667 return ENOTSUP;
2306 2321
2307 error: 2322 error:
2308 CHECK_POSIX_DO(pthread_rwlock_unlock(&fd_disp_lock), /* ignore */ ); 2323 CHECK_POSIX_DO(pthread_rwlock_unlock(&fd_disp_lock), /* ignore */ );
2309 return ret; 2324 return ret;
2310 } 2325 }
2326
2327
2328 /***************************************************************************************************************/
2329 /* messages logging facility */
2330 #include <stdarg.h>
2331
2332 static struct {
2333 struct {
2334 enum fd_msg_log_method meth;
2335 const char * metharg;
2336 } causes[FD_MSG_LOG_MAX + 1];
2337 pthread_mutex_t lock;
2338 int init;
2339 } ml_conf = { .lock = PTHREAD_MUTEX_INITIALIZER, .init = 0 };
2340
2341 static void ml_conf_init(void)
2342 {
2343 memset(&ml_conf.causes, 0, sizeof(ml_conf.causes));
2344 ml_conf.init = 1;
2345 }
2346
2347 /* Set a configuration property */
2348 int fd_msg_log_config(enum fd_msg_log_cause cause, enum fd_msg_log_method method, const char * arg)
2349 {
2350 /* Check the parameters are valid */
2351 TRACE_ENTRY("%d %d %p", cause, method, arg);
2352 CHECK_PARAMS( (cause >= 0) && (cause <= FD_MSG_LOG_MAX) );
2353 CHECK_PARAMS( (method >= FD_MSG_LOGTO_DEBUGONLY) && (method <= FD_MSG_LOGTO_DIR) );
2354 CHECK_PARAMS( (method == FD_MSG_LOGTO_DEBUGONLY) || (arg != NULL) );
2355
2356 /* Lock the configuration */
2357 CHECK_POSIX( pthread_mutex_lock(&ml_conf.lock) );
2358 if (!ml_conf.init) {
2359 ml_conf_init();
2360 }
2361
2362 /* Now set the parameter */
2363 ml_conf.causes[cause].meth = method;
2364 ml_conf.causes[cause].metharg = arg;
2365
2366 if (method) {
2367 TRACE_DEBUG(INFO, "Logging %s messages set to %s '%s'",
2368 (cause == FD_MSG_LOG_DROPPED) ? "DROPPED" :
2369 (cause == FD_MSG_LOG_RECEIVED) ? "RECEIVED" :
2370 (cause == FD_MSG_LOG_SENT) ? "SENT" :
2371 "???",
2372 (method == FD_MSG_LOGTO_FILE) ? "file" :
2373 (method == FD_MSG_LOGTO_DIR) ? "directory" :
2374 "???",
2375 arg);
2376 }
2377
2378 CHECK_POSIX( pthread_mutex_unlock(&ml_conf.lock) );
2379
2380 /* Done */
2381 return 0;
2382 }
2383
2384 /* Do not log anything within this one, since log lock is held */
2385 static void fd_cleanup_mutex_silent( void * mutex )
2386 {
2387 (void)pthread_mutex_unlock((pthread_mutex_t *)mutex);
2388 }
2389
2390 /* Really log the message */
2391 void fd_msg_log( enum fd_msg_log_cause cause, struct msg * msg, const char * prefix_format, ... )
2392 {
2393 va_list ap;
2394 enum fd_msg_log_method meth;
2395 const char * metharg;
2396 FILE * fstr;
2397
2398 TRACE_ENTRY("%d %p %p", cause, msg, prefix_format);
2399 CHECK_PARAMS_DO( (cause >= 0) && (cause <= FD_MSG_LOG_MAX),
2400 {
2401 TRACE_DEBUG(INFO, "Invalid cause received (%d)! Message was:", cause);
2402 fd_msg_dump_walk(INFO, msg);
2403 } );
2404
2405 /* First retrieve the config for this message */
2406 CHECK_POSIX_DO( pthread_mutex_lock(&ml_conf.lock), );
2407 if (!ml_conf.init) {
2408 ml_conf_init();
2409 }
2410 meth = ml_conf.causes[cause].meth;
2411 metharg = ml_conf.causes[cause].metharg;
2412 CHECK_POSIX_DO( pthread_mutex_unlock(&ml_conf.lock), );
2413
2414 /* Okay, now we will create the file descriptor */
2415 switch (meth) {
2416 case FD_MSG_LOGTO_DEBUGONLY:
2417 fstr = fd_g_debug_fstr;
2418 break;
2419
2420 case FD_MSG_LOGTO_FILE:
2421 TODO("Log to arg file");
2422 break;
2423 case FD_MSG_LOGTO_DIR:
2424 TODO("Log to arg directory in a new file");
2425 break;
2426 }
2427
2428 /* Then dump the prefix message to this stream */
2429 (void)pthread_mutex_lock(&fd_log_lock);
2430 pthread_cleanup_push(fd_cleanup_mutex_silent, &fd_log_lock);
2431 va_start(ap, prefix_format);
2432 vfprintf( fstr, prefix_format, ap);
2433 va_end(ap);
2434 fflush(fstr);
2435 pthread_cleanup_pop(0);
2436 (void)pthread_mutex_unlock(&fd_log_lock);
2437 fd_log_debug_fstr(fstr, "\n\n");
2438
2439 /* And now the message itself */
2440 fd_msg_dump_fstr(msg, fstr);
2441
2442 /* And finally close the stream if needed */
2443 TODO("close?");
2444 }
2445
"Welcome to our mercurial repository"