Loading SPI_CLK is no good

Technical discussions related to any XMOS development kit or reference design. Eg XK-1A, sliceKIT, etc.
User avatar
aclassifier
Respected Member
Posts: 483
Joined: Wed Apr 25, 2012 8:52 pm
Contact:

Loading SPI_CLK is no good

Post by aclassifier »

I am testing an xCORE-200 eXplorerKIT with a WiFI sliceCARD. The full background is described in a blog note [1]. The main problem here goes like this:

If I connect the SPI_CLK output pin to my BitScope USB scope I get a crash when I run in xTIMEcomposer. That goes even if I use a USB isolator. The scope has internal impedance of 1M||50pF. The crash I get looks like this:

Code: Select all

[  555 ms] **WELCOME TO THE SIMPLE WEBSERVER DEMO**
[  606 ms] Switching on Wi-Fi module.... 
[  657 ms] init
[ 1761 ms] WriteN 1 10   // In wifi_tiwisl_spi_first_write
[ 2416 ms] read2 1 ff.ff // After last spi_master_in_buffer in wifi_tiwisl_spi_read 
                         // in file wifi_tiwisl_spi.xc in module module_wifi_tiwisl
xrun: Program received signal ET_ILLEGAL_PC, Illegal program counter.
      [Switching to tile[0] core[1]]
      0xffffffff in ?? ()
This is 100% repeatable. If I connect the scope when it’s started OK then all is fine. // Commented text is mine.
  • If connect a 1M||47pF between SPI_CLK and GND then it hangs after the “init” text. Repeatable
  • If connect a 1M||47pF between SPI_CLK and 3V3 then it hangs after the “WriteN 1 10” text. Repeatable
  • If I connect any of these when it’s started OK, it stops. I even see it stop during startup with just the 20 cm wire hanging on SPI_CLK
I can understand the complete stop behaviour since the code does blocking calls waiting for things to go high or low with no timeout. But then, the SPI_CLK is just an output, isn’t it?

But the elegant message from xrun is more than I understand. How can the program counter become illegal? What's going on?

[1] http://www.teigfam.net/oyvind/home/tech ... otes-wifi/ (Disclaimer: no ads, no money, no gifts, just hobby!) You will also find this XCore text in that blog note, and I will link this up.


--
Øyvind Teig
Trondheim (Norway)
https://www.teigfam.net/oyvind/home/
User avatar
infiniteimprobability
XCore Legend
Posts: 1126
Joined: Thu May 27, 2010 10:08 am
Contact:

Post by infiniteimprobability »

I followed the link. Nice piece of work! You have clearly spent a lot of time and effort here.

Regarding loading the CLK output, I wonder if it is related to the way clocks are handled in the architecture? If you make an I/O pin an output from a clock block AND carry that clock into another clock block then the carried signal is actually derived from the pad (after the output buffer). This gives the unwanted side effect that loading the clock output pin can affect the downstream logic.

For example, in the old I2S scheme where the BCLK was a port output that also clocked the BCLK clock block (which clocks the data and LR), poor SI on the BCLK line could cause double clocking due to reflections coming back along the transmission line. Good SI/board design and/or using series resistors (22-33R) will avoid this as will using a buffer.

Regarding the exception.. that is strange. It would be good to know how -1 got loaded into the PC. XC is generally pretty safe (refs instead of pointers, array bounds checking..) but if there is a layer of C in there it may explain things as too many clocks/received words may cause something to fall off the end of it's buffer.

Some more debug visibility would be good. Try:

Code: Select all

xrun --dumpstate <mybin.xe>
after xrun has hit the exception.

In particular the SPC and backtrace may tell us how it got there.
User avatar
aclassifier
Respected Member
Posts: 483
Joined: Wed Apr 25, 2012 8:52 pm
Contact:

Post by aclassifier »

I'll be back in a day or two with the details you query for.
Off Topic
I followed the link. Nice piece of work! You have clearly spent a lot of time and effort here.
infiniteimprobability, thank you very much for the compliment! It warmed!-)
--
Øyvind Teig
Trondheim (Norway)
https://www.teigfam.net/oyvind/home/
User avatar
aclassifier
Respected Member
Posts: 483
Joined: Wed Apr 25, 2012 8:52 pm
Contact:

Post by aclassifier »

I hope this helps. I started SetEnv.command (beside xtimecomposer.app) and went, in the terminal window that then opened, all the way to my <bin> directory. First this:

Code: Select all

bash-3.2$ xrun -l

Available XMOS Devices
----------------------

  ID	Name			Adapter ID	Devices
  --	----			----------	-------
  0 	XMOS XTAG-3         	mqnHNZCF	O[0]
and then this:

Code: Select all

bash-3.2$ xrun --version
Community_14.3.0 (build 16341, Apr-10-2017)
Copyright (C) XMOS Limited 2008-2017. All Rights Reserved.
Finally the magic you asked for. I attach all files in a zip.

Code: Select all

bash-3.2$ xrun --dumpstate _app_tiwisl_simple_webserver.xe
xrun: Program received signal ET_ILLEGAL_PC, Illegal program counter.
      [Switching to tile[0] core[2]]
      0xffffffff in ?? ()

      
      ***** Active Cores *****
        4  tile[1] core[0]  0x00040440 in _done ()
      * 3  tile[0] core[2]  0xffffffff in ?? ()
        2  tile[0] core[1]  xtcp_wifi_on (c_xtcp=2147614978) at /Users/teig/workspace/module_wifi_tiwisl/src/xtcp_client.xc:64
        1  tile[0] core[0]  0x00041702 in wifi_led_server (i_wifi_led_server=@0x7ff30, wifi_led_ports=<value optimized out>) at /Users/teig/workspace/module_wifi_tiwisl/src/wifi_tiwisl/wifi_led_server.xc:22
      
      Thread 4 (tile[1] core[0]):
      
      ***** Call Stack *****
      #0  0x00040440 in _done ()
      #1  0x0004043e in _done ()
      Backtrace stopped: previous frame identical to this frame (corrupt stack?)
      
      ***** Disassembly *****
      0x40440 <_done+12>:	waiteu (0r)      *
      0x40442:	stw (2rus)      r0, r0[0x0]
      0x40444 <_exit>:	entsp (lu6)     0x0
      0x40448 <_exit+4>:	add (2rus)      r1, r0, 0x0
      0x4044a <_exit+6>:	ldc (ru6)       r0, 0x0
      
      ***** Registers *****
      r0             0x7	7
      r1             0xffffffff	-1
      r2             0x1	1
      r3             0x0	0
      r4             0x2	2
      r5             0x0	0
      r6             0x0	0
      r7             0x0	0
      r8             0x0	0
      r9             0x0	0
      r10            0x40000	262144
      r11            0x0	0
      cp             0x40c14	265236
      dp             0x40c68	265320
      sp             0x7ff70	524144
      lr             0x4043e	263230	 _done + 10
      pc             0x40440	263232	 _done + 12
      sr             0x1	1
      spc            0x0	0
      ssr            0x0	0
      et             0x0	0
      ed             0x0	0
      sed            0x0	0
      kep            0x40080	262272
      ksp            0x40440	263232
      
      Thread 3 (tile[0] core[2]):
      
      ***** Call Stack *****
      #0  0xffffffff in ?? ()
      #1  0x0004497e in __sfvwrite ()
      #2  0x00044414 in __sprint ()
      #3  0x00043fe8 in vfiprintf ()
      #4  0x000427ca in iprintf ()
      #5  0x00041fce in wifi_tiwisl_spi_read (spi_if=<value optimized out>, spi_tiwisl_ctrl=<value optimized out>, buffer=<value optimized out>, num_bytes=65535, bypass_cmd=1) at /Users/teig/workspace/module_wifi_tiwisl/src/wifi_tiwisl/wifi_tiwisl_spi.xc:127
      #6  0x00041d5c in read_and_wait_for_event (tiwisl_spi=@0x459d0, tiwisl_ctrl=@0x459e8, opcode=16384, i_wifi_led_server=524072) at /Users/teig/workspace/module_wifi_tiwisl/src/wifi_tiwisl/wifi_tiwisl_server.xc:167
      #7  0x00041cf4 in write_and_wait_for_event (tiwisl_spi=@0x459d0, tiwisl_ctrl=@0x459e8, len=<value optimized out>, opcode=16384, i_wifi_led_server=524072) at /Users/teig/workspace/module_wifi_tiwisl/src/wifi_tiwisl/wifi_tiwisl_server.xc:144
      #8  0x000418fe in wifi_tiwisl_server (c_xtcp=2147614722, tiwisl_spi=@0x459d0, tiwisl_ctrl=@0x459e8, i_wifi_led_server=524072) at /Users/teig/workspace/module_wifi_tiwisl/src/wifi_tiwisl/wifi_tiwisl_server.xc:305
      #9  0x0004128d in __main__main_tile_0_task_xhttpd_1 (frame=0x0) at ../src/main.xc:42
      #10 0x00044514 in __start_core ()
      
      ***** Disassembly *****
      0xffffffff:	stw (ru6)       r4, dp[0x11]
      0x1:	and (3r)        r11, r8, r4
      0x3:	stw (ru6)       r4, dp[0x11]
      0x5:	and (3r)        r11, r8, r4
      0x7:	stw (ru6)       r4, dp[0x11]
      
      ***** Registers *****
      r0             0x0	0
      r1             0xffffffff	-1
      r2             0x4542c	283692
      r3             0x1	1
      r4             0x40	64
      r5             0x46710	288528
      r6             0x7f168	520552
      r7             0x4542c	283692
      r8             0x1	1
      r9             0x1	1
      r10            0x0	0
      r11            0xffffffff	-1
      cp             0x45228	283176
      dp             0x45838	284728
      sp             0x7f068	520296
      lr             0x4497e	280958	 __sfvwrite + 158
      pc             0xffffffff	-1
      sr             0x10	16
      spc            0xffffffff	-1
      ssr            0x0	0
      et             0x2	2
      ed             0x0	0
      sed            0x80020002	-2147352574
      kep            0x40080	262272
      ksp            0x400a4	262308
      
      Thread 2 (tile[0] core[1]):
      
      ***** Call Stack *****
      #0  xtcp_wifi_on (c_xtcp=2147614978) at /Users/teig/workspace/module_wifi_tiwisl/src/xtcp_client.xc:64
      #1  0x000412ec in xhttpd (c_wifi=<value optimized out>, i_wifi_led_server=<value optimized out>) at ../src/xhttpd.xc:65
      #2  0x000412a1 in __main__main_tile_0_task_wifi_led_server_2 (frame=0x80020102) at ../src/main.xc:43
      Backtrace stopped: frame did not save the PC
      
      ***** Disassembly *****
      0x4156c <xtcp_wifi_on+28>:	chkct (rus)     res[r0], 0x1 *
      0x4156e <xtcp_wifi_on+30>:	outct (rus)     res[r0], 0x1 *
      0x41570 <xtcp_wifi_on+32>:	in (2r)         r1, res[r0] *
      0x41572 <xtcp_wifi_on+34>:	chkct (rus)     res[r0], 0x1 *
      0x41574 <xtcp_wifi_on+36>:	outct (rus)     res[r0], 0x1 *
      
      ***** Registers *****
      r0             0x80020102	-2147352318
      r1             0x0	0
      r2             0x467f8	288760
      r3             0x34	52
      r4             0x7ff1c	524060
      r5             0x80020102	-2147352318
      r6             0x0	0
      r7             0x0	0
      r8             0x0	0
      r9             0x0	0
      r10            0x0	0
      r11            0x44e6c	282220
      cp             0x45228	283176
      dp             0x45838	284728
      sp             0x7fe90	523920
      lr             0x412ec	266988	 _Sxhttpd_0 + 64
      pc             0x4156c	267628	 xtcp_wifi_on + 28
      sr             0x40	64
      spc            0x0	0
      ssr            0x0	0
      et             0x0	0
      ed             0x0	0
      sed            0x0	0
      kep            0x40080	262272
      ksp            0x4156c	267628
      
      Thread 1 (tile[0] core[0]):
      
      ***** Call Stack *****
      #0  0x00041702 in wifi_led_server (i_wifi_led_server=@0x7ff30, wifi_led_ports=<value optimized out>) at /Users/teig/workspace/module_wifi_tiwisl/src/wifi_tiwisl/wifi_led_server.xc:22
      #1  0x000412ac in __main__main_tile_0_task_wifi_led_server_2 (frame=0x7ff30) at ../src/main.xc:43
      #2  0x000428cc in __start_other_cores ()
      #3  0x0004126d in __main__main_tile_0_task_wifi_tiwisl_server_0 (frame=0x7ff30) at ../src/main.xc:41
      #4  0x80020302 in ?? ()
      Backtrace stopped: frame did not save the PC
      
      ***** Disassembly *****
      0x41702 <wifi_led_server+102>:	waiteu (0r)      *
      0x41704 <wifi_led_server+104>:	get (0r)        r11, ed
      0x41706 <wifi_led_server+106>:	zext (rus)      r11, 0x10
      0x41708 <wifi_led_server+108>:	ldw (3r)        r3, r0[r11]
      0x4170a <wifi_led_server+110>:	ldw (2rus)      r3, r3[0x0]
      
      ***** Registers *****
      r0             0x7ff30	524080
      r1             0x0	0
      r2             0x1	1
      r3             0x41704	268036
      r4             0x40300	262912
      r5             0xd	13
      r6             0x7ff24	524068
      r7             0x7ff18	524056
      r8             0x6	6
      r9             0xfffffffd	-3
      r10            0x80020302	-2147351806
      r11            0x1	1
      cp             0x45228	283176
      dp             0x45838	284728
      sp             0x7fed8	523992
      lr             0x412ac	266924	 _Sxhttpd_0 + 0
      pc             0x41702	268034	 _Swifi_led_server_0 + 102
      sr             0x41	65
      spc            0x0	0
      ssr            0x0	0
      et             0x0	0
      ed             0x0	0
      sed            0x0	0
      kep            0x40080	262272
      ksp            0x41702	268034
ksp            0x41702	268034
Attachments
2017 09 20 A Loading SPI_CLK is no good.zip
All work spaces I use
(1.69 MiB) Downloaded 294 times
2017 09 20 A Loading SPI_CLK is no good.zip
All work spaces I use
(1.69 MiB) Downloaded 294 times
--
Øyvind Teig
Trondheim (Norway)
https://www.teigfam.net/oyvind/home/
User avatar
infiniteimprobability
XCore Legend
Posts: 1126
Joined: Thu May 27, 2010 10:08 am
Contact:

Post by infiniteimprobability »

Hi,
thanks for the code..

The relevant bit of the dump state is:

Code: Select all

***** Call Stack *****
      #0  0xffffffff in ?? ()
      #1  0x0004497e in __sfvwrite ()
      #2  0x00044414 in __sprint ()
      #3  0x00043fe8 in vfiprintf ()
      #4  0x000427ca in iprintf ()
      #5  0x00041fce in wifi_tiwisl_spi_read (spi_if=<value optimized out>, spi_tiwisl_ctrl=<value optimized out>, buffer=<value optimized out>, num_bytes=65535, bypass_cmd=1) at /Users/teig/workspace/module_wifi_tiwisl/src/wifi_tiwisl/wifi_tiwisl_spi.xc:127
Somewhere down the call stack from printf we can see an issue.

Looking at your code I can see a lot of printfs in the spi read/writes. Not an ideal place to put a print because higher layers may not be expecting to wait for a while. Also, debug_printf (lib_logging) is a LOT lighter weight for real time printing. It may not be the source of the issue.

I'm wondering whether spi_master_in_buffer gets upset if it sees too many clocks.. I am not sure how this could be the case though as I would expect wrong data but no overruns..
User avatar
aclassifier
Respected Member
Posts: 483
Joined: Wed Apr 25, 2012 8:52 pm
Contact:

Post by aclassifier »

I have removed the debug prints by setting the control defines from 1 to 0.

There is a different behaviour, but it is probably not as expected. In all cases it just hangs. But when I try to run it without the scope on SPI_CLK it works in all cases, with different degree of debug prints of course. I also tried, after this to compile as before and then I get the expected crash.

In any case there is a light load on a pin that makes the processor show this not expected behaviour.

The examples

Code: Select all

FIRST:  DEBUG_PRINT_SPI=0 
SECOND: DEBUG_PRINT_SPI=0 DEBUG_PRINT_EVENT_HANDLER=0
THIRD:  DEBUG_PRINT_SPI=0 DEBUG_PRINT_EVENT_HANDLER=0 DEBUG_TIWISL_SERVER_PRINTSTRLN=0
========== FIRST EXAMPLE ==========

Code: Select all

#define DEBUG_PRINT_SPI 0 // Teig. infiniteimprobability suggested to remove this (was 1)
== New result is simple hang with SPI_CLK connected to scope ==

Code: Select all

[  539 ms] **WELCOME TO THE SIMPLE WEBSERVER DEMO**
[  590 ms] Switching on Wi-Fi module.... 
== Same with scope not connected to SPI_CLK. Works. Since it doesn't spend time to print, LED1 is'nt seen blinking when it polls the Wifi card. When I scope it I see a period of 300 us with 186 us on ==

Code: Select all

[  545 ms] **WELCOME TO THE SIMPLE WEBSERVER DEMO**
[  596 ms] Switching on Wi-Fi module.... 
[ 2915 ms] Connecting to OM11-4
[10175 ms] #### #### IP Address:  192.168.1.9

(10175 ms) not httpd_handle_event 9 XTCP_IFUP new ip address
(42122 ms) httpd_handle_event 0 XTCP_NEW_CONNECTION
(42152 ms) httpd_handle_event 1 XTCP_RECV_DATA
(42203 ms) GET "Hello World! 1"

(42311 ms) httpd_handle_event 2 XTCP_REQUEST_DATA
(42356 ms) httpd_handle_event 3 XTCP_SENT_DATA
(  463 ms) #### #### Unsolicited event 4

(  573 ms) httpd_handle_event 7 XTCP_CLOSED

(17402 ms) httpd_handle_event 0 XTCP_NEW_CONNECTION
(17466 ms) httpd_handle_event 1 XTCP_RECV_DATA
(17518 ms) GET "Hello World! 2"

(17629 ms) httpd_handle_event 2 XTCP_REQUEST_DATA
(17677 ms) httpd_handle_event 3 XTCP_SENT_DATA
(18734 ms) #### #### Unsolicited event 4

(18856 ms) httpd_handle_event 7 XTCP_CLOSED

(20536 ms) httpd_handle_event 0 XTCP_NEW_CONNECTION
(20568 ms) httpd_handle_event 1 XTCP_RECV_DATA
(20622 ms) GET "Hello World! 3"

(20729 ms) httpd_handle_event 2 XTCP_REQUEST_DATA
(20776 ms) httpd_handle_event 3 XTCP_SENT_DATA
(21832 ms) #### #### Unsolicited event 4

(22067 ms) httpd_handle_event 7 XTCP_CLOSED
========== SECOND EXAMPLE ==========

Code: Select all

#define DEBUG_PRINT_EVENT_HANDLER 0  // infiniteimprobability suggested to remove this (was 1). Second example (DEBUG_PRINT_SPI still 0)
== New result is also simple hang with SPI_CLK connected to scope ==

Code: Select all

[  540 ms] **WELCOME TO THE SIMPLE WEBSERVER DEMO**
[  592 ms] Switching on Wi-Fi module....
== Same with scope not connected to SPI_CLK works ==

Code: Select all

[  543 ms] **WELCOME TO THE SIMPLE WEBSERVER DEMO**
[  595 ms] Switching on Wi-Fi module.... 
[ 2916 ms] Connecting to OM11-4
[10151 ms] #### #### IP Address:  192.168.1.9

(10151 ms) not httpd_handle_event 9 XTCP_IFUP new ip address
(17747 ms) httpd_handle_event 0 XTCP_NEW_CONNECTION
(17800 ms) httpd_handle_event 1 XTCP_RECV_DATA
(17853 ms) GET "Hello World! 1"

(17961 ms) httpd_handle_event 2 XTCP_REQUEST_DATA
(18008 ms) httpd_handle_event 3 XTCP_SENT_DATA
(19072 ms) httpd_handle_event 7 XTCP_CLOSED

(22116 ms) httpd_handle_event 0 XTCP_NEW_CONNECTION
(22151 ms) httpd_handle_event 1 XTCP_RECV_DATA
(22203 ms) GET "Hello World! 2"

(22322 ms) httpd_handle_event 2 XTCP_REQUEST_DATA
(22359 ms) httpd_handle_event 3 XTCP_SENT_DATA
(23427 ms) httpd_handle_event 7 XTCP_CLOSED

(25306 ms) httpd_handle_event 0 XTCP_NEW_CONNECTION
(25355 ms) httpd_handle_event 1 XTCP_RECV_DATA
(25407 ms) GET "Hello World! 3"

(25516 ms) httpd_handle_event 2 XTCP_REQUEST_DATA
(25563 ms) httpd_handle_event 3 XTCP_SENT_DATA
(26726 ms) httpd_handle_event 7 XTCP_CLOSED
========== THIRD EXAMPLE ==========

Code: Select all

#define DEBUG_TIWISL_SERVER_PRINTSTRLN 0 // Original in code. infiniteimprobability suggested to remove this (was 1). Third example
== New result is even now simple hang with SPI_CLK connected to scope ==

Code: Select all

[  534 ms] **WELCOME TO THE SIMPLE WEBSERVER DEMO**

== Same with scope not connected to SPI_CLK works == 

[  536 ms] **WELCOME TO THE SIMPLE WEBSERVER DEMO**
( 9596 ms) not httpd_handle_event 9 XTCP_IFUP new ip address
(24571 ms) httpd_handle_event 0 XTCP_NEW_CONNECTION
(24615 ms) httpd_handle_event 1 XTCP_RECV_DATA
(24667 ms) GET "Hello World! 1"

(24775 ms) httpd_handle_event 2 XTCP_REQUEST_DATA
(24820 ms) httpd_handle_event 3 XTCP_SENT_DATA
(25885 ms) httpd_handle_event 7 XTCP_CLOSED

(28728 ms) httpd_handle_event 0 XTCP_NEW_CONNECTION
(28775 ms) httpd_handle_event 1 XTCP_RECV_DATA
(28826 ms) GET "Hello World! 2"

(29036 ms) httpd_handle_event 2 XTCP_REQUEST_DATA
(29096 ms) httpd_handle_event 3 XTCP_SENT_DATA
(30164 ms) httpd_handle_event 7 XTCP_CLOSED
If I remove the wifiCARD then I get this log, with all debug print on. In this case it makes no difference whether SPI_CLK has the scope cable or not. Alas, the driver doesn't have any timeout to detect that the card is unplugged, and therefore may not come to the expected crash:

Code: Select all

