2022-06-15T07:55:58.710Z DEBUG Application data folder: /home/keyssin/.config/nrfconnect/pc-nrfconnect-linkmonitor 2022-06-15T07:55:58.810Z INFO Using nrf-device-lib-js version: 0.4.11 2022-06-15T07:55:58.810Z INFO Using nrf-device-lib version: 0.11.8 2022-06-15T07:55:58.811Z INFO Using nrfjprog DLL version: 10.15.4 2022-06-15T07:55:58.811Z INFO Using JLink version: JLink_V7.62b 2022-06-15T07:55:58.827Z DEBUG App pc-nrfconnect-linkmonitor v2.0.1 official 2022-06-15T07:55:58.828Z DEBUG App path: /home/keyssin/.nrfconnect-apps/node_modules/pc-nrfconnect-linkmonitor 2022-06-15T07:55:58.828Z DEBUG nRFConnect 3.11.1, required by the app is (^3.8.0) 2022-06-15T07:55:58.828Z DEBUG nRFConnect path: /tmp/.mount_nrfconHq599A/resources/app.asar 2022-06-15T07:55:58.828Z DEBUG HomeDir: /home/keyssin 2022-06-15T07:55:58.828Z DEBUG TmpDir: /tmp 2022-06-15T07:55:58.829Z INFO Installed JLink version does not match the provided version (V7.58b) 2022-06-15T07:56:04.876Z INFO Modem port is opened 2022-06-15T07:56:12.777Z DEBUG modem << [00:04:00.276,031] [0m watchdog: primary_feed_worker: Feeding watchdog[0m 2022-06-15T07:56:13.002Z DEBUG modem << [00:04:00.502,258] [0m app_event_manager: APP_EVT_DATA_GET_ALL[0m 2022-06-15T07:56:13.009Z DEBUG modem << [00:04:00.508,941] [0m bms_module: BMS Thread Enter in event_handler[0m 2022-06-15T07:56:13.018Z DEBUG modem << [00:04:00.515,899] [0m bms_module: BMS Thread enqueue is_app_module_event() in Event handler[0m 2022-06-15T07:56:13.026Z DEBUG modem << [00:04:00.525,360] [0m main: data_get: Main: Entered data_get()[0m 2022-06-15T07:56:13.034Z DEBUG modem << [00:04:00.531,951] [0m main: data_get: Modem_dyn data request through data_list[][0m 2022-06-15T07:56:13.041Z DEBUG modem << [00:04:00.540,252] [0m main: data_get: APP_BATT data request through data_list[][0m 2022-06-15T07:56:13.049Z DEBUG modem << [00:04:00.548,431] [0m main: data_get: APP_ENV data request through data_list[][0m 2022-06-15T07:56:13.058Z DEBUG modem << [00:04:00.556,549] [0m main: data_get: APP_NBR_CELLS data request through data_list[][0m 2022-06-15T07:56:13.066Z DEBUG modem << [00:04:00.565,124] [0m main: data_get: BMS data request through data_list[][0m 2022-06-15T07:56:13.072Z DEBUG modem << [00:04:00.572,845] [0m main: data_get: Requested Data count = 4[0m 2022-06-15T07:56:13.079Z DEBUG modem << [00:04:00.579,437] [0m main: data_get: The APP_DATA_COUNT_SIZE = 8[0m 2022-06-15T07:56:13.091Z DEBUG modem << [00:04:00.586,364] [0m main: data_get: Data requested through APP_EVT_DATA_GET Event: MOD_DYN, BAT, NEIGHBOR_CELLS, BMS_DATA[0m 2022-06-15T07:56:13.099Z DEBUG modem << [00:04:00.598,236] [0m main: data_get: Ready to submit APP_EVT_DATA_GET Event[0m 2022-06-15T07:56:13.111Z DEBUG modem << [00:04:00.606,140] [0m app_event_manager: APP_EVT_DATA_GET - Requested data types (MOD_DYN, BAT, NEIGHBOR_CELLS, BMS_DATA)[0m 2022-06-15T07:56:13.118Z DEBUG modem << [00:04:00.618,041] [0m bms_module: BMS Thread Enter in event_handler[0m 2022-06-15T07:56:13.127Z DEBUG modem << [00:04:00.624,969] [0m bms_module: BMS Thread enqueue is_app_module_event() in Event handler[0m 2022-06-15T07:56:13.134Z DEBUG modem << [00:04:00.634,399] [0m main: data_get: Submit APP_EVT_DATA_GET Event[0m 2022-06-15T07:56:13.142Z DEBUG modem << [00:04:00.641,387] [0m bms_module: New Message Received in BMS Thread[0m 2022-06-15T07:56:13.149Z DEBUG modem << [00:04:00.648,529] [0m bms_module: BMS Thread Enter in Running State[0m 2022-06-15T07:56:13.156Z DEBUG modem << [00:04:00.655,548] [0m bms_module: New Message Received in BMS Thread[0m 2022-06-15T07:56:13.163Z DEBUG modem << [00:04:00.662,628] [0m bms_module: BMS Thread Enter in Running State[0m 2022-06-15T07:56:13.172Z DEBUG modem << [00:04:00.669,677] [0m bms_module: BMS Thread: processing APP_EVT_DATA_GET in running State[0m 2022-06-15T07:56:13.180Z DEBUG modem << [00:04:00.678,741] [0m bms_module: BMS Thread: bms_run_event submit in Running State[0m 2022-06-15T07:56:13.209Z DEBUG modem << [00:04:00.687,347] [0m app_event_manager: BMS_DATA_READY - bms_id: 3902,PackV:0.00,SOC:0,Amp:0,max_mv:0,max_Vcell:0,min_mv:0,min_cell:0, max_temp:0,max_Tcell:32,min_temp:0,min_Tcell:0,device_state:0,chg+_MOS:0,dischg_MOS:0,bms_life:0, total_cells:0,temp_sensors:0,charger_status:0,load_status:0,average_volt:0.000000[0m 2022-06-15T07:56:13.217Z DEBUG modem << [00:04:00.716,430] [0m main: MAIN Thread: BMS Event detected and enqueued[0m 2022-06-15T07:56:13.224Z DEBUG modem << [00:04:00.723,876] [0m bms_module: BMS Thread Enter in event_handler[0m 2022-06-15T07:56:13.233Z DEBUG modem << [00:04:00.731,018] [0m modem_module: on_all_states: modem_module: APP_EVT_DATA_GET processing[0m 2022-06-15T07:56:13.243Z DEBUG modem << [00:04:00.740,478] [0m data_module: on_all_states: data_module: APP_EVT_DATA_GET processing[0m 2022-06-15T07:56:13.252Z DEBUG modem << [00:04:00.749,664] [0m data_module: on_all_states: data module: processing BMS_DATA_READY Event[0m 2022-06-15T07:56:13.263Z DEBUG modem << [00:04:00.759,155] [0m cloud_codec_ringbuffer: cloud_codec_populate_bms_buffer: Entry: 0 of 2 in bms buffer filled[0m 2022-06-15T07:56:13.273Z DEBUG modem << [00:04:00.770,202] [0m data_module: on_all_states: data module: populated bms_buf [0m 2022-06-15T07:56:13.281Z DEBUG modem << [00:04:00.778,564] [0m data_module: requested_data_status_set: processed requested_data_status_set()[0m 2022-06-15T07:56:13.291Z DEBUG modem << [00:04:00.788,421] [0m data_module: on_all_states: data module: processed BMS_DATA_READY Event[0m 2022-06-15T07:56:13.358Z DEBUG modem << [00:04:00.856,842] [0m app_event_manager: MODEM_EVT_MODEM_DYNAMIC_DATA_READY[0m 2022-06-15T07:56:13.371Z DEBUG modem << [00:04:00.865,447] [0m cloud_codec_ringbuffer: cloud_codec_populate_modem_dynamic_buffer: Entry: 2 of 2 in dynamic modem buffer filled[0m 2022-06-15T07:56:13.381Z DEBUG modem << [00:04:00.878,295] [0m data_module: requested_data_status_set: processed requested_data_status_set()[0m 2022-06-15T07:56:13.455Z DEBUG modem << [00:04:00.952,941] [0m app_event_manager: MODEM_EVT_BATTERY_DATA_READY[0m 2022-06-15T07:56:13.471Z DEBUG modem << [00:04:00.960,998] [0m cloud_codec_ringbuffer: clou%NCELLMEAS: 0,"01508417","310260","3468",336,5035,197,52,21,238734,5035,143,48,12,0,5035,430,47,10,0,5035,286,44,4,0,124514 2022-06-15T07:56:13.480Z DEBUG modem << [00:04:00.977,996] [0m modem_module: lte_evt_handler: Neighbor cell measurements received[0m 2022-06-15T07:56:13.488Z DEBUG modem << [00:04:00.987,030] [0m app_event_manager: MODEM_EVT_NEIGHBOR_CELLS_DATA_READY[0m 2022-06-15T07:56:13.495Z DEBUG modem << d_codec_populate_bat_buffer: Entry: 0 of 2 in battery buffer filled[0m 2022-06-15T07:56:13.505Z DEBUG modem << [00:04:01.001,800] [0m data_module: requested_data_status_set: processed requested_data_status_set()[0m 2022-06-15T07:56:13.511Z DEBUG modem << [00:04:01.011,749] [0m app_event_manager: DATA_EVT_DATA_READY[0m 2022-06-15T07:56:13.519Z DEBUG modem << [00:04:01.018,280] [0m bms_module: BMS Thread Enter in event_handler[0m 2022-06-15T07:56:13.528Z DEBUG modem << [00:04:01.025,238] [0m bms_module: BMS Thread enqueue is_data_module_event() in Event handler[0m 2022-06-15T07:56:13.538Z DEBUG modem << [00:04:01.035,095] [0m data_module: requested_data_status_set: processed requested_data_status_set()[0m 2022-06-15T07:56:13.549Z DEBUG modem << [00:04:01.045,013] [0m cloud_codec: cloud_codec_encode_neighbor_cells: Entered cloud_codec_encode_neighbour_cells[0m 2022-06-15T07:56:13.564Z DEBUG modem << Encoded message: 2022-06-15T07:56:13.571Z DEBUG modem << { 2022-06-15T07:56:13.573Z DEBUG modem << "mcc":310, 2022-06-15T07:56:13.577Z DEBUG modem << "mnc":260, 2022-06-15T07:56:13.579Z DEBUG modem << "cell":22053911, 2022-06-15T07:56:13.580Z DEBUG modem << "area":13416, 2022-06-15T07:56:13.581Z DEBUG modem << "earfcn":5035, 2022-06-15T07:56:13.582Z DEBUG modem << "adv":336, 2022-06-15T07:56:13.582Z DEBUG modem << "rsrp":-88, 2022-06-15T07:56:13.586Z DEBUG modem << "rsrq":-9, 2022-06-15T07:56:13.587Z DEBUG modem << "ts":1655279772883, 2022-06-15T07:56:13.588Z DEBUG modem << "nmr":[{ 2022-06-15T07:56:13.589Z DEBUG modem << "earfcn":5035, 2022-06-15T07:56:13.589Z DEBUG modem << "cell":143, 2022-06-15T07:56:13.593Z DEBUG modem << "rsrp":-92, 2022-06-15T07:56:13.594Z DEBUG modem << "rsrq":-14 2022-06-15T07:56:13.595Z DEBUG modem << }, { 2022-06-15T07:56:13.597Z DEBUG modem << "earfcn":5035, 2022-06-15T07:56:13.597Z DEBUG modem << "cell":430, 2022-06-15T07:56:13.598Z DEBUG modem << "rsrp":-93, 2022-06-15T07:56:13.603Z DEBUG modem << "rsrq":-15 2022-06-15T07:56:13.604Z DEBUG modem << }, { 2022-06-15T07:56:13.605Z DEBUG modem << "earfcn":5035, 2022-06-15T07:56:13.607Z DEBUG modem << "cell":286, 2022-06-15T07:56:13.608Z DEBUG modem << "rsrp":-96, 2022-06-15T07:56:13.609Z DEBUG modem << "rsrq":-18 2022-06-15T07:56:13.614Z DEBUG modem << }] 2022-06-15T07:56:13.615Z DEBUG modem << } 2022-06-15T07:56:13.616Z DEBUG modem << [00:04:01.106,353] [0m data_module: data_encode: Neighbor cell data encoded successfully[0m 2022-06-15T07:56:13.620Z DEBUG modem << [00:04:01.115,051] [0m data_module: data_list_add_pending: Pending data added: 0x2001d938[0m 2022-06-15T07:56:13.628Z DEBUG modem << [00:04:01.123,962] [0m app_event_manager: DATA_EVT_NEIGHBOR_CELLS_DATA_SEND[0m 2022-06-15T07:56:13.638Z DEBUG modem << [00:04:01.131,744] [0m bms_module: BMS Thread Enter in event_handler[0m 2022-06-15T07:56:13.641Z DEBUG modem << [00:04:01.138,702] [0m bms_module: BMS Thread enqueue is_data_module_event() in Event handler[0m 2022-06-15T07:56:13.649Z DEBUG modem << [00:04:01.148,681] [0m bms_module: New Message Received in BMS Thread[0m 2022-06-15T07:56:13.656Z DEBUG modem << [00:04:01.155,731] [0m bms_module: BMS Thread Enter in Running State[0m 2022-06-15T07:56:13.663Z DEBUG modem << [00:04:01.162,780] [0m bms_module: New Message Received in BMS Thread[0m 2022-06-15T07:56:13.670Z DEBUG modem << [00:04:01.169,921] [0m bms_module: BMS Thread Enter in Running State[0m 2022-06-15T07:56:13.679Z DEBUG modem << [00:04:01.176,971] [0m cloud_codec: cloud_codec_encode_data: Entered cloud_codec_encode_data[0m 2022-06-15T07:56:13.688Z DEBUG modem << [00:04:01.186,157] [0m cloud_codec: cloud_codec_encode_data: Added btn data to encode_data[0m 2022-06-15T07:56:13.698Z DEBUG modem << [00:04:01.195,159] [0m cloud_codec: cloud_codec_encode_data: Added mdm_sta data to encode_data[0m 2022-06-15T07:56:13.707Z DEBUG modem << [00:04:01.204,772] [0m cloud_codec: cloud_codec_encode_data: Added mdm_dyn data to encode_data[0m 2022-06-15T07:56:13.716Z DEBUG modem << [00:04:01.214,172] [0m cloud_codec: cloud_codec_encode_data: Added gnss data to encode_data[0m 2022-06-15T07:56:13.726Z DEBUG modem << [00:04:01.223,663] [0m cloud_codec: cloud_codec_encode_data: Added bms data to encode_data[0m 2022-06-15T07:56:13.735Z DEBUG modem << [00:04:01.232,696] [0m cloud_codec: cloud_codec_encode_data: Added env data to encode_data[0m 2022-06-15T07:56:13.744Z DEBUG modem << [00:04:01.241,760] [0m cloud_codec: cloud_codec_encode_data: Added mov data to encode_data[0m 2022-06-15T07:56:13.753Z DEBUG modem << [00:04:01.250,976] [0m cloud_codec: cloud_codec_encode_data: Added batt data to encode_data[0m 2022-06-15T07:56:13.760Z DEBUG modem << Encoded message: 2022-06-15T07:56:13.764Z DEBUG modem << { 2022-06-15T07:56:13.766Z DEBUG modem << "roam":{ 2022-06-15T07:56:13.767Z DEBUG modem << "v":{ 2022-06-15T07:56:13.768Z DEBUG modem << "rsrp":-92 2022-06-15T07:56:13.769Z DEBUG modem << }, 2022-06-15T07:56:13.774Z DEBUG modem << "ts":1655279772752 2022-06-15T07:56:13.776Z DEBUG modem << }, 2022-06-15T07:56:13.778Z DEBUG modem << "BMS Device":{ 2022-06-15T07:56:13.779Z DEBUG modem << "packet":{ 2022-06-15T07:56:13.786Z DEBUG modem << "bms_id":3902, 2022-06-15T07:56:13.788Z DEBUG modem << "Volt":0, 2022-06-15T07:56:13.789Z DEBUG modem << "SOC":0, 2022-06-15T07:56:13.790Z DEBUG modem << "Current":0 2022-06-15T07:56:13.791Z DEBUG modem << }, 2022-06-15T07:56:13.791Z DEBUG modem << "ts":1655279772574 2022-06-15T07:56:13.792Z DEBUG modem << }, 2022-06-15T07:56:13.792Z DEBUG modem << "bat":{ 2022-06-15T07:56:13.793Z DEBUG modem << "v":5062, 2022-06-15T07:56:13.799Z DEBUG modem << "ts":1655279772849 2022-06-15T07:56:13.800Z DEBUG modem << } 2022-06-15T07:56:13.801Z DEBUG modem << } 2022-06-15T07:56:13.802Z DEBUG modem << [00:04:01.290,649] [0m data_module: data_encode: Data encoded successfully[0m 2022-06-15T07:56:13.807Z DEBUG modem << [00:04:01.298,126] [0m data_module: data_list_add_pending: Pending data added: 0x2001d858[0m 2022-06-15T07:56:13.813Z DEBUG modem << [00:04:01.307,006] [0m app_event_manager: DATA_EVT_DATA_SEND[0m 2022-06-15T07:56:13.821Z DEBUG modem << [00:04:01.313,507] [0m bms_module: BMS Thread Enter in event_handler[0m 2022-06-15T07:56:13.827Z DEBUG modem << [00:04:01.320,434] [0m bms_module: BMS Thread enqueue is_data_module_event() in Event handler[0m 2022-06-15T07:56:13.834Z DEBUG modem << [00:04:01.329,986] [0m azure_iot_hub_topic: azure_iot_hub_prop_bag_str_get: Requested memory block size: 50[0m 2022-06-15T07:56:13.849Z DEBUG modem << [00:04:01.340,606] [0m azure_iot_hub: azure_iot_hub_send: Publishing to topic: devices/351358811475034/messages/events/ncellmeas&%24.ct=application%2Fjson&%24.ce=utf-8[0m 2022-06-15T07:56:13.860Z DEBUG modem << [00:04:01.356,597] [0m cloud_codec: cloud_codec_encode_batch_data: Entered cloud_codec_encode_batch_data[0m 2022-06-15T07:56:13.870Z DEBUG modem << [00:04:01.366,912] [0m cloud_codec: cloud_codec_encode_batch_data: Added mdm_sta data to encode_batch_data[0m 2022-06-15T07:56:13.881Z DEBUG modem << [00:04:01.377,380] [0m cloud_codec: cloud_codec_encode_batch_data: Added mdm_dyn data to encode_batch_data[0m 2022-06-15T07:56:13.891Z DEBUG modem << [00:04:01.387,847] [0m cloud_codec: cloud_codec_encode_batch_data: Added gnss data to encode_batch_data[0m 2022-06-15T07:56:13.901Z DEBUG modem << [00:04:01.398,010] [0m cloud_codec: cloud_codec_encode_batch_data: Added bms data to encode_batch_data[0m 2022-06-15T07:56:13.911Z DEBUG modem << [00:04:01.408,142] [0m cloud_codec: cloud_codec_encode_batch_data: Added sensor data to encode_batch_data[0m 2022-06-15T07:56:13.922Z DEBUG modem << [00:04:01.418,548] [0m cloud_codec: cloud_codec_encode_batch_data: Added battery data to encode_batch_data[0m 2022-06-15T07:56:13.932Z DEBUG modem << [00:04:01.429,016] [0m cloud_codec: cloud_codec_encode_batch_data: Added acc data to encode_batch_data[0m 2022-06-15T07:56:13.942Z DEBUG modem << [00:04:01.439,086] [0m cloud_codec: cloud_codec_encode_batch_data: No data to encode, JSON string empty...[0m 2022-06-15T07:56:13.952Z DEBUG modem << [00:04:01.449,462] [0m data_module: data_encode: No batch data to encode, ringbuffers are empty[0m 2022-06-15T07:56:13.960Z DEBUG modem << [00:04:01.458,953] [0m bms_module: New Message Received in BMS Thread[0m 2022-06-15T07:56:13.966Z DEBUG modem << [00:04:01.466,094] [0m bms_module: BMS Thread Enter in Runn+CSCON: 1 2022-06-15T07:56:13.973Z DEBUG modem << [00:04:01.472,991] [0m modem_module: lte_evt_handler: RRC mode: Connected[0m 2022-06-15T07:56:13.975Z DEBUG modem << ing State[0m 2022-06-15T07:56:13.987Z DEBUG modem << [00:04:01.482,879] [0m cloud_module: neighbor_cells_data_send: Neighbor cell data sent, data pointer: 0x2001d938[0m 2022-06-15T07:56:13.993Z DEBUG modem << [00:04:01.493,774] [0m app_event_manager: CLOUD_EVT_DATA_ACK[0m 2022-06-15T07:56:14.006Z DEBUG modem << [00:04:01.500,701] [0m azure_iot_hub: azure_iot_hub_send: Publishing to topic: $iothub/twin/PATCH/properties/reported/?$rid=241500[0m 2022-06-15T07:56:14.017Z DEBUG modem << [00:04:01.513,488] [0m data_module: data_ack: Pending data ACKed: 0x2001d938[0m 2022-06-15T07:56:14.024Z DEBUG modem << [00:04:01.522,521] [0m cloud_module: data_send: Data sent, data pointer: 0x2001d858[0m 2022-06-15T07:56:14.030Z DEBUG modem << [00:04:01.530,822] [0m app_event_manager: CLOUD_EVT_DATA_ACK[0m 2022-06-15T07:56:14.038Z DEBUG modem << [00:04:01.537,719] [0m data_module: data_ack: Pending data ACKed: 0x2001d858[0m 2022-06-15T07:56:15.026Z DEBUG modem << [00:04:02.522,399] [0m azure_iot_hub: on_publish: MQTT_EVT_PUBLISH: id = 0, len = 299 [0m 2022-06-15T07:56:15.036Z DEBUG modem << [00:04:02.531,158] [0m azure_iot_hub_topic: azure_iot_hub_topic_parse: Dynamic value: 400[0m 2022-06-15T07:56:15.043Z DEBUG modem << [00:04:02.540,039] [0m azure_iot_hub_topic: get_next_prop_bag: Key: $rid[0m 2022-06-15T07:56:15.049Z DEBUG modem << [00:04:02.547,363] [0m azure_iot_hub_topic: get_next_prop_bag: Value: 241500[0m 2022-06-15T07:56:15.056Z DEBUG modem << [00:04:02.555,145] [0m azure_iot_hub: on_publish: Device twin data received[0m 2022-06-15T07:56:15.066Z DEBUG modem << [00:04:02.562,866] [0m azure_iot_hub: device_twin_result_process: Bad twin request, malformed JSON?[0m 2022-06-15T07:56:15.077Z DEBUG modem << [00:04:02.572,601] [0m azure_iot_hub_integration: azure_iot_hub_event_handler: AZURE_IOT_HUB_EVT_TWIN_RESULT_FAIL[0m 2022-06-15T07:56:19.437Z DEBUG modem << +CSCON: 0 2022-06-15T07:56:19.446Z DEBUG modem << [00:04:06.943,969] [0m modem_module: lte_evt_handler: RRC mode: Idle[0m