SimpleSerial `WARNING:root:Unexpected start to command:`

I also posted this issue on Github already, but figured I might also try here. Issue follows, any help appreciated!

I have a CWLite with an STM32F4 target. Using the chipwhisperer virtual machine (version 5.5.1) I get a WARNING:root:Unexpected start to command: None when I try out a the simpleserial-base example. How would I go about debugging this?

I executed the following commands in the jupyer notebook:

import chipwhisperer as cw
scope = cw.scope()
target = cw.target(scope, cw.targets.SimpleSerial)
scope.default_setup()
cw.program_target(scope, cw.programmers.STM32FProgrammer, "../hardware/victims/firmware/simpleserial-base/simpleserial-base-CW308_STM32F4.hex")

This seems to work:

Serial baud rate = 115200
Detected known STMF32: STM32F40xxx/41xxx
Extended erase (0x44), this can take ten seconds or more
Attempting to program 5315 bytes at 0x8000000
STM32F Programming flash...
STM32F Reading flash...
Verified flash OK, 5315 bytes
Serial baud rate = 38400

Now I build the simpleserial-base example and want to send a simple message:

%%bash
cd …/hardware/victims/firmware/simpleserial-base/
make PLATFORM=“CW308_STM32F4” CRYPTO_TARGET=NONE
msg = bytearray([1,2,3,4])
target.simpleserial_write(“p”,msg)
print(target.simpleserial_read(“r”, 1000, timeout=10000))

which returns the error:

WARNING:root:Unexpected start to command: 
None

Printing the variables scope and target:

print(scope)
cwlite Device
sn         = 50203220313038543230323239313037
fw_version = 
    major = 0
    minor = 30
    debug = 0
gain = 
    mode = low
    gain = 0
    db   = 5.5
adc = 
    state          = False
    basic_mode     = low
    timeout        = 2
    offset         = 0
    presamples     = 0
    samples        = 0
    decimate       = 1
    trig_count     = 6010355
    fifo_fill_mode = normal
clock = 
    adc_src       = clkgen_x1
    adc_phase     = 0
    adc_freq      = 0
    adc_rate      = 0.0
    adc_locked    = True
    freq_ctr      = 0
    freq_ctr_src  = extclk
    clkgen_src    = system
    extclk_freq   = 10000000
    clkgen_mul    = 2
    clkgen_div    = 1
    clkgen_freq   = 192000000.0
    clkgen_locked = True
trigger = 
    triggers = tio4
    module   = basic
io = 
    tio1         = serial_tx
    tio2         = serial_rx
    tio3         = high_z
    tio4         = high_z
    pdid         = high_z
    pdic         = high_z
    nrst         = high_z
    glitch_hp    = False
    glitch_lp    = False
    extclk_src   = hs1
    hs2          = None
    target_pwr   = True
    tio_states   = (1, 1, 0, 0)
    cdc_settings = array('B', [1, 1])
glitch = 
    clk_src     = target
    width       = 10.15625
    width_fine  = 0
    offset      = 10.15625
    offset_fine = 0
    trigger_src = manual
    arm_timing  = after_scope
    ext_offset  = 0
    repeat      = 1
    output      = clock_xor
   
print(target)
Serial baud rate = 38400
SimpleSerial Settings =
	output_len             = 16
	baud                   = 38400
	simpleserial_last_read = 
	simpleserial_last_sent = 
	

I’m guessing your issue is msg = bytearray([1,2,3,4]) and target.simpleserial_write(“p”,msg). The message length for 'p' is fixed at 16 bytes, so the target thinks your message isn’t valid and ignores it.

If you want to change the message length, you’ll need to update the firmware. I’d recommend using SimpleSerialV2, as it supports variable length messages.

Alex

1 Like

Hi @Alex_Dewar, @jpthibault
I am also currently facing the same issue of "WARNING:ChipWhisperer Target:Unexpected start to command: "
I use CW1200, with XMEGA target currently, I can successfully run the AES code. Now I am trying to implement other crypto algorithm instead of AES.
So I modified the .c files accordingly and they are working fine in the visual studio.
I executed the following commands in the jupyter notebook:

import chipwhisperer as cw
scope = cw.scope()
scope.default_setup()
scope.adc.samples=95000


SCOPETYPE = 'OPENADC'
VERSION = 'HARDWARE'
target=cw.target(scope,  cw.targets.SimpleSerial)

%%bash -s "$PLATFORM" "$CRYPTO_TARGET"
cd ../hardware/victims/firmware/simpleserial-newcrypto
make PLATFORM=CWLITEXMEGA  CRYPTO_TARGET=AVRCRYPTOLIB SS_VER=SS_VER_1_1 

cw.program_target(scope, cw.programmers.XMEGAProgrammer,"../hardware/victims/firmware/simpleserial-newcrypto/simpleserial-newcrypto-CWLITEXMEGA.hex" )

So it is succesfull till here,
XMEGA Programming flash…
XMEGA Reading flash…
Verified flash OK, 11677 bytes

print(target.read())

Gives following character as output
¢

proj = cw.create_project("newcrypto", overwrite=True)


from tqdm import tnrange
import numpy as np
import time

