ubuntu@vol:~/docker_open5gs$ nano .env ubuntu@vol:~/docker_open5gs$ set -a ubuntu@vol:~/docker_open5gs$ source .env ubuntu@4th:~/docker_open5gs$ docker-compose up Creating network "docker_open5gs_default" with the default driver Creating mongo ... done Creating dns ... done Creating mysql ... done Creating rtpengine ... done Creating nrf ... done Creating fhoss ... done Creating hss ... done Creating webui ... done Creating pcrf ... done Creating smf ... done Creating udm ... done Creating udr ... done Creating ausf ... done Creating pcf ... done Creating nssf ... done Creating upf ... done Creating icscf ... done Creating scscf ... done Creating sgwu ... done Creating amf ... done Creating sgwc ... done Creating pcscf ... done Creating mme ... done Attaching to mysql, dns, mongo, nrf, rtpengine, pcf, smf, udr, ausf, hss, udm, webui, pcrf, nssf, fhoss, upf, icscf, scscf, sgwu, sgwc, amf, pcscf, mme amf | Open5GS daemon v2.2.7 amf | ausf | Open5GS daemon v2.2.7 ausf | ausf | 05/05 12:36:34.054: [app] INFO: Configuration: '/open5gs/install/etc/open5gs/ausf.yaml' (../lib/app/ogs-init.c:129) ausf | 05/05 12:36:34.055: [app] INFO: File Logging: '/open5gs/install/var/log/open5gs/ausf.log' (../lib/app/ogs-init.c:132) amf | 05/05 12:37:26.696: [app] INFO: Configuration: '/open5gs/install/etc/open5gs/amf.yaml' (../lib/app/ogs-init.c:129) amf | 05/05 12:37:26.697: [app] INFO: File Logging: '/open5gs/install/var/log/open5gs/amf.log' (../lib/app/ogs-init.c:132) ausf | 05/05 12:36:34.057: [sbi] INFO: nghttp2_server() [172.22.0.11]:7777 (../lib/sbi/nghttp2-server.c:145)dns | 05-May-2021 12:36:02.443 starting BIND 9.11.3-1ubuntu1.15-Ubuntu (Extended Support Version) dns | 05-May-2021 12:36:02.443 running on Linux x86_64 4.15.0-142-generic #146-Ubuntu SMP Tue Apr 13 01:11:19 UTC 2021 dns | 05-May-2021 12:36:02.443 built with '--build=x86_64-linux-gnu' '--prefix=/usr' '--includedir=/usr/include' '--mandir=/usr/share/man' '--infodir=/usr/share/info' '--sysconfdir=/etc' '--localstatedir=/var' '--disable-silent-rules' '--libdir=/usr/lib/x86_64-linux-gnu' '--libexecdir=/usr/lib/x86_64-linux-gnu' '--disable-maintainer-mode' '--disable-dependency-tracking' '--libdir=/usr/lib/x86_64-linux-gnu' '--sysconfdir=/etc/bind' '--with-python=python3' '--localstatedir=/' '--enable-threads' '--enable-largefile' '--with-libtool' '--enable-shared' '--enable-static' '--with-gost=no' '--with-openssl=/usr' '--with-gssapi=/usr' '--with-libjson=/usr' '--without-lmdb' '--with-gnu-ld' '--with-geoip=/usr' '--with-atf=no' '--enable-ipv6' '--enable-rrl' '--enable-filter-aaaa' '--enable-native-pkcs11' '--with-pkcs11=/usr/lib/softhsm/libsofthsm2.so' '--with-randomdev=/dev/urandom' '--with-eddsa=no' '--disable-isc-spnego' 'build_alias=x86_64-linux-gnu' 'CFLAGS=-g -O2 -fdebug-prefix-map=/build/bind9-zLYYTb/bind9-9.11.3+dfsg=. -fstack-protector-strong -Wformat -Werror=format-security -fno-strict-aliasing -fno-delete-null-pointer-checks -DNO_VERSION_DATE -DDIG_SIGCHASE' 'LDFLAGS=-Wl,-Bsymbolic-functions -Wl,-z,relro -Wl,-z,now' 'CPPFLAGS=-Wdate-time -D_FORTIFY_SOURCE=2' dns | 05-May-2021 12:36:02.443 running as: named -c /etc/bind/named.conf -g -u bind dns | 05-May-2021 12:36:02.443 ---------------------------------------------------- dns | 05-May-2021 12:36:02.443 BIND 9 is maintained by Internet Systems Consortium, dns | 05-May-2021 12:36:02.443 Inc. (ISC), a non-profit 501(c)(3) public-benefit dns | 05-May-2021 12:36:02.443 corporation. Support and training for BIND 9 are dns | 05-May-2021 12:36:02.443 available at https://www.isc.org/support dns | 05-May-2021 12:36:02.443 ---------------------------------------------------- dns | 05-May-2021 12:36:02.443 found 8 CPUs, using 8 worker threads dns | 05-May-2021 12:36:02.443 using 7 UDP listeners per interface amf | 05/05 12:37:26.705: [sbi] INFO: nghttp2_server() [172.22.0.10]:7777 (../lib/sbi/nghttp2-server.c:145)icscf | mysqld is alive amf | 05/05 12:37:26.706: [amf] INFO: ngap_server() [172.22.0.10]:38412 (../src/amf/ngap-sctp.c:54) hss | Generating a RSA private key dns | 05-May-2021 12:36:02.445 using up to 4096 sockets dns | 05-May-2021 12:36:04.651 loading configuration from '/etc/bind/named.conf' amf | 05/05 12:37:26.707: [sctp] INFO: AMF initialize...done (../src/amf/app.c:33) ausf | 05/05 12:36:34.122: [app] INFO: AUSF initialize...done (../src/ausf/app.c:31) amf | 05/05 12:37:26.711: [amf] INFO: [a6093870-ad9e-41eb-b980-937727dd07fd] NF registred [Heartbeat:10s] (../src/amf/nf-sm.c:199) dns | 05-May-2021 12:36:04.654 reading built-in trust anchors from file '/etc/bind/bind.keys' ausf | 05/05 12:36:34.667: [ausf] INFO: [86a8b14a-ad9e-41eb-bf13-91d4b20e6f5d] NF registred [Heartbeat:10s] (../src/ausf/nf-sm.c:199) nrf | Open5GS daemon v2.2.7 nrf | nssf | Open5GS daemon v2.2.7 nssf | icscf | 0(26) INFO: [core/sctp_core.c:74]: sctp_core_check_support(): SCTP API not enabled - if you want to use it, load sctp module ausf | 05/05 12:36:37.424: [ausf] INFO: [88a98618-ad9e-41eb-adf4-a90f9655630e] (NRF-notify) NF registered (../src/ausf/nnrf-handler.c:177) ausf | 05/05 12:36:37.424: [ausf] INFO: [88a98618-ad9e-41eb-adf4-a90f9655630e] (NRF-notify) NF Profile updated (../src/ausf/nnrf-handler.c:196) nrf | 05/05 12:36:08.329: [app] INFO: Configuration: '/open5gs/install/etc/open5gs/nrf.yaml' (../lib/app/ogs-init.c:129) nrf | 05/05 12:36:08.329: [app] INFO: File Logging: '/open5gs/install/var/log/open5gs/nrf.log' (../lib/app/ogs-init.c:132) dns | 05-May-2021 12:36:04.661 initializing GeoIP Country (IPv4) (type 1) DB pcrf | Generating a RSA private key pcf | Open5GS daemon v2.2.7 pcf | mysql | Waiting for MySQL to start. pcscf | mysqld is alive fhoss | changing: DiameterPeerHSS.xml c3p0.properties hibernate.properties hss.properties log4j.properties dns | 05-May-2021 12:36:04.662 GEO-106FREE 20180315 Build dns | 05-May-2021 12:36:04.662 initializing GeoIP Country (IPv6) (type 12) DB dns | 05-May-2021 12:36:04.664 GEO-106FREE 20180315 Build dns | 05-May-2021 12:36:04.664 GeoIP City (IPv4) (type 2) DB not available dns | 05-May-2021 12:36:04.664 GeoIP City (IPv4) (type 6) DB not available rtpengine | + RUNTIME=rtpengine nssf | 05/05 12:36:41.405: [app] INFO: Configuration: '/open5gs/install/etc/open5gs/nssf.yaml' (../lib/app/ogs-init.c:129) nssf | 05/05 12:36:41.406: [app] INFO: File Logging: '/open5gs/install/var/log/open5gs/nssf.log' (../lib/app/ogs-init.c:132) icscf | 0(26) INFO: [core/tcp_main.c:5042]: init_tcp(): using epoll_lt as the io watch method (auto detected) icscf | loading modules under config path: /usr/lib64/kamailio/modules_k/:/usr/lib64/kamailio/modules/:/usr/lib/kamailio/modules_k/:/usr/lib/kamailio/modules/:/usr/lib/x86_64-linux-gnu/kamailio/modules/:/usr/local/lib64/kamailio/modules icscf | Listening on icscf | udp: 172.22.0.19 [172.22.0.19]:4060 icscf | tcp: 172.22.0.19 [172.22.0.19]:4060 icscf | tcp: 127.0.0.1 [127.0.0.1]:4060 icscf | Aliases: icscf | *: ims.mnc001.mcc001.3gppnetwork.org:* icscf | mysql | * Stopping MySQL database server mysqld nssf | 05/05 12:36:41.408: [sbi] INFO: nghttp2_server() [172.22.0.28]:7777 (../lib/sbi/nghttp2-server.c:145)nssf | 05/05 12:36:41.409: [app] INFO: NSSF initialize...done (../src/nssf/app.c:31) dns | 05-May-2021 12:36:04.665 GeoIP City (IPv6) (type 30) DB not available dns | 05-May-2021 12:36:04.665 GeoIP City (IPv6) (type 31) DB not available dns | 05-May-2021 12:36:04.665 GeoIP Region (type 3) DB not available dns | 05-May-2021 12:36:04.665 GeoIP Region (type 7) DB not available mysql | ...done. mysql | * Starting MySQL database server mysqld rtpengine | + lsmod rtpengine | + grep xt_RTPENGINE mysql | ...done. nrf | 05/05 12:36:08.836: [sbi] INFO: nghttp2_server() [172.22.0.12]:7777 (../lib/sbi/nghttp2-server.c:145)pcf | 05/05 12:36:36.584: [app] INFO: Configuration: '/open5gs/install/etc/open5gs/pcf.yaml' (../lib/app/ogs-init.c:129) pcf | 05/05 12:36:36.584: [app] INFO: File Logging: '/open5gs/install/var/log/open5gs/pcf.log' (../lib/app/ogs-init.c:132) icscf | 0(26) INFO: rr [../outbound/api.h:52]: ob_load_api(): unable to import bind_ob - maybe module is not loaded icscf | 0(26) INFO: rr [rr_mod.c:177]: mod_init(): outbound module not available nrf | 05/05 12:36:08.836: [app] INFO: NRF initialize...done (../src/nrf/app.c:31) sgwu | Open5GS daemon v2.2.7 sgwu | scscf | mysqld is alive dns | 05-May-2021 12:36:04.665 GeoIP ISP (type 4) DB not available dns | 05-May-2021 12:36:04.665 GeoIP Org (type 5) DB not available dns | 05-May-2021 12:36:04.665 GeoIP AS (type 9) DB not available dns | 05-May-2021 12:36:04.665 GeoIP Domain (type 11) DB not available dns | 05-May-2021 12:36:04.665 GeoIP NetSpeed (type 10) DB not available nrf | 05/05 12:36:34.126: [nrf] INFO: [86a8b14a-ad9e-41eb-bf13-91d4b20e6f5d] NF registred [Heartbeat:10s] (../src/nrf/nf-sm.c:189) sgwc | Open5GS daemon v2.2.7 sgwc | icscf | 0(26) INFO: pike [pike.c:97]: pike_init(): PIKE - initializing rtpengine | + modprobe xt_RTPENGINE pcf | 05/05 12:36:36.710: [dbi] INFO: MongoDB URI: 'mongodb://172.22.0.2/open5gs' (../lib/dbi/ogs-mongoc.c:129) pcf | 05/05 12:36:36.710: [sbi] INFO: nghttp2_server() [172.22.0.27]:7777 (../lib/sbi/nghttp2-server.c:145)sgwu | 05/05 12:37:11.405: [app] INFO: Configuration: '/open5gs/install/etc/open5gs/sgwu.yaml' (../lib/app/ogs-init.c:129) sgwu | 05/05 12:37:11.406: [app] INFO: File Logging: '/open5gs/install/var/log/open5gs/sgwu.log' (../lib/app/ogs-init.c:132) nrf | 05/05 12:36:36.713: [nrf] INFO: [882a9bf0-ad9e-41eb-9e9c-416c57e7f199] NF registred [Heartbeat:10s] (../src/nrf/nf-sm.c:189) sgwu | 05/05 12:37:11.423: [pfcp] INFO: pfcp_server() [172.22.0.6]:8805 (../lib/pfcp/path.c:31) sgwu | 05/05 12:37:11.424: [pfcp] INFO: ogs_pfcp_connect() [172.22.0.5]:8805 (../lib/pfcp/path.c:60) icscf | 0(26) INFO: pike [ip_tree.c:81]: init_lock_set(): probing 256 set size dns | 05-May-2021 12:36:04.668 using default UDP/IPv4 port range: [32768, 60999] pcf | 05/05 12:36:36.711: [app] INFO: PCF initialize...done (../src/pcf/app.c:31) mysql | 2021-05-05T12:36:31.289105Z mysqld_safe Logging to syslog. scscf | 0(31) INFO: [core/sctp_core.c:74]: sctp_core_check_support(): SCTP API not enabled - if you want to use it, load sctp module pcf | 05/05 12:36:36.714: [pcf] INFO: [882a9bf0-ad9e-41eb-9e9c-416c57e7f199] NF registred [Heartbeat:10s] (../src/pcf/nf-sm.c:199) pcf | 05/05 12:36:40.361: [pcf] INFO: [8a6923b4-ad9e-41eb-9ed0-25acba1b443a] (NRF-notify) NF registered (../src/pcf/nnrf-handler.c:177) pcf | 05/05 12:36:40.361: [pcf] INFO: [8a6923b4-ad9e-41eb-9ed0-25acba1b443a] (NRF-notify) NF Profile updated (../src/pcf/nnrf-handler.c:196) nssf | 05/05 12:36:41.412: [nssf] INFO: [8b0a4e4c-ad9e-41eb-815f-0540bd13b2d2] NF registred [Heartbeat:10s] (../src/nssf/nf-sm.c:199) mysql | 2021-05-05T12:36:31.299692Z mysqld_safe Logging to '/var/log/mysql/error.log'. scscf | 0(31) INFO: [core/tcp_main.c:5042]: init_tcp(): using epoll_lt as the io watch method (auto detected) hss | .......+++++ smf | Generating a RSA private key mysql | 2021-05-05T12:36:31.368301Z mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql dns | 05-May-2021 12:36:04.668 using default UDP/IPv6 port range: [32768, 60999] nrf | 05/05 12:36:37.421: [nrf] INFO: [88a98618-ad9e-41eb-adf4-a90f9655630e] NF registred [Heartbeat:10s] (../src/nrf/nf-sm.c:189) nrf | 05/05 12:36:38.410: [nrf] INFO: [88d4aa3c-ad9e-41eb-af42-33b14ac7080c] NF registred [Heartbeat:10s] (../src/nrf/nf-sm.c:189) icscf | 0(26) INFO: [main.c:2779]: main(): processes (at least): 35 - shm size: 67108864 - pkg size: 8388608 rtpengine | rtpengine kernel module already loaded. icscf | 0(26) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 icscf | 0(26) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 icscf | 0(26) INFO: cdp [cdp_mod.c:240]: cdp_child_init(): CDiameterPeer child starting ... dns | 05-May-2021 12:36:04.671 listening on IPv6 interfaces, port 53 rtpengine | + echo 'rtpengine kernel module already loaded.' rtpengine | + '[' -z 172.22.0.16 ']' rtpengine | + '[' -z 0 ']' rtpengine | + '[' -z 172.22.0.16:2223 ']' rtpengine | + '[' -z 49000 ']' fhoss | changing: hss_db.sql hss_db_migrate_as_register.sql hss_db_migrate_dsai.sql userdata.sql dns | 05-May-2021 12:36:04.709 listening on IPv4 interface lo, 127.0.0.1#53 dns | 05-May-2021 12:36:04.716 listening on IPv4 interface eth0, 172.22.0.15#53 icscf | 9(35) INFO: cdp [worker.c:332]: worker_process(): [0] Worker process started... rtpengine | + '[' -z 50000 ']' rtpengine | + '[' -z 184 ']' rtpengine | + '[' -z /run/ngcp-rtpengine-daemon.pid ']'sgwu | 05/05 12:37:11.424: [gtp] INFO: gtp_server() [172.22.0.6]:2152 (../lib/gtp/path.c:31) sgwu | 05/05 12:37:11.424: [app] INFO: SGW-U initialize...done (../src/sgwu/app.c:31) rtpengine | ++ awk 'END{print $1}' /etc/hosts rtpengine | + LISTEN_CLI=172.22.0.16:9901 rtpengine | + OPTIONS= sgwu | 05/05 12:37:18.934: [pfcp] WARNING: [1] LOCAL No Reponse. Give up! for step 1 type 5 peer [172.22.0.5]:8805 (../lib/pfcp/xact.c:618) icscf | 10(36) INFO: cdp [worker.c:332]: worker_process(): [1] Worker process started... icscf | 11(37) INFO: cdp [worker.c:332]: worker_process(): [2] Worker process started... sgwu | 05/05 12:37:22.425: [sgwu] WARNING: Retry to association with peer [172.22.0.5]:8805 failed (../src/sgwu/pfcp-sm.c:102) sgwu | 05/05 12:37:25.152: [sgwu] INFO: PFCP associated (../src/sgwu/pfcp-sm.c:168) icscf | 8(34) INFO: ctl [io_listener.c:214]: io_listen_loop(): io_listen_loop: using epoll_lt io watch method (config) icscf | 12(38) INFO: cdp [worker.c:332]: worker_process(): [3] Worker process started... dns | 05-May-2021 12:36:04.722 couldn't mkdir '//run/named': Permission denied dns | 05-May-2021 12:36:04.722 generating session key for dynamic DNS rtpengine | + OPTIONS=' --interface=172.22.0.16 --listen-ng=172.22.0.16:2223 --listen-cli=172.22.0.16:9901 --pidfile=/run/ngcp-rtpengine-daemon.pid --port-min=49000 --port-max=50000 ' rtpengine | + OPTIONS=' --interface=172.22.0.16 --listen-ng=172.22.0.16:2223 --listen-cli=172.22.0.16:9901 --pidfile=/run/ngcp-rtpengine-daemon.pid --port-min=49000 --port-max=50000 --table=0 --tos=184 --foreground' rtpengine | + test no = yes dns | 05-May-2021 12:36:04.722 couldn't mkdir '//run/named': Permission denied dns | 05-May-2021 12:36:04.722 could not create //run/named/session.key dns | 05-May-2021 12:36:04.722 failed to generate session key for dynamic DNS: permission denied sgwc | 05/05 12:37:25.135: [app] INFO: Configuration: '/open5gs/install/etc/open5gs/sgwc.yaml' (../lib/app/ogs-init.c:129) sgwc | 05/05 12:37:25.136: [app] INFO: File Logging: '/open5gs/install/var/log/open5gs/sgwc.log' (../lib/app/ogs-init.c:132) udr | Open5GS daemon v2.2.7 udr | udm | Open5GS daemon v2.2.7 udm | sgwu | 05/05 12:37:27.432: [sgwu] WARNING: PFCP[RSP] has already been associated (../src/sgwu/pfcp-sm.c:200)webui | webui | > open5gs@2.2.6 dev /open5gs/webui webui | > node server/index.js webui | dns | 05-May-2021 12:36:04.724 sizing zone task pool based on 2 zones nrf | 05/05 12:36:40.359: [nrf] INFO: [8a6923b4-ad9e-41eb-9ed0-25acba1b443a] NF registred [Heartbeat:10s] (../src/nrf/nf-sm.c:189) scscf | loading modules under config path: /usr/lib64/kamailio/modules_k/:/usr/lib64/kamailio/modules/:/usr/lib/kamailio/modules_k/:/usr/lib/kamailio/modules/:/usr/lib/x86_64-linux-gnu/kamailio/modules/:/usr/local/lib64/kamailio/modules scscf | Listening on scscf | udp: 172.22.0.20 [172.22.0.20]:6060 scscf | tcp: 172.22.0.20 [172.22.0.20]:6060 scscf | Aliases: scscf | *: scscf.ims.mnc001.mcc001.3gppnetwork.org:* scscf | rtpengine | + set +e dns | 05-May-2021 12:36:04.725 none:103: 'max-cache-size 90%' - setting to 7177MB (out of 7975MB) dns | 05-May-2021 12:36:04.742 set up managed keys zone for view _default, file 'managed-keys.bind' dns | 05-May-2021 12:36:04.742 automatic empty zone: 10.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.742 automatic empty zone: 16.172.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.742 automatic empty zone: 17.172.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.742 automatic empty zone: 18.172.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.742 automatic empty zone: 19.172.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.742 automatic empty zone: 20.172.IN-ADDR.ARPA udm | 05/05 12:36:37.416: [app] INFO: Configuration: '/open5gs/install/etc/open5gs/udm.yaml' (../lib/app/ogs-init.c:129) udm | 05/05 12:36:37.416: [app] INFO: File Logging: '/open5gs/install/var/log/open5gs/udm.log' (../lib/app/ogs-init.c:132) scscf | 0(31) INFO: rr [../outbound/api.h:52]: ob_load_api(): unable to import bind_ob - maybe module is not loaded scscf | 0(31) INFO: rr [rr_mod.c:177]: mod_init(): outbound module not available scscf | 0(31) INFO: pike [pike.c:97]: pike_init(): PIKE - initializing icscf | 13(39) INFO: cdp [worker.c:332]: worker_process(): [4] Worker process started... icscf | 14(40) INFO: cdp [worker.c:332]: worker_process(): [5] Worker process started... nrf | 05/05 12:36:41.411: [nrf] INFO: [8b0a4e4c-ad9e-41eb-815f-0540bd13b2d2] NF registred [Heartbeat:10s] (../src/nrf/nf-sm.c:189) rtpengine | + '[' -e /proc/rtpengine/control ']' rtpengine | + echo 'del 0' scscf | 0(31) INFO: pike [ip_tree.c:81]: init_lock_set(): probing 256 set size upf | RTNETLINK answers: Permission denied udm | 05/05 12:36:37.418: [sbi] INFO: nghttp2_server() [172.22.0.13]:7777 (../lib/sbi/nghttp2-server.c:145)sgwc | 05/05 12:37:25.150: [gtp] INFO: gtp_server() [172.22.0.5]:2123 (../lib/gtp/path.c:31) icscf | 15(41) INFO: cdp [worker.c:332]: worker_process(): [6] Worker process started... icscf | 17(43) INFO: cdp [worker.c:332]: worker_process(): [8] Worker process started... nrf | 05/05 12:37:26.709: [nrf] INFO: [a6093870-ad9e-41eb-b980-937727dd07fd] NF registred [Heartbeat:10s] (../src/nrf/nf-sm.c:189) sgwc | 05/05 12:37:25.151: [pfcp] INFO: pfcp_server() [172.22.0.5]:8805 (../lib/pfcp/path.c:31) dns | 05-May-2021 12:36:04.742 automatic empty zone: 21.172.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.742 automatic empty zone: 22.172.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.742 automatic empty zone: 23.172.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.742 automatic empty zone: 24.172.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.743 automatic empty zone: 25.172.IN-ADDR.ARPA udm | 05/05 12:36:37.419: [app] INFO: UDM initialize...done (../src/udm/app.c:31) sgwc | 05/05 12:37:25.151: [pfcp] INFO: ogs_pfcp_connect() [172.22.0.6]:8805 (../lib/pfcp/path.c:60) dns | 05-May-2021 12:36:04.743 automatic empty zone: 26.172.IN-ADDR.ARPA rtpengine | + iptables -N rtpengine icscf | 18(44) INFO: cdp [worker.c:332]: worker_process(): [9] Worker process started... icscf | 21(47) INFO: cdp [worker.c:332]: worker_process(): [12] Worker process started... scscf | 0(31) INFO: ims_usrloc_scscf [hslot.c:69]: ul_init_locks(): locks array size 512 scscf | 0(31) INFO: ims_usrloc_scscf [contact_hslot.c:67]: init_contacts_locks(): locks array size 512 scscf | 0(31) INFO: ims_usrloc_scscf [hslot_sp.c:70]: subs_init_locks(): locks array size 512 fhoss | changing: DiameterPeerHSS.xml c3p0.properties hibernate.properties hss.properties log4j.properties dns | 05-May-2021 12:36:04.743 automatic empty zone: 27.172.IN-ADDR.ARPA rtpengine | + iptables -D INPUT -j rtpengine icscf | 19(45) INFO: cdp [worker.c:332]: worker_process(): [10] Worker process started... icscf | 20(46) INFO: cdp [worker.c:332]: worker_process(): [11] Worker process started... upf | RTNETLINK answers: Permission denied sgwc | 05/05 12:37:25.152: [app] INFO: SGW-C initialize...done (../src/sgwc/app.c:31) scscf | 0(31) INFO: [main.c:2779]: main(): processes (at least): 39 - shm size: 67108864 - pkg size: 8388608 udm | 05/05 12:36:37.424: [udm] INFO: [88a98618-ad9e-41eb-adf4-a90f9655630e] NF registred [Heartbeat:10s] (../src/udm/nf-sm.c:199) icscf | 16(42) INFO: cdp [worker.c:332]: worker_process(): [7] Worker process started... icscf | 24(50) INFO: cdp [worker.c:332]: worker_process(): [15] Worker process started... icscf | 22(48) INFO: cdp [worker.c:332]: worker_process(): [13] Worker process started... icscf | 25(51) INFO: cdp [receiver.c:454]: receiver_process(): receiver_process(): [] Receiver process doing init on new process... icscf | 25(51) INFO: cdp [receiver.c:459]: receiver_process(): receiver_process(): [] Receiver process starting up... udm | 05/05 12:36:40.361: [udm] INFO: [8a6923b4-ad9e-41eb-9ed0-25acba1b443a] (NRF-notify) NF registered (../src/udm/nnrf-handler.c:177) udm | 05/05 12:36:40.362: [udm] INFO: [8a6923b4-ad9e-41eb-9ed0-25acba1b443a] (NRF-notify) NF Profile updated (../src/udm/nnrf-handler.c:196) sgwc | 05/05 12:37:25.152: [sgwc] INFO: PFCP associated (../src/sgwc/pfcp-sm.c:172) rtpengine | + iptables -I INPUT -j rtpengine scscf | 0(31) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 scscf | 0(31) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 scscf | 0(31) INFO: cdp [cdp_mod.c:240]: cdp_child_init(): CDiameterPeer child starting ... udr | 05/05 12:36:40.349: [app] INFO: Configuration: '/open5gs/install/etc/open5gs/udr.yaml' (../lib/app/ogs-init.c:129) udr | 05/05 12:36:40.349: [app] INFO: File Logging: '/open5gs/install/var/log/open5gs/udr.log' (../lib/app/ogs-init.c:132) fhoss | mysqld is alive dns | 05-May-2021 12:36:04.743 automatic empty zone: 28.172.IN-ADDR.ARPA upf | Open5GS daemon v2.2.7 upf | upf | 05/05 12:36:51.537: [app] INFO: Configuration: '/open5gs/install/etc/open5gs/upf.yaml' (../lib/app/ogs-init.c:129) upf | 05/05 12:36:51.538: [app] INFO: File Logging: '/open5gs/install/var/log/open5gs/upf.log' (../lib/app/ogs-init.c:132) udr | 05/05 12:36:40.355: [dbi] INFO: MongoDB URI: 'mongodb://172.22.0.2/open5gs' (../lib/dbi/ogs-mongoc.c:129) upf | 05/05 12:36:51.561: [pfcp] INFO: pfcp_server() [172.22.0.8]:8805 (../lib/pfcp/path.c:31) upf | 05/05 12:36:51.561: [pfcp] INFO: ogs_pfcp_connect() [172.22.0.7]:8805 (../lib/pfcp/path.c:60) dns | 05-May-2021 12:36:04.744 automatic empty zone: 29.172.IN-ADDR.ARPA icscf | 26(52) INFO: cdp [receiver.c:454]: receiver_process(): receiver_process(): [hss.ims.mnc001.mcc001.3gppnetwork.org] Receiver process doing init on new process... icscf | 26(52) INFO: cdp [receiver.c:186]: add_serviced_peer(): add_serviced_peer(): Adding serviced_peer_t to receiver for peer [hss.ims.mnc001.mcc001.3gppnetwork.org] sgwc | 05/05 12:37:27.431: [sgwc] WARNING: PFCP[REQ] has already been associated (../src/sgwc/pfcp-sm.c:199)scscf | 1(32) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1] upf | 05/05 12:36:51.561: [gtp] INFO: gtp_server() [172.22.0.8]:2152 (../lib/gtp/path.c:31) upf | 05/05 12:36:51.563: [app] INFO: UPF initialize...done (../src/upf/app.c:31) upf | 05/05 12:36:51.563: [upf] INFO: PFCP associated (../src/upf/pfcp-sm.c:173) rtpengine | + iptables -D rtpengine -p udp -j RTPENGINE --id 0 rtpengine | + iptables -I rtpengine -p udp -j RTPENGINE --id 0 udr | 05/05 12:36:40.356: [sbi] INFO: nghttp2_server() [172.22.0.14]:7777 (../lib/sbi/nghttp2-server.c:145)udr | 05/05 12:36:40.357: [app] INFO: UDR initialize...done (../src/udr/app.c:31) icscf | 0(26) INFO: cdp [cdp_mod.c:242]: cdp_child_init(): ... CDiameterPeer child started fhoss | Building Classpath icscf | 27(53) INFO: cdp [acceptor.c:81]: acceptor_process(): Acceptor process starting up... udr | 05/05 12:36:40.361: [udr] INFO: [8a6923b4-ad9e-41eb-9ed0-25acba1b443a] NF registred [Heartbeat:10s] (../src/udr/nf-sm.c:199) dns | 05-May-2021 12:36:04.744 automatic empty zone: 30.172.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.744 automatic empty zone: 31.172.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.744 automatic empty zone: 168.192.IN-ADDR.ARPA scscf | 2(33) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [2] scscf | 3(34) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [3] upf | 05/05 12:36:51.909: [upf] WARNING: PFCP[REQ] has already been associated (../src/upf/pfcp-sm.c:200) icscf | 23(49) INFO: cdp [worker.c:332]: worker_process(): [14] Worker process started... icscf | 27(53) WARNING: cdp [tcp_accept.c:120]: create_socket(): create_socket(): Trying to open/bind/listen on 172.22.0.19 port 3869 icscf | 27(53) WARNING: cdp [tcp_accept.c:145]: create_socket(): create_socket(): Successful socket open/bind/listen on 172.22.0.19 port 3869 icscf | 27(53) INFO: cdp [acceptor.c:95]: acceptor_process(): Acceptor opened sockets. Entering accept loop ... icscf | 28(54) INFO: cdp [timer.c:205]: timer_process(): Timer process starting up... icscf | 28(54) INFO: cdp [peerstatemachine.c:526]: I_Snd_Conn_Req(): I_Snd_Conn_Req(): Peer hss.ims.mnc001.mcc001.3gppnetwork.org icscf | 30(56) INFO: jsonrpcs [jsonrpcs_sock.c:443]: jsonrpc_dgram_process(): a new child 0/56 smf | ..+++++ rtpengine | + iptables-save fhoss | Classpath is lib/xml-apis.jar:lib/xercesImpl.jar:lib/xerces-2.4.0.jar:lib/xalan-2.4.0.jar:lib/tomcat-util.jar:lib/tomcat-http.jar:lib/tomcat-coyote.jar:lib/struts.jar:lib/servlets-default.jar:lib/servlet-api.jar:lib/naming-resources.jar:lib/naming-factory.jar:lib/mysql-connector-java-3.1.12-bin.jar:lib/mx4j-3.0.1.jar:lib/log4j.jar:lib/junitee.jar:lib/junit.jar:lib/jta.jar:lib/jsp-api.jar:lib/jmx.jar:lib/jdp.jar:lib/jasper-runtime.jar:lib/jasper-compiler.jar:lib/jasper-compiler-jdt.jar:lib/hibernate3.jar:lib/ehcache-1.1.jar:lib/dom4j-1.6.1.jar:lib/commons-validator.jar:lib/commons-modeler.jar:lib/commons-logging.jar:lib/commons-logging-1.0.4.jar:lib/commons-lang.jar:lib/commons-fileupload.jar:lib/commons-el.jar:lib/commons-digester.jar:lib/commons-collections-3.1.jar:lib/commons-beanutils.jar:lib/cglib-2.1.3.jar:lib/catalina.jar:lib/catalina-optional.jar:lib/c3p0-0.9.1.jar:lib/base64.jar:lib/asm.jar:lib/asm-attrs.jar:lib/antlr-2.7.6.jar:lib/FHoSS.jar:/usr/lib/jvm/jdk1.7.0_80/jre/lib/:log4j.properties:.. fhoss | [main] INFO de.fhg.fokus.hss.main.TomcatServer - Tomcat-Server is started. icscf | 28(54) INFO: cdp [receiver.c:874]: peer_connect(): peer_connect(): Trying to connect to 172.22.0.18 port 3868 scscf | 4(35) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [4] fhoss | [main] INFO org.apache.catalina.startup.Embedded - Starting tomcat server fhoss | [main] INFO org.apache.catalina.core.StandardEngine - Starting Servlet Engine: Apache Tomcat/5.5.9 icscf | 28(54) ERROR: cdp [receiver.c:922]: peer_connect(): peer_connect(): Error opening connection to to 172.22.0.18 port 3868 >Connection refused dns | 05-May-2021 12:36:04.744 automatic empty zone: 64.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.744 automatic empty zone: 65.100.IN-ADDR.ARPA fhoss | [main] INFO org.apache.coyote.http11.Http11Protocol - Initializing Coyote HTTP/1.1 on http-172.22.0.18-8080 rtpengine | + ip6tables -N rtpengine rtpengine | + ip6tables -D INPUT -j rtpengine dns | 05-May-2021 12:36:04.744 automatic empty zone: 66.100.IN-ADDR.ARPA scscf | 0(31) INFO: cdp [cdp_mod.c:242]: cdp_child_init(): ... CDiameterPeer child started scscf | 0(31) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [0] scscf | 6(37) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [-1] rtpengine | + ip6tables -I INPUT -j rtpengine rtpengine | + ip6tables -D rtpengine -p udp -j RTPENGINE --id 0 dns | 05-May-2021 12:36:04.745 automatic empty zone: 67.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.745 automatic empty zone: 68.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.745 automatic empty zone: 69.100.IN-ADDR.ARPA fhoss | [main] INFO org.apache.coyote.http11.Http11Protocol - Starting Coyote HTTP/1.1 on http-172.22.0.18-8080 rtpengine | + ip6tables -I rtpengine -p udp -j RTPENGINE --id 0 scscf | 7(38) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [-1] fhoss | [main] WARN org.apache.catalina.connector.MapperListener - Unknown default host: 172.22.0.18 icscf | 26(52) INFO: cdp [receiver.c:459]: receiver_process(): receiver_process(): [hss.ims.mnc001.mcc001.3gppnetwork.org] Receiver process starting up... fhoss | [main] INFO org.apache.catalina.core.StandardHost - XML validation disabled scscf | 10(41) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1002] icscf | 27(53) INFO: cdp [tcp_accept.c:176]: accept_connection(): accept_connection(): new tcp connection accepted! fhoss | [main] INFO de.fhg.fokus.hss.web.servlet.ResponseFilter - Response Filter Initialisation! rtpengine | + ip6tables-save scscf | 10(41) INFO: cdp [worker.c:332]: worker_process(): [1] Worker process started... dns | 05-May-2021 12:36:04.745 automatic empty zone: 70.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.745 automatic empty zone: 71.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.745 automatic empty zone: 72.100.IN-ADDR.ARPA fhoss | log4j:WARN No appenders could be found for logger (org.apache.catalina.loader.WebappClassLoader). fhoss | log4j:WARN Please initialize the log4j system properly. fhoss | [main] INFO org.apache.struts.tiles.TilesPlugin - Tiles definition factory loaded for module ''. rtpengine | + ip r add 192.168.101.0/24 via 172.22.0.8 icscf | 25(51) INFO: cdp [receiver.c:186]: add_serviced_peer(): add_serviced_peer(): Adding serviced_peer_t to receiver for peer [] rtpengine | + set -x rtpengine | + exec rtpengine --interface=172.22.0.16 --listen-ng=172.22.0.16:2223 --listen-cli=172.22.0.16:9901 --pidfile=/run/ngcp-rtpengine-daemon.pid --port-min=49000 --port-max=50000 --table=0 --tos=184 --foreground icscf | 25(51) INFO: cdp [receiver.c:246]: drop_serviced_peer(): drop_serviced_peer(): Dropping serviced_peer_t from receiver for peer [hss.ims.mnc001.mcc001.3gppnetwork.org] dns | 05-May-2021 12:36:04.746 automatic empty zone: 73.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.746 automatic empty zone: 74.100.IN-ADDR.ARPA scscf | 9(40) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1001] fhoss | [main] INFO org.apache.struts.validator.ValidatorPlugIn - Loading validation rules file from '/WEB-INF/validator-rules.xml' mme | Generating a RSA private key fhoss | [main] INFO org.apache.struts.validator.ValidatorPlugIn - Loading validation rules file from '/WEB-INF/validation.xml' dns | 05-May-2021 12:36:04.746 automatic empty zone: 75.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.746 automatic empty zone: 76.100.IN-ADDR.ARPA fhoss | [main] INFO de.fhg.fokus.hss.main.TomcatServer - WebConsole of FHoSS was started ! scscf | 9(40) INFO: cdp [worker.c:332]: worker_process(): [0] Worker process started... scscf | 38(69) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [-4] scscf | 5(36) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [-1] fhoss | [main] INFO org.hibernate.cfg.Environment - Hibernate 3.2.1 scscf | 11(42) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1003] fhoss | [main] INFO org.hibernate.cfg.Environment - loaded properties from resource hibernate.properties: {hibernate.c3p0.timeout=3600, hibernate.connection.driver_class=com.mysql.jdbc.Driver, hibernate.connection.isolation=1, hibernate.c3p0.max_statements=0, hibernate.c3p0.max_size=30, hibernate.dialect=org.hibernate.dialect.MySQLDialect, hibernate.c3p0.idle_test_period=1200, hibernate.c3p0.min_size=1, hibernate.connection.username=hss, hibernate.c3p0.acquire_increment=1, hibernate.connection.url=jdbc:mysql://172.22.0.17:3306/hss_db, hibernate.bytecode.use_reflection_optimizer=false, hibernate.connection.password=****} dns | 05-May-2021 12:36:04.746 automatic empty zone: 77.100.IN-ADDR.ARPA scscf | 11(42) INFO: cdp [worker.c:332]: worker_process(): [2] Worker process started... fhoss | [main] INFO org.hibernate.cfg.Environment - Bytecode provider name : cglib dns | 05-May-2021 12:36:04.746 automatic empty zone: 78.100.IN-ADDR.ARPA scscf | 12(43) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1004] scscf | 12(43) INFO: cdp [worker.c:332]: worker_process(): [3] Worker process started... fhoss | [main] INFO org.hibernate.cfg.Environment - using JDK 1.4 java.sql.Timestamp handling fhoss | [main] INFO org.hibernate.cfg.Configuration - configuring from resource: /hibernate.cfg.xml fhoss | [main] INFO org.hibernate.cfg.Configuration - Configuration resource: /hibernate.cfg.xml dns | 05-May-2021 12:36:04.746 automatic empty zone: 79.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.746 automatic empty zone: 80.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.747 automatic empty zone: 81.100.IN-ADDR.ARPA fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/ApplicationServer.hbm.xml fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.ApplicationServer -> application_server dns | 05-May-2021 12:36:04.747 automatic empty zone: 82.100.IN-ADDR.ARPA fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/CapabilitiesSet.hbm.xml fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.CapabilitiesSet -> capabilities_set fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/Capability.hbm.xml dns | 05-May-2021 12:36:04.747 automatic empty zone: 83.100.IN-ADDR.ARPA scscf | 15(46) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1007] scscf | 8(39) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [-2] fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.Capability -> capability dns | 05-May-2021 12:36:04.747 automatic empty zone: 84.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.747 automatic empty zone: 85.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.747 automatic empty zone: 86.100.IN-ADDR.ARPA fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/ChargingInfo.hbm.xml fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.ChargingInfo -> charging_info fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/DSAI_IMPU.hbm.xml scscf | 16(47) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1008] dns | 05-May-2021 12:36:04.748 automatic empty zone: 87.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.748 automatic empty zone: 88.100.IN-ADDR.ARPA fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.DSAI_IMPU -> dsai_impu fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/DSAI_IFC.hbm.xml fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.DSAI_IFC -> dsai_ifc fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/DSAI.hbm.xml fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.DSAI -> dsai fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/IFC.hbm.xmlscscf | 15(46) INFO: cdp [worker.c:332]: worker_process(): [6] Worker process started... dns | 05-May-2021 12:36:04.748 automatic empty zone: 89.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.748 automatic empty zone: 90.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.748 automatic empty zone: 91.100.IN-ADDR.ARPA fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.IFC -> ifc fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/IMPI_IMPU.hbm.xml scscf | 16(47) INFO: cdp [worker.c:332]: worker_process(): [7] Worker process started... mme | ..............+++++ fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.IMPI_IMPU -> impi_impu fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/IMPI.hbm.xml fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.IMPI -> impi fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/IMPU.hbm.xml pcrf | ............................+++++ dns | 05-May-2021 12:36:04.748 automatic empty zone: 92.100.IN-ADDR.ARPA fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.IMPU -> impu scscf | 8(39) INFO: ctl [io_listener.c:214]: io_listen_loop(): io_listen_loop: using epoll_lt io watch method (config) fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/IMPU_VisitedNetwork.hbm.xml fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.IMPU_VisitedNetwork -> impu_visited_network fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/IMSU.hbm.xml fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.IMSU -> imsu fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/Preferred_SCSCF_Set.hbm.xml scscf | 13(44) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1005] scscf | 18(49) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1010] scscf | 20(51) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1012] dns | 05-May-2021 12:36:04.748 automatic empty zone: 93.100.IN-ADDR.ARPA scscf | 13(44) INFO: cdp [worker.c:332]: worker_process(): [4] Worker process started... dns | 05-May-2021 12:36:04.748 automatic empty zone: 94.100.IN-ADDR.ARPA fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.Preferred_SCSCF_Set -> preferred_scscf_set dns | 05-May-2021 12:36:04.749 automatic empty zone: 95.100.IN-ADDR.ARPA scscf | 18(49) INFO: cdp [worker.c:332]: worker_process(): [9] Worker process started... scscf | 17(48) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1009] smf | .............................+++++ smf | writing new private key to 'cakey.pem' dns | 05-May-2021 12:36:04.749 automatic empty zone: 96.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.749 automatic empty zone: 97.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.749 automatic empty zone: 98.100.IN-ADDR.ARPA fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/CxEvents.hbm.xml scscf | 20(51) INFO: cdp [worker.c:332]: worker_process(): [11] Worker process started... fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.CxEvents -> cx_events smf | ----- dns | 05-May-2021 12:36:04.749 automatic empty zone: 99.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.749 automatic empty zone: 100.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.749 automatic empty zone: 101.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.749 automatic empty zone: 102.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.749 automatic empty zone: 103.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.749 automatic empty zone: 104.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.749 automatic empty zone: 105.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.750 automatic empty zone: 106.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.750 automatic empty zone: 107.100.IN-ADDR.ARPA scscf | 17(48) INFO: cdp [worker.c:332]: worker_process(): [8] Worker process started... fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/Shared_IFC_Set.hbm.xml fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.Shared_IFC_Set -> shared_ifc_set dns | 05-May-2021 12:36:04.750 automatic empty zone: 108.100.IN-ADDR.ARPA smf | Generating RSA private key, 1024 bit long modulus (2 primes) fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/ShNotification.hbm.xml dns | 05-May-2021 12:36:04.750 automatic empty zone: 109.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.750 automatic empty zone: 110.100.IN-ADDR.ARPA mme | ..........+++++ mme | writing new private key to 'cakey.pem' mme | ----- hss | ...............................................+++++ scscf | 19(50) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1011] scscf | 19(50) INFO: cdp [worker.c:332]: worker_process(): [10] Worker process started... scscf | 14(45) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1006] scscf | 14(45) INFO: cdp [worker.c:332]: worker_process(): [5] Worker process started... scscf | 21(52) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1013] scscf | 21(52) INFO: cdp [worker.c:332]: worker_process(): [12] Worker process started... fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.ShNotification -> sh_notification mme | Generating RSA private key, 1024 bit long modulus (2 primes) hss | writing new private key to 'cakey.pem' scscf | 28(59) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1001] fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/ShSubscription.hbm.xml fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.ShSubscription -> sh_subscription scscf | 24(55) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1016] scscf | 28(59) INFO: cdp [timer.c:205]: timer_process(): Timer process starting up... scscf | 31(62) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [127] scscf | 28(59) INFO: cdp [peerstatemachine.c:526]: I_Snd_Conn_Req(): I_Snd_Conn_Req(): Peer hss.ims.mnc001.mcc001.3gppnetwork.org hss | ----- scscf | 24(55) INFO: cdp [worker.c:332]: worker_process(): [15] Worker process started... scscf | 31(62) DEBUG: ims_registrar_scscf [registrar_notify.c:2269]: notification_event_process(): Running notification_event_process scscf | 25(56) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1002] scscf | 28(59) INFO: cdp [receiver.c:874]: peer_connect(): peer_connect(): Trying to connect to 172.22.0.18 port 3868 fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/SP_IFC.hbm.xml hss | Generating RSA private key, 1024 bit long modulus (2 primes) scscf | 28(59) ERROR: cdp [receiver.c:922]: peer_connect(): peer_connect(): Error opening connection to to 172.22.0.18 port 3868 >Connection refused scscf | 25(56) INFO: cdp [receiver.c:454]: receiver_process(): receiver_process(): [] Receiver process doing init on new process... scscf | 25(56) INFO: cdp [receiver.c:459]: receiver_process(): receiver_process(): [] Receiver process starting up... fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.SP_IFC -> sp_ifcdns | 05-May-2021 12:36:04.750 automatic empty zone: 111.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.750 automatic empty zone: 112.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.750 automatic empty zone: 113.100.IN-ADDR.ARPA scscf | 23(54) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1015] fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/SP_Shared_IFC_Set.hbm.xml scscf | 22(53) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1014] fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.SP_Shared_IFC_Set -> sp_shared_ifc_set fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/SP.hbm.xml fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.SP -> sp fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/SPT.hbm.xmlscscf | 32(63) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [127] fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.SPT -> spt fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/TP.hbm.xml scscf | 23(54) INFO: cdp [worker.c:332]: worker_process(): [14] Worker process started... dns | 05-May-2021 12:36:04.750 automatic empty zone: 114.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.750 automatic empty zone: 115.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.751 automatic empty zone: 116.100.IN-ADDR.ARPA fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.TP -> tp fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/VisitedNetwork.hbm.xml scscf | 22(53) INFO: cdp [worker.c:332]: worker_process(): [13] Worker process started... fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.VisitedNetwork -> visited_network scscf | 32(63) DEBUG: ims_registrar_scscf [registrar_notify.c:2269]: notification_event_process(): Running notification_event_process dns | 05-May-2021 12:36:04.751 automatic empty zone: 117.100.IN-ADDR.ARPA scscf | 27(58) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1000] scscf | 27(58) INFO: cdp [acceptor.c:81]: acceptor_process(): Acceptor process starting up... scscf | 26(57) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [1000] fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/RepositoryData.hbm.xml pcrf | ....................+++++ dns | 05-May-2021 12:36:04.751 automatic empty zone: 118.100.IN-ADDR.ARPA pcrf | writing new private key to 'cakey.pem' mme | .........................+++++ scscf | 27(58) WARNING: cdp [tcp_accept.c:120]: create_socket(): create_socket(): Trying to open/bind/listen on 172.22.0.20 port 3870 scscf | 27(58) WARNING: cdp [tcp_accept.c:145]: create_socket(): create_socket(): Successful socket open/bind/listen on 172.22.0.20 port 3870 scscf | 27(58) INFO: cdp [acceptor.c:95]: acceptor_process(): Acceptor opened sockets. Entering accept loop ... scscf | 29(60) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [127] fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.RepositoryData -> repository_data dns | 05-May-2021 12:36:04.751 automatic empty zone: 119.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.751 automatic empty zone: 120.100.IN-ADDR.ARPA fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/AliasesRepositoryData.hbm.xml scscf | 26(57) INFO: cdp [receiver.c:454]: receiver_process(): receiver_process(): [hss.ims.mnc001.mcc001.3gppnetwork.org] Receiver process doing init on new process... scscf | 26(57) INFO: cdp [receiver.c:186]: add_serviced_peer(): add_serviced_peer(): Adding serviced_peer_t to receiver for peer [hss.ims.mnc001.mcc001.3gppnetwork.org] pcrf | ----- dns | 05-May-2021 12:36:04.752 automatic empty zone: 121.100.IN-ADDR.ARPA fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.AliasesRepositoryData -> aliases_repository_data pcrf | Generating RSA private key, 1024 bit long modulus (2 primes) hss | ......+++++ fhoss | [main] INFO org.hibernate.cfg.Configuration - Reading mappings from resource : mappings/Zh_USS.hbm.xml scscf | 33(64) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [-2] fhoss | [main] INFO org.hibernate.cfg.HbmBinder - Mapping class: de.fhg.fokus.hss.db.model.Zh_USS -> zh_ussscscf | 29(60) DEBUG: ims_registrar_scscf [registrar_notify.c:2269]: notification_event_process(): Running notification_event_process dns | 05-May-2021 12:36:04.752 automatic empty zone: 122.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.752 automatic empty zone: 123.100.IN-ADDR.ARPA fhoss | [main] INFO org.hibernate.cfg.Configuration - Configured SessionFactory: foo fhoss | [main] INFO org.hibernate.connection.C3P0ConnectionProvider - C3P0 using driver: com.mysql.jdbc.Driver at URL: jdbc:mysql://172.22.0.17:3306/hss_db scscf | 35(66) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [5] fhoss | [main] INFO org.hibernate.connection.C3P0ConnectionProvider - Connection properties: {user=hss, password=****, autocommit=false} scscf | 37(68) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [7] dns | 05-May-2021 12:36:04.752 automatic empty zone: 124.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.752 automatic empty zone: 125.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.752 automatic empty zone: 126.100.IN-ADDR.ARPA scscf | 36(67) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [6] scscf | 30(61) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [127] fhoss | [main] INFO org.hibernate.connection.C3P0ConnectionProvider - autocommit mode: false scscf | 34(65) DEBUG: ims_registrar_scscf [ims_registrar_scscf_mod.c:528]: child_init(): Initialization of module in child [-2] dns | 05-May-2021 12:36:04.752 automatic empty zone: 127.100.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.752 automatic empty zone: 0.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.752 automatic empty zone: 127.IN-ADDR.ARPA scscf | 30(61) DEBUG: ims_registrar_scscf [registrar_notify.c:2269]: notification_event_process(): Running notification_event_process fhoss | [main] INFO com.mchange.v2.log.MLog - MLog clients using log4j logging. scscf | 34(65) INFO: jsonrpcs [jsonrpcs_sock.c:443]: jsonrpc_dgram_process(): a new child 0/65 scscf | 26(57) INFO: cdp [receiver.c:459]: receiver_process(): receiver_process(): [hss.ims.mnc001.mcc001.3gppnetwork.org] Receiver process starting up... scscf | 5(36) DEBUG: ims_dialog [dlg_handlers.c:1923]: print_all_dlgs(): ******************** 5(36) DEBUG: ims_dialog [dlg_handlers.c:1924]: print_all_dlgs(): printing 4096 dialogs scscf | 5(36) DEBUG: ims_dialog [dlg_handlers.c:1934]: print_all_dlgs(): ******************** 5(36) DEBUG: ims_auth [authorize.c:187]: reg_await_timer(): Looking for expired/useless at 7559624 dns | 05-May-2021 12:36:04.752 automatic empty zone: 254.169.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.752 automatic empty zone: 2.0.192.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.753 automatic empty zone: 100.51.198.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.753 automatic empty zone: 113.0.203.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.753 automatic empty zone: 255.255.255.255.IN-ADDR.ARPA dns | 05-May-2021 12:36:04.753 automatic empty zone: 0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.IP6.ARPA fhoss | [main] INFO com.mchange.v2.c3p0.C3P0Registry - Initializing c3p0-0.9.1 [built 16-January-2007 14:46:42; debug? true; trace: 10] fhoss | [main] INFO org.hibernate.connection.C3P0ConnectionProvider - JDBC isolation level: READ_UNCOMMITTED scscf | 5(36) DEBUG: ims_auth [authorize.c:232]: reg_await_timer(): [DONE] Looking for expired/useless at 7559624 scscf | 27(58) INFO: cdp [tcp_accept.c:176]: accept_connection(): accept_connection(): new tcp connection accepted! scscf | 25(56) INFO: cdp [receiver.c:186]: add_serviced_peer(): add_serviced_peer(): Adding serviced_peer_t to receiver for peer [] dns | 05-May-2021 12:36:04.753 automatic empty zone: 1.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.0.IP6.ARPA fhoss | [main] INFO com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource - Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@a286cffc [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@923e9add [ acquireIncrement -> 1, acquireRetryAttempts -> 60, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, debugUnreturnedConnectionStackTraces -> false, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 1bqx2c2ahgsnf751rzxhvi|1e313298, idleConnectionTestPeriod -> 1200, initialPoolSize -> 1, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 3600, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 30, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 1, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@89297899 [ description -> null, driverClass -> null, factoryClassLocation -> null, identityToken -> 1bqx2c2ahgsnf751rzxhvi|7118a4, jdbcUrl -> jdbc:mysql://172.22.0.17:3306/hss_db, properties -> {user=******, password=******, autocommit=false} ], preferredTestQuery -> null, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false; userOverrides: {} ], dataSourceName -> null, factoryClassLocation -> null, identityToken -> 1bqx2c2ahgsnf751rzxhvi|5eb10a01, numHelperThreads -> 3 ] dns | 05-May-2021 12:36:04.753 automatic empty zone: D.F.IP6.ARPA fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - RDBMS: MySQL, version: 5.7.33-0ubuntu0.18.04.1 fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - JDBC driver: MySQL-AB JDBC Driver, version: mysql-connector-java-3.1.12 ( $Date: 2005-11-17 15:53:48 +0100 (Thu, 17 Nov 2005) $, $Revision$ ) fhoss | [main] INFO org.hibernate.dialect.Dialect - Using dialect: org.hibernate.dialect.MySQLDialect scscf | 25(56) INFO: cdp [receiver.c:246]: drop_serviced_peer(): drop_serviced_peer(): Dropping serviced_peer_t from receiver for peer [hss.ims.mnc001.mcc001.3gppnetwork.org] fhoss | [main] INFO org.hibernate.transaction.TransactionFactoryFactory - Using default transaction strategy (direct JDBC transactions) fhoss | [main] INFO org.hibernate.transaction.TransactionManagerLookupFactory - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended) fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Automatic flush during beforeCompletion(): disabledfhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Automatic session close at end of transaction: disabled dns | 05-May-2021 12:36:04.753 automatic empty zone: 8.E.F.IP6.ARPA fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - JDBC batch size: 15 fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - JDBC batch updates for versioned data: disabled dns | 05-May-2021 12:36:04.753 automatic empty zone: 9.E.F.IP6.ARPA fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Scrollable result sets: enabled fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - JDBC3 getGeneratedKeys(): enabled fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Connection release mode: auto fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Maximum outer join fetch depth: 2 dns | 05-May-2021 12:36:04.754 automatic empty zone: A.E.F.IP6.ARPA dns | 05-May-2021 12:36:04.754 automatic empty zone: B.E.F.IP6.ARPA fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Default batch fetch size: 1 hss | .........+++++ fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Generate SQL with comments: disabled dns | 05-May-2021 12:36:04.754 automatic empty zone: 8.B.D.0.1.0.0.2.IP6.ARPA hss | e is 65537 (0x010001) dns | 05-May-2021 12:36:04.754 automatic empty zone: EMPTY.AS112.ARPA fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Order SQL updates by primary key: disabled fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory fhoss | [main] INFO org.hibernate.hql.ast.ASTQueryTranslatorFactory - Using ASTQueryTranslatorFactory fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Query language substitutions: {} fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - JPA-QL strict compliance: disabled fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Second-level cache: enabled fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Query cache: disabled fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Cache provider: org.hibernate.cache.NoCacheProviderhss | Using configuration from /usr/lib/ssl/openssl.cnf dns | 05-May-2021 12:36:04.755 none:103: 'max-cache-size 90%' - setting to 7177MB (out of 7975MB) fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Optimize cache for minimal puts: disabled fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Structured second-level cache entries: disabled fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Statistics: disabled fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Deleted entity synthetic identifier rollback: disabled dns | 05-May-2021 12:36:04.768 configuring command channel from '/etc/bind/rndc.key' hss | Check that the request matches the signature hss | Signature ok fhoss | [main] INFO org.hibernate.cfg.SettingsFactory - Default entity-mode: pojo dns | 05-May-2021 12:36:04.771 command channel listening on 127.0.0.1#953 dns | 05-May-2021 12:36:04.771 configuring command channel from '/etc/bind/rndc.key' dns | 05-May-2021 12:36:04.771 couldn't add command channel ::1#953: address not available fhoss | [main] INFO org.hibernate.impl.SessionFactoryImpl - building session factory fhoss | [main] INFO org.hibernate.impl.SessionFactoryObjectFactory - Factory name: foo dns | 05-May-2021 12:36:04.771 not using config file logging statement for logging due to -g option hss | Certificate Details: hss | Serial Number: 1 (0x1) hss | Validity hss | Not Before: May 5 12:36:36 2021 GMT hss | Not After : May 3 12:36:36 2031 GMT hss | Subject: hss | countryName = KO hss | stateOrProvinceName = Seoul hss | organizationName = Open5GS hss | organizationalUnitName = Tests hss | commonName = hss.epc.mnc001.mcc001.3gppnetwork.org hss | X509v3 extensions: hss | X509v3 Basic Constraints: hss | CA:FALSE hss | Netscape Comment: hss | OpenSSL Generated Certificate hss | X509v3 Subject Key Identifier: hss | C4:80:61:ED:72:15:DB:45:75:17:72:44:AE:3D:54:C3:C4:92:7F:CE hss | X509v3 Authority Key Identifier: hss | keyid:02:EE:AA:88:60:23:8D:53:C9:B5:F2:52:69:F8:8E:BA:90:61:D0:95 hss | hss | Certificate is to be certified until May 3 12:36:36 2031 GMT (3650 days) hss | hss | Write out database with 1 new entries hss | Data Base Updated hss | Open5GS daemon v2.2.7 hss | fhoss | [main] INFO org.hibernate.util.NamingHelper - JNDI InitialContext properties:{} fhoss | [main] INFO org.hibernate.impl.SessionFactoryObjectFactory - Bound factory to JNDI name: foo hss | 05/05 12:36:46.772: [app] INFO: Configuration: '/open5gs/install/etc/open5gs/hss.yaml' (../lib/app/ogs-init.c:129) hss | 05/05 12:36:46.772: [app] INFO: File Logging: '/open5gs/install/var/log/open5gs/hss.log' (../lib/app/ogs-init.c:132) hss | 05/05 12:36:46.780: [dbi] INFO: MongoDB URI: 'mongodb://172.22.0.2/open5gs' (../lib/dbi/ogs-mongoc.c:129) dns | 05-May-2021 12:36:04.773 managed-keys-zone: loaded serial 0 fhoss | [main] WARN org.hibernate.impl.SessionFactoryObjectFactory - InitialContext did not implement EventContext hss | 05/05 12:36:46.940: [app] INFO: HSS initialize...done (../src/hss/app-init.c:31) dns | 05-May-2021 12:36:04.787 zone epc.mnc001.mcc001.3gppnetwork.org/IN: loaded serial 1 smf | ................................+++++ fhoss | [main] INFO de.fhg.fokus.diameter.DiameterPeer.DiameterPeer - Bean style constructor called, don't forget to configure! dns | 05-May-2021 12:36:04.789 zone ims.mnc001.mcc001.3gppnetwork.org/IN: loaded serial 1 dns | 05-May-2021 12:36:04.790 all zones loaded fhoss | [main] INFO de.fhg.fokus.diameter.DiameterPeer.DiameterPeer - FQDN: hss.ims.mnc001.mcc001.3gppnetwork.org fhoss | [main] INFO de.fhg.fokus.diameter.DiameterPeer.DiameterPeer - Realm: ims.mnc001.mcc001.3gppnetwork.org fhoss | [main] INFO de.fhg.fokus.diameter.DiameterPeer.DiameterPeer - Vendor_ID : 10415 fhoss | [main] INFO de.fhg.fokus.diameter.DiameterPeer.DiameterPeer - Product Name: JavaDiameterPeer fhoss | [main] INFO de.fhg.fokus.diameter.DiameterPeer.DiameterPeer - AcceptUnknwonPeers: true dns | 05-May-2021 12:36:04.791 running dns | 05-May-2021 12:36:04.791 zone ims.mnc001.mcc001.3gppnetwork.org/IN: sending notifies (serial 1) dns | 05-May-2021 12:36:04.791 zone epc.mnc001.mcc001.3gppnetwork.org/IN: sending notifies (serial 1) fhoss | [main] INFO de.fhg.fokus.diameter.DiameterPeer.DiameterPeer - DropUnknownOnDisconnect: true fhoss | [main] INFO de.fhg.fokus.hss.main.HSSContainer - fhoss | Type "exit" to stop FHoSS! fhoss | Exception in thread "main" java.lang.StringIndexOutOfBoundsException: String index out of range: -1 fhoss | at java.lang.String.checkBounds(String.java:371) fhoss | at java.lang.String.(String.java:535) fhoss | at de.fhg.fokus.hss.main.HSSContainer.waitForExit(HSSContainer.java:137) mme | ....................................+++++ mme | e is 65537 (0x010001) mme | Using configuration from /usr/lib/ssl/openssl.cnf mme | Check that the request matches the signature fhoss | at de.fhg.fokus.hss.main.HSSContainer.main(HSSContainer.java:111) mme | Signature ok mme | Certificate Details: mme | Serial Number: 1 (0x1) mme | Validity mme | Not Before: May 5 12:37:37 2021 GMT mme | Not After : May 3 12:37:37 2031 GMT mme | Subject: mme | countryName = KO mme | stateOrProvinceName = Seoul mme | organizationName = Open5GS mme | organizationalUnitName = Tests mme | commonName = mme.epc.mnc001.mcc001.3gppnetwork.org mme | X509v3 extensions: mme | X509v3 Basic Constraints: mme | CA:FALSE mme | Netscape Comment: mme | OpenSSL Generated Certificate mme | X509v3 Subject Key Identifier: mme | C7:FC:21:9A:B0:09:E6:53:86:40:56:32:BF:DD:6B:CA:09:C5:99:6C mme | X509v3 Authority Key Identifier: mme | keyid:2D:FF:46:79:58:19:7C:AF:30:D2:F7:39:77:E3:C8:72:6B:B9:C5:45 mme | mme | Certificate is to be certified until May 3 12:37:37 2031 GMT (3650 days) mme | mme | Write out database with 1 new entries mme | Data Base Updated smf | .....................................................+++++ smf | e is 65537 (0x010001) smf | Using configuration from /usr/lib/ssl/openssl.cnf smf | Check that the request matches the signature smf | Signature ok smf | Certificate Details: smf | Serial Number: 1 (0x1) smf | Validity smf | Not Before: May 5 12:36:35 2021 GMT smf | Not After : May 3 12:36:35 2031 GMT smf | Subject: smf | countryName = KO smf | stateOrProvinceName = Seoul smf | organizationName = Open5GS smf | organizationalUnitName = Tests pcrf | ...................................................................+++++ smf | commonName = mme.epc.mnc001.mcc001.3gppnetwork.org smf | X509v3 extensions: smf | X509v3 Basic Constraints: smf | CA:FALSE smf | Netscape Comment: smf | OpenSSL Generated Certificate smf | X509v3 Subject Key Identifier: smf | 3B:11:D0:BD:92:25:24:BF:E2:E1:BA:0B:C0:86:59:B4:4B:46:DA:95 smf | X509v3 Authority Key Identifier: smf | keyid:E2:65:93:B3:A5:63:67:EE:D5:A5:CD:95:0A:50:74:A6:82:BD:45:25 smf | smf | Certificate is to be certified until May 3 12:36:35 2031 GMT (3650 days) smf | smf | Write out database with 1 new entries smf | Data Base Updated smf | Generating RSA private key, 1024 bit long modulus (2 primes) pcrf | .....+++++ pcrf | e is 65537 (0x010001) pcrf | Using configuration from /usr/lib/ssl/openssl.cnf pcrf | Check that the request matches the signature pcrf | Signature ok smf | ..+++++ pcrf | Certificate Details: pcrf | Serial Number: 1 (0x1) pcrf | Validity pcrf | Not Before: May 5 12:36:39 2021 GMT pcrf | Not After : May 3 12:36:39 2031 GMT pcrf | Subject: pcrf | countryName = KO pcrf | stateOrProvinceName = Seoul pcrf | organizationName = Open5GS pcrf | organizationalUnitName = Tests pcrf | commonName = pcrf.epc.mnc001.mcc001.3gppnetwork.org pcrf | X509v3 extensions: pcrf | X509v3 Basic Constraints: pcrf | CA:FALSE pcrf | Netscape Comment: pcrf | OpenSSL Generated Certificate pcrf | X509v3 Subject Key Identifier: pcrf | F8:B5:CA:19:21:5B:5C:FF:E3:42:10:CF:15:39:0F:3D:01:6E:AC:2E pcrf | X509v3 Authority Key Identifier: pcrf | keyid:12:92:87:42:69:7F:CA:14:95:F1:C4:32:DE:1E:1F:33:E7:AE:50:E4 pcrf | pcrf | Certificate is to be certified until May 3 12:36:39 2031 GMT (3650 days) pcrf | pcrf | Write out database with 1 new entries pcrf | Data Base Updated pcrf | Open5GS daemon v2.2.7 pcrf | pcrf | 05/05 12:36:50.174: [app] INFO: Configuration: '/open5gs/install/etc/open5gs/pcrf.yaml' (../lib/app/ogs-init.c:129) pcrf | 05/05 12:36:50.174: [app] INFO: File Logging: '/open5gs/install/var/log/open5gs/pcrf.log' (../lib/app/ogs-init.c:132) pcrf | 05/05 12:36:50.181: [dbi] INFO: MongoDB URI: 'mongodb://172.22.0.2/open5gs' (../lib/dbi/ogs-mongoc.c:129) pcrf | 05/05 12:36:50.374: [diam] INFO: CONNECTED TO 'smf.epc.mnc001.mcc001.3gppnetwork.org' (SCTP,soc#18): (../lib/diameter/common/logger.c:108) pcrf | 05/05 12:36:50.374: [app] INFO: PCRF initialize...done (../src/pcrf/app-init.c:31) smf | ..............................................+++++ smf | e is 65537 (0x010001) smf | Using configuration from /usr/lib/ssl/openssl.cnf smf | Check that the request matches the signature smf | Signature ok smf | Certificate Details: smf | Serial Number: 2 (0x2) smf | Validity smf | Not Before: May 5 12:36:35 2021 GMT smf | Not After : May 3 12:36:35 2031 GMT smf | Subject: smf | countryName = KO smf | stateOrProvinceName = Seoul smf | organizationName = Open5GS smf | organizationalUnitName = Tests smf | commonName = hss.epc.mnc001.mcc001.3gppnetwork.org smf | X509v3 extensions: smf | X509v3 Basic Constraints: smf | CA:FALSE smf | Netscape Comment: smf | OpenSSL Generated Certificate smf | X509v3 Subject Key Identifier: smf | 99:EF:C8:5B:AD:BB:AF:57:43:35:81:0F:42:7E:C6:26:2B:66:3B:51 smf | X509v3 Authority Key Identifier: smf | keyid:E2:65:93:B3:A5:63:67:EE:D5:A5:CD:95:0A:50:74:A6:82:BD:45:25 smf | smf | Certificate is to be certified until May 3 12:36:35 2031 GMT (3650 days) smf | smf | Write out database with 1 new entries smf | Data Base Updated smf | Generating RSA private key, 1024 bit long modulus (2 primes) smf | .....+++++ smf | .................+++++ smf | e is 65537 (0x010001) smf | Using configuration from /usr/lib/ssl/openssl.cnf smf | Check that the request matches the signature smf | Signature ok smf | Certificate Details: smf | Serial Number: 3 (0x3) smf | Validity smf | Not Before: May 5 12:36:36 2021 GMT smf | Not After : May 3 12:36:36 2031 GMT smf | Subject: smf | countryName = KO smf | stateOrProvinceName = Seoul smf | organizationName = Open5GS smf | organizationalUnitName = Tests smf | commonName = smf.epc.mnc001.mcc001.3gppnetwork.org smf | X509v3 extensions: smf | X509v3 Basic Constraints: smf | CA:FALSE smf | Netscape Comment: smf | OpenSSL Generated Certificate smf | X509v3 Subject Key Identifier: smf | A3:E3:7C:55:BE:54:99:77:B7:53:B9:BA:30:FB:F6:96:90:A5:9A:58 smf | X509v3 Authority Key Identifier: smf | keyid:E2:65:93:B3:A5:63:67:EE:D5:A5:CD:95:0A:50:74:A6:82:BD:45:25 smf | smf | Certificate is to be certified until May 3 12:36:36 2031 GMT (3650 days) smf | smf | Write out database with 1 new entries smf | Data Base Updated smf | Generating RSA private key, 1024 bit long modulus (2 primes) smf | .....................+++++ smf | .......+++++ smf | e is 65537 (0x010001) smf | Using configuration from /usr/lib/ssl/openssl.cnf smf | Check that the request matches the signature smf | Signature ok smf | Certificate Details: smf | Serial Number: 4 (0x4) smf | Validity smf | Not Before: May 5 12:36:36 2021 GMT smf | Not After : May 3 12:36:36 2031 GMT smf | Subject: smf | countryName = KO smf | stateOrProvinceName = Seoul smf | organizationName = Open5GS smf | organizationalUnitName = Tests smf | commonName = pcrf.epc.mnc001.mcc001.3gppnetwork.org smf | X509v3 extensions: smf | X509v3 Basic Constraints: smf | CA:FALSE smf | Netscape Comment: smf | OpenSSL Generated Certificate smf | X509v3 Subject Key Identifier: smf | 55:55:F3:EC:49:B8:B8:26:11:88:D8:7B:1D:77:60:02:0D:EF:98:E0 smf | X509v3 Authority Key Identifier: smf | keyid:E2:65:93:B3:A5:63:67:EE:D5:A5:CD:95:0A:50:74:A6:82:BD:45:25 smf | smf | Certificate is to be certified until May 3 12:36:36 2031 GMT (3650 days) smf | smf | Write out database with 1 new entries smf | Data Base Updated smf | Open5GS daemon v2.2.7 smf | smf | 05/05 12:36:37.676: [app] INFO: Configuration: '/open5gs/install/etc/open5gs/smf.yaml' (../lib/app/ogs-init.c:129) smf | 05/05 12:36:37.676: [app] INFO: File Logging: '/open5gs/install/var/log/open5gs/smf.log' (../lib/app/ogs-init.c:132) smf | 05/05 12:36:38.404: [gtp] INFO: gtp_server() [172.22.0.7]:2123 (../lib/gtp/path.c:31) smf | 05/05 12:36:38.404: [gtp] INFO: gtp_server() [172.22.0.7]:2152 (../lib/gtp/path.c:31) smf | 05/05 12:36:38.404: [pfcp] INFO: pfcp_server() [172.22.0.7]:8805 (../lib/pfcp/path.c:31) smf | 05/05 12:36:38.405: [pfcp] INFO: ogs_pfcp_connect() [172.22.0.8]:8805 (../lib/pfcp/path.c:60) smf | 05/05 12:36:38.407: [sbi] INFO: nghttp2_server() [172.22.0.7]:7777 (../lib/sbi/nghttp2-server.c:145) smf | 05/05 12:36:38.408: [app] INFO: SMF initialize...done (../src/smf/app.c:31) smf | 05/05 12:36:38.410: [smf] INFO: [88d4aa3c-ad9e-41eb-af42-33b14ac7080c] NF registred [Heartbeat:10s] (../src/smf/nf-sm.c:200) smf | 05/05 12:36:45.913: [pfcp] WARNING: [1] LOCAL No Reponse. Give up! for step 1 type 5 peer [172.22.0.8]:8805 (../lib/pfcp/xact.c:618) smf | 05/05 12:36:49.406: [smf] WARNING: Retry to association with peer [172.22.0.8]:8805 failed (../src/smf/pfcp-sm.c:108) smf | 05/05 12:36:50.373: [diam] INFO: CONNECTED TO 'pcrf.epc.mnc001.mcc001.3gppnetwork.org' (SCTP,soc#7): (../lib/diameter/common/logger.c:108) smf | 05/05 12:36:51.562: [smf] INFO: PFCP associated (../src/smf/pfcp-sm.c:174) smf | 05/05 12:36:51.909: [smf] WARNING: PFCP[RSP] has already been associated (../src/smf/pfcp-sm.c:206) smf | 05/05 12:37:26.712: [smf] INFO: [a6093870-ad9e-41eb-b980-937727dd07fd] (NRF-notify) NF registered (../src/smf/nnrf-handler.c:177) smf | 05/05 12:37:26.712: [smf] INFO: [a6093870-ad9e-41eb-b980-937727dd07fd] (NRF-notify) NF Profile updated (../src/smf/nnrf-handler.c:196) mme | Open5GS daemon v2.2.7 mme | mme | 05/05 12:37:39.187: [app] INFO: Configuration: '/open5gs/install/etc/open5gs/mme.yaml' (../lib/app/ogs-init.c:129) mme | 05/05 12:37:39.187: [app] INFO: File Logging: '/open5gs/install/var/log/open5gs/mme.log' (../lib/app/ogs-init.c:132) hss | 05/05 12:37:39.309: [diam] INFO: CONNECTED TO 'mme.epc.mnc001.mcc001.3gppnetwork.org' (SCTP,soc#10): (../lib/diameter/common/logger.c:108) mme | 05/05 12:37:39.310: [diam] INFO: CONNECTED TO 'hss.epc.mnc001.mcc001.3gppnetwork.org' (SCTP,soc#14): (../lib/diameter/common/logger.c:108) mme | 05/05 12:37:39.383: [gtp] INFO: gtp_server() [172.22.0.9]:2123 (../lib/gtp/path.c:31) mme | 05/05 12:37:39.383: [gtp] INFO: gtp_connect() [172.22.0.5]:2123 (../lib/gtp/path.c:59) mme | 05/05 12:37:39.383: [mme] INFO: s1ap_server() [172.22.0.9]:36412 (../src/mme/s1ap-sctp.c:55) mme | 05/05 12:37:39.384: [sctp] INFO: MME initialize...done (../src/mme/app-init.c:33) scscf | 5(36) DEBUG: ims_dialog [dlg_handlers.c:1923]: print_all_dlgs(): ******************** 5(36) DEBUG: ims_dialog [dlg_handlers.c:1924]: print_all_dlgs(): printing 4096 dialogs scscf | 5(36) DEBUG: ims_dialog [dlg_handlers.c:1934]: print_all_dlgs(): ******************** 5(36) DEBUG: ims_auth [authorize.c:187]: reg_await_timer(): Looking for expired/useless at 7559634 scscf | 5(36) DEBUG: ims_auth [authorize.c:232]: reg_await_timer(): [DONE] Looking for expired/useless at 7559634 pcscf | 0(33) INFO: pv [pv_shv.c:60]: shvar_init_locks(): locks array size 16 pcscf | 0(33) INFO: [core/tcp_main.c:5042]: init_tcp(): using epoll_lt as the io watch method (auto detected) pcscf | loading modules under config path: /usr/lib64/kamailio/modules_k/:/usr/lib64/kamailio/modules/:/usr/lib/kamailio/modules_k/:/usr/lib/kamailio/modules/:/usr/lib/x86_64-linux-gnu/kamailio/modules/:/usr/local/lib64/kamailio/modules pcscf | Listening on pcscf | udp: 172.22.0.21 [172.22.0.21]:5060 pcscf | tcp: 172.22.0.21 [172.22.0.21]:5060 pcscf | Aliases: pcscf | *: pcscf.ims.mnc001.mcc001.3gppnetwork.org:* pcscf | pcscf | 0(33) INFO: rr [../outbound/api.h:52]: ob_load_api(): unable to import bind_ob - maybe module is not loaded pcscf | 0(33) INFO: rr [rr_mod.c:177]: mod_init(): outbound module not available pcscf | 0(33) INFO: auth [auth_mod.c:345]: mod_init(): qop set, but nonce-count (nc_enabled) support disabled pcscf | 0(33) INFO: path [../outbound/api.h:52]: ob_load_api(): unable to import bind_ob - maybe module is not loaded pcscf | 0(33) INFO: path [path_mod.c:151]: mod_init(): outbound module not available pcscf | 0(33) INFO: ims_usrloc_pcscf [hslot.c:62]: ul_init_locks(): locks array size 512 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:268]: mod_init(): Successfully bound to PCSCF Usrloc module pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:275]: mod_init(): Successfully bound to TM modulepcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:118]: ipsec_print_all_socket_lists(): Listening on: pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:5060 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:5100 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:6100 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:5101 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:6101 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:5102 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:6102 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:5103 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:6103 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:5104 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:6104 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:5105 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:6105 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:5106 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:6106 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:5107 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:6107 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:5108 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:6108 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:5109 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): udp: 172.22.0.21 [172.22.0.21]:6109 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:5060 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:5100 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:6100 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:5101 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:6101 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:5102 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:6102 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:5103 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:6103 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:5104 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:6104 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:5105 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:6105 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:5106 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:6106 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:5107 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:6107 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:5108 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:6108 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:5109 pcscf | 0(33) INFO: ims_ipsec_pcscf [ims_ipsec_pcscf_mod.c:168]: ipsec_print_all_socket_lists(): tcp: 172.22.0.21 [172.22.0.21]:6109 pcscf | 0(33) INFO: ims_registrar_pcscf [ims_registrar_pcscf_mod.c:275]: mod_init(): Successfully bound to PCSCF IPSEC module pcscf | 0(33) INFO: [main.c:2779]: main(): processes (at least): 111 - shm size: 67108864 - pkg size: 8388608 pcscf | 0(33) WARNING: tm [tm.c:507]: fixup_routes(): t_on_failure("NATMANAGE"): empty/non existing route pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) INFO: [core/udp_server.c:154]: probe_max_receive_buffer(): SO_RCVBUF is initially 212992 pcscf | 0(33) INFO: [core/udp_server.c:206]: probe_max_receive_buffer(): SO_RCVBUF is finally 425984 pcscf | 0(33) ERROR: