Telegrams are not shown

[volkerdeHaas]

I've given up trying with my NanoCUL and Raspi because of always loosing ttyusb0 after several seconds. But I was able to see the telegrams from my Kamstrup heat counter (ttyusb0:cul:t1). So I got a IM871a USB Stick to finally overcome my problems. The Stick does receive the telegrams from the Kamstrup device on Wireless M-Bus Studio (t1 or t2 mode) run on my windows pc.
But when I connect the stick to my raspi I can't see any telegrams. When entering

wmbusmeters --debug --logtelegrams --verbose /dev/ttyUSB0:im871a:t1

I do get the following output:

(drivers) added builtin driver elster
(drivers) added builtin driver iperl
(drivers) added builtin driver kampress
(drivers) added builtin driver werhlemodwm
(wmbusmeters) version: 1.16.1-23-gefcc41d
(config) using device: /dev/ttyUSB0:im871a:t1
(config) number of meters: 0
(lookup) with file/hex "/dev/ttyUSB0" im871a
(serial) check if /dev/ttyUSB0 can be accessed
(serial) tty /dev/ttyUSB0 can be accessed
(serial) EVENT thread interrupted
(serial) before config: /dev/ttyUSB0 speed(B57600) input() output() control(CLOCAL|CREAD|CSIZE) local() special_chars() modem(DTR|RTS)
(serial) after config: /dev/ttyUSB0 speed(B57600) input() output() control(CLOCAL|CREAD|CSIZE) local() special_chars() modem(DTR|RTS)
(serialtty) opened /dev/ttyUSB0 fd 3 (detect im871a)
(serial) received binary ""
(serial /dev/ttyUSB0) sent "A5010F00"
(serial) EVENT thread interrupted
(serial) received binary "A581100833001601E33D000006BB"
(im871a) checkIM871AFrame "A581100833001601E33D000006BB"
(im871a) has_timestamp=0 has_rssi=0 has_crc16=1
(im871a) endpoint 1
(im871a) msgid 16
(im871a) got crc16 bb06 expected bb06
(im871a) received full frame
(device info bytes) "33001601E33D0000"
(im871a/im170a) info: type=im871a mode=collector firmware=16 hci=01 uid=00003de3
(serial /dev/ttyUSB0) sent "A5010500"
(serial) EVENT thread interrupted
(serial) received binary "A5810616FF000300B32576461000010000FF0702320101000600391E"
(im871a) checkIM871AFrame "A5810616FF000300B32576461000010000FF0702320101000600391E"
(im871a) has_timestamp=0 has_rssi=0 has_crc16=1
(im871a) endpoint 1
(im871a) msgid 6
(im871a) got crc16 1e39 expected 1e39
(im871a) received full frame
(serialtty) closed /dev/ttyUSB0 (detect im871a)
(device config bytes) "FF000300B32576461000010000FF0702320101000600"
(serial) EVENT thread interrupted
(im871a/im170a) config: other link_mode=t1 id=00104676 media=00 version=01 c_field=00 auto_rssi=01
(im871a/im170a) are you there? yes 00104676 im871a firmware: 16
(main) opening /dev/ttyUSB0:im871a:t1
Started config im871a[00104676] on /dev/ttyUSB0 listening on t1
(im871a) on /dev/ttyUSB0
(serial) EVENT thread interrupted
(serial) before config: /dev/ttyUSB0 speed(B57600) input() output() control(CLOCAL|CREAD|CSIZE) local() special_chars() modem(DTR|RTS)
(serial) after config: /dev/ttyUSB0 speed(B57600) input() output() control(CLOCAL|CREAD|CSIZE) local() special_chars() modem(DTR|RTS)
(serialtty) opened /dev/ttyUSB0 fd 3 (im871a)
(im871a) get config
(serial /dev/ttyUSB0) sent "A5010500"
(serial) EVENT thread interrupted
(serial) received binary "A5810616FF000300B32576461000010000FF0702320101000600391E"
(im871a) checkIM871AFrame "A5810616FF000300B32576461000010000FF0702320101000600391E"
(im871a) has_timestamp=0 has_rssi=0 has_crc16=1
(im871a) endpoint 1
(im871a) msgid 6
(im871a) got crc16 1e39 expected 1e39
(im871a) received full frame
(im871a) get config completed
(im871a) got device id 00104676
(main) regular reset of im871a on /dev/ttyUSB0 will happen every 82800 seconds
(im871a) get device info
(serial /dev/ttyUSB0) sent "A5010F00"
(serial) EVENT thread interrupted
(serial) received binary "A581100833001601E33D000006BB"
(im871a) checkIM871AFrame "A581100833001601E33D000006BB"
(im871a) has_timestamp=0 has_rssi=0 has_crc16=1
(im871a) endpoint 1
(im871a) msgid 16
(im871a) got crc16 bb06 expected bb06
(im871a) received full frame
(im871a) device info completed
(im871a) device info: type=im871a mode=collector firmware=16 hci=01 uid=00003de3
(im871a) set config to set link mode 03
(serial /dev/ttyUSB0) sent "A5010306000203300100"
(serial) EVENT thread interrupted
(serial) received binary "A58104009CF7"
(im871a) checkIM871AFrame "A58104009CF7"
(im871a) has_timestamp=0 has_rssi=0 has_crc16=1
(im871a) endpoint 1
(im871a) msgid 4
(im871a) got crc16 f79c expected f79c
(im871a) received full frame
(im871a) set config completed
(wmbus) no alarm (expected activity) for im871a
(serial) registered regular callback HOT_PLUG_DETECTOR(0) every 2 seconds
No meters configured. Printing id:s of all telegrams heard!
(serial) waiting for stop

I would be happy for any help. Is there anything I missed doing in order to receive messages with my IM871a
like I did with the NanoCul before ttyusb0 closes? For reference, here is the command and output from NanoCUL

i@raspberrypi:~ $ wmbusmeters --debug --logtelegrams --verbose /dev/ttyUSB0:cul:t1
(drivers) added builtin driver elster
(drivers) added builtin driver iperl
(drivers) added builtin driver kampress
(drivers) added builtin driver werhlemodwm
(wmbusmeters) version: 1.16.1-23-gefcc41d
(config) using device: /dev/ttyUSB0:cul:t1
(config) number of meters: 0
(lookup) with file/hex "/dev/ttyUSB0" cul
(serial) check if /dev/ttyUSB0 can be accessed
(serial) tty /dev/ttyUSB0 can be accessed
(serial) EVENT thread interrupted
(serial) before config: /dev/ttyUSB0 speed(B9600) input(ICRNL|IXON) output(ONLCR|OPOST) control(CLOCAL|CREAD|CSIZE|HUPCL) local(ECHO|ECHOCTL|ECHOE|ECHOK|ECHOKE|ICANON|IEXTEN|ISIG) special_chars(3,28,127,21,4,1,17,19,26,18,15,23,22) modem(DTR|RTS)
(serial) after config: /dev/ttyUSB0 speed(B38400) input() output() control(CLOCAL|CREAD|CSIZE) local() special_chars() modem(DTR|RTS)
(serialtty) opened /dev/ttyUSB0 fd 3 (detect cul)
(serial /dev/ttyUSB0) sent "560D0A"
(serial) EVENT thread interrupted
(serial) received binary ""
(cul) probe response ""
(serial /dev/ttyUSB0) sent "560D0A"
(serial) EVENT thread interrupted
(serial) received binary ""
(cul) probe response ""
(serial /dev/ttyUSB0) sent "560D0A"
(serial) EVENT thread interrupted
(serial) received binary "5620312E3637206E616E6F43554C3836385F723536380D0A"
(cul) probe response "V 1.67 nanoCUL868_r568<0D><0A>"
(serialtty) closed /dev/ttyUSB0 (detect cul)
(cul) are you there? yes
(serial) EVENT thread interrupted
(main) opening /dev/ttyUSB0:cul:t1
Started config cul on /dev/ttyUSB0 listening on t1
(cul) on /dev/ttyUSB0
(serial) EVENT thread interrupted
(serial) before config: /dev/ttyUSB0 speed(B38400) input() output() control(CLOCAL|CREAD|CSIZE) local() special_chars() modem(DTR|RTS)
(serial) after config: /dev/ttyUSB0 speed(B38400) input() output() control(CLOCAL|CREAD|CSIZE) local() special_chars() modem(DTR|RTS)
(serialtty) opened /dev/ttyUSB0 fd 3 (cul)
(main) regular reset of cul on /dev/ttyUSB0 will happen every 82800 seconds
(cul) set link mode t
(serial /dev/ttyUSB0) sent "6272740D0A"
(serial) EVENT thread interrupted
(serial) received binary "544D4F44450D0A"
(cul) checkCULFrame "TMODE<0D><0A>"
(cul) no leading 'b' so it is text and no frame
(cul) received "TMODE"(serial /dev/ttyUSB0) sent "5832310D0A"
(wmbus) no alarm (expected activity) for cul
(serial) EVENT thread interrupted
(serial) registered regular callback HOT_PLUG_DETECTOR(0) every 2 seconds
No meters configured. Printing id:s of all telegrams heard!
(serial) waiting for stop
(serial) received binary "6235453434324432433133373139333832343030"
(cul) checkCULFrame "b5E442D2C13719382400"
(cul) no eol found yet, partial frame
(serial) received binary "34384537463741444431303530323546394441384334343042303033323741434537353145384139314531453041324244343133373634363330"
(cul) checkCULFrame "b5E442D2C1371938240048E7F7ADD105025F9DA8C440B00327ACE751E8A91E1E0A2BD413764630"
(cul) no eol found yet, partial frame
(serial) received binary "33334346393730313831364238383441463845414237433236303331433330313836394238314339393043394530463236313933303343333230433236464636353641383933463733453543363243324544374235353446394146464146413639353238323342423533334546363834343135414542414137"
(cul) checkCULFrame "b5E442D2C1371938240048E7F7ADD105025F9DA8C440B00327ACE751E8A91E1E0A2BD41376463033CF9701816B884AF8EAB7C26031C301869B81C990C9E0F2619303C320C26FF656A893F73E5C62C2ED7B554F9AFFAFA6952823BB533EF684415AEBAA7"
(cul) no eol found yet, partial frame
(serial) received binary "4245323834333438444143313141443244314642383036390D0A"
(cul) checkCULFrame "b5E442D2C1371938240048E7F7ADD105025F9DA8C440B00327ACE751E8A91E1E0A2BD41376463033CF9701816B884AF8EAB7C26031C301869B81C990C9E0F2619303C320C26FF656A893F73E5C62C2ED7B554F9AFFAFA6952823BB533EF684415AEBAA7BE284348DAC11AD2D1FB8069<0D><0A>"
(cul) checkCULFrame RSSI_RAW=105
(cul) checkCULFrame LQI=64
(wmbus) trimming frame A "5E442D2C1371938240048E7F7ADD105025F9DA8C440B00327ACE751E8A91E1E0A2BD41376463033CF9701816B884AF8EAB7C26031C301869B81C990C9E0F2619303C320C26FF656A893F73E5C62C2ED7B554F9AFFAFA6952823BB533EF684415AEBAA7BE284348DAC11AD2D1FB"
(wmbus) ff a dll crc 0-9 8e7f ok
(wmbus) ff a dll crc mid 12-27 8a91 ok
(wmbus) ff a dll crc mid 30-45 af8e ok
(wmbus) ff a dll crc mid 48-63 303c ok
(wmbus) ff a dll crc mid 66-81 f9af ok
(wmbus) ff a dll crc mid 84-99 2843 ok
(wmbus) ff a dll crc final 102-106 d1fb ok
(wmbus) trimming frame A "5E442D2C1371938240048E7F7ADD105025F9DA8C440B00327ACE751E8A91E1E0A2BD41376463033CF9701816B884AF8EAB7C26031C301869B81C990C9E0F2619303C320C26FF656A893F73E5C62C2ED7B554F9AFFAFA6952823BB533EF684415AEBAA7BE284348DAC11AD2D1FB"
(wmbus) trimmed 14 dll crc bytes from frame a and ignored 0 suffix bytes.
(wmbus) trimmed frame A "5E442D2C1371938240047ADD105025F9DA8C440B00327ACE751EE1E0A2BD41376463033CF9701816B884AB7C26031C301869B81C990C9E0F2619320C26FF656A893F73E5C62C2ED7B554FAFA6952823BB533EF684415AEBAA7BE48DAC11AD2"
(cul) received full T1 frame
(meter) no meter handled checking 0 templates.
(wmbus) parseDLL @0 95
(wmbus) parseELL @10 85
(wmbus) parseNWL @10 85
(wmbus) parseAFL @10 85
(wmbus) parseTPL @10 85
(wmbus) parseDLL @0 95
(telegram) DLL L=5e C=44 (from meter SND_NR) M=2c2d (KAM) A=82937113 VER=40 TYPE=04 (Heat meter) (driver kamheat) DEV=cul RSSI=-22
(wmbus) parseELL @10 85
(wmbus) parseNWL @10 85
(wmbus) parseAFL @10 85
(wmbus) parseTPL @10 85
(TPL) num encrypted blocks 5 (80 bytes and remaining unencrypted 0 bytes)
(telegram) TPL CI=7a ACC=dd STS=10 CFG=2550 (synchronous AES_CBC_IV nb=5 cntn=0 ra=0 hc=0)
Received telegram from: 82937113
manufacturer: (KAM) Kamstrup Energi (0x2c2d)
type: Heat meter (0x04) encrypted
ver: 0x40
device: cul
rssi: -22 dBm
driver: kamheat
(wmbus) 000 : 5e length (94 bytes)
(wmbus) 001 : 44 dll-c (from meter SND_NR)
(wmbus) 002 : 2d2c dll-mfct (KAM)
(wmbus) 004 : 13719382 dll-id (82937113)
(wmbus) 008 : 40 dll-version
(wmbus) 009 : 04 dll-type (Heat meter)
(wmbus) 010 : 7a tpl-ci-field (EN 13757-3 Application Layer (short tplh))
(wmbus) 011 : dd tpl-acc-field
(wmbus) 012 : 10 tpl-sts-field (TEMPORARY_ERROR)
(wmbus) 013 : 5025 tpl-cfg 2550 (synchronous AES_CBC_IV nb=5 cntn=0 ra=0 hc=0 )
(wmbus) 015 CE: F9DA8C440B00327ACE751EE1E0A2BD41376463033CF9701816B884AB7C26031C301869B81C990C9E0F2619320C26FF656A893F73E5C62C2ED7B554FAFA6952823BB533EF684415AEBAA7BE48DAC11AD2 encrypted
telegram=|_5E442D2C1371938240047ADD105025F9DA8C440B00327ACE751EE1E0A2BD41376463033CF9701816B884AB7C26031C301869B81C990C9E0F2619320C26FF656A893F73E5C62C2ED7B554FAFA6952823BB533EF684415AEBAA7BE48DAC11AD2|+11
(wmbus) telegram from TODO ignored by all configured meters!
(serial) received binary "62354534343244324331333731393338323430303438453746374144453130"
(cul) checkCULFrame "b5E442D2C1371938240048E7F7ADE10"
(cul) no eol found yet, partial frame
(serial) received binary "35303235414231414541333038303731383446414637414445344643384144364439314341384541333535303136354639393337304646373841"
(cul) checkCULFrame "b5E442D2C1371938240048E7F7ADE105025AB1AEA30807184FAF7ADE4FC8AD6D91CA8EA3550165F99370FF78A"
(cul) no eol found yet, partial frame
(serial) received binary "30464134423245423234413539453139303032314638334137343744463536363339443936374538383332443431313535333235323636464244423530313039434543383430364437413632324534363539373443383137463739393942444642453443373033323643313236383035424233463934314345464637454435453645383036410D0A"
(cul) checkCULFrame "b5E442D2C1371938240048E7F7ADE105025AB1AEA30807184FAF7ADE4FC8AD6D91CA8EA3550165F99370FF78A0FA4B2EB24A59E190021F83A747DF56639D967E8832D41155325266FBDB50109CEC8406D7A622E465974C817F7999BDFBE4C70326C126805BB3F941CEFF7ED5E6E806A<0D><0A>"
(cul) checkCULFrame RSSI_RAW=106
(cul) checkCULFrame LQI=64
(wmbus) trimming frame A "5E442D2C1371938240048E7F7ADE105025AB1AEA30807184FAF7ADE4FC8AD6D91CA8EA3550165F99370FF78A0FA4B2EB24A59E190021F83A747DF56639D967E8832D41155325266FBDB50109CEC8406D7A622E465974C817F7999BDFBE4C70326C126805BB3F941CEFF7ED5E6E"
(wmbus) ff a dll crc 0-9 8e7f ok
(wmbus) ff a dll crc mid 12-27 fc8a ok
(wmbus) ff a dll crc mid 30-45 b2eb ok
(wmbus) ff a dll crc mid 48-63 832d ok
(wmbus) ff a dll crc mid 66-81 2e46 ok
(wmbus) ff a dll crc mid 84-99 bb3f ok
(wmbus) ff a dll crc final 102-106 5e6e ok
(wmbus) trimming frame A "5E442D2C1371938240048E7F7ADE105025AB1AEA30807184FAF7ADE4FC8AD6D91CA8EA3550165F99370FF78A0FA4B2EB24A59E190021F83A747DF56639D967E8832D41155325266FBDB50109CEC8406D7A622E465974C817F7999BDFBE4C70326C126805BB3F941CEFF7ED5E6E"
(wmbus) trimmed 14 dll crc bytes from frame a and ignored 0 suffix bytes.
(wmbus) trimmed frame A "5E442D2C1371938240047ADE105025AB1AEA30807184FAF7ADE4D6D91CA8EA3550165F99370FF78A0FA424A59E190021F83A747DF56639D967E841155325266FBDB50109CEC8406D7A625974C817F7999BDFBE4C70326C126805941CEFF7ED"
(cul) received full T1 frame
(meter) no meter handled checking 0 templates.
(wmbus) parseDLL @0 95
(wmbus) parseELL @10 85
(wmbus) parseNWL @10 85
(wmbus) parseAFL @10 85
(wmbus) parseTPL @10 85
(wmbus) parseDLL @0 95
(telegram) DLL L=5e C=44 (from meter SND_NR) M=2c2d (KAM) A=82937113 VER=40 TYPE=04 (Heat meter) (driver kamheat) DEV=cul RSSI=-21
(wmbus) parseELL @10 85
(wmbus) parseNWL @10 85
(wmbus) parseAFL @10 85
(wmbus) parseTPL @10 85
`

and after some telegrams (10 to 100 seconds) ttyusb vanishes magically:

`(serial) received binary ""
(serial) received binary ""
(serial) received binary ""
(serial) device /dev/ttyUSB0 is gone
(serial) closing non working fd=3 "/dev/ttyUSB0"
(wmbus) disconnected /dev/ttyUSB0 cul
(serialtty) closed /dev/ttyUSB0 (cul)
(cul) getDeviceId
Lost /dev/ttyUSB0 closing cul
(wmbus) closing....
(wmbus) deleted cul
No wmbus device detected, waiting for a device to be plugged in.
(shell) exec (capture output) "/bin/pidof"
(shell) arg "wmbusmetersd"
(shell) output: >>><<<
(shell) return code 1
(shell) 15275 exited
(shell) exec (capture output) "/bin/pidof"
(shell) arg "wmbusmeters"
(serial) EVENT thread interrupted
(shell) output: >>>15268 11990
<<<
(shell) return code 0
(shell) 15276 exited
(serial) EVENT thread interrupted
Notice! Other wmbusmeters (pid 11990) is running and it might hog any wmbus devices.
[ALARM SpecifiedDeviceNotFound] the device /dev/ttyUSB0:cul:t1 is not working
(serial) TIMER thread interrupted
(serial) EVENT thread interrupted