[  551 ms] **WELCOME TO THE SIMPLE WEBSERVER DEMO**
[  602 ms] Switching on Wi-Fi module.... 
[  653 ms] init
--
Øyvind Teig
Trondheim (Norway)
https://www.teigfam.net/oyvind/home/
Gothmag
XCore Addict
Posts: 129
Joined: Wed May 11, 2016 3:50 pm

Post by Gothmag »

Where and how are you probing this? What does the clock signal look like with the wifi card unplugged? Depending on the construction of it all you may just be real close to having an erroneous signal so adding the scope probe degrades it enough that it fails entirely. 12.5mhz isn't too fast, but it isn't slow either. Might try adding a low value series resistor(on the clock line/trace) if you need to probe the clock line if it isn't too much trouble, if it starts failing all the time it doesn't have the drive strength for your setup... The drive for an XMOS chip isn't terribly strong. If you can't find any other problems I'd probably write a quick program to prove the SPI bus is functional while probing with a different MCU that has a stronger drive current, if it has no problems you're just running into physical limits of your setup, so lower clock speed or don't probe it. If you can post photos of your signal with no wifi card, and even with if you can get anything. I'd also suggest not adding prints in the SPI code, it should all be done outside of transfers if it isn't. SPI timing is not forgiving at all.
User avatar
aclassifier
Respected Member
Posts: 483
Joined: Wed Apr 25, 2012 8:52 pm
Contact:

Post by aclassifier »

My BitScope samples at 20 MS/S, so I'd have to make a loop to see if I could use the sub-sampling at 500 MS/s. So I have no picture for you at the moment. That's what started this, I wanted to have a look, to see the signals. It's always nice to see. I must admit, I have ben looking for higher sampling rate USB scopes. (PICOSCOPE 2208B does 1GS/S.. and I could afford it)

I have double sets of xCORE-200 eXplorer boards and WiFi sliceCARDs and I have tried all permutations with and without load on PCI_CLK and I can not see any different behaviour. They simply never pass the stop point when loaded, always work fine and returns "Hello World X" over the air when not loaded.

Thinking about printing that collides with the SPI bus, what is the XMOS thinking here? Let's say that the SPI bus runs on one core alone (I know, it doesn't), that relates to a USART connected to interrupts on something like an ATMega, so it wouldn't really load the SPI I guess, by some clever design. Yes I know, printing is never really for free. Why is debug_printf (lib_logging) is a LOT lighter weight for real time printing? Does the debug usart enter the debug core, and floats over to XTAG3? Or is there the standard formatting that takes cycles here? When will debug print delay the SPI bus? That being said, when I did remove the debug (as seen above) loading of the SPI_CLK it still stopped. Ok that it one can see trace of prints in the crash call stack, but does that prove that this is the cause? An SPI bus that doesn't work will let the WiFi card rather alone, but shouldn't halt the XCORE, really? Or is it just the result? There is no debug prints in spi_master in any case. But as long as spi_master is not a task with its own core I guess you have a point. I have a feeling that the design here is not optimal.

ASIDE right now:
I see that when it "just hangs" with no crash error in the console, I now do see crash info in the Debug window, with stack trace like. By the way, this is with a different WiFi board. Same behaviour. First the log:

Code: Select all

[  582 ms] **WELCOME TO THE SIMPLE WEBSERVER DEMO**
[  634 ms] Switching on Wi-Fi module.... 
[  687 ms] init
[ 1791 ms] WriteN 1 10
[ 2463 ms] read2 1 ff.ff
..missing this:

Code: Select all

xrun: Program received signal ET_ILLEGAL_PC, Illegal program counter.
      [Switching to tile[0] core[2]]
      0xffffffff in ?? ()
..then the Debug stack:

Code: Select all