#tv1
keyd1=[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0]
textd1=[0,0,0,0,0,0,0,0]


text=bytearray(textd1)
key=bytearray(keyd1)


#trace3=cw.capture_trace(scope,target,text,key)
trace3=cw.capture_trace(scope,target,text,key)
ct=trace3.textout

Gives following warning:
WARNING:ChipWhisperer Target:Unexpected start to command:

So when I print trace3 the output is:
Trace(wave=array([ 0.09472656, -0.10058594, -0.14648438, …, 0.03417969,
0.11132812, 0.06738281]), textin=CWbytearray(b’00 00 00 00 00 00 00 00’), textout=None, key=CWbytearray(b’00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00’))

the textout value is NONE.

But, when I give

ct1=target.read()
ct1

the output is
‘r818665AA0D02DFDA0000000000000000\nz00\n’

This is the actual output required for me that is to be get assigned to textout

Following is the output of

print(scope)

cw1200 Device
sn = 50203120355448513130343230313034
fw_version =
major = 1
minor = 51
debug = 0
gain =
mode = high
gain = 30
db = 24.8359375
adc =
state = False
basic_mode = rising_edge
timeout = 2
offset = 0
presamples = 0
samples = 95000
decimate = 1
trig_count = 16554520
fifo_fill_mode = normal
stream_mode = False
clock =
adc_src = clkgen_x4
adc_phase = 0
adc_freq = 29538459
adc_rate = 29538459.0
adc_locked = True
freq_ctr = 0
freq_ctr_src = extclk
clkgen_src = system
extclk_freq = 10000000
clkgen_mul = 2
clkgen_div = 26
clkgen_freq = 7384615.384615385
clkgen_locked = True
trigger =
triggers = tio4
module = basic
aux_out = False
io =
tio1 = serial_rx
tio2 = serial_tx
tio3 = high_z
tio4 = high_z
pdid = high_z
pdic = high_z
nrst = high_z
glitch_hp = False
glitch_lp = False
extclk_src = hs1
hs2 = clkgen
target_pwr = True
tio_states = (1, 1, 0, 0)
cdc_settings = array(‘B’, [0, 0, 0, 0])
glitch =
clk_src = target
width = 10.15625
width_fine = 0
offset = 10.15625
offset_fine = 0
trigger_src = manual
arm_timing = after_scope
ext_offset = 0
repeat = 1
output = clock_xor
SAD =
threshold = 0
reference = [0]
decode_IO =
trigger_pattern = None
rx_baud = 38360.23667279412
decode_type = USART

print(target)

SimpleSerial Settings =
output_len = 16
baud = 38400
simpleserial_last_read =
simpleserial_last_sent = p0000000000000000

Following the simpleserial.c file used

#include "hal.h"
#include "simpleserial.h"
#include "newcrypto_independant.h"
#include <stdint.h>
#include <stdlib.h>

uint8_t get_key(uint8_t* k, uint8_t len)
{
	newcrypto_indep_key(k);
	return 0x00;
}

uint8_t get_pt(uint8_t* pt, uint8_t len)
{
	
     newcrypto_indep_enc_pretrigger(pt);

	trigger_high();

  #ifdef ADD_JITTER
  for (volatile uint8_t k = 0; k < (*pt & 0x0F); k++);
  #endif
    
	newcrypto_indep_enc(pt); /* encrypting the data block */
	trigger_low();

    newcrypto_indep_enc_posttrigger(pt);

	simpleserial_put('r', 16, pt); //value returned from the target
	return 0x00;
}

uint8_t reset(uint8_t* x, uint8_t len)
{
    	return 0x00;
}


int main(void)
{
	uint8_t tmp[KEY_LENGTH] = {DEFAULT_KEY};
    
    platform_init();
    init_uart();
    trigger_setup();

	newcrypto_indep_init();
	newcrypto_indep_key(tmp);

	simpleserial_init();
    
    simpleserial_addcmd('k', 16, get_key);
    simpleserial_addcmd('p', 8,  get_pt);  //plaintext is 64bits and key is 128 bits
    simpleserial_addcmd('x',  0,   reset);
	
    while(1)
        simpleserial_get();
}

Here i have tried changing as simpleserial_put(‘r’, 8, pt); instead of simpleserial_put(‘r’, 16, pt); as my expected output is 8 bytes only. but same error and i am getting the desired output at target.read() and not in textout associated with trace3.

How long does your encryption operation take? It could be that the serial read is timing out before your device starts sending data.

I can see the encryption trace getting plotted within few seconds (less than a minute) in jupyter lab. But for encryption there are many functions involved. Is there any steps to follow to find out the time taken for encryption operation?

What does scope.adc.trig_count say? That’ll give you the time between trigger_high() and trigger_low() in samples.

Alex

scope.adc.trig_count 

gives 16554520 as output.

Meanwhile I tried

target.simpleserial_read("r", 1000, timeout=10000)

which is resulting in
WARNING:ChipWhisperer Target:Unexpected start to command:

steve

Hi @Alex_Dewar,
I have updated the code and posted in the following link were I found something related, kindly suggest how to solve this issue: