search

opennetworkinglab / aether-onramp

Apache License 2.0
15 stars 22 forks source link

FAILED - RETRYING: [node1]: async check gnbsims #18

Open JhengLu opened 4 months ago

JhengLu commented 4 months ago

Hi there, When I want to run the command

make aether-gnbsim-run

It keeps showing the error:

FAILED - RETRYING: [node1]: async check gnbsims (500 retries left).
FAILED - RETRYING: [node1]: async check gnbsims (499 retries left).
FAILED - RETRYING: [node1]: async check gnbsims (498 retries left).
FAILED - RETRYING: [node1]: async check gnbsims (497 retries left).
FAILED - RETRYING: [node1]: async check gnbsims (496 retries left).
FAILED - RETRYING: [node1]: async check gnbsims (495 retries left).
FAILED - RETRYING: [node1]: async check gnbsims (494 retries left).
FAILED - RETRYING: [node1]: async check gnbsims (493 retries left).
FAILED - RETRYING: [node1]: async check gnbsims (492 retries left).
FAILED - RETRYING: [node1]: async check gnbsims (491 retries left).
FAILED - RETRYING: [node1]: async check gnbsims (490 retries left).
FAILED - RETRYING: [node1]: async check gnbsims (489 retries left).
FAILED - RETRYING: [node1]: async check gnbsims (488 retries left).
...

TASK [simulator : force stop gnbsims] **********************************************************************************************************************************************************
fatal: [node1]: FAILED! => {"changed": true, "cmd": "pkill -9 -f /gnbsim/bin/gnbsim\n", "delta": "0:00:00.026968", "end": "2024-04-22 20:36:39.871594", "msg": "non-zero return code", "rc": -9, "start": "2024-04-22 20:36:39.844626", "stderr": "", "stderr_lines": [], "stdout": "", "stdout_lines": []}
...ignoring

Can you help me solve this problem? The summary.log looks like this:

docker exec -it gnbsim-1 cat summary.log
time="2024-04-23T02:36:27Z" level=info msg="Profile Name: profile3 , Profile Type: anrelease" category=Summary component=GNBSIM
time="2024-04-23T02:36:27Z" level=info msg="Ue's Passed: 2 , Ue's Failed: 3" category=Summary component=GNBSIM
time="2024-04-23T02:36:27Z" level=info msg="Profile Errors:" category=Summary component=GNBSIM
time="2024-04-23T02:36:27Z" level=error msg="imsi:imsi-208930100007499, profile timeout" category=Summary component=GNBSIM
time="2024-04-23T02:36:27Z" level=error msg="imsi:imsi-208930100007500, profile timeout" category=Summary component=GNBSIM
time="2024-04-23T02:36:27Z" level=error msg="imsi:imsi-208930100007501, profile timeout" category=Summary component=GNBSIM
time="2024-04-23T02:36:27Z" level=info msg="Profile Status: FAIL" category=Summary component=GNBSIM
mbilal92 commented 4 months ago

@JhengLu can you share gnbsim.log file?

JhengLu commented 4 months ago

sure, this is the gnbsim.log file

