Read array tags for Omron PLC broken with v1.4.0

MountainKing91 commented 3 months ago

After upgrading from libplctag.NET 1.2.0 it is not possible to read arrays anymore.

PLC: Omron NX1P2

For example, I want to read a tag named "AlarmList", datatype BOOL[64]

Code:

var tag = new Tag<BoolPlcMapper, bool[]>()
{
    Name = "AlarmList",
    Gateway = "192.168.250.1",
    Path = "1,0",
    PlcType = PlcType.Omron,
    Protocol = Protocol.ab_eip,
    ArrayDimensions = new int[] { 64 },
    Timeout = TimeSpan.FromMilliseconds(5000)
};

tag.Read();

This code works fine with version 1.2.0 but throws an exception "ErrorBadParam" with 1.3.0 and 1.4.0. I looked at the changelog but I couldn't locate what has changed regarding arrays.

Logs level 4: logs.txt

kyle-github commented 3 months ago

So Rockwell does an interesting thing with BOOLs in UDTs. Bools in arrays are packed where the field is. Singleton BOOLs are packed into a hidden member (8 at a time IIRC). I wonder if that is the case here. Then the 0x0101 of the first two bytes in the result would be 257 which sounds like

256 - string data 1 - nul string terminator (like in C).

MountainKing91 commented 3 months ago

What could be a 'test' UDT to look deeper into this? Multiple BOOL values and a BOOL[xxx]?

MountainKing91 commented 3 months ago

With my UDT 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 01 00 01 00 01 00 00 00 00 00 00 40 8F 40 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

Bytes 0..1 - BOOL 2-257? 258? String 257/258..259 Padding 260-263 - Mode DINT 264-271 - Wait LINT 272-279 - Timeout LINT ...

I would expect a STRING[256] to be 2 bytes of count and 256 of actual data, total 258

kyle-github commented 3 months ago

It should be if they can be up to about 2k long! Certainly the SHORT_STRING type (one byte count word) is not going to work. If that is the case though, then the first two bytes in the result are the count word. And there's no sign of the BOOL.

With Rockwell, each field has an offset in the structure. Bit/BOOL fields additionally have a bit number. The second byte of the type is used for that: C1 04. The manual did not say anything about that with respect to alignment or memory use for Omron PLCs.

Can you post the debug dump again? For this case. I think we're missing something. All the fields are in order except perhaps the BOOL. It really looks like that byte right before the string data is not a count byte.

kyle-github commented 3 months ago

The first byte definitely changed when you toggled the Included field. The second one seems to be stuck at 01. It cannot be part of a count.

Ah, the fine manual seems to say that counts are not transmitted with strings. But the full set of bytes is sent even if the valid data is smaller.

That still leaves us with that pesky extra 01 byte...

MountainKing91 commented 3 months ago

The first byte definitely changed when you toggled the Included field

Yes!

Ah, the fine manual seems to say that counts are not transmitted with strings. But the full set of bytes is sent even if the valid data is smaller. This don't add up to me, strings are even worse than bools to grasp

dump

2024-06-19 00:10:28.714 thread(1) tag(0) INFO plc_tag_create_ex:838 Starting
2024-06-19 00:10:28.715 thread(1) tag(0) INFO initialize_modules:177 Starting.
2024-06-19 00:10:28.715 thread(1) tag(0) INFO initialize_modules:186 Creating library mutex.
2024-06-19 00:10:28.715 thread(1) tag(0) DETAIL mutex_create:726 Starting.
2024-06-19 00:10:28.715 thread(1) tag(0) DETAIL mutex_create:753 Done.
2024-06-19 00:10:28.715 thread(1) tag(0) INFO initialize_modules:207 Initializing library modules.
2024-06-19 00:10:28.715 thread(1) tag(0) INFO lib_init:136 Starting.
2024-06-19 00:10:28.715 thread(1) tag(0) INFO lib_init:140 Setting up global library data.
2024-06-19 00:10:28.715 thread(1) tag(0) INFO lib_init:142 Creating tag hashtable.
2024-06-19 00:10:28.715 thread(1) tag(0) INFO hashtable_create:75 Starting
2024-06-19 00:10:28.715 thread(1) tag(0) INFO hashtable_create:99 Done
2024-06-19 00:10:28.715 thread(1) tag(0) INFO lib_init:148 Creating tag hashtable mutex.
2024-06-19 00:10:28.715 thread(1) tag(0) DETAIL mutex_create:726 Starting.
2024-06-19 00:10:28.715 thread(1) tag(0) DETAIL mutex_create:753 Done.
2024-06-19 00:10:28.715 thread(1) tag(0) INFO lib_init:154 Creating tag condition variable.
2024-06-19 00:10:28.715 thread(1) tag(0) DETAIL cond_create:1087 Starting.
2024-06-19 00:10:28.715 thread(1) tag(0) DETAIL cond_create:1114 Done.
2024-06-19 00:10:28.715 thread(1) tag(0) INFO lib_init:160 Creating tag tickler thread.
2024-06-19 00:10:28.715 thread(1) tag(0) DETAIL thread_create:884 Starting.
2024-06-19 00:10:28.715 thread(1) tag(0) DETAIL thread_create:917 Done.
2024-06-19 00:10:28.715 thread(1) tag(0) INFO lib_init:166 Done.
2024-06-19 00:10:28.715 thread(1) tag(0) INFO initialize_modules:210 Initializing AB module.
2024-06-19 00:10:28.715 thread(1) tag(0) INFO ab_init:125 Initializing AB protocol library.
2024-06-19 00:10:28.715 thread(1) tag(0) DETAIL mutex_create:726 Starting.
2024-06-19 00:10:28.715 thread(2) tag(0) INFO tag_tickler_func:513 Starting.
2024-06-19 00:10:28.715 thread(1) tag(0) DETAIL mutex_create:753 Done.
2024-06-19 00:10:28.715 thread(1) tag(0) INFO ab_init:134 Finished initializing AB protocol library.
2024-06-19 00:10:28.715 thread(1) tag(0) INFO initialize_modules:215 Initializing Modbus module.
2024-06-19 00:10:28.715 thread(1) tag(0) INFO mb_init:2469 Starting.
2024-06-19 00:10:28.715 thread(1) tag(0) DETAIL mb_init:2471 Setting up mutex.
2024-06-19 00:10:28.715 thread(1) tag(0) DETAIL mutex_create:726 Starting.
2024-06-19 00:10:28.716 thread(1) tag(0) DETAIL mutex_create:753 Done.
2024-06-19 00:10:28.716 thread(1) tag(0) INFO mb_init:2480 Done.
2024-06-19 00:10:28.716 thread(1) tag(0) INFO initialize_modules:226 Done initializing library modules.
2024-06-19 00:10:28.716 thread(1) tag(0) INFO initialize_modules:231 Done.
2024-06-19 00:10:28.716 thread(1) tag(0) DETAIL attr_create_from_str:129 Starting.
2024-06-19 00:10:28.716 thread(1) tag(0) DETAIL attr_create_from_str:158 Key-value pair "protocol=ab_eip".
2024-06-19 00:10:28.716 thread(1) tag(0) DETAIL attr_create_from_str:173 Key-value pair before trimming "protocol":"ab_eip".
2024-06-19 00:10:28.717 thread(1) tag(0) DETAIL attr_create_from_str:185 Key-value pair after trimming "protocol":"ab_eip".
2024-06-19 00:10:28.717 thread(1) tag(0) DETAIL attr_create_from_str:158 Key-value pair "gateway=192.168.250.1".
2024-06-19 00:10:28.717 thread(1) tag(0) DETAIL attr_create_from_str:173 Key-value pair before trimming "gateway":"192.168.250.1".
2024-06-19 00:10:28.717 thread(1) tag(0) DETAIL attr_create_from_str:185 Key-value pair after trimming "gateway":"192.168.250.1".
2024-06-19 00:10:28.717 thread(1) tag(0) DETAIL attr_create_from_str:158 Key-value pair "path=1,0".
2024-06-19 00:10:28.717 thread(1) tag(0) DETAIL attr_create_from_str:173 Key-value pair before trimming "path":"1,0".
2024-06-19 00:10:28.717 thread(1) tag(0) DETAIL attr_create_from_str:185 Key-value pair after trimming "path":"1,0".
2024-06-19 00:10:28.718 thread(1) tag(0) DETAIL attr_create_from_str:158 Key-value pair "plc=omron-njnx".
2024-06-19 00:10:28.718 thread(1) tag(0) DETAIL attr_create_from_str:173 Key-value pair before trimming "plc":"omron-njnx".
2024-06-19 00:10:28.718 thread(1) tag(0) DETAIL attr_create_from_str:185 Key-value pair after trimming "plc":"omron-njnx".
2024-06-19 00:10:28.718 thread(1) tag(0) DETAIL attr_create_from_str:158 Key-value pair "name=SelectedStepCfg".
2024-06-19 00:10:28.718 thread(1) tag(0) DETAIL attr_create_from_str:173 Key-value pair before trimming "name":"SelectedStepCfg".
2024-06-19 00:10:28.718 thread(1) tag(0) DETAIL attr_create_from_str:185 Key-value pair after trimming "name":"SelectedStepCfg".
2024-06-19 00:10:28.718 thread(1) tag(0) DETAIL attr_create_from_str:216 Done.
2024-06-19 00:10:28.719 thread(1) tag(0) INFO find_tag_create_func:99 Matched protocol=ab_eip
2024-06-19 00:10:28.719 thread(1) tag(0) INFO ab_tag_create:175 Starting.
2024-06-19 00:10:28.719 thread(1) tag(0) INFO rc_alloc_impl:111 Starting, called from ab_tag_create:182
2024-06-19 00:10:28.719 thread(1) tag(0) INFO rc_alloc_impl:130 Done
2024-06-19 00:10:28.719 thread(1) tag(0) DETAIL rc_alloc_impl:135 Returning memory pointer 00EFEE00
2024-06-19 00:10:28.719 thread(1) tag(0) DETAIL ab_tag_create:188 tag=00EFEE00
2024-06-19 00:10:28.719 thread(1) tag(0) INFO plc_tag_generic_init_tag:467 Starting.
2024-06-19 00:10:28.719 thread(1) tag(0) DETAIL mutex_create:726 Starting.
2024-06-19 00:10:28.720 thread(1) tag(0) DETAIL mutex_create:753 Done.
2024-06-19 00:10:28.720 thread(1) tag(0) DETAIL mutex_create:726 Starting.
2024-06-19 00:10:28.720 thread(1) tag(0) DETAIL mutex_create:753 Done.
2024-06-19 00:10:28.720 thread(1) tag(0) DETAIL cond_create:1087 Starting.
2024-06-19 00:10:28.720 thread(1) tag(0) DETAIL cond_create:1114 Done.
2024-06-19 00:10:28.720 thread(1) tag(0) INFO plc_tag_generic_init_tag:498 Done.
2024-06-19 00:10:28.720 thread(1) tag(0) DETAIL get_plc_type:985 Found OMRON NJ/NX Series PLC.
2024-06-19 00:10:28.721 thread(1) tag(0) DETAIL get_plc_type:985 Found OMRON NJ/NX Series PLC.
2024-06-19 00:10:28.721 thread(1) tag(0) DETAIL session_find_or_create:254 Starting
2024-06-19 00:10:28.721 thread(1) tag(0) DETAIL session_find_or_create:278 Creating new session.
2024-06-19 00:10:28.721 thread(1) tag(0) INFO session_create_unsafe:475 Starting
2024-06-19 00:10:28.721 thread(1) tag(0) DETAIL session_create_unsafe:478 Session should use connected messaging.
2024-06-19 00:10:28.721 thread(1) tag(0) INFO rc_alloc_impl:111 Starting, called from session_create_unsafe:483
2024-06-19 00:10:28.722 thread(1) tag(0) INFO rc_alloc_impl:130 Done
2024-06-19 00:10:28.722 thread(1) tag(0) DETAIL rc_alloc_impl:135 Returning memory pointer 00EFF020
2024-06-19 00:10:28.722 thread(1) tag(0) DETAIL cip_encode_path:71 Starting
2024-06-19 00:10:28.722 thread(1) tag(0) DETAIL match_numeric_segment:195 Starting at position 0 in string 1,0.
2024-06-19 00:10:28.722 thread(1) tag(0) DETAIL match_numeric_segment:224 Remaining path ",0".
2024-06-19 00:10:28.722 thread(1) tag(0) DETAIL match_numeric_segment:229 Done. Found numeric segment 1.
2024-06-19 00:10:28.722 thread(1) tag(0) DETAIL cip_encode_path:89 Found numeric segment.
2024-06-19 00:10:28.723 thread(1) tag(0) DETAIL cip_encode_path:85 Skipping separator character ','.
2024-06-19 00:10:28.723 thread(1) tag(0) DETAIL match_numeric_segment:195 Starting at position 2 in string 1,0.
2024-06-19 00:10:28.723 thread(1) tag(0) DETAIL match_numeric_segment:224 Remaining path "".
2024-06-19 00:10:28.723 thread(1) tag(0) DETAIL match_numeric_segment:229 Done. Found numeric segment 0.
2024-06-19 00:10:28.723 thread(1) tag(0) DETAIL cip_encode_path:89 Found numeric segment.
2024-06-19 00:10:28.723 thread(1) tag(0) DETAIL cip_encode_path:130 PLC needs connection, adding path to the router object.
2024-06-19 00:10:28.723 thread(1) tag(0) DETAIL cip_encode_path:162 IOI size before 6
2024-06-19 00:10:28.724 thread(1) tag(0) DETAIL cip_encode_path:183 Done
2024-06-19 00:10:28.724 thread(1) tag(0) DETAIL session_create_unsafe:531 Setting connection_group_id to 0.
2024-06-19 00:10:28.724 thread(1) tag(0) DETAIL session_create_unsafe:571 Set maximum payload size to 1996 bytes.
2024-06-19 00:10:28.724 thread(1) tag(0) DETAIL add_session_unsafe:339 Starting
2024-06-19 00:10:28.724 thread(1) tag(0) DETAIL add_session_unsafe:349 Done
2024-06-19 00:10:28.724 thread(1) tag(0) INFO session_create_unsafe:588 Done
2024-06-19 00:10:28.725 thread(1) tag(0) DETAIL session_find_or_create:289 Passed attribute to prohibit use of extended ForwardOpen is 0.
2024-06-19 00:10:28.726 thread(1) tag(0) DETAIL session_find_or_create:290 Existing attribute to prohibit use of extended ForwardOpen is 0.
2024-06-19 00:10:28.726 thread(1) tag(0) INFO session_init:604 Starting.
2024-06-19 00:10:28.726 thread(1) tag(0) DETAIL mutex_create:726 Starting.
2024-06-19 00:10:28.727 thread(1) tag(0) DETAIL mutex_create:753 Done.
2024-06-19 00:10:28.727 thread(1) tag(0) DETAIL cond_create:1087 Starting.
2024-06-19 00:10:28.727 thread(1) tag(0) DETAIL cond_create:1114 Done.
2024-06-19 00:10:28.727 thread(1) tag(0) DETAIL thread_create:884 Starting.
2024-06-19 00:10:28.727 thread(1) tag(0) DETAIL thread_create:917 Done.
2024-06-19 00:10:28.727 thread(1) tag(0) INFO session_init:626 Done.
2024-06-19 00:10:28.727 thread(1) tag(0) DETAIL session_find_or_create:329 Done
2024-06-19 00:10:28.728 thread(3) tag(0) INFO session_handler:1038 Starting thread for session 00EFF020
2024-06-19 00:10:28.728 thread(1) tag(0) DETAIL ab_tag_create:289 using session=00EFF020
2024-06-19 00:10:28.728 thread(1) tag(0) DETAIL get_tag_data_type:527 Starting.
2024-06-19 00:10:28.728 thread(3) tag(0) DETAIL session_handler:1058 in SESSION_OPEN_SOCKET_START state.
2024-06-19 00:10:28.728 thread(3) tag(0) INFO session_open_socket:644 Starting.
2024-06-19 00:10:28.728 thread(1) tag(0) DETAIL get_tag_data_type:658 Done.
2024-06-19 00:10:28.728 thread(1) tag(0) DETAIL ab_tag_create:407 Setting up OMRON NJ/NX Series tag.
2024-06-19 00:10:28.729 thread(1) tag(0) DETAIL ab_tag_create:417 Using default Omron byte order.
2024-06-19 00:10:28.729 thread(1) tag(0) DETAIL ab_tag_create:423 Setting default Logix vtable.
2024-06-19 00:10:28.728 thread(3) tag(0) DETAIL socket_create:1311 Starting.
2024-06-19 00:10:28.729 thread(1) tag(0) DETAIL parse_symbolic_segment:720 Starting with name index=0 and encoded name index=1.
2024-06-19 00:10:28.729 thread(1) tag(0) DETAIL parse_symbolic_segment:759 Parsed symbolic segment "SelectedStepCfg" in tag name.
2024-06-19 00:10:28.729 thread(1) tag(0) DETAIL ab_tag_create:495 Kicking off initial read.
2024-06-19 00:10:28.730 thread(1) tag(0) INFO tag_read_start:312 Starting
2024-06-19 00:10:28.730 thread(1) tag(0) INFO build_read_request_connected:423 Starting.
2024-06-19 00:10:28.730 thread(3) tag(0) DETAIL socket_create:1334 Done.
2024-06-19 00:10:28.730 thread(1) tag(0) DETAIL session_create_request:2525 Starting.
2024-06-19 00:10:28.730 thread(3) tag(0) DETAIL session_open_socket:678 Using default port 44818.
2024-06-19 00:10:28.732 thread(1) tag(0) INFO rc_alloc_impl:111 Starting, called from session_create_request:2534
2024-06-19 00:10:28.732 thread(1) tag(0) INFO rc_alloc_impl:130 Done
2024-06-19 00:10:28.732 thread(3) tag(0) DETAIL socket_connect_tcp_start:1355 Starting.
2024-06-19 00:10:28.732 thread(1) tag(0) DETAIL rc_alloc_impl:135 Returning memory pointer 00E812F8
2024-06-19 00:10:28.733 thread(1) tag(0) DETAIL session_create_request:2548 Done.
2024-06-19 00:10:28.733 thread(1) tag(0) INFO session_add_request:966 Starting. sess=00EFF020, req=00E812F8
2024-06-19 00:10:28.733 thread(1) tag(0) DETAIL session_add_request_unsafe:931 Starting.
2024-06-19 00:10:28.733 thread(1) tag(0) DETAIL session_add_request_unsafe:950 Total requests in the queue: 1
2024-06-19 00:10:28.733 thread(1) tag(0) DETAIL session_add_request_unsafe:952 Done.
2024-06-19 00:10:28.734 thread(1) tag(0) INFO session_add_request:974 Done.
2024-06-19 00:10:28.734 thread(1) tag(0) INFO build_read_request_connected:508 Done
2024-06-19 00:10:28.734 thread(1) tag(0) INFO tag_read_start:341 Done.
2024-06-19 00:10:28.734 thread(3) tag(0) DETAIL socket_connect_tcp_start:1404 Found numeric IP address: 192.168.250.1
2024-06-19 00:10:28.734 thread(1) tag(0) DETAIL ab_tag_create:508 Using vtable 795EDC90.
2024-06-19 00:10:28.734 thread(1) tag(0) INFO ab_tag_create:510 Done.
2024-06-19 00:10:28.734 thread(3) tag(0) DETAIL socket_connect_tcp_start:1444 Setting up wake pipe.
2024-06-19 00:10:28.734 thread(3) tag(0) INFO sock_create_event_wakeup_channel:2161 Starting.
2024-06-19 00:10:28.734 thread(1) tag(0) INFO set_tag_byte_order:3969 Starting.
2024-06-19 00:10:28.736 thread(1) tag(0) INFO set_tag_byte_order:4287 Done.
2024-06-19 00:10:28.735 thread(3) tag(0) INFO sock_create_event_wakeup_channel:2308 Done.
2024-06-19 00:10:28.736 thread(1) tag(0) DETAIL add_tag_lookup:4390 Starting.
2024-06-19 00:10:28.736 thread(1) tag(0) DETAIL add_tag_lookup:4410 Found unused ID 11
2024-06-19 00:10:28.736 thread(3) tag(0) DETAIL socket_connect_tcp_start:1475 Socket connection attempt 0 started successfully.
2024-06-19 00:10:28.736 thread(1) tag(0) DETAIL add_tag_lookup:4430 Done.
2024-06-19 00:10:28.737 thread(1) tag(11) INFO plc_tag_create_ex:973 Returning mapped tag ID 11
2024-06-19 00:10:28.737 thread(3) tag(0) DETAIL socket_connect_tcp_start:1501 Done.
2024-06-19 00:10:28.737 thread(1) tag(11) DETAIL plc_tag_create_ex:999 Tag status after creation is PLCTAG_STATUS_PENDING.
2024-06-19 00:10:28.737 thread(3) tag(0) INFO session_open_socket:693 Done.
2024-06-19 00:10:28.737 thread(1) tag(11) DETAIL plc_tag_tickler_wake_impl:220 Starting. Called from plc_tag_create_ex:1010.
2024-06-19 00:10:28.737 thread(3) tag(0) DETAIL session_handler:1074 Connect started, going to state SESSION_OPEN_SOCKET_WAIT.
2024-06-19 00:10:28.738 thread(1) tag(11) DETAIL plc_tag_tickler_wake_impl:233 Done. Called from plc_tag_create_ex:1010.
2024-06-19 00:10:28.738 thread(2) tag(11) DETAIL tag_tickler_func:550 Tickling tag 11.
2024-06-19 00:10:28.738 thread(3) tag(0) DETAIL session_handler:1086 in SESSION_OPEN_SOCKET_WAIT state.
2024-06-19 00:10:28.738 thread(3) tag(0) DETAIL socket_connect_tcp_check:1518 Starting.
2024-06-19 00:10:28.738 thread(2) tag(11) DETAIL plc_tag_generic_tickler:281 Tickling tag 11.
2024-06-19 00:10:28.738 thread(2) tag(11) DETAIL plc_tag_generic_tickler:386 Done.
2024-06-19 00:10:28.739 thread(2) tag(0) DETAIL check_read_request_status:1154 Read not ready with status PLCTAG_STATUS_PENDING.
2024-06-19 00:10:28.739 thread(2) tag(0) DETAIL check_read_status_connected:1369 Read request status is not OK.
2024-06-19 00:10:28.740 thread(3) tag(0) DETAIL socket_connect_tcp_check:1538 Socket is connected.
2024-06-19 00:10:28.740 thread(3) tag(0) DETAIL socket_connect_tcp_check:1598 Done.
2024-06-19 00:10:28.740 thread(3) tag(0) INFO session_handler:1092 Socket connection succeeded.
2024-06-19 00:10:28.740 thread(3) tag(0) DETAIL session_handler:1113 in SESSION_REGISTER state.
2024-06-19 00:10:28.741 thread(3) tag(0) INFO session_register:706 Starting.
2024-06-19 00:10:28.741 thread(3) tag(0) INFO send_eip_request:1876 Starting.
2024-06-19 00:10:28.741 thread(3) tag(0) INFO send_eip_request:1889 Sending packet of size 28
2024-06-19 00:10:28.741 thread(3) tag(0) INFO send_eip_request:1890 00000 65 00 04 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.741 thread(3) tag(0) INFO send_eip_request:1890 00016 00 00 00 00 00 00 00 00 01 00 00 00
2024-06-19 00:10:28.741 thread(3) tag(0) DETAIL socket_write:1945 Starting.
2024-06-19 00:10:28.742 thread(3) tag(0) DETAIL socket_write:2072 Done: result = 28.
2024-06-19 00:10:28.742 thread(3) tag(0) INFO send_eip_request:1932 Done.
2024-06-19 00:10:28.742 thread(3) tag(0) INFO recv_eip_response:1952 Starting.
2024-06-19 00:10:28.742 thread(3) tag(0) DETAIL socket_read:1807 Starting.
2024-06-19 00:10:28.742 thread(3) tag(0) DETAIL socket_read:1836 Immediate read attempt did not succeed, now wait for select().
2024-06-19 00:10:28.746 thread(3) tag(0) DETAIL socket_read:1864 Socket can read data.
2024-06-19 00:10:28.746 thread(3) tag(0) DETAIL socket_read:1934 Done: result = 24.
2024-06-19 00:10:28.746 thread(3) tag(0) DETAIL socket_read:1807 Starting.
2024-06-19 00:10:28.746 thread(3) tag(0) DETAIL socket_read:1934 Done: result = 4.
2024-06-19 00:10:28.746 thread(3) tag(0) INFO recv_eip_response:2023 request received all needed data (28 bytes of 28).
2024-06-19 00:10:28.746 thread(3) tag(0) INFO recv_eip_response:2025 00000 65 00 04 00 70 01 8f 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.747 thread(3) tag(0) INFO recv_eip_response:2025 00016 00 00 00 00 00 00 00 00 01 00 00 00
2024-06-19 00:10:28.747 thread(3) tag(0) INFO recv_eip_response:2032 Done.
2024-06-19 00:10:28.747 thread(3) tag(0) INFO session_register:773 Done.
2024-06-19 00:10:28.747 thread(3) tag(0) DETAIL session_handler:1129 in SESSION_SEND_FORWARD_OPEN state.
2024-06-19 00:10:28.747 thread(3) tag(0) INFO send_forward_open_request:2070 Starting
2024-06-19 00:10:28.747 thread(3) tag(0) DETAIL send_forward_open_request:2091 Flag prohibiting use of extended ForwardOpen is 0.
2024-06-19 00:10:28.747 thread(3) tag(0) DETAIL send_forward_open_request:2155 Set maximum payload size guess to 1996 bytes.
2024-06-19 00:10:28.748 thread(3) tag(0) INFO send_extended_forward_open_request:2259 Starting
2024-06-19 00:10:28.748 thread(3) tag(0) INFO send_eip_request:1876 Starting.
2024-06-19 00:10:28.748 thread(3) tag(0) INFO send_eip_request:1889 Sending packet of size 92
2024-06-19 00:10:28.748 thread(3) tag(0) INFO send_eip_request:1890 00000 6f 00 44 00 70 01 8f 00 00 00 00 00 e8 71 00 00
2024-06-19 00:10:28.748 thread(3) tag(0) INFO send_eip_request:1890 00016 00 00 00 00 00 00 00 00 00 00 00 00 01 00 02 00
2024-06-19 00:10:28.748 thread(3) tag(0) INFO send_eip_request:1890 00032 00 00 00 00 b2 00 34 00 5b 02 20 06 24 01 0a 05
2024-06-19 00:10:28.748 thread(3) tag(0) INFO send_eip_request:1890 00048 00 00 00 00 8a 19 00 00 e9 69 3d f3 45 43 50 21
2024-06-19 00:10:28.749 thread(3) tag(0) INFO send_eip_request:1890 00064 01 00 00 00 40 42 0f 00 cc 07 00 42 40 42 0f 00
2024-06-19 00:10:28.749 thread(3) tag(0) INFO send_eip_request:1890 00080 cc 07 00 42 a3 03 01 00 20 02 24 01
2024-06-19 00:10:28.749 thread(3) tag(0) DETAIL socket_write:1945 Starting.
2024-06-19 00:10:28.749 thread(3) tag(0) DETAIL socket_write:2072 Done: result = 92.
2024-06-19 00:10:28.749 thread(3) tag(0) INFO send_eip_request:1932 Done.
2024-06-19 00:10:28.749 thread(3) tag(0) INFO send_extended_forward_open_request:2318 Done
2024-06-19 00:10:28.749 thread(3) tag(0) INFO send_forward_open_request:2160 Done
2024-06-19 00:10:28.750 thread(3) tag(0) DETAIL session_handler:1135 Send Forward Open succeeded, going to SESSION_RECEIVE_FORWARD_OPEN state.
2024-06-19 00:10:28.750 thread(3) tag(0) DETAIL session_handler:1142 in SESSION_RECEIVE_FORWARD_OPEN state.
2024-06-19 00:10:28.750 thread(3) tag(0) INFO receive_forward_open_response:2331 Starting
2024-06-19 00:10:28.750 thread(3) tag(0) INFO recv_eip_response:1952 Starting.
2024-06-19 00:10:28.750 thread(3) tag(0) DETAIL socket_read:1807 Starting.
2024-06-19 00:10:28.750 thread(3) tag(0) DETAIL socket_read:1836 Immediate read attempt did not succeed, now wait for select().
2024-06-19 00:10:28.754 thread(3) tag(0) DETAIL socket_read:1864 Socket can read data.
2024-06-19 00:10:28.754 thread(3) tag(0) DETAIL socket_read:1934 Done: result = 24.
2024-06-19 00:10:28.754 thread(3) tag(0) DETAIL socket_read:1807 Starting.
2024-06-19 00:10:28.754 thread(3) tag(0) DETAIL socket_read:1934 Done: result = 46.
2024-06-19 00:10:28.754 thread(3) tag(0) INFO recv_eip_response:2023 request received all needed data (70 bytes of 70).
2024-06-19 00:10:28.754 thread(3) tag(0) INFO recv_eip_response:2025 00000 6f 00 2e 00 70 01 8f 00 00 00 00 00 e8 71 00 00
2024-06-19 00:10:28.755 thread(3) tag(0) INFO recv_eip_response:2025 00016 00 00 00 00 00 00 00 00 00 00 00 00 01 00 02 00
2024-06-19 00:10:28.756 thread(3) tag(0) INFO recv_eip_response:2025 00032 00 00 00 00 b2 00 1e 00 db 00 00 00 c1 47 0d 7f
2024-06-19 00:10:28.756 thread(3) tag(0) INFO recv_eip_response:2025 00048 8a 19 00 00 e9 69 3d f3 45 43 50 21 40 42 0f 00
2024-06-19 00:10:28.756 thread(3) tag(0) INFO recv_eip_response:2025 00064 40 42 0f 00 00 00
2024-06-19 00:10:28.756 thread(3) tag(0) INFO recv_eip_response:2032 Done.
2024-06-19 00:10:28.756 thread(3) tag(0) INFO receive_forward_open_response:2393 ForwardOpen succeeded with our connection ID 198a and the PLC connection ID 7f0d47c1 with packet size 1996.
2024-06-19 00:10:28.757 thread(3) tag(0) INFO receive_forward_open_response:2398 Done.
2024-06-19 00:10:28.757 thread(3) tag(0) DETAIL session_handler:1161 Send Forward Open succeeded, going to SESSION_IDLE state.
2024-06-19 00:10:28.757 thread(3) tag(0) DETAIL session_handler:1168 in SESSION_IDLE state.
2024-06-19 00:10:28.757 thread(3) tag(0) DETAIL session_handler:1174 There are 1 requests pending before cleanup and sending.
2024-06-19 00:10:28.757 thread(3) tag(0) DETAIL get_payload_size:1679 Starting.
2024-06-19 00:10:28.757 thread(3) tag(0) DETAIL get_payload_size:1693 Done.
2024-06-19 00:10:28.758 thread(3) tag(0) INFO process_requests:1450 1 requests to process.
2024-06-19 00:10:28.758 thread(3) tag(0) INFO pack_requests:1714 Starting.
2024-06-19 00:10:28.758 thread(3) tag(0) INFO pack_requests:1724 Only one request, so done.
2024-06-19 00:10:28.758 thread(3) tag(0) INFO prepare_request:1816 Starting.
2024-06-19 00:10:28.758 thread(3) tag(0) DETAIL prepare_request:1845 cpf_targ_conn_id=7f0d47c1
2024-06-19 00:10:28.758 thread(3) tag(0) INFO prepare_request:1853 Preparing connected packet with connection ID 198a and sequence ID 1(1)
2024-06-19 00:10:28.758 thread(3) tag(0) INFO prepare_request:1860 Prepared packet of size 68
2024-06-19 00:10:28.758 thread(3) tag(0) INFO prepare_request:1861 00000 70 00 2c 00 70 01 8f 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.759 thread(3) tag(0) INFO prepare_request:1861 00016 00 00 00 00 00 00 00 00 00 00 00 00 01 00 02 00
2024-06-19 00:10:28.759 thread(3) tag(0) INFO prepare_request:1861 00032 a1 00 04 00 c1 47 0d 7f b1 00 18 00 01 00 4c 09
2024-06-19 00:10:28.759 thread(3) tag(0) INFO prepare_request:1861 00048 91 0f 53 65 6c 65 63 74 65 64 53 74 65 70 43 66
2024-06-19 00:10:28.759 thread(3) tag(0) INFO prepare_request:1861 00064 67 00 01 00
2024-06-19 00:10:28.759 thread(3) tag(0) INFO prepare_request:1863 Done.
2024-06-19 00:10:28.759 thread(3) tag(0) INFO send_eip_request:1876 Starting.
2024-06-19 00:10:28.759 thread(3) tag(0) INFO send_eip_request:1889 Sending packet of size 68
2024-06-19 00:10:28.760 thread(3) tag(0) INFO send_eip_request:1890 00000 70 00 2c 00 70 01 8f 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.760 thread(3) tag(0) INFO send_eip_request:1890 00016 00 00 00 00 00 00 00 00 00 00 00 00 01 00 02 00
2024-06-19 00:10:28.760 thread(3) tag(0) INFO send_eip_request:1890 00032 a1 00 04 00 c1 47 0d 7f b1 00 18 00 01 00 4c 09
2024-06-19 00:10:28.760 thread(3) tag(0) INFO send_eip_request:1890 00048 91 0f 53 65 6c 65 63 74 65 64 53 74 65 70 43 66
2024-06-19 00:10:28.760 thread(3) tag(0) INFO send_eip_request:1890 00064 67 00 01 00
2024-06-19 00:10:28.760 thread(3) tag(0) DETAIL socket_write:1945 Starting.
2024-06-19 00:10:28.760 thread(3) tag(0) DETAIL socket_write:2072 Done: result = 68.
2024-06-19 00:10:28.761 thread(3) tag(0) INFO send_eip_request:1932 Done.
2024-06-19 00:10:28.761 thread(3) tag(0) INFO recv_eip_response:1952 Starting.
2024-06-19 00:10:28.761 thread(3) tag(0) DETAIL socket_read:1807 Starting.
2024-06-19 00:10:28.761 thread(3) tag(0) DETAIL socket_read:1836 Immediate read attempt did not succeed, now wait for select().
2024-06-19 00:10:28.766 thread(3) tag(0) DETAIL socket_read:1864 Socket can read data.
2024-06-19 00:10:28.766 thread(3) tag(0) DETAIL socket_read:1934 Done: result = 24.
2024-06-19 00:10:28.766 thread(3) tag(0) DETAIL socket_read:1807 Starting.
2024-06-19 00:10:28.766 thread(3) tag(0) DETAIL socket_read:1934 Done: result = 430.
2024-06-19 00:10:28.766 thread(3) tag(0) INFO recv_eip_response:2023 request received all needed data (454 bytes of 454).
2024-06-19 00:10:28.767 thread(3) tag(0) INFO recv_eip_response:2025 00000 70 00 ae 01 70 01 8f 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.767 thread(3) tag(0) INFO recv_eip_response:2025 00016 00 00 00 00 00 00 00 00 00 00 00 00 00 00 02 00
2024-06-19 00:10:28.767 thread(3) tag(0) INFO recv_eip_response:2025 00032 a1 00 04 00 8a 19 00 00 b1 00 9a 01 01 00 cc 00
2024-06-19 00:10:28.767 thread(3) tag(0) INFO recv_eip_response:2025 00048 00 00 a0 02 72 a2 00 01 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.767 thread(3) tag(0) INFO recv_eip_response:2025 00064 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.767 thread(3) tag(0) INFO recv_eip_response:2025 00080 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.767 thread(3) tag(0) INFO recv_eip_response:2025 00096 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.767 thread(3) tag(0) INFO recv_eip_response:2025 00112 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.768 thread(3) tag(0) INFO recv_eip_response:2025 00128 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.768 thread(3) tag(0) INFO recv_eip_response:2025 00144 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.768 thread(3) tag(0) INFO recv_eip_response:2025 00160 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.768 thread(3) tag(0) INFO recv_eip_response:2025 00176 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.768 thread(3) tag(0) INFO recv_eip_response:2025 00192 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.768 thread(3) tag(0) INFO recv_eip_response:2025 00208 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.768 thread(3) tag(0) INFO recv_eip_response:2025 00224 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.769 thread(3) tag(0) INFO recv_eip_response:2025 00240 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.769 thread(3) tag(0) INFO recv_eip_response:2025 00256 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.769 thread(3) tag(0) INFO recv_eip_response:2025 00272 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.769 thread(3) tag(0) INFO recv_eip_response:2025 00288 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.769 thread(3) tag(0) INFO recv_eip_response:2025 00304 00 00 00 00 00 00 00 00 00 00 04 00 00 00 c4 09
2024-06-19 00:10:28.769 thread(3) tag(0) INFO recv_eip_response:2025 00320 00 00 00 00 00 00 88 13 00 00 00 00 00 00 01 00
2024-06-19 00:10:28.770 thread(3) tag(0) INFO recv_eip_response:2025 00336 01 00 01 00 01 00 00 00 00 00 00 40 8f 40 00 00
2024-06-19 00:10:28.770 thread(3) tag(0) INFO recv_eip_response:2025 00352 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.770 thread(3) tag(0) INFO recv_eip_response:2025 00368 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.770 thread(3) tag(0) INFO recv_eip_response:2025 00384 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.770 thread(3) tag(0) INFO recv_eip_response:2025 00400 00 00 00 58 9b 40 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.770 thread(3) tag(0) INFO recv_eip_response:2025 00416 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.770 thread(3) tag(0) INFO recv_eip_response:2025 00432 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.770 thread(3) tag(0) INFO recv_eip_response:2025 00448 00 00 00 00 00 00
2024-06-19 00:10:28.771 thread(3) tag(0) INFO recv_eip_response:2032 Done.
2024-06-19 00:10:28.771 thread(3) tag(0) INFO unpack_response:1558 Starting.
2024-06-19 00:10:28.771 thread(3) tag(0) INFO unpack_response:1567 Got single response packet.  Copying 454 bytes unchanged.
2024-06-19 00:10:28.771 thread(3) tag(0) INFO unpack_response:1656 Unpacked packet:
2024-06-19 00:10:28.771 thread(3) tag(0) INFO unpack_response:1657 00000 70 00 ae 01 70 01 8f 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.771 thread(3) tag(0) INFO unpack_response:1657 00016 00 00 00 00 00 00 00 00 00 00 00 00 00 00 02 00
2024-06-19 00:10:28.771 thread(3) tag(0) INFO unpack_response:1657 00032 a1 00 04 00 8a 19 00 00 b1 00 9a 01 01 00 cc 00
2024-06-19 00:10:28.772 thread(3) tag(0) INFO unpack_response:1657 00048 00 00 a0 02 72 a2 00 01 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.772 thread(3) tag(0) INFO unpack_response:1657 00064 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.772 thread(3) tag(0) INFO unpack_response:1657 00080 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.772 thread(3) tag(0) INFO unpack_response:1657 00096 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.772 thread(3) tag(0) INFO unpack_response:1657 00112 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.772 thread(3) tag(0) INFO unpack_response:1657 00128 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.772 thread(3) tag(0) INFO unpack_response:1657 00144 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.773 thread(3) tag(0) INFO unpack_response:1657 00160 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.773 thread(3) tag(0) INFO unpack_response:1657 00176 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.773 thread(3) tag(0) INFO unpack_response:1657 00192 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.773 thread(3) tag(0) INFO unpack_response:1657 00208 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.773 thread(3) tag(0) INFO unpack_response:1657 00224 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.773 thread(3) tag(0) INFO unpack_response:1657 00240 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.773 thread(3) tag(0) INFO unpack_response:1657 00256 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.774 thread(3) tag(0) INFO unpack_response:1657 00272 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.774 thread(3) tag(0) INFO unpack_response:1657 00288 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.774 thread(3) tag(0) INFO unpack_response:1657 00304 00 00 00 00 00 00 00 00 00 00 04 00 00 00 c4 09
2024-06-19 00:10:28.774 thread(3) tag(0) INFO unpack_response:1657 00320 00 00 00 00 00 00 88 13 00 00 00 00 00 00 01 00
2024-06-19 00:10:28.774 thread(3) tag(0) INFO unpack_response:1657 00336 01 00 01 00 01 00 00 00 00 00 00 40 8f 40 00 00
2024-06-19 00:10:28.774 thread(3) tag(0) INFO unpack_response:1657 00352 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.776 thread(3) tag(0) INFO unpack_response:1657 00368 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.776 thread(3) tag(0) INFO unpack_response:1657 00384 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.776 thread(3) tag(0) INFO unpack_response:1657 00400 00 00 00 58 9b 40 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.776 thread(3) tag(0) INFO unpack_response:1657 00416 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.777 thread(3) tag(0) INFO unpack_response:1657 00432 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.777 thread(3) tag(0) INFO unpack_response:1657 00448 00 00 00 00 00 00
2024-06-19 00:10:28.777 thread(3) tag(0) DETAIL unpack_response:1666 Done.
2024-06-19 00:10:28.777 thread(3) tag(0) DETAIL plc_tag_tickler_wake_impl:220 Starting. Called from process_requests:1538.
2024-06-19 00:10:28.777 thread(3) tag(0) DETAIL plc_tag_tickler_wake_impl:233 Done. Called from process_requests:1538.
2024-06-19 00:10:28.777 thread(2) tag(11) DETAIL tag_tickler_func:550 Tickling tag 11.
2024-06-19 00:10:28.777 thread(2) tag(11) DETAIL plc_tag_generic_tickler:281 Tickling tag 11.
2024-06-19 00:10:28.777 thread(2) tag(11) DETAIL plc_tag_generic_tickler:386 Done.
2024-06-19 00:10:28.777 thread(2) tag(0) DETAIL check_read_status_connected:1438 type byte = 160 (0xa0)
2024-06-19 00:10:28.777 thread(2) tag(0) DETAIL check_read_status_connected:1454 Type data is 4 bytes long.
2024-06-19 00:10:28.777 thread(2) tag(0) DETAIL check_read_status_connected:1455 00000 a0 02 72 a2
2024-06-19 00:10:28.777 thread(2) tag(0) DETAIL check_read_status_connected:1477 Increasing tag buffer size to 400 bytes.
2024-06-19 00:10:28.777 thread(2) tag(0) INFO check_read_status_connected:1487 Got 400 bytes of data
2024-06-19 00:10:28.777 thread(2) tag(0) DETAIL rc_dec_impl:242 Calling cleanup functions due to call at check_read_status_connected:1520 for 00E812F8.
2024-06-19 00:10:28.778 thread(2) tag(0) INFO refcount_cleanup:256 Starting
2024-06-19 00:10:28.778 thread(2) tag(0) DETAIL request_destroy:2567 Starting.
2024-06-19 00:10:28.778 thread(2) tag(0) DETAIL request_destroy:2576 Done.
2024-06-19 00:10:28.778 thread(2) tag(0) INFO refcount_cleanup:268 Done.
2024-06-19 00:10:28.778 thread(2) tag(0) DETAIL tag_raise_event:201 PLCTAG_EVENT_CREATED raised with status PLCTAG_STATUS_OK.
2024-06-19 00:10:28.778 thread(2) tag(0) DETAIL tag_raise_event:218 PLCTAG_EVENT_READ_COMPLETED raised with status PLCTAG_STATUS_OK.
2024-06-19 00:10:28.778 thread(2) tag(0) DETAIL plc_tag_tickler_wake_impl:220 Starting. Called from tag_tickler_func:569.
2024-06-19 00:10:28.778 thread(2) tag(0) DETAIL plc_tag_tickler_wake_impl:233 Done. Called from tag_tickler_func:569.
2024-06-19 00:10:28.778 thread(2) tag(11) DETAIL plc_tag_generic_handle_event_callbacks:402 Tag creation complete with status PLCTAG_STATUS_OK.
2024-06-19 00:10:28.778 thread(1) tag(11) DETAIL tag_raise_event:201 PLCTAG_EVENT_CREATED raised with status PLCTAG_STATUS_OK.
2024-06-19 00:10:28.778 thread(1) tag(11) DETAIL tag_raise_event:207 PLCTAG_EVENT_CREATED skipped due to duplication.
2024-06-19 00:10:28.778 thread(1) tag(11) INFO plc_tag_create_ex:1069 tag set up elapsed time 41ms
2024-06-19 00:10:28.779 thread(1) tag(0) INFO plc_tag_create_ex:1075 Done.
2024-06-19 00:10:28.780 thread(2) tag(11) DETAIL tag_tickler_func:550 Tickling tag 11.
2024-06-19 00:10:28.780 thread(2) tag(11) DETAIL plc_tag_generic_tickler:281 Tickling tag 11.
2024-06-19 00:10:28.780 thread(2) tag(11) DETAIL plc_tag_generic_tickler:386 Done.
2024-06-19 00:10:28.780 thread(1) tag(11) INFO plc_tag_read:1607 Starting.
2024-06-19 00:10:28.780 thread(1) tag(11) DETAIL tag_raise_event:235 PLCTAG_EVENT_READ_STARTED raised with status PLCTAG_STATUS_OK.
2024-06-19 00:10:28.780 thread(1) tag(11) DETAIL tag_raise_event:239 Enabled PLCTAG_EVENT_READ_COMPLETE.
2024-06-19 00:10:28.780 thread(1) tag(11) DETAIL plc_tag_generic_handle_event_callbacks:410 Tag read started with status PLCTAG_STATUS_OK.
2024-06-19 00:10:28.781 thread(1) tag(0) INFO tag_read_start:312 Starting
2024-06-19 00:10:28.781 thread(1) tag(0) INFO build_read_request_connected:423 Starting.
2024-06-19 00:10:28.781 thread(1) tag(0) DETAIL session_create_request:2525 Starting.
2024-06-19 00:10:28.781 thread(1) tag(0) INFO rc_alloc_impl:111 Starting, called from session_create_request:2534
2024-06-19 00:10:28.781 thread(1) tag(0) INFO rc_alloc_impl:130 Done
2024-06-19 00:10:28.781 thread(1) tag(0) DETAIL rc_alloc_impl:135 Returning memory pointer 00E80B10
2024-06-19 00:10:28.781 thread(1) tag(0) DETAIL session_create_request:2548 Done.
2024-06-19 00:10:28.781 thread(1) tag(0) INFO session_add_request:966 Starting. sess=00EFF020, req=00E80B10
2024-06-19 00:10:28.782 thread(1) tag(0) DETAIL session_add_request_unsafe:931 Starting.
2024-06-19 00:10:28.782 thread(1) tag(0) DETAIL session_add_request_unsafe:950 Total requests in the queue: 1
2024-06-19 00:10:28.782 thread(1) tag(0) DETAIL session_add_request_unsafe:952 Done.
2024-06-19 00:10:28.782 thread(1) tag(0) INFO session_add_request:974 Done.
2024-06-19 00:10:28.782 thread(1) tag(0) INFO build_read_request_connected:508 Done
2024-06-19 00:10:28.782 thread(1) tag(0) INFO tag_read_start:341 Done.
2024-06-19 00:10:28.782 thread(3) tag(0) DETAIL session_handler:1168 in SESSION_IDLE state.
2024-06-19 00:10:28.782 thread(1) tag(0) DETAIL plc_tag_tickler_wake_impl:220 Starting. Called from plc_tag_read:1682.
2024-06-19 00:10:28.782 thread(3) tag(0) DETAIL session_handler:1174 There are 1 requests pending before cleanup and sending.
2024-06-19 00:10:28.783 thread(1) tag(0) DETAIL plc_tag_tickler_wake_impl:233 Done. Called from plc_tag_read:1682.
2024-06-19 00:10:28.783 thread(2) tag(11) DETAIL tag_tickler_func:550 Tickling tag 11.
2024-06-19 00:10:28.783 thread(2) tag(11) DETAIL plc_tag_generic_tickler:281 Tickling tag 11.
2024-06-19 00:10:28.783 thread(2) tag(11) DETAIL plc_tag_generic_tickler:386 Done.
2024-06-19 00:10:28.783 thread(3) tag(0) DETAIL get_payload_size:1679 Starting.
2024-06-19 00:10:28.784 thread(3) tag(0) DETAIL get_payload_size:1693 Done.
2024-06-19 00:10:28.783 thread(2) tag(0) DETAIL check_read_request_status:1154 Read not ready with status PLCTAG_STATUS_PENDING.
2024-06-19 00:10:28.784 thread(2) tag(0) DETAIL check_read_status_connected:1369 Read request status is not OK.
2024-06-19 00:10:28.784 thread(3) tag(0) INFO process_requests:1450 1 requests to process.
2024-06-19 00:10:28.784 thread(3) tag(0) INFO pack_requests:1714 Starting.
2024-06-19 00:10:28.784 thread(3) tag(11) INFO pack_requests:1724 Only one request, so done.
2024-06-19 00:10:28.784 thread(3) tag(0) INFO prepare_request:1816 Starting.
2024-06-19 00:10:28.784 thread(3) tag(0) DETAIL prepare_request:1845 cpf_targ_conn_id=7f0d47c1
2024-06-19 00:10:28.785 thread(3) tag(0) INFO prepare_request:1853 Preparing connected packet with connection ID 198a and sequence ID 2(2)
2024-06-19 00:10:28.786 thread(3) tag(0) INFO prepare_request:1860 Prepared packet of size 68
2024-06-19 00:10:28.786 thread(3) tag(0) INFO prepare_request:1861 00000 70 00 2c 00 70 01 8f 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.786 thread(3) tag(0) INFO prepare_request:1861 00016 00 00 00 00 00 00 00 00 00 00 00 00 01 00 02 00
2024-06-19 00:10:28.786 thread(3) tag(0) INFO prepare_request:1861 00032 a1 00 04 00 c1 47 0d 7f b1 00 18 00 02 00 4c 09
2024-06-19 00:10:28.786 thread(3) tag(0) INFO prepare_request:1861 00048 91 0f 53 65 6c 65 63 74 65 64 53 74 65 70 43 66
2024-06-19 00:10:28.787 thread(3) tag(0) INFO prepare_request:1861 00064 67 00 01 00
2024-06-19 00:10:28.787 thread(3) tag(0) INFO prepare_request:1863 Done.
2024-06-19 00:10:28.787 thread(3) tag(0) INFO send_eip_request:1876 Starting.
2024-06-19 00:10:28.787 thread(3) tag(0) INFO send_eip_request:1889 Sending packet of size 68
2024-06-19 00:10:28.787 thread(3) tag(0) INFO send_eip_request:1890 00000 70 00 2c 00 70 01 8f 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.787 thread(3) tag(0) INFO send_eip_request:1890 00016 00 00 00 00 00 00 00 00 00 00 00 00 01 00 02 00
2024-06-19 00:10:28.787 thread(3) tag(0) INFO send_eip_request:1890 00032 a1 00 04 00 c1 47 0d 7f b1 00 18 00 02 00 4c 09
2024-06-19 00:10:28.787 thread(3) tag(0) INFO send_eip_request:1890 00048 91 0f 53 65 6c 65 63 74 65 64 53 74 65 70 43 66
2024-06-19 00:10:28.788 thread(3) tag(0) INFO send_eip_request:1890 00064 67 00 01 00
2024-06-19 00:10:28.788 thread(3) tag(0) DETAIL socket_write:1945 Starting.
2024-06-19 00:10:28.788 thread(3) tag(0) DETAIL socket_write:2072 Done: result = 68.
2024-06-19 00:10:28.788 thread(3) tag(0) INFO send_eip_request:1932 Done.
2024-06-19 00:10:28.788 thread(3) tag(0) INFO recv_eip_response:1952 Starting.
2024-06-19 00:10:28.788 thread(3) tag(0) DETAIL socket_read:1807 Starting.
2024-06-19 00:10:28.788 thread(3) tag(0) DETAIL socket_read:1836 Immediate read attempt did not succeed, now wait for select().
2024-06-19 00:10:28.794 thread(3) tag(0) DETAIL socket_read:1864 Socket can read data.
2024-06-19 00:10:28.794 thread(3) tag(0) DETAIL socket_read:1934 Done: result = 24.
2024-06-19 00:10:28.794 thread(3) tag(0) DETAIL socket_read:1807 Starting.
2024-06-19 00:10:28.795 thread(3) tag(0) DETAIL socket_read:1934 Done: result = 430.
2024-06-19 00:10:28.796 thread(3) tag(0) INFO recv_eip_response:2023 request received all needed data (454 bytes of 454).
2024-06-19 00:10:28.796 thread(3) tag(0) INFO recv_eip_response:2025 00000 70 00 ae 01 70 01 8f 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.796 thread(3) tag(0) INFO recv_eip_response:2025 00016 00 00 00 00 00 00 00 00 00 00 00 00 00 00 02 00
2024-06-19 00:10:28.796 thread(3) tag(0) INFO recv_eip_response:2025 00032 a1 00 04 00 8a 19 00 00 b1 00 9a 01 02 00 cc 00
2024-06-19 00:10:28.796 thread(3) tag(0) INFO recv_eip_response:2025 00048 00 00 a0 02 72 a2 00 01 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.796 thread(3) tag(0) INFO recv_eip_response:2025 00064 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.797 thread(3) tag(0) INFO recv_eip_response:2025 00080 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.797 thread(3) tag(0) INFO recv_eip_response:2025 00096 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.797 thread(3) tag(0) INFO recv_eip_response:2025 00112 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.797 thread(3) tag(0) INFO recv_eip_response:2025 00128 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.797 thread(3) tag(0) INFO recv_eip_response:2025 00144 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.797 thread(3) tag(0) INFO recv_eip_response:2025 00160 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.797 thread(3) tag(0) INFO recv_eip_response:2025 00176 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.798 thread(3) tag(0) INFO recv_eip_response:2025 00192 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.798 thread(3) tag(0) INFO recv_eip_response:2025 00208 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.798 thread(3) tag(0) INFO recv_eip_response:2025 00224 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.798 thread(3) tag(0) INFO recv_eip_response:2025 00240 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.798 thread(3) tag(0) INFO recv_eip_response:2025 00256 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.798 thread(3) tag(0) INFO recv_eip_response:2025 00272 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.798 thread(3) tag(0) INFO recv_eip_response:2025 00288 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.798 thread(3) tag(0) INFO recv_eip_response:2025 00304 00 00 00 00 00 00 00 00 00 00 04 00 00 00 c4 09
2024-06-19 00:10:28.799 thread(3) tag(0) INFO recv_eip_response:2025 00320 00 00 00 00 00 00 88 13 00 00 00 00 00 00 01 00
2024-06-19 00:10:28.799 thread(3) tag(0) INFO recv_eip_response:2025 00336 01 00 01 00 01 00 00 00 00 00 00 40 8f 40 00 00
2024-06-19 00:10:28.799 thread(3) tag(0) INFO recv_eip_response:2025 00352 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.799 thread(3) tag(0) INFO recv_eip_response:2025 00368 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.799 thread(3) tag(0) INFO recv_eip_response:2025 00384 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.799 thread(3) tag(0) INFO recv_eip_response:2025 00400 00 00 00 58 9b 40 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.799 thread(3) tag(0) INFO recv_eip_response:2025 00416 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.800 thread(3) tag(0) INFO recv_eip_response:2025 00432 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.800 thread(3) tag(0) INFO recv_eip_response:2025 00448 00 00 00 00 00 00
2024-06-19 00:10:28.800 thread(3) tag(0) INFO recv_eip_response:2032 Done.
2024-06-19 00:10:28.800 thread(3) tag(11) INFO unpack_response:1558 Starting.
2024-06-19 00:10:28.800 thread(3) tag(11) INFO unpack_response:1567 Got single response packet.  Copying 454 bytes unchanged.
2024-06-19 00:10:28.800 thread(3) tag(11) INFO unpack_response:1656 Unpacked packet:
2024-06-19 00:10:28.800 thread(3) tag(11) INFO unpack_response:1657 00000 70 00 ae 01 70 01 8f 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.800 thread(3) tag(11) INFO unpack_response:1657 00016 00 00 00 00 00 00 00 00 00 00 00 00 00 00 02 00
2024-06-19 00:10:28.801 thread(3) tag(11) INFO unpack_response:1657 00032 a1 00 04 00 8a 19 00 00 b1 00 9a 01 02 00 cc 00
2024-06-19 00:10:28.801 thread(3) tag(11) INFO unpack_response:1657 00048 00 00 a0 02 72 a2 00 01 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.801 thread(3) tag(11) INFO unpack_response:1657 00064 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.801 thread(3) tag(11) INFO unpack_response:1657 00080 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.801 thread(3) tag(11) INFO unpack_response:1657 00096 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.802 thread(3) tag(11) INFO unpack_response:1657 00112 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.802 thread(3) tag(11) INFO unpack_response:1657 00128 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.802 thread(3) tag(11) INFO unpack_response:1657 00144 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.802 thread(3) tag(11) INFO unpack_response:1657 00160 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.802 thread(3) tag(11) INFO unpack_response:1657 00176 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.802 thread(3) tag(11) INFO unpack_response:1657 00192 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.802 thread(3) tag(11) INFO unpack_response:1657 00208 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.803 thread(3) tag(11) INFO unpack_response:1657 00224 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.803 thread(3) tag(11) INFO unpack_response:1657 00240 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.803 thread(3) tag(11) INFO unpack_response:1657 00256 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.803 thread(3) tag(11) INFO unpack_response:1657 00272 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.803 thread(3) tag(11) INFO unpack_response:1657 00288 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.803 thread(3) tag(11) INFO unpack_response:1657 00304 00 00 00 00 00 00 00 00 00 00 04 00 00 00 c4 09
2024-06-19 00:10:28.803 thread(3) tag(11) INFO unpack_response:1657 00320 00 00 00 00 00 00 88 13 00 00 00 00 00 00 01 00
2024-06-19 00:10:28.804 thread(3) tag(11) INFO unpack_response:1657 00336 01 00 01 00 01 00 00 00 00 00 00 40 8f 40 00 00
2024-06-19 00:10:28.804 thread(3) tag(11) INFO unpack_response:1657 00352 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.804 thread(3) tag(11) INFO unpack_response:1657 00368 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.804 thread(3) tag(11) INFO unpack_response:1657 00384 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.804 thread(3) tag(11) INFO unpack_response:1657 00400 00 00 00 58 9b 40 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.804 thread(3) tag(11) INFO unpack_response:1657 00416 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.804 thread(3) tag(11) INFO unpack_response:1657 00432 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2024-06-19 00:10:28.804 thread(3) tag(11) INFO unpack_response:1657 00448 00 00 00 00 00 00
2024-06-19 00:10:28.805 thread(3) tag(11) DETAIL unpack_response:1666 Done.
2024-06-19 00:10:28.806 thread(3) tag(11) DETAIL plc_tag_tickler_wake_impl:220 Starting. Called from process_requests:1538.
2024-06-19 00:10:28.806 thread(3) tag(11) DETAIL plc_tag_tickler_wake_impl:233 Done. Called from process_requests:1538.
2024-06-19 00:10:28.806 thread(2) tag(11) DETAIL tag_tickler_func:550 Tickling tag 11.
2024-06-19 00:10:28.806 thread(2) tag(11) DETAIL plc_tag_generic_tickler:281 Tickling tag 11.
2024-06-19 00:10:28.806 thread(2) tag(11) DETAIL plc_tag_generic_tickler:386 Done.
2024-06-19 00:10:28.807 thread(2) tag(0) INFO check_read_status_connected:1487 Got 400 bytes of data
2024-06-19 00:10:28.807 thread(2) tag(0) DETAIL rc_dec_impl:242 Calling cleanup functions due to call at check_read_status_connected:1520 for 00E80B10.
2024-06-19 00:10:28.807 thread(2) tag(0) INFO refcount_cleanup:256 Starting
2024-06-19 00:10:28.807 thread(2) tag(0) DETAIL request_destroy:2567 Starting.
2024-06-19 00:10:28.807 thread(2) tag(0) DETAIL request_destroy:2576 Done.
2024-06-19 00:10:28.807 thread(2) tag(0) INFO refcount_cleanup:268 Done.
2024-06-19 00:10:28.807 thread(2) tag(0) DETAIL tag_raise_event:218 PLCTAG_EVENT_READ_COMPLETED raised with status PLCTAG_STATUS_OK.
2024-06-19 00:10:28.807 thread(2) tag(0) DETAIL tag_raise_event:230 Disabled PLCTAG_EVENT_READ_COMPLETE.
2024-06-19 00:10:28.808 thread(2) tag(0) DETAIL plc_tag_tickler_wake_impl:220 Starting. Called from tag_tickler_func:569.
2024-06-19 00:10:28.808 thread(2) tag(0) DETAIL plc_tag_tickler_wake_impl:233 Done. Called from tag_tickler_func:569.
2024-06-19 00:10:28.808 thread(2) tag(11) DETAIL plc_tag_generic_handle_event_callbacks:434 Tag read completed with status PLCTAG_STATUS_OK.
2024-06-19 00:10:28.808 thread(1) tag(11) DETAIL tag_raise_event:218 PLCTAG_EVENT_READ_COMPLETED raised with status PLCTAG_STATUS_OK.
2024-06-19 00:10:28.808 thread(1) tag(11) INFO plc_tag_read:1724 elapsed time 26ms
2024-06-19 00:10:28.808 thread(2) tag(11) DETAIL tag_tickler_func:550 Tickling tag 11.
2024-06-19 00:10:28.808 thread(1) tag(0) INFO plc_tag_read:1737 Done
2024-06-19 00:10:28.809 thread(2) tag(11) DETAIL plc_tag_generic_tickler:281 Tickling tag 11.
2024-06-19 00:10:28.809 thread(2) tag(11) DETAIL plc_tag_generic_tickler:386 Done.
400
00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 04 00 00 00 C4 09 00 00 00 00 00 00 88 13 00 00 00 00 00 00 01 00 01 00 01 00 01 00 00 00 00 00 00 40 8F 40 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 58 9B 40 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