_app_tiwisl_simple_webserver.xe [xCORE Application]	
	xCORE Debugger (10:18 21.09.17) (Suspended)	
		tile[0] core[0]  (Suspended)	
			2 wifi_led_server() wifi_led_server.xc:29 0x00041718	
			1 xhttpd() xhttpd.xc:58 0x000412ad	
		tile[0] core[1]  (Suspended)	
			3 xtcp_wifi_on() xtcp_client.xc:64 0x0004156c	
			2 xhttpd() xhttpd.xc:65 0x000412ec	
			1 __main__main_tile_0_task_wifi_led_server_2() main.xc:43 0x000412a1	
		tile[0] core[2]  (Suspended: Signal 'ET_ILLEGAL_PC' received. Description: Illegal program counter.)	
			11 <symbol is not available> 0xffffffff	
			10 __sfvwrite()  0x000449ce	
			9 __sprint()  0x00044464	
			8 vfiprintf()  0x00044038	
			7 iprintf()  0x0004281a	
			6 wifi_tiwisl_spi_read() wifi_tiwisl_spi.xc:127 0x0004201e	
			5 read_and_wait_for_event() wifi_tiwisl_server.xc:167 0x00041dac	
			4 write_and_wait_for_event() wifi_tiwisl_server.xc:144 0x00041d44	
			3 wifi_tiwisl_server() wifi_tiwisl_server.xc:305 0x0004194e	
			2 __main__main_tile_0_task_xhttpd_1() main.xc:42 0x0004128d	
			1 __start_core()  0x00044564	
		tile[1] core[0]  (Suspended)	
			2 _done()  0x00040440	
			1 _done()  0x0004043e	
	xgdb (10:18 21.09.17)	
	/Users/teig/workspace/_app_tiwisl_simple_webserver/bin/_app_tiwisl_simple_webserver.xe (10:18 21.09.17)	
..or maybe this is just because I by coincidence was doung Debug instead of Run? I tested this, and it's probably so. When it "hangs" after this:

Code: Select all

[  564 ms] **WELCOME TO THE SIMPLE WEBSERVER DEMO**

when run as Debug it shows this with SPI_CLK connected and nothing if I do Run:

Code: Select all

_app_tiwisl_simple_webserver.xe [xCORE Application]	
	xCORE Debugger (10:48 21.09.17)	
		tile[0] core[0]  (Running)CDTDebugModelPresentation.12=signal	
		tile[1] core[0]  (Running)CDTDebugModelPresentation.12=signal	
	xgdb (10:48 21.09.17)	
	/Users/teig/workspace/_app_tiwisl_simple_webserver/bin/_app_tiwisl_simple_webserver.xe (10:48 21.09.17)
--
Øyvind Teig
Trondheim (Norway)
https://www.teigfam.net/oyvind/home/
User avatar
aclassifier
Respected Member
Posts: 483
Joined: Wed Apr 25, 2012 8:52 pm
Contact:

Post by aclassifier »

I have now switched to debug_printf. I discovered it was called lib_logging and imported it the normal way, and that it was not this: https://www.xmos.com/published/debug-printing-module

However, it still stops when I load SPI_CLK.

Is there a different drive cabability on the xCORE-200 eXplorer than on the same pins of the startKIT processor? I have used the same pin mapping.

I will try (within a day or two) to see whether we have the same SPI_CLK load matter on the startKIT and come back here.
--
Øyvind Teig
Trondheim (Norway)
https://www.teigfam.net/oyvind/home/
User avatar
infiniteimprobability
XCore Legend
Posts: 1126
Joined: Thu May 27, 2010 10:08 am
Contact:

Post by infiniteimprobability »

However, it still stops when I load SPI_CLK.

Is there a different drive cabability on the xCORE-200 eXplorer than on the same pins of the startKIT processor? I have used the same pin mapping.
Hmm - does definitely sound like this issue about cascaded clocks going via the output pad.
xCORE-200 drive is the same drive strength - 4mA, although the pin in reality drives pretty hard (hence why series resistors on clock lines are a good idea). A handful of pins are 8mA:


https://www.google.co.uk/url?sa=t&rct=j ... tg2GnE74Ng
Post Reply