d57cebcdbf81:/gnbsim/bin# cat gnbsim.log
time="2024-04-23T02:31:17Z" level=info msg="App Name: GNBSIM" category=App component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Setting log level to: info" category=App component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="GNodeB IP:  GNodeB Port: 9487" category=GNodeB component=GNBSIM gnb=gnb1
time="2024-04-23T02:31:17Z" level=info msg="User Plane transport listening on: 172.20.0.2:2152" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:17Z" level=info msg="Current range selector value: 3" category=GNodeB component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Current ID range start: 50331648 end: 67108863" category=GNodeB component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Connected to AMF, AMF IP: 128.110.217.112 AMF Port: 38412" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:17Z" level=info msg="Wrote 61 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:17Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:17.591567935 +0000 UTC m=+0.035196893  1 0}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Read 48 bytes from 128.110.217.112:38412\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:17Z" level=info msg="NG Setup Successful: true" category=GNodeB component=GNBSIM gnb=gnb1
time="2024-04-23T02:31:17Z" level=error msg="disabled profileType  register" category=App component=GNBSIM
time="2024-04-23T02:31:17Z" level=error msg="disabled profileType  pdusessest" category=App component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Init profile: profile3 , profile type: anrelease" category=Profile component=GNBSIM profile=profile3
time="2024-04-23T02:31:17Z" level=info msg="Adding new GnbCpUe for RANUENGAPID: 50331648" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:17Z" level=info msg="Connected to gNodeB, Name:gnb1, IP:, Port:9487" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="SIM UE Init complete" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Adding new GnbCpUe for RANUENGAPID: 50331649" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:17Z" level=info msg="Handling event: CONNECTION-REQUEST-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:17Z" level=info msg="Handling event: CONNECTION-REQUEST-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:17Z" level=info msg="Connected to gNodeB, Name:gnb1, IP:, Port:9487" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:17Z" level=info msg="SIM UE Init complete" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:17Z" level=info msg="Adding new GnbCpUe for RANUENGAPID: 50331650" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:17Z" level=info msg="Connected to gNodeB, Name:gnb1, IP:, Port:9487" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:17Z" level=info msg="SIM UE Init complete" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:17Z" level=info msg="Handling event: CONNECTION-REQUEST-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:17Z" level=info msg="Adding new GnbCpUe for RANUENGAPID: 50331651" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:17Z" level=info msg="Connected to gNodeB, Name:gnb1, IP:, Port:9487" category=SimUe component=GNBSIM supi=imsi-208930100007500
time="2024-04-23T02:31:17Z" level=info msg="SIM UE Init complete" category=SimUe component=GNBSIM supi=imsi-208930100007500
time="2024-04-23T02:31:17Z" level=info msg="Adding new GnbCpUe for RANUENGAPID: 50331652" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:17Z" level=info msg="Handling event: CONNECTION-REQUEST-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331651 subcategory=GnbCpUe
time="2024-04-23T02:31:17Z" level=info msg="Connected to gNodeB, Name:gnb1, IP:, Port:9487" category=SimUe component=GNBSIM supi=imsi-208930100007501
time="2024-04-23T02:31:17Z" level=info msg="SIM UE Init complete" category=SimUe component=GNBSIM supi=imsi-208930100007501
time="2024-04-23T02:31:17Z" level=error msg="disabled profileType  uetriggservicereq" category=App component=GNBSIM
time="2024-04-23T02:31:17Z" level=error msg="disabled profileType  deregister" category=App component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Handling event: CONNECTION-REQUEST-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331652 subcategory=GnbCpUe
time="2024-04-23T02:31:17Z" level=error msg="disabled profileType  nwtriggeruedereg" category=App component=GNBSIM
time="2024-04-23T02:31:17Z" level=error msg="disabled profileType  uereqpdusessrelease" category=App component=GNBSIM
time="2024-04-23T02:31:17Z" level=error msg="disabled profileType  custom" category=App component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="ExecuteProfile started " category=Profile component=GNBSIM profile=profile3
time="2024-04-23T02:31:17Z" level=info msg="ExecuteProfile ExecInParallel false. Waiting for UEs to finish procesessing" category=Profile component=GNBSIM profile=profile3
time="2024-04-23T02:31:17Z" level=info msg="Execute procedure  REGISTRATION-PROCEDURE" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Waiting for procedure result from imsiStateMachine" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Handling event: PROC-START-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Start new procedure  REGISTRATION-PROCEDURE" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Initiating Registration Procedure" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Handling: REGISTRATION-REQUEST-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Received Event: REG_PROC_START:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007497 3 0}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Received Event: REG_REQ_OUT:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007497 4 1}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Handling event: REGISTRATION-REQUEST-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Handling event: REGISTRATION-REQUEST-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:17Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:17.597936394 +0000 UTC m=+0.041565358  1 1}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Find the UE  imsi-208930100007497" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Wrote 73 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:17Z" level=info msg="Read 71 bytes from 128.110.217.112\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:17Z" level=info msg="Received Event: MSG_IN:  &{2024-04-23 02:31:17.629442313 +0000 UTC m=+0.073071283  2 2}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Fetching GnbCpUe for RANUENGAPID: 50331648" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:17Z" level=info msg="Handling event: DOWNLINK-NAS-TRANSPORT-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:17Z" level=info msg="Handling event: DL-INFO-TRANSFER-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Handling: DL-INFO-TRANSFER-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Received Message Type: 86" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Handling event: AUTHENTICATION-REQUEST-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Next Event: AUTHENTICATION-RESPONSE-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Handling: AUTHENTICATION-RESPONSE-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Received Event: AUTH_REQ_IN:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007497 5 2}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Find the UE  imsi-208930100007497" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Time[us] between Reg Req & Auth Req  31505" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Handling event: AUTHENTICATION-RESPONSE-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Handling event: UL-INFO-TRANSFER-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:17Z" level=info msg="Received Event: AUTH_RSP_OUT:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007497 6 3}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:17.631372366 +0000 UTC m=+0.075001346  1 3}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Find the UE  imsi-208930100007497" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Wrote 69 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:17Z" level=info msg="Received Event: MSG_IN:  &{2024-04-23 02:31:17.656122905 +0000 UTC m=+0.099751881  2 4}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Read 48 bytes from 128.110.217.112\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:17Z" level=info msg="Fetching GnbCpUe for RANUENGAPID: 50331648" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:17Z" level=info msg="Handling event: DOWNLINK-NAS-TRANSPORT-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:17Z" level=info msg="Handling event: DL-INFO-TRANSFER-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Handling: DL-INFO-TRANSFER-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Calculate NAS MAC (algorithm: 2, DLCount: 0x0)" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="NAS integrity key: e7ec7152870b3558173abe3eb3f7dd35" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="cmac value: 0xf310f2fd" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Received Message Type: 93" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Handling event: SECURITY-MODE-COMMAND-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Handling: SECURITY-MODE-COMPLETE-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Handling event: SECURITY-MODE-COMPLETE-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Handling event: UL-INFO-TRANSFER-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:17Z" level=info msg="Received Event: SECM_CMD_IN:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007497 7 4}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Find the UE  imsi-208930100007497" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Time[us] between Auth Rsp and Sec M Req  24750" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Received Event: SECM_CMP_OUT:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007497 8 5}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:17.657936357 +0000 UTC m=+0.101565315  1 5}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Find the UE  imsi-208930100007497" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Wrote 99 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:17Z" level=info msg="Read 153 bytes from 128.110.217.112\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:17Z" level=info msg="Received Event: MSG_IN:  &{2024-04-23 02:31:17.753839696 +0000 UTC m=+0.197468745  2 6}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Fetching GnbCpUe for RANUENGAPID: 50331648" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:17Z" level=info msg="Handling event: INITIAL-CONTEXT-SETUP-REQUEST-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:17Z" level=info msg="Handling event: DL-INFO-TRANSFER-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Handling: DL-INFO-TRANSFER-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Received Event: ICS_REQ_IN:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007497 9 6}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Find the UE  imsi-208930100007497" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Time[us] between Sec Mod Cmd & ICSReq  95903" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Calculate NAS MAC (algorithm: 2, DLCount: 0x1)" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="NAS integrity key: e7ec7152870b3558173abe3eb3f7dd35" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="cmac value: 0x8b697481" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Received Message Type: 66" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Handling event: REGISTRATION-ACCEPT-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Handling: REGISTRATION-COMPLETE-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Handling event: REGISTRATION-COMPLETE-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="imsiStateMachine received result " category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Received Event: REG_COMP_OUT:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007497 10 7}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="procedure: REGISTRATION-PROCEDURE, status: PROC-PASS-EVENT, E2E latency [ms]: 161" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:17.758522965 +0000 UTC m=+0.202151988  1 0}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Procedure Result: PASS, imsi: imsi-208930100007497" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Execute procedure  PDU-SESSION-ESTABLISHMENT-PROCEDURE" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Wrote 24 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:17Z" level=info msg="Handling event: PROC-START-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Start new procedure  PDU-SESSION-ESTABLISHMENT-PROCEDURE" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Initiating UE Requested PDU Session Establishment Procedure" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Waiting for procedure result from imsiStateMachine" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Handling event: UL-INFO-TRANSFER-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:17Z" level=info msg="Received Event: REG_PROC_START:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007497 3 0}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Handling: PDU-SESSION-ESTABLISHMENT-REQUEST-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Received Event: PDU_SESS_REQ_OUT:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007497 18 8}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Handling event: PDU-SESSION-ESTABLISHMENT-REQUEST-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:17Z" level=info msg="Wrote 58 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:17Z" level=info msg="Handling event: UL-INFO-TRANSFER-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:17Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:17.760930658 +0000 UTC m=+0.204559696  1 7}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Find the UE  imsi-208930100007497" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Wrote 84 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:17Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:17.762819616 +0000 UTC m=+0.206448634  1 8}" category=Stats component=GNBSIM
time="2024-04-23T02:31:17Z" level=info msg="Find the UE  imsi-208930100007497" category=Stats component=GNBSIM
time="2024-04-23T02:31:18Z" level=info msg="Read 198 bytes from 128.110.217.112\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:18Z" level=info msg="Received Event: MSG_IN:  &{2024-04-23 02:31:18.085546242 +0000 UTC m=+0.529175255  2 9}" category=Stats component=GNBSIM
time="2024-04-23T02:31:18Z" level=info msg="Fetching GnbCpUe for RANUENGAPID: 50331648" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:18Z" level=info msg="Handling event: PDU-SESSION-RESOURCE-SETUP-REQUEST-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:18Z" level=info msg="PDU Session ID: 10" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:18Z" level=info msg="S-NSSAI - SST:  1" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:18Z" level=info msg="S-NSSAI - SD:  010203" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:18Z" level=info msg="UL GTP-TEID:  5945309" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:18Z" level=info msg="DL GTP-TEID:  50331648" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:18Z" level=info msg="UPF Endpoint IP:  192.168.252.3" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:18Z" level=info msg="PDU Session Type:  IPV4" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:18Z" level=info msg="QoS Flow Id: 1" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:18Z" level=info msg="Non Dynamic 5QI: 9" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:18Z" level=info msg="ARP Priority Level: 6" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:18Z" level=info msg="Pre-emption Capability: 1" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:18Z" level=info msg="Pre-emption Vulnerability: 1" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:18Z" level=info msg="Adding new QosFlowItem corresponding to QFI: 1" category=GNodeB component=GNBSIM dlteid=50331648 subcategory=GnbUpUe
time="2024-04-23T02:31:18Z" level=info msg="Fetching GnbUpf corresponding to IP: 192.168.252.3" category=GNodeB component=GNBSIM subcategory=GnbPeerDao
time="2024-04-23T02:31:18Z" level=warning msg="key not present: 192.168.252.3" category=GNodeB component=GNBSIM subcategory=GnbPeerDao
time="2024-04-23T02:31:18Z" level=info msg="Adding new GnbUpf corresponding to IP: 192.168.252.3" category=GNodeB component=GNBSIM subcategory=GnbPeerDao
time="2024-04-23T02:31:18Z" level=info msg="Adding new GnbUpUe for PDU Sess ID: 10" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:18Z" level=info msg="Handling event: DL-INFO-TRANSFER-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Handling: DL-INFO-TRANSFER-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Calculate NAS MAC (algorithm: 2, DLCount: 0x2)" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="NAS integrity key: e7ec7152870b3558173abe3eb3f7dd35" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="cmac value: 0x9586dede" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Received Message Type: 104" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Payload contaner type:{1}" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Handling event: PDU-SESSION-ESTABLISHMENT-ACCEPT-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Next Event: PDU-SESSION-ESTABLISHMENT-ACCEPT-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Handling: PDU-SESSION-ESTABLISHMENT-ACCEPT-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Adding new PDU Session for PDU Sess ID: 10" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="PDU Session ID: 10" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="PDU Session Type: IPV4" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="SSC Mode: 1" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="PDU Address: 172.250.0.6" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Received Event: PDU_SESS_ACC_IN:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007497 19 9}" category=Stats component=GNBSIM
time="2024-04-23T02:31:18Z" level=info msg="Find the UE  imsi-208930100007497" category=Stats component=GNBSIM
time="2024-04-23T02:31:18Z" level=info msg="Time[us] between PDU Sess Req & Accept  322726" category=Stats component=GNBSIM
time="2024-04-23T02:31:18Z" level=info msg="Handling event: DATA-BEARER-SETUP-REQUEST-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Handling: DATA-BEARER-SETUP-REQUEST-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Fetching PDU Session for pduSessId: 10" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Handling event: DATA-BEARER-SETUP-RESPONSE-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="imsiStateMachine received result " category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="procedure: PDU-SESSION-ESTABLISHMENT-PROCEDURE, status: PROC-PASS-EVENT, E2E latency [ms]: 833" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Handling: INIT-EVENT" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Handling event: DATA-BEARER-SETUP-RESPONSE-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:18Z" level=info msg="Fetching GnbUpUe for pduSessId: 10" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:18Z" level=info msg="Adding new GnbUpUe for TEID: 50331648 Downlink: true" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:18Z" level=info msg="Procedure Result: PASS, imsi: imsi-208930100007497" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Execute procedure  USER-DATA-PACKET-GENERATION-PROCEDURE" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Waiting for procedure result from imsiStateMachine" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Handling event: PROC-START-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Start new procedure  USER-DATA-PACKET-GENERATION-PROCEDURE" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Initiating User Data Packet Generation Procedure" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Please wait, initiating uplink user data in 3 seconds ..." category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:18Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:18.594397742 +0000 UTC m=+1.038026765  1 10}" category=Stats component=GNBSIM
time="2024-04-23T02:31:18Z" level=info msg="Wrote 45 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:18Z" level=info msg="No transaction found for Id: 10" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Handling: DATA-PACKET-GENERATION-REQUEST-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Handling: DATA-PACKET-GENERATION-REQUEST-EVENT" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Sent UDP Packet, length: 92 bytes\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Read 92 bytes from 192.168.252.3:2152\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Fetching GnbUpf corresponding to IP: 192.168.252.3" category=GNodeB component=GNBSIM subcategory=GnbPeerDao
time="2024-04-23T02:31:21Z" level=info msg="PDU Session Container Extension header length:1" category=Util component=GNBSIM subcategory=GTP
time="2024-04-23T02:31:21Z" level=info msg="Received QFI value in downlink G-PDU: 1" category=GNodeB component=GNBSIM dlteid=50331648 subcategory=GnbUpUe
time="2024-04-23T02:31:21Z" level=info msg="Sent DL user data packet to UE" category=GNodeB component=GNBSIM dlteid=50331648 subcategory=GnbUpUe
time="2024-04-23T02:31:21Z" level=info msg="Received QFI value in downlink user data packet: 1" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Received ICMP Echo Reply, ID:12394, Seq:1" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Sent UDP Packet, length: 92 bytes\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Read 92 bytes from 192.168.252.3:2152\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Fetching GnbUpf corresponding to IP: 192.168.252.3" category=GNodeB component=GNBSIM subcategory=GnbPeerDao
time="2024-04-23T02:31:21Z" level=info msg="PDU Session Container Extension header length:1" category=Util component=GNBSIM subcategory=GTP
time="2024-04-23T02:31:21Z" level=info msg="Received QFI value in downlink G-PDU: 1" category=GNodeB component=GNBSIM dlteid=50331648 subcategory=GnbUpUe
time="2024-04-23T02:31:21Z" level=info msg="Sent DL user data packet to UE" category=GNodeB component=GNBSIM dlteid=50331648 subcategory=GnbUpUe
time="2024-04-23T02:31:21Z" level=info msg="Received QFI value in downlink user data packet: 1" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Received ICMP Echo Reply, ID:12394, Seq:2" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Sent UDP Packet, length: 92 bytes\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Read 92 bytes from 192.168.252.3:2152\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Fetching GnbUpf corresponding to IP: 192.168.252.3" category=GNodeB component=GNBSIM subcategory=GnbPeerDao
time="2024-04-23T02:31:21Z" level=info msg="PDU Session Container Extension header length:1" category=Util component=GNBSIM subcategory=GTP
time="2024-04-23T02:31:21Z" level=info msg="Received QFI value in downlink G-PDU: 1" category=GNodeB component=GNBSIM dlteid=50331648 subcategory=GnbUpUe
time="2024-04-23T02:31:21Z" level=info msg="Sent DL user data packet to UE" category=GNodeB component=GNBSIM dlteid=50331648 subcategory=GnbUpUe
time="2024-04-23T02:31:21Z" level=info msg="Received QFI value in downlink user data packet: 1" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Received ICMP Echo Reply, ID:12394, Seq:3" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Sent UDP Packet, length: 92 bytes\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Read 92 bytes from 192.168.252.3:2152\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Fetching GnbUpf corresponding to IP: 192.168.252.3" category=GNodeB component=GNBSIM subcategory=GnbPeerDao
time="2024-04-23T02:31:21Z" level=info msg="PDU Session Container Extension header length:1" category=Util component=GNBSIM subcategory=GTP
time="2024-04-23T02:31:21Z" level=info msg="Received QFI value in downlink G-PDU: 1" category=GNodeB component=GNBSIM dlteid=50331648 subcategory=GnbUpUe
time="2024-04-23T02:31:21Z" level=info msg="Sent DL user data packet to UE" category=GNodeB component=GNBSIM dlteid=50331648 subcategory=GnbUpUe
time="2024-04-23T02:31:21Z" level=info msg="Received QFI value in downlink user data packet: 1" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Received ICMP Echo Reply, ID:12394, Seq:4" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Sent UDP Packet, length: 92 bytes\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Read 92 bytes from 192.168.252.3:2152\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Fetching GnbUpf corresponding to IP: 192.168.252.3" category=GNodeB component=GNBSIM subcategory=GnbPeerDao
time="2024-04-23T02:31:21Z" level=info msg="PDU Session Container Extension header length:1" category=Util component=GNBSIM subcategory=GTP
time="2024-04-23T02:31:21Z" level=info msg="Received QFI value in downlink G-PDU: 1" category=GNodeB component=GNBSIM dlteid=50331648 subcategory=GnbUpUe
time="2024-04-23T02:31:21Z" level=info msg="Sent DL user data packet to UE" category=GNodeB component=GNBSIM dlteid=50331648 subcategory=GnbUpUe
time="2024-04-23T02:31:21Z" level=info msg="Received QFI value in downlink user data packet: 1" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Received ICMP Echo Reply, ID:12394, Seq:5" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Handling: DATA-PACKET-SUCCESS-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Handling event: DATA-PACKET-SUCCESS-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="imsiStateMachine received result " category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="procedure: USER-DATA-PACKET-GENERATION-PROCEDURE, status: PROC-PASS-EVENT, E2E latency [ms]: 3007" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Procedure Result: PASS, imsi: imsi-208930100007497" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Execute procedure  AN-RELEASE-PROCEDURE" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Waiting for procedure result from imsiStateMachine" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Handling event: PROC-START-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Start new procedure  AN-RELEASE-PROCEDURE" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Initiating AN Release Procedure" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Handling event: TRIGGER-AN-RELEASE-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:21Z" level=info msg="Received UE_CTX_REL_OUT  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007497 49 11}" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Wrote 37 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:21.601517574 +0000 UTC m=+4.045146588  1 11}" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Find the UE  imsi-208930100007497" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Received Event: MSG_IN:  &{2024-04-23 02:31:21.67636398 +0000 UTC m=+4.119992950  2 12}" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Read 26 bytes from 128.110.217.112\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Fetching GnbCpUe for RANUENGAPID: 50331648" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:21Z" level=info msg="Handling event: UE-CONTEXT-RELEASE-COMMAND-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:21Z" level=info msg="Cause RadioNetwork[20]\n" category=Util component=GNBSIM subcategory=NGAP
time="2024-04-23T02:31:21Z" level=info msg="Received Event: UE_CTX_CMD_IN:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007497 50 12}" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Wrote 50 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Handling event: QUIT-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:21Z" level=info msg="Find the UE  imsi-208930100007497" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Removing GnbUpUe for TEID: 50331648 Downlink: true" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:21Z" level=info msg="Handling: QUIT-EVENT" category=GNodeB component=GNBSIM dlteid=50331648 subcategory=GnbUpUe
time="2024-04-23T02:31:21Z" level=info msg="Time[us] between Ctx Rel Req & Cmd  74846" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:21.679397528 +0000 UTC m=+4.123026515  1 12}" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Handling event: CONNECTION-RELEASE-REQUEST-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="No transaction found for Id: 12" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="imsiStateMachine received result " category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="procedure: AN-RELEASE-PROCEDURE, status: PROC-PASS-EVENT, E2E latency [ms]: 80" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Procedure Result: PASS, imsi: imsi-208930100007497" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Handling: CONNECTION-RELEASE-REQUEST-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Handling: CONNECTION-RELEASE-REQUEST-EVENT" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="Gnb User-plane UE Context terminated" category=GNodeB component=GNBSIM dlteid=50331648 subcategory=GnbUpUe
time="2024-04-23T02:31:21Z" level=info msg="gNB Control-Plane UE context terminated" category=GNodeB component=GNBSIM ranuengapid=50331648 subcategory=GnbCpUe
time="2024-04-23T02:31:21Z" level=info msg="No more procedures left" category=Profile component=GNBSIM profile=profile3
time="2024-04-23T02:31:21Z" level=info msg="imsiStateMachine no more proc to execute" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="imsiStateMachine ended" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007497
time="2024-04-23T02:31:21Z" level=info msg="ExecuteProfile ExecInParallel false. Waiting for UEs to finish procesessing" category=Profile component=GNBSIM profile=profile3
time="2024-04-23T02:31:21Z" level=info msg="Execute procedure  REGISTRATION-PROCEDURE" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Waiting for procedure result from imsiStateMachine" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Handling event: PROC-START-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Start new procedure  REGISTRATION-PROCEDURE" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Initiating Registration Procedure" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Handling: REGISTRATION-REQUEST-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Received Event: REG_PROC_START:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007498 3 0}" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Handling event: REGISTRATION-REQUEST-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Received Event: REG_REQ_OUT:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007498 4 13}" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Handling event: REGISTRATION-REQUEST-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:21Z" level=info msg="Wrote 73 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:21.682329247 +0000 UTC m=+4.125958236  1 13}" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Find the UE  imsi-208930100007498" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Read 71 bytes from 128.110.217.112\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Received Event: MSG_IN:  &{2024-04-23 02:31:21.934880359 +0000 UTC m=+4.378509372  2 14}" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Fetching GnbCpUe for RANUENGAPID: 50331649" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:21Z" level=info msg="Handling event: DOWNLINK-NAS-TRANSPORT-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:21Z" level=info msg="Handling event: DL-INFO-TRANSFER-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Handling: DL-INFO-TRANSFER-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Received Message Type: 86" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Handling event: AUTHENTICATION-REQUEST-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Next Event: AUTHENTICATION-RESPONSE-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Handling: AUTHENTICATION-RESPONSE-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Received Event: AUTH_REQ_IN:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007498 5 14}" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Find the UE  imsi-208930100007498" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Time[us] between Reg Req & Auth Req  252551" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Received Event: AUTH_RSP_OUT:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007498 6 15}" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Handling event: AUTHENTICATION-RESPONSE-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Handling event: UL-INFO-TRANSFER-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:21Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:21.9389966 +0000 UTC m=+4.382625618  1 15}" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Find the UE  imsi-208930100007498" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Wrote 69 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Read 48 bytes from 128.110.217.112\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Received Event: MSG_IN:  &{2024-04-23 02:31:21.973321938 +0000 UTC m=+4.416950966  2 16}" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Fetching GnbCpUe for RANUENGAPID: 50331649" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:21Z" level=info msg="Handling event: DOWNLINK-NAS-TRANSPORT-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:21Z" level=info msg="Handling event: DL-INFO-TRANSFER-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Handling: DL-INFO-TRANSFER-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Calculate NAS MAC (algorithm: 2, DLCount: 0x0)" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="NAS integrity key: be7b24482d7b14c8c810697fe81d8c81" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="cmac value: 0x2360d10c" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Received Message Type: 93" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Handling event: SECURITY-MODE-COMMAND-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Handling: SECURITY-MODE-COMPLETE-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Received Event: SECM_CMD_IN:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007498 7 16}" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Find the UE  imsi-208930100007498" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Handling event: SECURITY-MODE-COMPLETE-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:21Z" level=info msg="Handling event: UL-INFO-TRANSFER-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:21Z" level=info msg="Time[us] between Auth Rsp and Sec M Req  34325" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Received Event: SECM_CMP_OUT:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007498 8 17}" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:21.97732219 +0000 UTC m=+4.420951208  1 17}" category=Stats component=GNBSIM
time="2024-04-23T02:31:21Z" level=info msg="Wrote 99 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:21Z" level=info msg="Find the UE  imsi-208930100007498" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Read 153 bytes from 128.110.217.112\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:22Z" level=info msg="Received Event: MSG_IN:  &{2024-04-23 02:31:22.078963517 +0000 UTC m=+4.522592535  2 18}" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Fetching GnbCpUe for RANUENGAPID: 50331649" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:22Z" level=info msg="Handling event: INITIAL-CONTEXT-SETUP-REQUEST-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="Handling event: DL-INFO-TRANSFER-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Handling: DL-INFO-TRANSFER-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Calculate NAS MAC (algorithm: 2, DLCount: 0x1)" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="NAS integrity key: be7b24482d7b14c8c810697fe81d8c81" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="cmac value: 0x5a1a9076" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Received Message Type: 66" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Handling event: REGISTRATION-ACCEPT-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Handling: REGISTRATION-COMPLETE-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Received Event: ICS_REQ_IN:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007498 9 18}" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Find the UE  imsi-208930100007498" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Time[us] between Sec Mod Cmd & ICSReq  101641" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Received Event: REG_COMP_OUT:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007498 10 19}" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Handling event: REGISTRATION-COMPLETE-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="imsiStateMachine received result " category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="procedure: REGISTRATION-PROCEDURE, status: PROC-PASS-EVENT, E2E latency [ms]: 405" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Procedure Result: PASS, imsi: imsi-208930100007498" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Execute procedure  PDU-SESSION-ESTABLISHMENT-PROCEDURE" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Waiting for procedure result from imsiStateMachine" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Wrote 24 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:22Z" level=info msg="Handling event: UL-INFO-TRANSFER-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:22.085515291 +0000 UTC m=+4.529144309  1 0}" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Handling event: PROC-START-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Start new procedure  PDU-SESSION-ESTABLISHMENT-PROCEDURE" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Initiating UE Requested PDU Session Establishment Procedure" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Handling: PDU-SESSION-ESTABLISHMENT-REQUEST-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Received Event: REG_PROC_START:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007498 3 0}" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Received Event: PDU_SESS_REQ_OUT:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007498 18 20}" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Handling event: PDU-SESSION-ESTABLISHMENT-REQUEST-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Wrote 58 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:22Z" level=info msg="Handling event: UL-INFO-TRANSFER-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:22.088509201 +0000 UTC m=+4.532138219  1 19}" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Find the UE  imsi-208930100007498" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Wrote 84 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:22Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:22.090245319 +0000 UTC m=+4.533874337  1 20}" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Find the UE  imsi-208930100007498" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Read 198 bytes from 128.110.217.112\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:22Z" level=info msg="Received Event: MSG_IN:  &{2024-04-23 02:31:22.430542332 +0000 UTC m=+4.874171296  2 21}" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Fetching GnbCpUe for RANUENGAPID: 50331649" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:22Z" level=info msg="Handling event: PDU-SESSION-RESOURCE-SETUP-REQUEST-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="PDU Session ID: 10" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="S-NSSAI - SST:  1" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="S-NSSAI - SD:  010203" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="UL GTP-TEID:  5945307" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="DL GTP-TEID:  50331649" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="UPF Endpoint IP:  192.168.252.3" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="PDU Session Type:  IPV4" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="QoS Flow Id: 1" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="Non Dynamic 5QI: 9" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="ARP Priority Level: 6" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="Pre-emption Capability: 1" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="Pre-emption Vulnerability: 1" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="Adding new QosFlowItem corresponding to QFI: 1" category=GNodeB component=GNBSIM dlteid=50331649 subcategory=GnbUpUe
time="2024-04-23T02:31:22Z" level=info msg="Fetching GnbUpf corresponding to IP: 192.168.252.3" category=GNodeB component=GNBSIM subcategory=GnbPeerDao
time="2024-04-23T02:31:22Z" level=info msg="Adding new GnbUpUe for PDU Sess ID: 10" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="Handling event: DL-INFO-TRANSFER-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Handling: DL-INFO-TRANSFER-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Calculate NAS MAC (algorithm: 2, DLCount: 0x2)" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="NAS integrity key: be7b24482d7b14c8c810697fe81d8c81" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="cmac value: 0xd03df244" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Received Message Type: 104" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Payload contaner type:{1}" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Handling event: PDU-SESSION-ESTABLISHMENT-ACCEPT-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Next Event: PDU-SESSION-ESTABLISHMENT-ACCEPT-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Handling: PDU-SESSION-ESTABLISHMENT-ACCEPT-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Adding new PDU Session for PDU Sess ID: 10" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="PDU Session ID: 10" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="PDU Session Type: IPV4" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="SSC Mode: 1" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="PDU Address: 172.250.0.7" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Received Event: PDU_SESS_ACC_IN:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007498 19 21}" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Find the UE  imsi-208930100007498" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Time[us] between PDU Sess Req & Accept  340296" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Handling event: DATA-BEARER-SETUP-REQUEST-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Handling: DATA-BEARER-SETUP-REQUEST-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Fetching PDU Session for pduSessId: 10" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Handling event: DATA-BEARER-SETUP-RESPONSE-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Handling: INIT-EVENT" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="imsiStateMachine received result " category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Handling event: DATA-BEARER-SETUP-RESPONSE-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="procedure: PDU-SESSION-ESTABLISHMENT-PROCEDURE, status: PROC-PASS-EVENT, E2E latency [ms]: 848" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Procedure Result: PASS, imsi: imsi-208930100007498" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Execute procedure  USER-DATA-PACKET-GENERATION-PROCEDURE" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Waiting for procedure result from imsiStateMachine" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Handling event: PROC-START-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Fetching GnbUpUe for pduSessId: 10" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:22Z" level=info msg="Start new procedure  USER-DATA-PACKET-GENERATION-PROCEDURE" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Adding new GnbUpUe for TEID: 50331649 Downlink: true" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:22Z" level=info msg="Initiating User Data Packet Generation Procedure" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Please wait, initiating uplink user data in 3 seconds ..." category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:22Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:22.936199385 +0000 UTC m=+5.379828383  1 22}" category=Stats component=GNBSIM
time="2024-04-23T02:31:22Z" level=info msg="Wrote 45 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:22Z" level=info msg="No transaction found for Id: 22" category=Stats component=GNBSIM
time="2024-04-23T02:31:25Z" level=info msg="Handling: DATA-PACKET-GENERATION-REQUEST-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Handling: DATA-PACKET-GENERATION-REQUEST-EVENT" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Sent UDP Packet, length: 92 bytes\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:25Z" level=info msg="Read 92 bytes from 192.168.252.3:2152\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:25Z" level=info msg="Fetching GnbUpf corresponding to IP: 192.168.252.3" category=GNodeB component=GNBSIM subcategory=GnbPeerDao
time="2024-04-23T02:31:25Z" level=info msg="PDU Session Container Extension header length:1" category=Util component=GNBSIM subcategory=GTP
time="2024-04-23T02:31:25Z" level=info msg="Received QFI value in downlink G-PDU: 1" category=GNodeB component=GNBSIM dlteid=50331649 subcategory=GnbUpUe
time="2024-04-23T02:31:25Z" level=info msg="Sent DL user data packet to UE" category=GNodeB component=GNBSIM dlteid=50331649 subcategory=GnbUpUe
time="2024-04-23T02:31:25Z" level=info msg="Received QFI value in downlink user data packet: 1" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Received ICMP Echo Reply, ID:12394, Seq:1" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Sent UDP Packet, length: 92 bytes\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:25Z" level=info msg="Read 92 bytes from 192.168.252.3:2152\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:25Z" level=info msg="Fetching GnbUpf corresponding to IP: 192.168.252.3" category=GNodeB component=GNBSIM subcategory=GnbPeerDao
time="2024-04-23T02:31:25Z" level=info msg="PDU Session Container Extension header length:1" category=Util component=GNBSIM subcategory=GTP
time="2024-04-23T02:31:25Z" level=info msg="Received QFI value in downlink G-PDU: 1" category=GNodeB component=GNBSIM dlteid=50331649 subcategory=GnbUpUe
time="2024-04-23T02:31:25Z" level=info msg="Sent DL user data packet to UE" category=GNodeB component=GNBSIM dlteid=50331649 subcategory=GnbUpUe
time="2024-04-23T02:31:25Z" level=info msg="Received QFI value in downlink user data packet: 1" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Received ICMP Echo Reply, ID:12394, Seq:2" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Sent UDP Packet, length: 92 bytes\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:25Z" level=info msg="Read 92 bytes from 192.168.252.3:2152\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:25Z" level=info msg="Fetching GnbUpf corresponding to IP: 192.168.252.3" category=GNodeB component=GNBSIM subcategory=GnbPeerDao
time="2024-04-23T02:31:25Z" level=info msg="PDU Session Container Extension header length:1" category=Util component=GNBSIM subcategory=GTP
time="2024-04-23T02:31:25Z" level=info msg="Received QFI value in downlink G-PDU: 1" category=GNodeB component=GNBSIM dlteid=50331649 subcategory=GnbUpUe
time="2024-04-23T02:31:25Z" level=info msg="Sent DL user data packet to UE" category=GNodeB component=GNBSIM dlteid=50331649 subcategory=GnbUpUe
time="2024-04-23T02:31:25Z" level=info msg="Received QFI value in downlink user data packet: 1" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Received ICMP Echo Reply, ID:12394, Seq:3" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Sent UDP Packet, length: 92 bytes\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:25Z" level=info msg="Read 92 bytes from 192.168.252.3:2152\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:25Z" level=info msg="Fetching GnbUpf corresponding to IP: 192.168.252.3" category=GNodeB component=GNBSIM subcategory=GnbPeerDao
time="2024-04-23T02:31:25Z" level=info msg="PDU Session Container Extension header length:1" category=Util component=GNBSIM subcategory=GTP
time="2024-04-23T02:31:25Z" level=info msg="Received QFI value in downlink G-PDU: 1" category=GNodeB component=GNBSIM dlteid=50331649 subcategory=GnbUpUe
time="2024-04-23T02:31:25Z" level=info msg="Sent DL user data packet to UE" category=GNodeB component=GNBSIM dlteid=50331649 subcategory=GnbUpUe
time="2024-04-23T02:31:25Z" level=info msg="Received QFI value in downlink user data packet: 1" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Received ICMP Echo Reply, ID:12394, Seq:4" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Sent UDP Packet, length: 92 bytes\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:25Z" level=info msg="Read 92 bytes from 192.168.252.3:2152\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:31:25Z" level=info msg="Fetching GnbUpf corresponding to IP: 192.168.252.3" category=GNodeB component=GNBSIM subcategory=GnbPeerDao
time="2024-04-23T02:31:25Z" level=info msg="PDU Session Container Extension header length:1" category=Util component=GNBSIM subcategory=GTP
time="2024-04-23T02:31:25Z" level=info msg="Received QFI value in downlink G-PDU: 1" category=GNodeB component=GNBSIM dlteid=50331649 subcategory=GnbUpUe
time="2024-04-23T02:31:25Z" level=info msg="Sent DL user data packet to UE" category=GNodeB component=GNBSIM dlteid=50331649 subcategory=GnbUpUe
time="2024-04-23T02:31:25Z" level=info msg="Received QFI value in downlink user data packet: 1" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Received ICMP Echo Reply, ID:12394, Seq:5" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Handling: DATA-PACKET-SUCCESS-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Handling event: DATA-PACKET-SUCCESS-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="imsiStateMachine received result " category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="procedure: USER-DATA-PACKET-GENERATION-PROCEDURE, status: PROC-PASS-EVENT, E2E latency [ms]: 3005" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Procedure Result: PASS, imsi: imsi-208930100007498" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Execute procedure  AN-RELEASE-PROCEDURE" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Waiting for procedure result from imsiStateMachine" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Handling event: PROC-START-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Start new procedure  AN-RELEASE-PROCEDURE" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Initiating AN Release Procedure" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:25Z" level=info msg="Handling event: TRIGGER-AN-RELEASE-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:25Z" level=info msg="Received UE_CTX_REL_OUT  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007498 49 23}" category=Stats component=GNBSIM
time="2024-04-23T02:31:25Z" level=info msg="Wrote 37 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:25Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:25.941158894 +0000 UTC m=+8.384787907  1 23}" category=Stats component=GNBSIM
time="2024-04-23T02:31:25Z" level=info msg="Find the UE  imsi-208930100007498" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Read 26 bytes from 128.110.217.112\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:26Z" level=info msg="Received Event: MSG_IN:  &{2024-04-23 02:31:26.015193946 +0000 UTC m=+8.458822922  2 24}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Fetching GnbCpUe for RANUENGAPID: 50331649" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:26Z" level=info msg="Handling event: UE-CONTEXT-RELEASE-COMMAND-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="Cause RadioNetwork[20]\n" category=Util component=GNBSIM subcategory=NGAP
time="2024-04-23T02:31:26Z" level=info msg="Received Event: UE_CTX_CMD_IN:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007498 50 24}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Find the UE  imsi-208930100007498" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Time[us] between Ctx Rel Req & Cmd  74035" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:26.016759427 +0000 UTC m=+8.460388383  1 24}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="No transaction found for Id: 24" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Wrote 50 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:26Z" level=info msg="Handling event: QUIT-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="Removing GnbUpUe for TEID: 50331649 Downlink: true" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:26Z" level=info msg="Handling: QUIT-EVENT" category=GNodeB component=GNBSIM dlteid=50331649 subcategory=GnbUpUe
time="2024-04-23T02:31:26Z" level=info msg="Handling event: CONNECTION-RELEASE-REQUEST-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:26Z" level=info msg="imsiStateMachine received result " category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:26Z" level=info msg="Handling: CONNECTION-RELEASE-REQUEST-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:26Z" level=info msg="Handling: CONNECTION-RELEASE-REQUEST-EVENT" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007498
time="2024-04-23T02:31:26Z" level=info msg="Gnb User-plane UE Context terminated" category=GNodeB component=GNBSIM dlteid=50331649 subcategory=GnbUpUe
time="2024-04-23T02:31:26Z" level=info msg="gNB Control-Plane UE context terminated" category=GNodeB component=GNBSIM ranuengapid=50331649 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="procedure: AN-RELEASE-PROCEDURE, status: PROC-PASS-EVENT, E2E latency [ms]: 77" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:26Z" level=info msg="Procedure Result: PASS, imsi: imsi-208930100007498" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:26Z" level=info msg="No more procedures left" category=Profile component=GNBSIM profile=profile3
time="2024-04-23T02:31:26Z" level=info msg="imsiStateMachine no more proc to execute" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:26Z" level=info msg="imsiStateMachine ended" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007498
time="2024-04-23T02:31:26Z" level=info msg="ExecuteProfile ExecInParallel false. Waiting for UEs to finish procesessing" category=Profile component=GNBSIM profile=profile3
time="2024-04-23T02:31:26Z" level=info msg="Execute procedure  REGISTRATION-PROCEDURE" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Waiting for procedure result from imsiStateMachine" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling event: PROC-START-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Start new procedure  REGISTRATION-PROCEDURE" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Initiating Registration Procedure" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling: REGISTRATION-REQUEST-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling event: REGISTRATION-REQUEST-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling event: REGISTRATION-REQUEST-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="Received Event: REG_PROC_START:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007499 3 0}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Received Event: REG_REQ_OUT:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007499 4 25}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Wrote 73 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:26Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:26.018812059 +0000 UTC m=+8.462441032  1 25}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Find the UE  imsi-208930100007499" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Read 71 bytes from 128.110.217.112\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:26Z" level=info msg="Received Event: MSG_IN:  &{2024-04-23 02:31:26.270532581 +0000 UTC m=+8.714161664  2 26}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Fetching GnbCpUe for RANUENGAPID: 50331650" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:26Z" level=info msg="Handling event: DOWNLINK-NAS-TRANSPORT-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="Handling event: DL-INFO-TRANSFER-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling: DL-INFO-TRANSFER-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Received Message Type: 86" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling event: AUTHENTICATION-REQUEST-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Next Event: AUTHENTICATION-RESPONSE-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling: AUTHENTICATION-RESPONSE-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Received Event: AUTH_REQ_IN:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007499 5 26}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Find the UE  imsi-208930100007499" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Time[us] between Reg Req & Auth Req  251720" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Received Event: AUTH_RSP_OUT:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007499 6 27}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Handling event: AUTHENTICATION-RESPONSE-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling event: UL-INFO-TRANSFER-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:26.27496662 +0000 UTC m=+8.718595638  1 27}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Find the UE  imsi-208930100007499" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Wrote 69 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:26Z" level=info msg="Received Event: MSG_IN:  &{2024-04-23 02:31:26.308084227 +0000 UTC m=+8.751713280  2 28}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Read 48 bytes from 128.110.217.112\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:26Z" level=info msg="Fetching GnbCpUe for RANUENGAPID: 50331650" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:26Z" level=info msg="Handling event: DOWNLINK-NAS-TRANSPORT-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="Handling event: DL-INFO-TRANSFER-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling: DL-INFO-TRANSFER-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Calculate NAS MAC (algorithm: 2, DLCount: 0x0)" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="NAS integrity key: f871fea67895c124334cdf1e67796f3e" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="cmac value: 0x6f2f609b" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Received Message Type: 93" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling event: SECURITY-MODE-COMMAND-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling: SECURITY-MODE-COMPLETE-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Received Event: SECM_CMD_IN:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007499 7 28}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Handling event: SECURITY-MODE-COMPLETE-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Find the UE  imsi-208930100007499" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Time[us] between Auth Rsp and Sec M Req  33117" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Handling event: UL-INFO-TRANSFER-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="Received Event: SECM_CMP_OUT:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007499 8 29}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:26.312252288 +0000 UTC m=+8.755881301  1 29}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Find the UE  imsi-208930100007499" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Wrote 99 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:26Z" level=info msg="Read 153 bytes from 128.110.217.112\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:26Z" level=info msg="Received Event: MSG_IN:  &{2024-04-23 02:31:26.422091383 +0000 UTC m=+8.865720341  2 30}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Fetching GnbCpUe for RANUENGAPID: 50331650" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:26Z" level=info msg="Handling event: INITIAL-CONTEXT-SETUP-REQUEST-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="Handling event: DL-INFO-TRANSFER-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling: DL-INFO-TRANSFER-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Calculate NAS MAC (algorithm: 2, DLCount: 0x1)" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="NAS integrity key: f871fea67895c124334cdf1e67796f3e" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="cmac value: 0xa5e35d30" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Received Message Type: 66" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling event: REGISTRATION-ACCEPT-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Received Event: ICS_REQ_IN:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007499 9 30}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Find the UE  imsi-208930100007499" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Time[us] between Sec Mod Cmd & ICSReq  109839" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Handling: REGISTRATION-COMPLETE-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling event: REGISTRATION-COMPLETE-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="imsiStateMachine received result " category=ProfUeCtx component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="procedure: REGISTRATION-PROCEDURE, status: PROC-PASS-EVENT, E2E latency [ms]: 406" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Received Event: REG_COMP_OUT:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007499 10 31}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Procedure Result: PASS, imsi: imsi-208930100007499" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Execute procedure  PDU-SESSION-ESTABLISHMENT-PROCEDURE" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Waiting for procedure result from imsiStateMachine" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:26.424251242 +0000 UTC m=+8.867880248  1 0}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Handling event: PROC-START-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Start new procedure  PDU-SESSION-ESTABLISHMENT-PROCEDURE" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Wrote 24 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:26Z" level=info msg="Handling event: UL-INFO-TRANSFER-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="Initiating UE Requested PDU Session Establishment Procedure" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling: PDU-SESSION-ESTABLISHMENT-REQUEST-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Received Event: REG_PROC_START:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007499 3 0}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Received Event: PDU_SESS_REQ_OUT:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007499 18 32}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Handling event: PDU-SESSION-ESTABLISHMENT-REQUEST-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Wrote 58 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:26Z" level=info msg="Handling event: UL-INFO-TRANSFER-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:26.425915704 +0000 UTC m=+8.869544711  1 31}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Find the UE  imsi-208930100007499" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Wrote 84 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:26Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:26.427447142 +0000 UTC m=+8.871076144  1 32}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Find the UE  imsi-208930100007499" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Read 198 bytes from 128.110.217.112\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:26Z" level=info msg="Received Event: MSG_IN:  &{2024-04-23 02:31:26.745587992 +0000 UTC m=+9.189216963  2 33}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Fetching GnbCpUe for RANUENGAPID: 50331650" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:26Z" level=info msg="Handling event: PDU-SESSION-RESOURCE-SETUP-REQUEST-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="PDU Session ID: 10" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="S-NSSAI - SST:  1" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="S-NSSAI - SD:  010203" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="UL GTP-TEID:  5945305" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="DL GTP-TEID:  50331650" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="UPF Endpoint IP:  192.168.252.3" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="PDU Session Type:  IPV4" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="QoS Flow Id: 1" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="Non Dynamic 5QI: 9" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="ARP Priority Level: 6" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="Pre-emption Capability: 1" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="Pre-emption Vulnerability: 1" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="Adding new QosFlowItem corresponding to QFI: 1" category=GNodeB component=GNBSIM dlteid=50331650 subcategory=GnbUpUe
time="2024-04-23T02:31:26Z" level=info msg="Fetching GnbUpf corresponding to IP: 192.168.252.3" category=GNodeB component=GNBSIM subcategory=GnbPeerDao
time="2024-04-23T02:31:26Z" level=info msg="Adding new GnbUpUe for PDU Sess ID: 10" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:26Z" level=info msg="Handling event: DL-INFO-TRANSFER-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling: DL-INFO-TRANSFER-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Calculate NAS MAC (algorithm: 2, DLCount: 0x2)" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="NAS integrity key: f871fea67895c124334cdf1e67796f3e" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="cmac value: 0xa69c7ae5" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Received Message Type: 104" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Payload contaner type:{1}" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling event: PDU-SESSION-ESTABLISHMENT-ACCEPT-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Next Event: PDU-SESSION-ESTABLISHMENT-ACCEPT-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Handling: PDU-SESSION-ESTABLISHMENT-ACCEPT-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Adding new PDU Session for PDU Sess ID: 10" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="PDU Session ID: 10" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="PDU Session Type: IPV4" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="SSC Mode: 1" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="PDU Address: 172.250.0.8" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:26Z" level=info msg="Received Event: PDU_SESS_ACC_IN:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007499 19 33}" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Find the UE  imsi-208930100007499" category=Stats component=GNBSIM
time="2024-04-23T02:31:26Z" level=info msg="Time[us] between PDU Sess Req & Accept  318140" category=Stats component=GNBSIM
time="2024-04-23T02:31:27Z" level=info msg="Handling event: DATA-BEARER-SETUP-REQUEST-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:27Z" level=info msg="Handling: DATA-BEARER-SETUP-REQUEST-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:27Z" level=info msg="Fetching PDU Session for pduSessId: 10" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:27Z" level=info msg="Handling event: DATA-BEARER-SETUP-RESPONSE-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:27Z" level=info msg="imsiStateMachine received result " category=ProfUeCtx component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:27Z" level=info msg="Handling: INIT-EVENT" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007499
time="2024-04-23T02:31:27Z" level=info msg="Handling event: DATA-BEARER-SETUP-RESPONSE-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:27Z" level=info msg="Fetching GnbUpUe for pduSessId: 10" category=GNodeB component=GNBSIM ranuengapid=50331650 subcategory=GnbCpUe
time="2024-04-23T02:31:27Z" level=info msg="procedure: PDU-SESSION-ESTABLISHMENT-PROCEDURE, status: PROC-PASS-EVENT, E2E latency [ms]: 824" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:27Z" level=info msg="Adding new GnbUpUe for TEID: 50331650 Downlink: true" category=GNodeB component=GNBSIM subcategory=GnbUeDao
time="2024-04-23T02:31:27Z" level=info msg="Procedure Result: PASS, imsi: imsi-208930100007499" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:27Z" level=info msg="Execute procedure  USER-DATA-PACKET-GENERATION-PROCEDURE" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:27Z" level=info msg="Waiting for procedure result from imsiStateMachine" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:27Z" level=info msg="Handling event: PROC-START-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:27Z" level=info msg="Start new procedure  USER-DATA-PACKET-GENERATION-PROCEDURE" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:27Z" level=info msg="Initiating User Data Packet Generation Procedure" category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:27Z" level=info msg="Please wait, initiating uplink user data in 3 seconds ..." category=SimUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:27Z" level=info msg="Received Event: MSG_OUT:  &{2024-04-23 02:31:27.251127728 +0000 UTC m=+9.694756772  1 34}" category=Stats component=GNBSIM
time="2024-04-23T02:31:27Z" level=info msg="Wrote 45 bytes\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:27Z" level=info msg="No transaction found for Id: 34" category=Stats component=GNBSIM
time="2024-04-23T02:31:29Z" level=error msg="Handle connection[addr: <nil>] error: connection reset by peer\n" category=GNodeB component=GNBSIM subcategory=ControlPlaneTransport
time="2024-04-23T02:31:30Z" level=info msg="Handling: DATA-PACKET-GENERATION-REQUEST-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:31:30Z" level=info msg="Handling: DATA-PACKET-GENERATION-REQUEST-EVENT" category=RealUe component=GNBSIM pdusessid=10 subcategory=PduSession supi=imsi-208930100007499
time="2024-04-23T02:31:30Z" level=info msg="Sent UDP Packet, length: 92 bytes\n" category=GNodeB component=GNBSIM subcategory=UserPlaneTransport
time="2024-04-23T02:33:07Z" level=info msg="Procedure Result: FAIL, imsi:imsi-208930100007499, profile timeout" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:33:07Z" level=info msg="imsiStateMachine ended" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007499
time="2024-04-23T02:33:07Z" level=info msg="ExecuteProfile ExecInParallel false. Waiting for UEs to finish procesessing" category=Profile component=GNBSIM profile=profile3
time="2024-04-23T02:33:07Z" level=info msg="Execute procedure  REGISTRATION-PROCEDURE" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007500
time="2024-04-23T02:33:07Z" level=info msg="Waiting for procedure result from imsiStateMachine" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007500
time="2024-04-23T02:33:07Z" level=info msg="Handling event: PROC-START-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007500
time="2024-04-23T02:33:07Z" level=info msg="Start new procedure  REGISTRATION-PROCEDURE" category=SimUe component=GNBSIM supi=imsi-208930100007500
time="2024-04-23T02:33:07Z" level=info msg="Initiating Registration Procedure" category=SimUe component=GNBSIM supi=imsi-208930100007500
time="2024-04-23T02:33:07Z" level=info msg="Handling: REGISTRATION-REQUEST-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007500
time="2024-04-23T02:33:07Z" level=info msg="Received Event: REG_PROC_START:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007500 3 0}" category=Stats component=GNBSIM
time="2024-04-23T02:33:07Z" level=info msg="Handling event: REGISTRATION-REQUEST-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007500
time="2024-04-23T02:33:07Z" level=info msg="Handling event: REGISTRATION-REQUEST-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331651 subcategory=GnbCpUe
time="2024-04-23T02:33:07Z" level=info msg="Received Event: REG_REQ_OUT:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007500 4 35}" category=Stats component=GNBSIM
time="2024-04-23T02:33:07Z" level=error msg="SendToPeer failed: AMF IP address is nil" category=GNodeB component=GNBSIM ranuengapid=50331651 subcategory=GnbCpUe
time="2024-04-23T02:34:47Z" level=info msg="Procedure Result: FAIL, imsi:imsi-208930100007500, profile timeout" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007500
time="2024-04-23T02:34:47Z" level=info msg="imsiStateMachine ended" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007500
time="2024-04-23T02:34:47Z" level=info msg="ExecuteProfile ExecInParallel false. Waiting for UEs to finish procesessing" category=Profile component=GNBSIM profile=profile3
time="2024-04-23T02:34:47Z" level=info msg="Execute procedure  REGISTRATION-PROCEDURE" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007501
time="2024-04-23T02:34:47Z" level=info msg="Waiting for procedure result from imsiStateMachine" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007501
time="2024-04-23T02:34:47Z" level=info msg="Handling event: PROC-START-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007501
time="2024-04-23T02:34:47Z" level=info msg="Start new procedure  REGISTRATION-PROCEDURE" category=SimUe component=GNBSIM supi=imsi-208930100007501
time="2024-04-23T02:34:47Z" level=info msg="Initiating Registration Procedure" category=SimUe component=GNBSIM supi=imsi-208930100007501
time="2024-04-23T02:34:47Z" level=info msg="Handling: REGISTRATION-REQUEST-EVENT" category=RealUe component=GNBSIM supi=imsi-208930100007501
time="2024-04-23T02:34:47Z" level=info msg="Handling event: REGISTRATION-REQUEST-EVENT" category=SimUe component=GNBSIM supi=imsi-208930100007501
time="2024-04-23T02:34:47Z" level=info msg="Received Event: REG_PROC_START:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007501 3 0}" category=Stats component=GNBSIM
time="2024-04-23T02:34:47Z" level=info msg="Handling event: REGISTRATION-REQUEST-EVENT" category=GNodeB component=GNBSIM ranuengapid=50331652 subcategory=GnbCpUe
time="2024-04-23T02:34:47Z" level=info msg="Received Event: REG_REQ_OUT:  &{0001-01-01 00:00:00 +0000 UTC imsi-208930100007501 4 36}" category=Stats component=GNBSIM
time="2024-04-23T02:34:47Z" level=error msg="SendToPeer failed: AMF IP address is nil" category=GNodeB component=GNBSIM ranuengapid=50331652 subcategory=GnbCpUe
time="2024-04-23T02:36:27Z" level=info msg="Procedure Result: FAIL, imsi:imsi-208930100007501, profile timeout" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007501
time="2024-04-23T02:36:27Z" level=info msg="imsiStateMachine ended" category=ProfUeCtx component=GNBSIM supi=imsi-208930100007501
time="2024-04-23T02:36:27Z" level=info msg="ExecuteProfile ended" category=Profile component=GNBSIM profile=profile3
time="2024-04-23T02:36:32Z" level=info msg="Dump all metrics" category=Stats component=GNBSIM
time="2024-04-23T02:36:32Z" level=info msg="UE: imsi-208930100007497, TotalRegTime[us]: 152158, RegReqAuthReq[us]: 31505,  AuthRspSecMReq[us]: 24750, SecModeRspICReq[us]: 95903" category=Stats component=GNBSIM
time="2024-04-23T02:36:32Z" level=info msg="UE: imsi-208930100007497, TotalPduEstTime[us]: 322726, PduSessReqAccept[us]: 322726" category=Stats component=GNBSIM
time="2024-04-23T02:36:32Z" level=info msg="UE: imsi-208930100007497, TotalCtxReleaseTime[us]: 74846, CtxRelReqCmdTime[us]: 74846" category=Stats component=GNBSIM
time="2024-04-23T02:36:32Z" level=info msg="UE: imsi-208930100007498, TotalRegTime[us]: 388517, RegReqAuthReq[us]: 252551,  AuthRspSecMReq[us]: 34325, SecModeRspICReq[us]: 101641" category=Stats component=GNBSIM
time="2024-04-23T02:36:32Z" level=info msg="UE: imsi-208930100007498, TotalPduEstTime[us]: 340296, PduSessReqAccept[us]: 340296" category=Stats component=GNBSIM
time="2024-04-23T02:36:32Z" level=info msg="UE: imsi-208930100007498, TotalCtxReleaseTime[us]: 74035, CtxRelReqCmdTime[us]: 74035" category=Stats component=GNBSIM
time="2024-04-23T02:36:32Z" level=info msg="UE: imsi-208930100007499, TotalRegTime[us]: 394676, RegReqAuthReq[us]: 251720,  AuthRspSecMReq[us]: 33117, SecModeRspICReq[us]: 109839" category=Stats component=GNBSIM
time="2024-04-23T02:36:32Z" level=info msg="UE: imsi-208930100007499, TotalPduEstTime[us]: 318140, PduSessReqAccept[us]: 318140" category=Stats component=GNBSIM