kyle-github commented 3 months ago

I wonder if we are chasing a red herring. What if that byte is 1 because there is garbage in the data in memory? It is effectively padding.

MountainKing91 commented 3 months ago

The non-evidentiated bytes are for alignment, correct?

MountainKing91 commented 3 months ago

I wonder if we are chasing a red herring. What if that byte is 1 because there is garbage in the data in memory? It is effectively padding.

How can I make sure of this? I tried power cycling the plc, it doesn't change anything.

Not sure if this helps:

kyle-github commented 3 months ago

I think you were close.

So there can be a count between the data type and the data. But it is the number of elements so can only be one here.

But it should be 01 00 not 00 01.

I am baffled.

kyle-github commented 3 months ago

Back to your question about alignment. I think there should be some alignment padding bytes at the end of the string data. I think it is the last two bytes in the area you marked as part of the string.

MountainKing91 commented 3 months ago

So, in this image I have marked with different colors all the different areas in the buffer

The first two bytes I don't understand, the first definitely changes when toggling "Included", but the second is always 01 no matter what. We would expect them to be fully dedicated to Included, 00 00 if FALSE and 01 00 if TRUE
The next 258 bytes seem dedicated to the STRING[256] "Description", but why 258? Padding? When I write something in Description, the 1st character goes into the 3rd byte (the 1st of the dark green range)... example: "abcdefg" --> from the 3rd byte going forward I have 61 62 63 64 65 66 67 00 00 00 ...
The BOOL values in the middle (ligth and dark grey) they all occupies 2 bytes each, as expected at this point for BOOL inside a UDT
Everything else looks fine, apart from bytes 340-343 and bytes 396-399, which are "blank" but I assume it is the alignement of the UDT AxisConfiguration, following the rule specified in the w506 manual

kyle-github commented 3 months ago

I am tracking known Omron problems in issue 469 in the core DLL project. If I have missed any, please let me know.

timyhac commented 3 months ago

@MountainKing91 - have you tried writing a different value to that second byte to the PLC? Could be a way to test the theory that one of the bytes is padding garbage

MountainKing91 commented 3 months ago

@timyhac I have tried to read and write the entire UDT, with mixed results. Everything depends on how I decode and encode the string, which is a known issue at this point.

Now that you asked I tried with this:

Clear the struct from the PLC

Read

myTag.Read();
string hexString = BitConverter.ToString(buffer);
Console.WriteLine(hexString.Replace('-', ' '));

00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

Write a clean buffer with libplctag

byte[] newBuffer = new byte[400];
hexString = BitConverter.ToString(newBuffer);
Console.WriteLine(hexString.Replace('-', ' '));
myTag.SetBuffer(newBuffer);
myTag.Write();

Read again

myTag.Read();
string hexString = BitConverter.ToString(buffer);
Console.WriteLine(hexString.Replace('-', ' '));

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

Now the suspect byte is actually 00 ...

I set Included := TRUE plc side and read again

01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

I set Included := FALSE, Description := 'abcdefg' plc side and read again

00 00 61 62 63 64 65 66 67 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

I set Included := TRUE, Description := 'abcdefg' plc side and read again

01 00 61 62 63 64 65 66 67 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

...

NOW IT'S WORKING AS EXPECTED =/

So it's me creating a mess with custom mappers I guess

timyhac commented 3 months ago

Nice - to me that is consistent with Kyle's red herring theory that byte 2 is padding and the value is garbage leftover from whatever used to occupy that memory on the PLC - or as you suggest, accidentally was set when playing around with the mappers :D

MountainKing91 commented 3 months ago

This also checks with the manual: STRING buffer is prefixed with 2 bytes containing the byte count only for standalone STRING[...] tags. When the string is part of an array or UTD these 2 bytes must not be there.

@timyhac basically in the string mapper I have to detect if I'm decoding/encoding a single tag or if I am dealing with udt/array

timyhac commented 3 months ago

If you're able to do it based on the Tag name then we could solve the problem by exposing Name to the mappers - this should be reasonably straightforward but I'll need to do this. This investigation you guys have done is pretty strong evidence its necessary.

The other possibility is to use the new API _tag.GetByteArrayAttribute("raw_tag_type_bytes"); - I think this would work for some Rockwell devices but I'm not sure about your Omron model. Ah - no that won't work either, at least it won't be very efficient the way the Mapper system is currently designed because you'd probably wat to store the tag type after the first read and then just re-use it. Not sure if that would work. There are some shortcomings with the Mapper system and I think this is another example where it doesn't work that well.

MountainKing91 commented 3 months ago

If you're able to do it based on the Tag name then we could solve the problem by exposing Name to the mappers

I am trying to do it in the mapper itself, checking if the tag buffer size is longer than the element size (that would mean I am decoding/encoding something which is part of a bigger buffer, array or udt).

The problem is, we have seen that it's hard to discern all the cases. Don't even get me started with array of strings ;-)

MountainKing91 commented 3 months ago

@timyhac back to bool arrays, this mapper is working, it is only for bools array tags defined with no index in the name (bits are packed),

public class OmronNonIndexedBoolArrayMapper : PlcMapperBase<bool[]>, IPlcMapper<bool[]>
{
    public override int? ElementSize => 1;

    public override bool[] Decode(Tag tag, int offset)
    {
        byte[] buffer = tag.GetBuffer();

        bool[] rc = new bool[buffer.Length * 8]; // bits are packed --> I have 8 bits for each byte

        BitArray bitArray = new BitArray(buffer);

        for (int i = 0; i < rc.Length; i++)
        {
            rc[i] = bitArray.Get(offset + i);
        }

        return rc;
    }

    public override void Encode(Tag tag, int offset, bool[] value)
    {
        byte[] buffer = tag.GetBuffer();

        BitArray bitArray = new BitArray(value);
        int size = RoundToNextMultiple(value.Length, 8);
        byte[] newBuffer = new byte[size];
        bitArray.CopyTo(newBuffer, 0);

        Array.Copy(newBuffer, 0, buffer, offset, newBuffer.Length);

        tag.SetBuffer(buffer);
    }

    private int RoundToNextMultiple(int value, int multiple)
    {
        int remainder = value % multiple;
        int result = value - remainder;
        if (remainder >= 1) result += multiple;
        return result;
    }
}

Is this approach viable? One good thing about mappers is that they automatically handle arrays, here I don't have that though

timyhac commented 3 months ago

Its great that you've got it working!

I'm not sure what the goals of your overall solution are so its difficult to say whether its viable.

From quickly scanning the code the only thing I'd mention is that you could store the buffer in the mapper and reuse it and instead use the overload which takes an existing buffer: GetBuffer(byte[] buffer) - could be useful if the buffer is very large and you're reading/writing frequently to reduce GC pressure.

MountainKing91 commented 3 months ago

Thanks for the advice, I'll look into it. I'm constantly polling the tag values so it's a lot of reads for sure.

Just to give a little context, right now my main focus is on developing a WPF app to control/supervise and program a test rig. The PLC is an Omron NX. I decided to use WPF in order to go around certain shortcomings of my usual HMI platform. Libplctag seemed the best communication library out there, I already used v1.2.0 in a previous project and I liked it, this time it's a bit more complex (some big utd arrays and nested udts), especially since I am not a C# guru. Still got quite a bunch of stuff to figure out, but I think it's worth dedicating the time. And I'm learning a lot!

timyhac commented 3 months ago

In terms of actions from this github issue, the remaining improvement opportunities are:

https://github.com/libplctag/libplctag/issues/468 and/or
Pass Name through to IPlcMapper

MountainKing91 commented 3 months ago

@timyhac I did not quit grasp what you have in mind when you say

Pass Name through to IPlcMapper

timyhac commented 3 months ago

If the mapper has the tag name then you could parse it and determine which tag structure decoding routines to use. This would only be useful if you wanted to have a single BoolPlcMapper that can handle everything BOOL: Atomic, Arrays, Different make/models of PLC etc.

Come to think of it, the Decode and Encode methods already have access to the underlying Tag object so could get the name from that.

kyle-github commented 3 months ago

I have been thinking about this. Suppose we have an array of UDTs. Then you could have a tag path like myTag[14]. That will bring back the whole UDT. In this case we should see a 4-byte type A0 02 wx yz.

If I have a UDT of arrays it is a little easier myUDTTag.arrayA. Then we should see the data type for an element of that array. But that could be BOOL.

Can you have an array of arrays?

Lots of corner cases here.

MountainKing91 commented 3 months ago

This would only be useful if you wanted to have a single BoolPlcMapper that can handle everything BOOL: Atomic, Arrays, Different make/models of PLC etc.

This would be great - at this moment I have various custom mappers even for "standard" datatypes, created to go around stuff not yet implemented in the library or that is not currently working for Omron plcs (for example DATE_AND_TIME, UNIONs). This if fine but not optimal. For DATE_AND_TIME I took advantage of https://github.com/libplctag/libplctag/issues/464 but it might not always be that easy.

Come to think of it, the Decode and Encode methods already have access to the underlying Tag object so could get the name from that

True

MountainKing91 commented 3 months ago

Can you have an array of arrays?

I think you can.

kyle-github commented 3 months ago

It is relatively straightforward to get at least some type information about a tag via the CIP calls I have been using in the test program I sent. Once we get that working, it could be folded into the library. The Omron way of doing this is much less efficient but also much more lightweight than Rockwell's way of doing things.

As to mappers, I would assume that there could be one set of simple mappers for standard CIP objects. But structured data like arrays and UDTs are going to have challenges that differ per manufacturer and even per PLC model (i.e. the Omron NJ/NX series has different internal alignment rules than the CJ series).

There are other differences. Rockwell has very clear information on the layout of UDTs. Each field has an offset within the UDT. So things like alignment just never are a concern. So far, I have not seen how to get that kind of offset data from Omron so I suspect that you have to figure it out yourself from their alignment rules.

timyhac commented 3 months ago

Is there anything else that needs to be done in libplctag here? As far as I can tell this is all working.

MountainKing91 commented 3 months ago

I think yes.

For Omron BOOL tags we know that the BoolPlcMapper is not working because of https://github.com/libplctag/libplctag.NET/issues/381#issuecomment-2175749750 and we also know

different packing if the tag is standalone, in udt or array and how it is requested
what to do to go around that, for now (custom mapper)

Also for STRING[...] there are issues due to differences from Rockwell and Omron, so the standard mapper is not working. When writing a custom string mapper we have to remember that in case of standalone string tags the actual value bytes are prefixed with a 2 bytes characters count, if the string tag is inside a udt then there is no prefix!

I think this issue can be closed.

timyhac commented 3 months ago

Wonderful!

hamduc7 commented 3 months ago

Hi @MountainKing91

I see this task is closed. I tried to use your OmronNonIndexedBoolArrayMapper but it has error. My device has an array tag DEAERATOR_LEVEL_ANIMATION_SEQUENCE_REGISTER[63] BIT

I also have a struct tag, but I don't see a code to read this tag.

Could you pls tell me how to read values in this tag?

Thank you very much.

MountainKing91 commented 3 months ago

Hi @hamduc7 ,

My device has an array tag DEAERATOR_LEVEL_ANIMATION_SEQUENCE_REGISTER[63] BIT

Is this an ARRAY OF [0..63] BOOL? Can I see your code? Bools array are tricky, my mapper worked fine for ARRAY OF [0..63] BOOL but it throws an exception for array sizes non multiple of 16 IIRC.

I also have a struct tag, but I don't see a code to read this tag.

You don't see it because there is none :) For custom UDTs you have to define a custom mapper.

Look the above posts about how to decode/encode bool tags depending on where they are used (standalone, inside an array, inside a struct, ...). I also suggest first thing first to try registering a complex tag without mappers and anly using Tag, and take a look at the buffer. @timyhac suggested me to to this and it has been a great advice.

hamduc7 commented 3 months ago

Thank @MountainKing91 Let me check some hints in this thread.

libplctag / libplctag.NET

Read array tags for Omron PLC broken with v1.4.0 #381